Heading:qjk40(635)
Control Transfer Counting Tooly756qjk40\b30B
Page Numbers: Yes  X: 527  Y: 10.5"qjk40
Inter-Office Memorandumz18592l4445y762\f5b
To	Mesa Users	Date	October 27, 1980z18592l4445d2998e21(0,65535)(1,4445)(5,11684)(6,14146)\f7 2f0t2 1t0 10t6 1f7t0 4f0t7 1t0
From	Jim Sandman	Location	Palo Altoz18592l4445d2998y716e25\f7 4f0t2 1t0 11t6 1f7t0 8f0t7 1t0
Subject	Control Transfer Counting Tool	Organization	SDD/SS/Mesaz18592l4445d2998e25\f7 7f0t2 1t0b30t6B1f7t0 12f0t7 1t0
XEROX       z18592l508y644e14(2116)\f2 5f0
Filed on: [Iris]<Mesa>Doc>XferCounter.bravo (and .press)e30(0,16051)(1,65535)(5,65535)(6,65535)\f7 56f1
x2e12(2116)
A tool for studying the behavior of Mesa programs is described below.  It counts the number of control transfers (XFERs) to a module and records the time spent executing in a module.  It can also be used to gather information on the flow of control between groups of modules.  An XFER is the general control transfer mechanism in Mesa.  The following are all XFERs: procedure call, return from a procedure, traps, and process switches.x2e12jk40(1799)\114f7b4f0B162f7b4f0B75f7b4f0B
The system is implemented as a set of commands that can be executed from the Mesa Debugger, a routine that intercepts all XFERs and collects statistics about them, and a routine that intercepts conditional breakpoints for turning the XFER monitoring on and off.  Existing Debugger commands are used to specify where XFER monitoring is enabled, and additional commands are provided for controlling the counting of XFERs and outputting the results.x2e12jk40\122f7b4f0B108f7b4f0B78f7b4f0B93f7b4f0B
This tool is intended to provide a global view of the behavior of a system.  With this tool, a user can identify modules that warrant closer study with other tools such as the Performance Monitor.x2e12jk40
Componentsx2e24jk80\b10i
CountTool is the component of the tool that is loaded with client programs built on top of Alto/Mesa.  This configuration contains one module: Counter; it contains the XFER trap handler and a breakpoint handler.  CountTool must be loaded and started in the system it will monitor.  This may be done by including CountTool in the client configuration whose control module imports and starts XferCountDefs.Counter or by executing the following command in the Alto Executive:x2e12jk40\f6b9f0B134f6b7f0B18f7b4f0B41f6b9f0B90f6b9f0B69f6b21f0B
>Mesa CountTool Clientl4269x2e12jk40\f8
CountPackage is the component that is loaded into the Mesa Debugger.  It implements the basic commands required to enable XFER monitoring and to output measurement results.  CountPackage must be loaded into the Debugger before its commands can be executed.  The easiest way is to load it when installing the Debugger by executing the following command in the Alto Executive:x2e12jk40\f6b12f0B110f7b4f0B48f6b12f0B
>XDebug CountPackage/ll4269x2e12jk40\f8 8f6 12f8 2f0bi
The CountPackage creates a window through which all interaction with the tool takes place.x2e12jk40\4f6b12f0B
Operationx2e18jk80\b
There are two modes of operation, plain and matrix.  Plain mode (the default) simply records the time spend in a module and the number of XFERs to that module.  Matrix mode is used to gather information on flow of control between groups of modules.  Each module is a member of one of sixteen groups.  A sixteen by sixteen matrix of counts and times is maintained by the Counter.  The rows of the matrix are the groups of the source of the XFER, the from group.  The columns of the matrix are the groups of the destination of the XFER, the to group.x2e12jk40\138f7b4f0B297f7b4f0B6f8 4f0 76f7b4f0B6f8 2f0
In plain mode when XFER monitoring is enabled and a XFER occurs, the trap handler calculates the time since the last XFER and adds that to the cumulative time for the current module.  It then calculates which module is the destination of the XFER and makes that the current module, incrementing its count.  In matrix mode when XFER monitoring is enabled and a XFER occurs, the trap handler updates the appropriate element of the matrix.  In both modes, the XFER handler then completes the XFER, and the client program continues.x2e12jk40\19f7b4f0B29f7b4f0B61f7b4f0B121f7b4f0B81f7b4f0B29f7b4f0B93f7b4f0B28f7b4f0B
The state of XFER monitoring can be controlled by two methods.  The first is by setting a conditional break to be handled by the tool's breakpoint handler.  The second is by calling the procedures XferCountDefs.StartCounting and XferCountDefs.StopCounting.x2e12jk40\13f7b4f0B180f6b27f0B5f6b26f0B
When the break handler intercepts a breakpoint, it checks to see if the breakpoint is conditional.  If not, the break handler proceeds to the Debugger.  If it is, the state of XFER monitoring is changed and program execution is resumed.  A condition of zero turns on XFER monitoring; a condition of one toggles the state of XFER monitoring; a condition of two turns off XFER monitoring.  Any other condition has no effect.x2e12jk40\176f7b4f0B87f7b4f0B53f7b4f0B42f7b4f0B
The procedures XferCountDefs.StartCounting and XferCountDefs.StopCounting provide an alternative method of enabling XFER monitoring.  These procedures may be called from statements in the client program, or they may be called from the Debugger's interpreter.x2e12jk40\15f6b27f0B5f6b26f0B43f7b4f0B
Since multiple processes may interact with each other, there is the concept of the tracked process.  If the tracked process is not NIL, only those XFERs that are encountered during execution of the tracked process are counted; all others are simply resumed.  If the tracked process is NIL, then all processes are tracked.x2e12jk40\83i15I33f7 3f0 13f7b4f0B133f7 4f0
The group information for matrix mode is entered into the Counter by reading an edited version of the output from the debugger's Display GlobalFrameTable command.  Appending the group number to the line for a modules will assign the module to that group.  If no group number is specified, the module is assigned to the group of the previous line.  Modules not assigned to any group are members of group zero.  For example:e12jk40(2116)\129f8 24f0 9g
StringsB, G:173134B, gfi:33B 1	group 1
StringsA, G:173140B, gfi:32B	group 1
StreamsC, G:173144B, gfi:31B 2	group 2
StreamsB, G:173150B, gfi:30B	group 2
StreamsA, G:173154B, gfi:27B	group 2
SegmentsB, G:173160B, gfi:26B 3	group 3
SegmentsA, G:173164B, gfi:25B	group 3
OurProcess, G:173170B, gfi:24B 4	group 4
NonResident, G:173210B, gfi:23B	group 4
Modules, G:173214B, gfi:22B	group 4
Miscellaneous, G:173220B, gfi:21B	group 4
MesaInit, G:173224B, gfi:20B 0	group 0
MesaDebug, G:173234B, gfi:17B	group 0l4269e18k40(0,13312)\f8g31f0G7f8g30f0G7f8g32f0G7f8g30f0G7f8g30f0G7f8g32f0G8f8g30f0G8f8g33f0G8f8g32f0G8f8g28f0G8f8g34f0G8f8g31f0G8f8g30f0G8f8g
Window and Commandsx2e18jk80(1799)\b
Interaction with the CountPackage is done through its window.  There are three subwindows: the message subwindow, the form subwindow, and the log subwindow.  Error messages and warnings are displayed in the message subwindow.  Commands are invoked in the form subwindow.  All output is displayed in the log subwindow and written on Count.log.  An illustration of the window during a sample session is shown below.x2e12jk40\21f6b12f0B299f8 9f0
<==<CountToolFig.press<x2e6jk40
x2e120jk40
x2e120jk40
x2e44jk40
Monitor: {off, on}x2e12jk80\f8 18b
turns off/on the tools breakpoint handler.  All conditional breakpoints will affect the state of XFER monitoring when the monitor is on, and will behave as normal conditional breakpoints when it is off.l4269x2e12jk40\97f7b4f0B
Zero Tables!x2e12jk80\f8 12b
zeros out all counts and times.l4269x2e12jk40
Condition Breaks!x2e12jk40\f8 17b
makes all non-conditional breakpoints conditional by adding the condition "1" to them.l4269x2e12jk40
Print Tables!x2e12jk80\f8 13b
displays all the statistics for each module in order of increasing global frame table index (gfi) for plain mode.  In matrix mode, it displays the statistics for each nonzero element of the matrix.  The output format of times is sec.msec:usec.  This command may be aborted by typing ^DEL.l4269x2e12jk40\229f8 13f0 41f7b4f0B
Print Sorted!x2e12jk40\f8 13b
displays all the statistics for each module in order of decreasing time or decreasing number of XFERs depending on the value of Sort by.  This command may be aborted by typing ^DEL.  Not allowed in matrix mode.l4269x2e12jk40\96f7b4f0B28f8 7f0 41f7b4f0B1f8 2f0
Sort by: {count, time}x2e12jk40\f8 22b
when set to count, the Print Sorted command displays table entries in order of decreasing number of XFERs, otherwise it displays in order of decreasing time.l4269x2e12jk40\12f8 5f0 6f8 12f0 65f7b4f0B
Print Module!x2e12jk40\f8 13b
displays the statistics for the module specified by Module.  Not allowed in matrix mode.l4269x2e12jk40\52f8 6f0 1f8 2f0
Module:x2e12jk40\f8 7b
specifys the module to the Print Module command.  It is either the module's global frame table index (gfi), its global frame address (g), or its module name (if the current configuration contains the desired module).l4269x2e12jk40\27f8 12f0
Set Process!x2e12jk40\f8 12b
specifies that only those XFERs executed by the specified process are to be counted.  The default case is to track all processes.l4269x2e12jk40\26f7b4f0B
Process:x2e12jk40\f8 8b
used by the Set Process command.  It contains an octal ProcessHandle as obtained from the Debugger's List Processes command.  If Process is empty, all processes are tracked.l4269x2e12jk40\12f8 11f0 32f6 13f0 33f8 14f0 14f8 7f0
Mode: {plain, matrix}e12jk72(2116)\f8g21f0
when set to plain (default), the Counter records transfers between modules.  When set to matrix, the Counter records transfers from one group to another.l4269e6jk40\12f8 5f0 72f8 6f0 58g
Load Matrix!e12jk72\f8g12f0
using the current selection as a file name, reads the file to input group information.l4269e6jk40\86g
Show Group!e12jk72\f8g11f0
using the current selection as a group number, prints the names of the modules belonging to that group.  This command may be aborted by typing ^DEL.l4269e6jk40\143f7b4f0B1g
Limitationsx2e18jk80(1799)\b11B
1. Execution speed:  Xfer monitoring slows down the executions of a program considerably, since extra processing is done on every XFER.  As a result, interrupt processes that are triggered by clocks (e.g., the keyboard process) will run relatively more frequently.x2e12jk40\130f7b4f0B
2. Idle loop accounting:  When no process is running, the Mesa Emulator runs in its idle loop waiting for a process to become ready.  This idle time is charged to the process that was last running.x2e12jk40
3. Time base:  The time base available on the Alto is a twenty-six bit counter, where the basic unit of time is 38 microseconds.  Thus the counter turns over every 40 minutes, and no individual time greater than 40 minutes is meaningful.  Total times are thirty-two bit numbers and will overflow after 340 minutes.x2e12jk40
4. Overhead calculation:  Due to implementation restrictions and timer granularity, some of the overhead of processing an XFER trap is incorrectly assigned to the client program instead of the CountTool.  As a result, times must be interpreted as only a relative measure of the time spent in a module.x2e18jk40\122f7b4f0B67f6b9f0B
5. Counter sizes:  Counts are thirty-two bit numbers.  The maximum total count is 4,294,967,295 XFERs!x2e12jk40\82v13V1f7b4f0B1v1V
6. Memory requirements:  The CountTool requires seven pages of resident memory: two for its code and five for its frames and tables.  This may affect the performance of some systems that use a lot of memory, especially on the Alto.x2e12jk40\29f6b9f0B
7. Worry mode:  The CountTool operates in worry mode; as a consequence, you may find that you cannot Quit from the Debugger after your session.  Use the Kill command instead.x2e12jk40\20f6b9f0B72f8 4f0 48f8 4f0
Getting Startedx2e18jk40\b
The steps required for using the count tool are outlined below.x2e12jk40
1. obtain the .bcd files for CountTool and CountPackage. x2e12jk40\14f8 4f0 11f6b9f0B5f6b12f0B
2. install the CountPackage in the Debugger.x2e12jk40\15f6b12f0B
3. start your program with the CountTool included.x2e12jk40\31f6b9f0B
4. enter the Debugger and set conditional breakpoints to enable monitoring as desired.x2e12jk40
5. turn the break handler on by setting the Monitor parameter to on.x2e12jk40\44f8 7f0 14f8 2f0
6. proceed with program execution.x2e12jk40
7. return to the Debugger via an interrupt or an unconditional breakpoint.l3584d3008x2e12jk40
8. display results with the Print commands.x2e12jk40\28f8 5f0
Sample Sessione18k80(635)\b14B
The following annotated listing of Debug.log and Count.log should give a fair idea of the use of the count tool.  It counts the XFERs executed when loading a module.x2e12jk40(1799)\35f8 9f0 5f8 9f0 70f7b4f0B
(635)
From Debug.log:

