Skip to content

Commit

Permalink
Make sure the TraceEventSession is stopped in GcMetricsProvider (#1218)
Browse files Browse the repository at this point in the history 
* Update MetricsTests.cs

Do allocations on LOH and trigger LOH GC

* GC metrics: call _traceEventSession.Stop

* Update GcMetricsProvider.cs

* Update GcMetricsProvider.cs

Use TraceLoadedDotNetRuntime.GCEnd to get GC duration instead of manually calculating it on Full Framework

* Update GcMetricsProvider.cs

* Update MetricsCollector.cs

GcMetricsProvider has dependencies that can't be loaded in some environment - therefore we try-catch the `new GcMetricsProvider`  line.

* GC test: decrease number of iterations and handle when _traceEventSessionTask == null

* Reuse _currentProcessId variable and avoid code elimination in GC test
  • Loading branch information
@gregkalapos
gregkalapos authored Mar 16, 2021
1 parent 648595b commit 88a8d64
Show file tree
Hide file tree
Showing 3 changed files with 65 additions and 46 deletions.
11 changes: 9 additions & 2 deletions src/Elastic.Apm/Metrics/MetricsCollector.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -97,8 +97,15 @@ public MetricsCollector(IApmLogger logger, IPayloadSender payloadSender, IConfig
GcMetricsProvider.GcTimeName);
if (collectGcCount || collectGen0Size || collectGen1Size || collectGen2Size || collectGen3Size)
{
MetricsProviders.Add(new GcMetricsProvider(_logger, collectGcCount, collectGen0Size, collectGen1Size, collectGen2Size,
collectGen3Size, collectGcTime));
try
{
MetricsProviders.Add(new GcMetricsProvider(_logger, collectGcCount, collectGen0Size, collectGen1Size, collectGen2Size,
collectGen3Size, collectGcTime));
}
catch (Exception e)
{
_logger.Warning()?.LogException(e, "Failed loading {ProviderName}", nameof(GcMetricsProvider));
}
}

var collectCgroupMemLimitBytes = !WildcardMatcher.IsAnyMatch(currentConfigSnapshot.DisableMetrics,
Expand Down
75 changes: 40 additions & 35 deletions src/Elastic.Apm/Metrics/MetricsProvider/GcMetricsProvider.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -50,6 +50,7 @@ internal class GcMetricsProvider : IMetricsProvider, IDisposable
private readonly TraceEventSession _traceEventSession;
private readonly Task _traceEventSessionTask;
private readonly int _currentProcessId;
private TraceLoadedDotNetRuntime _traceLoadedDotNetRuntime;

private volatile bool _isMetricAlreadyCaptured;
private uint _gcCount;
Expand All @@ -58,7 +59,6 @@ internal class GcMetricsProvider : IMetricsProvider, IDisposable
private ulong _gen2Size;
private ulong _gen3Size;
private long _gcTimeInTicks;
private long _gcStartTime;

public GcMetricsProvider(IApmLogger logger, bool collectGcCount = true, bool collectGcGen0Size = true, bool collectGcGen1Size = true,
bool collectGcGen2Size = true, bool collectGcGen3Size = true, bool collectGcTime = true
Expand All @@ -74,35 +74,42 @@ public GcMetricsProvider(IApmLogger logger, bool collectGcCount = true, bool col

if (PlatformDetection.IsDotNetFullFramework)
{
TraceEventSessionName = SessionNamePrefix + Guid.NewGuid();
_traceEventSession = new TraceEventSession(TraceEventSessionName);
_currentProcessId = Process.GetCurrentProcess().Id;
_traceEventSessionTask = Task.Run(() =>
try
{
try
{
_traceEventSession.Source.NeedLoadedDotNetRuntimes();
_traceEventSession.EnableProvider(
ClrTraceEventParser.ProviderGuid,
TraceEventLevel.Informational,
(ulong)ClrTraceEventParser.Keywords.GC // garbage collector details
);
}
catch (Exception e)
TraceEventSessionName = SessionNamePrefix + Guid.NewGuid();
_traceEventSession = new TraceEventSession(TraceEventSessionName);
_currentProcessId = Process.GetCurrentProcess().Id;

_traceEventSession.Source.NeedLoadedDotNetRuntimes();
_traceEventSession.EnableProvider(
ClrTraceEventParser.ProviderGuid,
TraceEventLevel.Informational,
(ulong)ClrTraceEventParser.Keywords.GC // garbage collector details
);

_traceEventSession.Source.AddCallbackOnProcessStart(process =>
{
_logger.Warning()?.LogException(e, "TraceEventSession initialization failed - GC metrics won't be collected");
return;
}
process.AddCallbackOnDotNetRuntimeLoad(runtime =>
{
_traceLoadedDotNetRuntime = runtime;
runtime.GCEnd += RuntimeGCEnd;
});
});

_traceEventSession.Source.Clr.GCStop += ClrOnGCStop;
_traceEventSession.Source.Clr.GCHeapStats += ClrOnGCHeapStats;
_traceEventSession.Source.Clr.GCStart += ClrOnStart;

_traceEventSession.Source.Process();
});
_traceEventSessionTask = Task.Run(() =>
{
_traceEventSession.Source.Process();
});
}
catch (Exception e)
{
_logger.Warning()?.LogException(e, "TraceEventSession initialization failed - GC metrics won't be collected");
return;
}
}


if (PlatformDetection.IsDotNetCore || PlatformDetection.IsDotNet5)
_eventListener = new GcEventListener(this, logger);
}
Expand Down Expand Up @@ -161,12 +168,15 @@ public void Dispose()
_eventListener?.Dispose();
if (_traceEventSession != null)
{
_traceEventSession.Source.Clr.GCStop -= ClrOnGCStop;
_traceEventSession.Source.Clr.GCHeapStats -= ClrOnGCHeapStats;
_traceEventSession.Source.Clr.GCStart -= ClrOnStart;
if (_traceLoadedDotNetRuntime != null)
_traceLoadedDotNetRuntime.GCEnd -= RuntimeGCEnd;

_traceEventSession.Stop(true);
_traceEventSession.Source.Dispose();
_traceEventSession.Dispose();

if (_traceEventSessionTask.IsCompleted || _traceEventSessionTask.IsFaulted || _traceEventSessionTask.IsCanceled)
if (_traceEventSessionTask != null && (_traceEventSessionTask.IsCompleted || _traceEventSessionTask.IsFaulted || _traceEventSessionTask.IsCanceled))
_traceEventSessionTask.Dispose();
}
}
Expand All @@ -187,22 +197,17 @@ private void ClrOnGCHeapStats(GCHeapStatsTraceData a)
}
}

