Golang runtime: apparent deadlock after building with PGO

Go version

go1.24.2 linux/amd64 and linux/arm64

Output of `go env` in your module/workspace:

n/a

What did you do?

Compiled programs with PGO enabled.

What did you see happen?

The programs makes no observable progress. We see gaps in metrics, can't connect to HTTP endpoints, no work getting done. We eventually have to kill the programs.

I have some example goroutine dumps after killing the affected programs with SIGQUIT. I don't have a good way to sanitize them, so I've opted to manually include the goroutines which seem "interesting" (basically, not parked). I can provide more information as needed. Here are some examples:

Example 1

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

goroutine 0 gp=0x5a60560 m=0 mp=0x5a62540 [idle]:
runtime.futex(0x5a62680, 0x80, 0x0, 0x0, 0x0, 0x0)
    /usr/local/go/src/runtime/sys_linux_amd64.s:557 +0x21 fp=0x7ffc033100b0 sp=0x7ffc033100a8 pc=0x4fc321
runtime.futexsleep(0x0?, 0x5a62540?, 0x0?)
    /usr/local/go/src/runtime/os_linux.go:75 +0x30 fp=0x7ffc03310100 sp=0x7ffc033100b0 pc=0x4ac390
runtime.notesleep(0x5a62680)
    /usr/local/go/src/runtime/lock_futex.go:47 +0x87 fp=0x7ffc03310138 sp=0x7ffc03310100 pc=0x47bc67
runtime.mPark(...)
    /usr/local/go/src/runtime/proc.go:1887
runtime.stopm()
    /usr/local/go/src/runtime/proc.go:2907 +0x8c fp=0x7ffc03310168 sp=0x7ffc03310138 pc=0x4b824c
runtime.findRunnable()
    /usr/local/go/src/runtime/proc.go:3644 +0xede fp=0x7ffc03310300 sp=0x7ffc03310168 pc=0x4ba09e
runtime.schedule(...)
    /usr/local/go/src/runtime/proc.go:4017
runtime.park_m(0xc000899a40)
    /usr/local/go/src/runtime/proc.go:4141 +0x295 fp=0x7ffc033103b0 sp=0x7ffc03310300 pc=0x4bb955
runtime.mcall()
    /usr/local/go/src/runtime/asm_amd64.s:459 +0x4e fp=0x7ffc033103c8 sp=0x7ffc033103b0 pc=0x4f84ce

[ ... elided ... ]

goroutine 39308 gp=0xc008ab8a80 m=nil [semacquire]:
runtime.gopark(0x454bb95?, 0x7600000078e2?, 0x40?, 0x42?, 0x561ff48?)
    /usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc004469370 sp=0xc004469350 pc=0x4f098e
runtime.goparkunlock(...)
    /usr/local/go/src/runtime/proc.go:441
runtime.semacquire1(0x5a61298, 0x0, 0x0, 0x0, 0x12)
    /usr/local/go/src/runtime/sema.go:188 +0x21d fp=0xc0044693d8 sp=0xc004469370 pc=0x4c88bd
runtime.semacquire(...)
    /usr/local/go/src/runtime/sema.go:139
runtime.gcStart({0x76f35c56cf30?, 0x22?, 0x5a61980?})
    /usr/local/go/src/runtime/mgc.go:668 +0x19a fp=0xc0044694d0 sp=0xc0044693d8 pc=0x48823a
runtime.mallocgcSmallScanNoHeader(...)
    /usr/local/go/src/runtime/malloc.go:1425
runtime.mallocgc(0xe8, 0x3059ea0, 0x1)
    /usr/local/go/src/runtime/malloc.go:1058 +0x40f fp=0xc004469578 sp=0xc0044694d0 pc=0x4ed04f
runtime.newobject(0xc012116a00?)
    /usr/local/go/src/runtime/malloc.go:1714 +0x25 fp=0xc0044695a0 sp=0xc004469578 pc=0x47e825
runtime.CallersFrames(...)
    /usr/local/go/src/runtime/symtab.go:81
runtime.makeTraceFrames(0xa, {0xc004106000, 0x42, 0x80})
    /usr/local/go/src/runtime/tracestack.go:208 +0x65 fp=0xc0044696c0 sp=0xc0044695a0 pc=0x4e3de5
