GNU bug report logs - #29335
'guix publish' workers occasionally crash

Previous Next

Package: guix;

Reported by: ludo <at> gnu.org (Ludovic Courtès)

Date: Fri, 17 Nov 2017 10:12:01 UTC

Severity: important

Done: ludo <at> gnu.org (Ludovic Courtès)

Bug is archived. No further changes may be made.

Full log

View this message in rfc822 format

From: ludo <at> gnu.org (Ludovic Courtès)
To: 29335 <at> debbugs.gnu.org
Subject: bug#29335: 'guix publish' workers occasionally crash
Date: Fri, 17 Nov 2017 13:22:58 +0100

If we look at our worker threads, they’re all stuck in mutex_lock:

--8<---------------cut here---------------start------------->8---
(gdb) info threads
  Id   Target Id         Frame
* 1    Thread 0x7f7ee99d5f00 (LWP 4105) "guix publish" 0x00007f7ee79c60ad in poll () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libc.so.6
  2    Thread 0x7f7ee78e6700 (LWP 4106) ".guix-real" 0x00007f7ee900d58f in pthread_cond_wait@@GLIBC_2.3.2 () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libpthread.so.0
  3    Thread 0x7f7ee70e5700 (LWP 4107) ".guix-real" 0x00007f7ee900d58f in pthread_cond_wait@@GLIBC_2.3.2 () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libpthread.so.0
  4    Thread 0x7f7ee68e4700 (LWP 4108) ".guix-real" 0x00007f7ee900d58f in pthread_cond_wait@@GLIBC_2.3.2 () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libpthread.so.0
  5    Thread 0x7f7ee60e3700 (LWP 4109) ".guix-real" 0x00007f7ee900d58f in pthread_cond_wait@@GLIBC_2.3.2 () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libpthread.so.0
  6    Thread 0x7f7ee58e2700 (LWP 4110) ".guix-real" 0x00007f7ee900d58f in pthread_cond_wait@@GLIBC_2.3.2 () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libpthread.so.0
  7    Thread 0x7f7ee50e1700 (LWP 4111) ".guix-real" 0x00007f7ee900d58f in pthread_cond_wait@@GLIBC_2.3.2 () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libpthread.so.0
  8    Thread 0x7f7ee48e0700 (LWP 4112) ".guix-real" 0x00007f7ee900d58f in pthread_cond_wait@@GLIBC_2.3.2 () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libpthread.so.0
  9    Thread 0x7f7ee3a4f700 (LWP 4113) ".guix-real" 0x00007f7ee9010aed in read () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libpthread.so.0
  10   Thread 0x7f7ee114b700 (LWP 4114) ".guix-real" 0x00007f7ee9010aed in read () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libpthread.so.0
  11   Thread 0x7f7edf892700 (LWP 4116) "publish worker" 0x00007f7ee90108fc in __lll_lock_wait () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libpthread.so.0
  12   Thread 0x7f7edf090700 (LWP 4117) "publish worker" 0x00007f7ee90108fc in __lll_lock_wait () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libpthread.so.0
  13   Thread 0x7f7ede88e700 (LWP 4118) "publish worker" 0x00007f7ee90108fc in __lll_lock_wait () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libpthread.so.0
  14   Thread 0x7f7ede08c700 (LWP 4119) "publish worker" 0x00007f7ee90108fc in __lll_lock_wait () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libpthread.so.0
  15   Thread 0x7f7edd88a700 (LWP 4120) "publish worker" 0x00007f7ee90108fc in __lll_lock_wait () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libpthread.so.0
  16   Thread 0x7f7edd088700 (LWP 4121) "publish worker" 0x00007f7ee90108fc in __lll_lock_wait () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libpthread.so.0
(gdb) thread apply 11-16 bt

Thread 11 (Thread 0x7f7edf892700 (LWP 4116)):
#0  0x00007f7ee90108fc in __lll_lock_wait () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libpthread.so.0
#1  0x00007f7ee9009b05 in pthread_mutex_lock () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libpthread.so.0
#2  0x00007f7ee9545815 in scm_pthread_mutex_lock (mutex=<optimized out>) at threads.c:1600
#3  0x00007f7ee9545969 in scm_dynwind_pthread_mutex_lock (mutex=0x7f7ee97bbfa0 <scm_i_misc_mutex>) at threads.c:1613
#4  0x00007f7ee94e2927 in scm_readdir (port=#<unmatched-tag 10a77>) at filesys.c:1749
#5  0x00007f7ee9553c4d in vm_regular_engine (thread=0x7f7ee97bbfa0 <scm_i_misc_mutex>, vp=0x211bea0, registers=0x0, resume=-385808132) at vm-engine.c:784
#6  0x00007f7ee95572aa in scm_call_n (proc=proc <at> entry=#<unmatched-tag 20045>, argv=argv <at> entry=0x0, nargs=nargs <at> entry=0) at vm.c:1257
#7  0x00007f7ee94da7d9 in scm_call_0 (proc=proc <at> entry=#<unmatched-tag 20045>) at eval.c:481
#8  0x00007f7ee94cbef8 in scm_call_with_unblocked_asyncs (proc=#<unmatched-tag 20045>) at async.c:400
#9  0x00007f7ee9553c4d in vm_regular_engine (thread=0x7f7ee97bbfa0 <scm_i_misc_mutex>, vp=0x211bea0, registers=0x0, resume=-385808132) at vm-engine.c:784
#10 0x00007f7ee95572aa in scm_call_n (proc=#<unmatched-tag 50045>, argv=argv <at> entry=0x0, nargs=nargs <at> entry=0) at vm.c:1257
#11 0x00007f7ee94da7d9 in scm_call_0 (proc=<optimized out>) at eval.c:481
#12 0x00007f7ee9544fe6 in really_launch (d=0x266ab80) at threads.c:793
#13 0x00007f7ee94d4cba in c_body (d=0x7f7edf891e60) at continuations.c:422
#14 0x00007f7ee9553c4d in vm_regular_engine (thread=0x7f7ee97bbfa0 <scm_i_misc_mutex>, vp=0x211bea0, registers=0x0, resume=-385808132) at vm-engine.c:784
#15 0x00007f7ee95572aa in scm_call_n (proc=proc <at> entry=#<unmatched-tag 1077>, argv=argv <at> entry=0x0, nargs=nargs <at> entry=0) at vm.c:1257
#16 0x00007f7ee94da7d9 in scm_call_0 (proc=proc <at> entry=#<unmatched-tag 1077>) at eval.c:481
#17 0x00007f7ee95464e6 in catch (tag=tag <at> entry=#t, thunk=#<unmatched-tag 1077>, handler=#<unmatched-tag 11077>, pre_unwind_handler=#<unmatched-tag 11077>) at throw.c:137
#18 0x00007f7ee9546825 in scm_catch_with_pre_unwind_handler (key=key <at> entry=#t, thunk=<optimized out>, handler=<optimized out>, pre_unwind_handler=<optimized out>) at throw.c:254
#19 0x00007f7ee95469df in scm_c_catch (tag=tag <at> entry=#t, body=body <at> entry=0x7f7ee94d4cb0 <c_body>, body_data=body_data <at> entry=0x7f7edf891e60, handler=handler <at> entry=0x7f7ee94d4f40 <c_handler>,
    handler_data=handler_data <at> entry=0x7f7edf891e60, pre_unwind_handler=pre_unwind_handler <at> entry=0x7f7ee94d4da0 <pre_unwind_handler>, pre_unwind_handler_data=0x2079ce0) at throw.c:377
#20 0x00007f7ee94d52a0 in scm_i_with_continuation_barrier (body=body <at> entry=0x7f7ee94d4cb0 <c_body>, body_data=body_data <at> entry=0x7f7edf891e60, handler=handler <at> entry=0x7f7ee94d4f40 <c_handler>,
    handler_data=handler_data <at> entry=0x7f7edf891e60, pre_unwind_handler=pre_unwind_handler <at> entry=0x7f7ee94d4da0 <pre_unwind_handler>, pre_unwind_handler_data=0x2079ce0) at continuations.c:360
#21 0x00007f7ee94d5335 in scm_c_with_continuation_barrier (func=<optimized out>, data=<optimized out>) at continuations.c:456
#22 0x00007f7ee954510c in with_guile (base=0x7f7edf891ec0, data=0x7f7edf891ef0) at threads.c:660
#23 0x00007f7ee923a732 in GC_call_with_stack_base () from /gnu/store/9blidf28xz0a0glnv6a4xcw6nxadg427-libgc-7.6.0/lib/libgc.so.1
#24 0x00007f7ee95447dd in scm_i_with_guile (dynamic_state=<optimized out>, data=0x266ab80, func=0x7f7ee9544f70 <really_launch>) at threads.c:703
#25 launch_thread (d=0x266ab80) at threads.c:802
#26 0x00007f7ee9007454 in start_thread () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libpthread.so.0
#27 0x00007f7ee79cf7bf in clone () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libc.so.6

