runtime: TestCgoCallbackPprof failures [consistent failure]

[gopherbot]

#!watchflakes
default <- pkg == "runtime" && test == "TestCgoCallbackPprof"

Issue created automatically to collect these failures.

Example (log):

=== RUN   TestCgoCallbackPprof
=== PAUSE TestCgoCallbackPprof
=== CONT  TestCgoCallbackPprof
    crash_cgo_test.go:82: /opt/golang/swarm/.swarming/w/ir/x/t/go-build3524664490/testprogcgo.exe CgoCallbackPprof: exit status 1
    crash_cgo_test.go:84: expected "OK\n", but got:
        Missing main.go_callback1_callee sample in profile PeriodType: cpu nanoseconds
        Period: 10000000
        Time: 2025-03-14 21:17:33.76739446 +0100 CET
        Duration: 1.000138207s
        Samples:
        samples/count cpu/nanoseconds
        Locations
        Mappings
        1: 0x0/0x0/0x0   
        
--- FAIL: TestCgoCallbackPprof (1.91s)

— watchflakes

[gopherbot]

Found new dashboard test flakes for:

#!watchflakes
default <- pkg == "runtime" && test == "TestCgoCallbackPprof"

2025-03-14 19:54 gotip-solaris-amd64 go@577bb3d0 runtime.TestCgoCallbackPprof (log)

=== RUN   TestCgoCallbackPprof
=== PAUSE TestCgoCallbackPprof
=== CONT  TestCgoCallbackPprof
    crash_cgo_test.go:82: /opt/golang/swarm/.swarming/w/ir/x/t/go-build3524664490/testprogcgo.exe CgoCallbackPprof: exit status 1
    crash_cgo_test.go:84: expected "OK\n", but got:
        Missing main.go_callback1_callee sample in profile PeriodType: cpu nanoseconds
        Period: 10000000
        Time: 2025-03-14 21:17:33.76739446 +0100 CET
        Duration: 1.000138207s
        Samples:
        samples/count cpu/nanoseconds
        Locations
        Mappings
        1: 0x0/0x0/0x0   
        
--- FAIL: TestCgoCallbackPprof (1.91s)

2025-03-14 22:04 gotip-solaris-amd64 go@c1c7e590 runtime.TestCgoCallbackPprof (log)

=== RUN   TestCgoCallbackPprof
=== PAUSE TestCgoCallbackPprof
=== CONT  TestCgoCallbackPprof
    crash_cgo_test.go:82: /opt/golang/swarm/.swarming/w/ir/x/t/go-build3650242876/testprogcgo.exe CgoCallbackPprof: exit status 1
    crash_cgo_test.go:84: expected "OK\n", but got:
        Missing main.go_callback1_callee sample in profile PeriodType: cpu nanoseconds
        Period: 10000000
        Time: 2025-03-14 23:39:33.261679381 +0100 CET
        Duration: 1.016906031s
        Samples:
        samples/count cpu/nanoseconds
        Locations
        Mappings
        1: 0x0/0x0/0x0   
        
--- FAIL: TestCgoCallbackPprof (1.60s)

2025-03-14 22:09 gotip-solaris-amd64 go@580b6ee6 runtime.TestCgoCallbackPprof (log)

=== RUN   TestCgoCallbackPprof
=== PAUSE TestCgoCallbackPprof
=== CONT  TestCgoCallbackPprof
    crash_cgo_test.go:82: /opt/golang/swarm/.swarming/w/ir/x/t/go-build731108824/testprogcgo.exe CgoCallbackPprof: exit status 1
    crash_cgo_test.go:84: expected "OK\n", but got:
        Missing main.go_callback1_callee sample in profile PeriodType: cpu nanoseconds
        Period: 10000000
        Time: 2025-03-15 00:20:23.575268065 +0100 CET
        Duration: 1.000114755s
        Samples:
        samples/count cpu/nanoseconds
        Locations
        Mappings
        1: 0x0/0x0/0x0   
        
