Subject: bug#37822: closed (Re: bug#37822: guile-fibers build failure)

From: [email-masked] (GNU bug Tracking System)
Date: Sun, 20 Oct 2019 12:51:02 +0000

Your bug report

#37822: guile-fibers build failure

which was filed against the guix package, has been closed.

The explanation is attached below, along with your original report.
If you require more details, please reply to [email-masked].

-- 
37822: http://debbugs.gnu.org/cgi/bugreport.cgi?bug=37822
GNU Bug Tracking System
Contact [email-masked] with problems

Subject: Re: bug#37822: guile-fibers build failure
From: Christopher Baines <[email-masked]>
To: [email-masked]
Date: Sun, 20 Oct 2019 13:50:09 +0100
List-Id: <debbugs-submit.debbugs.gnu.org>

Christopher Baines <[email-masked]> writes:

> The guile-fibers package seems to fail to build on some machines.
>
> starting phase `check'
> make  check-am
> make[1]: Entering directory '/tmp/guix-build-guile-fibers-1.0.0.drv-0/fibers-1.0.0'
> make  check-TESTS
> make[2]: Entering directory '/tmp/guix-build-guile-fibers-1.0.0.drv-0/fibers-1.0.0'
> assert #f equal to #f: ok
> assert #t terminates: ok
> assert (false-if-exception (begin (run-fibers) #t)) equal to #f: ok
> assert terminates: (run-fibers (lambda () (sleep 1)) #:drain? #t): ok (1.044672258 s)
> assert terminates: (run-fibers (lambda () (do-times 1 (spawn-fiber (lambda () #t)))) #:drain? #t): ok (0.034571671 s)
> assert terminates: (run-fibers (lambda () (do-times 10 (spawn-fiber (lambda () #t)))) #:drain? #t): ok (0.05742899 s)
> assert terminates: (run-fibers (lambda () (do-times 100 (spawn-fiber (lambda () #t)))) #:drain? #t): ok (0.022090434 s)
> assert terminates: (run-fibers (lambda () (do-times 1000 (spawn-fiber (lambda () #t)))) #:drain? #t): ok (0.110914993 s)
> assert terminates: (run-fibers (lambda () (do-times 10000 (spawn-fiber (lambda () #t)))) #:drain? #t): ok (0.110751905 s)
> assert terminates: (run-fibers (lambda () (do-times 100000 (spawn-fiber (lambda () #t)))) #:drain? #t): ok (0.747805854 s)
> assert terminates: (run-fibers (lambda () (do-times 100000 (spawn-fiber (lambda () #t) #:parallel? #t))) #:drain? #t): ok (1.116078927 s)
> assert terminates: (run-fibers (lambda () (do-times 100000 (spawn-fiber loop-to-1e4))) #:drain? #t): ok (396.536024374 s)
> assert terminates: (run-fibers (lambda () (do-times 100000 (spawn-fiber loop-to-1e4 #:parallel? #t))) #:drain? #t): ok (67.471703208 s)
> assert terminates: (run-fibers (lambda () (do-times 1 (spawn-fiber (lambda () (sleep 1))))) #:drain? #t): ok (1.027788168 s)
> assert terminates: (run-fibers (lambda () (do-times 10 (spawn-fiber (lambda () (sleep 1))))) #:drain? #t): /gnu/store/29jhbbg1hf557x8j53f9sxd9imlmf02a-bash-minimal-5.0.7/bin/bash: line 5:  2
> 445 Aborted                 top_srcdir="/tmp/guix-build-guile-fibers-1.0.0.drv-0/fibers-1.0.0" ./env /gnu/store/1mkkv2caiqbdbbd256c4dirfi4kwsacv-guile-2.2.6/bin/guile -s ${dir}$tst
> FAIL: tests/basic.scm
>
>
> This is from milano-guix-1, which has 32 cores. I'm a bit confused as to
> what is actually causing the test to fail. I'm guessing it could be
> timing out, but I can't see anything looking at the time the test takes
> to run.

I've now tried running the tests using Guix immediately prior to the
recent core-updates merge (d57660c54907cc6fba8b0adf6295fd2311ada6cf),
and immediately after the merge
(cf3d1763ede1a329c2bc932c84591ab594bb6c96) and the tests passed before,
and failed afterwards.

I've also tried running the tests manually, I did see a couple of times
a failure that mentioned about "Too many open files" [1].

I then attempted to raise the limit for open files, I think using
prlimit like `prlimit --nofile=8096:8096 --pid GUIX_DAEMON_PID` did the
trick, and that meant that I built the package sucessfully.

I'm thinking now that there's a relationship between the number of cores
the tests are run with, and the required file descriptors. Also, I'm
pretty sure this behaviour changed when core-updates was merged.

I'll close this bug for now, as I've found a way to build the package.

1:
make  check-TESTS
make[2]: Entering directory '/home/cbaines/fibers-1.0.0'
assert #f equal to #f: ok
assert #t terminates: ok
assert (false-if-exception (begin (run-fibers) #t)) equal to #f: ok
assert terminates: (run-fibers (lambda () (sleep 1)) #:drain? #t): ok (1.065373625 s)
assert terminates: (run-fibers (lambda () (do-times 1 (spawn-fiber (lambda () #t)))) #:drain? #t): ok (0.099213566 s)
assert terminates: (run-fibers (lambda () (do-times 10 (spawn-fiber (lambda () #t)))) #:drain? #t): ok (0.25544907 s)
assert terminates: (run-fibers (lambda () (do-times 100 (spawn-fiber (lambda () #t)))) #:drain? #t): ok (0.072169616 s)
assert terminates: (run-fibers (lambda () (do-times 1000 (spawn-fiber (lambda () #t)))) #:drain? #t): ok (0.02872572 s)
assert terminates: (run-fibers (lambda () (do-times 10000 (spawn-fiber (lambda () #t)))) #:drain? #t): ok (0.099789859 s)
assert terminates: (run-fibers (lambda () (do-times 100000 (spawn-fiber (lambda () #t)))) #:drain? #t): ok (0.560994013 s)
assert terminates: (run-fibers (lambda () (do-times 100000 (spawn-fiber (lambda () #t) #:parallel? #t))) #:drain? #t): ok (0.913570257 s)
assert terminates: (run-fibers (lambda () (do-times 100000 (spawn-fiber loop-to-1e4))) #:drain? #t): ok (7.429164661 s)
assert terminates: (run-fibers (lambda () (do-times 100000 (spawn-fiber loop-to-1e4 #:parallel? #t))) #:drain? #t): ok (1.135422681 s)
assert terminates: (run-fibers (lambda () (do-times 1 (spawn-fiber (lambda () (sleep 1))))) #:drain? #t): ok (1.020960002 s)
assert terminates: (run-fibers (lambda () (do-times 10 (spawn-fiber (lambda () (sleep 1))))) #:drain? #t): ok (1.065859212 s)
assert terminates: (run-fibers (lambda () (do-times 100 (spawn-fiber (lambda () (sleep 1))))) #:drain? #t): Backtrace:
In ice-9/boot-9.scm:
   222:29 19 (map1 (15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30))
   222:29 18 (map1 (16 17 18 19 20 21 22 23 24 25 26 27 28 29 30))
   222:29 17 (map1 (17 18 19 20 21 22 23 24 25 26 27 28 29 30))
   222:29 16 (map1 (18 19 20 21 22 23 24 25 26 27 28 29 30))
   222:29 15 (map1 (19 20 21 22 23 24 25 26 27 28 29 30))
   222:29 14 (map1 (20 21 22 23 24 25 26 27 28 29 30))
   222:29 13 (map1 (21 22 23 24 25 26 27 28 29 30))
   222:29 12 (map1 (22 23 24 25 26 27 28 29 30))
   222:29 11 (map1 (23 24 25 26 27 28 29 30))
   222:29 10 (map1 (24 25 26 27 28 29 30))
   222:29  9 (map1 (25 26 27 28 29 30))
   222:29  8 (map1 (26 27 28 29 30))
   222:29  7 (map1 (27 28 29 30))
   222:29  6 (map1 (28 29 30))
   222:29  5 (map1 (29 30))
   222:17  4 (map1 (30))
In fibers/internal.scm:
   149:14  3 (make-scheduler #:parallelism _ #:prompt-tag _)
In fibers/epoll.scm:
    94:31  2 (epoll-create #:close-on-exec? _ #:maxevents _)
    53:14  1 (make-wake-pipe)
In unknown file:
           0 (pipe)

ERROR: In procedure pipe:
In procedure pipe: Too many open files
FAIL: tests/basic.scm

Subject: guile-fibers build failure
From: Christopher Baines <[email-masked]>
To: [email-masked]
Date: Sat, 19 Oct 2019 09:50:53 +0100
List-Id: <debbugs-submit.debbugs.gnu.org>

The guile-fibers package seems to fail to build on some machines.

starting phase `check'
make  check-am
make[1]: Entering directory '/tmp/guix-build-guile-fibers-1.0.0.drv-0/fibers-1.0.0'
make  check-TESTS
make[2]: Entering directory '/tmp/guix-build-guile-fibers-1.0.0.drv-0/fibers-1.0.0'
assert #f equal to #f: ok
assert #t terminates: ok
assert (false-if-exception (begin (run-fibers) #t)) equal to #f: ok
assert terminates: (run-fibers (lambda () (sleep 1)) #:drain? #t): ok (1.044672258 s)
assert terminates: (run-fibers (lambda () (do-times 1 (spawn-fiber (lambda () #t)))) #:drain? #t): ok (0.034571671 s)
assert terminates: (run-fibers (lambda () (do-times 10 (spawn-fiber (lambda () #t)))) #:drain? #t): ok (0.05742899 s)
assert terminates: (run-fibers (lambda () (do-times 100 (spawn-fiber (lambda () #t)))) #:drain? #t): ok (0.022090434 s)
assert terminates: (run-fibers (lambda () (do-times 1000 (spawn-fiber (lambda () #t)))) #:drain? #t): ok (0.110914993 s)
assert terminates: (run-fibers (lambda () (do-times 10000 (spawn-fiber (lambda () #t)))) #:drain? #t): ok (0.110751905 s)
assert terminates: (run-fibers (lambda () (do-times 100000 (spawn-fiber (lambda () #t)))) #:drain? #t): ok (0.747805854 s)
assert terminates: (run-fibers (lambda () (do-times 100000 (spawn-fiber (lambda () #t) #:parallel? #t))) #:drain? #t): ok (1.116078927 s)
assert terminates: (run-fibers (lambda () (do-times 100000 (spawn-fiber loop-to-1e4))) #:drain? #t): ok (396.536024374 s)
assert terminates: (run-fibers (lambda () (do-times 100000 (spawn-fiber loop-to-1e4 #:parallel? #t))) #:drain? #t): ok (67.471703208 s)
assert terminates: (run-fibers (lambda () (do-times 1 (spawn-fiber (lambda () (sleep 1))))) #:drain? #t): ok (1.027788168 s)
assert terminates: (run-fibers (lambda () (do-times 10 (spawn-fiber (lambda () (sleep 1))))) #:drain? #t): /gnu/store/29jhbbg1hf557x8j53f9sxd9imlmf02a-bash-minimal-5.0.7/bin/bash: line 5:  2
445 Aborted                 top_srcdir="/tmp/guix-build-guile-fibers-1.0.0.drv-0/fibers-1.0.0" ./env /gnu/store/1mkkv2caiqbdbbd256c4dirfi4kwsacv-guile-2.2.6/bin/guile -s ${dir}$tst
FAIL: tests/basic.scm

This is from milano-guix-1, which has 32 cores. I'm a bit confused as to
what is actually causing the test to fail. I'm guessing it could be
timing out, but I can't see anything looking at the time the test takes
to run.

For comparison, this is a successful run for the above tests.

starting phase `check'
make  check-am
make[1]: Entering directory '/tmp/guix-build-guile-fibers-1.0.0.drv-0/fibers-1.0.0'
make  check-TESTS
make[2]: Entering directory '/tmp/guix-build-guile-fibers-1.0.0.drv-0/fibers-1.0.0'
assert #f equal to #f: ok
assert #t terminates: ok
assert (false-if-exception (begin (run-fibers) #t)) equal to #f: ok
assert terminates: (run-fibers (lambda () (sleep 1)) #:drain? #t): ok (1.005070844 s)
assert terminates: (run-fibers (lambda () (do-times 1 (spawn-fiber (lambda () #t)))) #:drain? #t): ok (0.0018557 s)
assert terminates: (run-fibers (lambda () (do-times 10 (spawn-fiber (lambda () #t)))) #:drain? #t): ok (0.001681844 s)
assert terminates: (run-fibers (lambda () (do-times 100 (spawn-fiber (lambda () #t)))) #:drain? #t): ok (0.024649538 s)
assert terminates: (run-fibers (lambda () (do-times 1000 (spawn-fiber (lambda () #t)))) #:drain? #t): ok (0.004700786 s)
assert terminates: (run-fibers (lambda () (do-times 10000 (spawn-fiber (lambda () #t)))) #:drain? #t): ok (0.039034647 s)
assert terminates: (run-fibers (lambda () (do-times 100000 (spawn-fiber (lambda () #t)))) #:drain? #t): ok (0.300057354 s)
assert terminates: (run-fibers (lambda () (do-times 100000 (spawn-fiber (lambda () #t) #:parallel? #t))) #:drain? #t): ok (0.324367502 s)
assert terminates: (run-fibers (lambda () (do-times 100000 (spawn-fiber loop-to-1e4))) #:drain? #t): ok (149.039109838 s)
assert terminates: (run-fibers (lambda () (do-times 100000 (spawn-fiber loop-to-1e4 #:parallel? #t))) #:drain? #t): ok (27.865951688 s)
assert terminates: (run-fibers (lambda () (do-times 1 (spawn-fiber (lambda () (sleep 1))))) #:drain? #t): ok (1.004129529 s)
assert terminates: (run-fibers (lambda () (do-times 10 (spawn-fiber (lambda () (sleep 1))))) #:drain? #t): ok (1.002370241 s)
assert terminates: (run-fibers (lambda () (do-times 100 (spawn-fiber (lambda () (sleep 1))))) #:drain? #t): ok (1.005520729 s)
assert terminates: (run-fibers (lambda () (do-times 1000 (spawn-fiber (lambda () (sleep 1))))) #:drain? #t): ok (1.062105807 s)
assert terminates: (run-fibers (lambda () (do-times 10000 (spawn-fiber (lambda () (sleep 1))))) #:drain? #t): ok (1.839309678 s)
assert terminates: (run-fibers (lambda () (do-times 20000 (spawn-fiber (lambda () (sleep 1))))) #:drain? #t): ok (2.814509145 s)
assert terminates: (run-fibers (lambda () (do-times 40000 (spawn-fiber (lambda () (sleep 1))))) #:drain? #t): ok (5.607027563 s)
assert terminates: (run-fibers (lambda () (spawn-fiber-tree 5 (lambda () (sleep 1)))) #:drain? #t): ok (1.011493675 s)
assert terminates: (run-fibers (lambda () (spawn-fiber-chain 5)) #:drain? #t): ok (0.016214238 s)
assert terminates: (run-fibers (lambda () (spawn-fiber-chain 50)) #:drain? #t): ok (0.00423236 s)
assert terminates: (run-fibers (lambda () (spawn-fiber-chain 500)) #:drain? #t): ok (0.003719253 s)
assert terminates: (run-fibers (lambda () (spawn-fiber-chain 5000)) #:drain? #t): ok (0.025188573 s)
assert terminates: (run-fibers (lambda () (spawn-fiber-chain 50000)) #:drain? #t): ok (0.250818527 s)
assert terminates: (run-fibers (lambda () (spawn-fiber-chain 500000)) #:drain? #t): ok (2.460237427 s)
assert terminates: (run-fibers (lambda () (spawn-fiber-chain 5000000)) #:drain? #t): ok (24.836223284 s)
assert terminates: (run-fibers (lambda () (test-run-order 10)) #:parallelism 1 #:drain? #t): ok (0.005306942 s)
assert terminates: (run-fibers (lambda () (test-wakeup-order 10)) #:parallelism 1 #:drain? #t): ok (2.40722e-4 s)
assert terminates: (run-fibers (lambda () 1) #:drain? #t): ok (0.001929389 s)
assert run-fiber-return-vals equal to (1): ok
assert terminates: (run-fibers (lambda () (do-times 20 (check-sleep (random 1.0)))) #:drain? #t): ;;; note: auto-compilation is enabled, set GUILE_AUTO_COMPILE=0
;;;       or pass the --no-auto-compile argument to disable.
;;; compiling /tmp/guix-build-guile-fibers-1.0.0.drv-0/fibers-1.0.0/./tests/basic.scm
;;; WARNING: compilation of /tmp/guix-build-guile-fibers-1.0.0.drv-0/fibers-1.0.0/./tests/basic.scm failed:
;;; failed to create path for auto-compiled file "/tmp/guix-build-guile-fibers-1.0.0.drv-0/fibers-1.0.0/./tests/basic.scm"
assert sleep 0.01910927417495763s < actual 0.019145132s: #t (diff: 0.18764619060916013%)
assert sleep 0.024869744140937303s < actual 0.024898784s: #t (diff: 0.11676782397972449%)
assert sleep 0.05190218899823896s < actual 0.051972101s: #t (diff: 0.13469952445245262%)
assert sleep 0.07769845538751641s < actual 0.077729954s: #t (diff: 0.04053956069847074%)
assert sleep 0.08845495012372985s < actual 0.088485864s: #t (diff: 0.03494872387232731%)
assert sleep 0.15580748281365422s < actual 0.155834698s: #t (diff: 0.017467188259705484%)
assert sleep 0.2606627789498001s < actual 0.260890831s: #t (diff: 0.08748930365842449%)
assert sleep 0.2673394552296189s < actual 0.267357932s: #t (diff: 0.006911351848632854%)
assert sleep 0.29310693200006604s < actual 0.293135829s: #t (diff: 0.009858859269136263%)
assert sleep 0.2934838551523557s < actual 0.293499175s: #t (diff: 0.005219996730773745%)
assert sleep 0.357478762512242s < actual 0.357505507s: #t (diff: 0.00748142003459793%)
assert sleep 0.4336257477895825s < actual 0.43383964s: #t (diff: 0.04932645524575758%)
assert sleep 0.4567640342315482s < actual 0.456969344s: #t (diff: 0.044948759767655215%)
assert sleep 0.47751651120863536s < actual 0.477539228s: #t (diff: 0.004757278718409239%)
assert sleep 0.4816563500411119s < actual 0.481682329s: #t (diff: 0.005393671003382431%)
assert sleep 0.5132483764237162s < actual 0.513301348s: #t (diff: 0.010320846342060342%)
assert sleep 0.5272744959176786s < actual 0.52729335s: #t (diff: 0.003575762239091523%)
assert sleep 0.777461044570536s < actual 0.777491122s: #t (diff: 0.003868673507706317%)
assert sleep 0.8278778710734596s < actual 0.827898268s: #t (diff: 0.0024637603266271747%)
assert sleep 0.9526730873636382s < actual 0.952835541s: #t (diff: 0.01705240113493354%)
ok (0.955494686 s)
PASS: tests/basic.scm