golang / go

The Go programming language
https://go.dev
BSD 3-Clause "New" or "Revised" License
123.26k stars 17.57k forks source link

cmd/compile: seemingly stuck writing telemetry #68311

Closed dominikh closed 2 months ago

dominikh commented 3 months ago

Go version

go version devel go1.23-82c371a307 Fri Jun 28 19:59:35 2024 +0000 linux/amd64

Output of go env in your module/workspace:

GO111MODULE=''
GOARCH='amd64'
GOBIN=''
GOCACHE='/home/dominikh/.cache/go-build'
GOENV='/home/dominikh/.config/go/env'
GOEXE=''
GOEXPERIMENT=''
GOFLAGS=''
GOHOSTARCH='amd64'
GOHOSTOS='linux'
GOINSECURE=''
GOMODCACHE='/home/dominikh/prj/pkg/mod'
GONOPROXY=''
GONOSUMDB=''
GOOS='linux'
GOPATH='/home/dominikh/prj'
GOPRIVATE=''
GOPROXY='https://proxy.golang.org,direct'
GOROOT='/home/dominikh/prj/go'
GOSUMDB='sum.golang.org'
GOTMPDIR=''
GOTOOLCHAIN='auto'
GOTOOLDIR='/home/dominikh/prj/go/pkg/tool/linux_amd64'
GOVCS=''
GOVERSION='devel go1.23-82c371a307 Fri Jun 28 19:59:35 2024 +0000'
GODEBUG=''
GOTELEMETRY='local'
GOTELEMETRYDIR='/home/dominikh/.config/go/telemetry'
GCCGO='gccgo'
GOAMD64='v1'
AR='ar'
CC='gcc'
CXX='g++'
CGO_ENABLED='1'
GOMOD='/home/dominikh/prj/src/honnef.co/go/wgpu-demo/go.mod'
GOWORK=''
CGO_CFLAGS='-O2 -g'
CGO_CPPFLAGS=''
CGO_CXXFLAGS='-O2 -g'
CGO_FFLAGS='-O2 -g'
CGO_LDFLAGS='-O2 -g'
PKG_CONFIG='pkg-config'
GOGCCFLAGS='-fPIC -m64 -pthread -Wl,--no-gc-sections -fmessage-length=0 -ffile-prefix-map=/tmp/nix-shell.KkNJRp/go-build3177551663=/tmp/go-build -gno-record-gcc-switches'

What did you do?

Run go tool compile -help

What did you see happen?

The process never terminates and shows high CPU usage, most of which is spent in syscalls.. strace -ff shows a rapid and endless stream of

