Visualising the .NET Garbage Collector

As part of an ongoing attempt to learn more about how a real-life Garbage Collector (GC) works (see part 1) and after being inspired by Julia Evans’ excellent post gzip + poetry = awesome I spent a some time writing a tool to enable a live visualisation of the .NET GC in action.

As part of an ongoing attempt to learn more about how a real-life Garbage Collector (GC) works (see part 1) and after being inspired by Julia Evans’ excellent post gzip + poetry = awesome I spent a some time writing a tool to enable a live visualisation of the .NET GC in action.

GC Pauses

Most of the visualisation and summary information is relatively easy to calculate, however the timings for the GC pauses are not always straight-forward. Since .NET 4.5 the Server GC has 2 main modes available the new Background GC mode and the existing Foreground/Non-Concurrent one. The .NET Workstation GC has had a Background GC mode since .NET 4.0 and a Concurrent mode before that.

The main benefit of the Background mode is that it reduces GC pauses, or more specifically it reduces the time that the GC has to suspend all the user threads running inside the CLR. The problem with these “stop-the-world” pauses, as they are also known, is that during this time your application can’t continue with whatever it was doing and if the pauses last long enough users will notice.

As you can see in the image below (courtesy of the .NET Blog) , with the newer Background mode in .NET 4.5 the time during which user-threads are suspended is much smaller (the dark blue arrows). They only need to be suspended for part of the GC process, not the entire duration.

Foreground (Blocking) GC flow

So calculating the pauses for a Foreground GC (this means all Gen 0/1 GCs and full blocking GCs) is relatively straightforward, using the info from the excellent blog post by Maoni Stephens the main developer on the .NET GC:

GCSuspendEE_V1

GCSuspendEEEnd_V1 <– suspension is done

GCStart_V1

GCEnd_V1 <– actual GC is done

GCRestartEEBegin_V1

GCRestartEEEnd_V1 <– resumption is done.

So the pause is just the difference between the timestamp of the GCSuspendEEEnd_V1 event and that of the GCRestartEEEnd_V1.

Background GC flow

However for Background GC (Gen 2) it is more complicated, again from Maoni’s blog post:

GCSuspendEE_V1

GCSuspendEEEnd_V1

GCStart_V1 <– Background GC starts

GCRestartEEBegin_V1

GCRestartEEEnd_V1 <– done with the initial suspension

GCSuspendEE_V1

GCSuspendEEEnd_V1

GCRestartEEBegin_V1

GCRestartEEEnd_V1 <– done with Background GC’s own suspension

GCSuspendEE_V1

GCSuspendEEEnd_V1 <– suspension for Foreground GC is done

GCStart_V1

GCEnd_V1 <– Foreground GC is done

GCRestartEEBegin_V1

GCRestartEEEnd_V1 <– resumption for Foreground GC is done

GCEnd_V1 <– Background GC ends

It’s a bit easier to understand these steps by using an annotated version of the image from the MSDN page on GC (the numbers along the bottom correspond to the steps above)

Of course there could be more than one foreground GC, there could be 0+ between line 5) and 6), and more than one between line 9) and 16).

We may also decide to do an ephemeral GC before we start the BGC (as BGC is meant for gen2) so you might also see an ephemeral GC between line 3) and 4) – the only difference between it and a normal ephemeral GC is you wouldn’t see its own suspension and resumption events as we already suspended/resumed for BGC purpose.

Age of Ascent - GC Pauses

Finally, if you want a more dramatic way of visualising a “Stop the World” or more accurately a “Stop the Universe” GC pause, take a look at the video below. The GC pause starts at around 7 seconds in (credit to Ben Adams and Age of Ascent)