runtime: mayMoreStackPreempt failures #55160

rsc · 2022-09-20T02:34:04Z

#!watchflakes
default <- section == "maymorestack=mayMoreStackPreempt" || pkg == "runtime:mayMoreStackPreempt"

Intermittent failures in the new mayMoreStackPreempt. This bug will replace #54778 and #55073.

The text was updated successfully, but these errors were encountered:

gopherbot · 2022-09-20T02:35:53Z

Found new matching flaky dashboard failures.

2022-09-02 19:08 linux-386-longtest go@dbf442b1 runtime.TestVDSO (log)

--- FAIL: TestVDSO (0.12s)
    testenv.go:468: [/workdir/tmp/go-build505441303/testprog.exe SignalInVDSO] exit status: signal: segmentation fault (core dumped)
    crash_test.go:144: output:


        wanted:
        success

2022-09-02 19:08 linux-386-longtest go@b91e3737 runtime.TestVDSO (log)

--- FAIL: TestVDSO (0.07s)
    testenv.go:468: [/workdir/tmp/go-build4244626990/testprog.exe SignalInVDSO] exit status: signal: segmentation fault (core dumped)
    crash_test.go:144: output:


        wanted:
        success

2022-09-02 19:09 linux-386-longtest go@55ca6a20 runtime.TestVDSO (log)

--- FAIL: TestVDSO (0.47s)
    testenv.go:468: [/workdir/tmp/go-build771899026/testprog.exe SignalInVDSO] exit status: signal: segmentation fault (core dumped)
    crash_test.go:144: output:


        wanted:
        success

2022-09-02 19:22 linux-386-longtest go@0fda8b19 runtime.TestVDSO (log)

--- FAIL: TestVDSO (0.94s)
    testenv.go:468: [/workdir/tmp/go-build428612025/testprog.exe SignalInVDSO] exit status: signal: segmentation fault (core dumped)
    crash_test.go:144: output:


        wanted:
        success

2022-09-02 19:22 linux-386-longtest go@0fda8b19 runtime.TestCgoPprofCallback (log)

--- FAIL: TestCgoPprofCallback (0.76s)
    testenv.go:468: [/workdir/tmp/go-build428612025/testprogcgo.exe CgoPprofCallback] exit status: signal: segmentation fault (core dumped)
    crash_cgo_test.go:228: expected "OK\n" got

2022-09-03 15:45 linux-386-longtest go@f798dc68 runtime.TestVDSO (log)

--- FAIL: TestVDSO (0.90s)
    testenv.go:468: [/workdir/tmp/go-build1281399444/testprog.exe SignalInVDSO] exit status: signal: segmentation fault (core dumped)
    crash_test.go:144: output:


        wanted:
        success

2022-09-03 18:21 linux-386-longtest go@a0f05823 runtime.TestVDSO (log)

--- FAIL: TestVDSO (0.46s)
    testenv.go:468: [/workdir/tmp/go-build2488815781/testprog.exe SignalInVDSO] exit status: signal: segmentation fault (core dumped)
    crash_test.go:144: output:


        wanted:
        success

2022-09-03 18:21 linux-386-longtest go@a0f05823 runtime.TestCgoPprofCallback (log)

--- FAIL: TestCgoPprofCallback (0.50s)
    testenv.go:468: [/workdir/tmp/go-build2488815781/testprogcgo.exe CgoPprofCallback] exit status: signal: segmentation fault (core dumped)
    crash_cgo_test.go:228: expected "OK\n" got

2022-09-04 04:17 linux-386-longtest go@535fe2b2 runtime.TestVDSO (log)

--- FAIL: TestVDSO (0.50s)
    testenv.go:468: [/workdir/tmp/go-build3332541852/testprog.exe SignalInVDSO] exit status: signal: segmentation fault (core dumped)
    crash_test.go:144: output:


        wanted:
        success

2022-09-05 07:14 linux-386-longtest go@3fbcf05d runtime.TestVDSO (log)

--- FAIL: TestVDSO (0.14s)
    testenv.go:468: [/workdir/tmp/go-build2637521369/testprog.exe SignalInVDSO] exit status: signal: segmentation fault (core dumped)
    crash_test.go:144: output:


        wanted:
        success

2022-09-05 07:17 linux-386-longtest go@4e7e7ae1 runtime.TestVDSO (log)

--- FAIL: TestVDSO (0.21s)
    testenv.go:468: [/workdir/tmp/go-build436015263/testprog.exe SignalInVDSO] exit status: signal: segmentation fault (core dumped)
    crash_test.go:144: output:


        wanted:
        success

2022-09-05 08:08 linux-386-longtest go@4ad55cd9 runtime.TestVDSO (log)

--- FAIL: TestVDSO (0.91s)
    testenv.go:468: [/workdir/tmp/go-build596332148/testprog.exe SignalInVDSO] exit status: signal: segmentation fault (core dumped)
    crash_test.go:144: output:


        wanted:
        success

2022-09-05 08:08 linux-386-longtest go@af7f4176 runtime.TestVDSO (log)

--- FAIL: TestVDSO (0.57s)
    testenv.go:468: [/workdir/tmp/go-build2390128426/testprog.exe SignalInVDSO] exit status: signal: segmentation fault (core dumped)
    crash_test.go:144: output:


        wanted:
        success

2022-09-05 08:28 linux-386-longtest go@bd5595d7 runtime.TestVDSO (log)

--- FAIL: TestVDSO (0.36s)
    testenv.go:468: [/workdir/tmp/go-build202959485/testprog.exe SignalInVDSO] exit status: signal: segmentation fault (core dumped)
    crash_test.go:144: output:


        wanted:
        success

2022-09-05 08:28 linux-386-longtest go@bd5595d7 runtime.TestCgoPprofCallback (log)

--- FAIL: TestCgoPprofCallback (1.14s)
    testenv.go:468: [/workdir/tmp/go-build202959485/testprogcgo.exe CgoPprofCallback] exit status: signal: segmentation fault (core dumped)
    crash_cgo_test.go:228: expected "OK\n" got

2022-09-05 21:39 linux-386-longtest go@4c1ca42a runtime.TestVDSO (log)

--- FAIL: TestVDSO (0.43s)
    testenv.go:468: [/workdir/tmp/go-build2185756284/testprog.exe SignalInVDSO] exit status: signal: segmentation fault (core dumped)
    crash_test.go:144: output:


        wanted:
        success

2022-09-06 14:44 linux-386-longtest go@a60a3dc5 runtime.TestCgoPprofCallback (log)