[pid 701400] openat(AT_FDCWD, "/home/dominikh/.config/go/telemetry/local/compile@devel-devel-linux-amd64-2024-07-04.v1.count", O_RDWR|O_CREAT|O_CLOEXEC, 0666) = 6
[pid 701400] fcntl(6, F_GETFL)          = 0x8002 (flags O_RDWR|O_LARGEFILE)
[pid 701405] <... nanosleep resumed>NULL) = 0
[pid 701400] fcntl(6, F_SETFL, O_RDWR|O_NONBLOCK|O_LARGEFILE <unfinished ...>
[pid 701405] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid 701400] <... fcntl resumed>)       = 0
[pid 701400] epoll_ctl(4, EPOLL_CTL_ADD, 6, {events=EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, data={u32=1507866546, u64=9223363117715568562}}) = -1 EPERM (Operation not permitted)
[pid 701400] fcntl(6, F_GETFL)          = 0x8802 (flags O_RDWR|O_NONBLOCK|O_LARGEFILE)
[pid 701400] fcntl(6, F_SETFL, O_RDWR|O_LARGEFILE) = 0
[pid 701405] <... nanosleep resumed>NULL) = 0
[pid 701400] fstat(6,  <unfinished ...>
[pid 701405] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid 701400] <... fstat resumed>{st_mode=S_IFREG|0644, st_size=16384, ...}) = 0
[pid 701400] fstat(6, {st_mode=S_IFREG|0644, st_size=16384, ...}) = 0
[pid 701400] mmap(NULL, 16384, PROT_READ|PROT_WRITE, MAP_SHARED, 6, 0) = 0x7ffff7e20000
[pid 701400] munmap(0x7fffb121c000, 16384 <unfinished ...>
[pid 701405] <... nanosleep resumed>NULL) = 0
[pid 701400] <... munmap resumed>)      = 0
[pid 701405] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid 701400] close(7)                   = 0
[pid 701400] openat(AT_FDCWD, "/home/dominikh/.config/go/telemetry/local/compile@devel-devel-linux-amd64-2024-07-04.v1.count", O_RDWR|O_CREAT|O_CLOEXEC, 0666) = 7
[pid 701400] fcntl(7, F_GETFL)          = 0x8002 (flags O_RDWR|O_LARGEFILE)
[pid 701405] <... nanosleep resumed>NULL) = 0
[pid 701400] fcntl(7, F_SETFL, O_RDWR|O_NONBLOCK|O_LARGEFILE <unfinished ...>
[pid 701405] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid 701400] <... fcntl resumed>)       = 0
[pid 701400] epoll_ctl(4, EPOLL_CTL_ADD, 7, {events=EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, data={u32=1507866547, u64=9223363117715568563}}) = -1 EPERM (Operation not permitted)
[pid 701400] fcntl(7, F_GETFL)          = 0x8802 (flags O_RDWR|O_NONBLOCK|O_LARGEFILE)
[pid 701400] fcntl(7, F_SETFL, O_RDWR|O_LARGEFILE) = 0
[pid 701405] <... nanosleep resumed>NULL) = 0
[pid 701400] fstat(7,  <unfinished ...>
[pid 701405] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid 701400] <... fstat resumed>{st_mode=S_IFREG|0644, st_size=16384, ...}) = 0
[pid 701400] fstat(7, {st_mode=S_IFREG|0644, st_size=16384, ...}) = 0
[pid 701400] mmap(NULL, 16384, PROT_READ|PROT_WRITE, MAP_SHARED, 7, 0) = 0x7fffb121c000
[pid 701400] munmap(0x7ffff7e20000, 16384 <unfinished ...>
[pid 701405] <... nanosleep resumed>NULL) = 0
[pid 701400] <... munmap resumed>)      = 0
[pid 701405] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid 701400] close(6)                   = 0
[pid 701400] openat(AT_FDCWD, "/home/dominikh/.config/go/telemetry/local/compile@devel-devel-linux-amd64-2024-07-04.v1.count", O_RDWR|O_CREAT|O_CLOEXEC, 0666) = 6
[pid 701400] fcntl(6, F_GETFL)          = 0x8002 (flags O_RDWR|O_LARGEFILE)
[pid 701405] <... nanosleep resumed>NULL) = 0
[pid 701400] fcntl(6, F_SETFL, O_RDWR|O_NONBLOCK|O_LARGEFILE <unfinished ...>
[pid 701405] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid 701400] <... fcntl resumed>)       = 0
[pid 701400] epoll_ctl(4, EPOLL_CTL_ADD, 6, {events=EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, data={u32=1507866548, u64=9223363117715568564}}) = -1 EPERM (Operation not permitted)
[pid 701400] fcntl(6, F_GETFL)          = 0x8802 (flags O_RDWR|O_NONBLOCK|O_LARGEFILE)
[pid 701400] fcntl(6, F_SETFL, O_RDWR|O_LARGEFILE) = 0
[pid 701405] <... nanosleep resumed>NULL) = 0
[pid 701400] fstat(6,  <unfinished ...>
[pid 701405] nanosleep({tv_sec=0, tv_nsec=40000},  <unfinished ...>
[pid 701400] <... fstat resumed>{st_mode=S_IFREG|0644, st_size=16384, ...}) = 0
[pid 701400] fstat(6, {st_mode=S_IFREG|0644, st_size=16384, ...}) = 0
[pid 701400] mmap(NULL, 16384, PROT_READ|PROT_WRITE, MAP_SHARED, 6, 0) = 0x7ffff7e20000
[pid 701400] munmap(0x7fffb121c000, 16384) = 0
[pid 701400] close(7 <unfinished ...>
[pid 701405] <... nanosleep resumed>NULL) = 0
[pid 701400] <... close resumed>)       = 0
[pid 701405] nanosleep({tv_sec=0, tv_nsec=80000},  <unfinished ...>
[pid 701400] openat(AT_FDCWD, "/home/dominikh/.config/go/telemetry/local/compile@devel-devel-linux-amd64-2024-07-04.v1.count", O_RDWR|O_CREAT|O_CLOEXEC, 0666) = 7
[pid 701400] fcntl(7, F_GETFL)          = 0x8002 (flags O_RDWR|O_LARGEFILE)
[pid 701400] fcntl(7, F_SETFL, O_RDWR|O_NONBLOCK|O_LARGEFILE) = 0
[pid 701400] epoll_ctl(4, EPOLL_CTL_ADD, 7, {events=EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, data={u32=1507866549, u64=9223363117715568565}}) = -1 EPERM (Operation not permitted)
[pid 701400] fcntl(7, F_GETFL)          = 0x8802 (flags O_RDWR|O_NONBLOCK|O_LARGEFILE)
[pid 701400] fcntl(7, F_SETFL, O_RDWR|O_LARGEFILE <unfinished ...>
[pid 701405] <... nanosleep resumed>NULL) = 0
[pid 701400] <... fcntl resumed>)       = 0
[pid 701405] nanosleep({tv_sec=0, tv_nsec=160000},  <unfinished ...>
[pid 701400] fstat(7, {st_mode=S_IFREG|0644, st_size=16384, ...}) = 0
[pid 701400] fstat(7, {st_mode=S_IFREG|0644, st_size=16384, ...}) = 0
[pid 701400] mmap(NULL, 16384, PROT_READ|PROT_WRITE, MAP_SHARED, 7, 0) = 0x7fffb121c000
[pid 701400] munmap(0x7ffff7e20000, 16384) = 0
[pid 701400] close(6)                   = 0

What did you expect to see?

Not that.

gabyhelp commented 3 months ago

Related Issues

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

dominikh commented 3 months ago

Stacktrace after sending SIGQUIT:

PC=0x47d461 m=0 sigcode=128

goroutine 0 gp=0x1505d20 m=0 mp=0x15085c0 [idle]:
runtime.futex(0x1508700, 0x80, 0x0, 0x0, 0x0, 0x0)
    /home/dominikh/prj/go/src/runtime/sys_linux_amd64.s:557 +0x21 fp=0x7fffffff92d0 sp=0x7fffffff92c8 pc=0x47d461
runtime.futexsleep(0x7fffffff9348?, 0x40feb0?, 0x1fd40c782?)
    /home/dominikh/prj/go/src/runtime/os_linux.go:69 +0x30 fp=0x7fffffff9320 sp=0x7fffffff92d0 pc=0x437cd0
runtime.notesleep(0x1508700)
    /home/dominikh/prj/go/src/runtime/lock_futex.go:170 +0x87 fp=0x7fffffff9358 sp=0x7fffffff9320 pc=0x410047
runtime.mPark(...)
    /home/dominikh/prj/go/src/runtime/proc.go:1866
runtime.stopm()
    /home/dominikh/prj/go/src/runtime/proc.go:2885 +0x8c fp=0x7fffffff9388 sp=0x7fffffff9358 pc=0x44302c
runtime.findRunnable()
    /home/dominikh/prj/go/src/runtime/proc.go:3622 +0xd5c fp=0x7fffffff9500 sp=0x7fffffff9388 pc=0x444a9c
runtime.schedule()
    /home/dominikh/prj/go/src/runtime/proc.go:3995 +0xb1 fp=0x7fffffff9538 sp=0x7fffffff9500 pc=0x445b71
runtime.park_m(0xc0004a2540)
    /home/dominikh/prj/go/src/runtime/proc.go:4102 +0x1eb fp=0x7fffffff9590 sp=0x7fffffff9538 pc=0x445f8b
runtime.mcall()
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:459 +0x4e fp=0x7fffffff95a8 sp=0x7fffffff9590 pc=0x4797ce

goroutine 1 gp=0xc0000061c0 m=nil [runnable]:
syscall.Syscall(0x48, 0x7, 0x3, 0x0)
    /home/dominikh/prj/go/src/syscall/syscall_linux.go:73 +0x25 fp=0xc0001a7448 sp=0xc0001a73e8 pc=0x4c9b05
syscall.fcntl(0x4e3fa5?, 0xc000c82020?, 0xc0001a7401?)
    /home/dominikh/prj/go/src/syscall/zsyscall_linux_amd64.go:432 +0x25 fp=0xc0001a7480 sp=0xc0001a7448 pc=0x4c8025
syscall.SetNonblock(0x7, 0x0)
    /home/dominikh/prj/go/src/syscall/exec_unix.go:106 +0x27 fp=0xc0001a74a8 sp=0xc0001a7480 pc=0x4c40c7
os.newFile(0x7, {0xc00003e540, 0x5d}, 0x1, 0x0)
    /home/dominikh/prj/go/src/os/file_unix.go:238 +0x17f fp=0xc0001a74e8 sp=0xc0001a74a8 pc=0x4f1dff
os.openFileNolog({0xc00003e540, 0x5d}, 0x42, 0xc00000?)
    /home/dominikh/prj/go/src/os/file_unix.go:297 +0x192 fp=0xc0001a7580 sp=0xc0001a74e8 pc=0x4f2032
os.OpenFile({0xc00003e540, 0x5d}, 0x42, 0x1b6)
    /home/dominikh/prj/go/src/os/file.go:385 +0x3e fp=0xc0001a75b0 sp=0xc0001a7580 pc=0x4f0b3e
cmd/vendor/golang.org/x/telemetry/internal/counter.openMapped({0xc00003e540, 0x5d}, {0xc000188510, 0x8e}, 0xc000b00000)
    /home/dominikh/prj/go/src/cmd/vendor/golang.org/x/telemetry/internal/counter/file.go:395 +0xb7 fp=0xc0001a76c8 sp=0xc0001a75b0 pc=0x5265f7
cmd/vendor/golang.org/x/telemetry/internal/counter.(*mappedFile).newCounter(0xc000b00000, {0xddb98c, 0x13})
    /home/dominikh/prj/go/src/cmd/vendor/golang.org/x/telemetry/internal/counter/file.go:609 +0x205 fp=0xc0001a77d8 sp=0xc0001a76c8 pc=0x527425
cmd/vendor/golang.org/x/telemetry/internal/counter.(*file).newCounter1(0x1505800, {0xddb98c, 0x13})
    /home/dominikh/prj/go/src/cmd/vendor/golang.org/x/telemetry/internal/counter/file.go:328 +0x1a8 fp=0xc0001a7890 sp=0xc0001a77d8 pc=0x526148
cmd/vendor/golang.org/x/telemetry/internal/counter.(*file).newCounter(0x0?, {0xddb98c?, 0x0?})
    /home/dominikh/prj/go/src/cmd/vendor/golang.org/x/telemetry/internal/counter/file.go:311 +0x18 fp=0xc0001a78c0 sp=0xc0001a7890 pc=0x525f58
cmd/vendor/golang.org/x/telemetry/internal/counter.(*file).lookup(0xdf1c54?, {0xddb98c?, 0xc000113990?})
    /home/dominikh/prj/go/src/cmd/vendor/golang.org/x/telemetry/internal/counter/file.go:104 +0x2f fp=0xc0001a7910 sp=0xc0001a78c0 pc=0x524b0f
cmd/vendor/golang.org/x/telemetry/internal/counter.(*Counter).releaseLock(0xc000192780, 0xffffffff)
    /home/dominikh/prj/go/src/cmd/vendor/golang.org/x/telemetry/internal/counter/counter.go:224 +0x16b fp=0xc0001a79c0 sp=0xc0001a7910 pc=0x52400b
cmd/vendor/golang.org/x/telemetry/internal/counter.(*Counter).Add(0xc000192780, 0x1)
    /home/dominikh/prj/go/src/cmd/vendor/golang.org/x/telemetry/internal/counter/counter.go:178 +0x38a fp=0xc0001a7a68 sp=0xc0001a79c0 pc=0x523aea
cmd/vendor/golang.org/x/telemetry/internal/counter.(*Counter).Inc(...)
    /home/dominikh/prj/go/src/cmd/vendor/golang.org/x/telemetry/internal/counter/counter.go:130
cmd/vendor/golang.org/x/telemetry/counter.Inc(...)
    /home/dominikh/prj/go/src/cmd/vendor/golang.org/x/telemetry/counter/counter.go:23
cmd/internal/telemetry/counter.Inc(...)
    /home/dominikh/prj/go/src/cmd/internal/telemetry/counter/counter.go:29
cmd/compile/internal/gc.Main(0xe09ff8)
    /home/dominikh/prj/go/src/cmd/compile/internal/gc/main.go:63 +0xdd fp=0xc0001a7ef0 sp=0xc0001a7a68 pc=0xcc0a9d
main.main()
    /home/dominikh/prj/go/src/cmd/compile/main.go:57 +0xf9 fp=0xc0001a7f50 sp=0xc0001a7ef0 pc=0xceb119
runtime.main()
    /home/dominikh/prj/go/src/runtime/proc.go:272 +0x28b fp=0xc0001a7fe0 sp=0xc0001a7f50 pc=0x43e3ab
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0001a7fe8 sp=0xc0001a7fe0 pc=0x47b681

goroutine 2 gp=0xc000006700 m=nil [force gc (idle)]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc0000c2fa8 sp=0xc0000c2f88 pc=0x473b4e
runtime.goparkunlock(...)
    /home/dominikh/prj/go/src/runtime/proc.go:430
runtime.forcegchelper()
    /home/dominikh/prj/go/src/runtime/proc.go:337 +0xb3 fp=0xc0000c2fe0 sp=0xc0000c2fa8 pc=0x43e6f3
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0000c2fe8 sp=0xc0000c2fe0 pc=0x47b681
created by runtime.init.7 in goroutine 1
    /home/dominikh/prj/go/src/runtime/proc.go:325 +0x1a

goroutine 3 gp=0xc000006c40 m=nil [GC sweep wait]:
runtime.gopark(0x1?, 0x0?, 0x0?, 0x0?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc0000c3780 sp=0xc0000c3760 pc=0x473b4e
runtime.goparkunlock(...)
    /home/dominikh/prj/go/src/runtime/proc.go:430
runtime.bgsweep(0xc0000e4000)
    /home/dominikh/prj/go/src/runtime/mgcsweep.go:317 +0xdf fp=0xc0000c37c8 sp=0xc0000c3780 pc=0x426d5f
runtime.gcenable.gowrap1()
    /home/dominikh/prj/go/src/runtime/mgc.go:203 +0x25 fp=0xc0000c37e0 sp=0xc0000c37c8 pc=0x41b405
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0000c37e8 sp=0xc0000c37e0 pc=0x47b681
created by runtime.gcenable in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:203 +0x66

goroutine 4 gp=0xc000006e00 m=nil [GC scavenge wait]:
runtime.gopark(0x4e58ac?, 0x4bc268?, 0x0?, 0x0?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc0000c3f78 sp=0xc0000c3f58 pc=0x473b4e
runtime.goparkunlock(...)
    /home/dominikh/prj/go/src/runtime/proc.go:430
runtime.(*scavengerState).park(0x1505760)
    /home/dominikh/prj/go/src/runtime/mgcscavenge.go:425 +0x49 fp=0xc0000c3fa8 sp=0xc0000c3f78 pc=0x424749
runtime.bgscavenge(0xc0000e4000)
    /home/dominikh/prj/go/src/runtime/mgcscavenge.go:658 +0x59 fp=0xc0000c3fc8 sp=0xc0000c3fa8 pc=0x424cd9
runtime.gcenable.gowrap2()
    /home/dominikh/prj/go/src/runtime/mgc.go:204 +0x25 fp=0xc0000c3fe0 sp=0xc0000c3fc8 pc=0x41b3a5
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0000c3fe8 sp=0xc0000c3fe0 pc=0x47b681
created by runtime.gcenable in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:204 +0xa5

goroutine 5 gp=0xc000007340 m=nil [finalizer wait]:
runtime.gopark(0x0?, 0xe0b8d0?, 0x10?, 0x23?, 0x1000000010?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc0000c2620 sp=0xc0000c2600 pc=0x473b4e
runtime.runfinq()
    /home/dominikh/prj/go/src/runtime/mfinal.go:193 +0x107 fp=0xc0000c27e0 sp=0xc0000c2620 pc=0x41a487
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0000c27e8 sp=0xc0000c27e0 pc=0x47b681
created by runtime.createfing in goroutine 1
    /home/dominikh/prj/go/src/runtime/mfinal.go:163 +0x3d

goroutine 6 gp=0xc000007500 m=nil [GC worker (idle)]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc0000c4738 sp=0xc0000c4718 pc=0x473b4e
runtime.gcBgMarkWorker(0xc00003a620)
    /home/dominikh/prj/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc0000c47c8 sp=0xc0000c4738 pc=0x41d729
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x25 fp=0xc0000c47e0 sp=0xc0000c47c8 pc=0x41d605
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0000c47e8 sp=0xc0000c47e0 pc=0x47b681
created by runtime.gcBgMarkStartWorkers in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x105

goroutine 7 gp=0xc0000076c0 m=nil [GC worker (idle)]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc0000c4f38 sp=0xc0000c4f18 pc=0x473b4e
runtime.gcBgMarkWorker(0xc00003a620)
    /home/dominikh/prj/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc0000c4fc8 sp=0xc0000c4f38 pc=0x41d729
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x25 fp=0xc0000c4fe0 sp=0xc0000c4fc8 pc=0x41d605
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0000c4fe8 sp=0xc0000c4fe0 pc=0x47b681
created by runtime.gcBgMarkStartWorkers in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x105

goroutine 8 gp=0xc000007880 m=nil [GC worker (idle)]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc0000c5738 sp=0xc0000c5718 pc=0x473b4e
runtime.gcBgMarkWorker(0xc00003a620)
    /home/dominikh/prj/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc0000c57c8 sp=0xc0000c5738 pc=0x41d729
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x25 fp=0xc0000c57e0 sp=0xc0000c57c8 pc=0x41d605
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0000c57e8 sp=0xc0000c57e0 pc=0x47b681
created by runtime.gcBgMarkStartWorkers in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x105

goroutine 9 gp=0xc000007a40 m=nil [GC worker (idle)]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc0000c5f38 sp=0xc0000c5f18 pc=0x473b4e
runtime.gcBgMarkWorker(0xc00003a620)
    /home/dominikh/prj/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc0000c5fc8 sp=0xc0000c5f38 pc=0x41d729
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x25 fp=0xc0000c5fe0 sp=0xc0000c5fc8 pc=0x41d605
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0000c5fe8 sp=0xc0000c5fe0 pc=0x47b681
created by runtime.gcBgMarkStartWorkers in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x105

goroutine 10 gp=0xc000007c00 m=nil [GC worker (idle)]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc0000be738 sp=0xc0000be718 pc=0x473b4e
runtime.gcBgMarkWorker(0xc00003a620)
    /home/dominikh/prj/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc0000be7c8 sp=0xc0000be738 pc=0x41d729
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x25 fp=0xc0000be7e0 sp=0xc0000be7c8 pc=0x41d605
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0000be7e8 sp=0xc0000be7e0 pc=0x47b681
created by runtime.gcBgMarkStartWorkers in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x105

goroutine 11 gp=0xc000007dc0 m=nil [GC worker (idle)]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc0000bef38 sp=0xc0000bef18 pc=0x473b4e
runtime.gcBgMarkWorker(0xc00003a620)
    /home/dominikh/prj/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc0000befc8 sp=0xc0000bef38 pc=0x41d729
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x25 fp=0xc0000befe0 sp=0xc0000befc8 pc=0x41d605
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0000befe8 sp=0xc0000befe0 pc=0x47b681
created by runtime.gcBgMarkStartWorkers in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x105

goroutine 12 gp=0xc000498000 m=nil [GC worker (idle)]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc0000bf738 sp=0xc0000bf718 pc=0x473b4e
runtime.gcBgMarkWorker(0xc00003a620)
    /home/dominikh/prj/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc0000bf7c8 sp=0xc0000bf738 pc=0x41d729
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x25 fp=0xc0000bf7e0 sp=0xc0000bf7c8 pc=0x41d605
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0000bf7e8 sp=0xc0000bf7e0 pc=0x47b681
created by runtime.gcBgMarkStartWorkers in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x105

goroutine 13 gp=0xc0004981c0 m=nil [GC worker (idle)]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc0000bff38 sp=0xc0000bff18 pc=0x473b4e
runtime.gcBgMarkWorker(0xc00003a620)
    /home/dominikh/prj/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc0000bffc8 sp=0xc0000bff38 pc=0x41d729
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x25 fp=0xc0000bffe0 sp=0xc0000bffc8 pc=0x41d605
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0000bffe8 sp=0xc0000bffe0 pc=0x47b681
created by runtime.gcBgMarkStartWorkers in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x105

goroutine 14 gp=0xc000498380 m=nil [GC worker (idle)]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc0000c0738 sp=0xc0000c0718 pc=0x473b4e
runtime.gcBgMarkWorker(0xc00003a620)
    /home/dominikh/prj/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc0000c07c8 sp=0xc0000c0738 pc=0x41d729
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x25 fp=0xc0000c07e0 sp=0xc0000c07c8 pc=0x41d605
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0000c07e8 sp=0xc0000c07e0 pc=0x47b681
created by runtime.gcBgMarkStartWorkers in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x105

goroutine 15 gp=0xc000498540 m=nil [GC worker (idle)]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc0000c0f38 sp=0xc0000c0f18 pc=0x473b4e
runtime.gcBgMarkWorker(0xc00003a620)
    /home/dominikh/prj/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc0000c0fc8 sp=0xc0000c0f38 pc=0x41d729
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x25 fp=0xc0000c0fe0 sp=0xc0000c0fc8 pc=0x41d605
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0000c0fe8 sp=0xc0000c0fe0 pc=0x47b681
created by runtime.gcBgMarkStartWorkers in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x105

goroutine 16 gp=0xc000498700 m=nil [GC worker (idle)]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc0000c1738 sp=0xc0000c1718 pc=0x473b4e
runtime.gcBgMarkWorker(0xc00003a620)
    /home/dominikh/prj/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc0000c17c8 sp=0xc0000c1738 pc=0x41d729
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x25 fp=0xc0000c17e0 sp=0xc0000c17c8 pc=0x41d605
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0000c17e8 sp=0xc0000c17e0 pc=0x47b681
created by runtime.gcBgMarkStartWorkers in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x105

goroutine 17 gp=0xc0004988c0 m=nil [GC worker (idle)]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc0000c1f38 sp=0xc0000c1f18 pc=0x473b4e
runtime.gcBgMarkWorker(0xc00003a620)
    /home/dominikh/prj/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc0000c1fc8 sp=0xc0000c1f38 pc=0x41d729
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x25 fp=0xc0000c1fe0 sp=0xc0000c1fc8 pc=0x41d605
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0000c1fe8 sp=0xc0000c1fe0 pc=0x47b681
created by runtime.gcBgMarkStartWorkers in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x105

goroutine 18 gp=0xc000498a80 m=nil [GC worker (idle)]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc00049e738 sp=0xc00049e718 pc=0x473b4e
runtime.gcBgMarkWorker(0xc00003a620)
    /home/dominikh/prj/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc00049e7c8 sp=0xc00049e738 pc=0x41d729
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x25 fp=0xc00049e7e0 sp=0xc00049e7c8 pc=0x41d605
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc00049e7e8 sp=0xc00049e7e0 pc=0x47b681
created by runtime.gcBgMarkStartWorkers in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x105

goroutine 19 gp=0xc000498c40 m=nil [GC worker (idle)]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc00049ef38 sp=0xc00049ef18 pc=0x473b4e
runtime.gcBgMarkWorker(0xc00003a620)
    /home/dominikh/prj/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc00049efc8 sp=0xc00049ef38 pc=0x41d729
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x25 fp=0xc00049efe0 sp=0xc00049efc8 pc=0x41d605
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc00049efe8 sp=0xc00049efe0 pc=0x47b681
created by runtime.gcBgMarkStartWorkers in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x105

goroutine 20 gp=0xc000498e00 m=nil [GC worker (idle)]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc00049f738 sp=0xc00049f718 pc=0x473b4e
runtime.gcBgMarkWorker(0xc00003a620)
    /home/dominikh/prj/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc00049f7c8 sp=0xc00049f738 pc=0x41d729
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x25 fp=0xc00049f7e0 sp=0xc00049f7c8 pc=0x41d605
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc00049f7e8 sp=0xc00049f7e0 pc=0x47b681
created by runtime.gcBgMarkStartWorkers in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x105

goroutine 21 gp=0xc000498fc0 m=nil [GC worker (idle)]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc00049ff38 sp=0xc00049ff18 pc=0x473b4e
runtime.gcBgMarkWorker(0xc00003a620)
    /home/dominikh/prj/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc00049ffc8 sp=0xc00049ff38 pc=0x41d729
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x25 fp=0xc00049ffe0 sp=0xc00049ffc8 pc=0x41d605
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc00049ffe8 sp=0xc00049ffe0 pc=0x47b681
created by runtime.gcBgMarkStartWorkers in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x105

goroutine 22 gp=0xc000499180 m=nil [GC worker (idle)]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc0004a0738 sp=0xc0004a0718 pc=0x473b4e
runtime.gcBgMarkWorker(0xc00003a620)
    /home/dominikh/prj/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc0004a07c8 sp=0xc0004a0738 pc=0x41d729
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x25 fp=0xc0004a07e0 sp=0xc0004a07c8 pc=0x41d605
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0004a07e8 sp=0xc0004a07e0 pc=0x47b681
created by runtime.gcBgMarkStartWorkers in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x105

goroutine 23 gp=0xc000499340 m=nil [GC worker (idle)]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc0004a0f38 sp=0xc0004a0f18 pc=0x473b4e
runtime.gcBgMarkWorker(0xc00003a620)
    /home/dominikh/prj/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc0004a0fc8 sp=0xc0004a0f38 pc=0x41d729
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x25 fp=0xc0004a0fe0 sp=0xc0004a0fc8 pc=0x41d605
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0004a0fe8 sp=0xc0004a0fe0 pc=0x47b681
created by runtime.gcBgMarkStartWorkers in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x105

goroutine 24 gp=0xc000499500 m=nil [GC worker (idle)]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc0004a1738 sp=0xc0004a1718 pc=0x473b4e
runtime.gcBgMarkWorker(0xc00003a620)
    /home/dominikh/prj/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc0004a17c8 sp=0xc0004a1738 pc=0x41d729
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x25 fp=0xc0004a17e0 sp=0xc0004a17c8 pc=0x41d605
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0004a17e8 sp=0xc0004a17e0 pc=0x47b681
created by runtime.gcBgMarkStartWorkers in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x105

goroutine 25 gp=0xc0004996c0 m=nil [GC worker (idle)]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc0004a1f38 sp=0xc0004a1f18 pc=0x473b4e
runtime.gcBgMarkWorker(0xc00003a620)
    /home/dominikh/prj/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc0004a1fc8 sp=0xc0004a1f38 pc=0x41d729
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x25 fp=0xc0004a1fe0 sp=0xc0004a1fc8 pc=0x41d605
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0004a1fe8 sp=0xc0004a1fe0 pc=0x47b681
created by runtime.gcBgMarkStartWorkers in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x105

goroutine 26 gp=0xc000499880 m=nil [GC worker (idle)]:
runtime.gopark(0x48fdfa016780?, 0x3?, 0x34?, 0x5?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc00049a738 sp=0xc00049a718 pc=0x473b4e
runtime.gcBgMarkWorker(0xc00003a620)
    /home/dominikh/prj/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc00049a7c8 sp=0xc00049a738 pc=0x41d729
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x25 fp=0xc00049a7e0 sp=0xc00049a7c8 pc=0x41d605
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc00049a7e8 sp=0xc00049a7e0 pc=0x47b681
created by runtime.gcBgMarkStartWorkers in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x105

goroutine 27 gp=0xc000499a40 m=nil [GC worker (idle)]:
runtime.gopark(0x48fdfd40b712?, 0x1?, 0x5?, 0xd1?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc00049af38 sp=0xc00049af18 pc=0x473b4e
runtime.gcBgMarkWorker(0xc00003a620)
    /home/dominikh/prj/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc00049afc8 sp=0xc00049af38 pc=0x41d729
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x25 fp=0xc00049afe0 sp=0xc00049afc8 pc=0x41d605
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc00049afe8 sp=0xc00049afe0 pc=0x47b681
created by runtime.gcBgMarkStartWorkers in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x105

goroutine 28 gp=0xc000499c00 m=nil [GC worker (idle)]:
runtime.gopark(0x48fdfd40b3b4?, 0x3?, 0x7?, 0x5d?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc00049b738 sp=0xc00049b718 pc=0x473b4e
runtime.gcBgMarkWorker(0xc00003a620)
    /home/dominikh/prj/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc00049b7c8 sp=0xc00049b738 pc=0x41d729
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x25 fp=0xc00049b7e0 sp=0xc00049b7c8 pc=0x41d605
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc00049b7e8 sp=0xc00049b7e0 pc=0x47b681
created by runtime.gcBgMarkStartWorkers in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x105

goroutine 29 gp=0xc000499dc0 m=nil [GC worker (idle)]:
runtime.gopark(0x153ce60?, 0x1?, 0x61?, 0xf0?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc00049bf38 sp=0xc00049bf18 pc=0x473b4e
runtime.gcBgMarkWorker(0xc00003a620)
    /home/dominikh/prj/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc00049bfc8 sp=0xc00049bf38 pc=0x41d729
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x25 fp=0xc00049bfe0 sp=0xc00049bfc8 pc=0x41d605
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc00049bfe8 sp=0xc00049bfe0 pc=0x47b681
created by runtime.gcBgMarkStartWorkers in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x105

goroutine 30 gp=0xc0004a2000 m=nil [GC worker (idle)]:
runtime.gopark(0x48fdfd4096fa?, 0x1?, 0x35?, 0x9f?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc00049c738 sp=0xc00049c718 pc=0x473b4e
runtime.gcBgMarkWorker(0xc00003a620)
    /home/dominikh/prj/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc00049c7c8 sp=0xc00049c738 pc=0x41d729
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x25 fp=0xc00049c7e0 sp=0xc00049c7c8 pc=0x41d605
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc00049c7e8 sp=0xc00049c7e0 pc=0x47b681
created by runtime.gcBgMarkStartWorkers in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x105

goroutine 31 gp=0xc0004a21c0 m=nil [GC worker (idle)]:
runtime.gopark(0x48fc7cc3039e?, 0x1?, 0x70?, 0x49?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc00049cf38 sp=0xc00049cf18 pc=0x473b4e
runtime.gcBgMarkWorker(0xc00003a620)
    /home/dominikh/prj/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc00049cfc8 sp=0xc00049cf38 pc=0x41d729
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x25 fp=0xc00049cfe0 sp=0xc00049cfc8 pc=0x41d605
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc00049cfe8 sp=0xc00049cfe0 pc=0x47b681
created by runtime.gcBgMarkStartWorkers in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x105

goroutine 32 gp=0xc0004a2380 m=nil [GC worker (idle)]:
runtime.gopark(0x48fdfd40b039?, 0x1?, 0x39?, 0xcb?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc00049d738 sp=0xc00049d718 pc=0x473b4e
runtime.gcBgMarkWorker(0xc00003a620)
    /home/dominikh/prj/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc00049d7c8 sp=0xc00049d738 pc=0x41d729
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x25 fp=0xc00049d7e0 sp=0xc00049d7c8 pc=0x41d605
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc00049d7e8 sp=0xc00049d7e0 pc=0x47b681
created by runtime.gcBgMarkStartWorkers in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x105

goroutine 33 gp=0xc0004a2540 m=nil [GC worker (idle)]:
runtime.gopark(0x153ce60?, 0x1?, 0x67?, 0xf5?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc00049df38 sp=0xc00049df18 pc=0x473b4e
runtime.gcBgMarkWorker(0xc00003a620)
    /home/dominikh/prj/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc00049dfc8 sp=0xc00049df38 pc=0x41d729
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x25 fp=0xc00049dfe0 sp=0xc00049dfc8 pc=0x41d605
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc00049dfe8 sp=0xc00049dfe0 pc=0x47b681
created by runtime.gcBgMarkStartWorkers in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x105

goroutine 34 gp=0xc0004a2700 m=nil [GC worker (idle)]:
runtime.gopark(0x48fdfd43572a?, 0x1?, 0x81?, 0x2?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc0004a8738 sp=0xc0004a8718 pc=0x473b4e
runtime.gcBgMarkWorker(0xc00003a620)
    /home/dominikh/prj/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc0004a87c8 sp=0xc0004a8738 pc=0x41d729
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x25 fp=0xc0004a87e0 sp=0xc0004a87c8 pc=0x41d605
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0004a87e8 sp=0xc0004a87e0 pc=0x47b681
created by runtime.gcBgMarkStartWorkers in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x105

goroutine 35 gp=0xc0004a28c0 m=nil [GC worker (idle)]:
runtime.gopark(0x48fdfd4096f0?, 0x1?, 0xb3?, 0x48?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc0004a8f38 sp=0xc0004a8f18 pc=0x473b4e
runtime.gcBgMarkWorker(0xc00003a620)
    /home/dominikh/prj/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc0004a8fc8 sp=0xc0004a8f38 pc=0x41d729
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x25 fp=0xc0004a8fe0 sp=0xc0004a8fc8 pc=0x41d605
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0004a8fe8 sp=0xc0004a8fe0 pc=0x47b681
created by runtime.gcBgMarkStartWorkers in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x105

goroutine 36 gp=0xc0004a2a80 m=nil [GC worker (idle)]:
runtime.gopark(0x48fdfd42a521?, 0x3?, 0x5c?, 0x84?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc0004a9738 sp=0xc0004a9718 pc=0x473b4e
runtime.gcBgMarkWorker(0xc00003a620)
    /home/dominikh/prj/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc0004a97c8 sp=0xc0004a9738 pc=0x41d729
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x25 fp=0xc0004a97e0 sp=0xc0004a97c8 pc=0x41d605
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0004a97e8 sp=0xc0004a97e0 pc=0x47b681
created by runtime.gcBgMarkStartWorkers in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x105

goroutine 37 gp=0xc0004a2c40 m=nil [GC worker (idle)]:
runtime.gopark(0x153ce60?, 0x3?, 0x91?, 0x6c?, 0x0?)
    /home/dominikh/prj/go/src/runtime/proc.go:424 +0xce fp=0xc0004a9f38 sp=0xc0004a9f18 pc=0x473b4e
runtime.gcBgMarkWorker(0xc00003a620)
    /home/dominikh/prj/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc0004a9fc8 sp=0xc0004a9f38 pc=0x41d729
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x25 fp=0xc0004a9fe0 sp=0xc0004a9fc8 pc=0x41d605
runtime.goexit({})
    /home/dominikh/prj/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0004a9fe8 sp=0xc0004a9fe0 pc=0x47b681
created by runtime.gcBgMarkStartWorkers in goroutine 1
    /home/dominikh/prj/go/src/runtime/mgc.go:1279 +0x105

rax    0xca
rbx    0x0
rcx    0x47d463
rdx    0x0
rdi    0x1508700
rsi    0x80
rbp    0x7fffffff9310
rsp    0x7fffffff92c8
r8     0x0
r9     0x0
r10    0x0
r11    0x286
r12    0x3
r13    0x1
r14    0x1505d20
r15    0x1d
rip    0x47d461
rflags 0x286
cs     0x33
fs     0x0
gs     0x0
dominikh commented 3 months ago

I don't know how to reproduce this. I've used this version of Go for quite a bit, and it suddenly started behaving this way, so I suspect it depends on some system state. It currently reproduces every time with this Go version, and doesn't reproduce with Go 1.22. I've avoided perturbing the system so it stays reproducible for me.

git bisect in go points, unhelpfully, to

commit efc347348e965f8db4f036ac0c9c7bf214b7a929
Author: Michael Matloob <matloob@golang.org>
Date:   Tue May 14 14:48:52 2024 -0400

    cmd: pull in golang.org/x/telemetry@7d78a97

    Commands run:
        go get golang.org/x/telemetry@7d78a97
        go mod tidy
        go mod vendor

    Change-Id: Iea0fbe11bcc69fac35fba0ee3d02cd14344a3ee9
    Reviewed-on: https://go-review.googlesource.com/c/go/+/585455
    LUCI-TryBot-Result: Go LUCI <golang-scoped@luci-project-accounts.iam.gserviceaccount.com>
    Reviewed-by: Robert Findley <rfindley@google.com>

~I'll bisect golang.org/x/telemetry next.~ I'm afraid I can't quite figure out the combination of modules and vendoring in go and how I'd bisect that dependency, especially because of transitive dependencies on newer versions of it.

dmitshur commented 3 months ago

That CL pulled in 7 changes from x/telemetry: https://go.googlesource.com/telemetry/+log/51e8b5d718eb..7d78a974cc44. Skipping ones that were test-only or modifying services (and not vendored to the main repo), it leaves 3 I think:

It should be possible to temporarily swap out the vendored x/telemetry version arbitrarily by using go mod edit -replace with a local path (pointing to intended x/telemetry commit checked out, with local edits if desired) or a pseudo-version, then go mod vendor.

dominikh commented 3 months ago

Aha. I tried adding the replace manually in go.mod, but either I forgot to go mod vendor afterwards, or go mod edit -replace does more work than modifying the go.mod when vendoring is in use. Either way, this works, thanks.

It bisects to

commit 4a0682cf430de51aba1059af8bd30fb06e7ac4b1 (HEAD)
Author: Rob Findley <rfindley@google.com>
Date:   Mon May 13 16:48:50 2024 +0000

    internal/configgen: add special handling for toolchain program versions
findleyr commented 2 months ago

Thanks very much @dominikh. I also can't reproduce this, so it seems very important that you are able to preserve your system state.

That https://go.dev/cl/585198 is implicated is probably a red herring: that CL changed the telemetry file path, by detecting when the version of toolchain programs is really the Go version. My first guess is that there's something corrupted about your counter file, and reverting to an older CL changes the path to not point to that corrupted file.

One quick test for this would be: does this reproduce today? (If it was some sort of corrupted file, it wouldn't reproduce the next day).

Unfortunately, since I am only seeing this a few days later, we have a ~3/7 chance that a weekly telemetry aggregation operation will have wiped away your old counter file :(. In that case, we'd have very little to go on, but could make the code in question more defensive.

CC @golang/telemetry

dominikh commented 2 months ago

does this reproduce today?

It does not currently reproduce; I tried at the same commit as from my initial report.

Unfortunately, since I am only seeing this a few days later, we have a ~3/7 chance that a weekly telemetry aggregation operation will have wiped away your old counter file :(.

I should have an abundance of ZFS snapshots covering that directory for the day I reported the issue.

Can you share ls -l ~/.config/go/telemetry/local?

$ ls -l ~/.config/go/telemetry/local
total 681
-rw-r--r-- 1 dominikh users 16384 Jul  3 15:38 'asm@devel-devel-linux-amd64-2024-07-03.v1.count'
-rw-r--r-- 1 dominikh users 16384 Jul  8 00:43 'asm@devel-devel-linux-amd64-2024-07-07.v1.count'
-rw-r--r-- 1 dominikh users 16384 Jul  7 13:54 'asm@go1.23rc1-go1.23rc1-linux-amd64-2024-07-07.v1.count'
-rw-r--r-- 1 dominikh users 16384 Jul  3 17:53 'cgo@devel-devel-linux-amd64-2024-07-03.v1.count'
-rw-r--r-- 1 dominikh users 16384 Jul  8 00:43 'cgo@devel-devel-linux-amd64-2024-07-07.v1.count'
-rw-r--r-- 1 dominikh users 16384 Jul  7 13:54 'cgo@go1.23rc1-go1.23rc1-linux-amd64-2024-07-07.v1.count'
-rw-r--r-- 1 dominikh users 16384 Jul  3 17:53 'compile@devel-devel-linux-amd64-2024-07-03.v1.count'
-rw-r--r-- 1 dominikh users 16384 Jul  4 18:37 'compile@devel-devel-linux-amd64-2024-07-04.v1.count'
-rw-r--r-- 1 dominikh users 16384 Jul  8 00:44 'compile@devel-devel-linux-amd64-2024-07-07.v1.count'
-rw-r--r-- 1 dominikh users 16384 Jul  5 00:23  compile-devel-linux-amd64-2024-07-04.v1.count
-rw-r--r-- 1 dominikh users 16384 Jul  5 23:32  compile-devel-linux-amd64-2024-07-05.v1.count
-rw-r--r-- 1 dominikh users 16384 Jul  7 01:59  compile-devel-linux-amd64-2024-07-06.v1.count
-rw-r--r-- 1 dominikh users 16384 Jul  8 00:06  compile-devel-linux-amd64-2024-07-07.v1.count
-rw-r--r-- 1 dominikh users 16384 Jul  7 13:54 'compile@go1.23rc1-go1.23rc1-linux-amd64-2024-07-07.v1.count'
-rw-r--r-- 1 dominikh users 16384 Jul  4 18:47 'doc@devel-devel-linux-amd64-2024-07-04.v1.count'
-rw-r--r-- 1 dominikh users 16384 Jul  3 17:53 'go@devel-devel-linux-amd64-2024-07-03.v1.count'
-rw-r--r-- 1 dominikh users 16384 Jul  4 19:06 'go@devel-devel-linux-amd64-2024-07-04.v1.count'
-rw-r--r-- 1 dominikh users 16384 Jul  8 00:44 'go@devel-devel-linux-amd64-2024-07-07.v1.count'
-rw-r--r-- 1 dominikh users 16384 Jul  5 00:23  go-devel-linux-amd64-2024-07-04.v1.count
-rw-r--r-- 1 dominikh users 16384 Jul  5 23:32  go-devel-linux-amd64-2024-07-05.v1.count
-rw-r--r-- 1 dominikh users 16384 Jul  7 01:59  go-devel-linux-amd64-2024-07-06.v1.count
-rw-r--r-- 1 dominikh users 16384 Jul  8 00:06  go-devel-linux-amd64-2024-07-07.v1.count
-rw-r--r-- 1 dominikh users 16384 Jul  3 17:53 'gofmt@devel-devel-linux-amd64-2024-07-03.v1.count'
-rw-r--r-- 1 dominikh users 16384 Jul  4 19:06 'gofmt@devel-devel-linux-amd64-2024-07-04.v1.count'
-rw-r--r-- 1 dominikh users 16384 Jul  7 13:54 'go@go1.23rc1-go1.23rc1-linux-amd64-2024-07-07.v1.count'
-rw-r--r-- 1 dominikh users 16384 Jul  4 18:37 'gopls@devel-devel-linux-amd64-2024-07-03.v1.count'
-rw-r--r-- 1 dominikh users 16384 Jul  6 19:57 'gopls@devel-devel-linux-amd64-2024-07-04.v1.count'
-rw-r--r-- 1 dominikh users 16384 Jul  6 03:05 'gopls@devel-devel-linux-amd64-2024-07-05.v1.count'
-rw-r--r-- 1 dominikh users 16384 Jul  7 14:37 'gopls@devel-devel-linux-amd64-2024-07-06.v1.count'
-rw-r--r-- 1 dominikh users 16384 Jul  8 00:07 'gopls@devel-devel-linux-amd64-2024-07-07.v1.count'
-rw-r--r-- 1 dominikh users 16384 Dec  7  2023 'gopls@devel-go1.21.0-linux-amd64-2023-12-07.v1.count'
-rw-r--r-- 1 dominikh users 16384 Dec 29  2023 'gopls@devel-go1.21.0-linux-amd64-2023-12-29.v1.count'
-rw-r--r-- 1 dominikh users 16384 Mar 21 04:29 'gopls@devel-go1.22.0-linux-amd64-2024-03-21.v1.count'
-rw-r--r-- 1 dominikh users 16384 May  9 20:57 'gopls@devel-go1.22.0-linux-amd64-2024-05-09.v1.count'
-rw-r--r-- 1 dominikh users 16384 Jul  3 17:53 'link@devel-devel-linux-amd64-2024-07-03.v1.count'
-rw-r--r-- 1 dominikh users 16384 Jul  8 00:43 'link@devel-devel-linux-amd64-2024-07-07.v1.count'
-rw-r--r-- 1 dominikh users 16384 Jul  5 00:15  link-devel-linux-amd64-2024-07-04.v1.count
-rw-r--r-- 1 dominikh users 16384 Jul  5 14:54  link-devel-linux-amd64-2024-07-05.v1.count
-rw-r--r-- 1 dominikh users 16384 Jul  6 23:16  link-devel-linux-amd64-2024-07-06.v1.count
-rw-r--r-- 1 dominikh users 16384 Jul  7 23:05  link-devel-linux-amd64-2024-07-07.v1.count
-rw-r--r-- 1 dominikh users 16384 Jul  7 13:54 'link@go1.23rc1-go1.23rc1-linux-amd64-2024-07-07.v1.count'
-rw-r--r-- 1 dominikh users  1510 Nov 15  2023  local.2023-11-15.json
-rw-r--r-- 1 dominikh users  3202 Nov 24  2023  local.2023-11-22.json
-rw-r--r-- 1 dominikh users  1388 Nov 30  2023  local.2023-11-29.json
-rw-r--r-- 1 dominikh users  1689 Dec 10  2023  local.2023-12-06.json
-rw-r--r-- 1 dominikh users  3166 Dec 13  2023  local.2023-12-13.json
-rw-r--r-- 1 dominikh users  3254 Dec 21  2023  local.2023-12-20.json
-rw-r--r-- 1 dominikh users  3140 Jan 14 02:07  local.2023-12-27.json
-rw-r--r-- 1 dominikh users  4137 Jan 25 14:42  local.2024-01-03.json
-rw-r--r-- 1 dominikh users  1259 Jan 25 14:42  local.2024-01-10.json
-rw-r--r-- 1 dominikh users  4358 Jan 25 14:42  local.2024-01-24.json
-rw-r--r-- 1 dominikh users  3118 Jan 31 17:38  local.2024-01-31.json
-rw-r--r-- 1 dominikh users  3990 Feb  8 14:15  local.2024-02-07.json
-rw-r--r-- 1 dominikh users  2419 Feb 14 14:29  local.2024-02-14.json
-rw-r--r-- 1 dominikh users  4440 Feb 21 04:10  local.2024-02-21.json
-rw-r--r-- 1 dominikh users  1667 Mar  8 02:44  local.2024-02-28.json
-rw-r--r-- 1 dominikh users  1122 Mar  8 02:44  local.2024-03-06.json
-rw-r--r-- 1 dominikh users  2086 Mar 13 01:58  local.2024-03-13.json
-rw-r--r-- 1 dominikh users  3543 Mar 20 01:04  local.2024-03-20.json
-rw-r--r-- 1 dominikh users  2059 Mar 27 03:33  local.2024-03-27.json
-rw-r--r-- 1 dominikh users  2686 Apr  4 10:34  local.2024-04-03.json
-rw-r--r-- 1 dominikh users  2599 Apr 12 19:34  local.2024-04-10.json
-rw-r--r-- 1 dominikh users  1813 Apr 17 03:46  local.2024-04-17.json
-rw-r--r-- 1 dominikh users  2120 Apr 24 02:27  local.2024-04-24.json
-rw-r--r-- 1 dominikh users  2650 May  2 00:38  local.2024-05-01.json
-rw-r--r-- 1 dominikh users  1668 May  8 02:59  local.2024-05-08.json
-rw-r--r-- 1 dominikh users  5633 May 15 19:12  local.2024-05-15.json
-rw-r--r-- 1 dominikh users  6380 May 22 20:07  local.2024-05-22.json
-rw-r--r-- 1 dominikh users  5024 May 30 22:10  local.2024-05-29.json
-rw-r--r-- 1 dominikh users  5249 Jun  5 17:08  local.2024-06-05.json
-rw-r--r-- 1 dominikh users  6589 Jun 12 21:22  local.2024-06-12.json
-rw-r--r-- 1 dominikh users  6099 Jun 19 02:24  local.2024-06-19.json
-rw-r--r-- 1 dominikh users  7599 Jun 26 15:35  local.2024-06-26.json
-rw-r--r-- 1 dominikh users 11755 Jul  3 15:18  local.2024-07-03.json
-rw-r--r-- 1 dominikh users 16384 Jul  4 19:39 'preprofile@devel-devel-linux-amd64-2024-07-04.v1.count'
-rw-r--r-- 1 dominikh users 16384 Jul  8 00:43 'preprofile@devel-devel-linux-amd64-2024-07-07.v1.count'
-rw-r--r-- 1 dominikh users     0 Jul  7 23:50  upload.token
-rw-r--r-- 1 dominikh users 16384 Jul  3 17:53 'vet@devel-devel-linux-amd64-2024-07-03.v1.count'
-rw-r--r-- 1 dominikh users 16384 Jul  4 18:37 'vet@devel-devel-linux-amd64-2024-07-04.v1.count'
-rw-r--r-- 1 dominikh users 16384 Jul  7 13:54 'vet@go1.23rc1-go1.23rc1-linux-amd64-2024-07-07.v1.count'
-rw-r--r-- 1 dominikh users     2 Nov 10  2023  weekends
hyangah commented 2 months ago

Is it possible for us to have the copy of the counter file ?

/home/dominikh/.config/go/telemetry/local/compile@devel-devel-linux-amd64-2024-07-04.v1.count

From the strace output, it looks like Open->mmap->munmap was repeated, probably for each counter definition in the program (*). If that was caused by a corrupted counter file, I hope the copy of corrupted counter file may give us some hints.

(*): can we memoize the error occurred during openMapped and avoid repeating this open->mmap->munmap sequence for every counter?

dominikh commented 2 months ago

compile@devel-devel-linux-amd64-2024-07-04.v1.count.gz

findleyr commented 2 months ago

Can you also share go@devel-devel-linux-amd64-2024-07-04.v1.count?

dominikh commented 2 months ago

go@devel-devel-linux-amd64-2024-07-04.v1.count.gz

findleyr commented 2 months ago

Thanks very much.

Some initial observations:

Now looking into the raw contents of compile@devel.

dominikh commented 2 months ago

Just in case anything unbroke the files since I filed the issue, I've pulled the telemetry from a snapshot a couple minutes before I filed the issue: telemetry.tar.gz

findleyr commented 2 months ago

Ok, after much staring I can sort of reproduce this. Sadly, not with the data you provided: the counter files seems clean.

The recovery code in your stack is not reached by any test, and cannot be correct. It will almost certainly result in an infinite loop: https://go.googlesource.com/telemetry/+/af73eac657e13cac0a57b38deaebc48902589649/internal/counter/file.go#599

In short: at this point we have a pointer to a location in the file that exceeds the bounds of the file. No amount of re-mapping is going to fix this. Furthermore, we only write these types of pointers after successfully extending the file and acquiring allocation using a compare-and-swap on the allocation limit. I didn't spot a bug in the happy path: counter heads should only point to valid locations in the counter file. Therefore, the bug seems related to either a race or external mutation of the file. Given that the timing of this corruption is the day after the weekly file expiry, it seems likely that file rotation is involved.

Nevertheless, a straightforward way to force the corruption is to write enough data that the file must be extended, and then truncate it back to its previous length. By doing so, we can reproduce the conditions of the corruption, and experience the same symptoms: a process hanging while telemetry pointlessly unmaps and remaps the file.

So, there are several actions items to close this bug:

Fortunately, since the fix is to just return an error from a branch that is (almost) never reached, it should be very safe for 1.23.

dominikh commented 2 months ago

Given that the timing of this corruption is the day after the weekly file expiry, it seems likely that file rotation is involved.

Would this reproduce across many runs? The way I originally discovered the bug was go build hanging, with numerous go tool compile -V=full processes spinning. I reproduced the issue many times, with go build, with go tool compile -h, and with make.bash in the Go source tree (which is how I bisected the problem originally: run make.bash, see if it hangs waiting on go tool compile -V=full processes).

findleyr commented 2 months ago

Yes, once the file is corrupted in this way I'd expect it could reproduce nearly 100% of the time (technically, it depends on which counters are incremented, but it looks presumably the problematic counter is incremented every invocation).

gopherbot commented 2 months ago

Change https://go.dev/cl/597336 mentions this issue: internal/mmap: add a test for atomic operations on mmapped files

gopherbot commented 2 months ago

Change https://go.dev/cl/597337 mentions this issue: internal/counter: fix handling of corrupt counter files

cherrymui commented 2 months ago

I'm not sure this is really related: it seems the telemetry code (openMapped)uses both the write syscall and mmap. This could be... tricky. In the old linker we used to use both write and mmap. In the new linker we switched to use solely mmap (or solely write, if mmap is not supported). I don't remember exactly if/what issue we run into with mixing mmap and write, but I'm also not sure it is guaranteed to be synchronized/consistent. It may also depend the specific file system implementation. To be more on the safe side it may be better to use only one. If you have to use both, maybe add an msync call in between.

findleyr commented 2 months ago

Updates:

gopherbot commented 2 months ago

Change https://go.dev/cl/597278 mentions this issue: internal/counter: add a test for concurrent counter file extension

findleyr commented 2 months ago

@cherrymui I think the write in openMapped -- at the end of the first page -- it problematic but probably not the problem here, since is far away and only done when the file is first created. Please let me know if that is inconsistent with your intuition. Can you more generally elaborate on the types of mmap problems the old linker encountered?

cherrymui commented 2 months ago

I haven't carefully read the telemetry code. You're probably right that mixing write and mmap is not directly related to this issue. For the linker, it is possible that the concern was more on the theoretical side. If there is anything, it would result in inconsistent file content and the executable would fail to run. E.g. on Windows, we found that we need to call FlushViewOfFile even we solely use mmap (MapViewOfFile), #38440. I don't recall we see any actual failure on Linux. It may also depend on the underlying file system implementation.

Besides openMapped, it seems extend also writes 0s to the end. If the file is accessed concurrently by multiple processes, is it possible that this write races with writings in mmap?

findleyr commented 2 months ago

Thanks @cherrymui. Yes, the write in extend is the race I alluded to above :). Not super likely based on the rate of writing, but still a theoretical race. We probably won't fix that for this release.

cherrymui commented 2 months ago

Sounds good, thanks. I wonder if you could just use File.Truncate to extend the file, if the content of the tail being 0 is not important. Or you worry about multiple processes extending the file and Truncate actually shortening the file?

rsc commented 2 months ago

Truncate actually shortening the file is no worse than writing zeros over the file. There is a tiny race there either way; that's why we check info.Size immediately before doing the write. We can check info.Size immediately before a Truncate just as easily.

rsc commented 2 months ago

I retract my comment about Truncate. There is no race using write, because I reserved the final bytes of every page to be unused specifically so we could write there to ensure the file was >= that length. In contrast, using Truncate would introduce a race that does not exist today.

rsc commented 2 months ago

I have spent two hours puzzling through this bug and came to the same conclusions as @findleyr and @hyangah about the right changes to make to prevent future infinite loops.

BUT, like them, I do not see how the infinite loop happens without corrupt files, and the file in the telemetry.tar.gz is certainly not corrupt.

@dominikh, I wonder if perhaps since any process that opened the counter file would hang, nothing ever closed the counter file, and without an explicit close(2) call, perhaps the in-memory changes were in kernel buffers but not flushed to disk yet at the time of the snapshot. Can you please check for any slightly later snapshots that have different contents in compile@devel-devel-linux-amd64-2024-07-04.v1.count than the telemetry.tar.gz that you uploaded? That one has:

% hexdump -C compile@devel-devel-linux-amd64-2024-07-04.v1.count
00000000  23 20 74 65 6c 65 6d 65  74 72 79 2f 63 6f 75 6e  |# telemetry/coun|
00000010  74 65 72 20 66 69 6c 65  20 76 31 0a c0 00 00 00  |ter file v1.....|
00000020  54 69 6d 65 42 65 67 69  6e 3a 20 32 30 32 34 2d  |TimeBegin: 2024-|
00000030  30 37 2d 30 34 54 30 30  3a 30 30 3a 30 30 5a 0a  |07-04T00:00:00Z.|
00000040  54 69 6d 65 45 6e 64 3a  20 32 30 32 34 2d 30 37  |TimeEnd: 2024-07|
00000050  2d 31 30 54 30 30 3a 30  30 3a 30 30 5a 0a 50 72  |-10T00:00:00Z.Pr|
00000060  6f 67 72 61 6d 3a 20 63  6d 64 2f 63 6f 6d 70 69  |ogram: cmd/compi|
00000070  6c 65 0a 56 65 72 73 69  6f 6e 3a 20 64 65 76 65  |le.Version: deve|
00000080  6c 0a 47 6f 56 65 72 73  69 6f 6e 3a 20 64 65 76  |l.GoVersion: dev|
00000090  65 6c 0a 47 4f 4f 53 3a  20 6c 69 6e 75 78 0a 47  |el.GOOS: linux.G|
000000a0  4f 41 52 43 48 3a 20 61  6d 64 36 34 0a 0a 00 00  |OARCH: amd64....|
000000b0  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
*
00004000
% 

That is, it's a completely empty counter file, just a 0xc0-byte header. If you find any later copies of the file that have non-zero bytes between 0xc0 and 0x4000, that would be very interesting. Thanks.

dominikh commented 2 months ago

The file is identical to the one I uploaded in every snapshot, from 20240704_171111 to 20240710_220029. It no longer exists in newer snapshots.

rsc commented 2 months ago

Very very odd. Thanks very much for checking @dominikh.

rsc commented 2 months ago

I packaged up a test of what I think must have been happening in the reported problem, namely multiple processes trying to create a new telemetry file at the same time. I don't understand why that would cause a problem. I've run it on Linux under stress for over 90 minutes with no problems, but I am not using ZFS, and perhaps ZFS and mmap are interacting badly.

@dominikh If you are willing to help investigate,

go install golang.org/x/tools/cmd/stress@latest
git clone https://go.googlesource.com/telemetry
cd telemetry
git fetch origin refs/changes/95/597795/2 && git checkout FETCH_HEAD
cd internal/counter
go test -c
stress -timeout 1m ./counter.test -test.run=ConcurrentOpen

will just run forever printing status updates every 5 seconds. If something gets stuck you should see a timeout message.

dominikh commented 2 months ago
9m5s: 15884 runs so far, 0 failures

I'm happy to keep this running for longer, but with how reliably I was triggering it that one day, this doesn't seem very promising.

On the other hand, the problem hasn't reproduced naturally for me, either. I also had to reboot the machine at one point, so a lot of the state from that day is gone by now.

As for ZFS and mmap, that path isn't as special as it would seem. Mmaping a file causes ZFS to use the Linux page cache instead of the ARC and normal reads check it for dirty pages.

rsc commented 2 months ago

@dominikh The reliable hang was because the mmap'ed pages had been corrupted into a bad state, but apparently not a bad state reflected in the file itself. (It must be corrupt because the infinite loop is only possible if a specific word in the file is >16384 (= size of mapping we are seeing in the strace and the size of the file in the snapshot), but that word is <16384 in your snapshot. So somehow that loop is not reading the word from the file.) Once the mmap-available copy was corrupted, all future accesses would hang the same way.

I was wondering how to trigger the mmap corruption itself. Since the snapshot file was an empty counters file (with no counter data written yet), I reasoned that perhaps the bad state was somehow triggered by multiple processes trying to create the file at the same time and interacting badly with the combination of concurrent creation, mmap, and ZFS. So the test repeatedly runs 10 concurrent creates and then has each make a counter. If the same mmap corruption happened, the test would hang. I guess not. Thanks for trying it.

rsc commented 2 months ago

We've closed this issue because we've avoided the infinite loop at least, but I'm still curious whether we can provoke it. We may just never understand it. The code looks solid at least.

If this was any other program, the answer would be to add a telemetry counter so we could at least find out whether this presumably rare occurrence is happening in the wild. Unfortunately, since this is the code that is trying to reach the telemetry counters, we can't increment a counter when it fails. šŸ˜µā€šŸ’«

findleyr commented 2 months ago

@rsc something @hyangah suggested is to write a 'corrupt' byte near the start of the counter file, which when read by the uploader process could be recorded in a different counter file.

rsc commented 2 months ago

Indeed, there are plenty of special cases we could imagine introducing, including just writing an empty "counter-bug-yyyy-mm-dd" file. I'm not sure we're there yet.

gopherbot commented 2 months ago

Change https://go.dev/cl/598115 mentions this issue: gopls: update x/telemetry dependency

gopherbot commented 2 months ago

Change https://go.dev/cl/598056 mentions this issue: [gopls-release-branch.0.16] gopls: update x/telemetry dependency

cuonglm commented 2 months ago

The issue seems to happen to me when I was testing #63285 (Just run go build main.go with the reproducer provided).

Not sure it could be the same problem here, but the hanging is there.

$ go version
go version devel go1.23-90c6558b6a Wed Jul 17 07:00:20 2024 +0000 linux/amd64

git bisect points to: 483a913a55215a063ee7a7f218e9ed8f3c7ba21b

For now, I have created a backup of ~/.config/go/telemetry, here's the strace output (I let it run for ~ 1minute).

68311.txt

findleyr commented 2 months ago

@cuonglm, it doesn't look like the exact same issue, as I don't see any munmap calls in your strace. In fact, the telemetry system calls at first glance look somewhat reasonable (reading the mode, the upload.token, mmapping the counter file).

Questions:

  1. Is this still reproducible?
  2. Can you grab a stack after sigquit the hanging process?
  3. If you rm or mv ~/.config/go/telemetry, does it no longer reproduce?
  4. When you say it bisects, you mean before telemetry was integrated it does not hang, and after, it does?
cuonglm commented 2 months ago

@findleyr

Is this still reproducible?

Yes, still reproducible for me at this moment.

If you rm or mv ~/.config/go/telemetry, does it no longer reproduce?

It's still reproducible after removing ~/.config/go/telemetry.

When you say it bisects, you mean before telemetry was integrated it does not hang, and after, it does?

Yes.

Can you grab a stack after sigquit the hanging process?

Here's it:

Output after sending SIGQUIT
{23:09}~/p:main āœ“ āž­ go build main.go 
SIGQUIT: quit
PC=0x47af01 m=0 sigcode=0

goroutine 0 gp=0xfd3140 m=0 mp=0xfd4e60 [idle]:
runtime.futex(0xfd4fa0, 0x80, 0x0, 0x0, 0x0, 0x0)
    /home/cuonglm/sources/go/src/runtime/sys_linux_amd64.s:557 +0x21 fp=0x7fff6a0918c0 sp=0x7fff6a0918b8 pc=0x47af01
runtime.futexsleep(0x7fff6a091938?, 0x40f350?, 0xc000000800?)
    /home/cuonglm/sources/go/src/runtime/os_linux.go:69 +0x30 fp=0x7fff6a091910 sp=0x7fff6a0918c0 pc=0x434f30
runtime.notesleep(0xfd4fa0)
    /home/cuonglm/sources/go/src/runtime/lock_futex.go:170 +0x87 fp=0x7fff6a091948 sp=0x7fff6a091910 pc=0x40f4e7
runtime.mPark(...)
    /home/cuonglm/sources/go/src/runtime/proc.go:1866
runtime.stopm()
    /home/cuonglm/sources/go/src/runtime/proc.go:2885 +0x8c fp=0x7fff6a091978 sp=0x7fff6a091948 pc=0x44032c
runtime.exitsyscall0(0xc000105dc0)
    /home/cuonglm/sources/go/src/runtime/proc.go:4816 +0x1f6 fp=0x7fff6a0919c0 sp=0x7fff6a091978 pc=0x444d16
runtime.mcall()
    /home/cuonglm/sources/go/src/runtime/asm_amd64.s:459 +0x4e fp=0x7fff6a0919d8 sp=0x7fff6a0919c0 pc=0x47726e

goroutine 1 gp=0xc0000061c0 m=nil [semacquire]:
runtime.gopark(0x7fa5ab9865b8?, 0x8?, 0x40?, 0xa5?, 0xc000113718?)
    /home/cuonglm/sources/go/src/runtime/proc.go:424 +0xce fp=0xc00018b690 sp=0xc00018b670 pc=0x47126e
runtime.goparkunlock(...)
    /home/cuonglm/sources/go/src/runtime/proc.go:430
runtime.semacquire1(0xc000249978, 0x0, 0x1, 0x0, 0x12)
    /home/cuonglm/sources/go/src/runtime/sema.go:178 +0x225 fp=0xc00018b6f8 sp=0xc00018b690 pc=0x44e725
sync.runtime_Semacquire(0xc0003119b0?)
    /home/cuonglm/sources/go/src/runtime/sema.go:71 +0x25 fp=0xc00018b730 sp=0xc00018b6f8 pc=0x472805
sync.(*WaitGroup).Wait(0x0?)
    /home/cuonglm/sources/go/src/sync/waitgroup.go:118 +0x48 fp=0xc00018b758 sp=0xc00018b730 pc=0x487888
cmd/go/internal/work.(*Builder).Do(0xc00015a360, {0xc18e18, 0xff4ba0}, 0xc00032c160)
    /home/cuonglm/sources/go/src/cmd/go/internal/work/exec.go:230 +0x478 fp=0xc00018b870 sp=0xc00018b758 pc=0x942c38
cmd/go/internal/work.runBuild({0xc18e18, 0xff4ba0}, 0xc000130378?, {0xc0000224a0, 0x1, 0x1})
    /home/cuonglm/sources/go/src/cmd/go/internal/work/build.go:547 +0x74c fp=0xc00018b9d0 sp=0xc00018b870 pc=0x93ae4c
main.invoke(0xfc62e0, {0xc000022490, 0x2, 0x2})
    /home/cuonglm/sources/go/src/cmd/go/main.go:299 +0x84e fp=0xc00018bcd8 sp=0xc00018b9d0 pc=0x9e1d8e
main.main()
    /home/cuonglm/sources/go/src/cmd/go/main.go:213 +0xea5 fp=0xc00018bf50 sp=0xc00018bcd8 pc=0x9e11e5
runtime.main()
    /home/cuonglm/sources/go/src/runtime/proc.go:272 +0x28b fp=0xc00018bfe0 sp=0xc00018bf50 pc=0x43b6ab
runtime.goexit({})
    /home/cuonglm/sources/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc00018bfe8 sp=0xc00018bfe0 pc=0x479121

goroutine 2 gp=0xc000006700 m=nil [force gc (idle)]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
    /home/cuonglm/sources/go/src/runtime/proc.go:424 +0xce fp=0xc000064fa8 sp=0xc000064f88 pc=0x47126e
runtime.goparkunlock(...)
    /home/cuonglm/sources/go/src/runtime/proc.go:430
runtime.forcegchelper()
    /home/cuonglm/sources/go/src/runtime/proc.go:337 +0xb3 fp=0xc000064fe0 sp=0xc000064fa8 pc=0x43b9f3
runtime.goexit({})
    /home/cuonglm/sources/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc000064fe8 sp=0xc000064fe0 pc=0x479121
created by runtime.init.7 in goroutine 1
    /home/cuonglm/sources/go/src/runtime/proc.go:325 +0x1a

goroutine 3 gp=0xc000006c40 m=nil [GC sweep wait]:
runtime.gopark(0x1?, 0x0?, 0x0?, 0x0?, 0x0?)
    /home/cuonglm/sources/go/src/runtime/proc.go:424 +0xce fp=0xc000065780 sp=0xc000065760 pc=0x47126e
runtime.goparkunlock(...)
    /home/cuonglm/sources/go/src/runtime/proc.go:430
runtime.bgsweep(0xc00007e000)
    /home/cuonglm/sources/go/src/runtime/mgcsweep.go:317 +0xdf fp=0xc0000657c8 sp=0xc000065780 pc=0x42651f
runtime.gcenable.gowrap1()
    /home/cuonglm/sources/go/src/runtime/mgc.go:203 +0x25 fp=0xc0000657e0 sp=0xc0000657c8 pc=0x41ac05
runtime.goexit({})
    /home/cuonglm/sources/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0000657e8 sp=0xc0000657e0 pc=0x479121
created by runtime.gcenable in goroutine 1
    /home/cuonglm/sources/go/src/runtime/mgc.go:203 +0x66

goroutine 4 gp=0xc000006e00 m=nil [GC scavenge wait]:
runtime.gopark(0x3b9de3a9?, 0x3b9aca00?, 0x0?, 0x0?, 0x0?)
    /home/cuonglm/sources/go/src/runtime/proc.go:424 +0xce fp=0xc000065f78 sp=0xc000065f58 pc=0x47126e
runtime.goparkunlock(...)
    /home/cuonglm/sources/go/src/runtime/proc.go:430
runtime.(*scavengerState).park(0xfd2a00)
    /home/cuonglm/sources/go/src/runtime/mgcscavenge.go:425 +0x49 fp=0xc000065fa8 sp=0xc000065f78 pc=0x423f09
runtime.bgscavenge(0xc00007e000)
    /home/cuonglm/sources/go/src/runtime/mgcscavenge.go:658 +0x59 fp=0xc000065fc8 sp=0xc000065fa8 pc=0x424499
runtime.gcenable.gowrap2()
    /home/cuonglm/sources/go/src/runtime/mgc.go:204 +0x25 fp=0xc000065fe0 sp=0xc000065fc8 pc=0x41aba5
runtime.goexit({})
    /home/cuonglm/sources/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc000065fe8 sp=0xc000065fe0 pc=0x479121
created by runtime.gcenable in goroutine 1
    /home/cuonglm/sources/go/src/runtime/mgc.go:204 +0xa5

goroutine 5 gp=0xc000007340 m=nil [finalizer wait]:
runtime.gopark(0x0?, 0xb602d8?, 0x0?, 0xa0?, 0x2000000020?)
    /home/cuonglm/sources/go/src/runtime/proc.go:424 +0xce fp=0xc000064620 sp=0xc000064600 pc=0x47126e
runtime.runfinq()
    /home/cuonglm/sources/go/src/runtime/mfinal.go:193 +0x107 fp=0xc0000647e0 sp=0xc000064620 pc=0x419c87
runtime.goexit({})
    /home/cuonglm/sources/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0000647e8 sp=0xc0000647e0 pc=0x479121
created by runtime.createfing in goroutine 1
    /home/cuonglm/sources/go/src/runtime/mfinal.go:163 +0x3d

goroutine 17 gp=0xc000104380 m=nil [chan receive]:
runtime.gopark(0xc000060760?, 0x695c45?, 0x10?, 0xe5?, 0xc213e0?)
    /home/cuonglm/sources/go/src/runtime/proc.go:424 +0xce fp=0xc000060718 sp=0xc0000606f8 pc=0x47126e
runtime.chanrecv(0xc000136070, 0x0, 0x1)
    /home/cuonglm/sources/go/src/runtime/chan.go:639 +0x41c fp=0xc000060790 sp=0xc000060718 pc=0x409d7c
runtime.chanrecv1(0x0?, 0x0?)
    /home/cuonglm/sources/go/src/runtime/chan.go:489 +0x12 fp=0xc0000607b8 sp=0xc000060790 pc=0x409932
runtime.unique_runtime_registerUniqueMapCleanup.func1(...)
    /home/cuonglm/sources/go/src/runtime/mgc.go:1732
runtime.unique_runtime_registerUniqueMapCleanup.gowrap1()
    /home/cuonglm/sources/go/src/runtime/mgc.go:1735 +0x2f fp=0xc0000607e0 sp=0xc0000607b8 pc=0x41dc0f
runtime.goexit({})
    /home/cuonglm/sources/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0000607e8 sp=0xc0000607e0 pc=0x479121
created by unique.runtime_registerUniqueMapCleanup in goroutine 1
    /home/cuonglm/sources/go/src/runtime/mgc.go:1730 +0x96

goroutine 21 gp=0xc000104540 m=nil [select]:
runtime.gopark(0xc000499f90?, 0x2?, 0x0?, 0x0?, 0xc000499f5c?)
    /home/cuonglm/sources/go/src/runtime/proc.go:424 +0xce fp=0xc000512df8 sp=0xc000512dd8 pc=0x47126e
runtime.selectgo(0xc000512f90, 0xc000499f58, 0xc00032dce0?, 0x0, 0x0?, 0x1)
    /home/cuonglm/sources/go/src/runtime/select.go:335 +0x7a5 fp=0xc000512f20 sp=0xc000512df8 pc=0x44d685
cmd/go/internal/work.(*Builder).Do.func4()
    /home/cuonglm/sources/go/src/cmd/go/internal/work/exec.go:211 +0x105 fp=0xc000512fe0 sp=0xc000512f20 pc=0x942ee5
runtime.goexit({})
    /home/cuonglm/sources/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc000512fe8 sp=0xc000512fe0 pc=0x479121
created by cmd/go/internal/work.(*Builder).Do in goroutine 1
    /home/cuonglm/sources/go/src/cmd/go/internal/work/exec.go:207 +0x3d1

goroutine 20 gp=0xc000104700 m=nil [select]:
runtime.gopark(0xc0000f5f90?, 0x2?, 0x0?, 0x0?, 0xc0000f5f5c?)
    /home/cuonglm/sources/go/src/runtime/proc.go:424 +0xce fp=0xc0005a7df8 sp=0xc0005a7dd8 pc=0x47126e
runtime.selectgo(0xc0005a7f90, 0xc0000f5f58, 0xc00032cc60?, 0x0, 0xff4ba0?, 0x1)
    /home/cuonglm/sources/go/src/runtime/select.go:335 +0x7a5 fp=0xc0005a7f20 sp=0xc0005a7df8 pc=0x44d685
cmd/go/internal/work.(*Builder).Do.func4()
    /home/cuonglm/sources/go/src/cmd/go/internal/work/exec.go:211 +0x105 fp=0xc0005a7fe0 sp=0xc0005a7f20 pc=0x942ee5
runtime.goexit({})
    /home/cuonglm/sources/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0005a7fe8 sp=0xc0005a7fe0 pc=0x479121
created by cmd/go/internal/work.(*Builder).Do in goroutine 1
    /home/cuonglm/sources/go/src/cmd/go/internal/work/exec.go:207 +0x3d1

goroutine 22 gp=0xc000105880 m=7 mp=0xc000500008 [syscall]:
syscall.Syscall6(0xf7, 0x3, 0xc, 0xc000188cd0, 0x4, 0xc000462090, 0x0)
    /home/cuonglm/sources/go/src/syscall/syscall_linux.go:95 +0x39 fp=0xc000188c90 sp=0xc000188c30 pc=0x496999
os.(*Process).pidfdWait(0xc000428120?)
    /home/cuonglm/sources/go/src/os/pidfd_linux.go:92 +0x236 fp=0xc000188dc0 sp=0xc000188c90 pc=0x5026f6
os.(*Process).wait(0xc000414254?)
    /home/cuonglm/sources/go/src/os/exec_unix.go:27 +0x25 fp=0xc000188de0 sp=0xc000188dc0 pc=0x4fda05
os.(*Process).Wait(...)
    /home/cuonglm/sources/go/src/os/exec.go:358
os/exec.(*Cmd).Wait(0xc0004b0180)
    /home/cuonglm/sources/go/src/os/exec/exec.go:906 +0x45 fp=0xc000188e40 sp=0xc000188de0 pc=0x539a85
os/exec.(*Cmd).Run(0xc0004b0180)
    /home/cuonglm/sources/go/src/os/exec/exec.go:610 +0x2d fp=0xc000188e58 sp=0xc000188e40 pc=0x53870d
cmd/go/internal/work.(*Shell).runOut(0xc00059a070, {0xc00002819c, 0xf}, {0x0, 0x0, 0x800a6f672e?}, {0xc0004ca100?, 0x4232c5?, 0xff60a0?})
    /home/cuonglm/sources/go/src/cmd/go/internal/work/shell.go:637 +0x66a fp=0xc000189038 sp=0xc000188e58 pc=0x975e4a
cmd/go/internal/work.gcToolchain.gc({}, 0x45592a?, 0xc00032c420, {0xc000414180, 0x24}, {0xc0000a6140, 0x92, 0xa0}, {0x0, 0x0, ...}, ...)
    /home/cuonglm/sources/go/src/cmd/go/internal/work/gc.go:179 +0x182d fp=0xc0001892b8 sp=0xc000189038 pc=0x96258d
cmd/go/internal/work.(*gcToolchain).gc(0x0?, 0x0?, 0x0?, {0xc000414180?, 0x0?}, {0xc0000a6140?, 0x0?, 0x0?}, {0x0, 0x0, ...}, ...)
    :1 +0xdf fp=0xc000189358 sp=0xc0001892b8 pc=0x97803f
cmd/go/internal/work.(*Builder).build(0xc00015a360, {0x27?, 0x0?}, 0xc00032c420)
    /home/cuonglm/sources/go/src/cmd/go/internal/work/exec.go:891 +0x323f fp=0xc000189d98 sp=0xc000189358 pc=0x948e3f
cmd/go/internal/work.(*buildActor).Act(0xc18e18?, 0xff4ba0?, {0xc18e18?, 0xff4ba0?}, 0xc000189f10?)
    /home/cuonglm/sources/go/src/cmd/go/internal/work/action.go:461 +0x29 fp=0xc000189dc8 sp=0xc000189d98 pc=0x9353e9
cmd/go/internal/work.(*Builder).Do.func3({0xc18e18, 0xff4ba0}, 0xc00032c420)
    /home/cuonglm/sources/go/src/cmd/go/internal/work/exec.go:152 +0x7a4 fp=0xc000189f20 sp=0xc000189dc8 pc=0x943804
cmd/go/internal/work.(*Builder).Do.func4()
    /home/cuonglm/sources/go/src/cmd/go/internal/work/exec.go:221 +0xae fp=0xc000189fe0 sp=0xc000189f20 pc=0x942e8e
runtime.goexit({})
    /home/cuonglm/sources/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc000189fe8 sp=0xc000189fe0 pc=0x479121
created by cmd/go/internal/work.(*Builder).Do in goroutine 1
    /home/cuonglm/sources/go/src/cmd/go/internal/work/exec.go:207 +0x3d1

goroutine 23 gp=0xc000105a40 m=nil [select]:
runtime.gopark(0xc00060bf90?, 0x2?, 0x0?, 0x0?, 0xc00060bf5c?)
    /home/cuonglm/sources/go/src/runtime/proc.go:424 +0xce fp=0xc00060bdf8 sp=0xc00060bdd8 pc=0x47126e
runtime.selectgo(0xc00060bf90, 0xc00060bf58, 0xc00032c6e0?, 0x0, 0x0?, 0x1)
    /home/cuonglm/sources/go/src/runtime/select.go:335 +0x7a5 fp=0xc00060bf20 sp=0xc00060bdf8 pc=0x44d685
cmd/go/internal/work.(*Builder).Do.func4()
    /home/cuonglm/sources/go/src/cmd/go/internal/work/exec.go:211 +0x105 fp=0xc00060bfe0 sp=0xc00060bf20 pc=0x942ee5
runtime.goexit({})
    /home/cuonglm/sources/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc00060bfe8 sp=0xc00060bfe0 pc=0x479121
created by cmd/go/internal/work.(*Builder).Do in goroutine 1
    /home/cuonglm/sources/go/src/cmd/go/internal/work/exec.go:207 +0x3d1

goroutine 24 gp=0xc000105c00 m=nil [select]:
runtime.gopark(0xc0000f9f90?, 0x2?, 0x0?, 0x0?, 0xc0000f9f5c?)
    /home/cuonglm/sources/go/src/runtime/proc.go:424 +0xce fp=0xc0000a1df8 sp=0xc0000a1dd8 pc=0x47126e
runtime.selectgo(0xc0000a1f90, 0xc0000f9f58, 0xc00032da20?, 0x0, 0x0?, 0x1)
    /home/cuonglm/sources/go/src/runtime/select.go:335 +0x7a5 fp=0xc0000a1f20 sp=0xc0000a1df8 pc=0x44d685
cmd/go/internal/work.(*Builder).Do.func4()
    /home/cuonglm/sources/go/src/cmd/go/internal/work/exec.go:211 +0x105 fp=0xc0000a1fe0 sp=0xc0000a1f20 pc=0x942ee5
runtime.goexit({})
    /home/cuonglm/sources/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0000a1fe8 sp=0xc0000a1fe0 pc=0x479121
created by cmd/go/internal/work.(*Builder).Do in goroutine 1
    /home/cuonglm/sources/go/src/cmd/go/internal/work/exec.go:207 +0x3d1

goroutine 25 gp=0xc000105dc0 m=nil [select]:
runtime.gopark(0xc000609f90?, 0x2?, 0x0?, 0x0?, 0xc000609f5c?)
    /home/cuonglm/sources/go/src/runtime/proc.go:424 +0xce fp=0xc0005acdf8 sp=0xc0005acdd8 pc=0x47126e
runtime.selectgo(0xc0005acf90, 0xc000609f58, 0xc00032d4a0?, 0x0, 0x0?, 0x1)
    /home/cuonglm/sources/go/src/runtime/select.go:335 +0x7a5 fp=0xc0005acf20 sp=0xc0005acdf8 pc=0x44d685
cmd/go/internal/work.(*Builder).Do.func4()
    /home/cuonglm/sources/go/src/cmd/go/internal/work/exec.go:211 +0x105 fp=0xc0005acfe0 sp=0xc0005acf20 pc=0x942ee5
runtime.goexit({})
    /home/cuonglm/sources/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0005acfe8 sp=0xc0005acfe0 pc=0x479121
created by cmd/go/internal/work.(*Builder).Do in goroutine 1
    /home/cuonglm/sources/go/src/cmd/go/internal/work/exec.go:207 +0x3d1

goroutine 26 gp=0xc00033a000 m=nil [select]:
runtime.gopark(0xc000605f90?, 0x2?, 0x0?, 0x0?, 0xc000605f5c?)
    /home/cuonglm/sources/go/src/runtime/proc.go:424 +0xce fp=0xc00009bdf8 sp=0xc00009bdd8 pc=0x47126e
runtime.selectgo(0xc00009bf90, 0xc000605f58, 0xc00032db80?, 0x0, 0x0?, 0x1)
    /home/cuonglm/sources/go/src/runtime/select.go:335 +0x7a5 fp=0xc00009bf20 sp=0xc00009bdf8 pc=0x44d685
cmd/go/internal/work.(*Builder).Do.func4()
    /home/cuonglm/sources/go/src/cmd/go/internal/work/exec.go:211 +0x105 fp=0xc00009bfe0 sp=0xc00009bf20 pc=0x942ee5
runtime.goexit({})
    /home/cuonglm/sources/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc00009bfe8 sp=0xc00009bfe0 pc=0x479121
created by cmd/go/internal/work.(*Builder).Do in goroutine 1
    /home/cuonglm/sources/go/src/cmd/go/internal/work/exec.go:207 +0x3d1

goroutine 27 gp=0xc00033a1c0 m=nil [select]:
runtime.gopark(0xc00018df90?, 0x2?, 0x0?, 0x0?, 0xc00018df5c?)
    /home/cuonglm/sources/go/src/runtime/proc.go:424 +0xce fp=0xc00009cdf8 sp=0xc00009cdd8 pc=0x47126e
runtime.selectgo(0xc00009cf90, 0xc00018df58, 0xc00032c840?, 0x0, 0x0?, 0x1)
    /home/cuonglm/sources/go/src/runtime/select.go:335 +0x7a5 fp=0xc00009cf20 sp=0xc00009cdf8 pc=0x44d685
cmd/go/internal/work.(*Builder).Do.func4()
    /home/cuonglm/sources/go/src/cmd/go/internal/work/exec.go:211 +0x105 fp=0xc00009cfe0 sp=0xc00009cf20 pc=0x942ee5
runtime.goexit({})
    /home/cuonglm/sources/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc00009cfe8 sp=0xc00009cfe0 pc=0x479121
created by cmd/go/internal/work.(*Builder).Do in goroutine 1
    /home/cuonglm/sources/go/src/cmd/go/internal/work/exec.go:207 +0x3d1

goroutine 65 gp=0xc000584380 m=nil [GC worker (idle)]:
runtime.gopark(0x3fb43ffb5044?, 0x0?, 0x1?, 0x0?, 0x101000000000000?)
    /home/cuonglm/sources/go/src/runtime/proc.go:424 +0xce fp=0xc000063f38 sp=0xc000063f18 pc=0x47126e
runtime.gcBgMarkWorker(0xc0005bc000)
    /home/cuonglm/sources/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc000063fc8 sp=0xc000063f38 pc=0x41cf29
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/cuonglm/sources/go/src/runtime/mgc.go:1279 +0x25 fp=0xc000063fe0 sp=0xc000063fc8 pc=0x41ce05
runtime.goexit({})
    /home/cuonglm/sources/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc000063fe8 sp=0xc000063fe0 pc=0x479121
created by runtime.gcBgMarkStartWorkers in goroutine 26
    /home/cuonglm/sources/go/src/runtime/mgc.go:1279 +0x105

goroutine 66 gp=0xc000584540 m=nil [GC worker (idle)]:
runtime.gopark(0x3fb440140f6e?, 0x0?, 0x0?, 0x0?, 0x0?)
    /home/cuonglm/sources/go/src/runtime/proc.go:424 +0xce fp=0xc0003b4738 sp=0xc0003b4718 pc=0x47126e
runtime.gcBgMarkWorker(0xc0005bc000)
    /home/cuonglm/sources/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc0003b47c8 sp=0xc0003b4738 pc=0x41cf29
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/cuonglm/sources/go/src/runtime/mgc.go:1279 +0x25 fp=0xc0003b47e0 sp=0xc0003b47c8 pc=0x41ce05
runtime.goexit({})
    /home/cuonglm/sources/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0003b47e8 sp=0xc0003b47e0 pc=0x479121
created by runtime.gcBgMarkStartWorkers in goroutine 26
    /home/cuonglm/sources/go/src/runtime/mgc.go:1279 +0x105

goroutine 67 gp=0xc000584700 m=nil [GC worker (idle)]:
runtime.gopark(0x3fb44012a296?, 0x0?, 0x0?, 0x0?, 0x0?)
    /home/cuonglm/sources/go/src/runtime/proc.go:424 +0xce fp=0xc0003b4f38 sp=0xc0003b4f18 pc=0x47126e
runtime.gcBgMarkWorker(0xc0005bc000)
    /home/cuonglm/sources/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc0003b4fc8 sp=0xc0003b4f38 pc=0x41cf29
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/cuonglm/sources/go/src/runtime/mgc.go:1279 +0x25 fp=0xc0003b4fe0 sp=0xc0003b4fc8 pc=0x41ce05
runtime.goexit({})
    /home/cuonglm/sources/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0003b4fe8 sp=0xc0003b4fe0 pc=0x479121
created by runtime.gcBgMarkStartWorkers in goroutine 26
    /home/cuonglm/sources/go/src/runtime/mgc.go:1279 +0x105

goroutine 68 gp=0xc0005848c0 m=nil [GC worker (idle)]:
runtime.gopark(0x3fb44012a09a?, 0x1?, 0x34?, 0xeb?, 0x0?)
    /home/cuonglm/sources/go/src/runtime/proc.go:424 +0xce fp=0xc0003b5738 sp=0xc0003b5718 pc=0x47126e
runtime.gcBgMarkWorker(0xc0005bc000)
    /home/cuonglm/sources/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc0003b57c8 sp=0xc0003b5738 pc=0x41cf29
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/cuonglm/sources/go/src/runtime/mgc.go:1279 +0x25 fp=0xc0003b57e0 sp=0xc0003b57c8 pc=0x41ce05
runtime.goexit({})
    /home/cuonglm/sources/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0003b57e8 sp=0xc0003b57e0 pc=0x479121
created by runtime.gcBgMarkStartWorkers in goroutine 26
    /home/cuonglm/sources/go/src/runtime/mgc.go:1279 +0x105

goroutine 69 gp=0xc000584a80 m=nil [GC worker (idle)]:
runtime.gopark(0x3fb44014a0dd?, 0x3?, 0x85?, 0x60?, 0x0?)
    /home/cuonglm/sources/go/src/runtime/proc.go:424 +0xce fp=0xc0003b5f38 sp=0xc0003b5f18 pc=0x47126e
runtime.gcBgMarkWorker(0xc0005bc000)
    /home/cuonglm/sources/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc0003b5fc8 sp=0xc0003b5f38 pc=0x41cf29
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/cuonglm/sources/go/src/runtime/mgc.go:1279 +0x25 fp=0xc0003b5fe0 sp=0xc0003b5fc8 pc=0x41ce05
runtime.goexit({})
    /home/cuonglm/sources/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0003b5fe8 sp=0xc0003b5fe0 pc=0x479121
created by runtime.gcBgMarkStartWorkers in goroutine 26
    /home/cuonglm/sources/go/src/runtime/mgc.go:1279 +0x105

goroutine 70 gp=0xc000584c40 m=nil [GC worker (idle)]:
runtime.gopark(0x3fb44014a100?, 0x0?, 0x0?, 0x0?, 0x0?)
    /home/cuonglm/sources/go/src/runtime/proc.go:424 +0xce fp=0xc0003b6738 sp=0xc0003b6718 pc=0x47126e
runtime.gcBgMarkWorker(0xc0005bc000)
    /home/cuonglm/sources/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc0003b67c8 sp=0xc0003b6738 pc=0x41cf29
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/cuonglm/sources/go/src/runtime/mgc.go:1279 +0x25 fp=0xc0003b67e0 sp=0xc0003b67c8 pc=0x41ce05
runtime.goexit({})
    /home/cuonglm/sources/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0003b67e8 sp=0xc0003b67e0 pc=0x479121
created by runtime.gcBgMarkStartWorkers in goroutine 26
    /home/cuonglm/sources/go/src/runtime/mgc.go:1279 +0x105

goroutine 71 gp=0xc000584e00 m=nil [GC worker (idle)]:
runtime.gopark(0x3fb440141467?, 0x1?, 0x8a?, 0xb3?, 0x0?)
    /home/cuonglm/sources/go/src/runtime/proc.go:424 +0xce fp=0xc0003b6f38 sp=0xc0003b6f18 pc=0x47126e
runtime.gcBgMarkWorker(0xc0005bc000)
    /home/cuonglm/sources/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc0003b6fc8 sp=0xc0003b6f38 pc=0x41cf29
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/cuonglm/sources/go/src/runtime/mgc.go:1279 +0x25 fp=0xc0003b6fe0 sp=0xc0003b6fc8 pc=0x41ce05
runtime.goexit({})
    /home/cuonglm/sources/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0003b6fe8 sp=0xc0003b6fe0 pc=0x479121
created by runtime.gcBgMarkStartWorkers in goroutine 26
    /home/cuonglm/sources/go/src/runtime/mgc.go:1279 +0x105

goroutine 72 gp=0xc000584fc0 m=nil [GC worker (idle)]:
runtime.gopark(0x3fb44014a1d2?, 0x0?, 0x0?, 0x0?, 0x0?)
    /home/cuonglm/sources/go/src/runtime/proc.go:424 +0xce fp=0xc0003b7738 sp=0xc0003b7718 pc=0x47126e
runtime.gcBgMarkWorker(0xc0005bc000)
    /home/cuonglm/sources/go/src/runtime/mgc.go:1363 +0xe9 fp=0xc0003b77c8 sp=0xc0003b7738 pc=0x41cf29
runtime.gcBgMarkStartWorkers.gowrap1()
    /home/cuonglm/sources/go/src/runtime/mgc.go:1279 +0x25 fp=0xc0003b77e0 sp=0xc0003b77c8 pc=0x41ce05
runtime.goexit({})
    /home/cuonglm/sources/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0003b77e8 sp=0xc0003b77e0 pc=0x479121
created by runtime.gcBgMarkStartWorkers in goroutine 26
    /home/cuonglm/sources/go/src/runtime/mgc.go:1279 +0x105

goroutine 99 gp=0xc000626380 m=nil [IO wait]:
runtime.gopark(0x200?, 0x429b5b?, 0x80?, 0x3f?, 0xb?)
    /home/cuonglm/sources/go/src/runtime/proc.go:424 +0xce fp=0xc000510ba0 sp=0xc000510b80 pc=0x47126e
runtime.netpollblock(0x494c98?, 0x407f66?, 0x0?)
    /home/cuonglm/sources/go/src/runtime/netpoll.go:575 +0xf7 fp=0xc000510bd8 sp=0xc000510ba0 pc=0x4341d7
internal/poll.runtime_pollWait(0x7fa564eb9910, 0x72)
    /home/cuonglm/sources/go/src/runtime/netpoll.go:351 +0x85 fp=0xc000510bf8 sp=0xc000510bd8 pc=0x470565
internal/poll.(*pollDesc).wait(0xc0004b6540?, 0xc000300000?, 0x1)
    /home/cuonglm/sources/go/src/internal/poll/fd_poll_runtime.go:84 +0x27 fp=0xc000510c20 sp=0xc000510bf8 pc=0x4f12e7
internal/poll.(*pollDesc).waitRead(...)
    /home/cuonglm/sources/go/src/internal/poll/fd_poll_runtime.go:89
internal/poll.(*FD).Read(0xc0004b6540, {0xc000300000, 0x200, 0x200})
    /home/cuonglm/sources/go/src/internal/poll/fd_unix.go:165 +0x27a fp=0xc000510cb8 sp=0xc000510c20 pc=0x4f25da
os.(*File).read(...)
    /home/cuonglm/sources/go/src/os/file_posix.go:29
os.(*File).Read(0xc0004b4098, {0xc000300000?, 0x41af96?, 0x0?})
    /home/cuonglm/sources/go/src/os/file.go:124 +0x52 fp=0xc000510cf8 sp=0xc000510cb8 pc=0x4fe312
os.(*fileWithoutWriteTo).Read(0xc0004a61e0?, {0xc000300000?, 0x40e59f?, 0xa57e20?})
    :1 +0x25 fp=0xc000510d28 sp=0xc000510cf8 pc=0x508165
bytes.(*Buffer).ReadFrom(0xc0004a61e0, {0xc12c60, 0xc000622008})
    /home/cuonglm/sources/go/src/bytes/buffer.go:211 +0x98 fp=0xc000510d80 sp=0xc000510d28 pc=0x532b18
io.copyBuffer({0xc12e40, 0xc0004a61e0}, {0xc12c60, 0xc000622008}, {0x0, 0x0, 0x0})
    /home/cuonglm/sources/go/src/io/io.go:415 +0x151 fp=0xc000510df8 sp=0xc000510d80 pc=0x4e8871
io.Copy(...)
    /home/cuonglm/sources/go/src/io/io.go:388
os.genericWriteTo(0xc0004b4098?, {0xc12e40, 0xc0004a61e0})
    /home/cuonglm/sources/go/src/os/file.go:275 +0x4f fp=0xc000510e48 sp=0xc000510df8 pc=0x4fec4f
os.(*File).WriteTo(0xc0004b4098, {0xc12e40, 0xc0004a61e0})
    /home/cuonglm/sources/go/src/os/file.go:253 +0x9c fp=0xc000510e88 sp=0xc000510e48 pc=0x4feb7c
io.copyBuffer({0xc12e40, 0xc0004a61e0}, {0xc12b80, 0xc0004b4098}, {0x0, 0x0, 0x0})
    /home/cuonglm/sources/go/src/io/io.go:411 +0x9d fp=0xc000510f00 sp=0xc000510e88 pc=0x4e87bd
io.Copy(...)
    /home/cuonglm/sources/go/src/io/io.go:388
os/exec.(*Cmd).writerDescriptor.func1()
    /home/cuonglm/sources/go/src/os/exec/exec.go:580 +0x34 fp=0xc000510f60 sp=0xc000510f00 pc=0x538694
os/exec.(*Cmd).Start.func2(0xc0000627b0?)
    /home/cuonglm/sources/go/src/os/exec/exec.go:733 +0x2c fp=0xc000510fc8 sp=0xc000510f60 pc=0x53930c
os/exec.(*Cmd).Start.gowrap1()
    /home/cuonglm/sources/go/src/os/exec/exec.go:745 +0x24 fp=0xc000510fe0 sp=0xc000510fc8 pc=0x5392a4
runtime.goexit({})
    /home/cuonglm/sources/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc000510fe8 sp=0xc000510fe0 pc=0x479121
created by os/exec.(*Cmd).Start in goroutine 22
    /home/cuonglm/sources/go/src/os/exec/exec.go:732 +0x98b

rax    0xca
rbx    0x0
rcx    0x47af03
rdx    0x0
rdi    0xfd4fa0
rsi    0x80
rbp    0x7fff6a091900
rsp    0x7fff6a0918b8
r8     0x0
r9     0x0
r10    0x0
r11    0x286
r12    0x444b20
r13    0x0
r14    0xfd3140
r15    0x3ffffffffffff
rip    0x47af01
rflags 0x286
cs     0x33
fs     0x0
gs     0x0
cuonglm commented 2 months ago

FYI, it seems to only happen with the reproducer in #63285:

.
ā”œā”€ā”€ 68311.txt
ā”œā”€ā”€ go.mod
ā”œā”€ā”€ iterator
ā”‚Ā Ā  ā””ā”€ā”€ iterator.go
ā”œā”€ā”€ main.go
ā””ā”€ā”€ vector
    ā””ā”€ā”€ vector.go

2 directories, 5 files

Simple hello world or others compile/run just fine.

cuonglm commented 2 months ago

Oh, so I sent SIGQUIT to go build main.go, not the go tool compile. I checkout https://github.com/golang/go/commit/483a913a55215a063ee7a7f218e9ed8f3c7ba21b, then sending SIGQUIT to go tool compile command.

Output after sending SIGQUIT
{23:26}~/p:main āœ“ āž­ go build main.go                                       
# whatever/vector
SIGQUIT: quit
PC=0x486601 m=0 sigcode=0

goroutine 0 gp=0x189e420 m=0 mp=0x18a0cc0 [idle]:
runtime.futex(0x18a0e00, 0x80, 0x0, 0x0, 0x0, 0x0)
    ../sources/go/src/runtime/sys_linux_amd64.s:557 +0x21 fp=0x7ffe861990f0 sp=0x7ffe861990e8 pc=0x486601
runtime.futexsleep(0x0?, 0x86199170?, 0x411510?)
    ../sources/go/src/runtime/os_linux.go:69 +0x30 fp=0x7ffe86199140 sp=0x7ffe861990f0 pc=0x442b10
runtime.notesleep(...)
    ../sources/go/src/runtime/lock_futex.go:170
runtime.mPark()
    ../sources/go/src/runtime/proc.go:1805 +0x85 fp=0x7ffe86199180 sp=0x7ffe86199140 pc=0x44c105
runtime.stopm()
    ../sources/go/src/runtime/proc.go:2814 +0x71 fp=0x7ffe861991a8 sp=0x7ffe86199180 pc=0x44d831
runtime.findRunnable()
    ../sources/go/src/runtime/proc.go:3541 +0xe92 fp=0x7ffe86199370 sp=0x7ffe861991a8 pc=0x44f4f2
runtime.schedule()
    ../sources/go/src/runtime/proc.go:3914 +0xb1 fp=0x7ffe861993a8 sp=0x7ffe86199370 pc=0x450731
runtime.park_m(0xc0000061c0)
    ../sources/go/src/runtime/proc.go:4021 +0x1eb fp=0x7ffe86199400 sp=0x7ffe861993a8 pc=0x450b4b
runtime.mcall()
    ../sources/go/src/runtime/asm_amd64.s:458 +0x4e fp=0x7ffe86199418 sp=0x7ffe86199400 pc=0x48294e

goroutine 1 gp=0xc0000061c0 m=nil [sync.Mutex.Lock]:
runtime.gopark(0xc000111740?, 0xc000111788?, 0x0?, 0x80?, 0x460ad0?)
    ../sources/go/src/runtime/proc.go:401 +0xce fp=0xc000111590 sp=0xc000111570 pc=0x448fae
runtime.goparkunlock(...)
    ../sources/go/src/runtime/proc.go:407
runtime.semacquire1(0xc00043decc, 0x0, 0x3, 0x1, 0x15)
    ../sources/go/src/runtime/sema.go:160 +0x225 fp=0xc0001115f8 sp=0xc000111590 pc=0x45c4a5
sync.runtime_SemacquireMutex(0x1?, 0x90?, 0xc000441940?)
    ../sources/go/src/runtime/sema.go:77 +0x25 fp=0xc000111630 sp=0xc0001115f8 pc=0x480aa5
sync.(*Mutex).lockSlow(0xc00043dec8)
    ../sources/go/src/sync/mutex.go:171 +0x15d fp=0xc000111680 sp=0xc000111630 pc=0x4a317d
sync.(*Mutex).Lock(...)
    ../sources/go/src/sync/mutex.go:90
cmd/compile/internal/types2.(*Named).resolve(0xc00043dea0)
    ../sources/go/src/cmd/compile/internal/types2/named.go:165 +0x6c fp=0xc000111718 sp=0xc000111680 pc=0xdefc0c
cmd/compile/internal/types2.(*Named).TypeParams(...)
    ../sources/go/src/cmd/compile/internal/types2/named.go:311
cmd/compile/internal/types2.(*subster).typ(0xc000111f48, {0x11a5188, 0xc00044e1c0})
    ../sources/go/src/cmd/compile/internal/types2/subst.go:242 +0xb47 fp=0xc000111940 sp=0xc000111718 pc=0xe0e4e7
cmd/compile/internal/types2.(*subster).var_(0xc0000061c0?, 0xc00044e230)
    ../sources/go/src/cmd/compile/internal/types2/subst.go:304 +0x2c fp=0xc000111980 sp=0xc000111940 pc=0xe0f04c
cmd/compile/internal/types2.(*subster).varList(0xc000111f48, {0xc00006a760, 0x1, 0x0?})
    ../sources/go/src/cmd/compile/internal/types2/subst.go:330 +0x7b fp=0xc0001119e8 sp=0xc000111980 pc=0xe0f29b
cmd/compile/internal/types2.(*subster).tuple(0xffffffffffffffff?, 0xc000416900)
    ../sources/go/src/cmd/compile/internal/types2/subst.go:320 +0x2f fp=0xc000111a30 sp=0xc0001119e8 pc=0xe0f18f
cmd/compile/internal/types2.(*subster).typ(0xc000111f48, {0x11a5160, 0xc000441980})
    ../sources/go/src/cmd/compile/internal/types2/subst.go:155 +0x626 fp=0xc000111c58 sp=0xc000111a30 pc=0xe0dfc6
cmd/compile/internal/types2.(*subster).func_(0x12?, 0xc00044e2a0)
    ../sources/go/src/cmd/compile/internal/types2/subst.go:347 +0x2c fp=0xc000111c98 sp=0xc000111c58 pc=0xe0f3cc
cmd/compile/internal/types2.(*subster).funcList(0xc000111f48, {0xc0004168a0, 0x3, 0xc000111d70?})
    ../sources/go/src/cmd/compile/internal/types2/subst.go:364 +0x7b fp=0xc000111d00 sp=0xc000111c98 pc=0xe0f55b
cmd/compile/internal/types2.(*subster).typ(0xc000111f48, {0x11a51d8, 0xc0004463c0})
    ../sources/go/src/cmd/compile/internal/types2/subst.go:179 +0x752 fp=0xc000111f28 sp=0xc000111d00 pc=0xe0e0f2
cmd/compile/internal/types2.(*Checker).subst(0x0, {0x0?, 0x7ee80?, 0xc0?}, {0x11a51d8, 0xc0004463c0}, 0xc0001b5e60, 0xc00044e000, 0x0)
    ../sources/go/src/cmd/compile/internal/types2/subst.go:78 +0x1ad fp=0xc000111fc0 sp=0xc000111f28 pc=0xe0d90d
cmd/compile/internal/types2.(*Named).expandUnderlying(0xc00044e000)
    ../sources/go/src/cmd/compile/internal/types2/named.go:651 +0x4e9 fp=0xc0001120e0 sp=0xc000111fc0 pc=0xdf1f09
cmd/compile/internal/types2.(*Named).resolve(0xc00044e000)
    ../sources/go/src/cmd/compile/internal/types2/named.go:178 +0x165 fp=0xc000112178 sp=0xc0001120e0 pc=0xdefd05
cmd/compile/internal/types2.(*Named).Underlying(...)
    ../sources/go/src/cmd/compile/internal/types2/named.go:489
cmd/compile/internal/types2.(*Named).under(0xc00044e000)
    ../sources/go/src/cmd/compile/internal/types2/named.go:517 +0x2a fp=0xc000112350 sp=0xc000112178 pc=0xdf148a
cmd/compile/internal/types2.under({0x11a5188?, 0xc00044e000?})
    ../sources/go/src/cmd/compile/internal/types2/under.go:13 +0x9d fp=0xc000112370 sp=0xc000112350 pc=0xe1ba3d
cmd/compile/internal/types2.(*TypeParam).iface(0xc0001b5b60)
    ../sources/go/src/cmd/compile/internal/types2/typeparam.go:109 +0x31 fp=0xc0001123e0 sp=0xc000112370 pc=0xe10d51
cmd/compile/internal/types2.(*TypeParam).SetConstraint(...)
    ../sources/go/src/cmd/compile/internal/types2/typeparam.go:86
cmd/compile/internal/importer.(*reader).typeParamNames(0xc00043f2c0)
    ../sources/go/src/cmd/compile/internal/importer/ureader.go:514 +0x205 fp=0xc000112458 sp=0xc0001123e0 pc=0xe2bdc5
cmd/compile/internal/importer.(*pkgReader).objIdx.func1.1(0xfe09a9?)
    ../sources/go/src/cmd/compile/internal/importer/ureader.go:434 +0x25 fp=0xc0001124c8 sp=0xc000112458 pc=0xe2b6a5
cmd/compile/internal/types2.(*Named).resolve(0xc00043dea0)
    ../sources/go/src/cmd/compile/internal/types2/named.go:204 +0x109 fp=0xc000112560 sp=0xc0001124c8 pc=0xdefca9
cmd/compile/internal/types2.(*Named).TypeParams(...)
    ../sources/go/src/cmd/compile/internal/types2/named.go:311
cmd/compile/internal/types2.isGeneric({0x11a5188?, 0xc00043dea0?})
    ../sources/go/src/cmd/compile/internal/types2/predicates.go:141 +0x3c fp=0xc000112580 sp=0xc000112560 pc=0xdf6a1c
cmd/compile/internal/types2.(*Checker).genericType(0xc000007a40, {0x11aa920, 0xc000443c70}, 0xc0001126a8)
    ../sources/go/src/cmd/compile/internal/types2/typexpr.go:218 +0x9d fp=0xc0001125f8 sp=0xc000112580 pc=0xe1855d
cmd/compile/internal/types2.(*Checker).instantiatedType(0xc000007a40, {0x11aa920, 0xc000443c70}, {0xc00007eb60, 0x2, 0x2}, 0x0)
    ../sources/go/src/cmd/compile/internal/types2/typexpr.go:457 +0x1ea fp=0xc000112780 sp=0xc0001125f8 pc=0xe1a62a
cmd/compile/internal/types2.(*Checker).typInternal(0xc000007a40, {0x11aa8d8, 0xc00043e8a0}, 0x0)
    ../sources/go/src/cmd/compile/internal/types2/typexpr.go:297 +0xa18 fp=0xc000112908 sp=0xc000112780 pc=0xe19198
cmd/compile/internal/types2.(*Checker).definedType(...)
    ../sources/go/src/cmd/compile/internal/types2/typexpr.go:202
cmd/compile/internal/types2.(*Checker).varType(0xc000007a40, {0x11aa8d8, 0xc00043e8a0})
    ../sources/go/src/cmd/compile/internal/types2/typexpr.go:166 +0x32 fp=0xc000112988 sp=0xc000112908 pc=0xe177b2
cmd/compile/internal/types2.(*Checker).collectParams(...)
    ../sources/go/src/cmd/compile/internal/types2/signature.go:292
cmd/compile/internal/types2.(*Checker).funcType(0xc000007a40, 0xc000441540, 0xc0001b4cf0, {0x0, 0x0, 0x0}, 0xc00043cf50)
    ../sources/go/src/cmd/compile/internal/types2/signature.go:187 +0x120e fp=0xc000112cf8 sp=0xc000112988 pc=0xe0128e
cmd/compile/internal/types2.(*Checker).funcDecl(0xc000007a40, 0xc00043d3b0, 0xc00043eea0)
    ../sources/go/src/cmd/compile/internal/types2/decl.go:768 +0xdc fp=0xc000112d78 sp=0xc000112cf8 pc=0xdcf4fc
cmd/compile/internal/types2.(*Checker).objDecl(0xc000007a40, {0x11af840, 0xc00043d3b0}, 0x0)
    ../sources/go/src/cmd/compile/internal/types2/decl.go:193 +0x930 fp=0xc000112fb0 sp=0xc000112d78 pc=0xdcadb0
cmd/compile/internal/types2.(*Checker).packageObjects(...)
    ../sources/go/src/cmd/compile/internal/types2/resolver.go:726
cmd/compile/internal/types2.(*Checker).checkFiles(0xc000007a40, {0xc00006a610, 0x1, 0x1})
    ../sources/go/src/cmd/compile/internal/types2/check.go:445 +0x62d fp=0xc000113178 sp=0xc000112fb0 pc=0xdc366d
cmd/compile/internal/types2.(*Checker).Files(0x7ffe8619ad3b?, {0xc00006a610?, 0x0?, 0x0?})
    ../sources/go/src/cmd/compile/internal/types2/check.go:408 +0x75 fp=0xc0001131e0 sp=0xc000113178 pc=0xdc2f75
cmd/compile/internal/types2.(*Config).Check(0xc00043cfc0, {0x7ffe8619ad3b?, 0xc0000140d7?}, {0xc00006a610, 0x1, 0x1}, 0xc00043ea80)
    ../sources/go/src/cmd/compile/internal/types2/api.go:480 +0x66 fp=0xc000113218 sp=0xc0001131e0 pc=0xdb0c26
cmd/compile/internal/noder.checkFiles({0x0, {0x0, 0x0}}, {0xc00006a590, 0x1, 0xc0000cf538?})
    ../sources/go/src/cmd/compile/internal/noder/irgen.go:91 +0x5c9 fp=0xc000113480 sp=0xc000113218 pc=0xe37189
cmd/compile/internal/noder.writePkgStub({0x0?, {0x0?, 0x0?}}, {0xc00006a590, 0x1, 0x1})
    ../sources/go/src/cmd/compile/internal/noder/unified.go:307 +0x6a fp=0xc000113798 sp=0xc000113480 pc=0xe5bbea
cmd/compile/internal/noder.unified({0x0?, {0x0?, 0x0?}}, {0xc00006a590?, 0xee5960?, 0x0?})
    ../sources/go/src/cmd/compile/internal/noder/unified.go:183 +0x9a fp=0xc000113940 sp=0xc000113798 pc=0xe5b15a
cmd/compile/internal/noder.LoadPackage({0xc000024220, 0x1, 0x2})
    ../sources/go/src/cmd/compile/internal/noder/noder.go:77 +0x43a fp=0xc000113a68 sp=0xc000113940 pc=0xe3c1ba
cmd/compile/internal/gc.Main(0x1048ed0)
    ../sources/go/src/cmd/compile/internal/gc/main.go:200 +0xbed fp=0xc000113ef0 sp=0xc000113a68 pc=0xe8ad6d
main.main()
    ../sources/go/src/cmd/compile/main.go:57 +0xf9 fp=0xc000113f50 sp=0xc000113ef0 pc=0xeb48b9
runtime.main()
    ../sources/go/src/runtime/proc.go:270 +0x28b fp=0xc000113fe0 sp=0xc000113f50 pc=0x448b4b
runtime.goexit({})
    ../sources/go/src/runtime/asm_amd64.s:1699 +0x1 fp=0xc000113fe8 sp=0xc000113fe0 pc=0x484801

goroutine 2 gp=0xc000006700 m=nil [force gc (idle)]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
    ../sources/go/src/runtime/proc.go:401 +0xce fp=0xc000066fa8 sp=0xc000066f88 pc=0x448fae
runtime.goparkunlock(...)
    ../sources/go/src/runtime/proc.go:407
runtime.forcegchelper()
    ../sources/go/src/runtime/proc.go:325 +0xb3 fp=0xc000066fe0 sp=0xc000066fa8 pc=0x448e13
runtime.goexit({})
    ../sources/go/src/runtime/asm_amd64.s:1699 +0x1 fp=0xc000066fe8 sp=0xc000066fe0 pc=0x484801
created by runtime.init.6 in goroutine 1
    ../sources/go/src/runtime/proc.go:313 +0x1a

goroutine 3 gp=0xc000006c40 m=nil [GC sweep wait]:
runtime.gopark(0xc00007c000?, 0x119ac00?, 0x0?, 0x0?, 0x0?)
    ../sources/go/src/runtime/proc.go:401 +0xce fp=0xc000067750 sp=0xc000067730 pc=0x448fae
runtime.goparkunlock(...)
    ../sources/go/src/runtime/proc.go:407
runtime.bgsweep(0xc00007c000)
    ../sources/go/src/runtime/mgcsweep.go:277 +0x94 fp=0xc0000677c8 sp=0xc000067750 pc=0x430af4
runtime.gcenable.gowrap1()
    ../sources/go/src/runtime/mgc.go:203 +0x25 fp=0xc0000677e0 sp=0xc0000677c8 pc=0x424345
runtime.goexit({})
    ../sources/go/src/runtime/asm_amd64.s:1699 +0x1 fp=0xc0000677e8 sp=0xc0000677e0 pc=0x484801
created by runtime.gcenable in goroutine 1
    ../sources/go/src/runtime/mgc.go:203 +0x66

goroutine 4 gp=0xc000006e00 m=nil [GC scavenge wait]:
runtime.gopark(0xc00007c060?, 0x0?, 0x80?, 0xa2?, 0xc00007c000?)
    ../sources/go/src/runtime/proc.go:401 +0xce fp=0xc000067f78 sp=0xc000067f58 pc=0x448fae
runtime.goparkunlock(...)
    ../sources/go/src/runtime/proc.go:407
runtime.(*scavengerState).park(0x189dba0)
    ../sources/go/src/runtime/mgcscavenge.go:425 +0x49 fp=0xc000067fa8 sp=0xc000067f78 pc=0x42dd89
runtime.bgscavenge(0xc00007c000)
    ../sources/go/src/runtime/mgcscavenge.go:653 +0x3c fp=0xc000067fc8 sp=0xc000067fa8 pc=0x42e2fc
runtime.gcenable.gowrap2()
    ../sources/go/src/runtime/mgc.go:204 +0x25 fp=0xc000067fe0 sp=0xc000067fc8 pc=0x4242e5
runtime.goexit({})
    ../sources/go/src/runtime/asm_amd64.s:1699 +0x1 fp=0xc000067fe8 sp=0xc000067fe0 pc=0x484801
created by runtime.gcenable in goroutine 1
    ../sources/go/src/runtime/mgc.go:204 +0xa5

goroutine 5 gp=0xc000007340 m=nil [finalizer wait]:
runtime.gopark(0x48?, 0x490010?, 0xd8?, 0x66?, 0x41368f?)
    ../sources/go/src/runtime/proc.go:401 +0xce fp=0xc000066620 sp=0xc000066600 pc=0x448fae
runtime.runfinq()
    ../sources/go/src/runtime/mfinal.go:193 +0x107 fp=0xc0000667e0 sp=0xc000066620 pc=0x423227
runtime.goexit({})
    ../sources/go/src/runtime/asm_amd64.s:1699 +0x1 fp=0xc0000667e8 sp=0xc0000667e0 pc=0x484801
created by runtime.createfing in goroutine 1
    ../sources/go/src/runtime/mfinal.go:163 +0x3d

goroutine 6 gp=0xc000007500 m=nil [chan receive]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
    ../sources/go/src/runtime/proc.go:401 +0xce fp=0xc000068718 sp=0xc0000686f8 pc=0x448fae
runtime.chanrecv(0xc0000940e0, 0x0, 0x1)
    ../sources/go/src/runtime/chan.go:629 +0x41c fp=0xc000068790 sp=0xc000068718 pc=0x40b53c
runtime.chanrecv1(0x0?, 0x0?)
    ../sources/go/src/runtime/chan.go:479 +0x12 fp=0xc0000687b8 sp=0xc000068790 pc=0x40b0f2
runtime.unique_runtime_registerUniqueMapCleanup.func1(...)
    ../sources/go/src/runtime/mgc.go:1712
runtime.unique_runtime_registerUniqueMapCleanup.gowrap1()
    ../sources/go/src/runtime/mgc.go:1715 +0x2f fp=0xc0000687e0 sp=0xc0000687b8 pc=0x42732f
runtime.goexit({})
    ../sources/go/src/runtime/asm_amd64.s:1699 +0x1 fp=0xc0000687e8 sp=0xc0000687e0 pc=0x484801
created by unique.runtime_registerUniqueMapCleanup in goroutine 1
    ../sources/go/src/runtime/mgc.go:1710 +0x96

rax    0xca
rbx    0x0
rcx    0x486603
rdx    0x0
rdi    0x18a0e00
rsi    0x80
rbp    0x7ffe86199130
rsp    0x7ffe861990e8
r8     0x0
r9     0x0
r10    0x0
r11    0x286
r12    0x1
r13    0xa0761d6478bd642f
r14    0x189e420
r15    0x6
rip    0x486601
rflags 0x286
cs     0x33
fs     0x0
gs     0x0
findleyr commented 2 months ago

@cuonglm it looks quite like you are reproducing #63285, in other words: you are seeing a hang in go/types.

Now to figure out how telemetry is related at all. What happens before the bisection point? I understand it doesn't hang, but presumably the go/types bug still exists. What type of error do you get?

cuonglm commented 2 months ago

@cuonglm it looks quite like you are reproducing #63285, in other words: you are seeing a hang in go/types.

Now to figure out how telemetry is related at all. What happens before the bisection point? I understand it doesn't hang, but presumably the go/types bug still exists. What type of error do you get?

I got the same error reported in #63285 with 805f6b3f5db714ce8f7dae2776748f6df96f288b:

fatal error: all goroutines are asleep - deadlock!

With 483a913a55215a063ee7a7f218e9ed8f3c7ba21b, go build main.go starts hanging.

cuonglm commented 2 months ago

So I tried removing all telemetry code in cmd/compile, go build does not hang anymore:

diff --git a/src/cmd/compile/internal/base/print.go b/src/cmd/compile/internal/base/print.go
index 119f06fbc0..21df275bcd 100644
--- a/src/cmd/compile/internal/base/print.go
+++ b/src/cmd/compile/internal/base/print.go
@@ -14,7 +14,6 @@ import (
        "strings"

        "cmd/internal/src"
-       "cmd/internal/telemetry/counter"
 )

 // An errorMsg is a queued error message, waiting to be printed.
@@ -195,8 +194,6 @@ func Fatalf(format string, args ...interface{}) {
        FatalfAt(Pos, format, args...)
 }

-var bugStack = counter.NewStack("compile/bug", 16) // 16 is arbitrary; used by gopls and crashmonitor
-
 // FatalfAt reports a fatal error - an internal problem - at pos and exits.
 // If other errors have already been printed, then FatalfAt just quietly exits.
 // (The internal problem may have been caused by incomplete information
@@ -212,7 +209,7 @@ var bugStack = counter.NewStack("compile/bug", 16) // 16 is arbitrary; used by g
 func FatalfAt(pos src.XPos, format string, args ...interface{}) {
        FlushErrors()

-       bugStack.Inc()
+       //bugStack.Inc()

        if Debug.Panic != 0 || numErrors == 0 {
                fmt.Printf("%v: internal compiler error: ", FmtPos(pos))
diff --git a/src/cmd/compile/internal/gc/main.go b/src/cmd/compile/internal/gc/main.go
index f68cf4deaf..7f6559b0af 100644
--- a/src/cmd/compile/internal/gc/main.go
+++ b/src/cmd/compile/internal/gc/main.go
@@ -30,7 +30,6 @@ import (
        "cmd/internal/obj"
        "cmd/internal/objabi"
        "cmd/internal/src"
-       "cmd/internal/telemetry/counter"
        "flag"
        "fmt"
        "internal/buildcfg"
@@ -59,8 +58,8 @@ func handlePanic() {
 // code, and finally writes the compiled package definition to disk.
 func Main(archInit func(*ssagen.ArchInfo)) {
        base.Timer.Start("fe", "init")
-       counter.Open()
-       counter.Inc("compile/invocations")
+       //counter.Open()
+       //counter.Inc("compile/invocations")

        defer handlePanic()
findleyr commented 2 months ago

I got the same error reported in https://github.com/golang/go/issues/63285 with https://github.com/golang/go/commit/805f6b3f5db714ce8f7dae2776748f6df96f288b:

(sorry, should have assumed as much)

Ok, my guess is that the timer to rotate the counter file breaks deadlock detection. https://go.googlesource.com/telemetry/+/refs/heads/master/internal/counter/file.go#192

findleyr commented 2 months ago

Thanks for reporting. Filed as #68497.