Thread 12 (Thread 0x7f7edf090700 (LWP 4117)):
#0  0x00007f7ee90108fc in __lll_lock_wait () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libpthread.so.0
#1  0x00007f7ee9009b05 in pthread_mutex_lock () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libpthread.so.0
#2  0x00007f7ee9545815 in scm_pthread_mutex_lock (mutex=<optimized out>) at threads.c:1600
#3  0x00007f7ee9545969 in scm_dynwind_pthread_mutex_lock (mutex=0x7f7ee97bbfa0 <scm_i_misc_mutex>) at threads.c:1613
#4  0x00007f7ee94d8dbb in scm_strerror (err=err <at> entry=17) at error.c:128
#5  0x00007f7ee94d8e73 in scm_syserror (subr=subr <at> entry=0x7f7ee956b07a <s_scm_mkdir> "mkdir") at error.c:169
#6  0x00007f7ee94e2189 in scm_mkdir (path=<optimized out>, mode=<optimized out>) at filesys.c:1274
#7  0x00007f7ee9553c4d in vm_regular_engine (thread=0x7f7ee97bbfa0 <scm_i_misc_mutex>, vp=0x211be10, registers=0x0, resume=-385808132) at vm-engine.c:784
#8  0x00007f7ee95572aa in scm_call_n (proc=proc <at> entry=#<unmatched-tag 20045>, argv=argv <at> entry=0x0, nargs=nargs <at> entry=0) at vm.c:1257
#9  0x00007f7ee94da7d9 in scm_call_0 (proc=proc <at> entry=#<unmatched-tag 20045>) at eval.c:481
#10 0x00007f7ee94cbef8 in scm_call_with_unblocked_asyncs (proc=#<unmatched-tag 20045>) at async.c:400
#11 0x00007f7ee9553c4d in vm_regular_engine (thread=0x7f7ee97bbfa0 <scm_i_misc_mutex>, vp=0x211be10, registers=0x0, resume=-385808132) at vm-engine.c:784
#12 0x00007f7ee95572aa in scm_call_n (proc=#<unmatched-tag 50045>, argv=argv <at> entry=0x0, nargs=nargs <at> entry=0) at vm.c:1257
#13 0x00007f7ee94da7d9 in scm_call_0 (proc=<optimized out>) at eval.c:481
#14 0x00007f7ee9544fe6 in really_launch (d=0x266ab40) at threads.c:793
#15 0x00007f7ee94d4cba in c_body (d=0x7f7edf08fe60) at continuations.c:422
#16 0x00007f7ee9553c4d in vm_regular_engine (thread=0x7f7ee97bbfa0 <scm_i_misc_mutex>, vp=0x211be10, registers=0x0, resume=-385808132) at vm-engine.c:784
#17 0x00007f7ee95572aa in scm_call_n (proc=proc <at> entry=#<unmatched-tag 1077>, argv=argv <at> entry=0x0, nargs=nargs <at> entry=0) at vm.c:1257
#18 0x00007f7ee94da7d9 in scm_call_0 (proc=proc <at> entry=#<unmatched-tag 1077>) at eval.c:481
#19 0x00007f7ee95464e6 in catch (tag=tag <at> entry=#t, thunk=#<unmatched-tag 1077>, handler=#<unmatched-tag 11077>, pre_unwind_handler=#<unmatched-tag 11077>) at throw.c:137
#20 0x00007f7ee9546825 in scm_catch_with_pre_unwind_handler (key=key <at> entry=#t, thunk=<optimized out>, handler=<optimized out>, pre_unwind_handler=<optimized out>) at throw.c:254
#21 0x00007f7ee95469df in scm_c_catch (tag=tag <at> entry=#t, body=body <at> entry=0x7f7ee94d4cb0 <c_body>, body_data=body_data <at> entry=0x7f7edf08fe60, handler=handler <at> entry=0x7f7ee94d4f40 <c_handler>,
    handler_data=handler_data <at> entry=0x7f7edf08fe60, pre_unwind_handler=pre_unwind_handler <at> entry=0x7f7ee94d4da0 <pre_unwind_handler>, pre_unwind_handler_data=0x2079ce0) at throw.c:377
#22 0x00007f7ee94d52a0 in scm_i_with_continuation_barrier (body=body <at> entry=0x7f7ee94d4cb0 <c_body>, body_data=body_data <at> entry=0x7f7edf08fe60, handler=handler <at> entry=0x7f7ee94d4f40 <c_handler>,
    handler_data=handler_data <at> entry=0x7f7edf08fe60, pre_unwind_handler=pre_unwind_handler <at> entry=0x7f7ee94d4da0 <pre_unwind_handler>, pre_unwind_handler_data=0x2079ce0) at continuations.c:360
#23 0x00007f7ee94d5335 in scm_c_with_continuation_barrier (func=<optimized out>, data=<optimized out>) at continuations.c:456
#24 0x00007f7ee954510c in with_guile (base=0x7f7edf08fec0, data=0x7f7edf08fef0) at threads.c:660
#25 0x00007f7ee923a732 in GC_call_with_stack_base () from /gnu/store/9blidf28xz0a0glnv6a4xcw6nxadg427-libgc-7.6.0/lib/libgc.so.1
#26 0x00007f7ee95447dd in scm_i_with_guile (dynamic_state=<optimized out>, data=0x266ab40, func=0x7f7ee9544f70 <really_launch>) at threads.c:703
#27 launch_thread (d=0x266ab40) at threads.c:802
#28 0x00007f7ee9007454 in start_thread () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libpthread.so.0
#29 0x00007f7ee79cf7bf in clone () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libc.so.6

