dotnet / msbuild

The Microsoft Build Engine (MSBuild) is the build platform for .NET and Visual Studio.
https://docs.microsoft.com/visualstudio/msbuild/msbuild
MIT License
5.17k stars 1.34k forks source link

[Bug]: BuildCheck: Internal error thrown when reporting results #10176

Open ladipro opened 1 month ago

ladipro commented 1 month ago

Issue Description

When a build check subscribes to task invocation events and attempts to report a result from its task invocation action, MSBuild sometimes crashes with ContextID {0} should have been in the ID-to-project file mapping but wasn't!.

Steps to Reproduce

Reproduced with the upcoming DoubleWritesAnalyzer, for example.

Expected Behavior

The analyzer can report results from the task invocation action.

Actual Behavior

When building a larger solution with /m, the build fails with ContextID {0} should have been in the ID-to-project file mapping but wasn't! at this callstack:

    Microsoft.Build.Framework.dll!Microsoft.Build.Framework.InternalErrorException.LaunchDebugger(string message, string innerMessage) Line 134 C#
    Microsoft.Build.Framework.dll!Microsoft.Build.Framework.InternalErrorException.ConsiderDebuggerLaunch(string message, System.Exception innerException) Line 125 C#
    Microsoft.Build.Framework.dll!Microsoft.Build.Framework.InternalErrorException.InternalErrorException(string message) Line 38   C#
    Microsoft.Build.dll!Microsoft.Build.Shared.ErrorUtilities.ThrowInternalError(string message, object[] args) Line 58 C#
    Microsoft.Build.dll!Microsoft.Build.BackEnd.Logging.LoggingService.GetAndVerifyProjectFileFromContext(Microsoft.Build.Framework.BuildEventContext context) Line 1847    C#
    Microsoft.Build.dll!Microsoft.Build.BackEnd.Logging.LoggingService.LogBuildEvent(Microsoft.Build.Framework.BuildEventArgs buildEvent) Line 1195 C#
    Microsoft.Build.dll!Microsoft.Build.BackEnd.Logging.LoggingContext.LogBuildEvent(Microsoft.Build.Framework.BuildEventArgs buildEvent) Line 291  C#
    Microsoft.Build.dll!Microsoft.Build.Experimental.BuildCheck.Infrastructure.BuildEventsProcessor.ReportResult(Microsoft.Build.Experimental.BuildCheck.Infrastructure.BuildAnalyzerWrapper analyzerWrapper, Microsoft.Build.BackEnd.Logging.LoggingContext loggingContext, Microsoft.Build.Experimental.BuildCheck.Infrastructure.BuildAnalyzerConfigurationInternal[] configPerRule, Microsoft.Build.Experimental.BuildCheck.BuildCheckResult result) Line 195   C#
