GNU bug report logs - #30986
‘guix substitute’ spins forever

Please note: This is a static page, with minimal formatting, updated once a day.
Click here to see this page with the latest information and nicer formatting.

Package: guix; Reported by: ludo@HIDDEN (Ludovic Courtès); dated Thu, 29 Mar 2018 15:19:02 UTC; Maintainer for guix is bug-guix@HIDDEN.

Message received at 30986 <at> debbugs.gnu.org:


Received: (at 30986) by debbugs.gnu.org; 16 Jun 2025 11:49:56 +0000
From debbugs-submit-bounces <at> debbugs.gnu.org Mon Jun 16 07:49:55 2025
Received: from localhost ([127.0.0.1]:43607 helo=debbugs.gnu.org)
	by debbugs.gnu.org with esmtp (Exim 4.84_2)
	(envelope-from <debbugs-submit-bounces <at> debbugs.gnu.org>)
	id 1uR8LY-0008B6-Oa
	for submit <at> debbugs.gnu.org; Mon, 16 Jun 2025 07:49:55 -0400
Received: from mail-wm1-x333.google.com ([2a00:1450:4864:20::333]:44164)
 by debbugs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_128_GCM_SHA256:128)
 (Exim 4.84_2) (envelope-from <zimon.toutoune@HIDDEN>)
 id 1uR8LL-00088O-Pz
 for 30986 <at> debbugs.gnu.org; Mon, 16 Jun 2025 07:49:43 -0400
Received: by mail-wm1-x333.google.com with SMTP id
 5b1f17b1804b1-4530921461aso36848435e9.0
 for <30986 <at> debbugs.gnu.org>; Mon, 16 Jun 2025 04:49:39 -0700 (PDT)
DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed;
 d=gmail.com; s=20230601; t=1750074573; x=1750679373; darn=debbugs.gnu.org;
 h=content-transfer-encoding:mime-version:user-agent:message-id:date
 :references:in-reply-to:subject:cc:to:from:from:to:cc:subject:date
 :message-id:reply-to;
 bh=VFUyp53n6+dIFg4AfDvJ9XU0aiujURc7Tya7cqR1+WQ=;
 b=BB2a+1qx4E0wvd5RGBNKPRLfkEOcbfzJEDugYv/0spOGYG3+i4QpCwqzHMA1yACJST
 HfPo3iXiZHosjtSJBIo10dhyUiZI/aNbLUV2Qijkk3JO1y6gqF433pqtWXn4bZI0JCBH
 svdiQgVJCFdUb5Vh3JXJ3ygE3bSXyGfCS5jn2YJizPJDEZhR3pjVceef3+ZqXRw7kYPm
 JGnbCQ7t9RAEt07GfguTIBK4KDU+1hdqshTaomoITzF892EVsSaUlPbWoValQ1xA0Dwp
 15oiEoilq3U+s+V5j0FNsD9mHFBFhbI/RVGYlkikv9dhLHOfmwDuw42ofEl5cqhNx+ru
 wz8A==
X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed;
 d=1e100.net; s=20230601; t=1750074573; x=1750679373;
 h=content-transfer-encoding:mime-version:user-agent:message-id:date
 :references:in-reply-to:subject:cc:to:from:x-gm-message-state:from
 :to:cc:subject:date:message-id:reply-to;
 bh=VFUyp53n6+dIFg4AfDvJ9XU0aiujURc7Tya7cqR1+WQ=;
 b=FTCbomhe5yQ+dVMRWyCHE3yD5gNo8pH9Sjwzth0Btdo45ZZmgF9IJikXYbekGDunsz
 fvv461BFxSllp9lhNZoZFa7Gm18pdVaGMatcC/NWHNR3LYgAjH7vQ+mqfy66LhRlvAyo
 +BxPoP6/IhKrZMl6rhZBIPj15so6qOzknxz1y8YtAEizF0Gl7ylmHSlWMpaGykVVQh5H
 qVAihxMXMFL6eMPXvkUJPqgwGCQBEkl3zD4v5tSjPum8wGY45FZ8JRa/1EYopFovziV0
 s1yxp17jWdO0v499GiBTN+AKWrvjMzTOh9Xv7Hv80aMStuC2Rpi7ijfLjghQ3lJi75nN
 oAHg==
