ecs-dotnet icon indicating copy to clipboard operation
ecs-dotnet copied to clipboard

[BUG] Memory leak

Open urielginsburg opened this issue 2 years ago • 1 comments

ECS integration/library project(s) (e.g. Elastic.CommonSchema.Serilog):

ECS schema version (e.g. 1.4.0): 8.6.1

ECS .NET assembly version (e.g. 1.4.2): 8.6.1

Elasticsearch version (if applicable): 8.6.2

.NET framework / OS: Core 7 / Any OS

During a soak test on an AKS cluster, during which we enabled verbose logging, our services reached staggering sizes of memory. I took a dmp with dotnet-dump and it turns out there are huge numbers of EcsDocument objects that remain in the generation 2 pool, even after they had been sent to elasticsearch (I verified several of the document instances actually existed in elasticsearch).

Steps to reproduce: As far as I can say, simply logging a big amount of log lines reproduces this behavior. I created a sample program to demonstrate this:

using Elastic.Serilog.Sinks;
using Serilog;

var memoryBefore = GC.GetTotalMemory(false);
Console.WriteLine($"Memory before: {memoryBefore} bytes");

Serilog.Debugging.SelfLog.Enable(s => Console.WriteLine(s));


Log.Logger = new LoggerConfiguration()
    .WriteTo.Elasticsearch(new[] { new Uri("http://localhost:9200") }, o =>
    {
        o.BootstrapMethod = Elastic.Ingest.Elasticsearch.BootstrapMethod.Failure;
        o.MinimumLevel = Serilog.Events.LogEventLevel.Verbose;
        o.DataStream = new Elastic.Ingest.Elasticsearch.DataStreams.DataStreamName("logs");
    }) 
    .CreateLogger();


var random = new Random();
Parallel.For(0, 10000, i =>
{
    var randomData = $"Logging information {i} - Random value: {random.NextDouble()}";
    Log.Information(randomData);
});

Log.CloseAndFlush();

await Task.Delay(TimeSpan.FromMinutes(1));

// Force garbage collection
GC.Collect();
GC.WaitForPendingFinalizers();
GC.Collect();

var memoryAfter = GC.GetTotalMemory(false);
Console.WriteLine($"Memory after: {memoryAfter} bytes");

var memoryUsed = memoryAfter - memoryBefore;
Console.WriteLine($"Memory used: {memoryUsed} bytes");

Here is the output of 'dotnet-dump analyze' of one of the instances:

> gcroot 0x7F09547ABCD8
HandleTable:
    00007f4904e113a8 (strong handle)
          -> 7f0904c04428     System.Object[]
          -> 7f092d05caf8     System.Buffers.TlsOverPerCoreLockedStacksArrayPool<Elastic.CommonSchema.EcsDocument>
          -> 7f092d05cb60     System.Buffers.TlsOverPerCoreLockedStacksArrayPool<Elastic.CommonSchema.EcsDocument>+PerCoreLockedStacks[]
          -> 7f092712fea0     System.Buffers.TlsOverPerCoreLockedStacksArrayPool<Elastic.CommonSchema.EcsDocument>+PerCoreLockedStacks
          -> 7f092712feb8     System.Buffers.TlsOverPerCoreLockedStacksArrayPool<Elastic.CommonSchema.EcsDocument>+LockedStack[]
          -> 7f0927130298     System.Buffers.TlsOverPerCoreLockedStacksArrayPool<Elastic.CommonSchema.EcsDocument>+LockedStack
          -> 7f09271302b8     Elastic.CommonSchema.EcsDocument[][]
          -> 7f09567f2568     Elastic.CommonSchema.EcsDocument[]
          -> 7f09547abcd8     Elastic.CommonSchema.EcsDocument

urielginsburg avatar Oct 20 '23 13:10 urielginsburg