--- FAIL: TestCgoPprofCallback (0.37s)
    testenv.go:468: [/workdir/tmp/go-build1980997514/testprogcgo.exe CgoPprofCallback] exit status: signal: segmentation fault (core dumped)
    crash_cgo_test.go:228: expected "OK\n" got

2022-09-06 15:44 linux-386-longtest go@32f68b5a runtime.TestVDSO (log)

--- FAIL: TestVDSO (0.11s)
    testenv.go:468: [/workdir/tmp/go-build1672150549/testprog.exe SignalInVDSO] exit status: signal: segmentation fault (core dumped)
    crash_test.go:144: output:


        wanted:
        success

2022-09-06 15:44 linux-386-longtest go@32f68b5a runtime.TestCgoPprofCallback (log)

--- FAIL: TestCgoPprofCallback (0.40s)
    testenv.go:468: [/workdir/tmp/go-build1672150549/testprogcgo.exe CgoPprofCallback] exit status: signal: segmentation fault (core dumped)
    crash_cgo_test.go:228: expected "OK\n" got

2022-09-06 15:48 linux-386-longtest go@07b19bf5 runtime.TestVDSO (log)

--- FAIL: TestVDSO (0.15s)
    testenv.go:468: [/workdir/tmp/go-build2315874385/testprog.exe SignalInVDSO] exit status: signal: segmentation fault (core dumped)
    crash_test.go:144: output:


        wanted:
        success

2022-09-02 19:08 linux-amd64-longtest go@dbf442b1 runtime.TestCgoPprofCallback (log)

--- FAIL: TestCgoPprofCallback (0.87s)
    testenv.go:468: [/workdir/tmp/go-build2891867005/testprogcgo.exe CgoPprofCallback] exit status: signal: segmentation fault (core dumped)
    crash_cgo_test.go:228: expected "OK\n" got

2022-09-02 19:08 linux-amd64-longtest go@dbf442b1 runtime.TestCgoCCodeSIGPROF (log)

--- FAIL: TestCgoCCodeSIGPROF (0.32s)
    testenv.go:468: [/workdir/tmp/go-build2891867005/testprogcgo.exe CgoCCodeSIGPROF] exit status: signal: segmentation fault (core dumped)
    crash_cgo_test.go:215: expected "OK\n" got

2022-09-02 19:08 linux-amd64-longtest go@b91e3737 runtime.TestCgoPprofCallback (log)

--- FAIL: TestCgoPprofCallback (3.24s)
    testenv.go:468: [/workdir/tmp/go-build687456613/testprogcgo.exe CgoPprofCallback] exit status: signal: segmentation fault (core dumped)
    crash_cgo_test.go:228: expected "OK\n" got

2022-09-03 15:45 linux-amd64-longtest go@f798dc68 runtime.TestCgoPprofCallback (log)

--- FAIL: TestCgoPprofCallback (2.81s)
    testenv.go:468: [/workdir/tmp/go-build4078786360/testprogcgo.exe CgoPprofCallback] exit status: signal: segmentation fault (core dumped)
    crash_cgo_test.go:228: expected "OK\n" got

2022-09-03 18:21 linux-amd64-longtest go@a0f05823 runtime.TestCgoPprofCallback (log)

--- FAIL: TestCgoPprofCallback (0.97s)
    testenv.go:468: [/workdir/tmp/go-build956381195/testprogcgo.exe CgoPprofCallback] exit status: signal: segmentation fault (core dumped)
    crash_cgo_test.go:228: expected "OK\n" got

2022-09-04 04:17 linux-amd64-longtest go@535fe2b2 runtime.TestCgoPprofCallback (log)

--- FAIL: TestCgoPprofCallback (3.27s)
    testenv.go:468: [/workdir/tmp/go-build2525853216/testprogcgo.exe CgoPprofCallback] exit status: signal: segmentation fault (core dumped)
    crash_cgo_test.go:228: expected "OK\n" got

2022-09-05 08:12 linux-amd64-longtest go@67e65424 runtime.TestCgoPprofCallback (log)

--- FAIL: TestCgoPprofCallback (0.42s)
    testenv.go:468: [/workdir/tmp/go-build3155816942/testprogcgo.exe CgoPprofCallback] exit status: signal: segmentation fault (core dumped)
    crash_cgo_test.go:228: expected "OK\n" got

2022-09-05 08:12 linux-amd64-longtest go@67e65424 runtime.TestCgoCCodeSIGPROF (log)

--- FAIL: TestCgoCCodeSIGPROF (0.18s)
    testenv.go:468: [/workdir/tmp/go-build3155816942/testprogcgo.exe CgoCCodeSIGPROF] exit status: signal: segmentation fault (core dumped)
    crash_cgo_test.go:215: expected "OK\n" got

2022-09-05 21:39 linux-amd64-longtest go@4c1ca42a runtime.TestCgoPprofCallback (log)

--- FAIL: TestCgoPprofCallback (0.67s)
    testenv.go:468: [/workdir/tmp/go-build1237047364/testprogcgo.exe CgoPprofCallback] exit status: signal: segmentation fault (core dumped)
    crash_cgo_test.go:228: expected "OK\n" got

2022-09-06 11:14 linux-amd64-longtest go@1c504843 runtime.TestCgoPprofCallback (log)

--- FAIL: TestCgoPprofCallback (2.60s)
    testenv.go:468: [/workdir/tmp/go-build4096451727/testprogcgo.exe CgoPprofCallback] exit status: signal: segmentation fault (core dumped)
    crash_cgo_test.go:228: expected "OK\n" got

— watchflakes

rsc · 2022-09-20T02:39:31Z

These were coming in multiple times per day and have now stopped for almost two weeks. Closing.

gopherbot · 2022-09-20T03:32:24Z

Found new matching flaky dashboard failures for:

    #!watchflakes
    post <- section == "maymorestack=mayMoreStackPreempt"

2022-08-23 03:09 windows-amd64-longtest go@0a52d806 (log)

XXXBANNERXXX:Test execution environment.
# GOARCH: amd64
# CPU: Intel(R) Xeon(R) CPU @ 2.20GHz
# GOOS: windows
# OS Version: 10.0.14393
fatal error: advapi32.dll not found
runtime: panic before malloc heap initialized
go: error obtaining buildID for go tool compile: exit status 0xc0000005

go tool dist: FAILED: go list -f={{if .Stale}}	STALE {{.ImportPath}}: {{.StaleReason}}{{end}} std: exit status 1

— watchflakes

gopherbot · 2022-09-21T19:00:41Z

Found new dashboard test flakes for:

    #!watchflakes
    post <- section == "maymorestack=mayMoreStackPreempt"

