<> <> <> <> 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]]; <> <> < 0 THEN BEGIN>> <> <> <> <> <> <> 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;  <> <Measurements>Measure.mesa.>> 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 < 644/10000 = 161/2500 usec/cycle>> <> 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];  <> <STSRT.SAI.>> 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 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.