Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Deadlock during publishing #1305

Open
russelltg opened this issue Jun 19, 2024 · 20 comments
Open

Deadlock during publishing #1305

russelltg opened this issue Jun 19, 2024 · 20 comments
Assignees
Labels
bug please confirm resolved We believe the issue is resolved ! if so, please close the issue, thanks ;-)

Comments

@russelltg
Copy link
Contributor

russelltg commented Jun 19, 2024

We recently updated our aptly to nightly to get #1271 which we ran into a bunch, but woke up today to 2 builds hung during publish. We use the REST api.

Context

$ aptly version
aptly version: '1.5.0+145+gb5bf2cbc'

I did save a core file, are there binaries with symbols available? Happy to update this with backtraces if I can get symbols....

@neolynx neolynx self-assigned this Jun 19, 2024
@neolynx
Copy link
Member

neolynx commented Jun 19, 2024

We merged a bunch of PRs lately, but did not observe this so far. are you using async mode for the rest API (i.e. getting a task.ID and waiting for it) ?

I would suspect the queue to somehow miss a task or not finish in here: 4503580

What distribution are you on ?

goxz is still used for building: https://github.com/aptly-dev/aptly/actions/runs/9545612734/job/26307439641, not sure how to get the symbols there.

@russelltg
Copy link
Contributor Author

I'm on Ubuntu 22.04, and no we do not use async mode--would this be preferable?

@neolynx
Copy link
Member

neolynx commented Jun 19, 2024

I would not use async mode, if your code does not need to do other things in parallel.

the nightly builds should come with debug symbols in the aptly binary:

file usr/bin/aptly 
usr/bin/aptly: ELF 64-bit LSB executable, x86-64, version 1 (SYSV), dynamically linked, interpreter /lib64/ld-linux-x86-64.so.2, Go BuildID=ZT3f2ryYxkeZgzWX4wzJ/qqXbXU1wLzvIZnQpg7Aw/qXraYWmrhjFAhqoaFH6U/GWQWRDivHfWPRXQKJvVH, with debug_info, not stripped

so you should be able to analyze the core dump, maybe you need to have the source code in the working dir.

@russelltg
Copy link
Contributor Author

It seems there is only debug symbols for the runtime itself:

Stacks of all threads

(gdb) thread apply all bt

Thread 20 (LWP 22091):
#0  runtime.futex () at /__t/go/1.21.11/x64/src/runtime/sys_linux_amd64.s:558
#1  0x0000000000436cf0 in runtime.futexsleep (addr=0xfffffffffffffe00, val=0, ns=4650275) at /__t/go/1.21.11/x64/src/runtime/os_linux.go:69
#2  0x000000000040ecc7 in runtime.notesleep (n=0xc000075548) at /__t/go/1.21.11/x64/src/runtime/lock_futex.go:160
#3  0x00000000004414ec in runtime.mPark () at /__t/go/1.21.11/x64/src/runtime/proc.go:1634
#4  runtime.stopm () at /__t/go/1.21.11/x64/src/runtime/proc.go:2531
#5  0x00000000004458b6 in runtime.exitsyscall0 (gp=0xc0001be9c0) at /__t/go/1.21.11/x64/src/runtime/proc.go:4353
#6  0x000000000046b88e in runtime.mcall () at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:458
#7  0x0000000000000000 in ?? ()

Thread 19 (LWP 22090):
#0  runtime.futex () at /__t/go/1.21.11/x64/src/runtime/sys_linux_amd64.s:558
#1  0x0000000000436cf0 in runtime.futexsleep (addr=0xfffffffffffffe00, val=0, ns=4650275) at /__t/go/1.21.11/x64/src/runtime/os_linux.go:69
#2  0x000000000040ecc7 in runtime.notesleep (n=0xc000100948) at /__t/go/1.21.11/x64/src/runtime/lock_futex.go:160
#3  0x00000000004414ec in runtime.mPark () at /__t/go/1.21.11/x64/src/runtime/proc.go:1634
#4  runtime.stopm () at /__t/go/1.21.11/x64/src/runtime/proc.go:2531
#5  0x0000000000442e1c in runtime.findRunnable (gp=<optimized out>, inheritTime=<optimized out>, tryWakeP=<optimized out>) at /__t/go/1.21.11/x64/src/runtime/proc.go:3224
#6  0x0000000000443c11 in runtime.schedule () at /__t/go/1.21.11/x64/src/runtime/proc.go:3577
#7  0x000000000044411f in runtime.park_m (gp=0xc0011dc820) at /__t/go/1.21.11/x64/src/runtime/proc.go:3740
#8  0x000000000046b88e in runtime.mcall () at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:458
#9  0x0000000000000000 in ?? ()

Thread 18 (LWP 3802830):
#0  runtime/internal/syscall.Syscall6 () at /__t/go/1.21.11/x64/src/runtime/internal/syscall/asm_linux_amd64.s:36
#1  0x0000000000407185 in runtime/internal/syscall.EpollWait (epfd=<optimized out>, events=..., maxev=<optimized out>, waitms=<optimized out>, n=<optimized out>, errno=<optimized out>) at /__t/go/1.21.11/x64/src/runtime/internal/syscall/syscall_linux.go:55
#2  0x0000000000436a2b in runtime.netpoll (delay=<optimized out>, ~r0=...) at /__t/go/1.21.11/x64/src/runtime/netpoll_epoll.go:118
#3  0x0000000000442aa5 in runtime.findRunnable (gp=<optimized out>, inheritTime=<optimized out>, tryWakeP=<optimized out>) at /__t/go/1.21.11/x64/src/runtime/proc.go:3186
#4  0x0000000000443c11 in runtime.schedule () at /__t/go/1.21.11/x64/src/runtime/proc.go:3577
#5  0x000000000044411f in runtime.park_m (gp=0xc0011dc820) at /__t/go/1.21.11/x64/src/runtime/proc.go:3740
#6  0x000000000046b88e in runtime.mcall () at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:458
#7  0x0000000000000000 in ?? ()

Thread 17 (LWP 3802829):
#0  runtime.futex () at /__t/go/1.21.11/x64/src/runtime/sys_linux_amd64.s:558
#1  0x0000000000436cf0 in runtime.futexsleep (addr=0xfffffffffffffe00, val=0, ns=4650275) at /__t/go/1.21.11/x64/src/runtime/os_linux.go:69
#2  0x000000000040ecc7 in runtime.notesleep (n=0xc00089a948) at /__t/go/1.21.11/x64/src/runtime/lock_futex.go:160
#3  0x00000000004414ec in runtime.mPark () at /__t/go/1.21.11/x64/src/runtime/proc.go:1634
#4  runtime.stopm () at /__t/go/1.21.11/x64/src/runtime/proc.go:2531
#5  0x0000000000442e1c in runtime.findRunnable (gp=<optimized out>, inheritTime=<optimized out>, tryWakeP=<optimized out>) at /__t/go/1.21.11/x64/src/runtime/proc.go:3224
#6  0x0000000000443c11 in runtime.schedule () at /__t/go/1.21.11/x64/src/runtime/proc.go:3577
#7  0x00000000004458bb in runtime.exitsyscall0 (gp=0xc000682b60) at /__t/go/1.21.11/x64/src/runtime/proc.go:4354
#8  0x000000000046b88e in runtime.mcall () at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:458
#9  0x0000000000000000 in ?? ()

Thread 16 (LWP 3776910):
#0  runtime.futex () at /__t/go/1.21.11/x64/src/runtime/sys_linux_amd64.s:558
#1  0x0000000000436cf0 in runtime.futexsleep (addr=0xfffffffffffffe00, val=0, ns=4650275) at /__t/go/1.21.11/x64/src/runtime/os_linux.go:69
#2  0x000000000040ecc7 in runtime.notesleep (n=0xc000100548) at /__t/go/1.21.11/x64/src/runtime/lock_futex.go:160
#3  0x00000000004414ec in runtime.mPark () at /__t/go/1.21.11/x64/src/runtime/proc.go:1634
#4  runtime.stopm () at /__t/go/1.21.11/x64/src/runtime/proc.go:2531
#5  0x0000000000442e1c in runtime.findRunnable (gp=<optimized out>, inheritTime=<optimized out>, tryWakeP=<optimized out>) at /__t/go/1.21.11/x64/src/runtime/proc.go:3224
#6  0x0000000000443c11 in runtime.schedule () at /__t/go/1.21.11/x64/src/runtime/proc.go:3577
#7  0x0000000000444b26 in runtime.goexit0 (gp=0xc000603520) at /__t/go/1.21.11/x64/src/runtime/proc.go:3916
#8  0x000000000046b88e in runtime.mcall () at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:458
#9  0x0000000000000000 in ?? ()

Thread 15 (LWP 3626458):
#0  runtime.futex () at /__t/go/1.21.11/x64/src/runtime/sys_linux_amd64.s:558
#1  0x0000000000436cf0 in runtime.futexsleep (addr=0xfffffffffffffe00, val=0, ns=4650275) at /__t/go/1.21.11/x64/src/runtime/os_linux.go:69
#2  0x000000000040ecc7 in runtime.notesleep (n=0xc000681148) at /__t/go/1.21.11/x64/src/runtime/lock_futex.go:160
#3  0x00000000004414ec in runtime.mPark () at /__t/go/1.21.11/x64/src/runtime/proc.go:1634
#4  runtime.stopm () at /__t/go/1.21.11/x64/src/runtime/proc.go:2531
#5  0x0000000000442e1c in runtime.findRunnable (gp=<optimized out>, inheritTime=<optimized out>, tryWakeP=<optimized out>) at /__t/go/1.21.11/x64/src/runtime/proc.go:3224
#6  0x0000000000443c11 in runtime.schedule () at /__t/go/1.21.11/x64/src/runtime/proc.go:3577
#7  0x000000000044411f in runtime.park_m (gp=0xc0001024e0) at /__t/go/1.21.11/x64/src/runtime/proc.go:3740
#8  0x000000000046b88e in runtime.mcall () at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:458
#9  0x0000000000000000 in ?? ()

Thread 14 (LWP 3623636):
#0  runtime.futex () at /__t/go/1.21.11/x64/src/runtime/sys_linux_amd64.s:558
#1  0x0000000000436cf0 in runtime.futexsleep (addr=0xfffffffffffffe00, val=0, ns=4650275) at /__t/go/1.21.11/x64/src/runtime/os_linux.go:69
#2  0x000000000040ecc7 in runtime.notesleep (n=0xc00089a148) at /__t/go/1.21.11/x64/src/runtime/lock_futex.go:160
#3  0x00000000004414ec in runtime.mPark () at /__t/go/1.21.11/x64/src/runtime/proc.go:1634
#4  runtime.stopm () at /__t/go/1.21.11/x64/src/runtime/proc.go:2531
#5  0x0000000000442e1c in runtime.findRunnable (gp=<optimized out>, inheritTime=<optimized out>, tryWakeP=<optimized out>) at /__t/go/1.21.11/x64/src/runtime/proc.go:3224
#6  0x0000000000443c11 in runtime.schedule () at /__t/go/1.21.11/x64/src/runtime/proc.go:3577
#7  0x000000000044411f in runtime.park_m (gp=0xc000007520) at /__t/go/1.21.11/x64/src/runtime/proc.go:3740
#8  0x000000000046b88e in runtime.mcall () at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:458
#9  0x0000000000000000 in ?? ()

Thread 13 (LWP 3623580):
#0  runtime.futex () at /__t/go/1.21.11/x64/src/runtime/sys_linux_amd64.s:558
--Type <RET> for more, q to quit, c to continue without paging--c
#1  0x0000000000436cf0 in runtime.futexsleep (addr=0xfffffffffffffe00, val=0, ns=4650275) at /__t/go/1.21.11/x64/src/runtime/os_linux.go:69
#2  0x000000000040ecc7 in runtime.notesleep (n=0xc00068c148) at /__t/go/1.21.11/x64/src/runtime/lock_futex.go:160
#3  0x00000000004414ec in runtime.mPark () at /__t/go/1.21.11/x64/src/runtime/proc.go:1634
#4  runtime.stopm () at /__t/go/1.21.11/x64/src/runtime/proc.go:2531
#5  0x00000000004458b6 in runtime.exitsyscall0 (gp=0xc002426000) at /__t/go/1.21.11/x64/src/runtime/proc.go:4353
#6  0x000000000046b88e in runtime.mcall () at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:458
#7  0x0000000000000000 in ?? ()

