Problem matchers for error messages that span multiple lines

[massimocode]

• VSCode Version: 1.4.0-insider 01a3f8
• OS Version: Windows 10 x64

I'm unable to get a message built up from several lines in the output. In the output below, I would like the message to contain the spec name, and the reason it failed. Any ideas if this is possible?

I have the following output from NUnit:

Project dotnettesting (.NETCoreApp,Version=v1.0) was previously compiled. Skipping compilation.
NUnit .NET Core Runner 3.4.0 
Copyright (C) 2016 Charlie Poole
Runtime Environment
    OS Platform: Windows
     OS Version: 10.0.10586
        Runtime: win10-x64
Test Files
    c:\projects\dotnettesting\bin\Debug\netcoreapp1.0\dotnettesting.dll
Errors and Failures
1) Failed : CalculatorSpec.ShouldFail
  Expected: 0
  But was:  3
at CalculatorSpec.ShouldFail() in c:\projects\dotnettesting\Calculator.spec.cs:line 12
2) Failed : CalculatorSpec.Will_Fail
  Expected: 0
  But was:  3
at CalculatorSpec.Will_Fail() in c:\projects\dotnettesting\Calculator.spec.cs:line 17
Run Settings
    WorkDirectory: c:\projects\dotnettesting
Test Run Summary
  Overall result: Failed
  Test Count: 3, Passed: 1, Failed: 2, Inconclusive: 0, Skipped: 0
    Failed Tests - Failures: 2, Errors: 0, Invalid: 0
  Start time: 2016-07-22 19:16:50Z
    End time: 2016-07-22 19:16:51Z
    Duration: 0.362 seconds
Results saved as c:\projects\dotnettesting\TestResult.xml
SUMMARY: Total: 1 targets, Passed: 0, Failed: 1.

I have configured the following problem matcher:

"pattern": [
    {
        "regexp": "^\\d+\\) Failed.*$"
    },
    {
        "regexp": "^(.*)$",
        "message": 1
    },
    {
        "regexp": "^(.*)$",
        "message": 1
    },
    {
        "regexp": "^at (.*\\(\\)) in (.*):line (\\d+)$",
        "location": 3,
        "file": 2
    }
]

[dbaeumer]

It is partly possible but without actually capturing both messages. A message can only be captured once. Can you share a project showing this output. Then I can have a look why it doesn't work?

[massimocode]

@dbaeumer sure, I've just uploaded the sample project here:
https://github.com/massimocode/dotnettesting

Let me know if you need anything else.

Ideally what would be cool is if we should capture both lines relevant to the failure so that it gets reported as "Expected: 0 But was: 3", literally just replacing the new lines with spaces or something.

[dbaeumer]

@massimocode thanks for the example. I cloned it and run the task, however it produces the following output for me (which I have to admit is not parseable by the framework right now):

Project dotnettesting (.NETCoreApp,Version=v1.0) will be compiled because Input items removed from last build
Compiling dotnettesting for .NETCoreApp,Version=v1.0
Compilation succeeded.
    0 Warning(s)
    0 Error(s)
Time elapsed 00:00:01.5436183

NUnit .NET Core Runner 3.4.0 
Copyright (C) 2016 Charlie Poole
Runtime Environment
    OS Platform: Windows
     OS Version: 10.0.14393
        Runtime: win10-x64
Test Files
    p:\mseng\VSCode\Playgrounds\bugs\dotnettesting\bin\Debug\netcoreapp1.0\dotnettesting.dll
Run Settings
    WorkDirectory: p:\mseng\VSCode\Playgrounds\bugs\dotnettesting
Test Run Summary
  Overall result: Passed
  Test Count: 3, Passed: 3, Failed: 0, Inconclusive: 0, Skipped: 0
  Start time: 2016-08-15 10:22:13Z
    End time: 2016-08-15 10:22:13Z
    Duration: 0.233 seconds