2022-09-06 15:48 linux-amd64-longtest go@07b19bf5 runtime.TestCgoPprofCallback (log)

--- FAIL: TestCgoPprofCallback (0.58s)
    testenv.go:468: [/workdir/tmp/go-build3380638690/testprogcgo.exe CgoPprofCallback] exit status: signal: segmentation fault (core dumped)
    crash_cgo_test.go:228: expected "OK\n" got

— watchflakes

gopherbot · 2022-11-04T17:59:45Z

Found new dashboard test flakes for:

    #!watchflakes
    post <- section == "maymorestack=mayMoreStackPreempt"

2022-10-31 21:00 linux-386-longtest go@ec0b5402 runtime.TestCgoTracebackContextPreemption (log)

--- FAIL: TestCgoTracebackContextPreemption (60.06s)
    testenv.go:454: context deadline exceeded: terminating command: /workdir/tmp/go-build82099082/testprogcgo.exe TracebackContextPreemption
    crash_test.go:59: /workdir/tmp/go-build82099082/testprogcgo.exe TracebackContextPreemption: exit status 2
    crash_cgo_test.go:284: expected "OK\n" got SIGQUIT: quit
        PC=0x80b7eff m=0 sigcode=0

        eax    0x0
        ebx    0x8296d10
        ecx    0x80
        edx    0x0
        edi    0x0
        esi    0x0
        ebp    0x0
        esp    0xffb85348
        eip    0x80b7eff
        eflags 0x286
        cs     0x23
        fs     0x0
        gs     0x63

2022-11-02 18:19 linux-386-longtest go@07a70bca runtime.TestCgoTracebackContextPreemption (log)

--- FAIL: TestCgoTracebackContextPreemption (60.06s)
    exec.go:152: context deadline exceeded: terminating command: /workdir/tmp/go-build3697616094/testprogcgo.exe TracebackContextPreemption
    crash_test.go:59: /workdir/tmp/go-build3697616094/testprogcgo.exe TracebackContextPreemption: exit status 2
    crash_cgo_test.go:284: expected "OK\n" got SIGQUIT: quit
        PC=0x80b7eff m=0 sigcode=0

        eax    0xfffffff5
        ebx    0x8296d10
        ecx    0x80
        edx    0x0
        edi    0x0
        esi    0x0
        ebp    0x0
        esp    0xffb80458
        eip    0x80b7eff
        eflags 0x286
        cs     0x23
        fs     0x0
        gs     0x63

2022-11-03 15:17 linux-386-longtest go@1bfb51f8 runtime.TestCgoTracebackContextPreemption (log)

--- FAIL: TestCgoTracebackContextPreemption (60.06s)
    exec.go:152: context deadline exceeded: terminating command: /workdir/tmp/go-build368093199/testprogcgo.exe TracebackContextPreemption
    crash_test.go:59: /workdir/tmp/go-build368093199/testprogcgo.exe TracebackContextPreemption: exit status 2
    crash_cgo_test.go:284: expected "OK\n" got SIGQUIT: quit
        PC=0x80b7eff m=0 sigcode=0

        eax    0x0
        ebx    0x8296d10
        ecx    0x80
        edx    0x0
        edi    0x0
        esi    0x0
        ebp    0x0
        esp    0xffbb95b4
        eip    0x80b7eff
        eflags 0x286
        cs     0x23
        fs     0x0
        gs     0x63

2022-11-03 15:30 linux-386-longtest go@e81263c7 runtime.TestCgoTracebackContextPreemption (log)

--- FAIL: TestCgoTracebackContextPreemption (60.06s)
    exec.go:152: context deadline exceeded: terminating command: /workdir/tmp/go-build1088517119/testprogcgo.exe TracebackContextPreemption
    crash_test.go:59: /workdir/tmp/go-build1088517119/testprogcgo.exe TracebackContextPreemption: exit status 2
    crash_cgo_test.go:284: expected "OK\n" got SIGQUIT: quit
        PC=0x80b7eff m=0 sigcode=0

        eax    0x1
        ebx    0x9c80310
        ecx    0x81
        edx    0x1
        edi    0x0
        esi    0x0
        ebp    0x0
        esp    0xffdec718
        eip    0x80b7eff
        eflags 0x292
        cs     0x23
        fs     0x0
        gs     0x63

2022-11-03 17:01 linux-386-longtest go@667c53e1 runtime.TestCgoTracebackContextPreemption (log)

--- FAIL: TestCgoTracebackContextPreemption (60.06s)
    exec.go:152: context deadline exceeded: terminating command: /workdir/tmp/go-build1853768809/testprogcgo.exe TracebackContextPreemption
    crash_test.go:59: /workdir/tmp/go-build1853768809/testprogcgo.exe TracebackContextPreemption: exit status 2
    crash_cgo_test.go:284: expected "OK\n" got SIGQUIT: quit
        PC=0x80b7eff m=0 sigcode=0

        eax    0x0
        ebx    0x8296d10
        ecx    0x80
        edx    0x0
        edi    0x0
        esi    0x0
        ebp    0x0
        esp    0xffcd9648
        eip    0x80b7eff
        eflags 0x286
        cs     0x23
        fs     0x0
        gs     0x63

2022-11-03 17:40 linux-386-longtest go@7abc8a2e runtime.TestCgoTracebackContextPreemption (log)

--- FAIL: TestCgoTracebackContextPreemption (60.06s)
    exec.go:152: context deadline exceeded: terminating command: /workdir/tmp/go-build3148955378/testprogcgo.exe TracebackContextPreemption
    crash_test.go:59: /workdir/tmp/go-build3148955378/testprogcgo.exe TracebackContextPreemption: exit status 2
    crash_cgo_test.go:284: expected "OK\n" got SIGQUIT: quit
        PC=0x80b7eff m=0 sigcode=0

        eax    0x0
        ebx    0x8296d10
        ecx    0x80
        edx    0x0
        edi    0x0
        esi    0x0
        ebp    0x0
        esp    0xffa0a878
        eip    0x80b7eff
        eflags 0x286
        cs     0x23
        fs     0x0
        gs     0x63

2022-11-03 18:33 linux-386-longtest go@44cabb80 runtime.TestCgoTracebackContextPreemption (log)

