Up | Next | Prev | PrevTail | Tail |
The Unix profil system call provides a facility to get information about the cpu consumption in a
LISP program. A simple interface was build to be able to turn profiling on and off and to map
the results on to the LISP address space. For details, please refer to the source code in
$pxu/spy.sl. (spywhole N:Integer): void expr
(spyprint): void expr
(spyon fwa lwa tslice bucketsize power): void expr
(spyoff): void expr
Example:
It is easy to see that the command (null (setq aa(expt 3000 10000))) leads to a
lot of bignum computations. The spyprint output proves that. Please note that INITCODE sums
up all the functions that belong to PSL’s C runtime support. In this case the high percentage is
due to the fact that the (old) SPARC implementation performs integer multiply and divide in
software i.e. in non LISP code.
Qualified counting is used to measure the cpu time spend between call and return from a
function, not necessarily spend within the body of the function. It gives an overview about the
costs that a call of particular function causes. The sum shown as result may be bigger that 100
percent, if a function and its callee are both measured or if gc time is accumulated.
(qualtime S:list): void macro
(print!-qualtime): void expr
Example:
For our own applications it had turned out to be useful to know the callers of a function
especially when the function is called very, very often, e.g. basic routines like generic arithmetic.
To provide this a module qualified counting was generated using a similar syntax like qualified
timing. (qualcount S:list): void macro
(print!-qualcount): void expr
(reset!-qualcount): void expr
Example:
NIL
(spywhole 4)
NIL
(null (setq aa(expt 3000 10000)))
NIL
(spyprint) % This was done on a SUN4 PSL
214 39.5% BPLUSA2
204 37.7% INITCODE
67 12.3% WTIMESDOUBLE
15 2.7% COPYFROMONESTATICHEAP
12 2.2% XXCOPYFROMSTACK
12 2.2% SET_HEAP_SIZE
NIL
26.6.2 Qualified timing
(off usermode)
(qualtime gtpos times2)
(null (setq aa(expt 3000 10000))) % this will be measured
(print-qualtime)
⋆⋆⋆⋆⋆⋆⋆⋆⋆⋆⋆ Qualified Timing ⋆⋆⋆⋆⋆⋆⋆⋆⋆⋆⋆⋆⋆⋆
⋆⋆⋆⋆ Overall Cpu time : 5083 ⋆⋆⋆⋆⋆
⋆⋆⋆ TIMES2 ⋆ calls : 18 ⋆ time : 5797 ⋆ % 114
⋆⋆⋆ GTPOS ⋆ calls : 5560 ⋆ time : 935 ⋆ % 18
26.6.3 Qualified counting
(off usermode)
(qualcount faslin intern)
⋆⋆⋆ Function ‘G0003' has been redefined
⋆⋆⋆ Function ‘FASLIN' has been redefined
⋆⋆⋆ Function ‘G0025' has been redefined
⋆⋆⋆ Function ‘INTERN' has been redefined
(load nbig30) % this will be counted
(print-qualcount)
⋆⋆⋆⋆⋆⋆⋆⋆⋆⋆⋆⋆⋆ calls for function FASLIN ⋆⋆⋆⋆⋆⋆⋆⋆⋆⋆⋆⋆⋆
⋆⋆⋆⋆⋆⋆⋆⋆⋆⋆⋆⋆⋆ calls for function INTERN ⋆⋆⋆⋆⋆⋆⋆⋆⋆⋆⋆⋆⋆
number of calls : 306 from READ-ID-TABLE
Up Next Prev PrevTail Front