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);
    }
}

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();
    }
}

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.