Subject: bug#59321: ice-9's open-input-pipe is unexpectedly slow on some systems

From: Andrew Whatson <[email-masked]>
Date: Fri, 18 Nov 2022 14:49:05 +1000

Hi Nate,

Thanks for reporting this!  I'm able to reproduce on my systems, and
have identified the culprit:

 > strace -c -f guile -c '(begin (use-modules (ice-9 popen) (ice-9
rdelim)) (display (read-delimited "" (open-input-pipe "ls"))))'

 % time     seconds  usecs/call     calls    errors syscall
 ------ ----------- ----------- --------- --------- ------------------
  93.38    0.309261           1    250107    249994 close
   4.61    0.015268         135       113        21 futex
   0.52    0.001730           4       430       270 newfstatat
   0.38    0.001263           6       183           mmap
   0.29    0.000953           4       197        92 openat
   0.16    0.000542         180         3           execve
 <...snip...>

These close calls are from the start_child routine in libguile/posix.c:

 static pid_t
 start_child (const char *exec_file, char **exec_argv,
          int reading, int c2p[2], int writing, int p2c[2],
              int in, int out, int err)
 {
   int pid;
   int max_fd = 1024;

 #if defined (HAVE_GETRLIMIT) && defined (RLIMIT_NOFILE)
   {
     struct rlimit lim = { 0, 0 };
     if (getrlimit (RLIMIT_NOFILE, &lim) == 0)
       max_fd = lim.rlim_cur;
   }
 #endif

 <...snip...>
   /* Close all file descriptors in ports inherited from the parent
      except for in, out, and err.  Heavy-handed, but robust.  */
   while (max_fd--)
     if (max_fd != in && max_fd != out && max_fd != err)
       close (max_fd);
 <...snip...>

On my system, `ulimit -n` shows the maximum number of open files as
250000, explaining the 250000 calls to close shown by strace.

Testing a build of guile with the max_fd loop commented out shows the
expected performance:

 # unmodified guile
 > time guile -c '(begin (use-modules (ice-9 popen) (ice-9 rdelim))
(display (read-delimited "" (open-input-pipe "ls"))))'
 real 0m0.202s

 # guile patched to remove max_fd loop
 > time guile -c '(begin (use-modules (ice-9 popen) (ice-9 rdelim))
(display (read-delimited "" (open-input-pipe "ls"))))'
 real 0m0.056s

Forcibly closing file descriptors like this shouldn't be necessary if
the application has properly opened descriptors with the FD_CLOEXEC
flag.  It would be good to get input from some more experienced Guile
hackers on the potential consequences of this change.

Cheers,
Andrew