--- FAIL: TestCgoTracebackContextPreemption (60.06s)
    exec.go:152: context deadline exceeded: terminating command: /workdir/tmp/go-build2865322188/testprogcgo.exe TracebackContextPreemption
    crash_test.go:59: /workdir/tmp/go-build2865322188/testprogcgo.exe TracebackContextPreemption: exit status 2
    crash_cgo_test.go:284: expected "OK\n" got SIGQUIT: quit
        PC=0x80b7efd m=0 sigcode=0

        eax    0xf0
        ebx    0x8296d10
        ecx    0x80
        edx    0x0
        edi    0x0
        esi    0x0
        ebp    0x0
        esp    0xfff0a0e8
        eip    0x80b7efd
        eflags 0x286
        cs     0x23
        fs     0x0
        gs     0x63

2022-11-03 19:34 linux-386-longtest go@3511c822 runtime.TestCgoTracebackContextPreemption (log)

--- FAIL: TestCgoTracebackContextPreemption (60.06s)
    exec.go:152: context deadline exceeded: terminating command: /workdir/tmp/go-build1678369203/testprogcgo.exe TracebackContextPreemption
    crash_test.go:59: /workdir/tmp/go-build1678369203/testprogcgo.exe TracebackContextPreemption: exit status 2
    crash_cgo_test.go:284: expected "OK\n" got SIGQUIT: quit
        PC=0x80b7eff m=0 sigcode=0

        eax    0x0
        ebx    0x8296d10
        ecx    0x80
        edx    0x0
        edi    0x0
        esi    0x0
        ebp    0x0
        esp    0xffac9090
        eip    0x80b7eff
        eflags 0x286
        cs     0x23
        fs     0x0
        gs     0x63

2022-11-03 19:59 linux-386-longtest go@d031e9e0 runtime.TestCgoTracebackContextPreemption (log)

--- FAIL: TestCgoTracebackContextPreemption (60.06s)
    exec.go:152: context deadline exceeded: terminating command: /workdir/tmp/go-build3827993796/testprogcgo.exe TracebackContextPreemption
    crash_test.go:59: /workdir/tmp/go-build3827993796/testprogcgo.exe TracebackContextPreemption: exit status 2
    crash_cgo_test.go:284: expected "OK\n" got SIGQUIT: quit
        PC=0x80b7d6f m=0 sigcode=0

        eax    0x1
        ebx    0x9846e50
        ecx    0x81
        edx    0x1
        edi    0x0
        esi    0x0
        ebp    0x0
        esp    0xff9e7c18
        eip    0x80b7d6f
        eflags 0x292
        cs     0x23
        fs     0x0
        gs     0x63

— watchflakes

cherrymui · 2023-01-13T23:23:00Z

No more failure for a while. Probably fixed by CL https://golang.org/cl/447495 , which is submitted at Nov. 4, so the time seems to match.

gopherbot · 2023-02-02T19:57:00Z

Found new dashboard test flakes for:

    #!watchflakes
    post <- section == "maymorestack=mayMoreStackPreempt"

2023-01-25 16:38 linux-arm64-longtest go@1d3088ef runtime.TestCrashDumpsAllThreads (log)

panic: test timed out after 50m0s
running tests:
	TestCrashDumpsAllThreads (49m39s)

runtime.gopark(0x4362a0?, 0xffff64c08d00?, 0x2?, 0x1b?, 0x5?)
	/tmp/workdir/go/src/runtime/proc.go:381 +0x124 fp=0x4000bbfcb0 sp=0x4000bbfc90 pc=0x53e84
runtime.netpollblock(0xffff64c08ce8?, 0x72?, 0x0?)
	/tmp/workdir/go/src/runtime/netpoll.go:527 +0x190 fp=0x4000bbfcf0 sp=0x4000bbfcb0 pc=0x4b9b0
internal/poll.runtime_pollWait(0xffff64c08ce8, 0x72)
	/tmp/workdir/go/src/runtime/netpoll.go:306 +0xd0 fp=0x4000bbfd20 sp=0x4000bbfcf0 pc=0x8da60
internal/poll.(*pollDesc).wait(0x4a1470?, 0x6a05c0?, 0x1)
	/tmp/workdir/go/src/internal/poll/fd_poll_runtime.go:84 +0x28 fp=0x4000bbfd50 sp=0x4000bbfd20 pc=0xc0108
internal/poll.(*pollDesc).waitRead(...)
	/tmp/workdir/go/src/internal/poll/fd_poll_runtime.go:89
internal/poll.(*FD).Read(0x4000981f80, {0x4000bbfea7, 0x1, 0x1})
	/tmp/workdir/go/src/internal/poll/fd_unix.go:167 +0x200 fp=0x4000bbfdf0 sp=0x4000bbfd50 pc=0xc0df0
os.(*File).read(...)
	/tmp/workdir/go/src/os/file_posix.go:31
os.(*File).Read(0x40026ae180, {0x4000bbfea7?, 0x4000bbff30?, 0x1?})
	/tmp/workdir/go/src/os/file.go:118 +0x58 fp=0x4000bbfe50 sp=0x4000bbfdf0 pc=0xc55c8
runtime_test.TestCrashDumpsAllThreads(0x4000e0fba0)
	/tmp/workdir/go/src/runtime/crash_unix_test.go:117 +0x4ac fp=0x4000bbff60 sp=0x4000bbfe50 pc=0x2c235c
testing.tRunner(0x4000e0fba0, 0x437308)

2023-02-01 21:30 linux-amd64-longtest go@cda461bb runtime.TestCrashDumpsAllThreads (log)

panic: test timed out after 50m0s
running tests:
	TestCrashDumpsAllThreads (49m41s)

runtime.gopark(0x83f3d8?, 0x7f22a44dab20?, 0x2?, 0x1b?, 0x5?)
	/workdir/go/src/runtime/proc.go:381 +0x110 fp=0xc000a17cf8 sp=0xc000a17cd8 pc=0x440f30
runtime.netpollblock(0x7f22a44dab08?, 0x72?, 0x0?)
	/workdir/go/src/runtime/netpoll.go:527 +0x117 fp=0xc000a17d30 sp=0xc000a17cf8 pc=0x4391d7
internal/poll.runtime_pollWait(0x7f22a44dab08, 0x72)
	/workdir/go/src/runtime/netpoll.go:306 +0xa5 fp=0xc000a17d50 sp=0xc000a17d30 pc=0x4778a5
internal/poll.(*pollDesc).wait(0x8a7c60?, 0xaa75c8?, 0x1)
	/workdir/go/src/internal/poll/fd_poll_runtime.go:84 +0x27 fp=0xc000a17d78 sp=0xc000a17d50 pc=0x4a8c67
internal/poll.(*pollDesc).waitRead(...)
	/workdir/go/src/internal/poll/fd_poll_runtime.go:89
