Skip to content

runtime: new timer code breaks TestLockedDeadlock2 on Solaris #35393

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
rorth opened this issue Nov 6, 2019 · 6 comments
Closed

runtime: new timer code breaks TestLockedDeadlock2 on Solaris #35393

rorth opened this issue Nov 6, 2019 · 6 comments
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. OS-Solaris Soon This needs action soon. (recent regressions, service outages, unusual time-sensitive situations)
Milestone

Comments

@rorth
Copy link

rorth commented Nov 6, 2019

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

$ go version
go version devel +6becb03334 Wed Oct 30 21:43:57 2019 +0000 solaris/amd64

Does this issue reproduce with the latest release?

Yes.

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

go env Output
$ go env
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/homes/ro/.xdg/SunOS/.cache/go-build"
GOENV="/homes/ro/.xdg/SunOS/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="solaris"
GONOPROXY=""
GONOSUMDB=""
GOOS="solaris"
GOPATH="/homes/ro/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/var/gcc/go/goroot"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/var/gcc/go/goroot/pkg/tool/solaris_amd64"GCCGO="/usr/bin/gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/var/gcc/go/goroot/src/go.mod"
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-build464021887=/tmp/go-build -gno-record-gcc-switches"

What did you do?

For a couple of days, the solaris-amd64 builder has been failing most of the the time, while
until Oct 31 it has been almost completely reliable.

This started off as a failure in runtime.TestLockedDeadlock2.

What did you expect to see?

The test should continue to pass as before.

What did you see instead?

It started to fail like this

