net/http: panic "slice bounds out of range" while reading chunked response body #22330

benburkert · 2017-10-18T17:33:49Z

Please answer these questions before submitting your issue. Thanks!

What version of Go are you using (`go version`)?

go version go1.8.3 linux/amd64

Does this issue reproduce with the latest release?

unknown

What operating system and processor architecture are you using (`go env`)?

GOARCH="amd64"
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"

What did you do?

A HTTP service proxies it's request to an upstream HTTP service. The upstream sends back a chunked encoded response.

What did you expect to see?

The service is expected to proxy the response from the upstream back to the downstream client.

What did you see instead?

The process sporadically panics with a runtime error: slice bounds out of range message in the bufio.(*Reader).ReadSlice.

panic: runtime error: slice bounds out of range

goroutine 134054 [running]:
bufio.(*Reader).ReadSlice(0xc4204e17a0, 0xa, 0x92e7e8, 0xc4206dd940, 0xc4206dd930, 0xc420718680, 0xc420b2a850)
    /usr/local/go/src/bufio/bufio.go:316 +0x258
bufio.(*Reader).ReadLine(0xc4204e17a0, 0xc4201185a0, 0x90, 0x90, 0x8fc0e0, 0xc420b2a8b8, 0xc4206dda08)
    /usr/local/go/src/bufio/bufio.go:367 +0x37
net/textproto.(*Reader).readLineSlice(0xc4206ddaf8, 0x0, 0xc4206dda30, 0x40fdb8, 0x90, 0x8fc0e0)
    /usr/local/go/src/net/textproto/reader.go:55 +0x5f
net/textproto.(*Reader).ReadLine(0xc4206ddaf8, 0xc4201185a0, 0xc4207a3520, 0x0, 0x0)
    /usr/local/go/src/net/textproto/reader.go:36 +0x2f
net/http.ReadResponse(0xc4204e17a0, 0xc4200bcb00, 0xc4206ddb80, 0x5f916d, 0xc420314440)
    /usr/local/go/src/net/http/response.go:148 +0xca
net/http.(*persistConn).readResponse(0xc420554a20, 0xc4200bcb00, 0xc420a38300, 0x0, 0x0, 0xc420a381e0, 0xc420b2a150, 0xc420686870, 0x0, 0x0)
    /usr/local/go/src/net/http/transport.go:1649 +0x57
net/http.(*persistConn).readLoop(0xc420554a20)
    /usr/local/go/src/net/http/transport.go:1489 +0x12c0
created by net/http.(*Transport).dialConn
/usr/local/go/src/net/http/transport.go:1117 +0xa35

Running the service with the race detector enabled shows a data race between net/http.(*body).readLocked()/bufio.(*Reader).ReadSlice() and net/http.(*persistConn).readLoop()/bufio.(*Reader).Peek() that is likely related:

==================
WARNING: DATA RACE
Read at 0x00c42088e508 by goroutine 169:
  bufio.(*Reader).ReadSlice()
      /usr/local/go/src/bufio/bufio.go:316 +0x5f
  net/http/internal.readChunkLine()
      /usr/local/go/src/net/http/internal/chunked.go:122 +0x4a
  net/http/internal.(*chunkedReader).beginChunk()
      /usr/local/go/src/net/http/internal/chunked.go:48 +0x5c
  net/http/internal.(*chunkedReader).Read()
      /usr/local/go/src/net/http/internal/chunked.go:93 +0x229
  net/http.(*body).readLocked()
      /usr/local/go/src/net/http/transfer.go:761 +0xbf
  net/http.(*body).Read()
      /usr/local/go/src/net/http/transfer.go:753 +0x131
  io.copyBuffer()
      /usr/local/go/src/io/io.go:390 +0x116
  io.CopyBuffer()
      /usr/local/go/src/io/io.go:371 +0xa5
  REDACTED http handler
  net/http.serverHandler.ServeHTTP()
      /usr/local/go/src/net/http/server.go:2568 +0xbc
  net/http.(*conn).serve()
      /usr/local/go/src/net/http/server.go:1825 +0x71a

Previous write at 0x00c42088e508 by goroutine 8:
  bufio.(*Reader).fill()
      /usr/local/go/src/bufio/bufio.go:88 +0x561
  bufio.(*Reader).Peek()
      /usr/local/go/src/bufio/bufio.go:129 +0x131
  net/http.(*persistConn).readLoop()
      /usr/local/go/src/net/http/transport.go:1474 +0x2b5

Goroutine 169 (running) created at:
  net/http.(*Server).Serve()
      /usr/local/go/src/net/http/server.go:2668 +0x35f
  REDACTED main func

Goroutine 8 (running) created at:
  net/http.(*Transport).dialConn()
      /usr/local/go/src/net/http/transport.go:1117 +0xc07
  net/http.(*Transport).getConn.func4()
      /usr/local/go/src/net/http/transport.go:908 +0xa2
==================

The text was updated successfully, but these errors were encountered:

benburkert · 2017-10-18T17:40:57Z

A short investigation points to a data race between the Peek call by readLoop on the connection's bufio.Reader and the chunked body reader. It appears that the EOF signal, forwarded by the bodyEOFSignal reader, is forwarded once the body reader returns an EOF but not necessarily before all body data has been read from the bufio.Reader. The Peek(1) call does not grab the persistConn's lock, and bufio.Peek may call bufio.fill, which can rearrange the backing slice. My guess is that this only seems to show up with chunked responses because small reads (smaller than the buffer size) are performed when the chunk size is small.

dsnet · 2017-10-18T17:49:37Z

Thank you for the report. Do you have a minimal reproduction that we can run?

benburkert · 2017-10-18T17:53:47Z