internal/poll.(*FD).Read(0xc0007b96e0, {0xc000a17eaf, 0x1, 0x1})
	/workdir/go/src/internal/poll/fd_unix.go:167 +0x27a fp=0xc000a17e10 sp=0xc000a17d78 pc=0x4a997a
os.(*File).read(...)
	/workdir/go/src/os/file_posix.go:31
os.(*File).Read(0xc00238e190, {0xc000a17eaf?, 0xc000985f38?, 0x1?})
	/workdir/go/src/os/file.go:118 +0x4c fp=0xc000a17e68 sp=0xc000a17e10 pc=0x4ae5cc
runtime_test.TestCrashDumpsAllThreads(0xc000b17a00)
	/workdir/go/src/runtime/crash_unix_test.go:117 +0x579 fp=0xc000a17f70 sp=0xc000a17e68 pc=0x6d0ef9
testing.tRunner(0xc000b17a00, 0x8404c8)

— watchflakes

prattmic · 2023-02-14T17:27:52Z

cc @aclements

These timeouts blocked release branch CLs as flakes; we should get them fixed or skipped.

aclements · 2023-02-15T14:26:17Z

This reproduces pretty quickly on my linux/amd64 laptop with:

cd runtime
go test -c
GOFLAGS="-gcflags=runtime=-d=maymorestack=runtime.mayMoreStackPreempt -gcflags=runtime/testdata/...=" stress2 ./runtime.test -test.run=CrashDumpsAllThreads -test.timeout=30m

Of course, my usual first step would be to send it a SIGQUIT and see what's happening, but that's exactly what fails in this test. 😛 I haven't debugged yet. gdb may hold answers.

For reference, I initially tried running the testprog directly with the below script before I realized there are various pipes and signals involved in running this test. We might still need to reproduce those, but I'm hoping we can debug this through the test driver.

cd runtime/testdata/testprog
GOFLAGS="-gcflags=runtime=-d=maymorestack=runtime.mayMoreStackPreempt -gcflags=runtime/testdata/...=" go build
# Expects to write to FD 3 and then get a SIGQUIT
GOTRACEBACK=crash GOGC=off GODEBUG=asyncpreemptoff=1 ./testprog CrashDumpsAllThreads

gopherbot · 2024-04-18T21:52:43Z

Found new dashboard test flakes for:

    #!watchflakes
    default <- section == "maymorestack=mayMoreStackPreempt" || pkg == "runtime:mayMoreStackPreempt"

2024-04-08 15:39 gotip-windows-amd64-longtest go@ae0a08de runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:919: error at event 836: no frequency event found
    crash_test.go:940: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:888 +0x85
--- FAIL: TestCrashWhileTracing (0.16s)

2024-04-08 15:53 gotip-windows-amd64-longtest go@da732dd1 runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:919: error at event 1103: no frequency event found
    crash_test.go:940: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:888 +0x85
--- FAIL: TestCrashWhileTracing (0.16s)

2024-04-08 20:33 gotip-windows-amd64-longtest go@50a50590 runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:919: error at event 1125: no frequency event found
    crash_test.go:940: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:888 +0x85
--- FAIL: TestCrashWhileTracing (0.16s)

2024-04-08 21:03 gotip-windows-amd64-longtest go@017478a9 runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:919: error at event 1128: no frequency event found
    crash_test.go:940: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:888 +0x85
--- FAIL: TestCrashWhileTracing (0.17s)

2024-04-10 17:23 gotip-windows-amd64-longtest go@73981695 runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:921: error at event 1: failed to read full batch: read 3233 but wanted 65458
    crash_test.go:942: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:945: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:947: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:888 +0x85
--- FAIL: TestCrashWhileTracing (0.15s)

2024-04-10 19:41 gotip-windows-amd64-longtest go@5b5d6f87 runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:921: error at event 1: failed to read full batch: read 2703 but wanted 65455
    crash_test.go:942: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:945: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:947: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:888 +0x85
--- FAIL: TestCrashWhileTracing (0.17s)

2024-04-11 16:15 gotip-windows-amd64-longtest go@48e00ab7 runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:921: error at event 1: failed to read full batch: read 2532 but wanted 65456
    crash_test.go:942: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:945: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:947: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:888 +0x85
--- FAIL: TestCrashWhileTracing (0.17s)

2024-04-11 20:22 gotip-windows-amd64-longtest go@1843464f runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:921: error at event 1: failed to read full batch: read 2244 but wanted 65457
    crash_test.go:942: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:945: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:947: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:888 +0x85
--- FAIL: TestCrashWhileTracing (0.17s)

2024-04-11 21:23 gotip-windows-amd64-longtest go@bfb1f563 runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:921: error at event 1: failed to read full batch: read 920 but wanted 65456
    crash_test.go:942: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:945: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:947: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:888 +0x85
--- FAIL: TestCrashWhileTracing (0.16s)

2024-04-12 14:07 gotip-windows-amd64-longtest go@5c20d5fa runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:921: error at event 1: failed to read full batch: read 3541 but wanted 65458
    crash_test.go:942: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:945: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:947: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:888 +0x85
--- FAIL: TestCrashWhileTracing (0.15s)

2024-04-12 19:15 gotip-windows-amd64-longtest go@2f3ff1fc runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:921: error at event 1: failed to read full batch: read 2907 but wanted 65458
    crash_test.go:942: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:945: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:947: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:888 +0x85
--- FAIL: TestCrashWhileTracing (0.15s)

2024-04-14 18:17 gotip-windows-amd64-longtest go@37f48222 runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:921: error at event 1: failed to read full batch: read 2748 but wanted 65456
    crash_test.go:942: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:945: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:947: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:888 +0x85
--- FAIL: TestCrashWhileTracing (0.16s)

2024-04-15 17:03 gotip-windows-amd64-longtest go@7b10c49e runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:916: error at event 1: failed to read full batch: read 1644 but wanted 65457
    crash_test.go:937: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:940: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:942: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:887 +0x85
--- FAIL: TestCrashWhileTracing (0.15s)

2024-04-15 17:38 gotip-windows-amd64-longtest go@59209c4b runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:916: error at event 1: failed to read full batch: read 3279 but wanted 65457
    crash_test.go:937: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:940: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:942: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:887 +0x85
--- FAIL: TestCrashWhileTracing (0.15s)

2024-04-17 19:54 gotip-windows-amd64-longtest go@2073b35e runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:916: error at event 1: failed to read full batch: read 2364 but wanted 65458
    crash_test.go:937: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:940: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:942: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:887 +0x85
--- FAIL: TestCrashWhileTracing (0.15s)

— watchflakes

mknyszek · 2024-04-18T23:40:02Z

