DIRECTORY
BasicTime USING [GetClockPulses, GMT, Now, Pulses, PulsesToMicroseconds],
IO USING [card, int, PutChar, PutF, PutRope, rope, STREAM, time],
LupineExerciser USING [Counter, String],
LupineExerciserPrivate USING [
CallSpy, CheckAbort, ExerciseHandle, PrecisionTime,
RingBufferIndex, SortBuffer, SortBufferIndex, SystemTime ],
PrincOps USING [zMISC],
Process USING [Yield],
UnsafeStorage USING [GetSystemUZone];


LupineExerciserTimerImpl: PROGRAM
IMPORTS
BasicTime, IO, LupineExerciserPrivate, Process, UnsafeStorage
EXPORTS LupineExerciser, LupineExerciserPrivate
= BEGIN OPEN LupineExerciser;



SystemTime: TYPE = LupineExerciserPrivate.SystemTime;
PrecisionTime: TYPE = LupineExerciserPrivate.PrecisionTime;
RingBufferIndex: TYPE = LupineExerciserPrivate.RingBufferIndex;



Handle: PUBLIC TYPE = LupineExerciserPrivate.ExerciseHandle;

heap: UNCOUNTED ZONE = UnsafeStorage.GetSystemUZone[];


Start: PUBLIC PROC [self: Handle, name: String] =
BEGIN OPEN tp: self.tp;
LupineExerciserPrivate.CheckAbort[self];
self.outLogStream.PutF["\n\nTiming %g trials of %g", IO.int[tp.trialsPerPass], IO.rope[name]];
TimeStamp[self, " at "];
PreparePrecisionTimings[self];
IF tp.spying THEN LupineExerciserPrivate.CallSpy[self, startSpying];
StartTimer[self: self, reset: TRUE];
END;

Stamp: PUBLIC PROC [self: Handle] = 
BEGIN
StopTimer[self];
self.outLogStream.PutF["Doing %g ", IO.int[self.tp.testsPerTrial]];
TimeStamp[self, " calls at "];
StartTimer[self];
END;

Delay: PUBLIC PROC [self: Handle] =
BEGIN
StopTimer[self];
LupineExerciserPrivate.CheckAbort[self];
DoDelay[self, 600];
StartTimer[self];
END;

Stop: PUBLIC PROC [self: Handle] =
BEGIN OPEN tp: self.tp;
ms, tenths: LONG INTEGER;
StopTimer[self];
IF tp.spying THEN LupineExerciserPrivate.CallSpy[self, stopSpying];
LupineExerciserPrivate.CheckAbort[self];
IF tp.trialsPerPass = 0 OR tp.testsPerTrial = 0
THEN ms _ tenths _ 0
ELSE [ms, tenths] _ ConvertTimer[
ReadTimer[self].elapsed /
(tp.trialsPerPass*LONG[tp.testsPerTrial]) ];
self.outLogStream.PutF["The mean call time (overhead included) was %g.%g", IO.int[ms], IO.int[tenths]];
TimeStamp[self, " ms at "];
PrintPrecisionTimings[self];
IF tp.spying AND tp.showSpyData=afterEachTest
THEN LupineExerciserPrivate.CallSpy[self, displayStats];
END;

TimeStamp: PROC [self: Handle, herald: String] =
BEGIN
time: BasicTime.GMT _ BasicTime.Now[];
LupineExerciserPrivate.CheckAbort[self];
self.outLogStream.PutF["%g%g.\n", IO.rope[herald], IO.time[time]];
END;



Microseconds: TYPE = LONG CARDINAL;

ReadPilotClock: PROC RETURNS [SystemTime] =
INLINE {RETURN[ LOOPHOLE[BasicTime.GetClockPulses[]] ]};

PilotPrecisionRead: PROC RETURNS [--SystemTime-- PrecisionTime] =
INLINE { RETURN[ ReadPilotClock[] ] };

PilotPrecisionConvert: PROC [pt: --SystemTime-- PrecisionTime]
RETURNS [--microseconds:-- Microseconds] =
INLINE {RETURN[ SystemTimeToUsec[pt] ]};



