Errors during AfterEach block obscure errors encountered during an It block

tomcart90 commented 4 years ago

1. General summary of the issue

I'd been using an AfterEach block to assert that certain mock functions were called for all tests within a Describe block. One of the tests started to fail due to a bug in our production code, however this failure was obscured from us and instead the error we received came from the assertion in the AfterEach block due to one of the mock functions not being called when expected. Both of these errors were symptoms of the bug we had in our production code, however the first error was the more useful of the two. It seemed to me that actually both errors should have been presented to me, but the first was always lost.

After reading: https://github.com/pester/Pester/wiki/BeforeEach-and-AfterEach I realise that I'm possibly abusing the use of AfterEach in that I'm making assertions within that block rather than simply performing clean-up tasks. However that's not entirely clear from the documentation, and losing an error in this way makes debugging much harder.

This issue is fairly easy to reproduce with the following code:

Describe "Desc" {
    AfterEach {
        $false | Should -BeTrue
    }
    It "It" {
        $true | Should -BeFalse
    }
}

When executed produces the following output:

Describing Desc
    [-] It 96ms
      at <ScriptBlock>, <path to test file>: line 5
      5:         $false | Should -BeTrue
      Expected $true, but got $false.

Showing only the error raised in the AfterEach block.

2. Describe Your Environment

Pester version : 4.8.1 C:\Program Files\PowerShell\Modules\Pester\4.8.1\Pester.psd1 PowerShell version : 6.1.2 OS version : Microsoft Windows NT 10.0.18362.0

3. Expected Behavior

Documentation made clear that BeforeEach/AfterEach blocks should not be used for assertions, and that any error raised within these blocks may obscure actual test results.
In situations like this were multiple errors are raised keep a record of those errors and report them all at the end of test execution.

4.Current Behavior

Documentation around BeforeEach/AfterEach isn't entirely clear regarding the use of assertions and the effect of errors raised within these blocks.
Only the last error raised during test execution is output.

5. Possible Solution

The problem and therefore solution are twofold here. I think the documentation around BeforeEach/AfterEach could be improved if the intention is that they should ONLY perform setup/teardown activities and that any errors raised within an AfterEach block may obscure actual errors raised during test execution.

Storing and reporting all errors encountered during test execution would make debugging an issue such as this much easier.

6. Context

This issue resulted in a production code issue taking longer to debug than was necessary as we were only receiving the error reported in the AfterEach block, not that which was reported within the It block.

nohwnd commented 4 years ago

Thank you for raising this issue. I think that going with the second option of reporting multiple errors, if they happen is a better way to go. This is useful in both described cases:

when a legitimate code clean up fails after a test failure
when assert fails in AfterEach (as you descibed)

It is true that AfterEach block is primarily meant to do clean ups, but I am sure there are situations when putting assertion in it is beneficial. In any case I can't prevent you from putting the assertion there, because I don't have any control over the scriptblock you provide. 🙂

In Pester v5 we are also adding "compound assertions" that will report all assertion failures from a block unless you specify -ErrorAction Stop, so the infrastructure to do this is already there. What needs to be added is additional info that identifies the block the error was raised from (which I don't think is needed for the first iteration, and is not particularly easy to do), and that should be it.

I am adding this to the v5.x milestone, but expect this to be at least partially tackled in the initial release of v5, because it aligns well with how the internal runtime handles errors right now.

tomcart90 commented 4 years ago

Fantastic, thanks @nohwnd! Let me know if I can be of assistance in verifying your changes.

nohwnd commented 4 years ago

It's on a good way :)

nohwnd commented 4 years ago

Closing this as fixed because the code is now merged in the v5.0 branch.

pester / Pester