PANIC in readNext

[vyzo]

A relay has crashed with an index out of range.

Apr 18 20:42:52 ip-172-31-43-83 relay.sh[4778]: panic: runtime error: index out of range
Apr 18 20:42:52 ip-172-31-43-83 relay.sh[4778]: goroutine 25260147699 [running]:
Apr 18 20:42:52 ip-172-31-43-83 relay.sh[4778]: bufio.(*Reader).Read(0xc0f1b2c780, 0xc04347c2eb, 0x3142, 0x3d15, 0x20, 0x0, 0x0)
Apr 18 20:42:52 ip-172-31-43-83 relay.sh[4778]:         /usr/local/go/src/bufio/bufio.go:214 +0x3de
Apr 18 20:42:52 ip-172-31-43-83 relay.sh[4778]: io.ReadAtLeast(0xf26220, 0xc0f1b2c780, 0xc04347c000, 0x342d, 0x4000, 0x342d, 0xc0fc028d78, 0x85961f, 0xf26200)
Apr 18 20:42:52 ip-172-31-43-83 relay.sh[4778]:         /usr/local/go/src/io/io.go:310 +0x88
Apr 18 20:42:52 ip-172-31-43-83 relay.sh[4778]: io.ReadFull(...)
Apr 18 20:42:52 ip-172-31-43-83 relay.sh[4778]:         /usr/local/go/src/io/io.go:329
Apr 18 20:42:52 ip-172-31-43-83 relay.sh[4778]: github.com/libp2p/go-mplex.(*Multiplex).readNext(0xc01eb60230, 0x216, 0x7, 0x0, 0x0, 0xec0295e)
Apr 18 20:42:52 ip-172-31-43-83 relay.sh[4778]:         /home/ubuntu/go/pkg/mod/github.com/libp2p/[email protected]/multiplex.go:448 +0xc0
Apr 18 20:42:52 ip-172-31-43-83 relay.sh[4778]: github.com/libp2p/go-mplex.(*Multiplex).handleIncoming(0xc01eb60230)
Apr 18 20:42:52 ip-172-31-43-83 relay.sh[4778]:         /home/ubuntu/go/pkg/mod/github.com/libp2p/[email protected]/multiplex.go:281 +0x155
Apr 18 20:42:52 ip-172-31-43-83 relay.sh[4778]: created by github.com/libp2p/go-mplex.NewMultiplex
Apr 18 20:42:52 ip-172-31-43-83 relay.sh[4778]:         /home/ubuntu/go/pkg/mod/github.com/libp2p/[email protected]/multiplex.go:78 +0x1de

[Stebalien]

Secio could be returning the wrong length. That's all I can think of.

[Stebalien]

I've found libp2p/go-msgio#12 but I don't think that's the cause.

[ziranliu]

I have encountered this panic problem too and it's hard to reproduce. I look forward to your progress.

[vyzo]

Another one crashed; so it's a real bug, not some cosmic ray.

Apr 22 10:52:33 ip-172-31-4-200 relay.sh[9628]: panic: runtime error: index out of range
Apr 22 10:52:33 ip-172-31-4-200 relay.sh[9628]: goroutine 35695718100 [running]:
Apr 22 10:52:33 ip-172-31-4-200 relay.sh[9628]: bufio.(*Reader).Read(0xc16a1105a0, 0xc03361a3e0, 0x4dbf, 0x7c20, 0x21, 0x0, 0x0)
Apr 22 10:52:33 ip-172-31-4-200 relay.sh[9628]:         /usr/local/go/src/bufio/bufio.go:214 +0x3de
Apr 22 10:52:33 ip-172-31-4-200 relay.sh[9628]: io.ReadAtLeast(0xf26220, 0xc16a1105a0, 0xc033602000, 0x1d19f, 0x20000, 0x1d19f, 0xc09de19d78, 0x85961f, 0xf26200)
Apr 22 10:52:33 ip-172-31-4-200 relay.sh[9628]:         /usr/local/go/src/io/io.go:310 +0x88
Apr 22 10:52:33 ip-172-31-4-200 relay.sh[9628]: io.ReadFull(...)
Apr 22 10:52:33 ip-172-31-4-200 relay.sh[9628]:         /usr/local/go/src/io/io.go:329
Apr 22 10:52:33 ip-172-31-4-200 relay.sh[9628]: github.com/libp2p/go-mplex.(*Multiplex).readNext(0xc12d594230, 0x4f4, 0x7, 0x0, 0x0, 0x0)
Apr 22 10:52:33 ip-172-31-4-200 relay.sh[9628]:         /home/ubuntu/go/pkg/mod/github.com/libp2p/[email protected]/multiplex.go:448 +0xc0
Apr 22 10:52:33 ip-172-31-4-200 relay.sh[9628]: github.com/libp2p/go-mplex.(*Multiplex).handleIncoming(0xc12d594230)
Apr 22 10:52:33 ip-172-31-4-200 relay.sh[9628]:         /home/ubuntu/go/pkg/mod/github.com/libp2p/[email protected]/multiplex.go:281 +0x155
Apr 22 10:52:33 ip-172-31-4-200 relay.sh[9628]: created by github.com/libp2p/go-mplex.NewMultiplex
Apr 22 10:52:33 ip-172-31-4-200 relay.sh[9628]:         /home/ubuntu/go/pkg/mod/github.com/libp2p/[email protected]/multiplex.go:78 +0x1de