Thread 13 (Thread 0x7f7ede88e700 (LWP 4118)):
#0  0x00007f7ee90108fc in __lll_lock_wait () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libpthread.so.0
#1  0x00007f7ee9009b05 in pthread_mutex_lock () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libpthread.so.0
#2  0x00007f7ee9545815 in scm_pthread_mutex_lock (mutex=<optimized out>) at threads.c:1600
#3  0x00007f7ee9545969 in scm_dynwind_pthread_mutex_lock (mutex=0x7f7ee97bbfa0 <scm_i_misc_mutex>) at threads.c:1613
#4  0x00007f7ee94e2927 in scm_readdir (port=#<unmatched-tag 10a77>) at filesys.c:1749
#5  0x00007f7ee9553c4d in vm_regular_engine (thread=0x7f7ee97bbfa0 <scm_i_misc_mutex>, vp=0x211bd80, registers=0x0, resume=-385808132) at vm-engine.c:784
#6  0x00007f7ee95572aa in scm_call_n (proc=proc <at> entry=#<unmatched-tag 20045>, argv=argv <at> entry=0x0, nargs=nargs <at> entry=0) at vm.c:1257
#7  0x00007f7ee94da7d9 in scm_call_0 (proc=proc <at> entry=#<unmatched-tag 20045>) at eval.c:481
#8  0x00007f7ee94cbef8 in scm_call_with_unblocked_asyncs (proc=#<unmatched-tag 20045>) at async.c:400
#9  0x00007f7ee9553c4d in vm_regular_engine (thread=0x7f7ee97bbfa0 <scm_i_misc_mutex>, vp=0x211bd80, registers=0x0, resume=-385808132) at vm-engine.c:784
#10 0x00007f7ee95572aa in scm_call_n (proc=#<unmatched-tag 50045>, argv=argv <at> entry=0x0, nargs=nargs <at> entry=0) at vm.c:1257
#11 0x00007f7ee94da7d9 in scm_call_0 (proc=<optimized out>) at eval.c:481
#12 0x00007f7ee9544fe6 in really_launch (d=0x266ab00) at threads.c:793
#13 0x00007f7ee94d4cba in c_body (d=0x7f7ede88de60) at continuations.c:422
#14 0x00007f7ee9553c4d in vm_regular_engine (thread=0x7f7ee97bbfa0 <scm_i_misc_mutex>, vp=0x211bd80, registers=0x0, resume=-385808132) at vm-engine.c:784
#15 0x00007f7ee95572aa in scm_call_n (proc=proc <at> entry=#<unmatched-tag 1077>, argv=argv <at> entry=0x0, nargs=nargs <at> entry=0) at vm.c:1257
#16 0x00007f7ee94da7d9 in scm_call_0 (proc=proc <at> entry=#<unmatched-tag 1077>) at eval.c:481
#17 0x00007f7ee95464e6 in catch (tag=tag <at> entry=#t, thunk=#<unmatched-tag 1077>, handler=#<unmatched-tag 11077>, pre_unwind_handler=#<unmatched-tag 11077>) at throw.c:137
#18 0x00007f7ee9546825 in scm_catch_with_pre_unwind_handler (key=key <at> entry=#t, thunk=<optimized out>, handler=<optimized out>, pre_unwind_handler=<optimized out>) at throw.c:254
#19 0x00007f7ee95469df in scm_c_catch (tag=tag <at> entry=#t, body=body <at> entry=0x7f7ee94d4cb0 <c_body>, body_data=body_data <at> entry=0x7f7ede88de60, handler=handler <at> entry=0x7f7ee94d4f40 <c_handler>,
    handler_data=handler_data <at> entry=0x7f7ede88de60, pre_unwind_handler=pre_unwind_handler <at> entry=0x7f7ee94d4da0 <pre_unwind_handler>, pre_unwind_handler_data=0x2079ce0) at throw.c:377
#20 0x00007f7ee94d52a0 in scm_i_with_continuation_barrier (body=body <at> entry=0x7f7ee94d4cb0 <c_body>, body_data=body_data <at> entry=0x7f7ede88de60, handler=handler <at> entry=0x7f7ee94d4f40 <c_handler>,
    handler_data=handler_data <at> entry=0x7f7ede88de60, pre_unwind_handler=pre_unwind_handler <at> entry=0x7f7ee94d4da0 <pre_unwind_handler>, pre_unwind_handler_data=0x2079ce0) at continuations.c:360
#21 0x00007f7ee94d5335 in scm_c_with_continuation_barrier (func=<optimized out>, data=<optimized out>) at continuations.c:456
#22 0x00007f7ee954510c in with_guile (base=0x7f7ede88dec0, data=0x7f7ede88def0) at threads.c:660
#23 0x00007f7ee923a732 in GC_call_with_stack_base () from /gnu/store/9blidf28xz0a0glnv6a4xcw6nxadg427-libgc-7.6.0/lib/libgc.so.1
#24 0x00007f7ee95447dd in scm_i_with_guile (dynamic_state=<optimized out>, data=0x266ab00, func=0x7f7ee9544f70 <really_launch>) at threads.c:703
#25 launch_thread (d=0x266ab00) at threads.c:802
#26 0x00007f7ee9007454 in start_thread () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libpthread.so.0
#27 0x00007f7ee79cf7bf in clone () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libc.so.6

