bufio: add comment on broken underlying readers

[tubzby]

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

$ go version
go version go1.17.3 linux/amd64

Does this issue reproduce with the latest release?

Yes

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

Running on Ubuntu 20.04.2 LTS AMD64

go env Output

$ go env
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/home/XXX/.cache/go-build"
GOENV="/home/XXX/.config/go/env"
GOEXE=""
GOEXPERIMENT=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/home/XXX/go/pkg/mod"
GONOPROXY="gitee.com"
GONOSUMDB="gitee.com"
GOOS="linux"
GOPATH="/home/XXX/go"
GOPRIVATE="gitee.com"
GOPROXY="https://goproxy.io,direct"
GOROOT="/usr/local/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/local/go/pkg/tool/linux_amd64"
GOVCS=""
GOVERSION="go1.17.3"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/dev/null"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build304548871=/tmp/go-build -gno-record-gcc-switches"

What did you do?

I'm using gomavlib: https://github.com/aler9/gomavlib to build a server process , but find out some server crash like this:

 uavm[212516]: panic: runtime error: slice bounds out of range [:987] with capacity 512
 uavm[212516]: goroutine 845 [running]:
 uavm[212516]: bufio.(*Reader).Read(0xc0005f7860, {0xc00060d72f, 0x1, 0x1})
 uavm[212516]:         /usr/local/go/src/bufio/bufio.go:238 +0x7f9
 uavm[212516]: io.ReadAtLeast({0x1199040, 0xc0005f7860}, {0xc00060d72f, 0x1, 0x1}, 0x1)
 uavm[212516]:         /usr/local/go/src/io/io.go:328 +0xde
 uavm[212516]: io.ReadFull(...)
 uavm[212516]:         /usr/local/go/src/io/io.go:347
 uavm[212516]: github.com/aler9/gomavlib/pkg/frame.(*V2Frame).Decode(0xc00043e660, 0x7fd4bbec5420)
 uavm[212516]:         /home/XXX/go/pkg/mod/github.com/aler9/gomavlib@v0.0.0-20211028051547-c91b43b554d6/pkg/frame/v2.go:141 +0x3af
 uavm[212516]: github.com/aler9/gomavlib/pkg/transceiver.(*Transceiver).Read(0xc0005b4100)
 uavm[212516]:         /home/XXX/go/pkg/mod/github.com/aler9/gomavlib@v0.0.0-20211028051547-c91b43b554d6/pkg/transceiver/transceiver.go:130 +0xcb
 uavm[212516]: github.com/aler9/gomavlib.(*Channel).run.func1()
 uavm[212516]:         /home/XXX/go/pkg/mod/github.com/aler9/gomavlib@v0.0.0-20211028051547-c91b43b554d6/channel.go:93 +0x18f
 uavm[212516]: created by github.com/aler9/gomavlib.(*Channel).run
 uavm[212516]:         /home/XXX/go/pkg/mod/github.com/aler9/gomavlib@v0.0.0-20211028051547-c91b43b554d6/channel.go:85 +0x199
 systemd[1]: uavm.service: Main process exited, code=exited, status=2/INVALIDARGUMENT

The code in gomavlib causing the problem is :

