bug#43079: guix ignores available substitutes

bug#43079: guix ignores available substitutes

[Jonathan Brielmaier]

I have a laptop and a desktop which are using the same system
configuration apart from hostname, uuid of hard disk, bootloader (EFI vs
grub) and mount-points.

So I expect that those systems behave very similar but they don't. Doing
a system reconfigure on the desktop works as expected, on the laptop
not. It doesn't fetch substitutes and therefore wants to build hundreds
of packages/derivations.

I can connect from my laptop to ci.guix.gnu.org and fetching substitutes
via wget works.

guix version
============
guix describe @ laptop
  guix eb622c6
    Repository-URL: https://git.savannah.gnu.org/git/guix.git
    Branch: master
    Commit: eb622c6b128024179494253510bebe8bcacb8e6f

But I found a strange thing.

1. step: try to "build" a package which should fetch just the
substitutes -> it doesn't work
================================================================
guix@laptop $ guix build calibre --dry-run
Folgende Ableitungen würden erstellt:
   /gnu/store/djli9lxajn8r8d8hq6r4848yj6p79k3j-calibre-4.18.0.drv
   /gnu/store/28gk4rylv0hsrswybp6biaxznwa81avm-python2-html5lib-1.0.1.drv
   /gnu/store/5507fjclaf39ad92wj9pv53zqbfzzqil-python2-six-1.14.0.drv

/gnu/store/0gf3jrj490sljsar5ldp1609ng68bpgr-python2-pluggy-bootstrap-0.13.1.drv

/gnu/store/j37a17a6bv1r6j0bm1hpy5qph9mcyy2w-python2-importlib-metadata-bootstrap-1.5.0.drv
   /gnu/store/mf69d2vgccqmgyrd0nq9nf545sjrxzy4-python2-typing-3.7.4.3.drv
   /gnu/store/z836bndwjprjz6hi6zcd7b0bl0hd140l-typing-3.7.4.3.tar.gz.drv

/gnu/store/zwl80hfc4srhw6yjmfj1v048rx2dxk52-python2-importlib-resources-bootstrap-1.0.2.drv

/gnu/store/ac07fdv2zb5fbcgb6hnfzdyb3vs98pzi-python2-pytest-bootstrap-4.6.9.drv
   /gnu/store/kv1g1y8fz650h5wnj4wjiw0ja30z1di3-six-1.14.0.tar.gz.drv

/gnu/store/p3q7k35ws1zpf28zv6n8mlk8jpy341da-python2-webencodings-0.5.1.drv
   /gnu/store/2hm00zq5y23inwqh5lgg7zhyic1nj07h-python2-funcsigs-1.0.2.drv
   /gnu/store/16a8hm8dhz6xfvyv52q2zzlmcfai949s-python2-traceback2-1.4.0.drv
   /gnu/store/aayb3j040ykg8rp9igwcd22816871gvz-traceback2-1.4.0.tar.gz.drv
   /gnu/store/dwrfcmgh3x8aw1h95385m6jx7pvl2n3d-python2-unittest2-1.1.0.drv
   /gnu/store/kd27bgwpmbcw7p5cd7a52cz91112xr18-unittest2-1.1.0.tar.xz.drv
   /gnu/store/572fw1qqprqrjvkx3c1hrq9kgawc6b0w-unittest2-1.1.0.tar.gz.drv

/gnu/store/c49sxyw60z2wym3xx64v3c2k98ddfvcj-python2-importlib-metadata-1.5.0.drv

/gnu/store/hyzp3l78cwlchmf75qxryfv0wg0xhx2p-python2-importlib-resources-1.0.2.drv
   /gnu/store/xgqpc3sprszggp6i3hgiag5xlg02jskl-python2-pathlib2-2.3.5.drv

/gnu/store/klj6vgh9jqwcbw3xx7fmcf0ga2jialhy-python2-contextlib2-0.6.0.post1.drv
   /gnu/store/yc3a0bldf937hwkvwmv9r37b5zlmyq4i-python2-zipp-1.0.0.drv
   /gnu/store/bvf121wfwkp7j4ll73mkk0xdxk6z5xwm-zipp-1.0.0.tar.gz.drv
   /gnu/store/dp5wrnylljpjxiiw8rhhxdk0k2s0qfqj-python2-pytest-4.6.9.drv
   /gnu/store/q3vxw8j5b6ilga6n5irxvlrff6ayjl5d-python2-mock-3.0.5.drv
   /gnu/store/rdwixhs7x4kgr7ib4ag7z81n3gcswg28-python2-pluggy-0.13.1.drv
   /gnu/store/xw2hnqjgwb0nx1v76isv39mp994shz7j-webencodings-0.5.1.tar.gz.drv

