Local caching behavior affected by network state

Local caching behavior affected by network state

[Leo Famulari]

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

I've noticed confusing behavior regarding the memoized cache, which
depends on the state of the network connection.

I have a built package in my store and I am connected to the internet:

$ ./pre-inst-env guix build gss
substitute: updating list of substitutes from 'https://example.com'... 100.0%
/gnu/store/ywh8cz5j63s8iwr2w2lzj3vyhqwqlhcz-gss-1.0.3

Then, I disable my network interface and run the command again:

$ ./pre-inst-env guix build gss
@ substituter-started /gnu/store/y9akh452n3p4w2v631nj0injx7y0d68x-mpc-1.0.3.tar.gz /gnu/store/6z7d9fpaph1yl1csfnnkrdv6jzr4simn-guix-0.13.0-2.de9d8f0/libexec/guix/substitute
Downloading https://mirror.hydra.gnu.org/guix/nar/y9akh452n3p4w2v631nj0injx7y0d68x-mpc-1.0.3.tar.gz...
guix substitute: error: host name lookup error: Temporary failure in name resolution
@ substituter-failed /gnu/store/y9akh452n3p4w2v631nj0injx7y0d68x-mpc-1.0.3.tar.gz 256 fetching path `/gnu/store/y9akh452n3p4w2v631nj0injx7y0d68x-mpc-1.0.3.tar.gz' failed with exit code 1
@ build-started /gnu/store/y4r20fnm9ba129r2ry6s2k1ss975dknd-gcc-5.4.0.tar.xz.drv - x86_64-linux /var/log/guix/drvs/y4//r20fnm9ba129r2ry6s2k1ss975dknd-gcc-5.4.0.tar.xz.drv.bz2
guix build: error: build failed: some substitutes for the outputs of derivation `/gnu/store/ikdvc8qn0bi57hn3ci72l5xlqyss96ys-mpc-1.0.3.tar.gz.drv' failed (usually happens due to networking issues); try `--fallback' to build derivation from source
$ ./pre-inst-env guix build gss --fallback
/gnu/store/ywh8cz5j63s8iwr2w2lzj3vyhqwqlhcz-gss-1.0.3

So, when I am offline, I have to use --fallback for the local cache to
work.

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

Re: Local caching behavior affected by network state

[Ricardo Wurmus]

Leo Famulari <leo@famulari.name> writes:

> I've noticed confusing behavior regarding the memoized cache, which
> depends on the state of the network connection.
[…]
> So, when I am offline, I have to use --fallback for the local cache to
> work.

I see this too, especially since the glibc graft, because all packages
are now grafted.  Here’s a package I have just built with “guix build
axoloti”.  Then I go offline and try to install it:

--8<---------------cut here---------------start------------->8---
guix package -i axoloti
[…]
The following package will be upgraded:
   axoloti	1.0.12 → 1.0.12	/gnu/store/v74k2b6mivsmz1q00slpl9dxjlg9qa3r-axoloti-1.0.12


Starting download of /gnu/store/jjprvyxxwxy27y1djs20wg04sljjaww4-glibc-2.25.tar.xz
From http://ftpmirror.gnu.org/glibc/glibc-2.25.tar.xz...
ERROR: In procedure getaddrinfo: Name or service not known

Starting download of /gnu/store/jjprvyxxwxy27y1djs20wg04sljjaww4-glibc-2.25.tar.xz
From ftp://ftp.cs.tu-berlin.de/pub/gnu/glibc/glibc-2.25.tar.xz...
ERROR: In procedure getaddrinfo: Name or service not known

Starting download of /gnu/store/jjprvyxxwxy27y1djs20wg04sljjaww4-glibc-2.25.tar.xz
From ftp://ftp.funet.fi/pub/mirrors/ftp.gnu.org/gnu/glibc/glibc-2.25.tar.xz...
ERROR: In procedure getaddrinfo: Name or service not known

Starting download of /gnu/store/jjprvyxxwxy27y1djs20wg04sljjaww4-glibc-2.25.tar.xz
From http://ftp.gnu.org/pub/gnu/glibc/glibc-2.25.tar.xz...
ERROR: In procedure getaddrinfo: Name or service not known

Starting download of /gnu/store/jjprvyxxwxy27y1djs20wg04sljjaww4-glibc-2.25.tar.xz
From http://mirror.hydra.gnu.org/file/glibc-2.25.tar.xz/sha256/1813dzkgw6v8q8q1m4v96yfis7vjqc9pslqib6j9mrwh6fxxjyq6...
ERROR: In procedure getaddrinfo: Name or service not known

