[Indigo]<Cedar>Spy>SpyLogReaderImpl.mesa!2

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[BOOLEAN ← FALSE] = {

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: BOOLEAN ← FALSE;

triggerExtent: BasicTime.Pulses;

whichTrigger: NAT ← 1;

SetTrigger: PROC[extent: BasicTime.Pulses, which: NAT ← 1, enable: BOOLEAN ← TRUE] = BEGIN

useTrigger ← enable;

triggerExtent ← extent;

whichTrigger ← which;

END;

FindTrigger: PROC RETURNS[trigger: BasicTime.Pulses] = BEGIN

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: BOOLEAN ← FALSE;

spyTime: ARRAY [0..3] OF RECORD[

time: BasicTime.Pulses];

ReadSpyLog: PROCEDURE[ignoreBefore: BasicTime.Pulses, spyOnSpyLog: BOOL] =

BEGIN

i: CARDINAL;

data: BOOLEAN ← FALSE;

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

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;

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

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.STREAM ← IO.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;

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;

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;

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;

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;

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: BOOL ← FALSE;

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;

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;

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;

total ← process*SIZE[ProcessRec] +

(mods + procs)*SIZE[ProcRec] + sons*SIZE[Call];

END;