Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Produce clearer, contextual failures when assert.async callbacks are called incorrectly #1595

Closed
wants to merge 18 commits into from

Conversation

smcclure15
Copy link
Member

When the assert.async callback is invoked outside of its originating tests, we can issue a better message showing what test it came from. This is true for when it is called in another test (and we leverage pushFailure) or after all tests have run (and we throw new Error).

This was done in tandem with removing the global onError handler condition where we were outside of tests, instead of making a new "fake" or "placeholder" sort of test on the fly to report those errors, which caused more issues down the line since that was unexpected as far as "hook lifecycles" are concerned.

A few prior issues contain some key use cases, which highlight the user-facing differences...

From #1377

Repro:

QUnit.test( "demo", assert => {
	assert.timeout( 10 );
	const done = assert.async();
	assert.true( true );
	setTimeout( done, 20 );
} );

Current Behavior

CLI

TAP version 13
not ok 1 demo
  ---
  message: "Test took longer than 10ms; test timed out."
  severity: failed
  actual  : null
  expected: undefined
  stack:     at listOnTimeout (internal/timers.js:554:17)
    at processTimers (internal/timers.js:497:7)
  ...
1..1
# pass 0
# skip 0
# todo 0
# fail 1
/SNIP/qunit.js:2352
        if (module.hooks[handler].length) {
                                  ^

TypeError: Cannot read property 'length' of undefined
    at processHooks (/SNIP/qunit.js:2352:35)
    at Test.hooks (/SNIP/qunit.js:2361:9)
    at runTest (/SNIP/qunit.js:2498:43)
    at advanceTestQueue (/SNIP/qunit.js:1913:20)
    at Object.advance (/SNIP/qunit.js:1863:7)
    at Test.queue (/SNIP/qunit.js:2516:25)
    at test (/SNIP/qunit.js:2743:13)
    at Object.onError (/SNIP/qunit.js:3434:7)
    at process.<anonymous> (/SNIP/qunit/src/cli/run.js:107:9)
    at process.emit (events.js:315:20)

Browser

Same test results, but with errors in console:

qunit.js:3005 Uncaught Error: assert.async callback called after test finished.
    at done (qunit.js:3005)
qunit.js:2352 Uncaught TypeError: Cannot read property 'length' of undefined
    at processHooks (qunit.js:2352)
    at Test.hooks (qunit.js:2361)
    at runTest (qunit.js:2498)
    at advanceTestQueue (qunit.js:1913)
    at Object.advance (qunit.js:1863)
    at Test.queue (qunit.js:2516)
    at test (qunit.js:2743)
    at Object.onError (qunit.js:3434)
    at window$1.onerror (qunit.js:5472)

Proposed Behavior

CLI

TAP version 13
not ok 1 demo
  ---
  message: Test took longer than 10ms; test timed out.
  severity: failed
  actual  : null
  expected: undefined
  stack: |
        at listOnTimeout (internal/timers.js:554:17)
        at processTimers (internal/timers.js:497:7)
  ...
1..1
# pass 0
# skip 0
# todo 0
# fail 1

Browser

Same test results, but this is shown in console:

qunit.js:2965 Uncaught Error: `assert.async` callback from test 'demo' called after tests finished.
    at done (qunit.js:2965)

From #1432

Repro:

QUnit.module('Trailing failures on exception', {
  afterEach: assert => {
    let done = assert.async();
    setTimeout(done, 50);
  }
}, function () {
  QUnit.test('Test A', assert => {
    assert.ok(true);
    let done = assert.async();
    setTimeout(done, 10);
    throw new Error('oops');
  });
  QUnit.test('Test B', assert => {
    assert.ok(true);
  });
});

Current Behavior

CLI

TAP version 13
not ok 1 Trailing failures on exception > Test A
  ---
  message: "Died on test #2     at Object.<anonymous> (/SNIP/demo.js:7:9): oops"
  severity: failed
  actual  : null
  expected: undefined
  stack: Error: oops
    at Object.<anonymous> (/SNIP/demo.js:11:11)
  ...
not ok 2 Trailing failures on exception > Test B
  ---
  message: "assert.async callback called after test finished."
  severity: failed
  actual  : null
  expected: undefined
  stack: undefined:undefined
  ...
1..2
# pass 0
# skip 0
# todo 0
# fail 2

Browser

The second test fails with "script error" and "stack: 0", and with console errors:

qunit.js:3005 Uncaught Error: assert.async callback called after test finished.
    at done (qunit.js:3005)

Proposed Behavior

CLI

TAP version 13
not ok 1 Trailing failures on exception > Test A
  ---
  message: "Died on test #2     at Object.<anonymous> (/SNIP/demo.js:7:9): oops"
  severity: failed
  actual  : null
  expected: undefined
  stack: |
    Error: oops
        at Object.<anonymous> (/SNIP/demo.js:11:11)
  ...
not ok 2 Trailing failures on exception > Test B
  ---
  message: "`assert.async` callback from test 'Test A' was called during this test."
  severity: failed
  actual  : null
  expected: undefined
  stack: |
        at listOnTimeout (internal/timers.js:554:17)
        at processTimers (internal/timers.js:497:7)
  ...
1..2
# pass 0
# skip 0
# todo 0
# fail 2

Browser

The test failures are reported the same as above CLI, and the console is empty.

@smcclure15 smcclure15 changed the title Issue clearer and contextual failures when assert.async callbacks is called incorrectly Produce clearer, contextual failures when assert.async callbacks are called incorrectly Apr 16, 2021
@Krinkle
Copy link
Member

Krinkle commented Apr 16, 2021

Looking good! 👍

Took a quick peek at the failing Node 10 run:

not ok 28 CLI Main > assert.async > drooling calls across tests to assert.async callback
  ---
  message: failed
  severity: failed
  actual  : |+
    TAP version 13
    not ok 1 Test A
      ---
      message: |+
        Died on test #2     at Object.<anonymous> (/qunit/test/cli/fixtures/drooling-done.js:5:7)
-            at internal: this is an intentional error
+            at internal
+            at run (/qunit/src/cli/run.js:79:5): this is an intentional error

That smells like it might be a combination of Node 10 having slightly different output, and my newly-added normalization logic being imperfect. Might be worth turning that off locally to see what's underneath. I'm hoping there's a straight-forward way to improve the normalization since I'd really not like to go back to pattern matching, but we may have to for a few tests, perhaps as interim solution and then we could try to fix normalize later (or get away with pattern matching until we drop Node 10 late this year, maybe with QUnit 3.0).

Comment on lines -20 to -27
} else {
test( "global failure", extend( function() {
pushFailure(
error.message,
error.stacktrace || error.fileName + ":" + error.lineNumber,
...args
);
}, { validTest: true } ) );
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I have to self-flag this, after some more thorough bashing. Here's my counter-example:

QUnit.module( "foo", function() {
    QUnit.test('hello', assert => {
        assert.ok(1);
    });
    throw new Error("oops");
} );

In the current release, that shows a console error with Uncaught Error: oops, but it also shows a "global failure" as script error. In this PR, you see the console error, but otherwise a passing test in the report. That is a no-go, and I will re-work this.

@smcclure15
Copy link
Member Author

I'm trying to merge #1599 back in, given there's a bunch of overlap, but I'm really wrestling with the churn.
I will favor closing this and then starting with a clean slate... I don't want to bombard others with updates and this still requires more pragmatic investigations and polish here.

@smcclure15 smcclure15 closed this Apr 28, 2021
@smcclure15 smcclure15 deleted the async-drool branch September 20, 2021 20:33
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Development

Successfully merging this pull request may close these issues.

None yet

2 participants