--- FAIL: TestCgoCallbackPprof (1.24s)

2025-03-14 22:42 gotip-solaris-amd64 go@3c3b8dd4 runtime.TestCgoCallbackPprof (log)

=== RUN   TestCgoCallbackPprof
=== PAUSE TestCgoCallbackPprof
=== CONT  TestCgoCallbackPprof
    crash_cgo_test.go:82: /opt/golang/swarm/.swarming/w/ir/x/t/go-build3909770638/testprogcgo.exe CgoCallbackPprof: exit status 1
    crash_cgo_test.go:84: expected "OK\n", but got:
        Missing main.go_callback1_callee sample in profile PeriodType: cpu nanoseconds
        Period: 10000000
        Time: 2025-03-15 00:58:05.376443686 +0100 CET
        Duration: 1.000112091s
        Samples:
        samples/count cpu/nanoseconds
        Locations
        Mappings
        1: 0x0/0x0/0x0   
        
--- FAIL: TestCgoCallbackPprof (1.11s)

— watchflakes

[gopherbot]

Found new dashboard test flakes for:

#!watchflakes
default <- pkg == "runtime" && test == "TestCgoCallbackPprof"

2025-03-14 22:08 gotip-solaris-amd64 go@853b5144 runtime.TestCgoCallbackPprof (log)

=== RUN   TestCgoCallbackPprof
=== PAUSE TestCgoCallbackPprof
=== CONT  TestCgoCallbackPprof
    crash_cgo_test.go:82: /opt/golang/swarm/.swarming/w/ir/x/t/go-build2634739003/testprogcgo.exe CgoCallbackPprof: exit status 1
    crash_cgo_test.go:84: expected "OK\n", but got:
        Missing main.go_callback1_callee sample in profile PeriodType: cpu nanoseconds
        Period: 10000000
        Time: 2025-03-15 02:11:11.689065556 +0100 CET
        Duration: 1.00011361s
        Samples:
        samples/count cpu/nanoseconds
        Locations
        Mappings
        1: 0x0/0x0/0x0   
        
--- FAIL: TestCgoCallbackPprof (1.38s)

2025-03-14 22:08 gotip-solaris-amd64 go@5bb73e65 runtime.TestCgoCallbackPprof (log)

=== RUN   TestCgoCallbackPprof
=== PAUSE TestCgoCallbackPprof
=== CONT  TestCgoCallbackPprof
    crash_cgo_test.go:82: /opt/golang/swarm/.swarming/w/ir/x/t/go-build1109232295/testprogcgo.exe CgoCallbackPprof: exit status 1
    crash_cgo_test.go:84: expected "OK\n", but got:
        Missing main.go_callback1_callee sample in profile PeriodType: cpu nanoseconds
        Period: 10000000
        Time: 2025-03-15 01:34:12.743206325 +0100 CET
        Duration: 1.000127488s
        Samples:
        samples/count cpu/nanoseconds
        Locations
        Mappings
        1: 0x0/0x0/0x0   
        
--- FAIL: TestCgoCallbackPprof (2.20s)

— watchflakes

[ianlancetaylor]

CC @prattmic This test was added in https://go.dev/cl/658035.

[gopherbot]

Found new dashboard test flakes for:

#!watchflakes
default <- pkg == "runtime" && test == "TestCgoCallbackPprof"

2025-03-15 12:58 gotip-solaris-amd64 go@c01fa0cc runtime.TestCgoCallbackPprof (log)

=== RUN   TestCgoCallbackPprof
=== PAUSE TestCgoCallbackPprof
=== CONT  TestCgoCallbackPprof
    crash_cgo_test.go:82: /opt/golang/swarm/.swarming/w/ir/x/t/go-build2180706285/testprogcgo.exe CgoCallbackPprof: exit status 1
    crash_cgo_test.go:84: expected "OK\n", but got:
        Missing main.go_callback1_callee sample in profile PeriodType: cpu nanoseconds
        Period: 10000000
        Time: 2025-03-15 14:09:41.260074671 +0100 CET
        Duration: 1.000137559s
        Samples:
        samples/count cpu/nanoseconds
        Locations
        Mappings
        1: 0x0/0x0/0x0   
        
