GNU bug report logs

#48279 Daemon enters substitute query loop when only one of several outputs is substitutable

PackageSource(s)Maintainer(s)
guix PTS Buildd Popcon
Reply or subscribe to this bug. View this bug as an mbox, status mbox, or maintainer mbox

Report forwarded to rekado@elephly.net, zimon.toutoune@gmail.com, bug-guix@gnu.org:
bug#48279; Package guix. (Fri, 07 May 2021 19:46:02 GMT) (full text, mbox, link).


Acknowledgement sent to Ludovic Courtès <ludovic.courtes@inria.fr>:
New bug report received and forwarded. Copy sent to rekado@elephly.net, zimon.toutoune@gmail.com, bug-guix@gnu.org. (Fri, 07 May 2021 19:46:02 GMT) (full text, mbox, link).


Message #5 received at submit@debbugs.gnu.org (full text, mbox, reply):

From: Ludovic Courtès <ludovic.courtes@inria.fr>
To: <bug-guix@gnu.org>
Subject: Daemon enters substitute query loop when only one of several outputs is substitutable
Date: Fri, 07 May 2021 21:45:15 +0200
Hi!

‘guix build /gnu/store/1k8lgjs4al3gp3hri73wrbslbqa16hac-guile-ssh-0.11.3.drv’ (it’s a derivation from
d57660c54907cc6fba8b0adf6295fd2311ada6cf, Oct. 2019) currently enters an
endless substitute query loop (with ci.guix.gnu.org substitutes enabled,
where ci.guix.gnu.org currently lacks this substitute):

--8<---------------cut here---------------start------------->8---
$ guix describe
Generacio 182	May 04 2021 08:56:26	(nuna)
  guix fcd002c
    repository URL: https://git.savannah.gnu.org/git/guix.git
    branch: master
    commit: fcd002ccfa3a2bf28a9d05ab2992464afc6e5fca
$ guix build /gnu/store/1k8lgjs4al3gp3hri73wrbslbqa16hac-guile-ssh-0.11.3.drv --debug=3
La jena derivo estos konstruata:
   /gnu/store/1k8lgjs4al3gp3hri73wrbslbqa16hac-guile-ssh-0.11.3.drv
[at this point, loops…]
--8<---------------cut here---------------end--------------->8---

Looking at the corresponding ‘guix substitute --query’ process shows
this:

