Skip to content

runtime: TestDebugCallLarge can hang on android/amd64 #25519

Closed
@eliasnaur

Description

@eliasnaur

The android/amd64 (emulator) builder started to timeout in the runtime tests. Running

$ CC_FOR_android_amd64=<path-to-ndk-clang> ./androidtest.bash

and then

$ GOOS=android go test -short -v -run DebugCall -count=1000 runtime

will trigger a hang, as evidenced by the stopped output. Then the offending process can be found on the device with adb shell, top and then a backtrace can be triggered with kill -QUIT <pid>. I got:

SIGQUIT: quit
PC=0x725ac5581e41 m=0 sigcode=0

goroutine 0 [idle]:
runtime.futex(0x725ac5a72800, 0x80, 0x0, 0x0, 0x725a00000000, 0x7ffd627d9128, 0x0, 0x0, 0x7ffd627d9148, 0x725ac552b112, ...)
	/home/elias/dev/go-tip/src/runtime/sys_linux_amd64.s:531 +0x21 fp=0x7ffd627d90d0 sp=0x7ffd627d90c8 pc=0x725ac5581e41
runtime.futexsleep(0x725ac5a72800, 0x7ffd00000000, 0xffffffffffffffff)
	/home/elias/dev/go-tip/src/runtime/os_linux.go:46 +0x4b fp=0x7ffd627d9120 sp=0x7ffd627d90d0 pc=0x725ac554a78b
runtime.notesleep(0x725ac5a72800)
	/home/elias/dev/go-tip/src/runtime/lock_futex.go:151 +0xa2 fp=0x7ffd627d9158 sp=0x7ffd627d9120 pc=0x725ac552b112
runtime.stoplockedm()
	/home/elias/dev/go-tip/src/runtime/proc.go:2146 +0x8a fp=0x7ffd627d9198 sp=0x7ffd627d9158 pc=0x725ac555315a
runtime.schedule()
	/home/elias/dev/go-tip/src/runtime/proc.go:2538 +0x2d9 fp=0x7ffd627d91e0 sp=0x7ffd627d9198 pc=0x725ac5554889
runtime.park_m(0xc000000300)
	/home/elias/dev/go-tip/src/runtime/proc.go:2649 +0xae fp=0x7ffd627d9210 sp=0x7ffd627d91e0 pc=0x725ac5554a0e
runtime.mcall(0x7ffd627d92c8)
	/home/elias/dev/go-tip/src/runtime/asm_amd64.s:331 +0x5b fp=0x7ffd627d9220 sp=0x7ffd627d9210 pc=0x725ac557df0b

goroutine 1 [chan receive, locked to thread]:
runtime.gopark(0x725ac58a3338, 0xc0000b82f8, 0x170d, 0x3)
	/home/elias/dev/go-tip/src/runtime/proc.go:297 +0xeb fp=0xc00008db08 sp=0xc00008dae8 pc=0x725ac554eadb
runtime.goparkunlock(0xc0000b82f8, 0x170d, 0x3)
	/home/elias/dev/go-tip/src/runtime/proc.go:303 +0x53 fp=0xc00008db38 sp=0xc00008db08 pc=0x725ac554eb83
runtime.chanrecv(0xc0000b82a0, 0xc00008dc4f, 0xc000000301, 0x725ac5608943)
	/home/elias/dev/go-tip/src/runtime/chan.go:520 +0x2be fp=0xc00008dbc8 sp=0xc00008db38 pc=0x725ac5525ace
runtime.chanrecv1(0xc0000b82a0, 0xc00008dc4f)
	/home/elias/dev/go-tip/src/runtime/chan.go:402 +0x2b fp=0xc00008dbf8 sp=0xc00008dbc8 pc=0x725ac55257bb
testing.(*T).Run(0xc00013c100, 0x725ac576c621, 0x12, 0x725ac58a40d0, 0x725ac55af101)
	/home/elias/dev/go-tip/src/testing/testing.go:879 +0x37a fp=0xc00008dcb0 sp=0xc00008dbf8 pc=0x725ac560896a
testing.runTests.func1(0xc0000cc500)
	/home/elias/dev/go-tip/src/testing/testing.go:1119 +0x78 fp=0xc00008dd00 sp=0xc00008dcb0 pc=0x725ac560c6e8
testing.tRunner(0xc0000cc500, 0xc00008ddb8)
	/home/elias/dev/go-tip/src/testing/testing.go:827 +0xbf fp=0xc00008dd28 sp=0xc00008dd00 pc=0x725ac560858f
