From mboxrd@z Thu Jan 1 00:00:00 1970 Path: news.gmane.io!.POSTED.blaine.gmane.org!not-for-mail From: Andrew Whatson Newsgroups: gmane.lisp.guile.bugs Subject: bug#59321: ice-9's open-input-pipe is unexpectedly slow on some systems Date: Fri, 18 Nov 2022 14:49:05 +1000 Message-ID: References: <8d55cf7d1e5382c874cfcaee1f4cddd3@posteo.de> Mime-Version: 1.0 Content-Type: text/plain; charset="UTF-8" Injection-Info: ciao.gmane.io; posting-host="blaine.gmane.org:116.202.254.214"; logging-data="11826"; mail-complaints-to="usenet@ciao.gmane.io" Cc: 59321@debbugs.gnu.org To: hylophile@posteo.de Original-X-From: bug-guile-bounces+guile-bugs=m.gmane-mx.org@gnu.org Fri Nov 18 05:50:40 2022 Return-path: Envelope-to: guile-bugs@m.gmane-mx.org Original-Received: from lists.gnu.org ([209.51.188.17]) by ciao.gmane.io with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.92) (envelope-from ) id 1ovtKq-0002vs-6C for guile-bugs@m.gmane-mx.org; Fri, 18 Nov 2022 05:50:40 +0100 Original-Received: from localhost ([::1] helo=lists1p.gnu.org) by lists.gnu.org with esmtp (Exim 4.90_1) (envelope-from ) id 1ovtKI-0004yi-H7; Thu, 17 Nov 2022 23:50:06 -0500 Original-Received: from eggs.gnu.org ([2001:470:142:3::10]) by lists.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1ovtKF-0004yL-RU for bug-guile@gnu.org; Thu, 17 Nov 2022 23:50:03 -0500 Original-Received: from debbugs.gnu.org ([209.51.188.43]) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_128_GCM_SHA256:128) (Exim 4.90_1) (envelope-from ) id 1ovtKF-0006qU-Ib for bug-guile@gnu.org; Thu, 17 Nov 2022 23:50:03 -0500 Original-Received: from Debian-debbugs by debbugs.gnu.org with local (Exim 4.84_2) (envelope-from ) id 1ovtKF-0007t8-5E for bug-guile@gnu.org; Thu, 17 Nov 2022 23:50:03 -0500 X-Loop: help-debbugs@gnu.org In-Reply-To: <8d55cf7d1e5382c874cfcaee1f4cddd3@posteo.de> Resent-From: Andrew Whatson Original-Sender: "Debbugs-submit" Resent-CC: bug-guile@gnu.org Resent-Date: Fri, 18 Nov 2022 04:50:02 +0000 Resent-Message-ID: Resent-Sender: help-debbugs@gnu.org X-GNU-PR-Message: followup 59321 X-GNU-PR-Package: guile Original-Received: via spool by 59321-submit@debbugs.gnu.org id=B59321.166874696430269 (code B ref 59321); Fri, 18 Nov 2022 04:50:02 +0000 Original-Received: (at 59321) by debbugs.gnu.org; 18 Nov 2022 04:49:24 +0000 Original-Received: from localhost ([127.0.0.1]:34896 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1ovtJb-0007s7-Qo for submit@debbugs.gnu.org; Thu, 17 Nov 2022 23:49:24 -0500 Original-Received: from mail-yw1-f181.google.com ([209.85.128.181]:36355) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1ovtJZ-0007rv-Pm for 59321@debbugs.gnu.org; Thu, 17 Nov 2022 23:49:22 -0500 Original-Received: by mail-yw1-f181.google.com with SMTP id 00721157ae682-37063f855e5so39386727b3.3 for <59321@debbugs.gnu.org>; Thu, 17 Nov 2022 20:49:21 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20210112; h=cc:to:subject:message-id:date:from:mime-version:from:to:cc:subject :date:message-id:reply-to; bh=4e+HqZh93T+Omb3LJMI6aXQuk+8ehnB9Ch9VuVY/o4Q=; b=Avs/rxumSHTGa3FdNyAqbFqtQrKaIUXL+A5XaaqQWUNNDy4I1m/MdFRIDjAYb8di+9 m50H8r8CQmRFPKLnXs1FU+zLD6ThU66JmyELBOtMuOwcOuHOwOxHDCFJ/f7FYrwW1Yim LIAhLQ/4zzv5TtgUW8EbttStH+tamXqCDpXI8fziD3K72a/ojn6YIODkKxHzBlcNI6w+ qxj9UKAQh8AvO+QSyeLAmY0C3pyBhsGL6GFi2WArsFqOPkwU6QL32OHJLPs+EPd7biVN zMPXMRfG69Sz/N/l06C2B7DjOG9U6e8bYTtZZFm1jJJHfcYYKUYoh+KjQ5PU7MSikr+5 unIg== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20210112; h=cc:to:subject:message-id:date:from:mime-version:x-gm-message-state :from:to:cc:subject:date:message-id:reply-to; bh=4e+HqZh93T+Omb3LJMI6aXQuk+8ehnB9Ch9VuVY/o4Q=; b=L00YfqYlVEf1U/PTEe7JDqYdHb8aLe96a7THtrExBJQ39Zv1UZ/Wq8KS35fhgXjv5q y3wQlE7vfRRljqtjMZLmOFwzVI52GXpjQDqymgIYDiYj/hZ4ZAA91yz+it939CJdnk1i IV/GqUlgY/62lGiW+A159CSXB3jvDbrhGE5xi+D6aylHFJQTRRkL2kij90MoHEcqYNWR Gbuz57R+n28u7FSBIUxC+hgpxPVNyfq1vZGGi0mHccxXGG4/adwEth1SFZPWRru2XJR/ uPTI/QJDIwKpgNbLSbVjGjY6YaMYJdFG1EmLWjv/0qRgOFNRKa4PuYb6AApA5DTJQOMM 4oxQ== X-Gm-Message-State: ANoB5plUGpW8NPXIgh8Ncko//y0hbPwXOl+TDm+RqmdDqcdHlpHZVjLk IlzjuAMQsAghkacvCdDDsKrk/LQKrEOM4egbESg= X-Google-Smtp-Source: AA0mqf5EeohGz6EY+7nU0I/KcBPSvR5iPFt3OZtGd/0uBj7/ApV6W9ggT8R+QxQXIfEM4Ktg3N1gIZP9GbjlKcP3yg0= X-Received: by 2002:a81:49c4:0:b0:368:f9d0:1f28 with SMTP id w187-20020a8149c4000000b00368f9d01f28mr5218260ywa.374.1668746956005; Thu, 17 Nov 2022 20:49:16 -0800 (PST) X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list X-BeenThere: bug-guile@gnu.org List-Id: "Bug reports for GUILE, GNU's Ubiquitous Extension Language" List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: bug-guile-bounces+guile-bugs=m.gmane-mx.org@gnu.org Original-Sender: bug-guile-bounces+guile-bugs=m.gmane-mx.org@gnu.org Xref: news.gmane.io gmane.lisp.guile.bugs:10436 Archived-At: 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