msbuild: [Bug]: msbuild binary logger generating excessive memory spike at end of build
Issue Description
When running msbuild /t:restore /bl on a large repo we are running out of memory at the end of the build on a 64GB machine. We see a large spike in memory after the console output shows the build as complete, before the process terminates with an out of memory exception.
This is a regression for as we started seeing this behavior in 17.6 preview, but we did not see this behavior in VS 17.5.
Steps to Reproduce
We have a large repo.
Expected Behavior
Expect that we can complete restore build with less than 64GB of memory, we do not see a memory spike with VS 17.5.
MSBuild version 17.5.1+f6fdcf537 for .NET Framework

Actual Behavior
We are seeing a huge 30GB memory spike after the build completes and an out of memory exception.
MSBuild version 17.6.0-preview-23164-01+18fe51042 for .NET Framework

Build succeeded.
0 Warning(s)
0 Error(s)
Time Elapsed 00:09:43.47
MSBUILD : error MSB1025: An internal failure occurred while running MSBuild.
Microsoft.Build.Framework.InternalErrorException: MSB0001: Internal MSBuild Error: Throwing from logger shutdown
=============
System.OutOfMemoryException: Exception of type 'System.OutOfMemoryException' was thrown.
at System.IO.MemoryStream.set_Capacity(Int32 value)
at System.IO.MemoryStream.EnsureCapacity(Int32 value)
at System.IO.MemoryStream.Write(Byte[] buffer, Int32 offset, Int32 count)
at System.IO.Compression.ZipArchiveEntry.WriteCentralDirectoryFileHeader()
at System.IO.Compression.ZipArchive.WriteFile()
at System.IO.Compression.ZipArchive.Dispose(Boolean disposing)
at Microsoft.Build.Logging.ProjectImportsCollector.Close(Boolean closeStream)
at Microsoft.Build.Logging.ProjectImportsCollector.GetAllBytes()
at Microsoft.Build.Logging.BinaryLogger.Shutdown()
at Microsoft.Build.BackEnd.Logging.LoggingService.ShutdownLogger(ILogger logger)
at Microsoft.Build.BackEnd.Logging.LoggingService.ShutdownComponent()
at Microsoft.Build.Evaluation.ProjectCollection.ShutDownLoggingService()
---> System.OutOfMemoryException: Exception of type 'System.OutOfMemoryException' was thrown.
at System.IO.MemoryStream.set_Capacity(Int32 value)
at System.IO.MemoryStream.EnsureCapacity(Int32 value)
at System.IO.MemoryStream.Write(Byte[] buffer, Int32 offset, Int32 count)
at System.IO.Compression.ZipArchiveEntry.WriteCentralDirectoryFileHeader()
at System.IO.Compression.ZipArchive.WriteFile()
at System.IO.Compression.ZipArchive.Dispose(Boolean disposing)
at Microsoft.Build.Logging.ProjectImportsCollector.Close(Boolean closeStream)
at Microsoft.Build.Logging.ProjectImportsCollector.GetAllBytes()
at Microsoft.Build.Logging.BinaryLogger.Shutdown()
at Microsoft.Build.BackEnd.Logging.LoggingService.ShutdownLogger(ILogger logger)
at Microsoft.Build.BackEnd.Logging.LoggingService.ShutdownComponent()
at Microsoft.Build.Evaluation.ProjectCollection.ShutDownLoggingService()
--- End of inner exception stack trace ---
at Microsoft.Build.Shared.ErrorUtilities.ThrowInternalError(String message, Exception innerException, Object[] args)
at Microsoft.Build.Evaluation.ProjectCollection.ShutDownLoggingService()
at Microsoft.Build.Evaluation.ProjectCollection.Dispose(Boolean disposing)
at Microsoft.Build.CommandLine.MSBuildApp.BuildProject(String projectFile, String[] targets, String toolsVersion, Dictionary`2 globalProperties, Dictionary`2 restoreProperties, ILogger[] loggers, LoggerVerbosity verbosity, DistributedLoggerRecord[] distributedLoggerRecords, Boolean needToValidateProject, String schemaFile, Int32 cpuCount, Boolean enableNodeReuse, TextWriter preprocessWriter, TextWriter targetsWriter, Boolean detailedSummary, ISet`1 warningsAsErrors, ISet`1 warningsNotAsErrors, ISet`1 warningsAsMessages, Boolean enableRestore, ProfilerLogger profilerLogger, Boolean enableProfiler, Boolean interactive, ProjectIsolationMode isolateProjects, GraphBuildOptions graphBuildOptions, Boolean lowPriority, String[] inputResultsCaches, String outputResultsCache, String commandLine)
at Microsoft.Build.CommandLine.MSBuildApp.Execute(String commandLine)
Unhandled Exception: Microsoft.Build.Framework.InternalErrorException: MSB0001: Internal MSBuild Error: Throwing from logger shutdown
=============
System.OutOfMemoryException: Exception of type 'System.OutOfMemoryException' was thrown.
at System.IO.MemoryStream.set_Capacity(Int32 value)
at System.IO.MemoryStream.EnsureCapacity(Int32 value)
at System.IO.MemoryStream.Write(Byte[] buffer, Int32 offset, Int32 count)
at System.IO.Compression.ZipArchiveEntry.WriteCentralDirectoryFileHeader()
at System.IO.Compression.ZipArchive.WriteFile()
at System.IO.Compression.ZipArchive.Dispose(Boolean disposing)
at Microsoft.Build.Logging.ProjectImportsCollector.Close(Boolean closeStream)
at Microsoft.Build.Logging.ProjectImportsCollector.GetAllBytes()
at Microsoft.Build.Logging.BinaryLogger.Shutdown()
at Microsoft.Build.BackEnd.Logging.LoggingService.ShutdownLogger(ILogger logger)
at Microsoft.Build.BackEnd.Logging.LoggingService.ShutdownComponent()
at Microsoft.Build.Evaluation.ProjectCollection.ShutDownLoggingService()
---> System.OutOfMemoryException: Exception of type 'System.OutOfMemoryException' was thrown.
at System.IO.MemoryStream.set_Capacity(Int32 value)
at System.IO.MemoryStream.EnsureCapacity(Int32 value)
at System.IO.MemoryStream.Write(Byte[] buffer, Int32 offset, Int32 count)
at System.IO.Compression.ZipArchiveEntry.WriteCentralDirectoryFileHeader()
at System.IO.Compression.ZipArchive.WriteFile()
at System.IO.Compression.ZipArchive.Dispose(Boolean disposing)
at Microsoft.Build.Logging.ProjectImportsCollector.Close(Boolean closeStream)
at Microsoft.Build.Logging.ProjectImportsCollector.GetAllBytes()
at Microsoft.Build.Logging.BinaryLogger.Shutdown()
at Microsoft.Build.BackEnd.Logging.LoggingService.ShutdownLogger(ILogger logger)
at Microsoft.Build.BackEnd.Logging.LoggingService.ShutdownComponent()
at Microsoft.Build.Evaluation.ProjectCollection.ShutDownLoggingService()
--- End of inner exception stack trace ---
at Microsoft.Build.Shared.ErrorUtilities.ThrowInternalError(String message, Exception innerException, Object[] args)
at Microsoft.Build.Evaluation.ProjectCollection.ShutDownLoggingService()
at Microsoft.Build.Evaluation.ProjectCollection.Dispose(Boolean disposing)
at Microsoft.Build.CommandLine.MSBuildApp.BuildProject(String projectFile, String[] targets, String toolsVersion, Dictionary`2 globalProperties, Dictionary`2 restoreProperties, ILogger[] loggers, LoggerVerbosity verbosity, DistributedLoggerRecord[] distributedLoggerRecords, Boolean needToValidateProject, String schemaFile, Int32 cpuCount, Boolean enableNodeReuse, TextWriter preprocessWriter, TextWriter targetsWriter, Boolean detailedSummary, ISet`1 warningsAsErrors, ISet`1 warningsNotAsErrors, ISet`1 warningsAsMessages, Boolean enableRestore, ProfilerLogger profilerLogger, Boolean enableProfiler, Boolean interactive, ProjectIsolationMode isolateProjects, GraphBuildOptions graphBuildOptions, Boolean lowPriority, String[] inputResultsCaches, String outputResultsCache, String commandLine)
at Microsoft.Build.CommandLine.MSBuildApp.Execute(String commandLine)
at Microsoft.Build.CommandLine.MSBuildApp.Main()
Analysis
Passing the additional parameter /bl:ProjectImports=None is a workaround for the issue, but not ideal as we prefer to collect complete binlogs from our build agents.
Versions & Configurations
MSBuild version 17.6.0-preview-23164-01+18fe51042 for .NET Framework 17.6.0.16401
About this issue
- Original URL
- State: closed
- Created a year ago
- Reactions: 1
- Comments: 23 (20 by maintainers)
Commits related to this issue
- Fix binlog OOM embedding files Fixes #8595 by storing the embedded-file zip in a temporary directory (instead of memory or binlog target directory) to avoid problems with file watchers. — committed to dotnet/msbuild by rainersigwald a year ago
- Fix binlog OOM embedding files Fixes #8595 by storing the embedded-file zip in a temporary directory (instead of memory or binlog target directory) to avoid problems with file watchers. — committed to YuliiaKovalova/msbuild by rainersigwald a year ago
yeah, agree that a low-risk fix would be to revert the original change, store the zip in a temp location, and then only if we’re not embedding it, move the temp file to the source directory (to preserve prior behavior). if we are embedding it, just read it via streams (not byte[]), then delete the temporary zip.
Yup, we were just getting lucky. Not blaming your change, it was a good fix. Just started seeing some really huge builds and it became a problem. I think if we can get a safe temp file location, unique per process, we should write to that instead of the memory stream. Definitely shouldn’t be creating any files in the source directory.