testing.runTests(0xc00000c3a0, 0x725ac5a5caa0, 0x103, 0x103, 0x725ac5762940)
	/home/elias/dev/go-tip/src/testing/testing.go:1117 +0x2a2 fp=0xc00008dde8 sp=0xc00008dd28 pc=0x725ac5609e02
testing.(*M).Run(0xc0000b6200, 0x0)
	/home/elias/dev/go-tip/src/testing/testing.go:1034 +0x165 fp=0xc00008dee0 sp=0xc00008dde8 pc=0x725ac5608d65
runtime_test.TestMain(0xc0000b6200)
	/home/elias/dev/go-tip/src/runtime/crash_test.go:28 +0x2f fp=0xc00008df30 sp=0xc00008dee0 pc=0x725ac570aa0f
main.main()
	_testmain.go:1012 +0x13d fp=0xc00008df98 sp=0xc00008df30 pc=0x725ac576645d
runtime.main()
	/home/elias/dev/go-tip/src/runtime/proc.go:200 +0x207 fp=0xc00008dfe0 sp=0xc00008df98 pc=0x725ac554e6e7
runtime.goexit()
	/home/elias/dev/go-tip/src/runtime/asm_amd64.s:1365 +0x1 fp=0xc00008dfe8 sp=0xc00008dfe0 pc=0x725ac5580001

goroutine 2 [force gc (idle)]:
runtime.gopark(0x725ac58a3338, 0x725ac5a71580, 0x1410, 0x1)
	/home/elias/dev/go-tip/src/runtime/proc.go:297 +0xeb fp=0xc000036f80 sp=0xc000036f60 pc=0x725ac554eadb
runtime.goparkunlock(0x725ac5a71580, 0x1410, 0x1)
	/home/elias/dev/go-tip/src/runtime/proc.go:303 +0x53 fp=0xc000036fb0 sp=0xc000036f80 pc=0x725ac554eb83
runtime.forcegchelper()
	/home/elias/dev/go-tip/src/runtime/proc.go:250 +0xb3 fp=0xc000036fe0 sp=0xc000036fb0 pc=0x725ac554e953
runtime.goexit()
	/home/elias/dev/go-tip/src/runtime/asm_amd64.s:1365 +0x1 fp=0xc000036fe8 sp=0xc000036fe0 pc=0x725ac5580001
created by runtime.init.4
	/home/elias/dev/go-tip/src/runtime/proc.go:239 +0x35

goroutine 3 [GC sweep wait]:
runtime.gopark(0x725ac58a3338, 0x725ac5a71940, 0x725ac557140c, 0x1)
	/home/elias/dev/go-tip/src/runtime/proc.go:297 +0xeb fp=0xc000037780 sp=0xc000037760 pc=0x725ac554eadb
runtime.goparkunlock(0x725ac5a71940, 0x725ac57a140c, 0x1)
	/home/elias/dev/go-tip/src/runtime/proc.go:303 +0x53 fp=0xc0000377b0 sp=0xc000037780 pc=0x725ac554eb83
runtime.bgsweep(0xc00005e000)
	/home/elias/dev/go-tip/src/runtime/mgcsweep.go:71 +0x102 fp=0xc0000377d8 sp=0xc0000377b0 pc=0x725ac55409e2
runtime.goexit()
	/home/elias/dev/go-tip/src/runtime/asm_amd64.s:1365 +0x1 fp=0xc0000377e0 sp=0xc0000377d8 pc=0x725ac5580001
created by runtime.gcenable
	/home/elias/dev/go-tip/src/runtime/mgc.go:216 +0x58

goroutine 4 [finalizer wait]:
runtime.gopark(0x725ac58a3338, 0x725ac5a8eb80, 0x140f, 0x1)
	/home/elias/dev/go-tip/src/runtime/proc.go:297 +0xeb fp=0xc000037f28 sp=0xc000037f08 pc=0x725ac554eadb
runtime.goparkunlock(0x725ac5a8eb80, 0x140f, 0x1)
	/home/elias/dev/go-tip/src/runtime/proc.go:303 +0x53 fp=0xc000037f58 sp=0xc000037f28 pc=0x725ac554eb83
runtime.runfinq()
	/home/elias/dev/go-tip/src/runtime/mfinal.go:175 +0x99 fp=0xc000037fe0 sp=0xc000037f58 pc=0x725ac5538359
runtime.goexit()
	/home/elias/dev/go-tip/src/runtime/asm_amd64.s:1365 +0x1 fp=0xc000037fe8 sp=0xc000037fe0 pc=0x725ac5580001