--8<---------------cut here---------------start------------->8---
read(0, "info /gnu/store/q89w5vk8lyw4jw9knd104qk3381b03dw-guile-ssh-0.11.3 \n", 4096) = 67
openat(AT_FDCWD, "/var/guix/substitute/cache/4refhwxbjmeua2kwg2nmzhv4dg4d3dorpjefq7kiciw2pfhaf26a/q89w5vk8lyw4jw9knd104qk3381b03dw", O_RDONLY) = 14
fstat(14, {st_mode=S_IFREG|0600, st_size=99, ...}) = 0
lseek(14, 0, SEEK_CUR)                  = 0
read(14, "(narinfo (version 2) (cache-uri \"https://ci.guix.gnu.org\") (date 1620414701) (ttl 3600) (value #f))", 4096) = 99
close(14)                               = 0
write(4, "\n", 1)                       = 1
read(0, "info /gnu/store/q89w5vk8lyw4jw9knd104qk3381b03dw-guile-ssh-0.11.3 \n", 4096) = 67
openat(AT_FDCWD, "/var/guix/substitute/cache/4refhwxbjmeua2kwg2nmzhv4dg4d3dorpjefq7kiciw2pfhaf26a/q89w5vk8lyw4jw9knd104qk3381b03dw", O_RDONLY) = 14
fstat(14, {st_mode=S_IFREG|0600, st_size=99, ...}) = 0
lseek(14, 0, SEEK_CUR)                  = 0
read(14, "(narinfo (version 2) (cache-uri \"https://ci.guix.gnu.org\") (date 1620414701) (ttl 3600) (value #f))", 4096) = 99
close(14)                               = 0
write(4, "\n", 1)                       = 1
read(0, "info /gnu/store/2lfh3rblh0a38s36q7xyhkac6l5kknw3-guile-ssh-0.11.3-debug \n", 4096) = 73
openat(AT_FDCWD, "/var/guix/substitute/cache/4refhwxbjmeua2kwg2nmzhv4dg4d3dorpjefq7kiciw2pfhaf26a/2lfh3rblh0a38s36q7xyhkac6l5kknw3", O_RDONLY) = 14
fstat(14, {st_mode=S_IFREG|0600, st_size=1421, ...}) = 0
lseek(14, 0, SEEK_CUR)                  = 0
read(14, "(narinfo (version 2) (cache-uri \"https://ci.guix.gnu.org\") (date 1620414701) (ttl 7776000) (value \"StorePath: /gnu/store/2lfh3rblh0a38s36q7xyhkac6l5kknw3-guile-ssh-0.11.3-debug\\nURL: nar/gzip/2lfh3rblh0a38s36q7xyhkac6l5kknw3-guile-ssh-0.11.3-debug\\nCompression: gzip\\nFileSize: 347198\\nURL: nar/lzip/2lfh3rblh0a38s36q7xyhkac6l5kknw3-guile-ssh-0.11.3-debug\\nCompression: lzip\\nFileSize: 220285\\nNarHash: sha256:0xybb41pvgxyi4fcrgml2qd68wh3gwv78h4r81n54w6h2dskrf08\\nNarSize: 2360032\\nReferences: 4sqps8"..., 4096) = 1421
close(14)                               = 0
write(4, "/gnu/store/2lfh3rblh0a38s36q7xyhkac6l5kknw3-guile-ssh-0.11.3-debug\n", 67) = 67
write(4, "/gnu/store/9slm8shib43rjz1pykww0pikhb9rnfz9-guile-ssh-0.11.3.drv\n", 65) = 65
write(4, "5\n", 2)                      = 2
write(4, "/gnu/store/4sqps8dczv3g7rwbdibfz6rf5jlk7w90-gcc-5.5.0-lib\n", 58) = 58
write(4, "/gnu/store/9alic3caqhay3h8mx4iihpmyj6ymqpcx-guile-2.2.4\n", 56) = 56
write(4, "/gnu/store/h90vnqw0nwd0hhm1l5dgxsdrigddfmq4-glibc-2.28\n", 55) = 55
write(4, "/gnu/store/ljig01r4nazpjijhvmvrfwhv03ypc9a6-libssh-0.9.0\n", 57) = 57
write(4, "/gnu/store/q89w5vk8lyw4jw9knd104qk3381b03dw-guile-ssh-0.11.3\n", 61) = 61
write(4, "220285\n", 7)                 = 7
write(4, "2360032\n", 8)                = 8
write(4, "\n", 1)                       = 1
read(0, "info /gnu/store/q89w5vk8lyw4jw9knd104qk3381b03dw-guile-ssh-0.11.3 \n", 4096) = 67
openat(AT_FDCWD, "/var/guix/substitute/cache/4refhwxbjmeua2kwg2nmzhv4dg4d3dorpjefq7kiciw2pfhaf26a/q89w5vk8lyw4jw9knd104qk3381b03dw", O_RDONLY) = 14
fstat(14, {st_mode=S_IFREG|0600, st_size=99, ...}) = 0
lseek(14, 0, SEEK_CUR)                  = 0
read(14, "(narinfo (version 2) (cache-uri \"https://ci.guix.gnu.org\") (date 1620414701) (ttl 3600) (value #f))", 4096) = 99
close(14)                               = 0
write(4, "\n", 1)                       = 1
--8<---------------cut here---------------end--------------->8---

The “debug” output substitute is available, but not “out”, and the
daemon keeps asking alternatively for “out” (twice) and “debug” (once)
in a loop.

At that point, ‘guix build’ is stuck waiting for the reply to its
‘build-derivations’ RPC, so the problem appears to be in the daemon.

Running ‘guix build --debug=4 …’ shows this:

