bug#47496: Very slow `guix environment -l nyxt/build-scripts/guix.scm

bug#47496: Very slow `guix environment -l nyxt/build-scripts/guix.scm

[Pierre Neidhardt]

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

Nyxt provides a "guix.scm" to build Nyxt locally:

https://github.com/atlas-engineer/nyxt/blob/3239b10d816861d329dce10863cb84f9d0bd76ed/build-scripts/guix.scm

A few weeks ago (not sure exactly when and why), `guix environment -l
guix.scm` started being extremely slow.

By this, I mean that

--8<---------------cut here---------------start------------->8---
$ guix environment -v 99 --pure --load=build-scripts/guix.scm 
--8<---------------cut here---------------end--------------->8---

hangs for minutes, maybe hours before it proceeds.
It does not display anything, not even with "-v 99".

In one occurrence, it even hung completely after downloading a few substitutes:

--8<---------------cut here---------------start------------->8---
$ guix environment -v 99 --pure --load=build-scripts/guix.scm 
13.0 MB will be downloaded
downloading from https://ci.guix.gnu.org/nar/lzip/c3755727p11afak5azj52xv4hv9jy0wj-libselinux-3.0-python ...
 libselinux-3.0-python  141KiB                      1.1MiB/s 00:00 [##################] 100.0%

downloading from https://ci.guix.gnu.org/nar/lzip/qlyzqdx6i50d3rfz6hapf53gpjc43n7c-python-3.8.2-tk ...
 python-3.8.2-tk  30KiB                             7.4MiB/s 00:00 [##################] 100.0%

15.3 MB will be downloaded
downloading from https://ci.guix.gnu.org/nar/lzip/v2kdcv8d5dxsbb7s73nj020jry78mcvw-glib-2.62.6 ...
 glib-2.62.6  2.4MiB                                1.7MiB/s 00:01 [##################] 100.0%

downloading from https://ci.guix.gnu.org/nar/lzip/s5dlqhxqa36vax72mx341lhlrz7b1mpz-python2-2.7.17 ...
 python2-2.7.17  9.5MiB                             4.6MiB/s 00:02 [##################] 100.0%

downloading from https://ci.guix.gnu.org/nar/gzip/d1n7p65d3k8ddj0pmydgrsbk26xv5808-glib-2.62.6-bin ...
 glib-2.62.6-bin  149KiB                            2.5MiB/s 00:00 [##################] 100.0%

downloading from https://ci.guix.gnu.org/nar/lzip/wk4k3cnygif6is42iq5wgp1yihr5abv5-python2-2.7.17-tk ...
 python2-2.7.17-tk  28KiB                           5.9MiB/s 00:00 [##################] 100.0%

downloading from https://ci.guix.gnu.org/nar/lzip/rhwgqqg43jhwb4hzpzljp4b1ax9i0786-serf-1.3.9 ...
 serf-1.3.9  78KiB                                  5.5MiB/s 00:00 [##################] 100.0%

downloading from https://ci.guix.gnu.org/nar/lzip/9y6v4zy10pcanivd05chfryc2nsxnian-subversion-1.14.1 ...
 subversion-1.14.1  2.5MiB                          8.3MiB/s 00:00 [##################] 100.0%
--8<---------------cut here---------------end--------------->8---

(That's the full output, it hung there.)

Something must be wrong, because I found a workaround that's fishy: if I
comment out some inputs from the guix.scm and build the environment,
then it works.  Then I uncomment the commented inputs and this time the
environment builds in a few seconds.

Any idea?

-- 
Pierre Neidhardt
https://ambrevar.xyz/

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

bug#47496: Very slow `guix environment -l nyxt/build-scripts/guix.scm

[Ludovic Courtès]

Hi Pierre,

Pierre Neidhardt <mail@ambrevar.xyz> skribis:

> Nyxt provides a "guix.scm" to build Nyxt locally:
>
> https://github.com/atlas-engineer/nyxt/blob/3239b10d816861d329dce10863cb84f9d0bd76ed/build-scripts/guix.scm
>
> A few weeks ago (not sure exactly when and why), `guix environment -l
> guix.scm` started being extremely slow.
>
> By this, I mean that
>
> $ guix environment -v 99 --pure --load=build-scripts/guix.scm 

On a warm cache, I get:

--8<---------------cut here---------------start------------->8---
$ time guix environment -l /tmp/nyxt/build-scripts/guix.scm -v2 -n -- true
22.0 MB would be downloaded:
   /gnu/store/1dr7bkhy8f2v0kgpgm4swl0zrr740zwk-cl-webkit-2.4-10.0bc05cc
   /gnu/store/bpw4k590597g0n7n868qhlsf2cnclzl0-webkitgtk-2.30.6-doc
   /gnu/store/j67y7mzb5dyaqln90n3is85nz218bvxp-webkitgtk-2.30.6

real	0m6.060s
user	0m7.152s
sys	0m0.175s
$ time guix environment -l /tmp/nyxt/build-scripts/guix.scm -v2 -n --no-grafts -- true
La jena derivo estus konstruata:
   /gnu/store/apk1g220mh4g2fzddxy28ssmk6fy9wbm-profile.drv
0.0 MB would be downloaded:
   /gnu/store/1dr7bkhy8f2v0kgpgm4swl0zrr740zwk-cl-webkit-2.4-10.0bc05cc
The following profile hooks would be built:
   /gnu/store/3qhdrwww3yidqk6w98md9w4yfqv7sx4l-xdg-desktop-database.drv
   /gnu/store/7dnznrkrn5rajf60gfj0kvkgz5bylkdc-xdg-mime-database.drv
   /gnu/store/86df5c3j48wg59yrrcqya1rskmwbqjqb-gtk-im-modules.drv
   /gnu/store/9xjd6ax9hlmskhyagf46l28258azra0s-ca-certificate-bundle.drv
   /gnu/store/bb583drg33kg138fb25cb0zd7hhgxzw2-glib-schemas.drv
   /gnu/store/gw13b4ivyfzzvpdik3mgghx6n4ql8b6h-info-dir.drv
   /gnu/store/p2srmzy6b08x7gbg8nvmxzrr6ypsrqiq-gtk-icon-themes.drv
   /gnu/store/p3l0f5imh4021khfrnaqgk0xl5w5zmnh-fonts-dir.drv
   /gnu/store/wsryc95x85d0qdavgiw4fy1qglam6b84-manual-database.drv

real	0m4.497s
user	0m5.719s
sys	0m0.151s
$ guix describe
Generacio 179	Mar 30 2021 11:00:56	(nuna)
  guix 9098745
    repository URL: https://git.savannah.gnu.org/git/guix.git
    branch: master
    commit: 9098745b181b3022587a35afd255f7ff1d41ac86
--8<---------------cut here---------------end--------------->8---

That’s still too long.  The graft performance problem is what’s
discussed at <https://issues.guix.gnu.org/41702>.  The ‘--no-grafts’
performance is not great either, and I wonder if it’s suboptimal
behavior in the presence of many propagated inputs.

> Something must be wrong, because I found a workaround that's fishy: if I
> comment out some inputs from the guix.scm and build the environment,
> then it works.  Then I uncomment the commented inputs and this time the
> environment builds in a few seconds.

There was temporarily a performance regression regarding substitutes:

  https://issues.guix.gnu.org/47283

Given what you describe, this sounds like a likely culprit.  Would be
nice to see if after updating your daemon you still experience that kind
of behavior.

HTH,
Ludo’.

bug#47496: Very slow `guix environment -l nyxt/build-scripts/guix.scm

[Pierre Neidhardt]

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

Hi Ludo,

Thanks for testing!

It seems that we are experience something slightly different.  In my
case, it's not seconds but hours(!).

Also I cannot test on a warm cache because once the environment has
been built, then it's fast again.

It's only hanging seemingly forever if the environment is not built yet.
I suppose this has to do with substitutes indeed.

I'll with with --no-grafts and --no-substitutes.

-- 
Pierre Neidhardt
https://ambrevar.xyz/

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

bug#47496: Very slow `guix environment -l nyxt/build-scripts/guix.scm

[Pierre Neidhardt]

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

I just tried the following:

--8<---------------cut here---------------start------------->8---
guix environment -l ...
--8<---------------cut here---------------end--------------->8---

was forever until I stopped it.
Then


--8<---------------cut here---------------start------------->8---
guix environment --no-grafts -l ...
--8<---------------cut here---------------end--------------->8---

completed in a few seconds.

After this, 

--8<---------------cut here---------------start------------->8---
guix environment -l ...
--8<---------------cut here---------------end--------------->8---

again completed in just a few seconds too.

-- 
Pierre Neidhardt
https://ambrevar.xyz/

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

bug#47496: Very slow `guix environment -l nyxt/build-scripts/guix.scm

[Bengt Richter]

Hi,

On +2021-04-03 20:42:08 +0200, Pierre Neidhardt wrote:
> I just tried the following:
> 
> --8<---------------cut here---------------start------------->8---
> guix environment -l ...
> --8<---------------cut here---------------end--------------->8---
> 
> was forever until I stopped it.
> Then
> 
> 
> --8<---------------cut here---------------start------------->8---
> guix environment --no-grafts -l ...
> --8<---------------cut here---------------end--------------->8---
> 
> completed in a few seconds.
> 
> After this, 
> 
> --8<---------------cut here---------------start------------->8---
> guix environment -l ...
> --8<---------------cut here---------------end--------------->8---
> 
> again completed in just a few seconds too.
>

Could bash have cached a reference somwhere that made the difference?

If you are running in bash, type
    hash
to get a listing of things it has hash-table reference to

see also help bash (unless your shell context is different, in which case,
for convenience, the expected output is:
--8<---------------cut here---------------start------------->8---
hash: hash [-lr] [-p pathname] [-dt] [name ...]
    Remember or display program locations.
    
    Determine and remember the full pathname of each command NAME.  If
    no arguments are given, information about remembered commands is displayed.
    
    Options:
      -d	forget the remembered location of each NAME
      -l	display in a format that may be reused as input
      -p pathname	use PATHNAME as the full pathname of NAME
      -r	forget all remembered locations
      -t	print the remembered location of each NAME, preceding
    		each location with the corresponding NAME if multiple
    		NAMEs are given
    Arguments:
      NAME	Each NAME is searched for in $PATH and added to the list
    		of remembered commands.
    
    Exit Status:
    Returns success unless NAME is not found or an invalid option is given.
--8<---------------cut here---------------end--------------->8---

Usually this bites me by keeping on doing something old in spite of PATH changes,
but if "something old" got established by your
> --8<---------------cut here---------------start------------->8---
> guix environment --no-grafts -l ...
> --8<---------------cut here---------------end--------------->8---
maybe it could have gotten hash-cached and remembered to make
--8<---------------cut here---------------start------------->8---
> guix environment -l ...
> --8<---------------cut here---------------end--------------->8---
> "work" ??

Anyway, apparently some state change is "remembered" in your sequence above,
so I was reminded :)

> -- 
> Pierre Neidhardt
> https://ambrevar.xyz/

-- 
Regards,
Bengt Richter