Roslyn: VBC emitting extra console output on warning with " error:"

[tomasr]

Couldn't find an existing issue for this one (but could've missed it).

Compile the following piece of VB code in VS2015 with the "Implicit Type; Object Assumed" option set to "Warning":

Module Module1

    Sub Main()

        ' Causes build to fail
        Dim sEvent = String.Concat(" Error:", "Whatever")
        ' Won't cause build to fail
        Dim sEvent2 = String.Concat(" Another: ", "Whatever")
    End Sub

End Module

Both variable declarations will trigger a BC42020 warning. However, when the compiler encounters the sEvent declaration, it will include the line in the compiler output right after the warning, because it has the text " Error:" (leading space makes a difference).

This causes MSBuild/VS2015 to think the build failed and generate an strange error entry in the Errors window, even though only warnings were emitted during the build.

[gafter]

Is this an issue we can fix in the msbuild integration?

[tomasr]

I don't think fixing it in the msbuild integration is enough, as the Visual Studio compiler output parsing will also pick the written line as if it were an error message. So this compiler output:

------ Build started: Project: StrangeIssue, Configuration: Debug Any CPU ------
C:\Users\tomasr\Documents\Visual Studio 2015\Projects\StrangeIssue\StrangeIssue\Module1.vb(7,13): warning BC42020: Variable declaration without an 'As' clause; type of Object assumed.
VBC : Dim sEvent = String.Concat(" error : ", "Whatever")
C:\Users\tomasr\Documents\Visual Studio 2015\Projects\StrangeIssue\StrangeIssue\Module1.vb(9,13): warning BC42020: Variable declaration without an 'As' clause; type of Object assumed.
========== Build: 0 succeeded, 1 failed, 0 up-to-date, 0 skipped ==========

Leads to this:

[jaredpar]

Thanks for reporting @tomasre. Right now this doesn't quite meet our update 1 bar so I've moved it out to update 2.

I don't think fixing it in the msbuild integration is enough, as the Visual Studio compiler output parsing

I _think_ we have the same parsing routine for both of these locations. But yes this is something we need to verify.

[tomasr]

That's OK, I've only run into this issue twice, with code from the same customer in both cases. Probably not a very common case.

I am curious, however, why fixing the parsing would be required. Wouldn't the right fix be to prevent the compiler from writing the source code line to the output in the first place? :) (or maybe I just misunderstood what you guys said)

[jaredpar]

@tomasr it's fixing the parsing of the error messages. MSBuild finds errors by essentially scanning the textual output of the compiler. It needs to be made smarter to avoid confusing this case.

Ideally though it would use a structured format instead of parsing what we print to users.

[tomasr]

@jaredpar That still doesn't make sense to me.

My question is: why does the first source code line cause the compiler to reprint the line on the output, while the second one does not get reprinted?

In other words, why does the compiler find the content " error:" special enough to cause it to print it to the output?

[jaredpar]

@tomasr

My question is: why does the first source code line cause the compiler to reprint the line on the output, while the second one does not get reprinted?

I believe this is the source of the confusion. The compiler is actually printing out both source lines here. MSBuild is just incorrectly interpreting one of them as an error when it translates them to the error list.

This is viewable if you run the compiler directly from a shell. In that case the output is:

C:\Users\jaredpar\temp\test.vb(10) : error BC30209: Option Strict On requires all variable declarations to have an 'As' clause.

        Dim sEvent = String.Concat(" Error:", "Whatever")
            ~~~~~~
C:\Users\jaredpar\temp\test.vb(12) : error BC30209: Option Strict On requires all variable declarations to have an 'As' clause.

        Dim sEvent2 = String.Concat(" Another: ", "Whatever")

Note that in order to repro from command line you need the following put at the top of the repro code.

Option Strict On
Option Explicit On
Option Infer Off

[tomasr]

@jaredpar That does make perfect sense!

I'm kinda curious.... do both the VB and C# compiler dump the error lines to the console like this? And if it's not needed by the build system, why do so in the first place?

[jaredpar]

@tomasr

if it's not needed by the build system, why do so in the first place?

The compilers need to stand on their own as a tool. Printing the error lines to the command line provide as nice of an experience as possible for the user. Having the line of code, highlighted via carets, is actually pretty instructive (at least to me).

I think of this problem from a slightly different angle: why did a build system come along, take tools that have non-structured output and process that value using a regex? It's an approach that's always going to have issues and corner cases (as shown here). A better approach would be to ask the compilers for a way of getting structured output (json, XML, etc ...) that MSBuild can parse definitively.

The current regex approach has bitten us several times in the last few months (localization in particular). It's something I'd like to change to make it more reliable.

[tomasr]

@jaredpar

The compilers need to stand on their own as a tool. Printing the error lines to the command line provide as nice of an experience as possible for the user. Having the line of code, highlighted via carets, is actually pretty instructive (at least to me).

That makes sense, and I can agree with that. On the other hand, if the build system doesn't need that, one could argue the compiler should just have a flag that is enabled by the build system to prevent it from generating that output in the first place. Just saying :)

[jaredpar]

@tomasr

That's essentially how I envision it working. The compiler has a flag to support structured output and the build system uses it to make error parsing definitive.

On the other hand. Now that Roslyn has an API one could argue the build system should just host it and use the API to get back the errors definitively.

[ghost]

This is rather annoying. Analyzers basically can't report issues on lines that contain " error" strings, because it causes a build failure.

[niemyjski]

WOW, this just bit me too (C#). I upgraded from 4.0 to .net 4.7 and the build fails when my output is logged via console.out

"C:\Code\test\Master.proj" (default target) (1) -> (Test target) -> \InvalidNamespaceAndClassName.cst(1,1): error : ClassName attribute contains an invalid character. [C:\Code\test \Master.proj]