Results saved as p:\mseng\VSCode\Playgrounds\bugs\dotnettesting\TestResult.xml
SUMMARY: Total: 1 targets, Passed: 1, Failed: 0.

I am using dotnet --version: 1.0.0-preview2-003121

[massimocode]

@dbaeumer Apologies for that, the code I checked in had passing unit tests (so no errors to report).

I have since updated the repository to have the same 2 failing tests as in the original issue description.

The repository is here:
https://github.com/massimocode/dotnettesting

Thanks!

[dbaeumer]

I will have another look then. Thanks.

[indiejames]

I need this same functionality (capturing a message across multiple lines). I also have output from my tests like

Expected: 0
But was: 3

that I would like to capture as the 'message'.

[dbaeumer]

@indiejames we are working on making tasks API so that people can code this. Having a declarative approach to this requires me to invent a programming language in JSON :-(

[doudou]

@dbaeumer do you have an idea how high in the priority list a reporting API is ? We're comparing Atom with VSCode, and I really like VSCode. But on this front, the atom build plugin & problem reporter are light years ahead...

[dbaeumer]

It is OnDeck but not planned for a specific milestone.

[jpihl]

I had the same issue with gtest. I found a workaround which might help some people until this feature is available.

Here's my problemMatcher for gtest:

"problemMatcher": {
    "owner": "cpp",
    "fileLocation": ["relative", "${workspaceRoot}/test/src/"],
    "severity": "error",
    "pattern": [{
        "regexp": "^(.*):(\\d+):\\s+.*$",
        "file": 1,
        "line": 2
    },
    {
        "regexp": "^((:?Value of:.*)|(:?  Actual: .*)|(:?Expected: .*))$",
        "message": 1,
        "loop": true
    }]
}

I'm on linux so I can't build your test project, but I bet it can be done in a similar way.

The drawback of this approach is that it will produce a problem per line in the problem message, but you get the error message(s) when you hover over the line.

An excerpt of the output from my test:

...
[----------] 2 tests from test_copy
[ RUN      ] test_copy.same_size
../../test/src/test_copy.cpp:25: Failure
Value of: storage::is_equal(storage::storage(d1), storage::storage(d2))
  Actual: false
Expected: true
[  FAILED  ] test_copy.same_size (0 ms)
[ RUN      ] test_copy.not_same_size
[       OK ] test_copy.not_same_size (0 ms)
...

[AshleyYakeley]

This is a pain point for Haskell users, too. Here's a typical multi-line error from GHC:

    /home/ashley/Projects/Haskell/Truth/pinafore/lib/Pinafore/Language/Read.hs:253:28: error:
        • Could not deduce (ToTypeF
                              (Pinafore.Language.Type.PinaforeType baseedit)
                              Pinafore.Entity.Predicate)
            arising from a use of ‘qConstExpr’
          from the context: HasPinaforeEntityEdit baseedit
            bound by the type signature for:
                       readExpression3 :: forall baseedit.
                                          HasPinaforeEntityEdit baseedit =>
                                          Parser (PinaforeTypeCheck (QExpr baseedit))
            at lib/Pinafore/Language/Read.hs:(210,1)-(212,50)
        • In the second argument of ‘($)’, namely ‘qConstExpr p’
          In the second argument of ‘($)’, namely ‘return $ qConstExpr p’
          In a stmt of a 'do' block: return $ return $ qConstExpr p
        |
    253 |          return $ return $ qConstExpr p) <|>
        |                            ^^^^^^^^^^^^