Thread 12 (LWP 3623579):
#0  runtime.futex () at /__t/go/1.21.11/x64/src/runtime/sys_linux_amd64.s:558
#1  0x0000000000436cf0 in runtime.futexsleep (addr=0xfffffffffffffe00, val=0, ns=4650275) at /__t/go/1.21.11/x64/src/runtime/os_linux.go:69
#2  0x000000000040ecc7 in runtime.notesleep (n=0xc0001d8148) at /__t/go/1.21.11/x64/src/runtime/lock_futex.go:160
#3  0x00000000004414ec in runtime.mPark () at /__t/go/1.21.11/x64/src/runtime/proc.go:1634
#4  runtime.stopm () at /__t/go/1.21.11/x64/src/runtime/proc.go:2531
#5  0x0000000000442e1c in runtime.findRunnable (gp=<optimized out>, inheritTime=<optimized out>, tryWakeP=<optimized out>) at /__t/go/1.21.11/x64/src/runtime/proc.go:3224
#6  0x0000000000443c11 in runtime.schedule () at /__t/go/1.21.11/x64/src/runtime/proc.go:3577
#7  0x000000000044411f in runtime.park_m (gp=0xc0001bfa00) at /__t/go/1.21.11/x64/src/runtime/proc.go:3740
#8  0x000000000046b88e in runtime.mcall () at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:458
#9  0x0000000000000000 in ?? ()

Thread 11 (LWP 3623578):
#0  runtime.futex () at /__t/go/1.21.11/x64/src/runtime/sys_linux_amd64.s:558
#1  0x0000000000436cf0 in runtime.futexsleep (addr=0xfffffffffffffe00, val=0, ns=4650275) at /__t/go/1.21.11/x64/src/runtime/os_linux.go:69
#2  0x000000000040ecc7 in runtime.notesleep (n=0xc000680548) at /__t/go/1.21.11/x64/src/runtime/lock_futex.go:160
#3  0x00000000004414ec in runtime.mPark () at /__t/go/1.21.11/x64/src/runtime/proc.go:1634
#4  runtime.stopm () at /__t/go/1.21.11/x64/src/runtime/proc.go:2531
#5  0x0000000000442e1c in runtime.findRunnable (gp=<optimized out>, inheritTime=<optimized out>, tryWakeP=<optimized out>) at /__t/go/1.21.11/x64/src/runtime/proc.go:3224
#6  0x0000000000443c11 in runtime.schedule () at /__t/go/1.21.11/x64/src/runtime/proc.go:3577
#7  0x000000000044411f in runtime.park_m (gp=0xc0001bfa00) at /__t/go/1.21.11/x64/src/runtime/proc.go:3740
#8  0x000000000046b88e in runtime.mcall () at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:458
#9  0x0000000000000000 in ?? ()

Thread 10 (LWP 3409221):
#0  runtime.futex () at /__t/go/1.21.11/x64/src/runtime/sys_linux_amd64.s:558
#1  0x0000000000436cf0 in runtime.futexsleep (addr=0xfffffffffffffe00, val=0, ns=4650275) at /__t/go/1.21.11/x64/src/runtime/os_linux.go:69
#2  0x000000000040ecc7 in runtime.notesleep (n=0x1d6dcf8 <runtime[newmHandoff]+24>) at /__t/go/1.21.11/x64/src/runtime/lock_futex.go:160
#3  0x00000000004413d1 in runtime.templateThread () at /__t/go/1.21.11/x64/src/runtime/proc.go:2509
#4  0x000000000043ffd3 in runtime.mstart1 () at /__t/go/1.21.11/x64/src/runtime/proc.go:1602
#5  0x000000000043ff16 in runtime.mstart0 () at /__t/go/1.21.11/x64/src/runtime/proc.go:1559
#6  0x000000000046b805 in runtime.mstart () at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:394
#7  0x000000000046f5cf in runtime.clone () at /__t/go/1.21.11/x64/src/runtime/sys_linux_amd64.s:618
#8  0x0000000000000081 in ?? ()
#9  0x00000000012be860 in type:* ()
#10 0x00000000010fc460 in type:* ()
#11 0x0000000000000000 in ?? ()

Thread 9 (LWP 3409220):
#0  runtime.futex () at /__t/go/1.21.11/x64/src/runtime/sys_linux_amd64.s:558
#1  0x0000000000436cf0 in runtime.futexsleep (addr=0xfffffffffffffe00, val=0, ns=4650275) at /__t/go/1.21.11/x64/src/runtime/os_linux.go:69
#2  0x000000000040ecc7 in runtime.notesleep (n=0xc000074d48) at /__t/go/1.21.11/x64/src/runtime/lock_futex.go:160
#3  0x00000000004414ec in runtime.mPark () at /__t/go/1.21.11/x64/src/runtime/proc.go:1634
#4  runtime.stopm () at /__t/go/1.21.11/x64/src/runtime/proc.go:2531
#5  0x0000000000442e1c in runtime.findRunnable (gp=<optimized out>, inheritTime=<optimized out>, tryWakeP=<optimized out>) at /__t/go/1.21.11/x64/src/runtime/proc.go:3224
#6  0x0000000000443c11 in runtime.schedule () at /__t/go/1.21.11/x64/src/runtime/proc.go:3577
#7  0x000000000044411f in runtime.park_m (gp=0xc0001bfba0) at /__t/go/1.21.11/x64/src/runtime/proc.go:3740
#8  0x000000000046b88e in runtime.mcall () at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:458
#9  0x0000000000000000 in ?? ()

Thread 8 (LWP 3409219):
#0  runtime.futex () at /__t/go/1.21.11/x64/src/runtime/sys_linux_amd64.s:558
#1  0x0000000000436cf0 in runtime.futexsleep (addr=0xfffffffffffffe00, val=0, ns=4650275) at /__t/go/1.21.11/x64/src/runtime/os_linux.go:69
#2  0x000000000040ecc7 in runtime.notesleep (n=0xc000680148) at /__t/go/1.21.11/x64/src/runtime/lock_futex.go:160
#3  0x00000000004414ec in runtime.mPark () at /__t/go/1.21.11/x64/src/runtime/proc.go:1634
#4  runtime.stopm () at /__t/go/1.21.11/x64/src/runtime/proc.go:2531
#5  0x0000000000442e1c in runtime.findRunnable (gp=<optimized out>, inheritTime=<optimized out>, tryWakeP=<optimized out>) at /__t/go/1.21.11/x64/src/runtime/proc.go:3224
#6  0x0000000000443c11 in runtime.schedule () at /__t/go/1.21.11/x64/src/runtime/proc.go:3577
#7  0x000000000044411f in runtime.park_m (gp=0xc000006d00) at /__t/go/1.21.11/x64/src/runtime/proc.go:3740
#8  0x000000000046b88e in runtime.mcall () at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:458
#9  0x0000000000000000 in ?? ()

Thread 7 (LWP 3409218):
#0  runtime.futex () at /__t/go/1.21.11/x64/src/runtime/sys_linux_amd64.s:558
#1  0x0000000000436cf0 in runtime.futexsleep (addr=0xfffffffffffffe00, val=0, ns=4650275) at /__t/go/1.21.11/x64/src/runtime/os_linux.go:69
#2  0x000000000040ecc7 in runtime.notesleep (n=0xc000600148) at /__t/go/1.21.11/x64/src/runtime/lock_futex.go:160
#3  0x00000000004414ec in runtime.mPark () at /__t/go/1.21.11/x64/src/runtime/proc.go:1634
#4  runtime.stopm () at /__t/go/1.21.11/x64/src/runtime/proc.go:2531
#5  0x00000000004458b6 in runtime.exitsyscall0 (gp=0xc0011dda00) at /__t/go/1.21.11/x64/src/runtime/proc.go:4353
#6  0x000000000046b88e in runtime.mcall () at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:458
#7  0x0000000000000000 in ?? ()

Thread 6 (LWP 3409217):
#0  runtime.futex () at /__t/go/1.21.11/x64/src/runtime/sys_linux_amd64.s:558
#1  0x0000000000436cf0 in runtime.futexsleep (addr=0xfffffffffffffe00, val=0, ns=4650275) at /__t/go/1.21.11/x64/src/runtime/os_linux.go:69
#2  0x000000000040ecc7 in runtime.notesleep (n=0xc000580148) at /__t/go/1.21.11/x64/src/runtime/lock_futex.go:160
#3  0x0000000000441d53 in runtime.mPark () at /__t/go/1.21.11/x64/src/runtime/proc.go:1634
#4  runtime.stoplockedm () at /__t/go/1.21.11/x64/src/runtime/proc.go:2775
#5  0x0000000000443b9a in runtime.schedule () at /__t/go/1.21.11/x64/src/runtime/proc.go:3556
#6  0x000000000044411f in runtime.park_m (gp=0xc0001beb60) at /__t/go/1.21.11/x64/src/runtime/proc.go:3740
#7  0x000000000046b88e in runtime.mcall () at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:458
#8  0x0000000000000000 in ?? ()

Thread 5 (LWP 3409216):
#0  runtime.futex () at /__t/go/1.21.11/x64/src/runtime/sys_linux_amd64.s:558
#1  0x0000000000436cf0 in runtime.futexsleep (addr=0xfffffffffffffe00, val=0, ns=4650275) at /__t/go/1.21.11/x64/src/runtime/os_linux.go:69
#2  0x000000000040ecc7 in runtime.notesleep (n=0xc000100148) at /__t/go/1.21.11/x64/src/runtime/lock_futex.go:160
#3  0x00000000004414ec in runtime.mPark () at /__t/go/1.21.11/x64/src/runtime/proc.go:1634
#4  runtime.stopm () at /__t/go/1.21.11/x64/src/runtime/proc.go:2531
#5  0x0000000000442e1c in runtime.findRunnable (gp=<optimized out>, inheritTime=<optimized out>, tryWakeP=<optimized out>) at /__t/go/1.21.11/x64/src/runtime/proc.go:3224
#6  0x0000000000443c11 in runtime.schedule () at /__t/go/1.21.11/x64/src/runtime/proc.go:3577
#7  0x000000000044411f in runtime.park_m (gp=0xc000102340) at /__t/go/1.21.11/x64/src/runtime/proc.go:3740
#8  0x000000000046b88e in runtime.mcall () at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:458
#9  0x0000000000000000 in ?? ()

Thread 4 (LWP 3409215):
#0  runtime.futex () at /__t/go/1.21.11/x64/src/runtime/sys_linux_amd64.s:558
#1  0x0000000000436cf0 in runtime.futexsleep (addr=0xfffffffffffffe00, val=0, ns=4650275) at /__t/go/1.21.11/x64/src/runtime/os_linux.go:69
#2  0x000000000040eeb5 in runtime.notetsleep_internal (n=0x1d6de80 <runtime[sig]>, ns=-1, ~r0=<optimized out>) at /__t/go/1.21.11/x64/src/runtime/lock_futex.go:183
#3  0x000000000040efb8 in runtime.notetsleepg (n=0x1d6de80 <runtime[sig]>, ns=-1, ~r0=<optimized out>) at /__t/go/1.21.11/x64/src/runtime/lock_futex.go:237
#4  0x000000000046a1e9 in os/signal.signal_recv (~r0=<optimized out>) at /__t/go/1.21.11/x64/src/runtime/sigqueue.go:152
#5  0x00000000007879b3 in os/signal.loop () at /__t/go/1.21.11/x64/src/os/signal/signal_unix.go:23
#6  0x000000000046d701 in runtime.goexit () at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
#7  0x0000000000000000 in ?? ()

