msbuild: MSBUILD : corefx: error MSB4017: The build stopped unexpectedly because of an unexpected logger failure.

What I saw was caused by a DEVPATH that pointed to a bad file. Thanks, @KirillOsenkov

Hello,

We are having similar issue with MSBuild 17.1.0 (from VS 2022 17.1.2 installation) when using maximum CPU count, i.e. /m

MSBUILD : error MSB4017: The build stopped unexpectedly because of an unexpected logger failure. Microsoft.Build.Exceptions.InternalLoggerException: The build stopped unexpectedly because of an unexpected logger failure. —> System.NullReferenceException: Object reference not set to an instance of an object. at Microsoft.Build.BackEnd.Logging.ParallelConsoleLogger.WriteMessageAligned(String message, Boolean prefixAlreadyWritten, Int32 prefixAdjustment) at Microsoft.Build.BackEnd.Logging.ParallelConsoleLogger.PrintTargetNamePerMessage(BuildMessageEventArgs e, Boolean lightenText) at Microsoft.Build.BackEnd.Logging.ParallelConsoleLogger.PrintMessage(BuildMessageEventArgs e, Boolean lightenText) at Microsoft.Build.BackEnd.Logging.ParallelConsoleLogger.MessageHandler(Object sender, BuildMessageEventArgs e) at Microsoft.Build.Logging.ConsoleLogger.MessageHandler(Object sender, BuildMessageEventArgs e) at ColorLogger.ColorLogger.MessageHandler(Object sender, BuildMessageEventArgs e) in C:\Users\bouchraREKHADDA\source\repos\ColorLogger\ColorLogger.cs:line 140 at Microsoft.Build.Evaluation.ProjectCollection.ReusableLogger.MessageRaisedHandler(Object sender, BuildMessageEventArgs e) at Microsoft.Build.BackEnd.Logging.EventSourceSink.RaiseMessageEvent(Object sender, BuildMessageEventArgs buildEvent) — End of inner exception stack trace — at Microsoft.Build.Exceptions.InternalLoggerException.Throw(Exception innerException, BuildEventArgs e, String messageResourceName, Boolean initializationException, String[] messageArgs) at Microsoft.Build.BackEnd.Logging.EventSourceSink.RaiseMessageEvent(Object sender, BuildMessageEventArgs buildEvent) at Microsoft.Build.BackEnd.Logging.EventSourceSink.Consume(BuildEventArgs buildEvent) at Microsoft.Build.BackEnd.Logging.EventSourceSink.Consume(BuildEventArgs buildEvent, Int32 sinkId) at Microsoft.Build.BackEnd.Logging.EventRedirectorToSink.Microsoft.Build.Framework.IEventRedirector.ForwardEvent(BuildEventArgs buildEvent) at Microsoft.Build.BackEnd.Logging.CentralForwardingLogger.EventSource_AnyEventRaised(Object sender, BuildEventArgs buildEvent) at Microsoft.Build.BackEnd.Logging.EventSourceSink.RaiseAnyEvent(Object sender, BuildEventArgs buildEvent)

A full reproduction repository can be found here bouchraRekhadda/ColorLogger

There’s really not. The environment caused a mismatched system.dll to be loaded.

There are two implementations of CloneCustomMetadata() … ProjectItemInstance and TaskItem. I assume the logger gets the former:

            public IDictionary CloneCustomMetadata()
            {
                Dictionary<string, string> clonedMetadata = new Dictionary<string, string>(MSBuildNameIgnoreCaseComparer.Default);

                foreach (ProjectMetadataInstance metadatum in MetadataCollection)
                {
                    clonedMetadata[metadatum.Name] = metadatum.EvaluatedValue;
                }

                return clonedMetadata;
            }

clonedMetadata cannot be null. Also since MetadataCollection getter is not on the stack, and looks too big to inline I assume the NullReferenceException does not come from within it. And by inspection, it will never return null either. So either the dictionary contains a null metadatum - and from a quick look (I didn’t look carefully), it should not, because it uses key off each entry as its internal key - or something else is happening.

Implementation of CloneCustomMetadata() in TaskItem, if that’s relevant, is similar, again the source and target collection is checked for null.

Suggestion - some unprotected concurrent read and write to the backing dictionary here, either source or destination. That can often manifest as a NullReferenceException when accessing a dictionary. Since there’s definitely multithreading going on here, perhaps one thread didn’t properly “let go” of this item before it got to the logging thread?

If that’s a possibility, as well as code inspection, another possibility is swapping out the relevant Dictionary<K,V>'s with some custom dictionary that immediatley breaks into the debugger when a write occurs to it concurrent with another read (or write). That might possibly, in stress runs, cause this issue to happen locally, and make it possible to find the “other” callstack.