What Can't be Measured Can't be Improved: Investing in Measurement

This blog post only exists to prevent expired linking. My blog has moved to: http://pabloaizpiri.com/

--------------------------------------------------------------------------------

For sure we have all heard the saying and know it well- but few of the times do we apply it- especially if measuring (or making measuring easy) is going to take some work up front. We like to think we can "cowboy" it and figure out where out performance-hitting bugs are ourselves.

Today, I worked on my 3D engine most of the day. I had a blast and a lot of good came from all the work I put into it. Even though I still have a ways to go, I felt like I had gotten to the point where it was time to start measuring performance.

Performance is a pretty important topic for a 3D application- and especially considering I'm just starting out learning the ins and outs of DirectX (and to add insult to injury, I'm using a managed language), I wanted to make sure I'm writing fairly efficient code. I've learned not to micro-optimize, and I felt like now that I had gotten the basic concepts down and working I would begin profiling.

At first I was going to just insert a few Diagnostics.Stopwatch calls here and there but after thinking it through I decided that as important as performance was for a 3D engine, it would most likely be in my best interest to create a class to make measuring the performance of the engine very easily. This is important because as you're working, (if the use of your diagnostics class is easy enough), you will also be encouraged to add metrics to your application. I've realized that the time spent up-front to do this is invaluable, especially since I know I will use this class plenty in the future.

My approach was fairly simple- I knew it had to be something that was super easy to use or it would have a low ROI, but I also knew it had to provide valuable performance metrics and information, not just data.
Essentially it has four major timing calls:

• public void BeginSingle()
• public void EndSingle(string Name)
• public void BeginSpecific(string Name) 
• public void EndSpecific(string Name)

BeginSingle and EndSingle make timing a certain portion of code very easy. For example, say I want to measure a piece of code that calculates what should be hidden in a scene:

            TimingObject.BeginSingle();
     [..code that calculates visibility ...]
     TimingObject.EndSingle("CalculatingHiddenObjects");

The string passed to "EndSingle" will ensure that value it attached to some identifier. Now, if I need to nest between timings, I can use BeginSpecific and EndSpecific:

            TimingObject.BeginSpecific("TotalTime");
     TimingObject.BeginSingle();
     [..code that calculates visibility ...]
     TimingObject.EndSingle("CalculatingHiddenObjects");
     TimingObject.BeginSingle();
     [..other stuff ...]
     TimingObject.EndSingle("OtherCalculations");
     TimingObject.EndSpecific("TotalTime");

This model has worked remarkably well. Additionally, built into the class I have code that stores the times in an array and averages them, as well as takes note of the max and min values. The class also has a function to output all values to a text file, and provide percentages based on the total frame and entity render times sorted by the most expensive- this was a very useful feature for me!

Results? I have improved my code to where it is over 5x faster! Huge difference! It came much more in line with what I was hoping for. I'm very happy, and I was able to make excellent use of my time while learning some great lessons on how to write my DirectX code more efficiently. In line with the 80/20 "rule", indeed, about 80% of my bottle neck was in about 20% of my code. In the most complex scene I tested, I went from about 120 FPS, to about 680! That's a 566% improvement after about 25 minutes of constantly optimizing by testing out different things and looking through the generated performance log.

In closing, I felt like this was a successful approach I want to repeat again in other areas: first I learned how to write code that accomplished my goals without having to think about performance and I didn't waste my time micro-optimizing. Then, when I was ready, I invested some time up front to write a tool that made generating, collecting, and reading metrics easily and used that to tackle optimization. The 30 minutes that I spent up-front writing my timing class was definitely worth it in the end, and I would dare say probably saved me plenty of time.