runtime.dumpStacksRec(0x0?, {{0x0?, 0x8?}, 0x80?, 0x1?}, {0xc004106000, 0x80, 0x80})
    /usr/local/go/src/runtime/tracestack.go:165 +0xe5 fp=0xc004469768 sp=0xc0044696c0 pc=0x4e3805
runtime.dumpStacksRec(0x0?, {{0x0?, 0x1?}, 0x80?, 0x6?}, {0xc004106000, 0x80, 0x80})
    /usr/local/go/src/runtime/tracestack.go:199 +0x425 fp=0xc004469810 sp=0xc004469768 pc=0x4e3b45
runtime.dumpStacksRec(0x0?, {{0x0?, 0x6?}, 0x80?, 0x0?}, {0xc004106000, 0x80, 0x80})
    /usr/local/go/src/runtime/tracestack.go:199 +0x425 fp=0xc0044698b8 sp=0xc004469810 pc=0x4e3b45
runtime.dumpStacksRec(0x0?, {{0x0?, 0x6?}, 0x80?, 0x0?}, {0xc004106000, 0x80, 0x80})
    /usr/local/go/src/runtime/tracestack.go:199 +0x425 fp=0xc004469960 sp=0xc0044698b8 pc=0x4e3b45
runtime.dumpStacksRec(0x0?, {{0x0?, 0xc008ad6a48?}, 0x29?, 0xc008ad6a30?}, {0xc004106000, 0x80, 0x80})
    /usr/local/go/src/runtime/tracestack.go:199 +0x425 fp=0xc004469a08 sp=0xc004469960 pc=0x4e3b45
runtime.(*traceStackTable).dump(0x5a61820, 0xa)
    /usr/local/go/src/runtime/tracestack.go:153 +0x69 fp=0xc004469a58 sp=0xc004469a08 pc=0x4e36a9
runtime.traceAdvance(0x1)
    /usr/local/go/src/runtime/trace.go:589 +0x5db fp=0xc004469bb8 sp=0xc004469a58 pc=0x4f6b7b
runtime.StopTrace(...)
    /usr/local/go/src/runtime/trace.go:318
runtime/trace.Stop()
    /usr/local/go/src/runtime/trace/trace.go:148 +0x85 fp=0xc004469bf0 sp=0xc004469bb8 pc=0xa5f365
github.com/DataDog/dd-trace-go/v2/profiler.init.func4(0xc0041e2460)
    /go/pkg/mod/github.com/!data!dog/dd-trace-go/v2@v2.0.0-rc.23/profiler/profile.go:204 +0x1a5 fp=0xc004469c90 sp=0xc004469bf0 pc=0x22e5d25
github.com/DataDog/dd-trace-go/v2/profiler.(*profiler).runProfile(0xc0041e2460, 0x7)
    /go/pkg/mod/github.com/!data!dog/dd-trace-go/v2@v2.0.0-rc.23/profiler/profile.go:348 +0x290 fp=0xc004469e78 sp=0xc004469c90 pc=0x22e99f0
github.com/DataDog/dd-trace-go/v2/profiler.(*profiler).collect.func2(0x7)
    /go/pkg/mod/github.com/!data!dog/dd-trace-go/v2@v2.0.0-rc.23/profiler/profiler.go:361 +0xe5 fp=0xc004469fc8 sp=0xc004469e78 pc=0x22ed305
github.com/DataDog/dd-trace-go/v2/profiler.(*profiler).collect.gowrap2()
    /go/pkg/mod/github.com/!data!dog/dd-trace-go/v2@v2.0.0-rc.23/profiler/profiler.go:373 +0x24 fp=0xc004469fe0 sp=0xc004469fc8 pc=0x22ed1e4
runtime.goexit({})
    /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc004469fe8 sp=0xc004469fe0 pc=0x4fa501
created by github.com/DataDog/dd-trace-go/v2/profiler.(*profiler).collect in goroutine 81
    /go/pkg/mod/github.com/!data!dog/dd-trace-go/v2@v2.0.0-rc.23/profiler/profiler.go:356 +0x7c9

[ ... elided ... ]

