Fabio: Panic - httputil: ReverseProxy read error during body copy
Hi folks,
We're seeing Fabio panic and restart sporadically, possibly related to upgrading to Fabio 1.5.15. Any thoughts?
Jan 22 12:55:08 fabio-i-02e702007d6ff3c3b fabio[4352]: invalid log msg: 2021/01/22 12:55:08 httputil: ReverseProxy read error during body copy: read tcp 10.82.225.174:48238->10.82.36.232:25851: read: connection reset by peer
Jan 22 12:55:08 fabio-i-02e702007d6ff3c3b fabio[4352]: panic: runtime error: invalid memory address or nil pointer dereference
Jan 22 12:55:08 fabio-i-02e702007d6ff3c3b fabio[4352]: [signal SIGSEGV: segmentation violation code=0x1 addr=0x18 pc=0x56fc1e]
Jan 22 12:55:08 fabio-i-02e702007d6ff3c3b fabio[4352]: goroutine 63818849 [running]:
Jan 22 12:55:08 fabio-i-02e702007d6ff3c3b fabio[4352]: bufio.(*Reader).Read(0xc0001abce0, 0xc00148e000, 0x2000, 0x2000, 0xca2500, 0xd2cc20, 0x203001)
Jan 22 12:55:08 fabio-i-02e702007d6ff3c3b fabio[4352]: #011/usr/local/Cellar/go/1.15.5/libexec/src/bufio/bufio.go:213 +0x11e
Jan 22 12:55:08 fabio-i-02e702007d6ff3c3b fabio[4352]: io.(*LimitedReader).Read(0xc002068180, 0xc00148e000, 0x2000, 0x2000, 0xce291, 0xfa6800, 0xc0054f34f0)
Jan 22 12:55:08 fabio-i-02e702007d6ff3c3b fabio[4352]: #011/usr/local/Cellar/go/1.15.5/libexec/src/io/io.go:455 +0x63
Jan 22 12:55:08 fabio-i-02e702007d6ff3c3b fabio[4352]: net/http.(*body).readLocked(0xc003786580, 0xc00148e000, 0x2000, 0x2000, 0x0, 0xc004b48c40, 0xfa6600)
Jan 22 12:55:08 fabio-i-02e702007d6ff3c3b fabio[4352]: #011/usr/local/Cellar/go/1.15.5/libexec/src/net/http/transfer.go:833 +0x5f
Jan 22 12:55:08 fabio-i-02e702007d6ff3c3b fabio[4352]: net/http.bodyLocked.Read(0xc003786580, 0xc00148e000, 0x2000, 0x2000, 0xc170a0, 0xcd68e0, 0xc0037c8d20)
Jan 22 12:55:08 fabio-i-02e702007d6ff3c3b fabio[4352]: #011/usr/local/Cellar/go/1.15.5/libexec/src/net/http/transfer.go:1032 +0x7e
Jan 22 12:55:08 fabio-i-02e702007d6ff3c3b fabio[4352]: io.(*LimitedReader).Read(0xc002a481a0, 0xc00148e000, 0x2000, 0x2000, 0xcc9ea0, 0x40a43f, 0xc00001e000)
Jan 22 12:55:08 fabio-i-02e702007d6ff3c3b fabio[4352]: #011/usr/local/Cellar/go/1.15.5/libexec/src/io/io.go:455 +0x63
Jan 22 12:55:08 fabio-i-02e702007d6ff3c3b fabio[4352]: io/ioutil.devNull.ReadFrom(0x0, 0xfa6600, 0xc002a481a0, 0xca7420, 0x1, 0x7fab6192ddf8)
Jan 22 12:55:08 fabio-i-02e702007d6ff3c3b fabio[4352]: #011/usr/local/Cellar/go/1.15.5/libexec/src/io/ioutil/ioutil.go:144 +0x92
Jan 22 12:55:08 fabio-i-02e702007d6ff3c3b fabio[4352]: io.copyBuffer(0xfa7820, 0x1489478, 0xfa6600, 0xc002a481a0, 0x0, 0x0, 0x0, 0xc000556900, 0x1, 0x0)
Jan 22 12:55:08 fabio-i-02e702007d6ff3c3b fabio[4352]: #011/usr/local/Cellar/go/1.15.5/libexec/src/io/io.go:395 +0x2ff
Jan 22 12:55:08 fabio-i-02e702007d6ff3c3b fabio[4352]: io.Copy(...)
Jan 22 12:55:08 fabio-i-02e702007d6ff3c3b fabio[4352]: #011/usr/local/Cellar/go/1.15.5/libexec/src/io/io.go:368
Jan 22 12:55:08 fabio-i-02e702007d6ff3c3b fabio[4352]: io.CopyN(0xfa7820, 0x1489478, 0xfa78e0, 0xc003786580, 0x40000, 0xc0041d0180, 0xc004b48c40, 0xc002ddb450)
Jan 22 12:55:08 fabio-i-02e702007d6ff3c3b fabio[4352]: #011/usr/local/Cellar/go/1.15.5/libexec/src/io/io.go:344 +0x9a
Jan 22 12:55:08 fabio-i-02e702007d6ff3c3b fabio[4352]: net/http.(*body).Close(0xc003786580, 0x0, 0x0)
Jan 22 12:55:08 fabio-i-02e702007d6ff3c3b fabio[4352]: #011/usr/local/Cellar/go/1.15.5/libexec/src/net/http/transfer.go:985 +0x146
Jan 22 12:55:08 fabio-i-02e702007d6ff3c3b fabio[4352]: net/http.(*Request).closeBody(...)
Jan 22 12:55:08 fabio-i-02e702007d6ff3c3b fabio[4352]: #011/usr/local/Cellar/go/1.15.5/libexec/src/net/http/request.go:1388
Jan 22 12:55:08 fabio-i-02e702007d6ff3c3b fabio[4352]: net/http.(*persistConn).writeLoop(0xc002c71440)
Jan 22 12:55:08 fabio-i-02e702007d6ff3c3b fabio[4352]: #011/usr/local/Cellar/go/1.15.5/libexec/src/net/http/transport.go:2359 +0x399
Jan 22 12:55:08 fabio-i-02e702007d6ff3c3b fabio[4352]: created by net/http.(*Transport).dialConn
Jan 22 12:55:08 fabio-i-02e702007d6ff3c3b fabio[4352]: #011/usr/local/Cellar/go/1.15.5/libexec/src/net/http/transport.go:1709 +0xcdc
evandam
All 31 comments
Still seeing this issue, dropping logs from the same error last night. Can't tell much from logs, but maybe an issue related to forming the log message or a bad request/response from an upstream that Fabio is having trouble handling?
Feb 18 10:19:31 fabio-i-05593383f9253d36c fabio[21393]: invalid log msg: 2021/02/18 10:19:31 httputil: ReverseProxy read error during body copy: http: unexpected EOF reading trailer
Feb 18 10:59:29 fabio-i-05593383f9253d36c fabio[21393]: 2021/02/18 10:59:29 [INFO] Unregistered timer _./hashi
Feb 18 10:59:29 fabio-i-05593383f9253d36c fabio[21393]: 2021/02/18 10:59:29 [INFO] Unregistered timer usw2-prod1-fabio-alb_example_com./hashi
Feb 18 10:59:29 fabio-i-05593383f9253d36c fabio[21393]: 2021/02/18 10:59:29 [INFO] Config updates
Feb 18 10:59:29 fabio-i-05593383f9253d36c fabio[21393]: - ops-hashi-ui usw2-prod1-fabio-alb.example.com/hashi http://10.82.13.58:25311/ tags "latest" opts "strip=/hashi"
Feb 18 10:59:34 fabio-i-05593383f9253d36c fabio[21393]: 2021/02/18 10:59:34 [INFO] Config updates
Feb 18 10:59:34 fabio-i-05593383f9253d36c fabio[21393]: + ops-hashi-ui usw2-prod1-fabio-alb.example.com/hashi http://10.82.13.58:25311/ tags "latest" opts "strip=/hashi"
Feb 18 11:01:24 fabio-i-05593383f9253d36c fabio[21393]: invalid log msg: 2021/02/18 11:01:24 httputil: ReverseProxy read error during body copy: read tcp 10.82.207.213:47158->10.82.42.147:31829: read: connection reset by peer
Feb 18 11:01:24 fabio-i-05593383f9253d36c fabio[21393]: panic: runtime error: invalid memory address or nil pointer dereference
Feb 18 11:01:24 fabio-i-05593383f9253d36c fabio[21393]: [signal SIGSEGV: segmentation violation code=0x1 addr=0x18 pc=0x56fc1e]
Feb 18 11:01:24 fabio-i-05593383f9253d36c fabio[21393]: goroutine 1247736 [running]:
Feb 18 11:01:24 fabio-i-05593383f9253d36c fabio[21393]: bufio.(*Reader).Read(0xc0008460c0, 0xc00154e000, 0x2000, 0x2000, 0xca2500, 0xd2cc20, 0x203001)
Feb 18 11:01:24 fabio-i-05593383f9253d36c fabio[21393]: #011/usr/local/Cellar/go/1.15.5/libexec/src/bufio/bufio.go:213 +0x11e
Feb 18 11:01:24 fabio-i-05593383f9253d36c fabio[21393]: io.(*LimitedReader).Read(0xc001e77b40, 0xc00154e000, 0x2000, 0x2000, 0x40000, 0xfa6800, 0xc000076c30)
Feb 18 11:01:24 fabio-i-05593383f9253d36c fabio[21393]: #011/usr/local/Cellar/go/1.15.5/libexec/src/io/io.go:455 +0x63
Feb 18 11:01:24 fabio-i-05593383f9253d36c fabio[21393]: net/http.(*body).readLocked(0xc002836d80, 0xc00154e000, 0x2000, 0x2000, 0x0, 0xc0023e0d40, 0xfa6600)
Feb 18 11:01:24 fabio-i-05593383f9253d36c fabio[21393]: #011/usr/local/Cellar/go/1.15.5/libexec/src/net/http/transfer.go:833 +0x5f
Feb 18 11:01:24 fabio-i-05593383f9253d36c fabio[21393]: net/http.bodyLocked.Read(0xc002836d80, 0xc00154e000, 0x2000, 0x2000, 0xc170a0, 0xcd68e0, 0xc00153a940)
Feb 18 11:01:24 fabio-i-05593383f9253d36c fabio[21393]: #011/usr/local/Cellar/go/1.15.5/libexec/src/net/http/transfer.go:1032 +0x7e
Feb 18 11:01:24 fabio-i-05593383f9253d36c fabio[21393]: io.(*LimitedReader).Read(0xc001ad8500, 0xc00154e000, 0x2000, 0x2000, 0xcc9ea0, 0x40a43f, 0xc00001e000)
Feb 18 11:01:24 fabio-i-05593383f9253d36c fabio[21393]: #011/usr/local/Cellar/go/1.15.5/libexec/src/io/io.go:455 +0x63
Feb 18 11:01:24 fabio-i-05593383f9253d36c fabio[21393]: io/ioutil.devNull.ReadFrom(0x0, 0xfa6600, 0xc001ad8500, 0xca7420, 0x1, 0x7fddba1d7f78)
Feb 18 11:01:24 fabio-i-05593383f9253d36c fabio[21393]: #011/usr/local/Cellar/go/1.15.5/libexec/src/io/ioutil/ioutil.go:144 +0x92
Feb 18 11:01:24 fabio-i-05593383f9253d36c fabio[21393]: io.copyBuffer(0xfa7820, 0x1489478, 0xfa6600, 0xc001ad8500, 0x0, 0x0, 0x0, 0xc00112c780, 0x1, 0x0)
Feb 18 11:01:24 fabio-i-05593383f9253d36c fabio[21393]: #011/usr/local/Cellar/go/1.15.5/libexec/src/io/io.go:395 +0x2ff
Feb 18 11:01:24 fabio-i-05593383f9253d36c fabio[21393]: io.Copy(...)
Feb 18 11:01:24 fabio-i-05593383f9253d36c fabio[21393]: #011/usr/local/Cellar/go/1.15.5/libexec/src/io/io.go:368
Feb 18 11:01:24 fabio-i-05593383f9253d36c fabio[21393]: io.CopyN(0xfa7820, 0x1489478, 0xfa78e0, 0xc002836d80, 0x40000, 0xc000278480, 0xc0023e0d40, 0xc0011a57c0)
Feb 18 11:01:24 fabio-i-05593383f9253d36c fabio[21393]: #011/usr/local/Cellar/go/1.15.5/libexec/src/io/io.go:344 +0x9a
Feb 18 11:01:24 fabio-i-05593383f9253d36c fabio[21393]: net/http.(*body).Close(0xc002836d80, 0x0, 0x0)
Feb 18 11:01:24 fabio-i-05593383f9253d36c fabio[21393]: #011/usr/local/Cellar/go/1.15.5/libexec/src/net/http/transfer.go:985 +0x146
Feb 18 11:01:24 fabio-i-05593383f9253d36c fabio[21393]: net/http.(*Request).closeBody(...)
Feb 18 11:01:24 fabio-i-05593383f9253d36c fabio[21393]: #011/usr/local/Cellar/go/1.15.5/libexec/src/net/http/request.go:1388
Feb 18 11:01:24 fabio-i-05593383f9253d36c fabio[21393]: net/http.(*persistConn).writeLoop(0xc00118f680)
Feb 18 11:01:24 fabio-i-05593383f9253d36c fabio[21393]: #011/usr/local/Cellar/go/1.15.5/libexec/src/net/http/transport.go:2359 +0x399
Feb 18 11:01:24 fabio-i-05593383f9253d36c fabio[21393]: created by net/http.(*Transport).dialConn
Feb 18 11:01:24 fabio-i-05593383f9253d36c fabio[21393]: #011/usr/local/Cellar/go/1.15.5/libexec/src/net/http/transport.go:1709 +0xcdc
Feb 18 11:01:25 fabio-i-05593383f9253d36c fabio[30225]: 2021/02/18 11:01:25 [INFO] Setting log level to INFO
Feb 18 11:01:25 fabio-i-05593383f9253d36c fabio[30225]: 2021/02/18 11:01:25 [INFO] Runtime config
@magiconair, @pschultz maybe @nathanejohnson any idea with your expertise? 馃檹
scalp42
on 22 Feb 2021
@scalp42 this is interesting. That error appears to be coming from within golang standard library itself. What does memory usage look like during this time? Also what is your value for runtime.gogc ?
nathanejohnson
on 22 Feb 2021
@nathanejohnson memory usage looks consistent compared to other times, and our runtime.gogc = 800.
evandam
on 22 Feb 2021
Could you give a little more information on what host operating system you're using, what version etc? Anything else interesting in any of the other more general system logs?
nathanejohnson
on 22 Feb 2021
Also, for what it's worth, we changed the default runtime.gogc value from 800 to 100, if you are indeed running with 800 you might want to try lowering it to 100. 800 turns out to be a pretty poor default with modern runtimes.
nathanejohnson
on 22 Feb 2021
👍1
Running Ubuntu 18.04, Fabio 1.5.15-go1.5.15. I don't see anything unusual going on with Consul or other system logs, and the issue seems very sporadic (sometimes middle of the night with very low traffic, sometimes in the mornings, etc). We have downgraded to Fabio 1.5.14 to see if the issue is still occurring so I can report back with findings then.
evandam
on 22 Feb 2021
I was mainly looking for an OOM killer message from /var/log/syslog or similar. Regarding 1.5.14 -> 1.5.15, relatively little in the fabio codebase changed with this release. Were you running 1.5.14 before 1.5.15?
nathanejohnson
on 22 Feb 2021
The instance that had the error was consistently around ~30% memory used the whole time, and no OOM messages as far as I can see.
We did run 1.5.14 prior to upgrading and don't recall seeing this error, but not 100% sure since it's been a few months since we upgraded.
evandam
on 22 Feb 2021
@nathanejohnson just circling back, I can confirm this is happening on Fabio 1.5.14 and 1.5.13 as well.
evandam
on 24 Feb 2021
@evandam interesting. What all can you tell me about your environment besides ubuntu 18.04 ? Is this on your own hardware, bare metal or VM, selinux enabled? Once upon a time I remember seeing an issue with an unrelated project where upstream would issue a tcp reset and things would get sideways. Any help you could be in coming up with a reproducible test case would be much appreciated. Do you have any way of doing packet captures between fabio and upstream?
nathanejohnson
on 24 Feb 2021
Sure, we're on AWS, Ubuntu 18.04 running on c5.large instances, no selinux enabled.
After you mentioned it, I did notice a very tiny blip in TCP resets. I don't think I'm able to get much more but I believe this is immediately before the panic occurred.
Logs:
Feb 24 17:52:52 fabio-i-05e68c47b98d101e1 fabio[2872]: invalid log msg: 2021/02/24 17:52:52 httputil: ReverseProxy read error during body copy: read tcp 10.82.217.57:43158->10.82.15.87:26166: read: connection reset by peer
Feb 24 17:52:52 fabio-i-05e68c47b98d101e1 fabio[2872]: panic: runtime error: invalid memory address or nil pointer dereference
Feb 24 17:52:52 fabio-i-05e68c47b98d101e1 fabio[2872]: [signal SIGSEGV: segmentation violation code=0x1 addr=0x18 pc=0x55c330]
Feb 24 17:52:52 fabio-i-05e68c47b98d101e1 fabio[2872]: goroutine 2909100 [running]:
Feb 24 17:52:52 fabio-i-05e68c47b98d101e1 fabio[2872]: bufio.(*Reader).Read(0xc001d78cc0, 0xc0024c8000, 0x2000, 0x2000, 0x40a34a, 0xb71760, 0xbeca60)
Feb 24 17:52:52 fabio-i-05e68c47b98d101e1 fabio[2872]: #011/usr/local/Cellar/go/1.13.4/libexec/src/bufio/bufio.go:212 +0x130
Feb 24 17:52:52 fabio-i-05e68c47b98d101e1 fabio[2872]: io.(*LimitedReader).Read(0xc002bfedc0, 0xc0024c8000, 0x2000, 0x2000, 0xc002bfee40, 0x9bec5, 0xe6bbc0)
Feb 24 17:52:52 fabio-i-05e68c47b98d101e1 fabio[2872]: #011/usr/local/Cellar/go/1.13.4/libexec/src/io/io.go:448 +0x63
Feb 24 17:52:52 fabio-i-05e68c47b98d101e1 fabio[2872]: net/http.(*body).readLocked(0xc002e85700, 0xc0024c8000, 0x2000, 0x2000, 0x0, 0xe6aac0, 0xc00226b200)
Feb 24 17:52:52 fabio-i-05e68c47b98d101e1 fabio[2872]: #011/usr/local/Cellar/go/1.13.4/libexec/src/net/http/transfer.go:847 +0x5f
Feb 24 17:52:52 fabio-i-05e68c47b98d101e1 fabio[2872]: net/http.bodyLocked.Read(0xc002e85700, 0xc0024c8000, 0x2000, 0x2000, 0xaecc80, 0xc00299d450, 0xc002402400)
Feb 24 17:52:52 fabio-i-05e68c47b98d101e1 fabio[2872]: #011/usr/local/Cellar/go/1.13.4/libexec/src/net/http/transfer.go:1046 +0x7e
Feb 24 17:52:52 fabio-i-05e68c47b98d101e1 fabio[2872]: io.(*LimitedReader).Read(0xc002c1aa80, 0xc0024c8000, 0x2000, 0x2000, 0x10, 0x40905b, 0xc00001e000)
Feb 24 17:52:52 fabio-i-05e68c47b98d101e1 fabio[2872]: #011/usr/local/Cellar/go/1.13.4/libexec/src/io/io.go:448 +0x63
Feb 24 17:52:52 fabio-i-05e68c47b98d101e1 fabio[2872]: io/ioutil.devNull.ReadFrom(0x0, 0xe6ba20, 0xc002c1aa80, 0xb75cc0, 0x1, 0x7fd8ff70f2f8)
Feb 24 17:52:52 fabio-i-05e68c47b98d101e1 fabio[2872]: #011/usr/local/Cellar/go/1.13.4/libexec/src/io/ioutil/ioutil.go:147 +0x92
Feb 24 17:52:52 fabio-i-05e68c47b98d101e1 fabio[2872]: io.copyBuffer(0xe6ca40, 0x1371da0, 0xe6ba20, 0xc002c1aa80, 0x0, 0x0, 0x0, 0x42dfda, 0xa, 0x0)
Feb 24 17:52:52 fabio-i-05e68c47b98d101e1 fabio[2872]: #011/usr/local/Cellar/go/1.13.4/libexec/src/io/io.go:388 +0x2ed
Feb 24 17:52:52 fabio-i-05e68c47b98d101e1 fabio[2872]: io.Copy(...)
Feb 24 17:52:52 fabio-i-05e68c47b98d101e1 fabio[2872]: #011/usr/local/Cellar/go/1.13.4/libexec/src/io/io.go:364
Feb 24 17:52:52 fabio-i-05e68c47b98d101e1 fabio[2872]: io.CopyN(0xe6ca40, 0x1371da0, 0xe6cb00, 0xc002e85700, 0x40000, 0xc00226b200, 0xc001ff8d20, 0xc002dbd2c0)
Feb 24 17:52:52 fabio-i-05e68c47b98d101e1 fabio[2872]: #011/usr/local/Cellar/go/1.13.4/libexec/src/io/io.go:340 +0x9a
Feb 24 17:52:52 fabio-i-05e68c47b98d101e1 fabio[2872]: net/http.(*body).Close(0xc002e85700, 0x0, 0x0)
Feb 24 17:52:52 fabio-i-05e68c47b98d101e1 fabio[2872]: #011/usr/local/Cellar/go/1.13.4/libexec/src/net/http/transfer.go:999 +0x14a
Feb 24 17:52:52 fabio-i-05e68c47b98d101e1 fabio[2872]: net/http.(*Request).closeBody(...)
Feb 24 17:52:52 fabio-i-05e68c47b98d101e1 fabio[2872]: #011/usr/local/Cellar/go/1.13.4/libexec/src/net/http/request.go:1390
Feb 24 17:52:52 fabio-i-05e68c47b98d101e1 fabio[2872]: net/http.(*persistConn).writeLoop(0xc001b2a000)
Feb 24 17:52:52 fabio-i-05e68c47b98d101e1 fabio[2872]: #011/usr/local/Cellar/go/1.13.4/libexec/src/net/http/transport.go:2223 +0x35d
Feb 24 17:52:52 fabio-i-05e68c47b98d101e1 fabio[2872]: created by net/http.(*Transport).dialConn
Feb 24 17:52:52 fabio-i-05e68c47b98d101e1 fabio[2872]: #011/usr/local/Cellar/go/1.13.4/libexec/src/net/http/transport.go:1575 +0xb23
Feb 24 17:52:53 fabio-i-05e68c47b98d101e1 fabio[29078]: 2021/02/24 17:52:53 [INFO] Setting log level to INFO
Feb 24 17:52:53 fabio-i-05e68c47b98d101e1 fabio[29078]: 2021/02/24 17:52:53 [INFO] Runtime config
I have to wonder if this is related:
nathanejohnson
on 24 Feb 2021
Could you also paste your listener config?
nathanejohnson
on 24 Feb 2021
That seems promising! Here's my config.
glob.matching.disabled = false
log.access.format = $remote_host - $header.X-Forwarded-For - $header.X-Fabio-Request-Id - [$time_common] "$request" $response_status $response_body_size $response_time_ms "$header.Referer" "$header.User-Agent" upstream "$upstream_addr" "$upstream_service"
log.access.target = stdout
log.level = INFO
log.routes.format = delta
metrics.graphite.addr =
metrics.interval = 10s
metrics.names = {{clean .Host}}.{{clean .Path}}
metrics.prefix = {{clean .Exec}}
metrics.retry = 500ms
metrics.statsd.addr = 127.0.0.1:18125
metrics.target = statsd
metrics.timeout = 10s
proxy.addr = :9999
proxy.auth =
proxy.cs =
proxy.dialtimeout = 3s
proxy.flushinterval = 1s
proxy.globalflushinterval = 0
proxy.gzip.contenttype =
proxy.header.clientip =
proxy.header.requestid = X-Fabio-Request-Id
proxy.header.sts.maxage = 0
proxy.header.sts.preload = false
proxy.header.sts.subdomains = false
proxy.header.tls.value =
proxy.localip = 10.82.228.174
proxy.matcher = prefix
proxy.maxconn = 10000
proxy.noroutestatus = 404
proxy.responseheadertimeout = 0s
proxy.shutdownwait = 3s
proxy.strategy = rnd
registry.backend = consul
registry.consul.addr = localhost:8500
registry.consul.checksRequired = all
registry.consul.kvpath = /fabio/prod-usw2-prod1
registry.consul.noroutehtmlpath = /fabio/noroute.html
registry.consul.register.addr = :9998
registry.consul.register.checkInterval = 1s
registry.consul.register.checkTLSSkipVerify = false
registry.consul.register.checkTimeout = 3s
registry.consul.register.enabled = true
registry.consul.register.name = fabio
registry.consul.register.tags = prod-usw2-prod1
registry.consul.register.serviceMonitors = 1
registry.consul.service.status = passing
registry.consul.tagprefix = fabio-
registry.consul.token = <redacted>
registry.file.noroutehtmlpath =
registry.file.path =
registry.retry = 500ms
registry.static.noroutehtml =
registry.static.routes =
registry.timeout = 3s
runtime.gogc = 800
runtime.gomaxprocs = -1
ui.access = ro
ui.addr = :9998
ui.color = light-green
ui.title = prod-usw2-prod1 i-062843a095577e5fc
👀1
@evandam is it possible to play with proxy.flushinterval ? I'm curious if there is a race here when it's set to 1 second and the connection is torn down around the same time that timer fires. Interesting values there would be 0 or -1
nathanejohnson
on 25 Feb 2021
👍1
Sure thing, I can drop it to 0 first and see how it goes.
evandam
on 25 Feb 2021
Hey @nathanejohnson, still experiencing the same panic with proxy.flushinterval = 0. I'll try setting it to -1 for science, but any ideas besides this?
evandam
on 1 Mar 2021
@nathanejohnson confirming we still see the panic with proxy.flushinterval = -1 as well. :sob:
evandam
on 2 Mar 2021
@nathanejohnson I just noticed that when setting flushinterval to -1, it looks like Fabio actually flips this to 0, not sure if there's some validation check that changes it.
fabio.properties
glob.matching.disabled = false
log.access.format = $remote_host - $header.X-Forwarded-For - $header.X-Fabio-Request-Id - [$time_common] "$request" $response_status $response_body_size $response_time_ms "$header.Referer" "$header.User-Agent" upstream "$upstream_addr" "$upstream_service"
log.access.target = stdout
log.level = INFO
log.routes.format = detail
metrics.graphite.addr =
metrics.interval = 10s
metrics.names = {{clean .Host}}.{{clean .Path}}
metrics.prefix = {{clean .Exec}}
metrics.retry = 500ms
metrics.statsd.addr = 127.0.0.1:18125
metrics.target = statsd
metrics.timeout = 10s
proxy.addr = :9999
proxy.auth =
proxy.cs =
proxy.dialtimeout = 3s
proxy.flushinterval = -1
proxy.globalflushinterval = 0
proxy.gzip.contenttype =
proxy.header.clientip =
proxy.header.requestid = X-Fabio-Request-Id
proxy.header.sts.maxage = 0
proxy.header.sts.preload = false
proxy.header.sts.subdomains = false
proxy.header.tls.value =
proxy.localip = 10.82.217.57
proxy.matcher = prefix
proxy.maxconn = 10000
proxy.noroutestatus = 404
proxy.responseheadertimeout = 0s
proxy.shutdownwait = 3s
proxy.strategy = rnd
registry.backend = consul
registry.consul.addr = localhost:8500
registry.consul.checksRequired = all
registry.consul.kvpath = /fabio/prod-usw2-prod1
registry.consul.noroutehtmlpath = /fabio/noroute.html
registry.consul.register.addr = :9998
registry.consul.register.checkInterval = 1s
registry.consul.register.checkTLSSkipVerify = false
registry.consul.register.checkTimeout = 3s
registry.consul.register.enabled = true
registry.consul.register.name = fabio
registry.consul.register.tags = prod-usw2-prod1
registry.consul.register.serviceMonitors = 1
registry.consul.service.status = passing
registry.consul.tagprefix = fabio-
registry.consul.token = redacted
registry.file.noroutehtmlpath =
registry.file.path =
registry.retry = 500ms
registry.static.noroutehtml =
registry.static.routes =
registry.timeout = 3s
runtime.gogc = 100
runtime.gomaxprocs = -1
ui.access = ro
ui.addr = :9998
ui.color = light-green
ui.title = prod-usw2-prod1 i-05e68c47b98d101e1
fabio.log
Mar 3 16:54:04 fabio-i-05e68c47b98d101e1 fabio[21634]: invalid log msg: 2021/03/03 16:54:04 httputil: ReverseProxy read error during body copy: read tcp 10.82.217.57:49744->10.82.29.208:29826: read: connection reset by peer
Mar 3 16:54:04 fabio-i-05e68c47b98d101e1 fabio[21634]: panic: runtime error: invalid memory address or nil pointer dereference
Mar 3 16:54:04 fabio-i-05e68c47b98d101e1 fabio[21634]: [signal SIGSEGV: segmentation violation code=0x1 addr=0x18 pc=0x56fc1e]
Mar 3 16:54:04 fabio-i-05e68c47b98d101e1 fabio[21634]: goroutine 6095675 [running]:
Mar 3 16:54:04 fabio-i-05e68c47b98d101e1 fabio[21634]: bufio.(*Reader).Read(0xc0006d12c0, 0xc0006c0000, 0x2000, 0x2000, 0xca2500, 0xd2cc20, 0x203001)
Mar 3 16:54:04 fabio-i-05e68c47b98d101e1 fabio[21634]: #011/usr/local/Cellar/go/1.15.5/libexec/src/bufio/bufio.go:213 +0x11e
Mar 3 16:54:04 fabio-i-05e68c47b98d101e1 fabio[21634]: io.(*LimitedReader).Read(0xc000ad23e0, 0xc0006c0000, 0x2000, 0x2000, 0xbf292, 0xfa6800, 0xc000a30640)
Mar 3 16:54:04 fabio-i-05e68c47b98d101e1 fabio[21634]: #011/usr/local/Cellar/go/1.15.5/libexec/src/io/io.go:455 +0x63
Mar 3 16:54:04 fabio-i-05e68c47b98d101e1 fabio[21634]: net/http.(*body).readLocked(0xc000a77800, 0xc0006c0000, 0x2000, 0x2000, 0x1, 0xc000230000, 0xfa6600)
Mar 3 16:54:04 fabio-i-05e68c47b98d101e1 fabio[21634]: #011/usr/local/Cellar/go/1.15.5/libexec/src/net/http/transfer.go:833 +0x5f
Mar 3 16:54:04 fabio-i-05e68c47b98d101e1 fabio[21634]: net/http.bodyLocked.Read(0xc000a77800, 0xc0006c0000, 0x2000, 0x2000, 0xc170a0, 0xcd68e0, 0xc0006055c0)
Mar 3 16:54:04 fabio-i-05e68c47b98d101e1 fabio[21634]: #011/usr/local/Cellar/go/1.15.5/libexec/src/net/http/transfer.go:1032 +0x7e
Mar 3 16:54:04 fabio-i-05e68c47b98d101e1 fabio[21634]: io.(*LimitedReader).Read(0xc000a78600, 0xc0006c0000, 0x2000, 0x2000, 0xcc9ea0, 0x40a43f, 0xc00001e000)
Mar 3 16:54:04 fabio-i-05e68c47b98d101e1 fabio[21634]: #011/usr/local/Cellar/go/1.15.5/libexec/src/io/io.go:455 +0x63
Mar 3 16:54:04 fabio-i-05e68c47b98d101e1 fabio[21634]: io/ioutil.devNull.ReadFrom(0x0, 0xfa6600, 0xc000a78600, 0xca7420, 0x1, 0x7f77876a0738)
Mar 3 16:54:04 fabio-i-05e68c47b98d101e1 fabio[21634]: #011/usr/local/Cellar/go/1.15.5/libexec/src/io/ioutil/ioutil.go:144 +0x92
Mar 3 16:54:04 fabio-i-05e68c47b98d101e1 fabio[21634]: io.copyBuffer(0xfa7820, 0x1489478, 0xfa6600, 0xc000a78600, 0x0, 0x0, 0x0, 0xc000a9f680, 0x1, 0x0)
Mar 3 16:54:04 fabio-i-05e68c47b98d101e1 fabio[21634]: #011/usr/local/Cellar/go/1.15.5/libexec/src/io/io.go:395 +0x2ff
Mar 3 16:54:04 fabio-i-05e68c47b98d101e1 fabio[21634]: io.Copy(...)
Mar 3 16:54:04 fabio-i-05e68c47b98d101e1 fabio[21634]: #011/usr/local/Cellar/go/1.15.5/libexec/src/io/io.go:368
Mar 3 16:54:04 fabio-i-05e68c47b98d101e1 fabio[21634]: io.CopyN(0xfa7820, 0x1489478, 0xfa78e0, 0xc000a77800, 0x40000, 0xc000a23680, 0xc000230000, 0xc0007346c0)
Mar 3 16:54:04 fabio-i-05e68c47b98d101e1 fabio[21634]: #011/usr/local/Cellar/go/1.15.5/libexec/src/io/io.go:344 +0x9a
Mar 3 16:54:04 fabio-i-05e68c47b98d101e1 fabio[21634]: net/http.(*body).Close(0xc000a77800, 0x0, 0x0)
Mar 3 16:54:04 fabio-i-05e68c47b98d101e1 fabio[21634]: #011/usr/local/Cellar/go/1.15.5/libexec/src/net/http/transfer.go:985 +0x146
Mar 3 16:54:04 fabio-i-05e68c47b98d101e1 fabio[21634]: net/http.(*Request).closeBody(...)
Mar 3 16:54:04 fabio-i-05e68c47b98d101e1 fabio[21634]: #011/usr/local/Cellar/go/1.15.5/libexec/src/net/http/request.go:1388
Mar 3 16:54:04 fabio-i-05e68c47b98d101e1 fabio[21634]: net/http.(*persistConn).writeLoop(0xc0006ce000)
Mar 3 16:54:04 fabio-i-05e68c47b98d101e1 fabio[21634]: #011/usr/local/Cellar/go/1.15.5/libexec/src/net/http/transport.go:2359 +0x399
Mar 3 16:54:04 fabio-i-05e68c47b98d101e1 fabio[21634]: created by net/http.(*Transport).dialConn
Mar 3 16:54:04 fabio-i-05e68c47b98d101e1 fabio[21634]: #011/usr/local/Cellar/go/1.15.5/libexec/src/net/http/transport.go:1709 +0xcdc
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: 2021/03/03 16:54:05 [INFO] Setting log level to INFO
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: 2021/03/03 16:54:05 [INFO] Runtime config
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: {
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Proxy": {
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Strategy": "rnd",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Matcher": "prefix",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "NoRouteStatus": 404,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "MaxConn": 10000,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "ShutdownWait": 3000000000,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "DialTimeout": 3000000000,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "ResponseHeaderTimeout": 0,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "KeepAliveTimeout": 0,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "FlushInterval": 0,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "GlobalFlushInterval": 0,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "LocalIP": "10.82.217.57",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "ClientIPHeader": "",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "TLSHeader": "",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "TLSHeaderValue": "",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "GZIPContentTypes": null,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "RequestID": "X-Fabio-Request-Id",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "STSHeader": {
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "MaxAge": 0,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Subdomains": false,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Preload": false
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: },
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "AuthSchemes": {}
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: },
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Registry": {
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Backend": "consul",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Static": {
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "NoRouteHTML": "",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Routes": ""
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: },
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "File": {
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "NoRouteHTMLPath": "",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "RoutesPath": ""
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: },
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Consul": {
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Addr": "localhost:8500",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Scheme": "http",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Token": "redacted",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "KVPath": "/fabio/prod-usw2-prod1",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "NoRouteHTMLPath": "/fabio/noroute.html",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "TagPrefix": "fabio-",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Register": true,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "ServiceAddr": ":9998",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "ServiceName": "fabio",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "ServiceTags": [
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "prod-usw2-prod1"
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: ],
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "ServiceStatus": [
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "passing"
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: ],
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "CheckInterval": 1000000000,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "CheckTimeout": 3000000000,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "CheckScheme": "http",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "CheckTLSSkipVerify": false,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "ChecksRequired": "all",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "ServiceMonitors": 1,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "TLS": {
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "KeyFile": "",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "CertFile": "",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "CAFile": "",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "CAPath": "",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "InsecureSkipVerify": false
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: },
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "PollInterval": 0
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: },
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Custom": {
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Host": "",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Path": "",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "QueryParams": "",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Scheme": "https",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "CheckTLSSkipVerify": false,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "PollInterval": 5,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "NoRouteHTML": "",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Timeout": 10
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: },
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Timeout": 3000000000,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Retry": 500000000
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: },
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Listen": [
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: {
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Addr": ":9999",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Proto": "http",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "ReadTimeout": 0,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "WriteTimeout": 0,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "IdleTimeout": 0,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "CertSource": {
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Name": "",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Type": "",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "CertPath": "",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "KeyPath": "",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "ClientCAPath": "",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "CAUpgradeCN": "",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Refresh": 0,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Header": null,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "VaultFetchToken": ""
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: },
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "StrictMatch": false,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "TLSMinVersion": 0,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "TLSMaxVersion": 0,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "TLSCiphers": null,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "ProxyProto": false,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "ProxyHeaderTimeout": 0,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Refresh": 0
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: }
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: ],
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Log": {
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "AccessTarget": "stdout",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "RoutesFormat": "detail",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Level": "INFO"
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: },
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Metrics": {
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Target": "statsd",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Prefix": "{{clean .Exec}}",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Names": "{{clean .Host}}.{{clean .Path}}",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Interval": 10000000000,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Timeout": 10000000000,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Retry": 500000000,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "GraphiteAddr": "",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "StatsDAddr": "127.0.0.1:18125",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Circonus": {
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "APIKey": "",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "APIApp": "fabio",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "APIURL": "",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "CheckID": "",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "BrokerID": "",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "SubmissionURL": ""
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: }
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: },
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "UI": {
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Listen": {
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Addr": ":9998",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Proto": "http",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "ReadTimeout": 0,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "WriteTimeout": 0,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "IdleTimeout": 0,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "CertSource": {
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Name": "",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Type": "",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "CertPath": "",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "KeyPath": "",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "ClientCAPath": "",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "CAUpgradeCN": "",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Refresh": 0,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Header": null,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "VaultFetchToken": ""
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: },
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "StrictMatch": false,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "TLSMinVersion": 0,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "TLSMaxVersion": 0,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "TLSCiphers": null,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "ProxyProto": false,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "ProxyHeaderTimeout": 0,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Refresh": 0
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: },
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Color": "light-green",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Title": "prod-usw2-prod1 i-05e68c47b98d101e1",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Access": "ro"
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: },
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Runtime": {
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "GOGC": 100,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "GOMAXPROCS": 2
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: },
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Tracing": {
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "TracingEnabled": false,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "CollectorType": "http",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "ConnectString": "http://localhost:9411/api/v1/spans",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "ServiceName": "Fabiolb",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Topic": "Fabiolb-Kafka-Topic",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "SamplerRate": -1,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "SpanHost": "localhost:9998",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "SpanName": "",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "TraceID128Bit": true
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: },
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "ProfileMode": "",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "ProfilePath": "/tmp",
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "Insecure": false,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "GlobMatchingDisabled": false,
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: "GlobCacheSize": 1000
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: }
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: 2021/03/03 16:54:05 [INFO] Version 1.5.15 starting
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: 2021/03/03 16:54:05 [INFO] Go runtime is go1.15.5
Mar 3 16:54:05 fabio-i-05e68c47b98d101e1 fabio[4018]: 2021/03/03 16:54:05 [INFO] Sending metrics to StatsD on 127.0.0.1:18125 as "fabio"
So that is interesting. I guess this behavior comes from Frank's upstream parser. However, from a quick glance it looks like if you pass this value on the cli it should respect a negative value for proxy.flushinterval and proxy.globalflushinterval .
nathanejohnson
on 3 Mar 2021
No dice, still shows as invalid:
Mar 3 18:48:14 default-ubuntu-1804 fabio[23639]: invalid value "-1" for flag -proxy.flushinterval: parse error
Reading the docs, I'm not sure how big of a difference it makes between 0 and -1 anyways, so just want to make sure we're not getting off track for the wrong thing 馃槄
// If zero, no periodic flushing is done.
// A negative value means to flush immediately
// after each write to the client.
// The FlushInterval is ignored when ReverseProxy
// recognizes a response as a streaming response, or
// if its ContentLength is -1; for such responses, writes
// are flushed to the client immediately.
Apparently -1ns works, but -1 does not. Anyway, I doubt it will make much if any difference either, but -1 is supposed to return immediately instead of buffering. Also, flushinterval only comes into play when there is a specific mime type, otherwise globalflushinterval takes precedence. I always assumed it was a long shot anyway, but it would be interesting to see if both flushinterval and globalflushinterval set to -1ns changed the outcome.
nathanejohnson
on 3 Mar 2021
Got it, I just updated both properties to use -1ns so we'll see. Besides tweaking configs around like this, is there any reasonable way for Fabio to recover from this panic so it's just one failed request instead of crashing the whole service?
evandam
on 3 Mar 2021
I think that sounds reasonable, but I have to admit I'm very curious why it's happening in the first place. I'll look into setting up a sane recovery handler
nathanejohnson
on 3 Mar 2021
❤2
Agreed, I'm very curious, but at the same time it's causing blips of production downtime every time it occurs 馃槄
Thanks for investigating this one, really looking forward to seeing it handled!
evandam
on 3 Mar 2021
So I've scoured our logs and we're not seeing any panics (nil pointer deref or otherwise) on any of our production fabio load balancers. Some of these are handling a lot of concurrent connections, and others are handling high throughput (though from a relatively small number of concurrent connections). I would like to figure out a way to reproduce this locally, I think that will be a requirement for coming up with any sort of meaningful workaround.
nathanejohnson
on 4 Mar 2021
👀1
@nathanejohnson do you think there's still a way to recover gracefully and not make it crash? Would hope to be able to see which requests create the panic.
scalp42
on 4 Mar 2021
Not sure if it helps, but reading through https://stackoverflow.com/questions/41300350/go-httputil-reverseproxy-connection-reset-by-peer it seems like the ReverseProxy library can panic if there's a bad client using HTTP/1.0 in some cases? I checked our logs and it doesn't look like we have anything coming through using HTTP/1.0, but maybe it can give some inspiration for reproducing locally 馃槄
I can confirm that we see a tiny spike in TCP resets, so a client somehow sending a RST would likely trip it.
evandam
on 4 Mar 2021
Hey @nathanejohnson,
Just circling back, since setting proxy.flushinterval = -1ns and proxy.globalflushinterval = -1ns we haven't seen an issue, so maybe one of those did the trick.
evandam
on 15 Mar 2021
👀1
I think it's safe to say this resolved our issue. Thanks for the support @nathanejohnson!
I'm not sure if this means there was some race condition like you mentioned causing issues and it's still worth finding a fix for the real issue, though.
evandam
on 31 Mar 2021
Was this page helpful?
0 / 5 - 0 ratings
Related issues
doublerebel
路
11Comments
drawks
路
12Comments
kaspergrubbe
路
11Comments
tanuck
路
6Comments
evandam
路
5Comments
Most helpful comment
I think that sounds reasonable, but I have to admit I'm very curious why it's happening in the first place. I'll look into setting up a sane recovery handler