bug#27097: [PATCH] gnu: Add emacs-direnv.

bug#27097: [PATCH] gnu: Add emacs-direnv.

[Christopher Baines]

* gnu/packages/emacs.scm (emacs-direnv): New variable.
---
 gnu/packages/emacs.scm | 31 +++++++++++++++++++++++++++++++
 1 file changed, 31 insertions(+)

diff --git a/gnu/packages/emacs.scm b/gnu/packages/emacs.scm
index a59a4ca69..f378ec368 100644
--- a/gnu/packages/emacs.scm
+++ b/gnu/packages/emacs.scm
@@ -1227,6 +1227,37 @@ or XEmacs.")
 the Emacs buffer.")
     (license license:gpl3+)))
 
+(define-public emacs-direnv
+  (package
+    (name "emacs-direnv")
+    (version "1.2.0")
+    (source
+     (origin
+       (method url-fetch)
+       (uri (string-append
+             "https://github.com/wbolster/emacs-direnv/archive/"
+             version ".tar.gz"))
+       (file-name (string-append name "-" version ".tar.gz"))
+       (sha256
+        (base32
+         "0m9nxawklhiiysyibzzhh2zkxgq1fskqvaqb06f7r8dnhabfy9fr"))))
+    (build-system emacs-build-system)
+    (propagated-inputs
+     `(("dash" ,emacs-dash)
+       ("with-editor" ,emacs-with-editor)))
+    (home-page "https://github.com/wbolster/emacs-direnv")
+    (synopsis "Direnv integration for Emacs")
+    (description
+     "This package provides support for invoking direnv to get the environment
+for the current file and updating the environment within Emacs to match.
+
+Direnv can be invoked manually, and a global minor mode is included that will
+update the environment when the active buffer changes.
+
+Using emacs-direnv means that programs started from Emacs will use the
+environment set through Direnv.")
+    (license license:gpl3+)))
+
 (define-public emacs-google-maps
   (package
     (name "emacs-google-maps")
-- 
2.13.0

Combining Guix, direnv and Emacs for environment customisation

[Christopher Baines]

[-- Attachment #1: Type: text/plain, Size: 2776 bytes --]

Hey,

In summary, using direnv provides a convinient way to manage different
environments created from Guix. There is now support for using direnv
directly from Emacs.

So for a while now I've been using direnv and Guix, but thanks to
recent improvements with the Emacs integration, its now become even
more useful.

direnv [1] is an environment switcher for shells, for example, you want
to have a specific environment variable set when working on a particular
project, you drop a .envrc file in to the relevant directory and
providing direnv is hooked in to your shell, it will get loaded and
unloaded as you move in and out of that directory.

1: https://direnv.net/

While direnv is useful for simple environment variables, guix
environment can output environment variables with the --shell-paths
option. Using guix environment in a .envrc file would look something
like:

  eval "$(guix environment --ad-hoc guile --search-paths)"

There is a use_guix helper function in the direnv stdlib [2] that helps
with this, so you can just do:

  use guix --ad-hoc guile

2: https://github.com/direnv/direnv/blob/master/stdlib.sh#L574-L586

I've been using direnv and Guix for a while now, but to use both with
Emacs, I've been starting a shell outside of Emacs, navigating to the
relevant directory so that direnv sets up the environment, and then
starting Emacs from the shell such that running programs (e.g. linters,
ruby, ...) from Emacs works within the environment setup through Guix
and direnv.

I've recently become aware of emacs-direnv [3], which provides access
to the functionality of direnv from Emacs. When the global minor mode
is active, this means that moving around between buffers in Emacs can
completely change the environment within Emacs. This had made my
workflow simpler, as I now just open Emacs, and navigate to the
relevant directory, and direnv just works behind the scenes.

3: https://github.com/wbolster/emacs-direnv

One issue with this is that running guix environment from direnv will
slow down switching buffers. To make it a bit more useable, I found
some bash code that caches the results of running commands, and wrapped
that around guix environment when invoked from direnv. This helps speed
things up, but I don't think its useful in the long term.

For this particular use case, it would help if guix environment was
faster, perhaps by doing caching internally? On my system, running guix
environment --ad-hoc guile --search-paths repeatedly takes ~2 seconds,
I haven't looked at what the breakdown of this is yet.

I'd be interested in hearing if anyone does something similar for using
Guix, or if anyone does something different, but to the same effect?

Thanks,

Chris

[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 963 bytes --]

bug#27097: [PATCH] gnu: Add emacs-direnv.

[Ludovic Courtès]

Christopher Baines <mail@cbaines.net> skribis:

> * gnu/packages/emacs.scm (emacs-direnv): New variable.

Applied, thanks!

I wish Emacs-Guix had similar integration with ‘guix environment’.   :-)

Perhaps we should also provide shell hooks to provide an experience
comparable to that of direnv?

Ludo’.

Re: Combining Guix, direnv and Emacs for environment customisation

[Ludovic Courtès]

Hi Christopher!

Christopher Baines <mail@cbaines.net> skribis:

> direnv [1] is an environment switcher for shells, for example, you want
> to have a specific environment variable set when working on a particular
> project, you drop a .envrc file in to the relevant directory and
> providing direnv is hooked in to your shell, it will get loaded and
> unloaded as you move in and out of that directory.
>
> 1: https://direnv.net/
>
> While direnv is useful for simple environment variables, guix
> environment can output environment variables with the --shell-paths
> option. Using guix environment in a .envrc file would look something
> like:
>
>   eval "$(guix environment --ad-hoc guile --search-paths)"
>
> There is a use_guix helper function in the direnv stdlib [2] that helps
> with this, so you can just do:
>
>   use guix --ad-hoc guile

This is pretty cool!

However, using ‘guix environment --search-paths’ is kinda unsafe: the
items mentioned in its output are not protected from GC.  This is why
‘guix environment’ normally spawns a shell or some other process while
keep its guix-daemon session open.

> I've recently become aware of emacs-direnv [3], which provides access
> to the functionality of direnv from Emacs. When the global minor mode
> is active, this means that moving around between buffers in Emacs can
> completely change the environment within Emacs. This had made my
> workflow simpler, as I now just open Emacs, and navigate to the
> relevant directory, and direnv just works behind the scenes.
>
> 3: https://github.com/wbolster/emacs-direnv

I think it’d be great Emacs-Guix could do something similar, i.e.,
associate a ‘guix environment’ to a buffer.  :-)

> One issue with this is that running guix environment from direnv will
> slow down switching buffers. To make it a bit more useable, I found
> some bash code that caches the results of running commands, and wrapped
> that around guix environment when invoked from direnv. This helps speed
> things up, but I don't think its useful in the long term.
>
> For this particular use case, it would help if guix environment was
> faster, perhaps by doing caching internally? On my system, running guix
> environment --ad-hoc guile --search-paths repeatedly takes ~2 seconds,
> I haven't looked at what the breakdown of this is yet.

I agree that we could do a lot more things with a faster ‘guix
environment’.  My guess is that it won’t be easy to go optimize, and
very hard to go below 1 second.  We should profile that and see what can
be done.

Cheers,
Ludo’.

bug#27097: Combining Guix, direnv and Emacs for environment customisation

[Ludovic Courtès]

Hi Christopher!

Christopher Baines <mail@cbaines.net> skribis:

> direnv [1] is an environment switcher for shells, for example, you want
> to have a specific environment variable set when working on a particular
> project, you drop a .envrc file in to the relevant directory and
> providing direnv is hooked in to your shell, it will get loaded and
> unloaded as you move in and out of that directory.
>
> 1: https://direnv.net/
>
> While direnv is useful for simple environment variables, guix
> environment can output environment variables with the --shell-paths
> option. Using guix environment in a .envrc file would look something
> like:
>
>   eval "$(guix environment --ad-hoc guile --search-paths)"
>
> There is a use_guix helper function in the direnv stdlib [2] that helps
> with this, so you can just do:
>
>   use guix --ad-hoc guile

This is pretty cool!

However, using ‘guix environment --search-paths’ is kinda unsafe: the
items mentioned in its output are not protected from GC.  This is why
‘guix environment’ normally spawns a shell or some other process while
keep its guix-daemon session open.

> I've recently become aware of emacs-direnv [3], which provides access
> to the functionality of direnv from Emacs. When the global minor mode
> is active, this means that moving around between buffers in Emacs can
> completely change the environment within Emacs. This had made my
> workflow simpler, as I now just open Emacs, and navigate to the
> relevant directory, and direnv just works behind the scenes.
>
> 3: https://github.com/wbolster/emacs-direnv

I think it’d be great Emacs-Guix could do something similar, i.e.,
associate a ‘guix environment’ to a buffer.  :-)

> One issue with this is that running guix environment from direnv will
> slow down switching buffers. To make it a bit more useable, I found
> some bash code that caches the results of running commands, and wrapped
> that around guix environment when invoked from direnv. This helps speed
> things up, but I don't think its useful in the long term.
>
> For this particular use case, it would help if guix environment was
> faster, perhaps by doing caching internally? On my system, running guix
> environment --ad-hoc guile --search-paths repeatedly takes ~2 seconds,
> I haven't looked at what the breakdown of this is yet.

I agree that we could do a lot more things with a faster ‘guix
environment’.  My guess is that it won’t be easy to go optimize, and
very hard to go below 1 second.  We should profile that and see what can
be done.

Cheers,
Ludo’.

Re: Combining Guix, direnv and Emacs for environment customisation

[Roel Janssen]

Ludovic Courtès writes:

> I agree that we could do a lot more things with a faster ‘guix
> environment’.  My guess is that it won’t be easy to go optimize, and
> very hard to go below 1 second.  We should profile that and see what can
> be done.

FWIW, on our NFS-mounted /gnu, the 'guix environment' command takes at
least 20 seconds, but for any reasonably big environment it takes more
than one minute.  The biggest bottleneck here is the disk latency.
Could it be that 'guix environment' accesses many files?  If we could
reduce that, it would speed things up (at least for us ;)).

Kind regards,
Roel Janssen

Re: Combining Guix, direnv and Emacs for environment customisation

[Ludovic Courtès]

Roel Janssen <roel@gnu.org> skribis:

> Ludovic Courtès writes:
>
>> I agree that we could do a lot more things with a faster ‘guix
>> environment’.  My guess is that it won’t be easy to go optimize, and
>> very hard to go below 1 second.  We should profile that and see what can
>> be done.
>
> FWIW, on our NFS-mounted /gnu, the 'guix environment' command takes at
> least 20 seconds, but for any reasonably big environment it takes more
> than one minute.  The biggest bottleneck here is the disk latency.
> Could it be that 'guix environment' accesses many files?  If we could
> reduce that, it would speed things up (at least for us ;)).

Interesting.   Does guix-daemon access /gnu over NFS too?

Could you send the output of (first run the same command without
‘strace’):

  strace -c guix environment --ad-hoc coreutils --pure -- true

On my laptop I get:

--8<---------------cut here---------------start------------->8---
$ strace -c guix environment --ad-hoc coreutils --pure -- true
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 37.84    0.017268           1     14036     10965 stat
 15.13    0.006904           1      9990           read
 14.02    0.006398           1     10000           write
  8.75    0.003991        3991         1           wait4
  6.06    0.002764           1      5218         4 lstat
  4.73    0.002157           1      1930       136 open
  2.58    0.001176           1      1794           close
  2.08    0.000949           1      1717         3 lseek
  2.04    0.000932           1       689           mmap
  1.89    0.000861           1       645           mprotect
  1.71    0.000781           4       189        32 futex

[…]
--8<---------------cut here---------------end--------------->8---

We stat a lot mostly to access all the Guix modules.  Are they on NFS
too?

Thanks,
Ludo’.

bug#27097: Combining Guix, direnv and Emacs for environment customisation

[Ludovic Courtès]

Roel Janssen <roel@gnu.org> skribis:

> Ludovic Courtès writes:
>
>> I agree that we could do a lot more things with a faster ‘guix
>> environment’.  My guess is that it won’t be easy to go optimize, and
>> very hard to go below 1 second.  We should profile that and see what can
>> be done.
>
> FWIW, on our NFS-mounted /gnu, the 'guix environment' command takes at
> least 20 seconds, but for any reasonably big environment it takes more
> than one minute.  The biggest bottleneck here is the disk latency.
> Could it be that 'guix environment' accesses many files?  If we could
> reduce that, it would speed things up (at least for us ;)).

Interesting.   Does guix-daemon access /gnu over NFS too?

Could you send the output of (first run the same command without
‘strace’):

  strace -c guix environment --ad-hoc coreutils --pure -- true

On my laptop I get:

--8<---------------cut here---------------start------------->8---
$ strace -c guix environment --ad-hoc coreutils --pure -- true
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 37.84    0.017268           1     14036     10965 stat
 15.13    0.006904           1      9990           read
 14.02    0.006398           1     10000           write
  8.75    0.003991        3991         1           wait4
  6.06    0.002764           1      5218         4 lstat
  4.73    0.002157           1      1930       136 open
  2.58    0.001176           1      1794           close
  2.08    0.000949           1      1717         3 lseek
  2.04    0.000932           1       689           mmap
  1.89    0.000861           1       645           mprotect
  1.71    0.000781           4       189        32 futex

[…]
--8<---------------cut here---------------end--------------->8---

We stat a lot mostly to access all the Guix modules.  Are they on NFS
too?

Thanks,
Ludo’.

Re: Combining Guix, direnv and Emacs for environment customisation

[Roel Janssen]

Ludovic Courtès writes:

> Roel Janssen <roel@gnu.org> skribis:
>
>> Ludovic Courtès writes:
>>
>>> I agree that we could do a lot more things with a faster ‘guix
>>> environment’.  My guess is that it won’t be easy to go optimize, and
>>> very hard to go below 1 second.  We should profile that and see what can
>>> be done.
>>
>> FWIW, on our NFS-mounted /gnu, the 'guix environment' command takes at
>> least 20 seconds, but for any reasonably big environment it takes more
>> than one minute.  The biggest bottleneck here is the disk latency.
>> Could it be that 'guix environment' accesses many files?  If we could
>> reduce that, it would speed things up (at least for us ;)).
>
> Interesting.   Does guix-daemon access /gnu over NFS too?

Yes.

> Could you send the output of (first run the same command without
> ‘strace’):
>
>   strace -c guix environment --ad-hoc coreutils --pure -- true
>
> On my laptop I get:
>
> --8<---------------cut here---------------start------------->8---
> $ strace -c guix environment --ad-hoc coreutils --pure -- true
> % time     seconds  usecs/call     calls    errors syscall
> ------ ----------- ----------- --------- --------- ----------------
>  37.84    0.017268           1     14036     10965 stat
>  15.13    0.006904           1      9990           read
>  14.02    0.006398           1     10000           write
>   8.75    0.003991        3991         1           wait4
>   6.06    0.002764           1      5218         4 lstat
>   4.73    0.002157           1      1930       136 open
>   2.58    0.001176           1      1794           close
>   2.08    0.000949           1      1717         3 lseek
>   2.04    0.000932           1       689           mmap
>   1.89    0.000861           1       645           mprotect
>   1.71    0.000781           4       189        32 futex
>
> […]
> --8<---------------cut here---------------end--------------->8---
>
> We stat a lot mostly to access all the Guix modules.  Are they on NFS
> too?

Yes.

> Thanks,
> Ludo’.

Here's my output:

[rjanssen2@hpcguix ~]$ strace -c guix environment --ad-hoc coreutils --pure -- true
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 41.79    0.038363          22      1782       188 open
 14.71    0.013500           3      4769      1747 stat
 13.19    0.012106           2      8033           read
  6.06    0.005561        1854         3         1 wait4
  5.83    0.005356           8       633       147 futex
  4.15    0.003814           0     10020           write
  3.25    0.002987         157        19           clone
  3.23    0.002968           1      5086         2 lstat
  2.86    0.002627          25       105           sendfile
  1.04    0.000954         954         1           connect
  0.97    0.000889         889         1           socket
  0.63    0.000582           0      1596           close
  0.50    0.000460           1       685           mmap
  0.45    0.000414           0      1025           fstat
  0.42    0.000386           0      1520         3 lseek
  0.38    0.000350           1       644           mprotect
  0.28    0.000255          12        22           getdents
  0.11    0.000103           1       186           brk
  0.06    0.000051          26         2           madvise
  0.02    0.000021           4         5           munmap
  0.02    0.000021           0        65           clock_gettime
  0.01    0.000009           5         2           execve
  0.01    0.000006           0        50           rt_sigprocmask
  0.01    0.000005           0        13         1 fcntl
  0.01    0.000005           1         5           prlimit64
  0.00    0.000002           0        25           rt_sigaction
  0.00    0.000002           1         2           arch_prctl
  0.00    0.000001           0        10         3 ioctl
  0.00    0.000001           0         3         3 access
  0.00    0.000001           0         3           dup2
  0.00    0.000000           0         1           rt_sigreturn
  0.00    0.000000           0         1           pipe
  0.00    0.000000           0         2           getpid
  0.00    0.000000           0         2           uname
  0.00    0.000000           0         1           getcwd
  0.00    0.000000           0         2           readlink
  0.00    0.000000           0         1           sysinfo
  0.00    0.000000           0         1           getuid
  0.00    0.000000           0         1           getgid
  0.00    0.000000           0         1           geteuid
  0.00    0.000000           0         1           getegid
  0.00    0.000000           0         1           getppid
  0.00    0.000000           0         1           getpgrp
  0.00    0.000000           0         2           sched_getaffinity
  0.00    0.000000           0         1           set_tid_address
  0.00    0.000000           0         1           faccessat
  0.00    0.000000           0         1           set_robust_list
  0.00    0.000000           0         3           pipe2
------ ----------- ----------- --------- --------- ----------------
100.00    0.091800                 36339      2095 total


So the main difference is that calls to 'open' take a lot longer.
There's little we can do, other than come up with a good caching
mechanism.

Kind regards,
Roel Janssen

Re: Combining Guix, direnv and Emacs for environment customisation

[Ludovic Courtès]

Hi Roel,

Roel Janssen <roel@gnu.org> skribis:

> Ludovic Courtès writes:

[...]

>>> FWIW, on our NFS-mounted /gnu, the 'guix environment' command takes at
>>> least 20 seconds, but for any reasonably big environment it takes more
>>> than one minute.  The biggest bottleneck here is the disk latency.
>>> Could it be that 'guix environment' accesses many files?  If we could
>>> reduce that, it would speed things up (at least for us ;)).
>>
>> Interesting.   Does guix-daemon access /gnu over NFS too?
>
> Yes.

That is going to make builds verrrry slow.  I would suggest having
guix-daemon operate on the local /gnu (that’s what Ricardo did, IIRC).

>> We stat a lot mostly to access all the Guix modules.  Are they on NFS
>> too?
>
> Yes.

OK.

> Here's my output:
>
> [rjanssen2@hpcguix ~]$ strace -c guix environment --ad-hoc coreutils --pure -- true
> % time     seconds  usecs/call     calls    errors syscall
> ------ ----------- ----------- --------- --------- ----------------
>  41.79    0.038363          22      1782       188 open
>  14.71    0.013500           3      4769      1747 stat
>  13.19    0.012106           2      8033           read
>   6.06    0.005561        1854         3         1 wait4
>   5.83    0.005356           8       633       147 futex
>   4.15    0.003814           0     10020           write
>   3.25    0.002987         157        19           clone

[...]

> ------ ----------- ----------- --------- --------- ----------------
> 100.00    0.091800                 36339      2095 total
>
>
> So the main difference is that calls to 'open' take a lot longer.
> There's little we can do, other than come up with a good caching
> mechanism.

We should make sure these 1782 calls are all warranted (e.g., make sure
we don’t open the same file twice; this could be easily diagnosed by
looking at the output of ‘strace’.)

But then, as you say, it’s a process that opens lots of files.

We could cache package lookups, and maybe that’d help a little bit.
Currently we use ‘fold-packages’, which loads every single package
module, and then we look for a package named “coreutils” among them;
with a cache, we could directly load (gnu packages base) and its
dependencies.

Ludo’.

bug#27097: Combining Guix, direnv and Emacs for environment customisation

[Ludovic Courtès]

Hi Roel,

Roel Janssen <roel@gnu.org> skribis:

> Ludovic Courtès writes:

[...]

>>> FWIW, on our NFS-mounted /gnu, the 'guix environment' command takes at
>>> least 20 seconds, but for any reasonably big environment it takes more
>>> than one minute.  The biggest bottleneck here is the disk latency.
>>> Could it be that 'guix environment' accesses many files?  If we could
>>> reduce that, it would speed things up (at least for us ;)).
>>
>> Interesting.   Does guix-daemon access /gnu over NFS too?
>
> Yes.

That is going to make builds verrrry slow.  I would suggest having
guix-daemon operate on the local /gnu (that’s what Ricardo did, IIRC).

>> We stat a lot mostly to access all the Guix modules.  Are they on NFS
>> too?
>
> Yes.

OK.

> Here's my output:
>
> [rjanssen2@hpcguix ~]$ strace -c guix environment --ad-hoc coreutils --pure -- true
> % time     seconds  usecs/call     calls    errors syscall
> ------ ----------- ----------- --------- --------- ----------------
>  41.79    0.038363          22      1782       188 open
>  14.71    0.013500           3      4769      1747 stat
>  13.19    0.012106           2      8033           read
>   6.06    0.005561        1854         3         1 wait4
>   5.83    0.005356           8       633       147 futex
>   4.15    0.003814           0     10020           write
>   3.25    0.002987         157        19           clone

[...]

> ------ ----------- ----------- --------- --------- ----------------
> 100.00    0.091800                 36339      2095 total
>
>
> So the main difference is that calls to 'open' take a lot longer.
> There's little we can do, other than come up with a good caching
> mechanism.

We should make sure these 1782 calls are all warranted (e.g., make sure
we don’t open the same file twice; this could be easily diagnosed by
looking at the output of ‘strace’.)

But then, as you say, it’s a process that opens lots of files.

We could cache package lookups, and maybe that’d help a little bit.
Currently we use ‘fold-packages’, which loads every single package
module, and then we look for a package named “coreutils” among them;
with a cache, we could directly load (gnu packages base) and its
dependencies.

Ludo’.

Re: Combining Guix, direnv and Emacs for environment customisation

[Roel Janssen]

Ludovic Courtès writes:

> Hi Roel,
>
> Roel Janssen <roel@gnu.org> skribis:
>
>> Ludovic Courtès writes:
>
> [...]
>
>>>> FWIW, on our NFS-mounted /gnu, the 'guix environment' command takes at
>>>> least 20 seconds, but for any reasonably big environment it takes more
>>>> than one minute.  The biggest bottleneck here is the disk latency.
>>>> Could it be that 'guix environment' accesses many files?  If we could
>>>> reduce that, it would speed things up (at least for us ;)).
>>>
>>> Interesting.   Does guix-daemon access /gnu over NFS too?
>>
>> Yes.
>
> That is going to make builds verrrry slow.  I would suggest having
> guix-daemon operate on the local /gnu (that’s what Ricardo did, IIRC).

That definitely speeds things up about 50%.  So, running the environment
command from a node that is connected to the node that runs
guix-daemon, will take about 30 seconds instead of one minute.

This could be made faster by letting 'guix-daemon' do more of the work,
and let the client-side 'guix' only do the minimum.

(I know.. this remote-guix-daemon stuff voids the warranty.. ;))

The NFS overhead is pretty large.  Maybe we can better tune it, and if
so, document how to tune it for GNU Guix.  I already talked to our
storage expert, and tuning boils down to using fast disks, a
large-enough NFS cache, and low-latency network equipment.

The reason we have /gnu NFS-mounted on the build node is that we can
then very easily replace the node when it would have a hardware failure,
without even losing the ability to run programs that were already
installed.

>
>>> We stat a lot mostly to access all the Guix modules.  Are they on NFS
>>> too?
>>
>> Yes.
>
> OK.
>
>> Here's my output:
>>
>> [rjanssen2@hpcguix ~]$ strace -c guix environment --ad-hoc coreutils --pure -- true
>> % time     seconds  usecs/call     calls    errors syscall
>> ------ ----------- ----------- --------- --------- ----------------
>>  41.79    0.038363          22      1782       188 open
>>  14.71    0.013500           3      4769      1747 stat
>>  13.19    0.012106           2      8033           read
>>   6.06    0.005561        1854         3         1 wait4
>>   5.83    0.005356           8       633       147 futex
>>   4.15    0.003814           0     10020           write
>>   3.25    0.002987         157        19           clone
>
> [...]
>
>> ------ ----------- ----------- --------- --------- ----------------
>> 100.00    0.091800                 36339      2095 total
>>
>>
>> So the main difference is that calls to 'open' take a lot longer.
>> There's little we can do, other than come up with a good caching
>> mechanism.
>
> We should make sure these 1782 calls are all warranted (e.g., make sure
> we don’t open the same file twice; this could be easily diagnosed by
> looking at the output of ‘strace’.)
>
> But then, as you say, it’s a process that opens lots of files.
>
> We could cache package lookups, and maybe that’d help a little bit.
> Currently we use ‘fold-packages’, which loads every single package
> module, and then we look for a package named “coreutils” among them;
> with a cache, we could directly load (gnu packages base) and its
> dependencies.
>
> Ludo’.

Running 'guix package -A' only takes a couple of seconds.  So I don't
think that loading the Scheme modules is really a big issue.

Kind regards,
Roel Janssen

Performance on NFS

[Ludovic Courtès]

Hi Roel,

Roel Janssen <roel@gnu.org> skribis:

>> That is going to make builds verrrry slow.  I would suggest having
>> guix-daemon operate on the local /gnu (that’s what Ricardo did, IIRC).
>
> That definitely speeds things up about 50%.  So, running the environment
> command from a node that is connected to the node that runs
> guix-daemon, will take about 30 seconds instead of one minute.
>
> This could be made faster by letting 'guix-daemon' do more of the work,
> and let the client-side 'guix' only do the minimum.

Right, but it’s the client that computes the derivation, which involves
quite a bit of I/O and computation.

> (I know.. this remote-guix-daemon stuff voids the warranty.. ;))
>
> The NFS overhead is pretty large.  Maybe we can better tune it, and if
> so, document how to tune it for GNU Guix.  I already talked to our
> storage expert, and tuning boils down to using fast disks, a
> large-enough NFS cache, and low-latency network equipment.
>
> The reason we have /gnu NFS-mounted on the build node is that we can
> then very easily replace the node when it would have a hardware failure,
> without even losing the ability to run programs that were already
> installed.

I guess you could also use a RAID device for /gnu/store.  Or you could
have a local /gnu/store and replicate it elsewhere, maybe
opportunistically via ‘guix publish’.

>> We should make sure these 1782 calls are all warranted (e.g., make sure
>> we don’t open the same file twice; this could be easily diagnosed by
>> looking at the output of ‘strace’.)
>>
>> But then, as you say, it’s a process that opens lots of files.
>>
>> We could cache package lookups, and maybe that’d help a little bit.
>> Currently we use ‘fold-packages’, which loads every single package
>> module, and then we look for a package named “coreutils” among them;
>> with a cache, we could directly load (gnu packages base) and its
>> dependencies.
>>
>> Ludo’.
>
> Running 'guix package -A' only takes a couple of seconds.  So I don't
> think that loading the Scheme modules is really a big issue.

How does:

  time guix environment --ad-hoc coreutils --pure -- true

compare to:

  time guix environment --ad-hoc -e '(@ (gnu packages base) coreutils)' --pure -- true

?  That would give us an estimate of how much the cache I describe would
help.

Thanks,
Ludo’.

Re: Combining Guix, direnv and Emacs for environment customisation

[Ricardo Wurmus]

Roel Janssen <roel@gnu.org> writes:

> The NFS overhead is pretty large.  Maybe we can better tune it, and if
> so, document how to tune it for GNU Guix.  I already talked to our
> storage expert, and tuning boils down to using fast disks, a
> large-enough NFS cache, and low-latency network equipment.

We may get a faster NFS share soon (with some of the slow storage
settings disabled), but I don’t hold my breath when it comes to NFS
performance.

> The reason we have /gnu NFS-mounted on the build node is that we can
> then very easily replace the node when it would have a hardware failure,
> without even losing the ability to run programs that were already
> installed.

That’s the same reason I have for keeping /gnu on NFS.  I have been
experimenting with lsync (writing to local disks and then pushing
changes asynchronously from local-gnu to remote-gnu), but I wasn’t
convinced it would be reliable.

I’m not sure if this would help, though, when the nodes keep mounting
/gnu over NFS.

Is there a way to put /gnu on a Samba share instead?  I’d like to give
that a try, but I’m not sure about what would happen to ownership and
permissions (I don’t worry about hardlinks because I disabled
deduplication).

--
Ricardo

GPG: BCA6 89B6 3655 3801 C3C6  2150 197A 5888 235F ACAC
https://elephly.net

Performance on NFS

[Ludovic Courtès]

Ricardo Wurmus <rekado@elephly.net> skribis:

> Roel Janssen <roel@gnu.org> writes:

[...]

>> The reason we have /gnu NFS-mounted on the build node is that we can
>> then very easily replace the node when it would have a hardware failure,
>> without even losing the ability to run programs that were already
>> installed.
>
> That’s the same reason I have for keeping /gnu on NFS.  I have been
> experimenting with lsync (writing to local disks and then pushing
> changes asynchronously from local-gnu to remote-gnu), but I wasn’t
> convinced it would be reliable.
>
> I’m not sure if this would help, though, when the nodes keep mounting
> /gnu over NFS.

The nodes don’t do as much I/O the store as the daemon, so I think it
makes sense to use a local store for the node that runs guix-daemon.  In
general, Guix aside, building software on NFS is unavoidably slow.

> Is there a way to put /gnu on a Samba share instead?  I’d like to give
> that a try, but I’m not sure about what would happen to ownership and
> permissions (I don’t worry about hardlinks because I disabled
> deduplication).

I’m not sure if SMB is faster than NFS, is it?  9p (which Linux
supports) might work well.

Thanks,
Ludo’.

Re: Performance on NFS

[Ricardo Wurmus]

Ludovic Courtès <ludo@gnu.org> writes:

> I’m not sure if SMB is faster than NFS, is it?  9p (which Linux
> supports) might work well.

Sadly, our “storage appliances” only offer NFS or SMB (and maybe SCP).
I’d gladly try *anything* to get away from our slow NFS.

--
Ricardo

GPG: BCA6 89B6 3655 3801 C3C6  2150 197A 5888 235F ACAC
https://elephly.net

bug#27097: Performance on NFS

[Ricardo Wurmus]

Ludovic Courtès <ludo@gnu.org> writes:

> I’m not sure if SMB is faster than NFS, is it?  9p (which Linux
> supports) might work well.

Sadly, our “storage appliances” only offer NFS or SMB (and maybe SCP).
I’d gladly try *anything* to get away from our slow NFS.

--
Ricardo

GPG: BCA6 89B6 3655 3801 C3C6  2150 197A 5888 235F ACAC
https://elephly.net

Re: Performance on NFS

[Roel Janssen]

Ludovic Courtès writes:

> How does:
>
>   time guix environment --ad-hoc coreutils --pure -- true
>
> compare to:
>
>   time guix environment --ad-hoc -e '(@ (gnu packages base) coreutils)' --pure -- true
>
> ?  That would give us an estimate of how much the cache I describe would
> help.
>
> Thanks,
> Ludo’.

You should know that we have 'submit' nodes that use the guixr wrapper
script to connect to the guix-daemon that runs on the 'hpcguix' node.

Both have a /gnu mounted by a storage subsystem.

I couldn't run the second command on a 'submit' node.  But I could run
it in the 'hpcguix' node.


The first command:
------------------

[roel@hpc-submit1 ~]$ time guixr environment --ad-hoc coreutils --pure -- true

real    0m38.415s
user    0m6.075s
sys     0m0.611s

[roel@hpcguix ~]$ time guix environment --ad-hoc coreutils --pure -- true

real    0m27.054s
user    0m4.254s
sys     0m0.383s


The second command:
-------------------

[roel@hpcguix ~]$ time guix environment --ad-hoc -e '(@ (gnu packages base) coreutils)' --pure --no-substitutes --no-grafts -- true                                                                                                      
The following derivations will be built:
   /gnu/store/9wczighnyz1bz43j4wawf09z180g3ywv-profile.drv
   /gnu/store/ffsyhajbdcp1lcq6x65czghya1iydly8-info-dir.drv
   /gnu/store/5gyl3l23ps6f8dgay4awybwq7n9j9pzk-fonts-dir.drv
   /gnu/store/l2mwj2q4vnq2v5raxz64ra7jyphd2jyd-manual-database.drv
Creating manual page database for 1 packages... done in 5.524 s

real    1m6.812s
user    0m2.969s
sys     0m0.325s
[roel@hpcguix ~]$ time guix environment --ad-hoc -e '(@ (gnu packages base) coreutils)' --pure --no-substitutes --no-grafts -- true

real    0m23.357s
user    0m2.802s
sys     0m0.340s


I suspect that the difference between the two commands is that one only
looks for one module, while the other looks in all modules.  Looking at
the second run, I suppose the difference is quite small.

Kind regards,
Roel Janssen

Re: Performance on NFS

[Ludovic Courtès]

[-- Attachment #1: Type: text/plain, Size: 9697 bytes --]

Hi Roel,

Roel Janssen <roel@gnu.org> skribis:

> You should know that we have 'submit' nodes that use the guixr wrapper
> script to connect to the guix-daemon that runs on the 'hpcguix' node.
>
> Both have a /gnu mounted by a storage subsystem.
>
> I couldn't run the second command on a 'submit' node.  But I could run
> it in the 'hpcguix' node.

OK.

Side note: I think you can replace your ‘guixr’ wrapper by just doing:

  export GUIX_DAEMON_SOCKET=guix://hpcguix:1234

See <https://www.gnu.org/software/guix/manual/html_node/The-Store.html>.

> The first command:
> ------------------
>
> [roel@hpc-submit1 ~]$ time guixr environment --ad-hoc coreutils --pure -- true
>
> real    0m38.415s
> user    0m6.075s
> sys     0m0.611s
>
> [roel@hpcguix ~]$ time guix environment --ad-hoc coreutils --pure -- true
>
> real    0m27.054s
> user    0m4.254s
> sys     0m0.383s
>
>
> The second command:
> -------------------
>
> [roel@hpcguix ~]$ time guix environment --ad-hoc -e '(@ (gnu packages base) coreutils)' --pure --no-substitutes --no-grafts -- true                                                                                                      
> The following derivations will be built:
>    /gnu/store/9wczighnyz1bz43j4wawf09z180g3ywv-profile.drv
>    /gnu/store/ffsyhajbdcp1lcq6x65czghya1iydly8-info-dir.drv
>    /gnu/store/5gyl3l23ps6f8dgay4awybwq7n9j9pzk-fonts-dir.drv
>    /gnu/store/l2mwj2q4vnq2v5raxz64ra7jyphd2jyd-manual-database.drv
> Creating manual page database for 1 packages... done in 5.524 s
>
> real    1m6.812s
> user    0m2.969s
> sys     0m0.325s
> [roel@hpcguix ~]$ time guix environment --ad-hoc -e '(@ (gnu packages base) coreutils)' --pure --no-substitutes --no-grafts -- true
>
> real    0m23.357s
> user    0m2.802s
> sys     0m0.340s
>
>
> I suspect that the difference between the two commands is that one only
> looks for one module, while the other looks in all modules.  Looking at
> the second run, I suppose the difference is quite small.

Yeah, -e doesn’t seem to be much faster (there are still a lot of
modules to load anyway.)

At any rate, let’s see what we can do; 23 seconds is not okay.

I did a quick experiment:

--8<---------------cut here---------------start------------->8---
$ strace -o ,,s -s 123 guix environment --ad-hoc -e '(@ (gnu packages base) coreutils)' --pure --no-substitutes --no-grafts -- true
$ grep ^open ,,s |wc -l
1095
$ grep '^open.*ENOENT' ,,s |wc -l
136
$ grep -E '^(open|stat|lstat).*patches/gcc-arm-bug' ,,s |wc -l
27
$ grep -E '^(open|stat|lstat).*guix/build/utils' ,,s |wc -l
2190
--8<---------------cut here---------------end--------------->8---

After the patch below, I get:

--8<---------------cut here---------------start------------->8---
$ grep -E '^(open|stat|lstat).*guix/build/utils' ,,s2 |wc -l
14
$ grep -E '^(open|stat|lstat).*patches/gcc-arm-bug' ,,s2 |wc -l
4
--8<---------------cut here---------------end--------------->8---

Here’s the big picture before and after:

--8<---------------cut here---------------start------------->8---
$ strace -c guix environment --ad-hoc -e '(@ (gnu packages base) coreutils)' --pure --no-substitutes --no-grafts -- true
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 32.55    0.009781           1     10463      9158 stat
 15.55    0.004673           1      8780           write
 11.26    0.003385        3385         1           wait4
  7.94    0.002387          20       122        12 futex
  6.38    0.001917           0      5052         4 lstat
  5.70    0.001713           2      1095       136 open
  5.54    0.001664           1      2919           read
  3.02    0.000909           2       525           mmap
  2.96    0.000889         148         6           clone
  2.50    0.000751           2       481           mprotect
  2.00    0.000600           1       959           close
  1.56    0.000469           1       898         3 lseek
  1.10    0.000330           3       100           sendfile
  0.88    0.000264           0       541           fstat
  0.42    0.000127           1       175           brk
  0.15    0.000044           2        22           rt_sigaction
  0.09    0.000026           5         5           munmap
  0.06    0.000019           1        18           rt_sigprocmask
  0.06    0.000019           2        10         3 ioctl
  0.03    0.000010           3         3         3 access
  0.03    0.000010           2         6         1 fcntl
  0.03    0.000009           0        23           clock_gettime
  0.03    0.000008           2         5           prlimit64
  0.02    0.000006           6         1           statfs
  0.02    0.000005           2         3           pipe2
  0.01    0.000004           2         2           getpid
  0.01    0.000004           4         1           sysinfo
  0.01    0.000003           3         1           dup2
  0.01    0.000003           2         2           arch_prctl
  0.01    0.000003           3         1           set_tid_address
  0.01    0.000002           1         2           execve
  0.01    0.000002           1         2           uname
  0.01    0.000002           2         1           getuid
  0.01    0.000002           2         1           getgid
  0.01    0.000002           2         1           geteuid
  0.01    0.000002           2         1           getegid
  0.01    0.000002           2         1           getppid
  0.01    0.000002           2         1           getpgrp
  0.01    0.000002           2         1           set_robust_list
  0.00    0.000001           0        16           readlink
  0.00    0.000000           0         3           madvise
  0.00    0.000000           0         1           socket
  0.00    0.000000           0         1           connect
  0.00    0.000000           0         1           getcwd
  0.00    0.000000           0         2           sched_getaffinity
  0.00    0.000000           0         1           getrandom
------ ----------- ----------- --------- --------- ----------------
100.00    0.030051                 32256      9320 total
$ ./pre-inst-env strace -c guix environment --ad-hoc -e '(@ (gnu packages base) coreutils)' --pure --no-substitutes --no-grafts -- true
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 35.19    0.004311           0      9423      8117 stat
 25.25    0.003094           0      8780           write
  9.99    0.001224           0      2895           read
  7.88    0.000965           1      1062       122 open
  6.39    0.000783           7       117        10 futex
  3.80    0.000466           1       502           mmap
  3.34    0.000409           1       474           mprotect
  2.91    0.000357           0       940           close
  2.14    0.000262           0       900         3 lseek
  1.90    0.000233           0       518           fstat
  0.59    0.000072           1       100           sendfile
  0.26    0.000032           0       123           lstat
  0.20    0.000025           0        78           brk
  0.04    0.000005           0        23           clock_gettime
  0.02    0.000003           1         5           munmap
  0.02    0.000003           1         6           clone
  0.02    0.000002           0         5           rt_sigaction
  0.02    0.000002           0        15           rt_sigprocmask
  0.01    0.000001           1         1           wait4
  0.01    0.000001           1         1           arch_prctl
  0.01    0.000001           1         2           sched_getaffinity
  0.01    0.000001           0         3           prlimit64
  0.00    0.000000           0         7         1 ioctl
  0.00    0.000000           0         2         2 access
  0.00    0.000000           0         1           madvise
  0.00    0.000000           0         1           socket
  0.00    0.000000           0         1           connect
  0.00    0.000000           0         1           execve
  0.00    0.000000           0         1           uname
  0.00    0.000000           0         3           fcntl
  0.00    0.000000           0         1           getcwd
  0.00    0.000000           0         1           statfs
  0.00    0.000000           0         1           set_tid_address
  0.00    0.000000           0         1           set_robust_list
  0.00    0.000000           0         3           pipe2
  0.00    0.000000           0         1           getrandom
------ ----------- ----------- --------- --------- ----------------
100.00    0.012252                 25998      8255 total
--8<---------------cut here---------------end--------------->8---

So that’s shaving ~20% of the syscalls (notice the number of ‘lstat’
calls), which may make a difference on NFS.

Could you give it a try and report back?

This patch optimizes the ‘add-to-store’ on the client side.  Until now
the caching strategy in ‘add-to-store’ was very conservative: at each
call it would ‘lstat’ the given file and use the stat as a key in
caching.  Thus, if the file changed, we would notice and reopen it.

The obvious downside is that we’d keep doing ‘lstat’ for a case that’s
unlikely.  With this patch, we simply use the file name as the key in
the ‘add-to-store’ cache.

Though as you wrote before, ‘open’ is much more expensive that ‘stat’ on
NFS, so that’s where we should focus.

Thanks,
Ludo’.


[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #2: Type: text/x-patch, Size: 958 bytes --]

diff --git a/guix/store.scm b/guix/store.scm
index c94dfea95..8acde18d0 100644
--- a/guix/store.scm
+++ b/guix/store.scm
@@ -830,10 +830,9 @@ bits are kept.  HASH-ALGO must be a string such as \"sha256\".
 When RECURSIVE? is true, call (SELECT?  FILE STAT) for each directory entry,
 where FILE is the entry's absolute file name and STAT is the result of
 'lstat'; exclude entries for which SELECT? does not return true."
-      (let* ((st    (false-if-exception (lstat file-name)))
-             (args  `(,st ,basename ,recursive? ,hash-algo ,select?))
+      (let* ((args  `(,file-name ,basename ,recursive? ,hash-algo ,select?))
              (cache (nix-server-add-to-store-cache server)))
-        (or (and st (hash-ref cache args))
+        (or (hash-ref cache args)
             (let ((path (add-to-store server basename recursive?
                                       hash-algo file-name
                                       #:select? select?)))

Re: Performance on NFS

[Roel Janssen]

Ludovic Courtès writes:

> Hi Roel,
>
> Roel Janssen <roel@gnu.org> skribis:
>
>> You should know that we have 'submit' nodes that use the guixr wrapper
>> script to connect to the guix-daemon that runs on the 'hpcguix' node.
>>
>> Both have a /gnu mounted by a storage subsystem.
>>
>> I couldn't run the second command on a 'submit' node.  But I could run
>> it in the 'hpcguix' node.
>
> OK.
>
> Side note: I think you can replace your ‘guixr’ wrapper by just doing:
>
>   export GUIX_DAEMON_SOCKET=guix://hpcguix:1234
>
> See <https://www.gnu.org/software/guix/manual/html_node/The-Store.html>.
>
>> The first command:
>> ------------------
>>
>> [roel@hpc-submit1 ~]$ time guixr environment --ad-hoc coreutils --pure -- true
>>
>> real    0m38.415s
>> user    0m6.075s
>> sys     0m0.611s
>>
>> [roel@hpcguix ~]$ time guix environment --ad-hoc coreutils --pure -- true
>>
>> real    0m27.054s
>> user    0m4.254s
>> sys     0m0.383s
>>
>>
>> The second command:
>> -------------------
>>
>> [roel@hpcguix ~]$ time guix environment --ad-hoc -e '(@ (gnu packages base) coreutils)' --pure --no-substitutes --no-grafts -- true                                                                                                      
>> The following derivations will be built:
>>    /gnu/store/9wczighnyz1bz43j4wawf09z180g3ywv-profile.drv
>>    /gnu/store/ffsyhajbdcp1lcq6x65czghya1iydly8-info-dir.drv
>>    /gnu/store/5gyl3l23ps6f8dgay4awybwq7n9j9pzk-fonts-dir.drv
>>    /gnu/store/l2mwj2q4vnq2v5raxz64ra7jyphd2jyd-manual-database.drv
>> Creating manual page database for 1 packages... done in 5.524 s
>>
>> real    1m6.812s
>> user    0m2.969s
>> sys     0m0.325s
>> [roel@hpcguix ~]$ time guix environment --ad-hoc -e '(@ (gnu packages base) coreutils)' --pure --no-substitutes --no-grafts -- true
>>
>> real    0m23.357s
>> user    0m2.802s
>> sys     0m0.340s
>>
>>
>> I suspect that the difference between the two commands is that one only
>> looks for one module, while the other looks in all modules.  Looking at
>> the second run, I suppose the difference is quite small.
>
> Yeah, -e doesn’t seem to be much faster (there are still a lot of
> modules to load anyway.)
>
> At any rate, let’s see what we can do; 23 seconds is not okay.
>
> I did a quick experiment:
>
> --8<---------------cut here---------------start------------->8---
> $ strace -o ,,s -s 123 guix environment --ad-hoc -e '(@ (gnu packages base) coreutils)' --pure --no-substitutes --no-grafts -- true
> $ grep ^open ,,s |wc -l
> 1095
> $ grep '^open.*ENOENT' ,,s |wc -l
> 136
> $ grep -E '^(open|stat|lstat).*patches/gcc-arm-bug' ,,s |wc -l
> 27
> $ grep -E '^(open|stat|lstat).*guix/build/utils' ,,s |wc -l
> 2190
> --8<---------------cut here---------------end--------------->8---
>
> After the patch below, I get:
>
> --8<---------------cut here---------------start------------->8---
> $ grep -E '^(open|stat|lstat).*guix/build/utils' ,,s2 |wc -l
> 14
> $ grep -E '^(open|stat|lstat).*patches/gcc-arm-bug' ,,s2 |wc -l
> 4
> --8<---------------cut here---------------end--------------->8---
>
> Here’s the big picture before and after:
>
> --8<---------------cut here---------------start------------->8---
> $ strace -c guix environment --ad-hoc -e '(@ (gnu packages base) coreutils)' --pure --no-substitutes --no-grafts -- true
> % time     seconds  usecs/call     calls    errors syscall
> ------ ----------- ----------- --------- --------- ----------------
>  32.55    0.009781           1     10463      9158 stat
>  15.55    0.004673           1      8780           write
>  11.26    0.003385        3385         1           wait4
>   7.94    0.002387          20       122        12 futex
>   6.38    0.001917           0      5052         4 lstat
>   5.70    0.001713           2      1095       136 open
>   5.54    0.001664           1      2919           read
>   3.02    0.000909           2       525           mmap
>   2.96    0.000889         148         6           clone
>   2.50    0.000751           2       481           mprotect
>   2.00    0.000600           1       959           close
>   1.56    0.000469           1       898         3 lseek
>   1.10    0.000330           3       100           sendfile
>   0.88    0.000264           0       541           fstat
>   0.42    0.000127           1       175           brk
>   0.15    0.000044           2        22           rt_sigaction
>   0.09    0.000026           5         5           munmap
>   0.06    0.000019           1        18           rt_sigprocmask
>   0.06    0.000019           2        10         3 ioctl
>   0.03    0.000010           3         3         3 access
>   0.03    0.000010           2         6         1 fcntl
>   0.03    0.000009           0        23           clock_gettime
>   0.03    0.000008           2         5           prlimit64
>   0.02    0.000006           6         1           statfs
>   0.02    0.000005           2         3           pipe2
>   0.01    0.000004           2         2           getpid
>   0.01    0.000004           4         1           sysinfo
>   0.01    0.000003           3         1           dup2
>   0.01    0.000003           2         2           arch_prctl
>   0.01    0.000003           3         1           set_tid_address
>   0.01    0.000002           1         2           execve
>   0.01    0.000002           1         2           uname
>   0.01    0.000002           2         1           getuid
>   0.01    0.000002           2         1           getgid
>   0.01    0.000002           2         1           geteuid
>   0.01    0.000002           2         1           getegid
>   0.01    0.000002           2         1           getppid
>   0.01    0.000002           2         1           getpgrp
>   0.01    0.000002           2         1           set_robust_list
>   0.00    0.000001           0        16           readlink
>   0.00    0.000000           0         3           madvise
>   0.00    0.000000           0         1           socket
>   0.00    0.000000           0         1           connect
>   0.00    0.000000           0         1           getcwd
>   0.00    0.000000           0         2           sched_getaffinity
>   0.00    0.000000           0         1           getrandom
> ------ ----------- ----------- --------- --------- ----------------
> 100.00    0.030051                 32256      9320 total
> $ ./pre-inst-env strace -c guix environment --ad-hoc -e '(@ (gnu packages base) coreutils)' --pure --no-substitutes --no-grafts -- true
> % time     seconds  usecs/call     calls    errors syscall
> ------ ----------- ----------- --------- --------- ----------------
>  35.19    0.004311           0      9423      8117 stat
>  25.25    0.003094           0      8780           write
>   9.99    0.001224           0      2895           read
>   7.88    0.000965           1      1062       122 open
>   6.39    0.000783           7       117        10 futex
>   3.80    0.000466           1       502           mmap
>   3.34    0.000409           1       474           mprotect
>   2.91    0.000357           0       940           close
>   2.14    0.000262           0       900         3 lseek
>   1.90    0.000233           0       518           fstat
>   0.59    0.000072           1       100           sendfile
>   0.26    0.000032           0       123           lstat
>   0.20    0.000025           0        78           brk
>   0.04    0.000005           0        23           clock_gettime
>   0.02    0.000003           1         5           munmap
>   0.02    0.000003           1         6           clone
>   0.02    0.000002           0         5           rt_sigaction
>   0.02    0.000002           0        15           rt_sigprocmask
>   0.01    0.000001           1         1           wait4
>   0.01    0.000001           1         1           arch_prctl
>   0.01    0.000001           1         2           sched_getaffinity
>   0.01    0.000001           0         3           prlimit64
>   0.00    0.000000           0         7         1 ioctl
>   0.00    0.000000           0         2         2 access
>   0.00    0.000000           0         1           madvise
>   0.00    0.000000           0         1           socket
>   0.00    0.000000           0         1           connect
>   0.00    0.000000           0         1           execve
>   0.00    0.000000           0         1           uname
>   0.00    0.000000           0         3           fcntl
>   0.00    0.000000           0         1           getcwd
>   0.00    0.000000           0         1           statfs
>   0.00    0.000000           0         1           set_tid_address
>   0.00    0.000000           0         1           set_robust_list
>   0.00    0.000000           0         3           pipe2
>   0.00    0.000000           0         1           getrandom
> ------ ----------- ----------- --------- --------- ----------------
> 100.00    0.012252                 25998      8255 total
> --8<---------------cut here---------------end--------------->8---
>
> So that’s shaving ~20% of the syscalls (notice the number of ‘lstat’
> calls), which may make a difference on NFS.
>
> Could you give it a try and report back?
>
> This patch optimizes the ‘add-to-store’ on the client side.  Until now
> the caching strategy in ‘add-to-store’ was very conservative: at each
> call it would ‘lstat’ the given file and use the stat as a key in
> caching.  Thus, if the file changed, we would notice and reopen it.
>
> The obvious downside is that we’d keep doing ‘lstat’ for a case that’s
> unlikely.  With this patch, we simply use the file name as the key in
> the ‘add-to-store’ cache.
>
> Though as you wrote before, ‘open’ is much more expensive that ‘stat’ on
> NFS, so that’s where we should focus.
>
> Thanks,
> Ludo’.
>
> diff --git a/guix/store.scm b/guix/store.scm
> index c94dfea95..8acde18d0 100644
> --- a/guix/store.scm
> +++ b/guix/store.scm
> @@ -830,10 +830,9 @@ bits are kept.  HASH-ALGO must be a string such as \"sha256\".
>  When RECURSIVE? is true, call (SELECT?  FILE STAT) for each directory entry,
>  where FILE is the entry's absolute file name and STAT is the result of
>  'lstat'; exclude entries for which SELECT? does not return true."
> -      (let* ((st    (false-if-exception (lstat file-name)))
> -             (args  `(,st ,basename ,recursive? ,hash-algo ,select?))
> +      (let* ((args  `(,file-name ,basename ,recursive? ,hash-algo ,select?))
>               (cache (nix-server-add-to-store-cache server)))
> -        (or (and st (hash-ref cache args))
> +        (or (hash-ref cache args)
>              (let ((path (add-to-store server basename recursive?
>                                        hash-algo file-name
>                                        #:select? select?)))

Here are the timings.  The patched version is used with ./pre-inst-env,
and the unpatched version is not invoked using ./pre-inst-env.

With patch:
-----------------------------------------------------------------------------------------------------

[roel@hpc-submit1 guix]$ time ./pre-inst-env guix environment --pure coreutils --no-substitutes --no-grafts -- true
The following derivations will be built:
   /gnu/store/zfyjc6zmhjj19vx4h6z22kjbz75izm2d-profile.drv
   /gnu/store/p9nxlcyhvkiyfxllbb81m8jjnv1hfkhq-ca-certificate-bundle.drv
   /gnu/store/any2b7k23b16xq4pbym21dx0sg6ybmyi-info-dir.drv
   /gnu/store/55mmjkg47n58gql1yys053gl3vqfxlml-fonts-dir.drv
   /gnu/store/s5vinzd4rc9yffigamb5k76r4ipqim6z-manual-database.drv
Creating manual page database for 19 packages... done in 26.220 s
warning: collision encountered: /gnu/store/ri56wnmzkgzrajdyl5ydc55lrwy1164k-ld-wrapper-0/bin/ld /gnu/store/zq65kpvwwxgc3qqbf9apic8gyss2l0zq-binutils-2.27/bin/ld 
warning: arbitrarily choosing /gnu/store/ri56wnmzkgzrajdyl5ydc55lrwy1164k-ld-wrapper-0/bin/ld

real    6m14.571s
user    0m3.702s
sys     0m0.361s
[roel@hpc-submit1 guix]$ time ./pre-inst-env guix environment --pure coreutils --no-substitutes --no-grafts -- true

real    0m43.446s
user    0m3.393s
sys     0m0.452s
[roel@hpc-submit1 guix]$ time ./pre-inst-env guix environment --pure coreutils --no-substitutes --no-grafts -- true

real    0m22.405s
user    0m3.532s
sys     0m0.336s
[roel@hpc-submit1 guix]$ time ./pre-inst-env guix environment --pure coreutils --no-substitutes --no-grafts -- true

real    0m22.361s
user    0m3.356s
sys     0m0.326s
[roel@hpc-submit1 guix]$ time ./pre-inst-env guix environment --pure coreutils --no-substitutes --no-grafts -- true

real    0m17.993s
user    0m3.422s
sys     0m0.394s

Without patch:
-----------------------------------------------------------------------------------------------------

[roel@hpc-submit1 guix]$ time  guix environment --pure coreutils --no-substitutes --no-grafts -- true

real    0m41.746s
user    0m3.471s
sys     0m0.552s
[roel@hpc-submit1 guix]$ time  guix environment --pure coreutils --no-substitutes --no-grafts -- true

real    0m26.406s
user    0m3.451s
sys     0m0.523s
[roel@hpc-submit1 guix]$ time  guix environment --pure coreutils --no-substitutes --no-grafts -- true

real    0m37.703s
user    0m3.445s
sys     0m0.579s
[roel@hpc-submit1 guix]$ time  guix environment --pure coreutils --no-substitutes --no-grafts -- true

real    0m27.084s
user    0m3.538s
sys     0m0.428s

On hpcguix with patch:
-----------------------------------------------------------------------------------------------------

[roel@hpcguix guix]$ time ./pre-inst-env guix environment --pure coreutils --no-substitutes --no-grafts -- true

real    0m42.971s
user    0m3.335s
sys     0m0.386s
[roel@hpcguix guix]$ time ./pre-inst-env guix environment --pure coreutils --no-substitutes --no-grafts -- true

real    0m19.428s
user    0m3.239s
sys     0m0.367s
[roel@hpcguix guix]$ time ./pre-inst-env guix environment --pure coreutils --no-substitutes --no-grafts -- true

real    0m27.086s
user    0m3.073s
sys     0m0.348s
[roel@hpcguix guix]$ time ./pre-inst-env guix environment --pure coreutils --no-substitutes --no-grafts -- true

real    0m33.214s
user    0m3.068s
sys     0m0.296s
[roel@hpcguix guix]$ time ./pre-inst-env guix environment --pure coreutils --no-substitutes --no-grafts -- true

real    0m22.686s
user    0m3.010s
sys     0m0.305s

On hpcguix without patch:
-----------------------------------------------------------------------------------------------------

[roel@hpcguix guix]$ time guix environment --pure coreutils --no-substitutes --no-grafts -- true

real    0m28.502s
user    0m3.201s
sys     0m0.447s
[roel@hpcguix guix]$ time guix environment --pure coreutils --no-substitutes --no-grafts -- true

real    0m41.693s
user    0m3.061s
sys     0m0.301s
[roel@hpcguix guix]$ time guix environment --pure coreutils --no-substitutes --no-grafts -- true

real    0m26.178s
user    0m3.034s
sys     0m0.358s



From these timings, I don't think it has a big impact.  This makes me
wonder, can't we replace the disk-intensive stuff with a database?
If we only have to read the files on disk once, after which we extracted
the information (the hashes?) needed to compute which links have to be
created to make an environment, then actually creating the environment
can be as fast as only creating those links.

Maybe this is too vague, because I don't know what Guix needs to read
exactly here.

Kind regards,
Roel Janssen

[bug#27097] Performance on NFS

[Roel Janssen]

Ludovic Courtès writes:

> Hi Roel,
>
> Roel Janssen <roel@gnu.org> skribis:
>
>> You should know that we have 'submit' nodes that use the guixr wrapper
>> script to connect to the guix-daemon that runs on the 'hpcguix' node.
>>
>> Both have a /gnu mounted by a storage subsystem.
>>
>> I couldn't run the second command on a 'submit' node.  But I could run
>> it in the 'hpcguix' node.
>
> OK.
>
> Side note: I think you can replace your ‘guixr’ wrapper by just doing:
>
>   export GUIX_DAEMON_SOCKET=guix://hpcguix:1234
>
> See <https://www.gnu.org/software/guix/manual/html_node/The-Store.html>.
>
>> The first command:
>> ------------------
>>
>> [roel@hpc-submit1 ~]$ time guixr environment --ad-hoc coreutils --pure -- true
>>
>> real    0m38.415s
>> user    0m6.075s
>> sys     0m0.611s
>>
>> [roel@hpcguix ~]$ time guix environment --ad-hoc coreutils --pure -- true
>>
>> real    0m27.054s
>> user    0m4.254s
>> sys     0m0.383s
>>
>>
>> The second command:
>> -------------------
>>
>> [roel@hpcguix ~]$ time guix environment --ad-hoc -e '(@ (gnu packages base) coreutils)' --pure --no-substitutes --no-grafts -- true                                                                                                      
>> The following derivations will be built:
>>    /gnu/store/9wczighnyz1bz43j4wawf09z180g3ywv-profile.drv
>>    /gnu/store/ffsyhajbdcp1lcq6x65czghya1iydly8-info-dir.drv
>>    /gnu/store/5gyl3l23ps6f8dgay4awybwq7n9j9pzk-fonts-dir.drv
>>    /gnu/store/l2mwj2q4vnq2v5raxz64ra7jyphd2jyd-manual-database.drv
>> Creating manual page database for 1 packages... done in 5.524 s
>>
>> real    1m6.812s
>> user    0m2.969s
>> sys     0m0.325s
>> [roel@hpcguix ~]$ time guix environment --ad-hoc -e '(@ (gnu packages base) coreutils)' --pure --no-substitutes --no-grafts -- true
>>
>> real    0m23.357s
>> user    0m2.802s
>> sys     0m0.340s
>>
>>
>> I suspect that the difference between the two commands is that one only
>> looks for one module, while the other looks in all modules.  Looking at
>> the second run, I suppose the difference is quite small.
>
> Yeah, -e doesn’t seem to be much faster (there are still a lot of
> modules to load anyway.)
>
> At any rate, let’s see what we can do; 23 seconds is not okay.
>
> I did a quick experiment:
>
> --8<---------------cut here---------------start------------->8---
> $ strace -o ,,s -s 123 guix environment --ad-hoc -e '(@ (gnu packages base) coreutils)' --pure --no-substitutes --no-grafts -- true
> $ grep ^open ,,s |wc -l
> 1095
> $ grep '^open.*ENOENT' ,,s |wc -l
> 136
> $ grep -E '^(open|stat|lstat).*patches/gcc-arm-bug' ,,s |wc -l
> 27
> $ grep -E '^(open|stat|lstat).*guix/build/utils' ,,s |wc -l
> 2190
> --8<---------------cut here---------------end--------------->8---
>
> After the patch below, I get:
>
> --8<---------------cut here---------------start------------->8---
> $ grep -E '^(open|stat|lstat).*guix/build/utils' ,,s2 |wc -l
> 14
> $ grep -E '^(open|stat|lstat).*patches/gcc-arm-bug' ,,s2 |wc -l
> 4
> --8<---------------cut here---------------end--------------->8---
>
> Here’s the big picture before and after:
>
> --8<---------------cut here---------------start------------->8---
> $ strace -c guix environment --ad-hoc -e '(@ (gnu packages base) coreutils)' --pure --no-substitutes --no-grafts -- true
> % time     seconds  usecs/call     calls    errors syscall
> ------ ----------- ----------- --------- --------- ----------------
>  32.55    0.009781           1     10463      9158 stat
>  15.55    0.004673           1      8780           write
>  11.26    0.003385        3385         1           wait4
>   7.94    0.002387          20       122        12 futex
>   6.38    0.001917           0      5052         4 lstat
>   5.70    0.001713           2      1095       136 open
>   5.54    0.001664           1      2919           read
>   3.02    0.000909           2       525           mmap
>   2.96    0.000889         148         6           clone
>   2.50    0.000751           2       481           mprotect
>   2.00    0.000600           1       959           close
>   1.56    0.000469           1       898         3 lseek
>   1.10    0.000330           3       100           sendfile
>   0.88    0.000264           0       541           fstat
>   0.42    0.000127           1       175           brk
>   0.15    0.000044           2        22           rt_sigaction
>   0.09    0.000026           5         5           munmap
>   0.06    0.000019           1        18           rt_sigprocmask
>   0.06    0.000019           2        10         3 ioctl
>   0.03    0.000010           3         3         3 access
>   0.03    0.000010           2         6         1 fcntl
>   0.03    0.000009           0        23           clock_gettime
>   0.03    0.000008           2         5           prlimit64
>   0.02    0.000006           6         1           statfs
>   0.02    0.000005           2         3           pipe2
>   0.01    0.000004           2         2           getpid
>   0.01    0.000004           4         1           sysinfo
>   0.01    0.000003           3         1           dup2
>   0.01    0.000003           2         2           arch_prctl
>   0.01    0.000003           3         1           set_tid_address
>   0.01    0.000002           1         2           execve
>   0.01    0.000002           1         2           uname
>   0.01    0.000002           2         1           getuid
>   0.01    0.000002           2         1           getgid
>   0.01    0.000002           2         1           geteuid
>   0.01    0.000002           2         1           getegid
>   0.01    0.000002           2         1           getppid
>   0.01    0.000002           2         1           getpgrp
>   0.01    0.000002           2         1           set_robust_list
>   0.00    0.000001           0        16           readlink
>   0.00    0.000000           0         3           madvise
>   0.00    0.000000           0         1           socket
>   0.00    0.000000           0         1           connect
>   0.00    0.000000           0         1           getcwd
>   0.00    0.000000           0         2           sched_getaffinity
>   0.00    0.000000           0         1           getrandom
> ------ ----------- ----------- --------- --------- ----------------
> 100.00    0.030051                 32256      9320 total
> $ ./pre-inst-env strace -c guix environment --ad-hoc -e '(@ (gnu packages base) coreutils)' --pure --no-substitutes --no-grafts -- true
> % time     seconds  usecs/call     calls    errors syscall
> ------ ----------- ----------- --------- --------- ----------------
>  35.19    0.004311           0      9423      8117 stat
>  25.25    0.003094           0      8780           write
>   9.99    0.001224           0      2895           read
>   7.88    0.000965           1      1062       122 open
>   6.39    0.000783           7       117        10 futex
>   3.80    0.000466           1       502           mmap
>   3.34    0.000409           1       474           mprotect
>   2.91    0.000357           0       940           close
>   2.14    0.000262           0       900         3 lseek
>   1.90    0.000233           0       518           fstat
>   0.59    0.000072           1       100           sendfile
>   0.26    0.000032           0       123           lstat
>   0.20    0.000025           0        78           brk
>   0.04    0.000005           0        23           clock_gettime
>   0.02    0.000003           1         5           munmap
>   0.02    0.000003           1         6           clone
>   0.02    0.000002           0         5           rt_sigaction
>   0.02    0.000002           0        15           rt_sigprocmask
>   0.01    0.000001           1         1           wait4
>   0.01    0.000001           1         1           arch_prctl
>   0.01    0.000001           1         2           sched_getaffinity
>   0.01    0.000001           0         3           prlimit64
>   0.00    0.000000           0         7         1 ioctl
>   0.00    0.000000           0         2         2 access
>   0.00    0.000000           0         1           madvise
>   0.00    0.000000           0         1           socket
>   0.00    0.000000           0         1           connect
>   0.00    0.000000           0         1           execve
>   0.00    0.000000           0         1           uname
>   0.00    0.000000           0         3           fcntl
>   0.00    0.000000           0         1           getcwd
>   0.00    0.000000           0         1           statfs
>   0.00    0.000000           0         1           set_tid_address
>   0.00    0.000000           0         1           set_robust_list
>   0.00    0.000000           0         3           pipe2
>   0.00    0.000000           0         1           getrandom
> ------ ----------- ----------- --------- --------- ----------------
> 100.00    0.012252                 25998      8255 total
> --8<---------------cut here---------------end--------------->8---
>
> So that’s shaving ~20% of the syscalls (notice the number of ‘lstat’
> calls), which may make a difference on NFS.
>
> Could you give it a try and report back?
>
> This patch optimizes the ‘add-to-store’ on the client side.  Until now
> the caching strategy in ‘add-to-store’ was very conservative: at each
> call it would ‘lstat’ the given file and use the stat as a key in
> caching.  Thus, if the file changed, we would notice and reopen it.
>
> The obvious downside is that we’d keep doing ‘lstat’ for a case that’s
> unlikely.  With this patch, we simply use the file name as the key in
> the ‘add-to-store’ cache.
>
> Though as you wrote before, ‘open’ is much more expensive that ‘stat’ on
> NFS, so that’s where we should focus.
>
> Thanks,
> Ludo’.
>
> diff --git a/guix/store.scm b/guix/store.scm
> index c94dfea95..8acde18d0 100644
> --- a/guix/store.scm
> +++ b/guix/store.scm
> @@ -830,10 +830,9 @@ bits are kept.  HASH-ALGO must be a string such as \"sha256\".
>  When RECURSIVE? is true, call (SELECT?  FILE STAT) for each directory entry,
>  where FILE is the entry's absolute file name and STAT is the result of
>  'lstat'; exclude entries for which SELECT? does not return true."
> -      (let* ((st    (false-if-exception (lstat file-name)))
> -             (args  `(,st ,basename ,recursive? ,hash-algo ,select?))
> +      (let* ((args  `(,file-name ,basename ,recursive? ,hash-algo ,select?))
>               (cache (nix-server-add-to-store-cache server)))
> -        (or (and st (hash-ref cache args))
> +        (or (hash-ref cache args)
>              (let ((path (add-to-store server basename recursive?
>                                        hash-algo file-name
>                                        #:select? select?)))

Here are the timings.  The patched version is used with ./pre-inst-env,
and the unpatched version is not invoked using ./pre-inst-env.

With patch:
-----------------------------------------------------------------------------------------------------

[roel@hpc-submit1 guix]$ time ./pre-inst-env guix environment --pure coreutils --no-substitutes --no-grafts -- true
The following derivations will be built:
   /gnu/store/zfyjc6zmhjj19vx4h6z22kjbz75izm2d-profile.drv
   /gnu/store/p9nxlcyhvkiyfxllbb81m8jjnv1hfkhq-ca-certificate-bundle.drv
   /gnu/store/any2b7k23b16xq4pbym21dx0sg6ybmyi-info-dir.drv
   /gnu/store/55mmjkg47n58gql1yys053gl3vqfxlml-fonts-dir.drv
   /gnu/store/s5vinzd4rc9yffigamb5k76r4ipqim6z-manual-database.drv
Creating manual page database for 19 packages... done in 26.220 s
warning: collision encountered: /gnu/store/ri56wnmzkgzrajdyl5ydc55lrwy1164k-ld-wrapper-0/bin/ld /gnu/store/zq65kpvwwxgc3qqbf9apic8gyss2l0zq-binutils-2.27/bin/ld 
warning: arbitrarily choosing /gnu/store/ri56wnmzkgzrajdyl5ydc55lrwy1164k-ld-wrapper-0/bin/ld

real    6m14.571s
user    0m3.702s
sys     0m0.361s
[roel@hpc-submit1 guix]$ time ./pre-inst-env guix environment --pure coreutils --no-substitutes --no-grafts -- true

real    0m43.446s
user    0m3.393s
sys     0m0.452s
[roel@hpc-submit1 guix]$ time ./pre-inst-env guix environment --pure coreutils --no-substitutes --no-grafts -- true

real    0m22.405s
user    0m3.532s
sys     0m0.336s
[roel@hpc-submit1 guix]$ time ./pre-inst-env guix environment --pure coreutils --no-substitutes --no-grafts -- true

real    0m22.361s
user    0m3.356s
sys     0m0.326s
[roel@hpc-submit1 guix]$ time ./pre-inst-env guix environment --pure coreutils --no-substitutes --no-grafts -- true

real    0m17.993s
user    0m3.422s
sys     0m0.394s

Without patch:
-----------------------------------------------------------------------------------------------------

[roel@hpc-submit1 guix]$ time  guix environment --pure coreutils --no-substitutes --no-grafts -- true

real    0m41.746s
user    0m3.471s
sys     0m0.552s
[roel@hpc-submit1 guix]$ time  guix environment --pure coreutils --no-substitutes --no-grafts -- true

real    0m26.406s
user    0m3.451s
sys     0m0.523s
[roel@hpc-submit1 guix]$ time  guix environment --pure coreutils --no-substitutes --no-grafts -- true

real    0m37.703s
user    0m3.445s
sys     0m0.579s
[roel@hpc-submit1 guix]$ time  guix environment --pure coreutils --no-substitutes --no-grafts -- true

real    0m27.084s
user    0m3.538s
sys     0m0.428s

On hpcguix with patch:
-----------------------------------------------------------------------------------------------------

[roel@hpcguix guix]$ time ./pre-inst-env guix environment --pure coreutils --no-substitutes --no-grafts -- true

real    0m42.971s
user    0m3.335s
sys     0m0.386s
[roel@hpcguix guix]$ time ./pre-inst-env guix environment --pure coreutils --no-substitutes --no-grafts -- true

real    0m19.428s
user    0m3.239s
sys     0m0.367s
[roel@hpcguix guix]$ time ./pre-inst-env guix environment --pure coreutils --no-substitutes --no-grafts -- true

real    0m27.086s
user    0m3.073s
sys     0m0.348s
[roel@hpcguix guix]$ time ./pre-inst-env guix environment --pure coreutils --no-substitutes --no-grafts -- true

real    0m33.214s
user    0m3.068s
sys     0m0.296s
[roel@hpcguix guix]$ time ./pre-inst-env guix environment --pure coreutils --no-substitutes --no-grafts -- true

real    0m22.686s
user    0m3.010s
sys     0m0.305s

On hpcguix without patch:
-----------------------------------------------------------------------------------------------------

[roel@hpcguix guix]$ time guix environment --pure coreutils --no-substitutes --no-grafts -- true

real    0m28.502s
user    0m3.201s
sys     0m0.447s
[roel@hpcguix guix]$ time guix environment --pure coreutils --no-substitutes --no-grafts -- true

real    0m41.693s
user    0m3.061s
sys     0m0.301s
[roel@hpcguix guix]$ time guix environment --pure coreutils --no-substitutes --no-grafts -- true

real    0m26.178s
user    0m3.034s
sys     0m0.358s



From these timings, I don't think it has a big impact.  This makes me
wonder, can't we replace the disk-intensive stuff with a database?
If we only have to read the files on disk once, after which we extracted
the information (the hashes?) needed to compute which links have to be
created to make an environment, then actually creating the environment
can be as fast as only creating those links.

Maybe this is too vague, because I don't know what Guix needs to read
exactly here.

Kind regards,
Roel Janssen

Re: Performance on NFS

[Ludovic Courtès]

Hi!

Roel Janssen <roel@gnu.org> skribis:

> From these timings, I don't think it has a big impact.

Wait, wait.  If we take the best timings of each series of runs, we get:

  hpc-submit1: 26.4s -> 18.0s (-30%)
  hpc-guix:    26.2s -> 22.7s (-13%)

This is arguably insufficient but still non-negligible.  I’ve committed
it as b46712159c15f72fc28b71d17d5a7c74fcb64ed0.

With commit 015f17e8b9eff97f656852180ac51c75438d7f9d, the number of
open(2) calls for that same command drops from 991 to 795 (including 122
errors).  I suspect we can’t reduce it further:

--8<---------------cut here---------------start------------->8---
$ ./pre-inst-env strace -o ,,s guix build coreutils -n
$ grep '^open.*' < ,,s |wc -l
795
$ grep '^open.*\.go"' < ,,s |wc -l
563
$ grep '^open.*\.patch"' < ,,s |wc -l
29
$ grep '^open.*\.scm"' < ,,s |wc -l
6
--8<---------------cut here---------------end--------------->8---

Could you check how this affects performance on your NFS system?

There’s possibly another low-hanging fruit, which is to disable file
name canonicalization (via ‘%file-port-name-canonicalization’.)  It
special care though, so I’ll try that later.

> This makes me wonder, can't we replace the disk-intensive stuff with a
> database?  If we only have to read the files on disk once, after which
> we extracted the information (the hashes?) needed to compute which
> links have to be created to make an environment, then actually
> creating the environment can be as fast as only creating those links.

Essentially we need to compute derivations as a function of local files
(sent to the daemon with ‘add-to-store’) and other derivations.  We
cannot avoid that.

In the case of a remote server, communications with the daemon play an
important role too.  Have you tried setting ‘GUIX_DAEMON_SOCKET’ as
suggested before instead of using the “socat hack”?  I think this should
be faster (see commit 950d51c9d9a5107c5dac279da7d2e431134b5f43.)

HTH,
Ludo’.

Performance on NFS

[Ludovic Courtès]

Hello!

I just pushed another improvement:
d27cc3bfaafe6b5b0831e88afb1c46311d382a0b significantly reduces the
number of ‘stat’ calls when discovering .scm files.  I’d be curious to
see what impact it has on NFS.

Commit cbee955901b3e252ebdeb8066a2196055149198a also reduces the number
of ‘stat’ calls.

After that I have:

--8<---------------cut here---------------start------------->8---
$ ./pre-inst-env strace -c  guix environment --ad-hoc coreutils -- true 
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 27.03    0.006916           1     13585           read
 24.64    0.006306           1      9701      8029 stat
 21.25    0.005438           1     10698           write
 11.05    0.002828        2828         1           wait4
  3.60    0.000922           1      1598       122 open
  2.88    0.000738           4       203        28 futex
  1.79    0.000458           1       670           mmap
  1.75    0.000448           1       642           mprotect
  1.64    0.000419           0      1476           close
  1.36    0.000347           0      1411         3 lseek
  0.74    0.000190           2       107           sendfile
  0.70    0.000180           4        51           getdents
  0.62    0.000159           0       886           fstat
  0.54    0.000137           1       196           lstat
  0.22    0.000057           1        99           brk
  0.09    0.000024           4         6           clone
  0.02    0.000005           1         5           munmap
  0.02    0.000005           0        19           rt_sigprocmask
  0.02    0.000004           0        27           clock_gettime
  0.01    0.000003           3         1           getrandom
  0.01    0.000002           2         1           connect
  0.01    0.000002           1         3           prlimit64
  0.00    0.000001           1         2         2 access
  0.00    0.000001           1         1           socket
  0.00    0.000000           0         5           rt_sigaction
  0.00    0.000000           0         7         1 ioctl
  0.00    0.000000           0         1           madvise
  0.00    0.000000           0         1           execve
  0.00    0.000000           0         1           uname
  0.00    0.000000           0         3           fcntl
  0.00    0.000000           0         1           getcwd
  0.00    0.000000           0         1           statfs
  0.00    0.000000           0         1           arch_prctl
  0.00    0.000000           0         2           sched_getaffinity
  0.00    0.000000           0         1           set_tid_address
  0.00    0.000000           0         1           set_robust_list
  0.00    0.000000           0         3           pipe2
------ ----------- ----------- --------- --------- ----------------
100.00    0.025590                 41417      8185 total
$ git describe
v0.13.0-804-gf4453df9a
--8<---------------cut here---------------end--------------->8---

The number of ‘stat’ calls is a function of the number of entries in
‘GUILE_LOAD_PATH’ and ‘GUILE_LOAD_COMPILED_PATH’.  I can’t think of any
easy way to reduce it further.

The many ‘read’ and ‘write’ are due to the unbuffered port used for
RPCs, and definitely not great when talking to a remote store.  I’ve
tried to add some buffering but that turned out to be trickier than I
had hoped for.

To be continued!

Ludo’.

Re: Performance on NFS

[Roel Janssen]

Hello!

Ludovic Courtès writes:

> Hello!
>
> I just pushed another improvement:
> d27cc3bfaafe6b5b0831e88afb1c46311d382a0b significantly reduces the
> number of ‘stat’ calls when discovering .scm files.  I’d be curious to
> see what impact it has on NFS.
>
> Commit cbee955901b3e252ebdeb8066a2196055149198a also reduces the number
> of ‘stat’ calls.
>
> After that I have:
>
> --8<---------------cut here---------------start------------->8---
> $ ./pre-inst-env strace -c  guix environment --ad-hoc coreutils -- true 
> % time     seconds  usecs/call     calls    errors syscall
> ------ ----------- ----------- --------- --------- ----------------
>  27.03    0.006916           1     13585           read
>  24.64    0.006306           1      9701      8029 stat
>  21.25    0.005438           1     10698           write
>  11.05    0.002828        2828         1           wait4
>   3.60    0.000922           1      1598       122 open
>   2.88    0.000738           4       203        28 futex
>   1.79    0.000458           1       670           mmap
>   1.75    0.000448           1       642           mprotect
>   1.64    0.000419           0      1476           close
>   1.36    0.000347           0      1411         3 lseek
>   0.74    0.000190           2       107           sendfile
>   0.70    0.000180           4        51           getdents
>   0.62    0.000159           0       886           fstat
>   0.54    0.000137           1       196           lstat
>   0.22    0.000057           1        99           brk
>   0.09    0.000024           4         6           clone
>   0.02    0.000005           1         5           munmap
>   0.02    0.000005           0        19           rt_sigprocmask
>   0.02    0.000004           0        27           clock_gettime
>   0.01    0.000003           3         1           getrandom
>   0.01    0.000002           2         1           connect
>   0.01    0.000002           1         3           prlimit64
>   0.00    0.000001           1         2         2 access
>   0.00    0.000001           1         1           socket
>   0.00    0.000000           0         5           rt_sigaction
>   0.00    0.000000           0         7         1 ioctl
>   0.00    0.000000           0         1           madvise
>   0.00    0.000000           0         1           execve
>   0.00    0.000000           0         1           uname
>   0.00    0.000000           0         3           fcntl
>   0.00    0.000000           0         1           getcwd
>   0.00    0.000000           0         1           statfs
>   0.00    0.000000           0         1           arch_prctl
>   0.00    0.000000           0         2           sched_getaffinity
>   0.00    0.000000           0         1           set_tid_address
>   0.00    0.000000           0         1           set_robust_list
>   0.00    0.000000           0         3           pipe2
> ------ ----------- ----------- --------- --------- ----------------
> 100.00    0.025590                 41417      8185 total
> $ git describe
> v0.13.0-804-gf4453df9a
> --8<---------------cut here---------------end--------------->8---
>
> The number of ‘stat’ calls is a function of the number of entries in
> ‘GUILE_LOAD_PATH’ and ‘GUILE_LOAD_COMPILED_PATH’.  I can’t think of any
> easy way to reduce it further.
>
> The many ‘read’ and ‘write’ are due to the unbuffered port used for
> RPCs, and definitely not great when talking to a remote store.  I’ve
> tried to add some buffering but that turned out to be trickier than I
> had hoped for.
>
> To be continued!
>
> Ludo’.

I applied the patch, and here are the results:

[roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure -- true
The following derivations will be built:
   /gnu/store/0hz8g844432b5h9zbqr9cpsjy0brg15h-profile.drv
   /gnu/store/wkksb7bbx3jr0p6p5cj4kkphbwday0yd-info-dir.drv
   /gnu/store/cd2mwx9qprdy23p7j3pik2zs14nifn36-manual-database.drv
Creating manual page database for 1 packages... done in 1.816 s

real	1m14.686s
user	0m5.761s
sys	0m0.498s
[roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure -- true

real	0m34.100s
user	0m5.599s
sys	0m0.414s
[roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure -- true

real	0m33.821s
user	0m5.140s
sys	0m0.432s
[roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure --no-substitutes --no-grafts -- true
The following derivations will be built:
   /gnu/store/rvh0imjdimwm90nzr0fmr5gmp97lyiix-profile.drv
   /gnu/store/5hm3v4afjf9gix92ixqzv9bwc11a608s-fonts-dir.drv

real	0m37.200s
user	0m3.408s
sys	0m0.284s
[roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure --no-substitutes --no-grafts -- true

real	0m19.415s
user	0m3.466s
sys	0m0.306s
[roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure --no-substitutes --no-grafts -- true

real	0m18.850s
user	0m3.536s
sys	0m0.346s
[roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure --no-grafts -- true

real	0m16.003s
user	0m3.246s
sys	0m0.301s
[roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure --no-grafts -- true

real	0m18.205s
user	0m3.470s
sys	0m0.314s
[roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure --no-substitutes -- true

real	0m33.731s
user	0m5.111s
sys	0m0.428s
[roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure --no-substitutes -- true

real	0m30.993s
user	0m5.049s
sys	0m0.458s

Why is grafting so slow, even if it doesn't have to graft anything?

So, because grafting is disk-intensive rather than CPU-intensive, it might
be a good idea to be able to globally disable grafting.  (it would
reduce the after-we-build-it-time considerably for our cluster.)

Kind regards,
Roel Janssen

Re: Performance on NFS

[Ludovic Courtès]

Hi!

Roel Janssen <roel@gnu.org> skribis:

> I applied the patch, and here are the results:
>
> [roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure -- true
> The following derivations will be built:
>    /gnu/store/0hz8g844432b5h9zbqr9cpsjy0brg15h-profile.drv
>    /gnu/store/wkksb7bbx3jr0p6p5cj4kkphbwday0yd-info-dir.drv
>    /gnu/store/cd2mwx9qprdy23p7j3pik2zs14nifn36-manual-database.drv
> Creating manual page database for 1 packages... done in 1.816 s
>
> real	1m14.686s
> user	0m5.761s
> sys	0m0.498s
> [roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure -- true
>
> real	0m34.100s
> user	0m5.599s
> sys	0m0.414s
> [roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure -- true
>
> real	0m33.821s
> user	0m5.140s
> sys	0m0.432s

You’re telling me it’s just as bad as before, right?

> [roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure --no-substitutes --no-grafts -- true
> The following derivations will be built:
>    /gnu/store/rvh0imjdimwm90nzr0fmr5gmp97lyiix-profile.drv
>    /gnu/store/5hm3v4afjf9gix92ixqzv9bwc11a608s-fonts-dir.drv
>
> real	0m37.200s
> user	0m3.408s
> sys	0m0.284s
> [roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure --no-substitutes --no-grafts -- true
>
> real	0m19.415s
> user	0m3.466s
> sys	0m0.306s
> [roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure --no-substitutes --no-grafts -- true
>
> real	0m18.850s
> user	0m3.536s
> sys	0m0.346s
> [roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure --no-grafts -- true
>
> real	0m16.003s
> user	0m3.246s
> sys	0m0.301s
> [roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure --no-grafts -- true
>
> real	0m18.205s
> user	0m3.470s
> sys	0m0.314s
> [roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure --no-substitutes -- true
>
> real	0m33.731s
> user	0m5.111s
> sys	0m0.428s
> [roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure --no-substitutes -- true
>
> real	0m30.993s
> user	0m5.049s
> sys	0m0.458s
>
> Why is grafting so slow, even if it doesn't have to graft anything?

Grafting leads to a bunch of additional RPCs:

--8<---------------cut here---------------start------------->8---
$ GUIX_PROFILING=rpc ./pre-inst-env guix build coreutils
/gnu/store/mskh7zisxa313anqv68c5lr4hajldjc5-coreutils-8.27-debug
/gnu/store/xbvwxf4k5njnb3hn93xwqlppjkiz4hdv-coreutils-8.27
Remote procedure call summary: 379 RPCs
  build-things                   ...     1
  built-in-builders              ...     1
  valid-path?                    ...     5
  query-substitutable-path-infos ...     8
  query-references               ...    22
  query-valid-derivers           ...    48
  add-text-to-store              ...   294
$ GUIX_PROFILING=rpc ./pre-inst-env guix build coreutils --no-grafts
/gnu/store/mskh7zisxa313anqv68c5lr4hajldjc5-coreutils-8.27-debug
/gnu/store/xbvwxf4k5njnb3hn93xwqlppjkiz4hdv-coreutils-8.27
Remote procedure call summary: 294 RPCs
  built-in-builders              ...     1
  query-substitutable-path-infos ...     1
  build-things                   ...     1
  valid-path?                    ...     5
  add-text-to-store              ...   286
--8<---------------cut here---------------end--------------->8---

So the problem is probably not NFS in this case but rather RPC
performance.

However, I can’t help with this until you drop ‘guixr’ and use
GUIX_DAEMON_SOCKET=guix:// instead.  Hint hint.  ;-)

Thanks for your feedback,
Ludo’.

Re: Performance on NFS

[Roel Janssen]

Ludovic Courtès writes:

> Hi!
>
> Roel Janssen <roel@gnu.org> skribis:
>
>> I applied the patch, and here are the results:
>>
>> [roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure -- true
>> The following derivations will be built:
>>    /gnu/store/0hz8g844432b5h9zbqr9cpsjy0brg15h-profile.drv
>>    /gnu/store/wkksb7bbx3jr0p6p5cj4kkphbwday0yd-info-dir.drv
>>    /gnu/store/cd2mwx9qprdy23p7j3pik2zs14nifn36-manual-database.drv
>> Creating manual page database for 1 packages... done in 1.816 s
>>
>> real	1m14.686s
>> user	0m5.761s
>> sys	0m0.498s
>> [roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure -- true
>>
>> real	0m34.100s
>> user	0m5.599s
>> sys	0m0.414s
>> [roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure -- true
>>
>> real	0m33.821s
>> user	0m5.140s
>> sys	0m0.432s
>
> You’re telling me it’s just as bad as before, right?

Sorry for the somewhat hasted response.

Well, before it was more variable what the speed was.  Now it seems to
be pretty stable around ~30 to ~35 seconds with grafting, and ~15 to ~20
seconds without grafting.

I really appreciate the effort for optimizing.  And I feel it is
improving.

>
>> [roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure --no-substitutes --no-grafts -- true
>> The following derivations will be built:
>>    /gnu/store/rvh0imjdimwm90nzr0fmr5gmp97lyiix-profile.drv
>>    /gnu/store/5hm3v4afjf9gix92ixqzv9bwc11a608s-fonts-dir.drv
>>
>> real	0m37.200s
>> user	0m3.408s
>> sys	0m0.284s
>> [roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure --no-substitutes --no-grafts -- true
>>
>> real	0m19.415s
>> user	0m3.466s
>> sys	0m0.306s
>> [roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure --no-substitutes --no-grafts -- true
>>
>> real	0m18.850s
>> user	0m3.536s
>> sys	0m0.346s
>> [roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure --no-grafts -- true
>>
>> real	0m16.003s
>> user	0m3.246s
>> sys	0m0.301s
>> [roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure --no-grafts -- true
>>
>> real	0m18.205s
>> user	0m3.470s
>> sys	0m0.314s
>> [roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure --no-substitutes -- true
>>
>> real	0m33.731s
>> user	0m5.111s
>> sys	0m0.428s
>> [roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure --no-substitutes -- true
>>
>> real	0m30.993s
>> user	0m5.049s
>> sys	0m0.458s
>>
>> Why is grafting so slow, even if it doesn't have to graft anything?
>
> Grafting leads to a bunch of additional RPCs:
>
> --8<---------------cut here---------------start------------->8---
> $ GUIX_PROFILING=rpc ./pre-inst-env guix build coreutils
> /gnu/store/mskh7zisxa313anqv68c5lr4hajldjc5-coreutils-8.27-debug
> /gnu/store/xbvwxf4k5njnb3hn93xwqlppjkiz4hdv-coreutils-8.27
> Remote procedure call summary: 379 RPCs
>   build-things                   ...     1
>   built-in-builders              ...     1
>   valid-path?                    ...     5
>   query-substitutable-path-infos ...     8
>   query-references               ...    22
>   query-valid-derivers           ...    48
>   add-text-to-store              ...   294
> $ GUIX_PROFILING=rpc ./pre-inst-env guix build coreutils --no-grafts
> /gnu/store/mskh7zisxa313anqv68c5lr4hajldjc5-coreutils-8.27-debug
> /gnu/store/xbvwxf4k5njnb3hn93xwqlppjkiz4hdv-coreutils-8.27
> Remote procedure call summary: 294 RPCs
>   built-in-builders              ...     1
>   query-substitutable-path-infos ...     1
>   build-things                   ...     1
>   valid-path?                    ...     5
>   add-text-to-store              ...   286
> --8<---------------cut here---------------end--------------->8---
>
> So the problem is probably not NFS in this case but rather RPC
> performance.
>
> However, I can’t help with this until you drop ‘guixr’ and use
> GUIX_DAEMON_SOCKET=guix:// instead.  Hint hint.  ;-)

This is what guixr is already doing, see:
https://github.com/UMCUGenetics/guix-additions/blob/master/umcu/packages/guix.scm#L95

So I went a little bit further and did this:
[roel@hpcguix ~]$ export GUIX_DAEMON_SOCKET="/gnu/daemon-socket/socket"
[roel@hpcguix ~]$ export NIX_STATE_DIR=/gnu

This means that if I run "guix" on the same machine as where guix-daemon
is running, and communicate over the UNIX socket, I should not
experience a performance problem, other than a little bit of NFS
latency..

Here are the timings:

[roel@hpcguix ~]$ time guix environment --ad-hoc coreutils --pure --no-grafts -- true

real	0m16.293s
user	0m2.550s
sys	0m0.274s
[roel@hpcguix ~]$ time guix environment --ad-hoc coreutils --pure --no-grafts -- true

real	0m15.746s
user	0m2.411s
sys	0m0.260s
[roel@hpcguix ~]$ time guix environment --ad-hoc coreutils --pure -- true

real	0m32.821s
user	0m4.342s
sys	0m0.375s

[roel@hpcguix ~]$ time guix environment --ad-hoc coreutils --pure -- true

real	0m31.140s
user	0m4.361s
sys	0m0.312s


Looks pretty much the same.  Now, the only thing that can be trouble,
other than NFS's overhead, is that the daemon socket is on the NFS mount
as well.  I don't think that matters because the socket is not an actual
file from the kernel's perspective, so there shouldn't be any NFS
involvement there.  Nevertheless, I will try mounting the
/gnu/daemon-socket directory on a tmpfs (in memory) for maximum speed.

There's "nfsstat" that can display some NFS numbers.  Here's what the
client information looks like (run on hpcguix):

[roel@hpcguix ~]$ nfsstat -c
Client rpc stats:
calls      retrans    authrefrsh
21090135   0          21097679

Client nfs v3:
null         getattr      setattr      lookup       access       readlink     
0         0% 17580080 83% 500076    2% 842458    3% 930443    4% 1142      0% 
read         write        create       mkdir        symlink      mknod        
153231    0% 313668    1% 232301    1% 60846     0% 10604     0% 80        0% 
remove       rmdir        rename       link         readdir      readdirplus  
181436    0% 53549     0% 74060     0% 75984     0% 278       0% 76912     0% 
fsstat       fsinfo       pathconf     commit       
1402      0% 6         0% 3         0% 2481      0% 


The high number of getattr is probably due to the attribute cache.  I
also tried disabling the attribute cache with the "noac" mount option.
This lead to timings of (stably) around 2 minutes (with grafts enabled).

What worries me from these numbers is the authrefrsh, which are almost
equal to the number of calls.  What I think it means is that for almost
every call, it also checks whether the client is still authorized to get
data from the NFS server, effectively doubling the network packets,
doubling the network overhead.  What I can try here is disable
authentication.  I am not sure whether that is a good solution, but at
least we can get some performance impact numbers here.

I will report back with my findings here.

>
> Thanks for your feedback,
> Ludo’.

Thanks a lot for your efforts in speeding things up!

Kind regards,
Roel Janssen

Re: Performance on NFS

[Ricardo Wurmus]

Ludovic Courtès <ludovic.courtes@inria.fr> writes:

[…]

> So the problem is probably not NFS in this case but rather RPC
> performance.
>
> However, I can’t help with this until you drop ‘guixr’ and use
> GUIX_DAEMON_SOCKET=guix:// instead.  Hint hint.  ;-)

FWIW: I’m using GUIX_DAEMON_SOCKET=guix:// since a few days.  It allows
for a simpler “guixr”, which now only prints extra info and refuses to
run on the login node.  It’s really nice!

I haven’t noticed any difference in performance, but I certainly could
test patches.

Performance differs a lot for different packages.  “guix build bwa” (~ 7
seconds) is a lot faster than “guix build python2-numpy” (> 40 seconds),
for example.

--
Ricardo

GPG: BCA6 89B6 3655 3801 C3C6  2150 197A 5888 235F ACAC
https://elephly.net

RPC performance

[Ludovic Courtès]

Hello,

Ricardo Wurmus <rekado@elephly.net> skribis:

> Performance differs a lot for different packages.  “guix build bwa” (~ 7
> seconds) is a lot faster than “guix build python2-numpy” (> 40 seconds),
> for example.

My guess is that this is mostly due to RPC performance:

--8<---------------cut here---------------start------------->8---
$ GUIX_PROFILING=rpc time ./pre-inst-env guix build bwa -n
Remote procedure call summary: 266 RPCs
  built-in-builders              ...     1
  query-substitutable-path-infos ...     1
  valid-path?                    ...     3
  add-text-to-store              ...   261
0.88user 0.04system 0:00.83elapsed 110%CPU (0avgtext+0avgdata 497792maxresident)k
0inputs+0outputs (0major+11771minor)pagefaults 0swaps
$ GUIX_PROFILING=rpc time ./pre-inst-env guix build python2-numpy -n
Remote procedure call summary: 668 RPCs
  built-in-builders              ...     1
  query-substitutable-path-infos ...     1
  valid-path?                    ...     3
  add-text-to-store              ...   663
1.22user 0.06system 0:01.33elapsed 95%CPU (0avgtext+0avgdata 508288maxresident)k
1432inputs+0outputs (0major+10752minor)pagefaults 0swaps
--8<---------------cut here---------------end--------------->8---

There are several ways we can improve it, and over time we should try to
implement all of them:

  1. Buffer writes to the server socket (currently it’s terrible if you
     look at the ‘write’ calls in ‘strace’).

  2. Make fewer ‘add-text-to-store’ calls.  This can be done by, for
     instance, always using the same ‘-guile-builder’ script for
     everything that uses ‘gnu-build-system’, and parameterize the
     script through environment variables or similar.

  3. Replace N ‘add-text-to-store’ calls with a single ‘import-paths’
     call.  It’s not possible yet because ‘import-paths’ requires a
     signature, which is pointless for content-address items.

  4. Alternatively, change the protocol to allow for RPC pipelining
     (send N requests, then read N responses).  Currently this isn’t
     possible because all the RPCs call ‘process-stderr’ (which makes
     one or more round trips) because reading their response.

I’ll look into #1 soon and we can investigate #2 on the next
‘core-updates’ cycle.

Thanks,
Ludo’.

Re: RPC performance

[Ludovic Courtès]

[-- Attachment #1: Type: text/plain, Size: 649 bytes --]

ludovic.courtes@inria.fr (Ludovic Courtès) skribis:

> There are several ways we can improve it, and over time we should try to
> implement all of them:
>
>   1. Buffer writes to the server socket (currently it’s terrible if you
>      look at the ‘write’ calls in ‘strace’).

Could you test the effect of the patch below?  It reduces the number of
‘write’ calls from 9.5K to 2.0K on “guix build python2-numpy”.

(It’s not acceptable as-is because it allocates a new port and
associated buffer at each RPC, meaning that on my laptop the cost in
user time slightly outweighs the cost in system time.)

Ludo’.


[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #2: Type: text/x-patch, Size: 3457 bytes --]

diff --git a/guix/store.scm b/guix/store.scm
index 2acab6b1a..47fa3447f 100644
--- a/guix/store.scm
+++ b/guix/store.scm
@@ -321,13 +321,15 @@
 ;; remote-store.cc
 
 (define-record-type <nix-server>
-  (%make-nix-server socket major minor
+  (%make-nix-server socket major minor buffer
                     ats-cache atts-cache)
   nix-server?
   (socket nix-server-socket)
   (major  nix-server-major-version)
   (minor  nix-server-minor-version)
 
+  (buffer nix-server-output-buffer)
+
   ;; Caches.  We keep them per-connection, because store paths build
   ;; during the session are temporary GC roots kept for the duration of
   ;; the session.
@@ -499,6 +501,7 @@ for this connection will be pinned.  Return a server object."
                       (let ((conn (%make-nix-server port
                                                     (protocol-major v)
                                                     (protocol-minor v)
+                                                    (make-bytevector 8192)
                                                     (make-hash-table 100)
                                                     (make-hash-table 100))))
                         (let loop ((done? (process-stderr conn)))
@@ -718,6 +721,41 @@ encoding conversion errors."
     (let loop ((done? (process-stderr server)))
       (or done? (process-stderr server)))))
 
+(define (buffering-output-port port buffer)
+  ;; Note: In Guile 2.2.2, custom binary output ports already have their own
+  ;; 4K internal buffer.
+  (define size
+    (bytevector-length buffer))
+
+  (define total 0)
+
+  (define (flush)
+    (put-bytevector port buffer 0 total)
+    (set! total 0))
+
+  (define (write bv offset count)
+    (if (zero? count)                             ;end of file
+        (flush)
+        (let loop ((offset offset)
+                   (count count)
+                   (written 0))
+          (cond ((= total size)
+                 (flush)
+                 (loop offset count written))
+                ((zero? count)
+                 written)
+                (else
+                 (let ((to-copy (min count (- size total))))
+                   (bytevector-copy! bv offset buffer total to-copy)
+                   (set! total (+ total to-copy))
+                   (loop (+ offset to-copy) (- count to-copy)
+                         (+ written to-copy))))))))
+
+  (let ((port (make-custom-binary-output-port "buffering-output-port"
+                                              write #f #f flush)))
+    (setvbuf port _IONBF)
+    port))
+
 (define %rpc-calls
   ;; Mapping from RPC names (symbols) to invocation counts.
   (make-hash-table))
@@ -755,11 +793,15 @@ encoding conversion errors."
     ((_ (name (type arg) ...) docstring return ...)
      (lambda (server arg ...)
        docstring
-       (let ((s (nix-server-socket server)))
+       (let* ((s (nix-server-socket server))
+              (buffered (buffering-output-port
+                         s (nix-server-output-buffer server))))
          (record-operation 'name)
-         (write-int (operation-id name) s)
-         (write-arg type arg s)
+         (write-int (operation-id name) buffered)
+         (write-arg type arg buffered)
          ...
+         (close-port buffered)
+
          ;; Loop until the server is done sending error output.
          (let loop ((done? (process-stderr server)))
            (or done? (loop (process-stderr server))))

Re: RPC performance

[Ricardo Wurmus]

Ludovic Courtès <ludovic.courtes@inria.fr> writes:

> ludovic.courtes@inria.fr (Ludovic Courtès) skribis:
>
>> There are several ways we can improve it, and over time we should try to
>> implement all of them:
>>
>>   1. Buffer writes to the server socket (currently it’s terrible if you
>>      look at the ‘write’ calls in ‘strace’).
>
> Could you test the effect of the patch below?  It reduces the number of
> ‘write’ calls from 9.5K to 2.0K on “guix build python2-numpy”.

I have tried it but my setup is way too variable to allow me to compare
performance changes.  For “guix build bwa” when “bwa” has already been
built I get waiting times between 6 and 42 seconds.  Any improvement
would disappear in this terribly wide range.

I will soon have access to a new NFS share on a separate server and with
disabled read timestamps, which I hope will be more reliable.

-- 
Ricardo

GPG: BCA6 89B6 3655 3801 C3C6  2150 197A 5888 235F ACAC
https://elephly.net

Re: RPC performance

[Ludovic Courtès]

ludovic.courtes@inria.fr (Ludovic Courtès) skribis:

> There are several ways we can improve it, and over time we should try to
> implement all of them:
>
>   1. Buffer writes to the server socket (currently it’s terrible if you
>      look at the ‘write’ calls in ‘strace’).

Done in commit e037e9dbec1ab5a8cfaf65d73aa3afb2eeb98d71.  It doesn’t
significantly improve performance, probably because the other problems
are more acute, but it’s good to have.

Ludo’.

Re: RPC performance

[Ricardo Wurmus]

Ludovic Courtès <ludo@gnu.org> writes:

> ludovic.courtes@inria.fr (Ludovic Courtès) skribis:
>
>> There are several ways we can improve it, and over time we should try to
>> implement all of them:
>>
>>   1. Buffer writes to the server socket (currently it’s terrible if you
>>      look at the ‘write’ calls in ‘strace’).
>
> Done in commit e037e9dbec1ab5a8cfaf65d73aa3afb2eeb98d71.  It doesn’t
> significantly improve performance, probably because the other problems
> are more acute, but it’s good to have.

Thanks!  I’m looking forward to getting the new NFS server ready and
benefiting from these improvemets.

-- 
Ricardo

GPG: BCA6 89B6 3655 3801 C3C6  2150 197A 5888 235F ACAC
https://elephly.net

Re: RPC performance

[Andy Wingo]

On Mon 19 Jun 2017 10:15, ludovic.courtes@inria.fr (Ludovic Courtès) writes:

> +(define (buffering-output-port port buffer)
> +  ;; Note: In Guile 2.2.2, custom binary output ports already have their own
> +  ;; 4K internal buffer.
> +  (define size
> +    (bytevector-length buffer))
> +
> +  (define total 0)
> +
> +  (define (flush)
> +    (put-bytevector port buffer 0 total)
> +    (set! total 0))
> +
> +  (define (write bv offset count)
> +    (if (zero? count)                             ;end of file
> +        (flush)
> +        (let loop ((offset offset)
> +                   (count count)
> +                   (written 0))
> +          (cond ((= total size)
> +                 (flush)
> +                 (loop offset count written))
> +                ((zero? count)
> +                 written)
> +                (else
> +                 (let ((to-copy (min count (- size total))))
> +                   (bytevector-copy! bv offset buffer total to-copy)
> +                   (set! total (+ total to-copy))
> +                   (loop (+ offset to-copy) (- count to-copy)
> +                         (+ written to-copy))))))))
> +
> +  (let ((port (make-custom-binary-output-port "buffering-output-port"
> +                                              write #f #f flush)))
> +    (setvbuf port _IONBF)
> +    port))
> +

Why not just set to _IOFBF and let Guile 2.2's buffering handle it?

Andy

Re: RPC performance

[Ludovic Courtès]

Heya,

Andy Wingo <wingo@igalia.com> skribis:

> On Mon 19 Jun 2017 10:15, ludovic.courtes@inria.fr (Ludovic Courtès) writes:
>
>> +(define (buffering-output-port port buffer)
>> +  ;; Note: In Guile 2.2.2, custom binary output ports already have their own
>> +  ;; 4K internal buffer.
>> +  (define size
>> +    (bytevector-length buffer))
>> +
>> +  (define total 0)
>> +
>> +  (define (flush)
>> +    (put-bytevector port buffer 0 total)
>> +    (set! total 0))
>> +
>> +  (define (write bv offset count)
>> +    (if (zero? count)                             ;end of file
>> +        (flush)
>> +        (let loop ((offset offset)
>> +                   (count count)
>> +                   (written 0))
>> +          (cond ((= total size)
>> +                 (flush)
>> +                 (loop offset count written))
>> +                ((zero? count)
>> +                 written)
>> +                (else
>> +                 (let ((to-copy (min count (- size total))))
>> +                   (bytevector-copy! bv offset buffer total to-copy)
>> +                   (set! total (+ total to-copy))
>> +                   (loop (+ offset to-copy) (- count to-copy)
>> +                         (+ written to-copy))))))))
>> +
>> +  (let ((port (make-custom-binary-output-port "buffering-output-port"
>> +                                              write #f #f flush)))
>> +    (setvbuf port _IONBF)
>> +    port))
>> +
>
> Why not just set to _IOFBF and let Guile 2.2's buffering handle it?

Because we want controlled buffering when writing (we need to flush
pending output when we’re done writing the RPC request), and no
buffering at all when reading.

In C/C++ the way to do that is to have unbuffered streams and to do
application-level buffering by allocating output buffers of the right
size.

Thoughts?

Ludo’.

Re: RPC performance

[Andy Wingo]

On Thu 22 Jun 2017 18:05, ludovic.courtes@inria.fr (Ludovic Courtès) writes:

> Andy Wingo <wingo@igalia.com> skribis:
>
>> Why not just set to _IOFBF and let Guile 2.2's buffering handle it?
>
> Because we want controlled buffering when writing (we need to flush
> pending output when we’re done writing the RPC request), and no
> buffering at all when reading.

For controlling output buffering, there is the setvbuf buffer size, and
"force-output".  In Guile 2.2 the CBOP's "write" function is really a
"flush" function -- it only gets called when the internal buffer is
filled, or when flush-output is called, or (for line-buffered ports)
when a newline is written.

Why do you not want buffering when reading?  Do you need to hand off
this FD to some other process?

Andy

Re: RPC performance

[Ludovic Courtès]

Hi Andy,

Andy Wingo <wingo@igalia.com> skribis:

> On Thu 22 Jun 2017 18:05, ludovic.courtes@inria.fr (Ludovic Courtès) writes:
>
>> Andy Wingo <wingo@igalia.com> skribis:
>>
>>> Why not just set to _IOFBF and let Guile 2.2's buffering handle it?
>>
>> Because we want controlled buffering when writing (we need to flush
>> pending output when we’re done writing the RPC request), and no
>> buffering at all when reading.
>
> For controlling output buffering, there is the setvbuf buffer size, and
> "force-output".  In Guile 2.2 the CBOP's "write" function is really a
> "flush" function -- it only gets called when the internal buffer is
> filled, or when flush-output is called, or (for line-buffered ports)
> when a newline is written.
>
> Why do you not want buffering when reading?  Do you need to hand off
> this FD to some other process?

With the current protocol, often we’re just reading a handful of bytes.
Full buffering would mean that Guile would block on an 8K read or so
that will never be fulfilled.

Ludo’.

Re: RPC performance

[Andy Wingo]

Hi!

On Fri 23 Jun 2017 11:24, ludovic.courtes@inria.fr (Ludovic Courtès) writes:

> With the current protocol, often we’re just reading a handful of bytes.
> Full buffering would mean that Guile would block on an 8K read or so
> that will never be fulfilled.

That's not how it works :)  The "read" function of a port should only
block if no byte can be read.  If 1K bytes are available for an 8K
buffer, then the read function should return after filling only 1K
bytes; looping to fill at least 8K is some other code's responsibility.

In particular, "read" functions should not use get-bytevector-n, as
get-bytevector-n is defined to block until N bytes are available.
Instead they should use get-bytevector-some.  See:

  https://git.savannah.gnu.org/cgit/guile.git/commit/?h=stable-2.2&id=0c102b56e98da39b5a3213bdc567a31ad8ef3e73

Andy

Re: RPC performance

[Ludovic Courtès]

Andy Wingo <wingo@igalia.com> skribis:

> Hi!
>
> On Fri 23 Jun 2017 11:24, ludovic.courtes@inria.fr (Ludovic Courtès) writes:
>
>> With the current protocol, often we’re just reading a handful of bytes.
>> Full buffering would mean that Guile would block on an 8K read or so
>> that will never be fulfilled.
>
> That's not how it works :)  The "read" function of a port should only
> block if no byte can be read.  If 1K bytes are available for an 8K
> buffer, then the read function should return after filling only 1K
> bytes; looping to fill at least 8K is some other code's responsibility.

I must be missing something.  With full buffering, when my code does:

  (get-bytevector-n port 8)

I see read(2) hanging on an 8K read:

--8<---------------cut here---------------start------------->8---
#0  0x00007fb0b36baaed in read () at ../sysdeps/unix/syscall-template.S:84
#1  0x00007fb0b3b91c47 in fport_read (port=<optimized out>, dst=<optimized out>, start=<optimized out>, 
    count=8192) at fports.c:604
#2  0x00007fb0b3bbed77 in scm_i_read_bytes (port=port@entry=0x194f700, dst=0x195c000, start=start@entry=0, 
    count=8192) at ports.c:1544
#3  0x00007fb0b3bc25fe in scm_fill_input (port=port@entry=0x194f700, minimum_size=1, minimum_size@entry=0, 
    cur_out=cur_out@entry=0x7ffd7eee5f30, avail_out=avail_out@entry=0x7ffd7eee5f38) at ports.c:2677
#4  0x00007fb0b3bc3384 in scm_c_read_bytes (port=port@entry=0x194f700, dst=dst@entry=0x1952510, 
    start=start@entry=0, count=count@entry=8) at ports.c:1610
#5  0x00007fb0b3bc9838 in scm_get_bytevector_n (port=0x194f700, count=<optimized out>) at r6rs-ports.c:421
#6  0x00007fb0b3bfdc4d in vm_regular_engine (thread=0xe, vp=0x143df30, registers=0x2000, resume=-1284789523)
    at vm-engine.c:784
--8<---------------cut here---------------end--------------->8---

(That’s not Guile-specific.)  I agree that read(2) could return less
than 8K and not block, but it doesn’t have to.

I’ll see if I can investigate more later.

Thanks for your input,
Ludo’.

Re: RPC performance

[Andy Wingo]

On Mon 26 Jun 2017 13:54, ludovic.courtes@inria.fr (Ludovic Courtès) writes:

> Andy Wingo <wingo@igalia.com> skribis:
>
>> Hi!
>>
>> On Fri 23 Jun 2017 11:24, ludovic.courtes@inria.fr (Ludovic Courtès) writes:
>>
>>> With the current protocol, often we’re just reading a handful of bytes.
>>> Full buffering would mean that Guile would block on an 8K read or so
>>> that will never be fulfilled.
>>
>> That's not how it works :)  The "read" function of a port should only
>> block if no byte can be read.  If 1K bytes are available for an 8K
>> buffer, then the read function should return after filling only 1K
>> bytes; looping to fill at least 8K is some other code's responsibility.
>
> I must be missing something.  With full buffering, when my code does:
>
>   (get-bytevector-n port 8)

Note that get-bytevector-n will block until there are 8 bytes.

> I see read(2) hanging on an 8K read:
>
> #0  0x00007fb0b36baaed in read () at ../sysdeps/unix/syscall-template.S:84
> #1  0x00007fb0b3b91c47 in fport_read (port=<optimized out>, dst=<optimized out>, start=<optimized out>, 
>     count=8192) at fports.c:604
> #2  0x00007fb0b3bbed77 in scm_i_read_bytes (port=port@entry=0x194f700, dst=0x195c000, start=start@entry=0, 
>     count=8192) at ports.c:1544
> #3  0x00007fb0b3bc25fe in scm_fill_input (port=port@entry=0x194f700, minimum_size=1, minimum_size@entry=0, 
>     cur_out=cur_out@entry=0x7ffd7eee5f30, avail_out=avail_out@entry=0x7ffd7eee5f38) at ports.c:2677

Here this indicates that the buffer is empty, and that it's blocking on
receiving *any* bytes at all.

> (That’s not Guile-specific.)  I agree that read(2) could return less
> than 8K and not block, but it doesn’t have to.

I think this is incorrect.  Read returns when it has any bytes at all.
From read(2):

   It is not an error if this number is smaller than the number of
   bytes requested; this may happen for example because fewer bytes
   are actually available right now (maybe because we were close to
   end-of-file, or because we are reading from a pipe, or from a
   terminal), or because read() was interrupted by a signal.  See
   also NOTES.

In short the reason read is blocking for you is that there are no bytes
available -- if there were 8 bytes and only 8 bytes, the read(2) would
return directly.

If you have blocking problems related to 8K buffers, it's likely related
to using get-bytevector-n inside CBIP read() functions.

Andy

Re: Combining Guix, direnv and Emacs for environment customisation

[Thompson, David]

Hello Christopher,

Reviving this old thread, if you don't mind. :)

On Sat, May 27, 2017 at 7:31 AM, Christopher Baines <mail@cbaines.net> wrote:
>
> In summary, using direnv provides a convinient way to manage different
> environments created from Guix. There is now support for using direnv
> directly from Emacs.

This is great.  I need to try it out sometime.

> One issue with this is that running guix environment from direnv will
> slow down switching buffers. To make it a bit more useable, I found
> some bash code that caches the results of running commands, and wrapped
> that around guix environment when invoked from direnv. This helps speed
> things up, but I don't think its useful in the long term.
>
> For this particular use case, it would help if guix environment was
> faster, perhaps by doing caching internally? On my system, running guix
> environment --ad-hoc guile --search-paths repeatedly takes ~2 seconds,
> I haven't looked at what the breakdown of this is yet.
>
> I'd be interested in hearing if anyone does something similar for using
> Guix, or if anyone does something different, but to the same effect?

There is a feature missing in 'guix environment': saving the resulting
profile for easy access later.  I often want to build an environment
once and not update it for awhile, but with the current state of 'guix
environment' it's not possible. This leads me to pulling my hair out
when I do an upgrade of Guix and have to rebuild all of my development
environments. What was supposed to be a quick hack turns into a Guix
maintenance session.

Let's imagine that the first time `guix environment` is invoked it
creates a symlink in $PWD to the generated profile named
.guix-environment.  Future invocations of 'guix environment' would
short-circuit all the daemon communication, package module loading,
etc. and just apply the environment variables in the already built
profile.  Once we have that built, emacs-direnv integration is as
simple as sourcing .guix-environment/etc/profile, or running 'guix
environment' if the profile is not yet built.

WDYT?

(If time permits, I'd like to start contributing to Guix again by
overhauling 'guix environment' to be more convenient for day-to-day
development)

- Dave

Re: Combining Guix, direnv and Emacs for environment customisation

[Maxim Cournoyer]

Hi!

"Thompson, David" <dthompson2@worcester.edu> writes:

> There is a feature missing in 'guix environment': saving the resulting
> profile for easy access later.  I often want to build an environment
> once and not update it for awhile, but with the current state of 'guix
> environment' it's not possible. This leads me to pulling my hair out
> when I do an upgrade of Guix and have to rebuild all of my development
> environments. What was supposed to be a quick hack turns into a Guix
> maintenance session.

Have you tried creating extra persistent profiles? This
would seem to suite your use case better (although a 'save-env' feature
for environments would be neat!).

The doc is sparsed about the use of profiles, but Ricardo published some
useful write-up here: https://elephly.net/posts/latest.html where you'll
find some commands making use of it.

HTH,

Maxim

Re: Combining Guix, direnv and Emacs for environment customisation

[Carlo Zancanaro]

[-- Attachment #1: Type: text/plain, Size: 916 bytes --]

On Tue, Aug 29 2017, David wrote:
> There is a feature missing in 'guix environment': saving the resulting
> profile for easy access later.  I often want to build an environment
> once and not update it for awhile, but with the current state of 'guix
> environment' it's not possible. This leads me to pulling my hair out
> when I do an upgrade of Guix and have to rebuild all of my development
> environments. What was supposed to be a quick hack turns into a Guix
> maintenance session.

I also got frustrated by this when trying to keep my own checkout of
guix. Then I found out you can do this:

  guix environment guix --root=environment

This puts a link to the environment under `environment` in the local
directory. Then you can run `source environment/etc/profile; make` to
rebuild guix. This also protects the environment from garbage
collection, which was the actual problem I was trying to solve.

Carlo

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 487 bytes --]

Re: Combining Guix, direnv and Emacs for environment customisation

[Ludovic Courtès]

Carlo Zancanaro <carlo@zancanaro.id.au> skribis:

> On Tue, Aug 29 2017, David wrote:
>> There is a feature missing in 'guix environment': saving the resulting
>> profile for easy access later.  I often want to build an environment
>> once and not update it for awhile, but with the current state of 'guix
>> environment' it's not possible. This leads me to pulling my hair out
>> when I do an upgrade of Guix and have to rebuild all of my development
>> environments. What was supposed to be a quick hack turns into a Guix
>> maintenance session.
>
> I also got frustrated by this when trying to keep my own checkout of
> guix. Then I found out you can do this:
>
>   guix environment guix --root=environment
>
> This puts a link to the environment under `environment` in the local
> directory. Then you can run `source environment/etc/profile; make` to
> rebuild guix. This also protects the environment from garbage
> collection, which was the actual problem I was trying to solve.

It surely helps, but I think it would be even better if ‘guix
environment’ would directly include a way to reload the environment in
its UI, like Dave was suggesting.

Maybe it’s just a matter of adding a --reload option that does what you
wrote above for you?

Ludo’.

Re: Combining Guix, direnv and Emacs for environment customisation

[Ludovic Courtès]

Hi!

"Thompson, David" <dthompson2@worcester.edu> skribis:

> There is a feature missing in 'guix environment': saving the resulting
> profile for easy access later.  I often want to build an environment
> once and not update it for awhile, but with the current state of 'guix
> environment' it's not possible. This leads me to pulling my hair out
> when I do an upgrade of Guix and have to rebuild all of my development
> environments. What was supposed to be a quick hack turns into a Guix
> maintenance session.
>
> Let's imagine that the first time `guix environment` is invoked it
> creates a symlink in $PWD to the generated profile named
> .guix-environment.  Future invocations of 'guix environment' would
> short-circuit all the daemon communication, package module loading,
> etc. and just apply the environment variables in the already built
> profile.  Once we have that built, emacs-direnv integration is as
> simple as sourcing .guix-environment/etc/profile, or running 'guix
> environment' if the profile is not yet built.
>
> WDYT?

Like Carlo wrote, --root probably gets us halfway there already.  Maybe
a new “--save” could be added and be equivalent to
“--root=$PWD/.guix-environment”.  And then, indeed, “guix environment”
without any argument could simply source .guix-environment/etc/profile
and start from there.

How does that sound?

FWIW I’m interested in making ‘guix environment’ a drop-in replacement
for the “modules” command found on HPC clusters¹, which means startup
times below one second.  A simple cache like what you write above could
get us very close to that.

¹ http://modules.sourceforge.net/

> (If time permits, I'd like to start contributing to Guix again by
> overhauling 'guix environment' to be more convenient for day-to-day
> development)

Your inspiration and hack power would be welcome!  :-)

Ludo’.