private void ClrOnStart(GCStartTraceData obj) => Interlocked.Exchange(ref _gcStartTime, DateTime.UtcNow.Ticks);

private void ClrOnGCStop(GCEndTraceData a)
private void RuntimeGCEnd(TraceProcess traceProcess, Microsoft.Diagnostics.Tracing.Analysis.GC.TraceGC gc)
{
if (a.ProcessID == _currentProcessId)
if (traceProcess.ProcessID == _currentProcessId)
{
if (!_isMetricAlreadyCaptured)
{
lock (_lock)
_isMetricAlreadyCaptured = true;
}

var durationInTicks = DateTime.UtcNow.Ticks - Interlocked.Read(ref _gcStartTime);
Interlocked.Exchange(ref _gcTimeInTicks, Interlocked.Read(ref _gcTimeInTicks) + durationInTicks);

_gcCount = (uint)a.Count;
_gcTimeInTicks = (long)gc.DurationMSec * 10_000;
_gcCount = (uint)gc.Number;
}
}

Expand Down
25 changes: 16 additions & 9 deletions test/Elastic.Apm.Tests/MetricsTests.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -101,7 +101,7 @@ public void ProviderWithException()
{
var mockPayloadSender = new MockPayloadSender();
var testLogger = new TestLogger(LogLevel.Information);
using (var mc = new MetricsCollector(testLogger, mockPayloadSender, new ConfigStore(new MockConfigSnapshot(), testLogger)))
using (var mc = new MetricsCollector(testLogger, mockPayloadSender, new ConfigStore(new MockConfigSnapshot(disableMetrics: "*"), testLogger)))
{
mc.MetricsProviders.Clear();
var providerWithException = new MetricsProviderWithException();
Expand Down Expand Up @@ -298,22 +298,29 @@ public void CollectGcMetrics()
var hasGenSize = false;
var hasGcTime = false;


for (var j = 0; j < 1000; j++)
for (var j = 0; j < 10; j++)
{
for (var i = 0; i < 300_000; i++)
for (var i = 0; i < 500; i++)
{
var _ = new int[100];
var array = new int[10000000];
// In order to make sure the line above is not optimized away, let's use the array:
Console.WriteLine($"GC test, int[] allocated with length: {array.Length}");
}

GC.Collect();
GC.Collect(2, GCCollectionMode.Forced, true, true);
GC.WaitForFullGCComplete();
GC.Collect(2, GCCollectionMode.Forced, true, true);

for (var i = 0; i < 300_000; i++)
for (var i = 0; i < 500; i++)
{
var _ = new int[100];
var array = new int[10000000];
// In order to make sure the line above is not optimized away, let's use the array:
Console.WriteLine($"GC test, int[] allocated with length: {array.Length}");
}

GC.Collect();
GC.Collect(2, GCCollectionMode.Forced, true, true);
GC.WaitForFullGCComplete();
GC.Collect(2, GCCollectionMode.Forced, true, true);

var samples = gcMetricsProvider.GetSamples()?.ToArray();

Expand Down

0 comments on commit 88a8d64

Please sign in to comment.