1 Lisp Library Modules, Medley Release 1.0, SPY 1 Lisp Library Modules, Medley Release 1.0, SPY SPY 1 SPY 1 SPY 6 Spy(SPY NIL Spy NIL NIL 233) is a tool to help you make programs run faster by giving you a picture of where the program is spending its time. Description 1 Spy has two parts: a sampler and a displayer. The sampler runs while your program is running, and it monitors what your program is doing. The displayer displays the data gathered by the sampler. The sampler(SAMPLER NIL sampler NIL NIL 233) periodically interrupts the running program to account the functions in the current call stack(CALL% STACK NIL call% stack NIL NIL 233). This allows Spy to remember not only (proportionally) how long is spent in each individual function, but also how long each function is seen on the call stack. The sampler data structures minimize interference with the normal running of the program % there is little noticeable performance degradation. Spy doesn't log every call and return (it only samples), so you can run it even over long computations without fear of overflowing storage limits. The displayer(DISPLAYER NIL displayer NIL NIL 233) uses the Grapher(GRAPHER NIL Grapher NIL NIL 233) module to display the data gathered by the sampler. In the graph, the height of each node is adjusted to be proportional to the amount of time. Just as MasterScope and Browser give an interactive picture of the static structure(STATIC% STRUCTURE NIL static% structure NIL NIL 233) of the program, Spy gives an interactive picture of the dynamic structure(DYNAMIC% STRUCTURE NIL dynamic% structure NIL NIL 233). The displayer is interactive as well as graphic. That is, you can look at the data in a variety of ways, since it seems there is no one picture that says it all. Since the displayer knows the whole call graph(CALL% GRAPH NIL call% graph NIL NIL 233), it can show the entire tree structure, with separate calls to a function accounted separately, or merge separate calls to the same functions. Since the sampler records the entire calling stack when it samples, it can account for both individual and cumulative time. When the sampler runs, if a function is on the top of the stack, it adds to its individual total; if the function is on the stack at all, the sampler adds to the cumulative total. When there are several calls to the same function within the graph, the displayer can either merge the nodes (show the total time for the function in one node) or not. If a node is merged, then one of the boxes in the graph will have all of the time for that function accounted to it, and the rest will be left as ghost boxes. Spy has a variety of ways of controlling which nodes will be merged. Requirements 1 GRAPHER READNUMBER IMAGEOBJ Installation 1 Load SPY.LCOM and the required .LCOM modules from the library. User Interface 1 (SPY.BUTTON(SPY.BUTTON (function) NIL NIL NIL 234) POS) [Function] This function puts up a little window, which you can use to turn Spy on and off. If POS is NIL, you can drag the window with the mouse. If POS is specified (in the format xxx . yyy) then the window is placed at those coordinates. When Spy isn't watching, it looks like this: @C0Cll0lf` f`Ͼc f fl fl fl f#CȠnCȂ #TҗꀓU? #SQSߥ#@ Hs@Ђ%ksʤ(AD_sUʥ. _sľA&+o@VYW lwre# @SQiRLPCE J` ISĔ@DE+RC@#~C °DDG ?F"CP^$DCtz%7 CͷwF}CȂ,# Left-clicking (pressing the left mouse button) on it once turns on sampling, and the window looks like this: @C0ll0lf` f`c l` l`l l`l l`l l``ȠnCȂ #TҗꀓU? SQSߥ#@ Hs@Ђ%ksʤ(AD_sUʥ. _sľA&+o@VYU lRe#/@SUOZR RCDԉR+SČ}]/C´_#¹/_C/AMtW &,CP_@CA BV C @ @@CȀ # Clicking on it again turns off sampling, and displays the results (SPY.TREE 10). This is the simplest way of spying on operations. (See SPY.TREE below.) Note: You cannot turn off sampling if the mouse process is locked out. (SPY.START(SPY.START (function) NIL NIL NIL 234)) [Function] Reinitializes the internal Spy data structures, and turns on sampling. (SPY.END(SPY.END (function) NIL NIL NIL 234)) [Function] Turns off sampling, and cleans up the data structures in preparation for the display phase performed by SPY.TREE. (SPY.TOGGLE(SPY.TOGGLE (function) NIL NIL NIL 234)) [Function] If Spying is off, turn it on with (SPY.START). If it is on, turn it off with (SPY.END) and then show the results with (SPY.TREE 10). It is reasonable to use this with an interrupt character(INTERRUPT% CHARACTER NIL interrupt% character NIL NIL 234); e.g., (INTERRUPTCHAR (CHARCODE C) '(SPY.TOGGLE) T) enables Control-C (or any other character you specify) as an interrupt which turns spying on and off, the same as clicking on the Spy button. (If the Spy button is visible, it responds to the interrupt.) Then, a Control-C turns on spying, and another one turns it off. (WITH.SPY FORM) [Macro] Calls (SPY.START), evaluates FORM, calls (SPY.END), and then returns the value of FORM. For example, (WITH.SPY (LOAD 'FOO)) is basically (PROGN (SPY.START) (PROG1 (LOAD 'FOO) (SPY.END]. (SPY.TREE(SPY.TREE (function) NIL NIL NIL 235) THRESHOLD INDIVIDUALP MERGETYPE DEPTHLIMIT) [Function] SPY.TREE displays the results of the last SPY sampling in a Grapher window. There are a number of parameters that control the display, which you can either set when you call SPY.TREE, or set interactively with the menu. You normally just use (SPY.TREE) and the menus. THRESHOLD is a percentage (defaults to 0). If a function's contribution to the total elapsed time is lower than the threshold percentage, it is not displayed. INDIVIDUALP is either NIL or T. This controls whether cumulative or individual percentages are displayed. The default is cumulative, in which case a function is charged for the time spent in that function and all subfunctions; if individual, a function is only charged for the time spent in that function alone. MERGETYPE is one of (NONE, ALL, DEFAULT). This controls accounting for functions that appear in several places in the calling tree. Mergetype ALL indicates the total time spent for all calls to the same function, regardless of where it appears. Mergetype NONE indicates the times separately for each instance of the function. Mergetype DEFAULT is the same as NONE except for recursive functions. DEPTHLIMIT is a number (defaults to NIL = arbitrary depth; not completely debugged for other values). You will get a prompt to open a window, and then a graph will appear in it, something like this: `LJǎx=_vvf۷86vv۷ǏNJx000˻0fff`0fff`0X080`0`0X080`0`0X080`0`0X p8K108IR)j@(JX0`IP%)z@B0`9$qPŹ)z@%10XY>K)Z@%X08J2)ZH(JX0`r,K10`0X080`0`0X 08@?0`@?fffffffffff`&fffff0`00fffffffffff`&fffff0X000800;0`00``$0`00``$0X000806tȂ,< \2.Cܰ820` Eg1c090&(r +R%l%)JB`%%)J0`@nR)JP1'( +҄%d! JB`$! J0X~R)J02'*8+҇9 JCJ08yVRgJc?%* ~҄)  JiB J0`VR J8%/2F҄%d@%)JDiB`$%)J0` FR JP?8 t",c?0$b0$a0sX08@0`@fffff`0` fffff`ffffff0X]݀08;0``ffffffUUUUUUUUUUT0```0XXUUUUUUUUUUT088 0``a .D`Œg0`@`c$%nR$E 0X Y$D!~R E08$D-VRgE0``a>D%VRO0`` a%FR$H 0X[N`EgH08`8 0```@0```0X@XUUUUUUUUUUT08 0;0``ffffffUUUUUUUUUUT0``ffffff0X]݀080```0``0X %08[!`0`&"g p`0`$ l`0X(%`08`0````0```0X`08`0```0``0`0X`08`0```0```lz$&qg=0Xr%B*!P%* @ڤHJR08 b!Cj!D%* 2L`@HJ0``d !sjBG%*@JRNq90`` !A_"%h~@qHPP!0r@%Aц$PD%iFBPdHJR!0˻l@xD&G؀2L`XOId=0fff```0fff```0`0`0``0``0`0`0fffff``0fffff``0`0`0`0`0`0`00000000000000000 In this example, 100% of the time was spent under the top frame, T. That time was then divided up among three processes: \BACKGROUND.PROCESS, \MOUSE.PROCESS, :EXEC. The numbers to the left of the label are the percentages. The height of the box is proportional to the percentage (except that it is always made big enough to hold the label). The width isn't significant; it is just wide enough to hold the name of the function You can point at any of the nodes. Right Button Operation If you right-click on a node, the window title will change to show the function name, and the individual and cumulative percentages. The first number is the individual total and the second is the cumulative. If the right-click is not on a node, the title will change to show the name of the top frame and the total number of samples. Left/Middle Button Operations % on a Node If you left-click, or middle-click on a node, you will get a menu: TJ@@@GBHCQ"O"B>H B ȄD3B"GCB@K 8pLA DHA|HHA@HADK8pG8H$DO|H@$D800QŝR&"!>! $#"!IAKIIH<BpÞ<:8$HBFDBB|BB@ $HBBFDÆ<<:8 NewSubTree Creates another Spy window that includes data only from this node and its descendents (with the tree rooted at the selected node). Suppose that you were only interested in the actions that you had invoked with the mouse. You can left-click \MOUSE.PROCESS and select the NewSubTree option. You then get a picture like this: `Ϟpx?ϝ}{[:;=_[nvf}{nvpx9];000000000000000000000000000000000000 00 0000 3?00&(7)J"00"(?)B"00BH+)3"00|+) '00"#)J$I00'"3$I000000 00` 000000&fffffffffff0000;00&fffffffffff00 $00@UUUUUUUUUUP00800$UUUUUUUUUUP00$00P008(00 $P00@$(0.Eg"K0P0̌`!L93f!$ԥnR%jP8gIg(0͒! R%)J!$~R%zP$2@ JPHP0̖P%)BPVRgzP4$@ JH(0̚L9Cg"PVR/P8  YIaNP0̒JB!IB$䴥FR(P8@ YHP>H(0̒HR!)JNEg(˞$%@ JP"HP0`(!&3f1$Bw1a"O(0 0P00 8(00$P00$(00P008 (00$@UUUUUUUUUUP00$00@UUUUUUUUUUP000800$ffffffffffff00$ffffffffffff00 008@00$00@$00 00800 $00%B%{ 00R)B(B\@00V!)B(BZ00e!B(s00&RIB(B00R)Bm(B\@009&{ȔezZ000$00$0000800$00$`0000800$00$0000800$`00$0000800$00$00ű2.C08#@%)JB0$B@B! JB0$qBJC0@! JiB08@!%)JDiB0$13D.{0$0080$0$0080$0$0080$0&fffffffffff00;0&fffffffffff0000000000000000ffffffffffff0ffffffffffff0000000000 SubTree Behaves just like NewSubTree except that Spy will reuse the same window. Delete Removes the selected item (and its subbranches) from consideration in this window, and redisplays. For example, if you don't want to consider GETMOUSESTATE in the graph at all, you can delete the GETMOUSESTATE box and get: `Ϟpx?ϝ}{[:;=_[nvf}{nvpx9];000000000000000000000000000000000000000000000&fffffffffff0&fffffffffff000;00$00$ffffffffffff0000800$ffffffffffff00$0000800$00$0000800$00$0000800$00$0000800$00$0000800$00$0000800$00$0000800$00$0000800$00$0000800$00$00B%{2.C0̌`!L93f.Eg"K0:R)B(BZ@%)JB0͒! R%)J)$ԥnR%jP&B!)B(BFH@B! JB0̖P%)B($~R%zP%!B(s0BJC0̚L9CgPVRgzP?BIB(B@! JiB0̒JB!IB)PVR/P0:R)Bm(BZ@!%)JDiB0̒HR!)J)䴥FR(P%&{ȔezF13D.{0`(!&3fNEg(˞$0 000800$00$0000800$00$0000800$00$0000800$00$0000800$00$0000800$00$0000800$00$0000800$00$0000800$00$0000800$ffffffffffff00$ffffffffffff0000800$00&fffffffffff000;0&fffffffffff00000 The percentage for the SCROLL.HANDLER changed from 80% to 93% when GETMOUSESTATE was deleted. Merge Allows you to merge a node with its caller everywhere in the tree. Edit Invokes SEdit for the function in the node. InspectCode Shows the compiled code for the function in the node. Left/Middle Button Operation % Not on a Node If you press the left, or middle button while not on a node, you get a menu that will let you view or change the parameters for the Spy window: Legend Displays SPY border interpretation. Inspect Allows for the inspection of the current parameter settings for the Spy window. SetThreshold Sets the threshold for displaying a node. Any node whose percentage is below the threshold won't show up (unless it is needed to connect the graph together). You can set the initial threshold via the threshold argument to SPY.TREE; otherwise it defaults to zero. Individual/Cumulative This is used to toggle between the display of individual and cumulative times. The initial default is cumulative; you can set it to Individual by supplying T as the INDIVIDUALP argument to SPY.TREE (see below). MergeNone/MergeAll/MergeDefault This controls merging of nodes (see below). Ctrl-Left/Ctrl-Middle Button Operations If you press the left, or middle button while the control key is down, you will get the same menu, but the action will be deferred until you next use the left/middle button. For example, you can delete several nodes and then do one update. Merged Nodes(MERGED% NODES NIL Merged% Nodes NIL NIL 237) If two nodes are merged, then the merged node(MERGED% NODE NIL merged% node NIL NIL 237) will include the time (and descendents) of the other. The display of a merged node is different; it is shown with a thick gray border; e.g. , }UUUUUUUUUUUUUUUPUUUUUUUUUUUUUUUPPP(S@@P@@(Q8Ip3qP%"JR$J@)JP(Q%J\`$r(KP%"JP$B%)J(S9I2&IP(PP(UUUUUUUUUUUUUUUPUUUUUUUUUUUUUUUP The time in a merged node is the sum of the times for all occurrences. Other calls to the same function may show up as ghost boxes(GHOST% BOXES NIL ghost% boxes NIL NIL 238); e.g. Q  #0dx0 He)H pep @e@ 0b0"""""""""" The case where a function is merged with a recursive call to itself is handled specially: the head of the recursion is marked with a wider checkered border: }wwwwwwwwwwwwwwwptp hq̓1)H)J)tH9 A 8p)H!)@Dd)HhCc4pphwwwwwwwwwwwwwwwp and the tail of the recursion is shown in reverse video: p qmfcǍok۽o|۽ow7nۅqx9m In the recursive case, you can find a situation like this: =*UUUUP*UUUUP(PP(PP(PP(PP(`8Q$P($К8P($wwww` P$P0)`8PP(p`PP(`PP(p`PP(0PP*s% )cUUUUP-`(*5(UUUUP% };q% EcwwwvØDL0L 8p`pH 0H  8p`pH 0I  :Rowwww`rVo HR :RoqH H 8pH H 8wwwvLL; In this case, A calls B and C, and C calls A. All of the time is really spent in B, although only 10% is due to the call from the top-level, and 90% is under a call to C, which called A, which called B. In this situation, C is also recursive, of course, and also has the recursive border. If you find this display confusing, try the MERGENONE option and see if you get a clearer picture. MERGEDEFAULT means to merge any function that is not in SPY.NOMERGEFNS, initially set to (SI::*UNWIND-PROTECT* CL:EVAL \\EVAL-PROGN \\INTERPRET-ARGUMENTS \\INTERPRETER \\INTERPRETER1 ERRORSET \\EVAL \\EVALFORM APPLY \\PROGV EVAL). MERGENONE means not to merge at all. MERGEALL means to merge any two nodes for the same function. The default for Individual mode is MERGEALL. The default for Cumulative mode is MERGEDEFAULT. Individual and Cumulative Modes Spy initially comes up with the height of the boxes showing the amount of time the function was on the current call stack. This is called cumulative mode(CUMULATIVE% MODE NIL cumulative% mode NIL NIL 238), since each function gets the time that both it and the functions it calls account for. There is another kind of display, called Individual, in which the boxes are proportional to the amount of time the function was on the top of the stack. One thing to watch for: when you switch between Individual and Cumulative modes, the threshold stays the same. Sometimes the threshold for Individual needs to be higher; otherwise, functions will tend to disappear in the Individual tree. Also, switching to Individual mode(INDIVIDUAL% MODE NIL Individual% mode NIL NIL 239) also changes to MERGEALL, while switching to Cumulative changes you to MERGEDEFAULT. (SPY.LEGEND(SPY.LEGEND (function) NIL NIL NIL 239)) [Function] If you forget what the different shadings and borders mean, this function brings up a window that shows what they mean; i.e., it shows the interpretation of SPY.BORDERS or the other internal controls. SPY.FREQUENCY(SPY.FREQUENCY (variable) NIL NIL NIL 239) [Variable] How many times per second to sample? Initially set to 10. (Maximum 60). SPY.NOMERGEFNS(SPY.NOMERGEFNS (variable) NIL NIL NIL 239) [Variable] Functions on this list won't get merged under MergeDefault. Includes (SI::*UNWIND-PROTECT* CL:EVAL \\EVAL-PROGN \\INTERPRET-ARGUMENTS \\INTERPRETER \\INTERPRETER1 ERRORSET \\EVAL \\EVALFORM APPLY \\PROGV EVAL). You may need to add more. SPY.TREE(SPY.TREE (variable) NIL NIL NIL 239) [Variable] This variable (same name as the function) is used to hold the data from the last sampling. You can save it and restore it using UGLYVARS (see IRM). SPY.BORDERS(SPY.BORDERS (variable) NIL NIL NIL 239) [Variable] Used to control the border display on a tree. This is a list of (NODETYPE DESCRIPTION BORDERWIDTH TEXTURE INTERIORTEXTURE). SPY.FONT(SPY.FONT (variable) NIL NIL NIL 239) [Variable] Font used to display node labels. Initially GACHA 10. SPY.MAXLINES(SPY.MAXLINES (variable) NIL NIL NIL 239) [Variable] Maximum height of a node in the graph, measured in multiples of the font height of SPY.FONT. Limitations 1 Spy doesn't know anything about the interpreter (INTERPRETER% NIL interpreter% NIL NIL 239)or the internal workings of Lisp. Internal functions that are not REALFRAMEP(REALFRAMEP (function) NIL NIL NIL 239) and don't normally show up on BT backtraces (but do on BT!) will be shown in Spy. This includes things like \INTERPRETER1, which will appear underneath any interpreted function call. Thus Spy does not distinguish between frames that are interesting or not interesting to the user. [This page intentionally left blank] (LIST ((PAGE NIL (PAPERSIZE Letter FOLIOINFO (ARABIC "" "") STARTINGPAGE# 233) (0 0 612 792) ((FOLIO NIL (PARALOOKS (QUAD RIGHT) CHARLOOKS (SUPERSCRIPT 0 INVISIBLE OFF SELECTPOINT OFF PROTECTED OFF SIZE 10 FAMILY HELVETICA OVERLINE OFF STRIKEOUT OFF UNDERLINE OFF EXPANSION REGULAR SLOPE REGULAR WEIGHT MEDIUM INVERTED OFF USERINFO NIL STYLE NIL) FORMATINFO (ARABIC "" "")) (270 15 288 36) NIL) (HEADING NIL (HEADINGTYPE FOOTINGR) (54 27 558 36) NIL) (TEXT NIL NIL (54 54 504 702) NIL))) (PAGE NIL (PAPERSIZE Letter FOLIOINFO (ARABIC "" "")) (0 0 612 792) ((FOLIO NIL (PARALOOKS (QUAD LEFT) CHARLOOKS (SUPERSCRIPT 0 INVISIBLE OFF SELECTPOINT OFF PROTECTED OFF SIZE 10 FAMILY HELVETICA OVERLINE OFF STRIKEOUT OFF UNDERLINE OFF EXPANSION REGULAR SLOPE REGULAR WEIGHT MEDIUM INVERTED OFF USERINFO NIL STYLE NIL) FORMATINFO (ARABIC "" "")) (54 15 288 36) NIL) (HEADING NIL (HEADINGTYPE FOOTINGV) (54 27 558 36) NIL) (HEADING NIL (HEADINGTYPE VERSOHEAD) (54 762 558 36) NIL) (TEXT NIL NIL (54 54 504 684) NIL))) (PAGE NIL (PAPERSIZE Letter FOLIOINFO (ARABIC "" "")) (0 0 612 792) ((FOLIO NIL (PARALOOKS (QUAD RIGHT) CHARLOOKS (SUPERSCRIPT 0 INVISIBLE OFF SELECTPOINT OFF PROTECTED OFF SIZE 10 FAMILY HELVETICA OVERLINE OFF STRIKEOUT OFF UNDERLINE OFF EXPANSION REGULAR SLOPE REGULAR WEIGHT MEDIUM INVERTED OFF USERINFO NIL STYLE NIL) FORMATINFO (ARABIC "" "")) (270 15 288 36) NIL) (HEADING NIL (HEADINGTYPE FOOTINGR) (54 27 558 36) NIL) (HEADING NIL (HEADINGTYPE RECTOHEAD) (54 762 558 36) NIL) (TEXT NIL NIL (54 54 504 684) NIL)))))#3HHT5 ,5 ,HH3llT4TT2HH2HH 6T6$$T5l 3T2ll5ll 5ll3HH T3HHT2HH2HH2HH 2ll2HH2HH 2HH3T8 ,-TF PAGEHEADING VERSOHEADF PAGEHEADING RECTOHEADE PAGEHEADINGFOOTINGVE PAGEHEADINGFOOTINGR3T/TITAN TITAN CLASSIC CLASSICCLASSIC  HELVETICA  HELVETICA  HELVETICAMODERN MODERN TIMESROMAN MODERN MODERNMODERN ! HRULE.GETFNMODERN  !-   HRULE.GETFNMODERN   . HRULE.GETFNMODERN   HRULE.GETFNMODERN    HRULE.GETFNMODERN IM.INDEX.GETFNs  HRULE.GETFNMODERN  !IM.INDEX.GETFN_)IM.INDEX.GETFN\!_ %IM.INDEX.GETFN!IM.INDEX.GETFN5IM.INDEX.GETFNJ7IM.INDEX.GETFN)IM.INDEX.GETFN  HRULE.GETFNMODERN   HRULE.GETFNMODERN  HRULE.GETFNMODERN  'IM.INDEX.GETFN U/Z-$ BMOBJ.GETFN3MODERN  m$ BMOBJ.GETFN3MODERN  B ;  G &IM.INDEX.GETFN G$IM.INDEX.GETFN h 'IM.INDEX.GETFN "     8;IM.INDEX.GETFN       2 %IM.INDEX.GETFN* =      hoO! ?a'  BMOBJ.GETFN3MODERN  } #  S   D BMOBJ.GETFN3 TIMESROMAN   E ) BMOBJ.GETFN3Rl+ ) ) BMOBJ.GETFN3MODERN   J2C"    .Y!  M "  ( "  -IM.INDEX.GETFN -+IM.INDEX.GETFNL BMOBJ.GETFN3#+IM.INDEX.GETFN BMOBJ.GETFN3#L BMOBJ.GETFN39 BMOBJ.GETFN3#;V BMOBJ.GETFN3#N . N    5#%   3IM.INDEX.GETFN3IM.INDEX.GETFN/  'IM.INDEX.GETFN  ! *IM.INDEX.GETFNMODERN 6+IM.INDEX.GETFNMODERN E   %IM.INDEX.GETFNMODERN   (IM.INDEX.GETFNMODERN A9%IM.INDEX.GETFN 6 )IM.INDEX.GETFNMODERN S  HRULE.GETFNMODERN 0-IM.INDEX.GETFNB 'IM.INDEX.GETFNCLASSIC n %z