Timing how long garbage collection is taking in C#

Question

I'm concerned about how much time my application could be spending during garbage collection so I'm trying to figure out how to add some code to instrument this.

Based on some examples:

• https://msdn.microsoft.com/en-us/library/cc713687(v=vs.110).aspx
• http://www.codeproject.com/Articles/101136/Garbage-Collection-Notifications-in-NET

I've come up with the code below. I'm see GC taking around 200 ms locally. Does anyone know if the code below is reasonable? Or is there a better way?

class Program
{
 public static void Main(string[] args)
 {
 var done = false;
 var load = new List<byte[]>();
 var pollGC = new Action(() =>
 {
 // Register for a notification. 
 GC.RegisterForFullGCNotification(10, 10);
 Console.WriteLine("Registered for GC notification.");
 Stopwatch gcTimer = new Stopwatch();
 while (!done)
 {
 // Check for a notification of an approaching collection.
 GCNotificationStatus s = GC.WaitForFullGCApproach();
 if (s == GCNotificationStatus.Succeeded)
 {
 Console.WriteLine("GC is about to start.");
 load.Clear();
 gcTimer.Restart();
 }
 // Check for a notification of a completed collection.
 s = GC.WaitForFullGCComplete();
 if (s == GCNotificationStatus.Succeeded)
 {
 Console.WriteLine("GC has finished in {0} ms", gcTimer.ElapsedMilliseconds);
 }
 Thread.Sleep(500);
 }
 GC.CancelFullGCNotification();
 Console.WriteLine("Finished monitoring GC");
 });
 var doWork = new Action(() =>
 {
 while (!done)
 {
 try
 {
 load.Add(new byte[10000]);
 }
 catch (OutOfMemoryException)
 {
 Console.WriteLine("Out of memory. {0}", load.Count);
 }
 }
 });
 Console.WriteLine(GCSettings.IsServerGC);
 Task.Run(pollGC);
 Task.Run(doWork);
 Console.ReadLine();
 done = true;
 GC.CancelFullGCNotification();
 Thread.Sleep(2000);
 }
}

• Snowbody: Who's marking this as "broken code"? The OP says it seems to be working properly.
• Zer0: @Snowbody That code is broken. Will explain in answer.

Answer 1

Your design won't work. You're starting a timer using GC.WaitForFullGCApproach. But this method only indicates that a Full GC is imminent (not starting). It actually allows you some time to prepare for it and force a GC yourself using GC.Collect. Your numbers won't be accurate.

Why not try using the memory performance counters?

Alternatively you could do this:

while (!done)
{
 if (GC.WaitForFullGCApproach() == GCNotificationStatus.Succeeded)
 {
 //TODO - Do GC preparation here if need be
 Console.WriteLine("Full GC is imminent. Starting a GC manually.");
 load.Clear();
 gcTimer.Restart();
 GC.Collect();
 gcTimer.Stop();
 Console.WriteLine("GC has finished in {0} ms", gcTimer.ElapsedMilliseconds);
 GC.WaitForFullGCComplete();
 }
}

• Darragh: None of those performance counters report how long garbage collection is taking (as far as I can tell).
• Zer0: % time in GC is effectively how long it's taking. But if you need absolute numbers I would suggest doing a call to GC.Collect in response to an approach notification and using a Stopwatch to measure just that.
• Darragh: I'd rather not force a garbage collection myself...as I'm not trying to alter the 'normal' GC behavior...I'm just trying to monitor it. But as there doesn't seem to be any other way, I'll mark this as the 'answer'.

Answer 2

For continuous monitoring I agree with Zer0 to look at the % time spent in GC performance counters.

However for a session based analysis a more informative approach would be to collect the ETW traces from .NET. You can see here for the different GC related events, GCStart and GCEnd would most likely be relevant for you.

view the .NET documentation for Garbage Collection ETW Events

You can specify the GC Collect Only option exists which would be very useful here.

The GC Collect Only Checkbox - Turns off all providers except those that describe garbage collections. Thus even the GC allocation sampling is turned off. This mode logs even less data than GC Only, and thus can collect data over an every longer period of time (say a day) in reasonable size (say 200 meg). The /GCCollectOnly command line option achieves the same effect.