Skip to content

Commit

Permalink
feat(bench): add BenchContext::start() and BenchContext::end() (#18734)
Browse files Browse the repository at this point in the history 
Closes #17589.
```ts
Deno.bench("foo", async (t) => {
  const resource = setup(); // not included in measurement
  t.start();
  measuredOperation(resource);
  t.end();
  resource.close(); // not included in measurement
});
```
  • Loading branch information
@nayeemrmn
nayeemrmn authored Jul 31, 2023
1 parent e348c11 commit 02865cb
Show file tree
Hide file tree
Showing 7 changed files with 258 additions and 40 deletions.
157 changes: 126 additions & 31 deletions cli/js/40_testing.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -574,6 +574,15 @@ function withPermissions(fn, permissions) {

/** @type {Map<number, TestState | TestStepState>} */
const testStates = new Map();
/** @type {number | null} */
let currentBenchId = null;
// These local variables are used to track time measurements at
// `BenchContext::{start,end}` calls. They are global instead of using a state
// map to minimise the overhead of assigning them.
/** @type {number | null} */
let currentBenchUserExplicitStart = null;
/** @type {number | null} */
let currentBenchUserExplicitEnd = null;

// Main test function provided by Deno.
function test(
Expand Down Expand Up @@ -825,10 +834,11 @@ function benchStats(n, highPrecision, avg, min, max, all) {
};
}

async function benchMeasure(timeBudget, fn, async) {
async function benchMeasure(timeBudget, fn, async, context) {
let n = 0;
let avg = 0;
let wavg = 0;
let usedExplicitTimers = false;
const all = [];
let min = Infinity;
let max = -Infinity;
Expand All @@ -842,61 +852,101 @@ async function benchMeasure(timeBudget, fn, async) {
if (!async) {
while (budget > 0 || iterations-- > 0) {
const t1 = benchNow();

fn();
const iterationTime = benchNow() - t1;
fn(context);
const t2 = benchNow();
const totalTime = t2 - t1;
let measuredTime = totalTime;
if (currentBenchUserExplicitStart !== null) {
measuredTime -= currentBenchUserExplicitStart - t1;
currentBenchUserExplicitStart = null;
usedExplicitTimers = true;
}
if (currentBenchUserExplicitEnd !== null) {
measuredTime -= t2 - currentBenchUserExplicitEnd;
currentBenchUserExplicitEnd = null;
usedExplicitTimers = true;
}

c++;
wavg += iterationTime;
budget -= iterationTime;
wavg += measuredTime;
budget -= totalTime;
}
} else {
while (budget > 0 || iterations-- > 0) {
const t1 = benchNow();

await fn();
const iterationTime = benchNow() - t1;
await fn(context);
const t2 = benchNow();
const totalTime = t2 - t1;
let measuredTime = totalTime;
if (currentBenchUserExplicitStart !== null) {
measuredTime -= currentBenchUserExplicitStart - t1;
currentBenchUserExplicitStart = null;
usedExplicitTimers = true;
}
if (currentBenchUserExplicitEnd !== null) {
measuredTime -= t2 - currentBenchUserExplicitEnd;
currentBenchUserExplicitEnd = null;
usedExplicitTimers = true;
}

c++;
wavg += iterationTime;
budget -= iterationTime;
wavg += measuredTime;
budget -= totalTime;
}
}

wavg /= c;

// measure step
if (wavg > lowPrecisionThresholdInNs) {
if (wavg > lowPrecisionThresholdInNs || usedExplicitTimers) {
let iterations = 10;
let budget = timeBudget * 1e6;

if (!async) {
while (budget > 0 || iterations-- > 0) {
const t1 = benchNow();

fn();
const iterationTime = benchNow() - t1;
fn(context);
const t2 = benchNow();
const totalTime = t2 - t1;
let measuredTime = totalTime;
if (currentBenchUserExplicitStart !== null) {
measuredTime -= currentBenchUserExplicitStart - t1;
currentBenchUserExplicitStart = null;
}
if (currentBenchUserExplicitEnd !== null) {
measuredTime -= t2 - currentBenchUserExplicitEnd;
currentBenchUserExplicitEnd = null;
}

n++;
avg += iterationTime;
budget -= iterationTime;
ArrayPrototypePush(all, iterationTime);
if (iterationTime < min) min = iterationTime;
if (iterationTime > max) max = iterationTime;
avg += measuredTime;
budget -= totalTime;
ArrayPrototypePush(all, measuredTime);
if (measuredTime < min) min = measuredTime;
if (measuredTime > max) max = measuredTime;
}
} else {
while (budget > 0 || iterations-- > 0) {
const t1 = benchNow();

await fn();
const iterationTime = benchNow() - t1;
await fn(context);
const t2 = benchNow();
const totalTime = t2 - t1;
let measuredTime = totalTime;
if (currentBenchUserExplicitStart !== null) {
measuredTime -= currentBenchUserExplicitStart - t1;
currentBenchUserExplicitStart = null;
}
if (currentBenchUserExplicitEnd !== null) {
measuredTime -= t2 - currentBenchUserExplicitEnd;
currentBenchUserExplicitEnd = null;
}

n++;
avg += iterationTime;
budget -= iterationTime;
ArrayPrototypePush(all, iterationTime);
if (iterationTime < min) min = iterationTime;
if (iterationTime > max) max = iterationTime;
avg += measuredTime;
budget -= totalTime;
ArrayPrototypePush(all, measuredTime);
if (measuredTime < min) min = measuredTime;
if (measuredTime > max) max = measuredTime;
}
}
} else {
Expand All @@ -906,7 +956,11 @@ async function benchMeasure(timeBudget, fn, async) {
if (!async) {
while (budget > 0 || iterations-- > 0) {
const t1 = benchNow();
for (let c = 0; c < lowPrecisionThresholdInNs; c++) fn();
for (let c = 0; c < lowPrecisionThresholdInNs; c++) {
fn(context);
currentBenchUserExplicitStart = null;
currentBenchUserExplicitEnd = null;
}
const iterationTime = (benchNow() - t1) / lowPrecisionThresholdInNs;

n++;
Expand All @@ -919,7 +973,11 @@ async function benchMeasure(timeBudget, fn, async) {
} else {
while (budget > 0 || iterations-- > 0) {
const t1 = benchNow();
for (let c = 0; c < lowPrecisionThresholdInNs; c++) await fn();
for (let c = 0; c < lowPrecisionThresholdInNs; c++) {
await fn(context);
currentBenchUserExplicitStart = null;
currentBenchUserExplicitEnd = null;
}
const iterationTime = (benchNow() - t1) / lowPrecisionThresholdInNs;

n++;
Expand All @@ -936,12 +994,45 @@ async function benchMeasure(timeBudget, fn, async) {
return benchStats(n, wavg > lowPrecisionThresholdInNs, avg, min, max, all);
}

/** @param desc {BenchDescription} */
function createBenchContext(desc) {
return {
[SymbolToStringTag]: "BenchContext",
name: desc.name,
origin: desc.origin,
start() {
if (currentBenchId !== desc.id) {
throw new TypeError(
"The benchmark which this context belongs to is not being executed.",
);
}
if (currentBenchUserExplicitStart != null) {
throw new TypeError("BenchContext::start() has already been invoked.");
}
currentBenchUserExplicitStart = benchNow();
},
end() {
const end = benchNow();
if (currentBenchId !== desc.id) {
throw new TypeError(
"The benchmark which this context belongs to is not being executed.",
);
}
if (currentBenchUserExplicitEnd != null) {
throw new TypeError("BenchContext::end() has already been invoked.");
}
currentBenchUserExplicitEnd = end;
},
};
}

/** Wrap a user benchmark function in one which returns a structured result. */
function wrapBenchmark(desc) {
const fn = desc.fn;
return async function outerWrapped() {
let token = null;
const originalConsole = globalThis.console;
currentBenchId = desc.id;

try {
globalThis.console = new Console((s) => {
Expand All @@ -962,13 +1053,17 @@ function wrapBenchmark(desc) {
}

const benchTimeInMs = 500;
const stats = await benchMeasure(benchTimeInMs, fn, desc.async);
const context = createBenchContext(desc);
const stats = await benchMeasure(benchTimeInMs, fn, desc.async, context);

return { ok: stats };
} catch (error) {
return { failed: core.destructureError(error) };
} finally {
globalThis.console = originalConsole;
currentBenchId = null;
currentBenchUserExplicitStart = null;
currentBenchUserExplicitEnd = null;
if (bench.sanitizeExit) setExitHandler(null);
if (token !== null) restorePermissions(token);
}
Expand Down
6 changes: 6 additions & 0 deletions cli/tests/integration/bench_tests.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -181,6 +181,12 @@ itest!(check_local_by_default2 {
exit_code: 1,
});

itest!(bench_explicit_start_end {
args: "bench --quiet -A bench/explicit_start_and_end.ts",
output: "bench/explicit_start_and_end.out",
exit_code: 1,
});

itest!(bench_with_config {
args: "bench --config bench/collect/deno.jsonc bench/collect",
exit_code: 0,
Expand Down
2 changes: 1 addition & 1 deletion cli/tests/integration/lsp_tests.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -5130,7 +5130,7 @@ fn lsp_completions_auto_import() {
"source": "./b.ts",
"data": {
"exportName": "foo",
"exportMapKey": "foo|6802|file:///a/b",
"exportMapKey": "foo|6811|file:///a/b",
"moduleSpecifier": "./b.ts",
"fileName": "file:///a/b.ts"
},
Expand Down
25 changes: 25 additions & 0 deletions cli/tests/testdata/bench/explicit_start_and_end.out
View file
Original file line number Diff line number Diff line change
@@ -0,0 +1,25 @@
cpu: [WILDCARD]
runtime: deno [WILDCARD] ([WILDCARD])

[WILDCARD]/explicit_start_and_end.ts
benchmark time (avg) (min … max) p75 p99 p995
----------------------------------------------------- -----------------------------
start and end [WILDCARD] [WILDCARD]/iter[WILDCARD]([WILDCARD] … [WILDCARD]) [WILDCARD]
start only [WILDCARD] [WILDCARD]/iter[WILDCARD]([WILDCARD] … [WILDCARD]) [WILDCARD]
end only [WILDCARD] [WILDCARD]/iter[WILDCARD]([WILDCARD] … [WILDCARD]) [WILDCARD]
double start error: TypeError: BenchContext::start() has already been invoked.
t.start();
^
at BenchContext.start ([WILDCARD])
at [WILDCARD]/explicit_start_and_end.ts:[WILDCARD]
double end error: TypeError: BenchContext::end() has already been invoked.
t.end();
^
at BenchContext.end ([WILDCARD])
at [WILDCARD]/explicit_start_and_end.ts:[WILDCARD]
captured error: TypeError: The benchmark which this context belongs to is not being executed.
captured!.start();
^
at BenchContext.start ([WILDCARD])
at [WILDCARD]/explicit_start_and_end.ts:[WILDCARD]
error: Bench failed
50 changes: 50 additions & 0 deletions cli/tests/testdata/bench/explicit_start_and_end.ts
View file
Original file line number Diff line number Diff line change
@@ -0,0 +1,50 @@
Deno.bench("start and end", (t) => {
const id = setInterval(() => {}, 1000);
t.start();
Deno.inspect(id);
t.end();
clearInterval(id);
});

Deno.bench("start only", (t) => {
const id = setInterval(() => {}, 1000);
t.start();
Deno.inspect(id);
clearInterval(id);
});

Deno.bench("end only", (t) => {
const id = setInterval(() => {}, 1000);
Deno.inspect(id);
t.end();
clearInterval(id);
});

Deno.bench("double start", (t) => {
const id = setInterval(() => {}, 1000);
t.start();
t.start();
Deno.inspect(id);
t.end();
clearInterval(id);
});

let captured: Deno.BenchContext;

Deno.bench("double end", (t) => {
captured = t;
const id = setInterval(() => {}, 1000);
t.start();
Deno.inspect(id);
t.end();
t.end();
clearInterval(id);
});

Deno.bench("captured", () => {
const id = setInterval(() => {}, 1000);
captured!.start();
Deno.inspect(id);
captured!.end();
clearInterval(id);
});
2 changes: 1 addition & 1 deletion cli/tests/testdata/check/deno_unstable_not_found/main.out
View file
Original file line number Diff line number Diff line change
Expand Up @@ -6,7 +6,7 @@ Deno.openKv;
'open' is declared here.
export function open(
~~~~
at asset:///lib.deno.ns.d.ts:1667:19
at asset:///lib.deno.ns.d.ts:[WILDCARD]:19

TS2339 [ERROR]: Property 'createHttpClient' does not exist on type 'typeof Deno'. 'Deno.createHttpClient' is an unstable API. Did you forget to run with the '--unstable' flag? If not, try changing the 'lib' compiler option to include 'deno.unstable' or add a triple-slash directive to your entrypoint: /// <reference lib="deno.unstable" />
Deno.createHttpClient;
Expand Down
Loading

0 comments on commit 02865cb

Please sign in to comment.