The best I can do with the current problemMatcher is capture the first line of the full message (• Could not deduce (ToTypeF).

[AshleyYakeley]

If I wanted a quick fix for this, I'd create an append boolean JSON key similar to loop, but appending the message to the current problem instead of outputting a new problem.

[AshleyYakeley]

So it looks like the UI work done in 1.31 on multi-line messages is part of a fix to this issue, but providing an API is still to be done, is that correct?

[alexr00]

The UI work will be useful for this, but yes, there is still Task API that will need to be added.

[Tyriar]

I did some exploration with problem matchers on the weekend and I really wanted this. Having this would mean it could be done all in JSON committed to the repo, not require an extension as in #59337

I was trying to get a nice problem matcher with a multi-line message for mocha errors and to do that I ended up needing to do a custom mocha reporter to output a specific format and then repeating the message capture several times. The problem is the exact number of the TRACE: message captures needed to exist, otherwise the problem matcher wouldn't accept it.

Problem matcher I used:

      "problemMatcher": {
        "owner": "javascript",
        "severity": "error",
        "fileLocation": "absolute",
        "pattern": [
          {
            "regexp": "^\\s*File: ([^ ]+):(\\d+)",
            "file": 1,
            "line": 2,
          },
          { "regexp": "^\\s*Trace: (.+)", "message": 1 },
          { "regexp": "^\\s*Trace: (.+)", "message": 1 },
          { "regexp": "^\\s*Trace: (.+)", "message": 1 },
          { "regexp": "^\\s*Trace: (.+)", "message": 1 },
          { "regexp": "^\\s*Trace: (.+)", "message": 1 },
          { "regexp": "^\\s*Trace: (.+)", "message": 1 },
          { "regexp": "^\\s*Trace: (.+)", "message": 1 },
          { "regexp": "^\\s*Trace: (.+)", "message": 1 },
          { "regexp": "^\\s*Trace: (.+)", "message": 1 },
          { "regexp": "^\\s*Trace: (.+)", "message": 1 },
          { "regexp": "^\\s*Trace: (.+)", "message": 1 },
          { "regexp": "^\\s*Trace: (.+)", "message": 1 },
          { "regexp": "^\\s*Trace: (.+)", "message": 1 }
        ]
      }

The result after pressing F8 means I wouldn't even have to open the terminal 😍

I would expect something like this to work instead:

        "pattern": [
          {
            "regexp": "^\\s*File: ([^ ]+):(\\d+)",
            "file": 1,
            "line": 2,
          },
          { "regexp": "^\\s*Trace: (.+)", "message": 1, "repeat": true },
        ]

Without a problem matcher there is the issue of the message potentially containing empty lines which would need to be supported but I would expect something like this to work for the regular "spec" reporter:

"pattern": [
  {
    "regexp": "^\\s*(AssertionError: .+)",
    "file": 1,
    "line": 2,
    "message": 1
  },
  {
    "regexp": "...", // not "at ...", not sure how to do that without looking it up
    "message": 1,
    // Repeats the message until it no longer matches, needs to handle empty lines as well
    "repeatMessage": true
  },
]

[alx9r]

The method described previously by @jpihl seems to only show one error in 1.76.2:

[alx9r]

I tried every combination of emitting message output from by build and VS Code problem matcher that I could think of. I don't think meaningful display of multi-line problem messages of any kind is possible using any UI feature (except the editor) in 1.76.2. I definitely welcome an example demonstrating meaningful display of multiline messages. I have good control over what my build system emits, so if VS Code can be coerced into displaying a multiline message I expect I can adapt to that.

As a stop-gap I configured my build to dump each multiline message to a file and mention that file as a problem. The result is easily the best multiline problem user experience I have achieved using VS Code, but it's still extra steps to see view the right problems and far from ideal. At least I no longer have to hunt through terminal output to find details of test failures though.

Here is a screenshot of the UI for multiline problem messages with this approach:

[gar1t]

To pile on, Python's doctest reports errors in blocks that span lines.

Sample output:

**********************************************************************
File "test.md", line 1, in test.md
Failed example:
    print("hello")
Expected:
    goodbye
Got:
    hello
**********************************************************************
1 items had failures:
   1 of   1 in test.md
***Test Failed*** 1 failures.

[gadcam]

Would be very nice to get this feature!
On Windows it is a nightmare because of microsoft/terminal#405 not being fixed.
Whenever we have a long line we have a newline character and the pattern is broken.

The "workaround" I got for now in the case of eslint is this

{
  "version": "2.0.0",
  "tasks": [
    {
      "label": "ESLINT - Full project",
      "type": "shell",
      "command": "npx eslint . --format=compact",
      "problemMatcher": ["$eslint-compact"],
    }
  ]
}

It does not enable to match everything though (and even more so when I am not using my external monitor full screen).
But it is already way less worse.

I also tried to use something like this (with Git Bash) to remove spaces to get less long lines

      "command": "npx eslint . --output-file \"$TEMP\\eslint.log\"; sed 's/ \\{3,\\}/  /g' \"$TEMP\\eslint.log\"",
      "problemMatcher": ["$eslint-stylish"],

But this heuristic is performing worse on my project than the compact hack.

As a sidenote, I think it is very sad to have this kind of deadlock on Microsoft own ecosystem this is one more thing making me consider just switching to UNIX because a very basic thing has been broken for years.

[lloeki]

I've come to this issue from trying to parse Ruby's Minitest output in some meaningful way (using Minitest::Reporters::DefaultReporter, the original minitest reporter having basically the same format with a few irrelevant variations)

For reference, here's a typical Minitest output (which does not not report skips):

  1) Failure:
