bug#55441: [cuirass] hang in "In progress..."; runs out of pgsql connections

[Ludovic Courtès]

Hi,

Maxim Cournoyer <maxim.cournoyer@gmail.com> skribis:

> Berlin was reconfigured with this commit of Cuirass, and is now running
> the derivations with it, but so far still "In progress..." after more
> than 100 minutes [0]

Yeah, I’m not sure about the backtrace you report, however there’s again
a bunch of ‘cuirass evaluate’ processes hanging, this time with the main
thread stuck on ‘waitpid’ (presumably from the ‘close-inferior’ call):

--8<---------------cut here---------------start------------->8---
#0  0x00007f0886310f27 in __GI___wait4 (pid=86099, 
stat_loc=stat_loc@entry=0x7ffea0cb849c, options=options@entry=0, 
usage=usage@entry=0x0)
    at ../sysdeps/unix/sysv/linux/wait4.c:30
#1  0x00007f0886310ea7 in __GI___waitpid (pid=<optimized out>, 
stat_loc=stat_loc@entry=0x7ffea0cb849c, options=options@entry=0)
    at waitpid.c:38
#2  0x00007f08868ae25e in scm_waitpid (pid=86099, options=<optimized out>) at 
posix.c:727
#3  0x00007f088689a336 in vm_regular_engine (thread=0x7f08861fad80) at 
vm-engine.c:972
#4  0x00007f08868a75e9 in scm_call_n (proc=<optimized out>, argv=<optimized 
out>, nargs=1) at vm.c:1608
#5  0x00007f088680f457 in scm_primitive_eval (exp=<optimized out>,
    exp@entry=((@ (ice-9 control) %) (begin ((@@ (ice-9 command-line) 
load/lang) 
"/gnu/store/z8haznhwck4bjm4gxqy25wvwv4041wvx-cuirass-1.1.0-12.f087aaf/bin/.cuirass-real")
 (main (command-line)) (quit)))) at eval.c:671
#6  0x00007f08868154b6 in scm_eval (
    exp=((@ (ice-9 control) %) (begin ((@@ (ice-9 command-line) load/lang) 
"/gnu/store/z8haznhwck4bjm4gxqy25wvwv4041wvx-cuirass-1.1.0-12.f087aaf/bin/.cuirass-real")
 (main (command-line)) (quit))), module_or_state="#<struct module>" = {...}) at 
eval.c:705
#7  0x00007f08868793b6 in scm_shell (argc=9, argv=0x7ffea0cb8c98) at 
script.c:357
--8<---------------cut here---------------end--------------->8---

Process 86099 (the one it’s waiting for) is indeed ‘guix repl’ and it’s
waiting for input in read(0, …).

There’s a second thread stuck in ‘waitpid’:

--8<---------------cut here---------------start------------->8---
(gdb) thread 27
[Switching to thread 27 (LWP 86002)]
#0  0x00007f0886310f27 in __GI___wait4 (pid=86100, 
stat_loc=stat_loc@entry=0x7f085393c60c, options=options@entry=0, 
usage=usage@entry=0x0)
    at ../sysdeps/unix/sysv/linux/wait4.c:30
30      ../sysdeps/unix/sysv/linux/wait4.c: No such file or directory.
(gdb) bt
#0  0x00007f0886310f27 in __GI___wait4 (pid=86100, 
stat_loc=stat_loc@entry=0x7f085393c60c, options=options@entry=0, 
usage=usage@entry=0x0)
    at ../sysdeps/unix/sysv/linux/wait4.c:30
#1  0x00007f0886310ea7 in __GI___waitpid (pid=<optimized out>, 
stat_loc=stat_loc@entry=0x7f085393c60c, options=options@entry=0)
    at waitpid.c:38
