Friday 31 October 2008

Timing Code Execution

I recently came across some code written in VB6 that used the Timer function to record a value before code execution began, and another when it completed and used the difference between the two to calculate how long it had taken to execute the code.

Dim n As Double n = Timer() ' Some long running operation here... Debug.Print Timer() - n

Now this method of calculating how long it has taken to execute code is nothing new to me, and neither is the Timer function, however I stopped using that function many years ago because I classed it as inaccurate and not flexible enough. Seeing it used in recently written code I decided to conduct some experiments and do a little research to see how well founded my suspicions were.

Well it didn’t take long to start finding problems with the Timer function. The biggest drawback is that the maximum amount of time that can pass is 24 hours as the output of the function resets to zero at midnight every day. Also, the very output itself is determined on what the system clock reports, something I find is historically inaccurate (how many times do you notice your computers clock has lost or gained time? Before the introduction of Windows XP’s time synchronising feature I would regularly see my PC’s clock loose or gain several minutes in only a few weeks).

The first major problem I came across was what happened if the systems clock changed between the start and end of the code execution being timed. This is not as unlikely as it may seem, as Windows may reset the clock after synchronising it with the Internet time. Because the Timer function uses the PC’s clock to calculate its output, any change in the system time would be reflected in the output. For example if the time were changed to be two minutes later in the day than previously, then the return value of the timer function would also include this two minute addition and the code execution time would appear to have taken two minutes longer than it really did.

Another gripe that I have is the data type of the return value, a Double, or floating point real number. This means that when you perform calculations (like subtraction) on two return values you sometimes end up with a number with very many decimal points. This is misleading as the precision of the Timer function is at best only accurate to about 3 decimal points.

So what are the alternatives? Well there are other ways of timing code execution (or the timing of anything for that matter) but they all require you use the Win32Api. This should not be a problem as they are fairly easy functions, however it will seem a little peculiar to someone who has only ever used the rudimentary VB6 functions. The three I am going to look at are:

  • GetTickCount
  • timeGetTime
  • QueryPerformanceCounter

I am going to start by just looking at the first two functions. They are both very similar, both returning a value in milliseconds and both using the amount of time that has elapsed since the computer started. So what's the difference?

Below is a piece of code that measures the accuracy of each function:

Option Explicit Private Declare Function GetTickCount Lib "kernel32" () As Long Private Declare Function timeGetTime Lib "winmm.dll" () As Long Public Sub Main() Dim n As Long n = GetTickCount() Do Until GetTickCount() <> n Loop n = GetTickCount() - n Debug.Print "GetTickCount is accurate to within: " & _ Format(n / 1000, "0.000") & " seconds" n = timeGetTime() Do Until timeGetTime() <> n Loop n = timeGetTime() - n Debug.Print "timeGetTime is accurate to within: " & _ Format(n / 1000, "0.000") & " seconds" End Sub

The actual values may vary depending on the specific hardware you are using and more specifically the timer tick rate. I get a value of 16 milliseconds with GetTickCount and 1 millisecond with timeGetTime.

So although GetTickCount returns the number of milliseconds that have elapsed since the system was started, it is actually only accurate to about a 40th of a second. But because timeGetTime is a Windows Multimedia function there is a performance hit in its use. Its higher accuracy comes at a price. However, both of these functions are far more accurate than the VB6 Timer function.

It's not until we start using the QueryPerformanceCounter that we see very accurate timers, often with sub-microsecond precision. There is a drawback however, and that is that not all computers have the hardware to support the QueryPerformanceCounter, also the actual precision that can be achieved is not pre-determined and can change from one machine to the next. It may even vary on a laptop depending on whether it is running on AC power or battery power.

In order to use the QueryPerformanceCounter you first need to make a call to the QueryPerformanceFrequency function passing in a 8 byte variable (in VB6 we can use the Currency data type) and checking the return value is nonzero. The 8 byte value is the number of counts per second the system can achieve. A value of over 1,000,000 would indicate that each count can be done in less than one microsecond.

Option Explicit Private Declare Function QueryPerformanceFrequency Lib "kernel32" ( _ lpFrequency As Currency) As Long Private Declare Function QueryPerformanceCounter Lib "kernel32" ( _ lpPerformanceCount As Currency) As Long Public Sub Main() Dim curFreq As Currency Dim curStart As Currency Dim curEnd As Currency If QueryPerformanceFrequency(curFreq) <> 0 Then QueryPerformanceCounter curStart ' Some long running operation here... QueryPerformanceCounter curEnd Debug.Print "Code executed in " & _ (curEnd - curStart) / curFreq & " seconds" Else Debug.Print "Could not use the Performance Counter" End If End Sub

It is worth noting that because the Currency data type has a precision of 4 decimal places any value populated by the QueryPerformanceFrequency and QueryPerformanceCounter functions needs to be multiplied by 10,000. This does not matter in the code above because all the values in the function have the same precision. But, for example, if I wanted to inform the user of the frequency, or precision, of the performance counter I would have to multiply the curFreq variable by 10,000.

On my machine I get a frequency of 239,232, when multiplied up I get 2,392,320,000. This represents a precision of half a nanosecond. Many orders of magnitude more precise than the Timer VB6 function, and far more accurate too.


References:

  1. GetTickCount Function
  2. timeGetTime
  3. QueryPerformanceFrequency Function
  4. QueryPerformanceCounter Function
  5. The Old New Thing : Precision is not the same as accuracy

No comments: