(address . bug-guix@gnu.org)
This bug report might be related to bug #48005.
In the Guix Workflow Language we are always looking up packages
through an inferior Guix. That Guix will in most cases be just
the current Guix. As I was looking for ways to speed the GWL up,
I noticed that the use of inferiors itself contributes to a
significant loss in performance.
Here is a simple manifest to demonstrate this:
Toggle snippet (44 lines)
(use-modules (guix inferior)
(ice-9 match))
(define inferior
(open-inferior (format #false "~a/.config/guix" (getenv
"HOME"))))
(define packages
(list "bash-minimal"
"r-corrplot"
"r-crosstalk"
"r-data-table"
"r-deseq2"
"r-dt"
"r-genomicalignments"
"r-genomicranges"
"r-ggplot2"
"r-ggrepel"
"r-gprofiler"
"r-knitr"
"r-minimal"
"r-pheatmap"
"r-plotly"
"r-reshape2"
"r-rmarkdown"
"r-rsamtools"
"r-rtracklayer"
"r-s4vectors"
"r-scales"
"r-summarizedexperiment"
"r-tximport"))
(match (getenv "INFERIOR")
("y"
(packages->manifest
(map (lambda (specification)
(match (lookup-inferior-packages inferior
specification)
((first . rest) first)))
packages)))
(_
(specifications->manifest packages)))
When INFERIOR is set to “y”, each package specification will be
looked up in the current Guix via an inferior. For any other
values of INFERIOR the specifications are resolved with the
current Guix (the very same Guix) directly.
Here are the timings:
Toggle snippet (89 lines)
$ [env] export GUIX_PROFILING="object-cache
add-data-to-store-cache rpc"
$ [env] time INFERIOR=n guix build -m manifest-test.scm -d
/gnu/store/mwg47gbmi98bbrywk07y5l2h9p6d1hz5-bash-minimal-5.0.16.drv
/gnu/store/kcjk6z128fa07pzp8irp6lbbyl3g16nr-r-corrplot-0.84.drv
/gnu/store/s6hflcww9gaq87g5vaaydd4lphw63xjm-r-crosstalk-1.1.1.drv
/gnu/store/qrjgag94sv9lq12028y9iv12j75bva6c-r-data-table-1.14.0.drv
/gnu/store/v6xw6pg33xa8pg19nw0cxhz9b7ps26v7-r-deseq2-1.30.1.drv
/gnu/store/q1achql92wnij108msymr9mkr8pv2z1h-r-dt-0.17.drv
/gnu/store/iym2kzpjiqch22yrhg5lnv9sfazdfphn-r-genomicalignments-1.26.0.drv
/gnu/store/k913mn4q11pchgi63xrm8lb3svvqjcix-r-genomicranges-1.42.0.drv
/gnu/store/zkpabp1qx6m5yam3f9kninnsxagsgwqh-r-ggplot2-3.3.3.drv
/gnu/store/b6w1p6rhbk8shz1ydc2yqb38ypm0ijq9-r-ggrepel-0.9.1.drv
/gnu/store/bwmmls5qkf9cfs9m73qzabnr7w5jc8ra-r-gprofiler-0.7.0.drv
/gnu/store/j1m8hb4449rkfh3ij1l4379j1lngjr06-r-knitr-1.31.drv
/gnu/store/7ig30kf3i65s3rdcw1qik7vsjvspkjxy-r-minimal-4.0.4.drv
/gnu/store/mwg8c42sfsvcrbjhbw7mbdcphhz9hq3x-r-pheatmap-1.0.12.drv
/gnu/store/xjg40q7a7yl3l9v99kqapjylfjwapwk7-r-plotly-4.9.3.drv
/gnu/store/fhs8as885izfb1r6as07sn6jpjgfbl58-r-reshape2-1.4.4.drv
/gnu/store/6bcny1hhf83k85js6x3w7h1w3660ii8m-r-rmarkdown-2.7.drv
/gnu/store/87pr587bk9rzfkrjmrm4bcfjz95p1n9c-r-rsamtools-2.6.0.drv
/gnu/store/l3ibbpd4h7gm565vidbpyamdnhb0czhp-r-rtracklayer-1.50.0.drv
/gnu/store/8rf8d204kavcxkw6z71kxd2mzzqzxsk1-r-s4vectors-0.28.1.drv
/gnu/store/4nxw4lhcvj3q9j5v6mq9ri4v4vwmxd6h-r-scales-1.1.1.drv
/gnu/store/vpf3vkj58vwz92nxcpppil6580c84bb1-r-summarizedexperiment-1.20.0.drv
/gnu/store/cx3cl0nxwvzpaj484q2xcnz3v7zc1015-r-tximport-1.18.0.drv
Store object cache:
fresh caches: 2
lookups: 4540
hits: 3568 (78.6%)
cache size: 971 entries
'add-data-to-store' cache:
lookups: 3450
hits: 492 (14.3%)
.drv files: 2087 (60.5%)
Scheme files: 1347 (39.0%)
Remote procedure call summary: 3412 RPCs
built-in-builders ... 1
add-to-store/tree ... 16
add-to-store ... 177
query-references ... 260
add-text-to-store ... 2958
real 0m3.970s
user 0m4.055s
sys 0m0.173s
$ [env] time INFERIOR=y guix build -m manifest-test.scm -d
/gnu/store/mwg47gbmi98bbrywk07y5l2h9p6d1hz5-bash-minimal-5.0.16.drv
/gnu/store/hmk49rhbfqw2ss55392a7kq34xqg18i7-r-corrplot-0.84.drv
/gnu/store/sg8a3pvzxaq2qd4z918mdb2y0vq6w8mg-r-crosstalk-1.1.1.drv
/gnu/store/n3vk2kkq7zza7pfrjqqbv6xaxhnzdn2x-r-data-table-1.14.0.drv
/gnu/store/44fqdg0s6bcmcgafvgafycf2x82rfl7y-r-deseq2-1.30.1.drv
/gnu/store/03snyvyp9fr3nchrln6qhdca00i7lrsz-r-dt-0.17.drv
/gnu/store/rl48alwm40sl4b04rnk4cck2h4crr8gc-r-genomicalignments-1.26.0.drv
/gnu/store/ryl6hjflgpb72xl91jvp0ab6sl5cblc4-r-genomicranges-1.42.0.drv
/gnu/store/1hbg746cvi8s7vn03glzx46m0pdih5pw-r-ggplot2-3.3.3.drv
/gnu/store/nwvkjb314hh7z7vag0mk870isynp0hda-r-ggrepel-0.9.1.drv
/gnu/store/kvvygkc7vnznrqp4n2rvgsbz9z2jd6ns-r-gprofiler-0.7.0.drv
/gnu/store/0jv2zf34b2p1ddpxnzv5smq4717i4hfq-r-knitr-1.31.drv
/gnu/store/zgi8sfw54jv7wb33q9cs18ff1vlfy0fm-r-minimal-4.0.4.drv
/gnu/store/7w4jp2skqy0vn8i4pr26l94mw8vs8knc-r-pheatmap-1.0.12.drv
/gnu/store/xshkhmd8gpjkmi7npz0bw02wgb8mkysg-r-plotly-4.9.3.drv
/gnu/store/5jqkb3khygfc2y96nff92hfslc2c53yz-r-reshape2-1.4.4.drv
/gnu/store/x0fzqyjg1hq7a4n0wglr9sl71bzxwz0q-r-rmarkdown-2.7.drv
/gnu/store/3v78408vx5x28nb3cf42jarr7fy3b16v-r-rsamtools-2.6.0.drv
/gnu/store/qp4hjddv5sjxiiss0m55q4cv88k520gd-r-rtracklayer-1.50.0.drv
/gnu/store/pgfahjz3wfnppc07z0qbcsdc6mmpri0l-r-s4vectors-0.28.1.drv
/gnu/store/aq317mqb3rbc2rnq2y15k781q5qvf9ia-r-scales-1.1.1.drv
/gnu/store/w9dirjkx523398mhkjw0v4hxgq7x0b8s-r-summarizedexperiment-1.20.0.drv
/gnu/store/rfmzii8xsc3fk63s332ix2qgxpvdvrgf-r-tximport-1.18.0.drv
Store object cache:
fresh caches: 1
lookups: 23
hits: 0 (0.0%)
cache size: 23 entries
'add-data-to-store' cache:
lookups: 0
hits: 0 (100.0%)
.drv files: 0 (100.0%)
Scheme files: 0 (100.0%)
Remote procedure call summary: 0 RPCs
real 0m7.951s
user 0m2.191s
sys 0m0.240s
Note that nothing is built. This is merely to compute already
existing derivations. Computing the same derivations through an
inferior Guix takes about twice as long.
I’ll note that in the inferior case there are no
“add-data-to-store” calls compared to 2958 calls in the direct
case. I don’t know what to make of this. Is that information
lost as we cross over to the inferior Guix…? Or are there really
different / fewer RPCs?
Things look similar when we actually instantiate the manifest:
Toggle snippet (100 lines)
$ [env] time INFERIOR=n guix package -m manifest-test.scm -p
/tmp/foo
The following packages will be installed:
bash-minimal 5.0.16
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-minimal 4.0.4
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
nothing to be done
Store object cache:
fresh caches: 2
lookups: 41381
hits: 40249 (97.3%)
cache size: 1131 entries
'add-data-to-store' cache:
lookups: 6083
hits: 2950 (48.5%)
.drv files: 3407 (56.0%)
Scheme files: 2659 (43.7%)
Remote procedure call summary: 3897 RPCs
built-in-builders ... 1
add-to-store/tree ... 22
add-to-store ... 178
query-references ... 563
add-text-to-store ... 3133
real 0m12.697s
user 0m15.873s
sys 0m0.197s
$ [env] time INFERIOR=y guix package -m manifest-test.scm -p
/tmp/foo
The following packages will be installed:
bash-minimal 5.0.16
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-minimal 4.0.4
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
nothing to be done
Store object cache:
fresh caches: 2
lookups: 27162
hits: 26425 (97.3%)
cache size: 736 entries
'add-data-to-store' cache:
lookups: 887
hits: 52 (5.9%)
.drv files: 550 (62.0%)
Scheme files: 331 (37.3%)
Remote procedure call summary: 1011 RPCs
built-in-builders ... 1
add-to-store/tree ... 11
query-references ... 51
add-to-store ... 113
add-text-to-store ... 835
real 0m19.504s
user 0m4.014s
sys 0m0.411s
The first case with 12 seconds reproduces bug #48005. The second
case (going through the inferior) is much slower with over 19
seconds; if we squint this is also close to twice the amount of
time compared to the “direct” computation.
--
Ricardo