{Begin SubSec Performance Measuring}
{Title Performance Measuring}
{Text
This section describes functions that gather and display statistics about a computation, such as as the elapsed time, and the number of data objects of different types allocated. {fn TIMEALL} and {fn TIME} gather statistics on the evaluation of a specified form. {fn BREAKDOWN} gathers statistics on individual functions called during a computation. These functions can be used to determine which parts of a computation are consuming the most resources (time, storage, etc.), and could most profitably be improved.
{FnDef {FnName TIMEALL} {FnArgs TIMEFORM NUMBEROFTIMES TIMEWHAT INTERPFLG {anonarg}}
{Type NLAMBDA}
{Text
Evaluates the form {arg TIMEFORM} and prints statistics on time spent in various categories (elapsed, keyboard wait, swapping time, gc) and data type allocation.
For more accurate measurement on small computations, {arg NUMBEROFTIMES} may be specified (its default is 1) to cause {arg TIMEFORM} to be executed {arg NUMBEROFTIMES} times. To improve the accuracy of timing open-coded operations in this case, {fn TIMEALL} compiles a form to execute {arg TIMEFORM} {arg NUMBEROFTIMES} times (unless {arg INTERPFLG} is non-{lisp NIL}), and then times the execution of the compiled form.
Note: If {fn TIMEALL} is called with {arg NUMBEROFTIMES}>1, the dummy form is compiled with compiler optimizations on. This means that it is not meaningful to use {fn TIMEALL} with very simple forms that are optimized out by the compiler. For example, {lisp (TIMEALL '(IPLUS 2 3) 1000)} will time a compiled function which simply returns the number 5, since {lisp (IPLUS 2 3)} is optimized to the integer 5.
{arg TIMEWHAT} restricts the statistics to specific categories. It can be an atom or list of datatypes to monitor, and/or the atom {lisp TIME} to monitor time spent. Note that ordinarily, {fn TIMEALL} monitors all time and datatype usage, so this argument is rarely needed.
{fn TIMEALL} returns the value of the last evaluation of {arg TIMEFORM}.
}}
{FnDef {FnName TIME} {FnArgs TIMEX TIMEN TIMETYP}
{Type NLAMBDA}
{Text
{fn TIME} evaluates the form {arg TIMEX}, and prints out the number of {fn CONS} cells allocated and computation time. Garbage collection time is subtracted out. This function has been largely replaced by {fn TIMEALL}.
If {arg TIMEN} is greater than 1, {arg TIMEX} is executed {arg TIMEN} times, and {fn TIME} prints out (number of conses)/{arg TIMEN}, and (computation time)/{arg TIMEN}. If {arg TIMEN}={lisp NIL}, it defaults to 1. This is useful for more accurate measurement on small computations.
If {arg TIMETYP} is 0, {fn TIME} measures and prints total {it real} time as well as computation time. If {arg TIMETYP} = 3, {fn TIME} measures and prints garbage collection time as well as computation time. If {arg TIMETYP}={lisp T}, {fn TIME} measures and prints the number of pagefaults.
{fn TIME} returns the value of the last evaluation of {arg TIMEX}.
}}
{FnDef {FnName BOXCOUNT} {FnArgs TYPE N}
{Text
Returns the number of data objects of type {arg TYPE} allocated since this Interlisp system was created. {arg TYPE} can be any data type name (see {fn TYPENAME}, {PageRef Fn TYPENAME}). If {arg TYPE} is {lisp NIL}, it defaults to {lisp FIXP}. If {arg N} is non-{lisp NIL}, the corresponding counter is reset to {arg N}.
}}
{FnDef {FnName CONSCOUNT} {FnArgs N}
{Text
Returns the number of {fn CONS} cells allocated since this Interlisp system was created. If {arg N} is non-{lisp NIL}, resets the counter to {arg N}. Equivalent to {lisp (BOXCOUNT 'LISTP {arg N})}.
}}
{FnDef {FnName PAGEFAULTS} {FnArgs }
{Text
Returns the number of page faults since this Interlisp system was created.
}}
{Begin SubSec BREAKDOWN}
{Title BREAKDOWN}
{Text
{note {fn BREAKDOWN} was written by W. Teitelman, and extended by L. P. Deutsch.}
{fn TIMEALL} collects statistics for whole computations. {fn BREAKDOWN} is available to analyze the breakdown of computation time (or any other measureable quantity) function by function.
{FnDef {Name BREAKDOWN} {Args FN{sub 1} {ellipsis} FN{sub N}}
{Type NLAMBDA NOSPREAD}
{Text
The user calls {fn BREAKDOWN} giving it a list of function names (unevaluated). These functions are modified so that they keep track of various statistics.
To remove functions from those being monitored, simply {index UNBREAK FN}{fn UNBREAK} ({PageRef Fn UNBREAK}) the functions, thereby restoring them to their original state. To add functions, call {fn BREAKDOWN} on the new functions. This will not reset the counters for any functions not on the new list. However {lisp (BREAKDOWN)} will zero the counters of all functions being monitored.
The procedure used for measuring is such that if one function calls other and both are "broken down", then the time (or whatever quantity is being measured) spent in the inner function is {it not} charged to the outer function as well.
Note: {fn BREAKDOWN} will {it not} give accurate results if a function being measured is not returned from normally, e.g., a lower {fn RETFROM} (or {fn ERROR}) bypasses it. In this case, all of the time (or whatever quantity is being measured) between the time that function is entered and the time the next function being measured is entered will be charged to the first function.
}}
{FnDef {Name BRKDWNRESULTS} {Args RETURNVALUESFLG}
{Text
{fn BRKDWNRESULTS} prints the analysis of the statistics requested as well as the number of calls to each function. If {arg RETURNVALUESFLG} is non-{lisp NIL}, {fn BRKDWNRESULTS} will not to print the results, but instead return them in the form of a list of elements of the form {lisp ({arg FNNAME} {arg #CALLS} {arg VALUE})}.
}}
Example:
{lispcode
← (BREAKDOWN SUPERPRINT SUBPRINT COMMENT1)
(SUPERPRINT SUBPRINT COMMENT1)
← (PRETTYDEF '(SUPERPRINT) 'FOO)
FOO.;3
← (BRKDWNRESULTS)
FUNCTIONS TIME #CALLS PER CALL %
SUPERPRINT 8.261 365 0.023 20
SUBPRINT 31.910 141 0.226 76
COMMENT1 1.612 8 0.201 4
TOTAL 41.783 514 0.081
NIL
← (BRKDWNRESULTS T)
((SUPERPRINT 365 8261) (SUBPRINT 141 31910) (COMMENT1 8 1612))}
{fn BREAKDOWN} can be used to measure other statistics, by setting the following variables:
{VarDef {Name BRKDWNTYPE}
{Text
To use {fn BREAKDOWN} to measure other statistics, before calling {fn BREAKDOWN}, set the variable {var BRKDWNTYPE} to the quantity of interest, e.g., {lisp TIME}, {lisp CONSES}, etc, or a list of such quantities. Whenever {fn BREAKDOWN} is called with {var BRKDWNTYPE} not {lisp NIL}, {fn BREAKDOWN} performs the necessary changes to its internal state to conform to the new analysis. In particular, if this is the first time an analysis is being run with a particular statistic, a measuring function will be defined, and the compiler will be called to compile it. The functions being broken down will be redefined to call this measuring function. When {fn BREAKDOWN} is through initializing, it sets {var BRKDWNTYPE} back to {lisp NIL}. Subsequent calls to {fn BREAKDOWN} will measure the new statistic until {var BRKDWNTYPE} is again set and a new {fn BREAKDOWN} performed.
}}
{VarDef {Name BRKDWNTYPES}
{Text
The list {var BRKDWNTYPES} contains the information used to analyze new statistics. Each entry on {var BRKDWNTYPES} should be of the form {lisp ({arg TYPE} {arg FORM} {arg FUNCTION})}, where {arg TYPE} is a statistic name (as would appear in {var BRKDWNTYPE}), {arg FORM} computes the statistic, and {arg FUNCTION} (optional) converts the value of form to some more interesting quantity. For example, {lisp (TIME (CLOCK 2) (LAMBDA (X) (FQUOTIENT X 1000)))} measures computation time and reports the result in seconds instead of milliseconds. {var BRKDWNTYPES} currently contains entries for {lisp TIME}, {lisp CONSES}, {lisp PAGEFAULTS}, {lisp BOXES}, and {lisp FBOXES}.
}}
Example:
{lispcode
← (SETQ BRKDWNTYPE '(TIME CONSES))
(TIME CONSES)
← (BREAKDOWN MATCH CONSTRUCT)
(MATCH CONSTRUCT)
← (FLIP '(A B C D E F G H C Z) '(.. $1 .. #2 ..) '(.. #3 ..))
(A B D E F G H Z)
← (BRKDWNRESULTS)
FUNCTIONS TIME #CALLS PER CALL %
MATCH 0.036 1 0.036 54
CONSTRUCT 0.031 1 0.031 46
TOTAL 0.067 2 0.033
FUNCTIONS CONSES #CALLS PER CALL %
MATCH 32 1 32.000 40
CONSTRUCT 49 1 49.000 60
TOTAL 81 2 40.500
NIL}
Occasionally, a function being analyzed is sufficiently fast that the overhead involved in measuring it obscures the actual time spent in the function. If the user were using {fn TIME}, he would specify a value for {arg TIMEN} greater than 1 to give greater accuracy. A similar option is available for {fn BREAKDOWN}. The user can specify that a function(s) be executed a multiple number of times for each measurement, and the average value reported, by including a number in the list of functions given to {fn BREAKDOWN}, e.g., {lisp BREAKDOWN(EDITCOM EDIT4F 10 EDIT4E EQP)} means normal breakdown for {lisp EDITCOM} and {lisp EDIT4F} but executes (the body of) {lisp EDIT4E} and {lisp EQP} 10 times each time they are called. Of course, the functions so measured must not cause any harmful side effects, since they are executed more than once for each call. The printout from {fn BRKDWNRESULTS} will look the same as though each function were run only once, except that the measurement will be more accurate.
Another way of obtaining more accurate measurement is to expand the call to the measuring function in-line. If the value of {var BRKDWNCOMPFLG}{index BRKDWNCOMPFLG Var} is non-{lisp NIL} (initially {lisp NIL}), then whenever a function is broken-down, it will be redefined to call the measuring function, and then recompiled. The measuring function is expanded in-line via an appropriate macro. In addition, whenever {var BRKDWNTYPE}{index BRKDWNTYPE Var} is reset, the compiler is called for {it all} functions for which {var BRKDWNCOMPFLG} was set at the time they were originally broken-down, i.e. the setting of the flag at the time a function is broken-down determines whether the call to the measuring code is compiled in-line.
}{End SubSec BREAKDOWN}
}{End SubSec Performance Measuring}