Skip to content
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.

Sign up for GitHub

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

Jump to bottom

runtime: TestCgoCCodeSIGPROF failures #62101

Closed
mknyszek opened this issue Aug 17, 2023 · 7 comments
Closed

runtime: TestCgoCCodeSIGPROF failures #62101

mknyszek opened this issue Aug 17, 2023 · 7 comments
Labels
compiler/runtime Issues related to the Go compiler and/or runtime. NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Milestone
Backlog

Comments

@mknyszek
Copy link
Contributor

mknyszek commented Aug 17, 2023 •
edited by bcmills 

#!watchflakes
post <- test == "TestCgoCCodeSIGPROF" && date < "2023-08-08"

2023-08-07 19:31 linux-386-longtest go@d367ec6a runtime.TestCgoCCodeSIGPROF (log)
2023-08-07 19:31 linux-arm64-longtest go@aca65771 runtime.TestCgoCCodeSIGPROF (log)
2023-08-07 19:31 linux-amd64-longtest go@d367ec6a runtime.TestCgoCCodeSIGPROF (log)
2023-08-07 19:31 linux-amd64-longtest go@aca65771 runtime.TestCgoCCodeSIGPROF (log)
2023-08-07 21:16 linux-386-longtest go@008ab9ad runtime.TestCgoCCodeSIGPROF (log)
2023-08-07 21:16 darwin-amd64-longtest go@008ab9ad runtime.TestCgoCCodeSIGPROF (log)
@gopherbot gopherbot added the compiler/runtime Issues related to the Go compiler and/or runtime. label Aug 17, 2023
@mknyszek mknyszek mentioned this issue Aug 17, 2023
Open
@dmitshur dmitshur added this to the Backlog milestone Aug 17, 2023
@dmitshur dmitshur added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Aug 17, 2023
@gopherbot
Copy link

Found new dashboard test flakes for:

#!watchflakes
post <- test == "TestCgoCCodeSIGPROF"
2023-08-07 19:31 linux-386-longtest go@d367ec6a runtime.TestCgoCCodeSIGPROF (log) 
--- FAIL: TestCgoCCodeSIGPROF (0.59s)
    crash_cgo_test.go:217: /workdir/tmp/go-build2217381702/testprogcgo.exe CgoCCodeSIGPROF: exit status 2
    crash_cgo_test.go:220: expected "OK\n" got runtime: pcdata is 212 and 6 locals stack map entries for runtime.cgocallbackg (targetpc=0x804ddae)
        fatal error: bad symbol table

        runtime stack:
        runtime.throw({0x81aa1ba, 0x10})
        	/workdir/go/src/runtime/panic.go:859 +0x4d fp=0xff9d074c sp=0xff9d0738 pc=0x808560d
        runtime.(*stkframe).getStackMap(0xff9d0850, 0xff9d0990, 0x1)
        	/workdir/go/src/runtime/stkframe.go:202 +0x5e2 fp=0xff9d07b8 sp=0xff9d074c pc=0x80a20f2
        runtime.adjustframe(0xff9d0850, 0xff9d0984)
        	/workdir/go/src/runtime/stack.go:679 +0x57 fp=0xff9d0834 sp=0xff9d07b8 pc=0x809fd47
        runtime.copystack(0xa007100, 0x800)
        	/workdir/go/src/runtime/stack.go:932 +0x2d5 fp=0xff9d0aa8 sp=0xff9d0834 pc=0x80a0435
        runtime.newstack()
        	/workdir/go/src/runtime/stack.go:1113 +0x46f fp=0xff9d0b80 sp=0xff9d0aa8 pc=0x80a09df
        runtime.morestack()
        	/workdir/go/src/runtime/asm_386.s:453 +0x7c fp=0xff9d0b84 sp=0xff9d0b80 pc=0x80ba7ec