StartTimer: PROC [self: Handle, reset: BOOLEAN_FALSE] = 
INLINE BEGIN OPEN time: self.timer;
IF reset THEN time.elapsed _ 0;
time.start _ ReadPilotClock[];
END;

StopTimer: PROC [self: Handle] =
INLINE BEGIN OPEN time: self.timer;
time.event _ ReadPilotClock[] - time.start;
time.elapsed _ time.elapsed + time.event;
END;

ReadTimer: PROC [self: Handle] RETURNS [event, elapsed: SystemTime] =
INLINE BEGIN OPEN time: self.timer;
RETURN[time.event, time.elapsed]
END;

ConvertTimer: PROC [time: SystemTime] RETURNS [ms,tenthsOfMs: LONG INTEGER] =
INLINE BEGIN
time _ (SystemTimeToUsec[time]+50)/100;
ms _ time/10;
tenthsOfMs _ time MOD 10;
END;

SystemTimeToUsec: PROC [time: SystemTime] RETURNS [Microseconds] =
INLINE BEGIN
RETURN[ BasicTime.PulsesToMicroseconds[BasicTime.Pulses[time]] ]
END;


DoDelay: PROC [self: Handle, interval: --Microseconds-- LONG INTEGER] =
BEGIN
LastIntegerTime: SystemTime = LAST[LONG INTEGER];
DO
grossWait: SystemTime =
SystemTimeToUsec[ReadPilotClock[]-self.timer.lastDelayFinished];
waitTime: LONG INTEGER =
IF grossWait < LastIntegerTime THEN grossWait ELSE LastIntegerTime;
SELECT interval-waitTime FROM
< 0   => EXIT;
< 50 => Process.Yield;  --NULL;
ENDCASE => Process.Yield;
ENDLOOP;
self.timer.lastDelayFinished _ ReadPilotClock[];
END;




StartPrecisionTiming: PUBLIC PROC [self: Handle] =
--INLINE-- BEGIN OPEN timer: self.precisionTimer;
timer.start _ PrecisionRead[self];
END;

StopPrecisionTiming: PUBLIC PROC [self: Handle] =
--INLINE-- BEGIN OPEN timer: self.precisionTimer;
stopTime: PrecisionTime = PrecisionRead[self];
timer.ringBuffer[
(timer.ringIndex _ (timer.ringIndex+1) MOD LENGTH[timer.ringBuffer]) ] 
_ (stopTime - timer.start);
END;

PrecisionRead: PROC [self: Handle] RETURNS [--pt:-- PrecisionTime] =
INLINE BEGIN
RETURN[IF self.tp.useDoradoClock
THEN DoradoPrecisionRead[self] ELSE PilotPrecisionRead[] ];
END;

PrecisionConvert: PROC [self: Handle, pt: PrecisionTime]
RETURNS [--microseconds:-- Microseconds] =
INLINE BEGIN
RETURN[IF self.tp.useDoradoClock
THEN DoradoPrecisionConvert[pt] ELSE PilotPrecisionConvert[pt] ];
END;



InitPrecisionTimings: PUBLIC PROCEDURE [self: Handle] =
BEGIN OPEN timer: self.precisionTimer;
timer.sortBuffer _ heap.NEW[
LupineExerciserPrivate.SortBuffer[self.tp.testsPerTrial+2] ];
timer.ringBuffer _ DESCRIPTOR [ 
@timer.sortBuffer[FIRST[LupineExerciserPrivate.SortBufferIndex]+1],
LENGTH[DESCRIPTOR[timer.sortBuffer^]]-2 ];
END;

FinishPrecisionTimings: PUBLIC PROCEDURE [self: Handle] =
BEGIN OPEN timer: self.precisionTimer;
heap.FREE[@timer.sortBuffer];
timer.sortBuffer _ NIL;
timer.ringBuffer _ NIL;
END;

PreparePrecisionTimings: PROC [self: Handle] =
INLINE BEGIN OPEN timer: self.precisionTimer;
IF BASE[timer.ringBuffer] = NIL THEN ERROR;
timer.ringIndex _ PRED[LENGTH[timer.ringBuffer]];
IF self.tp.useDoradoClock THEN StartDoradoCounters[EmuCycles];
END;

