Logging callers

Chapter 2, Inside the profiler

When the program terminates, Turbo Pro filer converts the counts variable for each area to an actual time (based on the total number of timer ticks that occurred for the entire program).

When you disable collection on entry to routine func1, returning from func1 does not automatically reenable collection. You must explicitly reenable collection at func1's return point.

What do you do about multiple return statements? The answer is related to the implicit return points at the end of routines.

Even though you might have several explicit return points in your program, Turbo C actually turns all returns into jumps to a single exit point at the end of the routine. The line that receives the area marking for a return statement is the line associated with the closing brace for the routine. This is the actual assembly language return statement to which all other return statements in the routine are vectored.

To disable collection for a routine, set an area marker with a disable operation at the first line of the function and an enable on the line after the call to the function.

If you want to throw out the time spent in func1 but continue collection upon return from func1, you must set an area marker at

func1's return statement. If no explicit return statement exists, mark the closing curly brace associated with the end of the routine.

An active routine is a routine currently on the profiler's routine call stack. In active analysis, (that is, with the profiler collecting call histories and other data not related to times) Turbo Pro filer maintains its own routine call stack. This stack is similar to the stack found in any DOS program. However, the pro filer's stack is separate from the user's program stack and is used strictly to retain information about routine calls for which a return statement has not yet been executed.

In order to maintain an active routine stack, Turbo Profiler recognizes two types of area markers:

[J Routine-entry area markers (routine markers)

[J Normal area markers (label markers)

35

36

When the pro filer encounters a routine-entry area marker, it pushes the currently active routine (the last encountered routine-entry marker) onto its active routine stack. The newly

encountered routine marker then becomes the active routine marker.

Now, if a normal area marker trips, this encounter will have no effect on the current routine or on the active routine stack. When a normal area marker trips, it simply becomes the active area, which means that the pro filer forgets the previously active area. The currently active routine, however, remains on the stack until the pro filer encounters a return statement.

When a return is issued within an active routine, the area marker associated with that routine becomes inactive. The routine on top of the pro filer's active routine stack pops off the stack and

becomes the active routine, until a return statement executes within that routine, or until another routine-entry area marker is tripped.

Thus the profiler can maintain a complete call history for every marked routine. If you have enabled Statistics I Callers for all marked routines, then each time a routine-entry area marker is tripped, the profiler saves the entire profiler call stack in a buffer linked directly to the routine-entry marker.

If that call stack is identical to a call stack that was saved for a prior entry to this routine, the profiler increments a counter, rather than saving the call stack again. If, however, the call stack is different, the pro filer allocates a new buffer and logs the pro filer call stack to that new buffer. This makes it possible to maintain a record of every call path to a routine and the number of times each call path is traversed.

The profiler's active routine stack is related to two menu settings:

• Statistics I Callers (set to either Enabled or Disabled)

• the Callers option for each marked area in the Areas window You gain finer control over logging call paths by using the local menus of the Module and the Areas windows. You can set the Callers option for each of the marked areas separately. Both the Callers command on the Module local menu and the Options command on the Areas local menu lead to a dialog box where you can specify Callers as All Callers, Immediate Caller, or None.

Turbo Pro filer User's Guide

Sampling vs.

counting

ThIs happens only in passive mode.

Chapter 2, Inside the profiler

• All Callers means log the entire routine call stack each time the entry point is tripped.

II Immediate Caller means log only the top entry on the routine call stack when the entry point is tripped .

• None means don't log any routine stack information when this routine-entry marker is tripped.

By default, when you first profile a program, the Callers option for all routine-entry area marks is set to None.

Enabling Statistics I Callers from the main menu is the same as setting the Callers option to All Callers for each area marker listed in the Areas window. However, once you've hand-set any of the Callers options in the Areas window, setting Statistics I Callers to Enable won't change the value of the Callers options for any of the areas.

Disabling the Statistics I Callers option at this point tells the.

profiler not to log any stack information, but doesn't change the Caller settings in the Areas window. Neither does setting Statistics I Caller.)

The profiler does not actually measure time: It comes up with a very accurate estimate of time based on information from timer tick counts. This is a form of statistical sampling. By taking regular periodic samples of the current area, and by keeping a count for each area (which increments each time that area is active when the timer interrupts), the pro filer can estimate the time spent in a given area.

The profiler knows the total time taken to run the program. It also knows the total number of times the timer interrupted the

program. The time spent in a given area can be calculated as timearetl

=

*

This is not the true time spent in an area. !fyour program iterates over some routine at a frequency that is a multiple of the timer frequency (for example, a routine that generates a steady sound tone), the execution of a particular line (or area) might exactly coincide with most of the timer interrupts. This resonance could occur even though that line is not where the program is spending most of its time. This is rare, but possible.

37

If you suspect this sort of frequency collision, change the Statistics I Profiling Options I Clock speed value and compare the resulting profile to the previous one.