Thread 14 (Thread 0x7f7ede08c700 (LWP 4119)):
#0  0x00007f7ee90108fc in __lll_lock_wait () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libpthread.so.0
#1  0x00007f7ee9009b05 in pthread_mutex_lock () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libpthread.so.0
#2  0x00007f7ee9545815 in scm_pthread_mutex_lock (mutex=<optimized out>) at threads.c:1600
#3  0x00007f7ee9545969 in scm_dynwind_pthread_mutex_lock (mutex=0x7f7ee97bbfa0 <scm_i_misc_mutex>) at threads.c:1613
#4  0x00007f7ee94d8dbb in scm_strerror (err=err <at> entry=9) at error.c:128
#5  0x00007f7ee94d8e73 in scm_syserror (subr=subr <at> entry=0x7f7ee956afa0 <s_scm_readdir> "readdir") at error.c:169
#6  0x00007f7ee94e29b4 in scm_readdir (port=#<unmatched-tag 10a77>) at filesys.c:1754
#7  0x00007f7ee9553c4d in vm_regular_engine (thread=0x7f7ee97bbfa0 <scm_i_misc_mutex>, vp=0x211bcf0, registers=0x0, resume=-385808132) at vm-engine.c:784
#8  0x00007f7ee95572aa in scm_call_n (proc=proc <at> entry=#<unmatched-tag 20045>, argv=argv <at> entry=0x0, nargs=nargs <at> entry=0) at vm.c:1257
#9  0x00007f7ee94da7d9 in scm_call_0 (proc=proc <at> entry=#<unmatched-tag 20045>) at eval.c:481
#10 0x00007f7ee94cbef8 in scm_call_with_unblocked_asyncs (proc=#<unmatched-tag 20045>) at async.c:400
#11 0x00007f7ee9553c4d in vm_regular_engine (thread=0x7f7ee97bbfa0 <scm_i_misc_mutex>, vp=0x211bcf0, registers=0x0, resume=-385808132) at vm-engine.c:784
#12 0x00007f7ee95572aa in scm_call_n (proc=#<unmatched-tag 50045>, argv=argv <at> entry=0x0, nargs=nargs <at> entry=0) at vm.c:1257
#13 0x00007f7ee94da7d9 in scm_call_0 (proc=<optimized out>) at eval.c:481
#14 0x00007f7ee9544fe6 in really_launch (d=0x266aac0) at threads.c:793
#15 0x00007f7ee94d4cba in c_body (d=0x7f7ede08be60) at continuations.c:422
#16 0x00007f7ee9553c4d in vm_regular_engine (thread=0x7f7ee97bbfa0 <scm_i_misc_mutex>, vp=0x211bcf0, registers=0x0, resume=-385808132) at vm-engine.c:784
#17 0x00007f7ee95572aa in scm_call_n (proc=proc <at> entry=#<unmatched-tag 1077>, argv=argv <at> entry=0x0, nargs=nargs <at> entry=0) at vm.c:1257
#18 0x00007f7ee94da7d9 in scm_call_0 (proc=proc <at> entry=#<unmatched-tag 1077>) at eval.c:481
#19 0x00007f7ee95464e6 in catch (tag=tag <at> entry=#t, thunk=#<unmatched-tag 1077>, handler=#<unmatched-tag 11077>, pre_unwind_handler=#<unmatched-tag 11077>) at throw.c:137
#20 0x00007f7ee9546825 in scm_catch_with_pre_unwind_handler (key=key <at> entry=#t, thunk=<optimized out>, handler=<optimized out>, pre_unwind_handler=<optimized out>) at throw.c:254
#21 0x00007f7ee95469df in scm_c_catch (tag=tag <at> entry=#t, body=body <at> entry=0x7f7ee94d4cb0 <c_body>, body_data=body_data <at> entry=0x7f7ede08be60, handler=handler <at> entry=0x7f7ee94d4f40 <c_handler>,
    handler_data=handler_data <at> entry=0x7f7ede08be60, pre_unwind_handler=pre_unwind_handler <at> entry=0x7f7ee94d4da0 <pre_unwind_handler>, pre_unwind_handler_data=0x2079ce0) at throw.c:377
#22 0x00007f7ee94d52a0 in scm_i_with_continuation_barrier (body=body <at> entry=0x7f7ee94d4cb0 <c_body>, body_data=body_data <at> entry=0x7f7ede08be60, handler=handler <at> entry=0x7f7ee94d4f40 <c_handler>,
    handler_data=handler_data <at> entry=0x7f7ede08be60, pre_unwind_handler=pre_unwind_handler <at> entry=0x7f7ee94d4da0 <pre_unwind_handler>, pre_unwind_handler_data=0x2079ce0) at continuations.c:360
#23 0x00007f7ee94d5335 in scm_c_with_continuation_barrier (func=<optimized out>, data=<optimized out>) at continuations.c:456
#24 0x00007f7ee954510c in with_guile (base=0x7f7ede08bec0, data=0x7f7ede08bef0) at threads.c:660
#25 0x00007f7ee923a732 in GC_call_with_stack_base () from /gnu/store/9blidf28xz0a0glnv6a4xcw6nxadg427-libgc-7.6.0/lib/libgc.so.1
#26 0x00007f7ee95447dd in scm_i_with_guile (dynamic_state=<optimized out>, data=0x266aac0, func=0x7f7ee9544f70 <really_launch>) at threads.c:703
#27 launch_thread (d=0x266aac0) at threads.c:802
#28 0x00007f7ee9007454 in start_thread () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libpthread.so.0
#29 0x00007f7ee79cf7bf in clone () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libc.so.6

