[Cyan]<CedarChest6.1>Spy>SpyLogReaderImpl.mesa!3

SpyLogReaderImpl.mesa

Maxwell on December 14, 1983 2:25 pm

Russ Atkinson (RRA) April 7, 1986 12:55:53 pm PST

Pier, December 12, 1985 10:51:00 am PST

McCreight, April 11, 1986 2:30:38 pm PST

Mike Spreitzer September 24, 1986 3:39:08 pm PDT

Eric Nickell, November 25, 1986 4:04:34 pm PST

DIRECTORY

AMBridge USING [TVForPointerReferent],

AMTypes USING [TV, TVType, TypeToName],

Convert USING [RopeFromCard],

BasicTime USING [GetClockPulses, Pulses, PulsesToMicroseconds, PulsesToSeconds],

IO USING [ROS, RopeFromROS, Put, PutChar, PutF, PutFR, STREAM],

PrincOps USING [BytePC, CSegPrefix, EntryVectorItem, GFT, GlobalFrameHandle, LastAVSlot, NullPsbHandle, PsbIndex, PsbHandle],

PrincOpsUtils USING [PsbHandleToIndex],

PrintTV USING [Print],

Process USING [Priority],

RealOps USING [RoundLI],

Rope USING [Cat, FromChar, Equal, ROPE],

RTSymbolDefs USING [CallableBodyIndex, SymbolTableBase],

RTSymbolOps USING [AcquireRope, BodyName],

RTSymbols USING [AcquireSTBFromGFH, ReleaseSTB],

RTTypesPrivate USING [GetCBTI, GetEp, GFHToName],

RuntimeError USING [UNCAUGHT],

SpyLog USING [active, Close, Entry, NextEntry, OpenForRead],

SpyOps USING [Call, Count, DataType, freqDivisor, LevelData, pageFaults, Procedure, ProcessRef, ProcessRec, ProcRec, runningTime, Stack, stackHeader, stackLength, StackType, wordsAllocated, wordsReclaimed],

ViewerIO USING [CreateViewerStreams];

SpyLogReaderImpl: PROGRAM

IMPORTS AMBridge, AMTypes, BasicTime, Convert, IO, PrincOpsUtils, PrintTV, RealOps, Rope, RTSymbolOps, RTSymbols, RTTypesPrivate, RuntimeError, SpyLog, SpyOps, ViewerIO

EXPORTS SpyOps = {

OPEN SpyOps;

ROPE: TYPE = Rope.ROPE;

STREAM: TYPE = IO.STREAM;

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 PROC = {

NilLinks: PROC [proc: Procedure] RETURNS [BOOL ← 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 PROC [typescript: STREAM, datatype: SpyOps.DataType, spyOnSpyLog: BOOL] = {

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];

};

*********************************************

reading the section of the log just before a trigger

*********************************************

useTrigger: BOOL ← FALSE;

triggerExtent: BasicTime.Pulses;

whichTrigger: NAT ← 1;

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

useTrigger ← enable;

triggerExtent ← extent;

whichTrigger ← which;

};

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

entry: LONG POINTER TO SpyLog.Entry;

SpyLog.OpenForRead[]; -- open for reading

WHILE TRUE DO

entry ← SpyLog.NextEntry[];

IF entry = NIL THEN EXIT;

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];

};

*********************************************

building a call tree from the trace log

*********************************************

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

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

time: BasicTime.Pulses];

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

i: CARDINAL;

data: BOOL ← FALSE;

dataSize: CARDINAL ← 0;

first, last: BasicTime.Pulses ← 0;

active: BOOL ← 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[];

IF entry = NIL THEN EXIT;

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", [character['f]]]};

IF e.process # process THEN {

out.PutF[" Switch to process: %b\n", [cardinal[PrincOpsUtils.PsbHandleToIndex[e.process]]]];

process ← e.process};

PrintTrace[e.gfh, 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;

};