--- FAIL: TestCgoCallbackPprof (1.30s)

— watchflakes

[gopherbot]

Found new dashboard test flakes for:

#!watchflakes
default <- pkg == "runtime" && test == "TestCgoCallbackPprof"

2025-03-15 13:04 gotip-solaris-amd64 go@10d07066 runtime.TestCgoCallbackPprof (log)

=== RUN   TestCgoCallbackPprof
=== PAUSE TestCgoCallbackPprof
=== CONT  TestCgoCallbackPprof
    crash_cgo_test.go:82: /opt/golang/swarm/.swarming/w/ir/x/t/go-build161586048/testprogcgo.exe CgoCallbackPprof: exit status 1
    crash_cgo_test.go:84: expected "OK\n", but got:
        Missing main.go_callback1_callee sample in profile PeriodType: cpu nanoseconds
        Period: 10000000
        Time: 2025-03-15 15:21:54.866630971 +0100 CET
        Duration: 1.000489658s
        Samples:
        samples/count cpu/nanoseconds
        Locations
        Mappings
        1: 0x0/0x0/0x0   
        
--- FAIL: TestCgoCallbackPprof (1.63s)

2025-03-15 13:05 gotip-solaris-amd64 go@21417518 runtime.TestCgoCallbackPprof (log)

=== RUN   TestCgoCallbackPprof
=== PAUSE TestCgoCallbackPprof
=== CONT  TestCgoCallbackPprof
    crash_cgo_test.go:82: /opt/golang/swarm/.swarming/w/ir/x/t/go-build1228758431/testprogcgo.exe CgoCallbackPprof: exit status 1
    crash_cgo_test.go:84: expected "OK\n", but got:
        Missing main.go_callback1_callee sample in profile PeriodType: cpu nanoseconds
        Period: 10000000
        Time: 2025-03-15 14:46:29.088803596 +0100 CET
        Duration: 1.000122959s
        Samples:
        samples/count cpu/nanoseconds
        Locations
        Mappings
        1: 0x0/0x0/0x0   
        
--- FAIL: TestCgoCallbackPprof (1.42s)

— watchflakes

[gopherbot]

Found new dashboard test flakes for:

#!watchflakes
default <- pkg == "runtime" && test == "TestCgoCallbackPprof"

2025-03-15 13:02 gotip-solaris-amd64 go@e1f9013a runtime.TestCgoCallbackPprof (log)

=== RUN   TestCgoCallbackPprof
=== PAUSE TestCgoCallbackPprof
=== CONT  TestCgoCallbackPprof
    crash_cgo_test.go:82: /opt/golang/swarm/.swarming/w/ir/x/t/go-build812668119/testprogcgo.exe CgoCallbackPprof: exit status 1
    crash_cgo_test.go:84: expected "OK\n", but got:
        Missing main.go_callback1_callee sample in profile PeriodType: cpu nanoseconds
        Period: 10000000
        Time: 2025-03-15 16:34:21.239515409 +0100 CET
        Duration: 1.000131323s
        Samples:
        samples/count cpu/nanoseconds
        Locations
        Mappings
        1: 0x0/0x0/0x0   
        
--- FAIL: TestCgoCallbackPprof (1.31s)

2025-03-15 13:02 gotip-solaris-amd64 go@a8f2e63f runtime.TestCgoCallbackPprof (log)

