SpyLogReaderImpl.mesa
last modified by: John Maxwell on December 14, 1983 2:25 pm
DIRECTORY
AMBridge USING [TVForPointerReferent],
AMTypes USING [TV, TVType, TypeToName],
BasicTime USING [GetClockPulses, Pulses, PulsesToMicroseconds, PulsesToSeconds],
IO USING [card, char, CR, int, ROS, RopeFromROS, Put, PutChar, PutF, rope, STREAM, TAB],
PrincOps USING [BytePC, CSegPrefix, EntryVectorItem, GFTIndex, GlobalFrameHandle, LastAVSlot, NullPsbHandle, PsbIndex, PsbHandle],
PrincOpsUtils USING [PsbHandleToIndex],
PrintTV USING [Print],
Process USING [Priority],
RealOps USING [RoundI],
Rope USING [Cat, FromChar, Equal, ROPE],
RTSymbolDefs USING [CallableBodyIndex, SymbolTableBase],
RTSymbolOps USING [AcquireRope, BodyName],
RTSymbols USING [AcquireSTBFromGFH, ReleaseSTB],
RTTypesPrivate USING [GetCBTI, GetEp, GFHToName],
SpyLog USING [active, Close, Entry, NextEntry, OpenForRead],
SpyOps USING [Call, Count, DataType, GFHFromGFI, LevelData, pageFaults, Procedure, ProcessRef, ProcessRec, ProcRec, runningTime, Stack, stackHeader, stackLength, StackType, wordsAllocated, wordsReclaimed],
ViewerIO USING [CreateViewerStreams];
SpyLogReaderImpl: PROGRAM
IMPORTS
AMBridge, AMTypes, BasicTime, IO, PrincOpsUtils, PrintTV, RealOps, Rope, RTSymbolOps, RTSymbols, RTTypesPrivate, SpyLog, SpyOps, ViewerIO
EXPORTS SpyOps = BEGIN
OPEN IO, SpyOps;
ROPE: TYPE = Rope.ROPE;
Error: SIGNAL = CODE;
-- global variables and types --
processes: PUBLIC LIST OF ProcessRef ← NIL;
modules: PUBLIC LIST OF Procedure ← NIL;
current: SpyOps.DataType;
procedures listed in top down order
DestroyLog: PUBLIC PROCEDURE = {
NilLinks: PROC[proc: Procedure] RETURNS[BOOLEANFALSE] = {
proc.container ← NIL;
proc.parents ← NIL;
proc.sons ← NIL};
[] ← EnumerateProcs[NilLinks];
FOR modules ← modules, modules.rest WHILE modules # NIL DO
modules.first.container ← NIL;
modules.first.parents ← NIL;
modules.first.sons ← NIL;
ENDLOOP;
FOR processes ← processes, processes.rest WHILE processes # NIL DO
processes.first.sons ← NIL;
ENDLOOP;
processes ← NIL;
modules ← NIL;
SpyLog.Close[]};
ReadLog: PUBLIC PROCEDURE[typescript: IO.STREAM, datatype: SpyOps.DataType, spyOnSpyLog: BOOL] =
BEGIN
ignoreBefore: BasicTime.Pulses ← 0;
IF typescript = NIL THEN typescript ← ViewerIO.CreateViewerStreams["Spy log"].out;
typescript.Put[rope["(Please wait-- processing log.)\n\n"]];
current ← datatype;
typeName ← ALL[NIL];
SELECT current FROM
CPU => className ← NIL;
process, breakProcess => {
className ← "waiting";
typeName[0] ← "executing";
typeName[1] ← "pagefault";
typeName[2] ← "ML";
typeName[3] ← "CV";
typeName[4] ← "preempted"};
pagefaults => {
className ← "pagefault";
typeName[1] ← "data";
typeName[2] ← "code";
typeName[3] ← "xfer"};
allocations, wordsAllocated => {
className ← "allocation";
typeName[0] ← "safe";
typeName[1] ← "permanent";
typeName[2] ← "unsafe"};
userDefined => className ← "userBreaks";
ENDCASE => ERROR;
typeData ← ALL[0];
IF useTrigger THEN {
ignoreBefore ← FindTrigger[];
IF ignoreBefore = LOOPHOLE[0] THEN {
typescript.Put[rope["No trigger encountered.\n\n"]]; RETURN};
IF triggerExtent > ignoreBefore
THEN ignoreBefore ← 0
ELSE ignoreBefore ← ignoreBefore - triggerExtent};
ReadSpyLog[ignoreBefore, spyOnSpyLog];
SetAllContainers[];
PrintStatistics[typescript];
PrintInstructions[typescript];
PrintLogStatistics[typescript];
END;
*********************************************
reading the section of the log just before a trigger
*********************************************
useTrigger: BOOLEANFALSE;
triggerExtent: BasicTime.Pulses;
whichTrigger: NAT ← 1;
SetTrigger: PROC[extent: BasicTime.Pulses, which: NAT ← 1, enable: BOOLEANTRUE] = BEGIN
useTrigger ← enable;
triggerExtent ← extent;
whichTrigger ← which;
END;
FindTrigger: PROC RETURNS[trigger: BasicTime.Pulses] = BEGIN
count: NAT ← 0;
entry: LONG POINTER TO SpyLog.Entry;
SpyLog.OpenForRead[]; -- open for reading
WHILE TRUE DO
entry ← SpyLog.NextEntry[];
WITH e: entry SELECT FROM
endOfLog => EXIT;
data => {
stack: LONG POINTER TO SpyOps.Stack ← LOOPHOLE[@e.data];
IF stack.type # LAST[SpyOps.StackType] THEN LOOP;
count ← count + 1;
IF count < whichTrigger THEN LOOP;
RETURN[e.timestamp]};
ENDCASE;
ENDLOOP;
RETURN[0];
END;
*********************************************
building a call tree from the trace log
*********************************************
out: IO.STREAM;
public statistics
wakeups: PUBLIC Count ← 0; -- Number of times that Spy counted something
notScheduled: PUBLIC SpyOps.Count ← 0; -- no interesting process sceduled
skips: PUBLIC SpyOps.Count ← 0; -- waiting on disk
levelData: PUBLIC SpyOps.LevelData ← ALL[0];
typeName: ARRAY StackType OF Rope.ROPE;
typeData: ARRAY StackType OF Count;
className: Rope.ROPE;
private statistics
processed: Count ← 0; -- Number of stacks in the log
overflow: Count ← 0; -- # of samples with stacks >= SpyOps.stackLength
error: Count ← 0; -- # of samples with stacks >= SpyOps.stackLength
stackDepth: Count ← 0; -- sum of stack depths
noCalls, noProcesses, noProcs, noModules: Count ← 0;
readLog: BasicTime.Pulses; -- elapsed time to read log
recordSpyTime: BOOLEANFALSE;
spyTime: ARRAY [0..3] OF RECORD[
count: Count,
time: BasicTime.Pulses];
ReadSpyLog: PROCEDURE[ignoreBefore: BasicTime.Pulses, spyOnSpyLog: BOOL] =
BEGIN
i: CARDINAL;
data: BOOLEANFALSE;
dataSize: CARDINAL ← 0;
first, last: BasicTime.Pulses ← 0;
active: BOOLEAN ← SpyLog.active;
t1, delta, dataTime: BasicTime.Pulses;
entry: LONG POINTER TO SpyLog.Entry;
process: PrincOps.PsbHandle ← PrincOps.NullPsbHandle;
Initialize[];
SpyLog.OpenForRead[]; -- open for reading
readLog ← 0;
t1 ← BasicTime.GetClockPulses[];
WHILE TRUE DO
IF UserInput.userAbort THEN EXIT;
entry ← SpyLog.NextEntry[];
WITH e: entry SELECT FROM
endOfLog => EXIT;
nullEntry => LOOP;
trace => IF recordSpyTime THEN {
IF ~data THEN last ← e.timestamp;
IF data THEN {
delta ← e.timestamp - last;
IF delta > 10000000 THEN {data ← FALSE; RETURN};
SELECT delta FROM
<= 10 => i ← 0; <= 100 => i ← 1;
<= 1000 => i ← 2; ENDCASE => i ← 3;
spyTime[i].count ← spyTime[i].count + 1;
spyTime[i].time ← spyTime[i].time + delta};
data ← FALSE}
ELSE {
IF first = 0 THEN first ← e.timestamp;
IF last = 0 THEN delta ← 0 ELSE delta ← e.timestamp - last;
IF out = NIL THEN {
out ← ViewerIO.CreateViewerStreams["auxilary spy log"].out;
out.PutF["%l uSeconds delta data\n", char['f]]};
IF e.process # process THEN {
out.PutF[" Switch to process: %b\n", card[PrincOpsUtils.PsbHandleToIndex[e.process]]];
process ← e.process};
PrintTrace[e.gfi, e.pc, e.timestamp - first, delta];
last ← e.timestamp};
data => {
stack: LONG POINTER TO SpyOps.Stack;
IF useTrigger AND e.timestamp < ignoreBefore THEN LOOP;
IF e.rttype # SpyOps.Stack.CODE THEN {
IF first = 0 THEN first ← e.timestamp;
IF last = 0 THEN delta ← 0 ELSE delta ← e.timestamp - last;
PrintEntry[e.rttype, e.size, @e.data, e.timestamp - first, delta];
last ← e.timestamp; LOOP};
stack ← LOOPHOLE[@e.data];
IF useTrigger AND stack.type = LAST[SpyOps.StackType] THEN EXIT;
EnterStack[LOOPHOLE[@e.data], (e.size - SpyOps.stackHeader)/2];
dataSize ← e.size + 4;
dataTime ← e.timestamp;
data ← TRUE};
ENDCASE => SIGNAL Error;
ENDLOOP;
readLog ← BasicTime.GetClockPulses[]-t1;
IF active THEN SpyLog.Open[TRUE];
IF UserInput.userAbort THEN ERROR SpyOps.UserAborted;
stack ← NIL;
out ← NIL;
END;
PrintEntry: PROCEDURE[type, words: CARDINAL, data: LONG POINTER,
time, delta: BasicTime.Pulses] =
BEGIN
value: AMTypes.TV;
IF out = NIL THEN {
out ← ViewerIO.CreateViewerStreams["auxilary spy log"].out;
out.PutF["%l uSeconds delta data\n", char['f]]};
value ← AMBridge.TVForPointerReferent[data, LOOPHOLE[type]];
out.PutF["%9d%9d %g: \n",
card[BasicTime.PulsesToMicroseconds[time]],
card[BasicTime.PulsesToMicroseconds[delta]],
rope[AMTypes.TypeToName[AMTypes.TVType[value]]]];
PrintTV.Print[value, out];
out.PutChar[IO.CR];
END;
PrintTrace: PROCEDURE[gfi: PrincOps.GFTIndex, pc: PrincOps.BytePC,
time, delta: BasicTime.Pulses] =
BEGIN
name: Rope.ROPE ← GetName[gfi, pc];
out.PutF["%9d%9d %g (gfi: %g, pc: %g)\n",
card[BasicTime.PulsesToMicroseconds[time]],
card[BasicTime.PulsesToMicroseconds[delta]],
rope[name], card[gfi], card[pc]];
END;
GetName: PROC[gfi: PrincOps.GFTIndex, pc: PrincOps.BytePC] RETURNS[name: Rope.ROPE] =
BEGIN
proc: Rope.ROPE;
gfh: PrincOps.GlobalFrameHandle;
stb: RTSymbolDefs.SymbolTableBase ← [x[e: NIL]];
gfh ← SpyOps.GFHFromGFI[gfi];
name ← RTTypesPrivate.GFHToName[gfh];
BEGIN
ENABLE ANY => {IF stb # [x[e: NIL]] THEN RTSymbols.ReleaseSTB[stb]; CONTINUE};
ep: CARDINAL;
cbti: RTSymbolDefs.CallableBodyIndex;
stb ← RTSymbols.AcquireSTBFromGFH[gfh];
[ep,] ← RTTypesPrivate.GetEp[[pc], gfh, stb];
cbti ← RTTypesPrivate.GetCBTI[stb, ep];
proc ← RTSymbolOps.AcquireRope[stb, RTSymbolOps.BodyName[stb, cbti]];
RTSymbols.ReleaseSTB[stb];
END;
RETURN[Rope.Cat[name, ".", proc]];
END;
-- tree management --
Initialize: PROCEDURE =
BEGIN
processes ← NIL;
modules ← NIL;
stackDepth ← 0;
processed ← overflow ← error ← 0;
wakeups ← notScheduled ← skips ← 0;
noProcesses ← noCalls ← noProcs ← noModules ← 0;
spyTime ← ALL[[0, 0]];
levelData ← ALL[0];
stack ← NIL;
END;
EnumerateProcs: PROCEDURE[userProc: PROC[Procedure] RETURNS[BOOLEAN]]
RETURNS[last: Procedure] =
BEGIN
FOR m: LIST OF Procedure ← modules, m.rest WHILE m # NIL DO
FOR p: LIST OF Call ← m.first.sons, p.rest WHILE p # NIL DO
IF userProc[p.first.proc] THEN RETURN[p.first.proc];
ENDLOOP;
ENDLOOP;
RETURN[NIL];
END;
-- adding a stack to the call tree --
stack: ProcStack;
EnterStack: PROCEDURE[s: LONG POINTER TO SpyOps.Stack, n: CARDINAL] =
BEGIN
ENABLE Error => {error ← error + 1; CONTINUE};
INVARIANT: exactly n proc.calls or proc.count should be incremented.
process: ProcessRef ← NIL;
proc, newSon: Procedure ← NIL;
processed ← processed + 1;
wakeups ← wakeups + s.count;
IF s.level = 0 AND n = 0 THEN {SELECT s.type FROM
0 => notScheduled ← notScheduled + s.count;
1 => skips ← skips + s.count;
ENDCASE => error ← error + s.count;
RETURN};
-- add the first frame to the appropriate process list
process ← AddProcess[s.process];
process.calls ← process.calls + s.count;
stackDepth ← stackDepth + n;
IF process.level[0] # s.level THEN
FOR i: CARDINAL IN [0..4] DO
IF process.level[i] = s.level THEN EXIT;
IF process.level[i] # 0 THEN LOOP;
process.level[i] ← s.level;
EXIT; ENDLOOP;
levelData[s.level] ← levelData[s.level] + s.count;
-- [level: 7, n: 0] is the code for an overflow
IF s.level = 7 THEN {overflow ← overflow + s.count; RETURN};
IF n = 0 THEN RETURN ELSE n ← n - 1;
[process.sons, proc] ←
AddSon[process.sons, 0, s.frame[n].gfi, s.frame[n].pc, s.count];
IF stack = NIL THEN stack ← NEW[ProcStackRec ← []];
stack.process ← process;
AddFrame[stack, proc, 0];
WHILE TRUE DO
are we at the end of the stack?
IF n = 0 THEN EXIT ELSE n ← n - 1;
proc.calls ← proc.calls + s.count;
add the current frame to the current node
[proc.sons, newSon] ←
AddSon[proc.sons, s.frame[n+1].pc,
s.frame[n].gfi, s.frame[n].pc, s.count];
proc ← newSon;
AddFrame[stack, proc, s.frame[n+1].pc];
IF Recursive[stack] THEN {
proc.marked ← TRUE;
Undo[stack, s.count]};
ENDLOOP;
add in the leaf counts
proc.count ← proc.count + s.count;
IF s.type # 0 THEN { -- treat as a call even tho it's a count
[proc.sons, newSon] ← AddSon[proc.sons, s.frame[0].pc, 0, s.type, s.count];
newSon.count ← newSon.count + s.count};
typeData[s.type] ← typeData[s.type] + s.count;
stack.index ← 0;
END;
-- adding to the list of processes --
AddProcess: PROCEDURE[psb: PrincOps.PsbIndex]
RETURNS[process: ProcessRef ← NIL] =
BEGIN
list: LIST OF ProcessRef ← processes;
should we add it to the beginning of the list?
IF list = NIL OR psb < list.first.psb THEN {
process ← NewProcess[psb];
processes ← CONS[process, processes];
RETURN[process]};
WHILE list # NIL DO
process ← list.first;
is this the process we want?
IF process.psb = psb THEN RETURN[process];
should the process follow this one?
IF list.rest = NIL OR psb < list.rest.first.psb THEN {
process ← NewProcess[psb];
list.rest ← CONS[process, list.rest];
RETURN[process]};
list ← list.rest;
ENDLOOP;
ERROR;
END;
NewProcess: PROCEDURE[psb: PrincOps.PsbIndex]
RETURNS[process: ProcessRef] =
BEGIN
process ← NEW[ProcessRec ← []];
noProcesses ← noProcesses + 1;
process.psb ← psb;
END;
-- adding/deleting procedures from a LIST OF Call --
AddSon: PROC[list: LIST OF Call, from: CARDINAL, gfi: PrincOps.GFTIndex, pc, count: Count]
RETURNS[newList: LIST OF Call, procedure: Procedure] =
BEGIN
INVARIANT: the lists remain sorted
INVARIANT: exactly one LIST OF Call.calls will be incremented
procedure ← NIL;
newList ← list;
should we add it to the beginning of the list?
IF list = NIL OR from < list.first.pc THEN {
procedure ← AddProcedure[gfi, pc];
newList ← CONS[[from, count, procedure], list];
noCalls ← noCalls + 1;
RETURN[newList, procedure]};
WHILE list # NIL DO
procedure ← list.first.proc;
is this the procedure we want?
IF list.first.pc = from AND Equal[gfi, pc, procedure] THEN {
IF list.first.calls = 0 THEN list.first.proc.refs ← list.first.proc.refs + 1;
list.first.calls ← list.first.calls + count;
RETURN[newList, procedure]};
should the procedure follow this one?
IF list.rest = NIL OR from < list.rest.first.pc THEN {
procedure ← AddProcedure[gfi, pc];
list.rest ← CONS[[from, count, procedure], list.rest];
noCalls ← noCalls + 1;
RETURN[newList, procedure]};
list ← list.rest;
ENDLOOP;
ERROR;
END;
RemoveSon: PROC[proc: Procedure, pc: CARDINAL, list: LIST OF Call, count: Count]
RETURNS[newList: LIST OF Call] =
BEGIN
INVARIANT: the lists remain sorted
INVARIANT: exactly one LIST OF Call.calls will be decremented
prior: LIST OF Call;
FOR s: LIST OF Call ← list, s.rest DO
IF s = NIL THEN SIGNAL Error; -- where is it?
IF s.first.proc # proc OR s.first.pc # pc THEN {prior ← s; LOOP};
IF s.first.calls = 0 THEN RETURN[list];
s.first.calls ← s.first.calls - count;
IF s.first.calls = 0 THEN s.first.proc.refs ← s.first.proc.refs - 1;
IF s.first.calls > 0 THEN RETURN[list];
s.first.proc.refs ← s.first.proc.refs - 1;
IF s = list THEN RETURN[list.rest];
prior.rest ← s.rest;
RETURN[list];
ENDLOOP;
END;
GreaterThan: PROC[gfi: PrincOps.GFTIndex, pc: CARDINAL, proc: Procedure]
RETURNS[BOOLEAN] =
INLINE BEGIN
IF gfi > proc.gfi THEN RETURN[TRUE];
IF gfi < proc.gfi THEN RETURN[FALSE];
IF pc > proc.exitPC THEN RETURN[TRUE];
RETURN[FALSE];
END;
Equal: PROC[gfi: PrincOps.GFTIndex, pc: INT, proc: Procedure]
RETURNS[BOOLEAN] =
INLINE BEGIN
entryPC, exitPC: INT;
IF proc = NIL THEN RETURN[TRUE]; -- source
IF gfi # proc.gfi THEN RETURN[FALSE];
IF pc < (entryPC ← proc.entryPC) THEN RETURN[FALSE];
IF pc > (exitPC ← proc.exitPC) THEN RETURN[FALSE];
RETURN[TRUE];
END;
-- adding modules and procedures to the modules list --
AddProcedure: PROCEDURE[gfi: PrincOps.GFTIndex, pc: CARDINAL]
RETURNS[procedure: Procedure] =
BEGIN
INVARIANT: the lists remain sorted
INVARIANT: exactly one ref will be incremented
module: Procedure;
list: LIST OF Call;
module ← AddModule[gfi];
procedure ← NIL;
list ← module.sons;
should we add it to the beginning of the list?
IF list = NIL OR GreaterThan[gfi, pc, list.first.proc] THEN {
procedure ← NewProcedure[module, pc];
IF procedure = NIL THEN SIGNAL Error;
procedure.refs ← 1;
module.sons ← CONS[[0, 0, procedure], list];
noCalls ← noCalls + 1;
RETURN[procedure]};
WHILE list # NIL DO
procedure ← list.first.proc;
is this the procedure we want?
IF Equal[gfi, pc, procedure] THEN {
procedure.refs ← procedure.refs + 1;
RETURN[procedure]};
should the procedure follow this one?
IF list.rest = NIL OR GreaterThan[gfi, pc, list.rest.first.proc] THEN {
procedure ← NewProcedure[module, pc];
IF procedure = NIL THEN SIGNAL Error;
procedure.refs ← 1;
list.rest ← CONS[[0, 0, procedure], list.rest];
noCalls ← noCalls + 1;
RETURN[procedure]};
list ← list.rest;
ENDLOOP;
ERROR;
END;
AddModule: PROCEDURE[gfi: PrincOps.GFTIndex]
RETURNS[module: Procedure] =
BEGIN
INVARIANT: the lists remain sorted
list: LIST OF Procedure;
module ← NIL;
list ← modules;
should we add it to the beginning of the list?
IF list = NIL OR gfi > list.first.gfi THEN {
module ← NewModule[gfi];
modules ← CONS[module, list];
RETURN[module]};
WHILE list # NIL DO
module ← list.first;
is this the module we want?
IF gfi = module.gfi THEN RETURN[module];
should the module follow this one?
IF list.rest = NIL OR gfi > list.rest.first.gfi THEN {
module ← NewModule[gfi];
list.rest ← CONS[module, list.rest];
RETURN[module]};
list ← list.rest;
ENDLOOP;
ERROR;
END;
NewModule: PROCEDURE[gfi: PrincOps.GFTIndex]
RETURNS[module: Procedure] =
BEGIN
module ← NEW[ProcRec ← []];
noModules ← noModules + 1;
module.gfi ← gfi;
module.name ← (IF gfi = 0 THEN className ELSE RTTypesPrivate.GFHToName[SpyOps.GFHFromGFI[gfi]]);
END;
NewProcedure: PROCEDURE[module: Procedure, pc: CARDINAL]
RETURNS[procedure: Procedure ← NIL] =
BEGIN
name: ROPE;
entryPC, exitPC: CARDINAL ← pc;
IF module.gfi # 0 THEN [entryPC, exitPC] ← PcRange[module.gfi, pc];
procedure ← NEW[ProcRec ← []];
noProcs ← noProcs + 1;
procedure.gfi ← module.gfi;
procedure.entryPC ← entryPC;
procedure.exitPC ← exitPC;
IF module.gfi = 0 THEN name ← typeName[pc];
IF module.gfi = 0 AND name = NIL THEN {
stream: IO.STREAMIO.ROS[];
stream.Put[rope["type"], card[pc]];
typeName[pc] ← name ← IO.RopeFromROS[stream]};
procedure.name ← Rope.Cat[module.name, Rope.FromChar['.], name];
procedure.named ← name # NIL;
END;
PcRange: PROCEDURE[gfi: PrincOps.GFTIndex, pc: CARDINAL]
RETURNS[entry, exit: CARDINAL] =
BEGIN
procPC, min: CARDINAL ← pc;
gfh: PrincOps.GlobalFrameHandle;
ev: LONG POINTER TO PrincOps.CSegPrefix;
entry ← 0;
exit ← min ← 177777B;
gfh ← SpyOps.GFHFromGFI[gfi];
ev ← LOOPHOLE[gfh.code];
FOR i: CARDINAL IN [0..ev.header.info.ngfi*32) DO
heuristics to see if we are at the end of the entry vector
IF ev.entry[i].initialpc > 77777B THEN EXIT;
IF ev.entry[i].info.framesize > PrincOps.LastAVSlot THEN EXIT;
min ← MIN[min, ev.entry[i].initialpc/SIZE[PrincOps.EntryVectorItem]];
IF i+1 >= min THEN EXIT;
determine the entry and exit PCs.
procPC ← ev.entry[i].initialpc*2;
IF entry < procPC AND procPC <= pc THEN entry ← procPC;
IF pc < procPC AND procPC < exit THEN exit ← procPC;
ENDLOOP;
exit ← exit-1;
END;
-- handling marked stacks --
ProcStack: TYPE = REF ProcStackRec;
ProcStackRec: TYPE = RECORD[
process: ProcessRef ← NIL,
index: CARDINAL ← 0,
frame: ARRAY [0..SpyOps.stackLength) OF RECORD[
proc: Procedure ← NIL,
pc: CARDINAL ← 0]];
AddFrame: PROCEDURE[stack: ProcStack, proc: Procedure, pc: CARDINAL] = INLINE
{stack.frame[stack.index] ← [proc, pc]; stack.index ← stack.index + 1};
Recursive: PROCEDURE[stack: ProcStack] RETURNS[BOOLEAN] =
INLINE BEGIN
IF stack.index = 0 THEN RETURN[FALSE];
FOR i: CARDINAL DECREASING IN [0..stack.index-1) DO
IF stack.frame[i].proc = stack.frame[stack.index-1].proc THEN RETURN[TRUE];
ENDLOOP;
RETURN[FALSE];
END;
Undo: PROCEDURE[stack: ProcStack, count: Count] =
BEGIN
first, proc: Procedure;
IF stack.index = 0 THEN RETURN;
first ← stack.frame[stack.index-1].proc;
FOR i: CARDINAL DECREASING IN [0..stack.index-1) DO
proc ← stack.frame[i].proc;
proc.sons ← RemoveSon[stack.frame[i+1].proc, stack.frame[i+1].pc, proc.sons, count];
proc.calls ← proc.calls - count;
IF proc = first THEN {stack.index ← i + 1; RETURN};
ENDLOOP;
ERROR;
END;
*********************************************
determining the precedence relationships
*********************************************
ClearContainers: PROCEDURE =
BEGIN
FOR m: LIST OF Procedure ← modules, m.rest WHILE m # NIL DO
FOR p: LIST OF Call ← m.first.sons, p.rest WHILE p # NIL DO
p.first.proc.container ← NIL;
ENDLOOP;
ENDLOOP;
END;
SetAllContainers: PROCEDURE =
BEGIN
SetAllParents[];
set the root containers
FOR a: LIST OF ProcessRef ← processes, a.rest WHILE a # NIL DO
FOR s: LIST OF Call ← a.first.sons, s.rest WHILE s # NIL DO
s.first.proc.container ← s.first.proc;
ENDLOOP;
ENDLOOP;
chase down the trees
FOR a: LIST OF ProcessRef ← processes, a.rest WHILE a # NIL DO
FOR p: LIST OF Call ← a.first.sons, p.rest WHILE p # NIL DO
SetContainers[p.first.proc.sons];
ENDLOOP;
ENDLOOP;
catch all of the ones we missed
FOR m: LIST OF Procedure ← modules, m.rest WHILE m # NIL DO
FOR p: LIST OF Call ← m.first.sons, p.rest WHILE p # NIL DO
IF p.first.proc.container # NIL THEN LOOP;
p.first.proc.container ← Container[p.first.proc];
IF p.first.proc.container = NIL THEN p.first.proc.container ← p.first.proc;
ENDLOOP;
ENDLOOP;
END;
SetAllParents: PROC = BEGIN
proc: Procedure;
found: BOOLEAN;
FOR m: LIST OF Procedure ← modules, m.rest WHILE m # NIL DO
FOR p: LIST OF Call ← m.first.sons, p.rest WHILE p # NIL DO
proc ← p.first.proc; -- for each procedure . . .
FOR s: LIST OF Call ← proc.sons, s.rest WHILE s # NIL DO
found ← FALSE;
IF s.first.calls = 0 THEN LOOP;
FOR f: LIST OF Procedure ← s.first.proc.parents, f.rest WHILE f # NIL DO
IF f.first = proc THEN {found ← TRUE; EXIT};
ENDLOOP;
. . . add self to son's parent list
IF ~found THEN s.first.proc.parents ← CONS[proc, s.first.proc.parents];
ENDLOOP;
ENDLOOP;
ENDLOOP;
END;
SetContainers: PROCEDURE[sons: LIST OF Call] =
BEGIN
FOR s: LIST OF Call ← sons, s.rest DO
IF s = NIL THEN EXIT;
IF s.first.proc.container # NIL THEN LOOP;
s.first.proc.container ← Container[s.first.proc];
IF s.first.proc.container = NIL THEN LOOP;
SetContainers[s.first.proc.sons];
ENDLOOP;
END;
Container: PROCEDURE[proc: Procedure]
RETURNS[c: Procedure ← NIL] =
BEGIN
determine the intersection of the procedures that references proc
proc.marked ← TRUE;
FOR f: LIST OF Procedure ← proc.parents, f.rest WHILE f # NIL DO
IF f.first.marked THEN LOOP; -- already traversed it
IF f.first.container = NIL THEN f.first.container ← Container[f.first];
IF f.first.container = NIL THEN LOOP;
IF c = NIL THEN {c ← f.first; LOOP};
c ← Intersection[c, f.first];
IF c = NIL THEN {proc.marked ← FALSE; RETURN[proc]}; -- no container
ENDLOOP;
proc.marked ← FALSE;
END;
Intersection: PROCEDURE[a, b: Procedure] RETURNS[Procedure] =
BEGIN
DO IF a = b THEN RETURN[a];
FOR c: Procedure ← a, c.container DO
IF c.container = b THEN RETURN[b];
IF c.container = c THEN EXIT;
ENDLOOP;
FOR c: Procedure ← b, c.container DO
IF c.container = a THEN RETURN[a];
IF c.container = c THEN EXIT;
ENDLOOP;
IF a = a.container OR b = b.container THEN RETURN[NIL];
a ← a.container;
b ← b.container;
ENDLOOP;
END;
*********************************************
some printing
*********************************************
PrintStatistics: PROCEDURE[stream: IO.STREAM] =
BEGIN
seconds: INTEGER;
IF wakeups = 0 THEN RETURN;
print general statistics
seconds ← MAX[1, RealOps.RoundI[BasicTime.PulsesToSeconds[SpyOps.runningTime]]];
stream.PutF["Spy ran for %g minutes %g seconds.\n",
card[seconds/60], card[seconds MOD 60]];
stream.Put[rope["Total wakeups = "], card[wakeups]];
stream.Put[rope[" ("], card[wakeups/seconds], rope[" per second).\n"]];
IF current # pagefaults THEN {
stream.Put[rope["Total page faults = "], card[SpyOps.pageFaults]];
stream.Put[rope[" ("], card[SpyOps.pageFaults/seconds], rope[" per second).\n"]]};
stream.Put[rope["Total words allocated = "], card[SpyOps.wordsAllocated]];
stream.Put[rope[" ("], card[SpyOps.wordsAllocated/seconds], rope[" per second).\n"]];
stream.Put[rope["Total words reclaimed = "], card[SpyOps.wordsReclaimed]];
stream.Put[rope[" ("], card[SpyOps.wordsReclaimed/seconds], rope[" per second).\n"]];
print how the processor was used
stream.Put[rope["\nScheduled Process-Priority Summary:\n"]];
IF notScheduled # 0 THEN {
stream.Put[rope[" processor idle"]];
PrintCount[stream, notScheduled, 0, wakeups]};
IF skips # 0 THEN {
stream.Put[rope[" processor waiting on disk"]];
PrintCount[stream, skips, 0, wakeups]};
FOR i: Process.Priority IN Process.Priority DO
IF levelData[i] = 0 THEN LOOP;
stream.Put[rope[" priority "], rope[LevelName[i]]];
PrintCount[stream, levelData[i], 0, wakeups];
ENDLOOP;
stream.Put[char[CR]];
print breakdown by types:
IF className # NIL THEN {
header: Rope.ROPE;
headerPrinted: BOOLFALSE;
SELECT current FROM
pagefaults => header ← "Breakdown By Type Of Pagefault:\n";
allocations, wordsAllocated => header ← "Breakdown By Type Of Allocation:\n";
ENDCASE => header ← "Breakdown By Type Of Action:\n";
FOR i: StackType IN StackType DO
IF typeName[i] = NIL OR typeData[i] = 0 THEN LOOP;
IF ~headerPrinted THEN {
stream.Put[rope[header]];
headerPrinted ← TRUE};
IF current IN [process..breakProcess] AND i # 0
THEN stream.Put[rope[" waiting "], rope[typeName[i]]]
ELSE stream.Put[rope[" "], IF typeName[i] # NIL THEN rope[typeName[i]] ELSE int[i]];
PrintCount[stream, typeData[i], 0, wakeups];
ENDLOOP;
stream.Put[char[CR]]};
END;
PrintInstructions: PROCEDURE[stream: IO.STREAM] =
BEGIN
stream.Put[rope["Instructions (see SpyDoc.tioga for more information):"], char[CR]];
stream.Put[char[TAB], rope["Indentation is used to show containment."], char[CR]];
stream.Put[char[TAB], rope["Periods are used to keep track of procedures at the same level of indentation."], char[CR]];
stream.Put[char[TAB], rope["Exclamation points (!) are used to group together sets of disjoint procedures."], char[CR]];
stream.Put[char[TAB], rope["Italics are used to indicate procedures with more than one parent."], char[CR]];
stream.Put[char[TAB], rope["Bold is used to indicate procedures which actually had allocations or page faults."], char[CR]];
stream.Put[char[TAB], rope["Impl.Proc = x, y (o%) (z%):"], char[CR]];
stream.Put[char[TAB], rope[" x = counts in Impl.Proc."], char[CR]];
stream.Put[char[TAB], rope[" y = counts in procedures called from Impl.Proc."], char[CR]];
stream.Put[char[TAB], rope[" o = x/ total % (only displayed if > 1%)."], char[CR]];
stream.Put[char[TAB], rope[" z = (x + y)/ total = % time IN THE CALL STACK."], char[CR]];
stream.Put[char[CR]];
END;
PrintLogStatistics: PROCEDURE[stream: IO.STREAM] =
BEGIN
allocated: Count;
stream.Put[rope["Statistics on execution of Cedar Spy:"], char[CR]];
IF spyTime[0].count > 0 THEN {
stream.Put[
char[TAB], card[spyTime[0].count],
rope[" spy samples averaged "]];
PrintTime[stream, BasicTime.PulsesToMicroseconds[spyTime[0].time]/spyTime[0].count]};
IF spyTime[1].count > 0 THEN {
stream.Put[
char[TAB], card[spyTime[1].count],
rope[" spy samples averaged "]];
PrintTime[stream, BasicTime.PulsesToMicroseconds[spyTime[1].time]/spyTime[1].count]};
IF spyTime[2].count > 0 THEN {
stream.Put[
char[TAB], card[spyTime[2].count],
rope[" spy samples averaged "]];
PrintTime[stream, BasicTime.PulsesToMicroseconds[spyTime[2].time]/spyTime[2].count]};
IF spyTime[3].count > 0 THEN {
stream.Put[
char[TAB], card[spyTime[3].count],
rope[" spy samples averaged "]];
PrintTime[stream, BasicTime.PulsesToMicroseconds[spyTime[3].time]/spyTime[3].count]};
IF readLog IN (0..10000000] THEN {-- to avoid wrap around
stream.Put[
char[TAB], rope["Processed log in "]];
PrintTime[stream, BasicTime.PulsesToMicroseconds[readLog]]};
stream.Put[
rope["\tTotal samples read from log = "], card[processed], rope[".\n"]];
IF overflow > 0 THEN
stream.Put[char[TAB], card[overflow],
rope[" SAMPLES WITH STACKS OF >= 75 FRAMES!\n"]];
IF error > 0 THEN
stream.Put[char[TAB], card[error],
rope[" SAMPLES WERE CUT SHORT BECAUSE OF ERRORS!\n"]];
IF processed > 0 THEN
stream.Put[rope["\tAverage stack depth = "], card[stackDepth/processed], rope[".\n"]];
stream.Put[rope["\tNo. modules allocated = "], card[noModules], rope[".\n"]];
stream.Put[rope["\tNo. procedures allocated = "], card[noProcs], rope[".\n"]];
allocated ← noProcesses*SIZE[ProcessRec] + noCalls*SIZE[Call] +
noModules*SIZE[ProcRec] + noProcs*SIZE[ProcRec];
stream.Put[rope["\tTotal words allocated = "], card[allocated], rope[".\n"]];
stream.Put[char[CR]];
END;
perCentCR: ROPE = Rope.Cat["%).", Rope.FromChar[CR]];
LevelName: PROCEDURE[l: Process.Priority] RETURNS[ROPE] =
INLINE {RETURN[SELECT l FROM
0 => "monitoring", 3 => "foreground",
1 => "background", 4 => "pagefaultLow",
2 => "normal", 5 => "pagefaultHigh",
ENDCASE => "interrupt"]};
PrintCount: PROCEDURE[stream: IO.STREAM, c, sonC: Count, total: Count] =
BEGIN
IF c = 0 AND sonC = 0 THEN {stream.Put[char[CR]]; RETURN};
stream.Put[rope[" = "], card[c]];
IF sonC # 0 THEN stream.Put[rope[", "], card[sonC]];
IF total = 0 THEN {stream.Put[char[CR]]; RETURN};
IF (c*100/total) > 1 AND sonC # 0 THEN PerCent[stream, c, total];
PerCent[stream, c+sonC, total];
stream.Put[char['.], char[CR]];
END;
PerCent: PROCEDURE[stream: IO.STREAM, x, y: Count] =
BEGIN
q, r: Count;
IF y = 0 THEN y ← 1;
q ← (x*1000)/y;
r ← q MOD 10;
q ← q/10;
IF q = 0 AND r = 0 AND x # 0 THEN r ← 1; -- to avoid 0.0%
stream.Put[rope[" ("], card[q], char['.]];
stream.Put[card[r], rope["%)"]];
END;
PrintTime: PROCEDURE[stream: IO.STREAM, ticks: LONG CARDINAL] =
BEGIN
secs,mSecs,uSecs: LONG CARDINAL;
uSecs ← ticks;
secs ← uSecs/1000000;
uSecs ← uSecs - secs*1000000;
mSecs ← uSecs/1000;
uSecs ← uSecs - mSecs*1000;
IF secs # 0 OR mSecs > 10
THEN stream.PutF["%g.%g seconds.", card[secs], card[mSecs]]
ELSE stream.PutF["%g.%g milliseconds.", card[mSecs], card[uSecs]];
END;
*********************************************
debugging facilities
*********************************************
Find: PROCEDURE[name: ROPE] RETURNS[Procedure] =
BEGIN
list: LIST OF Procedure ← modules;
FOR m: LIST OF Procedure ← list, m.rest DO
IF m = NIL THEN EXIT;
IF Rope.Equal[name, m.first.name] THEN RETURN[m.first];
IF list # modules THEN LOOP;
FOR p: LIST OF Call ← m.first.sons, p.rest DO
IF p = NIL THEN EXIT;
IF Rope.Equal[name, p.first.proc.name] THEN RETURN[p.first.proc];
ENDLOOP;
ENDLOOP;
RETURN[NIL];
END;
END.. 
CountStorage: PROC RETURNS[process, mods, procs, sons: INTEGER, total:LONG INTEGER] =
BEGIN
process ← mods ← procs ← sons ← 0;
FOR m: LIST OF Procedure ← modules, m.rest DO
IF m = NIL THEN EXIT;
mods ← mods + 1;
FOR p: LIST OF Call ← m.first.sons, p.rest DO
IF p = NIL THEN EXIT;
sons ← sons + 1;
procs ← procs + 1;
FOR s: LIST OF Call ← p.first.proc.sons, s.rest DO
IF s = NIL THEN EXIT;
sons ← sons + 1;
ENDLOOP;
ENDLOOP;
ENDLOOP;
FOR p: LIST OF ProcessRef ← processes, p.rest DO
IF p = NIL THEN EXIT;
process ← process + 1;
FOR s: LIST OF Call ← p.first.sons, s.rest DO
IF s = NIL THEN EXIT;
sons ← sons + 1;
ENDLOOP;
ENDLOOP;
total ← process*SIZE[ProcessRec] +
(mods + procs)*SIZE[ProcRec] + sons*SIZE[Call];
END;