Alto/Mesa Debugger 6.0m of  5-Sep-80 12:02
25-Sep-80  9:56

You called?
>SEt Root configuration: MesaExec
-- set breakpoints to count XFERs involved with loading.
>SEt Module context: MesaExec
>Break Entry procedure: LoadNew Breakpoint #1.
>Break Xit procedure: LoadNew Breakpoint #2.
-- the Condition Breaks command will make these conditional.
-- Condition Breaks and set the process.
>Proceed [Confirm] 
You called?
-- look at the results.

>--Test.map	-- file containing group information.
-- set mode to matrix and load group information using Load Matrix command.
>Proceed [Confirm] 
You called?
-- look at the matrix.
>Kill session [Confirm] 

From Count.log:

Xfer Counter 6.0 of 19-Sep-80  9:53
25-Sep-80 10:48

Track process: 3647B	-- ignore keyboard and interrupt key
Conditionalized breaks

-- Output of Print Tables command with mode = plain
Total Xfers         4,088
Total Time      1.329:842
 Gfi Frame   Module                  #Xfers  %Xfers        Time  %Time
---- ------- ------------------ ----------- ------- ----------- ------
  1B 174164B Resident                    12     .29       6:286    .47
  3B 174030B DiskIO                     869   21.25     583:996  43.91
  4B 174000B Swapper                    530   12.96      96:050   7.22
  5B 173344B MDSRegion                  538   13.16     200:367  15.06
  7B 173314B BFS                          1     .02          76    .00
 10B 173304B Directory                   80    1.95      38:900   2.92
 11B 173270B DiskKD                       2     .04         533    .04
 13B 173260B Files                      140    3.42      15:392   1.15
 15B 173254B FSP                        100    2.44      15:468   1.16
 16B 173240B LoadState                   97    2.37     105:384   7.92
 22B 173214B Modules                     96    2.34      35:471   2.66
 23B 173210B NonResident                  3     .07         457    .03
 25B 173164B SegmentsA                   74    1.81      17:945   1.34
 26B 173160B SegmentsB                   89    2.17      13:487   1.01
 27B 173154B StreamsA                    55    1.34      10:629    .79
 30B 173150B StreamsB                    44    1.07       8:115    .61
 31B 173144B StreamsC                    55    1.34      10:629    .79
 32B 173140B StringsA                    89    2.17       9:525    .71
 33B 173134B StringsB                    19     .46       3:924    .29
 35B 173124B AlFont                     176    4.30      21:107   1.58
 36B 173104B AltoLoader                 237    5.79      29:070   2.18
 40B 173100B BcdOperations              153    3.74      16:421   1.23
 45B 172720B LoaderCore                 516   12.62      74:256   5.58
 47B 172660B StreamIO                    23     .56       2:057    .15
 50B 172650B SystemDisplay               82    2.00      13:830   1.03
 54B 170274B MesaExec                     8     .19         457    .03