>   Microsoft.Build.dll!Microsoft.Build.Experimental.BuildCheck.BuildCheckDataContext<Microsoft.Build.Experimental.BuildCheck.TaskInvocationAnalysisData>.ReportResult(Microsoft.Build.Experimental.BuildCheck.BuildCheckResult result) Line 58 C#
    Microsoft.Build.dll!Microsoft.Build.Experimental.BuildCheck.Analyzers.DoubleWritesAnalyzer.AnalyzeWrite(Microsoft.Build.Experimental.BuildCheck.BuildCheckDataContext<Microsoft.Build.Experimental.BuildCheck.TaskInvocationAnalysisData> context, string fileBeingWritten) Line 97 C#
    Microsoft.Build.dll!Microsoft.Build.Experimental.BuildCheck.Analyzers.DoubleWritesAnalyzer.AnalyzeCopyTask(Microsoft.Build.Experimental.BuildCheck.BuildCheckDataContext<Microsoft.Build.Experimental.BuildCheck.TaskInvocationAnalysisData> context) Line 74   C#
    Microsoft.Build.dll!Microsoft.Build.Experimental.BuildCheck.Analyzers.DoubleWritesAnalyzer.TaskInvocationAction(Microsoft.Build.Experimental.BuildCheck.BuildCheckDataContext<Microsoft.Build.Experimental.BuildCheck.TaskInvocationAnalysisData> context) Line 46  C#
    Microsoft.Build.dll!Microsoft.Build.Experimental.BuildCheck.Infrastructure.BuildCheckCentralContext.RegisterAction.__WrappedHandler|0(Microsoft.Build.Experimental.BuildCheck.BuildCheckDataContext<Microsoft.Build.Experimental.BuildCheck.TaskInvocationAnalysisData> context) Line 62    C#
    Microsoft.Build.dll!Microsoft.Build.Experimental.BuildCheck.Infrastructure.BuildCheckCentralContext.RunRegisteredActions.AnonymousMethod__0((Microsoft.Build.Experimental.BuildCheck.Infrastructure.BuildAnalyzerWrapper, System.Action<Microsoft.Build.Experimental.BuildCheck.BuildCheckDataContext<Microsoft.Build.Experimental.BuildCheck.TaskInvocationAnalysisData>>) analyzerCallback) Line 155  C#
    [External Code] 
    Microsoft.Build.dll!Microsoft.Build.Experimental.BuildCheck.Infrastructure.BuildCheckCentralContext.RunRegisteredActions<Microsoft.Build.Experimental.BuildCheck.TaskInvocationAnalysisData>(System.Collections.Generic.List<(Microsoft.Build.Experimental.BuildCheck.Infrastructure.BuildAnalyzerWrapper, System.Action<Microsoft.Build.Experimental.BuildCheck.BuildCheckDataContext<Microsoft.Build.Experimental.BuildCheck.TaskInvocationAnalysisData>>)> registeredCallbacks, Microsoft.Build.Experimental.BuildCheck.TaskInvocationAnalysisData analysisData, Microsoft.Build.BackEnd.Logging.LoggingContext loggingContext, System.Action<Microsoft.Build.Experimental.BuildCheck.Infrastructure.BuildAnalyzerWrapper, Microsoft.Build.BackEnd.Logging.LoggingContext, Microsoft.Build.Experimental.BuildCheck.Infrastructure.BuildAnalyzerConfigurationInternal[], Microsoft.Build.Experimental.BuildCheck.BuildCheckResult> resultHandler) Line 112    C#
    Microsoft.Build.dll!Microsoft.Build.Experimental.BuildCheck.Infrastructure.BuildCheckCentralContext.RunTaskInvocationActions(Microsoft.Build.Experimental.BuildCheck.TaskInvocationAnalysisData taskInvocationAnalysisData, Microsoft.Build.BackEnd.Logging.LoggingContext loggingContext, System.Action<Microsoft.Build.Experimental.BuildCheck.Infrastructure.BuildAnalyzerWrapper, Microsoft.Build.BackEnd.Logging.LoggingContext, Microsoft.Build.Experimental.BuildCheck.Infrastructure.BuildAnalyzerConfigurationInternal[], Microsoft.Build.Experimental.BuildCheck.BuildCheckResult> resultHandler) Line 99 C#
    Microsoft.Build.dll!Microsoft.Build.Experimental.BuildCheck.Infrastructure.BuildEventsProcessor.ProcessTaskFinishedEventArgs(Microsoft.Build.Experimental.BuildCheck.Logging.AnalyzerLoggingContext buildAnalysisContext, Microsoft.Build.Framework.TaskFinishedEventArgs taskFinishedEventArgs) Line 131   C#
    Microsoft.Build.dll!Microsoft.Build.Experimental.BuildCheck.Infrastructure.BuildCheckManagerProvider.BuildCheckManager.ProcessTaskFinishedEventArgs(Microsoft.Build.Experimental.BuildCheck.Logging.AnalyzerLoggingContext buildAnalysisContext, Microsoft.Build.Framework.TaskFinishedEventArgs taskFinishedEventArgs) Line 339    C#
    Microsoft.Build.dll!Microsoft.Build.Experimental.BuildCheck.Infrastructure.BuildCheckConnectorLogger.HandleTaskFinishedEvent(Microsoft.Build.Framework.TaskFinishedEventArgs eventArgs) Line 90 C#
    Microsoft.Build.dll!Microsoft.Build.Experimental.BuildCheck.Infrastructure.BuildCheckConnectorLogger.GetBuildEventHandlers.AnonymousMethod__26_7(Microsoft.Build.Framework.BuildEventArgs e) Line 166   C#
    Microsoft.Build.dll!Microsoft.Build.Experimental.BuildCheck.Infrastructure.BuildCheckConnectorLogger.EventSource_AnyEventRaised(object sender, Microsoft.Build.Framework.BuildEventArgs e) Line 108 C#
    Microsoft.Build.dll!Microsoft.Build.BackEnd.Logging.EventSourceSink.RaiseAnyEvent(object sender, Microsoft.Build.Framework.BuildEventArgs buildEvent) Line 911  C#
    Microsoft.Build.dll!Microsoft.Build.BackEnd.Logging.EventSourceSink.RaiseStatusEvent(object sender, Microsoft.Build.Framework.BuildStatusEventArgs buildEvent) Line 860 C#
    Microsoft.Build.dll!Microsoft.Build.BackEnd.Logging.EventSourceSink.RaiseTaskFinishedEvent(object sender, Microsoft.Build.Framework.TaskFinishedEventArgs buildEvent) Line 776  C#
    Microsoft.Build.dll!Microsoft.Build.BackEnd.Logging.EventSourceSink.Consume(Microsoft.Build.Framework.BuildEventArgs buildEvent) Line 236   C#
    Microsoft.Build.dll!Microsoft.Build.BackEnd.Logging.EventSourceSink.Consume(Microsoft.Build.Framework.BuildEventArgs buildEvent, int sinkId) Line 218   C#
    Microsoft.Build.dll!Microsoft.Build.BackEnd.Logging.LoggingService.RouteBuildEvent(System.Collections.Generic.KeyValuePair<int, Microsoft.Build.Framework.BuildEventArgs> nodeEvent) Line 1631  C#
    Microsoft.Build.dll!Microsoft.Build.BackEnd.Logging.LoggingService.RouteBuildEvent(object loggingEvent) Line 1615   C#
    Microsoft.Build.dll!Microsoft.Build.BackEnd.Logging.LoggingService.LoggingEventProcessor(object loggingEvent) Line 1455 C#
    Microsoft.Build.dll!Microsoft.Build.BackEnd.Logging.LoggingService.StartLoggingEventProcessing.__LoggingEventProc|141_0() Line 1342 C#

Analysis

Build check infra uses the BuildEventContext as passed to the AnyEventRaised handler of the build check logger. Apparently this context is not good for raising new events. It's not immediately clear to me where the bug is - either build check infra shouldn't be reusing the incoming context (because it could come from another node?) or logging infra should properly translate it when moving across processes. cc @JanKrivanek.

Versions & Configurations

MSBuild.exe built at commit 2d924ca8c28f63e3b562f05525a4fd4cb8c792aa

JanKrivanek commented 1 month ago

Goot catch and analysis!

Apparently the BuildEventContext is currently good for logging only in the node that created it via LogProjectStarted - as that's the only place where the _projectFileMap is filled (appart from project caching scenarios - that we can igfnore here):

https://github.com/dotnet/msbuild/blob/db79545e5940a69560c4885b792ef3a359f0de68/src/Build/BackEnd/Components/Logging/LoggingServiceLogMethods.cs#L509-L586

The other interresting thing is that this doesn't manifest in the out-of-proc end-2-end unit tests - this is given by the fact that ProjectContextId of the transfered BuildEventContext (attached to the BuildEvent) is initialized to invalid project (-2).

So it means: