#!watchflakes
default <- pkg == "internal/trace" && test == "TestTraceGCStress/AllocFree" && log ~ `SIGSEGV`
Issue created automatically to collect these failures.
Example (log):
=== RUN TestTraceGCStress/AllocFree
trace_test.go:614: stderr: runtime: out of memory: cannot allocate 4194304-byte block (4209803264 in use)
fatal error: out of memory
goroutine 55 gp=0xa489d48 m=11 mp=0x117d4808 [running]:
runtime.throw({0x8113430, 0xd})
/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/panic.go:1094 +0x35 fp=0xbc50f18 sp=0xbc50f04 pc=0x80bc8a5
runtime.(*mcache).refill(0xf7f62848, 0x59)
/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/mcache.go:186 +0x234 fp=0xbc50f44 sp=0xbc50f18 pc=0x8061894
runtime.(*mcache).nextFree(0xf7f62848, 0x59)
...
/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/trace.go:781 +0x54 fp=0xa82bf9c sp=0xa82bf78 pc=0x80c0004
runtime/trace.(*traceMultiplexer).startLocked.func1()
/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/trace/subscribe.go:167 +0xb2 fp=0xa82bff0 sp=0xa82bf9c pc=0x80f1f72
runtime.goexit({})
/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/asm_386.s:1386 +0x1 fp=0xa82bff4 sp=0xa82bff0 pc=0x80c1ba1
created by runtime/trace.(*traceMultiplexer).startLocked in goroutine 1
/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/trace/subscribe.go:157 +0x10d
exit status 2
trace_test.go:616: exit status 1
--- FAIL: TestTraceGCStress/AllocFree (3.26s)
Comment From: gopherbot
Found new dashboard test flakes for:
#!watchflakes
default <- pkg == "internal/trace" && test == "TestTraceGCStress/AllocFree"
2025-06-06 19:45 go1.25-linux-386-longtest release-branch.go1.25@5abb1d84 internal/trace.TestTraceGCStress/AllocFree (log)
=== RUN TestTraceGCStress/AllocFree trace_test.go:614: stderr: runtime: out of memory: cannot allocate 4194304-byte block (4209803264 in use) fatal error: out of memory goroutine 55 gp=0xa489d48 m=11 mp=0x117d4808 [running]: runtime.throw({0x8113430, 0xd}) /home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/panic.go:1094 +0x35 fp=0xbc50f18 sp=0xbc50f04 pc=0x80bc8a5 runtime.(*mcache).refill(0xf7f62848, 0x59) /home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/mcache.go:186 +0x234 fp=0xbc50f44 sp=0xbc50f18 pc=0x8061894 runtime.(*mcache).nextFree(0xf7f62848, 0x59) ... /home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/trace.go:781 +0x54 fp=0xa82bf9c sp=0xa82bf78 pc=0x80c0004 runtime/trace.(*traceMultiplexer).startLocked.func1() /home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/trace/subscribe.go:167 +0xb2 fp=0xa82bff0 sp=0xa82bf9c pc=0x80f1f72 runtime.goexit({}) /home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/asm_386.s:1386 +0x1 fp=0xa82bff4 sp=0xa82bff0 pc=0x80c1ba1 created by runtime/trace.(*traceMultiplexer).startLocked in goroutine 1 /home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/trace/subscribe.go:157 +0x10d exit status 2 trace_test.go:616: exit status 1 --- FAIL: TestTraceGCStress/AllocFree (3.26s)Comment From: gopherbot
Found new dashboard test flakes for:
#!watchflakes
default <- pkg == "internal/trace" && test == "TestTraceGCStress/AllocFree"
2025-06-27 15:23 gotip-linux-amd64-longtest-aliastypeparams go@fdc076ce internal/trace.TestTraceGCStress/AllocFree (log)
=== RUN TestTraceGCStress/AllocFree trace_test.go:635: stderr: SIGSEGV: segmentation violation PC=0x45d464 m=16 sigcode=1 addr=0x7ef34d6c5000 goroutine 0 gp=0xc00101a380 m=16 mp=0xc001010808 [idle]: runtime.traceAdvance.func6() /home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/trace.go:679 +0xa4 fp=0xc002413fc8 sp=0xc002413f88 pc=0x45d464 runtime.systemstack(0x0) /home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/asm_amd64.s:513 +0x4a fp=0xc002413fd8 sp=0xc002413fc8 pc=0x474b4a ... r13 0xc002f6a320 r14 0xc00101a380 r15 0xffffffffffffffff rip 0x45d464 rflags 0x10206 cs 0x33 fs 0x0 gs 0x0 trace_test.go:637: exit status 2 --- FAIL: TestTraceGCStress/AllocFree (1.04s)Comment From: mknyszek
Huh. I don't see how that last crash is possible given that trace.empty is always accessed under trace.lock... It implies that we observed trace.empty != nil and the immediately loaded it again and found it to be nil.
Comment From: mknyszek
Oh oops. It's indeed not nil! Then it must have been unmapped already. That makes much more sense. This suggests that some buffer was added to the empty list twice. This is moderately scary, since it means it was probably used by more than one thread simultaneously.
Comment From: gopherbot
Found new dashboard test flakes for:
#!watchflakes
default <- pkg == "internal/trace" && test == "TestTraceGCStress/AllocFree"
2025-06-27 23:34 go1.25-linux-amd64-longtest-aliastypeparams release-branch.go1.25@f1e6ae2f internal/trace.TestTraceGCStress/AllocFree (log)
=== RUN TestTraceGCStress/AllocFree reader_test.go:119: unexpected error while reading the trace: broken trace: failed to advance: frontier: [gen=1] M 652510 [GoStart time=3656500353792 g=34 g_seq=1151] M 652515 [GoStart time=3656516127808 g=46 g_seq=1486] M 652496 [GoStart time=3656516364096 g=36 g_seq=1226] M 652509 [GoStart time=3656516379776 g=43 g_seq=1477] M 652512 [GoStart time=3656516509888 g=41 g_seq=1510] M 652499 [GoStart time=3656516623680 g=35 g_seq=1495] ... String id=133 data="runtime.injectglist" String id=134 data="runtime.gcWakeAllAssists" String id=135 data="time.Sleep" String id=136 data="/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/time.go" --- FAIL: TestTraceGCStress/AllocFree (45.43s)Comment From: gopherbot
Found new dashboard test flakes for:
#!watchflakes
default <- pkg == "internal/trace" && test == "TestTraceGCStress/AllocFree"
2025-06-27 15:23 go1.25-linux-amd64-longtest-noswissmap release-branch.go1.25@fdc076ce internal/trace.TestTraceGCStress/AllocFree (log)
=== RUN TestTraceGCStress/AllocFree reader_test.go:119: unexpected error while reading the trace: inconsistent status for goroutine 1: old Waiting vs. new Running trace_test.go:663: found bad trace; dumping to test log... trace_test.go:674: Trace Go1.25 EventBatch gen=1 m=18446744073709551615 time=81295159521 size=26 Sync Frequency freq=15625000 ClockSnapshot dt=134 mono=5202890217913 sec=1751402864 nsec=286350015 ExperimentalBatch exp=1 gen=1 m=18446744073709551615 time=81295160132 data="\x01\x80\x80\x80\x80\x80\x18\x80@\b\x80\x10" ... String id=120 data="runtime.chanrecv1" String id=121 data="/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/chan.go" String id=122 data="runtime.(*wakeableSleep).sleep" String id=123 data="runtime.(*scavengerState).park" --- FAIL: TestTraceGCStress/AllocFree (48.52s)Comment From: gopherbot
Found new dashboard test flakes for:
#!watchflakes
default <- pkg == "internal/trace" && test == "TestTraceGCStress/AllocFree"
2025-07-07 16:14 gotip-linux-amd64-longtest-noswissmap go@33fb4819 internal/trace.TestTraceGCStress/AllocFree (log)
=== RUN TestTraceGCStress/AllocFree reader_test.go:119: unexpected error while reading the trace: tried to end event GCSweepBegin, but not in-flight trace_test.go:668: found bad trace; dumping to test log... trace_test.go:679: Trace Go1.25 EventBatch gen=1 m=18446744073709551615 time=13060334880 size=25 Sync Frequency freq=15625000 ClockSnapshot dt=135 mono=835861440955 sec=1751905751 nsec=780622697 ExperimentalBatch exp=1 gen=1 m=18446744073709551615 time=13060335530 data="\x01\x80\x80\x80\x80\x80\x18\x80@\b\x80\x10" ... String id=134 data="time.Sleep" String id=135 data="/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/time.go" String id=136 data="runtime/trace.runtime_readTrace" String id=137 data="runtime.forcegchelper" --- FAIL: TestTraceGCStress/AllocFree (55.85s)Comment From: gopherbot
Found new dashboard test flakes for:
#!watchflakes
default <- pkg == "internal/trace" && test == "TestTraceGCStress/AllocFree"
2025-07-08 16:29 go1.25-linux-amd64-longtest-noswissmap release-branch.go1.25@2899144b internal/trace.TestTraceGCStress/AllocFree (log)
=== RUN TestTraceGCStress/AllocFree reader_test.go:119: unexpected error while reading the trace: broken trace: failed to advance: frontier: [gen=1] M 20433 [GoStart time=142262309504 g=45 g_seq=1050] M 20439 [GoStart time=142262331072 g=40 g_seq=823] M 20430 [GoStart time=142262352640 g=46 g_seq=1024] M 20442 [GoStart time=142262389376 g=42 g_seq=631] M 20440 [GoStart time=142262390208 g=49 g_seq=1114] M 20435 [GoStart time=142262415424 g=42 g_seq=632] ... String id=136 data="runtime.traceStartReadCPU" String id=137 data="runtime.updateMaxProcsGoroutine" String id=138 data="runtime.(*scavengerState).park" String id=139 data="runtime.(*scavengerState).sleep" --- FAIL: TestTraceGCStress/AllocFree (43.78s)Comment From: gopherbot
Found new dashboard test flakes for:
#!watchflakes
default <- pkg == "internal/trace" && test == "TestTraceGCStress/AllocFree"