Re: [PATCH] build: pull: Compile .scm files in one process.

[Taylan Ulrich Bayırlı/Kammer]

address@hidden (Ludovic Courtès) writes:

> address@hidden (Taylan Ulrich "Bayırlı/Kammer") skribis:
>
>> It used to take ~18 minutes on my machine, now less than 3.
>
> Sounds compelling.  :-)
>
>> From fd5d9bf77fd38fad354d66c31e57bc9bbc86481f Mon Sep 17 00:00:00 2001
>> From: =?UTF-8?q?Taylan=20Ulrich=20Bay=C4=B1rl=C4=B1/Kammer?=
>>  <address@hidden>
>> Date: Thu, 5 Nov 2015 16:21:48 +0100
>> Subject: [PATCH] build: pull: Compile .scm files in one process.
>>
>> * guix/build/pull.scm (call-with-process): Removed procedure.
>> (report-build-progress): Removed procedure.
>> (p-for-each): Removed procedure.
>> (build-guix): Don't create subprocesses to compile the .scm files.
>
> [...]
>
>> -                        ;; Build guix/*.scm before gnu/*.scm to speed
>> -                        ;; things up.
>> -                        (sort (find-files out "\\.scm")
>> -                              (let ((guix (string-append out "/guix"))
>> -                                    (gnu  (string-append out "/gnu")))
>> -                                (lambda (a b)
>> -                                  (or (and (string-prefix? guix a)
>> -                                           (string-prefix? gnu b))
>> -                                      (string<? a b))))))))
>
> This logic should be kept (with this version of the patch, it starts
> compiling gnu.scm, which depends on many modules, so the progress report
> stays at 0% for maybe 30s and then suddenly reaches 20%.)

Ah, I see.  Indeed I was irritated by that long pause.

Sadly, when I reintroduce sorting, I get a different error:

=== snip ===
compiling...     17.9% of 463 filesBacktrace:
In ice-9/boot-9.scm:
2401: 19 [save-module-excursion #<procedure 3a86b40 at ice-9/boot-9.scm:3066:17 
()>]
3085: 18 [#<procedure 3a86b40 at ice-9/boot-9.scm:3066:17 ()>]
In unknown file:
   ?: 17 [primitive-load-path "gnu/packages/cross-base" ...]
In ice-9/eval.scm:
 505: 16 [#<procedure 79a6a0 at ice-9/eval.scm:499:4 (exp)> (define-module # # 
...)]
In ice-9/psyntax.scm:
1106: 15 [expand-top-sequence ((define-module # # # ...)) () ((top)) ...]
 989: 14 [scan ((define-module (gnu packages cross-base) #:use-module ...)) () 
...]
 279: 13 [scan ((#(syntax-object let # ...) (#) (# #) ...)) () ...]
In ice-9/eval.scm:
 411: 12 [eval # ()]
In ice-9/boot-9.scm:
2951: 11 [define-module* (gnu packages cross-base) #:filename ...]
2926: 10 [resolve-imports ((#) (#) (#) (#) ...)]
2864: 9 [resolve-interface (gnu packages commencement) #:select ...]
2789: 8 [#<procedure 84d4e0 at ice-9/boot-9.scm:2777:4 (name #:optional 
autoload version #:key ensure)> # ...]
3065: 7 [try-module-autoload (gnu packages commencement) #f]
2401: 6 [save-module-excursion #<procedure 3ad3a50 at ice-9/boot-9.scm:3066:17 
()>]
3085: 5 [#<procedure 3ad3a50 at ice-9/boot-9.scm:3066:17 ()>]
In unknown file:
   ?: 4 [primitive-load-path "gnu/packages/commencement" ...]
In ice-9/eval.scm:
 432: 3 Exception thrown while printing backtrace:
ERROR: In procedure package-location: Wrong type argument: Error while printing 
exception.

ice-9/boot-9.scm:106:20: In procedure #<procedure 3623e40 at 
ice-9/boot-9.scm:97:6 (thrown-k . args)>:
ice-9/boot-9.scm:106:20: In procedure package-version: Wrong type argument: 
Error while printing exception.
builder for `/gnu/store/94p9v7mgdl6n02skmbxnmmr82bxyz7bi-guix-latest.drv' 
failed with exit code 1
=== / snip ===

This prompted me to try a different hack which is to first *only* load
all module files and later compile them, but that produced a similar
error:

=== snip ===
Backtrace:
In ice-9/boot-9.scm:
3065: 19 [try-module-autoload (gnu packages cross-base) #f]
2401: 18 [save-module-excursion #<procedure 638cb10 at ice-9/boot-9.scm:3066:17 
()>]
3085: 17 [#<procedure 638cb10 at ice-9/boot-9.scm:3066:17 ()>]
In unknown file:
   ?: 16 [primitive-load-path "gnu/packages/cross-base" ...]
In ice-9/eval.scm:
 505: 15 [#<procedure 79a860 at ice-9/eval.scm:499:4 (exp)> (define-module # # 
...)]
In ice-9/psyntax.scm:
1106: 14 [expand-top-sequence ((define-module # # # ...)) () ((top)) ...]
 989: 13 [scan ((define-module (gnu packages cross-base) #:use-module ...)) () 
...]
 279: 12 [scan ((#(syntax-object let # ...) (#) (# #) ...)) () ...]
In ice-9/eval.scm:
 411: 11 [eval # ()]
In ice-9/boot-9.scm:
2951: 10 [define-module* (gnu packages cross-base) #:filename ...]
2926: 9 [resolve-imports ((#) (#) (#) (#) ...)]
2864: 8 [resolve-interface (gnu packages commencement) #:select ...]
2789: 7 [#<procedure 84e8a0 at ice-9/boot-9.scm:2777:4 (name #:optional 
autoload version #:key ensure)> # ...]
3065: 6 [try-module-autoload (gnu packages commencement) #f]
2401: 5 [save-module-excursion #<procedure 63b3c00 at ice-9/boot-9.scm:3066:17 
()>]
3085: 4 [#<procedure 63b3c00 at ice-9/boot-9.scm:3066:17 ()>]
In unknown file:
   ?: 3 [primitive-load-path "gnu/packages/commencement" ...]
In ice-9/eval.scm:
 432: 2 Exception thrown while printing backtrace:
ERROR: In procedure package-location: Wrong type argument: Error while printing 
exception.

ice-9/eval.scm:411:25: In procedure eval:
ice-9/eval.scm:411:25: In procedure package-version: Wrong type argument: Error 
while printing exception.
builder for `/gnu/store/cbd2vx8pbbhz098dfzwxj82n9h5lcvy4-guix-latest.drv' 
failed with exit code 1
=== / snip ===

I don't know if this relates to bug 15602, and I don't know how to
attempt to fix it.  Help appreciated.

>> +    ;; Compile the .scm files.  Also load every compiled file after writing 
>> it
>> +    ;; to work around <http://bugs.gnu.org/15602> (FIXME).
>> +    (let* ((files (filter (cut string-suffix? ".scm" <>)
>> +                          (find-files out "\\.scm")))
>> +           (total (length files)))
>> +      (let loop ((file (car files))
>> +                 (files (cdr files))
>> +                 (completed 0))
>> +        (display #\cr log-port)
>> +        (format log-port "compiling...\t~5,1f% of ~d files" ;FIXME: i18n
>> +                (* 100. (/ completed total)) total)
>> +        (force-output log-port)
>> +        (let ((go (string-append (string-drop-right file 4)
>> +                                 ".go")))
>> +          (format debug-port "~%compiling '~a'...~%" file)
>> +          (parameterize ((current-warning-port debug-port))
>> +            (compile-file file
>> +                          #:output-file go
>> +                          #:opts
>> +                          %auto-compilation-options)
>> +            (load-compiled go)))
>
> So this simple ‘load-compiled’ call addresses
> <http://bugs.gnu.org/15602>, right?  This is where the comment and
> explanation about this bug should go.
>
> The ‘load-compiled’ code seems to be the only difference with 52af657a,
> which was right before we noticed #15602 (which led to 178f77b2.)

The load-compiled trick at the very least works with the test case you
provided in #15602, although given the above error I'm not sure if it's
perhaps an incomplete work-around.

For now I only posted the work-around there; if we discover that the
above error is related, then I can post that there too, ideally after
finding another minimal test case demonstrating it.

> Another stylistic issue: please use ‘match’ instead of the unnameable
> primitives.  ;-)
>
> Could you send an updated patch?

Hehe, sure, here's a patch for the interim without the sorting, that
uses 'match'.  Is it fine the way I use it?

>From 428ef9840d0bfa594845fd5dc899083256155c28 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Taylan=20Ulrich=20Bay=C4=B1rl=C4=B1/Kammer?=
 <address@hidden>
Date: Thu, 5 Nov 2015 23:43:20 +0100
Subject: [PATCH] build: pull: Compile .scm files in one process.

* guix/build/pull.scm (call-with-process): Removed procedure.
(report-build-progress): Removed procedure.
(p-for-each): Removed procedure.
(build-guix): Don't create subprocesses to compile the .scm files.
---
 guix/build/pull.scm | 120 ++++++++++++----------------------------------------
 1 file changed, 26 insertions(+), 94 deletions(-)

diff --git a/guix/build/pull.scm b/guix/build/pull.scm
index 281be23..f921913 100644
--- a/guix/build/pull.scm
+++ b/guix/build/pull.scm
@@ -33,75 +33,10 @@
 ;;;
 ;;; Code:
 
-(define (call-with-process thunk)
-  "Run THUNK in a separate process that will return 0 if THUNK terminates
-normally, and 1 if an exception is raised."
-  (match (primitive-fork)
-    (0
-     (catch #t
-       (lambda ()
-         (thunk)
-         (primitive-exit 0))
-       (lambda (key . args)
-         (print-exception (current-error-port) #f key args)
-         (primitive-exit 1))))
-    (pid
-     #t)))
-
-(define* (report-build-progress total completed cont
-                                #:optional (log-port (current-error-port)))
-  "Report that COMPLETED out of TOTAL files have been completed, and call
-CONT."
-  (display #\cr log-port)
-  (format log-port "compiling...\t~5,1f% of ~d files" ;FIXME: i18n
-          (* 100. (/ completed total)) total)
-  (force-output log-port)
-  (cont))
-
-(define* (p-for-each proc lst
-                     #:optional (max-processes (current-processor-count))
-                     #:key (progress report-build-progress))
-  "Invoke PROC for each element of LST in a separate process, using up to
-MAX-PROCESSES processes in parallel.  Call PROGRESS at each step, passing it
-the continuation.  Raise an error if one of the processes exit with non-zero."
-  (define total
-    (length lst))
-
-  (define (wait-for-one-process)
-    (match (waitpid WAIT_ANY)
-      ((_ . status)
-       (unless (zero? (status:exit-val status))
-         (error "process failed" proc status)))))
-
-  (let loop ((lst       lst)
-             (running   0)
-             (completed 0))
-    (match lst
-      (()
-       (or (zero? running)
-           (let ((running   (- running 1))
-                 (completed (+ completed 1)))
-             (wait-for-one-process)
-             (progress total completed
-                       (lambda ()
-                         (loop lst running completed))))))
-      ((head . tail)
-       (if (< running max-processes)
-           (let ((running (+ 1 running)))
-             (call-with-process (cut proc head))
-             (progress total completed
-                       (lambda ()
-                         (loop tail running completed))))
-           (let ((running   (- running 1))
-                 (completed (+ completed 1)))
-             (wait-for-one-process)
-             (progress total completed
-                       (lambda ()
-                         (loop lst running completed)))))))))
-
 (define* (build-guix out source
                      #:key gcrypt
-                     (debug-port (%make-void-port "w")))
+                     (debug-port (%make-void-port "w"))
+                     (log-port (current-error-port)))
   "Build and install Guix in directory OUT using SOURCE, a directory
 containing the source code.  Write any debugging output to DEBUG-PORT."
   (setvbuf (current-output-port) _IOLBF)
@@ -130,33 +65,30 @@ containing the source code.  Write any debugging output to 
DEBUG-PORT."
     (set! %load-path (cons out %load-path))
     (set! %load-compiled-path (cons out %load-compiled-path))
 
-    ;; Compile the .scm files.  Do that in independent processes, à la
-    ;; 'make -j', to work around <http://bugs.gnu.org/15602> (FIXME).
-    ;; This ensures correctness, but is overly conservative and slow.
-    ;; The solution initially implemented (and described in the bug
-    ;; above) was slightly faster but consumed memory proportional to the
-    ;; number of modules, which quickly became unacceptable.
-    (p-for-each (lambda (file)
-                  (let ((go (string-append (string-drop-right file 4)
-                                           ".go")))
-                    (format debug-port "~%compiling '~a'...~%" file)
-                    (parameterize ((current-warning-port debug-port))
-                      (compile-file file
-                                    #:output-file go
-                                    #:opts
-                                    %auto-compilation-options))))
-
-                (filter (cut string-suffix? ".scm" <>)
-
-                        ;; Build guix/*.scm before gnu/*.scm to speed
-                        ;; things up.
-                        (sort (find-files out "\\.scm")
-                              (let ((guix (string-append out "/guix"))
-                                    (gnu  (string-append out "/gnu")))
-                                (lambda (a b)
-                                  (or (and (string-prefix? guix a)
-                                           (string-prefix? gnu b))
-                                      (string<? a b))))))))
+    ;; Compile the .scm files.  Also load every compiled file after writing it
+    ;; to work around <http://bugs.gnu.org/15602> (FIXME).
+    (let* ((files (filter (cut string-suffix? ".scm" <>)
+                          (find-files out "\\.scm")))
+           (total (length files)))
+      (let loop ((files files)
+                 (completed 0))
+        (match files
+          (() *unspecified*)
+          ((file . files)
+           (display #\cr log-port)
+           (format log-port "compiling...\t~5,1f% of ~d files" ;FIXME: i18n
+                   (* 100. (/ completed total)) total)
+           (force-output log-port)
+           (let ((go (string-append (string-drop-right file 4)
+                                    ".go")))
+             (format debug-port "~%compiling '~a'...~%" file)
+             (parameterize ((current-warning-port debug-port))
+               (compile-file file
+                             #:output-file go
+                             #:opts
+                             %auto-compilation-options)
+               (load-compiled go)))
+           (loop files (+ 1 completed)))))))
 
   ;; Remove the "fake" (guix config).
   (delete-file (string-append out "/guix/config.scm"))
-- 
2.5.0