The non-Windows failures are likely just stragglers from the fix. The Windows failures are likely because something is failing to flush (a pipe, in this case...?).

gopherbot · 2024-04-19T18:44:58Z

Found new dashboard test flakes for:

    #!watchflakes
    default <- section == "maymorestack=mayMoreStackPreempt" || pkg == "runtime:mayMoreStackPreempt"

2024-04-19 17:15 gotip-windows-amd64-longtest go@2ff89341 runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:916: error at event 1: failed to read full batch: read 3021 but wanted 65458
    crash_test.go:937: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:940: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:942: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:887 +0x85
--- FAIL: TestCrashWhileTracing (0.17s)

— watchflakes

gopherbot · 2024-04-26T08:50:55Z

Found new dashboard test flakes for:

    #!watchflakes
    default <- section == "maymorestack=mayMoreStackPreempt" || pkg == "runtime:mayMoreStackPreempt"

2024-04-24 18:15 gotip-windows-amd64-longtest go@e6891188 runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:916: error at event 1: failed to read full batch: read 2427 but wanted 65455
    crash_test.go:937: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:940: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:942: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:887 +0x85
--- FAIL: TestCrashWhileTracing (0.17s)

2024-04-25 00:43 gotip-windows-amd64-longtest go@799968df runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:916: error at event 1: failed to read full batch: read 2469 but wanted 65459
    crash_test.go:937: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:940: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:942: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:887 +0x85
--- FAIL: TestCrashWhileTracing (0.16s)

— watchflakes

gopherbot · 2024-04-26T08:57:36Z

Found new dashboard test flakes for:

    #!watchflakes
    default <- section == "maymorestack=mayMoreStackPreempt" || pkg == "runtime:mayMoreStackPreempt"

2024-04-25 01:05 gotip-windows-amd64-longtest go@db5f2b41 runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:916: error at event 1: failed to read full batch: read 3000 but wanted 65459
    crash_test.go:937: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:940: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:942: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:887 +0x85
--- FAIL: TestCrashWhileTracing (0.16s)

2024-04-25 11:28 gotip-windows-amd64-longtest go@8960925a runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:916: error at event 1: failed to read full batch: read 3018 but wanted 65457
    crash_test.go:937: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:940: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:942: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:887 +0x85
--- FAIL: TestCrashWhileTracing (0.15s)

2024-04-25 17:07 gotip-windows-amd64-longtest go@06478e4b runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:916: error at event 1: failed to read full batch: read 2241 but wanted 65457
    crash_test.go:937: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:940: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:942: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:887 +0x85
--- FAIL: TestCrashWhileTracing (0.16s)

— watchflakes

gopherbot · 2024-04-27T17:51:59Z

Found new dashboard test flakes for:

    #!watchflakes
    default <- section == "maymorestack=mayMoreStackPreempt" || pkg == "runtime:mayMoreStackPreempt"

2024-04-26 21:24 gotip-windows-amd64-longtest go@0e7f5cf3 runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:916: error at event 1: failed to read full batch: read 2439 but wanted 65456
    crash_test.go:937: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:940: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:942: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:887 +0x85
--- FAIL: TestCrashWhileTracing (0.15s)

2024-04-26 22:13 gotip-windows-amd64-longtest go@9effeeab runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:916: error at event 1: failed to read full batch: read 2583 but wanted 65457
    crash_test.go:937: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:940: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:942: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:887 +0x85
--- FAIL: TestCrashWhileTracing (0.16s)

2024-04-26 23:07 gotip-windows-amd64-longtest go@ad22356e runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:916: error at event 1: failed to read full batch: read 2199 but wanted 65455
    crash_test.go:937: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:940: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:942: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:887 +0x85
--- FAIL: TestCrashWhileTracing (0.17s)

— watchflakes

gopherbot · 2024-04-30T16:56:31Z

Found new dashboard test flakes for:

    #!watchflakes
    default <- section == "maymorestack=mayMoreStackPreempt" || pkg == "runtime:mayMoreStackPreempt"

2024-04-30 12:44 gotip-windows-amd64-longtest go@dc164ead runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:916: error at event 1: failed to read full batch: read 1836 but wanted 65457
    crash_test.go:937: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:940: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:942: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:887 +0x85
--- FAIL: TestCrashWhileTracing (0.22s)

— watchflakes

gopherbot · 2024-04-30T20:56:22Z

Found new dashboard test flakes for:

    #!watchflakes
    default <- section == "maymorestack=mayMoreStackPreempt" || pkg == "runtime:mayMoreStackPreempt"

2024-04-30 15:43 gotip-windows-amd64-longtest go@cf058730 runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:916: error at event 1: failed to read full batch: read 1087 but wanted 65456
    crash_test.go:937: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:940: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:942: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:887 +0x85
--- FAIL: TestCrashWhileTracing (0.17s)

— watchflakes

matloob · 2024-05-01T19:03:29Z

Should we skip this test on Windows until the flakiness is fixed?

gopherbot · 2024-05-03T00:12:18Z

Found new dashboard test flakes for:

    #!watchflakes
    default <- section == "maymorestack=mayMoreStackPreempt" || pkg == "runtime:mayMoreStackPreempt"

2024-05-02 21:10 windows-amd64-longtest go@8f71c763 runtime.TestCrashWhileTracing (log)

--- FAIL: TestCrashWhileTracing (0.15s)
    crash_test.go:916: error at event 1: failed to read full batch: read 2514 but wanted 65458
    crash_test.go:937: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:940: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:942: stderr output:
        panic: yzzyx

        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/workdir/go/src/runtime/crash_test.go:887 +0x85

— watchflakes

gopherbot · 2024-05-03T04:03:08Z

Found new dashboard test flakes for:

    #!watchflakes
    default <- section == "maymorestack=mayMoreStackPreempt" || pkg == "runtime:mayMoreStackPreempt"

2024-05-02 22:43 gotip-windows-amd64-longtest go@344075d9 runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:916: error at event 1: failed to read full batch: read 325 but wanted 65455
    crash_test.go:937: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:940: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:942: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:887 +0x85
--- FAIL: TestCrashWhileTracing (0.15s)

— watchflakes

gopherbot · 2024-05-03T18:10:54Z

Found new dashboard test flakes for:

    #!watchflakes
    default <- section == "maymorestack=mayMoreStackPreempt" || pkg == "runtime:mayMoreStackPreempt"

2024-05-03 16:41 gotip-linux-arm64-longtest go@44e48c7e runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:916: error at event 1: failed to read full batch: read 61420 but wanted 65456
    crash_test.go:937: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:940: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:942: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/crash_test.go:887 +0xbc
