Subject: bug#48005: low performance when building profile of already built packages

From: Ricardo Wurmus <[email-masked]>
Date: Sat, 24 Apr 2021 22:38:58 +0200

Here is a manifest that isn’t unusual for a bioinformatics 
workflow:

--8<---------------cut here---------------start------------->8---
(define packages
  (list "bash-minimal"
        "fastqc"
        "gzip"
        "htseq"
        "multiqc"
        "r-corrplot"
        "r-crosstalk"
        "r-data-table"
        "r-deseq2"
        "r-dt"
        "r-genomicalignments"
        "r-genomicranges"
        "r-ggplot2"
        "r-ggrepel"
        "r-gprofiler"
        "r-knitr"
        "r-pheatmap"
        "r-plotly"
        "r-reshape2"
        "r-rmarkdown"
        "r-rsamtools"
        "r-rtracklayer"
        "r-s4vectors"
        "r-scales"
        "r-summarizedexperiment"
        "r-tximport"
        "samtools"
        "sed"
        "trim-galore"))

(specifications->manifest packages)
--8<---------------cut here---------------end--------------->8---

When all these packages already exist and nothing is to be done 
when Guix is asked to instantiate this manifest, more than 13 
seconds pass.

--8<---------------cut here---------------start------------->8---
$ [env] export GUIX_PROFILING="object-cache 
add-data-to-store-cache rpc"
$ [env] time guix package -m manifest-test.scm -p /tmp/foo
The following packages will be installed:
   bash-minimal           5.0.16
   fastqc                 0.11.5
   gzip                   1.10
   htseq                  0.9.1
   multiqc                1.5
   r-corrplot             0.84
   r-crosstalk            1.1.1
   r-data-table           1.14.0
   r-deseq2               1.30.1
   r-dt                   0.17
   r-genomicalignments    1.26.0
   r-genomicranges        1.42.0
   r-ggplot2              3.3.3
   r-ggrepel              0.9.1
   r-gprofiler            0.7.0
   r-knitr                1.31
   r-pheatmap             1.0.12
   r-plotly               4.9.3
   r-reshape2             1.4.4
   r-rmarkdown            2.7
   r-rsamtools            2.6.0
   r-rtracklayer          1.50.0
   r-s4vectors            0.28.1
   r-scales               1.1.1
   r-summarizedexperiment 1.20.0
   r-tximport             1.18.0
   samtools               1.11
   sed                    4.8
   trim-galore            0.6.6
[[most of the time passes here]]

nothing to be done
Store object cache:
  fresh caches:     2
  lookups:      45493
  hits:         43943 (96.6%)
  cache size:    1549 entries

'add-data-to-store' cache:
  lookups:       7755
  hits:          3411 (44.0%)
  .drv files:    4357 (56.2%)
  Scheme files:  3343 (43.1%)
Remote procedure call summary: 5283 RPCs
  built-in-builders              ...     1
  add-to-store/tree              ...    27
  add-to-store                   ...   213
  query-references               ...   698
  add-text-to-store              ...  4344

real	0m13.379s
user	0m16.414s
sys	0m0.253s
--8<---------------cut here---------------end--------------->8---

Some of these R packages have a lot of transitive inputs, such as 
r-deseq2 with 81 transitive propagated inputs.  So there’s a lot 
of propagation here, which I suspect contributes to things being 
so unexpectedly slow.

This report may be related to performance issues reported for 
“guix environment” in https://issues.guix.gnu.org/41702, which 
also involves R packages (such as r-learnr with 46 transitive 
propagated inputs).

-- 
Ricardo