Number: 1007

Date:  7-May-84 17':09':33

Submitter: Masinter.PA

Source: 

Subject: want better SPY documentation

Lisp Version: 

Description: '
It is still a little rough, but I think it is useful in its current form and I wanted to get it out for comments. Please note '
a) if you are not running in <LispCore>Next>, load <LISPUSERS>INTPATCH.DCOM before you try this.'
b) the Dolphin and Dorado have a bug which will cause incorrectly large amounts of time to be accumulated to \3MBGETPACKET (or whatever.)'
'
'
SPY is a tool that helps you find out where your program is spending its time. SPY gathers statistics by periodically interrupting the running program, and looking back on the stack. SPY then will display the timing information graphically, using the GRAPHER package.'
'
(SPY.START)						[function]'
Reinitializes the internal SPY data structures, and turns on sampling.'
'
(SPY.END)							[function]'
Turns off sampling'
'
(WITH-SPY form) 					[macro] Calls'
(SPY.START), evaluates form, calls (SPY.END), and then returns the'
value of form.'
'
(SPY.TREE threshold nomerge) Displays the results of the last ''spy'' in a grapher window. If ''NOMERGE'' is T, duplicate subtrees and recursions will NOT be merged.'
'
Once you have the tree, you can change the threshold and switch between individual and cumulative times by buttoning with the left button anywhere NOT on a node (it will give you a menu with two items when you let up).'
'
If you button on a node, first, the title of the window will change to show you to individual and cumulative percentage of time in the given node. You will get a menu which includes items':'
'
SubTree		Create another spy window which includes data only from this node and its descendents.'
'
(and some other options which are not yet implemented).'
'
'
SPY differs from the "Stats" facility in Interlisp-D in that it does not log EVERY call and return; it relies on statistical frequency instead. This means you can sample much larger calculations without worry of filling up your disk. Also, SPY doesn''t slow down the calculation nearly as much. However, SPY keeps its data structures in virtual memory, and may interfere some with working set.'
'
Internal controls':'
'
SPY.FREQUENCY					[variable] '
How many times per second to sample? Initially set to 10.  (Maximum 60).'
'
SPY.NOMERGEFNS		[variable]'
Functions on this list won''t get merged. Includes (ERRORSET \EVAL EVALFORM APPLY EVAL). You may need to add more.'
'
-----'
'
Date': 14 May 84 09':46':10 PDT (Monday)'
From': Feuerman.PASA'
Subject': SPY reading'
To': Masinter.pa'
cc': , Feuerman'
'
Larry,'
'
I''ve just used your SPY package.  It worked on the second time!  (The first time, I QUOTEd form in the WITH-SPY call.  It wasn''t clear to me how the kind of MACRO you used evaluated its argument.)  At any rate, my question is':  How do you read the GRAPH that SPY.TREE produces?'
'
--Ken.'
'
-----'
'
Date': 14 May 84 17':25 PDT'
From': Masinter.pa'
Subject': Re': SPY reading'
In-reply-to': Feuerman.PASA''s message of 14 May 84 09':46':10 PDT (Monday)'
To': Feuerman.PASA'
cc': LispSupport'
'
Ken':'
'
Yes, the SPY documentation is in sorry shape. The basic idea is that when you call SPY.TREE() you get a tree where the height of the box is proportional to the amount of time in the function or beneath it. Buttoning a node will change the title to display information about the mode you buttoned. The left button will track, too.'
'
Using the middle button will give you a menu.  On an individual node, the menu items are "SubTree" and "Delete".  Delete will remove the indicated node from the tree, and redisplay as if those calls didn''t happen at all.'
'
SubTree will prompt you for another window which contains just the node you pointed at and its descendents.'
'
If you button outside a node, you''ll get to change a couple of settings for the window': '
Individual means to make the boxes proportional to the time spent in the individual functions, while'
Cumulative means to make them proportional the time in the function or below it.'
'
SetThreshold lets you set a threshold -- functions with times below the threshold won''t show.'
'
There are some options on ''merging''':'
MergeNone means always show the full expanded tree'
MergeDefault means to merge separate trees except for the subtrees of SPY.NOMERGEFNS.'
MergeAll means to merge separate trees ALWAYS'
'
'
The boxes have different borders. A black border is a ''normal'' node. A dotted border means a node which was merged somewhere else. A dark grey border means a node which was ''merged into''.'
'
This is crummy for documentation, but maybe it is a start. Why don''t you ask the obvious questions about places where this doesn''t make sense and I will try to fix it up.'
'
Thanks,'
'
Larry'
'
(I always have trouble getting documentation out)'
'
-----'
'
Date': 15 May 84 11':37':15 PDT (Tuesday)'
From': Feuerman.PASA'
Subject': Re': SPY reading'
In-reply-to': Masinter.pa''s message of 14 May 84 17':25 PDT'
To': Masinter.pa'
cc': Feuerman, LispSupport.pa'
'
Ok, Larry, some questions about that':'
'
What exactly are you referring to when you talk about "merging" trees?  How do seperate trees arise?  How is it decided how to merge them?'
'
I''ve been going under the assumption that direct descendents of a node are those that are called directly by the node (or at least appear just above the node in the backtrace stack).  True?'
'
There are two percentages listed in the title of the window.  Is the first number the percentage of time spent actually IN the node/function, and the second one the time spent in this node and all other nodes following it?'
'
Using my assumption from above, there are times when the numbers just don''t add up right, and it''s not from round-off error.  Sometimes I''ll have a node with (e.g.) 17% cumulative, but its descendent''s cumulatives add up to far more.  Does this make sense?'
'
--Ken.'
'
P.S.  I''ve still been able to use it to find out a great deal.  Thanks for the tool, it''s VERY useful!!'
'
-----'
'
Date': 20 MAY 84 14':15 PDT'
From': MASINTER.PA'
Subject': SPY readings'
To':   Feuerman.PASA'
cc':   LispSupport'
'
There was a bug in SPY having to do with ''recursive'' nodes. If A called B called A, it would merge the interior call to A with the exterior one, but would add in the cumulative time. '
'
I think you''ve inferred most of the operations of SPY. It is on my task list to write up SPY with a lot better documentation... but of course, there is a lot else on my task list, too.'
'
Larry'
'
-----'
'
Date': 21 May 84 00':47 PST'
From': masinter.pa'
Subject': new SPY'
To': LispFriends^'
'
There''s a new version of SPY on <LispUsers> which fixes a problem with the display when it was showing accumulated time for recursive calls.'
'
I also changed the default behavior to always show the percentages in the box along with the function name.'
'
'


Workaround: 

Test Case: 

Edit-By: Sannella.PA

Edit-Date: 27-Jun-84 14':15':02

Attn: 

Assigned To: Masinter

In/By: 

Disposition: [complete with graphics, apparently in the works to release]

System: Programming Environment

Subsystem: Performance Tools

Machine: 

Disk: 

Microcode Version: 

Memory Size: 

File Server: 

Server Software Version: 

Difficulty: Easy

Frequency: 

Impact: 

Priority: Absolutely

Status: Fixed

Problem Type: Documentation

Source Files: