GNU bug report logs - #21097
verify-store test failure on armhf-linux

Previous Next

Package: guix;

Reported by: Mark H Weaver <mhw <at> netris.org>

Date: Mon, 20 Jul 2015 19:07:01 UTC

Severity: normal

Tags: notabug, unreproducible

Done: Maxim Cournoyer <maxim.cournoyer <at> gmail.com>

Bug is archived. No further changes may be made.

To add a comment to this bug, you must first unarchive it, by sending
a message to control AT debbugs.gnu.org, with unarchive 21097 in the body.
You can then email your comments to 21097 AT debbugs.gnu.org in the normal way.

Toggle the display of automated, internal messages from the tracker.

View this report as an mbox folder, status mbox, maintainer mbox


Report forwarded to bug-guix <at> gnu.org:
bug#21097; Package guix. (Mon, 20 Jul 2015 19:07:01 GMT) Full text and rfc822 format available.

Acknowledgement sent to Mark H Weaver <mhw <at> netris.org>:
New bug report received and forwarded. Copy sent to bug-guix <at> gnu.org. (Mon, 20 Jul 2015 19:07:02 GMT) Full text and rfc822 format available.

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

From: Mark H Weaver <mhw <at> netris.org>
To: bug-guix <at> gnu.org
Subject: verify-store test failure on armhf-linux
Date: Mon, 20 Jul 2015 15:05:15 -0400
When building the guix-0.8.2.72cd8ec package on armhf-linux (using guix
from git b56724e), tests/store.scm fails.  Here's the relevant excerpt
from store.log:

--8<---------------cut here---------------start------------->8---
Test begin:
  test-name: "verify-store"
  source-file: "tests/store.scm"
  source-line: 638
  source-form: (test-assert "verify-store" (let* ((text (random-text)) (file1 (add-text-to-store %store "foo" text)) (file2 (add-text-to-store %store "bar" (random-text) (list file1)))) (and (pk (quote verify1) (verify-store %store)) (begin (delete-file file1) (not (pk (quote verify2) (verify-store %store)))) (begin (call-with-output-file file1 (lambda (port) (display text port))) (pk (quote verify3) (verify-store %store))))))
