Core: hooks invoked after a test is considered torn down can cause error

[scalvert]

Tell us about your runtime:

• QUnit version: 2.9.1
• What environment are you running QUnit in? (e.g., browser, Node):* Browser & Node
• How are you running QUnit? (e.g., script, testem, Grunt): * qunit Node CLI / testem

What are you trying to do?

A test whose done hooks are attempted to be invoked after the test is considered torn down can produce an error when trying to access those hooks.

Code that reproduces the problem:

QUnit.test( "hello test", function( assert ) {
  let done = assert.async()
  assert.ok( 1 == "1", "Passed!" );
  setTimeout(done,10);
  return Promise.reject();
});

Will result in:

Uncaught Error: assert.async callback called after test finished.
    at done (qunit-2.9.1.js:3773)
qunit-2.9.1.js:3107 Uncaught TypeError: Cannot read property 'length' of undefined
    at processHooks (qunit-2.9.1.js:3107)
    at Test.hooks (qunit-2.9.1.js:3116)
    at runTest (qunit-2.9.1.js:3254)
    at advanceTestQueue (qunit-2.9.1.js:2646)
    at Object.advance (qunit-2.9.1.js:2597)
    at Test.queue (qunit-2.9.1.js:3276)
    at test (qunit-2.9.1.js:3516)
    at Object.onError (qunit-2.9.1.js:4217)
    at window$1.onerror (qunit-2.9.1.js:5499)

Codepen: https://codepen.io/rwjblue/pen/KJLQEJ

If you have any relevant configuration information, please include that here:

What did you expect to happen?

Trying to access hooks on an already torn down test should not result in an error.

What actually happened?

An error was thrown when trying to access hooks on a module. At this point, hooks has already been torn down.

[trentmwillis]

The description here was a bit confusing to me, so I looked into this some more and I'm not sure the reproduction is a minimal repro.

I believe the error which needs to be fixed here is the Uncaught TypeError: Cannot read property 'length' of undefined and not the Uncaught Error: assert.async callback called after test finished.

If that is the case, it appears the error occurs anytime an assertion happens after an error (or rejected promise) has occurred within a test. You can find a smaller reproduction here which is the following:

QUnit.test( "assertion after errored test", function( assert ) {
  setTimeout(() => assert.ok(true), 10);
  return Promise.reject();
});

For some reason, when this happens QUnit is trying to invoke the test's module hooks (e.g., before, afterEach, etc.) which have been unset and thus leads to the error.

[scalvert]

I believe the error which needs to be fixed here is the Uncaught TypeError: Cannot read property 'length' of undefined

This is absolutely correct. If you look at the codepen and open the console, you can see that this error is ultimately thrown, albeit later in the execution (when the module's hooks are being run).

That minimal repro looks better :)

[scalvert]

Also, I had a tricky time trying to devise a reasonable test to guard against this regressing. I'm open to suggestions on how to make this better.

[Krinkle]

I've been looking into this a little and dumping here what I've got so far.

Test fails normally at first

The test case from Trent still fails more or less the same way today with qunit 2.14.1. The Promise.reject is returned asynchronously and this essentially makes the test known-asynchronous by the time the test callback ends. The runTest chain internally waits for the next microtask, it is correctly marked as failure and with the correct failure message from the rejected Promise. The test is then torn down despite there being a known unfulfilled assert.async() callback. This makes sense I think because if a test throws an exception or rejects itself in this way, we should not time out since we have no reason to believe anything else will come.

Test and module teardown

After this, because it is the last test in the module, the module teardown happens as well. This clears out module.hooks to an empty object, which is our safety measure to make sure hooks really can't be called after this point. If we removed this safety measure we'd not have the uncaught TypeError: Cannot read property 'length' of undefined on the console. But, that would merely hide the problem of course rather than solve it.

Report "global failure"

Then, when the setTimeout is scheduled, the assert.async() code throws an error because it relates to a test that has already ended. So far so good. It throws a descriptive error, which will appear in - what is now - the global scope. Thus we reach window.onerror and QUnit.onError, and we're about to report a "global failure". So far so good.

