bug#36509: guix pull: too many substitute updates, or bad log messages

[Ludovic Courtès]

Hi,

Robert Vollmert <address@hidden> skribis:

> When running `guix pull`, output like the following is common
> for me:
>
> $ guix pull
> Updating channel 'puzzlink' from Git repository at '/home/rob/guix-puzzlink'…
> […]
> Building from these channels:
>   guix      https://github.com/robx/guix.git  11f68b3
> […]
> Computing Guix derivation for 'x86_64-linux'... |
> The following derivations will be built:
>    /gnu/store/ym0l8rvnh3aa3qv8g3xgh1mszbhww8c2-elm.drv
> […]
>    /gnu/store/dcxwfh37bn8r3h8s9w7wfq8yhzynqxx5-profile.drv
> The following profile hooks will be built:
>    /gnu/store/biw1n2a956skpaa4m7rmka6j8h1clhmv-guix-package-cache.drv
> […]
>    /gnu/store/kxrkynck33ypwyy09ypi2qm7737fsw28-fonts-dir.drv
> substitute: updating substitutes from 'https://ci.guix.gnu.org'... 100.0%
> substitute: updating substitutes from 'https://ci.guix.gnu.org'... 100.0%
> substitute: updating substitutes from 'https://ci.guix.gnu.org'... 100.0%
> substitute: updating substitutes from 'https://ci.guix.gnu.org'... 100.0%
> substitute: updating substitutes from 'https://ci.guix.gnu.org'... 100.0%
> substitute: updating substitutes from 'https://ci.guix.gnu.org'... 100.0%
> substitute: updating substitutes from 'https://ci.guix.gnu.org'... 100.0%
> substitute: updating substitutes from 'https://ci.guix.gnu.org'... 100.0%
> substitute: updating substitutes from 'https://ci.guix.gnu.org'... 100.0%
> substitute: updating substitutes from 'https://ci.guix.gnu.org'... 100.0%
> substitute: updating substitutes from 'https://ci.guix.gnu.org'... 100.0%
> substitute: updating substitutes from 'https://ci.guix.gnu.org'... 100.0%
> substitute: updating substitutes from 'https://ci.guix.gnu.org'... 100.0%
> substitute: updating substitutes from 'https://ci.guix.gnu.org'... 100.0%
> substitute: updating substitutes from 'https://ci.guix.gnu.org'... 100.0%
> substitute: updating substitutes from 'https://ci.guix.gnu.org'... 100.0%
> substitute: updating substitutes from 'https://ci.guix.gnu.org'... 100.0%
> substitute: updating substitutes from 'https://ci.guix.gnu.org'... 100.0%
> substitute: updating substitutes from 'https://ci.guix.gnu.org'... 100.0%
> building /gnu/store/wxfi8mdp11l5k4ngkbsy9apcg9h74jfk-guix-system.drv…

I believe this is fixed by 9b9b753529db1c7a8c4628cc255e358703c15618.

The story here is that we were calling ‘show-what-to-build’ with
#:use-substitutes #f.  Thus, Guix would not try to see which substitutes
are available (and it’d report that everything must be built.)

But right after that, we’d build the profile with substitutes enabled,
and at that point it would have to fetch substitute info (“narinfos”)
for each of these, more or less one at a time (because ‘guix substitute
--substitute’ is called once for each store item.)

IOW, ‘show-what-to-build’ warms the substitute info cache as a
side-effect, and that cache warm-up was not happening here.

Thanks,
Ludo’.