[Axiom-developer] tracing and profiling

[Martin Rubey]

Waldek Hebisch <address@hidden> writes:

> When trying to speed up calculation profiling helps a lot.  I was
> unable to use profiling in gcl based FriCAS,

Hm, I used axiom's built in profiling capabilities quite a lot when developing
my guessing package.  It worked equally well with functions compiled from SPAD
code as with functions only defined in the interpreter, see sample below.

I do recall however, that it doesn't work with Aldor code, which I must say is
a great pity.  Same goes for tracing, which I find in fact an even more severe
restriction.  Since Aldor code is in the end also compiled to lisp, I wonder
whether this couldn't be fixed?

Martin

(1) -> tst a == if a <= 1 then 1 else tst(a-1) + tst(a-2)
                                                                   Type: Void
(2) -> tst 3
   Compiling function tst with type Integer -> PositiveInteger 

   (2)  3
                                                        Type: PositiveInteger
(3) -> )tr tst )ti )cou )nt
 
   Function traced: tst 
   Packages traced: 
      Integer, Integer
   Parameterized constructors traced:
      INT
(3) -> )tr INT )ti )cou )nt
 
   Function traced: tst 
   Packages traced: 
      Integer
   Parameterized constructors traced:
      INT
(4) -> tst 20

   (4)  10946
                                                        Type: PositiveInteger
(5) -> 
(4) -> )tr )st
--------------------- Traced function execution times ----------------------
   Integer.**,72 : 0.0 sec.
   Integer.+,67 : 0.02 sec.
   Integer.-,68 : 0.050000000000000003 sec.
   Integer.-,66 : 0.0 sec.
   Integer.<,65 : 0.029999999999999999 sec.
   Integer.=,64 : 0.0 sec.
   Integer.OMwrite,24 : 0.0 sec.
   Integer.OMwrite,23 : 0.0 sec.
   Integer.OMwrite,22 : 0.0 sec.
   Integer.OMwrite,20 : 0.0 sec.
   Integer.abs,61 : 0.0 sec.
   Integer.addmod,41 : 0.0 sec.
   Integer.base,29 : 0.0 sec.
   Integer.coerce,37 : 0.0 sec.
   Integer.convert,52 : 0.0 sec.
   Integer.convert,48 : 0.0 sec.
   Integer.convert,46 : 0.0 sec.
   Integer.convert,51 : 0.0 sec.
   Integer.convert,39 : 0.0 sec.
   Integer.copy,30 : 0.0 sec.
   Integer.dec,32 : 0.0 sec.
   Integer.divide,77 : 0.0 sec.
   Integer.exquo,82 : 0.0 sec.
   Integer.factor,103 : 0.0 sec.
   Integer.gcd,84 : 0.0 sec.
   Integer.gcdPolynomial,117 : 0.0 sec.
   Integer.hash,33 : 0.0 sec.
   Integer.inc,31 : 0.0 sec.
   Integer.latex,53 : 0.0 sec.
   Integer.length,40 : 0.0 sec.
   Integer.max,74 : 0.0 sec.
   Integer.min,75 : 0.0 sec.
   Integer.mulmod,43 : 0.0 sec.
   Integer.negative?,34 : 0.0 sec.
   Integer.odd?,73 : 0.0 sec.
   Integer.one?,26 : 0.0 sec.
   Integer.positiveRemainder,54 : 0.0 sec.
   Integer.quo,78 : 0.0 sec.
   Integer.random,63 : 0.0 sec.
   Integer.random,62 : 0.0 sec.
   Integer.recip,83 : 0.0 sec.
   Integer.reducedSystem,57 : 0.0 sec.
   Integer.reducedSystem,60 : 0.0 sec.
   Integer.rem,79 : 0.0 sec.
   Integer.shift,80 : 0.0 sec.
   Integer.submod,42 : 0.0 sec.
   Integer.unitCanonical,87 : 0.0 sec.
   Integer.unitNormal,86 : 0.0 sec.
   Integer.zero?,25 : 0.0 sec.
   *1;tst;1;frame0 : 0.56000000000000005 sec.
 
--------------------- Traced function execution counts ---------------------
   Integer.**,72 : 0 times
   Integer.+,67 : 10945 times
   Integer.-,68 : 21890 times
   Integer.-,66 : 0 times
   Integer.<,65 : 21891 times
   Integer.=,64 : 0 times
   Integer.OMwrite,24 : 0 times
   Integer.OMwrite,23 : 0 times
   Integer.OMwrite,22 : 0 times
   Integer.OMwrite,20 : 0 times
   Integer.abs,61 : 0 times
   Integer.addmod,41 : 0 times
   Integer.base,29 : 0 times
   Integer.coerce,37 : 1 times
   Integer.convert,52 : 0 times
   Integer.convert,48 : 0 times
   Integer.convert,46 : 0 times
   Integer.convert,51 : 0 times
   Integer.convert,39 : 0 times
   Integer.copy,30 : 0 times
   Integer.dec,32 : 0 times
   Integer.divide,77 : 0 times
   Integer.exquo,82 : 0 times
   Integer.factor,103 : 0 times
   Integer.gcd,84 : 0 times
   Integer.gcdPolynomial,117 : 0 times
   Integer.hash,33 : 0 times
   Integer.inc,31 : 0 times
   Integer.latex,53 : 0 times
   Integer.length,40 : 0 times
   Integer.max,74 : 0 times
   Integer.min,75 : 0 times
   Integer.mulmod,43 : 0 times
   Integer.negative?,34 : 0 times
   Integer.odd?,73 : 0 times
   Integer.one?,26 : 0 times
   Integer.positiveRemainder,54 : 0 times
   Integer.quo,78 : 0 times
   Integer.random,63 : 0 times
   Integer.random,62 : 0 times
   Integer.recip,83 : 0 times
   Integer.reducedSystem,57 : 0 times
   Integer.reducedSystem,60 : 0 times
   Integer.rem,79 : 0 times
   Integer.shift,80 : 0 times
   Integer.submod,42 : 0 times
   Integer.unitCanonical,87 : 0 times
   Integer.unitNormal,86 : 0 times
   Integer.zero?,25 : 0 times
   *1;tst;1;frame0 : 21891 times