build: slice bounds check failure

[josharian]

Build failure from darwin-386-cheney
(http://build.golang.org/log/89ebaa1281be8297290f8e7eda771da803a93b6e):

# ../test
# go run run.go -- index2.go

tmp__.go:3062: missing error "index|overflow|truncated|must be integer"
Unmatched Errors:
tmp__.go:3062: invalid slice index cni64big (index must be non-negative)

FAIL    index2.go   27.726s
exit status 1


It is unrelated to the commit that triggered it and has not recurred since.

[josharian]

Comment 1:

I can reproduce this. It happens intermittently, when using GOHOSTARCH=386 with a 64 bit
darwin kernel.
I'm going to bisect and get it down to as small and as reliable a test case as I can, at
which point I might hand it off to someone who knows what they're doing.

Status changed to Started.

[josharian]

Comment 2:

Bisection indicates that this started with
https://code.google.com/p/go/source/detail?r=50f52d5c2bb7dcb1b00b9c867660107d5a31c69b,
which appears to have uncovered a bug somewhere else.
I don't yet have a better test case than running `go run run.go` in a loop. `go run
run.go -- <some test>` doesn't do it. Removing directories from the list in run.go
cause failures in other ways -- panics, deadlocks, faults. It appears that some code,
somewhere, is now having a fun romp through other people's memory, unfettered from the
cruel shackles of null termination.
If anyone wants to take over, let me know. Otherwise, I'll keep poking at this for a bit
longer.

[dvyukov]

Comment 3:

I can reproduce it on linux/386, here are error that I observed:
# go run run.go -- index2.go
tmp__.go:211: missing error "index|overflow|truncated|must be integer"
Unmatched Errors:
tmp__.go:211: invalid slice index cni64 (index must be non-negative)
# go run run.go -- index2.go
tmp__.go:1769: missing error "index|overflow|truncated|must be integer"
Unmatched Errors:
tmp__.go:1769: invalid slice index ci32 (out of bounds for 100000-element array)
# go run run.go -- index2.go
tmp__.go:2747: missing error "index|overflow|truncated|must be integer"
Unmatched Errors:
tmp__.go:2747: invalid slice index ci32 (out of bounds for 100000-element array)
# go run run.go -- index2.go
tmp__.go:1297: missing error "index|overflow|truncated|must be integer"
Unmatched Errors:
tmp__.go:1297: constant -2.1 truncated to integer
tmp__.go:1297: invalid slice index cnfbad (index must be non-negative)
# go run run.go -- index2.go
tmp__.go:2603: missing error "index|overflow|truncated|must be integer"
Unmatched Errors:
tmp__.go:2603: invalid slice index cni8 (index must be non-negative)
I can't reproduce it on linux/amd64.

[dvyukov]

Comment 4:

I've tried to revert the change that removes zero termination for strings, and the crash
stopped happening.
But, I've also tried to run with GOGC=0 and hit the following crash in exactly the same
place where errors are matched:
fatal error: string concatenation too long
goroutine 135 [running]:
runtime.throw(0x828d240)
    src/pkg/runtime/panic.c:463 +0x68 fp=0xf75868b4
concatstring(0xf75868f8, 0x2, 0xf75868e8)
    src/pkg/runtime/string.goc:161 +0x5e fp=0xf75868d8
runtime.concatstring2(0x186bd8c0, 0xdeaddead, 0x817e3d8, 0x1, 0x0, ...)
    src/pkg/runtime/string.goc:185 +0x20 fp=0xf75868e8
main.func·006(0x186bd8c0, 0xdeaddead, 0x0, 0x0)
    test/run.go:731 +0x5d fp=0xf7586910
main.(*test).errorCheck(0x18470200, 0x18664600, 0x5ef, 0xf7586f60, 0x2, ...)
    test/run.go:737 +0x73c fp=0xf7586bbc
main.(*test).run(0x18470200)
    test/run.go:517 +0x1464 fp=0xf7586fbc
main.func·001()
    test/run.go:257 +0x29 fp=0xf7586fcc
runtime.goexit()
    src/pkg/runtime/proc.c:1438 fp=0xf7586fd0
created by main.runTests
    test/run.go:259 +0xad
This was with a slightly modified run.go which is attached.
The crash says that filterRe was freed (len of first member (expr string) is 0xdeaddead).
filterRe is created here:
853:            errs = append(errs, wantedError{
854:                reStr:    rx,
855:                re:       re,
856:                filterRe: regexp.MustCompile(filterPattern),
857:                lineNum:  lineNum,
858:                file:     short,
859:            })
Russ, can you check whether liveness analysis for this statement is correct or not?
run.go:856: live at call to MustCompile: t file short errs autotmp_1730 autotmp_1738
autotmp_1721 autotmp_1715 autotmp_1712 autotmp_1716 autotmp_1717 line rx autotmp_1726
autotmp_1734 re
run.go:859: live at call to growslice: t file short autotmp_1739 autotmp_1730
autotmp_1738 autotmp_1721 autotmp_1715 autotmp_1712 autotmp_1716 autotmp_1717 line
autotmp_1726 autotmp_1734
I am not sure why errs (return value) is not alive at 859.

Attachments:

1. run.go (22251 bytes)

[dvyukov]

Comment 5:

Here is another one in the same place suggesting that filterRe.expr is corrupted:
panic: regexp:
Compile("\x00\x00\x00\x00\x00\x00\x00\x00tN4\xf7sl\a\b\x98\xc7\x1f\b\x00\x00\x00\x00\x00\x00\x00"):
error parsing regexp: invalid UTF-8: `�s��`
goroutine 133 [running]:
runtime.panic(0x81422c0, 0x1878a120)
    src/pkg/runtime/panic.c:249 +0xb1
regexp.MustCompile(0x18659a60, 0x1b, 0x18659a60)
    src/pkg/regexp/regexp.go:206 +0x104
main.(*test).errorCheck(0x184ba340, 0x186c4000, 0x7969, 0xf74daf60, 0x2, ...)
    test/run.go:737 +0x75e
main.(*test).run(0x184ba340)
    test/run.go:517 +0x1464
main.func·001()
    test/run.go:257 +0x29
runtime.goexit()
    src/pkg/runtime/proc.c:1438
created by main.runTests
    test/run.go:259 +0xad

[josharian]

Comment 6:

Not 100% sure it's the same issue any longer, but this is now 99% reproducible with the
attached stripped-down append.go from tests. Run it with:
GODEBUG=efence=1 go run append.go
With 6g, all's well. With 8g, I see panics like:
unexpected fault address 0x107c84f7
fatal error: fault
[signal 0xb code=0x1 addr=0x107c84f7 pc=0xaeec]
goroutine 16 [running]:
runtime.throw(0x11b888)
    .../src/pkg/runtime/panic.c:463 +0x5f fp=0x3034c830
runtime.sigpanic()
    .../src/pkg/runtime/os_darwin.c:453 +0xf0 fp=0x3034c83c
MHeap_FreeLocked(0x129b40, 0x109e191c)
    .../src/pkg/runtime/mheap.c:433 +0x16c fp=0x3034c864
MHeap_Grow(0x129b40, 0x10)
    .../src/pkg/runtime/mheap.c:341 +0x165 fp=0x3034c88c
MHeap_AllocLocked(0x129b40, 0x1, 0x0)
    .../src/pkg/runtime/mheap.c:222 +0x2fc fp=0x3034c8ac
runtime.MHeap_Alloc(0x129b40, 0x1, 0x0, 0x101)
    .../src/pkg/runtime/mheap.c:178 +0x79 fp=0x3034c8c0
largealloc(0x0, 0x3034c920)
    .../src/pkg/runtime/malloc.goc:232 +0x91 fp=0x3034c8e4
runtime.mallocgc(0x8, 0x7c660, 0x0)
    .../src/pkg/runtime/malloc.goc:167 +0x9e fp=0x3034c920
cnew(0x7c660, 0x1, 0x0)
    .../src/pkg/runtime/malloc.goc:848 +0xa7 fp=0x3034c930
runtime.cnew(0x7c660)
    .../src/pkg/runtime/malloc.goc:855 +0x39 fp=0x3034c940
reflect.unsafe_New(0x7c660, 0x102c4228)
    .../src/pkg/runtime/iface.goc:578 +0x28 fp=0x3034c948
reflect.packEface(0x7c660, 0x113f0228, 0x0, 0x187, 0x0, ...)
    .../src/pkg/reflect/value.go:137 +0x82 fp=0x3034c97c
reflect.valueInterface(0x7c660, 0x113f0228, 0x0, 0x187, 0x0, ...)
    .../src/pkg/reflect/value.go:1081 +0x1a8 fp=0x3034c9d8
reflect.deepValueEqual(0x7c660, 0x113f0228, 0x0, 0x187, 0x7c660, ...)
    .../src/pkg/reflect/deepequal.go:125 +0x5eb fp=0x3034cb4c
reflect.deepValueEqual(0x8eda0, 0x113f0228, 0x0, 0x196, 0x8eda0, ...)
    .../src/pkg/reflect/deepequal.go:96 +0xbe5 fp=0x3034ccc0
reflect.deepValueEqual(0x7a160, 0x1245c000, 0x0, 0x172, 0x7a160, ...)
    .../src/pkg/reflect/deepequal.go:82 +0xaeb fp=0x3034ce34
reflect.DeepEqual(0x7a160, 0x1245c000, 0x7a160, 0x1245e000, 0x1ae9c)
    .../src/pkg/reflect/deepequal.go:144 +0x17b fp=0x3034ceb8
main.verify(0xa4508, 0x19, 0x7a160, 0x1245c000, 0x7a160, ...)
    .../test/append.go:21 +0x4d fp=0x3034cef8
main.main()
    .../test/append.go:33 +0x308 fp=0x3034cf98
runtime.main()
    .../src/pkg/runtime/proc.c:231 +0xfa fp=0x3034cfcc
runtime.goexit()
    .../src/pkg/runtime/proc.c:1438 fp=0x3034cfd0
created by _rt0_go
    .../src/pkg/runtime/asm_386.s:101 +0xf7
and
SIGSEGV: segmentation violation
PC=0x7fb2
runtime.MSpan_Sweep(0x107c7fd0)
    .../src/pkg/runtime/mgc0.c:1774 +0x102
runtime.sweepone()
    .../src/pkg/runtime/mgc0.c:1952 +0xd3
gc(0x3034c8d8)
    .../src/pkg/runtime/mgc0.c:2322 +0xea
mgc(0x1025e000)
    .../src/pkg/runtime/mgc0.c:2283 +0x2b
runtime.mcall(0x2217f)
    .../src/pkg/runtime/asm_386.s:190 +0x3c
goroutine 16 [garbage collection]:
runtime.gc(0x0)
    .../src/pkg/runtime/mgc0.c:2252 +0x196 fp=0x3034c8e4
runtime.mallocgc(0x2000, 0x7c660, 0x0)
    .../src/pkg/runtime/malloc.goc:213 +0x186 fp=0x3034c920
cnew(0x7c660, 0x1, 0x0)
    .../src/pkg/runtime/malloc.goc:848 +0xa7 fp=0x3034c930
runtime.cnew(0x7c660)
    .../src/pkg/runtime/malloc.goc:855 +0x39 fp=0x3034c940
reflect.unsafe_New(0x7c660, 0x25f90148)
    .../src/pkg/runtime/iface.goc:578 +0x28 fp=0x3034c948
reflect.packEface(0x7c660, 0x102c4150, 0x0, 0x187, 0x0, ...)
    .../src/pkg/reflect/value.go:137 +0x82 fp=0x3034c97c
reflect.valueInterface(0x7c660, 0x102c4150, 0x0, 0x187, 0x0, ...)
    .../src/pkg/reflect/value.go:1081 +0x1a8 fp=0x3034c9d8
reflect.deepValueEqual(0x7c660, 0x25f90150, 0x0, 0x187, 0x7c660, ...)
    .../src/pkg/reflect/deepequal.go:125 +0x5bf fp=0x3034cb4c
reflect.deepValueEqual(0x8eda0, 0x25f90150, 0x0, 0x196, 0x8eda0, ...)
    .../src/pkg/reflect/deepequal.go:96 +0xbe5 fp=0x3034ccc0
reflect.deepValueEqual(0x7a160, 0x25f92000, 0x0, 0x172, 0x7a160, ...)
    .../src/pkg/reflect/deepequal.go:82 +0xaeb fp=0x3034ce34
reflect.DeepEqual(0x7a160, 0x25f92000, 0x7a160, 0x25f94000, 0x1ae9c)
    .../src/pkg/reflect/deepequal.go:144 +0x17b fp=0x3034ceb8
main.verify(0x9ccd8, 0x8, 0x7a160, 0x25f92000, 0x7a160, ...)
    .../test/append.go:21 +0x4d fp=0x3034cef8
main.main()
    .../test/append.go:32 +0x282 fp=0x3034cf98
runtime.main()
    .../src/pkg/runtime/proc.c:231 +0xfa fp=0x3034cfcc
runtime.goexit()
    .../src/pkg/runtime/proc.c:1438 fp=0x3034cfd0
created by _rt0_go
    .../src/pkg/runtime/asm_386.s:101 +0xf7
eax     0x3024b000
ebx     0x107c7fe4
ecx     0x2b
edx     0x0
edi     0x107c8010
esi     0x2000
ebp     0x107c7fd0
esp     0x30364de8
eip     0x7fb2
eflags  0x10202
cs      0x1b
fs      0x23
gs      0xf

Attachments:

1. append.go (642 bytes)

[josharian]

Comment 7:

Status changed to Accepted.

[josharian]

Comment 8:

One of the crashes I see from append.go comes from within reflect/value.go:39, which is
part of `func memmove`, which has this comment at the top:
// TODO: This will have to go away when
// the new gc goes in.
So...I'd guess that that might have something to do with it. :)

[rsc]

Comment 9:

errs is not alive during the call to growslice because growslice is being passed the old
value of the variable and what it returns will overwrite the variable. the variable's
value during the call is not going to be read ever again.

Status changed to Duplicate.

Merged into issue #7344.