From e122217d16808e2bce996c6a90e837e2b05e4345 Mon Sep 17 00:00:00 2001 From: Timo Tijhof Date: Thu, 29 Jul 2021 00:54:46 +0100 Subject: [PATCH 01/10] Assert: Improve detection of bad calls to `assert.async()` callbacks MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit == Background == When creating two async pauses in a test, it was possible for a test to pass by invoking one of them twice, and the other not at all. Easy scenario (though perhaps not realistic): > Use `assert.async()` twice, assigned as done1 and done2 in the same > `QUnit.test()` case, and then simulate the failure scenario such that > you wrongly call done1 two times, and forget to call done2. Complex scenario across `QUnit.test()` and "afterEach" hooks, since these previously shared a single semaphore: > Use `assert.async()` once in a simple test, and schedule the resume > call in the future, but then fail with an uncaught error. The uncaught > error is found and `Test.run()` would internally kill the pause by > resetting the semaphore to zero (this make sense since we shouldn't > wait for the release once the test is known to have failed). > After this reset, we proceed to the "afterEach" hook. Suppose this > hook is also async, and during its execution, the originally scheduled > resume call happens. This would effectively end up releasing the > afterEach's async pause despite not being finished yet, and then we > proceed to the next test. That test would then fail when the afterEach's > own release call happens, failing as "release during a different test". This is the scenario of https://github.com/qunitjs/qunit/issues/1432. Fix this and numerous other edge cases by making the returned callbacks from `assert.async()` strict about which locks they release. Each lock now adds a unique token to a map, and invoking the release function decrements/removes this token from the map. == Notes == * es6-map.js assigns the fallback in all browsers. This is a bug, to be fixed later. * The `isNaN(semaphore)` logic was originally added in 2015 by ea3e350f. At the time, the internal resume function was public, and NaN could emerge through `QUnit.start("bla")` as result of `semaphore += "bla"`. This has not been possible for a while. During PR #1590, I did not trace the origin of this code, and thus did not realize that it was already obsolete (the semaphore itself is not publicly supported). * The "during different test" error is now almost impossible to trigger since we now kill pending locks during test failures and tolerate all late calls equally. This meant the `drooling-done.js` test case now fails in a more limited way. I added a new test case for coverage, that reproduces it still, but it's a lot more obscure – it requires the original test to pass and then also have an unexpected call during a different test. * I considered using the phrase "async lock" in the public-facing error messages, but found this perhaps too internal/technical when coming from the perspective of `var done = assert.async();`. In order to keep the code shared between handling of async-await, Promise, and assert.async, but remain friendly and understandable, I went for the phrase "async pause". Fixes https://github.com/qunitjs/qunit/issues/1432. --- src/assert.js | 43 +------ src/cli/run.js | 2 +- src/html-reporter/es6-map.js | 23 +++- src/test.js | 150 +++++++++++++++------- test/cli/fixtures/drooling-done.js | 2 +- test/cli/fixtures/drooling-extra-done.js | 18 +++ test/cli/fixtures/expected/tap-outputs.js | 82 +++++++++++- test/cli/fixtures/semaphore/nan.js | 5 - test/cli/fixtures/semaphore/restart.js | 4 - test/cli/main.js | 56 +++----- test/main/async.js | 52 ++------ test/main/promise.js | 6 +- 12 files changed, 260 insertions(+), 183 deletions(-) create mode 100644 test/cli/fixtures/drooling-extra-done.js delete mode 100644 test/cli/fixtures/semaphore/nan.js delete mode 100644 test/cli/fixtures/semaphore/restart.js diff --git a/src/assert.js b/src/assert.js index fd9da2ba1..c96b701aa 100644 --- a/src/assert.js +++ b/src/assert.js @@ -72,47 +72,10 @@ class Assert { } } - // Put a hold on processing and return a function that will release it a maximum of once. + // Create a new async pause and return a new function that can release the pause. async( count ) { - const test = this.test; - - let popped = false, - acceptCallCount = count; - - if ( typeof acceptCallCount === "undefined" ) { - acceptCallCount = 1; - } - - const resume = internalStop( test ); - - return function done() { - - if ( config.current === undefined ) { - throw new Error( "`assert.async` callback from test \"" + - test.testName + "\" called after tests finished." ); - } - - if ( config.current !== test ) { - config.current.pushFailure( - "`assert.async` callback from test \"" + - test.testName + "\" was called during this test." ); - return; - } - - if ( popped ) { - test.pushFailure( "Too many calls to the `assert.async` callback", - sourceFromStacktrace( 2 ) ); - return; - } - - acceptCallCount -= 1; - if ( acceptCallCount > 0 ) { - return; - } - - popped = true; - resume(); - }; + const requiredCalls = count === undefined ? 1 : count; + return internalStop( this.test, requiredCalls ); } // Exports test.push() to the user API diff --git a/src/cli/run.js b/src/cli/run.js index d4fd930e2..fa0797ab3 100644 --- a/src/cli/run.js +++ b/src/cli/run.js @@ -109,7 +109,7 @@ async function run( args, options ) { console.error( "Error: Process exited before tests finished running" ); const currentTest = QUnit.config.current; - if ( currentTest && currentTest.semaphore ) { + if ( currentTest && currentTest.asyncPauses.size ) { const name = currentTest.testName; console.error( "Last test to run (" + name + ") has an async hold. " + "Ensure all assert.async() callbacks are invoked and Promises resolve. " + diff --git a/src/html-reporter/es6-map.js b/src/html-reporter/es6-map.js index 2950a3263..2ff7e2389 100644 --- a/src/html-reporter/es6-map.js +++ b/src/html-reporter/es6-map.js @@ -1,14 +1,35 @@ -// Support IE 9-10, PhantomJS: Fallback for fuzzysort.js used by ./html.js +// Support IE 9-10, Safari 7, PhantomJS: Partial Map fallback. +// Used by html.js (via fuzzysort.js), and test.js. +// +// FIXME: This check is broken. This file is embedded in the qunit.js closure, +// thus the Map var is hoisted in that scope, and starts undefined (not a function). var Map = typeof Map === "function" ? Map : function StringMap() { var store = Object.create( null ); + var hasOwn = Object.prototype.hasOwnProperty; this.get = function( strKey ) { return store[ strKey ]; }; this.set = function( strKey, val ) { + if ( !hasOwn.call( store, strKey ) ) { + this.size++; + } store[ strKey ] = val; return this; }; + this.delete = function( strKey ) { + if ( hasOwn.call( store, strKey ) ) { + delete store[ strKey ]; + this.size--; + } + }; + this.forEach = function( callback ) { + for ( var strKey in store ) { + callback( store[ strKey ], strKey ); + } + }; this.clear = function() { store = Object.create( null ); + this.size = 0; }; + this.size = 0; }; diff --git a/src/test.js b/src/test.js index 41d119d63..1060a3c0b 100644 --- a/src/test.js +++ b/src/test.js @@ -25,12 +25,13 @@ import TestReport from "./reports/test"; export default function Test( settings ) { this.expected = null; this.assertions = []; - this.semaphore = 0; this.module = config.currentModule; this.steps = []; this.timeout = undefined; this.data = undefined; this.withData = false; + this.asyncNextPauseId = 1; + this.asyncPauses = new Map(); extend( this, settings ); // If a module is skipped, all its tests and the tests of the child suites @@ -201,9 +202,9 @@ Test.prototype = { } test.resolvePromise( promise ); - // If the test has a "lock" on it, but the timeout is 0, then we push a + // If the test has an async "pause" on it, but the timeout is 0, then we push a // failure as the test should be synchronous. - if ( test.timeout === 0 && test.semaphore !== 0 ) { + if ( test.timeout === 0 && test.asyncPauses.size > 0 ) { pushFailure( "Test did not finish synchronously even though assert.timeout( 0 ) was used.", sourceFromStacktrace( 2 ) @@ -810,22 +811,106 @@ export function resetTestTimeout( timeoutDuration ) { config.timeout = setTimeout( config.timeoutHandler( timeoutDuration ), timeoutDuration ); } -// Put a hold on processing and return a function that will release it. -export function internalStop( test ) { - let released = false; - test.semaphore += 1; +// Create a new async pause and return a new function that can release the pause. +// +// This mechanism is internally used by: +// +// * explicit async pauses, created by calling `assert.async()`, +// * implicit async pauses, created when `QUnit.test()` or module hook callbacks +// use async-await or otherwise return a Promise. +// +// Happy scenario: +// +// * Pause is created by calling internalStop(). +// +// Pause is released normally by invoking release() during the same test. +// +// The release() callback lets internal processing resume. +// +// Failure scenarios: +// +// * The test fails due to an uncaught exception. +// +// In this case, Test.run() will call internalRecover() which empties the clears all +// async pauses and sets `killed = true`. The killed flag means we silently ignore +// any late calls to the resume() callback, as we will have moved on to a different +// test by then, and we don't want to cause an extra "release during a different test" +// errors that the developer isn't really responsible for. This can happen when a test +// correctly schedules a call to release(), but also causes an uncaught error. The +// uncaught error means we will no longer wait for the release (as it might not arrive). +// +// * Pause is never released, or called an insufficient number of times. +// +// Our timeout handler will kill the pause and resume test processing, basically +// like internalRecover(), but for one pause instead of any/all. +// +// Here, too, any late calls to resume() will be silently ignored to avoid +// extra errors. We tolerate this since the original test will have already been +// marked as failure. +// +// TODO: QUnit 3 will enable timeouts by default , +// but right now a test will hang indefinitely if async pauses are not released, +// unless QUnit.config.testTimeout or assert.timeout() is used. +// +// * Pause is spontaneously released during a different test, +// or when no test is currently running. +// +// This is close to impossible because this error only happens if the original test +// succesfully finished first (since other failure scenarios kill pauses and ignore +// late calls). It can happen if a test ended exactly as expected, but has some +// external or shared state continuing to hold a reference to the release callback, +// and either the same test scheduled another call to it in the future, or a later test +// causes it to be called through some shared state. +// +// * Pause release() is called too often, during the same test. +// +// This is simply throws an error, after which uncaught error handling picks it up +// and processing resumes. +export function internalStop( test, requiredCalls = 1 ) { config.blocking = true; - // Set a recovery timeout, if so configured. + const pauseId = `#${test.asyncNextPauseId++}`; + const pause = { + killed: false, + remaining: requiredCalls + }; + test.asyncPauses.set( pauseId, pause ); + + function release() { + if ( pause.killed ) { + return; + } + if ( config.current === undefined ) { + throw new Error( "Unexpected release of async pause after tests finished.\n" + + `> Test: ${test.testName} [async ${pauseId}]` ); + } + if ( config.current !== test ) { + throw new Error( "Unexpected release of async pause during a different test.\n" + + `> Test: ${test.testName} [async ${pauseId}]` ); + } + if ( pause.remaining <= 0 ) { + throw new Error( "Tried to release async pause that was already released.\n" + + `> Test: ${test.testName} [async ${pauseId}]` ); + } + + // The `requiredCalls` parameter exists to support `assert.async(count)` + pause.remaining--; + if ( pause.remaining === 0 ) { + test.asyncPauses.delete( pauseId ); + } + + internalStart( test ); + } + if ( setTimeout ) { let timeoutDuration; - if ( typeof test.timeout === "number" ) { timeoutDuration = test.timeout; } else if ( typeof config.testTimeout === "number" ) { timeoutDuration = config.testTimeout; } + // Set a recovery timeout, if so configured. if ( typeof timeoutDuration === "number" && timeoutDuration > 0 ) { config.timeoutHandler = function( timeout ) { return function() { @@ -834,8 +919,10 @@ export function internalStop( test ) { `Test took longer than ${timeout}ms; test timed out.`, sourceFromStacktrace( 2 ) ); - released = true; - internalRecover( test ); + + pause.killed = true; + test.asyncPauses.delete( pauseId ); + internalStart( test ); }; }; clearTimeout( config.timeout ); @@ -846,56 +933,31 @@ export function internalStop( test ) { } } - return function resume() { - if ( released ) { - return; - } - - released = true; - test.semaphore -= 1; - internalStart( test ); - }; + return release; } // Forcefully release all processing holds. function internalRecover( test ) { - test.semaphore = 0; + test.asyncPauses.forEach( pause => { + pause.killed = true; + } ); + test.asyncPauses.clear(); internalStart( test ); } // Release a processing hold, scheduling a resumption attempt if no holds remain. function internalStart( test ) { - // If semaphore is non-numeric, throw error - if ( isNaN( test.semaphore ) ) { - test.semaphore = 0; - - pushFailure( - "Invalid value on test.semaphore", - sourceFromStacktrace( 2 ) - ); - } - - // Don't start until equal number of stop-calls - if ( test.semaphore > 0 ) { + // Ignore if other async pauses still exist. + if ( test.asyncPauses.size > 0 ) { return; } - // Throw an Error if start is called more often than stop - if ( test.semaphore < 0 ) { - test.semaphore = 0; - - pushFailure( - "Tried to restart test while already started (test's semaphore was 0 already)", - sourceFromStacktrace( 2 ) - ); - } - // Add a slight delay to allow more assertions etc. if ( setTimeout ) { clearTimeout( config.timeout ); config.timeout = setTimeout( function() { - if ( test.semaphore > 0 ) { + if ( test.asyncPauses.size > 0 ) { return; } diff --git a/test/cli/fixtures/drooling-done.js b/test/cli/fixtures/drooling-done.js index 9b2be1200..945add8e4 100644 --- a/test/cli/fixtures/drooling-done.js +++ b/test/cli/fixtures/drooling-done.js @@ -10,5 +10,5 @@ QUnit.test( "Test A", assert => { QUnit.test( "Test B", assert => { assert.ok( true ); - done(); + done(); // Silently ignored since "Test A" already failed and we killed its async pauses. } ); diff --git a/test/cli/fixtures/drooling-extra-done.js b/test/cli/fixtures/drooling-extra-done.js new file mode 100644 index 000000000..95a20b2c7 --- /dev/null +++ b/test/cli/fixtures/drooling-extra-done.js @@ -0,0 +1,18 @@ +QUnit.config.reorder = false; + +let done; + +QUnit.test( "Test A", assert => { + assert.ok( true ); + done = assert.async(); + + // Passing. + done(); +} ); + +QUnit.test( "Test B", assert => { + assert.ok( true ); + + // Boom + done(); +} ); diff --git a/test/cli/fixtures/expected/tap-outputs.js b/test/cli/fixtures/expected/tap-outputs.js index 59a704034..0f279c4d6 100644 --- a/test/cli/fixtures/expected/tap-outputs.js +++ b/test/cli/fixtures/expected/tap-outputs.js @@ -426,17 +426,89 @@ not ok 1 times out before scheduled done is called # pass 0 # skip 0 # todo 0 -# fail 1 -Bail out! Error: \`assert.async\` callback from test "times out before scheduled done is called" called after tests finished. +# fail 1`, + + "qunit drooling-done.js": +`TAP version 13 +not ok 1 Test A + --- + message: "Died on test #2 at Object.test (/qunit/qunit/qunit.js): this is an intentional error" + severity: failed + actual : null + expected: undefined + stack: | + Error: this is an intentional error + at /qunit/test/cli/fixtures/drooling-done.js:8:8 + ... +ok 2 Test B +1..2 +# pass 1 +# skip 0 +# todo 0 +# fail 1`, + + "qunit drooling-extra-done.js": +`TAP version 13 +ok 1 Test A +not ok 2 Test B --- - message: "Error: \`assert.async\` callback from test \\"times out before scheduled done is called\\" called after tests finished." + message: |+ + Died on test #2 at Object.test (/qunit/qunit/qunit.js): Unexpected release of async pause during a different test. + > Test: Test A [async #1] severity: failed + actual : null + expected: undefined stack: | - Error: \`assert.async\` callback from test "times out before scheduled done is called" called after tests finished. - at Timeout.done [as _onTimeout] (/qunit/qunit/qunit.js) + Error: Unexpected release of async pause during a different test. + > Test: Test A [async #1] + ... +1..2 +# pass 1 +# skip 0 +# todo 0 +# fail 1`, + + "qunit drooling-extra-done-outside.js": +`TAP version 13 +ok 1 extra done scheduled outside any test +1..1 +# pass 1 +# skip 0 +# todo 0 +# fail 0 +Bail out! Error: Unexpected release of async pause after tests finished. + --- + message: |+ + Error: Unexpected release of async pause after tests finished. + > Test: extra done scheduled outside any test [async #1] + severity: failed + stack: | + Error: Unexpected release of async pause after tests finished. + > Test: extra done scheduled outside any test [async #1] + at Timeout.release [as _onTimeout] (/qunit/qunit/qunit.js) at internal ...`, + "qunit too-many-done-calls.js": +`TAP version 13 +not ok 1 Test A + --- + message: |+ + Died on test #2 at Object.test (/qunit/qunit/qunit.js): Tried to release async pause that was already released. + > Test: Test A [async #1] + severity: failed + actual : null + expected: undefined + stack: | + Error: Tried to release async pause that was already released. + > Test: Test A [async #1] + ... +1..1 +# pass 0 +# skip 0 +# todo 0 +# fail 1`, + "qunit assert-expect/no-tests.js": `TAP version 13 1..0 diff --git a/test/cli/fixtures/semaphore/nan.js b/test/cli/fixtures/semaphore/nan.js deleted file mode 100644 index caafab53a..000000000 --- a/test/cli/fixtures/semaphore/nan.js +++ /dev/null @@ -1,5 +0,0 @@ -QUnit.test( "semaphore is set to NaN", assert => { - assert.test.semaphore = "not a number"; - assert.async(); - return Promise.resolve(); -} ); diff --git a/test/cli/fixtures/semaphore/restart.js b/test/cli/fixtures/semaphore/restart.js deleted file mode 100644 index 3edfefb23..000000000 --- a/test/cli/fixtures/semaphore/restart.js +++ /dev/null @@ -1,4 +0,0 @@ -QUnit.test( "tries to 'restart' the test", assert => { - assert.test.semaphore = -1; - return Promise.resolve(); -} ); diff --git a/test/cli/main.js b/test/cli/main.js index 043759afc..4c1c77f0e 100644 --- a/test/cli/main.js +++ b/test/cli/main.js @@ -571,34 +571,30 @@ CALLBACK: done`; } ); } ); - QUnit.module( "semaphore", () => { - QUnit.test( "invalid value", async assert => { + QUnit.module( "assert.async", () => { + + QUnit.test( "call after tests timeout", async assert => { + const command = "qunit done-after-timeout.js"; try { - await execute( "qunit semaphore/nan.js" ); + await execute( command ); } catch ( e ) { - assert.pushResult( { - result: e.stdout.includes( "message: Invalid value on test.semaphore" ), - actual: e.stdout + "\n" + e.stderr - } ); + assert.equal( e.code, 1 ); + assert.equal( e.stdout, expectedOutput[ command ] ); } } ); - QUnit.test( "try to restart ", async assert => { + QUnit.test( "drooling call to callback across tests", async assert => { + const command = "qunit drooling-done.js"; try { - await execute( "qunit semaphore/restart.js" ); + await execute( command ); } catch ( e ) { - assert.pushResult( { - result: e.stdout.includes( "message: \"Tried to restart test while already started (test's semaphore was 0 already)" ), - actual: e.stdout + "\n" + e.stderr - } ); + assert.equal( e.code, 1 ); + assert.equal( e.stdout, expectedOutput[ command ] ); } } ); - } ); - QUnit.module( "assert.async", () => { - - QUnit.test( "assert.async callback after tests timeout", async assert => { - const command = "qunit done-after-timeout.js"; + QUnit.test( "extra call to callback across tests", async assert => { + const command = "qunit drooling-extra-done.js"; try { await execute( command ); } catch ( e ) { @@ -607,37 +603,23 @@ CALLBACK: done`; } } ); - QUnit.test( "drooling calls across tests to assert.async callback", async assert => { - const command = "qunit drooling-done.js"; + QUnit.test( "extra call to callback outside tests", async assert => { + const command = "qunit drooling-extra-done-outside.js"; try { await execute( command ); } catch ( e ) { assert.equal( e.code, 1 ); - assert.equal( e.stderr, "" ); - - // code coverage and various Node versions can alter the stacks, - // so we can't compare exact strings, but we can spot-check - assert.true( e.stdout.includes( - "not ok 2 Test B\n" + - " ---\n" + - " message: \"`assert.async` callback from test \\\"Test A\\\" was called during this test.\"" ), e.stdout ); + assert.equal( e.stdout, expectedOutput[ command ] ); } } ); - QUnit.test( "too many calls to assert.async callback", async assert => { + QUnit.test( "too many calls to callback", async assert => { const command = "qunit too-many-done-calls.js"; try { await execute( command ); } catch ( e ) { assert.equal( e.code, 1 ); - assert.equal( e.stderr, "" ); - - // code coverage and various Node versions can alter the stacks, - // so we can't compare exact strings, but we can spot-check - assert.true( e.stdout.includes( - "not ok 1 Test A\n" + - " ---\n" + - " message: Too many calls to the `assert.async` callback" ), e.stdout ); + assert.equal( e.stdout, expectedOutput[ command ] ); } } ); diff --git a/test/main/async.js b/test/main/async.js index a784bf37f..5878cfe2b 100644 --- a/test/main/async.js +++ b/test/main/async.js @@ -113,17 +113,12 @@ QUnit.module( "assert.async", function() { assert.expect( 1 ); - // Duck-punch to force an Error to be thrown instead of a `pushFailure` call - assert.test.pushFailure = function( msg ) { - throw new Error( msg ); - }; - var overDone = assert.async(); overDone(); assert.throws( function() { overDone(); - }, new RegExp( "Too many calls to the `assert.async` callback" ) ); + }, /Tried to release async pause that was already released/ ); done(); } ); @@ -136,11 +131,6 @@ QUnit.module( "assert.async", function() { assert.expect( 1 ); - // Duck-punch to force an Error to be thrown instead of a `pushFailure` call - assert.test.pushFailure = function( msg ) { - throw new Error( msg ); - }; - var overDone = assert.async( 3 ); overDone(); overDone(); @@ -148,7 +138,7 @@ QUnit.module( "assert.async", function() { assert.throws( function() { overDone(); - }, new RegExp( "Too many calls to the `assert.async` callback" ) ); + }, /Tried to release async pause that was already released/ ); done(); } ); @@ -163,12 +153,10 @@ QUnit.module( "assert.async", function() { } ); QUnit.test( "errors if called after test finishes - part 2", function( assert ) { - - // Duck-punch to force an Error to be thrown instead of a `pushFailure` call - assert.test.pushFailure = function( msg ) { - throw new Error( msg ); - }; - assert.throws( previousTestDone, /Error: `assert\.async` callback from test "errors if called after test finishes - part 1" was called during this test./ ); + assert.throws( + previousTestDone, + /Unexpected release of async pause during a different test.\n> Test: errors if called after test finishes - part 1/ + ); } ); }() ); @@ -179,17 +167,12 @@ QUnit.module( "assert.async", function() { // internals in order to avoid post-`done` assertions causing additional failures var done = assert.async(); - // Duck-punch to force an Error to be thrown instead of a `pushFailure` call - assert.test.pushFailure = function( msg ) { - throw new Error( msg ); - }; - var overDone = assert.async(); overDone(); assert.throws( function() { overDone(); - }, new RegExp( "Too many calls to the `assert.async` callback" ) ); + }, /Tried to release async pause that was already released/ ); done(); } @@ -204,17 +187,12 @@ QUnit.module( "assert.async", function() { // internals in order to avoid post-`done` assertions causing additional failures var done = assert.async(); - // Duck-punch to force an Error to be thrown instead of a `pushFailure` call - assert.test.pushFailure = function( msg ) { - throw new Error( msg ); - }; - var overDone = assert.async(); overDone(); assert.throws( function() { overDone(); - }, new RegExp( "Too many calls to the `assert.async` callback" ) ); + }, /Tried to release async pause that was already released/ ); done(); } @@ -229,17 +207,12 @@ QUnit.module( "assert.async", function() { // internals in order to avoid post-`done` assertions causing additional failures var done = assert.async(); - // Duck-punch to force an Error to be thrown instead of a `pushFailure` call - assert.test.pushFailure = function( msg ) { - throw new Error( msg ); - }; - var overDone = assert.async(); overDone(); assert.throws( function() { overDone(); - }, new RegExp( "Too many calls to the `assert.async` callback" ) ); + }, /Tried to release async pause that was already released/ ); done(); } @@ -254,17 +227,12 @@ QUnit.module( "assert.async", function() { // internals in order to avoid post-`done` assertions causing additional failures var done = assert.async(); - // Duck-punch to force an Error to be thrown instead of a `pushFailure` call - assert.test.pushFailure = function( msg ) { - throw new Error( msg ); - }; - var overDone = assert.async(); overDone(); assert.throws( function() { overDone(); - }, new RegExp( "Too many calls to the `assert.async` callback" ) ); + }, /Tried to release async pause that was already released/ ); done(); } diff --git a/test/main/promise.js b/test/main/promise.js index d20dc47df..73956278c 100644 --- a/test/main/promise.js +++ b/test/main/promise.js @@ -204,16 +204,16 @@ QUnit.module( "Support for Promise", function() { return createMockPromise( assert, true, "this is an error" ); } ); - QUnit.test( "rejected Promise with async lock", function( assert ) { + QUnit.test( "rejected Promise with async pause", function( assert ) { assert.expect( 2 ); - assert.async(); // Important! We don't explicitly release the async lock + assert.async(); // Important! We don't explicitly release the async pause this.pushFailure = assert.test.pushFailure; assert.test.pushFailure = function( message ) { assert.strictEqual( message, - "Promise rejected during \"rejected Promise with async lock\": this is an error" + "Promise rejected during \"rejected Promise with async pause\": this is an error" ); }; From 759840b121cb2dbfce395a8f39d4a807e58d3b7c Mon Sep 17 00:00:00 2001 From: Timo Tijhof Date: Thu, 29 Jul 2021 17:09:13 +0100 Subject: [PATCH 02/10] Update src/test.js Co-authored-by: Steve McClure --- src/test.js | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/test.js b/src/test.js index 1060a3c0b..a5ba7460f 100644 --- a/src/test.js +++ b/src/test.js @@ -864,7 +864,7 @@ export function resetTestTimeout( timeoutDuration ) { // // * Pause release() is called too often, during the same test. // -// This is simply throws an error, after which uncaught error handling picks it up +// This simply throws an error, after which uncaught error handling picks it up // and processing resumes. export function internalStop( test, requiredCalls = 1 ) { config.blocking = true; From 3fb2b5cac21bb638ff132d81971b079d4d371b30 Mon Sep 17 00:00:00 2001 From: Timo Tijhof Date: Thu, 29 Jul 2021 17:14:14 +0100 Subject: [PATCH 03/10] Update src/cli/run.js Co-authored-by: Steve McClure --- src/cli/run.js | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/cli/run.js b/src/cli/run.js index fa0797ab3..4075f86e6 100644 --- a/src/cli/run.js +++ b/src/cli/run.js @@ -109,7 +109,7 @@ async function run( args, options ) { console.error( "Error: Process exited before tests finished running" ); const currentTest = QUnit.config.current; - if ( currentTest && currentTest.asyncPauses.size ) { + if ( currentTest && currentTest.asyncPauses.size > 0 ) { const name = currentTest.testName; console.error( "Last test to run (" + name + ") has an async hold. " + "Ensure all assert.async() callbacks are invoked and Promises resolve. " + From 5aae48b44c524bbc5fe821b514da8328cf9fdd73 Mon Sep 17 00:00:00 2001 From: Timo Tijhof Date: Thu, 29 Jul 2021 17:14:39 +0100 Subject: [PATCH 04/10] Add drooling-extra-done-outside.js --- test/cli/fixtures/drooling-extra-done-outside.js | 11 +++++++++++ 1 file changed, 11 insertions(+) create mode 100644 test/cli/fixtures/drooling-extra-done-outside.js diff --git a/test/cli/fixtures/drooling-extra-done-outside.js b/test/cli/fixtures/drooling-extra-done-outside.js new file mode 100644 index 000000000..433226042 --- /dev/null +++ b/test/cli/fixtures/drooling-extra-done-outside.js @@ -0,0 +1,11 @@ +QUnit.test( "extra done scheduled outside any test", assert => { + assert.timeout( 10 ); + const done = assert.async(); + assert.true( true ); + + // Later, boom! + setTimeout( done, 100 ); + + // Passing, end of test + done(); +} ); From b97a9e309604401ce5f8b47728a0e443bc79911d Mon Sep 17 00:00:00 2001 From: Timo Tijhof Date: Thu, 29 Jul 2021 17:16:40 +0100 Subject: [PATCH 05/10] Rename pause.killed to pause.cancelled --- src/test.js | 12 ++++++------ test/cli/fixtures/drooling-done.js | 5 ++++- 2 files changed, 10 insertions(+), 7 deletions(-) diff --git a/src/test.js b/src/test.js index a5ba7460f..88a4baefa 100644 --- a/src/test.js +++ b/src/test.js @@ -832,8 +832,8 @@ export function resetTestTimeout( timeoutDuration ) { // * The test fails due to an uncaught exception. // // In this case, Test.run() will call internalRecover() which empties the clears all -// async pauses and sets `killed = true`. The killed flag means we silently ignore -// any late calls to the resume() callback, as we will have moved on to a different +// async pauses and sets the cancelled flag, which means we silently ignore any +// late calls to the resume() callback, as we will have moved on to a different // test by then, and we don't want to cause an extra "release during a different test" // errors that the developer isn't really responsible for. This can happen when a test // correctly schedules a call to release(), but also causes an uncaught error. The @@ -871,13 +871,13 @@ export function internalStop( test, requiredCalls = 1 ) { const pauseId = `#${test.asyncNextPauseId++}`; const pause = { - killed: false, + cancelled: false, remaining: requiredCalls }; test.asyncPauses.set( pauseId, pause ); function release() { - if ( pause.killed ) { + if ( pause.cancelled ) { return; } if ( config.current === undefined ) { @@ -920,7 +920,7 @@ export function internalStop( test, requiredCalls = 1 ) { sourceFromStacktrace( 2 ) ); - pause.killed = true; + pause.cancelled = true; test.asyncPauses.delete( pauseId ); internalStart( test ); }; @@ -939,7 +939,7 @@ export function internalStop( test, requiredCalls = 1 ) { // Forcefully release all processing holds. function internalRecover( test ) { test.asyncPauses.forEach( pause => { - pause.killed = true; + pause.cancelled = true; } ); test.asyncPauses.clear(); internalStart( test ); diff --git a/test/cli/fixtures/drooling-done.js b/test/cli/fixtures/drooling-done.js index 945add8e4..22d53fbbc 100644 --- a/test/cli/fixtures/drooling-done.js +++ b/test/cli/fixtures/drooling-done.js @@ -10,5 +10,8 @@ QUnit.test( "Test A", assert => { QUnit.test( "Test B", assert => { assert.ok( true ); - done(); // Silently ignored since "Test A" already failed and we killed its async pauses. + + // This bad call is silently ignored because "Test A" already failed + // and we cancelled the async pauses. + done(); } ); From 5bc42c2bb6bc61652024088926f5762225cfe864 Mon Sep 17 00:00:00 2001 From: Timo Tijhof Date: Thu, 29 Jul 2021 17:44:47 +0100 Subject: [PATCH 06/10] Use pause IDs as map keys, move hash to formatted string --- src/test.js | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/src/test.js b/src/test.js index 88a4baefa..99a219302 100644 --- a/src/test.js +++ b/src/test.js @@ -869,7 +869,7 @@ export function resetTestTimeout( timeoutDuration ) { export function internalStop( test, requiredCalls = 1 ) { config.blocking = true; - const pauseId = `#${test.asyncNextPauseId++}`; + const pauseId = test.asyncNextPauseId++; const pause = { cancelled: false, remaining: requiredCalls @@ -882,15 +882,15 @@ export function internalStop( test, requiredCalls = 1 ) { } if ( config.current === undefined ) { throw new Error( "Unexpected release of async pause after tests finished.\n" + - `> Test: ${test.testName} [async ${pauseId}]` ); + `> Test: ${test.testName} [async #${pauseId}]` ); } if ( config.current !== test ) { throw new Error( "Unexpected release of async pause during a different test.\n" + - `> Test: ${test.testName} [async ${pauseId}]` ); + `> Test: ${test.testName} [async #${pauseId}]` ); } if ( pause.remaining <= 0 ) { throw new Error( "Tried to release async pause that was already released.\n" + - `> Test: ${test.testName} [async ${pauseId}]` ); + `> Test: ${test.testName} [async #${pauseId}]` ); } // The `requiredCalls` parameter exists to support `assert.async(count)` From 0969fb258104032573d2bd58bf0770931e30a192 Mon Sep 17 00:00:00 2001 From: Timo Tijhof Date: Thu, 29 Jul 2021 17:45:37 +0100 Subject: [PATCH 07/10] Move pause housekeeping up in timeoutHandler() --- src/test.js | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/src/test.js b/src/test.js index 99a219302..462e15cb2 100644 --- a/src/test.js +++ b/src/test.js @@ -915,13 +915,13 @@ export function internalStop( test, requiredCalls = 1 ) { config.timeoutHandler = function( timeout ) { return function() { config.timeout = null; + pause.cancelled = true; + test.asyncPauses.delete( pauseId ); + pushFailure( `Test took longer than ${timeout}ms; test timed out.`, sourceFromStacktrace( 2 ) ); - - pause.cancelled = true; - test.asyncPauses.delete( pauseId ); internalStart( test ); }; }; From 6f9ffea4f1b1dc3eaf72fc12d2adaaf574a495a5 Mon Sep 17 00:00:00 2001 From: Timo Tijhof Date: Thu, 29 Jul 2021 17:46:05 +0100 Subject: [PATCH 08/10] Call test.pushFailure() directly in timeoutHandler() No need to rely on global state for this. This also makes sure it is always reported under the correct test. Either way, we still get a last-minute check in pushFailure->pushResult that it is the current test. --- src/test.js | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/test.js b/src/test.js index 462e15cb2..14f9e2408 100644 --- a/src/test.js +++ b/src/test.js @@ -918,7 +918,7 @@ export function internalStop( test, requiredCalls = 1 ) { pause.cancelled = true; test.asyncPauses.delete( pauseId ); - pushFailure( + test.pushFailure( `Test took longer than ${timeout}ms; test timed out.`, sourceFromStacktrace( 2 ) ); From f7542963a875d65c42f994f786313e61ce31d64b Mon Sep 17 00:00:00 2001 From: Timo Tijhof Date: Mon, 2 Aug 2021 23:11:01 +0100 Subject: [PATCH 09/10] Move timeoutDuration inline comment back --- src/test.js | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/test.js b/src/test.js index 14f9e2408..9b29895d5 100644 --- a/src/test.js +++ b/src/test.js @@ -902,6 +902,7 @@ export function internalStop( test, requiredCalls = 1 ) { internalStart( test ); } + // Set a recovery timeout, if so configured. if ( setTimeout ) { let timeoutDuration; if ( typeof test.timeout === "number" ) { @@ -910,7 +911,6 @@ export function internalStop( test, requiredCalls = 1 ) { timeoutDuration = config.testTimeout; } - // Set a recovery timeout, if so configured. if ( typeof timeoutDuration === "number" && timeoutDuration > 0 ) { config.timeoutHandler = function( timeout ) { return function() { From fbb9e922026f4566cf14e300d830c82b6bb18f0f Mon Sep 17 00:00:00 2001 From: Timo Tijhof Date: Mon, 2 Aug 2021 23:14:32 +0100 Subject: [PATCH 10/10] Rename internal test.asyncNextPauseId to test.nextPauseId --- src/cli/run.js | 2 +- src/test.js | 22 +++++++++++----------- 2 files changed, 12 insertions(+), 12 deletions(-) diff --git a/src/cli/run.js b/src/cli/run.js index 4075f86e6..d73adbed5 100644 --- a/src/cli/run.js +++ b/src/cli/run.js @@ -109,7 +109,7 @@ async function run( args, options ) { console.error( "Error: Process exited before tests finished running" ); const currentTest = QUnit.config.current; - if ( currentTest && currentTest.asyncPauses.size > 0 ) { + if ( currentTest && currentTest.pauses.size > 0 ) { const name = currentTest.testName; console.error( "Last test to run (" + name + ") has an async hold. " + "Ensure all assert.async() callbacks are invoked and Promises resolve. " + diff --git a/src/test.js b/src/test.js index 9b29895d5..89d1cd63b 100644 --- a/src/test.js +++ b/src/test.js @@ -30,8 +30,8 @@ export default function Test( settings ) { this.timeout = undefined; this.data = undefined; this.withData = false; - this.asyncNextPauseId = 1; - this.asyncPauses = new Map(); + this.pauses = new Map(); + this.nextPauseId = 1; extend( this, settings ); // If a module is skipped, all its tests and the tests of the child suites @@ -204,7 +204,7 @@ Test.prototype = { // If the test has an async "pause" on it, but the timeout is 0, then we push a // failure as the test should be synchronous. - if ( test.timeout === 0 && test.asyncPauses.size > 0 ) { + if ( test.timeout === 0 && test.pauses.size > 0 ) { pushFailure( "Test did not finish synchronously even though assert.timeout( 0 ) was used.", sourceFromStacktrace( 2 ) @@ -869,12 +869,12 @@ export function resetTestTimeout( timeoutDuration ) { export function internalStop( test, requiredCalls = 1 ) { config.blocking = true; - const pauseId = test.asyncNextPauseId++; + const pauseId = test.nextPauseId++; const pause = { cancelled: false, remaining: requiredCalls }; - test.asyncPauses.set( pauseId, pause ); + test.pauses.set( pauseId, pause ); function release() { if ( pause.cancelled ) { @@ -896,7 +896,7 @@ export function internalStop( test, requiredCalls = 1 ) { // The `requiredCalls` parameter exists to support `assert.async(count)` pause.remaining--; if ( pause.remaining === 0 ) { - test.asyncPauses.delete( pauseId ); + test.pauses.delete( pauseId ); } internalStart( test ); @@ -916,7 +916,7 @@ export function internalStop( test, requiredCalls = 1 ) { return function() { config.timeout = null; pause.cancelled = true; - test.asyncPauses.delete( pauseId ); + test.pauses.delete( pauseId ); test.pushFailure( `Test took longer than ${timeout}ms; test timed out.`, @@ -938,10 +938,10 @@ export function internalStop( test, requiredCalls = 1 ) { // Forcefully release all processing holds. function internalRecover( test ) { - test.asyncPauses.forEach( pause => { + test.pauses.forEach( pause => { pause.cancelled = true; } ); - test.asyncPauses.clear(); + test.pauses.clear(); internalStart( test ); } @@ -949,7 +949,7 @@ function internalRecover( test ) { function internalStart( test ) { // Ignore if other async pauses still exist. - if ( test.asyncPauses.size > 0 ) { + if ( test.pauses.size > 0 ) { return; } @@ -957,7 +957,7 @@ function internalStart( test ) { if ( setTimeout ) { clearTimeout( config.timeout ); config.timeout = setTimeout( function() { - if ( test.asyncPauses.size > 0 ) { + if ( test.pauses.size > 0 ) { return; }