rax    0xca
rbx    0x0
rcx    0x4fc323
rdx    0x0
rdi    0x5a62680
rsi    0x80
rbp    0x7ffc033100f0
rsp    0x7ffc033100a8
r8     0x0
r9     0x0
r10    0x0
r11    0x286
r12    0x980ad
r13    0x1
r14    0x5a60560
r15    0x4
rip    0x4fc321
rflags 0x286
cs     0x33
fs     0x0
gs     0x0

Example 2

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

goroutine 0 gp=0x5a60560 m=0 mp=0x5a62540 [idle]:
runtime.futex(0x5a62680, 0x80, 0x0, 0x0, 0x0, 0x0)
    /usr/local/go/src/runtime/sys_linux_amd64.s:557 +0x21 fp=0x7fff0a80eb40 sp=0x7fff0a80eb38 pc=0x4fc321
runtime.futexsleep(0x7fff0a80ebb8?, 0x5a62540?, 0x7fff0a80ebd8?)
    /usr/local/go/src/runtime/os_linux.go:75 +0x30 fp=0x7fff0a80eb90 sp=0x7fff0a80eb40 pc=0x4ac390
runtime.notesleep(0x5a62680)
    /usr/local/go/src/runtime/lock_futex.go:47 +0x87 fp=0x7fff0a80ebc8 sp=0x7fff0a80eb90 pc=0x47bc67
runtime.mPark(...)
    /usr/local/go/src/runtime/proc.go:1887
runtime.stopm()
    /usr/local/go/src/runtime/proc.go:2907 +0x8c fp=0x7fff0a80ebf8 sp=0x7fff0a80ebc8 pc=0x4b824c
runtime.gcstopm()
    /usr/local/go/src/runtime/proc.go:3218 +0xcf fp=0x7fff0a80ec20 sp=0x7fff0a80ebf8 pc=0x4b8d4f
runtime.findRunnable()
    /usr/local/go/src/runtime/proc.go:3281 +0x1ca fp=0x7fff0a80edb8 sp=0x7fff0a80ec20 pc=0x4b938a
runtime.schedule(...)
    /usr/local/go/src/runtime/proc.go:4017
runtime.goschedImpl(0xc00bd67a40, 0x78?)
    /usr/local/go/src/runtime/proc.go:4175 +0x251 fp=0x7fff0a80ee20 sp=0x7fff0a80edb8 pc=0x4bc151
runtime.gopreempt_m(...)
    /usr/local/go/src/runtime/proc.go:4192
runtime.newstack()
    /usr/local/go/src/runtime/stack.go:1074 +0x3d1 fp=0x7fff0a80ef58 sp=0x7fff0a80ee20 pc=0x4ce811
runtime.morestack()
    /usr/local/go/src/runtime/asm_amd64.s:621 +0x7a fp=0x7fff0a80ef60 sp=0x7fff0a80ef58 pc=0x4f865a

goroutine 9508 gp=0xc0038fcc40 m=9 mp=0xc000850808 [trace reader (blocked)]:
    goroutine running on other thread; stack unavailable
created by runtime/trace.Start in goroutine 9489
    /usr/local/go/src/runtime/trace/trace.go:128 +0xcf

goroutine 9489 gp=0xc00beb7180 m=nil [runnable]:
runtime.funcfile({0x4cdf7b8?, 0x57f8180?}, 0x37?)
    /usr/local/go/src/runtime/symtab.go:1132 +0x92 fp=0xc0054bf2c8 sp=0xc0054bf2c0 pc=0x4d3772
runtime.funcline1({0x43456da?, 0x43456da?}, 0x4c7616, 0x0)
    /usr/local/go/src/runtime/symtab.go:1165 +0x689 fp=0xc0054bf3d0 sp=0xc0054bf2c8 pc=0x4f5949
runtime.(*Frames).Next(0xc0137e64b0)
    /usr/local/go/src/runtime/symtab.go:197 +0x729 fp=0xc0054bf4f8 sp=0xc0054bf3d0 pc=0x4d2429
runtime.makeTraceFrames(0x5, {0xc015362000, 0x3, 0x80})
    /usr/local/go/src/runtime/tracestack.go:210 +0x125 fp=0xc0054bf618 sp=0xc0054bf4f8 pc=0x4e3ea5
runtime.dumpStacksRec(0x0?, {{0x0?, 0x3d?}, 0x80?, 0xa?}, {0xc015362000, 0x80, 0x80})
    /usr/local/go/src/runtime/tracestack.go:165 +0xe5 fp=0xc0054bf6c0 sp=0xc0054bf618 pc=0x4e3805
