High gen0 collect overhead with (suppressed) finalizer objects

[peppy]

Overview

When allocating many objects with a finalizer present, there is a non-negligible overhead on GC gen0 collects, even if the finalizer has been suppressed via GC.SuppressFinalize. The hypothesis is that this is due to the emptying of the finalizer queue.

This is causing our real-time application to hitch on every gen0 collection (around 5-10ms pause time). These gen0 collections only happen every 20-60 seconds.

Use Case

A bit more information on our situation, in case it helps to put things into perspective.

Our team develops a rhythm game/framework which requires sustained very low latency execution. We have recently been tracking user reports of occasional high frame times which align with GC invocation, specifically gen0 collections.

Having worked with .NET (framework / core) for several decades, I have a general idea of what to expect in terms of gen0 collection performance, and the numbers we are seeing are much higher than expected, in the range of 5-15ms per collection with low (<1MB/s) alloc throughput and near zero promotion.

One cause turned out to be a texture upload class we have, which rents memory from ArrayPool and returns on disposal. This class may be constructed every frame for streaming texture data. While we do our best to explicitly dispose after consumption, it has a finalizer implemented as a safety measure, to ensure the memory is returned to the ArrayPool no matter what (I think this is a pretty common practice).

With our findings here, it seems that finalizers should be avoided in such cases, where objects are constructed in abundance. This is our general direction to resolve this issue, for what it's worth.

Reproduction

using System;

namespace TestBasicAllocs
{
    public static class Class1
    {
        public static void Main(string[] args)
        {
            bool finalizers = args[0] == "1";

            for (int i = 0; i < 10000000; i++)
            {
                if (finalizers)
                {
                    var thing = new FinalizingThing();
                    GC.SuppressFinalize(thing);
                }
                else
                    new NonFinalizingThing();
            }
        }
    }

    public class NonFinalizingThing
    {
        public NonFinalizingThing()
        {
        }
    }

    public class FinalizingThing
    {
        public FinalizingThing()
        {
        }

        ~FinalizingThing()
        {
        }
    }
}

Results

dotnet-trace collect -- .\bin\Debug\net5.0\TestBasicAllocs.exe 0

dotnet-trace collect -- .\bin\Debug\net5.0\TestBasicAllocs.exe 1

I am writing this issue up without a clear distinction of whether this should be considered a bug, performance issue, or an accepted (and potentially better-documented) hidden overhead of finalizers. I have read through .NET memory performance analysis documentation, which does mention that finalizers should be avoided, but also that calling GC.SuppressFinalize should recover all but the allocation overhead. Similar information is present in "official" documentation and user comments, but I have been unable to find anything referencing a gen0 collection-time overhead.

Also worth noting that while memory analysis guides and profilers like Jetbrains dotMemory will highlight finalizers that were not suppressed, it cannot provide visibility and does not find issue with large numbers of allocations of objects with finalizers present in general. Maybe in the majority of cases this pause overhead is considered acceptable, but do consider that the above benchmarks are cases where gen0s are happening quite regularly. In our actual usage we have seen pause times as long as 30-50ms due to the same underlying issue, which implies that this overhead is not part of the consideration as to how often to run gen0 collects.

I have tested against net472, .net core 3.1/3.2/5.0 and this is not a regression.

I couldn't figure out the best area label to add to this issue. If you have write-permissions please help me learn by adding exactly one area label.

Tagging subscribers to this area: @dotnet/gc
See info in area-owners.md if you want to be subscribed.

Issue Details

---

Overview

When allocating many objects with a finalizer present, there is a non-negligible overhead on GC gen0 collects, even if the finalizer has been suppressed via GC.SuppressFinalize. The hypothesis is that this is due to the emptying of the finalizer queue.

This is causing our real-time application to hitch on every gen0 collection (around 5-10ms pause time). These gen0 collections only happen every 20-60 seconds.

Use Case

A bit more information on our situation, in case it helps to put things into perspective.

Our team develops a rhythm game/framework which requires sustained very low latency execution. We have recently been tracking user reports of occasional high frame times which align with GC invocation, specifically gen0 collections.

Having worked with .NET (framework / core) for several decades, I have a general idea of what to expect in terms of gen0 collection performance, and the numbers we are seeing are much higher than expected, in the range of 5-15ms per collection with low (<1MB/s) alloc throughput and near zero promotion.