Now, the way QUnit.onError wants to report this "global failure" is by calling test( "global failure", … ); to insert a new last-minute test into the run, with a failed assertion under it to provide the details of the error. The problem is... under what module should we host this new Test?

If the test suite in question doesn't have any global tests, and uses a scoped module, then the "module teardown" that happened previously will have been the one specific to that scoped module. Thus we'd now be implicitly idling in the global module, and adding a test there is fine at this point since that module never existed/began until now, so it'll be begin, run this new test, and then teardown just fine.

But.. if the test suite did have some global tests earlier, or if the failing test itself is the last one in the global module, then the global module too will have closed by now. In which case QUnit.onError has nowhere to go with this, but neither it nor QUnit.test know about this, so they just append it to the global module anyway, and when it becomes its turn in the process queue to start, it can't since module.hooks has been closed already.

Re-opening a closed test suite

In earlier versions of QUnit, it was (unofficially) allowed on in our HTML runner to keep running tests from the console and we'd just keep appending them to the screen as if nothing is wrong. Internally this wasn't great, because it meant QUnit.done() - which must only run once - had already run, so these additional tests weren't "really" part of it if this had been e.g. an automated run from CI, it would have already heard the signal that it's over and closed the browser or otherwise stopped listening. There are still some cases where this can be abused, and our our internal tests sometimes use this limited window to e.g. run a test from within QUnit.done() and then have one more done() call after that.

Over time we've tried to restrict this since it's unprectable whether these end up reported or not in a CI context. You should only be able to end a run once, right?

Good news – I'm not 100% sure sure, but it seems unlikely that this could cause a false positive. The kinds of situations that result in these errors seem like things we can and do already detect. It's just that if two of these things happen, we tend to want to move on and not wait for any other possible failures, so any second problem might end up not reported back to CI if it happens after the test suite has already finished.

Bad news - We should not internally crash under these circumstances. And in addition to it being confusing when running QUnit in your browser directly, it can also at times show up in CI if it happens quick enough before the browser is shutdown.

I think perhaps the right thing to do here is to have QUnit.test() throw an Error if it's adding a test to an already closed module. Except of course this makes the problem recursive, since QUnit.onError will also find this one.

Some ideas

1. We could let QUnit.onError not try to report as a test failure and let the runtime (e.g. browser, node.js) handle it as an uncaught error. So in browsers this would mean we get Uncaught Error: assert.async callback called after test finished. in the console only. Basically the same as today, since it already doesn't succeed getting to the screen. And this would avoid the second failure we trigger currently, where module.hooks[handler] undefined happens when we call test() from onError().
2. We could change QUnit.onError to create its own module() and test(). We already distinguish between adding an assertion to a current test vs adding a new test. We could extend this furhter and also add a new module if the current module has closed already. But.. I'm not sure that this condition is actually possible since afaik we are never "between" modules. We may be briefly in a parent or global module, but we're never outside one, except if the global one has already been torn down. But, in that case QUnit.done() has been called already and we should not add new modules after that. We could do the native runtime error handling fallback after trying that, but I think that's bascially the same as point 1, since any other outcome seems impossible.

[Krinkle]

Nice short repro in #1592 by @smcclure15:

Run on latest QUnit 2.15.0 via CLI:

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

The first half of the run looks good:

TAP version 13
not ok 1 demo
  ---
  message: Test took longer than 10ms; test timed out.

It's correctly reported via the TAP output, but the process continues, and that "done" is finally executed, which throws this:

/<SNIP>/qunit.js:2312
        if (module.hooks[handler].length) {

TypeError: Cannot read property 'length' of undefined
    at processHooks (/<SNIP>/qunit.js:2312:35)
    <SNIP>

[Krinkle]

As part of fixing this, I'll have to convert the callbacks.html and events.html test cases to use TAP outputs instead, as their unofficial use of testing inside QUnit.done() would result in failures now. It took me a while to realize what was going on, because grunt-contrib-test was not making these as failed, but rather remained stuck indefinitely because its timeout option stopped working, and our own timeout did not help us here because we're after the end of QUnit.done where no timeout is applied to our internal code. There is just an uncaught error reported to the build output, but the task wouldn't exit. (Ref gruntjs/grunt-contrib-qunit#179.)