Starting download of /gnu/store/jjprvyxxwxy27y1djs20wg04sljjaww4-glibc-2.25.tar.xz
From http://tarballs.nixos.org/sha256/1813dzkgw6v8q8q1m4v96yfis7vjqc9pslqib6j9mrwh6fxxjyq6...
ERROR: In procedure getaddrinfo: Name or service not known
failed to download "/gnu/store/jjprvyxxwxy27y1djs20wg04sljjaww4-glibc-2.25.tar.xz" from "mirror://gnu/glibc/glibc-2.25.tar.xz"
builder for `/gnu/store/fwfj4y8sqswhgq53r82im26fr0880rp8-glibc-2.25.tar.xz.drv' failed to produce output path `/gnu/store/jjprvyxxwxy27y1djs20wg04sljjaww4-glibc-2.25.tar.xz'
cannot build derivation `/gnu/store/19kvn28ypyh8prmwdmynkghxiz9b4bz1-glibc-2.25.tar.xz.drv': 1 dependencies couldn't be built
cannot build derivation `/gnu/store/2mx66l7miv2brgnnl5scc66xhqbw6hzn-glibc-2.25.drv': 1 dependencies couldn't be built
guix package: error: build failed: build of `/gnu/store/2mx66l7miv2brgnnl5scc66xhqbw6hzn-glibc-2.25.drv' failed
--8<---------------cut here---------------end--------------->8---

The same is true for running “guix build” for a package that has already
been built:

--8<---------------cut here---------------start------------->8---
rekado in ~: guix build axoloti
substitute: updating list of substitutes from 'https://mirror.hydra.gnu.org'... 100.0%
substitute: updating list of substitutes from 'https://mirror.hydra.gnu.org'... 100.0%
substitute: updating list of substitutes from 'https://mirror.hydra.gnu.org'... 100.0%
substitute: updating list of substitutes from 'https://mirror.hydra.gnu.org'... 100.0%
substitute: updating list of substitutes from 'https://mirror.hydra.gnu.org'... 100.0%
substitute: updating list of substitutes from 'https://mirror.hydra.gnu.org'... 100.0%
updating list of substitutes from 'https://mirror.hydra.gnu.org'... 100.0%
substitute: updating list of substitutes from 'https://mirror.hydra.gnu.org'... 100.0%
substitute: updating list of substitutes from 'https://mirror.hydra.gnu.org'... 100.0%
@ build-started /gnu/store/25bi2vjnbw46y0qkgqh4p03idj02wzjq-axoloti-1.0.12.drv - x86_64-linux /var/log/guix/drvs/25//bi2vjnbw46y0qkgqh4p03idj02wzjq-axoloti-1.0.12.drv.bz2
[…]
/gnu/store/shkwjz6q2x411kf2s4y0n3gcwg792kfz-axoloti-1.0.12
rekado in ~: guix build axoloti
substitute: updating list of substitutes from 'https://mirror.hydra.gnu.org'... 100.0%
substitute: updating list of substitutes from 'https://mirror.hydra.gnu.org'... 100.0%
substitute: updating list of substitutes from 'https://mirror.hydra.gnu.org'... 100.0%
substitute: updating list of substitutes from 'https://mirror.hydra.gnu.org'... 100.0%
substitute: updating list of substitutes from 'https://mirror.hydra.gnu.org'... 100.0%
substitute: updating list of substitutes from 'https://mirror.hydra.gnu.org'... 100.0%
substitute: updating list of substitutes from 'https://mirror.hydra.gnu.org'... 100.0%
substitute: updating list of substitutes from 'https://mirror.hydra.gnu.org'... 100.0%
/gnu/store/shkwjz6q2x411kf2s4y0n3gcwg792kfz-axoloti-1.0.12
rekado in ~: [disconnects from the Internet]
rekado in ~: guix build axoloti
@ substituter-started /gnu/store/8d05y04l3mrfsrsspyckh413zq6az54w-glibc-2.25.tar.xz /gnu/store/nrd0v38d61l8y16vqkb1gws0bw45q885-guix-0.13.0-2.de9d8f0/libexec/guix/substitute
Downloading https://mirror.hydra.gnu.org/guix/nar/8d05y04l3mrfsrsspyckh413zq6az54w-glibc-2.25.tar.xz...
guix substitute: error: connect: Network is unreachable
@ substituter-failed /gnu/store/8d05y04l3mrfsrsspyckh413zq6az54w-glibc-2.25.tar.xz 256 fetching path `/gnu/store/8d05y04l3mrfsrsspyckh413zq6az54w-glibc-2.25.tar.xz' failed with exit code 1
@ substituter-started /gnu/store/v60fvaly0w8nsa0zh0nl531na1dq62nc-binutils-cross-boot0-2.27 /gnu/store/nrd0v38d61l8y16vqkb1gws0bw45q885-guix-0.13.0-2.de9d8f0/libexec/guix/substitute
killing process 20710
killing process 20710: No such process
guix build: error: build failed: some substitutes for the outputs of derivation `/gnu/store/2kpxf3738q9m1cja8msq613mgjpsx4s5-glibc-2.25.tar.xz.drv' failed (usually happens due to networking issues); try `--fallback' to build derivation from source
rekado in ~:
--8<---------------cut here---------------end--------------->8---