2023-08-07 19:31 linux-amd64-longtest go@d367ec6a runtime.TestCgoCCodeSIGPROF (log) 
--- FAIL: TestCgoCCodeSIGPROF (0.57s)
    crash_cgo_test.go:217: /workdir/tmp/go-build3951388949/testprogcgo.exe CgoCCodeSIGPROF: exit status 2
    crash_cgo_test.go:220: expected "OK\n" got runtime: pcdata is 32 and 2 args stack map entries for runtime.cgocallbackg (targetpc=0x475608)
        fatal error: bad symbol table

        runtime stack:
        runtime.throw({0x56e6e2?, 0x2?})
        	/workdir/go/src/runtime/panic.go:859 +0x5c fp=0x7ffe49afbd08 sp=0x7ffe49afbcd8 pc=0x43bcdc
        runtime.(*stkframe).getStackMap(0x7ffe49afbeb8, 0x7ffe49afc0b8?, 0x1?)
        	/workdir/go/src/runtime/stkframe.go:227 +0x43b fp=0x7ffe49afbdf0 sp=0x7ffe49afbd08 pc=0x45893b
        runtime.adjustframe(0x7ffe49afbeb8, 0x7ffe49afc0a0)
        	/workdir/go/src/runtime/stack.go:679 +0x9b fp=0x7ffe49afbe80 sp=0x7ffe49afbdf0 pc=0x4567bb
        runtime.copystack(0xc000007d40, 0x800?)
        	/workdir/go/src/runtime/stack.go:932 +0x325 fp=0x7ffe49afc278 sp=0x7ffe49afbe80 pc=0x456fa5
        runtime.newstack()
        	/workdir/go/src/runtime/stack.go:1113 +0x47f fp=0x7ffe49afc428 sp=0x7ffe49afc278 pc=0x45757f
        runtime.morestack()
        	/workdir/go/src/runtime/asm_amd64.s:593 +0x8f fp=0x7ffe49afc430 sp=0x7ffe49afc428 pc=0x47132f
2023-08-07 19:31 linux-amd64-longtest go@aca65771 runtime.TestCgoCCodeSIGPROF (log) 
--- FAIL: TestCgoCCodeSIGPROF (0.92s)
    crash_cgo_test.go:217: /workdir/tmp/go-build249561495/testprogcgo.exe CgoCCodeSIGPROF: exit status 2
    crash_cgo_test.go:220: expected "OK\n" got runtime: g 35: unexpected return pc for main._Cfunc_CallGoNop called from 0xc0000a5790
        stack: frame={sp:0xc0000a5768, fp:0xc0000a5778} stack=[0xc0000a5000,0xc0000a5800)
        0x000000c0000a5668:  0x0000000000000000  0x0000000000000000 
        0x000000c0000a5678:  0x0000000000000000  0x0000000000000000 
        0x000000c0000a5688:  0x000000000040686b <runtime.cgocall+0x000000000000004b>  0x0000000000000000 
        0x000000c0000a5698:  0x000000c0000a5730  0x000000c000186680 
        0x000000c0000a56a8:  0x000000c000060b00  0x00000000005270c0 <_cgoexp_e2caf0c5ce4d_GoNop+0x0000000000000000> 
        0x000000c0000a56b8:  0x00007f6f0ab73dd7  0x000000c0000a56e8 
...
        fatal error: unknown caller pc

        runtime stack:
        runtime.throw({0x56ebab?, 0xc0000a5800?})
        	/workdir/go/src/runtime/panic.go:859 +0x5c fp=0x7f6f0ab73a38 sp=0x7f6f0ab73a08 pc=0x43bc9c
        runtime.(*unwinder).next(0x7f6f0ab73ae8)
        	/workdir/go/src/runtime/traceback.go:462 +0x254 fp=0x7f6f0ab73ab0 sp=0x7f6f0ab73a38 pc=0x463c34
        runtime.copystack(0xc000186680, 0x800?)
        	/workdir/go/src/runtime/stack.go:930 +0x314 fp=0x7f6f0ab73ba8 sp=0x7f6f0ab73ab0 pc=0x456f54
        runtime.newstack()
        	/workdir/go/src/runtime/stack.go:1112 +0x47f fp=0x7f6f0ab73d58 sp=0x7f6f0ab73ba8 pc=0x45751f
        runtime.morestack()
        	/workdir/go/src/runtime/asm_amd64.s:593 +0x8f fp=0x7f6f0ab73d60 sp=0x7f6f0ab73d58 pc=0x47112f
