Received: (at submit) by debbugs.gnu.org; 29 Mar 2018 15:19:00 +0000
From debbugs-submit-bounces <at> debbugs.gnu.org Thu Mar 29 11:19:00 2018
Received: from localhost ([127.0.0.1]:58822 helo=debbugs.gnu.org)
by debbugs.gnu.org with esmtp (Exim 4.84_2)
(envelope-from <debbugs-submit-bounces <at> debbugs.gnu.org>)
id 1f1ZKO-0004qA-Bm
for submit <at> debbugs.gnu.org; Thu, 29 Mar 2018 11:19:00 -0400
Received: from eggs.gnu.org ([208.118.235.92]:34805)
by debbugs.gnu.org with esmtp (Exim 4.84_2)
(envelope-from <ludo@HIDDEN>) id 1f1ZKM-0004px-7x
for submit <at> debbugs.gnu.org; Thu, 29 Mar 2018 11:18:58 -0400
Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71)
(envelope-from <ludo@HIDDEN>) id 1f1ZKF-0006VK-8x
for submit <at> debbugs.gnu.org; Thu, 29 Mar 2018 11:18:52 -0400
X-Spam-Checker-Version: SpamAssassin 3.3.2 (2011-06-06) on eggs.gnu.org
X-Spam-Level:
X-Spam-Status: No, score=0.8 required=5.0 tests=BAYES_50,T_RP_MATCHES_RCVD,
WEIRD_QUOTING autolearn=disabled version=3.3.2
Received: from lists.gnu.org ([2001:4830:134:3::11]:47939)
by eggs.gnu.org with esmtps (TLS1.0:RSA_AES_256_CBC_SHA1:32)
(Exim 4.71) (envelope-from <ludo@HIDDEN>) id 1f1ZKF-0006Ur-5C
for submit <at> debbugs.gnu.org; Thu, 29 Mar 2018 11:18:51 -0400
Received: from eggs.gnu.org ([2001:4830:134:3::10]:54003)
by lists.gnu.org with esmtp (Exim 4.71)
(envelope-from <ludo@HIDDEN>) id 1f1ZKC-0008JN-PT
for bug-guix@HIDDEN; Thu, 29 Mar 2018 11:18:50 -0400
Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71)
(envelope-from <ludo@HIDDEN>) id 1f1ZK8-0006Nr-Nz
for bug-guix@HIDDEN; Thu, 29 Mar 2018 11:18:48 -0400
Received: from hera.aquilenet.fr ([2a0c:e300::1]:51140)
by eggs.gnu.org with esmtps (TLS1.0:DHE_RSA_AES_256_CBC_SHA1:32)
(Exim 4.71) (envelope-from <ludo@HIDDEN>) id 1f1ZK8-0006Lw-DH
for bug-guix@HIDDEN; Thu, 29 Mar 2018 11:18:44 -0400
Received: from localhost (localhost [127.0.0.1])
by hera.aquilenet.fr (Postfix) with ESMTP id AB8AB12AF3
for <bug-guix@HIDDEN>; Thu, 29 Mar 2018 17:18:42 +0200 (CEST)
X-Virus-Scanned: Debian amavisd-new at aquilenet.fr
Received: from hera.aquilenet.fr ([127.0.0.1])
by localhost (hera.aquilenet.fr [127.0.0.1]) (amavisd-new, port 10024)
with ESMTP id 2lWRHn25yAio for <bug-guix@HIDDEN>;
Thu, 29 Mar 2018 17:18:41 +0200 (CEST)
Received: from ribbon (unknown [193.50.110.67])
by hera.aquilenet.fr (Postfix) with ESMTPSA id 6CEAC12AF2
for <bug-guix@HIDDEN>; Thu, 29 Mar 2018 17:18:41 +0200 (CEST)
From: ludo@HIDDEN (Ludovic =?utf-8?Q?Court=C3=A8s?=)
To: bug-guix@HIDDEN
Subject: =?utf-8?Q?=E2=80=98guix_substitute=E2=80=99?= spins forever
X-URL: http://www.fdn.fr/~lcourtes/
X-Revolutionary-Date: 9 Germinal an 226 de la =?utf-8?Q?R=C3=A9volution?=
X-PGP-Key-ID: 0x090B11993D9AEBB5
X-PGP-Key: http://www.fdn.fr/~lcourtes/ludovic.asc
X-PGP-Fingerprint: 3CE4 6455 8A84 FDC6 9DB4 0CFB 090B 1199 3D9A EBB5
X-OS: x86_64-pc-linux-gnu
Date: Thu, 29 Mar 2018 17:18:40 +0200
Message-ID: <87po3mvrjj.fsf@HIDDEN>
User-Agent: Gnus/5.13 (Gnus v5.13) Emacs/25.3 (gnu/linux)
MIME-Version: 1.0
Content-Type: text/plain; charset=utf-8
Content-Transfer-Encoding: quoted-printable
X-detected-operating-system: by eggs.gnu.org: Genre and OS details not
recognized.
X-detected-operating-system: by eggs.gnu.org: GNU/Linux 2.6.x
X-Received-From: 2001:4830:134:3::11
X-Spam-Score: -5.0 (-----)
X-Debbugs-Envelope-To: submit
X-BeenThere: debbugs-submit <at> debbugs.gnu.org
X-Mailman-Version: 2.1.18
Precedence: list
List-Id: <debbugs-submit.debbugs.gnu.org>
List-Unsubscribe: <https://debbugs.gnu.org/cgi-bin/mailman/options/debbugs-submit>,
<mailto:debbugs-submit-request <at> debbugs.gnu.org?subject=unsubscribe>
List-Archive: <https://debbugs.gnu.org/cgi-bin/mailman/private/debbugs-submit/>
List-Post: <mailto:debbugs-submit <at> debbugs.gnu.org>
List-Help: <mailto:debbugs-submit-request <at> debbugs.gnu.org?subject=help>
List-Subscribe: <https://debbugs.gnu.org/cgi-bin/mailman/listinfo/debbugs-submit>,
<mailto:debbugs-submit-request <at> debbugs.gnu.org?subject=subscribe>
Errors-To: debbugs-submit-bounces <at> debbugs.gnu.org
Sender: "Debbugs-submit" <debbugs-submit-bounces <at> debbugs.gnu.org>
X-Spam-Score: -5.0 (-----)
I=E2=80=99ve stumbled upon a situation where =E2=80=98guix substitute=E2=80=
=99 would spin
endlessly. Tracing the =E2=80=98guix substitute=E2=80=99 process shows tha=
t the
following two =E2=80=9Cinfo=E2=80=9D queries would happen in a loop:
--8<---------------cut here---------------start------------->8---
read(0, "info /gnu/store/cwmia787gmr4pypna6na1nfirqlr8y0p-gcc-5.5.0 \n", 40=
96) =3D 60
openat(AT_FDCWD, "/var/guix/substitute/cache/bzh2rehitrzflwj2f3tcyt25s7xn3h=
wbhxey3r7suq2a65qr2ulq/cwmia787gmr4pypna6na1nfirqlr8y0p", O_RDONLY) =3D 13
fstat(13, {st_mode=3DS_IFREG|0600, st_size=3D1288, ...}) =3D 0
lseek(13, 0, SEEK_CUR) =3D 0
read(13, "(narinfo (version 2) (cache-uri \"https://berlin.guixsd.org\") (d=
ate 1522315393) (ttl 3888000) (value \"StorePath: /gnu/store/cwmia787gmr4py=
pna6na1nfirqlr8y0p-gcc-5.5.0\\nURL: nar/gzip/cwmia787gmr4pypna6na1nfirqlr8y=
0p-gcc-5.5.0\\nCompression: gzip\\nNarHash: sha256:039i94jrmfsvn859kjarcmqz=
abs3nspmbz912gy03p0v6n64dr56\\nNarSize: 98156824\\nReferences: 03j2yq30pcd2=
h17np0liarb2jdijg8y4-bash-static-4.4.19 6v2lw5wkb36lwcky5x4i5ris08jabihs-gl=
ibc-2.27 asm7j8dm594ljjv"..., 4096) =3D 1288
close(13) =3D 0
write(1, "/gnu/store/cwmia787gmr4pypna6na1nfirqlr8y0p-gcc-5.5.0\n", 54) =3D=
54
write(1, "/gnu/store/rvmhl8kb58zsj6pg2i2ha8f1dmx8wvm6-gcc-5.5.0.drv\n", 58)=
=3D 58
write(1, "5\n", 2) =3D 2
write(1, "/gnu/store/03j2yq30pcd2h17np0liarb2jdijg8y4-bash-static-4.4.19\n"=
, 63) =3D 63
write(1, "/gnu/store/6v2lw5wkb36lwcky5x4i5ris08jabihs-glibc-2.27\n", 55) =
=3D 55
write(1, "/gnu/store/asm7j8dm594ljjvs0x90h8qivl5qdaz8-gcc-5.5.0-lib\n", 58)=
=3D 58
write(1, "/gnu/store/cwmia787gmr4pypna6na1nfirqlr8y0p-gcc-5.5.0\n", 54) =3D=
54
write(1, "/gnu/store/s4nzclq0ma3v19lvg84z8c7nqys9w3ai-zlib-1.2.11\n", 56) =
=3D 56
write(1, "35550259\n", 9) =3D 9
write(1, "98156824\n", 9) =3D 9
write(1, "\n", 1) =3D 1
read(0, "info /gnu/store/asm7j8dm594ljjvs0x90h8qivl5qdaz8-gcc-5.5.0-lib \n"=
, 4096) =3D 64
openat(AT_FDCWD, "/var/guix/substitute/cache/bzh2rehitrzflwj2f3tcyt25s7xn3h=
wbhxey3r7suq2a65qr2ulq/asm7j8dm594ljjvs0x90h8qivl5qdaz8", O_RDONLY) =3D 13
fstat(13, {st_mode=3DS_IFREG|0600, st_size=3D100, ...}) =3D 0
lseek(13, 0, SEEK_CUR) =3D 0
read(13, "(narinfo (version 2) (cache-uri \"https://berlin.guixsd.org\") (d=
ate 1522315402) (ttl 300) (value #f))", 4096) =3D 100
close(13) =3D 0
openat(AT_FDCWD, "/var/guix/substitute/cache/s3o7shxygzvof4rs6c3ed5hfifavpy=
43khzg5fyjdmrnlfk3b7va/asm7j8dm594ljjvs0x90h8qivl5qdaz8", O_RDONLY) =3D 13
fstat(13, {st_mode=3DS_IFREG|0600, st_size=3D105, ...}) =3D 0
lseek(13, 0, SEEK_CUR) =3D 0
read(13, "(narinfo (version 2) (cache-uri \"https://mirror.hydra.gnu.org\")=
(date 1522315667) (ttl 10800) (value #f))", 4096) =3D 105
close(13) =3D 0
write(1, "\n", 1) =3D 1
--8<---------------cut here---------------end--------------->8---
The two store items being requested are outputs of the same derivations:
--8<---------------cut here---------------start------------->8---
$ head -c200 /gnu/store/rvmhl8kb58zsj6pg2i2ha8f1dmx8wvm6-gcc-5.5.0.drv
Derive([("lib","/gnu/store/asm7j8dm594ljjvs0x90h8qivl5qdaz8-gcc-5.5.0-lib",=
"",""),("out","/gnu/store/cwmia787gmr4pypna6na1nfirqlr8y0p-gcc-5.5.0","",""=
)],[("/gnu/store/0iwkdrk73cgpj1bq8jd66i8aca5hcm5v-
--8<---------------cut here---------------end--------------->8---
Another time, something similar happened in the middle of a series of
downloads:
--8<---------------cut here---------------start------------->8---
@ substituter-succeeded /gnu/store/wlkhfzz67h4wc3spj2fy8cvqaq8c60il-pkg-con=
fig-0.29.2
substitute: updating list of substitutes from 'https://berlin.guixsd.org'..=
. 100.0%
substitute: updating list of substitutes from 'https://mirror.hydra.gnu.org=
'... 100.0%
@ substituter-started /gnu/store/68yb572zpkn26skh2dp1z91w2dnmrzzb-libgc-7.6=
.4 /gnu/store/fbpk1zjcqd6p4ny8qx48mvlp4v7qfmld-guix-0.14.0-9.bdf0c64/libexe=
c/guix/substitute
Downloading https://berlin.guixsd.org/nar/gzip/68yb572zpkn26skh2dp1z91w2dnm=
rzzb-libgc-7.6.4...
libgc-7.6.4 398KiB =
=
2.2MiB/s 00:0=
0 [##################] 100.0%
@ substituter-succeeded /gnu/store/68yb572zpkn26skh2dp1z91w2dnmrzzb-libgc-7=
.6.4
substitute: updating list of substitutes from 'https://berlin.guixsd.org'..=
. 100.0%
[=E2=80=A6 hangs here=E2=80=A6]
--8<---------------cut here---------------end--------------->8---
While it=E2=80=99s hanging, =E2=80=98guix substitute=E2=80=99 receives this=
one query in a loop:
--8<---------------cut here---------------start------------->8---
read(0, "info /gnu/store/w91m22j33vxj3vvfa8lv04qjansdzr0d-libgc-7.6.4-debug=
\n", 4096) =3D 68
openat(AT_FDCWD, "/var/guix/substitute/cache/bzh2rehitrzflwj2f3tcyt25s7xn3h=
wbhxey3r7suq2a65qr2ulq/w91m22j33vxj3vvfa8lv04qjansdzr0d", O_RDONLY) =3D 13
fstat(13, {st_mode=3DS_IFREG|0600, st_size=3D100, ...}) =3D 0
lseek(13, 0, SEEK_CUR) =3D 0
read(13, "(narinfo (version 2) (cache-uri \"https://berlin.guixsd.org\") (d=
ate 1522315814) (ttl 300) (value #f))", 4096) =3D 100
close(13) =3D 0
openat(AT_FDCWD, "/var/guix/substitute/cache/s3o7shxygzvof4rs6c3ed5hfifavpy=
43khzg5fyjdmrnlfk3b7va/w91m22j33vxj3vvfa8lv04qjansdzr0d", O_RDONLY) =3D 13
fstat(13, {st_mode=3DS_IFREG|0600, st_size=3D105, ...}) =3D 0
lseek(13, 0, SEEK_CUR) =3D 0
read(13, "(narinfo (version 2) (cache-uri \"https://mirror.hydra.gnu.org\")=
(date 1522315814) (ttl 10800) (value #f))", 4096) =3D 105
close(13) =3D 0
write(1, "\n", 1) =3D 1
--8<---------------cut here---------------end--------------->8---
To unlock it, I did:
--8<---------------cut here---------------start------------->8---
$ sudo rm "/var/guix/substitute/cache/bzh2rehitrzflwj2f3tcyt25s7xn3hwbhxey3=
r7suq2a65qr2ulq/w91m22j33vxj3vvfa8lv04qjansdzr0d"
# =E2=80=A6 narinfo gets redownloaded and file gets regenerated:
$ sudo cat "/var/guix/substitute/cache/bzh2rehitrzflwj2f3tcyt25s7xn3hwbhxey=
3r7suq2a65qr2ulq/w91m22j33vxj3vvfa8lv04qjansdzr0d"
(narinfo (version 2) (cache-uri "https://berlin.guixsd.org") (date 15223164=
03) (ttl 3888000) (value "StorePath: /gnu/store/w91m22j33vxj3vvfa8lv04qjans=
dzr0d-libgc-7.6.4-debug\nURL: nar/gzip/w91m22j33vxj3vvfa8lv04qjansdzr0d-lib=
gc-7.6.4-debug\nCompression: gzip\nNarHash: sha256:0jrrknph5qs3n8v1prmmx4pg=
ixhhdnqjh04i066c3fp12yx35hb7\nNarSize: 1462960\nReferences: 68yb572zpkn26sk=
h2dp1z91w2dnmrzzb-libgc-7.6.4 6v2lw5wkb36lwcky5x4i5ris08jabihs-glibc-2.27 a=
sm7j8dm594ljjvs0x90h8qivl5qdaz8-gcc-5.5.0-lib cwmia787gmr4pypna6na1nfirqlr8=
y0p-gcc-5.5.0 fbclk7l7fn4qh6nwi1xl1wbszhhj6yfd-libatomic-ops-7.6.2\nFileSiz=
e: 543891\nSystem: x86_64-linux\nDeriver: 9c7ilc15k8p5b84lxhgn2jy6l6xgbdpj-=
libgc-7.6.4.drv\nSignature: 1;berlin.guixsd.org;KHNpZ25hdHVyZSAKIChkYXRhIAo=
gIChmbGFncyByZmM2OTc5KQogIChoYXNoIHNoYTI1NiAjRTBGRUExNkQ5ODU5Mjk1QjQ4N0IwOT=
c2RTVFRkIxNDUzRTdCOUVFNkJBNUFBRkY5NUFEQTg1REY5QUJENkI4QSMpCiAgKQogKHNpZy12Y=
WwgCiAgKGVjZHNhIAogICAociAjMDY0MkZCQUYwRDExNDM2NTc3NUY1QTI2REU3NDYyOTMyQzg5=
RjhCM0U4RDg5MzQ4MzRBNTQwRDAwMEVBQTk5QiMpCiAgIChzICMwMzQ1RUFCMDM1MzBEMzRFOTE=
wNzVFMzFFMUFENjM4OEI3NDAwRTQxRjRBOTExRjg0RDE0NEQ3M0QxMkVCMzY5IykKICAgKQogIC=
kKIChwdWJsaWMta2V5IAogIChlY2MgCiAgIChjdXJ2ZSBFZDI1NTE5KQogICAocSAjOEQxNTZGM=
jk1RDI0QjBEOUE4NkZBNTc0MUE4NDBGRjJEMjRGNjBGN0I2QzQxMzQ4MTRBRDU1NjI1OTcxQjM5=
NCMpCiAgICkKICApCiApCg=3D=3D\n"))
--8<---------------cut here---------------end--------------->8---
=E2=80=A6 and the daemon went on to substitute libgc-7.6.4-debug.
This apparently has to do with multiple-output derivations where not all
of the outputs are substitutable. The loop could come from
SubstitutionGoal::tryNext, which recurses:
SubstitutablePathInfos infos;
PathSet dummy(singleton<PathSet>(storePath));
worker.store.querySubstitutablePathInfos(sub, dummy, infos);
SubstitutablePathInfos::iterator k =3D infos.find(storePath);
if (k =3D=3D infos.end()) { tryNext(); return; }
info =3D k->second;
hasSubstitute =3D true;
Ludo=E2=80=99.
ludo@HIDDEN (Ludovic Courtès):bug-guix@HIDDEN.
Full text available.bug-guix@HIDDEN:bug#30986; Package guix.
Full text available.
GNU bug tracking system
Copyright (C) 1999 Darren O. Benham,
1997 nCipher Corporation Ltd,
1994-97 Ian Jackson.