bug#31085: Unexpected behaviour when running `guix build lilypond'

[Diego Nicola Barbato <dnbarbato@posteo.de>]

Hello

ludo@gnu.org (Ludovic Courtès) writes:

> Hello,
>
> Diego Nicola Barbato <dnbarbato@posteo.de> skribis:
>
>> I have experienced some unexpected behaviour when running `guix build
>> lilypond':
>> After verifying that there was a substitute available with `guix weather
>> -m m.scm' (Where m.scm evaluates to a manifest containing only lilypond)
>> I ran `guix build lilypond --dry-run' which claimed that a substitute
>> would be downloaded.  I then ran `guix build lilypond' which proceeded
>> to build lilypond from source (instead of downloading the substitute).
>>
>> Upon explaining this on IRC it was suggested that I try running `guix
>> build --no-grafts lilypond' (which actually downloaded the substitute)
>> then deleting the locally built lilypond with `guix gc --delete
>> /gnu/store/...' and finally running `guix build lilypond' again (which,
>> this time, grafted the substituted lilypond instead of building it from
>> source again).  While this fixed the issue I was told that this
>> behaviour was indeed unexpected.
>
> We’d have to see if this is still reproducible, but I have a plausible
> explanation.

I can consistently reproduce this in a VM with the following steps:

First I run:

 $ qemu-system-x86_64 -enable-kvm -snapshot -m 4G $(guix system vm-image bare-bones.scm --image-size=8G)

(Where bare-bones.scm is the bare-bones.tmpl after replacing /dev/sdX
with /dev/sda.)

Then after logging in as root:

 # guix pull --commit=872bda5de52a8f0514230ebc4e9680aab74f509a
 # guix build --dry-run lilypond

Which returns:

52.1 MB would be downloaded:
   /gnu/store/0amx7bcbs518lkqwfh2azmqrp2yqib0g-lilypond-2.19.80
   /gnu/store/7b5ykfl6jbrdl8j7xp630fga4as3234z-ghostscript-9.22
   /gnu/store/j4vj7h3wyb532g2j0axzjj43z2a0dg81-python-2.7.14
   /gnu/store/k2ak44m0miind785x22mmpbcwi0mq7hq-freetype-2.8.1
   /gnu/store/mkhfqx7m7pniyic0kh0lnafmajymn4dr-guile-1.8.8
   /gnu/store/pwbx5fhjrq9crr1c0d2x08ch0l6vr3cv-pango-1.40.14
   /gnu/store/qm8ri32n0rkh749v3jb3x8s8ksjl7yd3-fontconfig-2.12.6
   /gnu/store/sm37m59gq3smxxz8gs4jikn50qg0g7xh-glib-2.54.2

Then:

 # guix build lilypond

Which, after downloading the dependencies, starts to build lilypond from
source.

> Substitute info is cached locally.  guix-daemon caches it under
> /var/guix/substitute/cache, but ‘guix weather’ caches it under
> ~/.cache/guix/substitute (that’s because it needs fine-grain control
> over substitute info and thus cannot simply use the
> ‘substitutable-path-info’ daemon RPC.)  Each cached entry has a
> time-to-live (TTL).
>
> What could have happened is that /var/guix/substitute/ had a
> not-expired-yet entry saying that there’s no substitute for LilyPond
> (which is why ‘guix build’ ended up building from source), whereas ‘guix
> weather’ was run at a point when there was a substitute.

The unexpected behaviour was that `guix build lilypond' started to build
lilypond from source after `guix build --dry-run lilypond' had claimed
that nothing would be built and that it would download a substitute.  I
assume that `guix build --dry-run' is not affected by the substitute
info used by `guix weather'.  I only ran `guix weather' in order to
double check that there were indeed substitutes available (Sorry for the
red herring).

Greetings

Diego