One cause turned out to be a texture upload class we have, which rents memory from ArrayPool and returns on disposal. This class may be constructed every frame for streaming texture data. While we do our best to explicitly dispose after consumption, it has a finalizer implemented as a safety measure, to ensure the memory is returned to the ArrayPool no matter what (I think this is a pretty common practice).

With our findings here, it seems that finalizers should be avoided in such cases, where objects are constructed in abundance. This is our general direction to resolve this issue, for what it's worth.

Reproduction

using System;

namespace TestBasicAllocs
{
    public static class Class1
    {
        public static void Main(string[] args)
        {
            bool finalizers = args[0] == "1";

            for (int i = 0; i < 10000000; i++)
            {
                if (finalizers)
                {
                    var thing = new FinalizingThing();
                    GC.SuppressFinalize(thing);
                }
                else
                    new NonFinalizingThing();
            }
        }
    }

    public class NonFinalizingThing
    {
        public NonFinalizingThing()
        {
        }
    }

    public class FinalizingThing
    {
        public FinalizingThing()
        {
        }

        ~FinalizingThing()
        {
        }
    }
}

Results

dotnet-trace collect -- .\bin\Debug\net5.0\TestBasicAllocs.exe 0

dotnet-trace collect -- .\bin\Debug\net5.0\TestBasicAllocs.exe 1

I am writing this issue up without a clear distinction of whether this should be considered a bug, performance issue, or an accepted (and potentially better-documented) hidden overhead of finalizers. I have read through .NET memory performance analysis documentation, which does mention that finalizers should be avoided, but also that calling GC.SuppressFinalize should recover all but the allocation overhead. Similar information is present in "official" documentation and user comments, but I have been unable to find anything referencing a gen0 collection-time overhead.

Also worth noting that while memory analysis guides and profilers like Jetbrains dotMemory will highlight finalizers that were not suppressed, it cannot provide visibility and does not find issue with large numbers of allocations of objects with finalizers present in general. Maybe in the majority of cases this pause overhead is considered acceptable, but do consider that the above benchmarks are cases where gen0s are happening quite regularly. In our actual usage we have seen pause times as long as 30-50ms due to the same underlying issue, which implies that this overhead is not part of the consideration as to how often to run gen0 collects.

I have tested against net472, .net core 3.1/3.2/5.0 and this is not a regression.

Author:	peppy
Assignees:	-
Labels:	area-GC-coreclr, tenet-performance, untriaged
Milestone:	-

[jkotas]

it has a finalizer implemented as a safety measure, to ensure the memory is returned to the ArrayPool no matter what (I think this is a pretty common practice).

The typical pattern that we use in the core libraries is to just let garbage collector to take care of cleaning up after rare error cases. I do not think we have any place in the core libraries where we have a finalizer just to return memory to the array pool.

[peppy]

@jkotas That is what I could see in my investigation (the lack of finalizer), but could you explain how the clean-up is done in this case? Will the arraypool eventually assume the array isn't being returned and stop tracking it? Figured this out (memory is only added back on Return).

We have a few other cases where we do use finalizers for non-ArrayPool.Return reasons (although are currently looking to remove them as a result of this investigation). Another example where the finalizer is there for safety is a texture upload which is handling unmanaged (ffmpeg) memory handles, for instance.

Is it safe to say that your advice here is that finalizers should be avoided at all costs, even when SuppressFinalizer is correctly used? Is this referenced somewhere in documentation or usage guidelines that I have somehow missed? If not, it might be a worthwhile addition to warn others that potentially see finalizers as a method of running clean-up logic, expecting there to be a negligible overhead with correct (seldomly-invoked) usage.

[jkotas]

The pooled arrays are just regular arrays. Once they become unreachable, they will get collected just like regular array. Of course, you do not want to depend on the pooled arrays getting collected all the time since it would effectively disable pooling. It is fine to depend on GC to collect the pooled array in rare circumstances.

Finalizers make sense on types that are holding unmanaged resources if you would like to make these types robust against incorrect use. For public types, .NET design guidelines recommend using SafeHandles for unmanaged resource lifetime management. SafeHandles take care of finalization if resource is not disposed properly, but also protect against race conditions between use and disposal.

