TimerLoopImpl.mesa
Copyright © 1992 by Xerox Corporation. All rights reserved.
Bier, December 29, 1992 12:18 pm PST
Contents: Provides an accurate estimate of the time taken by a given Cedar routine by running that routine many times and subtracting away the loop overhead.
DIRECTORY
BasicTime, Commander, FS, IO, PFS, PFSNames, Process, Real, RealFns, RefText, RefTextExtras, Rope, TimerLoop;
TimerLoopImpl:
CEDAR
PROGRAM
IMPORTS BasicTime, Commander, FS, IO, PFS, PFSNames, Process, Real, RealFns, RefText, RefTextExtras, Rope
EXPORTS TimerLoop = BEGIN
ROPE: TYPE = Rope.ROPE;
STREAM: TYPE = IO.STREAM;
Dummy: PROC = {};
Period:
PROC [start, end: BasicTime.Pulses]
RETURNS [diff: BasicTime.Pulses] = {
diff ¬
IF end >= start
THEN end - start
ELSE (LAST[BasicTime.Pulses] - start) + end + 1;
};
TimeByCount:
PUBLIC PROC [init:
PROC, doit:
PROC, count:
CARD]
RETURNS [totalMicrosecs, initTotalMicrosecs:
CARD, avgMicrosecs, initAvgMicrosecs:
REAL] = {
startTime, endTime: BasicTime.Pulses ¬ 0;
initTotal, total, initTotal2: BasicTime.Pulses ¬ 0;
x: CARD ¬ 0;
floatCount: REAL ¬ count;
ok: BOOL ¬ FALSE;
error: REAL;
UNTIL ok
DO
startTime ¬ BasicTime.GetClockPulses[];
FOR i:
NAT
IN [0..count)
DO
init[];
Dummy[];
ENDLOOP;
endTime ¬ BasicTime.GetClockPulses[];
initTotal ¬ Period[startTime, endTime];
startTime ¬ BasicTime.GetClockPulses[];
FOR i:
NAT
IN [0..count)
DO
init[];
doit[];
ENDLOOP;
endTime ¬ BasicTime.GetClockPulses[];
total ¬ Period[startTime, endTime];
startTime ¬ BasicTime.GetClockPulses[];
FOR i:
NAT
IN [0..count)
DO
init[];
Dummy[];
ENDLOOP;
endTime ¬ BasicTime.GetClockPulses[];
initTotal2 ¬ Period[startTime, endTime];
error ¬ initTotal2-initTotal;
IF ABS[error]/MIN[initTotal, initTotal2] < 0.05 AND total > initTotal THEN ok ¬ TRUE;
ENDLOOP;
total ¬ total - initTotal;
totalMicrosecs ¬ BasicTime.PulsesToMicroseconds[total];
initTotalMicrosecs ¬ BasicTime.PulsesToMicroseconds[initTotal];
avgMicrosecs ¬ totalMicrosecs/floatCount;
initAvgMicrosecs ¬ initTotalMicrosecs/floatCount;
};
TimeForAPeriod:
PUBLIC
PROC [init:
PROC, doit:
PROC, periodMillisecs:
CARD ¬ 2000]
RETURNS [avgMicrosecs, initAvgMicrosecs:
REAL ¬ 0.0, count, trials:
CARD, worstAvg, worstInitAvg:
REAL ¬ 0.0] = {
totalMicrosecs: CARD;
testCount: CARD = 20;
testCountFloat: REAL = testCount;
startTime: BasicTime.Pulses;
periodPulses: BasicTime.Pulses ¬ BasicTime.MicrosecondsToPulses[periodMillisecs*1000];
now: BasicTime.Pulses;
microSecsPerTrial: REAL = 5000.0; -- can the CPU stay stable for this long?
microSecsPerCall: REAL;
startTime ¬ BasicTime.GetClockPulses[];
Phase 1:
[totalMicrosecs, ----, avgMicrosecs, initAvgMicrosecs] ¬ TimeByCount[init, doit, 1];
now ¬ BasicTime.GetClockPulses[];
IF Period[startTime, now] > periodPulses
THEN {
count ¬ 1; trials ¬ 1;
RETURN;
};
Phase 2:
[totalMicrosecs, ----, avgMicrosecs, initAvgMicrosecs] ¬ TimeByCount[init, doit, testCount];
IF Period[startTime, now] > periodPulses
THEN {
count ¬ testCount; trials ¬ 1;
RETURN;
};
Phase 3:
microSecsPerCall ¬ avgMicrosecs + 3*initAvgMicrosecs;
count ¬ Real.Ceiling[microSecsPerTrial/microSecsPerCall]; -- calls per trial
IF count < 10 THEN count ¬ 10;
trials ¬ 0;
BEGIN
thisTotal: CARD;
thisAvg, thisInitAvg: REAL;
worstTotal: CARD;
totalMicrosecs ¬ LAST[CARD];
worstTotal ¬ 0;
UNTIL Period[startTime, now] > periodPulses
DO
[thisTotal, ----, thisAvg, thisInitAvg] ¬ TimeByCount[init, doit, count];
trials ¬ trials + 1;
IF thisTotal < totalMicrosecs
THEN {
totalMicrosecs ¬ thisTotal;
avgMicrosecs ¬ thisAvg;
initAvgMicrosecs ¬ thisInitAvg;
};
IF thisTotal > worstTotal
THEN {
worstTotal ¬ thisTotal;
worstAvg ¬ thisAvg;
worstInitAvg ¬ thisInitAvg;
};
now ¬ BasicTime.GetClockPulses[];
ENDLOOP;
END;
};
ReportForAPeriod:
PUBLIC PROC [f:
STREAM, name:
ROPE, init:
PROC, doit:
PROC, periodMillisecs:
CARD] = {
count, trials: CARD;
avg, initAvg, worstAvg, worstInitAvg: REAL;
Process.PauseMsec[1000]; -- allow the machine to settle
[avg, initAvg, count, trials, worstAvg, worstInitAvg] ¬ TimeForAPeriod[init, doit, periodMillisecs];
f.PutRope[name];
f.PutChar[':];
f.PutChar[IO.SP];
IF Rope.Length[name] < 15
THEN {
FOR i:
NAT
IN [0..15-Rope.Length[name])
DO
f.PutChar[IO.SP];
ENDLOOP;
};
f.PutFL["%4.2f avg, %4.2f worst avg over %g calls, %g trials (init: %4.2f avg)\n", LIST[[real[avg]], [real[worstAvg]], [cardinal[count]], [cardinal[trials]], [real[initAvg]]] ];
};
TimeArithmetic: Commander.CommandProc = {
x: REAL ¬ 0;
n: CARD ¬ 0;
msec: CARD ¬ 1000;
FloatAssignment: PROC = {x ¬ 3};
FloatPlus: PROC = {x ¬ x+1}; FloatPlusInit: PROC = {x ¬ 1};
FloatPlusTwice: PROC = {x ¬ x+1; x ¬ x+1};
FloatMultiply: PROC = {x ¬ x*2}; FloatMultiplyInit: PROC = {x ¬ 2};
SquareRoot: PROC = {x ¬ RealFns.SqRt[x]}; SquareRootInit: PROC = {x ¬ 2};
Assignment: PROC = {n ¬ 3};
Plus: PROC = {n ¬ n+1}; PlusInit: PROC = {n ¬ 1};
Multiply: PROC = {n ¬ n*2}; MultiplyInit: PROC = {n ¬ 2};
cmd.out.PutRope["All times in microseconds. Spending at least 1 second on each test.\n"];
ReportForAPeriod[cmd.out, "x ← 3", Dummy, FloatAssignment, msec];
ReportForAPeriod[cmd.out, "x ← x+1", FloatPlusInit, FloatPlus, msec];
ReportForAPeriod[cmd.out, "x←x+1; x←x+1", FloatPlusInit, FloatPlusTwice, msec];
ReportForAPeriod[cmd.out, "x ← x*2", FloatMultiplyInit, FloatMultiply, msec];
ReportForAPeriod[cmd.out, "x ← RealFns.SqRt[x]", SquareRootInit, SquareRoot, msec];
cmd.out.PutChar[IO.LF];
ReportForAPeriod[cmd.out, "n ← 3", Dummy, Assignment, msec];
ReportForAPeriod[cmd.out, "n ← n+1", PlusInit, Plus, msec];
ReportForAPeriod[cmd.out, "n ← n*2", MultiplyInit, Multiply, msec];
};
TimeIO: Commander.CommandProc = {
msec: CARD ¬ 3000;
t: REF TEXT;
input: ROPE = "Hello 3.14159 34";
spaceInput: ROPE = " 3.14159 34";
s: STREAM ¬ IO.RIS[input];
spaceS: STREAM ¬ IO.RIS[spaceInput];
InitS: PROC = {IO.SetIndex[s, 0]};
InitSpaceS: PROC = {IO.SetIndex[spaceS, 0]};
GetCedarTokenRope: PROC = {[] ¬ IO.GetCedarTokenRope[s]};
GetCedarToken: PROC = {[] ¬ IO.GetCedarToken[s, t]};
SkipWhitespace: PROC = {[] ¬ IO.SkipWhitespace[s]};
cmd.out.PutRope["All times in microseconds. Spending at least 3 seconds on each test.\n"];
ReportForAPeriod[cmd.out, "GetCedarTokenRope", InitS, GetCedarTokenRope, msec];
t ¬ RefTextExtras.ObtainScratch16[];
ReportForAPeriod[cmd.out, "GetCedarToken", InitS, GetCedarToken, msec];
RefTextExtras.ReleaseScratch16[t];
ReportForAPeriod[cmd.out, "SkipWhitespace", InitSpaceS, SkipWhitespace, msec];
};
TimeRefText: Commander.CommandProc = {
msec: CARD ¬ 3000;
t: REF TEXT;
ObtainAndRelease54: PROC = {t ¬ RefText.ObtainScratch[54]; RefText.ReleaseScratch[t]};
ObtainAndRelease100: PROC = {t ¬ RefText.ObtainScratch[100]; RefText.ReleaseScratch[t]};
ObtainAndRelease8192: PROC = {t ¬ RefText.ObtainScratch[8192]; RefText.ReleaseScratch[t]};
ObtainAndRelease8192Inline: PROC = {t ¬ RefTextExtras.ObtainScratch8192[]; RefTextExtras.ReleaseScratch8192[t]};
ObtainAndRelease8193: PROC = {t ¬ RefText.ObtainScratch[8193]; RefText.ReleaseScratch[t]};
cmd.out.PutRope["All times in microseconds. Spending at least 3 seconds on each test.\n"];
ReportForAPeriod[cmd.out, "ObtainAndRelease[54]", Dummy, ObtainAndRelease54, msec];
ReportForAPeriod[cmd.out, "ObtainAndRelease[100]", Dummy, ObtainAndRelease100, msec];
ReportForAPeriod[cmd.out, "ObtainAndRelease[8192]", Dummy, ObtainAndRelease8192, msec];
ReportForAPeriod[cmd.out, "ObtainAndRelease8192", Dummy, ObtainAndRelease8192Inline, msec];
ReportForAPeriod[cmd.out, "ObtainAndRelease[8193]", Dummy, ObtainAndRelease8193, msec];
};
filePath, fullPath: PFSNames.PATH;
fileName: ROPE = "/Cedar10.1/Top/Rope.df";
fullName: ROPE;
GetVersion:
PROC [path: PFSNames.
PATH]
RETURNS [version:
CARD ¬ 0] = {
NullSeparator: PFSNames.SeparatorProc = {};
FindVersion: PFSNames.ComponentProc = {
PROC[comp: Component, ref: REF];
IF comp.version.versionKind = numeric THEN version ¬ comp.version.version;
};
PFSNames.Map[path, FindVersion, NullSeparator, NIL];
};
TimeFS: Commander.CommandProc = {
msec: CARD ¬ 3000;
t: REF TEXT;
FileInfoRemoteCheck: PROC = {[] ¬ FS.FileInfo[name: fileName]; };
FileInfo: PROC = {[] ¬ FS.FileInfo[name: fileName, remoteCheck: FALSE]; };
FileInfoVersioned: PROC = {[] ¬ FS.FileInfo[name: fullName, remoteCheck: FALSE]; };
PFSFileInfo: PROC = {[] ¬ PFS.FileInfo[name: filePath]; };
PFSFileInfoVersioned: PROC = {[] ¬ PFS.FileInfo[name: fullPath]; };
cmd.out.PutRope["All times in microseconds. Spending at least 3 seconds on each test.\n"];
ReportForAPeriod[cmd.out, "FileInfo (with remote check)", Dummy, FileInfoRemoteCheck, msec];
ReportForAPeriod[cmd.out, "FileInfo (without remote check)", Dummy, FileInfo, msec];
ReportForAPeriod[cmd.out, "FileInfo (without remote check, versioned)", Dummy, FileInfoVersioned, msec];
ReportForAPeriod[cmd.out, "PFS.FileInfo (no version)", Dummy, PFSFileInfo, msec];
ReportForAPeriod[cmd.out, "PFS.FileInfo (versioned)", Dummy, PFSFileInfoVersioned, msec];
cmd.out.PutFL["The highest version of %g is %g (FS), %g (PFS)\n", LIST[[rope[fileName]], [rope[versionRope]], [cardinal[GetVersion[fullPath]]]] ];
};
versionRope: ROPE;
Init:
PROC = {
filePath ¬ PFS.PathFromRope[fileName];
fullPath ¬ PFS.FileInfo[filePath].fullFName;
fullName ¬ FS.FileInfo[fileName].fullFName;
versionRope ¬ Rope.Substr[fullName, Rope.Index[fullName, 0, "!", FALSE]];
};
Init[];
Commander.Register["TimeArithmetic", TimeArithmetic, "Runs TimerLoopImpl on arithmetic operations"];
Commander.Register["TimeIO", TimeIO, "Runs TimerLoopImpl on IO.mesa operations"];
Commander.Register["TimeRefText", TimeRefText, "Runs TimerLoopImpl on RefText.mesa and RefTextExtras.mesa operations"];
Commander.Register["TimeFS", TimeFS, "Runs TimerLoopImpl on FS.mesa"];
END.