Hi all,
I'm trying to find out whether this is a known problem or just me
before I
file anything, so I'm asking here first -- with data.
After a `guix pull` in early July my `guix home reconfigure` went
from
roughly 6s real / 10s user to ~11s real / ~32s user, with nothing
new to
build. I chased it down carefully, and it is *not* my
configuration, not
modularisation, not `-L` vs. channels, and not `GUIX_PACKAGE_PATH`
-- it is
the guix core itself getting more expensive to *evaluate*.
Swapping only the guix core via `guix time-machine` (same config,
same
machine, `guix home build`, 0 derivations built, warm run):
package count guix 7e93e39 (Apr 12) guix cc4bea9
(Jul 06) factor
---------------------- ---------------------
--------------------- ------
42 (repro below) ~5.3s user ~10.9s
user ~2.0x
205 (my real home cfg) ~10.1s user ~32.6s
user ~3.2x
All runs build/download nothing -- pure evaluation ("Computing
Guix
derivation"). `user >> real` throughout, i.e. CPU/GC-bound across
the 16
threads here.
Self-contained reproducer (no third-party channels), a
home-environment
whose only cost is resolving public package specifications:
;; repro-home.scm
(use-modules (gnu home) (gnu packages))
(home-environment
(packages
(specifications->packages
(list
"emacs" "vim" "git" "tmux" "htop" "tree" "curl" "wget"
"rsync"
"openssh" "gnupg" "ripgrep" "fzf" "jq" "python" "node"
"gcc-toolchain"
"make" "cmake" "gdb" "clang" "rust" "go" "ffmpeg"
"imagemagick"
"graphviz" "inkscape" "gimp" "vlc" "mpv" "foot" "rofi"
"qemu"
"wireguard-tools" "ansible" "sqlite" "postgresql" "nginx"
"coreutils" "sed" "gawk" "grep"))))
Measured with a channels.scm that pins only guix (no other
channels), warm
run (first run populates the store, second is timed):
time guix time-machine -C channels-<commit>.scm -- home build
repro-home.scm >/dev/null
Coarse bisect over guix master with that 42-package reproducer
(user CPU
seconds, every run built 0 derivations):
date commit user
------- -------- -------
Apr 12 7e93e39 5.28s
Apr 30 98c4a00 5.29s
May 19 5f42ab7 7.48s <- step 1
Jun 09 fdb0ad0 7.99s
Jun 24 db5c934 11.16s <- step 2
Jul 06 cc4bea9 10.89s
So it's not a single commit: the slowdown arrives in (at least)
two steps,
roughly late-Apr..mid-May and early..late-June, flat in between
and after.
It also scales super-linearly with the number of packages resolved
-- the
Apr->Jul factor grows from ~1.4x at 10 packages to ~3.2x at
205. That
matches a quadratic cost in macro expansion /
`define-record-type*` (many
small `let`s), which is where I'd expect the time to go.
One more clue: across the pull the on-disk Guile object-code cache
switched
from ~/.cache/guile/ccache/3.0-LE-8-4.6 to 3.0-LE-8-4.7, i.e. the
bundled
Guile bytecode version changed in this window -- so a Guile change
may be
involved rather than (only) a guix-side one.
My questions to the list:
1. Is anyone else seeing reconfigure/pull evaluation get
noticeably slower
over the last few months? Can you reproduce the package-count
scaling
with the snippet above?
2. Is there already an issue tracking this? Codeberg #8985
("Interpreting
package modules is slow", psyntax:search /
define-record-type* / heavy
GC) looks like it could share the same root cause, but it's
framed as a
steady-state cost around `guix pull`, not a `guix home`
regression, so
I'm not sure it's the same thing.
3. If it's not #8985 and not otherwise known, where should this
go -- a
comment on #8985, or a new issue?
Happy to run further measurements (finer bisect down to the exact
commits,
gcprof on a specific commit, Guile-version mapping per step).
Thanks,
Alexander