runtime.dumpStacksRec(0x0?, {{0x0?, 0xa?}, 0x80?, 0x4?}, {0xc015362000, 0x80, 0x80})
    /usr/local/go/src/runtime/tracestack.go:199 +0x425 fp=0xc0054bf768 sp=0xc0054bf6c0 pc=0x4e3b45
runtime.dumpStacksRec(0x0?, {{0x0?, 0x4?}, 0x80?, 0x6?}, {0xc015362000, 0x80, 0x80})
    /usr/local/go/src/runtime/tracestack.go:199 +0x425 fp=0xc0054bf810 sp=0xc0054bf768 pc=0x4e3b45
runtime.dumpStacksRec(0x0?, {{0x0?, 0x6?}, 0x80?, 0x0?}, {0xc015362000, 0x80, 0x80})
    /usr/local/go/src/runtime/tracestack.go:199 +0x425 fp=0xc0054bf8b8 sp=0xc0054bf810 pc=0x4e3b45
runtime.dumpStacksRec(0x0?, {{0x0?, 0x6?}, 0x80?, 0x0?}, {0xc015362000, 0x80, 0x80})
    /usr/local/go/src/runtime/tracestack.go:199 +0x425 fp=0xc0054bf960 sp=0xc0054bf8b8 pc=0x4e3b45
runtime.dumpStacksRec(0x0?, {{0x0?, 0xc000d0aa48?}, 0x29?, 0xc000d0aa30?}, {0xc015362000, 0x80, 0x80})
    /usr/local/go/src/runtime/tracestack.go:199 +0x425 fp=0xc0054bfa08 sp=0xc0054bf960 pc=0x4e3b45
runtime.(*traceStackTable).dump(0x5a618d0, 0x5)
    /usr/local/go/src/runtime/tracestack.go:153 +0x69 fp=0xc0054bfa58 sp=0xc0054bfa08 pc=0x4e36a9
runtime.traceAdvance(0x1)
    /usr/local/go/src/runtime/trace.go:589 +0x5db fp=0xc0054bfbb8 sp=0xc0054bfa58 pc=0x4f6b7b
runtime.StopTrace(...)
    /usr/local/go/src/runtime/trace.go:318
runtime/trace.Stop()
    /usr/local/go/src/runtime/trace/trace.go:148 +0x85 fp=0xc0054bfbf0 sp=0xc0054bfbb8 pc=0xa5f365
github.com/DataDog/dd-trace-go/v2/profiler.init.func4(0xc005e94140)
    /go/pkg/mod/github.com/!data!dog/dd-trace-go/v2@v2.0.0-rc.23/profiler/profile.go:204 +0x1a5 fp=0xc0054bfc90 sp=0xc0054bfbf0 pc=0x22e5d25
github.com/DataDog/dd-trace-go/v2/profiler.(*profiler).runProfile(0xc005e94140, 0x7)
    /go/pkg/mod/github.com/!data!dog/dd-trace-go/v2@v2.0.0-rc.23/profiler/profile.go:348 +0x290 fp=0xc0054bfe78 sp=0xc0054bfc90 pc=0x22e99f0
github.com/DataDog/dd-trace-go/v2/profiler.(*profiler).collect.func2(0x7)
    /go/pkg/mod/github.com/!data!dog/dd-trace-go/v2@v2.0.0-rc.23/profiler/profiler.go:361 +0xe5 fp=0xc0054bffc8 sp=0xc0054bfe78 pc=0x22ed305
github.com/DataDog/dd-trace-go/v2/profiler.(*profiler).collect.gowrap2()
    /go/pkg/mod/github.com/!data!dog/dd-trace-go/v2@v2.0.0-rc.23/profiler/profiler.go:373 +0x24 fp=0xc0054bffe0 sp=0xc0054bffc8 pc=0x22ed1e4
runtime.goexit({})
    /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0054bffe8 sp=0xc0054bffe0 pc=0x4fa501
created by github.com/DataDog/dd-trace-go/v2/profiler.(*profiler).collect in goroutine 144
    /go/pkg/mod/github.com/!data!dog/dd-trace-go/v2@v2.0.0-rc.23/profiler/profiler.go:356 +0x7c9

