From 9a1066869457037d6ab24965da82e80e1e5c77a9 Mon Sep 17 00:00:00 2001 From: Andreu Botella Date: Tue, 30 Nov 2021 01:27:30 +0100 Subject: [PATCH] fix(test): Improve reliability of `deno test`'s op sanitizer with timers (#12934) Although not easy to replicate in the wild, the `deno test` op sanitizer can fail when there are intervals that started before a test runs, since the op sanitizer can end up running in the time between the timer op for an interval's run resolves and the op for the next run starts. This change fixes that by adding a new macrotask callback that will run after the timer macrotask queue has drained. This ensures that there is a timer op if there are any timers which are unresolved by the time the op sanitizer runs. --- cli/tests/integration/test_tests.rs | 10 ++++++ .../testdata/test/ops_sanitizer_nexttick.out | 7 ++++ .../testdata/test/ops_sanitizer_nexttick.ts | 11 ++++++ .../test/ops_sanitizer_timeout_failure.out | 6 ++++ .../test/ops_sanitizer_timeout_failure.ts | 22 ++++++++++++ runtime/js/40_testing.js | 35 ++++++++++++++++++- 6 files changed, 90 insertions(+), 1 deletion(-) create mode 100644 cli/tests/testdata/test/ops_sanitizer_nexttick.out create mode 100644 cli/tests/testdata/test/ops_sanitizer_nexttick.ts create mode 100644 cli/tests/testdata/test/ops_sanitizer_timeout_failure.out create mode 100644 cli/tests/testdata/test/ops_sanitizer_timeout_failure.ts diff --git a/cli/tests/integration/test_tests.rs b/cli/tests/integration/test_tests.rs index 3f23efca22..bddb0cc6e5 100644 --- a/cli/tests/integration/test_tests.rs +++ b/cli/tests/integration/test_tests.rs @@ -151,6 +151,16 @@ itest!(ops_sanitizer_unstable { output: "test/ops_sanitizer_unstable.out", }); +itest!(ops_sanitizer_timeout_failure { + args: "test test/ops_sanitizer_timeout_failure.ts", + output: "test/ops_sanitizer_timeout_failure.out", +}); + +itest!(ops_sanitizer_nexttick { + args: "test test/ops_sanitizer_nexttick.ts", + output: "test/ops_sanitizer_nexttick.out", +}); + itest!(exit_sanitizer { args: "test test/exit_sanitizer.ts", output: "test/exit_sanitizer.out", diff --git a/cli/tests/testdata/test/ops_sanitizer_nexttick.out b/cli/tests/testdata/test/ops_sanitizer_nexttick.out new file mode 100644 index 0000000000..43a4915d04 --- /dev/null +++ b/cli/tests/testdata/test/ops_sanitizer_nexttick.out @@ -0,0 +1,7 @@ +Check [WILDCARD]/testdata/test/ops_sanitizer_nexttick.ts +running 2 tests from [WILDCARD]/testdata/test/ops_sanitizer_nexttick.ts +test test 1 ... ok ([WILDCARD]) +test test 2 ... ok ([WILDCARD]) + +test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out ([WILDCARD]) + diff --git a/cli/tests/testdata/test/ops_sanitizer_nexttick.ts b/cli/tests/testdata/test/ops_sanitizer_nexttick.ts new file mode 100644 index 0000000000..fcc9cb92a2 --- /dev/null +++ b/cli/tests/testdata/test/ops_sanitizer_nexttick.ts @@ -0,0 +1,11 @@ +import { nextTick } from "../../../../test_util/std/node/_next_tick.ts"; + +// https://github.com/denoland/deno_std/issues/1651 + +Deno.test("test 1", async () => { + await new Promise((resolve) => nextTick(resolve)); +}); + +Deno.test("test 2", async () => { + await new Promise((resolve) => nextTick(resolve)); +}); diff --git a/cli/tests/testdata/test/ops_sanitizer_timeout_failure.out b/cli/tests/testdata/test/ops_sanitizer_timeout_failure.out new file mode 100644 index 0000000000..81a1af63b8 --- /dev/null +++ b/cli/tests/testdata/test/ops_sanitizer_timeout_failure.out @@ -0,0 +1,6 @@ +Check [WILDCARD]/testdata/test/ops_sanitizer_timeout_failure.ts +running 1 test from [WILDCARD]/testdata/test/ops_sanitizer_timeout_failure.ts +test wait ... ok ([WILDCARD]) + +test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out ([WILDCARD]) + diff --git a/cli/tests/testdata/test/ops_sanitizer_timeout_failure.ts b/cli/tests/testdata/test/ops_sanitizer_timeout_failure.ts new file mode 100644 index 0000000000..d40a5a2581 --- /dev/null +++ b/cli/tests/testdata/test/ops_sanitizer_timeout_failure.ts @@ -0,0 +1,22 @@ +let intervalHandle: number; +let firstIntervalPromise: Promise; + +addEventListener("load", () => { + firstIntervalPromise = new Promise((resolve) => { + let firstIntervalCalled = false; + intervalHandle = setInterval(() => { + if (!firstIntervalCalled) { + resolve(); + firstIntervalCalled = true; + } + }, 5); + }); +}); + +addEventListener("unload", () => { + clearInterval(intervalHandle); +}); + +Deno.test("wait", async function () { + await firstIntervalPromise; +}); diff --git a/runtime/js/40_testing.js b/runtime/js/40_testing.js index 053afc5dab..e8b07d494a 100644 --- a/runtime/js/40_testing.js +++ b/runtime/js/40_testing.js @@ -30,6 +30,37 @@ } = window.__bootstrap.primordials; let testStepsEnabled = false; + let opSanitizerDelayResolve = null; + + // Even if every resource is closed by the end of a test, there can be a delay + // until the pending ops have all finished. This function returns a promise + // that resolves when it's (probably) fine to run the op sanitizer. + // + // This is implemented by adding a macrotask callback that runs after the + // timer macrotasks, so we can guarantee that a currently running interval + // will have an associated op. An additional `setTimeout` of 0 is needed + // before that, though, in order to give time for worker message ops to finish + // (since timeouts of 0 don't queue tasks in the timer queue immediately). + function opSanitizerDelay() { + return new Promise((resolve, reject) => { + setTimeout(() => { + if (opSanitizerDelayResolve !== null) { + reject(new Error("There is an op sanitizer delay already.")); + } else { + opSanitizerDelayResolve = resolve; + } + }, 0); + }); + } + + function handleOpSanitizerDelayMacrotask() { + if (opSanitizerDelayResolve !== null) { + opSanitizerDelayResolve(); + opSanitizerDelayResolve = null; + } + return true; + } + // Wrap test function in additional assertion that makes sure // the test case does not leak async "ops" - ie. number of async // completed ops after the test is the same as number of dispatched @@ -45,7 +76,7 @@ // Defer until next event loop turn - that way timeouts and intervals // cleared can actually be removed from resource table, otherwise // false positives may occur (https://github.com/denoland/deno/issues/4591) - await new Promise((resolve) => setTimeout(resolve, 0)); + await opSanitizerDelay(); } if (step.shouldSkipSanitizers) { @@ -466,6 +497,8 @@ finishing test case.`; filter = null, shuffle = null, } = {}) { + core.setMacrotaskCallback(handleOpSanitizerDelayMacrotask); + const origin = getTestOrigin(); const originalConsole = globalThis.console;