Failed Pester 5 tests are not shown in Problems

[fflaten]

Issue Description

When using Pester 5.0.3 to execute a test task, the failed tests are not shown in Problems-view like they used to do with Pester 3.4. This seems to be caused by the new output-format in Pester 5 which doesn't fit with the $pester-problemMatcher regex.

Replacing the current matcher ^\s*(?:\[-\]\s+)(.*?)(?:\s+\d+\.?\d*\s*m?s)\s*$ with ^\s*(?:\[-\]\s+)(.*?)(?:\s+\d+\.?\d*\s*m?s)(?:\s+\(.*?\))?\s*$ in a regex online tester seems to detect both Pester 3.4 and Pester 5 output, but I had problems making it work by editing directly in package.json (remember to escape \), so might need something more.

Proof-of-concept(Click to Expand)

demo.tests.ps1

Describe "VSCode Problem demo" {
    Context "MyContext" {
        if((Get-Module Pester).Version -ge "5.0") {
            It "fails Pester5" {
                1 | Should -Be 2
            }
        } else {
            It "fails Pester" {
                1 | Should Be 2
            }
        }
    }
}

tasks.json

{
    "version": "2.0.0",
    "windows": {
        "options": {
            "shell": {
                "executable": "C:\\Windows\\System32\\WindowsPowerShell\\v1.0\\powershell.exe",
                "args": [
                    "-NoProfile",
                    "-ExecutionPolicy",
                    "Bypass",
                    "-Command"
                ]
            }
        }
    },
    "tasks": [
        {
            "label": "Test",
            "type": "shell",
            "command": "Import-Module 'C:\\Program Files\\WindowsPowerShell\\Modules\\Pester\\3.4.0\\Pester.psd1'; Invoke-Pester -PesterOption @{IncludeVSCodeMarker=$true}",
            "group": {
                "kind": "test",
                "isDefault": true
            },
            "problemMatcher": [
                "$pester"
            ]
        },
        {
            "label": "TestPester5",
            "type": "shell",
            "command": "Import-Module 'C:\\Program Files\\WindowsPowerShell\\Modules\\Pester\\5.0.3\\Pester.psd1'; Invoke-Pester -Configuration ([PesterConfiguration]@{Output=@{Verbosity = 'Detailed'}; Debug = @{ ShowNavigationMarkers = $true } })",
            "group": {
                "kind": "test",
                "isDefault": true
            },
            "problemMatcher": [
                "$pester"
            ]
        }
    ]
}

Output Pester 3.4 (shown in Problems-tab):

Describing VSCode Problem demo
   Context MyContext
    [-] fails Pester 398ms
      at <ScriptBlock>, C:\Sandbox\demo.tests.ps1: line 9
      Expected: {2}
      But was:  {1}
      9:                 1 | Should Be 2
      at <ScriptBlock>, C:\Sandbox\demo.tests.ps1: line 9
Tests completed in 398ms
Passed: 0 Failed: 1 Skipped: 0 Pending: 0 Inconclusive: 0

Output Pester 5.0.3 (not shown in Problems-tab):

Starting discovery in 1 files.
Discovering in demo.tests.ps1.
Found 1 tests. 95ms
Discovery finished in 192ms.

Running tests from 'demo.tests.ps1'
Describing VSCode Problem demo, C:\Sandbox\demo.tests.ps1:1
 Context MyContext, C:\Sandbox\demo.tests.ps1:2
   [-] fails Pester5, C:\Sandbox\demo.tests.ps1:4 124ms (94ms|30ms)
    Expected 2, but got 1.
    at 1 | Should -Be 2, C:\Sandbox\demo.tests.ps1:5
    at <ScriptBlock>, C:\Sandbox\demo.tests.ps1:5
Tests completed in 727ms
Tests Passed: 0, Failed: 1, Skipped: 0 NotRun: 0

Attached Logs

Follow the instructions in the README about
capturing and sending logs.

Environment Information

Visual Studio Code

Name	Version
Operating System	Windows_NT x64 10.0.19041
VSCode	1.48.2
PowerShell Extension Version	2020.6.0

PowerShell Information

Name	Value
PSVersion	7.0.3
PSEdition	Core
GitCommitId	7.0.3
OS	Microsoft Windows 10.0.19041
Platform	Win32NT
PSCompatibleVersions	1.0 2.0 3.0 4.0 5.0 5.1.10032.0 6.0.0 6.1.0 6.2.0 7.0.3
PSRemotingProtocolVersion	2.3
SerializationVersion	1.1.0.1
WSManStackVersion	3.0

Visual Studio Code Extensions