goroutine 9495 gp=0xc00bd67a40 m=nil [runnable]:
runtime/pprof.(*profMap).lookup(0xc0047ae040, {0xc01d1bd4d8, 0x2, 0x1e565?}, 0x0)
    /usr/local/go/src/runtime/pprof/map.go:28 +0x4dd fp=0xc003749ed8 sp=0xc003749ed0 pc=0xa4539d
runtime/pprof.(*profileBuilder).addCPUData(0x5f5e100?, {0xc01d1bc748?, 0x7b8120?, 0xc00c200150?}, {0xc006c10590?, 0x39a41f8?, 0xc00c2009a0?})
    /usr/local/go/src/runtime/pprof/proto.go:338 +0x105 fp=0xc003749f58 sp=0xc003749ed8 pc=0xa4d145
runtime/pprof.profileWriter({0x395c2a0?, 0xc0252e37d0?})
    /usr/local/go/src/runtime/pprof/pprof.go:873 +0x70 fp=0xc003749fc0 sp=0xc003749f58 pc=0xa49910
runtime/pprof.StartCPUProfile.gowrap2()
    /usr/local/go/src/runtime/pprof/pprof.go:856 +0x25 fp=0xc003749fe0 sp=0xc003749fc0 pc=0xa49805
runtime.goexit({})
    /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc003749fe8 sp=0xc003749fe0 pc=0x4fa501
created by runtime/pprof.StartCPUProfile in goroutine 9483
    /usr/local/go/src/runtime/pprof/pprof.go:856 +0x136

rax    0xca
rbx    0x0
rcx    0x4fc323
rdx    0x0
rdi    0x5a62680
rsi    0x80
rbp    0x7fff0a80eb80
rsp    0x7fff0a80eb38
r8     0x0
r9     0x0
r10    0x0
r11    0x286
r12    0x7fff0a80ebd8
r13    0x1
r14    0x5a60560
r15    0x18
rip    0x4fc321
rflags 0x286
cs     0x33
fs     0x0
gs     0x0