X-Gm-Message-State: AOJu0Yx6pZJ7eSpBCs/S3w4me9yETIupn/oZ5sOAMnApwKcS21ZxOIlt
 VQA0i5qGrEZ28yPOjHK8AqFr5djjDAbiB4LXSnu+y2uriR7+q7GAAFQCDyO0/40d
X-Gm-Gg: ASbGncvgHh85NRJBEna6LrWSvNfvoKxDlpa4UpxIYuBPuiNfVeGl0ynFrNW6GmAxTlm
 6IS3gwPofW1rhyw4fTDwtirw9zg+/ITV8uAkAkJdO7BShJBznUhK5SPNoFEEJbZcmFA0/oa5JFY
 SW3LRf32ln+rXV1VSeIFj4WejG0n6S5VMLXPlOn2hCdlynXPecgZW5nCLqTZ1F11y4jRyPJky1w
 q5sBEDzqwQxnPDLOM8qwhxhnCa9PtT2v11ThHxsJskVaKYIqxRnZsbtwdqzpTfE3kmZb/bm6nw4
 xCwu4FHtUWmTwexdJu3uqxgS7rOnm9rMJSEPOiTyXkFr1/9XTtbrZoHuYTxdEH+ThjDA1gUVgQ8
 8GEyu9fx16XrgeesOCRX1EXw=
X-Google-Smtp-Source: AGHT+IES2wua2NN/ZOUNmnUkPdRt1EpE7Dr5oQOAMgphmm0yf+z969Qjtg63L9y1bSYW4zFrJcuAQA==
X-Received: by 2002:a05:600c:4ed1:b0:453:78f:fa9f with SMTP id
 5b1f17b1804b1-4533ca510afmr80532635e9.11.1750074573303; 
 Mon, 16 Jun 2025 04:49:33 -0700 (PDT)
Received: from lili (nat-dsi-209.net.univ-paris-diderot.fr. [81.194.30.209])
 by smtp.gmail.com with ESMTPSA id
 5b1f17b1804b1-4532e256d95sm141420535e9.31.2025.06.16.04.49.32
 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256);
 Mon, 16 Jun 2025 04:49:33 -0700 (PDT)
From: Simon Tournier <zimon.toutoune@HIDDEN>
To: ludo@HIDDEN (Ludovic =?utf-8?Q?Court=C3=A8s?=)
Subject: Re: bug#30986: =?utf-8?Q?=E2=80=98guix_substitute=E2=80=99?= spins
 forever
In-Reply-To: <87po3mvrjj.fsf@HIDDEN> ("Ludovic =?utf-8?Q?Court=C3=A8s=22'?=
 =?utf-8?Q?s?= message of "Thu, 29 Mar 2018 17:18:40 +0200")
References: <87po3mvrjj.fsf@HIDDEN>
Date: Mon, 16 Jun 2025 12:05:37 +0200
Message-ID: <87ldps80i6.fsf@HIDDEN>
User-Agent: Gnus/5.13 (Gnus v5.13)
MIME-Version: 1.0
Content-Type: text/plain; charset=utf-8
Content-Transfer-Encoding: quoted-printable
X-Spam-Score: 0.0 (/)
X-Debbugs-Envelope-To: 30986
Cc: 30986 <at> debbugs.gnu.org
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: -1.0 (-)

Hi Ludo,

Digging into the bug tracker for some triage, I hit this:

    https://issues.guix.gnu.org/issue/30986

and it reminds me our recent discussion here:

    https://codeberg.org/guix/guix/issues/430

WDYT?