Visual Studio Code Extensions(Click to Expand)

Extension	Author	Version
azure-account	ms-vscode	0.9.2
azure-pipelines	ms-azure-devops	1.174.2
gc-excelviewer	GrapeCity	3.0.40
githistory	donjayamanne	0.6.9
gitlens	eamodio	10.2.2
hexeditor	ms-vscode	1.2.1
ilspy-vscode	icsharpcode	0.9.0
material-icon-theme	PKief	4.2.0
material-theme	zhuangtongfa	3.8.7
open-in-browser	techer	2.0.0
powershell	ms-vscode	2020.6.0
rainbow-csv	mechatroner	1.7.1
reg	ionutvmi	1.0.1
remote-containers	ms-vscode-remote	0.134.1
remote-ssh	ms-vscode-remote	0.51.0
remote-ssh-edit	ms-vscode-remote	0.51.0
remote-wsl	ms-vscode-remote	0.44.5
vscode-azurefunctions	ms-azuretools	0.24.0
vscode-azurestorage	ms-azuretools	0.9.0
vscode-docker	ms-azuretools	1.5.0
vscode-remote-extensionpack	ms-vscode-remote	0.20.0
vscode-test-explorer	hbenl	2.19.1
vsliveshare	ms-vsliveshare	1.0.2731
xml	DotJoshJohnson	2.5.1

[SydneyhSmith]

Thanks @fflaten I believe @nohwnd has started on a new problems matcher for Pester 5 output, can you confirm? Thanks!

[fflaten]

Thanks for the update. Seems to be related to pester/Pester#1452 and pester/Pester#1577. Should still track the issue here I guess considering the problemmatcher is a feature of the extension.

[nohwnd]

There was this PR #2447 where we talked about this, but I actually did not do anything. @fflaten if you want to implement this PRs are more than welcome. On Pester side you'd need to use the mentioned environment variables to detect if we are running in vscode to enable the appropriate output (if needed). I There already is an option on the configuration object but that one is ignored as described in pester/Pester#1577.

[SydneyhSmith]

Thanks @nohwnd for the update, on the vscode side looks like the change would happen here https://github.com/powershell/vscode-powershell/blob/master/package.json#L456-L474 I will go ahead and mark this issue as up for grabs

[fflaten]

@nohwnd I'll take a look when I get a chance.

  /**
   * The name of a predefined problem pattern, the inline definition
   * of a problem pattern or an array of problem patterns to match
   * problems spread over multiple lines.
   */
  pattern?: string | ProblemPattern | ProblemPattern[];

Quote from: https://code.visualstudio.com/docs/editor/tasks-appendix

Do the patterns need to match the line order perfectly when using the ProblemPattern[] option? The pester problemmatcher has two patterns, but Pester 5 doesn't output the file+line pattern on line 2. Might explain why my first attempt to modify the pattern in package.json failed.

[nohwnd]

@fflaten IDK tagging @tillig who fixed the matcher in #2447 and @rkeithhill who I think wrote the original matcher for v4. Hope they can help.

[tillig]

Something I noticed, which may or may not affect things here, is that Pester 5 doesn't issue any failure for exceptions occurring in BeforeAll. Using the test fixture I used before...

Describe "Reproduce Issue" {
    Context "Failing BeforeAll in Context block" {
        BeforeAll {
            $pathToCommand = Get-Command nosuchcommand.exe | Select-Object -ExpandProperty Source
            &othermissingcommand $pathToCommand
        }
    }
    It "has two failures - context and test" {
        $False | Should -Be $True
    }
}

...only the failure in the test is logged.

> Executing task: Invoke-Pester <


Starting discovery in 1 files.
Discovery finished in 158ms.
[-] Reproduce Issue.has two failures - context and test 126ms (103ms|23ms)
 Expected $true, but got $false.
 at $False | Should -Be $True, /Users/tillig/dev/tillig/PesterTest/Failing.Tests.ps1:9
 at <ScriptBlock>, /Users/tillig/dev/tillig/PesterTest/Failing.Tests.ps1:9
Tests completed in 534ms
Tests Passed: 0, Failed: 1, Skipped: 0 NotRun: 0

That affects, in part, the problem matcher because it was written to detect both context and individual test failures.

[tillig]

Oh, nevermind, I see it's a 5.x update problem. BeforeAll can't be in Context anymore.

[tillig]

I've messed around with it for a while and I think @fflaten comment here is on the nose:

Do the patterns need to match the line order perfectly when using the ProblemPattern[] option? The pester problemmatcher has two patterns, but Pester 5 doesn't output the file+line pattern on line 2.