=== RUN   TestCgoCallbackPprof
=== PAUSE TestCgoCallbackPprof
=== CONT  TestCgoCallbackPprof
    crash_cgo_test.go:82: /opt/golang/swarm/.swarming/w/ir/x/t/go-build368879354/testprogcgo.exe CgoCallbackPprof: exit status 1
    crash_cgo_test.go:84: expected "OK\n", but got:
        Missing main.go_callback1_callee sample in profile PeriodType: cpu nanoseconds
        Period: 10000000
        Time: 2025-03-15 15:57:06.855672084 +0100 CET
        Duration: 1.000117387s
        Samples:
        samples/count cpu/nanoseconds
        Locations
        Mappings
        1: 0x0/0x0/0x0   
        
--- FAIL: TestCgoCallbackPprof (1.20s)

— watchflakes

[gopherbot]

Found new dashboard test flakes for:

#!watchflakes
default <- pkg == "runtime" && test == "TestCgoCallbackPprof"

2025-03-15 20:07 gotip-solaris-amd64 go@bb6a4000 runtime.TestCgoCallbackPprof (log)

=== RUN   TestCgoCallbackPprof
=== PAUSE TestCgoCallbackPprof
=== CONT  TestCgoCallbackPprof
    crash_cgo_test.go:82: /opt/golang/swarm/.swarming/w/ir/x/t/go-build3233798774/testprogcgo.exe CgoCallbackPprof: exit status 1
    crash_cgo_test.go:84: expected "OK\n", but got:
        Missing main.go_callback1_callee sample in profile PeriodType: cpu nanoseconds
        Period: 10000000
        Time: 2025-03-15 21:43:04.635311333 +0100 CET
        Duration: 1.000146339s
        Samples:
        samples/count cpu/nanoseconds
                  1   10000000: 1 2 3 4 5 6 7 8 9 10 11 
        Locations
             1: 0x601dfe M=1 runtime.ready /opt/golang/swarm/.swarming/w/ir/x/w/goroot/src/runtime/proc.go:1068 s=1063
             2: 0x61e004 M=1 runtime.goroutineReady.goready.func1 /opt/golang/swarm/.swarming/w/ir/x/w/goroot/src/runtime/proc.go:479 s=478
             3: 0x61df6c M=1 runtime.goready /opt/golang/swarm/.swarming/w/ir/x/w/goroot/src/runtime/proc.go:478 s=477
                     runtime.goroutineReady /opt/golang/swarm/.swarming/w/ir/x/w/goroot/src/runtime/time.go:417 s=416
             4: 0x61f6a2 M=1 runtime.(*timer).unlockAndRun /opt/golang/swarm/.swarming/w/ir/x/w/goroot/src/runtime/time.go:1176 s=1062
             5: 0x61f3c8 M=1 runtime.(*timers).run /opt/golang/swarm/.swarming/w/ir/x/w/goroot/src/runtime/time.go:1051 s=1017
             6: 0x61f1f8 M=1 runtime.(*timers).check /opt/golang/swarm/.swarming/w/ir/x/w/goroot/src/runtime/time.go:985 s=952
             7: 0x6071b2 M=1 runtime.stealWork /opt/golang/swarm/.swarming/w/ir/x/w/goroot/src/runtime/proc.go:3732 s=3699
             8: 0x6061e4 M=1 runtime.findRunnable /opt/golang/swarm/.swarming/w/ir/x/w/goroot/src/runtime/proc.go:3409 s=3294
             9: 0x607c30 M=1 runtime.schedule /opt/golang/swarm/.swarming/w/ir/x/w/goroot/src/runtime/proc.go:4040 s=4011
            10: 0x6080e4 M=1 runtime.park_m /opt/golang/swarm/.swarming/w/ir/x/w/goroot/src/runtime/proc.go:4164 s=4113
            11: 0x639d36 M=1 runtime.mcall /opt/golang/swarm/.swarming/w/ir/x/w/goroot/src/runtime/asm_amd64.s:457 s=427
        Mappings
        1: 0x0/0x0/0x0   [FN]
        
--- FAIL: TestCgoCallbackPprof (1.25s)

— watchflakes

[gopherbot]

Found new dashboard test flakes for:

