Monitoring Garbage Collector in C#
Asked Answered
A

1

34

I have a WPF application that is experiencing a lot of performance issues. The worst of them is that sometimes the application just freezes for a few seconds before running again.

I am currently debugging the application to see what this freeze might be related to, and I believe that one of things that may be causing it is the Garbage Collector. Since my application is running in a very limited environment, I believe that the Garbage Collector can be using all of the machine's resources when it is ran and leaving none to our application.

To check this hypotheses I found these articles: Garbage Collection Notifications and Garbage Collection Notifications in .NET 4.0, that explain how my application can be notified when the Garbage Collector will begin running and when it is finished.

So, based on those articles I created the class below to get the notifications:

public sealed class GCMonitor
{
    private static volatile GCMonitor instance;
    private static object syncRoot = new object();

    private Thread gcMonitorThread;
    private ThreadStart gcMonitorThreadStart;

    private bool isRunning;

    public static GCMonitor GetInstance()
    {
        if (instance == null)
        {
            lock (syncRoot)
            {
                instance = new GCMonitor();
            }
        }

        return instance;
    }

    private GCMonitor()
    {
        isRunning = false;
        gcMonitorThreadStart = new ThreadStart(DoGCMonitoring);
        gcMonitorThread = new Thread(gcMonitorThreadStart);
    }

    public void StartGCMonitoring()
    {
        if (!isRunning)
        {
            gcMonitorThread.Start();
            isRunning = true;
            AllocationTest();
        }
    }

    private void DoGCMonitoring()
    {
        long beforeGC = 0;
        long afterGC = 0;

        try
        {

            while (true)
            {
                // Check for a notification of an approaching collection.
                GCNotificationStatus s = GC.WaitForFullGCApproach(10000);
                if (s == GCNotificationStatus.Succeeded)
                {
                    //Call event
                    beforeGC = GC.GetTotalMemory(false);
                    LogHelper.Log.InfoFormat("===> GC <=== " + Environment.NewLine + "GC is about to begin. Memory before GC: %d", beforeGC);
                    GC.Collect();

                }
                else if (s == GCNotificationStatus.Canceled)
                {
                    LogHelper.Log.Info("===> GC <=== " + Environment.NewLine + "GC about to begin event was cancelled");
                }
                else if (s == GCNotificationStatus.Timeout)
                {
                    LogHelper.Log.Info("===> GC <=== " + Environment.NewLine + "GC about to begin event was timeout");
                }
                else if (s == GCNotificationStatus.NotApplicable)
                {
                    LogHelper.Log.Info("===> GC <=== " + Environment.NewLine + "GC about to begin event was not applicable");
                }
                else if (s == GCNotificationStatus.Failed)
                {
                    LogHelper.Log.Info("===> GC <=== " + Environment.NewLine + "GC about to begin event failed");
                }

                // Check for a notification of a completed collection.
                s = GC.WaitForFullGCComplete(10000);
                if (s == GCNotificationStatus.Succeeded)
                {
                    //Call event
                    afterGC = GC.GetTotalMemory(false);
                    LogHelper.Log.InfoFormat("===> GC <=== " + Environment.NewLine + "GC has ended. Memory after GC: %d", afterGC);

                    long diff = beforeGC - afterGC;

                    if (diff > 0)
                    {
                        LogHelper.Log.InfoFormat("===> GC <=== " + Environment.NewLine + "Collected memory: %d", diff);
                    }

                }
                else if (s == GCNotificationStatus.Canceled)
                {
                    LogHelper.Log.Info("===> GC <=== " + Environment.NewLine + "GC finished event was cancelled");
                }
                else if (s == GCNotificationStatus.Timeout)
                {
                    LogHelper.Log.Info("===> GC <=== " + Environment.NewLine + "GC finished event was timeout");
                }
                else if (s == GCNotificationStatus.NotApplicable)
                {
                    LogHelper.Log.Info("===> GC <=== " + Environment.NewLine + "GC finished event was not applicable");
                }
                else if (s == GCNotificationStatus.Failed)
                {
                    LogHelper.Log.Info("===> GC <=== " + Environment.NewLine + "GC finished event failed");
                }

                Thread.Sleep(1500);
            }
        }
        catch (Exception e)
        {
            LogHelper.Log.Error("  ********************   Garbage Collector Error  ************************ ");
            LogHelper.LogAllErrorExceptions(e);
            LogHelper.Log.Error("  -------------------   Garbage Collector Error  --------------------- ");
        }
    }