Graft::HookPoint::.const_exist?::when given a string of existing Constant#test_0001_anonymous [spec/graft/hook_point_spec.rb:56]:
Expected: false
  Actual: true

  2) Error:
Graft::HookPoint::.parse::when an valid class method notation#test_0001_anonymous:
RuntimeError: 
    spec/graft/hook_point_spec.rb:49:in `block (4 levels) in <top (required)>'

Here's a typical Minitest::Reporters::DefaultReporter output (which does report skips):

Error:
Graft::HookPoint::.parse::when an valid class method notation#test_0001_anonymous:
RuntimeError: 
    spec/graft/hook_point_spec.rb:49:in `block (4 levels) in <top (required)>'

Skipped:
Graft::HookPoint::.resolve_const::when given a string of existing Constant#test_0004_anonymous [/Users/loic.nageleisen/Source/github.com/DataDog/graft-rb/spec/graft/hook_point_spec.rb:78]:
FIXME: This is not working as expected

Failure:
Graft::HookPoint::.const_exist?::when given a string of existing Constant#test_0001_anonymous [/Users/loic.nageleisen/Source/github.com/DataDog/graft-rb/spec/graft/hook_point_spec.rb:56]
Minitest::Assertion: Expected: false
  Actual: true

We'll work with the latter.

