Dudes and dudettes. Statprof works for profiling guile-vm. If you ask
me, that's pretty sweet.
Here's a profile of loading (oop goops). It's long because, well,
syncase... also I had to increase the sampling frequency because
otherwise the results were really unstable.
scheme@(guile-user)> (use-modules (statprof))
scheme@(guile-user)> (with-statprof #:hz 1000 (resolve-module '(oop goops)))
% cumulative self
time seconds seconds name
15.46 0.05 0.05 eqv?
10.31 0.14 0.04 write-bytecode
3.09 0.09 0.01 glil->assembly
3.09 0.01 0.01 memv
3.09 0.01 0.01 module-make-local-var!
2.06 0.17 0.01 for-each
2.06 0.09 0.01 map
2.06 0.02 0.01 %init-goops-builtins
2.06 0.01 0.01 record-accessor
2.06 0.01 0.01 lookup-transformer
2.06 0.01 0.01 record-predicate
2.06 0.01 0.01 comp
1.03 0.34 0.00 dynamic-wind
1.03 0.03 0.00 translate-1
1.03 0.02 0.00 add-method!
1.03 0.01 0.00 assoc-ref
1.03 0.01 0.00 make-glil-program
1.03 0.01 0.00 comp
1.03 0.00 0.00 syntmp-write-134
1.03 0.00 0.00 syntmp-fk-20
1.03 0.00 0.00 syntmp-fk-31
1.03 0.00 0.00 syntmp-write-byte-18
1.03 0.00 0.00 syntmp-fk-15
1.03 0.00 0.00 syntmp-fk-24
1.03 0.00 0.00 syntmp-write-byte-18
1.03 0.00 0.00 syntmp-fk-35
1.03 0.00 0.00 syntmp-fk-35
1.03 0.00 0.00 syntmp-fk-14
1.03 0.00 0.00 compute-closure-level
1.03 0.00 0.00 syntmp-fk-28
1.03 0.00 0.00 syntmp-fk-13
1.03 0.00 0.00 finish
1.03 0.00 0.00 syntmp-fk-30
1.03 0.00 0.00 comp
1.03 0.00 0.00 dump
1.03 0.00 0.00 syntmp-fk-25
1.03 0.00 0.00 syntmp-fk-18
1.03 0.00 0.00 syntmp-fk-34
1.03 0.00 0.00 syntmp-fk-33
1.03 0.00 0.00 lp
1.03 0.00 0.00 lp
1.03 0.00 0.00 syntmp-fk-13
1.03 0.00 0.00 syntmp-fk-20
1.03 0.00 0.00 syntmp-fk-35
1.03 0.00 0.00 loop
1.03 0.00 0.00 syntmp-fk-14
1.03 0.00 0.00 dump
1.03 0.00 0.00 syntmp-fk-20
1.03 0.00 0.00 syntmp-write-139
1.03 0.00 0.00 loop
1.03 0.00 0.00 syntmp-fk-13
1.03 0.00 0.00 dump
1.03 0.00 0.00 dump
1.03 0.00 0.00 syntmp-fk-34
1.03 0.00 0.00 syntmp-fk-30
1.03 0.00 0.00 close-binding
1.03 0.00 0.00 syntmp-fk-22
1.03 0.00 0.00 syntmp-fk-28
1.03 0.00 0.00 syntmp-fk-22
1.03 0.00 0.00 syntmp-fk-20
1.03 0.00 0.00 syntmp-fk-21
0.00 0.34 0.00 load-compiled/vm
0.00 0.30 0.00 save-module-excursion
0.00 0.30 0.00 load-file
0.00 0.30 0.00 compute-entry-with-cmethod
0.00 0.30 0.00 compile-method/vm
0.00 0.30 0.00 compile-fold
0.00 0.30 0.00 memoize-method!
0.00 0.29 0.00 make-instance
0.00 0.29 0.00 initialize
0.00 0.14 0.00 compile-bytecode
0.00 0.13 0.00 %goops-loaded
0.00 0.13 0.00 make-extended-generic
0.00 0.13 0.00 compute-cmethod
0.00 0.13 0.00 make-next-method
0.00 0.11 0.00 ensure-generic
0.00 0.09 0.00 compile-assembly
0.00 0.09 0.00 compile-asm
0.00 0.05 0.00 byte-length
0.00 0.04 0.00 call-with-ghil-bindings
0.00 0.03 0.00 compile-glil
0.00 0.03 0.00 codegen
0.00 0.02 0.00 lp
0.00 0.02 0.00 lp
0.00 0.01 0.00 lp
0.00 0.01 0.00 lp
0.00 0.01 0.00 comp
0.00 0.01 0.00 lp
0.00 0.01 0.00 lp
0.00 0.01 0.00 lp
0.00 0.01 0.00 lp
0.00 0.01 0.00 retrans
0.00 0.01 0.00 lp
0.00 0.01 0.00 syntmp-fk-810
0.00 0.01 0.00 retrans
0.00 0.01 0.00 comp
0.00 0.01 0.00 call-with-deferred-observers
0.00 0.01 0.00 lp
0.00 0.01 0.00 comp
0.00 0.01 0.00 retrans
0.00 0.01 0.00 make-glil-var
0.00 0.01 0.00 retrans
0.00 0.01 0.00 retrans
0.00 0.01 0.00 retrans
0.00 0.01 0.00 assoc-ref-or-acons
0.00 0.01 0.00 retrans
0.00 0.01 0.00 syntmp-fk-782
0.00 0.01 0.00 comp
0.00 0.00 0.00 loop
0.00 0.00 0.00 syntmp-fk-810
0.00 0.00 0.00 comp
0.00 0.00 0.00 syntmp-fk-782
0.00 0.00 0.00 push-call!
0.00 0.00 0.00 lp
0.00 0.00 0.00 retrans
0.00 0.00 0.00 lp
0.00 0.00 0.00 lp
0.00 0.00 0.00 retrans
0.00 0.00 0.00 lp
0.00 0.00 0.00 lp
0.00 0.00 0.00 comp-push
0.00 0.00 0.00 syntmp-fk-810
0.00 0.00 0.00 lp
0.00 0.00 0.00 retrans
0.00 0.00 0.00 lp
0.00 0.00 0.00 comp-push
0.00 0.00 0.00 push-call!
0.00 0.00 0.00 retrans
0.00 0.00 0.00 lp
0.00 0.00 0.00 comp
0.00 0.00 0.00 finish
0.00 0.00 0.00 retrans
0.00 0.00 0.00 retrans
0.00 0.00 0.00 comp
0.00 0.00 0.00 resolve-interface
0.00 0.00 0.00 retrans
0.00 0.00 0.00 module-export!
0.00 0.00 0.00 retrans
0.00 0.00 0.00 syntmp-fk-33
0.00 0.00 0.00 retrans
0.00 0.00 0.00 syntmp-fk-31
0.00 0.00 0.00 call-with-ghil-environment
0.00 0.00 0.00 syntmp-fk-782
0.00 0.00 0.00 retrans
0.00 0.00 0.00 syntmp-fk-26
0.00 0.00 0.00 retrans
0.00 0.00 0.00 syntmp-fk-30
0.00 0.00 0.00 retrans
0.00 0.00 0.00 syntmp-fk-782
0.00 0.00 0.00 lp
0.00 0.00 0.00 retrans
0.00 0.00 0.00 syntmp-fk-782
0.00 0.00 0.00 comp-push
0.00 0.00 0.00 retrans
0.00 0.00 0.00 finish
0.00 0.00 0.00 syntmp-fk-29
0.00 0.00 0.00 retrans
0.00 0.00 0.00 write-string
0.00 0.00 0.00 push-call!
0.00 0.00 0.00 syntmp-fk-782
0.00 0.00 0.00 write-char
0.00 0.00 0.00 syntmp-fk-810
0.00 0.00 0.00 syntmp-fk-810
0.00 0.00 0.00 lp
0.00 0.00 0.00 retrans
0.00 0.00 0.00 syntmp-fk-35
0.00 0.00 0.00 syntmp-fk-782
0.00 0.00 0.00 lp
0.00 0.00 0.00 lp
0.00 0.00 0.00 retrans
0.00 0.00 0.00 retrans
0.00 0.00 0.00 loop
0.00 0.00 0.00 retrans
0.00 0.00 0.00 comp-push
0.00 0.00 0.00 push-call!
0.00 0.00 0.00 syntmp-fk-23
0.00 0.00 0.00 comp-push
0.00 0.00 0.00 retrans
0.00 0.00 0.00 lp
0.00 0.00 0.00 retrans
0.00 0.00 0.00 retrans
0.00 0.00 0.00 retrans
0.00 0.00 0.00 comp-push
0.00 0.00 0.00 lp
0.00 0.00 0.00 push-call!
0.00 0.00 0.00 loop
0.00 0.00 0.00 for-each*
0.00 0.00 0.00 write-string
0.00 0.00 0.00 syntmp-fk-23
0.00 0.00 0.00 write-char
0.00 0.00 0.00 retrans
0.00 0.00 0.00 syntmp-fk-17
0.00 0.00 0.00 lp
0.00 0.00 0.00 comp-push
0.00 0.00 0.00 syntmp-fk-31
0.00 0.00 0.00 retrans
0.00 0.00 0.00 retrans
0.00 0.00 0.00 syntmp-fk-13
0.00 0.00 0.00 syntmp-fk-27
0.00 0.00 0.00 syntmp-fk-19
0.00 0.00 0.00 comp-push
0.00 0.00 0.00 retrans
---
Sample count: 97
Total time: 0.34 seconds (7/50 seconds in GC)
$1 = #<directory (oop goops) b7259830>
I'm not yet sure what to make of this. It seems like the compiler itself
can be sped up by a factor of two or so, which sounds nice. We'll see.
Anyway, glad to see that statprof works with the new vm.
Andy
--
http://wingolog.org/
