Fixing My Xbox Performance Problem

The Symptoms
Most of the time I tested my game on my PC because I simply had no Xbox available. Now that I have one, I tested my game on the Xbox and had really bad results. It ran only at average 40-50 frames per second. So I looked at my scheduling visualizer to search for the bottleneck (see this blogpost from march for a description of the visualizer):

Task execution times Xbox 360

In the test scene there were ca. ten missiles and 15 space-crafts (enemies + own ships) and the framerate was down to ca. 35 fps. Very bad! The bottleneck was the physics task (blue bar). It took average 31ms per frame. The graphics task (green bar) had always to wait for the physics task. So I had to search there for my problem.
And just for fun the same scene on my PC (Intel Quadcore 2.5 GHz + Radeon HD 6700):

Task execution times PC (Intel Quadcore 2.5 GHz + Radeon HD 6700)

You can see, there is absolutely no performance problem on the PC! Further you can see that the Xenon CPU used in the Xbox is really really slow. The physics calculations take over a hundred times longer. Ok, its a unfair comparison, the Xenon is from the year 2005 and my Core 2 Quad Q9300 is from 2008. Additionally there must be some other problems. Factor 100 is just too much. This can't be all reduced to the hardware. Maybe some specific Xbox .Net compact framework problems.
I learned from this, that you have to test all the time on the hardware your game is targeted for.

The Problem

Searching for the problem I had a closer look at the Jitter Physics source code for the first time. The engines debug timers showed that the engine spent 95% of the time in the collision detection system, which uses the Sweep and Prune algorithm. A very good description of this algorithm and its implementation can be found on the Jitter homepage. The core idea behind this and most other collision detection algorithms is, to figure out which of the possible collisions can actually happen and put them into a list. This step is called the broadphase. In the next step (the narrowphase), only those object pairs in the list are actually tested for collision, using a more complex collision check which also calculates things like the collision points.
After reading the article about Sweep and Prune I had an idea what the reason for my performance problems could be.
I've put the perception for AI (also used for the player's radar) in the physics system. Perception means, figuring out which other game entities the AI can see right now. So every physics object carried a sensor collision shape around to "see" surrounding objects. Every game entity inside the shape can be seen by the AI. This is illustrated in the picture below:

I have drawn circles into the radar on the screenshot to show the approximated shape of the sensor. Doing perception inside the collision system doubled the number of objects that need a broadphase collision check. Also there are many completely useless broadphase collision checks between two sensors. Putting the perception into the physics systems was just a very bad idea! But the main CPU cycle wastage came from gathering perception data in EVERY FRAME. Thats just not necessary.

The Solution
The solution is easy. Move the perception gathering out of the collision system and don't gather every frame. It took me a few hours to move perception into the AI system. Have a look at the nice result:

Good Performance (Xbox): Perception in AI system, gathering interval one second

For comparison - Bad Performance (Xbox): Perception in physics system

Now I have frame rates between 70 and 80 and all tasks have to wait for the graphics system. This means I have now plenty of CPU cycles left to increase the number of enemies, implement new cool weapons or improve my AI.

Howto use the CLRProfiler

Earlier this year I gave CLRProfiler a try. I found a few bad corners in my code, in which  unnecessary garbage is produced. I reduced garbage collection to about one collection every two or three minutes. Lately I wrote much new code, so I checked again. The garbage collection time line statistic looked like this:

One collection every 2.5 seconds! Not good!
Now I will explain how you can find the part of the code where the garbage comes from. First of all, you can see that the peeks are all orange, which means that the problem comes from string allocation (see the legend right). This is very common in .NET, because strings are immutable objects, which means, that you get a complete new string on the heap every time you concatenate strings without using the StringBuilder. So how to find the code that causes the problem? In the Time Line window, mark the timespan which you want to inspect, like in the picture below.

With a right click the context menu opens, where you select "Show Who Allocated". This opens the next windows, which shows what data was allocated in the marked timespan. Nice!

You can see in the top right corner, that 1,2MB of string data were allocated in the interval. If you look further left, along the fat pink line, you can see also who allocated the string data. In the class SunBurnGraphicsModel in the method PreDraw, a call (or calls) to StringBuilder.Append are causing the problem. Heres the relevant part of the PreDraw code (SbText is a StringBuilder):

m_infoBox.SbText.Clear();
// draw team number
m_infoBox.SbText.Append("Team ");
m_infoBox.SbText.Append(m_teamNumber);
m_infoBox.TextColor = TeamColors[m_teamNumber];
m_scene.InfoTextDrawer.SubmitInfoBox(m_infoBox);

So whats the problem? Its this line:

m_infoBox.SbText.Append(m_teamNumber);

Sadly thats equivalent to this (which I didn't knew):

m_infoBox.SbText.Append(m_teamNumber.ToString());

I thought that if StringBuilder has a method Append(int), this method won't call ToString(). But thats exactly what it does, meaning that every time the line is called, a new string gets allocated on the heap.
Now the line gets called every frame for every game object. My test level contains 500 objects. The size of a string in .Net is 20 byte + (size / 2) * 4byte (size / 2 rounded down). With size=1 that means that every frame 500 * 20byte = 10.000 byte of garbage gets produced. In 2.7 seconds (with average 55 frames/second) thats 150 frames * 10.000 byte = ca. 1.4MB of "1", "2" and "0" strings (all the possible team numbers)! Thats roughly the number which you can see in the allocation graph.

The Solution:
After googling some time I found this blog with a very nice description of exact my problem. Gavin Pugh wrote some extension methods for StringBuilder which avoid this problem. I only had to change the problematic line of code to this, to get rid of the problem completely:

m_infoBox.Text.Concat(m_teamNumber, 1);

After that, the garbage collection time line looked like this:

All the string allocation are gone. Ca. 12 seconds between two garbage collections. Still a bad value, but much better then before.
I part two I will show you some more typical "garbage" code I found.