@dsnet not yet, i'm still working on one but it's proving to be quite tricky to trigger. I'll update the ticket as soon as I have a reproduction.

dsnet · 2017-10-18T17:56:37Z

\cc @tombergan

tombergan · 2017-10-18T18:13:42Z

Can you say more about "REDACTED http handler", specifically, what the copy is copying?

tombergan · 2017-10-18T18:22:18Z

Does the error occur with 1.9?

benburkert · 2017-10-18T18:29:23Z

The handler is running a modified version of httputil.ReverseProxy, and the io.CopyBuffer comes from the ReverseProxy.copyResponse method, which still calls io.CopyBuffered directly.

I'm only able to trigger the panic & data race in a production environment where running 1.9/tip is not an option. If I'm able to reproduce it locally I will be sure to test with go1.9 and tip.

benburkert · 2017-10-19T16:25:07Z

This program reproduces the data race: https://play.golang.org/p/QztsfgNHNr

It looks like the data race is triggered by a 304 response that has a chunked encoded empty body. go1.9 and tip also hit the data race.

bradfitz · 2017-10-19T16:35:38Z

I'm not really following this thread (still on leave), but of note: a 304 response never has a body.

https://tools.ietf.org/html/rfc7230#section-3.3.3 says:

Any response to a HEAD request and any response with a 1xx
(Informational), 204 (No Content), or 304 (Not Modified) status
code is always terminated by the first empty line after the
header fields, regardless of the header fields present in the
message, and thus cannot contain a message body.

If Go is processing a server saying:

"HTTP/1.1 304 NOT MODIFIED\r\nConnection: keep-alive\r\nTransfer-Encoding: chunked\r\n\r\n0\r\n\r\n"

It would stop after the first \r\n\r\n and start reading 0\r\n\r\n as the next response, which may not be ready yet.

Any server sending such a response is buggy, but I agree that Go shouldn't have a data race when handling an invalid response, if that's indeed what's happening here. (I haven't looked.)

gopherbot · 2017-10-19T17:47:26Z

Change https://golang.org/cl/71910 mentions this issue: net/http: ignore response body when forbidden by status code

bradfitz · 2017-10-19T17:59:05Z

@benburkert, I realize now you said the exact same thing. I had looked at your play.golang.org snippet, came back to comment, and never read your very next sentence. Sorry.

benburkert · 2017-10-19T18:05:02Z

@bradfitz no worries, thanks for digging up the relevant section of the RFC so quickly!

A 1XX, 204, or 304 response may not include a response body according to RFC 7230, section 3.3.3. If a buggy server returns a 204 or 304 response with a body that is chunked encoded, the invalid body is currently made readable in the Response. This can lead to data races due to the transport connection's read loop which does not wait for the body EOF when the response status is 204 or 304. The correct behavior is to ignore the body on a 204 or 304 response, and treat the body data as the beginning of the next request on the connection. Updates #22330. Change-Id: I89a457ceb783b6f66136d5bf9be0a9b0a04fa955 Reviewed-on: https://go-review.googlesource.com/71910 Reviewed-by: Tom Bergan <tombergan@google.com> Reviewed-by: Brad Fitzpatrick <bradfitz@golang.org> Run-TryBot: Tom Bergan <tombergan@google.com>

ianlancetaylor · 2018-03-29T18:41:38Z

Is there anything else to fix here?

bradfitz · 2018-03-29T18:45:29Z

Looks done. @benburkert, let me know if you had more in mind.

dsnet added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Oct 18, 2017

benburkert mentioned this issue Oct 19, 2017

Transfer-Encoding header on 1xx, 204, 304 response httpwg/http-core#41

Closed

ianlancetaylor added this to the Go1.11 milestone Mar 29, 2018

bradfitz closed this as completed Mar 29, 2018

golang locked and limited conversation to collaborators Mar 29, 2019

gopherbot added the FrozenDueToAge label Mar 29, 2019

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

net/http: panic "slice bounds out of range" while reading chunked response body #22330

net/http: panic "slice bounds out of range" while reading chunked response body #22330

benburkert commented Oct 18, 2017

benburkert commented Oct 18, 2017

dsnet commented Oct 18, 2017

benburkert commented Oct 18, 2017

dsnet commented Oct 18, 2017

tombergan commented Oct 18, 2017

tombergan commented Oct 18, 2017

benburkert commented Oct 18, 2017 •

edited

benburkert commented Oct 19, 2017

bradfitz commented Oct 19, 2017

gopherbot commented Oct 19, 2017

bradfitz commented Oct 19, 2017

benburkert commented Oct 19, 2017

ianlancetaylor commented Mar 29, 2018

bradfitz commented Mar 29, 2018

net/http: panic "slice bounds out of range" while reading chunked response body #22330

net/http: panic "slice bounds out of range" while reading chunked response body #22330

Comments

benburkert commented Oct 18, 2017

What version of Go are you using (go version)?

Does this issue reproduce with the latest release?

What operating system and processor architecture are you using (go env)?

What did you do?

What did you expect to see?

What did you see instead?

benburkert commented Oct 18, 2017

dsnet commented Oct 18, 2017

benburkert commented Oct 18, 2017

dsnet commented Oct 18, 2017

tombergan commented Oct 18, 2017

tombergan commented Oct 18, 2017

benburkert commented Oct 18, 2017 • edited

benburkert commented Oct 19, 2017

bradfitz commented Oct 19, 2017

gopherbot commented Oct 19, 2017

bradfitz commented Oct 19, 2017

benburkert commented Oct 19, 2017

ianlancetaylor commented Mar 29, 2018

bradfitz commented Mar 29, 2018

What version of Go are you using (`go version`)?

What operating system and processor architecture are you using (`go env`)?

benburkert commented Oct 18, 2017 •

edited