* Compilation time with Guile 3.0.3-to-be
@ 2020-06-04 7:50 Ludovic Courtès
2020-06-04 8:26 ` Christopher Baines
` (3 more replies)
0 siblings, 4 replies; 6+ messages in thread
From: Ludovic Courtès @ 2020-06-04 7:50 UTC (permalink / raw)
To: guix-devel, Andy Wingo
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’.
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: Compilation time with Guile 3.0.3-to-be
2020-06-04 7:50 Compilation time with Guile 3.0.3-to-be Ludovic Courtès
@ 2020-06-04 8:26 ` Christopher Baines
2020-06-04 9:50 ` Andy Wingo
` (2 subsequent siblings)
3 siblings, 0 replies; 6+ messages in thread
From: Christopher Baines @ 2020-06-04 8:26 UTC (permalink / raw)
To: guix-devel
[-- Attachment #1: Type: text/plain, Size: 705 bytes --]
Ludovic Courtès <ludo@gnu.org> writes:
> 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!
Indeed, thanks Andy! That's an amazing speedup :D
[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 962 bytes --]
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: Compilation time with Guile 3.0.3-to-be
2020-06-04 7:50 Compilation time with Guile 3.0.3-to-be Ludovic Courtès
2020-06-04 8:26 ` Christopher Baines
@ 2020-06-04 9:50 ` Andy Wingo
2020-06-04 13:29 ` Ludovic Courtès
2020-06-04 12:38 ` Katherine Cox-Buday
2020-06-04 12:45 ` Ludovic Courtès
3 siblings, 1 reply; 6+ messages in thread
From: Andy Wingo @ 2020-06-04 9:50 UTC (permalink / raw)
To: Ludovic Courtès; +Cc: guix-devel
Hi :)
On Thu 04 Jun 2020 09:50, Ludovic Courtès <ludo@gnu.org> writes:
> 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)
Nice!! Thanks for testing :-)
> 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)))
Here fwiw I would use -O1. It is basically the same as -O0 except that
it adds partial evaluation and it inlines primcalls. If you are willing
to do partial evaluation, you are probably willing to inline primcalls
too; I think it typically leads to less code and the compilation time is
similar to -O0.
> ((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)))
Interesting. I think this is probably a bug of some sort that we'll
have to keep working on.
> With the new -O1, the scheme->tree-il conversion (mostly macro
> expansion) accounts for half of the build time on large files:
>
> 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.
Interesting data :)
Note that in 3.0.3 there is also a new phase called "lowering". Before
a compiler from Tree-IL to language X is called, the tree-IL program is
"lowered" -- meaning canonicalized and optionally optimized.
(define (lower-exp exp env optimization-level opts)
(let ((make-lowerer (language-lowerer (lookup-language 'tree-il))))
((make-lowerer optimization-level opts) exp env)))
Similarly there is an analysis pass for warnings, which runs before
lowering:
(define (analyze-exp exp env warning-level warnings)
(let ((make-analyzer (language-analyzer (lookup-language 'tree-il))))
((make-analyzer warning-level warnings) exp env)))
These can be interesting to test different phases of the tree-il ->
bytecode path.
> The profile looks like this:
>
> 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
>
> It’d be great to waive the anonymity of that first lambda. :-)
I think I just fixed it :)
> 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!
I think the reap-pipes call is a pretty bad sign, incidentally!
Cheers,
Andy
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: Compilation time with Guile 3.0.3-to-be
2020-06-04 7:50 Compilation time with Guile 3.0.3-to-be Ludovic Courtès
2020-06-04 8:26 ` Christopher Baines
2020-06-04 9:50 ` Andy Wingo
@ 2020-06-04 12:38 ` Katherine Cox-Buday
2020-06-04 12:45 ` Ludovic Courtès
3 siblings, 0 replies; 6+ messages in thread
From: Katherine Cox-Buday @ 2020-06-04 12:38 UTC (permalink / raw)
To: Ludovic Courtès; +Cc: guix-devel
Ludovic Courtès <ludo@gnu.org> writes:
> So this part is ~2.5 times faster than before, yay! Thank you, Andy!
I find a sense of peace working on and with Guix. It seems to me that
Guix has the fundamentals correct, and so change feels like progress and
not churn. We seem to have the right people, working on the right
things, with empathy.
Also, Andy, I appreciated the addendum in your blog post. Thanks for
your efforts towards Guile too!
--
Katherine
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: Compilation time with Guile 3.0.3-to-be
2020-06-04 7:50 Compilation time with Guile 3.0.3-to-be Ludovic Courtès
` (2 preceding siblings ...)
2020-06-04 12:38 ` Katherine Cox-Buday
@ 2020-06-04 12:45 ` Ludovic Courtès
3 siblings, 0 replies; 6+ messages in thread
From: Ludovic Courtès @ 2020-06-04 12:45 UTC (permalink / raw)
To: guix-devel
[-- Attachment #1: Type: text/plain, Size: 314 bytes --]
Ludovic Courtès <ludo@gnu.org> skribis:
> 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:
Oh, here comes the attached patch.
Ludo’.
[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #2: Type: text/x-patch, Size: 2585 bytes --]
diff --git a/gnu/packages/guile.scm b/gnu/packages/guile.scm
index c2dc7f6d5f..2c9a9825e4 100644
--- a/gnu/packages/guile.scm
+++ b/gnu/packages/guile.scm
@@ -322,6 +322,41 @@ without requiring the source code to be rewritten.")
`(("bdw-gc" ,libgc-7)
,@(srfi-1:alist-delete "bdw-gc" (package-propagated-inputs guile-3.0)))))))
+(define-public guile-devel
+ (let ((commit "e2066d2e639ecc81078e83fcd7acd8b75faf27a3")
+ (revision "0"))
+ (package
+ (inherit guile-3.0)
+ (version (git-version (package-version guile-3.0)
+ revision commit))
+ (source (origin
+ (method git-fetch)
+ (uri (git-reference
+ (url "https://git.savannah.gnu.org/git/guile.git")
+ (commit commit)))
+ (file-name (git-file-name "guile" version))
+ (sha256
+ (base32
+ "1qipc4j2wbc2h22qsqp7n81ykclmnw8zxay06gqyaijk3nyf0bbn"))))
+ (arguments
+ (substitute-keyword-arguments (package-arguments guile-3.0)
+ ((#:phases phases '%standard-phases)
+ `(modify-phases ,phases
+ (add-before 'check 'skip-failing-tests
+ (lambda _
+ (setenv "XFAIL_TESTS" "test-out-of-memory")
+ (delete-file "test-suite/tests/version.test")
+ #t))))))
+ (native-inputs
+ `(("autoconf" ,autoconf)
+ ("automake" ,automake)
+ ("libtool" ,libtool)
+ ("flex" ,flex)
+ ("gettext" ,gnu-gettext)
+ ("texinfo" ,texinfo)
+ ("util-linux" ,util-linux) ;for 'rev', used in popen.test
+ ,@(package-native-inputs guile-3.0))))))
+
(define-public guile-3.0/fixed
;; A package of Guile that's rarely changed. It is the one used in the
;; `base' module, and thus changing it entails a full rebuild.
@@ -776,3 +811,4 @@ manipulate repositories of the Git version control system.")
;;; guile.scm ends here
+
diff --git a/guix/self.scm b/guix/self.scm
index 60fe6e6b01..7449406dc5 100644
--- a/guix/self.scm
+++ b/guix/self.scm
@@ -48,7 +48,7 @@
(let ((ref (lambda (module variable)
(module-ref (resolve-interface module) variable))))
(match-lambda
- ("guile" (ref '(gnu packages guile) 'guile-3.0/libgc-7))
+ ("guile" (ref '(gnu packages guile) 'guile-devel))
("guile-json" (ref '(gnu packages guile) 'guile-json-3))
("guile-ssh" (ref '(gnu packages ssh) 'guile-ssh))
("guile-git" (ref '(gnu packages guile) 'guile-git))
^ permalink raw reply related [flat|nested] 6+ messages in thread
* Re: Compilation time with Guile 3.0.3-to-be
2020-06-04 9:50 ` Andy Wingo
@ 2020-06-04 13:29 ` Ludovic Courtès
0 siblings, 0 replies; 6+ messages in thread
From: Ludovic Courtès @ 2020-06-04 13:29 UTC (permalink / raw)
To: Andy Wingo; +Cc: guix-devel
Hello!
Andy Wingo <wingo@igalia.com> skribis:
> On Thu 04 Jun 2020 09:50, Ludovic Courtès <ludo@gnu.org> writes:
[...]
>> 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)))
>
> Here fwiw I would use -O1. It is basically the same as -O0 except that
> it adds partial evaluation and it inlines primcalls. If you are willing
> to do partial evaluation, you are probably willing to inline primcalls
> too; I think it typically leads to less code and the compilation time is
> similar to -O0.
Alright, let’s do that.
>> ((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)))
>
> Interesting. I think this is probably a bug of some sort that we'll
> have to keep working on.
Yeah I think memory consumption increases noticeably with
letrectification, which in turns means more GC activity.
> Note that in 3.0.3 there is also a new phase called "lowering". Before
> a compiler from Tree-IL to language X is called, the tree-IL program is
> "lowered" -- meaning canonicalized and optionally optimized.
>
> (define (lower-exp exp env optimization-level opts)
> (let ((make-lowerer (language-lowerer (lookup-language 'tree-il))))
> ((make-lowerer optimization-level opts) exp env)))
>
> Similarly there is an analysis pass for warnings, which runs before
> lowering:
>
> (define (analyze-exp exp env warning-level warnings)
> (let ((make-analyzer (language-analyzer (lookup-language 'tree-il))))
> ((make-analyzer warning-level warnings) exp env)))
>
> These can be interesting to test different phases of the tree-il ->
> bytecode path.
OK, I’ll take a look.
>> The profile looks like this:
>>
>> 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
[...]
>> It’d be great to waive the anonymity of that first lambda. :-)
>
> I think I just fixed it :)
Yay, thank you, it’s much nicer now!
--8<---------------cut here---------------start------------->8---
scheme@(guile-user)> ,use(system base compile)
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
16.24 0.52 0.49 set-source-properties!
12.82 0.47 0.39 ice-9/boot-9.scm:3128:0:module-gensym
4.27 0.13 0.13 ice-9/popen.scm:168:0:reap-pipes
4.27 0.13 0.13 ice-9/psyntax.scm:749:8:search
3.42 0.13 0.10 ice-9/boot-9.scm:2201:0:%load-announce
3.42 0.10 0.10 ice-9/boot-9.scm:3434:11:b
3.42 0.10 0.10 read
3.42 0.10 0.10 source-properties
2.56 50.34 0.08 ice-9/threads.scm:388:4
2.56 12.56 0.08 ice-9/psyntax.scm:1611:10:parse
2.56 0.08 0.08 module-variable
2.56 0.08 0.08 memoize-expression
2.56 0.08 0.08 ice-9/psyntax.scm:668:4:make-binding-wrap
1.71 0.08 0.05 ice-9/boot-9.scm:2790:0:module-ref-submodule
1.71 0.05 0.05 number->string
1.71 0.05 0.05 ice-9/boot-9.scm:1396:0:symbol-append
1.71 0.05 0.05 append
1.71 0.05 0.05 string-append
0.85 270.25 0.03 ice-9/boot-9.scm:220:5:map1
--8<---------------cut here---------------end--------------->8---
Nowadays I freak out every time I see those weak hash tables show up. ;-)
Well, given the size of the file, it’s no surprise that
‘set-source-properties!’ is called a lot, but it’s still worrying that
it’s #1. (Perhaps an issue similar to <https://bugs.gnu.org/40194>?)
> I think the reap-pipes call is a pretty bad sign, incidentally!
Yeah, it was discussed recently and I can’t explain it:
https://lists.gnu.org/archive/html/guile-devel/2020-05/msg00019.html
Thanks for your feedback!
Ludo’.
^ permalink raw reply [flat|nested] 6+ messages in thread
end of thread, other threads:[~2020-06-04 13:30 UTC | newest]
Thread overview: 6+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2020-06-04 7:50 Compilation time with Guile 3.0.3-to-be Ludovic Courtès
2020-06-04 8:26 ` Christopher Baines
2020-06-04 9:50 ` Andy Wingo
2020-06-04 13:29 ` Ludovic Courtès
2020-06-04 12:38 ` Katherine Cox-Buday
2020-06-04 12:45 ` Ludovic Courtès
Code repositories for project(s) associated with this public inbox
https://git.savannah.gnu.org/cgit/guix.git
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).