func (f *V2Frame) Decode(br *bufio.Reader) error {
	// header
	buf, err := br.Peek(9)
	if err != nil {
		return err
	}
	br.Discard(9)
	msgLen := buf[0]
	f.IncompatibilityFlag = buf[1]
	f.CompatibilityFlag = buf[2]
	f.SequenceID = buf[3]
	f.SystemID = buf[4]
	f.ComponentID = buf[5]
	msgID := uint24Decode(buf[6:])

	// discard frame if incompatibility flag is not understood, as in recommendations
	if f.IncompatibilityFlag != 0 && f.IncompatibilityFlag != V2FlagSigned {
		return fmt.Errorf("unknown incompatibility flag (%d)", f.IncompatibilityFlag)
	}

	// message
	var msgEncoded []byte
	if msgLen > 0 {
		msgEncoded = make([]byte, msgLen)
                // THIS LINE IS CAUSING THE CRASH!!!!!!!!!!!!!!!!
		_, err = io.ReadFull(br, msgEncoded)
		if err != nil {
			return err
		}
	}

The bufio.Reader is created with a size of 512, how can we copy with a byte array index value 987?

I have already built the process using -race and found no data race report. From my point of view, io.ReadFull is not supposed to crash on this scenario, that's why I fire an issue here.

But I can't reproduce it right now, I'm still trying to figure out what might cause this, any clues and suggestions are welcome.

What did you expect to see?

Expect the process not to crash.

What did you see instead?

Process crash on some situation.

[andig]

Could you build a minimal reproducer with the function in question? I would agree it shoudn't crash looking at https://pkg.go.dev/io#ReadFull

[tubzby]

@andig Still trying, I will update here ASAP.

[nishanths]

In case it helps, in similar issues in the past it seems like the panic might have been due to concurrent Read calls to the bufio.Reader.

[tubzby]

@nishanths Thanks, that's the first thing came into my mind, I will double-check that.

[tubzby]

Finally, I figured it out, it was caused by an invalid implementation of io.Read:

https://github.com/aler9/gomavlib/blob/bb2bb0de607f0b2d782de88087cf82045a4ef1fc/pkg/udplistener/udplistener.go#L97

// Read implements the net.Conn interface.
func (c *conn) Read(byt []byte) (int, error) {
	var buf []byte
	var ok bool

	if !c.readDeadline.IsZero() {
		readTimer := time.NewTimer(time.Until(c.readDeadline))
		defer readTimer.Stop()

		select {
		case <-readTimer.C:
			return 0, errTimeout
		case buf, ok = <-c.read:
		}
	} else {
		buf, ok = <-c.read
	}

	if !ok {
		return 0, errTerminated
	}

	copy(byt, buf)
	c.listener.readDone <- struct{}{}
	return len(buf), nil
}

This function returns the length of buf instead of how many bytes has been copied into byt.

On the other hand, bufio use what have returned without any check to update the write position, thus causing an invalid w that out of range of inside buf, which in my case is something more than 512.

func (b *Reader) Read(p []byte) (n int, err error) {
	n = len(p)
	if n == 0 {
		if b.Buffered() > 0 {
			return 0, nil
		}
		return 0, b.readErr()
	}
	if b.r == b.w {
		if b.err != nil {
			return 0, b.readErr()
		}
		if len(p) >= len(b.buf) {
			// Large read, empty buffer.
			// Read directly into p to avoid copy.
			n, b.err = b.rd.Read(p)
			if n < 0 {
				panic(errNegativeRead)
			}
			if n > 0 {
				b.lastByte = int(p[n-1])
				b.lastRuneSize = -1
			}
			return n, b.readErr()
		}
		// One read.
		// Do not use b.fill, which will loop.
		b.r = 0
		b.w = 0
		n, b.err = b.rd.Read(b.buf)
		if n < 0 {
			panic(errNegativeRead)
		}
		if n == 0 {
			return 0, b.readErr()
		}
		b.w += n
	}

	// copy as much as we can
	n = copy(p, b.buf[b.r:b.w])
	b.r += n
	b.lastByte = int(b.buf[b.r-1])
	b.lastRuneSize = -1
	return n, nil
}

For my case, I will fix the invalid implementation of io.Read, but I think it will be helpful if we add some extra sanity check here, maybe a panic with an error, because your problem will panic anyway later on and it's much harder to trace.

[randall77]

We don't generally try to defend against misbehaving io.Readers. There are lots of places readers and writers are used, and do we really want to defend against bad behavior everywhere?
In addition, it's only a partial defense. It would only catch the error if the return value was wrong enough to overflow the buffer. A wrong answer that was still within the bounds of the buffer would generate bad behavior (junk data?) without triggering the check.
The error here isn't really all that much "later". It's immediately after the call to the underlying badly-behaved reader. It's not an unbounded time later.

All that said, I think we could do something here. Maybe just a comment on the line with [b.r:b.w] saying that if it out-of-bounds panics, it must be because of a misbehaving reader. That should be enough to get a hint about the cause from the line number of the backtrace.

[gopherbot]

Change https://golang.org/cl/367214 mentions this issue: bufio: mention that panic at slicing means underlying reader is broken