ro@foo-foo 85 > ../bin/go test -short -tags= -timeout=9m0s -gcflags=all= runtime--- FAIL: TestLockedDeadlock2 (60.03s)
    crash_test.go:95: testprog LockedDeadlock2 exit status: exit status 2
    crash_test.go:207: output does not start with "fatal error: all goroutines are asleep - deadlock!\n":
        SIGQUIT: quit (ASCII FS)
        PC=0x7fffbf2710a7 m=0 sigcode=0
        
        goroutine 0 [idle]:
        runtime: unknown pc 0x7fffbf2710a7
        stack: frame={sp:0x7fffbfffea58, fp:0x0} stack=[0x7fffbffeed18,0x7fffbfffecb0)
        00007fffbfffe958:  0000000000000000  0000000000000000 
        00007fffbfffe968:  0000000000000000  0000000000000000 
        00007fffbfffe978:  0000000000000000  0000000000000000 
        00007fffbfffe988:  0000000000000000  0000000000000000 
        00007fffbfffe998:  0000000000000000  0000000000000000 
        00007fffbfffe9a8:  0000000000000000  0000000000000000 
        00007fffbfffe9b8:  0000000000000000  0000000000000000 
        00007fffbfffe9c8:  0000000000000000  0000000000000000 
        00007fffbfffe9d8:  0000000000000000  0000000000000000 
        00007fffbfffe9e8:  00007fffbf6d2a40  00007fffbfffea20 
        00007fffbfffe9f8:  00007fffbf265755  0000000000000000 
        00007fffbfffea08:  00000000005e2160  00007fffbf6d2a40 
        00007fffbfffea18:  00007fffbf659700  00007fffbfffea40 
        00007fffbfffea28:  00007fffbf265882  0000000000000000 
        00007fffbfffea38:  0000000000000000  00007fffbfffea50 
        00007fffbfffea48:  00007fffbf265b69  00007fffbfffeab0 
        00007fffbfffea58: <00007fffbf261a97  0000000000000000 
        00007fffbfffea68:  00007fffbf659700  0000000000000000 
        00007fffbfffea78:  0000000000000000  0000000000000000 
        00007fffbfffea88:  00000000005e2160  0000000000519bd8 
        00007fffbfffea98:  0000000000000000  00000000000000f1 
        00007fffbfffeaa8:  00000000005c6fe0  00007fffbfffeac0 
        00007fffbfffeab8:  00007fffbf261c3c  00007fffbfffeae0 
        00007fffbfffeac8:  00007fffbf253908  0000000000000000 
        00007fffbfffead8:  0000000000000000  00007fffbfffeb68 
        00007fffbfffeae8:  000000000045abba   00000000005c72a0 
        00007fffbfffeaf8:  0000000000458b7f   00007fffbfffeb40 
        00007fffbfffeb08:  00007fffbf26729d  00007fffbf62a18c 
        00007fffbfffeb18:  00007fffbf3c6480  00007fffbf6d2a40 
        00007fffbfffeb28:  00007fffbfffeb40  0000000000000000 
        00007fffbfffeb38:  00007fffbf3c6400  0000000000429acc  
        00007fffbfffeb48:  000000000045ab60   00000000005c72a0 
        runtime: unknown pc 0x7fffbf2710a7
        stack: frame={sp:0x7fffbfffea58, fp:0x0} stack=[0x7fffbffeed18,0x7fffbfffecb0)
        00007fffbfffe958:  0000000000000000  0000000000000000 
        00007fffbfffe968:  0000000000000000  0000000000000000 
        00007fffbfffe978:  0000000000000000  0000000000000000 
        00007fffbfffe988:  0000000000000000  0000000000000000 
        00007fffbfffe998:  0000000000000000  0000000000000000 
        00007fffbfffe9a8:  0000000000000000  0000000000000000 
        00007fffbfffe9b8:  0000000000000000  0000000000000000 
        00007fffbfffe9c8:  0000000000000000  0000000000000000 
        00007fffbfffe9d8:  0000000000000000  0000000000000000 
        00007fffbfffe9e8:  00007fffbf6d2a40  00007fffbfffea20 
        00007fffbfffe9f8:  00007fffbf265755  0000000000000000 
        00007fffbfffea08:  00000000005e2160  00007fffbf6d2a40 
        00007fffbfffea18:  00007fffbf659700  00007fffbfffea40 
        00007fffbfffea28:  00007fffbf265882  0000000000000000 
        00007fffbfffea38:  0000000000000000  00007fffbfffea50 
        00007fffbfffea48:  00007fffbf265b69  00007fffbfffeab0 
        00007fffbfffea58: <00007fffbf261a97  0000000000000000 
        00007fffbfffea68:  00007fffbf659700  0000000000000000 
        00007fffbfffea78:  0000000000000000  0000000000000000 
        00007fffbfffea88:  00000000005e2160  0000000000519bd8 
        00007fffbfffea98:  0000000000000000  00000000000000f1 
        00007fffbfffeaa8:  00000000005c6fe0  00007fffbfffeac0 
        00007fffbfffeab8:  00007fffbf261c3c  00007fffbfffeae0 
        00007fffbfffeac8:  00007fffbf253908  0000000000000000 
        00007fffbfffead8:  0000000000000000  00007fffbfffeb68 
        00007fffbfffeae8:  000000000045abba   00000000005c72a0 
        00007fffbfffeaf8:  0000000000458b7f   00007fffbfffeb40 
        00007fffbfffeb08:  00007fffbf26729d  00007fffbf62a18c 
        00007fffbfffeb18:  00007fffbf3c6480  00007fffbf6d2a40 
        00007fffbfffeb28:  00007fffbfffeb40  0000000000000000 
        00007fffbfffeb38:  00007fffbf3c6400  0000000000429acc  
        00007fffbfffeb48:  000000000045ab60   00000000005c72a0 
        
        goroutine 1 [sleep]:
        time.Sleep(0xf4240)

<                /var/gcc/go/goroot/src/runtime/time.go:247 +0xba
        main.LockedDeadlock2()
                /var/gcc/go/goroot/src/runtime/testdata/testprog/deadlock.go:60 +0x42
        main.main()
                /var/gcc/go/goroot/src/runtime/testdata/testprog/main.go:34 +0x1cc
        
        goroutine 33 [select (no cases), locked to thread]:
        main.LockedDeadlock2.func1()
                /var/gcc/go/goroot/src/runtime/testdata/testprog/deadlock.go:58 +0x25
        created by main.LockedDeadlock2
                /var/gcc/go/goroot/src/runtime/testdata/testprog/deadlock.go:56 +0x35
        
        rax    0x5b
        rbx    0x7fffbf6d2a40
        rcx    0x0
        rdx    0x0
        rdi    0x0
        rsi    0x0
        rbp    0x7fffbfffeab0
        rsp    0x7fffbfffea58
        r8     0x0
        r9     0x1
        r10    0x0
        r11    0x91
        r12    0x5e2160
        r13    0x0
        r14    0x0
        r15    0x0
        rip    0x7fffbf2710a7
        rflags 0x247
        cs     0x53
        fs     0x0
        gs     0x0
--- FAIL: TestCgoLockOSThreadExit (63.48s)
    crash_test.go:95: testprogcgo LockOSThreadAlt exit status: exit status 2
    proc_test.go:900: want "OK\n", got "SIGQUIT: quit (ASCII FS)\nPC=0x7fffbf271
