MSBUILD : corefx: error MSB4017: The build stopped unexpectedly because of an unexpected logger failure. #4098
Comments
|
Looks like we could nullref in that method if we were passed null: It's coming from a And that ctor mostly just passes along the passed-in item list which I wouldn't expect to have any null entries. @robertborr Does this repro consistently? |
|
We just hit this in another Linux build. https://dev.azure.com/dnceng/public/_build/results?buildId=81583 Note that the callstack shown differs by 1 line after Write(ITaskItem item) call. It has item.CloneCustomMetadata in the callstack, which tells me that item wouldn't be null in that case. 2019-01-28T21:50:31.9837577Z 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.
+ 2019-01-28T21:50:31.9838228Z at Microsoft.Build.Execution.ProjectItemInstance.TaskItem.CloneCustomMetadata()
2019-01-28T21:50:31.9838392Z at Microsoft.Build.Logging.BuildEventArgsWriter.Write(ITaskItem item)
2019-01-28T21:50:31.9838539Z at Microsoft.Build.Logging.BuildEventArgsWriter.WriteItems(IEnumerable items)
2019-01-28T21:50:31.9838676Z at Microsoft.Build.Logging.BuildEventArgsWriter.Write(ProjectStartedEventArgs e)
2019-01-28T21:50:31.9838827Z at Microsoft.Build.Logging.BuildEventArgsWriter.Write(BuildEventArgs e)
2019-01-28T21:50:31.9838971Z at Microsoft.Build.Logging.BinaryLogger.Write(BuildEventArgs e)
2019-01-28T21:50:31.9839121Z at Microsoft.Build.Logging.BinaryLogger.EventSource_AnyEventRaised(Object sender, BuildEventArgs e)
2019-01-28T21:50:31.9839279Z at Microsoft.Build.Evaluation.ProjectCollection.ReusableLogger.AnyEventRaisedHandler(Object sender, BuildEventArgs e)
2019-01-28T21:50:31.9839452Z at Microsoft.Build.BackEnd.Logging.EventSourceSink.RaiseAnyEvent(Object sender, BuildEventArgs buildEvent)
2019-01-28T21:50:31.9839907Z --- End of inner exception stack trace ---
2019-01-28T21:50:31.9840084Z at Microsoft.Build.Exceptions.InternalLoggerException.Throw(Exception innerException, BuildEventArgs e, String messageResourceName, Boolean initializationException, String[] messageArgs)
2019-01-28T21:50:31.9840288Z at Microsoft.Build.BackEnd.Logging.EventSourceSink.RaiseAnyEvent(Object sender, BuildEventArgs buildEvent)
2019-01-28T21:50:31.9840463Z at Microsoft.Build.BackEnd.Logging.EventSourceSink.RaiseStatusEvent(Object sender, BuildStatusEventArgs buildEvent)
2019-01-28T21:50:31.9840644Z at Microsoft.Build.BackEnd.Logging.EventSourceSink.RaiseProjectStartedEvent(Object sender, ProjectStartedEventArgs buildEvent)
2019-01-28T21:50:31.9840800Z at Microsoft.Build.BackEnd.Logging.EventSourceSink.Consume(BuildEventArgs buildEvent)
2019-01-28T21:50:31.9840960Z at Microsoft.Build.BackEnd.Logging.EventSourceSink.Consume(BuildEventArgs buildEvent, Int32 sinkId)
2019-01-28T21:50:31.9841160Z at Microsoft.Build.BackEnd.Logging.EventRedirectorToSink.Microsoft.Build.Framework.IEventRedirector.ForwardEvent(BuildEventArgs buildEvent)
2019-01-28T21:50:31.9841349Z at Microsoft.Build.BackEnd.Logging.CentralForwardingLogger.EventSource_AnyEventRaised(Object sender, BuildEventArgs buildEvent)
2019-01-28T21:50:31.9841512Z at Microsoft.Build.BackEnd.Logging.EventSourceSink.RaiseAnyEvent(Object sender, BuildEventArgs buildEvent)
2019-01-28T21:50:32.0326589Z Build failed (exit code '1'). |
|
There are two implementations of 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;
}
Implementation of 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 |
This comment has been minimized.
This comment has been minimized.
This comment has been minimized.
This comment has been minimized.
This comment has been minimized.
This comment has been minimized.
This comment has been minimized.
This comment has been minimized.
This comment has been minimized.
This comment has been minimized.
This comment has been minimized.
This comment has been minimized.
|
Happened again in corefx: https://dnceng.visualstudio.com/public/_build/results?buildId=339171&view=logs |
This comment has been minimized.
This comment has been minimized.
|
The fact that it's intermittent suggests to me that Dan is right and it's an unprotected Dictionary access (race condition). If some metadata.Name was actually null we'd see it reliably all the time. Just locking around it would probably be expensive? |
|
Hi, I'm blocked by this issue. May I know if there is any workaround here? Thanks! I encountered this issue when I build our projects (starting from changing TFM to netcoreapp5.0). |
|
@heng-liu your callstack is different, it looks like a bug in |
|
@wli3 another example of an issue with the MSBuildLogger.FormatAndSend. I tagged on on a different issue for this earlier today. |
|
@heng-liu that is a separate issue. dotnet/sdk#3868 |
|
Thanks all for your help! |
|
Hello. Experiencing same issue while trying to compile cmake based project. Clean VS 2019 install. |
|
Hello, We are having similar issue with MSBuild
A full reproduction repository can be found here bouchraRekhadda/ColorLogger |
|
Any update please on the above request ? |
In corefx build https://dnceng.visualstudio.com/internal/_build/results?buildId=79263
failed with this issue.
The connected issue is : https://github.com/dotnet/core-eng/issues/5071
The issue seems to be similar to
The text was updated successfully, but these errors were encountered: