KirillOsenkov / MSBuildStructuredLog

A logger for MSBuild that records a structured representation of executed targets, tasks, property and item values.
MIT License
1.45k stars 196 forks source link

How to release memory after reading and analyzing bin logs #633

Closed rkieslinger closed 1 year ago

rkieslinger commented 1 year ago

I'm using the nuget package MSBuild.StructuredLogger in an ASP.NET Core 7.0 application, to automatically analyze new builds from our Azure DevOps Pipelines.

The size of our bin logs is about 30 MB, but when I'm reading them using BinaryLog.ReadBuild(), it takes up to 8-9 GB RAM. That is not a huge problem, but after analyzing, it doesn't seem as if the memory will ever gets released. Because it's an ASP.NET Core service which is running 24/7 and analyzes about 100 builds a day, I'm a little worried.

I guess BinaryLog.ReadBuild() creates a lot of small objects, but shouldn't the Garbage Collector take care of them?

Thanks in advance and huge shoutout to everyone who helped creating this awesome tool. It helped us improving our builds so much.

KirillOsenkov commented 1 year ago

Thanks for the report! I did happen to fix a memory leak just yesterday: https://github.com/KirillOsenkov/MSBuildStructuredLog/commit/534eecf2ca7bb9afcff9bb56ad42c26cf0684f7f

Just published a new version: https://www.nuget.org/packages/MSBuild.StructuredLogger/2.1.745

It's possible that there are other memory leaks, but it's hard to say without debugging. You can capture a full memory dump of your process and then investigate it with a memory profiler such as JetBrains dotMemory or .NET MemProfiler. It will usually show you what reference chain is holding the "Build" object in memory.

KirillOsenkov commented 1 year ago

The memory consumption of 8-9 GB is expected, because binlog is a highly compressed format on disk, with string deduplication, etc. When it expands to load into memory it is expected to grow by 500-600x. However once you remove all references to the Build object, it should go away. If it doesn't, it's a memory leak and we have to look into it.

rkieslinger commented 1 year ago

I further analyzed it and it doesn't seem to be a memory leak. I couldn't find any left over references to the Build object and my process does not allocate more than like 8-9 GB RAM at any time, even there are 50 builds to be analyzed on a day. So it seems that the Garbage Collector is just a little lazy and only kicks in, when a new Build object (and childs) are being created.

When I add the following line, it immediately jumps down to about 100 MB:

GC.Collect(2, GCCollectionMode.Aggressive, true, true);
KirillOsenkov commented 1 year ago

Nice, glad to hear. I’m guessing it’s using the server GC mode which is optimized for more request handling throughput.