--- FAIL: TestCrashWhileTracing (0.12s)

— watchflakes

gopherbot · 2024-05-03T20:25:47Z

Found new dashboard test flakes for:

    #!watchflakes
    default <- section == "maymorestack=mayMoreStackPreempt" || pkg == "runtime:mayMoreStackPreempt"

2024-05-03 18:15 gotip-windows-amd64-longtest go@23f760fd runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:916: error at event 1: failed to read full batch: read 2583 but wanted 65455
    crash_test.go:937: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:940: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:942: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:887 +0x85
--- FAIL: TestCrashWhileTracing (0.17s)

— watchflakes

gopherbot · 2024-05-04T08:38:31Z

Found new dashboard test flakes for:

    #!watchflakes
    default <- section == "maymorestack=mayMoreStackPreempt" || pkg == "runtime:mayMoreStackPreempt"

2024-05-04 07:50 gotip-windows-amd64-longtest go@17fce632 runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:916: error at event 1: failed to read full batch: read 2802 but wanted 65456
    crash_test.go:937: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:940: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:942: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:887 +0x85
--- FAIL: TestCrashWhileTracing (0.16s)

— watchflakes

gopherbot · 2024-05-05T09:55:45Z

Found new dashboard test flakes for:

    #!watchflakes
    default <- section == "maymorestack=mayMoreStackPreempt" || pkg == "runtime:mayMoreStackPreempt"

2024-05-04 07:51 gotip-windows-amd64-longtest go@20130cc3 runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:916: error at event 1: failed to read full batch: read 2580 but wanted 65457
    crash_test.go:937: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:940: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:942: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:887 +0x85
--- FAIL: TestCrashWhileTracing (0.18s)

— watchflakes

gopherbot · 2024-05-06T12:50:07Z

Found new dashboard test flakes for:

    #!watchflakes
    default <- section == "maymorestack=mayMoreStackPreempt" || pkg == "runtime:mayMoreStackPreempt"

2024-05-05 00:26 gotip-windows-amd64-longtest go@619b419a runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:916: error at event 1: failed to read full batch: read 2226 but wanted 65458
    crash_test.go:937: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:940: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:942: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:887 +0x85
--- FAIL: TestCrashWhileTracing (0.16s)

— watchflakes

gopherbot · 2024-05-06T16:50:21Z

Found new dashboard test flakes for:

    #!watchflakes
    default <- section == "maymorestack=mayMoreStackPreempt" || pkg == "runtime:mayMoreStackPreempt"

2024-05-06 14:00 gotip-windows-amd64-longtest go@eabf59bc runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:916: error at event 1: failed to read full batch: read 1241 but wanted 65457
    crash_test.go:937: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:940: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:942: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:887 +0x85
--- FAIL: TestCrashWhileTracing (0.15s)

— watchflakes

gopherbot · 2024-05-06T21:50:20Z

Found new dashboard test flakes for:

    #!watchflakes
    default <- section == "maymorestack=mayMoreStackPreempt" || pkg == "runtime:mayMoreStackPreempt"

2024-05-06 20:33 gotip-linux-arm64-longtest go@5a181c50 runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:916: error at event 1: failed to read full batch: read 61420 but wanted 65458
    crash_test.go:937: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:940: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:942: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/crash_test.go:887 +0xbc
--- FAIL: TestCrashWhileTracing (0.12s)

— watchflakes

gopherbot · 2024-05-06T23:56:58Z

Found new dashboard test flakes for:

    #!watchflakes
    default <- section == "maymorestack=mayMoreStackPreempt" || pkg == "runtime:mayMoreStackPreempt"

2024-05-06 21:14 gotip-linux-386-longtest go@e988d6c4 runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:916: error at event 1: failed to read full batch: read 61420 but wanted 65473
    crash_test.go:937: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:940: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:942: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/crash_test.go:887 +0xb4
--- FAIL: TestCrashWhileTracing (0.67s)

2024-05-06 21:14 gotip-windows-amd64-longtest go@e988d6c4 runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:916: error at event 1: failed to read full batch: read 2625 but wanted 65456
    crash_test.go:937: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:940: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:942: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:887 +0x85
--- FAIL: TestCrashWhileTracing (0.16s)

— watchflakes

mknyszek · 2024-05-07T21:32:45Z

@matloob Ah, sorry for missing this.

I'll send a skip and/or a fix ASAP.

mknyszek · 2024-05-07T21:40:22Z

I was able to reproduce. I may be able to find a fix.

gopherbot · 2024-05-08T11:04:10Z

Found new dashboard test flakes for:

    #!watchflakes
    default <- section == "maymorestack=mayMoreStackPreempt" || pkg == "runtime:mayMoreStackPreempt"

2024-05-07 15:21 gotip-windows-amd64-longtest go@38ee0c76 runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:916: error at event 1: failed to read full batch: read 3194 but wanted 65455
    crash_test.go:937: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:940: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:942: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:887 +0x85
--- FAIL: TestCrashWhileTracing (0.17s)

2024-05-07 18:24 gotip-linux-386-longtest go@1e4de058 runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:916: error at event 1: failed to read full batch: read 61420 but wanted 65470
    crash_test.go:937: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:940: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:942: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/crash_test.go:887 +0xb4
--- FAIL: TestCrashWhileTracing (0.63s)

— watchflakes

gopherbot · 2024-05-08T16:45:52Z

Change https://go.dev/cl/584275 mentions this issue: internal/trace/v2: correctly handle a broken spilled batch

gopherbot · 2024-05-08T18:57:28Z

Found new dashboard test flakes for:

    #!watchflakes
    default <- section == "maymorestack=mayMoreStackPreempt" || pkg == "runtime:mayMoreStackPreempt"

2024-05-08 16:13 gotip-windows-amd64-longtest go@328aa9e3 runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:916: error at event 1: failed to read full batch: read 910 but wanted 65455
    crash_test.go:937: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:940: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:942: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:887 +0x85
--- FAIL: TestCrashWhileTracing (0.18s)

2024-05-08 17:09 gotip-windows-amd64-longtest go@93e3696b runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:916: error at event 1: failed to read full batch: read 1830 but wanted 65458
    crash_test.go:937: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:940: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:942: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:887 +0x85
--- FAIL: TestCrashWhileTracing (0.17s)

2024-05-08 17:47 gotip-linux-386-longtest go@724bab15 runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:916: error at event 1: failed to read full batch: read 61420 but wanted 65469
    crash_test.go:937: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:940: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:942: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/crash_test.go:887 +0xb4
--- FAIL: TestCrashWhileTracing (0.57s)