Ignored Xfers            98
Ignored Time        309:943(1536)\f8 123f0 2f8 1f0 24f8 1f7b4f0B24f8 123f0 6f8 17f0 41f8 16f0 22f8 32f0 24f8 12f0 53f8 8f0 32f8 13f0 9f8 32f0 23f8 116f0 38f8 23f0 13f8 14f0 12f8 13f0 1f8


-- Output of Print Sorted command with Sorted by = count
Total Xfers         4,088
Total Time      1.329:842
 Gfi Frame   Module                  #Xfers  %Xfers        Time  %Time
---- ------- ------------------ ----------- ------- ----------- ------
  3B 174030B DiskIO                     869   21.25     583:996  43.91
  5B 173344B MDSRegion                  538   13.16     200:367  15.06
  4B 174000B Swapper                    530   12.96      96:050   7.22
 45B 172720B LoaderCore                 516   12.62      74:256   5.58
 36B 173104B AltoLoader                 237    5.79      29:070   2.18
 35B 173124B AlFont                     176    4.30      21:107   1.58
 40B 173100B BcdOperations              153    3.74      16:421   1.23
 13B 173260B Files                      140    3.42      15:392   1.15
 15B 173254B FSP                        100    2.44      15:468   1.16
 16B 173240B LoadState                   97    2.37     105:384   7.92
 22B 173214B Modules                     96    2.34      35:471   2.66
 26B 173160B SegmentsB                   89    2.17      13:487   1.01
 32B 173140B StringsA                    89    2.17       9:525    .71
 50B 172650B SystemDisplay               82    2.00      13:830   1.03
 10B 173304B Directory                   80    1.95      38:900   2.92
 25B 173164B SegmentsA                   74    1.81      17:945   1.34
 27B 173154B StreamsA                    55    1.34      10:629    .79
 31B 173144B StreamsC                    55    1.34      10:629    .79
 30B 173150B StreamsB                    44    1.07       8:115    .61
 47B 172660B StreamIO                    23     .56       2:057    .15
 33B 173134B StringsB                    19     .46       3:924    .29
  1B 174164B Resident                    12     .29       6:286    .47
 54B 170274B MesaExec                     8     .19         457    .03
 23B 173210B NonResident                  3     .07         457    .03
 11B 173270B DiskKD                       2     .04         533    .04
  7B 173314B BFS                          1     .02          76    .00
Ignored Xfers            98
Ignored Time        309:943\f8 1f0 13f8 14f0 12f8 18f0 1f8


-- Output of Print Sorted command with Sorted by = time
Total Xfers         4,088
Total Time      1.329:842
 Gfi Frame   Module                  #Xfers  %Xfers        Time  %Time
---- ------- ------------------ ----------- ------- ----------- ------
  3B 174030B DiskIO                     869   21.25     583:996  43.91
  5B 173344B MDSRegion                  538   13.16     200:367  15.06
 16B 173240B LoadState                   97    2.37     105:384   7.92
  4B 174000B Swapper                    530   12.96      96:050   7.22
 45B 172720B LoaderCore                 516   12.62      74:256   5.58
 10B 173304B Directory                   80    1.95      38:900   2.92
 22B 173214B Modules                     96    2.34      35:471   2.66
 36B 173104B AltoLoader                 237    5.79      29:070   2.18
 35B 173124B AlFont                     176    4.30      21:107   1.58
 25B 173164B SegmentsA                   74    1.81      17:945   1.34
 40B 173100B BcdOperations              153    3.74      16:421   1.23
 15B 173254B FSP                        100    2.44      15:468   1.16
 13B 173260B Files                      140    3.42      15:392   1.15
 50B 172650B SystemDisplay               82    2.00      13:830   1.03
 26B 173160B SegmentsB                   89    2.17      13:487   1.01
 31B 173144B StreamsC                    55    1.34      10:629    .79
 27B 173154B StreamsA                    55    1.34      10:629    .79
 32B 173140B StringsA                    89    2.17       9:525    .71
 30B 173150B StreamsB                    44    1.07       8:115    .61
  1B 174164B Resident                    12     .29       6:286    .47
 33B 173134B StringsB                    19     .46       3:924    .29
 47B 172660B StreamIO                    23     .56       2:057    .15
 11B 173270B DiskKD                       2     .04         533    .04
 23B 173210B NonResident                  3     .07         457    .03
 54B 170274B MesaExec                     8     .19         457    .03
  7B 173314B BFS                          1     .02          76    .00