0a7 m=0 sigcode=0\n\ngoroutine 0 [idle]:\nruntime: unknown pc 0x7fffbf2710a7\nstack: frame={sp:0x7fffbfffea48, fp:0x0} stack=[0x7fffbf800000,0x7fffbfffeca0)\n00007fffbfffe948:  0000000000000002  0000000000000001 \n00007fffbfffe958:  0000000000000000  0000000000000000 \n00007fffbfffe968:  00007fffbfffeb58  0000000000000000 \n00007fffbfffe978:  0000000000000000  0000000000000000 \n00007fffbfffe988:  0000000000ff0000  000000c000014160 \n00007fffbfffe998:  0000000000000019  000000c000018100 \n00007fffbfffe9a8:  000000000000000b  000000c0000180f0 \n00007fffbfffe9b8:  000000000000000b  000000c000014160 \n00007fffbfffe9c8:  0000000000000019  000000c000018100 \n00007fffbfffe9d8:  00007fffbf6d2a40  00007fffbfffea10 \n00007fffbfffe9e8:  00007fffbf265755  0000003000000018 \n00007fffbfffe9f8:  0000000000714dd0  00007fffbf6d2a40 \n00007fffbfffea08:  00007fffbf650700  00007fffbfffea30 \n00007fffbfffea18:  00007fffbf265882  0000000000000000 \n00007fffbfffea28:  0000000000000000  00007fffbfffea40 \n00007fffbfffea38:  00007fffbf265b69  00007fffbfffeaa0 \n00007fffbfffea48: <00007fffbf261a97  00007fffbfffeaf0 \n00007fffbfffea58:  00007fffbf650700  0000000000000000 \n00007fffbfffea68:  0000000000000008  0000000000000008 \n00007fffbfffea78:  0000000000714dd0  0000000000000002 \n00007fffbfffea88:  0000000000000003  ffffffffffffffff \n00007fffbfffea98:  00000000006f83a0  00007fffbfffeab0 \n00007fffbfffeaa8:  00007fffbf261c3c  00007fffbfffead0 \n00007fffbfffeab8:  00007fffbf253908  00007fffbf68f6d0 \n00007fffbfffeac8:  0000000000000400  00007fffbfffeb58 \n00007fffbfffead8:  0000000000574d0a   00000000006f8660 \n00007fffbfffeae8:  0000000000572b0f   00007fffbfffeb58 \n00007fffbfffeaf8:  000000000055ae9e   000000c0000fa010 \n00007fffbfffeb08:  0000000000000000  0000000000000000 \n00007fffbfffeb18:  00007fffbfffeb30  0000000000000000 \n00007fffbfffeb28:  0000000000000001  0000000000540ffc  \n00007fffbfffeb38:  0000000000574cb0   00000000006f8660 \nruntime: unknown pc 0x7fffbf2710a7\nstack: frame={sp:0x7fffbfffea48, fp:0x0} stack=[0x7fffbf800000,0x7fffbfffeca0)\n00007fffbfffe948:  0000000000000002  0000000000000001 \n00007fffbfffe958:  0000000000000000  0000000000000000 \n00007fffbfffe968:  00007fffbfffeb58  0000000000000000 \n00007fffbfffe978:  0000000000000000  0000000000000000 \n00007fffbfffe988:  0000000000ff0000  000000c000014160 \n00007fffbfffe998:  0000000000000019  000000c000018100 \n00007fffbfffe9a8:  000000000000000b  000000c0000180f0 \n00007fffbfffe9b8:  000000000000000b  000000c000014160 \n00007fffbfffe9c8:  0000000000000019  000000c000018100 \n00007fffbfffe9d8:  00007fffbf6d2a40  00007fffbfffea10 \n00007fffbfffe9e8:  00007fffbf265755  0000003000000018 \n00007fffbfffe9f8:  0000000000714dd0  00007fffbf6d2a40 \n00007fffbfffea08:  00007fffbf650700  00007fffbfffea30 \n00007fffbfffea18:  00007fffbf265882  0000000000000000 \n00007fffbfffea28:  0000000000000000  00007fffbfffea40 \n00007fffbfffea38:  00007fffbf265b69  00007fffbfffeaa0 \n00007fffbfffea48: <00007fffbf261a97  00007fffbfffeaf0 \n00007fffbfffea58:  00007fffbf650700  0000000000000000 \n00007fffbfffea68:  0000000000000008  0000000000000008 \n00007fffbfffea78:  0000000000714dd0  0000000000000002 \n00007fffbfffea88:  0000000000000003  ffffffffffffffff \n00007fffbfffea98:  00000000006f83a0  00007fffbfffeab0 \n00007fffbfffeaa8:  00007fffbf261c3c  00007fffbfffead0 \n00007fffbfffeab8:  00007fffbf253908  00007fffbf68f6d0 \n00007fffbfffeac8:  0000000000000400  00007fffbfffeb58 \n00007fffbfffead8:  0000000000574d0a   00000000006f8660 \n00007fffbfffeae8:  0000000000572b0f   00007fffbfffeb58 \n00007fffbfffeaf8:  000000000055ae9e   000000c0000fa010 \n00007fffbfffeb08:  0000000000000000  0000000000000000 \n00007fffbfffeb18:  00007fffbfffeb30  0000000000000000 \n00007fffbfffeb28:  0000000000000001  0000000000540ffc  \n00007fffbfffeb38:  0000000000574cb0   00000000006f8660 \n\ngoroutine 1 [sleep, locked to thread]:\ntime.Sleep(0xf4240)\n\t/var/gcc/go/goroot/src/runtime/time.go:247 +0xba\nmain.LockOSThreadAlt()\n\t/var/gcc/go/goroot/src/runtime/testdata/testprogcgo/lockosthread.go:97 +0xd2\nmain.main()\n\t/var/gcc/go/goroot/src/runtime/testdata/testprogcgo/main.go:34 +0x1cc\n\nrax    0x5b\nrbx    0x7fffbf6d2a40\nrcx    0x0\nrdx    0x0\nrdi    0x0\nrsi    0x0\nrbp    0x7fffbfffeaa0\nrsp    0x7fffbfffea48\nr8     0x0\nr9     0x1\nr10    0x0\nr11    0x969cf2b00000000\nr12    0x714dd0\nr13    0x0\nr14    0x0\nr15    0x0\nrip    0x7fffbf2710a7\nrflags 0x247\ncs     0x53\nfs     0x0\ngs     0x0\n"
FAIL
FAIL    runtime 136.118s
FAIL