I can avoid the “guix build” problem by passing “--no-grafts”.

--
Ricardo

GPG: BCA6 89B6 3655 3801 C3C6  2150 197A 5888 235F ACAC
https://elephly.net

Re: Local caching behavior affected by network state

[Leo Famulari]

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

On Fri, Jun 30, 2017 at 09:07:06PM +0200, Ricardo Wurmus wrote:
> 
> Leo Famulari <leo@famulari.name> writes:
> 
> > I've noticed confusing behavior regarding the memoized cache, which
> > depends on the state of the network connection.
> […]
> > So, when I am offline, I have to use --fallback for the local cache to
> > work.

Update: Sometimes even --fallback does not help, and Guix still tries to
build stuff when I think it doesn't need to.

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

Re: Local caching behavior affected by network state

[Ludovic Courtès]

Heya,

Thanks for the heads-up, this is terrible indeed.

Ricardo Wurmus <rekado@elephly.net> skribis:

> rekado in ~: guix build axoloti
> substitute: updating list of substitutes from 'https://mirror.hydra.gnu.org'... 100.0%
> substitute: updating list of substitutes from 'https://mirror.hydra.gnu.org'... 100.0%
> substitute: updating list of substitutes from 'https://mirror.hydra.gnu.org'... 100.0%
> substitute: updating list of substitutes from 'https://mirror.hydra.gnu.org'... 100.0%
> substitute: updating list of substitutes from 'https://mirror.hydra.gnu.org'... 100.0%
> substitute: updating list of substitutes from 'https://mirror.hydra.gnu.org'... 100.0%
> substitute: updating list of substitutes from 'https://mirror.hydra.gnu.org'... 100.0%
> substitute: updating list of substitutes from 'https://mirror.hydra.gnu.org'... 100.0%

This should be mitigated by b2fde4800d39863d9260509ac0b174b459d42840 (a
cache helpful to the grafting code wasn’t caching anything…).

> /gnu/store/shkwjz6q2x411kf2s4y0n3gcwg792kfz-axoloti-1.0.12
> rekado in ~: [disconnects from the Internet]
> rekado in ~: guix build axoloti
> @ substituter-started /gnu/store/8d05y04l3mrfsrsspyckh413zq6az54w-glibc-2.25.tar.xz /gnu/store/nrd0v38d61l8y16vqkb1gws0bw45q885-guix-0.13.0-2.de9d8f0/libexec/guix/substitute
> Downloading https://mirror.hydra.gnu.org/guix/nar/8d05y04l3mrfsrsspyckh413zq6az54w-glibc-2.25.tar.xz...
> guix substitute: error: connect: Network is unreachable

This one is trickier.  Replacements are also subject to grafting, so the
grafting code queries the references of the replacement of ‘glibc-final’
to determine whether it should be grafted.  The problem is that we
typically have the “out” output of the replacement on disk, but not its
“debug” output.  Because of that, the code keeps asking substitute info
for the “debug” output (that info is cached in /var/guix/substitute/
normally for several days.)

This can be seen with:

--8<---------------cut here---------------start------------->8---
$ ./pre-inst-env guix build -e '(begin (use-modules (guix)) (package-replacement (@@ (gnu packages commencement) glibc-final)))'  --no-grafts -n
32.6 MB would be downloaded:
   /gnu/store/qx8h0rc2n91bg5jraqgdizsxbdhx53w9-glibc-2.25-debug
   /gnu/store/ybpgv1v7606xw7mafda66w10hiynpiw2-glibc-2.25
--8<---------------cut here---------------end--------------->8---

(Bonus bug: /gnu/store/ybpgv1v7606xw7mafda66w10hiynpiw2-glibc-2.25
doesn’t need to be downloaded, it’s already here.)

On top of that, on my machine, bayfront.guixsd.org is the first
substitute URL.  bayfront is currently off-line, so there’s definitely
no cached substitute info for qx8h0rc2n91bg5jraqgdizsxbdhx53w9 in cache,
so ‘guix substitute’ goes on to try and connect to bayfront.guixsd.org,
fails badly (‘guix substitute’ exits I think), which then leads to the
last-resort case in grafts.scm:189.

Do you also have bayfront on your substitute URLs?  If so, can you try
removing it to verify this hypothesis?

Thanks,
Ludo’.