PrintEntry: PROC [type, words: CARDINAL, data: LONG POINTER, time, delta: BasicTime.Pulses] = {

value: AMTypes.TV;

IF out = NIL THEN {

out ← ViewerIO.CreateViewerStreams["auxilary spy log"].out;

out.PutF["%l uSeconds delta data\n", [character['f]]]};

value ← AMBridge.TVForPointerReferent[data, LOOPHOLE[type]];

out.PutF["%9d%9d %g: \n",

[cardinal[BasicTime.PulsesToMicroseconds[time]]],

[cardinal[BasicTime.PulsesToMicroseconds[delta]]],

[rope[AMTypes.TypeToName[AMTypes.TVType[value]]]]];

PrintTV.Print[value, out];

out.PutChar['\n];

};

PrintTrace: PROC [gfh: PrincOps.GlobalFrameHandle, pc: PrincOps.BytePC, time, delta: BasicTime.Pulses] = {

out.PutF["%9d%9d %g (gfh: %g, pc: %g)\n",

[cardinal[BasicTime.PulsesToMicroseconds[time]]],

[cardinal[BasicTime.PulsesToMicroseconds[delta]]],

[rope[name]], [cardinal[LOOPHOLE[gfh, CARDINAL]]], [cardinal[pc]]];

};

GetName: PROC [gfh: PrincOps.GlobalFrameHandle, pc: PrincOps.BytePC] RETURNS [name: Rope.ROPE ← NIL] = {

proc: Rope.ROPE;

stb: RTSymbolDefs.SymbolTableBase ← [x[e: NIL]];

name ← RTTypesPrivate.GFHToName[gfh ! RuntimeError.UNCAUGHT => GO TO badNews];

{

ENABLE {

RuntimeError.UNCAUGHT => {

IF stb # [x[e: NIL]] THEN {RTSymbols.ReleaseSTB[stb]; stb ← [x[e: NIL]]};

CONTINUE};

UNWIND => {

IF stb # [x[e: NIL]] THEN {RTSymbols.ReleaseSTB[stb]; stb ← [x[e: NIL]]};

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];

};

name ← Rope.Cat[name, ".", proc];

EXITS badNews =>

name ← IO.PutFR["%bB.%bB", [cardinal[LOOPHOLE[gfh, CARDINAL]]], [cardinal[pc]] ];

};

tree management

Initialize: PROC = {

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;

};

EnumerateProcs: PROC [userProc: PROC [Procedure] RETURNS [BOOL]] RETURNS [last: Procedure] = {

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];

};

adding a stack to the call tree

stack: ProcStack;

EnterStack: PROC [s: LONG POINTER TO SpyOps.Stack, n: CARDINAL] = {

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].gfh, s.frame[n].pc, s.count];

IF proc = NIL THEN {stack ← NIL; RETURN};

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].gfh, s.frame[n].pc, s.count];

proc ← newSon;

IF proc = NIL THEN EXIT;

AddFrame[stack, proc, s.frame[n+1].pc];

IF Recursive[stack] THEN Undo[stack, s.count];

ENDLOOP;

IF proc # NIL THEN {

add in the leaf counts

proc.count ← proc.count + s.count;

proc.countLocs ← AddCountLocs[list: proc.countLocs, pc: s.frame[0].pc, 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, NIL, s.type, s.count];

IF newSon # NIL THEN newSon.count ← newSon.count + s.count;

};

typeData[s.type] ← typeData[s.type] + s.count;

stack.index ← 0;

};

adding to the list of processes --

AddProcess: PROC [psb: PrincOps.PsbIndex] RETURNS [process: ProcessRef ← NIL] = {

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;

};

NewProcess: PROC [psb: PrincOps.PsbIndex] RETURNS [process: ProcessRef] = {

process ← NEW[ProcessRec ← []];

noProcesses ← noProcesses + 1;

process.psb ← psb;

};

adding/deleting procedures from a LIST OF Call --

AddSon: PROC [list: LIST OF Call, from: CARDINAL, gfh: PrincOps.GlobalFrameHandle, pc, count: Count] RETURNS [newList: LIST OF Call, procedure: Procedure] = {

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[gfh, pc];

IF procedure = NIL THEN RETURN [NIL, NIL];

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[gfh, 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[gfh, pc];

IF procedure = NIL THEN RETURN [NIL, NIL];

list.rest ← CONS[[from, count, procedure], list.rest];

noCalls ← noCalls + 1;

RETURN [newList, procedure]};

list ← list.rest;

ENDLOOP;

ERROR;

};

RemoveSon: PROC [proc: Procedure, pc: CARDINAL, list: LIST OF Call, count: Count] RETURNS [newList: LIST OF Call] = {

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;

};