2023-08-07 19:31 linux-arm64-longtest go@aca65771 runtime.TestCgoCCodeSIGPROF (log) 
--- FAIL: TestCgoCCodeSIGPROF (0.28s)
    crash_cgo_test.go:217: /tmp/workdir/tmp/go-build2962622675/testprogcgo.exe CgoCCodeSIGPROF: exit status 2
    crash_cgo_test.go:220: expected "OK\n" got runtime: g6: frame.sp=0x4000284782 top=0x40002847d0
        	stack=[0x4000284000-0x4000284800
        fatal error: traceback did not unwind completely

        runtime stack:
        runtime.throw({0x572985?, 0x1?})
        	/tmp/workdir/go/src/runtime/panic.go:859 +0x40 fp=0xf8d5df7fb400 sp=0xf8d5df7fb3d0 pc=0x43dc00
        runtime.(*unwinder).finishInternal(0xf8d5df7fb518?)
        	/tmp/workdir/go/src/runtime/traceback.go:558 +0x138 fp=0xf8d5df7fb440 sp=0xf8d5df7fb400 pc=0x468c98
        runtime.(*unwinder).next(0xf8d5df7fb518?)
        	/tmp/workdir/go/src/runtime/traceback.go:439 +0x2c8 fp=0xf8d5df7fb4d0 sp=0xf8d5df7fb440 pc=0x468aa8
        runtime.copystack(0x4000003d40, 0x800)
        	/tmp/workdir/go/src/runtime/stack.go:930 +0x2fc fp=0xf8d5df7fb5d0 sp=0xf8d5df7fb4d0 pc=0x45b5bc
        runtime.newstack()
        	/tmp/workdir/go/src/runtime/stack.go:1112 +0x384 fp=0xf8d5df7fb780 sp=0xf8d5df7fb5d0 pc=0x45ba84
        runtime.morestack()
        	/tmp/workdir/go/src/runtime/asm_arm64.s:316 +0x70 fp=0xf8d5df7fb780 sp=0xf8d5df7fb780 pc=0x476ab0
2023-08-07 21:16 darwin-amd64-longtest go@008ab9ad runtime.TestCgoCCodeSIGPROF (log) 
--- FAIL: TestCgoCCodeSIGPROF (0.51s)
    crash_cgo_test.go:217: /tmp/buildlet/tmp/go-build2813057027/testprogcgo.exe CgoCCodeSIGPROF: exit status 2
    crash_cgo_test.go:220: expected "OK\n" got runtime: pcdata is 32 and 2 locals stack map entries for main._Cfunc_CallGoNop (targetpc=0x10e37df7e)
        fatal error: bad symbol table

        runtime stack:
        runtime.throw({0x10e38cc1e?, 0x2?})
        	/tmp/buildlet/go/src/runtime/panic.go:859 +0x5c fp=0x70000a8d3a18 sp=0x70000a8d39e8 pc=0x10e2a023c
        runtime.(*stkframe).getStackMap(0x70000a8d3bb8, 0x1?)
        	/tmp/buildlet/go/src/runtime/stkframe.go:202 +0x5bb fp=0x70000a8d3af0 sp=0x70000a8d3a18 pc=0x10e2bcf3b
        runtime.adjustframe(0x70000a8d3bb8, 0x70000a8d3c20)
        	/tmp/buildlet/go/src/runtime/stack.go:678 +0x92 fp=0x70000a8d3b80 sp=0x70000a8d3af0 pc=0x10e2bac52
        runtime.copystack(0xc000102b60, 0x800?)
        	/tmp/buildlet/go/src/runtime/stack.go:931 +0x30a fp=0x70000a8d3c78 sp=0x70000a8d3b80 pc=0x10e2bb42a
        runtime.newstack()
        	/tmp/buildlet/go/src/runtime/stack.go:1112 +0x47f fp=0x70000a8d3e28 sp=0x70000a8d3c78 pc=0x10e2bb9ff
        runtime.morestack()
        	/tmp/buildlet/go/src/runtime/asm_amd64.s:593 +0x8f fp=0x70000a8d3e30 sp=0x70000a8d3e28 pc=0x10e2d5daf
2023-08-07 21:16 linux-386-longtest go@008ab9ad runtime.TestCgoCCodeSIGPROF (log) 
--- FAIL: TestCgoCCodeSIGPROF (0.73s)
    crash_cgo_test.go:217: /workdir/tmp/go-build80679251/testprogcgo.exe CgoCCodeSIGPROF: exit status 2
    crash_cgo_test.go:220: expected "OK\n" got runtime: g 19: unexpected return pc for runtime.cgocallbackg1.func3 called from 0x4e07d00
        stack: frame={sp:0x920e6dc, fp:0x920e6df} stack=[0x920e000,0x920e800)
        0x0920e65c:  0x00000000  0x00000000  0x00000000  0x00000000 
        0x0920e66c:  0x00000000  0x00000000  0x00000000  0x00000000 
        0x0920e67c:  0x00000000  0x00000000  0x00000000  0x00000000 
        0x0920e68c:  0x00000000  0x00000000  0x00000000  0x00000000 
        0x0920e69c:  0x00000000  0x00000000  0x00000000  0x00000000 
        0x0920e6ac:  0x00000000  0x00000000  0x00000000  0x00000000 
...
        fatal error: unknown caller pc

        runtime stack:
        runtime.throw({0x81aa6a3, 0x11})
        	/workdir/go/src/runtime/panic.go:859 +0x4d fp=0xeeec80d8 sp=0xeeec80c4 pc=0x808551d
        runtime.(*unwinder).next(0xeeec8130)
        	/workdir/go/src/runtime/traceback.go:462 +0x27d fp=0xeeec8114 sp=0xeeec80d8 pc=0x80ace7d
        runtime.copystack(0x9084300, 0x800)
        	/workdir/go/src/runtime/stack.go:930 +0x270 fp=0xeeec8188 sp=0xeeec8114 pc=0x80a0280
        runtime.newstack()
        	/workdir/go/src/runtime/stack.go:1112 +0x46f fp=0xeeec8260 sp=0xeeec8188 pc=0x80a07ff
        runtime.morestack()
        	/workdir/go/src/runtime/asm_386.s:453 +0x7c fp=0xeeec8264 sp=0xeeec8260 pc=0x80ba2cc

— watchflakes

@aclements
Copy link
Member

Observation: These are all in mayMoreStackMove mode.

@aclements
Copy link
Member

Also, they are almost all calling morestack from

        runtime.cgocallbackg1.func3()
        	/workdir/go/src/runtime/cgocall.go:318 +0x37 fp=0x920e6e0 sp=0x920e6dc pc=0x804e117
        runtime.cgocallbackg1(0x816e980, 0xeeec82ab, 0x0)
        	/workdir/go/src/runtime/cgocall.go:338 +0x24d fp=0x920e73c sp=0x920e6e0 pc=0x804e07d
        runtime.cgocallbackg(0x816e980, 0xeeec82ab, 0x0)
        	/workdir/go/src/runtime/cgocall.go:245 +0xef fp=0x920e774 sp=0x920e73c pc=0x804ddaf
        runtime.cgocallback(0x804dc66, 0x816f8e3, 0x920e7b4)
        	/workdir/go/src/runtime/asm_386.s:779 +0x9f fp=0x920e784 sp=0x920e774 pc=0x80bb4bf
        runtime.systemstack_switch()
        	/workdir/go/src/runtime/asm_386.s:341 fp=0x920e788 sp=0x920e784 pc=0x80ba1c0
        runtime.cgocall(0x816f8e3, 0x9044fb4)
        	/workdir/go/src/runtime/cgocall.go:175 +0x86 fp=0x920e7a0 sp=0x920e788 pc=0x804dc66
        main._Cfunc_CallGoNop()
        	_cgo_gotypes.go:155 +0x33 fp=0x920e7b4 sp=0x920e7a0 pc=0x81646c3
        main.CgoCCodeSIGPROF.func1()
        	/workdir/go/src/runtime/testdata/testprogcgo/aprof.go:44 +0x4a fp=0x920e7f0 sp=0x920e7b4 pc=0x81654fa

https://build.golang.org/log/92454d0a9eff3074e86a7705f9cf8c0e706bbd1e has this at the top of the stack instead:

        runtime.cgocallbackg1(0x5270c0, 0x7f6f0ab73dd7?, 0x0)
        	/workdir/go/src/runtime/cgocall.go:268 +0x37b fp=0xc0000a5640 sp=0xc0000a5638 pc=0x406e1b

But I would guess it's the same failure and we just failed to print the "real" top of stack in this one.

@bcmills
Copy link
Contributor

bcmills commented Aug 21, 2023

The traceback did not unwind completely failure mode also appears in one of the recent failures on #62105, and one found in #55161 (comment) (for which watchflakes may file a new issue shortly).

@bcmills bcmills mentioned this issue Aug 21, 2023
Open
@bcmills
Copy link
Contributor

bcmills commented Aug 21, 2023

All of the non-timeout failures here and on #62105 occurred on 2023-08-07, and not after.
(It appears that this is exactly the breakage that was rolled back in https://go.dev/cl/516856?)

@bcmills bcmills mentioned this issue Aug 21, 2023
Closed
@aclements
Copy link
Member

Yeah, I should have looked more closely at the commit hashes. This is exactly what was fixed by CL 516856, as @bcmills pointed out. Closing.

@bcmills
Copy link
Contributor

bcmills commented Aug 21, 2023

I've updated the watchflakes patterns to prevent it from reopening these issues for unrelated failures in the future.

(See #57632 (comment).)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
compiler/runtime Issues related to the Go compiler and/or runtime. NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Projects
Test Flakes
Archived in project
Milestone
Backlog
Development

No branches or pull requests
5 participants
@mknyszek @dmitshur @aclements @bcmills @gopherbot