PrintPrecisionTimings: PROC [self: Handle] =
BEGIN OPEN timer: self.precisionTimer;
ringBufferLength: CARDINAL _ LENGTH[timer.ringBuffer];
Range: INTEGER = MIN[10, ringBufferLength];
PrintRange: PROC [herald: String, startIndex: RingBufferIndex] =
BEGIN
self.outLogStream.PutRope[herald];
FOR i: RingBufferIndex IN [startIndex..startIndex+Range) DO
IF timer.ringBuffer[i] > 99999
THEN self.outLogStream.PutRope[" **********"]
ELSE self.outLogStream.PutF["%6g", IO.card[timer.ringBuffer[i]]];
ENDLOOP;
self.outLogStream.PutChar['\n];
END;  -- PrintRange.
FOR i: RingBufferIndex IN [FIRST[RingBufferIndex]..ringBufferLength) DO
timer.ringBuffer[i] _ PrecisionConvert[self, timer.ringBuffer[i]];
ENDLOOP;
QuickSort[DESCRIPTOR[timer.sortBuffer^]];
self.outLogStream.PutF["Some instantaneous call times (microseconds) from a %g element ring buffer:\n", IO.int[ringBufferLength]];
PrintRange["  Fastest times:", FIRST[RingBufferIndex]];
PrintRange["  Median times: ",
FIRST[RingBufferIndex] + (ringBufferLength-Range)/2 ];
PrintRange["  Slowest times:",
FIRST[RingBufferIndex]+ringBufferLength-Range];
END;



doradoCounters: CounterVector _ ZeroCounterVector;

DoradoPrecisionRead: PROC [self: Handle] RETURNS [PrecisionTime] =
INLINE BEGIN
ReadDoradoCounters[@doradoCounters];
RETURN[IF self.tp.countOnlyEmulatorCycles
THEN doradoCounters.A.low ELSE doradoCounters.B.low ];
END;

DoradoPrecisionConvert: PROC [pt: PrecisionTime]
RETURNS [--microseconds:-- Microseconds] =
INLINE BEGIN
RETURN[
(LONG[161]*(pt/LONG[2500]))
+ ( LONG[161]*(pt MOD LONG[2500])+LONG[2500/2] )/LONG[2500] ];
END;

StartDoradoCounters: PROCEDURE [CounterDescriptor] =
MACHINE CODE BEGIN PrincOps.zMISC, 240B END;

ReadDoradoCounters: PROCEDURE [CounterVectorPtr] =
MACHINE CODE BEGIN PrincOps.zMISC, 241B END;

StopDoradoCounters: PROCEDURE =
MACHINE CODE BEGIN PrincOps.zMISC, 242B END;

CounterVector: TYPE = MACHINE DEPENDENT RECORD [
A(0): MACHINE DEPENDENT RECORD [low(0): LONG CARDINAL, high(2): CARDINAL],
B(3): MACHINE DEPENDENT RECORD [low(0): LONG CARDINAL, high(2): CARDINAL] ];

ZeroCounterVector: CounterVector = [[0,0],[0,0]];

CounterVectorPtr: TYPE = LONG POINTER TO CounterVector;

ASelection: TYPE = MACHINE DEPENDENT {
true, hold, procRef, ifuJump, miss, bpa, bpc, bpe };

BSelection: TYPE = MACHINE DEPENDENT {
true, hold, ifuRef, ifuNrdy, miss, bpb, bpc, bpd };

allA, allB, doA, doB: BOOLEAN = TRUE;
emuOnlyA, emuOnlyB, notIS: BOOLEAN = FALSE;

CounterDescriptor: TYPE = MACHINE DEPENDENT RECORD  [
instrSet: BOOLEAN,
ignoreBits123: [0..7],
enableA, enableB: BOOLEAN,
ignoreBits67: [0..3],
aSelects: ASelection,
allTasksA: BOOLEAN,
bSelects: BSelection,
allTasksB: BOOLEAN  ];

EmuCycles: CounterDescriptor = [notIS,0,doA,doB,0,true,emuOnlyA,true,allB];



QuickSort: PROC [table: LONG DESCRIPTOR FOR ARRAY OF PrecisionTime] =
BEGIN
first: INTEGER = 0;
last: INTEGER = LENGTH[table]-1;
M: INTEGER = 9;
PP, L, R, I, J: INTEGER;
V, TK: PrecisionTime;
STACK: ARRAY [0..20) OF INTEGER;

table[first] _ FIRST[PrecisionTime];  table[last] _ LAST[PrecisionTime];
PP _ 0; L _ first+1; R _ last-1;

WHILE PP >=0 DO
I _ L; J _ R+1; V _ table[L];
WHILE I < J DO
I_I+1; WHILE table[I]<V DO I _ I+1 ENDLOOP;
J_J-1; WHILE table[J]>V DO J _ J-1 ENDLOOP;
TK_table[J]; table[J]_table[I]; table[I]_TK;
ENDLOOP;
table[I]_table[J]; table[J]_table[L]; table[L]_TK;
SELECT TRUE FROM
R-J > J-L =>
SELECT TRUE FROM
R-J <= M => NULL;
J-L <= M => {L_J+1; LOOP};
ENDCASE => BEGIN
PP_PP+2; STACK[PP]_J+1; STACK[PP+1]_R; R_J-1;
LOOP;
END;
J-L <= M => NULL;
R-J <= M => {R_J-1; LOOP};
ENDCASE => BEGIN
PP _ PP+2; STACK[PP]_L; STACK[PP+1]_J-1; L_J+1;
LOOP;
END;
L_STACK[PP];
R_STACK[PP+1];
PP_PP-2;
REPEAT
FINISHED =>
FOR I IN [2..last) DO
V_table[I]; J_I-1;
WHILE table[J]>V DO table[J+1]_table[J]; J_J-1 ENDLOOP;
table[J+1]_V;
ENDLOOP;
ENDLOOP;
END;





END.  -- LupineExerciserTimerImpl.

ŒLupineExerciserTimerImpl.mesa.
Copyright c 1985 by Xerox Corporation.  All rights reserved.
Last edited by BZM on 14-Mar-82 13:24:24.
Last edited by Bob Hagmann February 8, 1985 5:09:04 pm PST
Private types.
Exerciser instance data.
Primary time logging routines that use Pilot's timer.
Pilot Timing Routines.
Spin at least "interval" between executions.  There is a startup glitch.
Individual call high precision timing routines.
Precision timing routines.
FOR i: RingBufferIndex IN [0..LENGTH[timer.ringBuffer]) DO
timer.ringBuffer[i] _ 0 ENDLOOP;
IF LENGTH[timer.ringBuffer] > 0 THEN BEGIN
timer.ringBuffer[0] _ 0;
Inline.LongCopy[
from: @timer.ringBuffer[0],
to: @timer.ringBuffer[1],
nwords: LENGTH[timer.ringBuffer]*SIZE[PrecisionTime];
END;
Dorado 64ns precision counter routines.
Modified from [Ivy]<McDaniel>Measurements>Measure.mesa.
Measured clock time was 2*32.2 ns => 644/10000 = 161/2500 usec/cycle
Compute slowly to avoid overflow and do rounding.
This Quicksort routine is from Sedgewick's thesis.
It is a transliteration of [Maxc2]<Guibas>STSRT.SAI.
Originally: STACK: ARRAY [0:2*(LOG(256/(M+2)) DIV 1)+1] OF INTEGER;
Module Initialization.
Κ˜
head™Icodešœ
Οm
œ1™<J™)J™:—J˜J˜š
Οk	˜	Jšœ
žœ:˜IJšžœ
žœ)žœ˜AJšœžœ˜(šœžœ˜J˜3J˜;—Jšœ	žœ	˜Jšœžœ	˜Jš
œ%˜%J˜J˜—šœž˜!š
ž˜Jš
œ=˜=—Jšžœ(˜/Jšœžœ
žœ˜J˜J˜—Jš
œ™˜Jšœžœ%˜5Jšœžœ(˜;Jšœžœ*˜?J˜J˜—Jš
œ™˜Jšœžœ
žœ)˜<J˜Jšœžœ"˜6—J˜
Jš
œ5™5˜šΟnœžœ
žœ˜1Jšžœ
žœ
˜Jš
œ(˜(Jš
œ^˜^J˜J˜Jšžœžœ3˜DJšœžœ˜$Jšžœ
˜J˜—šŸœžœ
žœ˜$Jš
ž˜J˜Jš
œC˜CJ˜J˜Jšžœ
˜J˜—šŸœžœ
žœ˜#Jš
ž˜J˜Jš
œ(˜(J˜J˜Jšžœ
˜J˜—šŸœžœ
žœ˜"Jšžœ
žœ
˜Jšœžœ
žœ
˜J˜Jšžœžœ2˜CJš
œ(˜(šžœžœ˜/Jšžœ˜šžœ˜!J˜Jšœžœ˜,——Jš
œg˜gJ˜J˜šžœžœ˜-Jšžœ4˜8—Jšžœ
˜J˜—šŸ	œžœ!˜0Jš
ž˜J˜&Jš
œ(˜(Jš
œB˜BJšžœ
˜J˜——J˜
Jš
œ™˜Jšœžœžœ
žœ
˜#J˜šŸœžœ
žœ˜+Jšžœžœžœ ˜8J˜—šŸœžœ
žœΟcœ˜AJšžœžœ˜&J˜—šŸœžœ œ˜>Jšžœ œ˜*Jšžœžœ˜(J˜J˜J˜—šŸ
œžœžœ
žœ˜8Jšžœ
žœ
žœ˜#Jšžœžœ˜J˜Jšžœ
˜J˜—šŸ	œžœ˜ Jšžœ
žœ
žœ˜#J˜+J˜)Jšžœ
˜J˜—šŸ	œžœžœ˜EJšžœ
žœ
žœ˜#Jšžœ˜ Jšžœ
˜J˜—š
Ÿœžœžœžœ
žœ˜MJšžœ
ž˜J˜'J˜
Jšœžœ˜Jšžœ
˜J˜—šŸœžœžœ˜BJšžœ
ž˜Jšžœ:˜@Jšžœ
˜J˜J˜—š
Ÿœžœ œ
žœ
žœ˜GJš
œH™HJš
ž˜Jšœžœ
žœ
žœ˜1š
ž˜˜J˜@—šœ
žœ
žœ˜Jšžœžœžœ˜C—šžœž˜Jšœ	žœ
˜Jšœ ˜Jšžœ˜—Jšžœ
˜—J˜0Jšžœ
˜J˜——J˜
Jš
œ/™/J˜˜šŸœžœ
žœ˜2Jš 
œ
žœ
žœ˜1J˜"Jšžœ
˜J˜—šŸœžœ
žœ˜1Jš 
œ
žœ
žœ˜1J˜.˜šœ'žœ
žœ˜GJ˜——Jšžœ
˜J˜—šŸ
œžœžœ œ˜DJšžœ
ž˜šžœ
žœ˜ Jšžœžœ˜;—Jšžœ
˜J˜—šŸœžœ"˜8Jšžœ œ˜*Jšžœ
ž˜šžœ
žœ˜ Jšžœžœ˜A—Jšžœ
˜J˜——J˜
Jš
œ™˜šŸœžœ
ž	œ˜7Jšžœ
žœ˜&šœžœ
˜Jš
œ=˜=—šœž
œ˜ Jšœžœ,˜CJšžœ
ž
œ˜*—Jšžœ
˜J˜—šŸœžœ
ž	œ˜9Jšžœ
žœ˜&Jšœžœ˜Jšœžœ
˜Jšœžœ
˜Jšžœ
˜J˜—šŸœžœ˜.Jšžœ
žœ
žœ˜-Jš
žœ
žœžœ
žœ
žœ
˜+Jšœžœ
žœ˜1Jš
œ:™:Jš
œ ™ Jš
œ*™*Jš
œ™Jš
œ™Jš
œ™Jš
œ™Jš
œ5™5Jš
œ™Jšžœžœ ˜>Jšžœ
˜J˜—šŸœžœ˜,Jšžœ
žœ˜&Jšœžœžœ˜6Jšœžœžœ˜+šŸ
œžœ0˜@Jš
ž˜Jš
œ"˜"šžœžœ ž˜;šžœ˜Jšžœ)˜-Jšžœ=˜A—Jšžœ
˜—Jš
œ˜Jšžœ ˜—šžœžœžœ%ž˜GJ˜BJšžœ
˜—Jšœ
ž
œ˜)Jš
œ‚
˜‚
Jšœžœ˜7˜Jšžœ1˜6—˜Jšžœ*˜/—Jšžœ
˜J˜—J˜
Jš
œ'™'Jš
œ7™7J˜J˜2J˜šŸœžœžœ˜BJšžœ
ž˜J˜$šžœ
žœ ˜)Jšžœž
œžœž
œ˜6—Jšžœ
˜J˜—šŸœžœ˜0Jšžœ œ˜*Jšžœ
ž˜Jš
œD™DJš
œ1™1šžœ
˜Jšœ
žœ
žœ˜Jšœžœ
žœ
žœžœžœ	˜>—Jšžœ
˜J˜—šŸœž	œ˜4Jšžœ
žœ
žœžœ
˜,J˜—šŸœž	œ˜2Jšžœ
žœ
žœžœ
˜,J˜—šŸœž	œ˜Jšžœ
žœ
žœžœ
˜,J˜—š	œžœžœ
ž	œ
žœ˜0Jšž
œžœ
ž	œ
žœ
žœ
žœžœ˜JJšž
œžœ
ž	œ
žœ
žœ
žœžœ˜LJ˜—J˜1J˜Jš	œžœžœ
žœ
žœ˜7J˜šœžœžœ
ž	œ˜&J˜4J˜—šœžœžœ
ž	œ˜&J˜3J˜—Jšœžœžœ
˜%Jšœžœžœ
˜+J˜š	œžœžœ
ž	œ
žœ˜5Jšœ
žœ
˜J˜Jšœžœ
˜J˜J˜Jšœžœ
˜J˜Jšœžœ˜J˜—J˜KJ˜—J˜
Jš
œ2™2Jš
œ4™4˜šŸ	œžœ	žœ
ž
œ
žœ
žœ
žœ˜EJš
ž˜Jšœžœ˜Jšœžœžœ
˜ Jšž
œžœ˜Jšžœž
œž
œž
œž
œžœ
˜Jšž
œžœ˜Jšžœžœ	žœ
žœ
˜ Jš
œC™CJ˜Jšœžœ žœ˜HJšžœž
œž
œ
˜ J˜šžœ
žœž˜Jšž
œž
œž
œž
œž
œ	ž
œ˜šžœ
ž
œž
œ
ž˜Jšž
œ
ž
œžœž
œž
œ
žœ
ž
œž
œžœ
˜+Jšž
œ
ž
œžœž
œž
œ
žœ
ž
œž
œžœ
˜+Jšžœž
œ	ž
œž
œ	ž
œžœ
˜,Jšžœ
˜—Jš
œž
œž
œ	ž
œž
œ	ž
œžœ
˜2šžœ
žœ
ž˜šž
œ
ž
œž
œ
ž
œ˜šžœ
žœ
ž˜Jšž
œ
ž
œž
œžœ
˜Jšž
œ
ž
œž
œž
œ
ž
œžœ˜šžœž˜Jšžœ
žœžœ
žœž
œžœ
žœž
œž
œ
ž
œ˜-Jšžœ
˜Jšžœ
˜———Jšž
œ
ž
œž
œžœ
˜Jšž
œ
ž
œž
œž
œ
ž
œžœ˜šžœž˜Jšžœžœžœ
žœž
œžœ
žœž
œž
œ
ž
œ˜/Jšžœ
˜Jšžœ
˜——Jšž
œ
žœ
žœ˜Jšž
œ
žœ
žœ˜Jšžœ
žœ˜š
ž˜šžœ˜šžœ
ž
œ
žœž˜Jšž
œž
œž
œ
ž
œ˜Jšžœž
œž
œ
žœž
œ
ž
œž
œ
ž
œžœ
˜7Jšœž
œž
œ
˜
Jšžœ
˜———Jšžœ
˜—Jšžœ
˜J˜J˜J˜——Jš
œ™J˜˜Jšžœ ˜"J˜——…—%‚9