Test end:
  result-kind: fail
  actual-value: #f
  actual-error: (srfi-34 #<condition &nix-protocol-error [message: "invalidating path `/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/pp8ls5jri3l8x8y24g1x3h6lkj0lr4gv-bash-light-4.3.39-guile-builder' in database: FOREIGN KEY constraint failed" status: 1] 6112e8>)
--8<---------------cut here---------------end--------------->8---

and here's the relevant excerpt from test-suite.log:

--8<---------------cut here---------------start------------->8---
FAIL: tests/store
=================

accepted connection from pid 11899, user nixbld
spurious SIGPOLL
spurious SIGPOLL
accepted connection from pid 11899, user nixbld
accepted connection from pid 11899, user nixbld
random seed for tests: 1437429386
finding garbage collector roots...
spurious SIGPOLL
;;; note: auto-compilation is enabled, set GUILE_AUTO_COMPILE=0
;;;       or pass the --no-auto-compile argument to disable.
;;; compiling /tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/nix/scripts/list-runtime-roots
;;; compiled /tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/var/11882/cache-11882/guile/ccache/2.0-LE-4-2.0/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/nix/scripts/list-runtime-roots.go
removing stale temporary roots file `/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/var/11882/temproots/11918'
determining live/dead paths...
accepted connection from pid 11899, user nixbld
finding garbage collector roots...
spurious SIGPOLL
determining live/dead paths...
finding garbage collector roots...
determining live/dead paths...
finding garbage collector roots...
spurious SIGPOLL
deleting unused links...
accepted connection from pid 11899, user nixbld
finding garbage collector roots...
removing stale temporary roots file `/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/var/11882/temproots/11931'
deleting `/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/11qvkv7a29d8lr7i39xkc7ssxs937mq1-delete-me'
deleting `/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/trash'
deleting unused links...
note: currently hard linking saves 0.87 MiB
accepted connection from pid 11899, user nixbld
finding garbage collector roots...
removing stale temporary roots file `/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/var/11882/temproots/11934'
deleting `/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/slxqx1hirlk920mhda5q09l7ranxi49v-delete-me'
deleting `/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/trash'
deleting unused links...
note: currently hard linking saves 0.87 MiB
spurious SIGPOLL
@ build-started /tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/zc2jhjjv8l341zrnwgz6gjjb745m0pqy-the-thing.drv - armhf-linux /tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/var/log/guix/drvs/zc//2jhjjv8l341zrnwgz6gjjb745m0pqy-the-thing.drv.bz2
@ build-succeeded /tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/zc2jhjjv8l341zrnwgz6gjjb745m0pqy-the-thing.drv -
spurious SIGPOLL
spurious SIGPOLL
spurious SIGPOLL
@ build-started /tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/1jfk46pd0szlvfy0a2gdbn452p6px6hb-the-thing.drv - armhf-linux /tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/var/log/guix/drvs/1j//fk46pd0szlvfy0a2gdbn452p6px6hb-the-thing.drv.bz2
@ build-succeeded /tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/1jfk46pd0szlvfy0a2gdbn452p6px6hb-the-thing.drv -
@ build-started /tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/irn5b0434i1wz7xgf8l6s28rak05pnb2-the-thing.drv - armhf-linux /tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/var/log/guix/drvs/ir//n5b0434i1wz7xgf8l6s28rak05pnb2-the-thing.drv.bz2
@ build-succeeded /tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/irn5b0434i1wz7xgf8l6s28rak05pnb2-the-thing.drv -
accepted connection from pid 11899, user nixbld
spurious SIGPOLL
spurious SIGPOLL
spurious SIGPOLL
substitute: warning: authentication and authorization of substitutes disabled!
substitute: guix substitute: warning: ACL for archive imports seems to be uninitialized, substitutes may be unavailable
substitute: guix substitute: warning: failed to look up host 'hydra.gnu.org' (Name or service not known), substituter disabled
accepted connection from pid 11899, user nixbld
substitute: warning: authentication and authorization of substitutes disabled!
substitute: guix substitute: warning: ACL for archive imports seems to be uninitialized, substitutes may be unavailable
substitute: guix substitute: warning: failed to look up host 'hydra.gnu.org' (Name or service not known), substituter disabled
accepted connection from pid 11899, user nixbld
spurious SIGPOLL
substitute: warning: authentication and authorization of substitutes disabled!
substitute: guix substitute: warning: ACL for archive imports seems to be uninitialized, substitutes may be unavailable
accepted connection from pid 11899, user nixbld
accepted connection from pid 11899, user nixbld
substitute: warning: authentication and authorization of substitutes disabled!
substitute: guix substitute: warning: ACL for archive imports seems to be uninitialized, substitutes may be unavailable
accepted connection from pid 11899, user nixbld
substitute: warning: authentication and authorization of substitutes disabled!
substitute: guix substitute: warning: ACL for archive imports seems to be uninitialized, substitutes may be unavailable
substitute: guix substitute: warning: failed to look up host 'does-not-exist' (Name or service not known), substituter disabled
accepted connection from pid 11899, user nixbld
substitute: warning: authentication and authorization of substitutes disabled!
substitute: guix substitute: warning: ACL for archive imports seems to be uninitialized, substitutes may be unavailable
accepted connection from pid 11899, user nixbld
spurious SIGPOLL
substitute: warning: authentication and authorization of substitutes disabled!
substitute: guix substitute: warning: ACL for archive imports seems to be uninitialized, substitutes may be unavailable
@ substituter-started /tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/7qgyllsl6a5p2ajvmb50hhaf30j2g210-substitute-me /tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/nix/scripts/substitute
warning: authentication and authorization of substitutes disabled!
guix substitute: warning: ACL for archive imports seems to be uninitialized, substitutes may be unavailable
downloading `/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/7qgyllsl6a5p2ajvmb50hhaf30j2g210-substitute-me' (0.0 MiB installed)...
file:///.../example.nar	100.0% of 0.2 KiB (0. KiB/s)
@ substituter-succeeded /tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/7qgyllsl6a5p2ajvmb50hhaf30j2g210-substitute-me
accepted connection from pid 11899, user nixbld
spurious SIGPOLL
substitute: warning: authentication and authorization of substitutes disabled!
substitute: guix substitute: warning: ACL for archive imports seems to be uninitialized, substitutes may be unavailable
@ substituter-started /tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/z5vn02279xx3a53wgkpwjhyc958aqsb0-substitute-me /tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/nix/scripts/substitute
warning: authentication and authorization of substitutes disabled!
guix substitute: warning: ACL for archive imports seems to be uninitialized, substitutes may be unavailable
downloading `/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/z5vn02279xx3a53wgkpwjhyc958aqsb0-substitute-me' (0.0 MiB installed)...
file:///.../example.nar	100.0% of 0.2 KiB (0. KiB/s)
@ substituter-succeeded /tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/z5vn02279xx3a53wgkpwjhyc958aqsb0-substitute-me
accepted connection from pid 11899, user nixbld
spurious SIGPOLL
substitute: warning: authentication and authorization of substitutes disabled!
substitute: guix substitute: warning: ACL for archive imports seems to be uninitialized, substitutes may be unavailable
@ substituter-started /tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/5yjlx1h1vrrxwba8kqirr0g3hfzlwiaf-corrupt-substitute /tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/nix/scripts/substitute
warning: authentication and authorization of substitutes disabled!
guix substitute: warning: ACL for archive imports seems to be uninitialized, substitutes may be unavailable
downloading `/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/5yjlx1h1vrrxwba8kqirr0g3hfzlwiaf-corrupt-substitute' (0.0 MiB installed)...
file:///.../example.nar	100.0% of 0.1 KiB (0. KiB/s)
@ substituter-failed /tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/5yjlx1h1vrrxwba8kqirr0g3hfzlwiaf-corrupt-substitute 0 hash mismatch in downloaded path `/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/5yjlx1h1vrrxwba8kqirr0g3hfzlwiaf-corrupt-substitute': expected 0000000000000000000000000000000000000000000000000000000000000000, got b8f73a6eb280e63169b1de2a5b5e154676fe1ada685f1e5c7183cbb2c1dcd535
accepted connection from pid 11899, user nixbld
spurious SIGPOLL
substitute: warning: authentication and authorization of substitutes disabled!
substitute: guix substitute: warning: ACL for archive imports seems to be uninitialized, substitutes may be unavailable
@ substituter-started /tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/k3b1rdf0gpm5gf5bpajjdbfcavzyylc3-substitute-me-not /tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/nix/scripts/substitute
warning: authentication and authorization of substitutes disabled!
guix substitute: warning: ACL for archive imports seems to be uninitialized, substitutes may be unavailable
downloading `/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/k3b1rdf0gpm5gf5bpajjdbfcavzyylc3-substitute-me-not' (0.0 MiB installed)...
guix substitute: error: open-file: No such file or directory: "/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/var/11882/substituter-data/example.nar"
@ substituter-failed /tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/k3b1rdf0gpm5gf5bpajjdbfcavzyylc3-substitute-me-not 256 fetching path `/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/k3b1rdf0gpm5gf5bpajjdbfcavzyylc3-substitute-me-not' failed with exit code 1
@ substituter-started /tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/k3b1rdf0gpm5gf5bpajjdbfcavzyylc3-substitute-me-not /tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/nix/scripts/substitute
warning: authentication and authorization of substitutes disabled!
guix substitute: warning: ACL for archive imports seems to be uninitialized, substitutes may be unavailable
downloading `/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/k3b1rdf0gpm5gf5bpajjdbfcavzyylc3-substitute-me-not' (0.0 MiB installed)...
guix substitute: error: open-file: No such file or directory: "/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/var/11882/substituter-data/example.nar"
@ substituter-failed /tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/k3b1rdf0gpm5gf5bpajjdbfcavzyylc3-substitute-me-not 256 fetching path `/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/k3b1rdf0gpm5gf5bpajjdbfcavzyylc3-substitute-me-not' failed with exit code 1
@ build-started /tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/7p05inz3glbnq25gz9hmhnypcrdsvakh-substitute-me-not.drv - armhf-linux /tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/var/log/guix/drvs/7p//05inz3glbnq25gz9hmhnypcrdsvakh-substitute-me-not.drv.bz2
@ build-succeeded /tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/7p05inz3glbnq25gz9hmhnypcrdsvakh-substitute-me-not.drv -
spurious SIGPOLL
finding garbage collector roots...
deleting unused links...
spurious SIGPOLL
finding garbage collector roots...
deleting unused links...
finding garbage collector roots...
deleting unused links...
finding garbage collector roots...
deleting unused links...
warning: SQLite database is busy
spurious SIGPOLL
spurious SIGPOLL
finding garbage collector roots...
deleting unused links...
reading the Nix store...
reading the Nix store...
path `/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/2y1kd9wn0jzsyi2dylgrwda3fb48dmrk-foo' disappeared, but it still has valid referrers!
reading the Nix store...
path `/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/pp8ls5jri3l8x8y24g1x3h6lkj0lr4gv-bash-light-4.3.39-guile-builder' disappeared, removing from database...
accepted connection from pid 11899, user nixbld
warning: SQLite database is busy
substitute: warning: authentication and authorization of substitutes disabled!
substitute: guix substitute: warning: ACL for archive imports seems to be uninitialized, substitutes may be unavailable
fetching path `/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/p41xfgyizl8fbsx48vmfdrlzv6kbchf6-corrupt'...
warning: authentication and authorization of substitutes disabled!
guix substitute: warning: ACL for archive imports seems to be uninitialized, substitutes may be unavailable
downloading `/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/p41xfgyizl8fbsx48vmfdrlzv6kbchf6-corrupt' (0.0 MiB installed)...
file:///.../example.nar	100.0% of 0.2 KiB (0. KiB/s)
reading the Nix store...
checking path existence...
checking hashes...
reading the Nix store...
checking path existence...
checking hashes...
path `/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/p41xfgyizl8fbsx48vmfdrlzv6kbchf6-corrupt' was modified! expected hash `9651f97f6b1f9238ccfe2942cb09b9c2246abbd1a7a1fb07879a089aa572796c', got `e09c480e2e93336cd3c45aa129f81a0d7ba56c410b849d7779a8136074413b3d'
finding garbage collector roots...
removing stale temporary roots file `/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/var/11882/temproots/12103'
deleting `/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/p41xfgyizl8fbsx48vmfdrlzv6kbchf6-corrupt'
deleting `/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/trash'
deleting unused links...
note: currently hard linking saves 0.89 MiB
%%%% Starting test store  (Writing full log to "store.log")

;;; ("/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/var/log/guix/drvs/1j/fk46pd0szlvfy0a2gdbn452p6px6hb-the-thing.drv.bz2")

;;; ("/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/var/log/guix/drvs/ir/n5b0434i1wz7xgf8l6s28rak05pnb2-the-thing.drv.bz2")

;;; (spi (#<<substitutable> path: "/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/wmjyqgjm865fwrfflkgd1fzarlcpax0s-guile-bootstrap-2.0" deriver: "/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/k4d55b6f5qzm3nl0dkhb6k7hbjw4i06d-guile-bootstrap-2.0.drv" refs: () dl-size: 0 nar-size: 1234>))

;;; (corrupt #<condition &nix-protocol-error [message: "some substitutes for the outputs of derivation `/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/bvanpcwr75pqg20smknv6v1g0jm6gkxy-corrupt-substitute.drv' failed (usually happens due to networking issues); try `--fallback' to build derivation from source " status: 1] 73b210>)

;;; (c #<condition &nix-protocol-error [message: "signed hash doesn't match actual contents of imported archive; archive could be corrupt, or someone is trying to import a Trojan horse" status: 1] 854630>)

;;; (verify1 #t)

;;; (verify2 #f)
tests/store.scm:638: FAIL verify-store
# of expected passes      42
# of unexpected failures  1
./test-env: line 1: 11898 Terminated              "/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/pre-inst-env" "/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/guix-daemon" --disable-chroot --substitute-urls="$GUIX_BINARY_SUBSTITUTE_URL"
FAIL tests/store.scm (exit status: 1)
--8<---------------cut here---------------end--------------->8---




Information forwarded to bug-guix <at> gnu.org:
bug#21097; Package guix. (Mon, 20 Jul 2015 20:25:02 GMT) Full text and rfc822 format available.

Message #8 received at 21097 <at> debbugs.gnu.org (full text, mbox):

From: ludo <at> gnu.org (Ludovic Courtès)
To: Mark H Weaver <mhw <at> netris.org>
Cc: 21097 <at> debbugs.gnu.org
Subject: Re: bug#21097: verify-store test failure on armhf-linux
Date: Mon, 20 Jul 2015 22:24:01 +0200
Mark H Weaver <mhw <at> netris.org> skribis:

>   actual-error: (srfi-34 #<condition &nix-protocol-error [message: "invalidating path `/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/pp8ls5jri3l8x8y24g1x3h6lkj0lr4gv-bash-light-4.3.39-guile-builder' in database: FOREIGN KEY constraint failed" status: 1] 6112e8>)

Ouch.  This has been seen in Nix before:
<http://lists.science.uu.nl/pipermail/nix-dev/2011-December/007471.html>.

Is it 100% reproducible?

Thanks,
Ludo’.




Information forwarded to bug-guix <at> gnu.org:
bug#21097; Package guix. (Mon, 20 Jul 2015 23:26:02 GMT) Full text and rfc822 format available.

Message #11 received at 21097 <at> debbugs.gnu.org (full text, mbox):

From: Mark H Weaver <mhw <at> netris.org>
To: ludo <at> gnu.org (Ludovic Courtès)
Cc: 21097 <at> debbugs.gnu.org
Subject: Re: bug#21097: verify-store test failure on armhf-linux
Date: Mon, 20 Jul 2015 19:24:49 -0400
ludo <at> gnu.org (Ludovic Courtès) writes:

> Mark H Weaver <mhw <at> netris.org> skribis:
>
>> actual-error: (srfi-34 #<condition &nix-protocol-error [message:
> "invalidating path
> `/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/pp8ls5jri3l8x8y24g1x3h6lkj0lr4gv-bash-light-4.3.39-guile-builder'
> in database: FOREIGN KEY constraint failed" status: 1] 6112e8>)
>
> Ouch.  This has been seen in Nix before:
> <http://lists.science.uu.nl/pipermail/nix-dev/2011-December/007471.html>.
>
> Is it 100% reproducible?

Unfortunately, I've been unable to reproduce it.  I ran the same test in
the failed build directory 10 more times, and it succeeded all 10 times.
I then restarted the build and it built successfully.

     Mark




Added tag(s) unreproducible. Request was from ludo <at> gnu.org (Ludovic Courtès) to control <at> debbugs.gnu.org. (Fri, 11 Sep 2015 17:28:01 GMT) Full text and rfc822 format available.

Information forwarded to bug-guix <at> gnu.org:
bug#21097; Package guix. (Tue, 03 Nov 2015 22:42:02 GMT) Full text and rfc822 format available.

Message #16 received at 21097 <at> debbugs.gnu.org (full text, mbox):

From: ludo <at> gnu.org (Ludovic Courtès)
To: Mark H Weaver <mhw <at> netris.org>
Cc: 21097 <at> debbugs.gnu.org
Subject: Re: bug#21097: verify-store test failure on armhf-linux
Date: Tue, 03 Nov 2015 23:41:16 +0100
Mark H Weaver <mhw <at> netris.org> skribis:

> Test begin:
>   test-name: "verify-store"
>   source-file: "tests/store.scm"
>   source-line: 638
>   source-form: (test-assert "verify-store" (let* ((text (random-text)) (file1 (add-text-to-store %store "foo" text)) (file2 (add-text-to-store %store "bar" (random-text) (list file1)))) (and (pk (quote verify1) (verify-store %store)) (begin (delete-file file1) (not (pk (quote verify2) (verify-store %store)))) (begin (call-with-output-file file1 (lambda (port) (display text port))) (pk (quote verify3) (verify-store %store))))))
> Test end:
>   result-kind: fail
>   actual-value: #f
>   actual-error: (srfi-34 #<condition &nix-protocol-error [message: "invalidating path `/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/pp8ls5jri3l8x8y24g1x3h6lkj0lr4gv-bash-light-4.3.39-guile-builder' in database: FOREIGN KEY constraint failed" status: 1] 6112e8>)

[...]

> path `/tmp/nix-build-guix-0.8.2.72cd8ec.drv-0/source/test-tmp/store/pp8ls5jri3l8x8y24g1x3h6lkj0lr4gv-bash-light-4.3.39-guile-builder' disappeared, removing from database...

I’ve become convinced that this is due to parallelism: several
guix-daemon processes run at the same time.  In this case, I bet this
process tries to remove an item from the ValidPaths table while another
is trying to add it in the Refs table or something.

In dc57d527 I added #:parallel-tests? #f for ‘guix-devel’.  Eventually
we should fix the makefile to run this test alone, as is done for
‘guix-gc.sh’.

Thanks,
Ludo’.




Information forwarded to bug-guix <at> gnu.org:
bug#21097; Package guix. (Fri, 08 Jun 2018 08:22:01 GMT) Full text and rfc822 format available.

Message #19 received at 21097 <at> debbugs.gnu.org (full text, mbox):

From: Chris Marusich <cmmarusich <at> gmail.com>
To: ludo <at> gnu.org (Ludovic Courtès)
Cc: Mark H Weaver <mhw <at> netris.org>, 21097 <at> debbugs.gnu.org
Subject: Re: bug#21097: verify-store test failure on armhf-linux
Date: Fri, 08 Jun 2018 01:21:33 -0700
[Message part 1 (text/plain, inline)]
ludo <at> gnu.org (Ludovic Courtès) writes:

> I’ve become convinced that this is due to parallelism: several
> guix-daemon processes run at the same time.  In this case, I bet this
> process tries to remove an item from the ValidPaths table while another
> is trying to add it in the Refs table or something.
>
> In dc57d527 I added #:parallel-tests? #f for ‘guix-devel’.  Eventually
> we should fix the makefile to run this test alone, as is done for
> ‘guix-gc.sh’.

In the 2 years and 7 months since we disabled parallel tests in commit
dc57d527aee4eb18ec5fb345f90d6637bbd1a4d2 to work around this bug, we may
have allowed other parallelism bugs to quietly creep in.  Today, I
observed a parallel test failure that seems unrelated to the original
bug reported here.  And anecdotally, I feel that the tests frequently
fail spuriously when I run them in parallel.  Until we get to the bottom
of this, I agree that the best thing to do is to always run the tests in
serial.

For completeness, below I'll report the failure I observed today.

On my x86_64-linux GuixSD machine, using Guix version
0ec430f79530ee343c175347952f91a78adca5ec (this is what my
~/.config/guix/latest points to), I entered a Guix development
environment via "guix environment guix".  In Guix's Git repository, I
checked out commit 4dd91dff477b9717b3fa494b23976e4d69ab7dfc (the current
tip of core-updates) and ran the following commands:

    ./bootstrap && ./configure --localstatedir=/var && make -j \
        && make -j check

The following tests failed:

    FAIL: tests/guix-hash.sh
    FAIL: tests/guix-download.sh
    FAIL: tests/guix-build.sh
    FAIL: tests/guix-package.sh
    FAIL: tests/guix-system.sh

When I immediately ran "make recheck" without making any changes, the
same 5 tests passed.  Note that this ran the tests in serial because I
omitted -j.  When I ran the same 5 tests again in parallel using the
following command, they all passed:

    make -j check TESTS="tests/guix-hash.sh tests/guix-download.sh \
        tests/guix-build.sh tests/guix-package.sh tests/guix-system.sh"

I also tried running just tests/guix-hash.sh and tests/guix-download.sh
together 10 times in serial and then 10 times in parallel.
Unfortunately, this didn't reproduce the failure, either (i.e., all 20
test runs passed).

All in all, this seems to suggest that the failures I observed might be
caused by a parallelism bug when running the entire test suite.

Regarding the cause of failure, the 5 tests all failed with a message
like the following:

--8<---------------cut here---------------start------------->8---
ERROR: In procedure canonicalize-path:
In procedure canonicalize-path: No such file or directory
+ guix download --version
Backtrace:
In ice-9/boot-9.scm:
  2875:24 19 (_)
   222:17 18 (map1 (((guix utils)) ((guix config)) ((guix #)) ((…)) …))
  2788:17 17 (resolve-interface (guix utils) #:select _ #:hide _ # _ …)
  2714:10 16 (_ (guix utils) _ _ #:ensure _)
  2982:16 15 (try-module-autoload _ _)
   2312:4 14 (save-module-excursion #<procedure 1397630 at ice-9/boo…>)
  3002:22 13 (_)
In unknown file:
          12 (primitive-load-path "guix/utils" #<procedure 130d260 a…>)
In guix/utils.scm:
     26:0 11 (_)
In ice-9/boot-9.scm:
   2862:4 10 (define-module* _ #:filename _ #:pure _ #:version _ # _ …)
  2875:24  9 (_)
   222:17  8 (map1 (((guix config)) ((srfi srfi-1)) ((srfi #)) (#) …))
  2788:17  7 (resolve-interface (guix config) #:select _ #:hide _ # _ …)
  2714:10  6 (_ (guix config) _ _ #:ensure _)
  2982:16  5 (try-module-autoload _ _)
   2312:4  4 (save-module-excursion #<procedure 13975d0 at ice-9/boo…>)
  3002:22  3 (_)
In unknown file:
           2 (primitive-load-path "guix/config" #<procedure 130d1a0 …>)
In guix/config.scm:
     86:6  1 (_)
In unknown file:
           0 (canonicalize-path "/home/marusich/guix/test-tmp/db")
--8<---------------cut here---------------end--------------->8---

All the test failures looked the same, except that instead of "guix
download --version", the equivalent command (e.g., "guix system
--version") was invoked.

I realize this information doesn't help solve the original bug reported
here.  However, it's a real failure, so I hope it'll be useful.  In any
case, it shows that there are probably multiple parallelism bugs lurking
in our code now.  We're going to have to solve all those parallelism
bugs before we can reliably run the tests in parallel again.

-- 
Chris
[signature.asc (application/pgp-signature, inline)]

Added tag(s) notabug. Request was from Maxim Cournoyer <maxim.cournoyer <at> gmail.com> to control <at> debbugs.gnu.org. (Tue, 29 Aug 2023 03:11:02 GMT) Full text and rfc822 format available.

Reply sent to Maxim Cournoyer <maxim.cournoyer <at> gmail.com>:
You have taken responsibility. (Tue, 29 Aug 2023 03:11:02 GMT) Full text and rfc822 format available.

Notification sent to Mark H Weaver <mhw <at> netris.org>:
bug acknowledged by developer. (Tue, 29 Aug 2023 03:11:03 GMT) Full text and rfc822 format available.

Message #26 received at 21097-done <at> debbugs.gnu.org (full text, mbox):

From: Maxim Cournoyer <maxim.cournoyer <at> gmail.com>
To: ludo <at> gnu.org (Ludovic Courtès)
Cc: control <at> debbugs.gnu.org, 21097-done <at> debbugs.gnu.org
Subject: Re: bug#21097: verify-store test failure on armhf-linux
Date: Mon, 28 Aug 2023 23:09:56 -0400
tags 21097 + notabug
quit

Hello,

ludo <at> gnu.org (Ludovic Courtès) writes:

> tags 21097 unreproducible

Nearly 8 years later, I'm closing this forgotten, non-reproducible
issue.

-- 
Thanks,
Maxim




bug archived. Request was from Debbugs Internal Request <help-debbugs <at> gnu.org> to internal_control <at> debbugs.gnu.org. (Tue, 26 Sep 2023 11:24:11 GMT) Full text and rfc822 format available.

This bug report was last modified 205 days ago.

Previous Next


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