GreaterThan: PROC [gfh: PrincOps.GlobalFrameHandle, pc: CARDINAL, proc: Procedure] RETURNS [BOOL] = INLINE {

IF gfh # proc.gfh THEN

RETURN [LOOPHOLE[gfh, CARDINAL] > LOOPHOLE[proc.gfh, CARDINAL]];

RETURN [pc > proc.exitPC];

};

Equal: PROC [gfh: PrincOps.GlobalFrameHandle, pc: INT, proc: Procedure] RETURNS [BOOL] = INLINE {

entryPC, exitPC: INT;

IF proc = NIL THEN RETURN [TRUE]; -- source

IF gfh # proc.gfh THEN RETURN [FALSE];

IF pc < (entryPC ← proc.entryPC) THEN RETURN [FALSE];

IF pc > (exitPC ← proc.exitPC) THEN RETURN [FALSE];

RETURN [TRUE];

};

AddCountLocs: PROC [list: LIST OF Call, pc: CARDINAL, count: Count] RETURNS [new: LIST OF Call] ~ {

Insert: PROC [list: LIST OF Call] ~ {

SELECT TRUE FROM

list.rest=NIL OR pc<list.rest.first.pc => list.rest ← CONS[call, list.rest];

pc=list.rest.first.pc => list.rest.first.calls ← list.rest.first.calls+count;

ENDCASE => Insert[list.rest];

};

call: Call ~ [pc: pc, calls: count];

IF list=NIL OR pc<list.first.pc THEN RETURN [CONS[call, list]];

Insert[new ← list];

};

adding modules and procedures to the modules list

