Measure GC Allocations and Collections using TraceEvent

In this post I will explore  how we could use TraceEvent to measure our code (even at function level) for GC Allocations and Collections.

Save this with “.linq” extension and then open in  linqpad.

Here is the TL;DR

Why would I want to know GC events on a function level? Doesn’t the PerfMon counter  provide that information on an application level? Isn’t Premature optimization root of all evil?

Yes, for most of the part Premature optimization is not necessary. And PerfMon GC counter’s would give answers for the whole application. But it is usually after we build the application and when we start running into performance issues we start looking at them.

The motivation behind this are two things Measure Early and Often for Performance and Essential Truths Everyone Should Know about Performance in a Large Managed Codebase

If you haven’t read or watched the above video please do it. It let’s us know why and how to do it.

In the above video Dustin talks about Roslyn code base and how they used Perfview to measure Roslyn code base and identify potential bottlenecks early to avoid Perf issues.

One of the key differences between managed code and native code with respect to performance is GC. If GC is working hard then your application might not be able to get the performance that you are expecting. GC is good but if we don’t know which calls allocate what amount of data then it is an issue. Especially if you have a section code that is hit very often and which requires a lot of Perf, it is good know where the allocations are coming from. It is not explicit always.

In the above video Dustin shows few examples of Roslyn code where they were able to identify subtle issues that could allocate a lot when you are trying to get the most out of the code.There is also Roslyn Heap Allocation Analyzer which looks at the code help us identify allocations which isn’t necessary. It is a cool project.

I took one of the examples from the video as a motivation to check if  I could measure and make it a utility in my toolbox to help me when I need one.

In the above example I am trying look for a word “pede” in the lorem ipsum text. The code could get it using “foreach” or using the “Any” operator. I would like to run this few times to check what are the allocations and how long does it take. I used LINQPad as a scratch pad.

Here is the result of GC Allocations of using “Any” for 500 iterations and NOT the foreach

GCAllocations

The were 118 allocations of Enumerator and 146 allocations Func. GC usually allocates 100K each time it allocates that’s what is shown in the allocation amount column.

And here is GC Allocations when using “foreach”

GCAllocationWithForEach

There are hardly any new allocations compared to the previous one.

Here is the GC Collections when using  “Any”

GCCollection

There were 18 GC Collections using Any.

Here it is using foreach  and there were 0 collections.

ZeorCollections

Here is measure it time duration results using Any

MeasureWithAny

And here it is using Foreach

MeasureWithForEach

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s