I was recently performance testing a logging component I’d written which simply logs entries to text file when I stumbled on a performance bottle neck I’d never come accross before.
I wrote the following simple test:
System.Diagnostics.Debug.WriteLine(“Starting 10000 logs entries at: ” + DateTime.Now.TimeOfDay.ToString());
for(int i = 0; i < 10000; i++)
Logger.Instance.CreateLogEntry(“New entry number ” + i.ToString());
System.Diagnostics.Debug.WriteLine(“Finished writing entries at: ” + DateTime.Now.TimeOfDay.ToString());
This managed 10,000 writes in 0.5 secs. I then added the following line into the CreateLogEntry method:
if (_logDate.Date != DateTime.Now.Date)
I was using this check to see if the date had rolled over to the next day (This component is used by a windows serivce that runs continuously and creates a new log file each day). When I re-ran my test imagine my horror to see that the 10,000 writes was now taking 5 mins and 19 secs!
For a moment I wondered how date comparisons in .NET could possible be so slow, and it was then that I realised I was never initialising _logDate, so each time the CreateLogEntry method was called I was doing a comparison between DateTime.Now.Date and null. After fixing my mistake I was back to doing 10,000 writes in 0.53 secs… much better!
It did teach me an important leason though. Comparison with null is very expensive and should be avoided at all costs if performance is a priority.