created by runtime.createfing
	/home/elias/dev/go-tip/src/runtime/mfinal.go:156 +0x61

goroutine 9 [GC worker (idle)]:
runtime.gopark(0x725ac58a31a0, 0xc000018560, 0x1417, 0x0)
	/home/elias/dev/go-tip/src/runtime/proc.go:297 +0xeb fp=0xc000038f60 sp=0xc000038f40 pc=0x725ac554eadb
runtime.gcBgMarkWorker(0xc000024000)
	/home/elias/dev/go-tip/src/runtime/mgc.go:1772 +0xfc fp=0xc000038fd8 sp=0xc000038f60 pc=0x725ac553bc5c
runtime.goexit()
	/home/elias/dev/go-tip/src/runtime/asm_amd64.s:1365 +0x1 fp=0xc000038fe0 sp=0xc000038fd8 pc=0x725ac5580001
created by runtime.gcBgMarkStartWorkers
	/home/elias/dev/go-tip/src/runtime/mgc.go:1720 +0x77

goroutine 10 [GC worker (idle)]:
runtime.gopark(0x725ac58a31a0, 0xc000018570, 0x1417, 0x0)
	/home/elias/dev/go-tip/src/runtime/proc.go:297 +0xeb fp=0xc000039760 sp=0xc000039740 pc=0x725ac554eadb
runtime.gcBgMarkWorker(0xc000026500)
	/home/elias/dev/go-tip/src/runtime/mgc.go:1772 +0xfc fp=0xc0000397d8 sp=0xc000039760 pc=0x725ac553bc5c
runtime.goexit()
	/home/elias/dev/go-tip/src/runtime/asm_amd64.s:1365 +0x1 fp=0xc0000397e0 sp=0xc0000397d8 pc=0x725ac5580001
created by runtime.gcBgMarkStartWorkers
	/home/elias/dev/go-tip/src/runtime/mgc.go:1720 +0x77

goroutine 3619 [syscall]:
runtime.notetsleepg(0xc0000ef548, 0xffffffffffffffff, 0xc00006a6c0)
	/home/elias/dev/go-tip/src/runtime/lock_futex.go:227 +0x37 fp=0xc0000892a8 sp=0xc000089278 pc=0x725ac552b3e7
runtime.InjectDebugCall(0xc0000f1680, 0x725ac584a260, 0x725ac58a40c8, 0x725ac5834900, 0xc000140000, 0x725ac58a4af8, 0x0, 0x0, 0x0, 0x0)
	/home/elias/dev/go-tip/src/runtime/export_debug_test.go:59 +0x203 fp=0xc000089300 sp=0xc0000892a8 pc=0x725ac55786b3
runtime_test.TestDebugCallLarge(0xc00013c100)
	/home/elias/dev/go-tip/src/runtime/debug_test.go:115 +0x10f fp=0xc000089fa8 sp=0xc000089300 pc=0x725ac571364f
testing.tRunner(0xc00013c100, 0x725ac58a40d0)
	/home/elias/dev/go-tip/src/testing/testing.go:827 +0xbf fp=0xc000089fd0 sp=0xc000089fa8 pc=0x725ac560858f
runtime.goexit()
	/home/elias/dev/go-tip/src/runtime/asm_amd64.s:1365 +0x1 fp=0xc000089fd8 sp=0xc000089fd0 pc=0x725ac5580001
created by testing.(*T).Run
	/home/elias/dev/go-tip/src/testing/testing.go:878 +0x353

goroutine 3610 [running, locked to thread]:
	goroutine running on other thread; stack unavailable
created by runtime_test.startDebugCallWorker
	/home/elias/dev/go-tip/src/runtime/debug_test.go:33 +0xc9

rax    0xca
rbx    0x725ac5a726c0
rcx    0xffffffffffffffff
rdx    0x0
rdi    0x725ac5a72800
rsi    0x80
rbp    0x7ffd627d9110
rsp    0x7ffd627d90c8
r8     0x0
r9     0x0
r10    0x0
r11    0x286
r12    0xc00012a000
r13    0xc
r14    0xb
r15    0x200
rip    0x725ac5581e41
rflags 0x286
cs     0x33
fs     0x0
gs     0x0

TestDebugCallLarge was added in CL 109699, so CC'ing @aclements .

Metadata

Metadata

Assignees

No one assigned

    Labels

    FrozenDueToAgeNeedsFixThe path to resolution is known, but the work has not been done.TestingAn issue that has been verified to require only test changes, not just a test failure.

    Type

    No type

    Projects

    No projects

    Milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions