Test runner executes after() in declared order

Version

v18.16.0

Platform

Linux tester 5.15.0-75-generic #82-Ubuntu SMP Tue Jun 6 23:10:23 UTC 2023 x86_64 GNU/Linux

Subsystem

test_runner

What steps will reproduce the bug?

test("mytest", async (t) => {
	t.after(async () => { console.log("this is declared first"); });
	t.after(async () => { console.log("this is declared next"); });
	t.after(async () => { console.log("this is declared last"); });
});

How often does it reproduce? Is there a required condition?

Always.

What is the expected behavior? Why is that the expected behavior?

I would expect the after functions to be executed in reverse order:
ℹ this is declared last
ℹ this is declared next
ℹ this is declared first
✔ mytest (3.16807ms)

What do you see instead?

ℹ this is declared first
ℹ this is declared next
ℹ this is declared last
✔ mytest (3.16807ms)

Additional information

Various frameworks provide setup / teardown before and after a test. Usually its desired to perform setup in declared order but teardown in reverse order. This is very convenient because there maybe inter-dependencies. Consider the contrived example of:

Create browser instance.
Create incognito context.
Create browser tab.
Do tests inside tab.

Once the test ends, regardless of success/failure these should then be torn down in reverse order:

Destroy browser tab.
Destroy incognito context.
Destroy browser instance.

If after() was executed in reverse order, setup and teardown could be conveniently written as below, providing clean teardown regardless at which point setup failed:

test("mytest", async (t) => {
	const browser = await create_browser_instance();
	t.after(() => destroy_browser_instance(browser));
	const context = await create_incognito_context(browser); // if this fails, browser will still be terminated.
	t.after(() => destroy_incognito_context(context));
	const tab = await create_browser_tab(context); // if this fails, context will still be destroyed and browser terminated.
	t.after(() => destroy_browser_tab(tab));
	// your test here
});

However, not only is after() executed in declared order, subsequent after() are skipped entirely. I also discovered after() eating the reported error, leaving a very confused developer as to why his test failed with nothing but this as output:
▶ Mytest
✔ subtest 1 (17.906258ms)
✔ subtest 2 (32.88647ms)
✔ subtest 3 (21.395154ms)
✔ subtest 4 (27.778948ms)
▶ Mytest (242.726795ms) <-- Red triangle, nothing else.

ℹ tests 1
ℹ pass 0
ℹ fail 1
ℹ cancelled 0
ℹ skipped 0
ℹ todo 0
ℹ duration_ms 361.519968

It took a lot of digging to figure out that the first after() was trying to destroy something that was still in use.

To perform teardown in the correct order I'll have to do it manually:

test("mytest", async (t) => {
	const ctx = {};
	t.after(async () => {
		if (ctx.tab) {
			await destroy_browser_tab(ctx.tab);
		}
		if (ctx.context) {
			await destroy_incognito_context(ctx.context);
		}
		if (ctx.browser) {
			await destroy_browser_instance(ctx.browser);
		}
	});
	ctx.browser = await create_browser_instance();
	ctx.context = await create_incognito_context(ctx.browser);
	ctx.tab = await create_browser_tab(ctx.context);
	// your test here
});

Which makes me wonder why even bother with after() since try {} catch {} finally {} provides the same functionality.

@MoLow

Hey @MoLow ,
I would like to work on this issue of changing the order of the after() hook in the test_runner. I understand that this is a relatively simple change, but I would like to make sure that I am doing it correctly.
Is there anything I need to keep in mind while working on this?

I am not sure this is a simple change
and I am not convinced changing the current behavior is the correct thing to do

I'm hesitant to add this rather than just ship a defer utility on top of Symbol.dispose/asyncDispose

Mocha runs afterEach hooks in reverse order:

Mocha runs after in fifo order though:

describe("something", () => {
    after(() => console.log(1))
    after(() => console.log(2))
    after(() => console.log(3))
    it("foos", () => {});
})

Would log 1,2,3 and not 3,2,1

And so does Jest (with afterAll, in a much slower fashion and with more verbose output) with the default modern runner. The legacy runner (and jasmine in standalone) does log 3,2,1 but it doesn't seem to be the standard order.

I don't think we should change this. Running them in reverse order is, IMO, more mental overhead for users.