This started at commit 6becb03, while reverting to
commit 81a74b4 lets the test pass reliably.

Meanwhile, the situation of the builder has become even worse with the cmd/go always timing out
after 20 minutes, mostly blocking the builder. It's hard to tell if this is a consequence of the
same issue or something completely different, so I'll hold off reporting it until this issue is resolved.

@bcmills
Copy link
Contributor

bcmills commented Nov 6, 2019

See previously #35274.

@bcmills
Copy link
Contributor

bcmills commented Nov 6, 2019

Meanwhile, the situation of the builder has become even worse with the cmd/go always timing out after 20 minutes, mostly blocking the builder.

That is almost certainly #35375.

@bcmills bcmills added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Nov 6, 2019
@bcmills bcmills added this to the Go1.14 milestone Nov 6, 2019
@bcmills bcmills added the Soon This needs action soon. (recent regressions, service outages, unusual time-sensitive situations) label Nov 6, 2019
@bcmills bcmills changed the title New timer code breaks runtime.TestLockedDeadlock2 on Solaris runtime: new timer code breaks TestLockedDeadlock2 on Solaris Nov 6, 2019
@ianlancetaylor
Copy link
Contributor

The LockedDeadlock2 error should be fixed by https://golang.org/cl/204800 == d80ab3e. Are the test failures you are seeing after that CL was committed on Mon Nov 4 21:37:08 2019 +0000?

@rorth
Copy link
Author

rorth commented Nov 6, 2019

The LockedDeadlock2 error should be fixed by https://golang.org/cl/204800 == d80ab3e.

Confirmed: after I've updated my tree to that commit, runtime passes reliably.

Are the test failures you are seeing after that CL was committed on Mon Nov 4 21:37:08 2019 +0000?

Yes, every build in the last couple of days has been failing on the solaris-amd64 builder. I'll try your proposed patch momentarily.

@rorth
Copy link
Author

rorth commented Nov 6, 2019

Just finished: both the testsuite as a whole passes, and repeated runs of cmd/go, which had been
failing before, pass reliably.

@ianlancetaylor
Copy link
Contributor

Thanks. I just submitted https://golang.org/cl/205558, so I think we are good here.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. OS-Solaris Soon This needs action soon. (recent regressions, service outages, unusual time-sensitive situations)
Projects
None yet
Development

No branches or pull requests

4 participants