So here how it goes, I have three problemMatchers:

        "problemMatcher": [

First, attempting to capture Errors (i.e there was an uncaught exception); VSCode is thoroughly unhappy with that one, it doesn't even want to match on grounds that file+line are captured too far down the list:

        //  Sadly VSCode has problems with multiline messages: https://github.com/microsoft/vscode/issues/9635
            {
                "owner": "ruby",
                "fileLocation": "absolute",
                "severity": "error",
                "pattern": [
                    {
                        "regexp": "^(Error):$",
                        "message": 1
                    },
                    // Capture test
                    {
                        "regexp": "^(.*)#.*?:$",
                        "message": 1,
                    },
                    // Capture exception
                    {
                        "regexp": "^(.*):$",
                        "message": 1,
                    },
                    // Capture path
                    {
                        "regexp": "^\\s*\\[(\\S+):([0-9]+)\\]$",
                        "file": 2,
                        "line": 3
                    },
                ]
            },

Then we have this for test Failures (i.e an assertion failed); the following works, but if I uncomment anything starting with the third pattern it suddenly fails to match:

          {
                "owner": "ruby",
                "fileLocation": "absolute",
                "severity": "error",
                "pattern": [
                    {
                        "regexp": "^(Failure):$",
                        "message": 1
                    },
                    {
                        "regexp": "^(.*)#.* \\[(\\S+):([0-9]+)\\]$",
                        "message": 1,
                        "file": 2,
                        "line": 3
                    },
                //  Sadly VSCode has problems with multiline messages: https://github.com/microsoft/vscode/issues/9635
                //  {
                //      "regexp": "^.*(Expected: .*)$",
                //      "message": 1,
                //  },
                //  {
                //      "regexp": "^.*(Actual: .*)$",
                //      "message": 1,
                //  }
                ]
            },

Interestingly enough the reason for the match failure is visible when trying something like @Tyriar did (just eat with "regexp": "^(.*)$" repeatedly and shove it in message: 1): it becomes obvious that the second line was matched by the second pattern but then the third pattern attempts to match against the second line AGAIN instead of the third.

Finally the third one, for Skips; this one almost works but suffers the same fate as the one before, uncommenting the last item has it matched against the same second line instead of the third:

            {
                "owner": "ruby",
                "fileLocation": "absolute",
                "severity": "info",
                "pattern": [
                    {
                        "regexp": "^(Skipped):$",
                        "message": 1,
                    },
                    // Capture path
                    {
                        "regexp": "^(.*) \\[(\\S+):([0-9]+)\\]:$",
                        "file": 2,
                        "line": 3
                    },
                    // Capture test
                    {
                        "regexp": "^(.*)#.*?$",
                        "message": 1,
                    },
                //  Sadly VSCode has problems with multiline messages: https://github.com/microsoft/vscode/issues/9635
                //  // Capture skip message
                //  {
                //      "regexp": "^(.*)$",
                //      "message": 1,
                //  },
                ]
            }

And we're done:

        ],

It all gets really odd if you add/replace with a bunch of these "regexp": "^(.*)$" and restart VSCode, you see that it eventually goes forward for some obscure reason and ends up matching against the third line, and the same process repeats: it takes a while for it to then match on the fourth, etc... And then if you rerun a couple fo times or make some changes, eventually it stops and only the second line is ever matched against, repeatedly.

I've attached a couple or three screenshots:

• first one is running the task once right after a project reopen: only the Failure one matches, but it looks like it works; the Skip one may have been mismatching on an incorrect line.

  

• second one is running the task a second time with no changes whatsoever: the Failure now matches repeatedly on the second line, and the Skip one appears to work and captures the skip reason.

  

• third one is running the task a third time with no changes whatsoever: both the Failure and Skip now match repeatedly on the second line.

  

If I add 10 "regexp": "^(.*)$", I'll see the same line being matched 10 times instead of a sequence of 10 different lines.

Again, there was no change whatsoever between these runs, merely re-running the task again, which produced identical output yet different matching results.

So overall "message": 1 accumulation across lines appears to work just fine and I am happy with the resulting UI:

... but matching multiple lines, each with a distinct pattern, appears to be broken in some way that makes it completely unreliable and useless.

[Nippey]

Hello,
let me provide sampe output from the Greenhills compiler, these messages are multiline as well:

"C:\ghs\comp_202015\ansi\stdint.h", line 40: error #256: invalid redeclaration
          of type name "uint32_t" (declared at line 218 of
          "..\..\..\source\driver\src\general\headerfile.h")
    typedef unsigned int uint32_t;

"..\..\..\source\middleware\driver\sourcefile.c", line 214: error #70:
          incomplete type is not allowed
      struct _addr addr;
                  ^

Errors are always terminated by a dual-linechange.
What also would be interesting, if the "column" matcher would also ingest a string instead of a number and will count the number of characters.
This way one could easily parse these things: ^

This regex parses the output just fine if used with Python.re:
^\"(?<file>[^\"]+)\", line (?<line>\d+): (?<severity>[^#]+) #(?<code>[^:]+):(:?\s*\r?\n\s+)?(?<message>(.|\r?\n)*?)(:?\r?\n){2}

But it seems VSCode is missing the "multiline" modifier in its matcher...