New test reporter hook

[ventuno]

Idea

Introduce a new Test Reporter hook (e.g.: beforeTestEnd) that is triggered when a test ends but before after* hooks are triggered.

Context

Recently I found myself trying to improve the logging of failed tests, in particular tests failing non-deterministically (e.g.: flaky).
The idea is to provide the ability log (together with the failed assertion) the information about the environment when the test run completes.
Take an Ember component as an example, one might want to log additional information like:

1. the content of the Mirage db;
2. the components' hierarchy: similar to the one provided by Ember Inspector with the ability to see the values of properties when a failure occurred;
3. the value of properties set in the test environment.

The above is currently impossible because testDone/testEnd hooks are triggered after after* hooks which is normally used to clean up the test environment for the next test to run. So accessing QUnit.config.current.testEnvironment in testDone/testEnd does not provide any useful information.

Proposed solution

Test frameworks cannot obviously provide any framework-specific functionality, but can provide the test environment information when reporting so that 3rd party test reporters built on top of the common js-reporters interface.
My proposal is to introduce a new hook beforeTestEnd hook (not sure if we would need a beforeSuiteEnd as well) which is called before after* hooks and passes the testEnvironment (when available) as an argument.

Ideally this should be part of the js-reporters standard, but I wanted to introduce the idea to the QUnit community first.

@Krinkle / @trentmwillis thoughts?

[ventuno]

@Krinkle / @trentmwillis: #1480 is a WIP on how this would work. I hope this provides more clarity.

[Krinkle]

Thanks @ventuno. I think this seems out of scope for reporting events, which are meant to be async, deterministic and react only to the information given to them.

I like your use case though, and hope this is something we could make work within the QUnit runtime. For example, through the after or afterEach hooks. Would that work? If so, I think we could create or document ways to make it easier to register those for Ember's test runner. I've iterated on a number of ways to do this for the QUnit test suite of Wikimeida software (MediaWiki, and VisualEditor) which worked fairly well.

[ventuno]

Thanks for looking into this @Krinkle. A function call in the afterEach hook of a QUnit module is currently how I'm achieving this. Unfortunately there are a few issues with this approach:

1. lack of ergonomics: the only way for this to work is to call the function that logs the test status into the module's afterEach hook. This means that for existing (large) code bases you have to add the function call to each individual module, which is not very scalable (moreover you have to remember to add it to each new individual module). Notice that this is the only option because you want to call the logging function in the innermost afterEach hook otherwise some of the status could be cleaned up by some other call to afterEach. This means that something à-la setupRenderingTest (to further the Ember example) cannot be used either;
2. all in all it's a hacky solution, in my current implementation based on the afterEach hook I need to:
   a) on afterEach: check if the test failed (I need also to determine that the test failed by myself by checking the assertions array); serialize the test status and add it to a map (indexed by testId) attached to the window object;
   b) on testDone: check the map on the window object and emit the testEnd event passing in the extra information (I rely custom test reporter, (tests are run by testem) so that the test status can be logged to the console (or saved to a file).

Does that make sense?

[Krinkle]

@ventuno Absolutely! I wanted to understand if the timing and overall contract of afterEach would suit your needs. I agree we would need to make this much simpler indeed.

The way I've handled this in projects myself is by wrapping the module function, like so:

const orgModule = QUnit.module;
let nested = false;
QUnit.module = function (name, executeNow) {
  if (nested || typeof executeNow !== 'function') {
    // Ignore nested modules, already inherits parent hooks.
    // Ignore non-scoped modules.
    return orgModule.apply(this, arguments);
  }
  const orgExecute = executeNow;
  executeNow = function (hooks) {
    hooks.beforeEach(function () {
      // Do global setup, e.g. sinon sandbox, app fixtures, etc.
    });
    hooks.afterEach(function () {
      // Do global teardown, e.g. restore sandbox, or assert zero open transactions.
    });
    nested = true;
    const ret = orgExecute.apply(this, arguments);
    nested = false;
    return ret;
  };
  return orgModule(name, executeNow);
};

This reduces the "hackiness" factor by a lot, but remains rather hacky still.

Perhaps an officially supported "global hook" would make sense. E.g. a way to implicitly add before, beforeEach, after, afterEach to all modules. That would also give you the future space for a "per suite" hook as you were hinting at.

In terms of ergonomics, I imagine it could work something like this:

QUnit.hooks.afterEach((assert) => {
 /* … */
});

[rwjblue]

Recently I found myself trying to improve the logging of failed tests, in particular tests failing non-deterministically (e.g.: flaky).

FWIW, ember-qunit's test isolation validation should make this much better.

[rwjblue]

@Krinkle - In order to implement that we ultimately did end up monkey patching QUnit.config.current.finish, we made some detailed notes on why we went this route (obviously monkey patching is not great):

We looked at using:

• afterEach - the ordering of when the afterEach is called is not easy to guarantee (ancestor afterEaches have to be accounted for too)
• QUnit.on('testEnd') - is executed too late; the test is already considered done so we're unable to push a new assert to fail the current test
• 'QUnit.done' - it detaches the failure from the actual test that failed, making it more confusing to the end user.

https://github.com/emberjs/ember-qunit/blob/57c3327d1e3402b92afbfa067ab91d5428817807/addon-test-support/test-isolation-validation.js#L62-L77

[ventuno]

Thanks @Krinkle, something like the proposed QUnit.hooks.afterEach() would be a great start, but would still require some hacky solution if I wanted to log the "additional information" to a file (e.g.: think of testem TAP reporter). I wonder if we can find a solution that other frameworks could leverage without having to hack their way around.

[Krinkle]

@rwjblue I'd love to know if the global QUnit.hooks is suitable for ember-qunit in its current state. Its handlers should be reliably the first for beforeEach and last afterEach, independent of when or how a module and parent module's hooks are registered.

@ventuno I suggest we add QUnit.hooks.beforeAfterEach() for the testem use case. The name isn't great, but I think it captures best what we're trying to do. And unlike event callbacks, these are logically meant to be part of and be able to inspect and/or influence the test run.