[BUG]: [DotNetCoreCLIv2]: opt-in the MSBuild logger to new `IEventSource4`

[KirillOsenkov]

New issue checklist

• [X] I searched for existing GitHub issues
• [X] I read pipeline troubleshooting guide
• [X] I checked how to collect logs

Task name

DotNetCoreCLI

Task version

2

Issue Description

DotNetCoreCLIV2 uses an MSBuild logger named Microsoft.TeamFoundation.DistributedTask.MSBuild.Logger.dll.

The source of the logger can be found in repo microsoft/azure-pipelines-msbuild-logger.

The binary of the logger is referenced here: https://github.com/microsoft/azure-pipelines-tasks/blob/cccb1c6abdf27c119fc664fc963bc918039c00db/Tasks/DotNetCoreCLIV2/make.json#L5

and here: https://github.com/microsoft/azure-pipelines-tasks/blob/6b291c4a2f8b945b469259cc4dc685a966bc0335/Tasks/DotNetCoreCLIV2/dotnetcore.ts#L111-L114

The logger is legacy and doesn't support some newer MSBuild features. Specifically, when this logger is added to MSBuild, MSBuild loses the ability to log all properties and items on ProjectEvaluationFinishedEventArgs. This is a severe impediment for everyone who is using MSBuild binlogs recorded by Azure DevOps.

The logger needs to be updated to opt-in to the newer features. It is currently referencing a super old version of Microsoft.Build.Framework.dll. We need to determine what is the minimum supported version of MSBuild that this task runs with, and reference the corresponding version of Microsoft.Build.Framework NuGet package. I recommend 17.5.0: https://www.nuget.org/packages/Microsoft.Build.Framework/17.5.0

After the new MSBuild is referenced by the logger project, you need to add this to the Initialize() method of the Logger class:

https://github.com/dotnet/sdk/blob/91a440681da35b13a1528bd6dcf35c64a2c221ab/src/Cli/dotnet/commands/dotnet-msbuild/MSBuildForwardingLogger.cs#L20-L25

        public void Initialize(IEventSource eventSource)
        {
            // Declare lack of dependency on having properties/items in ProjectStarted events
            // (since this logger doesn't ever care about those events it's irrelevant)
            if (eventSource is IEventSource4 eventSource4)
            {
                eventSource4.IncludeEvaluationPropertiesAndItems();
            }

I'd be happy to code review this work. This needs to be done because I'm seeing many binlogs submitted by customers which are missing this important information and it's not obvious that it's missing and there are no instructions on how to fix this.

Environment type (Please select at least one enviroment where you face this issue)

• [ ] Self-Hosted
• [X] Microsoft Hosted
• [ ] VMSS Pool
• [ ] Container

Azure DevOps Server type

dev.azure.com (formerly visualstudio.com)

Azure DevOps Server Version (if applicable)

No response

Operation system

Windows 10

Relevant log output

N/A

Full task logs with system.debug enabled

N/A

Repro steps

N/A

[KirillOsenkov]

@max-zaytsev @DenisRumyantsev @anatolybolshakov

FYI @JustinSchneiderPBI

[KirillOsenkov]

While we're updating the logger we should also fix #16366

[KirillOsenkov]

16301 is also related

[KirillOsenkov]

In general, the MSBuild logger is poorly written, unnecessarily complicated, buggy and should be rewritten from scratch.

It should look something like this: https://github.com/dotnet/msbuild/blob/abc2f4620f6749289cafeed7c9a9a80eaeb38e28/src%2FBuild%2FLogging%2FSimpleErrorLogger.cs

Perhaps we could even repurpose the MSBuild built-in SimpleErrorLogger to output AzureDevOps-specific outputs.

Observations from reviewing the current (legacy) logger:

1. ExternalProjectStartedEventArgs is obsolete and no longer used
2. opt-in to IEventSource4 (this is what this bug is about), also move to reading properties from ProjectEvaluationFinishedEventArgs instead of ProjectStartedEventArgs, but it shouldn't probably read properties at all
3. It doesn't need to be a pair of central/distributed logger. It should be a simple logger, and passed to MSBuild using a simple /l, instead of passing both loggers like today.

The logger literally logs three types of strings:

$"##vso[task.logissue type={Escape(type)};sourcepath={Escape(file)};linenumber={Escape(line)};columnnumber={Escape(column)};code={Escape(code)};]{Escape(message)}"

            StringBuilder loggingCommand = new StringBuilder();
            loggingCommand.Append($"##vso[task.logdetail ");
            loggingCommand.Append($"id={Escape(id)};");
            loggingCommand.Append($"parentid={Escape(parentId)};");
            loggingCommand.Append($"name={Escape(name)};");
            loggingCommand.Append($"type={Escape(type)};");
            loggingCommand.Append($"starttime={Escape(starttime)};");
            loggingCommand.Append($"state={Escape(state)};");
            if (!String.IsNullOrEmpty(targets))
            {
                loggingCommand.Append($"targetname={Escape(targets)};");
            }

            loggingCommand.Append("]");
            Console.WriteLine(loggingCommand.ToString());

            StringBuilder loggingCommand = new StringBuilder();
            loggingCommand.Append($"##vso[task.logdetail ");
            loggingCommand.Append($"id={Escape(id)};");
            loggingCommand.Append($"parentid={Escape(parentId)};");
            if (name != null)
            {
                loggingCommand.Append($"name={Escape(name)};");
            }

            loggingCommand.Append($"type={Escape(type)};");
            loggingCommand.Append($"result={Escape(result)};");
            loggingCommand.Append($"finishtime={Escape(finishTime)};");
            loggingCommand.Append($"progress={Escape(progress)};");
            loggingCommand.Append($"state={Escape(state)};");
            loggingCommand.Append($"parentid={Escape(parentId)};");
            loggingCommand.Append($"name={Escape(name)};");
            loggingCommand.Append("]");
            Console.WriteLine(loggingCommand.ToString());

It tries to be smart and use the logdetail feature for nesting projects, but is this even supported at all? I've never seen this in action? Does anyone have any screenshots?

Even if we still need to support this, there should be a much easier way to achieve nesting, although my inclination would be to not do it at all and just do a flat list of errors and/or warnings.

In fact I just wrote a logger from scratch that does all that: https://github.com/KirillOsenkov/MSBuildTools/tree/main/src/ErrorLogger

Perhaps just ship this logger instead of the current one. Here's how to use it:

C:\temp\net60>msbuild /l:C:\MSBuildTools\src\ErrorLogger\bin\Debug\netstandard2.0\ErrorLogger.dll /noconlog /nologo
##vso[task.logissue type=Error;sourcepath=C:\temp\net60\Program.cs;linenumber=22;columnnumber=9;code=CS1056;]Unexpected character '$'

[github-actions[bot]]

This issue is stale because it has been open for 180 days with no activity. Remove the stale label or comment on the issue otherwise this will be closed in 5 days

[KirillOsenkov]

this still needs fixing