
| 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