runtime: heapBitsForSpan: base out of range

[karalabe]

We've received another crash report on android/arm (ARMv7) with Go 1.8.1 around memory allocations: ethereum/go-ethereum#14422.

The report claims that it was a one off event and couldn't reproduce it, so we can't really tell much more about it than the crash log. The crash part of the dump is below, but you can look ad the linked issue for the full version.

E/Go: fatal error: heapBitsForSpan: base out of range
E/Go: runtime stack:
E/Go: runtime.throw(0x9f0a62d5, 0x22)
E/Go: 	/home/travis/build/ethereum/go-ethereum/go/src/runtime/panic.go:596 +0x78
E/Go: runtime.heapBitsForSpan(0x93fd0000, 0x1, 0x16)
E/Go: 	/home/travis/build/ethereum/go-ethereum/go/src/runtime/mbitmap.go:377 +0x84
E/Go: runtime.(*mcentral).grow(0x9f92fc08, 0x0)
E/Go: 	/home/travis/build/ethereum/go-ethereum/go/src/runtime/mcentral.go:220 +0xc0
E/Go: runtime.(*mcentral).cacheSpan(0x9f92fc08, 0xf0)
E/Go: 	/home/travis/build/ethereum/go-ethereum/go/src/runtime/mcentral.go:93 +0x10c
E/Go: runtime.(*mcache).refill(0x7e4484b0, 0x16, 0x744)
E/Go: 	/home/travis/build/ethereum/go-ethereum/go/src/runtime/mcache.go:122 +0x84
E/Go: runtime.(*mcache).nextFree.func1()
E/Go: 	/home/travis/build/ethereum/go-ethereum/go/src/runtime/malloc.go:526 +0x24
E/Go: runtime.systemstack(0x8e698a80)
E/Go: 	/home/travis/build/ethereum/go-ethereum/go/src/runtime/asm_arm.s:264 +0x8c
E/Go: runtime.mstart()
E/Go: 	/home/travis/build/ethereum/go-ethereum/go/src/runtime/proc.go:1132
E/Go: goroutine 26327 [running]:
E/Go: runtime.systemstack_switch()
E/Go: 	/home/travis/build/ethereum/go-ethereum/go/src/runtime/asm_arm.s:209 +0x4 fp=0x98a02bb8 sp=0x98a02bb4
E/Go: runtime.(*mcache).nextFree(0x7e4484b0, 0x16, 0x0, 0x9ed7102c, 0x0)
E/Go: 	/home/travis/build/ethereum/go-ethereum/go/src/runtime/malloc.go:527 +0xa0 fp=0x98a02be4 sp=0x98a02bb8
E/Go: runtime.mallocgc(0x1a0, 0x9f4abc98, 0x9e90ed01, 0x93449a00)
E/Go: 	/home/travis/build/ethereum/go-ethereum/go/src/runtime/malloc.go:679 +0x918 fp=0x98a02c3c sp=0x98a02be4
E/Go: runtime.newobject(0x9f4abc98, 0x93449a00)
E/Go: 	/home/travis/build/ethereum/go-ethereum/go/src/runtime/malloc.go:808 +0x2c fp=0x98a02c50 sp=0x98a02c3c
E/Go: github.com/ethereum/go-ethereum/consensus/clique.sigHash(0x8fad6200, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
E/Go: 	/home/travis/go/src/github.com/ethereum/go-ethereum/consensus/clique/clique.go:141 +0x50 fp=0x98a02c9c sp=0x98a02c50
E/Go: github.com/ethereum/go-ethereum/consensus/clique.ecrecover(0x8fad6200, 0x0, 0x0, 0x0, 0x0, 0x0, 0xd59502e1, 0x67d94ad7)
E/Go: 	/home/travis/go/src/github.com/ethereum/go-ethereum/consensus/clique/clique.go:173 +0x9c fp=0x98a02d00 sp=0x98a02c9c
E/Go: github.com/ethereum/go-ethereum/consensus/clique.(*Clique).verifySeal(0x8ee910e0, 0x9f873ac8, 0x8ee91180, 0x8fad6200, 0x8f7ec000, 0x21e, 0x1580, 0xf4ccd9d, 0x6ddf6dff)
E/Go: 	/home/travis/go/src/github.com/ethereum/go-ethereum/consensus/clique/clique.go:467 +0x14c fp=0x98a02e14 sp=0x98a02d00
E/Go: github.com/ethereum/go-ethereum/consensus/clique.(*Clique).verifyCascadingFields(0x8ee910e0, 0x9f873ac8, 0x8ee91180, 0x8fad6200, 0x8f7ec000, 0x21e, 0x1580, 0x2, 0x0)
E/Go: 	/home/travis/go/src/github.com/ethereum/go-ethereum/consensus/clique/clique.go:354 +0x49c fp=0x98a02edc sp=0x98a02e14
E/Go: github.com/ethereum/go-ethereum/consensus/clique.(*Clique).verifyHeader(0x8ee910e0, 0x9f873ac8, 0x8ee91180, 0x8fad6200, 0x8f7ec000, 0x21e, 0x1580, 0x0, 0x0)
E/Go: 	/home/travis/go/src/github.com/ethereum/go-ethereum/consensus/clique/clique.go:311 +0x2fc fp=0x98a02f48 sp=0x98a02edc
E/Go: github.com/ethereum/go-ethereum/consensus/clique.(*Clique).VerifyHeaders.func1(0x8f7ec000, 0x800, 0x1580, 0x8ee910e0, 0x9f873ac8, 0x8ee91180, 0x94022d00, 0x94022d40)
E/Go: 	/home/travis/go/src/github.com/ethereum/go-ethereum/consensus/clique/clique.go:243 +0x70 fp=0x98a02fcc sp=0x98a02f48
E/Go: runtime.goexit()
E/Go: 	/home/travis/build/ethereum/go-ethereum/go/src/runtime/asm_arm.s:1017 +0x4 fp=0x98a02fcc sp=0x98a02fcc
E/Go: created by github.com/ethereum/go-ethereum/consensus/clique.(*Clique).VerifyHeaders
E/Go: 	/home/travis/go/src/github.com/ethereum/go-ethereum/consensus/clique/clique.go:251 +0xb4

[gopherbot]

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

[gopherbot]

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

[aclements]

Some debugging notes:

runtime.mallocgc(0x1a0, 0x9f4abc98, 0x9e90ed01, 0x93449a00) - Size is 0x1a0 (416) bytes.
runtime.(*mcache).nextFree(0x7e4484b0, 0x16, 0x0, 0x9ed7102c, 0x0) - Size class is 0x16, which is exactly 416 bytes.
runtime.(*mcache).refill(0x7e4484b0, 0x16, 0x744) - The class 0x16 mcache was out of free objects.
runtime.(*mcentral).grow(0x9f92fc08, 0x0) - The class 0x16 mcentral was also out of free objects.

At this point it would have called mheap_.alloc(1, 0x16, false, true) to allocate a new 1 page span. Given that heapBitsForSpan is complaining about the base, this probably got to mheap_.grow(1), since that's the only path that modifies the arena bounds.

We can also glean some things about the address space layout. Since this is 32-bit, arena_start is 0. That means the failure must have happened because base >= mheap_.arena_used, where base = 0x93fd0000. This base is interesting because it's below Go's static data, which includes the string to throw at 0x9f0a62d5 and the mcentral at 0x9f92fc08. I'm not positive, but I think this means we're allocating outside the initial arena reservation. However, this g's stack starts at address 0x98a02fcc, which means we've already heap allocated above the bad base address, which means arena_used > base at some point in the past.

This suggests two possibilities: 1. arena_used somehow got entirely corrupted (which isn't very helpful for debugging) or 2. some intentional update to arena_used decreased it (possibly as a result of overflow), which is never supposed to happen.

[aclements]

Found it (I love symbolic execution). Actually, I'm surprised this doesn't fail more often.

1. mallocinit reserves some memory for the arena. Let's say it gets a 128MB mapping at a high address like 0x70000000. It sets arena_start to 0 (because this is 32-bit), arena_used to 0x70000000, and arena_end to 0x78000000.
2. Now, we do an allocation larger than arena_end - arena_used. Let's say it's a 256MB allocation. mheap.sysAlloc takes the first branch to grow the reservation. There's still plenty of address space above arena_end, so it calls sysReserve with arena_end.
3. sysReserve is free to put the mapping wherever it wants (the address is just a hint). Let's say it returns a low address for p, like 0x10000000.
4. mheap.sysAlloc takes the h.arena_start <= p && p+p_size-h.arena_start-1 <= _MaxArena32 branch. But this code assumes that the new mapping will appear somewhere above arena_end, so it blindly sets arena_start to p. In this case, this lowers arena_used to 0x10000000, so now we think everything above that is not in the Go heap.

I think the fix is easy, but we've screwed up this code more times than I care to count. :) I'll put together and verify a patch on Monday, if not earlier.

[gopherbot]

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