    private void AllocationTest()
    {
        // Start a thread using WaitForFullGCProc.
        Thread stress = new Thread(() =>
        {
            while (true)
            {
                List<char[]> lst = new List<char[]>();

                try
                {
                    for (int i = 0; i <= 30; i++)
                    {
                        char[] bbb = new char[900000]; // creates a block of 1000 characters
                        lst.Add(bbb);                // Adding to list ensures that the object doesnt gets out of scope
                    }

                    Thread.Sleep(1000);
                }
                catch (Exception ex)
                {
                    LogHelper.Log.Error("  ********************   Garbage Collector Error  ************************ ");
                    LogHelper.LogAllErrorExceptions(e);
                    LogHelper.Log.Error("  -------------------   Garbage Collector Error  --------------------- ");
                }
            }


        });
        stress.Start();
    }
}

And I've added the gcConcurrent option to my app.config file (below):

<?xml version="1.0"?>
<configuration>
  <configSections>
    <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net-net-2.0"/>
  </configSections>

  <runtime>
    <gcConcurrent enabled="false" />
  </runtime>

  <log4net>
    <appender name="Root.ALL" type="log4net.Appender.RollingFileAppender">
      <param name="File" value="../Logs/Root.All.log"/>
      <param name="AppendToFile" value="true"/>
      <param name="MaxSizeRollBackups" value="10"/>
      <param name="MaximumFileSize" value="8388608"/>
      <param name="RollingStyle" value="Size"/>
      <param name="StaticLogFileName" value="true"/>
      <layout type="log4net.Layout.PatternLayout">
      <param name="ConversionPattern" value="%date [%thread] %-5level - %message%newline"/>
      </layout>
    </appender>
    <root>
      <level value="ALL"/>
      <appender-ref ref="Root.ALL"/>
    </root>
  </log4net>

  <appSettings>
    <add key="setting1" value="1"/>
    <add key="setting2" value="2"/>
  </appSettings>
  <startup>
    <supportedRuntime version="v2.0.50727"/>
  </startup>

</configuration>

However, whenever the application is executed, it seems as if no notification is sent that the Garbage Collector will run. I've put breakpoints in the DoGCMonitoring and it appears that the conditions (s == GCNotificationStatus.Succeeded) and (s == GCNotificationStatus.Succeeded) are never satisfied, therefore the contents of those ifs statements are never executed.

What am I doing wrong?

Note: I am using C# with WPF and the .NET Framework 3.5.

UPDATE 1

Updated my GCMonitor test with the AllocationTest method. This method is for testing purposes only. I just wanted to make sure that enough memory was being allocated to force the Garbage Collector to run.

UPDATE 2

Updated the DoGCMonitoring method, with new checks on the return of the methods WaitForFullGCApproach and WaitForFullGCComplete. From what I've seen so far my application is going directly to the (s == GCNotificationStatus.NotApplicable) condition. So I think that I have some misconfiguration somewhere that is stopping me from getting the desired results.

The documentation for the GCNotificationStatus enum can be found here.

Animus answered 12/3, 2012 at 15:30 Comment(8)
Have you tried actually profiling it with a tool, say something like the windows performance monitor or windbg - instead of trying to write a GC wrapper?Digiovanni
Maybe the GC isn't running (yet). Can you show AllocationTest() ?Dedededen
Hi, I actually do have a profiling tool, however the freeze problem that I mentioned earlier is happening in a production environment, and not on my machine (I cannot reproduce it). And unfortunately for me I cannot run the profiling tool in the production environement.Animus
If you suspect that it's the GC, you can try creating a virtual machine with very limited RAM (say, WinXP with 256MB) and running your application there. If the issue reappears there, increase the available RAM and try again. Also - it is normal for the GC to freeze your process while it does its thing. After all, it needs a frozen state of affairs in order to traverse the object graph and find items eligible for collection.Alonsoalonzo
What evidence do you have that GC is the problem?Dragonet
@Alonsoalonzo that's technically incorrect. The server GC (used in ASP.NET for example) is a stop-the-world garbage collector. The workstation GC (used in WPF, and most other desktop applications) is a concurrent GC- it does not stop the world.Dovecote
@ChrisShain - Oh... I didn't know that... I wonder how it can do its thing if the object graph keeps changing from underneath it?Alonsoalonzo
The .NET concurrent GC, like the JVM concurrent GC, still stops-the-world for the initial mark. AFAIK, the only x86 without a heap-proportional stop the world is Azul Zing. You can read some more about stop-the-world in concurrent JVM here... blog.griddynamics.com/2011/06/…Greenburg
V
54

