runtime: some kind deadlock issue with the new scheduler

[alberts]

What steps will reproduce the problem?

GOMAXPROCS=random ./run.bash --no-rebuild in a loop

What do you see instead?

# ../test
run mallocfin.go: incorrect output
checkdead: find g 4 in status 1
fatal error: checkdead: runnable g

goroutine 1 [sleep]:
time.Sleep(0xf4240)
/build/go.tip/go/src/pkg/runtime/ztime_linux_amd64.c:19 +0x2f
main.main()
/build/go.tip/go/test/mallocfin.go:68 +0x190

goroutine 3 [finalizer wait]:
exit status 2

exit status 1

Which compiler are you using (5g, 6g, 8g, gccgo)?

6g

Which operating system are you using?

linux

Which version are you using?  (run 'go version')

go version devel +e7e2b3ec4717 Wed Mar 06 16:15:04 2013 -0800 linux/amd64

Please provide any additional information below.

I've seen another hint of this. I think I have a build where the go command deadlocked
while running short tests.

the test that timed out was compress/lzw, which usually takes only a few milliseconds,
so I suspect the go command that was running it got very confused.

panic: test timed out

goroutine 7 [running]:
testing.alarm()
        /build/go.tip/go/src/pkg/testing/testing.go:526 +0x53
created by time.goFunc
        /build/go.tip/go/src/pkg/time/sleep.go:122 +0x48

goroutine 1 [chan receive]:
testing.RunTests(0x52a0f8, 0x5b6000, 0x3, 0x3, 0x1, ...)
        /build/go.tip/go/src/pkg/testing/testing.go:427 +0x88e
testing.Main(0x52a0f8, 0x5b6000, 0x3, 0x3, 0x5b6410, ...)
        /build/go.tip/go/src/pkg/testing/testing.go:358 +0x8a
main.main()
        compress/lzw/_test/_testmain.go:59 +0x9a

goroutine 5 [semacquire]:
sync.runtime_Semacquire(0xc200000118)
        /build/go.tip/go/src/pkg/runtime/zsema_linux_amd64.c:165 +0x2e
sync.(*Cond).Wait(0xc2000a3030)
        /build/go.tip/go/src/pkg/sync/cond.go:73 +0x95
io.(*pipe).read(0xc2000a3000, 0xc2000de000, 0x1000, 0x1000, 0x0, ...)
        /build/go.tip/go/src/pkg/io/pipe.go:52 +0x1f2
io.(*PipeReader).Read(0xc200000108, 0xc2000de000, 0x1000, 0x1000,
0x51373842, ...)
        /build/go.tip/go/src/pkg/io/pipe.go:130 +0x5d
bufio.(*Reader).fill(0xc2000a51e0)
        /build/go.tip/go/src/pkg/bufio/bufio.go:79 +0x10c
bufio.(*Reader).ReadByte(0xc2000a51e0, 0x20, 0x0, 0x0)
        /build/go.tip/go/src/pkg/bufio/bufio.go:171 +0x7d
compress/lzw.(*decoder).readLSB(0xc2000d8300, 0x414b5e, 0xc20004f008,
0x100000002)
        /build/go.tip/go/src/pkg/compress/lzw/reader.go:83 +0x3a
compress/lzw.(*decoder).decode(0xc2000d8300)
        /build/go.tip/go/src/pkg/compress/lzw/reader.go:133 +0x34
compress/lzw.(*decoder).Read(0xc2000d8300, 0xc200092a00, 0x200, 0x200,
0x201, ...)
        /build/go.tip/go/src/pkg/compress/lzw/reader.go:122 +0x17e
bytes.(*Buffer).ReadFrom(0x7f7febee9a68, 0xc20004a630, 0xc2000d8300,
0x0, 0x0, ...)
        /build/go.tip/go/src/pkg/bytes/buffer.go:166 +0x203
io/ioutil.readAll(0xc20004a630, 0xc2000d8300, 0x200, 0x0, 0x0, ...)
        /build/go.tip/go/src/pkg/io/ioutil/ioutil.go:32 +0x141
io/ioutil.ReadAll(0xc20004a630, 0xc2000d8300, 0xc2000d8300,
0xc20004a630, 0xc2000d8300, ...)
        /build/go.tip/go/src/pkg/io/ioutil/ioutil.go:41 +0x3d
compress/lzw.testFile(0xc20008e120, 0x5138e8, 0x11, 0x0, 0x6, ...)
        /build/go.tip/go/src/pkg/compress/lzw/writer_test.go:67 +0x5d3
compress/lzw.TestWriter(0xc20008e120)
        /build/go.tip/go/src/pkg/compress/lzw/writer_test.go:93 +0x172
testing.tRunner(0xc20008e120, 0x5b6018)
        /build/go.tip/go/src/pkg/testing/testing.go:346 +0x8a
created by testing.RunTests
        /build/go.tip/go/src/pkg/testing/testing.go:426 +0x86b

goroutine 6 [running]:
syscall.Syscall()
        /build/go.tip/go/src/pkg/syscall/asm_linux_amd64.s:16 +0x5
syscall.read(0x4, 0xc2000c2000, 0x1000, 0x1000, 0x4301c0, ...)
        /build/go.tip/go/src/pkg/syscall/zerrors_linux_amd64.go:2337 +0x70
syscall.Read(0x0, 0x43071e, 0xc2000b1000, 0x234, 0x0, ...)
        /build/go.tip/go/src/pkg/syscall/syscall_unix.go:132 +0x5a
created by compress/lzw.testFile
        /build/go.tip/go/src/pkg/compress/lzw/writer_test.go:61 +0x4b3
FAIL    compress/lzw    120.020s

[alberts]

Comment 1:

actually, correction on the compress/lzw bit: that trace is from the test itself, no the
go command running it.

[dvyukov]

Comment 2:

Please test with https://golang.org/cl/7424054/

[alberts]

Comment 3:

Struggling to reproduce the mallocfin.go one. I've had another test timeout lockup
though.
It will probably be easiest for me if you get CL 7424054 merged and then we can see what
happens over the next few days.

[dvyukov]

Comment 4:

cl/7424054 is  submitted
it fixed similar hangups for me

[alberts]

Comment 5:

looks like it fixed it. tests ran through the night.

[rsc]

Comment 6:

Status changed to Fixed.