On Thu, 29 Mar 2018 at 17:18, ludo@HIDDEN (Ludovic Court=C3=A8s) wrote:

> 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 t=
hat the
> following two =E2=80=9Cinfo=E2=80=9D queries would happen in a loop:
>
> read(0, "info /gnu/store/cwmia787gmr4pypna6na1nfirqlr8y0p-gcc-5.5.0 \n", =
4096) =3D 60
> openat(AT_FDCWD, "/var/guix/substitute/cache/bzh2rehitrzflwj2f3tcyt25s7xn=
3hwbhxey3r7suq2a65qr2ulq/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\") =
(date 1522315393) (ttl 3888000) (value \"StorePath: /gnu/store/cwmia787gmr4=
pypna6na1nfirqlr8y0p-gcc-5.5.0\\nURL: nar/gzip/cwmia787gmr4pypna6na1nfirqlr=
8y0p-gcc-5.5.0\\nCompression: gzip\\nNarHash: sha256:039i94jrmfsvn859kjarcm=
qzabs3nspmbz912gy03p0v6n64dr56\\nNarSize: 98156824\\nReferences: 03j2yq30pc=
d2h17np0liarb2jdijg8y4-bash-static-4.4.19 6v2lw5wkb36lwcky5x4i5ris08jabihs-=
glibc-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", 5=
8) =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", 5=
8) =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/bzh2rehitrzflwj2f3tcyt25s7xn=
3hwbhxey3r7suq2a65qr2ulq/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\") =
(date 1522315402) (ttl 300) (value #f))", 4096) =3D 100
> close(13)                               =3D 0
> openat(AT_FDCWD, "/var/guix/substitute/cache/s3o7shxygzvof4rs6c3ed5hfifav=
py43khzg5fyjdmrnlfk3b7va/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
>
>
> The two store items being requested are outputs of the same derivations:
>
> $ 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-
>
>
> Another time, something similar happened in the middle of a series of
> downloads:
>
> @ substituter-succeeded /gnu/store/wlkhfzz67h4wc3spj2fy8cvqaq8c60il-pkg-c=
onfig-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.o=
rg'... 100.0%
> @ substituter-started /gnu/store/68yb572zpkn26skh2dp1z91w2dnmrzzb-libgc-7=
.6.4 /gnu/store/fbpk1zjcqd6p4ny8qx48mvlp4v7qfmld-guix-0.14.0-9.bdf0c64/libe=
xec/guix/substitute
> Downloading https://berlin.guixsd.org/nar/gzip/68yb572zpkn26skh2dp1z91w2d=
nmrzzb-libgc-7.6.4...
>  libgc-7.6.4  398KiB                                                     =
                                                                           =
                                                                2.2MiB/s 00=
:00 [##################] 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]
>
>
> While it=E2=80=99s hanging, =E2=80=98guix substitute=E2=80=99 receives th=
is one query in a loop:
>
> read(0, "info /gnu/store/w91m22j33vxj3vvfa8lv04qjansdzr0d-libgc-7.6.4-deb=
ug \n", 4096) =3D 68
> openat(AT_FDCWD, "/var/guix/substitute/cache/bzh2rehitrzflwj2f3tcyt25s7xn=
3hwbhxey3r7suq2a65qr2ulq/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\") =
(date 1522315814) (ttl 300) (value #f))", 4096) =3D 100
> close(13)                               =3D 0
> openat(AT_FDCWD, "/var/guix/substitute/cache/s3o7shxygzvof4rs6c3ed5hfifav=
py43khzg5fyjdmrnlfk3b7va/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
>
>
> To unlock it, I did:
>
> $ sudo rm "/var/guix/substitute/cache/bzh2rehitrzflwj2f3tcyt25s7xn3hwbhxe=
y3r7suq2a65qr2ulq/w91m22j33vxj3vvfa8lv04qjansdzr0d"
> # =E2=80=A6 narinfo gets redownloaded and file gets regenerated:
> $ sudo cat "/var/guix/substitute/cache/bzh2rehitrzflwj2f3tcyt25s7xn3hwbhx=
ey3r7suq2a65qr2ulq/w91m22j33vxj3vvfa8lv04qjansdzr0d"
> (narinfo (version 2) (cache-uri "https://berlin.guixsd.org") (date 152231=
6403) (ttl 3888000) (value "StorePath: /gnu/store/w91m22j33vxj3vvfa8lv04qja=
nsdzr0d-libgc-7.6.4-debug\nURL: nar/gzip/w91m22j33vxj3vvfa8lv04qjansdzr0d-l=
ibgc-7.6.4-debug\nCompression: gzip\nNarHash: sha256:0jrrknph5qs3n8v1prmmx4=
pgixhhdnqjh04i066c3fp12yx35hb7\nNarSize: 1462960\nReferences: 68yb572zpkn26=
skh2dp1z91w2dnmrzzb-libgc-7.6.4 6v2lw5wkb36lwcky5x4i5ris08jabihs-glibc-2.27=
 asm7j8dm594ljjvs0x90h8qivl5qdaz8-gcc-5.5.0-lib cwmia787gmr4pypna6na1nfirql=
r8y0p-gcc-5.5.0 fbclk7l7fn4qh6nwi1xl1wbszhhj6yfd-libatomic-ops-7.6.2\nFileS=
ize: 543891\nSystem: x86_64-linux\nDeriver: 9c7ilc15k8p5b84lxhgn2jy6l6xgbdp=
j-libgc-7.6.4.drv\nSignature: 1;berlin.guixsd.org;KHNpZ25hdHVyZSAKIChkYXRhI=
AogIChmbGFncyByZmM2OTc5KQogIChoYXNoIHNoYTI1NiAjRTBGRUExNkQ5ODU5Mjk1QjQ4N0Iw=
OTc2RTVFRkIxNDUzRTdCOUVFNkJBNUFBRkY5NUFEQTg1REY5QUJENkI4QSMpCiAgKQogKHNpZy1=
2YWwgCiAgKGVjZHNhIAogICAociAjMDY0MkZCQUYwRDExNDM2NTc3NUY1QTI2REU3NDYyOTMyQz=
g5RjhCM0U4RDg5MzQ4MzRBNTQwRDAwMEVBQTk5QiMpCiAgIChzICMwMzQ1RUFCMDM1MzBEMzRFO=
TEwNzVFMzFFMUFENjM4OEI3NDAwRTQxRjRBOTExRjg0RDE0NEQ3M0QxMkVCMzY5IykKICAgKQog=
ICkKIChwdWJsaWMta2V5IAogIChlY2MgCiAgIChjdXJ2ZSBFZDI1NTE5KQogICAocSAjOEQxNTZ=
GMjk1RDI0QjBEOUE4NkZBNTc0MUE4NDBGRjJEMjRGNjBGN0I2QzQxMzQ4MTRBRDU1NjI1OTcxQj=
M5NCMpCiAgICkKICApCiApCg=3D=3D\n"))
>
> =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;

BTW, if it appears to you unrelated, what is the status of this old bug
with only one message? :-)

Cheers,
simon




Information forwarded to bug-guix@HIDDEN:
bug#30986; Package guix. Full text available.

Message received at submit <at> debbugs.gnu.org:


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.




Acknowledgement sent to ludo@HIDDEN (Ludovic Courtès):
New bug report received and forwarded. Copy sent to bug-guix@HIDDEN. Full text available.
Report forwarded to bug-guix@HIDDEN:
bug#30986; Package guix. Full text available.
Please note: This is a static page, with minimal formatting, updated once a day.
Click here to see this page with the latest information and nicer formatting.
Last modified: Mon, 16 Jun 2025 12:00:02 UTC

GNU bug tracking system
Copyright (C) 1999 Darren O. Benham, 1997 nCipher Corporation Ltd, 1994-97 Ian Jackson.