Making Code Faster: Pulling Out the Profiler

After doing all I can without reaching out to the profiler, and managing to get a x45 performance gain, let's see what the profiler actually tells us. We’ll use the single-threaded version since that is easier.

Here it is:

We can see that dictionary operations take a lot of time, which is to be expected. But what is very surprising is that the date time calls are extremely expensive in this case.

The relevant code for those is here. You can see that it is pretty nice, but there are a bunch of things there that are likely costing us. The exception inside the method prevents inlining; there is error handling here that we don’t need since we can safely assume in this exercise that the data is valid, etc.

So, I changed the ParseTime to do this directly, like so:

private static readonly int[] DaysToMonth365 = {
    0, 31, 59, 90, 120, 151, 181, 212, 243, 273, 304, 334, 365};
private static readonly int[] DaysToMonth366 = {
    0, 31, 60, 91, 121, 152, 182, 213, 244, 274, 305, 335, 366};

private const long TicksPerMillisecond = 10000;
private const long TicksPerSecond = TicksPerMillisecond * 1000;
private const long TicksPerMinute = TicksPerSecond * 60;
private const long TicksPerHour = TicksPerMinute * 60;
private const long TicksPerDay = TicksPerHour * 24;

private static long ParseTime(byte* buffer)
{
    var year = ParseInt(buffer, 4);
    var month = ParseInt(buffer + 5, 2);
    var day = ParseInt(buffer + 8, 2);
    var hour = ParseInt(buffer + 11, 2);
    var min = ParseInt(buffer + 14, 2);
    var sec = ParseInt(buffer + 17, 2);

    var leap = year%4 == 0 && (year%100 != 0 || year%400 == 0);

    int[] days = leap ? DaysToMonth366 : DaysToMonth365;
    int y = year - 1;
    int n = y*365 + y/4 - y/100 + y/400 + days[month - 1] + day - 1;

    long totalSeconds = (long)hour * 3600 + (long)min * 60 + sec;

    return n*TicksPerDay + totalSeconds*TicksPerSecond;
}

That tiny change saved us 11%!

Here are our current costs:

Note that we reduced the cost of parse significantly (at the cost of error handling, though), but there is still a lot of work being done here. It turns out that we were actually measuring the time to write to the summary file as well (that is what all those FormatHelpers calls are), so that dirties the results somewhat.

The next place that we need to look at is the Dictionary. It is expensive even though the usage of FastRecord means that we only need a single call per line; that isn’t so much fun. Note that it is using the GenericEqualityComparer. Can we do better?

We’ll go back to the parallel version with the ParseTime optimization and we are now running at 628 ms. At this rate, I don’t think that there is much more room for improvements, so unless someone suggests something, we are done.