The v4 failure output looked like:

    [-] has two failures - context and test 7ms
      at <ScriptBlock>, /Users/tillig/dev/powershell-test/Failing.Tests.ps1: line 7
      14:         $False | Should -Be $True
      Expected $true, but got $false.

The v5 failure output has reordered things:

[-] Reproduce Issue.has two failures - context and test 135ms (94ms|41ms)
 Expected $true, but got $false.
 at $False | Should -Be $True, /Users/tillig/dev/tillig/PesterTest/Failing.Tests.ps1:7
 at <ScriptBlock>, /Users/tillig/dev/tillig/PesterTest/Failing.Tests.ps1:7

I was able to get test failures to show up using a custom problem matcher in the tasks.json file:

{
  "linux": {
    "options": {
      "shell": {
        "args": [
          "-NoProfile",
          "-Command"
        ],
        "executable": "/usr/bin/pwsh"
      }
    }
  },
  "osx": {
    "options": {
      "shell": {
        "args": [
          "-NoProfile",
          "-Command"
        ],
        "executable": "/usr/local/microsoft/powershell/7/pwsh"
      }
    }
  },
  "tasks": [
    {
      "command": "Invoke-Pester",
      "group": {
        "isDefault": true,
        "kind": "test"
      },
      "label": "test",
      "options": {
        "cwd": "${workspaceFolder}"
      },
      "problemMatcher": {
        "fileLocation": "absolute",
        "owner": "powershell",
        "pattern": [
          {
            "message": 1,
            "regexp": "^\\s*\\[-\\]\\s+(.+)$"
          },
          {
            "regexp": ".*"
          },
          {
            "file": 2,
            "line": 3,
            "regexp": "^\\s*[Aa]t\\s+([^,]+,\\s*)?(.+?):(\\d+)$"
          }
        ],
        "severity": "error"
      },
      "type": "shell"
    }
  ],
  "version": "2.0.0",
  "windows": {
    "options": {
      "shell": {
        "args": [
          "-NoProfile",
          "-ExecutionPolicy",
          "Bypass",
          "-Command"
        ],
        "executable": "C:\\Windows\\System32\\WindowsPowerShell\\v1.0\\powershell.exe"
      }
    }
  }
}

Note that there's an extra regexp in there that basically "eats" the line between the message and the location. That seemed to be the secret.

The problem is, this doesn't work if the problem has a multi-line message. For example, if I have a failure in the BeforeAll, it looks like this:

[-] Describe Reproduce Issue failed
 CommandNotFoundException: The term 'othermissingcommand' is not recognized as the name of a cmdlet, function, script file, or operable program.
 Check the spelling of the name, or if a path was included, verify that the path is correct and try again.
 at <ScriptBlock>, /Users/tillig/dev/tillig/PesterTest/Failing.Tests.ps1:4

Note that's two lines between the message and the location.

I didn't see a way to say "eat a bunch of lines until it matches the location expression." I did try using the loop option on that second expression along with something like

{
  "regexp": "^(?!\\s*[Aa]t\\s+).*$",
  "loop": true
}

so instead of matching .* it'd match any line that doesn't start with at... but you can't use loop on anything but the last expression. So, no luck there.

It'd be easiest if the Pester output would be formatted like

[-] Test failure message
at Function, /Path/to/file:1
  Whatever additional error message is required
  including stack trace

Sort of how it was in v4. I mean, better still would be if there was an all-on-one-line machine parsable output format that also looked OK in a console, like a build error.

[-] Test failure message [/Path/to/file 1:15]

Where the message, path, line, and character are there, all nice and regex-able.

But, barring that... it seems like Pester 5 would need a new matcher specific to this new format, it'd need to know how to "eat" the extra error message line, and I don't think you'd be able to show context/BeforeAll sorts of failures anymore because the arbitrary lines in between message and location can't be dealt with properly.

[rkeithhill]

And now you know why back in the v3 days, @dlwyatt and I worked out a Pester configuration option to output specifically for VSCode so I could make the problem matcher regex work. Really though, Pester should adopt an output format that is stable & easy for problem matchers like this e.g:

[-] Reproduce Issue.has two failures - context and test 126ms (103ms|23ms)
 Location: /Users/tillig/dev/tillig/PesterTest/Failing.Tests.ps1:9
 Expected $true, but got $false.
 at $False | Should -Be $True, /Users/tillig/dev/tillig/PesterTest/Failing.Tests.ps1:9

[nohwnd]

Oh, nevermind, I see it's a 5.x update problem. BeforeAll can't be in Context anymore.

It can, it's just that your BeforeAll is in Context that has no It, so BeforeAll won't run because it would not setup any test.