bug#49439: grafts cause “guix environment” to get killed with OOM

[Sarah Morgensen <iskarian@mgsn.dev>]

Hi,

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

[...]

>> I can reproduce this with pigx-scrnaseq as well a number of other
>> packages (listed below).
>>
>> $ ./pre-inst-env guix describe -f channels
>> (list (channel
>>         (name 'guix)
>>         (url "/home/sarah/guix")
>>         (commit
>>           "3217a04b0352c2dd13323257b369604eeabfccc3")))
>>
>> Does not complete within 5 minutes:

Okay, so all of a sudden I can't reproduce this; even with the same
commit as above, it completes in ~20s.

  guix time-machine --commit=3217a04 -- environment pigx-scrnaseq --search-paths >/dev/null

> What hardware are you using?

Virtualbox VM with VT-x etc. on a host i7-6700. The VM has 6GB of memory.

>
> Here’s what I observe (with everything already in store and on a hot
> cache, with an i7 CPU):
>
> $ guix describe
> Generacio 188	Jul 25 2021 12:47:29	(nuna)
>   guix a92dfbc
>     repository URL: https://git.savannah.gnu.org/git/guix.git
>     branch: master
>     commit: a92dfbce30777de6ca05031e275410cf9f56c84c
> $ time GUIX_PROFILING=gc guix environment pigx-scrnaseq --search-paths --no-grafts >/dev/null
> Garbage collection statistics:
>   heap size:        160.31 MiB
>   allocated:        1440.70 MiB
>   GC times:         39
>   time spent in GC: 4.51 seconds (46% of user time)
>
> real	0m7.534s
> user	0m9.747s
> sys	0m0.167s
> $ time GUIX_PROFILING=gc guix environment pigx-scrnaseq --search-paths  >/dev/null
> Garbage collection statistics:
>   heap size:        168.31 MiB
>   allocated:        2111.71 MiB
>   GC times:         53
>   time spent in GC: 6.92 seconds (45% of user time)
>
> real	0m12.100s
> user	0m15.517s
> sys	0m0.198s
>
>
> Commit 78daf9e02e5bc51f91488d8237cab2050cc060cf optimizes
> ‘coalesce-duplicate-inputs’, which was quadratic in the number of inputs (!).
> After that change, I get:
>
> $ time GUIX_PROFILING=gc ./pre-inst-env guix environment pigx-scrnaseq --search-paths --no-grafts  >/dev/null
> Garbage collection statistics:
>   heap size:        168.31 MiB
>   allocated:        716.58 MiB
>   GC times:         24
>   time spent in GC: 2.65 seconds (40% of user time)
>
> real	0m5.720s
> user	0m6.708s
> sys	0m0.149s
> $ time GUIX_PROFILING=gc ./pre-inst-env guix environment pigx-scrnaseq --search-paths  >/dev/null
> Garbage collection statistics:
>   heap size:        160.31 MiB
>   allocated:        1387.96 MiB
>   GC times:         42
>   time spent in GC: 5.87 seconds (43% of user time)
>
> real	0m10.821s
> user	0m13.513s
> sys	0m0.198s
>
> Could you tell me if it improves the situation for you?

*Now* my experience is like yours:

--8<---------------cut here---------------start------------->8---
$ guix describe
Generation 9	Jul 27 2021 12:35:05	(current)
  guix d0ec739
    repository URL: https://git.savannah.gnu.org/git/guix.git
    branch: master
    commit: d0ec73907c2995034a34339f4a7c2c72c2e21fea

time GUIX_PROFILING=gc guix time-machine --commit=3217a04 -- environment pigx-scrnaseq --search-paths >/dev/null
Garbage collection statistics:
  heap size:        176.31 MiB
  allocated:        2107.82 MiB
  GC times:         52
  time spent in GC: 5.26 seconds (23% of user time)

real	0m20.471s
user	0m22.605s
sys	0m0.372s

$ time GUIX_PROFILING=gc guix environment pigx-scrnaseq --search-paths >/dev/null
Garbage collection statistics:
  heap size:        152.31 MiB
  allocated:        1367.16 MiB
  GC times:         40
  time spent in GC: 3.25 seconds (21% of user time)

real	0m14.701s
user	0m15.698s
sys	0m0.361s
--8<---------------cut here---------------end--------------->8---

But why was it occurring before? The only I thing I can think of is that
I didn't have everything in the store first. Is there a way I can prune
just the relevant items from the store to test this?

>
> It’s not the end of the road, but it should be an improvement.
>
> Thanks,
> Ludo’.

--
Sarah