Thread 15 (Thread 0x7f7edd88a700 (LWP 4120)):
#0  0x00007f7ee90108fc in __lll_lock_wait () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libpthread.so.0
#1  0x00007f7ee9009b05 in pthread_mutex_lock () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libpthread.so.0
#2  0x00007f7ee9545815 in scm_pthread_mutex_lock (mutex=<optimized out>) at threads.c:1600
#3  0x00007f7ee9545969 in scm_dynwind_pthread_mutex_lock (mutex=0x7f7ee97bbfa0 <scm_i_misc_mutex>) at threads.c:1613
#4  0x00007f7ee94e2927 in scm_readdir (port=#<unmatched-tag 10a77>) at filesys.c:1749
#5  0x00007f7ee9553c4d in vm_regular_engine (thread=0x7f7ee97bbfa0 <scm_i_misc_mutex>, vp=0x211bc60, registers=0x0, resume=-385808132) at vm-engine.c:784
#6  0x00007f7ee95572aa in scm_call_n (proc=proc <at> entry=#<unmatched-tag 20045>, argv=argv <at> entry=0x0, nargs=nargs <at> entry=0) at vm.c:1257
#7  0x00007f7ee94da7d9 in scm_call_0 (proc=proc <at> entry=#<unmatched-tag 20045>) at eval.c:481
#8  0x00007f7ee94cbef8 in scm_call_with_unblocked_asyncs (proc=#<unmatched-tag 20045>) at async.c:400
#9  0x00007f7ee9553c4d in vm_regular_engine (thread=0x7f7ee97bbfa0 <scm_i_misc_mutex>, vp=0x211bc60, registers=0x0, resume=-385808132) at vm-engine.c:784
#10 0x00007f7ee95572aa in scm_call_n (proc=#<unmatched-tag 50045>, argv=argv <at> entry=0x0, nargs=nargs <at> entry=0) at vm.c:1257
#11 0x00007f7ee94da7d9 in scm_call_0 (proc=<optimized out>) at eval.c:481
---Type <return> to continue, or q <return> to quit---
#12 0x00007f7ee9544fe6 in really_launch (d=0x266aa80) at threads.c:793
#13 0x00007f7ee94d4cba in c_body (d=0x7f7edd889e60) at continuations.c:422
#14 0x00007f7ee9553c4d in vm_regular_engine (thread=0x7f7ee97bbfa0 <scm_i_misc_mutex>, vp=0x211bc60, registers=0x0, resume=-385808132) at vm-engine.c:784
#15 0x00007f7ee95572aa in scm_call_n (proc=proc <at> entry=#<unmatched-tag 1077>, argv=argv <at> entry=0x0, nargs=nargs <at> entry=0) at vm.c:1257
#16 0x00007f7ee94da7d9 in scm_call_0 (proc=proc <at> entry=#<unmatched-tag 1077>) at eval.c:481
#17 0x00007f7ee95464e6 in catch (tag=tag <at> entry=#t, thunk=#<unmatched-tag 1077>, handler=#<unmatched-tag 11077>, pre_unwind_handler=#<unmatched-tag 11077>) at throw.c:137
#18 0x00007f7ee9546825 in scm_catch_with_pre_unwind_handler (key=key <at> entry=#t, thunk=<optimized out>, handler=<optimized out>, pre_unwind_handler=<optimized out>) at throw.c:254
#19 0x00007f7ee95469df in scm_c_catch (tag=tag <at> entry=#t, body=body <at> entry=0x7f7ee94d4cb0 <c_body>, body_data=body_data <at> entry=0x7f7edd889e60, handler=handler <at> entry=0x7f7ee94d4f40 <c_handler>,
    handler_data=handler_data <at> entry=0x7f7edd889e60, pre_unwind_handler=pre_unwind_handler <at> entry=0x7f7ee94d4da0 <pre_unwind_handler>, pre_unwind_handler_data=0x2079ce0) at throw.c:377
#20 0x00007f7ee94d52a0 in scm_i_with_continuation_barrier (body=body <at> entry=0x7f7ee94d4cb0 <c_body>, body_data=body_data <at> entry=0x7f7edd889e60, handler=handler <at> entry=0x7f7ee94d4f40 <c_handler>,
    handler_data=handler_data <at> entry=0x7f7edd889e60, pre_unwind_handler=pre_unwind_handler <at> entry=0x7f7ee94d4da0 <pre_unwind_handler>, pre_unwind_handler_data=0x2079ce0) at continuations.c:360
#21 0x00007f7ee94d5335 in scm_c_with_continuation_barrier (func=<optimized out>, data=<optimized out>) at continuations.c:456
#22 0x00007f7ee954510c in with_guile (base=0x7f7edd889ec0, data=0x7f7edd889ef0) at threads.c:660
#23 0x00007f7ee923a732 in GC_call_with_stack_base () from /gnu/store/9blidf28xz0a0glnv6a4xcw6nxadg427-libgc-7.6.0/lib/libgc.so.1
#24 0x00007f7ee95447dd in scm_i_with_guile (dynamic_state=<optimized out>, data=0x266aa80, func=0x7f7ee9544f70 <really_launch>) at threads.c:703
#25 launch_thread (d=0x266aa80) at threads.c:802
#26 0x00007f7ee9007454 in start_thread () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libpthread.so.0
#27 0x00007f7ee79cf7bf in clone () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libc.so.6