Thread 3 (LWP 3409214):
#0  runtime.futex () at /__t/go/1.21.11/x64/src/runtime/sys_linux_amd64.s:558
#1  0x0000000000436cf0 in runtime.futexsleep (addr=0xfffffffffffffe00, val=0, ns=4650275) at /__t/go/1.21.11/x64/src/runtime/os_linux.go:69
#2  0x000000000040ecc7 in runtime.notesleep (n=0xc000074548) at /__t/go/1.21.11/x64/src/runtime/lock_futex.go:160
#3  0x00000000004414ec in runtime.mPark () at /__t/go/1.21.11/x64/src/runtime/proc.go:1634
#4  runtime.stopm () at /__t/go/1.21.11/x64/src/runtime/proc.go:2531
#5  0x0000000000442e1c in runtime.findRunnable (gp=<optimized out>, inheritTime=<optimized out>, tryWakeP=<optimized out>) at /__t/go/1.21.11/x64/src/runtime/proc.go:3224
#6  0x0000000000443c11 in runtime.schedule () at /__t/go/1.21.11/x64/src/runtime/proc.go:3577
#7  0x000000000044411f in runtime.park_m (gp=0xc000683d40) at /__t/go/1.21.11/x64/src/runtime/proc.go:3740
#8  0x000000000046b88e in runtime.mcall () at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:458
#9  0x0000000000000000 in ?? ()

Thread 2 (LWP 3409213):
#0  runtime.futex () at /__t/go/1.21.11/x64/src/runtime/sys_linux_amd64.s:558
#1  0x0000000000436d65 in runtime.futexsleep (addr=<optimized out>, val=<optimized out>, ns=<optimized out>) at /__t/go/1.21.11/x64/src/runtime/os_linux.go:75
#2  0x000000000040edf3 in runtime.notetsleep_internal (n=0x1d2b1e0 <runtime[sched]+256>, ns=1989866024, ~r0=<optimized out>) at /__t/go/1.21.11/x64/src/runtime/lock_futex.go:202
#3  0x000000000040ef29 in runtime.notetsleep (n=0xfffffffffffffdfc, ns=0, ~r0=<optimized out>) at /__t/go/1.21.11/x64/src/runtime/lock_futex.go:225
#4  0x0000000000448606 in runtime.sysmon () at /__t/go/1.21.11/x64/src/runtime/proc.go:5565
#5  0x000000000043ffd3 in runtime.mstart1 () at /__t/go/1.21.11/x64/src/runtime/proc.go:1602
#6  0x000000000043ff16 in runtime.mstart0 () at /__t/go/1.21.11/x64/src/runtime/proc.go:1559
#7  0x000000000046b805 in runtime.mstart () at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:394
#8  0x000000000046f5cf in runtime.clone () at /__t/go/1.21.11/x64/src/runtime/sys_linux_amd64.s:618
#9  0x0000000000000000 in ?? ()

Thread 1 (LWP 3409212):
#0  runtime.futex () at /__t/go/1.21.11/x64/src/runtime/sys_linux_amd64.s:558
#1  0x0000000000436cf0 in runtime.futexsleep (addr=0xfffffffffffffe00, val=0, ns=4650275) at /__t/go/1.21.11/x64/src/runtime/os_linux.go:69
#2  0x000000000040ecc7 in runtime.notesleep (n=0x1d2aa28 <runtime.m0+328>) at /__t/go/1.21.11/x64/src/runtime/lock_futex.go:160
#3  0x00000000004414ec in runtime.mPark () at /__t/go/1.21.11/x64/src/runtime/proc.go:1634
#4  runtime.stopm () at /__t/go/1.21.11/x64/src/runtime/proc.go:2531
#5  0x0000000000442e1c in runtime.findRunnable (gp=<optimized out>, inheritTime=<optimized out>, tryWakeP=<optimized out>) at /__t/go/1.21.11/x64/src/runtime/proc.go:3224
#6  0x0000000000443c11 in runtime.schedule () at /__t/go/1.21.11/x64/src/runtime/proc.go:3577
#7  0x000000000044411f in runtime.park_m (gp=0xc0011dc820) at /__t/go/1.21.11/x64/src/runtime/proc.go:3740
#8  0x000000000046b88e in runtime.mcall () at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:458
#9  0x00007ffea8ec6558 in ?? ()
#10 0x000000000046feff in runtime.newproc (fn=0x46b78f <runtime.rt0_go+303>) at <autogenerated>:1
#11 0x000000000046b805 in runtime.mstart () at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:394
#12 0x000000000046b78f in runtime.rt0_go () at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:358
#13 0x0000000000000006 in ?? ()
#14 0x00007ffea8ec65a8 in ?? ()
#15 0x0000000000000000 in ?? ()
(gdb)

@neolynx
Copy link
Member

neolynx commented Jun 21, 2024

how did you obtain the core dump ? did aptly crash or did you trigger it ?

how are you invoking gdb ?