[vyzo]

I can confirm that the bug is still there, another one crashed running with the msgio patch.

[vyzo]

Progress: Running with with the patch in #45 triggers the oversize read assertion:

Apr 27 23:35:14 ip-172-31-47-240 relay.sh[28862]: panic: oversize read! n: 97488 len: 32678
Apr 27 23:35:14 ip-172-31-47-240 relay.sh[28862]: goroutine 735857932 [running]:
Apr 27 23:35:14 ip-172-31-47-240 relay.sh[28862]: github.com/libp2p/go-mplex.(*wrappedReader).Read(0xc03c2c6080, 0xc10028ffc7, 0x7fa6, 0x2a039, 0x3b, 0x0, 0x0)
Apr 27 23:35:14 ip-172-31-47-240 relay.sh[28862]:         /home/ubuntu/go/pkg/mod/github.com/libp2p/[email protected]/multiplex.go:468 +0x156
Apr 27 23:35:14 ip-172-31-47-240 relay.sh[28862]: bufio.(*Reader).Read(0xc081f7ccc0, 0xc10028ffc7, 0x7fa6, 0x2a039, 0x3b, 0x0, 0x0)
Apr 27 23:35:14 ip-172-31-47-240 relay.sh[28862]:         /usr/local/go/src/bufio/bufio.go:209 +0x126
Apr 27 23:35:14 ip-172-31-47-240 relay.sh[28862]: io.ReadAtLeast(0xf65300, 0xc081f7ccc0, 0xc1001ba000, 0xddf6d, 0x100000, 0xddf6d, 0xc0ae05bd78, 0x85a88f, 0xf652e0)
Apr 27 23:35:14 ip-172-31-47-240 relay.sh[28862]:         /usr/local/go/src/io/io.go:310 +0x88
Apr 27 23:35:14 ip-172-31-47-240 relay.sh[28862]: io.ReadFull(...)
Apr 27 23:35:14 ip-172-31-47-240 relay.sh[28862]:         /usr/local/go/src/io/io.go:329
Apr 27 23:35:14 ip-172-31-47-240 relay.sh[28862]: github.com/libp2p/go-mplex.(*Multiplex).readNext(0xc00908e380, 0x6a1, 0x4, 0x0, 0x0, 0x0)
Apr 27 23:35:14 ip-172-31-47-240 relay.sh[28862]:         /home/ubuntu/go/pkg/mod/github.com/libp2p/[email protected]/multiplex.go:448 +0xc0
Apr 27 23:35:14 ip-172-31-47-240 relay.sh[28862]: github.com/libp2p/go-mplex.(*Multiplex).handleIncoming(0xc00908e380)
Apr 27 23:35:14 ip-172-31-47-240 relay.sh[28862]:         /home/ubuntu/go/pkg/mod/github.com/libp2p/[email protected]/multiplex.go:281 +0x155
Apr 27 23:35:14 ip-172-31-47-240 relay.sh[28862]: created by github.com/libp2p/go-mplex.NewMultiplex
Apr 27 23:35:14 ip-172-31-47-240 relay.sh[28862]:         /home/ubuntu/go/pkg/mod/github.com/libp2p/[email protected]/multiplex.go:78 +0x2e2

[vyzo]

So the underlying connection claims to have read more than what space is available in the buffer.

[vyzo]

We have high hopes for libp2p/go-libp2p-secio#44 fixing the issue; we'll just have to wait a few days and see if any more crashes are observed in the relays.