2024-05-08 17:47 gotip-linux-386-longtest go@c3bd543c runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:916: error at event 1: failed to read full batch: read 61420 but wanted 65469
    crash_test.go:937: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:940: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:942: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/crash_test.go:887 +0xb4
--- FAIL: TestCrashWhileTracing (0.56s)

— watchflakes

gopherbot · 2024-05-08T19:57:27Z

Found new dashboard test flakes for:

    #!watchflakes
    default <- section == "maymorestack=mayMoreStackPreempt" || pkg == "runtime:mayMoreStackPreempt"

2024-05-08 18:03 gotip-windows-amd64-longtest go@ff743ce8 runtime:mayMoreStackPreempt.TestCrashWhileTracing (log)

=== RUN   TestCrashWhileTracing
    crash_test.go:916: error at event 1: failed to read full batch: read 1896 but wanted 65459
    crash_test.go:937: expected at least one full generation to have been emitted before the trace was considered broken
    crash_test.go:940: expected one matching log event matching, but none of the 1 received trace events match
    crash_test.go:942: stderr output:
        panic: yzzyx
        
        goroutine 1 [running]:
        runtime_test.init.1()
        	C:/b/s/w/ir/x/w/goroot/src/runtime/crash_test.go:887 +0x85
--- FAIL: TestCrashWhileTracing (0.16s)

— watchflakes

gopherbot added the compiler/runtime Issues related to the Go compiler and/or runtime. label Sep 20, 2022

rsc added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Sep 20, 2022

rsc added this to Test Flakes Sep 20, 2022

rsc moved this to Active in Test Flakes Sep 20, 2022

rsc closed this as completed Sep 20, 2022

Repository owner moved this from Active to Done in Test Flakes Sep 20, 2022

gopherbot reopened this Sep 20, 2022

rsc closed this as completed Sep 20, 2022

rsc changed the title ~~runtime: flaky failures with mayMoreStackPreempt~~ runtime: mayMoreStackPreempt failures Sep 20, 2022

gopherbot reopened this Nov 4, 2022

mknyszek added this to Go Compiler / Runtime Nov 9, 2022

mknyszek added this to the Go1.20 milestone Nov 9, 2022

mknyszek self-assigned this Nov 9, 2022

mknyszek moved this to Todo in Go Compiler / Runtime Nov 9, 2022

mknyszek removed their assignment Nov 23, 2022

cherrymui closed this as completed Jan 13, 2023

github-project-automation bot moved this from Todo to Done in Go Compiler / Runtime Jan 13, 2023

gopherbot reopened this Feb 2, 2023

github-project-automation bot moved this from Done to In Progress in Go Compiler / Runtime Feb 2, 2023

dmitshur modified the milestones: Go1.20, Backlog Feb 2, 2023

gopherbot reopened this Apr 18, 2024

github-project-automation bot moved this from Done to In Progress in Go Compiler / Runtime Apr 18, 2024

mknyszek self-assigned this Apr 18, 2024

gopherbot closed this as completed in 4513f1a May 8, 2024

github-project-automation bot moved this from In Progress to Done in Go Compiler / Runtime May 8, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

runtime: mayMoreStackPreempt failures #55160

runtime: mayMoreStackPreempt failures #55160

rsc commented Sep 20, 2022 •

edited by cherrymui

Loading

gopherbot commented Sep 20, 2022 •

edited by rsc

Loading

rsc commented Sep 20, 2022

gopherbot commented Sep 20, 2022 •

edited

Loading

gopherbot commented Sep 21, 2022

gopherbot commented Nov 4, 2022

cherrymui commented Jan 13, 2023

gopherbot commented Feb 2, 2023

prattmic commented Feb 14, 2023

aclements commented Feb 15, 2023 •

edited

Loading

gopherbot commented Apr 18, 2024

mknyszek commented Apr 18, 2024

gopherbot commented Apr 19, 2024

gopherbot commented Apr 26, 2024

gopherbot commented Apr 26, 2024

gopherbot commented Apr 27, 2024

gopherbot commented Apr 30, 2024

gopherbot commented Apr 30, 2024

matloob commented May 1, 2024

gopherbot commented May 3, 2024

gopherbot commented May 3, 2024

gopherbot commented May 3, 2024

gopherbot commented May 3, 2024

gopherbot commented May 4, 2024

gopherbot commented May 5, 2024

gopherbot commented May 6, 2024

gopherbot commented May 6, 2024

gopherbot commented May 6, 2024

gopherbot commented May 6, 2024

mknyszek commented May 7, 2024

mknyszek commented May 7, 2024

gopherbot commented May 8, 2024

gopherbot commented May 8, 2024

gopherbot commented May 8, 2024

gopherbot commented May 8, 2024

runtime: mayMoreStackPreempt failures #55160

runtime: mayMoreStackPreempt failures #55160

Comments

rsc commented Sep 20, 2022 • edited by cherrymui Loading

gopherbot commented Sep 20, 2022 • edited by rsc Loading

rsc commented Sep 20, 2022

gopherbot commented Sep 20, 2022 • edited Loading

gopherbot commented Sep 21, 2022

gopherbot commented Nov 4, 2022

cherrymui commented Jan 13, 2023

gopherbot commented Feb 2, 2023

prattmic commented Feb 14, 2023

aclements commented Feb 15, 2023 • edited Loading

gopherbot commented Apr 18, 2024

mknyszek commented Apr 18, 2024

gopherbot commented Apr 19, 2024

gopherbot commented Apr 26, 2024

gopherbot commented Apr 26, 2024

gopherbot commented Apr 27, 2024

gopherbot commented Apr 30, 2024

gopherbot commented Apr 30, 2024

matloob commented May 1, 2024

gopherbot commented May 3, 2024

gopherbot commented May 3, 2024

gopherbot commented May 3, 2024

gopherbot commented May 3, 2024

gopherbot commented May 4, 2024

gopherbot commented May 5, 2024

gopherbot commented May 6, 2024

gopherbot commented May 6, 2024

gopherbot commented May 6, 2024

gopherbot commented May 6, 2024

mknyszek commented May 7, 2024

mknyszek commented May 7, 2024

gopherbot commented May 8, 2024

gopherbot commented May 8, 2024

gopherbot commented May 8, 2024

gopherbot commented May 8, 2024

rsc commented Sep 20, 2022 •

edited by cherrymui

Loading

gopherbot commented Sep 20, 2022 •

edited by rsc

Loading

gopherbot commented Sep 20, 2022 •

edited

Loading

aclements commented Feb 15, 2023 •

edited

Loading