Compilation time with Guile 3.0.3-to-be

["Ludovic Courtès" <ludo@gnu.org>]

Hello!

Here’s a followup to Andy’s great blog post about the new “baseline
compiler” that’ll be in Guile 3.0.3:

  https://wingolog.org/archives/2020/06/03/a-baseline-compiler-for-guile

With the attached patch I’ve run ‘make as-derivation’ (equivalent to
‘guix pull’) and timed the builds of guix-packages-base.drv (279 files)
and guix-packages.drv (217 files) on my 4-core i7 laptop:

  • guix-packages-base.drv: 1m30s (was 4m)

  • guix-packages.drv: 30s (was 1m8s)

So this part is ~2.5 times faster than before, yay!  Thank you, Andy!
This is quite an achievement, especially given that, before compiling,
there’s an initial phase during which we load all the files, and that
phase is sequential and takes the same amount of time in both cases.

For the record, the optimizations currently used in (guix build compile)
are between the new -O0 and -O1:

  (cond ((or (string-contains file "gnu/packages/")
             (string-contains file "gnu/tests/"))
         ;; Level 0 is good enough but partial evaluation helps preserve the
         ;; "macro writer's bill of rights".
         (override-option #:partial-eval? #t
                          (optimizations-for-level 0)))
        ((string-contains file "gnu/services/")
         ;; '-O2 -Ono-letrectify' compiles about ~20% faster than '-O2' for
         ;; large files like gnu/services/mail.scm.
         (override-option #:letrectify? #f
                          (optimizations-for-level 2)))
        (else
         (optimizations-for-level 3)))

With the new -O1, the scheme->tree-il conversion (mostly macro
expansion) accounts for half of the build time on large files:

--8<---------------cut here---------------start------------->8---
scheme@(guile-user)> ,use(system base optimize)
scheme@(guile-user)> ,time (compile-file "gnu/packages/python-xyz.scm" #:opts (optimizations-for-level 1))
$1 = "/data/src/guile-3.0/cache/guile/ccache/3.0-LE-8-4.3/home/ludo/src/guix/gnu/packages/python-xyz.scm.go"
;; 4.154311s real time, 5.604945s run time.  2.538106s spent in GC.
--8<---------------cut here---------------end--------------->8---

vs.:

--8<---------------cut here---------------start------------->8---
scheme@(guile-user)> ,use(system base compile)
scheme@(guile-user)> ,time (define t (call-with-input-file  "gnu/packages/python-xyz.scm" (lambda (port) (read-and-compile port #:to 'tree-il))))
;; 2.206563s real time, 3.057369s run time.  1.339261s spent in GC.
--8<---------------cut here---------------end--------------->8---

The profile looks like this:

--8<---------------cut here---------------start------------->8---
scheme@(guile-user)> ,pr (define t (call-with-input-file  "gnu/packages/python-xyz.scm" (lambda (port) (read-and-compile port #:to 'tree-il))))
%     cumulative   self             
time   seconds     seconds  procedure
 13.16      0.45      0.40  anon #x1136458
 10.53      0.35      0.32  ice-9/popen.scm:168:0:reap-pipes
  7.89      0.24      0.24  anon #x1132af8
  6.14      0.35      0.19  ice-9/boot-9.scm:3128:0:module-gensym
  5.26      0.21      0.16  ice-9/boot-9.scm:2201:0:%load-announce
  4.39      0.19      0.13  ice-9/psyntax.scm:749:8:search
  3.51      0.69      0.11  ice-9/psyntax.scm:2964:6:match*
  3.51      0.11      0.11  anon #x11334e8
  3.51      0.11      0.11  anon #x1136428
  2.63      0.08      0.08  anon #x113a258
  1.75      0.05      0.05  ice-9/psyntax.scm:3017:12:$sc-dispatch
  1.75      0.05      0.05  anon #x1139e68
  0.88    277.30      0.03  ice-9/boot-9.scm:220:5:map1
--8<---------------cut here---------------end--------------->8---

It’d be great to waive the anonymity of that first lambda.  :-)
I was wondering what fraction of that time was spent running Guix macros
(‘package’, ‘base32’, and so on), but it’s difficult to answer that
question here.  Probably something to investigate so we can make further
progress!

Ludo’.