SpyLogReaderImpl.mesa
Copyright © 1985, 1986 by Xerox Corporation. All rights reserved.
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
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, 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] = {
count: NAT ← 0;
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[
count: Count,
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] = {
name: Rope.ROPE ← GetName[gfh, pc];
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;
ENDLOOP;
RETURN [NIL];
};
adding a stack to the call tree
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;
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];
};
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] = {
name: ROPE;
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;
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;
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;
};
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;
ENDLOOP;
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]]];
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;
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;
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];
};