Tools of the Trade: Part Three – CLRProfiler

Over the last few days I’ve been encountering a growing realisation of just how many excellent C#/XNA/programming tools there are out there, that I use regularly; and therefore how large this mini-series will become, if I continue with this pattern of one article per tool. Still, there remain a few that I think are important enough to talk about in detail, before I summarise the rest more concisely (though leaving open the possibility of returning to them later).

So by now, you will hopefully be keeping the compiler warning level as high as possible, checking your code for style-based or semantic errors with FxCop, and when necessary, checking how the assemblies you’re interacting with do the things they do with Reflector. Now, perhaps, you’re starting to wonder about what the code you’re writing is doing at run time.

Probably the most notable thing your XNA/C# game  will be doing compared to, say, C++, which is (or at least, has been for many years) the de facto language used in the games industry, is dealing with memory in a completely different way. C# is a managed language. This means that where in C++ you use “new” to allocate memory and “delete” to deallocate it (with the possibility of leaks, scribbles and access violations), in C# you use “new” to get a reference to an object, and the garbage collector tidies it up for you when you’re finished with it.

There is a lot that I could write about the garbage collector. It’s probably fair to say that dealing with garbage correctly is key to programming in C#. In fact, until two minutes ago this article was about 1000 words longer, until I realised that I’d written a whole bunch of stuff more relevant to GC itself than the tool the article is about, and even then had either gone into too much or not enough detail depending on your point of view. (Perhaps something for a future article, or even series, if there is demand). In summary:

– GC on Windows is not a good thing and you should try to avoid generating garbage where reasonably convenient.
– GC on Xbox is a very bad thing, and if your game is intended for Xbox 360 you should go out of your way to avoid it everywhere possible.

The other day I was working on Pandemonium and noticed that my frame rate had plummetted from 1800 Hz in the morning to 200 Hz by the evening. Now, 200Hz is more than enough – for a finished game! But I only had one character running around a simple background so it seemed a bit low. Losing 1600 Hz in a day is not a good day. Luckily, using some of the Kensei.Dev.Options I’ve shown before, it took just a couple of mouse clicks to realise that I was suffering lots of garbage collections. This was confirmed when I used another Kensei.Dev.Option to show more details:

    if ( Options.GetOption( “Profile.ShowGarbage” ) )

    {

        Kensei.Dev.DevText.Print( “Max Garbage Generation: “ + GC.MaxGeneration.ToString(), Color.LimeGreen );

#if !XBOX

        for ( int i = 0; i <= GC.MaxGeneration; ++i )

        {

            Kensei.Dev.DevText.Print( “Generation “ + i.ToString() + “: “ + GC.CollectionCount( i ).ToString() + ” collections”, Color.LimeGreen );

        }

#endif

        Kensei.Dev.DevText.Print( “Total Memory: “ + GC.GetTotalMemory( false ).ToString( “n0” ), Color.LimeGreen );

    }

It was clear that something was generating lots of garbage. Suspicion soon fell on my background hits implementation, as that’s what I’d worked on that day. It was deliberately simple, just an array of triangles, each with a BoundingBox, against which I would test lines and swept spheres. I know an octree or kd-tree would be better but that’s something I can address later. It might not be a very quick method, but it shouldn’t be generating garbage.

Visual inspection of the code revealed nothing so to find the cause, I fired up the CLRProfiler (top tip: make sure to use version 2.0 and run as Administrator) and asked it to run my game. The first thing you should note is that it is invasive: my frame rate dropped from about 200 Hz without it, to less than 10 Hz with it running.

The CLR Profiler

So, clear the “Profiling Active” checkbox, only then “Start Application”, get yourself to the part of your game that’s slow, and only then tick “Profiling Active” for a few seconds before clearing it again. That will generate a report.

A CLR Profiler report

109 Generation 0 garbage collections is quite a lot in the few seconds I ran the game for. Ideally, a game would have zero garbage collections during gameplay. (That’s not possible if you’re using XACT for sound, but it’s a good ideal to get as close to as possible). The Time Line button in the centre gives the best view of when GCs happen and why.

The CLR Profiler Timeline

The coloured peaks show garbage, which you can see was increasing very sharply before dropping as each collection occurred. The vertical black line can be moved to show what the garbage consists of at each time slice; here I placed it just before a GC, and it shows me that 2MB (99% of my garbage) was from System.SZArrayHelper.SZGenericArrayEnumerator<T>. The rest was basically strings generated by the Kensei.Dev prints, listed above, and can be ignored. But – where did this SZGenericArrayEnumerator come from?

Back on the report page, I was interested in Heap Statistics, and wanted to see what had been allocated, so clicked Allocation Graph at the top. This shows a diagram indicating where all the garbage comes from. The highest level is on the left, and you go progressively further right to get more detail. So, Program::Main is the first significant box on the left and will have created 100% of the garbage – so all the garbage in your program was created by your program, go figure – but what’s lower down (ie. to the right)?

The Allocation Graph

As expected, 99% of the garbage is SZGenericArrayEnumerator – which comes from SZArrayHelper::GetEnumerator – which comes in turn from BoundingBox::CreateFromPoints. There was only one place this appeared in my code, and yes, it was bad. In order to provide a (small) speedup to my collision detection, which I’ve already mentioned I knew to be non-optional but wasn’t ready to spend time on yet, I’d done a Line-BoundingBox check to reject misses before doing a Line-Triangle check. And, being lazy and naughty, I’d created a new BoundingBox every test:

    foreach ( Triangle triangle in data.Triangles )

    {

        BoundingBox box = BoundingBox.CreateFromPoints( triangle.Vertices );

Just to be clear, here. foreach has gotten a really bad reputation for garbage because in CLR 1.0 the enumerator that foreach uses to traverse the container was of reference type. Some people, wrongly, claim that you should avoid it for that reason. That’s nonsense – in CLR 2.0 onwards, foreach is safer, easier to read, and at least as performant as a for loop. You should definitely prefer foreach in almost all cases. All my garbage was coming not from foreach, but from BoundingBox.CreateFromPoints.

The fix was easy – instead of creating a new BoundingBox for each Triangle for each hit test, I’d store the BoundingBox with the Triangle when they were created in the Content Pipeline. No more garbage, or at least, none at runtime; and the Content Pipeline doesn’t care about garbage. Really, I ought to have done it that way in the first place, so a definite slap on the wrist for me.

Only one thing still niggled. BoundingBox is a value type (created on the stack) so why was BoundingBox.CreateFromPoints creating garbage? The answer comes when you look back at the screenshot of Reflector in the previous article. BoundingBox.CreateFromPoints has a foreach loop in the middle of it, and foreach creates garbage.

“But Andy, wait!” I hear you cry. “You just said foreach doesn’t create garbage, in fact, you said that was nonsense!” Well, yes, though I did insert the word “almost” in a key position. The truth is that foreach does not create garbage for arrays, Lists, LinkedLists and any container other than Collection<T>. However, BoundingBox.CreateFromPoints has been designed to handle any container via the IEnumerable interface, which means the enumerator has to be boxed. Boxing means it is moved onto the heap, and is therefore garbage.

I’m still a little surprised that an array-specialised version of BoundingBox.CreateFromPoints isn’t provided but then, I guess it’s not exactly difficult to write if you desperately need it – especially given that Reflector shows how! In any case, I hope that this demonstration of how CLRProfiler helped me with a garbage problem, has shown how it can help you, too. Leave a comment and let me know how helpful you’re finding these articles.

“First, solve the problem. Then, write the code.” – John Johnson