/gnu/store/43n3hn59ap7nzks59a11p1vahsf9wqrh-python2-html2text-2019.8.11.drv
   /gnu/store/61lb2rbvdwpzxxm23qk6vvqsk9mcchgj-python2-pillow-6.2.1.drv
   /gnu/store/6474sh8h3w5d0hgd4q2xx90gkgqwd0l5-python2-dateutil-2.8.1.drv
   /gnu/store/8ddh4irmpqvr1vb6ai7b6b04mbgdm7x8-python2-pytest-cov-2.8.1.drv
   /gnu/store/73zvgpxg2wga2xrkg8mv8f65p7rv846k-python2-odfpy-1.4.1.drv
   /gnu/store/868g8grxqv6yyb1gfsib0i9ygfh3rkic-python2-cssselect-1.1.0.drv
   /gnu/store/azpwlsxcfqbh1y846f98dzg98vdyf8q1-python2-chardet-3.0.4.drv
   /gnu/store/bf7psbq535awadm5ydc1n2wlnkxl4rm4-python2-msgpack-1.0.0.drv
   /gnu/store/ci254iy86210q41p72cdqj53hxmakrwq-python2-flake8-3.8.3.drv
   /gnu/store/s44mm4nh0hhc8zkw77zlxh84vnfs676p-python2-mccabe-0.6.1.drv
   /gnu/store/y5bw36xvkiykcza4b1bhv6s4pwxiqszy-python2-pycodestyle-2.6.0.drv
   /gnu/store/gvycs2vxdapxcd7jmn9xh6g9rlxsxv0p-python2-mechanize-0.4.5.drv

/gnu/store/p3i2n5h9rsdclrn6p0v24d19g43ljd00-python2-pyqtwebengine-5.14.0.drv
   /gnu/store/w2l6gy7jj14fcfaaa514199nfbgxabdc-qtwebengine-5.14.2.drv
   /gnu/store/rwd337f70yppg243hp418nlw0dmmcvif-js-mathjax-2.7.2.drv
   /gnu/store/58yxhzfyf9lhab6d5ja91mj3ak42aq00-uglify-js-0.1-1.429c5e1d8.drv

/gnu/store/fqbfj9flm0r51bcalz8z8jjrj896rqnj-sbcl-cl-uglify-js-0.1-1.429c5e1d8.drv
   /gnu/store/7ga1f87f8d1qw0szipaa4yky6qy9fwdi-sbcl-parse-number-1.7.drv
   /gnu/store/rsqsp69vjkfvkljbkm6n0jcw4d5d881b-sbcl-2.0.7.drv
   /gnu/store/gq8g27c0x9ppaxfghbjgjxzm60rxsh1n-sbcl-2.0.7-source.tar.bz2.drv
   /gnu/store/b5b90k32mdaivc8b15n6091v09r77r74-sbcl-iterate-1.5.drv

/gnu/store/pfvsajb34n3yxxm7s1hz5mlqs7lfkiia-sbcl-rt-1990.12.19-1.a6a7503.drv
   /gnu/store/c2jcrvsnkxr6fhpzkrvz5ibjl37jhj6p-sbcl-cl-ppcre-2.1.1.drv
   /gnu/store/wrph6hlxpsjxs8x4wz1nkl075xky8c16-sbcl-flexi-streams-1.0.18.drv

/gnu/store/ifpc2kw8mq83j7klvw7mh1q23bxq30vc-sbcl-trivial-gray-streams-0.0.0-1.ebd59b1.drv

/gnu/store/cvsqd5iiyj2m0q9lv53qnz6sd2lcwn9l-sbcl-cl-ppcre-unicode-2.1.1.drv
   /gnu/store/2v3yf2h4w0lds9gpm4b70sk9irldmw2q-sbcl-cl-unicode-0.1.6.drv