Thread 16 (Thread 0x7f7edd088700 (LWP 4121)):
#0  0x00007f7ee90108fc in __lll_lock_wait () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libpthread.so.0
#1  0x00007f7ee9009b05 in pthread_mutex_lock () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libpthread.so.0
#2  0x00007f7ee9545815 in scm_pthread_mutex_lock (mutex=<optimized out>) at threads.c:1600
#3  0x00007f7ee9545969 in scm_dynwind_pthread_mutex_lock (mutex=0x7f7ee97bbfa0 <scm_i_misc_mutex>) at threads.c:1613
#4  0x00007f7ee94d8dbb in scm_strerror (err=err <at> entry=9) at error.c:128
#5  0x00007f7ee94d8e73 in scm_syserror (subr=subr <at> entry=0x7f7ee956bbd9 "fport_close") at error.c:169
#6  0x00007f7ee94e7a85 in fport_close (port=<optimized out>) at fports.c:677
#7  0x00007f7ee9514785 in release_port (port=#<port 4 2a15940>) at ports.c:158
#8  0x00007f7ee9517a0b in scm_close_port (port=#<port 4 2a15940>) at ports.c:887
#9  0x00007f7ee9553c4d in vm_regular_engine (thread=0x7f7ee97bbfa0 <scm_i_misc_mutex>, vp=0x211bbd0, registers=0x0, resume=-385808132) at vm-engine.c:784
#10 0x00007f7ee95572aa in scm_call_n (proc=#<unmatched-tag 20045>, argv=<optimized out>, nargs=0) at vm.c:1257
#11 0x00007f7ee9514785 in release_port (port=#<port 4 2a158c0>) at ports.c:158
#12 0x00007f7ee9517a0b in scm_close_port (port=#<port 4 2a158c0>) at ports.c:887
#13 0x00007f7ee9553c4d in vm_regular_engine (thread=0x7f7ee97bbfa0 <scm_i_misc_mutex>, vp=0x211bbd0, registers=0x0, resume=-385808132) at vm-engine.c:784
#14 0x00007f7ee95572aa in scm_call_n (proc=#<unmatched-tag 10045>, argv=argv <at> entry=0x0, nargs=nargs <at> entry=0) at vm.c:1257
#15 0x00007f7ee94da7d9 in scm_call_0 (proc=<optimized out>) at eval.c:481
#16 0x00007f7ee94d7ba0 in scm_dynstack_unwind_1 (dynstack=dynstack <at> entry=0x1fd9088) at dynstack.c:407
#17 0x00007f7ee94d7cd0 in scm_dynstack_unwind (dynstack=dynstack <at> entry=0x1fd9088, base=0x29e1720) at dynstack.c:437
#18 0x00007f7ee94d4b02 in scm_c_abort (vp=0x211bbd0, tag=<optimized out>, n=5, argv=0x7f7edd087200, current_registers=<optimized out>) at control.c:162
#19 0x00007f7ee9548df1 in vm_abort (vp=<optimized out>, tag=<optimized out>, nargs=<optimized out>, current_registers=<optimized out>) at vm.c:340
#20 0x00007f7ee9553cc6 in vm_regular_engine (thread=0x7f7ee97bbfa0 <scm_i_misc_mutex>, vp=0x211bbd0, registers=0x0, resume=-385808132) at vm-engine.c:1004
#21 0x00007f7ee95572aa in scm_call_n (proc=proc <at> entry=#<unmatched-tag 10045>, argv=<optimized out>, nargs=5) at vm.c:1257
#22 0x00007f7ee94dab6b in scm_apply_0 (proc=#<unmatched-tag 10045>, args=()) at eval.c:594
#23 0x00007f7ee94db76d in scm_apply_1 (proc=<optimized out>, arg1=arg1 <at> entry=system-error, args=<optimized out>) at eval.c:600
#24 0x00007f7ee954686c in scm_throw (key=key <at> entry=system-error, args=<optimized out>) at throw.c:266
#25 0x00007f7ee9546de5 in scm_ithrow (key=key <at> entry=system-error, args=<optimized out>, no_return=no_return <at> entry=1) at throw.c:611
#26 0x00007f7ee94d8d75 in scm_error_scm (key=key <at> entry=system-error, subr=<optimized out>, message=message <at> entry="~A", args=args <at> entry=("Invalid argument"), data=data <at> entry=(22)) at error.c:94
#27 0x00007f7ee94d8e2f in scm_error (key=system-error, subr=subr <at> entry=0x7f7ee956bbf1 "fport_read", message=message <at> entry=0x7f7ee95732db "~A", args=("Invalid argument"), rest=rest <at> entry=(22))
    at error.c:59
#28 0x00007f7ee94d8eaa in scm_syserror (subr=subr <at> entry=0x7f7ee956bbf1 "fport_read") at error.c:169
#29 0x00007f7ee94e7c75 in fport_read (port=<optimized out>, dst=<optimized out>, start=<optimized out>, count=58928) at fports.c:614
#30 0x00007f7ee9514d77 in scm_i_read_bytes (port=port <at> entry=#<port 2 26655c0>, dst=dst <at> entry="#<vu8vector>" = {...}, start=start <at> entry=0, count=count <at> entry=58928) at ports.c:1544
#31 0x00007f7ee95193fc in scm_c_read_bytes (port=port <at> entry=#<port 2 26655c0>, dst=dst <at> entry="#<vu8vector>" = {...}, start=start <at> entry=0, count=58928) at ports.c:1624
#32 0x00007f7ee951eb78 in scm_get_bytevector_n_x (port=#<port 2 26655c0>, bv="#<vu8vector>" = {...}, start=<optimized out>, count=58928) at r6rs-ports.c:461
#33 0x00007f7ee9553c4d in vm_regular_engine (thread=0x7f7ee97bbfa0 <scm_i_misc_mutex>, vp=0x211bbd0, registers=0x0, resume=-385808132) at vm-engine.c:784
#34 0x00007f7ee95572aa in scm_call_n (proc=proc <at> entry=#<unmatched-tag 20045>, argv=argv <at> entry=0x0, nargs=nargs <at> entry=0) at vm.c:1257
#35 0x00007f7ee94da7d9 in scm_call_0 (proc=proc <at> entry=#<unmatched-tag 20045>) at eval.c:481
#36 0x00007f7ee94cbef8 in scm_call_with_unblocked_asyncs (proc=#<unmatched-tag 20045>) at async.c:400
#37 0x00007f7ee9553c4d in vm_regular_engine (thread=0x7f7ee97bbfa0 <scm_i_misc_mutex>, vp=0x211bbd0, registers=0x0, resume=-385808132) at vm-engine.c:784
#38 0x00007f7ee95572aa in scm_call_n (proc=#<unmatched-tag 50045>, argv=argv <at> entry=0x0, nargs=nargs <at> entry=0) at vm.c:1257
#39 0x00007f7ee94da7d9 in scm_call_0 (proc=<optimized out>) at eval.c:481
#40 0x00007f7ee9544fe6 in really_launch (d=0x266aa40) at threads.c:793
#41 0x00007f7ee94d4cba in c_body (d=0x7f7edd087e60) at continuations.c:422
#42 0x00007f7ee9553c4d in vm_regular_engine (thread=0x7f7ee97bbfa0 <scm_i_misc_mutex>, vp=0x211bbd0, registers=0x0, resume=-385808132) at vm-engine.c:784
#43 0x00007f7ee95572aa in scm_call_n (proc=proc <at> entry=#<unmatched-tag 1077>, argv=argv <at> entry=0x0, nargs=nargs <at> entry=0) at vm.c:1257
#44 0x00007f7ee94da7d9 in scm_call_0 (proc=proc <at> entry=#<unmatched-tag 1077>) at eval.c:481
#45 0x00007f7ee95464e6 in catch (tag=tag <at> entry=#t, thunk=#<unmatched-tag 1077>, handler=#<unmatched-tag 11077>, pre_unwind_handler=#<unmatched-tag 11077>) at throw.c:137
#46 0x00007f7ee9546825 in scm_catch_with_pre_unwind_handler (key=key <at> entry=#t, thunk=<optimized out>, handler=<optimized out>, pre_unwind_handler=<optimized out>) at throw.c:254
#47 0x00007f7ee95469df in scm_c_catch (tag=tag <at> entry=#t, body=body <at> entry=0x7f7ee94d4cb0 <c_body>, body_data=body_data <at> entry=0x7f7edd087e60, handler=handler <at> entry=0x7f7ee94d4f40 <c_handler>,
    handler_data=handler_data <at> entry=0x7f7edd087e60, pre_unwind_handler=pre_unwind_handler <at> entry=0x7f7ee94d4da0 <pre_unwind_handler>, pre_unwind_handler_data=0x2079ce0) at throw.c:377
