Get-PesterResult is broken in Beta

[Jaykul]

You're accepting $Test as a [ScriptBlock] and then trying to use $test.File in the phoney stacktrace.

Should probably just use $Exception.ScriptStackTrace or call Get-PSCallStack or something.

The result is that any time there's an exception, the error printed says "at line: $line in " with no file name.

[Jaykul]

OK, after looking at this, that function is totally useless in the current code. From It.ps1:

    $Result = Get-PesterResult -Test $Test -Exception $PesterException
    $Pester.AddTestResult($Result.name, $Result.Success, $null, $result.failuremessage, $result.StackTrace )
    $Pester.testresult[-1] | Write-PesterResult

As it stands, there's no reason to have Get-PesterResult. that I can see, the little work that it's doing to calculate the message could be done in AddTestResult instead and that would simplify the code here.

[dlwyatt]

The result is that any time there's an exception, the error printed says "at line: $line in " with no file name.

I've noticed that too; seems to be linked to the new InModuleScope code. Some of the script blocks that get executed are generated on the fly, which causes the file information to be lost. (This also makes breakpoints fail if you set them in the test script, which is kind of annoying.)

Test code without InModuleScope has worked fine for me:

Describe 'Test' {
    It 'Fails' {
        throw 'Some error'
    }
}

<#
Describing Test
 [-] Fails 204ms
   Some error
   at line: 3 in C:\Source\Temp\test.Tests.ps1
#>

[Jaykul]

Oh, I know ... that whole function is using scope variables... It just needs to change to $testFile instead of $test.File to use the one that's set in the outer scope (i.e. in Invoke-Pester) It also pulls the $Name from the caller scope instead of passing it as a parameter

Feels sloppy, maybe make it $script:TestFile to make sure you're referring to a module-scope variable....

[dlwyatt]

That would work for the test name (though we'd also have to account for having test files executed directly rather than via Invoke-Pester), but the line number would still be mangled or lost in those cases. There might be a better way to make it work.

Right now we're making defensive copies of script blocks in a lot of places before calling Set-ScriptBlockScope, to avoid having any side effects on the ScriptBlock object that the caller passed in. I'll have to test a bit, but I suspect this is where the file / line information is being lost.

Instead of making new ScriptBlock objects, perhaps a try/finally construct to leverage the original object and change its state back to its original value would fix this problem, while still keeping these scope-fiddling bits of code from having side effects.

[dlwyatt]

Try this branch and see if it clears up your problems as well: https://github.com/dlwyatt/Pester/tree/DebuggingInfoInModuleScope

Using this test code:

Describe 'Test' {
    It 'Fails' {
        throw 'Some error'
    }

    InModuleScope Pester {
        It 'Fails in module' {
            throw 'Some error'
        }
    }
}

The Beta branch currently produces this output:

<#
Describing Test
 [-] Fails 60ms
   Some error
   at line: 3 in C:\Source\Temp\test.Tests.ps1
 [-] Fails in module 25ms
   Some error
   at line: 3 in 
#>

With the update, it gives good information for both filename and line number:

<#
Describing Test
 [-] Fails 53ms
   Some error
   at line: 3 in C:\Source\Temp\test.Tests.ps1
 [-] Fails in module 41ms
   Some error
   at line: 8 in C:\Source\Temp\test.Tests.ps1
#>

[dlwyatt]

As noted in the commit message for this test, we also build script blocks in memory in the Mocking code and for BeforeEach / AfterEach. I'm not sure if there are scenarios where either one of those would contribute to wacky test output, though.

[Jaykul]

It's still going to completely lie when exceptions are thrown from the SUT

[dlwyatt]

I wasn't involved with writing this originally, but I think that's intentional. Most exceptions in an It block are going to come from a Should assertion of some sort, and it's not terribly helpful to output that the exception came from line 89 in Should.ps1 every time. Instead, the output tells you which line in the test script contains the call to Should (or whatever other function produced the terminating error.)

[dlwyatt]

Ah, I see what you mean. For non-Should assertions, the line number is coming from the SUT, but the file name still refers to the Test file. Yeah, that's crap. Should be a simple fix, though.

[dlwyatt]

Question: For exceptions that came from something other than Should, is it preferable to show the file path / line number of the code that actually threw the exception, the file path / line number of the line in the Test code which called out to whatever threw the exception, or both?

[dlwyatt]

Updated the https://github.com/dlwyatt/Pester/tree/DebuggingInfoInModuleScope branch to output the SUT path / line number when it's responsible for throwing the error. May come back to that to change or add information.

[Jaykul]

Can you try my version? ;-) https://github.com/Jaykul/Pester/tree/DebuggingInfoInModuleScope

I added your tests and some more showing exceptions in the scripts under test under \Examples\ErrorMessageTests

[Jaykul]

Ok, your new version works too ;-)

Deep inside, I still prefer to print the stacktrace line the way I did it, because it looks like what I'm used to seeing, and shows the function name when it can, but I can live with either (especially since frequently the function name is just: at <ScriptBlock>)

[dlwyatt]

I'm fine with either one, but we'd need to change the implementation on your branch to something that works in PowerShell 2.0. Doesn't look like the ScriptStackTrace property existed on ErrorRecord objects in that version, but we should be able to piece together the same information from other available properties either in the ErrorRecord itself, or in Get-PSCallStack.

[Jaykul]

Yeah, just use your version then ;-) it'll keep the message the way it has been in Pester.

[dlwyatt]

OK, I'll go ahead and turn it into a PR as-is for now, and we can tweak the line contents later if desired.