MSBuild occasionally succeeds despite /WarnAsError:MSB3270

[atniomn]

Issue Description

When running MSBuild with /WarnAsError:MSB3270, MSBuild will occasionally succeed, despite warnings being promoted into an errors.

I do not observe this behavior with /graph:true

Steps to Reproduce

I notice there are many other issues similar to this one, so I took it upon myself to construct a reliable reproduction of the issue.

WarnAsErrorTest.zip

The code attached contains a really simple C# solution (.NET Framework 4.7.2 console application) which deliberately has misaligned platforms.

I have included a powershell script, test.ps1, which can be run with /graph:false

PS WarnAsErrorTest> .\test.ps1

or with /graph:true

PS WarnAsErrorTest> .\test.ps1 -GraphBuild $true

Expected Behavior

Regardless of whether or not I am using /graph:true, MSBuild should fail in a deterministic manner

Actual Behavior

MSBuild fails most of the time, but occasionally succeeds.

Versions & Configurations

Microsoft (R) Build Engine version 16.6.0+5ff7b0c9e for .NET Framework
Copyright (C) Microsoft Corporation. All rights reserved.

16.6.0.22303

pwsh v7.0.3

I recommend /graph:true to anyone experiencing this problem.
I understand the historic justification for having /graph:false be default, but /graph:true seems much more sane now.

[benvillalobos]

Note to self: Might need to lean on Mihai for this one.

[pakrym]

Related: #9825

[pakrym]

Related: #3295

[atniomn]

Related: #4842

[benvillalobos]

This was likely resolved by #6174 and I can't repro this on 16.10 msbuild. Are you still seeing this on an updated MSBuild?

To be specific, this should be available in vs16.10 preview 1

[benvillalobos]

Closing this as resolved.

[Forgind]

I'm seeing this still in 17.0 with the repro I provided here in at least some cases.

[benvillalobos]

The reason this was reopened: There seems to be a difference between dotnet build and msbuild when building a project like the one at #7094. dotnet build sees a successful build (despite errors) while msbuild sees the proper build failure.

Versions:
6.0.100/ msbuild 17.0 c9eb9dd(sees repro)
full framework 17.0+ doesn't see the issue.

[benvillalobos]

Can confirm this still happens.

C:\Users\bevillal\Downloads\Compressed\WarnAsErrorTest\WarnAsErrorTest\TestProj>dotnet build /t:AlwaysRun /WarnAsError:NAT011
MSBuild version 17.4.0-preview-22470-08+6521b1591 for .NET
  Determining projects to restore...
  All projects are up-to-date for restore.
C:\Users\bevillal\Downloads\Compressed\WarnAsErrorTest\WarnAsErrorTest\TestProj\TestProj.csproj(12,9): error NAT011: You fail
C:\Users\bevillal\Downloads\Compressed\WarnAsErrorTest\WarnAsErrorTest\TestProj\TestProj.csproj(13,9): warning NAT012: Other Fail

Build FAILED.

C:\Users\bevillal\Downloads\Compressed\WarnAsErrorTest\WarnAsErrorTest\TestProj\TestProj.csproj(13,9): warning NAT012: Other Fail
C:\Users\bevillal\Downloads\Compressed\WarnAsErrorTest\WarnAsErrorTest\TestProj\TestProj.csproj(12,9): error NAT011: You fail
    1 Warning(s)
    1 Error(s)

Time Elapsed 00:00:00.17

C:\Users\bevillal\Downloads\Compressed\WarnAsErrorTest\WarnAsErrorTest\TestProj>
C:\Users\bevillal\Downloads\Compressed\WarnAsErrorTest\WarnAsErrorTest\TestProj>dotnet build /t:AlwaysRun /WarnAsError:NAT011
MSBuild version 17.4.0-preview-22470-08+6521b1591 for .NET
  Determining projects to restore...
  All projects are up-to-date for restore.
C:\Users\bevillal\Downloads\Compressed\WarnAsErrorTest\WarnAsErrorTest\TestProj\TestProj.csproj(12,9): error NAT011: You fail
C:\Users\bevillal\Downloads\Compressed\WarnAsErrorTest\WarnAsErrorTest\TestProj\TestProj.csproj(13,9): warning NAT012: Other Fail

Build succeeded.

C:\Users\bevillal\Downloads\Compressed\WarnAsErrorTest\WarnAsErrorTest\TestProj\TestProj.csproj(13,9): warning NAT012: Other Fail
C:\Users\bevillal\Downloads\Compressed\WarnAsErrorTest\WarnAsErrorTest\TestProj\TestProj.csproj(12,9): error NAT011: You fail
    1 Warning(s)
    1 Error(s)

Time Elapsed 00:00:00.15

dotnet --version

7.0.100-rc.2.22477.23

Investigation Notes

After quite a bit of digging I don't see anything wrong with the way that the SDK logs the error. It correctly gets all the way to logging an error into the logging service here, which goes into ProcessLoggingEvent where it goes into the queue and I can't track it down anymore.

msbuild/src/Build/BackEnd/Components/RequestBuilder/TaskHost.cs

Line 451 in d14b74d

_taskLoggingContext.LoggingService.LogBuildEvent(e);

It's worth noting that the first warning getting logged (the one that should error) hits line 1191, whereas the second (the one that doesn't fail) hits line 1198. It's worth noting because RouteBuildEvent has logic to properly account for errors.

msbuild/src/Build/BackEnd/Components/Logging/LoggingService.cs

Lines 1178 to 1201 in d14b74d

	internal virtual void ProcessLoggingEvent(object buildEvent)
	{
	ErrorUtilities.VerifyThrow(buildEvent != null, "buildEvent is null");
	if (_logMode == LoggerMode.Asynchronous)
	{
	// Block until queue is not full.
	while (_eventQueue.Count >= _queueCapacity)
	{
	// Block and wait for dequeue event.
	_dequeueEvent.Wait();
	_dequeueEvent.Reset();
	}
	_eventQueue.Enqueue(buildEvent);
	_enqueueEvent.Set();
	}
	else
	{
	lock (_lockObject)
	{
	RouteBuildEvent(buildEvent);
	}
	}
	}

[AR-May]

This issue resurfaced again: dotnet/installer#8735
We will close this one as a duplicate in favor to the issue above.
The PR with fix is already attached to the issue above.