#2  0x00007f08868ae25e in scm_waitpid (pid=86100, options=<optimized out>) at 
posix.c:727
#3  0x00007f088689a336 in vm_regular_engine (thread=0x7f087d54e240) at 
vm-engine.c:972
#4  0x00007f08868a75e9 in scm_call_n (proc=<optimized out>, argv=<optimized 
out>, nargs=0) at vm.c:1608
#5  0x00007f088680ba0e in scm_call_with_unblocked_asyncs (proc=#<program 
7f0854a50f40>) at async.c:406
#6  0x00007f088689a336 in vm_regular_engine (thread=0x7f087d54e240) at 
vm-engine.c:972
#7  0x00007f08868a75e9 in scm_call_n (proc=<optimized out>, argv=<optimized 
out>, nargs=0) at vm.c:1608
--8<---------------cut here---------------end--------------->8---

and then a couple of threads in ‘read’:

--8<---------------cut here---------------start------------->8---
#0  __libc_read (nbytes=1, buf=0x7f085a69ab90, fd=5) at 
../sysdeps/unix/sysv/linux/read.c:26
#1  __libc_read (fd=5, buf=buf@entry=0x7f085a69ab90, nbytes=nbytes@entry=1) at 
../sysdeps/unix/sysv/linux/read.c:24
#2  0x00007f08868252e8 in fport_read (port=<optimized out>, dst=<optimized 
out>, start=<optimized out>, count=1) at fports.c:597
#3  0x00007f0886865d22 in scm_i_read_bytes (port=port@entry=#<port #<port-type 
file 7f087e821b40> 7f0854af6d20>, dst="#<vu8vector>" = {...}, 
    start=start@entry=0, count=1) at ports.c:1566
#4  0x00007f08868681c7 in scm_fill_input (port=port@entry=#<port #<port-type 
file 7f087e821b40> 7f0854af6d20>, 
    minimum_size=minimum_size@entry=1, cur_out=cur_out@entry=0x7f085313b5e0, 
avail_out=avail_out@entry=0x7f085313b588) at ports.c:2693
#5  0x00007f0886868d5c in peek_iconv_codepoint (port=#<port #<port-type file 
7f087e821b40> 7f0854af6d20>, buf=buf@entry=0x7f085313b5e8, 
    cur=cur@entry=0x7f085313b5e0, len=len@entry=0x7f085313b5d8) at ports.c:1944
#6  0x00007f0886868e4a in peek_codepoint (len=0x7f085313b5d8, 
cur=0x7f085313b5e0, buf=0x7f085313b5e8, port=<optimized out>) at ports.c:1988
#7  scm_peek_char (port=<optimized out>) at ports.c:2202
#8  0x00007f087e62582b in ?? ()
#9  0x0000000000857760 in ?? ()
#10 0x00007f087e6257a0 in ?? ()
#11 0x00007f087d850c48 in ?? ()
#12 0x00007f0886844ccc in scm_jit_enter_mcode (thread=0x7f087d54e000, 
mcode=0x857770 "\034\234\003") at jit.c:6038
#13 0x00007f0886899f3c in vm_regular_engine (thread=0x7f087d54e000) at 
vm-engine.c:360
--8<---------------cut here---------------end--------------->8---

Normally we call ‘waitpid’ once the pipe has been closed:

--8<---------------cut here---------------start------------->8---
(define* (open-inferior directory
                        #:key (command "bin/guix")
                        (error-port (%make-void-port "w")))
  "Open the inferior Guix in DIRECTORY, running 'DIRECTORY/COMMAND repl' or
equivalent.  Return #f if the inferior could not be launched."
  (let ((pipe pid (inferior-pipe directory command error-port)))
    (port->inferior pipe
                    (lambda (port)
                      (close-port port)
                      (waitpid pid)))))   ;<----- here
--8<---------------cut here---------------end--------------->8---

… and when the pipe is closed, the child ‘guix repl’ process gets EOF
and exits.

So I’m not sure why the ‘guix repl’ process would stick around.

Thoughts?

Ludo’.