mcron (herd?) scheduling issues

  • Open
  • quality assurance status badge
Details
4 participants
  • Attila Lendvai
  • Timo Wilken
  • Ludovic Courtès
  • VÖRÖSK?I András
Owner
unassigned
Submitted by
VÖRÖSK?I András
Severity
normal
V
V
VÖRÖSK?I András wrote on 16 Nov 2023 18:00
(address . bug-guix@gnu.org)
CX0BTH384M7U.22ARMKPXTORWN@gmail.com
Hi,

I try to use mcron to fetch emails. I have the following in my
`home-configuration.scm`:

(service home-mcron-service-type
(home-mcron-configuration
(jobs (list
#~(job "*/15 * * * *" "mailctl fetch && notmuch new")))))

The reconfiguration runs fine, but the sheduling does not work at all.
Calling the command from the console works fine.

The job seems to work as expected:

[I] voroskoi@wasteland ~ [SIGINT]> ps aux |rg mcron /gnu/store/smz1v6jxzrs2ddl1nrgdjlm261jlf1vx-profile
root 426 0.0 0.2 157848 19840 ? Ssl 16:32 0:00 /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/bin/guile --no-auto-compile /gnu/store/2izimf0xymk3qm35i7lsqbhpid2235ik-mcron-1.2.3/bin/mcron --log --log-format ~1@*~a ~a: ~a~% /gnu/store/annwvnihjy5sghw6s05l6kzijk6rbg93-mcron-job /gnu/store/dx7gyb3mrfzpwrsfjfjfnicmiqz7jszw-mcron-job /gnu/store/knfag5iw4mqhf6lqb462p95zs3knici3-mcron-job
voroskoi 791 0.0 0.2 96020 22272 ? Ssl 16:33 0:00 /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/bin/guile --no-auto-compile /gnu/store/2izimf0xymk3qm35i7lsqbhpid2235ik-mcron-1.2.3/bin/mcron --log --log-format ~1@*~a ~a: ~a~% /gnu/store/b8dyn5kszvg8f41badp0lrcbi5xk95cj-mcron-job
voroskoi 9348 0.0 0.0 10460 7140 pts/3 S+ 17:52 0:00 rg mcron

However both `herd status` and `herd schedule mcron` hangs without any output.

Below is the strace output for the latter (both stops at this read call).

Can You give me any hint on this?

Thanks,


[I] voroskoi@wasteland ~> strace herd schedule mcron /gnu/store/smz1v6jxzrs2ddl1nrgdjlm261jlf1vx-profile
execve("/home/voroskoi/.guix-home/profile/bin/herd", ["herd", "schedule", "mcron"], 0x7ffd434a2480 /* 62 vars */) = 0
brk(NULL) = 0x1787000
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f42c5639000
access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
readlink("/proc/self/exe", "/gnu/store/n24l8hxn6nvb7lz7zjlyd"..., 4096) = 65
openat(AT_FDCWD, "/gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
newfstatat(3, "", {st_mode=S_IFREG|0444, st_size=6927, ...}, AT_EMPTY_PATH) = 0
mmap(NULL, 6927, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f42c5637000
close(3) = 0
openat(AT_FDCWD, "/gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0\0\0\0\0\0\0\0"..., 832) = 832
pread64(3, "\4\0\0\0 \0\0\0\5\0\0\0GNU\0\1\0\1\300\4\0\0\0\t\0\0\0\0\0\0\0"..., 48, 1257288) = 48
newfstatat(3, "", {st_mode=S_IFREG|0555, st_size=1290288, ...}, AT_EMPTY_PATH) = 0
mmap(NULL, 1329104, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f42c54f2000
mprotect(0x7f42c5524000, 1056768, PROT_NONE) = 0
mmap(0x7f42c5524000, 765952, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x32000) = 0x7f42c5524000
mmap(0x7f42c55df000, 286720, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xed000) = 0x7f42c55df000
mmap(0x7f42c5626000, 32768, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x133000) = 0x7f42c5626000
mmap(0x7f42c562e000, 34768, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f42c562e000
close(3) = 0
openat(AT_FDCWD, "/gnu/store/k1ha4n9v8d7myiiszvl2ic7xnb56l219-libgc-8.2.2/lib/libgc.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0\0\0\0\0\0\0\0"..., 832) = 832
pread64(3, "\4\0\0\0 \0\0\0\5\0\0\0GNU\0\1\0\1\300\4\0\0\0\v\0\0\0\0\0\0\0"..., 48, 180776) = 48
newfstatat(3, "", {st_mode=S_IFREG|0555, st_size=188792, ...}, AT_EMPTY_PATH) = 0
mmap(NULL, 445608, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f42c5485000
mmap(0x7f42c548c000, 114688, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x7000) = 0x7f42c548c000
mmap(0x7f42c54a8000, 40960, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x23000) = 0x7f42c54a8000
mmap(0x7f42c54b2000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2c000) = 0x7f42c54b2000
mmap(0x7f42c54b4000, 253096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f42c54b4000
close(3) = 0
openat(AT_FDCWD, "/gnu/store/l0y8jkmip7qpa7x33972mn0dsfy8ac01-libffi-3.4.4/lib/libffi.so.8", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0\0\0\0\0\0\0\0"..., 832) = 832
pread64(3, "\4\0\0\0 \0\0\0\5\0\0\0GNU\0\1\0\1\300\4\0\0\0\v\0\0\0\0\0\0\0"..., 48, 54296) = 48
newfstatat(3, "", {st_mode=S_IFREG|0555, st_size=60056, ...}, AT_EMPTY_PATH) = 0
mmap(NULL, 63296, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f42c5475000
mmap(0x7f42c5477000, 40960, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) = 0x7f42c5477000
mmap(0x7f42c5481000, 8192, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xc000) = 0x7f42c5481000
mmap(0x7f42c5483000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xd000) = 0x7f42c5483000
close(3) = 0
openat(AT_FDCWD, "/gnu/store/jmhgczf8brflqrq5qir8gw5aq7f16g1i-libunistring-1.0/lib/libunistring.so.2", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0\0\0\0\0\0\0\0"..., 832) = 832
pread64(3, "\4\0\0\0 \0\0\0\5\0\0\0GNU\0\1\0\1\300\4\0\0\0\v\0\0\0\0\0\0\0"..., 48, 1731768) = 48
newfstatat(3, "", {st_mode=S_IFREG|0555, st_size=1749064, ...}, AT_EMPTY_PATH) = 0
mmap(NULL, 1753288, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f42c52c8000
mmap(0x7f42c52db000, 217088, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x13000) = 0x7f42c52db000
mmap(0x7f42c5310000, 1437696, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x48000) = 0x7f42c5310000
mmap(0x7f42c546f000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1a6000) = 0x7f42c546f000
mmap(0x7f42c5474000, 200, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f42c5474000
close(3) = 0
openat(AT_FDCWD, "/gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libcrypt.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0\0\0\0\0\0\0\0"..., 832) = 832
newfstatat(3, "", {st_mode=S_IFREG|0555, st_size=47968, ...}, AT_EMPTY_PATH) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f42c52c6000
mmap(NULL, 233952, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f42c528c000
mprotect(0x7f42c528d000, 36864, PROT_NONE) = 0
mmap(0x7f42c528d000, 24576, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1000) = 0x7f42c528d000
mmap(0x7f42c5293000, 8192, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x7000) = 0x7f42c5293000
mmap(0x7f42c5296000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x9000) = 0x7f42c5296000
mmap(0x7f42c5298000, 184800, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f42c5298000
close(3) = 0
openat(AT_FDCWD, "/gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libm.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0\0\0\0\0\0\0\0"..., 832) = 832
newfstatat(3, "", {st_mode=S_IFREG|0555, st_size=981440, ...}, AT_EMPTY_PATH) = 0
mmap(NULL, 901392, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f42c51af000
mmap(0x7f42c51bd000, 458752, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xe000) = 0x7f42c51bd000
mmap(0x7f42c522d000, 380928, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x7e000) = 0x7f42c522d000
mmap(0x7f42c528a000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xda000) = 0x7f42c528a000
close(3) = 0
openat(AT_FDCWD, "/gnu/store/6ncav55lbk5kqvwwflrzcr41hp5jbq0c-gcc-11.3.0-lib/lib/libgcc_s.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0\0\0\0\0\0\0\0"..., 832) = 832
pread64(3, "\4\0\0\0 \0\0\0\5\0\0\0GNU\0\1\0\1\300\4\0\0\0\v\0\0\0\0\0\0\0"..., 48, 97560) = 48
newfstatat(3, "", {st_mode=S_IFREG|0444, st_size=100760, ...}, AT_EMPTY_PATH) = 0
mmap(NULL, 103496, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f42c5195000
mmap(0x7f42c5198000, 73728, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x3000) = 0x7f42c5198000
mmap(0x7f42c51aa000, 12288, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x15000) = 0x7f42c51aa000
mmap(0x7f42c51ad000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x17000) = 0x7f42c51ad000
close(3) = 0
openat(AT_FDCWD, "/gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\260\223\2\0\0\0\0\0"..., 832) = 832
pread64(3, "\6\0\0\0\4\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0"..., 784, 64) = 784
pread64(3, "\4\0\0\0000\0\0\0\5\0\0\0GNU\0\2\200\0\300\4\0\0\0\1\0\0\0\0\0\0\0"..., 64, 848) = 64
pread64(3, "\4\0\0\0\20\0\0\0\1\0\0\0GNU\0\0\0\0\0\2\0\0\0\6\0\0\0 \0\0\0", 32, 912) = 32
newfstatat(3, "", {st_mode=S_IFREG|0555, st_size=2335360, ...}, AT_EMPTY_PATH) = 0
pread64(3, "\6\0\0\0\4\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0"..., 784, 64) = 784
mmap(NULL, 2080720, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f42c4f99000
mprotect(0x7f42c4fc1000, 1839104, PROT_NONE) = 0
mmap(0x7f42c4fc1000, 1470464, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x28000) = 0x7f42c4fc1000
mmap(0x7f42c5128000, 364544, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x18f000) = 0x7f42c5128000
mmap(0x7f42c5182000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1e8000) = 0x7f42c5182000
mmap(0x7f42c5188000, 53200, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f42c5188000
close(3) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f42c4f97000
arch_prctl(ARCH_SET_FS, 0x7f42c4f98380) = 0
set_tid_address(0x7f42c4f98650) = 9402
set_robust_list(0x7f42c4f98660, 24) = 0
rseq(0x7f42c4f98d20, 0x20, 0, 0x53053053) = 0
mprotect(0x7f42c5182000, 16384, PROT_READ) = 0
mprotect(0x7f42c51ad000, 4096, PROT_READ) = 0
mprotect(0x7f42c528a000, 4096, PROT_READ) = 0
mprotect(0x7f42c5296000, 4096, PROT_READ) = 0
mprotect(0x7f42c546f000, 16384, PROT_READ) = 0
mprotect(0x7f42c5483000, 4096, PROT_READ) = 0
mprotect(0x7f42c54b2000, 4096, PROT_READ) = 0
mprotect(0x7f42c5626000, 16384, PROT_READ) = 0
mprotect(0x403000, 4096, PROT_READ) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f42c4f95000
mprotect(0x7f42c566f000, 8192, PROT_READ) = 0
prlimit64(0, RLIMIT_STACK, NULL, {rlim_cur=16384*1024, rlim_max=16384*1024}) = 0
munmap(0x7f42c5637000, 6927) = 0
getrandom("\x43\x85\x41\x6f\x49\xb4\xf5\xbf", 8, GRND_NONBLOCK) = 8
brk(NULL) = 0x1787000
brk(0x17a8000) = 0x17a8000
openat(AT_FDCWD, "/gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/share/locale/locale.alias", O_RDONLY|O_CLOEXEC) = 3
newfstatat(3, "", {st_mode=S_IFREG|0444, st_size=2998, ...}, AT_EMPTY_PATH) = 0
read(3, "# Locale name alias data base.\n#"..., 4096) = 2998
read(3, "", 4096) = 0
close(3) = 0
openat(AT_FDCWD, "/gnu/store/5fmqijrs5f7vx8mc2q2pmq26yvhb74sm-glibc-utf8-locales-2.35/lib/locale/2.35/en_US.utf8/LC_IDENTIFICATION", O_RDONLY|O_CLOEXEC) = 3
newfstatat(3, "", {st_mode=S_IFREG|0444, st_size=369, ...}, AT_EMPTY_PATH) = 0
mmap(NULL, 369, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f42c566e000
close(3) = 0
openat(AT_FDCWD, "/gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/gconv/gconv-modules.cache", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/gconv/gconv-modules", O_RDONLY|O_CLOEXEC) = 3
newfstatat(3, "", {st_mode=S_IFREG|0444, st_size=3808, ...}, AT_EMPTY_PATH) = 0
read(3, "# GNU libc iconv configuration.\n"..., 4096) = 3808
read(3, "", 4096) = 0
close(3) = 0
openat(AT_FDCWD, "/gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/gconv/gconv-modules.d", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 3
newfstatat(3, "", {st_mode=S_IFDIR|0555, st_size=4096, ...}, AT_EMPTY_PATH) = 0
getdents64(3, 0x178b7c0 /* 3 entries */, 32768) = 96
openat(AT_FDCWD, "/gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/gconv/gconv-modules.d/gconv-modules-extra.conf", O_RDONLY|O_CLOEXEC) = 4
newfstatat(4, "", {st_mode=S_IFREG|0444, st_size=53974, ...}, AT_EMPTY_PATH) = 0
read(4, "# GNU libc iconv configuration.\n"..., 4096) = 4096
read(4, "B1002//\tJUS_I.B1.002//\nmodule\tJU"..., 4096) = 4096
read(4, "59-5//\nalias\tISO_8859-5//\t\tISO-8"..., 4096) = 4096
read(4, "59-16//\t\tINTERNAL\t\tISO8859-16\t1\n"..., 4096) = 4096
read(4, "-SE-A\t1\nmodule\tINTERNAL\t\tEBCDIC-"..., 4096) = 4096
read(4, "97\t\t1\n\n#\tfrom\t\t\tto\t\t\tmodule\t\tcos"..., 4096) = 4096
read(4, "1\n\n#\tfrom\t\t\tto\t\t\tmodule\t\tcost\nal"..., 4096) = 4096
read(4, "6//\t\tIBM1046//\nalias\tCP1046//\t\tI"..., 4096) = 4096
brk(0x17c9000) = 0x17c9000
read(4, "\tto\t\t\tmodule\t\tcost\nalias\tRUSCII/"..., 4096) = 4096
read(4, "03//\nmodule\tCSN_369103//\t\tINTERN"..., 4096) = 4096
read(4, "\tmodule\t\tcost\nalias\tISO-IR-8-1//"..., 4096) = 4096
read(4, "IBM1156\t\t1\n\n#\tfrom\t\t\tto\t\t\tmodule"..., 4096) = 4096
read(4, "\t\tIBM1166//\nalias\tCP1166//\t\tIBM1"..., 4096) = 4096
read(4, "alias\tROMAN9//\t\tHP-ROMAN9//\nalia"..., 4096) = 726
read(4, "", 4096) = 0
close(4) = 0
getdents64(3, 0x178b7c0 /* 0 entries */, 32768) = 0
close(3) = 0
futex(0x7f42c5187a6c, FUTEX_WAKE_PRIVATE, 2147483647) = 0
openat(AT_FDCWD, "/gnu/store/5fmqijrs5f7vx8mc2q2pmq26yvhb74sm-glibc-utf8-locales-2.35/lib/locale/2.35/en_US.utf8/LC_MEASUREMENT", O_RDONLY|O_CLOEXEC) = 3
newfstatat(3, "", {st_mode=S_IFREG|0444, st_size=23, ...}, AT_EMPTY_PATH) = 0
mmap(NULL, 23, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f42c5638000
close(3) = 0
openat(AT_FDCWD, "/gnu/store/5fmqijrs5f7vx8mc2q2pmq26yvhb74sm-glibc-utf8-locales-2.35/lib/locale/2.35/en_US.utf8/LC_TELEPHONE", O_RDONLY|O_CLOEXEC) = 3
newfstatat(3, "", {st_mode=S_IFREG|0444, st_size=59, ...}, AT_EMPTY_PATH) = 0
mmap(NULL, 59, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f42c5637000
close(3) = 0
openat(AT_FDCWD, "/gnu/store/5fmqijrs5f7vx8mc2q2pmq26yvhb74sm-glibc-utf8-locales-2.35/lib/locale/2.35/en_US.utf8/LC_ADDRESS", O_RDONLY|O_CLOEXEC) = 3
newfstatat(3, "", {st_mode=S_IFREG|0444, st_size=167, ...}, AT_EMPTY_PATH) = 0
mmap(NULL, 167, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f42c4f94000
close(3) = 0
openat(AT_FDCWD, "/gnu/store/5fmqijrs5f7vx8mc2q2pmq26yvhb74sm-glibc-utf8-locales-2.35/lib/locale/2.35/en_US.utf8/LC_NAME", O_RDONLY|O_CLOEXEC) = 3
newfstatat(3, "", {st_mode=S_IFREG|0444, st_size=77, ...}, AT_EMPTY_PATH) = 0
mmap(NULL, 77, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f42c4f93000
close(3) = 0
openat(AT_FDCWD, "/gnu/store/5fmqijrs5f7vx8mc2q2pmq26yvhb74sm-glibc-utf8-locales-2.35/lib/locale/2.35/en_US.utf8/LC_PAPER", O_RDONLY|O_CLOEXEC) = 3
newfstatat(3, "", {st_mode=S_IFREG|0444, st_size=34, ...}, AT_EMPTY_PATH) = 0
mmap(NULL, 34, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f42c4f92000
close(3) = 0
openat(AT_FDCWD, "/gnu/store/5fmqijrs5f7vx8mc2q2pmq26yvhb74sm-glibc-utf8-locales-2.35/lib/locale/2.35/en_US.utf8/LC_MESSAGES", O_RDONLY|O_CLOEXEC) = 3
newfstatat(3, "", {st_mode=S_IFDIR|0555, st_size=4096, ...}, AT_EMPTY_PATH) = 0
close(3) = 0
openat(AT_FDCWD, "/gnu/store/5fmqijrs5f7vx8mc2q2pmq26yvhb74sm-glibc-utf8-locales-2.35/lib/locale/2.35/en_US.utf8/LC_MESSAGES/SYS_LC_MESSAGES", O_RDONLY|O_CLOEXEC) = 3
newfstatat(3, "", {st_mode=S_IFREG|0444, st_size=57, ...}, AT_EMPTY_PATH) = 0
mmap(NULL, 57, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f42c4f91000
close(3) = 0
openat(AT_FDCWD, "/gnu/store/5fmqijrs5f7vx8mc2q2pmq26yvhb74sm-glibc-utf8-locales-2.35/lib/locale/2.35/en_US.utf8/LC_MONETARY", O_RDONLY|O_CLOEXEC) = 3
newfstatat(3, "", {st_mode=S_IFREG|0444, st_size=286, ...}, AT_EMPTY_PATH) = 0
mmap(NULL, 286, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f42c4f90000
close(3) = 0
openat(AT_FDCWD, "/gnu/store/5fmqijrs5f7vx8mc2q2pmq26yvhb74sm-glibc-utf8-locales-2.35/lib/locale/2.35/en_US.utf8/LC_COLLATE", O_RDONLY|O_CLOEXEC) = 3
newfstatat(3, "", {st_mode=S_IFREG|0444, st_size=2586930, ...}, AT_EMPTY_PATH) = 0
mmap(NULL, 2586930, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f42c4c00000
close(3) = 0
openat(AT_FDCWD, "/gnu/store/5fmqijrs5f7vx8mc2q2pmq26yvhb74sm-glibc-utf8-locales-2.35/lib/locale/2.35/en_US.utf8/LC_TIME", O_RDONLY|O_CLOEXEC) = 3
newfstatat(3, "", {st_mode=S_IFREG|0444, st_size=3284, ...}, AT_EMPTY_PATH) = 0
mmap(NULL, 3284, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f42c4f8f000
close(3) = 0
openat(AT_FDCWD, "/gnu/store/5fmqijrs5f7vx8mc2q2pmq26yvhb74sm-glibc-utf8-locales-2.35/lib/locale/2.35/en_US.utf8/LC_NUMERIC", O_RDONLY|O_CLOEXEC) = 3
newfstatat(3, "", {st_mode=S_IFREG|0444, st_size=54, ...}, AT_EMPTY_PATH) = 0
mmap(NULL, 54, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f42c4f8e000
close(3) = 0
openat(AT_FDCWD, "/gnu/store/5fmqijrs5f7vx8mc2q2pmq26yvhb74sm-glibc-utf8-locales-2.35/lib/locale/2.35/en_US.utf8/LC_CTYPE", O_RDONLY|O_CLOEXEC) = 3
newfstatat(3, "", {st_mode=S_IFREG|0444, st_size=353616, ...}, AT_EMPTY_PATH) = 0
mmap(NULL, 353616, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f42c4f37000
close(3) = 0
futex(0x7f42c5636430, FUTEX_WAKE_PRIVATE, 2147483647) = 0
openat(AT_FDCWD, "/proc/self/maps", O_RDONLY|O_CLOEXEC) = 3
prlimit64(0, RLIMIT_STACK, NULL, {rlim_cur=16384*1024, rlim_max=16384*1024}) = 0
newfstatat(3, "", {st_mode=S_IFREG|0444, st_size=0, ...}, AT_EMPTY_PATH) = 0
read(3, "00400000-00401000 r--p 00000000 "..., 1024) = 1024
read(3, " /gnu/store/5fmqijrs5f7vx8mc2q"..., 1024) = 1024
read(3, "000-7f42c4f94000 r--p 00000000 1"..., 1024) = 1024
read(3, " /gnu/store/ln6hxqjvz"..., 1024) = 1024
read(3, "42c51af000-7f42c51bd000 r--p 000"..., 1024) = 1024
read(3, "0 r--p 00007000 103:03 15230985 "..., 1024) = 1024
read(3, "lqrq5qir8gw5aq7f16g1i-libunistri"..., 1024) = 1024
read(3, ".so.8.1.2\n7f42c5484000-7f42c5485"..., 1024) = 1024
read(3, "nu/store/n24l8hxn6nvb7lz7zjlyd7i"..., 1024) = 1024
read(3, "bc-utf8-locales-2.35/lib/locale/"..., 1024) = 1024
read(3, "6hxqjvz6m9gdd9s97pivlqck7hzs99-g"..., 1024) = 461
close(3) = 0
sched_getaffinity(9402, 32, [0 1 2 3 4 5 6 7]) = 32
mmap(NULL, 65536, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f42c4f27000
mmap(0x7f42c4f37000, 65536, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f42c4f17000
mmap(0x7f42c4f27000, 65536, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f42c4f07000
mmap(0x7f42c4f17000, 65536, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f42c4ef7000
mmap(0x7f42c4f07000, 65536, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f42c4ee7000
openat(AT_FDCWD, "/proc/stat", O_RDONLY) = 3
read(3, "cpu 230498 292 27982 3717201 62"..., 1700) = 1700
close(3) = 0
rt_sigaction(SIGPWR, {sa_handler=0x7f42c548e8e0, sa_mask=~[INT QUIT ABRT BUS SEGV TERM RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f42c4fd62a0}, NULL, 8) = 0
rt_sigaction(SIGXCPU, {sa_handler
This message was truncated. Download the full message here.
T
T
Timo Wilken wrote on 14 Dec 2023 23:55
Re: Shepherd stops responding during "guix system reconfigure"
(name . Attila Lendvai)(address . attila@lendvai.name)
CXODHED6PPG6.3PMFS738SPPMZ@lap.twilken.net
After a bit of searching, it looks like 67538, 67230 and 65178 may be the same
issue.

Attila Lendvai wrote:
Toggle quote (9 lines)
> > > my suspicion is that it's due to some error coming from a start
> > > GEXP that somehow derails shepherd's event loop.
> >
> > iirc I once managed to get a debugger out when it happened and it's
> > stuck waiting in one of the epoll/select/alike calls,
>
> ...or one of the start/stop GEXP's calls something that (sometimes?) blocks
> indefinitely (which violates the API of shepherd).

Same symptoms here again.

For context: this time I was trying to deploy some OCI/Docker containers using
Guix' `oci-container-service-type', specifically a Shepherd service called
"conduit". My code is here:


(Specifically, commits bf94f7872a1df293bd904bbd2c1ef7229f4f98a8 and
c87dcdae79c6266ac3dac70af08fbef5eb21629b.)

This is with Guix commit 1b2505217cf222d98cc960b8510660976a01cfa1.

I first ran "guix system reconfigure -L . tw/system/lud.scm" with commit
bf94f7872a1df293bd904bbd2c1ef7229f4f98a8, which had a bug (an env var was
wrong, so the container failed to start). This worked as expected in that
Shepherd tried to start the service, which failed, so Shepherd disabled it.

Then, I fixed the env var and re-ran "guix system reconfigure -L .
tw/system/lud.scm" with commit c87dcdae79c6266ac3dac70af08fbef5eb21629b.
Shepherd loaded the new "conduit" service fine, as far as I can tell, but
didn't restart it because it was still disabled.

I then enabled and started the service manually. Enabling worked fine, but on
start, I got no terminal output from Shepherd, and it hung.

I still had an error in my setup (directory permissions were wrong), and I got
a message in /var/log/messages to that effect:

Toggle snippet (13 lines)
Dec 14 21:33:50 localhost shepherd[1]: Service conduit is currently disabled.
Dec 14 21:34:04 localhost shepherd[1]: Enabled service conduit.
Dec 14 21:34:07 localhost shepherd[1]: Starting service user-homes...
Dec 14 21:34:07 localhost shepherd[1]: Service user-homes has been started.
Dec 14 21:34:07 localhost shepherd[1]: Service user-homes started.
Dec 14 21:34:07 localhost shepherd[1]: Service user-homes running with value #t.
Dec 14 21:34:07 localhost shepherd[1]: Starting service conduit...
Dec 14 21:34:07 localhost shepherd[1]: Service conduit has been started.
Dec 14 21:34:07 localhost shepherd[1]: Service conduit started.
Dec 14 21:34:07 localhost shepherd[1]: Service conduit running with value 13226.
Dec 14 21:34:07 localhost shepherd[1]: [docker] conduit: [...] "IO error: While open a file for appending: /var/lib/matrix-conduit/LOG: Permission denied"

...showing that Shepherd had at least tried to start the new container. The
container is not running, though (due to the error shown above), and nothing
with PID 13226 is running.

The "herd start conduit" command did not return, and ^C-ing it did not help.
Afterwards, every "herd" command also hung without any output.

Here are the last four lines of the output of "sudo strace -s1000 herd status"
on such a hung machine:

Toggle snippet (6 lines)
connect(10, {sa_family=AF_UNIX, sun_path="/var/run/shepherd/socket"}, 26) = 0
getcwd("/home/timo", 100) = 11
write(10, "(shepherd-command (version 0) (action status) (service root) (arguments ()) (directory \"/home/timo\"))", 101) = 101
read(10,

The "read(10, " call never completes.

At least in this case, Shepherd still seems to be processing inbound inet
connections, so I can open new SSH connections to the machine.

Attaching to PID 1 with strace shows it is stuck in "epoll_wait(13, "
(unsurprisingly, fd 13 points to "anon_inode:[eventpoll]"). Here's a backtrace
of all threads in "gdb -p 1":

Toggle snippet (105 lines)
(gdb) info threads
Id Target Id Frame
* 1 Thread 0x7f786544c380 (LWP 1) "shepherd" 0x00007f7865552626 in epoll_wait ()
from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6
2 Thread 0x7f7864e16640 (LWP 186) "GC-marker-0" 0x00007f78654cf16a in __futex_abstimed_wait_common ()
from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6
3 Thread 0x7f7864615640 (LWP 187) "GC-marker-1" 0x00007f78654cf16a in __futex_abstimed_wait_common ()
from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6
4 Thread 0x7f7863e14640 (LWP 188) "GC-marker-2" 0x00007f78654cf16a in __futex_abstimed_wait_common ()
from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6
5 Thread 0x7f78634c6640 (LWP 190) "shepherd" 0x00007f786554300c in read ()
from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6
(gdb) thread apply all bt

Thread 5 (Thread 0x7f78634c6640 (LWP 190) "shepherd"):
#0 0x00007f786554300c in read () from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6
#1 0x00007f7865a48cc7 in ?? () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#2 0x00007f78659427d1 in ?? () from /gnu/store/k1ha4n9v8d7myiiszvl2ic7xnb56l219-libgc-8.2.2/lib/libgc.so.1
#3 0x00007f786594438c in ?? () from /gnu/store/k1ha4n9v8d7myiiszvl2ic7xnb56l219-libgc-8.2.2/lib/libgc.so.1
#4 0x00007f786594e83c in GC_do_blocking () from /gnu/store/k1ha4n9v8d7myiiszvl2ic7xnb56l219-libgc-8.2.2/lib/libgc.so.1
#5 0x00007f7865a65455 in scm_without_guile () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#6 0x00007f7865a4d570 in ?? () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#7 0x00007f7865a71390 in ?? () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#8 0x00007f7865a7edb5 in scm_call_n () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#9 0x00007f78659e5b3e in scm_call_with_unblocked_asyncs () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#10 0x00007f7865a71390 in ?? () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#11 0x00007f7865a7edb5 in scm_call_n () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#12 0x00007f7865a6b0f3 in ?? () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#13 0x00007f78659e7e1a in ?? () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#14 0x00007f7865a71390 in ?? () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#15 0x00007f7865a7edb5 in scm_call_n () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#16 0x00007f78659e95ca in scm_call_2 () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#17 0x00007f7865a90092 in ?? () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#18 0x00007f7865a6be1f in scm_c_catch () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#19 0x00007f78659ea396 in scm_c_with_continuation_barrier () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#20 0x00007f7865a6b049 in ?? () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#21 0x00007f786594e7fa in GC_call_with_stack_base () from /gnu/store/k1ha4n9v8d7myiiszvl2ic7xnb56l219-libgc-8.2.2/lib/libgc.so.1
#22 0x00007f7865a64c5d in ?? () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#23 0x00007f78654d23aa in start_thread () from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6
#24 0x00007f7865552f7c in clone3 () from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6

Thread 4 (Thread 0x7f7863e14640 (LWP 188) "GC-marker-2"):
#0 0x00007f78654cf16a in __futex_abstimed_wait_common () from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6
#1 0x00007f78654d17e8 in pthread_cond_wait@@GLIBC_2.3.2 () from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6
#2 0x00007f7865948740 in ?? () from /gnu/store/k1ha4n9v8d7myiiszvl2ic7xnb56l219-libgc-8.2.2/lib/libgc.so.1
#3 0x00007f7865948897 in ?? () from /gnu/store/k1ha4n9v8d7myiiszvl2ic7xnb56l219-libgc-8.2.2/lib/libgc.so.1
#4 0x00007f78654d23aa in start_thread () from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6
#5 0x00007f7865552f7c in clone3 () from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6

Thread 3 (Thread 0x7f7864615640 (LWP 187) "GC-marker-1"):
#0 0x00007f78654cf16a in __futex_abstimed_wait_common () from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6
#1 0x00007f78654d17e8 in pthread_cond_wait@@GLIBC_2.3.2 () from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6
#2 0x00007f7865948740 in ?? () from /gnu/store/k1ha4n9v8d7myiiszvl2ic7xnb56l219-libgc-8.2.2/lib/libgc.so.1
#3 0x00007f7865948897 in ?? () from /gnu/store/k1ha4n9v8d7myiiszvl2ic7xnb56l219-libgc-8.2.2/lib/libgc.so.1
#4 0x00007f78654d23aa in start_thread () from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6
#5 0x00007f7865552f7c in clone3 () from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6

Thread 2 (Thread 0x7f7864e16640 (LWP 186) "GC-marker-0"):
#0 0x00007f78654cf16a in __futex_abstimed_wait_common () from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6
#1 0x00007f78654d17e8 in pthread_cond_wait@@GLIBC_2.3.2 () from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6
#2 0x00007f7865948740 in ?? () from /gnu/store/k1ha4n9v8d7myiiszvl2ic7xnb56l219-libgc-8.2.2/lib/libgc.so.1
#3 0x00007f7865948897 in ?? () from /gnu/store/k1ha4n9v8d7myiiszvl2ic7xnb56l219-libgc-8.2.2/lib/libgc.so.1
#4 0x00007f78654d23aa in start_thread () from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6
#5 0x00007f7865552f7c in clone3 () from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6

Thread 1 (Thread 0x7f786544c380 (LWP 1) "shepherd"):
#0 0x00007f7865552626 in epoll_wait () from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6
#1 0x00007f7862bb9335 in ?? () from /gnu/store/h4nsywbhn8b4qyh40fhykk3q40qkr3wd-guile-fibers-1.3.1/lib/guile/3.0/extensions/fibers-epoll.so
#2 0x00007f78659427d1 in ?? () from /gnu/store/k1ha4n9v8d7myiiszvl2ic7xnb56l219-libgc-8.2.2/lib/libgc.so.1
#3 0x00007f786594438c in ?? () from /gnu/store/k1ha4n9v8d7myiiszvl2ic7xnb56l219-libgc-8.2.2/lib/libgc.so.1
#4 0x00007f786594e83c in GC_do_blocking () from /gnu/store/k1ha4n9v8d7myiiszvl2ic7xnb56l219-libgc-8.2.2/lib/libgc.so.1
#5 0x00007f7865a65455 in scm_without_guile () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#6 0x00007f7862bb96ce in ?? () from /gnu/store/h4nsywbhn8b4qyh40fhykk3q40qkr3wd-guile-fibers-1.3.1/lib/guile/3.0/extensions/fibers-epoll.so
#7 0x00007f78606246c2 in ?? ()
#8 0x00007f78620ba628 in ?? ()
#9 0x00007f7860627610 in ?? ()
#10 0x00007f786520ad80 in ?? ()
#11 0x00007f7865a14edc in ?? () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#12 0x00007f7865a71215 in ?? () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#13 0x00007f7865a7edb5 in scm_call_n () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#14 0x00007f78659e9977 in scm_primitive_eval () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#15 0x00007f7865a1dff9 in scm_primitive_load () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#16 0x00007f7865a71390 in ?? () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#17 0x00007f7865a7edb5 in scm_call_n () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#18 0x00007f78659e9977 in scm_primitive_eval () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#19 0x00007f78659ef846 in scm_eval () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#20 0x00007f7865a4e3e6 in scm_shell () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#21 0x00007f7865a008cc in ?? () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#22 0x00007f78659e7e1a in ?? () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#23 0x00007f7865a71390 in ?? () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#24 0x00007f7865a7edb5 in scm_call_n () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#25 0x00007f78659e95ca in scm_call_2 () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#26 0x00007f7865a90092 in ?? () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#27 0x00007f7865a6be1f in scm_c_catch () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#28 0x00007f78659ea396 in scm_c_with_continuation_barrier () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#29 0x00007f7865a6b049 in ?? () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#30 0x00007f786594e7fa in GC_call_with_stack_base () from /gnu/store/k1ha4n9v8d7myiiszvl2ic7xnb56l219-libgc-8.2.2/lib/libgc.so.1
#31 0x00007f7865a653f8 in scm_with_guile () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#32 0x00007f7865a098e5 in scm_boot_guile () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#33 0x00000000004010f7 in ?? ()
#34 0x00007f78654761f7 in __libc_start_call_main () from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6
#35 0x00007f78654762ac in __libc_start_main_impl () from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6
#36 0x0000000000401171 in ?? ()

Unrelatedly, I also have another Shepherd on a different machine that became
stuck after I ran a bunch of "guix system reconfigure" commands. The
backtraces there, if it helps:

Toggle snippet (59 lines)
(gdb) info threads
Id Target Id Frame
* 1 Thread 0x7ffaceef2380 (LWP 1) "shepherd" 0x00007fface938626 in epoll_wait ()
from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6
2 Thread 0x7fface1aa640 (LWP 231) "GC-marker-0" 0x00007fface8b516a in __futex_abstimed_wait_common ()
from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6
3 Thread 0x7ffacd9a9640 (LWP 232) "GC-marker-1" 0x00007fface8b516a in __futex_abstimed_wait_common ()
from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6
4 Thread 0x7ffacd1a8640 (LWP 233) "GC-marker-2" 0x00007fface8b516a in __futex_abstimed_wait_common ()
from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6
5 Thread 0x7ffacc9a7640 (LWP 234) "GC-marker-3" 0x00007fface8b516a in __futex_abstimed_wait_common ()
from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6
6 Thread 0x7ffacc1a6640 (LWP 235) "GC-marker-4" 0x00007fface8b516a in __futex_abstimed_wait_common ()
from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6
7 Thread 0x7ffacb9a5640 (LWP 236) "GC-marker-5" 0x00007fface8b516a in __futex_abstimed_wait_common ()
from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6
8 Thread 0x7ffacb1a4640 (LWP 237) "GC-marker-6" 0x00007fface8b516a in __futex_abstimed_wait_common ()
from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6
9 Thread 0x7ffaca832640 (LWP 249) "shepherd" 0x00007fface92900c in read ()
from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6
10 Thread 0x7ffac89ca640 (LWP 26693) "shepherd" 0x00007fface92900c in read ()
from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6
(gdb) thread apply all bt

Thread 10 (Thread 0x7ffac89ca640 (LWP 26693) "shepherd"):
#0 0x00007fface92900c in read () from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6
#1 0x00007ffacedf0e57 in ?? () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#2 0x00007ffaced3c7d1 in ?? () from /gnu/store/k1ha4n9v8d7myiiszvl2ic7xnb56l219-libgc-8.2.2/lib/libgc.so.1
#3 0x00007ffaced3e38c in ?? () from /gnu/store/k1ha4n9v8d7myiiszvl2ic7xnb56l219-libgc-8.2.2/lib/libgc.so.1
#4 0x00007ffaced4883c in GC_do_blocking () from /gnu/store/k1ha4n9v8d7myiiszvl2ic7xnb56l219-libgc-8.2.2/lib/libgc.so.1
#5 0x00007ffacee62455 in scm_without_guile () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#6 0x00007ffacedf903d in ?? () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#7 0x00007ffacede4e1a in ?? () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#8 0x00007ffac6832022 in ?? ()
#9 0x00007fface4d97f0 in ?? ()
#10 0x00007ffac94766c0 in ?? ()
#11 0x00007fface5f4b40 in ?? ()
#12 0x00007ffacee11edc in ?? () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#13 0x00007ffacee6e215 in ?? () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#14 0x00007ffacee7bdb5 in scm_call_n () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#15 0x00007ffacede65ca in scm_call_2 () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#16 0x00007ffacee8d092 in ?? () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#17 0x00007ffacee68e1f in scm_c_catch () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#18 0x00007ffacede7396 in scm_c_with_continuation_barrier () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#19 0x00007ffacee68049 in ?? () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#20 0x00007ffaced487fa in GC_call_with_stack_base () from /gnu/store/k1ha4n9v8d7myiiszvl2ic7xnb56l219-libgc-8.2.2/lib/libgc.so.1
#21 0x00007ffacee623f8 in scm_with_guile () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#22 0x00007fface8b83aa in start_thread () from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6
#23 0x00007fface938f7c in clone3 () from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6

Thread 9 (Thread 0x7ffaca832640 (LWP 249) "shepherd"):
#0 0x00007fface92900c in read () from /gnu/store/ln6hxqjvz6m9gdd9s97pivlqck7hzs99-glibc-2.35/lib/libc.so.6
#1 0x00007ffacee45cc7 in ?? () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#2 0x00007ffaced3c7d1 in ?? () from /gnu/store/k1ha4n9v8d7myiiszvl2ic7xnb56l219-libgc-8.2.2/lib/libgc.so.1
#3 0x00007ffaced3e38c in ?? () from /gnu/store/k1ha4n9v8d7myiiszvl2ic7xnb56l219-libgc-8.2.2/lib/libgc.so.1
#4 0x00007ffaced4883c in GC_do_blocking () from /gnu/store/k1ha4n9v8d7myiiszvl2ic7xnb56l219-libgc-8.2.2/lib/libgc.so.1
#5 0x00007ffacee62455 in scm_without_guile () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4-guile-3.0.9/lib/libguile-3.0.so.1
#6 0x00007ffacee4a570 in ?? () from /gnu/store/n24l8hxn6nvb7lz7zjlyd7i05khrm0i4
This message was truncated. Download the full message here.
A
A
Attila Lendvai wrote on 15 Dec 2023 20:47
(name . Timo Wilken)(address . guix@twilken.net)
mnlkXTye7wOZNVq5cAf2dviIwfvb8APeTaM5rHUGoPKVlZz9l4VxGNAde8FbJIPf9yPYn0FRXSh0Vb5myA3E3407Us_echjM6SOWv6sE8jY=@lendvai.name
i think i have found the root cause of this, as documented here: https://issues.guix.gnu.org/67839

that issue contains patches for shepherd to reproduce it in its test suite.

--
• attila lendvai
• PGP: 963F 5D5F 45C7 DFCD 0A39
--
“What divides libertarians from everybody else is not a belief about rights or what rights people have, because the judgments libertarians make about the state are the same as the judgments almost everyone makes about private agents. So it's not that we believe in rights that other people don't believe in, or that other people believe in rights that we don't believe in. It's that other people think the state is exempt from the moral principles that apply to non-government agents.”
— Michael Huemer
T
T
Timo Wilken wrote on 15 Dec 2023 21:33
(name . Attila Lendvai)(address . attila@lendvai.name)
CXP6VUA179NT.24MHZOOPR4XQN@lap.twilken.net
On Fri Dec 15, 2023 at 8:47 PM CET, Attila Lendvai wrote:
Toggle quote (4 lines)
> i think i have found the root cause of this, as documented here: https://issues.guix.gnu.org/67839
>
> that issue contains patches for shepherd to reproduce it in its test suite.

Thank you very much for this, Attila!

Are the patch in 67839 and/or your branch "attila" linked from there in a
state that I could test them locally? Would it be valuable to you if I ran a
patched Shepherd and sent logs and/or backtraces as I encountered them?
A
A
Attila Lendvai wrote on 15 Dec 2023 22:24
(name . Timo Wilken)(address . guix@twilken.net)
Q25YR0CIwjc3XL1sWDYgC7JrIarMKDw3wg326jlNiwx0Rtmj7e_kkoFiry6KGSbid8fBo8bqW5jiaOs8WOK43ijSvz8qWq-RPNoCjz26kus=@lendvai.name
Toggle quote (3 lines)
> Thank you very much for this, Attila!


you're welcome! :)


Toggle quote (5 lines)
> Are the patch in 67839 and/or your branch "attila" linked from there in a
> state that I could test them locally? Would it be valuable to you if I ran a
> patched Shepherd and sent logs and/or backtraces as I encountered them?


it's nice of you, but not really. now that we have a failing test case in shepherd's unit tests that can reproduce it much easier.

with #67839 you would only get you an extra "Assertion failed" message over master, without much useful output.

as for my branch, it would emit a lot of useful log, including backtraces, but i keep force-pushing into it. i'm running my servers with it, though, so if you feel really adventurous, and want to join the debugging, then you can try... otherwise it's too much in flux.

what we need to focus on now is making shepherd's test suite run clean again, one way or another. then i can test it in a real life environment, and report back with any possible findings.

--
• attila lendvai
• PGP: 963F 5D5F 45C7 DFCD 0A39
--
“Ignorance might be bliss for the ignorant, but for the rest of us it's a fucking pain in the ass.”
— Ricky Gervais
L
L
Ludovic Courtès wrote on 20 Dec 2023 00:00
Re: bug#65419: [Shepherd] Non-responding service control fiber
(name . Attila Lendvai)(address . attila@lendvai.name)
87plz1hk6j.fsf_-_@gnu.org
Hello,

Attila Lendvai <attila@lendvai.name> skribis:

Toggle quote (4 lines)
> i think i have found the root cause of this, as documented here: https://issues.guix.gnu.org/67839
>
> that issue contains patches for shepherd to reproduce it in its test suite.

Yes, it looks like this long-standing and hard-to-debug issue may well
be fixed now, thumbs up Attila!!

We have accumulated quite a few fixes by now so I think I’ll release
0.10.3 hopefully in 2023 and otherwise soon after.

Thanks,
Ludo’.
?