#!watchflakes
default <- pkg == "runtime" && test == "TestCgoCallbackPprof"

2025-03-15 20:13 gotip-solaris-amd64 go@e6ffe764 runtime.TestCgoCallbackPprof (log)

=== RUN   TestCgoCallbackPprof
=== PAUSE TestCgoCallbackPprof
=== CONT  TestCgoCallbackPprof
    crash_cgo_test.go:82: /opt/golang/swarm/.swarming/w/ir/x/t/go-build1739061826/testprogcgo.exe CgoCallbackPprof: exit status 1
    crash_cgo_test.go:84: expected "OK\n", but got:
        Missing main.go_callback1_callee sample in profile PeriodType: cpu nanoseconds
        Period: 10000000
        Time: 2025-03-15 22:18:57.748337035 +0100 CET
        Duration: 1.000335238s
        Samples:
        samples/count cpu/nanoseconds
        Locations
        Mappings
        1: 0x0/0x0/0x0   
        
--- FAIL: TestCgoCallbackPprof (1.20s)

— watchflakes

[gopherbot]

Found new dashboard test flakes for:

#!watchflakes
default <- pkg == "runtime" && test == "TestCgoCallbackPprof"

2025-03-15 20:07 gotip-solaris-amd64 go@35139d6e runtime.TestCgoCallbackPprof (log)

=== RUN   TestCgoCallbackPprof
=== PAUSE TestCgoCallbackPprof
=== CONT  TestCgoCallbackPprof
    crash_cgo_test.go:82: /opt/golang/swarm/.swarming/w/ir/x/t/go-build3317949909/testprogcgo.exe CgoCallbackPprof: exit status 1
    crash_cgo_test.go:84: expected "OK\n", but got:
        Missing main.go_callback1_callee sample in profile PeriodType: cpu nanoseconds
        Period: 10000000
        Time: 2025-03-15 23:34:51.866836983 +0100 CET
        Duration: 1.000126926s
        Samples:
        samples/count cpu/nanoseconds
        Locations
        Mappings
        1: 0x0/0x0/0x0   
        
--- FAIL: TestCgoCallbackPprof (1.50s)

2025-03-15 20:12 gotip-solaris-amd64 go@e0edd3e1 runtime.TestCgoCallbackPprof (log)

=== RUN   TestCgoCallbackPprof
=== PAUSE TestCgoCallbackPprof
=== CONT  TestCgoCallbackPprof
    crash_cgo_test.go:82: /opt/golang/swarm/.swarming/w/ir/x/t/go-build4042005199/testprogcgo.exe CgoCallbackPprof: exit status 1
    crash_cgo_test.go:84: expected "OK\n", but got:
        Missing main.go_callback1_callee sample in profile PeriodType: cpu nanoseconds
        Period: 10000000
        Time: 2025-03-15 23:00:10.343506732 +0100 CET
        Duration: 1.000332622s
        Samples:
        samples/count cpu/nanoseconds
        Locations
        Mappings
        1: 0x0/0x0/0x0   
        
--- FAIL: TestCgoCallbackPprof (3.23s)

— watchflakes

[gopherbot]

Found new dashboard test flakes for:

#!watchflakes
default <- pkg == "runtime" && test == "TestCgoCallbackPprof"

2025-03-16 02:07 gotip-solaris-amd64 go@6fb7bdc9 runtime.TestCgoCallbackPprof (log)

=== RUN   TestCgoCallbackPprof
=== PAUSE TestCgoCallbackPprof
=== CONT  TestCgoCallbackPprof
    crash_cgo_test.go:82: /opt/golang/swarm/.swarming/w/ir/x/t/go-build402580209/testprogcgo.exe CgoCallbackPprof: exit status 1
    crash_cgo_test.go:84: expected "OK\n", but got:
        Missing main.go_callback1_callee sample in profile PeriodType: cpu nanoseconds
        Period: 10000000
        Time: 2025-03-16 03:16:08.851760618 +0100 CET
        Duration: 1.002527992s
        Samples:
        samples/count cpu/nanoseconds
        Locations
        Mappings
        1: 0x0/0x0/0x0   
        