AddProcedure: PROC [gfh: PrincOps.GlobalFrameHandle, pc: CARDINAL] RETURNS [procedure: Procedure ← NIL] = {

INVARIANT: the lists remain sorted

INVARIANT: exactly one ref will be incremented

module: Procedure;

list: LIST OF Call;

module ← AddModule[gfh];

IF module = NIL THEN RETURN;

list ← module.sons;

should we add it to the beginning of the list?

IF list = NIL OR GreaterThan[gfh, 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[gfh, pc, procedure] THEN {

procedure.refs ← procedure.refs + 1;

RETURN [procedure]};

should the procedure follow this one?

IF list.rest = NIL OR GreaterThan[gfh, 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;

};

AddModule: PROC [gfh: PrincOps.GlobalFrameHandle] RETURNS [module: Procedure ← NIL] = {

INVARIANT: the lists remain sorted

list: LIST OF Procedure ← modules;

ValidateGFH[gfh ! RuntimeError.UNCAUGHT => GO TO badGuy];

should we add it to the beginning of the list?

IF list = NIL OR LOOPHOLE[gfh, CARDINAL] > LOOPHOLE[list.first.gfh, CARDINAL] THEN {

module ← NewModule[gfh];

modules ← CONS[module, list];

RETURN [module]};

WHILE list # NIL DO

module ← list.first;

is this the module we want?

IF gfh = module.gfh THEN RETURN [module];

should the module follow this one?

IF list.rest = NIL OR LOOPHOLE[gfh, CARDINAL] > LOOPHOLE[list.rest.first.gfh, CARDINAL] THEN {

module ← NewModule[gfh];

list.rest ← CONS[module, list.rest];

RETURN [module]};

list ← list.rest;

ENDLOOP;

ERROR;

EXITS badGuy => RETURN [NIL];

};

ValidateGFH: PROC [gfh: PrincOps.GlobalFrameHandle] = {

IF gfh # PrincOps.GFT[gfh.gfi].framePtr THEN ERROR;

};

NewModule: PROC [gfh: PrincOps.GlobalFrameHandle] RETURNS [module: Procedure] = {

module ← NEW[ProcRec ← []];

noModules ← noModules + 1;

module.gfh ← gfh;

module.name ← (IF gfh = NIL THEN className ELSE RTTypesPrivate.GFHToName[gfh]);

};

NewProcedure: PROC [module: Procedure, pc: CARDINAL] RETURNS [procedure: Procedure ← NIL] = {

entryPC, exitPC: CARDINAL ← pc;

IF module.gfh # NIL THEN [entryPC, exitPC] ← PcRange[module.gfh, pc];

procedure ← NEW[ProcRec ← []];

noProcs ← noProcs + 1;

procedure.gfh ← module.gfh;

procedure.entryPC ← entryPC;

procedure.exitPC ← exitPC;

IF module.gfh = NIL THEN name ← typeName[pc];

IF module.gfh = NIL AND name = NIL THEN {

stream: STREAM ← IO.ROS[];

stream.Put[[rope["type"]], [cardinal[pc]]];

typeName[pc] ← name ← IO.RopeFromROS[stream]};

procedure.name ← Rope.Cat[module.name, Rope.FromChar['.], name];

procedure.named ← name # NIL;

};

PcRange: PROC [gfh: PrincOps.GlobalFrameHandle, pc: CARDINAL] RETURNS [entry, exit: CARDINAL] = {

procPC, min: CARDINAL ← pc;

ev: LONG POINTER TO PrincOps.CSegPrefix;

entry ← 0;

exit ← min ← 177777B;

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;

};

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: PROC [stack: ProcStack, proc: Procedure, pc: CARDINAL] = INLINE {

stack.frame[stack.index] ← [proc, pc];

stack.index ← stack.index + 1};

Recursive: PROC [stack: ProcStack] RETURNS [BOOL] = INLINE {

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];

};

Undo: PROC [stack: ProcStack, count: Count] = {

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;

};

*********************************************

determining the precedence relationships

*********************************************

ClearContainers: PROC = {

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;

};

SetAllContainers: PROC = {

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;

};

SetAllParents: PROC = {

proc: Procedure;

found: BOOL;

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;

};

SetContainers: PROC [sons: LIST OF Call] = {

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;

};

Container: PROC [proc: Procedure] RETURNS [c: Procedure ← NIL] = {

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;

};

Intersection: PROC [a, b: Procedure] RETURNS [Procedure] = {

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;

};

*********************************************

some printing

*********************************************

PrintStatistics: PROC [stream: STREAM] = {

seconds: INTEGER;

IF wakeups = 0 THEN RETURN;

print general statistics

seconds ← MAX[RealOps.RoundLI[BasicTime.PulsesToSeconds[SpyOps.runningTime]], 1];

stream.PutF["Spy ran for %g minutes %g seconds.\n",

[cardinal[seconds/60]], [cardinal[seconds MOD 60]]];

SELECT current FROM

CPU, process, breakProcess, allocations, wordsAllocated => stream.PutF["Sampling frequency divisor was %g.\n", [integer[freqDivisor]]];

pagefaults, userDefined => NULL;

ENDCASE => ERROR;

stream.Put[[rope["Total wakeups = "]], [cardinal[wakeups]]];

stream.Put[[rope[" ("]], [cardinal[wakeups/seconds]], [rope[" per second).\n"]]];

IF current # pagefaults THEN {

stream.Put[[rope["Total page faults = "]], [cardinal[SpyOps.pageFaults]]];

stream.Put[[rope[" ("]], [cardinal[SpyOps.pageFaults/seconds]], [rope[" per second).\n"]]]};

stream.Put[[rope["Total words allocated = "]], [cardinal[SpyOps.wordsAllocated]]];

stream.Put[[rope[" ("]], [cardinal[SpyOps.wordsAllocated/seconds]], [rope[" per second).\n"]]];

stream.Put[[rope["Total words reclaimed = "]], [cardinal[SpyOps.wordsReclaimed]]];

stream.Put[[rope[" ("]], [cardinal[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[[character['\n]]];

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 [integer[i]]];

PrintCount[stream, typeData[i], 0, wakeups];

ENDLOOP;

stream.Put[[character['\n]]]};

};

PrintInstructions: PROC [stream: STREAM] = {

stream.Put[[rope["Instructions (see SpyDoc.tioga for more information):"]], [character['\n]]];

stream.Put[[character['\t]], [rope["Indentation is used to show containment."]], [character['\n]]];

stream.Put[[character['\t]], [rope["Periods are used to keep track of procedures at the same level of indentation."]], [character['\n]]];

stream.Put[[character['\t]], [rope["Exclamation points (!) are used to group together sets of disjoint procedures."]], [character['\n]]];

stream.Put[[character['\t]], [rope["Italics are used to indicate procedures with more than one parent."]], [character['\n]]];

stream.Put[[character['\t]], [rope["Bold is used to indicate procedures which actually had allocations or page faults."]], [character['\n]]];

stream.Put[[character['\t]], [rope["Impl.Proc = x, y (o%) (z%):"]], [character['\n]]];

stream.Put[[character['\t]], [rope[" x = counts in Impl.Proc."]], [character['\n]]];

stream.Put[[character['\t]], [rope[" y = counts in procedures called from Impl.Proc."]], [character['\n]]];

stream.Put[[character['\t]], [rope[" o = x/ total % (only displayed if > 1%)."]], [character['\n]]];

stream.Put[[character['\t]], [rope[" z = (x + y)/ total = % time IN THE CALL STACK."]], [character['\n]]];

stream.Put[[character['\n]]];

};

PrintLogStatistics: PROC [stream: STREAM] = {

allocated: Count;

stream.Put[[rope["Statistics on execution of Cedar Spy:"]], [character['\n]]];

IF spyTime[0].count > 0 THEN {

stream.Put[

[character['\t]], [cardinal[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[

[character['\t]], [cardinal[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[

[character['\t]], [cardinal[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[

[character['\t]], [cardinal[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[

[character['\t]], [rope["Processed log in "]]];

PrintTime[stream, BasicTime.PulsesToMicroseconds[readLog]]};

stream.Put[

[rope["\tTotal samples read from log = "]], [cardinal[processed]], [rope[".\n"]]];

IF overflow > 0 THEN {

stream.Put[[character['\t]], [cardinal[overflow]],

[rope[" SAMPLES WITH STACKS OF >= "]] ];

stream.Put[ [rope[Convert.RopeFromCard[from: SpyOps.stackLength, showRadix: FALSE]]], [rope[" FRAMES!\n"]] ];

};

IF error > 0 THEN

stream.Put[[character['\t]], [cardinal[error]],

[rope[" SAMPLES WERE CUT SHORT BECAUSE OF ERRORS!\n"]]];

IF processed > 0 THEN

stream.Put[[rope["\tAverage stack depth = "]], [cardinal[stackDepth/processed]], [rope[".\n"]]];

stream.Put[[rope["\tNo. modules allocated = "]], [cardinal[noModules]], [rope[".\n"]]];

stream.Put[[rope["\tNo. procedures allocated = "]], [cardinal[noProcs]], [rope[".\n"]]];

allocated ← noProcesses*SIZE[ProcessRec] + noCalls*SIZE[Call] +

noModules*SIZE[ProcRec] + noProcs*SIZE[ProcRec];

stream.Put[[rope["\tTotal words allocated = "]], [cardinal[allocated]], [rope[".\n"]]];

stream.Put[[character['\n]]];

};

LevelName: PROC [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: PUBLIC PROC [stream: STREAM, c, sonC: Count, total: Count] = {

IF c = 0 AND sonC = 0 THEN {stream.Put[[character['\n]]]; RETURN};

stream.Put[[rope[" = "]], [cardinal[c]]];

IF sonC # 0 THEN stream.Put[[rope[", "]], [cardinal[sonC]]];

IF total = 0 THEN {stream.Put[[character['\n]]]; RETURN};

IF (c*100/total) > 1 AND sonC # 0 THEN PerCent[stream, c, total];

PerCent[stream, c+sonC, total];

stream.Put[[character['.]], [character['\n]]];

};

PerCent: PUBLIC PROC [stream: STREAM, x, y: Count] = {

q, r: Count;

sign: INT ← 1;

IF y = 0 THEN y ← 1;

q ← RealOps.RoundLI[(REAL[x]*1000.0)/REAL[y]];

IF q < 0 THEN {sign ← -1; q ← -q};

r ← IF q = 0 AND x # 0 THEN 1 ELSE (q MOD 10); -- to avoid 0.0%

q ← (q/10);

stream.Put[[rope[" ("]], [integer[sign*q]], [character['.]]];

stream.Put[[cardinal[r]], [rope["%)"]]];

};

PrintTime: PROC [stream: STREAM, ticks: LONG CARDINAL] = {

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.", [cardinal[secs]], [cardinal[mSecs]]]

ELSE stream.PutF["%g.%g milliseconds.", [cardinal[mSecs]], [cardinal[uSecs]]];

};

*********************************************

debugging facilities

*********************************************

Find: PROC [name: ROPE] RETURNS [Procedure] = {

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];

};

}..

CountStorage: PROC RETURNS [process, mods, procs, sons: INTEGER, total:LONG INTEGER] = {

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];

};