Add GC time to the .Net Agent

[jpenniman]

The .Net Agent already records the number collections and the heap sizes, however it is missing the pause time.

Recording GC pause times is critical for identifying memory leaks. When troubleshooting high memory utilization, we want to answer: "Is CPU high too?" and "How much of that CPU time is being used by the garbage collector?" If the garbage collector is running a lot, but collecting very little, it's an indication that there is likely a memory leak. Long GC pause times can also cause application performance issues even without a memory leak. Understanding pause times is key to understanding if application slowness is possibly do to long pause times or too frequent pauses.

The Java agent records: jvm.gc.time

I'm proposing a .net equivalent: clr.gc.time

For full framework:

_traceEventSession.Source.AddCallbackOnProcessStart(process =>
{
	process.AddCallbackOnDotNetRuntimeLoad(runtime =>
	{
		runtime.GCEnd += (traceProcess, gc) =>
		{
			if (traceProcess.ProcessID == Process.GetCurrentProcess().Id)
				_gcPauseTime = gc.PauseDurationMSec;
		};
	});
});

.Net Core doens't write pause time data o the event, but it can be calculated by capturing the instant of GCStart and doing the math in GCEnd. It's not perfect, since not all collections stop the world. Labeling the metric with the generation being collected and GC settings can help the engineer determine if the gc.time is a pause or not.

sealed class GcEventListener : EventListener
{
    long _gcStartTime;

    protected override void OnEventWritten(EventWrittenEventArgs eventData)
    {
        if (eventData.EventId == GcStartEvent)
        {
            _gcStartTime = DateTime.UtcNow.Ticks;
        }
        else if (eventData.EventId == GcEndEvent)
        {
            var gcStopTime = DateTime.UtcNow.Ticks;
            var pauseTime = (double)(gcStopTime - _gcStartTime) / 10_000.0
        }
    }
}

Our application currently uses similar code to get the GC Pause time. We've tested code in net461, net472, and netcoreapp3.1 on both Windows and Linux, and it successfully reports GC pause times in all targets. Ideally, we'd like to get this functionality into the Agent, so it's something we don't have to maintain separately.

I'm available to add this feature one we can agree on implementation approach.

[gregkalapos]

Hi @jpenniman

sounds reasonable. The set of metrics the agent currently collects is definitely not final, we plan to extend it and iterate on it. I'd be happy to help and review this if you open a PR.

The name clr.gc.time (in sync with the Java Agent) as you suggest sounds good to me.

And also the 2 proposed solutions are ok. You probably already found this file where you can implement it.

Before you open a PR please quickly go through our CONTRIBUTING.md.

[jpenniman]

Ok great. I'll go through the doc and sign the agreement.

[russcam]

This was implemented in #925.