--- FAIL: TestCgoCallbackPprof (1.48s)

— watchflakes

[gopherbot]

Found new dashboard test flakes for:

#!watchflakes
default <- pkg == "runtime" && test == "TestCgoCallbackPprof"

2025-03-16 22:46 gotip-solaris-amd64 go@38d146d5 runtime.TestCgoCallbackPprof (log)

=== RUN   TestCgoCallbackPprof
=== PAUSE TestCgoCallbackPprof
=== CONT  TestCgoCallbackPprof
    crash_cgo_test.go:82: /opt/golang/swarm/.swarming/w/ir/x/t/go-build1251886803/testprogcgo.exe CgoCallbackPprof: exit status 1
    crash_cgo_test.go:84: expected "OK\n", but got:
        Missing main.go_callback1_callee sample in profile PeriodType: cpu nanoseconds
        Period: 10000000
        Time: 2025-03-17 00:03:42.150577906 +0100 CET
        Duration: 1.00013755s
        Samples:
        samples/count cpu/nanoseconds
                  1   10000000: 1 2 3 4 5 6 7 8 9 10 11 12 13 
        Locations
             1: 0x63cb0b M=1 runtime.memclrNoHeapPointers /opt/golang/swarm/.swarming/w/ir/x/w/goroot/src/runtime/memclr_amd64.s:192 s=15
             2: 0x5d74d5 M=1 runtime.(*mspan).initHeapBits /opt/golang/swarm/.swarming/w/ir/x/w/goroot/src/runtime/mbitmap.go:545 s=537
             3: 0x5d9285 M=1 runtime.(*mcentral).grow /opt/golang/swarm/.swarming/w/ir/x/w/goroot/src/runtime/mcentral.go:263 s=250
             4: 0x5d90cd M=1 runtime.(*mcentral).cacheSpan /opt/golang/swarm/.swarming/w/ir/x/w/goroot/src/runtime/mcentral.go:170 s=81
             5: 0x5d86f2 M=1 runtime.(*mcache).refill /opt/golang/swarm/.swarming/w/ir/x/w/goroot/src/runtime/mcache.go:183 s=148
             6: 0x5d4c5d M=1 runtime.(*mcache).nextFree /opt/golang/swarm/.swarming/w/ir/x/w/goroot/src/runtime/malloc.go:961 s=951
             7: 0x5d552e M=1 runtime.mallocgcSmallScanNoHeader /opt/golang/swarm/.swarming/w/ir/x/w/goroot/src/runtime/malloc.go:1363 s=1337
             8: 0x631978 M=1 runtime.mallocgc /opt/golang/swarm/.swarming/w/ir/x/w/goroot/src/runtime/malloc.go:1055 s=1007
             9: 0x5d60a4 M=1 runtime.newobject /opt/golang/swarm/.swarming/w/ir/x/w/goroot/src/runtime/malloc.go:1711 s=1710
            10: 0x637dfc M=1 time.Sleep /opt/golang/swarm/.swarming/w/ir/x/w/goroot/src/runtime/time.go:313 s=305
            11: 0x6fa03c M=1 main.CgoCallbackPprof /opt/golang/swarm/.swarming/w/ir/x/w/goroot/src/runtime/testdata/testprogcgo/callback_pprof.go:58 s=50
            12: 0x6f7cb2 M=1 main.main /opt/golang/swarm/.swarming/w/ir/x/w/goroot/src/runtime/testdata/testprogcgo/main.go:34 s=24
            13: 0x60061c M=1 runtime.main /opt/golang/swarm/.swarming/w/ir/x/w/goroot/src/runtime/proc.go:283 s=147
        Mappings
        1: 0x0/0x0/0x0   [FN]
        
--- FAIL: TestCgoCallbackPprof (1.75s)

— watchflakes