net/http: ChunkedReader blocks Read until the next chunk arrives

[yauhen-l]

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

go version go1.7.1 linux/amd64

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

GOARCH="amd64"
GOBIN=""
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="/home/yauhen/ws"
GORACE=""
GOROOT="/home/yauhen/gosrc/go"
GOTOOLDIR="/home/yauhen/gosrc/go/pkg/tool/linux_amd64"
CC="gcc"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build478463408=/tmp/go-build -gno-record-gcc-switches"
CXX="g++"
CGO_ENABLED="1"

What did you do?

I've noticed that sometimes client(iOS, Android application) connected to my server sends chunks of chunked HTTP Transfer-Encoding in manner when end of current chunk is received in the next packet. E.g., client sends chunks every second: hello1\n, hello2\n, etc. Here is encoded result, where each line is sent with 1 second delay:

7\r\nhello1\n
\r\n7\r\nhello2\n
\r\n7\r\nhello3\n
...

Simulation on playground:
https://play.golang.org/p/Y9I7vYoGbx

What did you expect to see?

I expect to read chunk when it is ready in spite of how it is received: in one packet or in two.

What did you see instead?

I cannot read chunk until:
a) client closes connection
b) buffer of ChunkedReader is full
c) client sends line which ends with \r\n

[odeke-em]

Hello there @yauhen-l, I think the issue here is that you io.Pipe() is not being used properly, you forgot to close the pipe writer in your write goroutine so that means the buffer will instead get full before the program is done since you never explicitly closed it
To fix your problem, please don't forget to invoke defer pw.Close() in your write goroutine like this
https://play.golang.org/p/2eVg3OO2eo

and also the io.Pipe() docs mention that

IMO there is no bug here, just a forgotten pw.Close(). I'll let @bradfitz bless the bug with a close or a correction of my analysis.

[bradfitz]

@odeke-em, not quite.

More minimal example: https://play.golang.org/p/RuDNKvAQhT

Which says:

fatal error: all goroutines are asleep - deadlock!

goroutine 1 [semacquire]:
sync.runtime_notifyListWait(0x107406ac, 0x1)
    /usr/local/go/src/runtime/sema.go:267 +0x1e0
sync.(*Cond).Wait(0x107406a4, 0x3003bc)
    /usr/local/go/src/sync/cond.go:57 +0xe0
io.(*pipe).read(0x10740680, 0x10753000, 0x1000, 0x1000, 0x0, 0x0, 0x0, 0x1000)
    /usr/local/go/src/io/pipe.go:47 +0x3e0
io.(*PipeReader).Read(0x1070a4b8, 0x10753000, 0x1000, 0x1000, 0x1070a4b8, 0x0, 0x0, 0x1000)
    /usr/local/go/src/io/pipe.go:129 +0x60
bufio.(*Reader).fill(0x107363c0, 0x7881)
    /usr/local/go/src/bufio/bufio.go:97 +0x260
bufio.(*Reader).Read(0x107363c0, 0x10732b98, 0x2, 0x2, 0x7, 0x0, 0x0, 0x1000)
    /usr/local/go/src/bufio/bufio.go:209 +0x2c0
io.ReadAtLeast(0x3a07c0, 0x107363c0, 0x10732b98, 0x2, 0x2, 0x2, 0x0, 0x0, 0x0, 0xffd)
    /usr/local/go/src/io/io.go:307 +0xe0
io.ReadFull(0x3a07c0, 0x107363c0, 0x10732b98, 0x2, 0x2, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/local/go/src/io/io.go:325 +0x60
net/http/internal.(*chunkedReader).Read(0x10732b80, 0x1077d730, 0x0, 0x0, 0x7, 0x0, 0x0, 0x7)
    /usr/local/go/src/net/http/internal/chunked.go:95 +0x2a0
main.main()
    /tmp/sandbox227319092/main.go:17 +0x3c0

The report is that an io.Reader is supposed to return as soon as it has anything, without blocking further, and net/http/internal.(*chunkedReader).Read doesn't do that.

See src/net/http/internal/chunked.go:95 in the backtrace? That line 95 is the "ReadFull" at:

func (cr *chunkedReader) Read(b []uint8) (n int, err error) {
        for cr.err == nil {
                if cr.n == 0 {
                        if n > 0 && !cr.chunkHeaderAvailable() {
                                // We've read enough. Don't potentially block                                                                                                                                            
                                // reading a new chunk header.                                                                                                                                                           
                                break
                        }
                        cr.beginChunk()
                        continue
                }
                if len(b) == 0 {
                        break
                }
                rbuf := b
                if uint64(len(rbuf)) > cr.n {
                        rbuf = rbuf[:cr.n]
                }
                var n0 int
                n0, cr.err = cr.r.Read(rbuf)
                n += n0
                b = b[n0:]
                cr.n -= uint64(n0)
                // If we're at the end of a chunk, read the next two                                                                                                                                                     
                // bytes to verify they are "\r\n".                                                                                                                                                                      
                if cr.n == 0 && cr.err == nil {
                        if _, cr.err = io.ReadFull(cr.r, cr.buf[:2]); cr.err == nil {
                                if cr.buf[0] != '\r' || cr.buf[1] != '\n' {
                                        cr.err = errors.New("malformed chunked encoding")
                                }
                        }
                }
        }
        return n, cr.err
}

So we it has data to return, but it's blocking further to make sure the next two bytes are valid. It could instead delay that check if it kept more state.

[odeke-em]

@bradfitz awesome, thank you for the analysis and correction.

Ah I see, my remedy of pw.Close() then just masked the problem and completed the writes.

[gopherbot]

CL https://golang.org/cl/31329 mentions this issue.