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

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

[Diego Nicola Barbato]

Hello Guix

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.

I run GuixSD (commit: ae81bf4f995466a4650e2756d2763b8a163d2f63) on an
x86-64 machine.

Greetings

Diego

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

[Ludovic Courtès]

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.

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.

If that happens again, I’d suggest capturing immediately the two cached
entries so we can see whether this explanation holds.

Thanks,
Ludo’.

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

[Diego Nicola Barbato]

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

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

[Ludovic Courtès]

Hi,

Diego Nicola Barbato <dnbarbato@posteo.de> skribis:

> 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.

I could reproduce it.  This is fixed by commit
5e5d6613a3837586ccab51cd988b44c7df99253b.

The story is quite surprising: the ‘font-tex-gyre’ packages uses
‘url-fetch/zipbomb’.  ‘url-fetch/zipbomb’ refers to unzip to do its
job.  With grafts enabled, ‘url-fetch/zipbomb’ would use a grafted
unzip, leading to a different /gnu/store/…-tg-2.005otf.zip than when
grafts are disabled.

Consequently, the base lilypond.drv would already depend on whether or
not grafts are enabled.  When grafts are enabled, you would end up
having to build a lilypond that’s different from what “guix build
lilypond --no-grafts” builds because of this.

I hope this explanation makes any sense but anyway, it’s fixed now.  :-)

Thanks,
Ludo’.