unofficial mirror of guile-devel@gnu.org 
 help / color / mirror / Atom feed
* Compiler memory consumption
@ 2017-05-16 16:19 Ludovic Courtès
  2017-05-16 20:14 ` Andy Wingo
  0 siblings, 1 reply; 33+ messages in thread
From: Ludovic Courtès @ 2017-05-16 16:19 UTC (permalink / raw)
  To: guile-devel, Andy Wingo

[-- Attachment #1: Type: text/plain, Size: 15753 bytes --]

Hello!

Attached is a stripped-down version of Guix’s build-aux/compile-all.scm,
and here is the gcprof output I get while compiling
gnu/packages/python.scm, which defines 841 package objects (structs)
with 5 times more thunks of the form (lambda () value):

--8<---------------cut here---------------start------------->8---
$ ./pre-inst-env time guile --no-auto-compile profile-guilec.scm
  GUILEC   gnu/packages/python.go
%     cumulative   self             
time   seconds     seconds  procedure
 35.00     22.55     22.55  vector-copy
  6.67     17.18      4.30  language/cps/intset.scm:270:2:adjoin
  5.00      6.44      3.22  srfi/srfi-1.scm:590:5:map1
  3.33     31.14      2.15  ice-9/psyntax.scm:1521:10:rebuild-macro-output
  3.33      2.15      2.15  gensym
  3.33      2.15      2.15  language/tree-il/analyze.scm:544:4
  3.33      2.15      2.15  make-struct
  3.33      2.15      2.15  language/cps/intset.scm:187:0:persistent-intset
  3.33      2.15      2.15  read
  3.33      2.15      2.15  language/cps/intmap.scm:184:0:intmap-add!
  1.67     44.03      1.07  ice-9/psyntax.scm:1604:10:parse
  1.67      6.44      1.07  language/cps/intset.scm:269:0:intset-add
  1.67      5.37      1.07  ice-9/psyntax.scm:1313:6:syntax-type
  1.67      4.30      1.07  language/cps/intset.scm:547:2:union
  1.67      4.30      1.07  language/cps/intset.scm:316:2:remove
  1.67      2.15      1.07  language/cps/intset.scm:725:2:subtract-nodes
  1.67      1.07      1.07  language/cps/intset.scm:178:0:transient-intset
  1.67      1.07      1.07  ice-9/boot-9.scm:214:0:make-struct/no-tail
  1.67      1.07      1.07  language/tree-il/compile-cps.scm:345:2:convert-args
  1.67      1.07      1.07  cons
  1.67      1.07      1.07  language/tree-il/compile-cps.scm:240:0:adapt-arity
  1.67      1.07      1.07  string-append
  1.67      1.07      1.07  append
  1.67      1.07      1.07  hash-set!
  1.67      1.07      1.07  language/cps/intset.scm:149:0:add-level
  1.67      1.07      1.07  bytevector-u64-ref
  1.67      1.07      1.07  ice-9/vlist.scm:449:0:vhash-cons
  1.67      1.07      1.07  language/cps/renumber.scm:198:6
  0.00 264932.27      0.00  language/cps/renumber.scm:78:4:visit
  0.00   1101.88      0.00  language/tree-il.scm:425:2:lp
  0.00   1041.74      0.00  language/tree-il/compile-cps.scm:323:0:convert
  0.00    680.89      0.00  language/tree-il/peval.scm:716:2:loop
  0.00    637.93      0.00  ice-9/boot-9.scm:228:5:map1
  0.00    599.27      0.00  language/tree-il.scm:418:2:foldts
  0.00    263.12      0.00  language/tree-il/debug.scm:39:2:visit
  0.00    243.79      0.00  language/cps/intmap.scm:515:5:visit-branch
  0.00     68.73      0.00  ice-9/boot-9.scm:2313:0:save-module-excursion
  0.00     64.44      0.00  system/base/compile.scm:41:0:call-once
  0.00     64.44      0.00  ice-9/boot-9.scm:842:2:with-throw-handler
  0.00     64.44      0.00  ice-9/boot-9.scm:148:0:with-fluid*
  0.00     64.44      0.00  system/base/compile.scm:153:8
  0.00     64.44      0.00  system/base/compile.scm:210:0:read-and-compile
  0.00     64.44      0.00  system/base/compile.scm:58:9
  0.00     64.44      0.00  system/base/target.scm:51:0:with-target
  0.00     64.44      0.00  system/base/compile.scm:135:0:compile-file
  0.00     62.29      0.00  system/base/compile.scm:179:0:compile-fold
  0.00     59.07      0.00  ice-9/boot-9.scm:2706:4
  0.00     59.07      0.00  ice-9/boot-9.scm:2838:0:define-module*
  0.00     59.07      0.00  primitive-load-path
  0.00     59.07      0.00  ice-9/boot-9.scm:2751:0:resolve-interface
  0.00     59.07      0.00  ice-9/boot-9.scm:2967:0:try-module-autoload
  0.00     59.07      0.00  ice-9/boot-9.scm:2867:5
  0.00     59.07      0.00  ice-9/boot-9.scm:2987:17
  0.00     52.62      0.00  system/base/compile.scm:239:0:compile
  0.00     50.48      0.00  language/cps/intset.scm:468:5:visit-branch
  0.00     47.25      0.00  ice-9/psyntax.scm:2326:21:expand-let
  0.00     37.59      0.00  language/cps/intmap.scm:247:2:adjoin
  0.00     32.22      0.00  language/cps/compile-bytecode.scm:50:15
  0.00     32.22      0.00  language/cps/compile-bytecode.scm:585:0:emit-bytecode
  0.00     30.07      0.00  language/cps/slot-allocation.scm:841:0:allocate-slots
  0.00     30.07      0.00  language/cps/compile-bytecode.scm:84:0:compile-function
  0.00     24.70      0.00  language/cps/intmap.scm:246:0:intmap-add
  0.00     22.55      0.00  language/cps/intmap.scm:104:0:clone-branch-and-set
  0.00     17.18      0.00  language/cps/utils.scm:408:0:compute-sorted-strongly-connected-components
  0.00     17.18      0.00  language/cps/slot-allocation.scm:195:0:compute-reverse-control-flow-order
  0.00     13.96      0.00  language/cps/slot-allocation.scm:296:0:compute-live-variables
  0.00     11.81      0.00  system/vm/assembler.scm:1024:0:intern-constant
  0.00     11.81      0.00  language/cps/utils.scm:390:0:compute-strongly-connected-components
  0.00     11.81      0.00  language/tree-il/compile-cps.scm:832:5:lp
  0.00     10.74      0.00  language/cps/slot-allocation.scm:386:0:compute-lazy-vars
  0.00     10.74      0.00  language/tree-il/compile-cps.scm:1082:0:compile-cps
  0.00      9.67      0.00  ice-9/psyntax.scm:1078:6:expand-top-sequence
  0.00      9.67      0.00  language/cps/compile-bytecode.scm:607:0:compile-bytecode
  0.00      9.67      0.00  language/scheme/compile-tree-il.scm:29:3
  0.00      7.52      0.00  ice-9/psyntax.scm:1150:30
  0.00      6.44      0.00  language/cps/compile-bytecode.scm:594:0:lower-cps
  0.00      6.44      0.00  language/cps/renumber.scm:161:0:renumber
  0.00      5.37      0.00  language/cps/renumber.scm:112:0:compute-renaming
  0.00      5.37      0.00  language/cps/renumber.scm:151:2:visit-fun
  0.00      4.30      0.00  ice-9/psyntax.scm:1107:10:parse
  0.00      4.30      0.00  language/tree-il/optimize.scm:31:0:optimize
  0.00      3.22      0.00  ice-9/psyntax.scm:2931:8:match*
  0.00      3.22      0.00  language/tree-il/compile-cps.scm:965:0:optimize-tree-il
  0.00      3.22      0.00  language/cps/closure-conversion.scm:814:0:convert-closures
  0.00      3.22      0.00  srfi/srfi-1.scm:458:2:fold
  0.00      3.22      0.00  ice-9/psyntax.scm:1519:6:expand-macro
  0.00      3.22      0.00  language/tree-il/analyze.scm:533:0:analyze-tree
  0.00      3.22      0.00  language/cps/handle-interrupts.scm:56:0:add-handle-interrupts
  0.00      2.15      0.00  srfi/srfi-1.scm:634:2:for-each
  0.00      2.15      0.00  ice-9/psyntax.scm:2854:8:match-each
  0.00      2.15      0.00  anon #x7f082ea18034
  0.00      2.15      0.00  language/tree-il.scm:418:2:fold-values
  0.00      2.15      0.00  language/cps/utils.scm:125:0:intmap-map
  0.00      2.15      0.00  language/cps/closure-conversion.scm:349:2:visit-fun
  0.00      2.15      0.00  language/tree-il/compile-cps.scm:934:0:cps-convert/thunk
  0.00      2.15      0.00  srfi/srfi-1.scm:606:7:map2
  0.00      2.15      0.00  ice-9/boot-9.scm:2067:0:call-with-deferred-observers
  0.00      2.15      0.00  ice-9/eval.scm:292:11
  0.00      2.15      0.00  language/cps/utils.scm:127:16
  0.00      2.15      0.00  language/cps/intset.scm:466:2:intset-fold
  0.00      2.15      0.00  language/cps/renumber.scm:53:2:visit
  0.00      2.15      0.00  language/cps/intmap.scm:367:2:remove
  0.00      2.15      0.00  anon #x7f0827a7c0e8
  0.00      2.15      0.00  language/cps/utils.scm:394:4:visit-scc
  0.00      2.15      0.00  system/base/compile.scm:203:0:read-and-parse
  0.00      2.15      0.00  anon #x7f0827a600e8
  0.00      1.07      0.00  language/tree-il/analyze.scm:984:0:validate-arity
  0.00      1.07      0.00  language/cps/utils.scm:183:0:compute-defining-expressions
  0.00      1.07      0.00  ice-9/psyntax.scm:2240:28:lp
  0.00      1.07      0.00  ice-9/psyntax.scm:3084:2
  0.00      1.07      0.00  language/cps/closure-conversion.scm:355:13
  0.00      1.07      0.00  anon #x7f08265260e8
  0.00      1.07      0.00  anon #x7f0826a990e8
  0.00      1.07      0.00  language/cps/intset.scm:694:0:intset-subtract
  0.00      1.07      0.00  language/cps/closure-conversion.scm:324:5
  0.00      1.07      0.00  language/cps/utils.scm:202:0:compute-constant-values
  0.00      1.07      0.00  language/cps/utils.scm:509:0:intset-pop
  0.00      1.07      0.00  ice-9/psyntax.scm:1483:28
  0.00      1.07      0.00  system/vm/debug.scm:162:0:debug-context-from-image
  0.00      1.07      0.00  anon #x7f082696c0e8
  0.00      1.07      0.00  anon #x7f08269470e8
  0.00      1.07      0.00  anon #x7f08273920e8
  0.00      1.07      0.00  anon #x7f0826f990e8
  0.00      1.07      0.00  anon #x7f0826ee70e8
  0.00      1.07      0.00  language/cps/closure-conversion.scm:318:2:add-uses
  0.00      1.07      0.00  system/vm/linker.scm:357:0:add-symbols
  0.00      1.07      0.00  anon #x7f08274e80e8
  0.00      1.07      0.00  language/cps/utils.scm:432:2:component-successors
  0.00      1.07      0.00  anon #x7f08268b70e8
  0.00      1.07      0.00  system/vm/debug.scm:220:0:find-program-debug-info
  0.00      1.07      0.00  ice-9/boot-9.scm:2628:0:module-gensym
  0.00      1.07      0.00  anon #x7f08270220e8
  0.00      1.07      0.00  anon #x7f0826cc40e8
  0.00      1.07      0.00  anon #x7f0826f2f0e8
  0.00      1.07      0.00  anon #x7f08269000e8
  0.00      1.07      0.00  anon #x7f0826d960e8
  0.00      1.07      0.00  system/vm/program.scm:53:0:program-name
  0.00      1.07      0.00  anon #x7f0826d280e8
  0.00      1.07      0.00  anon #x7f0826efd0e8
  0.00      1.07      0.00  anon #x7f0826a060e8
  0.00      1.07      0.00  anon #x7f082719e0e8
  0.00      1.07      0.00  guix/memoization.scm:58:0
  0.00      1.07      0.00  anon #x7f08267e00e8
  0.00      1.07      0.00  anon #x7f08275440e8
  0.00      1.07      0.00  anon #x7f08270590e8
  0.00      1.07      0.00  language/cps/intset.scm:315:0:intset-remove
  0.00      1.07      0.00  anon #x7f08272a60e8
  0.00      1.07      0.00  anon #x7f082780a0e8
  0.00      1.07      0.00  language/cps/intset.scm:470:5:visit-branch
  0.00      1.07      0.00  system/vm/elf.scm:828:0:elf-section-by-name
  0.00      1.07      0.00  language/cps/closure-conversion.scm:66:0:filter-reachable
  0.00      1.07      0.00  language/cps/slot-allocation.scm:536:0:compute-shuffles
  0.00      1.07      0.00  anon #x7f08266af0e8
  0.00      1.07      0.00  anon #x7f08251ab0e8
  0.00      1.07      0.00  anon #x7f082706f0e8
  0.00      1.07      0.00  anon #x7f08273e60e8
  0.00      1.07      0.00  language/cps/utils.scm:514:0:solve-flow-equations
  0.00      1.07      0.00  language/cps/slot-allocation.scm:636:2:compute-shuffles
  0.00      1.07      0.00  language/cps/slot-allocation.scm:487:0:solve-parallel-move
  0.00      1.07      0.00  system/vm/linker.scm:635:0:allocate-elf
  0.00      1.07      0.00  ice-9/psyntax.scm:2968:8:match
  0.00      1.07      0.00  anon #x7f08274d40e8
  0.00      1.07      0.00  anon #x7f082689f0e8
  0.00      1.07      0.00  anon #x7f0826f430e8
  0.00      1.07      0.00  anon #x7f08273aa0e8
  0.00      1.07      0.00  anon #x7f0826f130e8
  0.00      1.07      0.00  anon #x7f08272d00e8
  0.00      1.07      0.00  language/cps/slot-allocation.scm:415:17
  0.00      1.07      0.00  anon #x7f08268820e8
  0.00      1.07      0.00  anon #x7f08268ce0e8
  0.00      1.07      0.00  anon #x7f08269e00e8
  0.00      1.07      0.00  anon #x7f0826d0d0e8
  0.00      1.07      0.00  ice-9/psyntax.scm:1411:6:expand-expr
  0.00      1.07      0.00  system/vm/linker.scm:371:0:allocate-segment
  0.00      1.07      0.00  anon #x7f0826ffb0e8
  0.00      1.07      0.00  language/cps/intset.scm:496:0:intset-union
  0.00      1.07      0.00  anon #x7f0826cd70e8
  0.00      1.07      0.00  system/vm/elf.scm:675:0:parse-elf64-section-header
  0.00      1.07      0.00  system/vm/assembler.scm:1144:0:emit-load-constant
  0.00      1.07      0.00  anon #x7f082721c0e8
  0.00      1.07      0.00  anon #x7f08273d30e8
  0.00      1.07      0.00  anon #x7f08251c70e8
  0.00      1.07      0.00  anon #x7f08273c00e8
  0.00      1.07      0.00  anon #x7f08272e60e8
  0.00      1.07      0.00  anon #x7f0826cab0e8
  0.00      1.07      0.00  anon #x7f082733b0e8
  0.00      1.07      0.00  ice-9/psyntax.scm:2336:49
  0.00      1.07      0.00  language/cps/intset.scm:204:0:intset-add!
  0.00      1.07      0.00  anon #x7f0826fcc0e8
  0.00      1.07      0.00  system/vm/linker.scm:706:0:link-elf
  0.00      1.07      0.00  anon #x7f0826d5b0e8
  0.00      1.07      0.00  procedure-name
  0.00      1.07      0.00  anon #x7f08272b80e8
  0.00      1.07      0.00  language/cps/compile-bytecode.scm:539:4:compile-cont
  0.00      1.07      0.00  ice-9/psyntax.scm:272:4
  0.00      1.07      0.00  language/cps/intmap.scm:366:0:intmap-remove
  0.00      1.07      0.00  language/tree-il/peval.scm:415:9
  0.00      1.07      0.00  anon #x7f0826fe70e8
  0.00      1.07      0.00  ice-9/vlist.scm:254:0:vlist-fold
  0.00      1.07      0.00  anon #x7f0826c520e8
---
Sample count: 60
Total time: 64.4376717 seconds (19.803807452 seconds in GC)
64.64user 0.18system 0:56.76elapsed 114%CPU (0avgtext+0avgdata 3966576maxresident)k
0inputs+7208outputs (0major+78248minor)pagefaults 0swaps
--8<---------------cut here---------------end--------------->8---

time(1) reports a maximum resident set size of 3.8G (though I see
something around 900MiB in ‘top’.)

‘vector-copy’ calls probably come from (language cps intmap) or
(language cps types).  Unfortunately the profile tells us what part of
the code is allocating, but it doesn’t tell us if our memory is actually
full of vectors.

(I looked at
<https://wingolog.org/archives/2014/07/01/flow-analysis-in-guile> but
I’m not really sure how to check whether intmaps/intsets are to blame.)

I generated a source file with this to mimic the code in python.scm
after macro expansion:

--8<---------------cut here---------------start------------->8---
(define body
  '(let* ((a "a")(b 'b)(c 'c)(d (lambda () 'd))(e (lambda () 'e))
          (f (lambda () 'f)) (g (lambda () 'g)))
     (let ((s (allocate-struct <foo> 20)))
       (struct-set! s 0 a)
       (struct-set! s 1 b)
       (struct-set! s 2 c)
       (struct-set! s 3 d)
       (struct-set! s 4 e)
       (struct-set! s 5 f)
       (struct-set! s 6 g)
       s)))

(let loop ((i 850))
  (unless (zero? i)
    (display
     (format #f "(define-public p~a ~s)\n"
             i body))
    (loop (1- i))))
--8<---------------cut here---------------end--------------->8---

‘vector-copy’ also comes first in the GC profile.  It runs in 105s (only
3s spent in GC) with 1.2G max RSS.  If we simplify the code (omit ‘let*’
or put fewer variables in there, use ‘make-struct’ instead of
‘allocate-struct’ + ‘struct-set!’, etc.)  memory consumption drops a
bit.

When compiling python.scm #:to 'cps, we end up with 1G max RSS in 6s.

Also, for reference, loading python.go peaks at 315M RSS:

--8<---------------cut here---------------start------------->8---
$ \time ./pre-inst-env guile -c '(use-modules (gnu packages python))'
0.18user 0.02system 0:00.18elapsed 112%CPU (0avgtext+0avgdata 315648maxresident)k
0inputs+0outputs (0major+7784minor)pagefaults 0swaps
--8<---------------cut here---------------end--------------->8---

The only conclusion I can draw is that cps-to-bytecode compilation seems
to be responsible for most of the memory consumption.

Thoughts on all this?

Thanks,
Ludo’.


[-- Attachment #2: the compilation script --]
[-- Type: text/plain, Size: 2375 bytes --]

(use-modules (ice-9 threads)
             (ice-9 match)
             (system base target)
             (system base message)
             (guix build utils))

(define warnings
  ;; FIXME: 'format' is missing because it reports "non-literal format
  ;; strings" due to the fact that we use 'G_' instead of '_'.  We'll need
  ;; help from Guile to solve this.
  '(unsupported-warning unbound-variable arity-mismatch))

(define host %host-type)

(define srcdir (getcwd))

(define (relative-file file)
  (if (string-prefix? (string-append srcdir "/") file)
      (string-drop file (+ 1 (string-length srcdir)))
      file))

(define (scm->go file)
  (let* ((relative (relative-file file))
         (without-extension (string-drop-right relative 4)))
    (string-append without-extension ".go")))


(cond-expand
  (guile-2.2 (use-modules (language tree-il optimize)
                          (language cps optimize)))
  (else #f))

(define %default-optimizations
  ;; Default optimization options (equivalent to -O2 on Guile 2.2).
  (cond-expand
    (guile-2.2 (append (tree-il-default-optimization-options)
                       (cps-default-optimization-options)))
    (else '())))

(define %lightweight-optimizations
  ;; Lightweight optimizations (like -O0, but with partial evaluation).
  (let loop ((opts %default-optimizations)
             (result '()))
    (match opts
      (() (reverse result))
      ((#:partial-eval? _ rest ...)
       (loop rest `(#t #:partial-eval? ,@result)))
      ((kw _ rest ...)
       (loop rest `(#f ,kw ,@result))))))

(define (optimization-options file)
  (if (string-contains file "gnu/packages/")
      %lightweight-optimizations                  ;build faster
      '()))

(define (compile-file* file output-mutex)
  (let ((go (scm->go file)))
    (with-mutex output-mutex
      (format #t "  GUILEC   ~a~%" go)
      (force-output))
    (mkdir-p (dirname go))
    (with-fluids ((*current-warning-prefix* ""))
      (with-target host
        (lambda ()
          (compile-file file
                        #:output-file go
                        #:to 'cps
                        #:opts `(#:warnings ,warnings
                                 ,@(optimization-options file))))))))

