-*- TEXT -*- [Written and maintained by RWK. The source lives in MC:Z;TIMER >] The TIMER package is a useful tool in making performance measurements. It currently will measure the amount of time spent inside a given function, without reference to where it is called from, etc. For example, if you wish to find out how many times the function FOO gets called and how much time out of the total it takes in doing a call to BAR, this package will tell you how much time BAR takes, and how many non-recursive calls to FOO there were and how much time total was consumed (both runtime and realtime.) *NOTE* : Due to the problem LISP has with needing DDT symbols in order to reference certain things, in order to load this file you will need to do  to DDT before loading. Perhaps someday LISP will be changed to make this step unnecessary. Functions: (Note, all functions are SUBRS, not an FSUBR or LSUBR among them) (TIME-FUNCTION ) The symbol *MUST* have one of the following properties: (SUBR, LSUBR, FSUBR). It cannot handle interpreted functions, although it can handle functions being called from interpreted code. See theory of operation section. (UNTIME-FUNCTION ) Removes the entry from its internal table of functions, withdraws the timer's prob, and returns T it was there and NIl otherwise. (TIME-SUBR ) (TIME-LSUBR ) These are like calling (TIME-FUNCTION ) except that the subr pointer is not on a functional property. This is for the sake of people who hack subr pointers. The only purpose of the symbol is for a handle to refer to the function by with GET-TIME and GET-ALL-TIMES. Due to LISP internals, it is necessary to distinguish between SUBR'S and LSUBR'S. If you blow it, UNTIME-FUNCTION it, since your LISP will die if you call a SUBR as an LSUBR or vice versa. (INIT-TIMER) Initializes all counts to zero and ensures that all probes are in place. Either this or (SET-TIMER) should be done between trials to ensure that the probes are in. (SET-TIMER) Ensures that all probes are in place. When a function is called from inside the timer, the probes are withdrawn, so that recursive calls will not get charged multiply and will not incurr the cost of running the timer. Quits and other abnormal exits out of a function being timed will result in the probes being left out, rather than being restored when the function returns. See below. (GET-TIME ) Returns the statistics on it's arguments. Currently in the order ( ) where the count is the number of non-recursive calls, and the runtime is in micro-seconds, and the real-time in seconds. (GET-ALL-TIMES) Returns an ALIST of the symbols which were given to TIME-FUNCTION and the results of (GET-TIME on those symbols). (UNTIME) Removes timing from all functions, and returns a list of the functions which were bing timed. Basic Usage: Load in the file ((DSK LIBLSP) TIMER FASL) and for each function you want to time, do (TIME-FUNCTION ). For example, if you want to find out how much consing an interpreted function does (interpreted, because compiled function does not contain calls to the function CONS) you would do (TIME-FUNCTION 'CONS). Then when you had done this for all the functions on which you wish to take statistics in a given run, do (INIT-TIMER) and run your test. Thereafter, if you wish to run additional tests, you should do either (INIT-TIMER) to reset the times and counts to zero, and to be sure that the probes are in place, or you should do (SET-TIMER) which will not clear the counts but will ensure that the probles are in place. (See section on theory of operation.) Getting results: There are two functions for getting back the results. GET-TIME gets the information for a single function, while GET-ALL-TIMES returns an ALIST of the function names and the results of a GET-TIME for that function. It is useful if you forget what functions you have being timed. Example of usage: (load '((liblsp)timer)) 143573 (time-function 'equal) ;It can time lisp functions T (time-function 'frotz) ;as well as user-functions, (time-function 'random-user-function) ;providing they're compiled. T (time-function 'cons) ;Will not get called from compiled code. T (get-all-times) ;just checking what we have here. ((EQUAL 0 0 0.0) (FROTZ 0 0 0.0) (RANDOM-USER-FUNCTION 0 0 0.0) (CONS 0 0 0.0)) (init-timer) T (mumble-frotz) ;Do something that calls the functions. ....... ;mumble-frotz could be interpreted, it's ;the functions timed that have to be ;compiled. (get-time 'cons) ;check the time on one function (0 0 0.0) ;It hasn't been called yet. (cons 'a 'b) (A . B) (get-time 'cons) (1 120 0.0) ;The cons called from the interpreter ;is different than the one called by the ;compiler. (set-timer) ;We want to add the following to the T ;previous timings. However, either ;SET-TIMER or INIT-TIMER should be done ;if you've been playing around at the ;terminal. (fumblefoot) ;some more timing testing. (get-all-times) ((EQUAL 235 298794 3.0) (FROTZ 3 4098080 10000.) (RANDOM-USER-FUNCTION 234 980 5.7) (CONS 1 120 0.0)) (UNTIME-ALL) ;Don't want these anymore. Removes probes. ------------------------------------------------------------------------------- Theory of operation: This package operates by clobbering the first two instructions of the code to be a call to one of two internal handlers, depending on whether or not it is an LSUBR. It remembers these instructions in the entry for the function, along with it's start address (so it can find the entry given the start address, and so it can easily restore the instructions). It clobbers two instructions instead of just one because of the posibilities of being NCALLed for number functions. On entry the timer's handler will get called, which will unclobber the first two instructions, and remember the runtime and realtime of entry. It will also clobber the return address in the manner appropriate for SUBR's or for LSUBR's, depending, to be the rest of the handler which counts the time spent in that function and saves that information in the appropriate slot of the entry for that function. It then replaces the probes (I.e. re-clobbers the first two instructions) so that future calls will run the timer. It can be given pointers to pure subrs, including LISP internals, since it unpurifies the locations it patches with the probes. ------------------------------------------------------------------------------- Problems with as-yet unimplemented solutions: It currently makes no allowances for garbage collections or time spent in interrupts. I plan to make it subtract out GC time and PDL-overflow time and ^B-break time and other asynchrounous interrupt time and present these separately. There are certain internal routines which this package would be able to time except there are no subr pointers to them. For example, CONS called from compiled code, and the various number consers get called with JSP T, ... rather than via the entry points for compiled code. It would not be hard to set it up to put in it's probes into these routines and tell how many of each kind of cons gets done from each function statistics are taken for. Similarly, it would often be nice to know A calls B. There could be a slot or two with indicies of functions already in the table, and the increases in the counts that these point to would be totaled and stored in another slot. Inaccuracies can result with abnormal exits. The solution to this would be to put in special probes at the entry to the various abnormal-exit stack unwinders, and parse the REGPDL for pointers to the various TIMER continuations. It could easily be set up so that these would contain an index into the table of functions in their left half so that the package could know what probes to put back before letting the stack-unwinder do it's thing. The SUBR/LSUBR dichotomy might be eliminated by checking the stack: Either (P) or (P)+(T) must contain the return address, T negative. Unless it was JRST'd to, the this should be one instruction after the instruction that called us. If this heuristic is good enough, it would be a win for both this and for STL's breakpoints hackery. For A calls B timing tests, it should keep track of how many times it gets called. The number of times the timer gets called while in the subject function should be multiplied times some magic constant and subtracted from the total.