I don't see GC.RegisterForFullGCNotification(int,int) anywhere in your code. It looks like you're using the WaitForFullGC[xxx] methods, but are never registering for the notification. That's probably why you're getting the NotApplicable status.

However, I'm doubting that GC is your problem, while possible, I suppose it would be good to know about all of the GC modes there are and the best ways to determine what is happening. There are two modes of Garbage Collection in .NET: the Server and Workstation. They both collect the same unused memory, however the way it's done is ever so slightly different.

  • Server Version - This mode tells the GC for you're using a server side application, and it tries to optimize collections for these scenarios. It will split the heap into several sections, 1 per CPU. When the GC is started, it will run one thread on each CPU in parallel. You really want multiple CPUs for this to work well. While the server version uses multiple threads for the GC, it's not the same as the concurrent workstation GC mode listed below. Each thread acts like the non-concurrent version.

  • Workstation Version - This mode tells GC you're using a client side application. It figures you have more limited resources than the Server version, and so there is only one GC thread. However, there are two configurations of the Workstation version: concurrent and non-concurrent.

    • Concurrent - This is the version turned on by default whenever the workstation GC is used (this would be the case for your WPF application). The GC is always running on a separate thread that is always marking objects for collection when the application is running. Furthermore, it chooses whether or not to compact the memory in certain generations, and makes that choice based on performance. It still has to freeze all threads to run a collection if compacting is done, but you will almost never see an unresponsive application when using this mode. This creates a better interactive experience for uses and is best for console or GUI apps.
    • Non-Concurrent - This is a version you can configure your application to use, if you'd like. In this mode, the GC thread sleeps until a GC is started, then it goes and marks all object trees that are garbage, frees the memory, and compacts it, all while all other threads are suspended. This can cause application to sometimes become unresponsive for a short period of time.

You can't register for notifications on the concurrent collector, since that's done in the background. It's possible that your application is not using the concurrent collector (I notice you have the gcConcurrent disabled in the app.config, but it seems that's only for testing?). If that's the case, you can certainly see your application freezing if there's heavy collections. This is why they created the concurrent collector. The type of GC mode can partially be set in code, and fully set in application configurations and machine configurations.

What can we do to figure out exactly what our application is using? At runtime, you can query the static GCSettings class (in System.Runtime). GCSettings.IsServerGC will tell you if you're running the workstation on server versions and GCSettings.LatencyMode can tell you if you're using the concurrent, non-concurrent or a special one you have to set in code which isn't really applicable here. I think that would be a good place to start, and could explain why it's running fine on your machine, but not production.

In the configuration files, <gcConcurrent enabled="true|false"/> or <gcServer enabled="true|false"/> control the modes of the garbage collector. Keep in mind this can be in your app.config file (located aside the executing assembly) or in the machine.config file, which is located in %windir%\Microsoft.NET\Framework\[version]\CONFIG\

You can also remotely use the Windows Performance Monitor to access the production machine's performance counters for .NET garbage collection and view those statistics. You can do the same with Event Tracing for Windows (ETW) all remotely. For performance monitor, you'd want the .NET CLR Memory object, and select your application in the instances list box.

Vania answered 12/3, 2012 at 17:11 Comment(1)
Hi, I did indeed forget the GC.RegisterForFullGCNotification(int,int) line... I feel a little stupid right now. Anyway thanks for your very complete answer!Animus

© 2022 - 2024 — McMap. All rights reserved.