Example 3 (from delve, analyzing a core file collected when we saw the issue

Note: goroutine 48 is running the execution tracer, and the leaf frame is calling morestack, waiting to be scheduled.

(dlv) goroutines -with running -t
  Goroutine 131 - User: src/runtime/sys_linux_arm64.s:138 runtime.usleep (0x2abc644) (thread 17) [preempted]
     0  0x0000000002abc644 in runtime.usleep
         at src/runtime/sys_linux_arm64.s:138
     1  0x0000000002a8dcb8 in runtime.sighandler
         at GOROOT/src/runtime/signal_unix.go:826
     2  0x0000000002a8d098 in runtime.sigtrampgo
         at GOROOT/src/runtime/signal_unix.go:490
     3  0x0000000002a7d6a4 in internal/runtime/atomic.(*Uint32).CompareAndSwap
         at GOROOT/src/internal/runtime/atomic/types.go:236
     4  0x0000000002a7d6a4 in runtime.casgstatus
         at GOROOT/src/runtime/proc.go:1211
     5  0x0000000002a7d6a4 in runtime.park_m
         at GOROOT/src/runtime/proc.go:4112
     6  0x0000000002ab9314 in runtime.mcall
         at src/runtime/asm_arm64.s:193
     7  0x0000000002a9afa8 in runtime.gopark
         at GOROOT/src/runtime/proc.go:435
     8  0x0000000002a9afa8 in runtime.ReadTrace
         at GOROOT/src/runtime/trace.go:758
     9  0x0000000002f91bec in runtime/trace.Start.func1
         at GOROOT/src/runtime/trace/trace.go:130
    10  0x0000000002abb854 in runtime.goexit
         at src/runtime/asm_arm64.s:1223
  Goroutine 133 - User: src/runtime/sys_linux_arm64.s:138 runtime.usleep (0x2abc644) (thread 22)
    0  0x0000000002abc644 in runtime.usleep
        at src/runtime/sys_linux_arm64.s:138
    1  0x0000000002a8dcb8 in runtime.sighandler
        at GOROOT/src/runtime/signal_unix.go:826
    2  0x0000000002a8d098 in runtime.sigtrampgo
        at GOROOT/src/runtime/signal_unix.go:490
    3  0x0000000002abcccc in runtime.futex
        at src/runtime/sys_linux_arm64.s:650
    4  0x0000000002a6d5fc in runtime.futexsleep
        at GOROOT/src/runtime/os_linux.go:75
    5  0x0000000002a3fd90 in runtime.notetsleep_internal
        at GOROOT/src/runtime/lock_futex.go:70
    6  0x0000000002a3fe70 in runtime.notetsleepg
        at GOROOT/src/runtime/lock_futex.go:124
    7  0x0000000002ab5570 in os/signal.signal_recv
        at GOROOT/src/runtime/sigqueue.go:152
    8  0x000000000336a6cc in os/signal.loop
        at GOROOT/src/os/signal/signal_unix.go:23
    9  0x0000000002abb854 in runtime.goexit
        at src/runtime/asm_arm64.s:1223
  Goroutine 107362 - User: src/runtime/sys_linux_arm64.s:138 runtime.usleep (0x2abc644) (thread 18)
     0  0x0000000002abc644 in runtime.usleep
         at src/runtime/sys_linux_arm64.s:138
     1  0x0000000002a8dcb8 in runtime.sighandler
         at GOROOT/src/runtime/signal_unix.go:826
     2  0x0000000002a8d098 in runtime.sigtrampgo
         at GOROOT/src/runtime/signal_unix.go:490
     3  0x0000000002abccd0 in runtime.futex
         at src/runtime/sys_linux_arm64.s:651
     4  0x0000000002a6d65c in runtime.futexsleep
         at GOROOT/src/runtime/os_linux.go:81
     5  0x0000000002a3fcf4 in runtime.notetsleep_internal
         at GOROOT/src/runtime/lock_futex.go:89
     6  0x0000000002a3fdf4 in runtime.notetsleep
         at GOROOT/src/runtime/lock_futex.go:112
     7  0x0000000002a77918 in runtime.stopTheWorldWithSema
         at GOROOT/src/runtime/proc.go:1612
     8  0x0000000002a4c9d8 in runtime.gcStart.func2
         at GOROOT/src/runtime/mgc.go:726
     9  0x0000000002ab93ac in runtime.systemstack
         at src/runtime/asm_arm64.s:244
    10  0x0000000002ab9328 in runtime.systemstack_switch
         at src/runtime/asm_arm64.s:201
    (truncated)
[3 goroutines]
(dlv) goroutine 48 bt
 0  0x0000000002a95ca0 in runtime.(*Func).Entry
    at GOROOT/src/runtime/symtab.go:794
 1  0x0000000002a94f6c in runtime.(*Frames).Next
    at GOROOT/src/runtime/symtab.go:120
 2  0x0000000002aa56a0 in runtime.makeTraceFrames
    at GOROOT/src/runtime/tracestack.go:210
 3  0x0000000002aa5154 in runtime.dumpStacksRec
    at GOROOT/src/runtime/tracestack.go:165
 4  0x0000000002aa5428 in runtime.dumpStacksRec
    at GOROOT/src/runtime/tracestack.go:199
 5  0x0000000002aa5428 in runtime.dumpStacksRec
    at GOROOT/src/runtime/tracestack.go:199
 6  0x0000000002aa5428 in runtime.dumpStacksRec
    at GOROOT/src/runtime/tracestack.go:199
 7  0x0000000002aa5428 in runtime.dumpStacksRec
    at GOROOT/src/runtime/tracestack.go:199
 8  0x0000000002aa5038 in runtime.(*traceStackTable).dump
    at GOROOT/src/runtime/tracestack.go:153
 9  0x0000000002ab7d1c in runtime.traceAdvance
    at GOROOT/src/runtime/trace.go:589
10  0x0000000002f91d88 in runtime.StopTrace
    at GOROOT/src/runtime/trace.go:318
11  0x0000000002f91d88 in runtime/trace.Stop
    at GOROOT/src/runtime/trace/trace.go:148
12  0x0000000003b74790 in gopkg.in/DataDog/dd-trace-go.v1/profiler.init.func4
    at external/in_gopkg_datadog_dd_trace_go_v1/profiler/profile.go:204
13  0x0000000003b77aac in gopkg.in/DataDog/dd-trace-go.v1/profiler.(*profiler).runProfile
    at external/in_gopkg_datadog_dd_trace_go_v1/profiler/profile.go:348
14  0x0000000003b7ac28 in gopkg.in/DataDog/dd-trace-go.v1/profiler.(*profiler).collect.func2
    at external/in_gopkg_datadog_dd_trace_go_v1/profiler/profiler.go:355
15  0x0000000003b7ab30 in gopkg.in/DataDog/dd-trace-go.v1/profiler.(*profiler).collect.gowrap2
    at external/in_gopkg_datadog_dd_trace_go_v1/profiler/profiler.go:367
16  0x0000000002abb854 in runtime.goexit
    at src/runtime/asm_arm64.s:1223

Here is the inlining info from `-pgodebug=3` output for the program that produced this core, using the same profile and source code:

hot-node enabled increased budget=2000 for func=sync/atomic.(*Pointer[go.shape.chan struct {}]).Load
hot-node enabled increased budget=2000 for func=sync/atomic.(*Pointer[go.shape.struct { sync.poolDequeue; sync.next sync/atomic.Pointer[sync.poolChainElt]; sync.prev sync/atomic.Pointer[sy
nc.poolChainElt] }]).Load
hot-node enabled increased budget=2000 for func=internal/sync.(*HashTrieMap[go.shape.interface {},go.shape.interface {}]).init
hot-node enabled increased budget=2000 for func=internal/sync.(*entry[go.shape.interface {},go.shape.interface {}]).lookup
hot-node enabled increased budget=2000 for func=internal/sync.(*HashTrieMap[go.shape.interface {},go.shape.interface {}]).Load
hot-node enabled increased budget=2000 for func=INTERNAL/internal/tree.(*Multi[go.shape.*uint8]).PathVisitorAscending
hot-budget check allows inlining for call errors.Is (cost 179) at INTERNAL/internal/tree/tree.go:129:15 in function INTERNAL/internal/tree.(*Multi[go.shape.*uint8]).PathVisitorAscending
hot-node enabled increased budget=2000 for func=INTERNAL/internal/tree.(*Multi[go.shape.*uint8]).PathVisitorDescending
hot-budget check allows inlining for call errors.Is (cost 179) at INTERNAL/internal/tree/tree.go:113:15 in function INTERNAL/internal/tree.(*Multi[go.shape.*uint8]).PathVisitorDescending
hot-node enabled increased budget=2000 for func=INTERNAL/internal/tree.(*Multi[go.shape.*uint8]).Add
hot-budget check allows inlining for call sync.(*RWMutex).Lock (cost 167) at INTERNAL/internal/tree/tree.go:61:14 in function INTERNAL/internal/tree.(*Multi[go.shape.*uint8]).Add
hot-node enabled increased budget=2000 for func=INTERNAL/internal/tree.(*Multi[go.shape.*uint8]).DimensionChildren
hot-node enabled increased budget=2000 for func=INTERNAL/internal/tree.(*Multi[go.shape.*uint8]).Children
hot-budget check allows inlining for call errors.Is (cost 179) at INTERNAL/internal/tree/tree.go:129:15 in function INTERNAL/internal/tree.(*Multi[go.shape.*uint8]).PathVisitorAscending
hot-budget check allows inlining for call errors.Is (cost 179) at INTERNAL/internal/tree/tree.go:113:15 in function INTERNAL/internal/tree.(*Multi[go.shape.*uint8]).PathVisitorDescending
hot-budget check allows inlining for call sync.(*RWMutex).Lock (cost 167) at INTERNAL/internal/tree/tree.go:61:14 in function INTERNAL/internal/tree.(*Multi[go.shape.*uint8]).Add

Not sure if it's relevant, but I've seen a goroutine running runtime.(*traceStackTable).dump via runtime.StopTrace in the stack dump from every instance I've seen of this issue.

What did you expect to see?

The programs function like normal. If we build the same source code but with PGO disabled, the programs work.

We have seen this for at least two programs at Datadog. We haven't reproduced the behavior in our development environments yet, but it does happen fairly consistently in production, so we can probably collect more diagnostics. I already have a core dump from one instance of this, and goroutine traceback dumps from others.

Comment From: gabyhelp

Related Issues

_{(Emoji vote if this was helpful or unhelpful; more detailed feedback welcome in this discussion.)}