Debugging can hurt you

I was working on a performance issue. In dTris my ski racing software, racers were taking 1-2 seconds to get from the start of the race course to being in progress after we have heard the timer acknowledge the racer is on course.

In a regular program this might not be that bad but dTris is a real time application which requires that the user have quick refresh of the information. I started logging all the timings and calculate the time from intial pulse read to final refresh of UI, there was Debug.WriteLine statements everywhere!

I just could not get the system to perform any better.

Then reading stack overflow it someone asked why is Debug.WriteLine so slow?

So I did a test of my log4net vs Debug.Witeline. Debug for writeline was 20x slower than my internal logging.

Line chart comparing Debug.WriteLine vs TimingLog performance across character counts from 0 to 2000

Debug.WriteLine avg

~460 µs

TimingLog avg

~4.3 µs

Speed advantage

~100×

Iterations per run

10,000

Debug.WriteLine (µs) TimingLog (µs, right axis)
Debug.WriteLine stays relatively flat around 450-580 µs; TimingLog rises from ~1.4 µs at 0 chars to ~8.5 µs at 2000 chars.

Character count (string length passed to timing call)

After updating all my Debugging statements to use my internal debug logger the performance issue went away.

  • Graph made by Claude