bug#41702: `guix environment` performance issues
Hi,
Lars-Dominik Braun skribis:
> grafting is still a performance issue imo. Compare for example:
Agreed. The fix in 58bb833365db4e8934a386497d5b00a063cfd27d is
incomplete: we’re still potentially doing things several times.
> $ time guix environment --ad-hoc --search-paths r-learnr
> guix environment --ad-hoc --search-paths r-learnr 5,90s user 0,09s system
> 210% cpu 2,844 total
> $ time guix environment --ad-hoc --search-paths r-learnr --no-grafts
> guix environment --ad-hoc --search-paths r-learnr --no-grafts 2,03s user
> 0,08s system 164% cpu 1,277 total
Here’s what I get over a local socket:
--8<---cut here---start->8---
ludo@ribbon ~/src/guix$ time guix environment --ad-hoc --search-paths r-learnr
--no-grafts
export
PATH="/gnu/store/wkhd1fnmg1q30g21bfn5jprz24m041w6-profile/bin${PATH:+:}$PATH"
real0m1.790s
user0m1.928s
sys 0m0.102s
ludo@ribbon ~/src/guix$ time guix environment --ad-hoc --search-paths r-learnr
export
PATH="/gnu/store/pwzrpzdbli2561f2yq70kljywn93h5w6-profile/bin${PATH:+:}$PATH"
real0m3.820s
user0m4.954s
sys 0m0.105s
--8<---cut here---end--->8---
Ludo’.
bug#41702: `guix environment` performance issues
Hi Maxim, > Judging from the above, it seems this issue has been resolved. grafting is still a performance issue imo. Compare for example: $ time guix environment --ad-hoc --search-paths r-learnr guix environment --ad-hoc --search-paths r-learnr 5,90s user 0,09s system 210% cpu 2,844 total $ time guix environment --ad-hoc --search-paths r-learnr --no-grafts guix environment --ad-hoc --search-paths r-learnr --no-grafts 2,03s user 0,08s system 164% cpu 1,277 total Cheers, Lars signature.asc Description: PGP signature
bug#41702: `guix environment` performance issues
Hello, Ludovic Courtès writes: > Hi Lars, > > Lars-Dominik Braun skribis: > >> From 42ff75c9d4da4eb2aeece96119ae5a65a9ccac82 Mon Sep 17 00:00:00 2001 >> From: Lars-Dominik Braun >> Date: Mon, 20 Jul 2020 11:27:35 +0200 >> Subject: [PATCH 1/2] gnu: guile-ssh: Update to 0.13.0. >> >> * gnu/packages/ssh.scm (guile-ssh): Update to 0.13.0. > > [...] > >> From 6a18c9a4533075d1ee9795777a998fde3e64030f Mon Sep 17 00:00:00 2001 >> From: Lars-Dominik Braun >> Date: Mon, 20 Jul 2020 11:28:51 +0200 >> Subject: [PATCH 2/2] guix: Speed up RPC via SSH connections. >> >> See issue #41702 >> >> * guix/ssh.scm (open-ssh-session): Enable #:nodelay. >> * m4/guix.m4 (GUIX_CHECK_GUILE_SSH): Add feature check for this new >> parameter. > > I adjusted the commit log and pushed. > > I think it’s okay to use the new Guile-SSH feature right away because > it’s not central, and ‘guix pull’ gives people the ability to get the > new Guile-SSH version. Judging from the above, it seems this issue has been resolved. Closing. Thank you, Maxim
bug#41702: `guix environment` performance issues
Hi Lars, Lars-Dominik Braun skribis: > From 42ff75c9d4da4eb2aeece96119ae5a65a9ccac82 Mon Sep 17 00:00:00 2001 > From: Lars-Dominik Braun > Date: Mon, 20 Jul 2020 11:27:35 +0200 > Subject: [PATCH 1/2] gnu: guile-ssh: Update to 0.13.0. > > * gnu/packages/ssh.scm (guile-ssh): Update to 0.13.0. [...] > From 6a18c9a4533075d1ee9795777a998fde3e64030f Mon Sep 17 00:00:00 2001 > From: Lars-Dominik Braun > Date: Mon, 20 Jul 2020 11:28:51 +0200 > Subject: [PATCH 2/2] guix: Speed up RPC via SSH connections. > > See issue #41702 > > * guix/ssh.scm (open-ssh-session): Enable #:nodelay. > * m4/guix.m4 (GUIX_CHECK_GUILE_SSH): Add feature check for this new parameter. I adjusted the commit log and pushed. I think it’s okay to use the new Guile-SSH feature right away because it’s not central, and ‘guix pull’ gives people the ability to get the new Guile-SSH version. Thanks! Ludo’.
bug#41702: `guix environment` performance issues
Hi Ludo,
a new version has been released, so here is the updated patchset. I’m not sure
if it’s possible to make the #:nodelay optional somehow, i.e. retaining
compatibility with guile-ssh<0.13.0. For now there’s a hard feature check.
Lars
From 42ff75c9d4da4eb2aeece96119ae5a65a9ccac82 Mon Sep 17 00:00:00 2001
From: Lars-Dominik Braun
Date: Mon, 20 Jul 2020 11:27:35 +0200
Subject: [PATCH 1/2] gnu: guile-ssh: Update to 0.13.0.
* gnu/packages/ssh.scm (guile-ssh): Update to 0.13.0.
---
gnu/packages/ssh.scm | 4 ++--
1 file changed, 2 insertions(+), 2 deletions(-)
diff --git a/gnu/packages/ssh.scm b/gnu/packages/ssh.scm
index a612b9dd15..50316ea1be 100644
--- a/gnu/packages/ssh.scm
+++ b/gnu/packages/ssh.scm
@@ -297,7 +297,7 @@ Additionally, various channel-specific options can be negotiated.")
(define-public guile-ssh
(package
(name "guile-ssh")
-(version "0.12.0")
+(version "0.13.0")
(home-page "https://github.com/artyom-poptsov/guile-ssh;)
(source (origin
(method git-fetch)
@@ -307,7 +307,7 @@ Additionally, various channel-specific options can be negotiated.")
(file-name (string-append name "-" version ".tar.gz"))
(sha256
(base32
-"054hd9rzfhb48gc1hw3rphhp0cnnd4bs5qmidy5ygsyvy9ravlad"))
+"1q96h98p6x7ah6nc0d2wfx503fmsj36riv9ka9s79z3lzwaf0k26"))
(modules '((guix build utils)
(build-system gnu-build-system)
(outputs '("out" "debug"))
--
2.20.1
From 6a18c9a4533075d1ee9795777a998fde3e64030f Mon Sep 17 00:00:00 2001
From: Lars-Dominik Braun
Date: Mon, 20 Jul 2020 11:28:51 +0200
Subject: [PATCH 2/2] guix: Speed up RPC via SSH connections.
See issue #41702
* guix/ssh.scm (open-ssh-session): Enable #:nodelay.
* m4/guix.m4 (GUIX_CHECK_GUILE_SSH): Add feature check for this new parameter.
---
guix/ssh.scm | 5 -
m4/guix.m4 | 6 --
2 files changed, 8 insertions(+), 3 deletions(-)
diff --git a/guix/ssh.scm b/guix/ssh.scm
index 2d7ca7d01d..3bffb0b525 100644
--- a/guix/ssh.scm
+++ b/guix/ssh.scm
@@ -129,7 +129,10 @@ Throw an error on failure."
;; We need lightweight compression when
;; exchanging full archives.
#:compression compression
- #:compression-level 3)))
+ #:compression-level 3
+
+ ;; Speed up RPC.
+ #:nodelay #t)))
;; Honor ~/.ssh/config.
(session-parse-config! session)
diff --git a/m4/guix.m4 b/m4/guix.m4
index 7c27ae74df..cce03045db 100644
--- a/m4/guix.m4
+++ b/m4/guix.m4
@@ -142,14 +142,16 @@ dnl GUIX_CHECK_GUILE_SSH
dnl
dnl Check whether a recent-enough Guile-SSH is available.
AC_DEFUN([GUIX_CHECK_GUILE_SSH], [
- dnl Check whether 'userauth-gssapi!' (introduced in 0.12.0) is present.
+ dnl Check whether '#:nodelay' paramater to 'make-session' (introduced in
+ dnl 0.13.0) is present.
AC_CACHE_CHECK([whether Guile-SSH is available and recent enough],
[guix_cv_have_recent_guile_ssh],
[GUILE_CHECK([retval],
[(and (@ (ssh channel) channel-send-eof)
(@ (ssh popen) open-remote-pipe)
(@ (ssh dist node) node-eval)
-(@ (ssh auth) userauth-gssapi!))])
+(@ (ssh auth) userauth-gssapi!)
+((@ (ssh session) make-session) #:nodelay #t))])
if test "$retval" = 0; then
guix_cv_have_recent_guile_ssh="yes"
else
--
2.20.1
signature.asc
Description: PGP signature
bug#41702: `guix environment` performance issues
Hi Ludo, > I’d rather wait; perhaps you can ask Artyom whether they’re planning for > a new release soonish? “I'll see if I can fix some random test failures with Guile 2.2 that sometimes occur, and then I'll prepare a new release.” > If there’s no plan for a release within two weeks, we can go ahead with > the patch you propose. Alright, I’ll prepare a new patch if either of the two events happen. Cheers, Lars signature.asc Description: PGP signature
bug#41702: `guix environment` performance issues
Hi, Lars-Dominik Braun skribis: > and the attached patch uses the new nodelay option, if we don’t want to wait > for another guile-ssh release. I’d rather wait; perhaps you can ask Artyom whether they’re planning for a new release soonish? If there’s no plan for a release within two weeks, we can go ahead with the patch you propose. > From 2892f79f819dd2dd9420f7e74bcb6e293d377452 Mon Sep 17 00:00:00 2001 > From: Lars-Dominik Braun > Date: Thu, 2 Jul 2020 13:59:51 +0200 > Subject: [PATCH] guix: Add nodelay to SSH store connection > > * gnu/packages/ssh.scm (guile-ssh)[patches]: Add patch. > * gnu/packages/patches/guile-ssh-0.12.0-nodelay.patch: New file. > * gnu/local.mk (dist_patch_DATA): Add it. > * guix/ssh.scm (open-ssh-session): Use new nodelay option. If we take this route, the two patches (guile-ssh changes, then (guix ssh) changes) should be separate. Also #:nodelay will cause a hard failure for people using an older Guile-SSH. I wonder how to guard against that; configure check, or run-time Guile-SSH version check? > +++ b/gnu/packages/patches/guile-ssh-0.12.0-nodelay.patch It would be good to include the URL of the upstream issue Thanks! Ludo’.
bug#41702: `guix environment` performance issues
Hi (again),
and the attached patch uses the new nodelay option, if we don’t want to wait
for another guile-ssh release.
Lars
From 2892f79f819dd2dd9420f7e74bcb6e293d377452 Mon Sep 17 00:00:00 2001
From: Lars-Dominik Braun
Date: Thu, 2 Jul 2020 13:59:51 +0200
Subject: [PATCH] guix: Add nodelay to SSH store connection
* gnu/packages/ssh.scm (guile-ssh)[patches]: Add patch.
* gnu/packages/patches/guile-ssh-0.12.0-nodelay.patch: New file.
* gnu/local.mk (dist_patch_DATA): Add it.
* guix/ssh.scm (open-ssh-session): Use new nodelay option.
---
gnu/local.mk | 1 +
.../patches/guile-ssh-0.12.0-nodelay.patch| 81 +++
gnu/packages/ssh.scm | 1 +
guix/ssh.scm | 4 +-
4 files changed, 86 insertions(+), 1 deletion(-)
create mode 100644 gnu/packages/patches/guile-ssh-0.12.0-nodelay.patch
diff --git a/gnu/local.mk b/gnu/local.mk
index 8bb56010c2..26725cbca1 100644
--- a/gnu/local.mk
+++ b/gnu/local.mk
@@ -1068,6 +1068,7 @@ dist_patch_DATA = \
%D%/packages/patches/guile-present-coding.patch \
%D%/packages/patches/guile-rsvg-pkgconfig.patch \
%D%/packages/patches/guile-emacs-fix-configure.patch \
+ %D%/packages/patches/guile-ssh-0.12.0-nodelay.patch \
%D%/packages/patches/gtk2-respect-GUIX_GTK2_PATH.patch \
%D%/packages/patches/gtk2-respect-GUIX_GTK2_IM_MODULE_FILE.patch \
%D%/packages/patches/gtk2-theme-paths.patch \
diff --git a/gnu/packages/patches/guile-ssh-0.12.0-nodelay.patch b/gnu/packages/patches/guile-ssh-0.12.0-nodelay.patch
new file mode 100644
index 00..bc649b7469
--- /dev/null
+++ b/gnu/packages/patches/guile-ssh-0.12.0-nodelay.patch
@@ -0,0 +1,81 @@
+commit f697c603ef196eb88c1d7d629e456bf5054e35a4
+Author: Lars-Dominik Braun
+Date: Thu Jul 2 13:26:21 2020 +0200
+
+modules/ssh/session.scm: Add nodelay to make-session
+
+* modules/ssh/session.scm (make-session): Add key nodelay
+
+diff --git a/modules/ssh/session.scm b/modules/ssh/session.scm
+index d7c0831..042bd5f 100644
+--- a/modules/ssh/session.scm
b/modules/ssh/session.scm
+@@ -74,7 +74,7 @@
+knownhosts timeout timeout-usec ssh1 ssh2 log-verbosity
+ciphers-c-s ciphers-s-c compression-c-s compression-s-c
+proxycommand stricthostkeycheck compression
+- compression-level callbacks config)
++ compression-level nodelay callbacks config)
+ "Make a new SSH session with specified configuration.\n
+ Return a new SSH session."
+ (let ((session (%make-session)))
+@@ -98,6 +98,7 @@ Return a new SSH session."
+ (session-set-if-specified! stricthostkeycheck)
+ (session-set-if-specified! compression)
+ (session-set-if-specified! compression-level)
++(session-set-if-specified! nodelay)
+ (session-set-if-specified! callbacks)
+
+ (when config
+
+commit b80121ae3e851a676f25fd2b7e33371b94a6e030
+Author: Lars-Dominik Braun
+Date: Thu Jul 2 08:52:13 2020 +0200
+
+libguile-ssh/session-func.c: Add NODELAY option
+
+* libguile-ssh/session-func.c (session_options, set_option): Add libssh’s
+ nodelay option.
+* tests/session.scm ("session-set!, valid values", "session-set!, invalid
+ values"): Add unit-tests.
+
+diff --git a/libguile-ssh/session-func.c b/libguile-ssh/session-func.c
+index 48db779..9240734 100644
+--- a/libguile-ssh/session-func.c
b/libguile-ssh/session-func.c
+@@ -71,6 +71,7 @@ static struct symbol_mapping session_options[] = {
+ { "stricthostkeycheck", SSH_OPTIONS_STRICTHOSTKEYCHECK },
+ { "compression",SSH_OPTIONS_COMPRESSION},
+ { "compression-level", SSH_OPTIONS_COMPRESSION_LEVEL },
++ { "nodelay",SSH_OPTIONS_NODELAY},
+ { "callbacks", GSSH_OPTIONS_CALLBACKS },
+ { NULL, -1 }
+ };
+@@ -366,6 +367,7 @@ set_option (SCM scm_session, struct session_data* sd, int type, SCM value)
+ case SSH_OPTIONS_SSH1:
+ case SSH_OPTIONS_SSH2:
+ case SSH_OPTIONS_STRICTHOSTKEYCHECK:
++case SSH_OPTIONS_NODELAY:
+ return set_bool_opt (session, type, value);
+
+ case SSH_OPTIONS_FD:
+diff --git a/tests/session.scm b/tests/session.scm
+index 2eb1df7..83a864d 100644
+--- a/tests/session.scm
b/tests/session.scm
+@@ -70,6 +70,7 @@
+ nolog)
+(compression "yes" "no")
+(compression-level 1 2 3 4 5 6 7 8 9)
++ (nodelay #f #t)
+(callbacks ((user-data . "hello")
+(global-request-callback . ,(const #f))
+ (res #t))
+@@ -95,6 +96,7 @@
+(log-verbosity "string" -1 0 1 2 3 4 5)
+(compression 12345)
+(compression-level -1 0 10)
++ (nodelay 12345 "string")
+
bug#41702: `guix environment` performance issues
Hi, > Would you like to send them a patch? done: https://github.com/artyom-poptsov/guile-ssh/pull/21 Cheers, Lars signature.asc Description: PGP signature
bug#41702: `guix environment` performance issues
Hi, Lars-Dominik Braun skribis: >> What we need is Guile-SSH bindings for ‘ssh_get_fd’, which would allow >> us to get at the actual file descriptor after the connection has been >> opened, and to set TCP_NODELAY there: >> >> >> http://api.libssh.org/stable/group__libssh__session.html#gafe509fcea47714b5cd277d1e35e83276 >> >> It’s not 100% clear though if it returns that “right” FD when there’s a >> proxy command. > wouldn’t it be easier to add the SSH_OPTIONS_NODELAY option (see [1]) to > guile-ssh (should be trivial[2]) and let guile-ssh handle all the connection > stuff without touching the socket? Or do we need the raw socket elsewhere? Good idea, I had overlooked that possibility. Would you like to send them a patch? Thanks, Ludo’.
bug#41702: `guix environment` performance issues
Hey, > What we need is Guile-SSH bindings for ‘ssh_get_fd’, which would allow > us to get at the actual file descriptor after the connection has been > opened, and to set TCP_NODELAY there: > > > http://api.libssh.org/stable/group__libssh__session.html#gafe509fcea47714b5cd277d1e35e83276 > > It’s not 100% clear though if it returns that “right” FD when there’s a > proxy command. wouldn’t it be easier to add the SSH_OPTIONS_NODELAY option (see [1]) to guile-ssh (should be trivial[2]) and let guile-ssh handle all the connection stuff without touching the socket? Or do we need the raw socket elsewhere? Cheers, Lars [1] http://api.libssh.org/stable/group__libssh__session.html#ga7a801b85800baa3f4e16f5b47db0a73d [2] https://github.com/artyom-poptsov/guile-ssh/blob/master/libguile-ssh/session-func.c#L52 signature.asc Description: PGP signature
bug#41702: `guix environment` performance issues
Hi, Ludovic Courtès skribis: > +(when open-connection > + (let* ((sock (open-connection host port))) > +;; Since 'session-set!' doesn't increase the revealed count of SOCK > +;; (as of Guile-SSH 0.12.0), do it ourselves. > +(set-port-revealed! sock 1) > +(session-set! session 'fd sock))) The problem with this approach is that ‘open-connection’ is past the raw host name; aliases, proxy commands, etc. from ~/.ssh/config are ignored. So it cannot go in as is. :-/ What we need is Guile-SSH bindings for ‘ssh_get_fd’, which would allow us to get at the actual file descriptor after the connection has been opened, and to set TCP_NODELAY there: http://api.libssh.org/stable/group__libssh__session.html#gafe509fcea47714b5cd277d1e35e83276 It’s not 100% clear though if it returns that “right” FD when there’s a proxy command. Ludo’.
bug#41702: `guix environment` performance issues
Hi Ludo, > The patch below is a noticeable improvement for me. On my laptop, > > GUIX_DAEMON_SOCKET=ssh://localhost ./pre-inst-env guix build libreoffice -n > > goes from 5.8s to 3.3s. It just does the same thing as we do for > guix://. > > Could you check what results it gives you? looking pretty good, comparing master without/with patch: ---snip--- N Min MaxMedian AvgStddev x 10 16.87 20.77 17.4417.802 1.1228515 + 10 9.92 13.67 10.1910.569 1.1254574 Difference at 99.0% confidence -7.233 +/- 1.44688 -40.6303% +/- 6.68735% ---snap--- > There’s a project to rewrite the daemon in Scheme, started by Caleb > Ristvedt (reepa) as part of GSoC a few years ago. This could be an > opportunity to add a new version of the protocol that would support > pipelining. Given how much improvement you’ve achieved so far I’d say we can (for now) probably get away with the current protocol. Still, what’s the status of this daemon? Lars signature.asc Description: PGP signature
bug#41702: `guix environment` performance issues
Hi,
Lars-Dominik Braun skribis:
> That would have been my best guess too, but it does not seem to be the biggest
> problem right now. Looking at the numbers again (both patches applied) with
> the
> attached manifest[1], I see that:
>
> ---snip---
> Local UNIX socket with and without --no-grafts:
> N Min MaxMedian AvgStddev
> x 10 6.07 6.35 6.145 6.160.08232726
> + 10 17.47 17.8917.54517.6020.14351152
> Difference at 99.0% confidence
> 11.442 +/- 0.150576
> 185.747% +/- 4.07133%
>
> Local UNIX socket vs. guix://localhost transport:
> N Min MaxMedian AvgStddev
> x 10 17.47 17.8917.54517.6020.14351152
> + 10 17.43 18.1 17.6117.6420.20131788
> No difference proven at 99.0% confidence
>
> Local UNIX socket vs ssh://localhost transport:
> N Min MaxMedian AvgStddev
> x 10 17.47 17.8917.54517.6020.14351152
> + 10 33.46 35.2734.31534.3590.53873205
> Difference at 99.0% confidence
> 16.757 +/- 0.5074
> 95.1994% +/- 3.13957%
> ---snap---
>
> So I would conclude:
>
> 1) Grafting still takes a lot of time and needs more work
Yes, I noticed that there’s still redundant work being done, so we may
need global caching in addition to what
58bb833365db4e8934a386497d5b00a063cfd27d did.
> 2) Linux optimizes localhost networking pretty well
> 3) Our SSH transport is terribly slow
Yes.
The patch below is a noticeable improvement for me. On my laptop,
GUIX_DAEMON_SOCKET=ssh://localhost ./pre-inst-env guix build libreoffice -n
goes from 5.8s to 3.3s. It just does the same thing as we do for
guix://.
Could you check what results it gives you?
> So, I guess it would make sense for me to look at the SSH transport itself
> again and see if there are any other low-hanging fruit. Not sure how much I
> can
> help with profiling guile/guix itself. A different/better RPC protocol is
> probably GSoC/v2.0-worthy?
There’s a project to rewrite the daemon in Scheme, started by Caleb
Ristvedt (reepa) as part of GSoC a few years ago. This could be an
opportunity to add a new version of the protocol that would support
pipelining.
Thanks,
Ludo’.
diff --git a/guix/ssh.scm b/guix/ssh.scm
index 2d7ca7d01d..a9312b7c8c 100644
--- a/guix/ssh.scm
+++ b/guix/ssh.scm
@@ -98,7 +98,7 @@ actual key does not match."
key type
(define* (open-ssh-session host #:key user port identity
- host-key
+ host-key open-connection
(compression %compression)
(timeout 3600))
"Open an SSH session for HOST and return it. IDENTITY specifies the file
@@ -110,6 +110,10 @@ When HOST-KEY is true, it must be a string like \"ssh-ed25519 C3Nz…
r...@example.org\"; the server is authenticated and an error is raised if its
host key is different from HOST-KEY.
+When OPEN-CONNECTION is true, it must be a two-argument procedure; it is
+passed HOST and PORT and must return a socket (a file port). When
+OPEN-CONNECTION is false, Guile-SSH takes care of opening the connection.
+
Install TIMEOUT as the maximum time in seconds after which a read or write
operation on a channel of the returned session is considered as failing.
@@ -134,6 +138,13 @@ Throw an error on failure."
;; Honor ~/.ssh/config.
(session-parse-config! session)
+(when open-connection
+ (let* ((sock (open-connection host port)))
+;; Since 'session-set!' doesn't increase the revealed count of SOCK
+;; (as of Guile-SSH 0.12.0), do it ourselves.
+(set-port-revealed! sock 1)
+(session-set! session 'fd sock)))
+
(match (connect! session)
('ok
(if host-key
diff --git a/guix/store/ssh.scm b/guix/store/ssh.scm
index 09c0832505..d07f0d7467 100644
--- a/guix/store/ssh.scm
+++ b/guix/store/ssh.scm
@@ -1,5 +1,5 @@
;;; GNU Guix --- Functional package management for GNU
-;;; Copyright © 2017 Ludovic Courtès
+;;; Copyright © 2017, 2020 Ludovic Courtès
;;;
;;; This file is part of GNU Guix.
;;;
@@ -19,6 +19,7 @@
(define-module (guix store ssh)
#:use-module (guix ssh)
#:use-module (web uri)
+ #:use-module (ssh session)
#:export (connect-to-daemon))
;;; Commentary:
@@ -29,11 +30,27 @@
;;;
;;; End:
+(define (open-connection host port)
+ "Open a connection to HOST and PORT. Use the standard SSH port if PORT is
+false."
+ (let* ((lst (getaddrinfo host
+(if port (number->string port) "ssh")
+(if port AI_NUMERICSERV 0)))
+ (addr (addrinfo:addr (car lst)))
+ (sock (socket (sockaddr:fam addr)
bug#41702: `guix environment` performance issues
Hey, > That’s over SSH, right? correct, the worst possible case: Inside two VM’s on a Laptop, SSH transport between them and /gnu+/var/guix on an NFS share (nfsd is in the same VM as guix-daemon). > Probably what’s killing us is the round-trip time for all these small > RPCs. We would need pipelining but the RPC protocol is not designed to > make that easy. That would have been my best guess too, but it does not seem to be the biggest problem right now. Looking at the numbers again (both patches applied) with the attached manifest[1], I see that: ---snip--- Local UNIX socket with and without --no-grafts: N Min MaxMedian AvgStddev x 10 6.07 6.35 6.145 6.160.08232726 + 10 17.47 17.8917.54517.6020.14351152 Difference at 99.0% confidence 11.442 +/- 0.150576 185.747% +/- 4.07133% Local UNIX socket vs. guix://localhost transport: N Min MaxMedian AvgStddev x 10 17.47 17.8917.54517.6020.14351152 + 10 17.43 18.1 17.6117.6420.20131788 No difference proven at 99.0% confidence Local UNIX socket vs ssh://localhost transport: N Min MaxMedian AvgStddev x 10 17.47 17.8917.54517.6020.14351152 + 10 33.46 35.2734.31534.3590.53873205 Difference at 99.0% confidence 16.757 +/- 0.5074 95.1994% +/- 3.13957% ---snap--- So I would conclude: 1) Grafting still takes a lot of time and needs more work 2) Linux optimizes localhost networking pretty well 3) Our SSH transport is terribly slow Moving to non-localhost communication between two VM’s: ---snip--- guix://localhost vs. guix://remote-host transport: N Min MaxMedian AvgStddev x 10 17.43 18.1 17.6117.6420.20131788 + 10 20.88 22.5821.09521.2220.49689704 Difference at 99.0% confidence 3.58 +/- 0.487934 20.2925% +/- 2.85159% guix://remote-host vs. ssh://remote-host: N Min MaxMedian AvgStddev x 10 20.88 22.5821.09521.2220.49689704 + 10 30.1 32.5631.00531.0930.70740606 Difference at 99.0% confidence 9.871 +/- 0.786769 46.5131% +/- 4.35326% ---snap--- Conclusion here is the same: Not alot of impact of networking/NFS and SSH transport is still terribly slow. (Confusingly faster than localhost though.) > Perhaps you could “strace -Tt” the thing to check whether this > hypothesis is correct by looking at the time we spend waiting for > replies? I’m not sure this will yield meaningful data for SSH, so I analyzet it for guix://localhost vs. guix://remote-host. Takeaway is, yes, of course there is a statistically significant difference and it’s about 40%±50%, which means this method is pretty useless, because we can’t bin RPC’s by type. So, I guess it would make sense for me to look at the SSH transport itself again and see if there are any other low-hanging fruit. Not sure how much I can help with profiling guile/guix itself. A different/better RPC protocol is probably GSoC/v2.0-worthy? Sorry for all the lengthy emails, Lars [1] You’ll need this channel: https://github.com/leibniz-psychology/guix-zpid (specifications->manifest '( "coreutils" "findutils" "procps" "strace" "openssh" "mit-krb5" "bash" "which" "zip" "geeqie" "util-linux" "grep" "glibc" ;; for locales "glibc-locales" ;; front-end software "jupyter-zpid" "python-jupyterlab" ;; available notebook kernel ; provided by jupyter-zpid ;"python-ipykernel" "r-irkernel" "rstudio-server-zpid" "r" ;; for RMarkdown "r-knitr" "r-yaml" "r-markdown" "r-rmarkdown" "texlive" ;; commonly used r packages "r-psych" "r-ggplot2" "r-lattice" "r-foreign" "r-readr" "r-haven" "r-dplyr" "r-tidyr" "r-stringr" "r-forecast" "r-lme4" "r-nlme" "r-nnet" "r-glmnet" "r-caret" "r-xmisc" "r-splitstackshape" "r-tm" "r-quanteda" "r-topicmodels" "r-stm" ;;"r-parallel" "r-dt" "r-nlp" "r-data-table" "r-hmisc" "r-learnr" "r-metafor" ;; for rmarkdown "ghc-pandoc" )) signature.asc Description: PGP signature
bug#41702: `guix environment` performance issues
Hi,
Lars-Dominik Braun skribis:
>> --8<---cut here---start->8---
>> $ time guix environment --ad-hoc r-learnr --search-paths
>> export
>> PATH="/gnu/store/n4wxbmqpafjfyawrla8xymzzdm5hxwph-profile/bin${PATH:+:}$PATH"
>>
>> real 0m11.328s
>> user 0m20.155s
>> sys 0m0.172s
>> $ time ./pre-inst-env guix environment --ad-hoc r-learnr --search-paths
>> export
>> PATH="/gnu/store/if6z77la3mx0qdzvcyl4qv9i5cyp48i0-profile/bin${PATH:+:}$PATH"
>>
>> real 0m4.602s
>> user 0m6.189s
>> sys 0m0.136s
>> --8<---cut here---end--->8---
> that’s awesome and brings me much closer to my goal of running all
> applications
> inside a `guix environment` container for reproducibility. Including the
> protocol fixes from #41720 I’m now down to ~30s from ~50s, which may be called
> somewhat usable. Obviously I’d be very interested in further speedups.
That’s over SSH, right?
Probably what’s killing us is the round-trip time for all these small
RPCs. We would need pipelining but the RPC protocol is not designed to
make that easy.
Perhaps you could “strace -Tt” the thing to check whether this
hypothesis is correct by looking at the time we spend waiting for
replies?
As for the CPU cost (i.e., going below the 4.6s above), we should keep
profiling just like you did.
Thanks,
Ludo’.
bug#41702: `guix environment` performance issues
Hi Ludo,
> --8<---cut here---start->8---
> $ time guix environment --ad-hoc r-learnr --search-paths
> export
> PATH="/gnu/store/n4wxbmqpafjfyawrla8xymzzdm5hxwph-profile/bin${PATH:+:}$PATH"
>
> real 0m11.328s
> user 0m20.155s
> sys 0m0.172s
> $ time ./pre-inst-env guix environment --ad-hoc r-learnr --search-paths
> export
> PATH="/gnu/store/if6z77la3mx0qdzvcyl4qv9i5cyp48i0-profile/bin${PATH:+:}$PATH"
>
> real 0m4.602s
> user 0m6.189s
> sys 0m0.136s
> --8<---cut here---end--->8---
that’s awesome and brings me much closer to my goal of running all applications
inside a `guix environment` container for reproducibility. Including the
protocol fixes from #41720 I’m now down to ~30s from ~50s, which may be called
somewhat usable. Obviously I’d be very interested in further speedups.
Thanks,
Lars
signature.asc
Description: PGP signature
bug#41702: `guix environment` performance issues
Ludovic Courtès skribis: > The patch below arranges so that ‘cumulative-grafts’ processes > dependencies in a batch, such that the derivation’s dependency graph is > traversed once for all, which makes a difference for derivations with > lots of inputs. Pushed: https://git.savannah.gnu.org/cgit/guix.git/commit/?id=58bb833365db4e8934a386497d5b00a063cfd27d Ludo’.
bug#41702: `guix environment` performance issues
Hi,
Lars-Dominik Braun skribis:
> Total time: 24.672604202 seconds (19.431122691 seconds in GC)
> ./pre-inst-env guix environment --ad-hoc r-learnr -- true 25,18s user 0,24s
> system 308% cpu 8,248 total
>
> More specifically in an anonymous function and reap-pipes, which is a gc hook,
> I believe:
>
> % cumulative self
> time secondsseconds calls procedure
> 33.41 14.49 8.24anon #xbb8480
> 27.95 6.90 6.90
> ice-9/popen.scm:145:0:reap-pipes
> 4.37 1.08 1.08anon #xbbdcd8
> 3.28 0.86 0.81
> ice-9/vlist.scm:539:0:vhash-assq
> 2.40 2.37 0.59guix/grafts.scm:202:22
Guile master has a fix for statprof that yields more useful info:
--8<---cut here---start->8---
scheme@(guile-user)> ,use(guix scripts environment)
scheme@(guile-user)> ,pr (guix-environment "--ad-hoc" "r-learnr" "--" "true")
% cumulative self
time seconds seconds procedure
29.84 9.87 6.16 append
19.56 4.04 4.04 %after-gc-thunk
6.85 1.87 1.42 ice-9/vlist.scm:539:0:vhash-assq
5.44 1.17 1.12 write
3.23 0.67 0.67 guix/derivations.scm:665:0:derivation->output-paths
2.82 0.58 0.58 string=?
2.42 2.37 0.50 guix/grafts.scm:202:22
2.42 0.50 0.50 list?
2.22 0.46 0.46 hashq
2.02 0.42 0.42 display
1.61 15.82 0.33 guix/grafts.scm:186:0:reference-origin
1.61 0.87 0.33 guix/grafts.scm:204:31
1.21 0.33 0.25 guix/derivations.scm:667:7
1.21 0.29 0.25 srfi/srfi-1.scm:817:0:any
1.01 1232.14 0.21 srfi/srfi-1.scm:584:5:map1
0.81 0.83 0.17 guix/derivations.scm:697:0:derivation/masked-inputs
0.81 0.75 0.17 srfi/srfi-1.scm:580:2:map
0.81 0.17 0.17
guix/derivations.scm:158:0:%derivation-input-derivation-procedure
0.60 0.17 0.12 reverse
0.60 0.12 0.12 hashq-ref
0.60 0.12 0.12 get-bytevector-n
0.60 0.12 0.12 procedure?
0.40 0.67 0.08 guix/packages.scm:1232:0:fold-bag-dependencies
0.40 0.12 0.08 string->utf8
0.40 0.12 0.08 ice-9/vlist.scm:534:0:vhash-assoc
0.40 0.12 0.08 ice-9/vlist.scm:449:0:vhash-cons
0.40 0.12 0.08 delete-duplicates
0.40 0.08 0.08 ice-9/boot-9.scm:1389:0:->bool
0.40 0.08 0.08 ice-9/boot-9.scm:2201:0:%load-announce
0.40 0.08 0.08 hash
0.40 0.08 0.08 guix/derivations.scm:665:0:derivation->output-paths
0.20 20.73 0.04 guix/gexp.scm:1061:2
--8<---cut here---end--->8---
Notice that the same command with ‘--no-grafts’ takes 2s instead of 11s.
The patch below arranges so that ‘cumulative-grafts’ processes
dependencies in a batch, such that the derivation’s dependency graph is
traversed once for all, which makes a difference for derivations with
lots of inputs.
Here’s the before/after comparison:
--8<---cut here---start->8---
$ time guix environment --ad-hoc r-learnr --search-paths
export
PATH="/gnu/store/n4wxbmqpafjfyawrla8xymzzdm5hxwph-profile/bin${PATH:+:}$PATH"
real0m11.328s
user0m20.155s
sys 0m0.172s
$ time ./pre-inst-env guix environment --ad-hoc r-learnr --search-paths
export
PATH="/gnu/store/if6z77la3mx0qdzvcyl4qv9i5cyp48i0-profile/bin${PATH:+:}$PATH"
real0m4.602s
user0m6.189s
sys 0m0.136s
--8<---cut here---end--->8---
There’s still room for improvement, but it’s much better.
Ludo’.
diff --git a/guix/grafts.scm b/guix/grafts.scm
index 69d6fe4469..910dcadc8a 100644
--- a/guix/grafts.scm
+++ b/guix/grafts.scm
@@ -20,10 +20,12 @@
#:use-module (guix store)
#:use-module (guix monads)
#:use-module (guix records)
+ #:use-module (guix combinators)
#:use-module (guix derivations)
#:use-module ((guix utils) #:select (%current-system))
#:use-module (guix sets)
#:use-module (srfi srfi-1)
+ #:use-module (srfi srfi-11)
#:use-module (srfi srfi-9 gnu)
#:use-module (srfi srfi-26)
#:use-module (srfi srfi-34)
@@ -183,32 +185,47 @@ references."
(set-current-state (vhash-cons key result cache))
(return result)))
-(define (reference-origin drv item)
- "Return the derivation/output pair among the inputs of DRV, recursively,
-that produces ITEM. Return #f if ITEM is not produced by a derivation (i.e.,
-it's a content-addressed \"source\"), or if it's not produced by a dependency
-of DRV."
+(define (reference-origins drv items)
+ "Return the derivation/output pairs among the inputs of DRV, recursively,
+that produce ITEMS. Elements of ITEMS not produced by a derivation (i.e.,
+it's a
bug#41702: `guix environment` performance issues
Hi, I’ve noticed that `guix environment` can be very very slow for some packages. Whereas usually a call like time guix environment --ad-hoc -- true takes 600ms to 1.5s, it takes 8.4s for the package r-learnr on my Ryzen 5 3600 with NVMe SSD, 32G of RAM and a warm cache. This seems to accumulate when trying to install multiple unrelated “slow” packages into the same environment, i.e. jupyter (2.9s) + r-rlearnr (8.4s) + r-stm (2.9s) = 12.1s. What these packages seem to have in common is a deep chain of propagated inputs. And in fact, if I create artificial test packages where test-999 propagates test-998, test-998→test-997 and so on the command above takes 1m 9s. A single package propagating 999 packages takes 4.5s. Instrumenting guix-environment’s with-store call with statprof I see a lot of time is spent in the garbage collector: Total time: 24.672604202 seconds (19.431122691 seconds in GC) ./pre-inst-env guix environment --ad-hoc r-learnr -- true 25,18s user 0,24s system 308% cpu 8,248 total More specifically in an anonymous function and reap-pipes, which is a gc hook, I believe: % cumulative self time secondsseconds calls procedure 33.41 14.49 8.24anon #xbb8480 27.95 6.90 6.90 ice-9/popen.scm:145:0:reap-pipes 4.37 1.08 1.08anon #xbbdcd8 3.28 0.86 0.81 ice-9/vlist.scm:539:0:vhash-assq 2.40 2.37 0.59guix/grafts.scm:202:22 Not sure if that helps tracking the issue down though. Cheers, Lars PS: Here’s `guix describe`: Generation 1Jun 03 2020 10:38:17(current) guix 9ab2790 repository URL: https://git.savannah.gnu.org/git/guix.git branch: master commit: 9ab2790e2acf872c0f2cf41ec180de80d1eee3f3 zpid bab33c1 repository URL: https://github.com/leibniz-psychology/guix-zpid.git branch: master commit: bab33c19e0f0304d7aa82751653eb85d8cad8c0a signature.asc Description: PGP signature