#48 0x00007f7ee94d52a0 in scm_i_with_continuation_barrier (body=body <at> entry=0x7f7ee94d4cb0 <c_body>, body_data=body_data <at> entry=0x7f7edd087e60, handler=handler <at> entry=0x7f7ee94d4f40 <c_handler>,
    handler_data=handler_data <at> entry=0x7f7edd087e60, pre_unwind_handler=pre_unwind_handler <at> entry=0x7f7ee94d4da0 <pre_unwind_handler>, pre_unwind_handler_data=0x2079ce0) at continuations.c:360
#49 0x00007f7ee94d5335 in scm_c_with_continuation_barrier (func=<optimized out>, data=<optimized out>) at continuations.c:456
#50 0x00007f7ee954510c in with_guile (base=0x7f7edd087ec0, data=0x7f7edd087ef0) at threads.c:660
#51 0x00007f7ee923a732 in GC_call_with_stack_base () from /gnu/store/9blidf28xz0a0glnv6a4xcw6nxadg427-libgc-7.6.0/lib/libgc.so.1
#52 0x00007f7ee95447dd in scm_i_with_guile (dynamic_state=<optimized out>, data=0x266aa40, func=0x7f7ee9544f70 <really_launch>) at threads.c:703
#53 launch_thread (d=0x266aa40) at threads.c:802
#54 0x00007f7ee9007454 in start_thread () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libpthread.so.0
#55 0x00007f7ee79cf7bf in clone () from /gnu/store/n6nvxlk2j8ysffjh3jphn1k5silnakh6-glibc-2.25/lib/libc.so.6
--8<---------------cut here---------------end--------------->8---

Thread 14 is in scm_readdir, so it holds the terrible
‘scm_i_misc_mutex’, but calling SCM_SYSERROR there causes it to try and
lock it again, leading to a deadlock:

--8<---------------cut here---------------start------------->8---
#3  0x00007f7ee9545969 in scm_dynwind_pthread_mutex_lock (mutex=0x7f7ee97bbfa0 <scm_i_misc_mutex>) at threads.c:1613
#4  0x00007f7ee94d8dbb in scm_strerror (err=err <at> entry=9) at error.c:128
#5  0x00007f7ee94d8e73 in scm_syserror (subr=subr <at> entry=0x7f7ee956afa0 <s_scm_readdir> "readdir") at error.c:169
#6  0x00007f7ee94e29b4 in scm_readdir (port=#<unmatched-tag 10a77>) at filesys.c:1754
--8<---------------cut here---------------end--------------->8---

Thread 16 got EINVAL from read(2), which sounds fishy:

--8<---------------cut here---------------start------------->8---
#29 0x00007f7ee94e7c75 in fport_read (port=<optimized out>, dst=<optimized out>, start=<optimized out>, count=58928) at fports.c:614
614     in fports.c
(gdb) p *fp
$1 = {fdes = 35, revealed = 0, options = 0}
(gdb) shell ls -l /proc/4105/fd/35
ls: cannot access '/proc/4105/fd/35': No such file or directory
--8<---------------cut here---------------end--------------->8---

To be continued…

Ludo’.
This bug report was last modified 7 years and 280 days ago.

Previous Next

GNU bug tracking system
Copyright (C) 1999 Darren O. Benham, 1997,2003 nCipher Corporation Ltd, 1994-97 Ian Jackson.