--8<---------------cut here---------------start------------->8---
|   |   substitution of `/gnu/store/2lfh3rblh0a38s36q7xyhkac6l5kknw3-guile-ssh-0.11.3-debug': created
|   |   substitution of `/gnu/store/2lfh3rblh0a38s36q7xyhkac6l5kknw3-guile-ssh-0.11.3-debug': woken up
|   |   substitution of `/gnu/store/q89w5vk8lyw4jw9knd104qk3381b03dw-guile-ssh-0.11.3': created
|   |   substitution of `/gnu/store/q89w5vk8lyw4jw9knd104qk3381b03dw-guile-ssh-0.11.3': woken up
|   |   substitution of `/gnu/store/q89w5vk8lyw4jw9knd104qk3381b03dw-guile-ssh-0.11.3': init
|   |   acquiring write lock on `/var/guix/temproots/18129'
|   |   downgrading to read lock on `/var/guix/temproots/18129'
|   |   substitution of `/gnu/store/q89w5vk8lyw4jw9knd104qk3381b03dw-guile-ssh-0.11.3': trying substituter
|   |   path `/gnu/store/q89w5vk8lyw4jw9knd104qk3381b03dw-guile-ssh-0.11.3' is required, but there is no substituter that can build it
|   |   substitution of `/gnu/store/q89w5vk8lyw4jw9knd104qk3381b03dw-guile-ssh-0.11.3': done
|   |   building of `/gnu/store/1k8lgjs4al3gp3hri73wrbslbqa16hac-guile-ssh-0.11.3.drv': waitee `substitution of `/gnu/store/q89w5vk8lyw4jw9knd104qk3381b03dw-guile-ssh-0.11.3'' done; 1 left
|   |   substitution of `/gnu/store/2lfh3rblh0a38s36q7xyhkac6l5kknw3-guile-ssh-0.11.3-debug': init
|   |   acquiring write lock on `/var/guix/temproots/18129'
|   |   downgrading to read lock on `/var/guix/temproots/18129'
|   |   substitution of `/gnu/store/2lfh3rblh0a38s36q7xyhkac6l5kknw3-guile-ssh-0.11.3-debug': trying substituter
|   |   substitution of `/gnu/store/4sqps8dczv3g7rwbdibfz6rf5jlk7w90-gcc-5.5.0-lib': created
|   |   substitution of `/gnu/store/4sqps8dczv3g7rwbdibfz6rf5jlk7w90-gcc-5.5.0-lib': woken up
|   |   substitution of `/gnu/store/9alic3caqhay3h8mx4iihpmyj6ymqpcx-guile-2.2.4': created
|   |   substitution of `/gnu/store/9alic3caqhay3h8mx4iihpmyj6ymqpcx-guile-2.2.4': woken up
|   |   substitution of `/gnu/store/h90vnqw0nwd0hhm1l5dgxsdrigddfmq4-glibc-2.28': created
|   |   substitution of `/gnu/store/h90vnqw0nwd0hhm1l5dgxsdrigddfmq4-glibc-2.28': woken up
|   |   substitution of `/gnu/store/ljig01r4nazpjijhvmvrfwhv03ypc9a6-libssh-0.9.0': created
|   |   substitution of `/gnu/store/ljig01r4nazpjijhvmvrfwhv03ypc9a6-libssh-0.9.0': woken up
|   |   substitution of `/gnu/store/q89w5vk8lyw4jw9knd104qk3381b03dw-guile-ssh-0.11.3': created
|   |   substitution of `/gnu/store/q89w5vk8lyw4jw9knd104qk3381b03dw-guile-ssh-0.11.3': woken up
|   |   substitution of `/gnu/store/q89w5vk8lyw4jw9knd104qk3381b03dw-guile-ssh-0.11.3': goal destroyed
|   |   substitution of `/gnu/store/4sqps8dczv3g7rwbdibfz6rf5jlk7w90-gcc-5.5.0-lib': init
|   |   acquiring write lock on `/var/guix/temproots/18129'
|   |   downgrading to read lock on `/var/guix/temproots/18129'
|   |   substitution of `/gnu/store/4sqps8dczv3g7rwbdibfz6rf5jlk7w90-gcc-5.5.0-lib': done
|   |   substitution of `/gnu/store/2lfh3rblh0a38s36q7xyhkac6l5kknw3-guile-ssh-0.11.3-debug': waitee `substitution of `/gnu/store/4sqps8dczv3g7rwbdibfz6rf5jlk7w90-gcc-5.5.0-lib'' done; 4 left
|   |   substitution of `/gnu/store/h90vnqw0nwd0hhm1l5dgxsdrigddfmq4-glibc-2.28': init
|   |   acquiring write lock on `/var/guix/temproots/18129'
|   |   downgrading to read lock on `/var/guix/temproots/18129'
|   |   substitution of `/gnu/store/h90vnqw0nwd0hhm1l5dgxsdrigddfmq4-glibc-2.28': done
|   |   substitution of `/gnu/store/2lfh3rblh0a38s36q7xyhkac6l5kknw3-guile-ssh-0.11.3-debug': waitee `substitution of `/gnu/store/h90vnqw0nwd0hhm1l5dgxsdrigddfmq4-glibc-2.28'' done; 3 left
|   |   substitution of `/gnu/store/9alic3caqhay3h8mx4iihpmyj6ymqpcx-guile-2.2.4': init
|   |   acquiring write lock on `/var/guix/temproots/18129'
|   |   downgrading to read lock on `/var/guix/temproots/18129'
|   |   substitution of `/gnu/store/9alic3caqhay3h8mx4iihpmyj6ymqpcx-guile-2.2.4': done
|   |   substitution of `/gnu/store/2lfh3rblh0a38s36q7xyhkac6l5kknw3-guile-ssh-0.11.3-debug': waitee `substitution of `/gnu/store/9alic3caqhay3h8mx4iihpmyj6ymqpcx-guile-2.2.4'' done; 2 left
|   |   substitution of `/gnu/store/q89w5vk8lyw4jw9knd104qk3381b03dw-guile-ssh-0.11.3': init
|   |   acquiring write lock on `/var/guix/temproots/18129'
|   |   downgrading to read lock on `/var/guix/temproots/18129'
|   |   substitution of `/gnu/store/q89w5vk8lyw4jw9knd104qk3381b03dw-guile-ssh-0.11.3': trying substituter
|   |   path `/gnu/store/q89w5vk8lyw4jw9knd104qk3381b03dw-guile-ssh-0.11.3' is required, but there is no substituter that can build it
|   |   substitution of `/gnu/store/q89w5vk8lyw4jw9knd104qk3381b03dw-guile-ssh-0.11.3': done
|   |   substitution of `/gnu/store/2lfh3rblh0a38s36q7xyhkac6l5kknw3-guile-ssh-0.11.3-debug': waitee `substitution of `/gnu/store/q89w5vk8lyw4jw9knd104qk3381b03dw-guile-ssh-0.11.3'' done; 1 left
|   |   substitution of `/gnu/store/ljig01r4nazpjijhvmvrfwhv03ypc9a6-libssh-0.9.0': init
|   |   acquiring write lock on `/var/guix/temproots/18129'
|   |   downgrading to read lock on `/var/guix/temproots/18129'
|   |   substitution of `/gnu/store/ljig01r4nazpjijhvmvrfwhv03ypc9a6-libssh-0.9.0': done
|   |   substitution of `/gnu/store/2lfh3rblh0a38s36q7xyhkac6l5kknw3-guile-ssh-0.11.3-debug': waitee `substitution of `/gnu/store/ljig01r4nazpjijhvmvrfwhv03ypc9a6-libssh-0.9.0'' done; 0 left
|   |   substitution of `/gnu/store/2lfh3rblh0a38s36q7xyhkac6l5kknw3-guile-ssh-0.11.3-debug': woken up
|   |   substitution of `/gnu/store/ljig01r4nazpjijhvmvrfwhv03ypc9a6-libssh-0.9.0': goal destroyed
|   |   substitution of `/gnu/store/q89w5vk8lyw4jw9knd104qk3381b03dw-guile-ssh-0.11.3': goal destroyed
|   |   substitution of `/gnu/store/9alic3caqhay3h8mx4iihpmyj6ymqpcx-guile-2.2.4': goal destroyed
|   |   substitution of `/gnu/store/h90vnqw0nwd0hhm1l5dgxsdrigddfmq4-glibc-2.28': goal destroyed
|   |   substitution of `/gnu/store/4sqps8dczv3g7rwbdibfz6rf5jlk7w90-gcc-5.5.0-lib': goal destroyed
|   |   substitution of `/gnu/store/2lfh3rblh0a38s36q7xyhkac6l5kknw3-guile-ssh-0.11.3-debug': all references realised
|   |   some references of path `/gnu/store/2lfh3rblh0a38s36q7xyhkac6l5kknw3-guile-ssh-0.11.3-debug' could not be realised
|   |   substitution of `/gnu/store/2lfh3rblh0a38s36q7xyhkac6l5kknw3-guile-ssh-0.11.3-debug': done
|   |   building of `/gnu/store/1k8lgjs4al3gp3hri73wrbslbqa16hac-guile-ssh-0.11.3.drv': waitee `substitution of `/gnu/store/2lfh3rblh0a38s36q7xyhkac6l5kknw3-guile-ssh-0.11.3-debug'' done; 0 left
|   |   building of `/gnu/store/1k8lgjs4al3gp3hri73wrbslbqa16hac-guile-ssh-0.11.3.drv': woken up
|   |   substitution of `/gnu/store/2lfh3rblh0a38s36q7xyhkac6l5kknw3-guile-ssh-0.11.3-debug': goal destroyed
|   |   building of `/gnu/store/1k8lgjs4al3gp3hri73wrbslbqa16hac-guile-ssh-0.11.3.drv': all outputs substituted (maybe)
--8<---------------cut here---------------end--------------->8---

Note “there is not substituter that can build it” (for “out”), as well
as the last line.

Nix commit 4ac4f675df3da01b6d814cd328dd3219dd472ac9 (from 2018) touches
code in this area.  To be continued…

Ludo’.




Severity set to 'important' from 'normal' Request was from Ludovic Courtès <ludo@gnu.org> to control@debbugs.gnu.org. (Thu, 12 Oct 2023 13:44:01 GMT) (full text, mbox, link).


Send a report that this bug log contains spam.


debbugs.gnu.org maintainers <help-debbugs@gnu.org>. Last modified: Sun Sep 8 03:21:15 2024; Machine Name: wallace-server

GNU bug tracking system

Debbugs is free software and licensed under the terms of the GNU Public License version 2. The current version can be obtained from https://bugs.debian.org/debbugs-source/.

Copyright © 1999 Darren O. Benham, 1997,2003 nCipher Corporation Ltd, 1994-97 Ian Jackson, 2005-2017 Don Armstrong, and many other contributors.