AfterEach is run before After hook

[schoepke]

Describe your problem

According to the docs on execution life cycle, the "afterEach" hooks should be run after any "after" hooks. However, the order is reversed.

What command line options do you use?

        val process = ProcessExecutor().command(
            dreddCommand,
            apiDefinitionFile.toString(),
            "http://127.0.0.1:${app.servers[0].port}",
            "--hookfiles=$hookFile",
            "--output=$outputPath/${outputFile.fileName}",
            "--reporter=xunit",
            //"--details",
            //"--level=debug",
            "--header=Authorization:Bearer $token",
            "--custom=rexchOfferId:${app.fixtures.rexOffer.id}",
            "--custom=saschaOfferId:${app.fixtures.saschaOffer.id}",
            "--custom=saschaBidId:$bidBySaschaId",
            "--custom=locationId:${app.fixtures.brunnenstr.id}",
            "--custom=locationHashOfState:${app.fixtures.brunnenstr.hashOfStateAsString()}",
            "--custom=ghostBidId:$bidByGhostId",
            "--custom=martinBidId:$bidByMartinId",
            "--custom=logoffToken:$logoffToken",
            "--custom=logoffToken2:$logoffToken2",
            "--custom=expiredLogoffToken:$expiredLogoffToken"
        )

What is in your dredd.yml?

none

What's your dredd --version output?

dredd v5.1.11 (Windows_NT 10.0.17134; x64)

Does dredd --level=debug uncover something?

Verbose level suffices to show it.
I also verified simply by adding hooks.log() calls in one "afterEach" and one "after" hook function.
My failing test log output (excerpt):

verbose: Processing transaction #8: authentication > /logoff > Invalidate Current Session/JWT > 401 > application/json; charset=utf-8
verbose: Running 'beforeEach' hooks
verbose: Running 'before' hooks
verbose: About to perform an HTTP request to the server under test: GET http://127.0.0.1:63475/logoff
verbose: Handling HTTP response from tested server
verbose: Running 'beforeEachValidation' hooks
verbose: Running 'beforeValidation' hooks
verbose: Validating HTTP transaction by Gavel.js
verbose: Running 'afterEach' hooks
hook: clearing test data cache (1 entries)
verbose: Running 'after' hooks
hook: GET (401) /logoff :: accessing test data cache (key=transaction.id): undefined
fail: GET (401) /logoff duration: 4ms

This showcases how the bug affects me: I store some data during the "before" hook for some transaction. I use this to do some test mutations, needed because the endpoint may return different error messages for the same error code, and I want to test this.
I implemented this with a simple object (the test cache) which is cleared after each transaction.
The data should still be accessible during the "after" hooks, but they're not, because the cache has been cleared prematurely by my "afterEach" hook.

I can work around this by putting the clear in the "beforeEach" hook, but nonetheless, I consider this either a documentation error or a bug. Whether the order of the "after*" life cycle hooks should be reversed from the "before*", is a design question I guess, imho "after" should come before "afterEach". If the code is correct, at least it needs to be documented and explained.

Can you send us failing test in a Pull Request?

This should be trivial to reproduce, the code causing this is transaction-runner.js:111

[honzajavorek]

Hi @schoepke, I'm sorry for answering after such a long time. This somehow slipped through my radars and now I found it during regular triaging.

Thank you for pointing this out. It's a serious discrepancy! The docs really say after is executed first and then afterEach. You are completely right that this needs to be fixed either in code or documentation.

Another documentation for Dredd hooks is here:

• after called after some specific HTTP transaction regardless its result
• afterEach called after each HTTP transaction
• afterAll called after whole test run

This again indicates after is executed before afterEach. We have this test which verifies the order for hook handler implementations in other languages:

0 ... before all modification
1 ... before each modification
2 ... before modification
3 ... before each validation modification
4 ... before validation modification
5 ... after modification
6 ... after each modification
7 ... after all modification

Thus I think all historical records and all implementations in other languages indicate the intention was to have after executed before afterEach.

This means it is a bug in the code 😱