Ignored Xfers            98
Ignored Time        309:943\f8 1f0 13f8 14f0 12f8 17f0 1f8


Matrix loaded

-- Output of Print Tables command with mode = matrix
Total Xfers         3,834
Total Time        871:004
From -> To          #Xfers   %Xfers           Time   %Time
----   ---     -----------  -------    -----------  ------
   1 ->  1               2      .05            114     .01
   1 ->  2               1      .02            114     .01
   1 ->  3               4      .10            266     .03
   2 ->  1               1      .02            419     .04
   2 ->  2             542    14.13        110:756   12.71
   2 ->  4             126     3.28         17:487    2.00
   2 ->  5              87     2.26         11:201    1.28
   2 ->  6               7      .18            342     .03
   2 -> 10              53     1.38         17:221    1.97
   3 ->  1               4      .10            228     .02
   3 ->  3             179     4.66         37:719    4.33
   3 ->  4              64     1.66          5:829     .66
   3 ->  6              13      .33          2:247     .25
   3 -> 10               1      .02             38     .00
   4 ->  2             124     3.23         19:240    2.20
   4 ->  3              61     1.59          6:705     .76
   4 ->  4           1,105    28.82        264:795   30.40
   4 ->  6              87     2.26         16:725    1.92
   4 ->  7               9      .23          1:790     .20
   4 ->  9               8      .20          5:486     .62
   5 ->  2              82     2.13         13:563    1.55
   6 ->  2               7      .18            495     .05
   6 ->  3              14      .36          2:057     .23
   6 ->  4              87     2.26         27:089    3.11
   6 ->  6             207     5.39         54:330    6.23
   6 ->  7              36      .93          7:658     .87
   6 -> 10              12      .31          1:066     .12
   7 ->  4               9      .23          2:552     .29
   7 ->  6              37      .96          5:067     .58
   7 ->  7             759    19.79        221:932   25.48
   9 ->  4              11      .28            647     .07
  10 ->  2              59     1.53          9:944    1.14
  10 ->  3               1      .02            152     .01
  10 ->  6              12      .31          3:543     .40
  10 -> 10              23      .59          2:171     .24

Ignored Xfers           396
Ignored Time        673:569
\1f8 15f0 12f8 14f0 12f8 14f0 1f8