(use-modules (statprof))

(gcprof
 (lambda ()
   (compile-file* ;; "t.scm"
                  "gnu/packages/python.scm"
                  (make-mutex))))

^ permalink raw reply	[flat|nested] 33+ messages in thread

end of thread, other threads:[~2017-10-31 16:56 UTC | newest]

Thread overview: 33+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2017-05-16 16:19 Compiler memory consumption Ludovic Courtès
2017-05-16 20:14 ` Andy Wingo
2017-05-16 20:45   ` Ludovic Courtès
2017-09-12  9:06   ` Ludovic Courtès
2017-09-17 13:56     ` Weak tables harmful to GC? Ludovic Courtès
2017-10-09 13:10       ` Christopher Allan Webber
2017-10-22  1:52       ` Ludovic Courtès
2017-10-22  2:20         ` Christopher Allan Webber
2017-10-23  0:16           ` Ludovic Courtès
2017-10-24 15:02             ` Ricardo Wurmus
2017-10-24 15:32             ` Ricardo Wurmus
2017-10-25  6:38               ` Ricardo Wurmus
2017-10-26  7:03               ` Ludovic Courtès
2017-10-26  8:35                 ` Ricardo Wurmus
2017-10-26 16:52                   ` Ricardo Wurmus
2017-10-27  5:28                     ` Ludovic Courtès
2017-10-28  9:56                       ` Ricardo Wurmus
2017-10-30 12:35                         ` Ludovic Courtès
2017-10-30 14:48                           ` Ricardo Wurmus
2017-10-30 17:20                             ` Ricardo Wurmus
2017-10-30 22:18                               ` Ludovic Courtès
2017-10-30 17:29                           ` bug#19180: " Andy Wingo
2017-10-30 23:13                             ` Ludovic Courtès
2017-10-31  8:25                               ` Andy Wingo
2017-10-31 16:56                                 ` Ludovic Courtès
2017-10-26 17:17                   ` Ludovic Courtès
2017-10-24 22:45             ` Christopher Allan Webber
2017-10-24 22:58               ` Ludovic Courtès
2017-10-25  0:50                 ` Christopher Allan Webber
2017-10-25 17:11                   ` Ludovic Courtès
2017-10-25 17:42     ` Compiler memory consumption Ludovic Courtès
2017-10-30 15:16       ` Andy Wingo
2017-10-30 15:52         ` Ludovic Courtès

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).