If I cannot use t.after, how to perform test-specific cleanup / teardown?

I don't understand this. I use the test runner's hooks to clean up after my tests all the time. If the issue is that you're expecting the after()s to be run in reverse order, then you can reverse the order of the after()s in your code and that should solve the problem?

also, you can use a single after and run code inside it in whatever order you want. that is inherent to the language, and depending on hooks running in a specific order (that is documented nowhere) seems a lot more magical to me than a single hook running code in whatever order it desires

If I cannot use t.after, how to perform test-specific cleanup / teardown? Wrap the entire test in a try ... finally? Performing teardown inside the actually test introduces non-test related overhead to timing results.

I'm wondering if we should abort a test context's AbortController on test completion and not just cancellation to allow this:

test("mytest", async ({ signal }) => {
	const browser = await createBrowserInstance({ signal });
	const context = await createIncognitoContext(browser, { signal });
	const tab = await createBrowserTab(context, { signal });
	// your test here
});

Not entirely related to this issue. (Also it's kind of besides the point but in that specific case it's fine to just close the browser since it owns the context and the tab which would also be closed with it.)

I see what you mean now. Essentially, you want to write your test like this and have the after() hooks run in reverse order:

test("mytest", async (t) => {
  const browser = await create_browser_instance();
  t.after(() => destroy_browser_instance(browser));
  const context = await create_incognito_context(browser);
  t.after(() => destroy_incognito_context(context));
  const tab = await create_browser_tab(context);
  t.after(() => destroy_browser_tab(tab));
});

It's still not a change that I would make, but I guess we can see how others feel.

@MoLow

It's still not a change that I would make, but I guess we can see how others feel.

Both mocha and Jest do it the same way we do with Jest even switching from reverse-order to fifo order so I doubt we should change it but I do see the use case and think we should address it.

How would you feel about the abort signal being passed to the test context always aborting when a test (or suite) completes and not just when they are cancelled? ( also cc @MoLow )

How would you feel about the abort signal being passed to the test context always aborting when a test (or suite) completes and not just when they are cancelled?

I think it makes sense. If anything was listening to that signal, it should abort at that point anyway.

@benjamingr

How would you feel about the abort signal being passed to the test context always aborting when a test (or suite) completes and not just when they are cancelled?

@benjamingr how would it solve the problem outlined here?

@benjamingr

@benjamingr how would it solve the problem outlined here?

You would use the signal for cleanup instead of after hooks like so #48736 (comment)

Yeah, I realized it later 😅

Not possible to perform global setup before the first test.
Not possible to perform global cleanup after the last test.

Does --import not work for that case? Or putting it in a global after/before?

Would docs/a guide showing how to run setupTests like logic help?

#48877 doesn't solve the termination problem because the test runner believes tests are still running.

Can you repro?

Suites are executed sequentially, always.

What do you mean sequentially?

Errors thrown in after() prevents execution of subsequent after() calls.

Happy to discuss this, I don't think it was raised before?

All forms of after() are executed in declared order.

Sure, though did the workaround with signal we changed not solve the problem?

Navigation Menu

Repository navigation

Test runner executes after() in declared order #48736

Version

Platform

Subsystem

What steps will reproduce the bug?

How often does it reproduce? Is there a required condition?

What is the expected behavior? Why is that the expected behavior?

What do you see instead?

Additional information

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Test runner executes after() in declared order #48736

Description

Version

Platform

Subsystem

What steps will reproduce the bug?

How often does it reproduce? Is there a required condition?

What is the expected behavior? Why is that the expected behavior?

What do you see instead?

Additional information

Activity

pulkit-30 commented on Jul 15, 2023

MoLow commented on Jul 16, 2023

benjamingr commented on Jul 16, 2023

benjamingr commented on Jul 16, 2023

benjamingr commented on Jul 16, 2023

cjihrig commented on Jul 16, 2023

cjihrig commented on Jul 16, 2023

MoLow commented on Jul 16, 2023

benjamingr commented on Jul 16, 2023

cjihrig commented on Jul 16, 2023

benjamingr commented on Jul 16, 2023

cjihrig commented on Jul 16, 2023

rluvaton commented on Jul 17, 2023

benjamingr commented on Jul 19, 2023

rluvaton commented on Jul 19, 2023

benjamingr commented on Aug 1, 2023

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions