Inter-Office MemorandumToMesa UsersDateOctober 27, 1980FromJim SandmanLocationPalo AltoSubjectPerformance Measurement ToolOrganizationSDD/SS/MesaXEROX Filed on: [Iris]Doc>PerformanceTool.bravo (and .press)A tool for the performance measurement of Mesa programs is described below. It allows users toidentify places in their programs and then collect timing and frequency statistics of programexecution between these places. The system is implemented as a set of commands that can beexecuted from the Mesa Debugger, plus a routine that intercepts all conditional breakpoints andcollects statistics about them. Existing Debugger commands are used to specify what points are tobe monitored, and additional commands are provided for controlling the measurements andoutputting the results.ConceptsA node is defined to be a point in a program where a breakpoint can be set by the Mesa Debugger.In fact, nodes are implemented via conditional breakpoints, so that while monitoring is turned on,the functioning of all conditional breakpoints is different. In particular, conditional breakpoints causeperformance data to be gathered rather than a breakpoint to be taken.A leg is defined by a pair of nodes, one called the from node and the other the to node. A leg isthe code executed between these nodes. Interesting items measured about a leg include the numberof times this leg was executed and the time required to execute the leg.Facilities are also provided for associating a histogram with any node or leg, thereby providing moredetailed distribution information about the entry than is provided by counts, sums, and averages.Since processor time or task time is not available on the Alto, the measure of computing is simplythe elapsed time between the time the from node is executed and the time the to node is executed.The concept of nodes and legs is borrowed from the Diamond Extended Test Module. Theperformance tool was first written by Paul Jalics, and has since been extended by the Mesa Group.TerminologyNode TableA table maintained by the measurement module containing information about each node. A nodefor each conditional breakpoint is entered into this table by the Collect nodes command or bythe measurement module when it encounters a conditional breakpoint that is not already in thetable. The node table has 20 entries.a[pi W|qarX +q5Fr R?qar +q5Fr MIqas+q 5Fr H0tr BgqF< ;rD :E9$ 8; 6'8 5O[ 32% 2 -s *rurA (D 'Au7r/ %E "Kur/urur B H /ur L u rur> u rur ur  J @! s v ZrN Bw r  +2 d& 2 >]FPerformance Measurement Tool2NodeIDThe index of a node in the node table, used in commands to identify a particular node. This is thesame as the breakpoint number assigned by the Debugger.Leg TableA table maintained by the measurement module containing various information about each leg.Legs are entered into this table by the command Add Legs or by the measurement module when itencounters a new leg and automatic insertion is enabled. The leg table has 41 entries, one of whichis reserved.LegIDThe index of a leg in the leg table. The LegID for a particular conditional breakpoint does notchange during a measurement session and is used in commands to identify a particular leg.HistogramAn optional table that may be associated with either a node or leg that records the distribution of avariable associated with the node or leg by incrementing counters in a number of buckets. Thedistribution may be either linear or logarithmic. In a linear distribuiton, a base may be specifiedwhich will be used as the offset for the first bucket. In a logarithmic distribution, the buckets areindexed by the number of leading binary zeros in the value. A scale is used to adjust the value foran optimal fit into the number of buckets. There is a storage pool of 256 words that is sharedamong all histograms to hold buckets and histogram information.Node HistogramA histogram associated with a node. The histogram variable of the node is the first variable in theconditional expression attached to the breakpoint that defines the node. The value is treated as a 16bit unsigned quantity. For a simple node histogram, the value is adjusted by subtracting the base(if any) and dividing by the scale factor; the resulting quotient is recorded. A logarithmic nodehistogram has a maximum of 16 buckets because the value is a 16 bit quantity.Leg HistogramA histogram associated with a leg. The histogram variable of the leg is the 32 bit time of the leg inunits of ticks. The value is adjusted by shifting the value to the right by the scale. A logarithmicleg histogram has a maximum of 32 buckets because the value is a 32 bit quantity.ComponentsPerfTool is the component of the measurement system that is loaded with client programs built ontop of Alto/Mesa. This configuration contains two modules: PerfMonitor andPerfBreakHandler. PerfMonitor initializes the PerfTool. PerfBreakHandler contains abreakpoint handler that intercepts all conditional breakpoints and accumulates statistical informationabout nodes and legs. PerfTool must be loaded and started in the system it will monitor. Thismay be done by including PerfTool in the client configuration whose control module startsPerfDefs.PerfMonitor or by executing the following command in the Alto Executive:Ws<8R?vNr_MI7IvFrFE0wr%C] XA >gv;r$vr19q*/6"v2rS1,Mur/uru rur- Y,65urur*X(?%v "JrG HGTFM^v rKh?'Q s PxrU6x rxrx rxrxr ZOxr- xrdxr= >X,(Performance Measurement Tool3>Mesa PerfTool ClientPerfPackage is the component that is loaded as a UserProc into the Debugger. It implementsthe basic commands required to manipulate the node table and the leg table and to outputmeasurement results. PerfPackage must be loaded into the Debugger before its commands canbe executed. It also needs the UserProc package. The easiest way is to load it when installingthe Debugger by executing the following command in the Alto Executive:>XDebug PerfPackage/lThe PerfPackage creates a window through which all interaction with the tool takes place.OperationWhen the break handler intercepts a breakpoint, it checks to see if the breakpoint is conditional. Ifso, it finds the node corresponding to the breakpoint, increments its counters, and processes itshistogram if one exists. If tracking of legs is enabled, the leg table is searched for the legs of whichthis node is a part. Otherwise, the breakpoint is resumed.In the simple case, a leg is tracked as follows. The break handler intercepts a conditionalbreakpoint that is the from node of the leg (from) and some time later it intercepts a conditionalbreakpoint that is the to node of the leg (to). At this point, the leg's time is recorded, its count isincremented, and its histogram (if any) is processed.This simple model of tracking a leg is complicated by recursion, signals, and multiple processes.With recursion, from may be encountered several times before to is encountered. With signals, aprocess may be unwound after it encounters from but before it encounters to. With multipleprocesses, one process may encounter from and then another immediately encounter to.To deal with the complication of multiple processes, there is the concept of the tracked process. Ifthe tracked process is not NIL then only those conditional breakpoints that are encountered by thetracked process are treated as nodes. All others are simply resumed as if they did not exist. If thetracked process is NIL, then all processes are tracked.To deal with these complications, there is a leg owner. A leg owner is the process that lastencountered from. When to is encountered and the current process is its owner, then the leg isrecorded and the leg owner is cleared. If the current process is not the owner, the leg is ignored.As a result of ignoring legs, from and to may be counted more times than the leg between them iscounted.Normally, when a node is encountered all legs of which that node is a part are tracked.Alternatively only the leg defined by the last node encountered and the current node is tracked.Window and CommandsInteraction with the PerfPackage is done through its window. There are three subwindows, themessage subwindow, the parameter subwindow, and the log subwindow. Error messages andwarnings are displayed in the message subwindow. Commands are invoked in the parametersubwindow. All output is displayed in the log subwindow. An illustration of the window during asample session is shown below.Ws<8SwvwOx r?NN Lux r5Jxr(I'FEwBrx r @>gs;r^9q U7 ]6";2'51,urvr1/urvr)-5* V(vr)vr'@+vr vr%%vr(vr"J=ur qrD^Tqr!-ur"^ vrvrEA#vrvr/hGr?! Psrx r9ZV> 9(d  >YFPerformance Measurement Tool4<==q"" ""0@ ""  ((""0"" ""0"" ((""0"" ""0@A p@"" @A @@(M9P8Ӏ'pN@@(""0SEE4D"QSA"" ""0QEPE"_AD"" QEPE"hPA@(SEPE4@"hQQSA(""1M9P8ӄ'p|D"" ""0D"" @((""0"" ""0"" ((""0"" ""0"" @(8US4(""0SD}M"" ""0Q|USD"" TQ@UTD (TSDQUTM(""0S8US4"" ""0"" ((""0"" ""0"" ((""0?"" ""0@A|@`"" @A?@(M)Ɯ@N89acHX88>(""0&kQEQEP@eQQEQE@"" ""0Q.PA E`@E_A1@"" Q.$PAEPEPA  (.EQEHEQSEQE(""1M.LN89D@DN088 "" ""0?@"" ? (`(""0"" ""0"" ((""0"" ""0"" (8X8(""0HQEQeQE"" ""0QA E0"" AA (IEQAQE(""08@8"" ""0"" ((""0"" ""0"" ((""0 "" ""0D "" D@(D8ՌTUS4(""0|$HE6R|}M"" ""0D#ENTUSD"" D ETUTD (D$IE4TQUTM(""0D#8TUS4"" ""0"" ((""0"" ""0"" ((""0"" ""0@A?p?`"" @A@O@(M9V9gEcJqD 8i:@C(""0DDDY EDIEfـDS"" ""0Q| )KD0nDQ"" Q@ )C cnDQ (DD@ @)@KEnDS(""1M8c cKD8n C"" ""0OD"" OD(a?`(""0"" ""0"" ((""0 "" ""1D ""  D(xV1P8ӀD8ՌT4(""1!IE4D|$HE6R|L@"" ""1!Q9PED#ENTD@"" !PIPED ETD(%IPE4@D$IE4TL(""1P=P8ӄD#8T4@"" ""0@@"" @D(8(""0"" ""0"" ((""0"" ""1@"" @ ($NH8#8(""1QQE!D@"" ""1Pa @|@"" PQA!@(IQE!D(""1ND88@"" ""0@"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" ((""0"" ""0"" (興"""""""""""""""""""""""""""""""""""""""""""""""""""""""""""""""" """""""""""""""""""""""""""""""""""""""""""""""""""""""""""""""" """""""""""""""""""""""""""""""""""""""""""""""""""""""""""""""" """""""""""""""""""""""""""""""""""""""""""""""""""""""""""""""" """""""""""""""""""""""""""""""""""""""""""""""""""""""""""""""" """""""""""""""""""""""""""""""""""""""""""""""""""""""""""""""" """""""""""""""""""""""""""""""""""""""""""""""""""""""""""""""" """""""""""""""""""""""""""""""""""""""""""""""""""""""""""""""" """""""""""""""""""""""""""""""""""""""""""""""""""""""""""""""" """""""""""""""""""""""""""""""""""""""""""""""""""""""""""""""" <==<<\s<8W5r5#uwrSBw g;yr;w 7r+wr(6#;yr2w/rwrwr$-;*w 'Ar wrur wr%"Kwr wrur wr Uw r-iwr wr w r u wZr wrxrgQ;w7r w rv r 6"w r wr4{0Xu- w)rw rw r(wrwr&lwrwrwr#wr@w2r&0yr]'Performance Measurement Tool87. Worry mode: The PerfBreakHandler operates in worry mode; as a consequence, you mayfind that you cannot Quit from the Debugger after your session. Use the Kill command instead.Getting StartedThe steps required for using the measurement tool are outlined below.1. obtain the .bcd files for PerfTool and PerfPackage. 2. install the PerfPackage in the Debugger.3. start your program with the PerfTool included.4. enter the Debugger and set conditional breakpoints as desired.6. turn measurements on by setting the Monitor parameter to on.7. collect nodes and manipulate the leg table as desired.8. proceed with program execution.9. return to the debugger via an interrupt or an unconditional breakpoint.10. display results with the Print commands.Sample SessionThe following annotated listing of Debug.log and Perf.log should give a fair idea of the use ofthe measurement tool. It monitors the time required for the swapper to allocate real memory pages.Alto/Mesa Debugger 6.0 of 25-Oct-80 22:5026-Oct-80 14:01You called?>SEt Root configuration: Mesa-- allocate most of memory to exercise the swapper>SEt Module context: SegmentsB> AllocatePages[140]37400B^-- set breakpoints to monitor the AllocVM procedure>SEt Module context: Swapper>Break Entry procedure: AllocVM Breakpoint #1.>ATtach Condition #: 1, condition: pages = 1-- a histogram is attached to this breakpoint and the variable pages will be counted.>Break Xit procedure: AllocVM Breakpoint #2.-- the Condition Breaks command is used to make this a conditional break.Performance Tool 6.0 of 21-Oct-80 15:0926-Oct-80 14:02Conditionalized breaksCollected nodesLeg from 1 to 2 addedZ>s<8Ukrxr &SwrwrNsKrEH0 wr xrx rDx rAxr >DA:'wr wr794X" 1 J-wr )sX &mrwrwr&$"A!w) :1 )rX2w!rX"wr w., rX?wr w, rXwrX2w'umd =[XPerformance Measurement Tool9 - - - - - - N O D E T A B L E C O N T E N T S - - - - - - - - - -Node Global Program Number of Config Module Id Frame Counter References Name Name---- ------ ------- ---------- -------- -------- 1 174000 2076 0 Mesa Swapper 2 174000 2521 0 Mesa SwapperAdded Histogram for Node 1Added Histogram for Leg 0-- execute Proceed, followed by an interrupt to the Debugger.Total Elapsed Time of Measurements = 69.627:210Elapsed Time less PerfMonitor Overhead = 67.100:932Total Overhead of PerfMonitor Breaks = 2.526:278Total number of Perf Breaks handled = 1,394Average Overhead per Perf Break = 1:812% of Total Time spent in PerfMonitor = 3.62 - - - - - - N O D E T A B L E C O N T E N T S - - - - - - - - - -Node Global Program Number of Config Module Id Frame Counter References Name Name---- ------ ------- ---------- -------- -------- 1* 174000 2076 697 Mesa Swapper 2 174000 2521 697 Mesa Swapper- - - - - - - L E G T A B L E C O N T E N T S - - - - - - - - -Leg From To # of Times Total Time Average Time % ofId Node Node Referenced sec.msec:usec sec.msec:usec Time--- ---- ---- ---------- ------------- ------------- ----- 0* 1 -> 2 697 27.328:536 39:208 39.24Histogram for Node 1Number of References 697Sum of Values 2,454Average Value 3Scale Factor 1Base 0 Value Count -------------- ------- 0 0 1 3 2 190 3 76 4 297 5 131 6 0 7 0 Overflow 0Histogram for Leg 0Number of References 697Sum of Values 719,172Average Value 1,031Scale Factor (2^n) 0 Value Count -------------- ------- 1 0]"s<8XOwFV0UG.S2R?1P1O6MJrX wr+Gw8F8D8C8A8@8=F;09.8z2615r12iE0B/aB-C,YC'&I%$%#A%!% 9%1)   |%%t%%ldP :^<Performance Measurement Tool10 2 0 4 0 8 0 16 0 32 34 64 99 128 1 256 0 512 1 1,024 562 2,048 0 Overflow 0s;w    }tld2 Q b@ TIMESROMAN  HELVETICA TIMESROMAN  TIMESROMAN LOGO TIMESROMAN  HELVETICA GACHA  HELVETICA   HELVETICA HELVETICA  HELVETICA  HELVETICA LOGO4hKOU]b!hjk%P=##:C:#=#B"Py:C:C"i rZ ( B "=i#B " 9eB: ;Z":#"iZ !WiW:Z": +iQB":B": +iGB":#* "B" : ;*PPB!l* "::B: ;Z":B":J"9W"iT"=#B ": C" 9B":qB)B:Z":*:B":B"i^: #: B":PP*J"PP*J":PPB"*iA":B: ;Z: j/m k#wiPerformanceTool.pressWick26-Oct-80 16:18:49 PSTk