[Top][All Lists]

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

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

From: hylophile
Subject: bug#59321: ice-9's open-input-pipe is unexpectedly slow on some systems
Date: Wed, 16 Nov 2022 18:06:06 +0000


while doing my first steps in Guile and porting a small shell script, I noticed that capturing stdout from a subshell is very slow:

$ time guile -c '(begin (use-modules (ice-9 popen) (ice-9 rdelim)) (display (read-delimited "" (open-input-pipe "ls"))))'
real    0m0,313s
user    0m0,008s
sys     0m0,007s

It takes around 300ms where I would expect around 40ms. The slowness happens on one of my machines, but not the other (at least not noticeably). However, I am fairly sure that my machine is not at fault, because this doesn't happen with other languages. Additionally, another Guile user tried this on their machines and also noticed slowness (around 200ms) on one of their machines. We did notice that the machines where the operation runs fast also run on better hardware, but the stark difference is still unexpected. Unfortunately I am not sure what exactly causes the issue, but I am happy to provide any further information needed.

The mentioned Guile user was able to pinpoint the delay to be between two read system calls by going through an strace. To reproduce:
1. Create an empty folder with one file named "testfile" in it

2. Run:
$ strace -o ice-9.trace -s 256 --timestamps=format:time,precision:ms guile -c '(begin (use-modules (ice-9 popen) (ice-9 rdelim)) (display (read-delimited "" (open-input-pipe "ls"))))'

3. In the resulting ice-9.trace, search for "testfile" and go up to the first read call which reads the output of ls. Between the first and the second read call, there is a noticeable delay. For one of my systems it's around 300ms, for the other it's around 90ms:

18:37:08.880 close(6)                   = 0
18:37:08.880 read(5, "i", 1)            = 1
18:37:09.189 --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=188843, si_uid=1000, si_status=0, si_utime=15 /* 0.15 s */, si_stime=14 /* 0.14 s */} ---
18:37:09.189 read(5, "c", 1)            = 1
18:37:09.189 read(5, "e", 1)            = 1


System information:

guile (GNU Guile) 3.0.8

I am using the Arch Linux guile package, I believe the build configuration can be found here:

Output of config.guess:

reply via email to

[Prev in Thread] Current Thread [Next in Thread]