[_CDCSL_93-16_]<1>Cedar>release>CodeTimer>CodeTimerDoc.tioga

CodeTimerDoc.tioga

Bier, November 13, 1992 4:03 pm PST

CodeTimer

CEDAR 7.0 —

CodeTimer

Long-Term Performance Instrumentation

Eric Bier

Abstract: Whereas Spy can tell you what fractions of the CPU time spent between line A and line B went to which routines, CodeTimer tells you how long it took to get from A to B. Together, they tell you what to fix and how well you did. To use CodeTimer you add a procedure StartInterval before line A, and StopInterval after line B. CodeTimer maintains several tables of named intervals (e.g. one per application). For each interval, it remembers the minimum, maximum, and average time taken to execute that interval since the last time the interval counter was reset. StartInterval and StopInterval commands are intended to be fast enough that you can leave them in your code. Currently CodeTimer prints the statistics onto a STREAM in human readable format. If there is a demand, I will add procedures to query the intervals procedurally.

Created by: Bier

Maintained by: <GargoyleImplementors^.pa>

Keywords: Time, Performance, Instrumentation, Interval

XEROX Xerox Corporation
Palo Alto Research Center
3333 Coyote Hill Road
Palo Alto, California 94304

1. CodeTimer CommandTool Commands

CodeTimer registers two important commands:

codeTimerOn -- activates the CodeTimer intervals. Until this command is given, CodeTimer will not take any statistics (in this mode CodeTimer.StartInterval and CodeTimer.StopInterval just check a boolean value and return).

codeTimerOff -- deactivates CodeTimer intervals.

In addition, CodeTimer can be run in one of two modes:

codeTimerNoteThreadsOn causes CodeTimer to distinguish calls to the same interval by different threads. When you print out your statistics, a thread number will be prepended to each interval name, as in 23.ThisName.

codeTimerNoteThreadsOff causes CodeTimer to treat calls to an interval identically regardless of which thread makes the call (this is the default). You should reset all statistics after changing this mode. When you print out your statistics, the number 0 will be prepended to each interval name, as in 0.ThisName. This mode will in general produce more compact output.

CodeTimer now assumes multi-threaded code by default. In this mode, each line of CodeTimer statistics begins with a small integer representing the thread in which the corresponding CodeTimer block was run.

If your program repeatedly forks a new thread, but the threads run consequtively, you may wish to try the command codeTimerNoteThreadsOff to have all procedure calls treated as though executed from the same thread.

The following commands print out statistics onto the Commander typescript. See also the CodeTimerTool, described in section 2.

PrintCodeTimeTables -- prints out all code time tables that CodeTimer currently knows about. The table for a package will only be registered if that package is currently loaded.

These commands act on entire tables (e.g., on all of the intervals in a given application):

PrintCodeTimes <tablename> -- prints out the minimum, maximum, and average times taken to execute the marked code blocks in the table named in the first argument.

ResetCodeTimes <tablename> -- zeros the code times for all of the intervals in this table.

These commands act on a particular interval in a table:

PrintIntervalTime <intervalname> <tablename> -- prints out the minimum, maximum, and average times taken to execute the named interval (in each context in which in appears) and its children.

PrintIntervalTotals <intervalname> <tablename> -- prints out the minimum, maximum, and average times taken to execute the named interval (totaled over all contexts in which it appears).

ResetIntervalTimes <intervalname> <tablename> -- zeros the code times for the named interval in the named table.

2. The CodeTimer Tool

There is a window-based tool for inspecting the current values for CodeTimer intervals. See CodeTimerToolDoc.tioga for more information, or just try the "CodeTimerTool" command to try it out.

3. Hints on using CodeTimer

CodeTimer counts StopIntervals and StartIntervals. If the number is not the same, it prints out a non-zero errs number. If this happens, make sure there isn't a RETURN or GOTO in the middle of your code interval that you have forgotten about.

CodeTimer statistics are repeatable enough to be useful, but there aren't too many significant digits there. No attempt is made to compensate for garbage collection delays, or time taken by other processes. For user interface code this isn't so bad, because your user has to wait through those delays, so you might as well face them too. Why are you allocating so much storage during an interactive operation anyway? Reset the table and run again to see how much the result fluctuates.

CodeTimer only prints out statistics for those intervals which have been used since they were reset.

4. How the Gargoyle Project Uses CodeTimer

The Gargoyle project has many timed intervals in its code. After large changes to Gargoyle, the implementors run a standard set of Gargoyle scripts. Each script resets the CodeTimer tables, runs the benchmark, opens a Typescript, and prints the times for all timed intervals that were exercised. The results for intervals of interest are copied into a large tioga file, GGPerformance, which contains a history of measurements.

5. A History of Changes to CodeTimer (new users can ignore)

CodeTimer.AddInterval[] calls are no longer necessary. CodeTimer creates intervals on the fly as they are encountered.