Problems running 'check-system'

[Chris Marusich]

Hi,

I'm having trouble running the system tests.  There are three issues:

Issue #1: I've noticed that I have to run 'make' before running 'make
check-system'.  An example will illustrate what I mean.

The following invocation fails in a clean checkout of master (in an
environment created via 'guix environment --pure guix'):

  ./bootstrap
  ./configure --localstatedir=/var
  make -j check-system TESTS=installed-os

It fails with this error message:

--8<---------------cut here---------------start------------->8---
[... some output omitted for brevity ...]

GUILEC   guix/scripts/copy.go
  GUILEC   guix/store/ssh.go
  GUILEC   guix/scripts/offload.go
  GUILEC   guix/config.go
  GUILEC   guix/tests.go
  GUILEC   guix/tests/http.go
;;; note: source file /home/marusich/guix/./build-aux/run-system-tests.scm
;;;       newer than compiled 
/home/marusich/.cache/guile/ccache/2.0-LE-8-2.0/home/marusich/guix/build-aux/run-system-tests.scm.go
In execvp of git: No such file or directory
Running 1 system tests...
Backtrace:
In ice-9/boot-9.scm:
  66: 19 [call-with-prompt prompt0 ...]
In ice-9/eval.scm:
 432: 18 [eval # #]
In ice-9/r4rs.scm:
  90: 17 [dynamic-wind #<procedure 3816e20 at ice-9/boot-9.scm:1143:2 _> ...]
In guix/store.scm:
1332: 16 [run-with-store # #<procedure 42f0d50 at ice-9/eval.scm:416:20 (a)> # 
...]
In ice-9/r4rs.scm:
  39: 15 [call-with-values #<procedure 42f0ae0 at ice-9/eval.scm:416:20 ()> ...]
In guix/monads.scm:
 376: 14 [#<procedure 42f0db0 at guix/monads.scm:373:2 (state)> #]
 376: 13 [#<procedure 42f0de0 at guix/monads.scm:373:2 (state)> #]
 376: 12 [#<procedure 42f0e40 at guix/monads.scm:373:2 (state)> #]
In gnu/tests/install.scm:
 230: 11 [#<procedure 389bca0 at gnu/tests/install.scm:230:4 (state)> #]
 142: 10 [#<procedure 48017e0 at gnu/tests/install.scm:142:2 (state)> #]
In gnu/services.scm:
 268: 9 [#<procedure 4801810 at gnu/services.scm:268:2 (state)> #]
In gnu/system.scm:
 275: 8 [#<procedure 4327240 at gnu/system.scm:275:2 (state)> #]
In guix/gexp.scm:
 604: 7 [#<procedure 480b900 at guix/gexp.scm:604:2 (state)> #]
 487: 6 [#<procedure 47ff680 at guix/gexp.scm:487:4 (state)> #]
 490: 5 [#<procedure 4803600 at guix/gexp.scm:490:22 (state)> #]
In guix/store.scm:
1252: 4 [#<procedure 4803630 at guix/store.scm:1251:28 (store)> #]
In guix/packages.scm:
 806: 3 [cache! #<weak-key-hash-table 1cc0dc0 0/113> # # ...]
1121: 2 [thunk]
1053: 1 [bag->derivation # # #]
In srfi/srfi-1.scm:
 575: 0 [map #<procedure 480c570 at guix/packages.scm:1055:30 
(t-9e7228c7bc8-578a)> ...]

srfi/srfi-1.scm:575:27: In procedure map:
srfi/srfi-1.scm:575:27: Throw to key `srfi-34' with args `(#<condition &message 
[message: "could not find bootstrap binary 'guile-2.0.9.tar.xz' for system 
'x86_64-linux'"] 4b62d80>)'.
make: *** [Makefile:5066: check-system] Error 1
[2] [env] address@hidden:~/guix
$ 
--8<---------------cut here---------------end--------------->8---

However, if I invoke 'make' first, then the "could not find bootstrap
binary" message does not show up, and the test proceeds to be run:

  ./bootstrap
  ./configure --localstatedir=/var
  make -j
  make -j check-system TESTS=installed-os

Is this expected?  I thought one of the benefits of using different
targets in a Makefile was so that you could invoke a specific target
(e.g., 'check-system') and only build the things necessary to run that
target.  It surprised me that I needed to also run the default target
first in this case.

Issue #2: even when I run 'make' first, the test fails.  It fails with
this message:

--8<---------------cut here---------------start------------->8---
[... some output omitted for brevity ...]

starting phase `copy-bootstrap-guile'
Backtrace:
In ice-9/boot-9.scm:
 160: 13 [catch #t #<catch-closure 8c5dc0> ...]
In unknown file:
   ?: 12 [apply-smob/1 #<catch-closure 8c5dc0>]
In ice-9/boot-9.scm:
  66: 11 [call-with-prompt prompt0 ...]
In ice-9/eval.scm:
 432: 10 [eval # #]
In ice-9/boot-9.scm:
2412: 9 [save-module-excursion #<procedure 8e6840 at ice-9/boot-9.scm:4084:3 
()>]
4089: 8 [#<procedure 8e6840 at ice-9/boot-9.scm:4084:3 ()>]
1734: 7 [%start-stack load-stack #<procedure 8f6e20 at ice-9/boot-9.scm:4080:10 
()>]
1739: 6 [#<procedure 8f8960 ()>]
In unknown file:
   ?: 5 [primitive-load 
"/gnu/store/wgh83kqjif20wfdg56iz7bxk9d4xmlk0-guix-0.12.0-9.25a4+-guile-builder"]
In ice-9/eval.scm:
 387: 4 [eval # ()]
In srfi/srfi-1.scm:
 827: 3 [every1 #<procedure f9fa40 at 
/gnu/store/a42pfdz8w5qxdkp6xz8783ydywmp0p8p-module-import/guix/build/gnu-build-system.scm:649:9
 (expr)> ...]
In 
/gnu/store/a42pfdz8w5qxdkp6xz8783ydywmp0p8p-module-import/guix/build/gnu-build-system.scm:
 653: 2 [#<procedure f9fa40 at 
/gnu/store/a42pfdz8w5qxdkp6xz8783ydywmp0p8p-module-import/guix/build/gnu-build-system.scm:649:9
 (expr)> #]
In ice-9/eval.scm:
 432: 1 [eval # #]
In unknown file:
   ?: 0 [copy-file 
"/gnu/store/dgncc5wmw8prxq09y71hqjc6g7rxqvvb-guile-2.0.9.tar.xz" ...]

ERROR: In procedure copy-file:
ERROR: In procedure copy-file: Permission denied
note: keeping build directory `/tmp/guix-build-guix-0.12.0-9.25a4+.drv-1'
builder for 
`/gnu/store/hm9bfka04gjbzjah7ilk3hp998bzdvqv-guix-0.12.0-9.25a4+.drv' failed 
with exit code 1
@ build-failed 
/gnu/store/hm9bfka04gjbzjah7ilk3hp998bzdvqv-guix-0.12.0-9.25a4+.drv - 1 builder 
for `/gnu/store/hm9bfka04gjbzjah7ilk3hp998bzdvqv-guix-0.12.0-9.25a4+.drv' 
failed with exit code 1
cannot build derivation 
`/gnu/store/1wc6ajd6mazb084ddl2mkpzcnkn42x2n-activate-service.drv': 1 
dependencies couldn't be built
cannot build derivation 
`/gnu/store/h1aw5zf5z7n5f51xa4dm0hz5b5n75gdm-ca-certificate-bundle.drv': 1 
dependencies couldn't be built
cannot build derivation 
`/gnu/store/lqkb3fxvqq7adakpgy5j4n6v05ycvd3n-fonts-dir.drv': 1 dependencies 
couldn't be built
cannot build derivation 
`/gnu/store/xvjycblb25lyd80mpxhf4azikzjz74bv-info-dir.drv': 1 dependencies 
couldn't be built
cannot build derivation 
`/gnu/store/n1dv7my6awklaplsk1j3j34dx5gqh3s1-manual-database.drv': 1 
dependencies couldn't be built
cannot build derivation 
`/gnu/store/khj9qjc52vgqmqkrwmmhr5iqqnz5h19g-shepherd-guix-daemon.scm.drv': 1 
dependencies couldn't be built
cannot build derivation 
`/gnu/store/azw92b3nf95gyqwx2lijzmqka43xfpn9-activate.drv': 1 dependencies 
couldn't be built
cannot build derivation 
`/gnu/store/91mp0bgpknv9i0x426m9w76pz4026qvn-profile.drv': 5 dependencies 
couldn't be built
cannot build derivation 
`/gnu/store/sl8mknzf3wsdcjjlp8w3zv1ng1s1kwhx-shepherd.conf.drv': 1 dependencies 
couldn't be built
cannot build derivation `/gnu/store/318yazn1vzp3814nny0x65jva7bn4ck7-boot.drv': 
2 dependencies couldn't be built
cannot build derivation 
`/gnu/store/igcd9wffmvnvyigjkxs2g277yfjahy8p-system.drv': 2 dependencies 
couldn't be built
cannot build derivation 
`/gnu/store/i34d0nscnns16amzkir0lly8763dhqdr-grub.cfg.drv': 1 dependencies 
couldn't be built
cannot build derivation 
`/gnu/store/c2vwrvygc5bnk1lh21qc4065m5ac9yx3-builder-in-linux-vm.drv': 2 
dependencies couldn't be built
cannot build derivation 
`/gnu/store/yfxmvgis6l03543c7yyqsq4awv1hl7m8-linux-vm-loader.drv': 1 
dependencies couldn't be built
cannot build derivation 
`/gnu/store/s4c5n2jf753vqk0bxmidjs4wxvzrjngr-disk-image.drv': 3 dependencies 
couldn't be built
cannot build derivation 
`/gnu/store/lji1bz94mgqd3v3cjb3h1pgbl6d23glv-installation.drv': 1 dependencies 
couldn't be built
cannot build derivation 
`/gnu/store/d074m8w00lgglwh84lrj7rasm703viw3-installed-os.drv': 1 dependencies 
couldn't be built
TOTAL: 1
FAIL: /gnu/store/cjqs0mc6vpkgzx7r7x24hz4r5hyqgink-installed-os
make: *** [Makefile:5066: check-system] Error 1
[2] [env] address@hidden:~/guix
$
--8<---------------cut here---------------end--------------->8---

Any idea why that's failing?  The file
/gnu/store/dgncc5wmw8prxq09y71hqjc6g7rxqvvb-guile-2.0.9.tar.xz is
readable by all users.  I tried to insert a "pk" in the file
guix/build/gnu-build-system.scm to see what the target of the copy
command was, but after about 24 hours (!!) of waiting for the subsequent
build to finish (for some reason this single-line change caused many
things to be rebuilt), I found that the build failed for a different,
apparently unrelated reason.  Quite unfortunate.

This brings me to Issue #3: the system tests appear to be unreliable and
impractical for day-to-day development.  Let me be clear: I really,
really want to like these system tests.  It's fantastic that the entire
system, its installation process, and other features can be tested
automatically.  I was hoping to hack around with them and eventually add
a system test for booting and installing from an ISO-9669 image.  But
with an iteration time of over 24 hours (like above) for a single-line
change, I don't know how helpful these tests really are for day-to-day
development.  I feel like I must be missing some kind of trick here to
speed up the iteration time.  Does anyone have any tips on how to speed
it up?  Maybe I'm missing something that's obvious to everyone else.

Finally, it seems like the system tests are not being run automatically
during the build of the Guix package, so I wonder if they're ever being
run by anyone at all.  Every time I've tried to run them recently,
they've failed, and my attempts to troubleshoot are frustrated by the
incredibly slow iteration time.  I have yet to find a commit on which
the system tests succeed, including the commit tagged for the v0.12.0
release.  I was hoping to find one so I could automatically bisect to
find out which commit introduced the I saw above, but at this rate I
doubt I'll be able to find one soon.

-- 
Chris

signature.asc
Description: PGP signature