/gnu/store/l4gxbwfqrij5mqv9hfxixq0mvgrhg48k-sbcl-cl-unicode-base-0.1.6.drv

/gnu/store/xfbf58b2nkpqrjqy5jnvqsms625ca8hw-sbcl-parse-js-0.0.0-1.fbadc6029.drv



2. step: try the same on a different system
===========================================
jonathan@remote-system ~$ guix build calibre
The following derivation will be built:
   /gnu/store/djli9lxajn8r8d8hq6r4848yj6p79k3j-calibre-4.18.0.drv
89.0 MB will be downloaded:
   /gnu/store/pwi4fbzxp6k30575j6yd7r93k1hly5d2-python2-dukpy-0.3
 [...]
   /gnu/store/5w29w5glfv7c9zzc145ml39zsa12kabq-python2-funcsigs-1.0.2
   /gnu/store/mkyzka766w2snbl4zd9j62p2w104zm3l-python2-html2text-2019.8.11
   /gnu/store/asvwznls5cm91mxq24rwfv4jixf6rm31-python2-html5lib-1.0.1
substituting
/gnu/store/2kssjypd0j7lhc246jj86kyyjlkqq6rl-calibre-4.18.0.tar.xz...
downloading from
https://ci.guix.gnu.org/nar/2kssjypd0j7lhc246jj86kyyjlkqq6rl-calibre-4.18.0.tar.xz
...
 calibre-4.18.0.tar.xz  35.7MiB
 15.3MiB/s 00:02 [##################] 100.0%

substituting /gnu/store/bsqiibz50k34jq4d93xag6gjj5gvn7y4-js-mathjax-2.7.2...
downloading from
https://ci.guix.gnu.org/nar/lzip/bsqiibz50k34jq4d93xag6gjj5gvn7y4-js-mathjax-2.7.2
...
 js-mathjax-2.7.2  2.6MiB
  1.9MiB/s 00:01 [##################] 100.0%

substituting /gnu/store/vkk19ky171b06jca0nfqm5s0zy5nc5bd-optipng-0.7.7...
downloading from
https://ci.guix.gnu.org/nar/lzip/vkk19ky171b06jca0nfqm5s0zy5nc5bd-optipng-0.7.7
...
 optipng-0.7.7  41KiB
  1.4MiB/s 00:00 [##################] 100.0%

substituting /gnu/store/g4ixn1vhxazn44dzbsw3c37kxlfhjvx3-podofo-0.9.6...
downloading from
https://ci.guix.gnu.org/nar/lzip/g4ixn1vhxazn44dzbsw3c37kxlfhjvx3-podofo-0.9.6
...
 podofo-0.9.6  1.2MiB
  2.6MiB/s 00:00 [##################] 100.0%

substituting
/gnu/store/9nq9dkjrfsnyipmqa516y02xgj1f5hm6-python2-appdirs-1.4.3...
downloading from
https://ci.guix.gnu.org/nar/lzip/9nq9dkjrfsnyipmqa516y02xgj1f5hm6-python2-appdirs-1.4.3
...
 python2-appdirs-1.4.3  11KiB

3. step: remove substitute cache on laptop
==========================================
sudo rm -rf /var/guix/substitute/cache/

4. step: rerun step 1 and you can see that it now has substitutes
=================================================================
guix@laptop ~$ guix build calibre --dry-run
substitute: Liste der Substitute von „https://ci.guix.gnu.org“ wird
aktualisiert … 100.0%
substitute: Liste der Substitute von „https://mirror.brielmaier.net“
wird aktualisiert … 100.0%
Folgende Ableitung würde erstellt:
   /gnu/store/djli9lxajn8r8d8hq6r4848yj6p79k3j-calibre-4.18.0.drv
42,2 MB würden heruntergeladen:
   /gnu/store/bsqiibz50k34jq4d93xag6gjj5gvn7y4-js-mathjax-2.7.2
   /gnu/store/xjjsr0iz35njjkzbvqqv6ywnnsi96rdj-python2-webencodings-0.5.1
   /gnu/store/gywcnby5yr7772cjbmf4vhvshp3s0is1-qtwebengine-5.14.2
   /gnu/store/2531vz02jggmkmrz3zqj60287kz3nxi4-python2-pyqtwebengine-5.14.0
   /gnu/store/wsy8k18ml97xld5j3d1v3c6aw50x8nq6-python2-mechanize-0.4.5
   /gnu/store/8h7b4bvn1zcxzpqih0wy6xlihsm3z3is-python2-pycodestyle-2.6.0
   /gnu/store/28hqf5rhn5cbsygrm7mdpy4jypyd95jc-python2-mccabe-0.6.1
   /gnu/store/fbkja9gaxkvlp493vq0m1iisxnbpbmi7-python2-flake8-3.8.3
   /gnu/store/1ycfggk9fjasik1k4w34fj72g0lwa61j-python2-msgpack-1.0.0
   /gnu/store/pxrh8ps7civz1iafj8klqjzk2jisqy78-python2-chardet-3.0.4
   /gnu/store/4q0p868nnwc3rkmms2lh9yk6gby87w7w-python2-cssselect-1.1.0
   /gnu/store/6nf0madn8ksciwdfgqh8vgj7x83520ma-python2-odfpy-1.4.1
   /gnu/store/10w4shanr7rpbg5mi124bva4s506gh2g-python2-dateutil-2.8.1
   /gnu/store/k9s2yn2khrlghav5asc813gw9f567n20-python2-pillow-6.2.1
   /gnu/store/xlj3v9vx1ar1cz11cgq054kc5c312wvi-python2-zipp-1.0.0
   /gnu/store/0hgxna28mdzspl5xzxxmg118qhbfhk5s-python2-pathlib2-2.3.5
   /gnu/store/xqwbsdfbcli5w0w4ns6ix4v9206a02w6-python2-pluggy-0.13.1
   /gnu/store/b6pxdvysqslmidp44pqs0xwsacc1a238-python2-mock-3.0.5

/gnu/store/lp0pn7n5knnbax6vjrfr7nyvls2hcga9-python2-contextlib2-0.6.0.post1

/gnu/store/3yvp9i6vv0bf7gc5bj9g1c83nh69rxzc-python2-importlib-resources-1.0.2

/gnu/store/n1xrr7vyaxp0048l84qhk44mak099khl-python2-importlib-resources-bootstrap-1.0.2
   /gnu/store/7vhmdrjny5cw9pjki8lvd67fgjw0a670-python2-typing-3.7.4.3

/gnu/store/0spblvb6p55mxyd869zf5nrwzpip1xzp-python2-importlib-metadata-bootstrap-1.5.0

/gnu/store/yfskq5hd6rsnxch7jhdrlwz9jc8gdb66-python2-pytest-bootstrap-4.6.9

/gnu/store/wgw4l07353rzb6nzvfngfl1axdf87jzy-python2-pluggy-bootstrap-0.13.1
   /gnu/store/xczivh749npq3lni1qflgfsz6c728qf3-python2-pytest-4.6.9

/gnu/store/ds665rg4n8wsick1hry5w0gdw5l10lsh-python2-importlib-metadata-1.5.0
   /gnu/store/lr88qfwz3lfwy2ygqbmnhc193d7m2k7l-python2-six-1.14.0
   /gnu/store/5w29w5glfv7c9zzc145ml39zsa12kabq-python2-funcsigs-1.0.2
   /gnu/store/mkyzka766w2snbl4zd9j62p2w104zm3l-python2-html2text-2019.8.11
   /gnu/store/asvwznls5cm91mxq24rwfv4jixf6rm31-python2-html5lib-1.0.1

========================================================================

Tobias provided me some nginx logs from ci.guix.gnu.org so here is some
further analysis:

guix@laptop $ guix build --dry-run inkscape
Folgende Ableitungen würden erstellt:
   /gnu/store/i1sh5hzlzxzgzbdl3jb8wgnn9hr912wn-inkscape-1.0.drv
   /gnu/store/1mzsr5z2qnrlr57gdv5mv7bhm1yg88z2-gtkspell3-3.0.10.drv
   /gnu/store/07sff3s4ckc81j2lxip0pcyikfqbqs6v-gtkspell3-3.0.10.tar.xz.drv

Where the inkscape drv derives to
/gnu/store/wp4v7qsyjngxggncz34gaidb3yqcqy3l-inkscape-1.0

https.access.log:XXX.XXX.XXX.XXX - - [28/Aug/2020:00:48:08 +0200] "GET
/wp4v7qsyjngxggncz34gaidb3yqcqy3l.narinfo HTTP/1.1" 200 3336 "-" "GNU Guile"

It's also in the cache:
-rw------- 1 root root 3451 28. Aug 01:18
/var/guix/substitute/cache/4refhwxbjmeua2kwg2nmzhv4dg4d3dorpjefq7kiciw2pfhaf26a/wp4v7qsyjngxggncz34gaidb3yqcqy3l

(narinfo (version 2) (cache-uri "https://ci.guix.gnu.org") (date
1598570321) (ttl 7776000) (value "StorePath:
/gnu/store/wp4v7qsyjngxggncz34gaidb3yqcqy3l-inkscape-1.0\nURL:
nar/gzip/wp4v7qsyjngxggncz34gaidb3yqcqy3l-inkscape-1.0\nCompression:
gzip\nFileSize: 40257671\nURL:
nar/lzip/wp4v7qsyjngxggncz34gaidb3yqcqy3l-inkscape-1.0\nCompression:
lzip\nFileSize: 16181383\nNarHash:
sha256:1i44f21lnxmajdir2jqvg9d28518fipbv3jq4cpf6wmmk1xgqr8m\nNarSize:
164233984\nReferences: 01b4w3m6mp55y531kyi1g8shh722kwqm-gcc-7.5.0-lib
07m4rm6cwdj2m5mzh6n19wldn1if3h0q-glibmm-2.62.0
[...]
zrmhnj3pwchn2msphgnwzwd3q89m46rn-aspell-0.60.8\nSystem:
x86_64-linux\nDeriver:
s8f2r8md9sjmmgnac1k5y881d6a84c90-inkscape-1.0.drv\nSignature:
1;berlin.guix.gnu.org;LONG_KEY\n"))

I have no idea what is wrong here...

bug#43079: guix ignores available substitutes

[Tobias Geerinckx-Rice via Bug reports for GNU Guix]

[-- Attachment #1: Type: text/plain, Size: 225 bytes --]

Jonathan Brielmaier 写道：
> Tobias provided me some nginx logs from ci.guix.gnu.org

...only a list of requests from Jonathan's IP during the past 
hour, for anyone wondering or worried :-)

Kind regards,

T G-R

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 227 bytes --]

bug#43079: guix ignores available substitutes

[Ludovic Courtès]

Hallo!

Jonathan Brielmaier <jonathan.brielmaier@web.de> skribis:

> Tobias provided me some nginx logs from ci.guix.gnu.org so here is some
> further analysis:
>
> guix@laptop $ guix build --dry-run inkscape
> Folgende Ableitungen würden erstellt:
>    /gnu/store/i1sh5hzlzxzgzbdl3jb8wgnn9hr912wn-inkscape-1.0.drv
>    /gnu/store/1mzsr5z2qnrlr57gdv5mv7bhm1yg88z2-gtkspell3-3.0.10.drv
>    /gnu/store/07sff3s4ckc81j2lxip0pcyikfqbqs6v-gtkspell3-3.0.10.tar.xz.drv
>
> Where the inkscape drv derives to
> /gnu/store/wp4v7qsyjngxggncz34gaidb3yqcqy3l-inkscape-1.0
>
> https.access.log:XXX.XXX.XXX.XXX - - [28/Aug/2020:00:48:08 +0200] "GET
> /wp4v7qsyjngxggncz34gaidb3yqcqy3l.narinfo HTTP/1.1" 200 3336 "-" "GNU Guile"
>
> It's also in the cache:
> -rw------- 1 root root 3451 28. Aug 01:18
> /var/guix/substitute/cache/4refhwxbjmeua2kwg2nmzhv4dg4d3dorpjefq7kiciw2pfhaf26a/wp4v7qsyjngxggncz34gaidb3yqcqy3l
>
> (narinfo (version 2) (cache-uri "https://ci.guix.gnu.org") (date
> 1598570321) (ttl 7776000) (value "StorePath:
> /gnu/store/wp4v7qsyjngxggncz34gaidb3yqcqy3l-inkscape-1.0\nURL:
> nar/gzip/wp4v7qsyjngxggncz34gaidb3yqcqy3l-inkscape-1.0\nCompression:
> gzip\nFileSize: 40257671\nURL:
> nar/lzip/wp4v7qsyjngxggncz34gaidb3yqcqy3l-inkscape-1.0\nCompression:
> lzip\nFileSize: 16181383\nNarHash:
> sha256:1i44f21lnxmajdir2jqvg9d28518fipbv3jq4cpf6wmmk1xgqr8m\nNarSize:
> 164233984\nReferences: 01b4w3m6mp55y531kyi1g8shh722kwqm-gcc-7.5.0-lib
> 07m4rm6cwdj2m5mzh6n19wldn1if3h0q-glibmm-2.62.0
> [...]
> zrmhnj3pwchn2msphgnwzwd3q89m46rn-aspell-0.60.8\nSystem:
> x86_64-linux\nDeriver:
> s8f2r8md9sjmmgnac1k5y881d6a84c90-inkscape-1.0.drv\nSignature:
> 1;berlin.guix.gnu.org;LONG_KEY\n"))
>
> I have no idea what is wrong here...

I’m not sure what conclusions you’re drawing here?  :-)

As you found, each entry in /var/guix/substitute/cache has a TTL,
including for negative lookups.  This is why one can observe different
behaviors on different machines: one machine can think the substitute is
unavailable (cached negative entry not yet expired), while the other got
a positive lookup soon after the substitute had been “baked” on the
server.

TTLs vary.  For successful lookups, this is usually a long TTL (see
‘guix publish --ttl’).  For negative lookups, there are two cases: a
1h-or-so TTL for “absolute no”, and a 5mn TTL for
“substitute-being-baked no”.

On top of that, nginx on ci.guix.gnu.org might perform extra caching,
though we’d need to check the config.

HTH!

Ludo’.

bug#43079: guix ignores available substitutes

[Jonathan Brielmaier]

On 28.08.20 16:23, Ludovic Courtès wrote:
> I’m not sure what conclusions you’re drawing here?  :-)

That my laptop doesn't really get substitutes...

> As you found, each entry in /var/guix/substitute/cache has a TTL,
> including for negative lookups.  This is why one can observe different
> behaviors on different machines: one machine can think the substitute is
> unavailable (cached negative entry not yet expired), while the other got
> a positive lookup soon after the substitute had been “baked” on the
> server.
>
> TTLs vary.  For successful lookups, this is usually a long TTL (see
> ‘guix publish --ttl’).  For negative lookups, there are two cases: a
> 1h-or-so TTL for “absolute no”, and a 5mn TTL for
> “substitute-being-baked no”.

So my question is how I can influence/change that behaviour for my
client? Because the current situation on my laptop is awful. And if it
doesn't get better I will move away that system from Guix System...

bug#43079: guix ignores available substitutes

[Ludovic Courtès]

Hi Jonathan,

Jonathan Brielmaier <jonathan.brielmaier@web.de> skribis:

> On 28.08.20 16:23, Ludovic Courtès wrote:
>> I’m not sure what conclusions you’re drawing here?  :-)
>
> That my laptop doesn't really get substitutes...
>
>> As you found, each entry in /var/guix/substitute/cache has a TTL,
>> including for negative lookups.  This is why one can observe different
>> behaviors on different machines: one machine can think the substitute is
>> unavailable (cached negative entry not yet expired), while the other got
>> a positive lookup soon after the substitute had been “baked” on the
>> server.
>>
>> TTLs vary.  For successful lookups, this is usually a long TTL (see
>> ‘guix publish --ttl’).  For negative lookups, there are two cases: a
>> 1h-or-so TTL for “absolute no”, and a 5mn TTL for
>> “substitute-being-baked no”.
>
> So my question is how I can influence/change that behaviour for my
> client? Because the current situation on my laptop is awful. And if it
> doesn't get better I will move away that system from Guix System...

I understand and sympathize with your frustration.  The issue is that
the build farm has been lagging behind: some substitutes tend to not be
available quickly enough, and in some cases it’s particularly annoying
(icecat, libreoffice, you name it.)

Before running ‘guix upgrade’, you can try:

  guix weather $(guix package -I | cut -f1)

That’ll show you whether now is a good time to upgrade, or whether you
should wait a little longer to do that.

As you know, there’s work to improve the situation on the build farm
(and perhaps with the tools themselves), but until that happens, this is
what I’d recommend.

HTH!

Ludo’.