I see the source code when I pass the -d argument and provide the git repo (checkout b5bf2cb Fix functional tests' '--capture' on Python 3):

gdb ./aptly -d ~/devel/aptly

which shows the source info:

GNU gdb (Debian 13.1-3) 13.1
Copyright (C) 2023 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
Type "show copying" and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<https://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
    <http://www.gnu.org/software/gdb/documentation/>.

For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from ./aptly...
warning: File "/usr/share/go-1.19/src/runtime/runtime-gdb.py" auto-loading has been declined by your `auto-load safe-path' set to "$debugdir:$datadir/auto-load".
To enable execution of this file add
        add-auto-load-safe-path /usr/share/go-1.19/src/runtime/runtime-gdb.py
line to your configuration file "/home/lynx/.config/gdb/gdbinit".
To completely disable this security protection add
        set auto-load safe-path /
line to your configuration file "/home/lynx/.config/gdb/gdbinit".
For more information about this security protection see the
"Auto-loading safe path" section in the GDB manual.  E.g., run from the shell:
        info "(gdb)Auto-loading safe path"
(gdb) l
2
3       import (
4               "os"
5
6               "github.com/aptly-dev/aptly/aptly"
7               "github.com/aptly-dev/aptly/cmd"
8
9               _ "embed"
10      )
11

@russelltg
Copy link
Contributor Author

I attached to it and generatedd it with gdb. I actually think the stack I sent is full and correct, it's just in the runtime on all threads. I downloaded delve which can print goroutine stacks:

Details

(dlv) goroutines -t
  Goroutine 1 - User: /__t/go/1.21.11/x64/src/net/fd_unix.go:172 net.(*netFD).accept (0x590709) [IO wait 6204700077917805]
         0  0x000000000043d84e in runtime.gopark
             at /__t/go/1.21.11/x64/src/runtime/proc.go:399
         1  0x00000000004360b7 in runtime.netpollblock
             at /__t/go/1.21.11/x64/src/runtime/netpoll.go:564
         2  0x0000000000467e25 in internal/poll.runtime_pollWait
             at /__t/go/1.21.11/x64/src/runtime/netpoll.go:343
         3  0x00000000004a8747 in internal/poll.(*pollDesc).wait
             at /__t/go/1.21.11/x64/src/internal/poll/fd_poll_runtime.go:84
         4  0x00000000004adc2c in internal/poll.(*pollDesc).waitRead
             at /__t/go/1.21.11/x64/src/internal/poll/fd_poll_runtime.go:89
         5  0x00000000004adc2c in internal/poll.(*FD).Accept
             at /__t/go/1.21.11/x64/src/internal/poll/fd_unix.go:611
         6  0x0000000000590709 in net.(*netFD).accept
             at /__t/go/1.21.11/x64/src/net/fd_unix.go:172
         7  0x00000000005a8a3e in net.(*TCPListener).accept
             at /__t/go/1.21.11/x64/src/net/tcpsock_posix.go:152
         8  0x00000000005a7bf0 in net.(*TCPListener).Accept
             at /__t/go/1.21.11/x64/src/net/tcpsock.go:315
         9  0x0000000000784bc4 in net/http.(*onceCloseListener).Accept
             at <autogenerated>:1
        10  0x0000000000761104 in net/http.(*Server).Serve
             at /__t/go/1.21.11/x64/src/net/http/server.go:3056
        (truncated)
  Goroutine 2 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [force gc (idle) 6238860108416273]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000043d6d3 in runtime.goparkunlock
            at /__t/go/1.21.11/x64/src/runtime/proc.go:404
        2  0x000000000043d6d3 in runtime.forcegchelper
            at /__t/go/1.21.11/x64/src/runtime/proc.go:322
        3  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 3 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [GC sweep wait]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000042871f in runtime.goparkunlock
            at /__t/go/1.21.11/x64/src/runtime/proc.go:404
        2  0x000000000042871f in runtime.bgsweep
            at /__t/go/1.21.11/x64/src/runtime/mgcsweep.go:321
        3  0x000000000041d865 in runtime.gcenable.func1
            at /__t/go/1.21.11/x64/src/runtime/mgc.go:200
        4  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 4 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [GC scavenge wait]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x0000000000425f89 in runtime.goparkunlock
            at /__t/go/1.21.11/x64/src/runtime/proc.go:404
        2  0x0000000000425f89 in runtime.(*scavengerState).park
            at /__t/go/1.21.11/x64/src/runtime/mgcscavenge.go:425
        3  0x0000000000426539 in runtime.bgscavenge
            at /__t/go/1.21.11/x64/src/runtime/mgcscavenge.go:658
        4  0x000000000041d805 in runtime.gcenable.func2
            at /__t/go/1.21.11/x64/src/runtime/mgc.go:201
        5  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 5 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [debug call 6203969295593780]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000041f3e5 in runtime.gcBgMarkWorker
            at /__t/go/1.21.11/x64/src/runtime/mgc.go:1295
        2  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 6 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [debug call 6203969295593780]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000041f3e5 in runtime.gcBgMarkWorker
            at /__t/go/1.21.11/x64/src/runtime/mgc.go:1295
        2  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 7 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [debug call]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000041f3e5 in runtime.gcBgMarkWorker
            at /__t/go/1.21.11/x64/src/runtime/mgc.go:1295
        2  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 8 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [debug call 6203969295593780]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000041f3e5 in runtime.gcBgMarkWorker
            at /__t/go/1.21.11/x64/src/runtime/mgc.go:1295
        2  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 13 - User: /__w/aptly/aptly/api/api.go:67 github.com/aptly-dev/aptly/api.acquireDatabase (0x103c2dc) [chan receive 6204700077917805]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x0000000000409bcd in runtime.chanrecv
            at /__t/go/1.21.11/x64/src/runtime/chan.go:583
        2  0x00000000004097f2 in runtime.chanrecv2
            at /__t/go/1.21.11/x64/src/runtime/chan.go:447
        3  0x000000000103c2dc in github.com/aptly-dev/aptly/api.acquireDatabase
            at /__w/aptly/aptly/api/api.go:67
        4  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 14 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [select 6056618705067474]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000044d2e5 in runtime.selectgo
            at /__t/go/1.21.11/x64/src/runtime/select.go:327
        2  0x000000000046455f in runtime.ensureSigM.func1
            at /__t/go/1.21.11/x64/src/runtime/signal_unix.go:1014
        3  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 15 - User: /__t/go/1.21.11/x64/src/runtime/sigqueue.go:152 os/signal.signal_recv (0x46a1e9) (thread 3409215)
        0  0x000000000046f523 in runtime.futex
            at /__t/go/1.21.11/x64/src/runtime/sys_linux_amd64.s:558
        1  0x0000000000436cf0 in runtime.futexsleep
            at /__t/go/1.21.11/x64/src/runtime/os_linux.go:69
        2  0x000000000040eeb5 in runtime.notetsleep_internal
            at /__t/go/1.21.11/x64/src/runtime/lock_futex.go:183
        3  0x000000000040efb8 in runtime.notetsleepg
            at /__t/go/1.21.11/x64/src/runtime/lock_futex.go:237
        4  0x000000000046a1e9 in os/signal.signal_recv
            at /__t/go/1.21.11/x64/src/runtime/sigqueue.go:152
        5  0x00000000007879b3 in os/signal.loop
            at /__t/go/1.21.11/x64/src/os/signal/signal_unix.go:23
        6  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 16 - User: /__w/aptly/aptly/cmd/api_serve.go:67 github.com/aptly-dev/aptly/cmd.aptlyAPIServe.func1 (0x105a7ab) [chan receive 6056618705067474]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x0000000000409bcd in runtime.chanrecv
            at /__t/go/1.21.11/x64/src/runtime/chan.go:583
        2  0x00000000004097f2 in runtime.chanrecv2
            at /__t/go/1.21.11/x64/src/runtime/chan.go:447
        3  0x000000000105a7ab in github.com/aptly-dev/aptly/cmd.aptlyAPIServe.func1
            at /__w/aptly/aptly/cmd/api_serve.go:67
        4  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 17 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [finalizer wait 6203437767031795]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000041c887 in runtime.runfinq
            at /__t/go/1.21.11/x64/src/runtime/mfinal.go:193
        2  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 18 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [debug call 6203969295593780]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000041f3e5 in runtime.gcBgMarkWorker
            at /__t/go/1.21.11/x64/src/runtime/mgc.go:1295
        2  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 19 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [debug call 6238860108416273]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000041f3e5 in runtime.gcBgMarkWorker
            at /__t/go/1.21.11/x64/src/runtime/mgc.go:1295
        2  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 33 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [debug call 6203969295593780]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000041f3e5 in runtime.gcBgMarkWorker
            at /__t/go/1.21.11/x64/src/runtime/mgc.go:1295
        2  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 34 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [debug call 6203969295593780]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000041f3e5 in runtime.gcBgMarkWorker
            at /__t/go/1.21.11/x64/src/runtime/mgc.go:1295
        2  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 77 - User: /__w/aptly/aptly/task/list.go:45 github.com/aptly-dev/aptly/task.(*List).consumer (0x963b1a) [select 6201894628857980]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000044d2e5 in runtime.selectgo
            at /__t/go/1.21.11/x64/src/runtime/select.go:327
        2  0x0000000000963b1a in github.com/aptly-dev/aptly/task.(*List).consumer
            at /__w/aptly/aptly/task/list.go:45
        3  0x0000000000963a65 in github.com/aptly-dev/aptly/task.NewList.func1
            at /__w/aptly/aptly/task/list.go:38
        4  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 124839 - User: /__t/go/1.21.11/x64/src/runtime/sema.go:62 sync.runtime_Semacquire (0x469a85) [semacquire 6203969295593780]
         0  0x000000000043d84e in runtime.gopark
             at /__t/go/1.21.11/x64/src/runtime/proc.go:399
         1  0x000000000044e318 in runtime.goparkunlock
             at /__t/go/1.21.11/x64/src/runtime/proc.go:404
         2  0x000000000044e318 in runtime.semacquire1
             at /__t/go/1.21.11/x64/src/runtime/sema.go:160
         3  0x0000000000469a85 in sync.runtime_Semacquire
             at /__t/go/1.21.11/x64/src/runtime/sema.go:62
         4  0x000000000047a008 in sync.(*WaitGroup).Wait
             at /__t/go/1.21.11/x64/src/sync/waitgroup.go:116
         5  0x00000000009653b9 in github.com/aptly-dev/aptly/task.(*List).WaitForTaskByID
             at /__w/aptly/aptly/task/list.go:242
         6  0x000000000103cc98 in github.com/aptly-dev/aptly/api.maybeRunTaskInBackground
             at /__w/aptly/aptly/api/api.go:174
         7  0x000000000104bc51 in github.com/aptly-dev/aptly/api.apiReposPackageFromDir
             at /__w/aptly/aptly/api/repos.go:341
         8  0x0000000001054564 in github.com/gin-gonic/gin.(*Context).Next
             at /github/home/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:174
         9  0x0000000001054564 in github.com/aptly-dev/aptly/api.Router.func1
             at /__w/aptly/aptly/api/router.go:89
        10  0x0000000000a8498b in github.com/gin-gonic/gin.(*Context).Next
             at /github/home/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:174
        (truncated)
  Goroutine 130116 - User: /__t/go/1.21.11/x64/src/runtime/sema.go:62 sync.runtime_Semacquire (0x469a85) [semacquire 6204700077917805]
         0  0x000000000043d84e in runtime.gopark
             at /__t/go/1.21.11/x64/src/runtime/proc.go:399
         1  0x000000000044e318 in runtime.goparkunlock
             at /__t/go/1.21.11/x64/src/runtime/proc.go:404
         2  0x000000000044e318 in runtime.semacquire1
             at /__t/go/1.21.11/x64/src/runtime/sema.go:160
         3  0x0000000000469a85 in sync.runtime_Semacquire
             at /__t/go/1.21.11/x64/src/runtime/sema.go:62
         4  0x000000000047a008 in sync.(*WaitGroup).Wait
             at /__t/go/1.21.11/x64/src/sync/waitgroup.go:116
         5  0x00000000009653b9 in github.com/aptly-dev/aptly/task.(*List).WaitForTaskByID
             at /__w/aptly/aptly/task/list.go:242
         6  0x000000000103cc98 in github.com/aptly-dev/aptly/api.maybeRunTaskInBackground
             at /__w/aptly/aptly/api/api.go:174
         7  0x000000000104bc51 in github.com/aptly-dev/aptly/api.apiReposPackageFromDir
             at /__w/aptly/aptly/api/repos.go:341
         8  0x0000000001054564 in github.com/gin-gonic/gin.(*Context).Next
             at /github/home/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:174
         9  0x0000000001054564 in github.com/aptly-dev/aptly/api.Router.func1
             at /__w/aptly/aptly/api/router.go:89
        10  0x0000000000a8498b in github.com/gin-gonic/gin.(*Context).Next
             at /github/home/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:174
        (truncated)
  Goroutine 130168 - User: /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/util/buffer_pool.go:206 github.com/syndtr/goleveldb/leveldb/util.(*BufferPool).drain (0xc2dff6) [select]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000044d2e5 in runtime.selectgo
            at /__t/go/1.21.11/x64/src/runtime/select.go:327
        2  0x0000000000c2dff6 in github.com/syndtr/goleveldb/leveldb/util.(*BufferPool).drain
            at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/util/buffer_pool.go:206
        3  0x0000000000c2e385 in github.com/syndtr/goleveldb/leveldb/util.NewBufferPool.func1
            at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/util/buffer_pool.go:237
        4  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 130169 - User: /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/session_util.go:189 github.com/syndtr/goleveldb/leveldb.(*session).refLoop (0xc68b7e) [select]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000044d2e5 in runtime.selectgo
            at /__t/go/1.21.11/x64/src/runtime/select.go:327
        2  0x0000000000c68b7e in github.com/syndtr/goleveldb/leveldb.(*session).refLoop
            at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/session_util.go:189
        3  0x0000000000c626e5 in github.com/syndtr/goleveldb/leveldb.newSession.func1
            at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/session.go:93
        4  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 130170 - User: /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db_compaction.go:91 github.com/syndtr/goleveldb/leveldb.(*DB).compactionError (0xc51b2a) [select 620396929559378
0]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000044d2e5 in runtime.selectgo
            at /__t/go/1.21.11/x64/src/runtime/select.go:327
        2  0x0000000000c51b2a in github.com/syndtr/goleveldb/leveldb.(*DB).compactionError
            at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db_compaction.go:91
        3  0x0000000000c4a0e5 in github.com/syndtr/goleveldb/leveldb.openDB.func1
            at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db.go:148
        4  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 130171 - User: /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db_state.go:101 github.com/syndtr/goleveldb/leveldb.(*DB).mpoolDrain (0xc5ac1c) [select]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000044d2e5 in runtime.selectgo
            at /__t/go/1.21.11/x64/src/runtime/select.go:327
        2  0x0000000000c5ac1c in github.com/syndtr/goleveldb/leveldb.(*DB).mpoolDrain
            at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db_state.go:101
        3  0x0000000000c4a085 in github.com/syndtr/goleveldb/leveldb.openDB.func2
            at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db.go:149
        4  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 130172 - User: /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db_compaction.go:836 github.com/syndtr/goleveldb/leveldb.(*DB).tCompaction (0xc571b8) [select 6203969295593780]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000044d2e5 in runtime.selectgo
            at /__t/go/1.21.11/x64/src/runtime/select.go:327
        2  0x0000000000c571b8 in github.com/syndtr/goleveldb/leveldb.(*DB).tCompaction
            at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db_compaction.go:836
        3  0x0000000000c4a025 in github.com/syndtr/goleveldb/leveldb.openDB.func3
            at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db.go:155
        4  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 130173 - User: /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db_compaction.go:773 github.com/syndtr/goleveldb/leveldb.(*DB).mCompaction (0xc569a5) [select 6203969295593780]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000044d2e5 in runtime.selectgo
            at /__t/go/1.21.11/x64/src/runtime/select.go:327
        2  0x0000000000c569a5 in github.com/syndtr/goleveldb/leveldb.(*DB).mCompaction
            at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db_compaction.go:773
        3  0x0000000000c49fc5 in github.com/syndtr/goleveldb/leveldb.openDB.func4
            at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db.go:156
        4  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
[26 goroutines]

@neolynx
Copy link
Member

neolynx commented Jun 24, 2024

thanks for the backtrace !

does it look like aptly was shutting down bcs of a signal (gorouting 15) ?

how did the builds "hang", REST api did not return or timeout ? was aptly still responding to other APIs ?
I would ne interesting to see the tasks, in case the queue lost on in a race condition.

@russelltg
Copy link
Contributor Author

Right, the REST api isn't returning. Both are stuck on /api/repos/{repo}/file/{dir} endpoint. It happened again last night, here's another stack for you:

Details

  Goroutine 1 - User: /__t/go/1.21.11/x64/src/net/fd_unix.go:172 net.(*netFD).accept (0x590709) [IO wait 6721491349644173]
         0  0x000000000043d84e in runtime.gopark
             at /__t/go/1.21.11/x64/src/runtime/proc.go:399
         1  0x00000000004360b7 in runtime.netpollblock
             at /__t/go/1.21.11/x64/src/runtime/netpoll.go:564
         2  0x0000000000467e25 in internal/poll.runtime_pollWait
             at /__t/go/1.21.11/x64/src/runtime/netpoll.go:343
         3  0x00000000004a8747 in internal/poll.(*pollDesc).wait
             at /__t/go/1.21.11/x64/src/internal/poll/fd_poll_runtime.go:84
         4  0x00000000004adc2c in internal/poll.(*pollDesc).waitRead
             at /__t/go/1.21.11/x64/src/internal/poll/fd_poll_runtime.go:89
         5  0x00000000004adc2c in internal/poll.(*FD).Accept
             at /__t/go/1.21.11/x64/src/internal/poll/fd_unix.go:611
         6  0x0000000000590709 in net.(*netFD).accept
             at /__t/go/1.21.11/x64/src/net/fd_unix.go:172
         7  0x00000000005a8a3e in net.(*TCPListener).accept
             at /__t/go/1.21.11/x64/src/net/tcpsock_posix.go:152
         8  0x00000000005a7bf0 in net.(*TCPListener).Accept
             at /__t/go/1.21.11/x64/src/net/tcpsock.go:315
         9  0x0000000000784bc4 in net/http.(*onceCloseListener).Accept
             at <autogenerated>:1
        10  0x0000000000761104 in net/http.(*Server).Serve
             at /__t/go/1.21.11/x64/src/net/http/server.go:3056
        (truncated)
  Goroutine 2 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [force gc (idle) 6745167362610867]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000043d6d3 in runtime.goparkunlock
            at /__t/go/1.21.11/x64/src/runtime/proc.go:404
        2  0x000000000043d6d3 in runtime.forcegchelper
            at /__t/go/1.21.11/x64/src/runtime/proc.go:322
        3  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 3 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [GC sweep wait]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000042871f in runtime.goparkunlock
            at /__t/go/1.21.11/x64/src/runtime/proc.go:404
        2  0x000000000042871f in runtime.bgsweep
            at /__t/go/1.21.11/x64/src/runtime/mgcsweep.go:321
        3  0x000000000041d865 in runtime.gcenable.func1
            at /__t/go/1.21.11/x64/src/runtime/mgc.go:200
        4  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 4 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [GC scavenge wait]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x0000000000425f89 in runtime.goparkunlock
            at /__t/go/1.21.11/x64/src/runtime/proc.go:404
        2  0x0000000000425f89 in runtime.(*scavengerState).park
            at /__t/go/1.21.11/x64/src/runtime/mgcscavenge.go:425
        3  0x0000000000426539 in runtime.bgscavenge
            at /__t/go/1.21.11/x64/src/runtime/mgcscavenge.go:658
        4  0x000000000041d805 in runtime.gcenable.func2
            at /__t/go/1.21.11/x64/src/runtime/mgc.go:201
        5  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 5 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [finalizer wait 6719701849407205]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000041c887 in runtime.runfinq
            at /__t/go/1.21.11/x64/src/runtime/mfinal.go:193
        2  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 6 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [debug call 6721125270361812]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000041f3e5 in runtime.gcBgMarkWorker
            at /__t/go/1.21.11/x64/src/runtime/mgc.go:1295
        2  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 7 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [debug call]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000041f3e5 in runtime.gcBgMarkWorker
            at /__t/go/1.21.11/x64/src/runtime/mgc.go:1295
        2  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 8 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [debug call 6745167362610867]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000041f3e5 in runtime.gcBgMarkWorker
            at /__t/go/1.21.11/x64/src/runtime/mgc.go:1295
        2  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 9 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [debug call 6721125270361812]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000041f3e5 in runtime.gcBgMarkWorker
            at /__t/go/1.21.11/x64/src/runtime/mgc.go:1295
        2  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 10 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [debug call 6721125270361812]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000041f3e5 in runtime.gcBgMarkWorker
            at /__t/go/1.21.11/x64/src/runtime/mgc.go:1295
        2  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 17 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [debug call 6721125270361812]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000041f3e5 in runtime.gcBgMarkWorker
            at /__t/go/1.21.11/x64/src/runtime/mgc.go:1295
        2  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 33 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [debug call 6721125270361812]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000041f3e5 in runtime.gcBgMarkWorker
            at /__t/go/1.21.11/x64/src/runtime/mgc.go:1295
        2  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 34 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [debug call 6721125270361812]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000041f3e5 in runtime.gcBgMarkWorker
            at /__t/go/1.21.11/x64/src/runtime/mgc.go:1295
        2  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 35 - User: /__t/go/1.21.11/x64/src/runtime/sigqueue.go:152 os/signal.signal_recv (0x46a1e9) (thread 1993149)
        0  0x000000000046f523 in runtime.futex
            at /__t/go/1.21.11/x64/src/runtime/sys_linux_amd64.s:558
        1  0x0000000000436cf0 in runtime.futexsleep
            at /__t/go/1.21.11/x64/src/runtime/os_linux.go:69
        2  0x000000000040eeb5 in runtime.notetsleep_internal
            at /__t/go/1.21.11/x64/src/runtime/lock_futex.go:183
        3  0x000000000040efb8 in runtime.notetsleepg
            at /__t/go/1.21.11/x64/src/runtime/lock_futex.go:237
        4  0x000000000046a1e9 in os/signal.signal_recv
            at /__t/go/1.21.11/x64/src/runtime/sigqueue.go:152
        5  0x00000000007879b3 in os/signal.loop
            at /__t/go/1.21.11/x64/src/os/signal/signal_unix.go:23
        6  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 36 - User: /__w/aptly/aptly/cmd/api_serve.go:67 github.com/aptly-dev/aptly/cmd.aptlyAPIServe.func1 (0x105a7ab) [chan receive 6239198207390683]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x0000000000409bcd in runtime.chanrecv
            at /__t/go/1.21.11/x64/src/runtime/chan.go:583
        2  0x00000000004097f2 in runtime.chanrecv2
            at /__t/go/1.21.11/x64/src/runtime/chan.go:447
        3  0x000000000105a7ab in github.com/aptly-dev/aptly/cmd.aptlyAPIServe.func1
            at /__w/aptly/aptly/cmd/api_serve.go:67
        4  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 58 - User: /__w/aptly/aptly/api/api.go:67 github.com/aptly-dev/aptly/api.acquireDatabase (0x103c2dc) [chan receive 6721611844050146]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x0000000000409bcd in runtime.chanrecv
            at /__t/go/1.21.11/x64/src/runtime/chan.go:583
        2  0x00000000004097f2 in runtime.chanrecv2
            at /__t/go/1.21.11/x64/src/runtime/chan.go:447
        3  0x000000000103c2dc in github.com/aptly-dev/aptly/api.acquireDatabase
            at /__w/aptly/aptly/api/api.go:67
        4  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 59 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [select 6239198207390683]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000044d2e5 in runtime.selectgo
            at /__t/go/1.21.11/x64/src/runtime/select.go:327
        2  0x000000000046455f in runtime.ensureSigM.func1
            at /__t/go/1.21.11/x64/src/runtime/signal_unix.go:1014
        3  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 3837 - User: /__w/aptly/aptly/task/list.go:45 github.com/aptly-dev/aptly/task.(*List).consumer (0x963b1a) [select 6719592690647828]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000044d2e5 in runtime.selectgo
            at /__t/go/1.21.11/x64/src/runtime/select.go:327
        2  0x0000000000963b1a in github.com/aptly-dev/aptly/task.(*List).consumer
            at /__w/aptly/aptly/task/list.go:45
        3  0x0000000000963a65 in github.com/aptly-dev/aptly/task.NewList.func1
            at /__w/aptly/aptly/task/list.go:38
        4  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 181819 - User: /__t/go/1.21.11/x64/src/runtime/sema.go:62 sync.runtime_Semacquire (0x469a85) [semacquire 6721125270361812]
         0  0x000000000043d84e in runtime.gopark
             at /__t/go/1.21.11/x64/src/runtime/proc.go:399
         1  0x000000000044e318 in runtime.goparkunlock
             at /__t/go/1.21.11/x64/src/runtime/proc.go:404
         2  0x000000000044e318 in runtime.semacquire1
             at /__t/go/1.21.11/x64/src/runtime/sema.go:160
         3  0x0000000000469a85 in sync.runtime_Semacquire
             at /__t/go/1.21.11/x64/src/runtime/sema.go:62
         4  0x000000000047a008 in sync.(*WaitGroup).Wait
             at /__t/go/1.21.11/x64/src/sync/waitgroup.go:116
         5  0x00000000009653b9 in github.com/aptly-dev/aptly/task.(*List).WaitForTaskByID
             at /__w/aptly/aptly/task/list.go:242
         6  0x000000000103cc98 in github.com/aptly-dev/aptly/api.maybeRunTaskInBackground
             at /__w/aptly/aptly/api/api.go:174
         7  0x000000000104bc51 in github.com/aptly-dev/aptly/api.apiReposPackageFromDir
             at /__w/aptly/aptly/api/repos.go:341
         8  0x0000000001054564 in github.com/gin-gonic/gin.(*Context).Next
             at /github/home/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:174
         9  0x0000000001054564 in github.com/aptly-dev/aptly/api.Router.func1
             at /__w/aptly/aptly/api/router.go:89
        10  0x0000000000a8498b in github.com/gin-gonic/gin.(*Context).Next
             at /github/home/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:174
        (truncated)
  Goroutine 186138 - User: /__t/go/1.21.11/x64/src/net/fd_posix.go:55 net.(*netFD).Read (0x58e6e5) [IO wait 6721611844050146]
         0  0x000000000043d84e in runtime.gopark
             at /__t/go/1.21.11/x64/src/runtime/proc.go:399
         1  0x00000000004360b7 in runtime.netpollblock
             at /__t/go/1.21.11/x64/src/runtime/netpoll.go:564
         2  0x0000000000467e25 in internal/poll.runtime_pollWait
             at /__t/go/1.21.11/x64/src/runtime/netpoll.go:343
         3  0x00000000004a8747 in internal/poll.(*pollDesc).wait
             at /__t/go/1.21.11/x64/src/internal/poll/fd_poll_runtime.go:84
         4  0x00000000004a9a3a in internal/poll.(*pollDesc).waitRead
             at /__t/go/1.21.11/x64/src/internal/poll/fd_poll_runtime.go:89
         5  0x00000000004a9a3a in internal/poll.(*FD).Read
             at /__t/go/1.21.11/x64/src/internal/poll/fd_unix.go:164
         6  0x000000000058e6e5 in net.(*netFD).Read
             at /__t/go/1.21.11/x64/src/net/fd_posix.go:55
         7  0x000000000059ff45 in net.(*conn).Read
             at /__t/go/1.21.11/x64/src/net/net.go:179
         8  0x00000000005b1305 in net.(*TCPConn).Read
             at <autogenerated>:1
         9  0x0000000000756e4b in net/http.(*connReader).Read
             at /__t/go/1.21.11/x64/src/net/http/server.go:791
        10  0x0000000000535dc3 in bufio.(*Reader).fill
             at /__t/go/1.21.11/x64/src/bufio/bufio.go:113
        (truncated)
  Goroutine 186149 - User: /__t/go/1.21.11/x64/src/net/fd_posix.go:55 net.(*netFD).Read (0x58e6e5) [IO wait 6721125270361812]
         0  0x000000000043d84e in runtime.gopark
             at /__t/go/1.21.11/x64/src/runtime/proc.go:399
         1  0x00000000004360b7 in runtime.netpollblock
             at /__t/go/1.21.11/x64/src/runtime/netpoll.go:564
         2  0x0000000000467e25 in internal/poll.runtime_pollWait
             at /__t/go/1.21.11/x64/src/runtime/netpoll.go:343
         3  0x00000000004a8747 in internal/poll.(*pollDesc).wait
             at /__t/go/1.21.11/x64/src/internal/poll/fd_poll_runtime.go:84
         4  0x00000000004a9a3a in internal/poll.(*pollDesc).waitRead
             at /__t/go/1.21.11/x64/src/internal/poll/fd_poll_runtime.go:89
         5  0x00000000004a9a3a in internal/poll.(*FD).Read
             at /__t/go/1.21.11/x64/src/internal/poll/fd_unix.go:164
         6  0x000000000058e6e5 in net.(*netFD).Read
             at /__t/go/1.21.11/x64/src/net/fd_posix.go:55
         7  0x000000000059ff45 in net.(*conn).Read
             at /__t/go/1.21.11/x64/src/net/net.go:179
         8  0x00000000005b1305 in net.(*TCPConn).Read
             at <autogenerated>:1
         9  0x0000000000756a17 in net/http.(*connReader).backgroundRead
             at /__t/go/1.21.11/x64/src/net/http/server.go:683
        10  0x0000000000756945 in net/http.(*connReader).startBackgroundRead.func2
             at /__t/go/1.21.11/x64/src/net/http/server.go:679
        (truncated)
  Goroutine 186150 - User: /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/util/buffer_pool.go:206 github.com/sy
ndtr/goleveldb/leveldb/util.(*BufferPool).drain (0xc2dff6) [select]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000044d2e5 in runtime.selectgo
            at /__t/go/1.21.11/x64/src/runtime/select.go:327
        2  0x0000000000c2dff6 in github.com/syndtr/goleveldb/leveldb/util.(*BufferPool).drain
            at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/util/buffer_pool.go:206
        3  0x0000000000c2e385 in github.com/syndtr/goleveldb/leveldb/util.NewBufferPool.func1
            at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/util/buffer_pool.go:237
        4  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 186151 - User: /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/session_util.go:189 github.com/syndtr
/goleveldb/leveldb.(*session).refLoop (0xc68b7e) [select 6745045409801714]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000044d2e5 in runtime.selectgo
            at /__t/go/1.21.11/x64/src/runtime/select.go:327
        2  0x0000000000c68b7e in github.com/syndtr/goleveldb/leveldb.(*session).refLoop
            at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/session_util.go:189
        3  0x0000000000c626e5 in github.com/syndtr/goleveldb/leveldb.newSession.func1
            at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/session.go:93
        4  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 186169 - User: /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db_compaction.go:91 github.com/syndtr
/goleveldb/leveldb.(*DB).compactionError (0xc51b2a) [select 6721125270361812]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000044d2e5 in runtime.selectgo
            at /__t/go/1.21.11/x64/src/runtime/select.go:327
        2  0x0000000000c51b2a in github.com/syndtr/goleveldb/leveldb.(*DB).compactionError
            at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db_compaction.go:91
        3  0x0000000000c4a0e5 in github.com/syndtr/goleveldb/leveldb.openDB.func1
            at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db.go:148
        4  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 186170 - User: /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db_state.go:101 github.com/syndtr/gol
eveldb/leveldb.(*DB).mpoolDrain (0xc5ac1c) [select]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000044d2e5 in runtime.selectgo
            at /__t/go/1.21.11/x64/src/runtime/select.go:327
        2  0x0000000000c5ac1c in github.com/syndtr/goleveldb/leveldb.(*DB).mpoolDrain
            at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db_state.go:101
        3  0x0000000000c4a085 in github.com/syndtr/goleveldb/leveldb.openDB.func2
            at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db.go:149
        4  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 186171 - User: /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db_compaction.go:836 github.com/syndt
r/goleveldb/leveldb.(*DB).tCompaction (0xc571b8) [select 6721125270361812]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000044d2e5 in runtime.selectgo
            at /__t/go/1.21.11/x64/src/runtime/select.go:327
        2  0x0000000000c571b8 in github.com/syndtr/goleveldb/leveldb.(*DB).tCompaction
            at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db_compaction.go:836
        3  0x0000000000c4a025 in github.com/syndtr/goleveldb/leveldb.openDB.func3
            at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db.go:155
        4  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 186172 - User: /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db_compaction.go:773 github.com/syndt
r/goleveldb/leveldb.(*DB).mCompaction (0xc569a5) [select 6721125270361812]
        0  0x000000000043d84e in runtime.gopark
            at /__t/go/1.21.11/x64/src/runtime/proc.go:399
        1  0x000000000044d2e5 in runtime.selectgo
            at /__t/go/1.21.11/x64/src/runtime/select.go:327
        2  0x0000000000c569a5 in github.com/syndtr/goleveldb/leveldb.(*DB).mCompaction
            at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db_compaction.go:773
        3  0x0000000000c49fc5 in github.com/syndtr/goleveldb/leveldb.openDB.func4
            at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db.go:156
        4  0x000000000046d701 in runtime.goexit
            at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 186226 - User: /__t/go/1.21.11/x64/src/runtime/sema.go:62 sync.runtime_Semacquire (0x469a85) [semacquire 6721611844050146]
         0  0x000000000043d84e in runtime.gopark
             at /__t/go/1.21.11/x64/src/runtime/proc.go:399
         1  0x000000000044e318 in runtime.goparkunlock
             at /__t/go/1.21.11/x64/src/runtime/proc.go:404
         2  0x000000000044e318 in runtime.semacquire1
             at /__t/go/1.21.11/x64/src/runtime/sema.go:160
         3  0x0000000000469a85 in sync.runtime_Semacquire
             at /__t/go/1.21.11/x64/src/runtime/sema.go:62
         4  0x000000000047a008 in sync.(*WaitGroup).Wait
             at /__t/go/1.21.11/x64/src/sync/waitgroup.go:116
         5  0x00000000009653b9 in github.com/aptly-dev/aptly/task.(*List).WaitForTaskByID
             at /__w/aptly/aptly/task/list.go:242
         6  0x000000000103cc98 in github.com/aptly-dev/aptly/api.maybeRunTaskInBackground
             at /__w/aptly/aptly/api/api.go:174
         7  0x000000000104bc51 in github.com/aptly-dev/aptly/api.apiReposPackageFromDir
             at /__w/aptly/aptly/api/repos.go:341
         8  0x0000000001054564 in github.com/gin-gonic/gin.(*Context).Next
             at /github/home/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:174
         9  0x0000000001054564 in github.com/aptly-dev/aptly/api.Router.func1
             at /__w/aptly/aptly/api/router.go:89
        10  0x0000000000a8498b in github.com/gin-gonic/gin.(*Context).Next
             at /github/home/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:174
        (truncated)
  Goroutine 186688 - User: /__t/go/1.21.11/x64/src/net/fd_posix.go:55 net.(*netFD).Read (0x58e6e5) [IO wait 6721611844050146]
         0  0x000000000043d84e in runtime.gopark
             at /__t/go/1.21.11/x64/src/runtime/proc.go:399
         1  0x00000000004360b7 in runtime.netpollblock
             at /__t/go/1.21.11/x64/src/runtime/netpoll.go:564
         2  0x0000000000467e25 in internal/poll.runtime_pollWait
             at /__t/go/1.21.11/x64/src/runtime/netpoll.go:343
         3  0x00000000004a8747 in internal/poll.(*pollDesc).wait
             at /__t/go/1.21.11/x64/src/internal/poll/fd_poll_runtime.go:84
         4  0x00000000004a9a3a in internal/poll.(*pollDesc).waitRead
             at /__t/go/1.21.11/x64/src/internal/poll/fd_poll_runtime.go:89
         5  0x00000000004a9a3a in internal/poll.(*FD).Read
             at /__t/go/1.21.11/x64/src/internal/poll/fd_unix.go:164
         6  0x000000000058e6e5 in net.(*netFD).Read
             at /__t/go/1.21.11/x64/src/net/fd_posix.go:55
         7  0x000000000059ff45 in net.(*conn).Read
             at /__t/go/1.21.11/x64/src/net/net.go:179
         8  0x00000000005b1305 in net.(*TCPConn).Read
             at <autogenerated>:1
         9  0x0000000000756a17 in net/http.(*connReader).backgroundRead
             at /__t/go/1.21.11/x64/src/net/http/server.go:683
        10  0x0000000000756945 in net/http.(*connReader).startBackgroundRead.func2
             at /__t/go/1.21.11/x64/src/net/http/server.go:679
        (truncated)
[29 goroutines]

Re signals, I don't think so, I think that's just the goroutine responsible for waiting for signals.

It seems like the goroutines with apiReposPackageFromDir in the stack are potentially problematic.

I'll leave the process running today, let me know if there is any info I can get for you by attaching. Did a little bit of digging and didn't see anything super obvious, but I'm not terribly familiar with the codebase.

@neolynx
Copy link
Member

neolynx commented Jun 25, 2024

looking at the previous backtrace, I think aptly is using running with -no-lock, probably as configured in the systemd service. This disables database locking, but I think regarding concurrency, locking that database would make sense.

could you try modifying the service and remove the -no-lock flag ?

for running aptly commands the service then needs to be stopped.

i tested with /api/publish but could not reproduce it. will try with /api/repos/{repo}/file/{dir} ...

@russelltg
Copy link
Contributor Author

I see. I thought this meant it would just lock during each transaction, which would allow for using aptly on the commandline.

I'll remove it and let you know if I hit more hangs.

@russelltg
Copy link
Contributor Author

I haven't hit this hang again since removing that.

Do you consider this a code bug or doc bug? I think at the very minimum if this is expected behavior it should be listed in the help text under -no-lock that "external synchronization is expected" or something like that.

Honestly, I thought -no-lock meant that it would lock around transactions instead of locking when the HTTP api is available. It doesn't indicate that, but I figured some implementation like that would be require to make that option safe--is it just inherently unsafe (ie, requires external syncronization)?

@neolynx
Copy link
Member

neolynx commented Jul 9, 2024

Thanks for reporting back !
I would consider this a bug, in fact I would prefer that a user would not need to handle database locking...

I think the problem is, that with no-lock, the database is locked for each api call, and unlocked when the api call finishes. Since we are queuing the API calls now, this leads to the deadlock. I will try to solve that and maybe make no-lock obsolete...

@russelltg
Copy link
Contributor Author

Haha, right after I said that it hung again.

Two builds both hitting /api/repos/{repo}/file/{dir} at the same time.

Last few lines in the log are

Jul 09 02:04:49 papt101ubu aptly[1421]: [GIN] 2024/07/09 - 02:04:49 | 200 |   2.43185991s |  192.168.11.239 | POST     "/api/files/staging_5.9.0.868"
Jul 09 02:04:49 papt101ubu aptly[1421]: [GIN] 2024/07/09 - 02:04:49 | 200 |    35.28453ms |  192.168.11.239 | POST     "/api/files/staging_5.9.0.868_dbg"
Jul 09 02:04:49 papt101ubu aptly[1421]: [GIN] 2024/07/09 - 02:04:49 | 200 |    5.781956ms |  192.168.11.239 | POST     "/api/files/staging_5.9.0.868"
Jul 09 02:04:49 papt101ubu aptly[1421]: [GIN] 2024/07/09 - 02:04:49 | 200 |   47.421944ms |  192.168.11.239 | POST     "/api/files/staging_5.9.0.868_dbg"
Jul 09 02:04:49 papt101ubu aptly[1421]: [GIN] 2024/07/09 - 02:04:49 | 200 |      83.943µs |  192.168.11.239 | POST     "/api/files/staging_5.9.0.868"
Jul 09 02:04:49 papt101ubu aptly[1421]: [GIN] 2024/07/09 - 02:04:49 | 200 |   25.267066ms |  192.168.11.239 | POST     "/api/files/staging_5.9.0.868_dbg"
Jul 09 02:04:49 papt101ubu aptly[1421]: 2024-07-09T02:04:49-06:00 DBG Executing task synchronously

Commandline is aptly api serve -listen=:8080 -db-open-attempts=10000 (I forgot to remove the -db-open-attempts after removing -no-lock, but it shouldn't matter)

Ya know, I think I might be uploading two things to the same "files" folder symultaneously--I should probably stop doing that.

backtrace

(dlv) goroutines -t
  Goroutine 1 - User: /__t/go/1.21.11/x64/src/net/fd_unix.go:172 net.(*netFD).accept (0x590709) [IO wait 59109176972212]
	 0  0x000000000043d84e in runtime.gopark
	     at /__t/go/1.21.11/x64/src/runtime/proc.go:399
	 1  0x00000000004360b7 in runtime.netpollblock
	     at /__t/go/1.21.11/x64/src/runtime/netpoll.go:564
	 2  0x0000000000467e25 in internal/poll.runtime_pollWait
	     at /__t/go/1.21.11/x64/src/runtime/netpoll.go:343
	 3  0x00000000004a8747 in internal/poll.(*pollDesc).wait
	     at /__t/go/1.21.11/x64/src/internal/poll/fd_poll_runtime.go:84
	 4  0x00000000004adc2c in internal/poll.(*pollDesc).waitRead
	     at /__t/go/1.21.11/x64/src/internal/poll/fd_poll_runtime.go:89
	 5  0x00000000004adc2c in internal/poll.(*FD).Accept
	     at /__t/go/1.21.11/x64/src/internal/poll/fd_unix.go:611
	 6  0x0000000000590709 in net.(*netFD).accept
	     at /__t/go/1.21.11/x64/src/net/fd_unix.go:172
	 7  0x00000000005a8a3e in net.(*TCPListener).accept
	     at /__t/go/1.21.11/x64/src/net/tcpsock_posix.go:152
	 8  0x00000000005a7bf0 in net.(*TCPListener).Accept
	     at /__t/go/1.21.11/x64/src/net/tcpsock.go:315
	 9  0x0000000000784bc4 in net/http.(*onceCloseListener).Accept
	     at <autogenerated>:1
	10  0x0000000000761104 in net/http.(*Server).Serve
	     at /__t/go/1.21.11/x64/src/net/http/server.go:3056
	(truncated)
  Goroutine 2 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [force gc (idle) 85917193343029]
	0  0x000000000043d84e in runtime.gopark
	    at /__t/go/1.21.11/x64/src/runtime/proc.go:399
	1  0x000000000043d6d3 in runtime.goparkunlock
	    at /__t/go/1.21.11/x64/src/runtime/proc.go:404
	2  0x000000000043d6d3 in runtime.forcegchelper
	    at /__t/go/1.21.11/x64/src/runtime/proc.go:322
	3  0x000000000046d701 in runtime.goexit
	    at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 3 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [GC sweep wait]
	0  0x000000000043d84e in runtime.gopark
	    at /__t/go/1.21.11/x64/src/runtime/proc.go:399
	1  0x000000000042871f in runtime.goparkunlock
	    at /__t/go/1.21.11/x64/src/runtime/proc.go:404
	2  0x000000000042871f in runtime.bgsweep
	    at /__t/go/1.21.11/x64/src/runtime/mgcsweep.go:321
	3  0x000000000041d865 in runtime.gcenable.func1
	    at /__t/go/1.21.11/x64/src/runtime/mgc.go:200
	4  0x000000000046d701 in runtime.goexit
	    at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 4 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [GC scavenge wait]
	0  0x000000000043d84e in runtime.gopark
	    at /__t/go/1.21.11/x64/src/runtime/proc.go:399
	1  0x0000000000425f89 in runtime.goparkunlock
	    at /__t/go/1.21.11/x64/src/runtime/proc.go:404
	2  0x0000000000425f89 in runtime.(*scavengerState).park
	    at /__t/go/1.21.11/x64/src/runtime/mgcscavenge.go:425
	3  0x0000000000426539 in runtime.bgscavenge
	    at /__t/go/1.21.11/x64/src/runtime/mgcscavenge.go:658
	4  0x000000000041d805 in runtime.gcenable.func2
	    at /__t/go/1.21.11/x64/src/runtime/mgc.go:201
	5  0x000000000046d701 in runtime.goexit
	    at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 5 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [finalizer wait 57488385365871]
	0  0x000000000043d84e in runtime.gopark
	    at /__t/go/1.21.11/x64/src/runtime/proc.go:399
	1  0x000000000041c887 in runtime.runfinq
	    at /__t/go/1.21.11/x64/src/runtime/mfinal.go:193
	2  0x000000000046d701 in runtime.goexit
	    at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 6 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [debug call 59205908904469]
	0  0x000000000043d84e in runtime.gopark
	    at /__t/go/1.21.11/x64/src/runtime/proc.go:399
	1  0x000000000041f3e5 in runtime.gcBgMarkWorker
	    at /__t/go/1.21.11/x64/src/runtime/mgc.go:1295
	2  0x000000000046d701 in runtime.goexit
	    at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 7 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [debug call 59205908904469]
	0  0x000000000043d84e in runtime.gopark
	    at /__t/go/1.21.11/x64/src/runtime/proc.go:399
	1  0x000000000041f3e5 in runtime.gcBgMarkWorker
	    at /__t/go/1.21.11/x64/src/runtime/mgc.go:1295
	2  0x000000000046d701 in runtime.goexit
	    at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 8 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [debug call]
	0  0x000000000043d84e in runtime.gopark
	    at /__t/go/1.21.11/x64/src/runtime/proc.go:399
	1  0x000000000041f3e5 in runtime.gcBgMarkWorker
	    at /__t/go/1.21.11/x64/src/runtime/mgc.go:1295
	2  0x000000000046d701 in runtime.goexit
	    at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 17 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [debug call 59205908904469]
	0  0x000000000043d84e in runtime.gopark
	    at /__t/go/1.21.11/x64/src/runtime/proc.go:399
	1  0x000000000041f3e5 in runtime.gcBgMarkWorker
	    at /__t/go/1.21.11/x64/src/runtime/mgc.go:1295
	2  0x000000000046d701 in runtime.goexit
	    at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 18 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [debug call 59205908904469]
	0  0x000000000043d84e in runtime.gopark
	    at /__t/go/1.21.11/x64/src/runtime/proc.go:399
	1  0x000000000041f3e5 in runtime.gcBgMarkWorker
	    at /__t/go/1.21.11/x64/src/runtime/mgc.go:1295
	2  0x000000000046d701 in runtime.goexit
	    at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 19 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [debug call 85917193343029]
	0  0x000000000043d84e in runtime.gopark
	    at /__t/go/1.21.11/x64/src/runtime/proc.go:399
	1  0x000000000041f3e5 in runtime.gcBgMarkWorker
	    at /__t/go/1.21.11/x64/src/runtime/mgc.go:1295
	2  0x000000000046d701 in runtime.goexit
	    at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 33 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [debug call 59205908904469]
	0  0x000000000043d84e in runtime.gopark
	    at /__t/go/1.21.11/x64/src/runtime/proc.go:399
	1  0x000000000041f3e5 in runtime.gcBgMarkWorker
	    at /__t/go/1.21.11/x64/src/runtime/mgc.go:1295
	2  0x000000000046d701 in runtime.goexit
	    at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 34 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [debug call 59205908904469]
	0  0x000000000043d84e in runtime.gopark
	    at /__t/go/1.21.11/x64/src/runtime/proc.go:399
	1  0x000000000041f3e5 in runtime.gcBgMarkWorker
	    at /__t/go/1.21.11/x64/src/runtime/mgc.go:1295
	2  0x000000000046d701 in runtime.goexit
	    at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 37 - User: /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/util/buffer_pool.go:206 github.com/syndtr/goleveldb/leveldb/util.(*BufferPool).drain (0xc2dff6) [select]
	0  0x000000000043d84e in runtime.gopark
	    at /__t/go/1.21.11/x64/src/runtime/proc.go:399
	1  0x000000000044d2e5 in runtime.selectgo
	    at /__t/go/1.21.11/x64/src/runtime/select.go:327
	2  0x0000000000c2dff6 in github.com/syndtr/goleveldb/leveldb/util.(*BufferPool).drain
	    at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/util/buffer_pool.go:206
	3  0x0000000000c2e385 in github.com/syndtr/goleveldb/leveldb/util.NewBufferPool.func1
	    at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/util/buffer_pool.go:237
	4  0x000000000046d701 in runtime.goexit
	    at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 38 - User: /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/session_util.go:189 github.com/syndtr/goleveldb/leveldb.(*session).refLoop (0xc68b7e) [select 85917193343029]
	0  0x000000000043d84e in runtime.gopark
	    at /__t/go/1.21.11/x64/src/runtime/proc.go:399
	1  0x000000000044d2e5 in runtime.selectgo
	    at /__t/go/1.21.11/x64/src/runtime/select.go:327
	2  0x0000000000c68b7e in github.com/syndtr/goleveldb/leveldb.(*session).refLoop
	    at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/session_util.go:189
	3  0x0000000000c626e5 in github.com/syndtr/goleveldb/leveldb.newSession.func1
	    at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/session.go:93
	4  0x000000000046d701 in runtime.goexit
	    at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 39 - User: /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db_compaction.go:91 github.com/syndtr/goleveldb/leveldb.(*DB).compactionError (0xc51b2a) [select 57546143563406]
	0  0x000000000043d84e in runtime.gopark
	    at /__t/go/1.21.11/x64/src/runtime/proc.go:399
	1  0x000000000044d2e5 in runtime.selectgo
	    at /__t/go/1.21.11/x64/src/runtime/select.go:327
	2  0x0000000000c51b2a in github.com/syndtr/goleveldb/leveldb.(*DB).compactionError
	    at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db_compaction.go:91
	3  0x0000000000c4a0e5 in github.com/syndtr/goleveldb/leveldb.openDB.func1
	    at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db.go:148
	4  0x000000000046d701 in runtime.goexit
	    at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 40 - User: /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db_state.go:101 github.com/syndtr/goleveldb/leveldb.(*DB).mpoolDrain (0xc5ac1c) [select]
	0  0x000000000043d84e in runtime.gopark
	    at /__t/go/1.21.11/x64/src/runtime/proc.go:399
	1  0x000000000044d2e5 in runtime.selectgo
	    at /__t/go/1.21.11/x64/src/runtime/select.go:327
	2  0x0000000000c5ac1c in github.com/syndtr/goleveldb/leveldb.(*DB).mpoolDrain
	    at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db_state.go:101
	3  0x0000000000c4a085 in github.com/syndtr/goleveldb/leveldb.openDB.func2
	    at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db.go:149
	4  0x000000000046d701 in runtime.goexit
	    at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 41 - User: /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db_compaction.go:836 github.com/syndtr/goleveldb/leveldb.(*DB).tCompaction (0xc571b8) [select 57546143563406]
	0  0x000000000043d84e in runtime.gopark
	    at /__t/go/1.21.11/x64/src/runtime/proc.go:399
	1  0x000000000044d2e5 in runtime.selectgo
	    at /__t/go/1.21.11/x64/src/runtime/select.go:327
	2  0x0000000000c571b8 in github.com/syndtr/goleveldb/leveldb.(*DB).tCompaction
	    at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db_compaction.go:836
	3  0x0000000000c4a025 in github.com/syndtr/goleveldb/leveldb.openDB.func3
	    at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db.go:155
	4  0x000000000046d701 in runtime.goexit
	    at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 42 - User: /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db_compaction.go:773 github.com/syndtr/goleveldb/leveldb.(*DB).mCompaction (0xc569a5) [select 55963719564471]
	0  0x000000000043d84e in runtime.gopark
	    at /__t/go/1.21.11/x64/src/runtime/proc.go:399
	1  0x000000000044d2e5 in runtime.selectgo
	    at /__t/go/1.21.11/x64/src/runtime/select.go:327
	2  0x0000000000c569a5 in github.com/syndtr/goleveldb/leveldb.(*DB).mCompaction
	    at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db_compaction.go:773
	3  0x0000000000c49fc5 in github.com/syndtr/goleveldb/leveldb.openDB.func4
	    at /github/home/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db.go:156
	4  0x000000000046d701 in runtime.goexit
	    at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 50 - User: /__t/go/1.21.11/x64/src/runtime/proc.go:399 runtime.gopark (0x43d84e) [select 26945817903]
	0  0x000000000043d84e in runtime.gopark
	    at /__t/go/1.21.11/x64/src/runtime/proc.go:399
	1  0x000000000044d2e5 in runtime.selectgo
	    at /__t/go/1.21.11/x64/src/runtime/select.go:327
	2  0x000000000046455f in runtime.ensureSigM.func1
	    at /__t/go/1.21.11/x64/src/runtime/signal_unix.go:1014
	3  0x000000000046d701 in runtime.goexit
	    at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 51 - User: /__t/go/1.21.11/x64/src/runtime/sigqueue.go:152 os/signal.signal_recv (0x46a1e9) (thread 1550)
	0  0x000000000046f523 in runtime.futex
	    at /__t/go/1.21.11/x64/src/runtime/sys_linux_amd64.s:558
	1  0x0000000000436cf0 in runtime.futexsleep
	    at /__t/go/1.21.11/x64/src/runtime/os_linux.go:69
	2  0x000000000040eeb5 in runtime.notetsleep_internal
	    at /__t/go/1.21.11/x64/src/runtime/lock_futex.go:183
	3  0x000000000040efb8 in runtime.notetsleepg
	    at /__t/go/1.21.11/x64/src/runtime/lock_futex.go:237
	4  0x000000000046a1e9 in os/signal.signal_recv
	    at /__t/go/1.21.11/x64/src/runtime/sigqueue.go:152
	5  0x00000000007879b3 in os/signal.loop
	    at /__t/go/1.21.11/x64/src/os/signal/signal_unix.go:23
	6  0x000000000046d701 in runtime.goexit
	    at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 65 - User: /__w/aptly/aptly/cmd/api_serve.go:67 github.com/aptly-dev/aptly/cmd.aptlyAPIServe.func1 (0x105a7ab) [chan receive 26945817903]
	0  0x000000000043d84e in runtime.gopark
	    at /__t/go/1.21.11/x64/src/runtime/proc.go:399
	1  0x0000000000409bcd in runtime.chanrecv
	    at /__t/go/1.21.11/x64/src/runtime/chan.go:583
	2  0x00000000004097f2 in runtime.chanrecv2
	    at /__t/go/1.21.11/x64/src/runtime/chan.go:447
	3  0x000000000105a7ab in github.com/aptly-dev/aptly/cmd.aptlyAPIServe.func1
	    at /__w/aptly/aptly/cmd/api_serve.go:67
	4  0x000000000046d701 in runtime.goexit
	    at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 641 - User: /__w/aptly/aptly/task/list.go:45 github.com/aptly-dev/aptly/task.(*List).consumer (0x963b1a) [select 56106702310397]
	0  0x000000000043d84e in runtime.gopark
	    at /__t/go/1.21.11/x64/src/runtime/proc.go:399
	1  0x000000000044d2e5 in runtime.selectgo
	    at /__t/go/1.21.11/x64/src/runtime/select.go:327
	2  0x0000000000963b1a in github.com/aptly-dev/aptly/task.(*List).consumer
	    at /__w/aptly/aptly/task/list.go:45
	3  0x0000000000963a65 in github.com/aptly-dev/aptly/task.NewList.func1
	    at /__w/aptly/aptly/task/list.go:38
	4  0x000000000046d701 in runtime.goexit
	    at /__t/go/1.21.11/x64/src/runtime/asm_amd64.s:1650
  Goroutine 34463 - User: /__t/go/1.21.11/x64/src/runtime/sema.go:62 sync.runtime_Semacquire (0x469a85) [semacquire 57768201813961]
	 0  0x000000000043d84e in runtime.gopark
	     at /__t/go/1.21.11/x64/src/runtime/proc.go:399
	 1  0x000000000044e318 in runtime.goparkunlock
	     at /__t/go/1.21.11/x64/src/runtime/proc.go:404
	 2  0x000000000044e318 in runtime.semacquire1
	     at /__t/go/1.21.11/x64/src/runtime/sema.go:160
	 3  0x0000000000469a85 in sync.runtime_Semacquire
	     at /__t/go/1.21.11/x64/src/runtime/sema.go:62
	 4  0x000000000047a008 in sync.(*WaitGroup).Wait
	     at /__t/go/1.21.11/x64/src/sync/waitgroup.go:116
	 5  0x00000000009653b9 in github.com/aptly-dev/aptly/task.(*List).WaitForTaskByID
	     at /__w/aptly/aptly/task/list.go:242
	 6  0x000000000103cc98 in github.com/aptly-dev/aptly/api.maybeRunTaskInBackground
	     at /__w/aptly/aptly/api/api.go:174
	 7  0x000000000104bc51 in github.com/aptly-dev/aptly/api.apiReposPackageFromDir
	     at /__w/aptly/aptly/api/repos.go:341
	 8  0x0000000000a8498b in github.com/gin-gonic/gin.(*Context).Next
	     at /github/home/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:174
	 9  0x000000000104fd05 in github.com/aptly-dev/aptly/api.Router.ErrorLogger.ErrorLoggerT.func6
	     at /github/home/go/pkg/mod/github.com/gin-gonic/[email protected]/logger.go:172
	10  0x0000000000a9163a in github.com/gin-gonic/gin.(*Context).Next
	     at /github/home/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:174
	11  0x0000000000a9163a in github.com/gin-gonic/gin.CustomRecoveryWithWriter.func1
	     at /github/home/go/pkg/mod/github.com/gin-gonic/[email protected]/recovery.go:102
	(truncated)
  Goroutine 35464 - User: /__t/go/1.21.11/x64/src/net/fd_posix.go:55 net.(*netFD).Read (0x58e6e5) [IO wait 57768201813961]
	 0  0x000000000043d84e in runtime.gopark
	     at /__t/go/1.21.11/x64/src/runtime/proc.go:399
	 1  0x00000000004360b7 in runtime.netpollblock
	     at /__t/go/1.21.11/x64/src/runtime/netpoll.go:564
	 2  0x0000000000467e25 in internal/poll.runtime_pollWait
	     at /__t/go/1.21.11/x64/src/runtime/netpoll.go:343
	 3  0x00000000004a8747 in internal/poll.(*pollDesc).wait
	     at /__t/go/1.21.11/x64/src/internal/poll/fd_poll_runtime.go:84
	 4  0x00000000004a9a3a in internal/poll.(*pollDesc).waitRead
	     at /__t/go/1.21.11/x64/src/internal/poll/fd_poll_runtime.go:89
	 5  0x00000000004a9a3a in internal/poll.(*FD).Read
	     at /__t/go/1.21.11/x64/src/internal/poll/fd_unix.go:164
	 6  0x000000000058e6e5 in net.(*netFD).Read
	     at /__t/go/1.21.11/x64/src/net/fd_posix.go:55
	 7  0x000000000059ff45 in net.(*conn).Read
	     at /__t/go/1.21.11/x64/src/net/net.go:179
	 8  0x00000000005b1305 in net.(*TCPConn).Read
	     at <autogenerated>:1
	 9  0x0000000000756a17 in net/http.(*connReader).backgroundRead
	     at /__t/go/1.21.11/x64/src/net/http/server.go:683
	10  0x0000000000756945 in net/http.(*connReader).startBackgroundRead.func2
	     at /__t/go/1.21.11/x64/src/net/http/server.go:679
	(truncated)
  Goroutine 35465 - User: /__t/go/1.21.11/x64/src/runtime/sema.go:62 sync.runtime_Semacquire (0x469a85) [semacquire 59205908904469]
	 0  0x000000000043d84e in runtime.gopark
	     at /__t/go/1.21.11/x64/src/runtime/proc.go:399
	 1  0x000000000044e318 in runtime.goparkunlock
	     at /__t/go/1.21.11/x64/src/runtime/proc.go:404
	 2  0x000000000044e318 in runtime.semacquire1
	     at /__t/go/1.21.11/x64/src/runtime/sema.go:160
	 3  0x0000000000469a85 in sync.runtime_Semacquire
	     at /__t/go/1.21.11/x64/src/runtime/sema.go:62
	 4  0x000000000047a008 in sync.(*WaitGroup).Wait
	     at /__t/go/1.21.11/x64/src/sync/waitgroup.go:116
	 5  0x00000000009653b9 in github.com/aptly-dev/aptly/task.(*List).WaitForTaskByID
	     at /__w/aptly/aptly/task/list.go:242
	 6  0x000000000103cc98 in github.com/aptly-dev/aptly/api.maybeRunTaskInBackground
	     at /__w/aptly/aptly/api/api.go:174
	 7  0x000000000104bc51 in github.com/aptly-dev/aptly/api.apiReposPackageFromDir
	     at /__w/aptly/aptly/api/repos.go:341
	 8  0x0000000000a8498b in github.com/gin-gonic/gin.(*Context).Next
	     at /github/home/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:174
	 9  0x000000000104fd05 in github.com/aptly-dev/aptly/api.Router.ErrorLogger.ErrorLoggerT.func6
	     at /github/home/go/pkg/mod/github.com/gin-gonic/[email protected]/logger.go:172
	10  0x0000000000a9163a in github.com/gin-gonic/gin.(*Context).Next
	     at /github/home/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:174
	11  0x0000000000a9163a in github.com/gin-gonic/gin.CustomRecoveryWithWriter.func1
	     at /github/home/go/pkg/mod/github.com/gin-gonic/[email protected]/recovery.go:102
	(truncated)
  Goroutine 35984 - User: /__t/go/1.21.11/x64/src/net/fd_posix.go:55 net.(*netFD).Read (0x58e6e5) [IO wait 59205908904469]
	 0  0x000000000043d84e in runtime.gopark
	     at /__t/go/1.21.11/x64/src/runtime/proc.go:399
	 1  0x00000000004360b7 in runtime.netpollblock
	     at /__t/go/1.21.11/x64/src/runtime/netpoll.go:564
	 2  0x0000000000467e25 in internal/poll.runtime_pollWait
	     at /__t/go/1.21.11/x64/src/runtime/netpoll.go:343
	 3  0x00000000004a8747 in internal/poll.(*pollDesc).wait
	     at /__t/go/1.21.11/x64/src/internal/poll/fd_poll_runtime.go:84
	 4  0x00000000004a9a3a in internal/poll.(*pollDesc).waitRead
	     at /__t/go/1.21.11/x64/src/internal/poll/fd_poll_runtime.go:89
	 5  0x00000000004a9a3a in internal/poll.(*FD).Read
	     at /__t/go/1.21.11/x64/src/internal/poll/fd_unix.go:164
	 6  0x000000000058e6e5 in net.(*netFD).Read
	     at /__t/go/1.21.11/x64/src/net/fd_posix.go:55
	 7  0x000000000059ff45 in net.(*conn).Read
	     at /__t/go/1.21.11/x64/src/net/net.go:179
	 8  0x00000000005b1305 in net.(*TCPConn).Read
	     at <autogenerated>:1
	 9  0x0000000000756a17 in net/http.(*connReader).backgroundRead
	     at /__t/go/1.21.11/x64/src/net/http/server.go:683
	10  0x0000000000756945 in net/http.(*connReader).startBackgroundRead.func2
	     at /__t/go/1.21.11/x64/src/net/http/server.go:679
	(truncated)
[27 goroutines]

@russelltg
Copy link
Contributor Author

russelltg commented Jul 9, 2024

I'm changing it to have a random component to the dir name, that makes a lot more sense haha.

Not sure exactly how aptly should function in this weird edgecase, but hanging seems wrong :)

@neolynx
Copy link
Member

neolynx commented Jul 10, 2024

That would have been my next question: are you using the same upload directory from different builders? :-)

aptly will remove that directory, which then causes concurrency problems. there is also an option to not remove the files, but this will need separate cleanup..

I would also suggest to use a random name for concurrent uploads. The edge case is difficult to handle I guess with the current implementation, I would prefer if aptly assigns an upload slot and the user does not need to manage that.

I will look into the backtrace to check if this is expected with the current implementation.

Thanks again for all the testing and analysis ! we'll get there :)

@neolynx
Copy link
Member

neolynx commented Sep 27, 2024

Hi @russelltg,

I think the problem was the concurrent usage of the same upload dir. It had nothing to do with the --no-lock, I assume you should be able to put that back.

Let us know if the latest CI build (see: #1345 for new APT sources) works fine for you and if we can close the issue !

@neolynx
Copy link
Member

neolynx commented Oct 22, 2024

Hi @russelltg,

there was more fixes for race conditions and concurrent operations merged to master! please update your ci build (1.6.0~beta1+20241022145612.767bc6bd).

I don't think the -no-lock was an issue, you could also try to put this one back...

let us know how this works !

@neolynx neolynx added the please confirm resolved We believe the issue is resolved ! if so, please close the issue, thanks ;-) label Oct 22, 2024
@NeroBurner
Copy link
Contributor

I'd like to try to update and check if the issue is resolved. But the newest version referenced in http://repo.aptly.info/dists/nightly/main/binary-amd64/Packages is 1.6.0~alpha30+247+g9b62b4e4 based on 9b62b4e4 from September 13th 2024. The 1.6.0~beta1 commit is much more recent 767bc6bd (from October 22nd 2024)

@neolynx
Copy link
Member

neolynx commented Oct 25, 2024

The APT URL has changes, see #1345

deb [signed-by=/etc/apt/keyrings/aptly.asc] http://repo.aptly.info/ci jammy main

@NeroBurner
Copy link
Contributor

Thanks! Installed the Ubuntu 24.04 noble version, will report back in about a week or so whether or not we encounter the lockup anymore

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug please confirm resolved We believe the issue is resolved ! if so, please close the issue, thanks ;-)
Projects
None yet
Development

No branches or pull requests

3 participants