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

About this issue

Original URL
State: closed
Created 3 years ago
Comments: 31 (12 by maintainers)

Most upvoted comments

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 Mar 3, 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 Mar 15, 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 Mar 4, 2021

@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 Feb 24, 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

evandam on Feb 24, 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 Feb 22, 2021