[En3Tho]

Having worked with wincrypt and other unmanaged apis, my 2 cents is that you should only use finalizers when it's absolutely necessary.

For example, when array is not returned to pool there is no risk of application blowing up, only risk of a slowdown and that could be detected by some kind of script runner and collecting GC/fps/other info in your building system. But when unmanaged resources are not released it could lead to memory leaks, dangling handles, unexpected failures. Those are much harder to detect and debug afterwards. And on top of that, I understand gamedev imposes very harsh requirements on latency and execution speed.

I would recommend using some kind of ref struct wrappers and few self made analyzers to detect their proper usage.

[smoogipoo]

Hi, I'm working on the same project referenced in the OP.

One case that we've recently discovered is WeakReference<T>. We're using ImageSharp's memory allocator to allocate buffers in the hopes that we can keep texture-related data using the same pool.
As it turns out, ImageSharp's ArrayPoolMemoryAllocator allocates Buffer<T>s which allocate WeakReference<T>s, which has a finalizer and triggers the same case as in the OP.

This was being done for graphing runtime work diagnostics, and thus we'd like to keep this a real-time/per-frame process.

The biggest problem we're having is that there's very little visibility on this, besides the raw number of objects allocated. We can get close by using ETW events and inspecting the types to see if they have finalizers, but it's by no means an exhaustive solution considering GCAllocationTick only occurs every ~100KB (this is our current path). We can write a compile-time analyzer but that's also pretty non-trivial if we have to inspect other assemblies and .NET internals like this. And finally, we can also look into having an automated test harness inspect GC pause times for any weirdness in a bunch of scenarios, but that's also tricky to do for various reasons though this is a long-term goal for general regression tests.

For example, if PerfView provided a count of finalizable objects at GC time, it would help track these issues down. If GCFinalizersEnd provided the type name (of just the last type name, as per the other ETW events), that may even be better since we can analyse logs received from users and see if this is the cause. That's just a few ideas that would help, if this overhead is otherwise unavoidable.

[Maoni0]

hi @peppy, thanks for your report. a comment -

I have read through .NET memory performance analysis documentation, which does mention that finalizers should be avoided, but also that calling GC.SuppressFinalize should recover all but the allocation overhead.

so that's not exactly what I said in the doc 😃 this is what I said in the Finalizers section -

However, if you suppress the finalizer with GC.SuppressFinalize, what you tell the GC is you don't need to run the finalizer of this object. So GC would have no reason to promote it. It will be reclaimed when GC finds it dead.

it just says GC will not need to promote it. it doesn't say GC would not need to scan it, and this text is about scanning -

When a GC happens, it will discover the objects that are still live and promote them. Then it will check with objects on the finalize queue to see if they are promoted - if an object is not promoted it means it's dead, even though it can't be reclaimed (see why in the next paragraph). If you have tons of finalizable objects in the generations being collected, this cost alone could be noticeable.

having said that, I completely agree we should make this more diagnosable. I did talk about the internals of finalization in this blog post where I mentioned the method names related to scanning are mentioned - you could look those up before we provide an easier solution. we can provide this time via events like we already do in the mark phase for other types of scanning (stack, handle table, etc). would that be sufficient for you?

hi @smoogipoo, right now we do log the type of the object that's being finalized in the FinalizeObject event if you have the type keyword enabled on informational level. can you please try that and see if the type for those objects show up for you? of course for your specific case, you will not see these events for WeakReference because for WeakReference we don't actually run their finalizers - GC just take a shortcut and frees the handle right away. what I mentioned above was we could fire an event that tells us how much time we spent in the finalization related scanning. that's another way. we can also include how many objects we scanned.

[peppy]

@Maoni0 Thanks for your reply; glad you found this issue (and thanks for your guide, it is a great read). Also apparently I am blind since I missed that specific part about scanning. I think the structure of the document may have played part in that – the "Finalizer" section header is a weird bullet point and is also smaller than the sub-headers following it, making them look like a new section.

[Maoni0]

@peppy I agree - I really struggled with the formatting since markdown offers pretty primitive options. I tried to make the line that says Finalizer part be more prominent by adding some kind of symbol but then it wouldn't let me make it a link sigh :) maybe I'll get one of the folks on my team who's better at this stuff to help me with formatting this better.