Improve stack trace and exception console output

[alx9r]

Note: This is my first PR. While I'm fairly confident about PowerShell and Pester, I'm a git/github novice.

---

This pull request improves the stack traces and exceptions that Pester outputs to the console. This is similar to PR #228 except that it (hopefully) addresses the concerns with that PR.

Stack trace outputs are complicated by the fact that ErrorRecord.ScriptStackTrace is not available in PowerShell 2. I did not find a good substitute for .ScriptStackTrace under PowerShell 2. Rather, I opted to use ErrorRecord.InvocationInfo to produce a single-line "stack trace" for PowerShell 2. This is the same technique as is already used in Get-PesterResult to produce TestResult.stackTrace.

The improvements of this PR over master and #228 are as follows:

• Console Output:
  • When ErrorRecord is a result of PesterAssertionFailed:
    • If .ScriptStackTrace is not available: No changes. The "Expected...But was" messages stay the same and there are no changes to the stack trace because .ScriptStackTrace is unavailable.
    • If .ScriptScriptTrace is available: The typical single line stack trace changes from eg. at line: 36 in C:\temp\scriptpath.ps1 to at <ScriptBlock>, C:\temp\scriptpath.ps1: line 36. The rest of the output is "Expected...But was", etc and remains unchanged.
  • When an exception other than PesterAssertionFailed produces the ErrorRecord:
    • Messages from exceptions are prefixed with their type name.
    • The full chain of nested exceptions are output instead of just the outer exception.
    • When .ScriptStackTrace is available the full unit-under-test stack trace is output. The lines of the stack trace that reference Pester internals are omitted.
• Implementation:
  • Adds plumbing to get .ErrorRecord into TestResult for later use. This aspect is similar to Include stack in test result output #228 which didn't seem to be a concern at that time.
  • Implements ConvertTo-FailureLines - This does the heavy-lifting of extracting, re-ordering, and formatting just the right script trace and exception details from ErrorRecord.
  • Adds call to ConvertTo-FailureLines to Write-PesterResult.

Console Output Comparison

These comparisons are using PowerShell 4.

On the left is prior to this PR. On the right is with this PR. Note the following:

• The first throws shows the full three lines of stack trace from the unit under test.
• The second throws shows the nested exceptions and name prefixes ArgumentException and FormatException.
• The should shows the slight difference in the way failed assertions are formatted.

Here is another output comparison from an integration test of a deeply nest project I'm working on. First the original output from Pester:

That is rather short and unhelpful during integration. The following is the exact same output except with this PR applied:

Note the completeness of the exceptions and stack trace. This is my motivation for this PR. It speeds iteration during integration because you get this information up-front without having to spend time setting breakpoints and stepping through code to get the same information.

Next Steps

Please tell me whether you think this PR could become a candidate for merging into master. I'm happy to put more work into improving/polishing/overhauling this PR. But I'd like to get some feedback to make sure I'm on the right track before spending more time on this.

[nohwnd]

This looks awesome. Going to test it now.

[alx9r]

@nohwnd My last commit outputs the same stack and exception trace on the console when there's an error in Context{} and Describe{} blocks too (in addition to the prior support for It{} blocks).

[nohwnd]

@alx9r sorry for not getting to it yet, I am still keeping it in mind, it's just a bit too busy at work these days. When doing additional changes you might consider squashing the changes together (easier way is to do it during interactive rebase) and then force push to your branch, it will reflect the changes here and the PR will get less messy.

[alx9r]

@nohwnd Thanks for the update and taking the time to help me with this. I've got some homework to do to understand how to squash these commits without causing problems. If it's OK with you I'll try get that done in the next week (assuming it's still possible to squash them).

[nohwnd]

@alx9r Sure, you can change the branch until it's merged. Just make sure that you sync your master with our master to avoid unexpedcted merge conflicts. If you struggle with it I can do all that for you later. For more info take a look here and here.

[briantist]

Really good stuff @alx9r !

[alx9r]

@nohwnd I followed your instructions here to squash those commits. Git didn't prompt me to resolve any conflicts, and it looks like my new single squashed commit is all that remains in this PR. It seems like that was a success.

CI also seems to be passing.

FWIW, I've put about 80 hours of PowerShell dev on this PR with no new issues. The additional traces definitely speed resolving integration test failures. I tinkered a little with exactly which stack trace lines should be output. I think the current compromise between showing too little to be useful and showing a bunch of references to Pester scriptblocks is about right.

Please let me know if there's anything else I need to do with this PR.

[nohwnd]

Awesome work, very appreciated! I will have a closer look later today hopefully.

[nohwnd]

Seems to be working great.

function tst1 {
    [math]::DivRem(10, 0 , [ref] $b)
}
function tst2 { tst1 }
function tst3 { tst2 }
function tst4 { tst3 }
function tst5 { tst4 }
function tst6 { tst5 }
function tst7 { tst6 }
function tst8 { tst7 }
function tst9 { tst8 }
function tst10 { tst9 }


Describe "tst" {
    It "does something useful" {
       tst10
    }
}

[alx9r]

Oh cool. Thanks for your help @nohwnd.