Windows DevCenter    
 Published on Windows DevCenter (http://www.windowsdevcenter.com/)
 See this if you're having trouble printing code examples

Using Timers to Evaluate Code Performance

by Ron Petrusha
03/01/2005

Frequently, in an effort to maximize performance, programmers need to evaluate the execution time of a block of code, and possibly to compare it with other comparable blocks of code. In this article, we'll examine the techniques available in Visual Basic for doing that.

The Timer Function

The most common way to time the execution of a particular block of code is to insert calls to the Visual Basic Timer function at the starting and ending points of the code to be timed. The function returns a Single, representing the approximate number of seconds that have elapsed since midnight. For instance, at 5:30:46 p.m., the Timer function returns a value of 63,046.21. We can then use code like the following to evaluate code performance; in this case, to compare the amount of time required to iterate a string array of 30,001 elements using a For loop and a For Each loop:

Dim strArr(30000) As String

Private Sub cmdFor_Click()

   Dim sngStart As Single, sngEnd As Single
   Dim ctr As Integer, ctrStart As Integer, ctrEnd As Integer
   Dim sValue As String

   ctrStart = LBound(x)
   ctrEnd = UBound(x)

   sngStart = Timer
   For ctr = ctrStart To ctrEnd
      sValue = x(ctr)
   Next
   sngEnd = Timer
   txtFor.Text = sngEnd - sngStart

End Sub

Private Sub cmdForNext_Click()

   Dim sngStart As Single, sngEnd As Single
   Dim mem As Variant
   Dim sValue As String

   sngStart = Timer
   For Each mem In x
      sValue = mem
   Next
   sngEnd = Timer
   txtForNext.Text = sngEnd - sngStart

End Sub

The results, however, may appear as shown in Figure 1. Although our code has attempted to time the execution of two loops that each iterate 1,000 elements of a string array, the text boxes show that no time has elapsed.

Figure 1
Figure 1. The result of using the Timer function

The reason for this apparent anomaly is the resolution of the Timer function, which is based entirely on the system clock. Table 1 shows the interval between ticks of the system clock in the various versions of Windows. This means that, on a system running Windows NT 3.5 or later, an elapsed time of 0ms to 9ms will not be detected, while times that vary by as much as 9ms can appear to be identical. (On systems running Windows 95/98/ME, these numbers are even greater.) For purposes of testing and evaluating code performance, the resolution of the Timer function is simply too imprecise.

Version Tick Frequency Ticks Per Second
Windows 95/98/ME 55ms approx. 18
Windows NT 3.1 16ms 62.5
Windows NT 3.5 and later 10ms 100
Table 1. Resolution of the system clock in Windows versions

In many cases, this degree of imprecision may be acceptable. When it is not, however, we can use the multimedia timer functions in the Win32 API to precisely measure the execution times of blocks of code.

Multimedia Timer Functions

While the resolution of the system timer used by Windows is dependent on the operating system, the resolution of the system's multimedia timers is dependent on installed hardware. You can determine the capabilities of the system's multimedia timers by calling the timeGetDevCaps function. Its syntax is:

Public Declare Function timeGetDevCaps Lib "winmm.dll" ( _
      ByRef lpTimeCaps As TIMECAPS,       ' Multimedia timer capabilities
      ByVal uSize As Long _               ' Set to Len(TIMECAPS)
     ) As Long

The TIMECAPS structure passed to the function is defined as follows:

Public Type TIMECAPS
   wPeriodMin As Long        ' Timer's minimum supported resolution
   wPeriodMax As Long        ' Timer's maximum supported resolution
End Type

On return, the members of the TIMECAPS structure are populated with their respective values, and the timeGetDevCaps function should return TIMERR_NOERROR. If the function fails, it returns TIMERR_STRUCT.

The most commonly used multimedia timing function is timeGetTime, which returns a Long containing the number of milliseconds that have elapsed since the system started. Its syntax is:

Public Declare Function timeGetTime Lib "winmm.dll" () As Long

By default, the timer's resolution is approximately 5ms, or about half that of the Visual Basic Timer function. However, this resolution can be overridden for an individual application by calling the timeBeginPeriod function. Its syntax is:


Public Declare Function timeBeginPeriod Lib "winmm.dll" 
     (ByVal uPeriod As Long) As Long

where uPeriod is the number of milliseconds to which to set the timer resolution. The function returns TIMERR_NOERROR if the function succeeds and TIMERR_NOCANDO if it fails. After you've finished using the timer, you should restore its default resolution by calling the timeEndPeriod function, which has the following syntax:


Public Declare Function timeEndPeriod Lib "winmm.dll" 
     (ByVal uPeriod As Long) As Long

The uPeriod argument here must match the uPeriod argument supplied in the call to the timeBeginPeriod function. In other words, for each call to timeBeginPeriod, there should be a corresponding call to timeEndPeriod with the same uPeriod argument.

There is one major complication with using timeGetTime. Because it returns a Long, it can hold values from 0 (presumably representing a system that has just started) to 232 (which represents a system that's been running for more than 49 days). In order to be confident that our timer will work correctly, we have to make an allowance for the special case in which the start time exceeds the end time. This can be handled with pseudo-code like the following:

If StartTime > EndTime Then
   ElspsedTime = EndTime + (&HFFFF - StartTime)

We now can rewrite our earlier code example that compares the execution time of a For and a For Each loop when iterating 30,001 elements of a string array to take advantage of the timeGetTime function instead of Timer. The following code sets the timer resolution to its minimum value (as reported by the TIMECAPS structure's wPeriodMin member), determines the elapsed time by successive calls to timeGetTime, and then calls timeEndPeriod to restore the default timer: 

Dim strArr(30000) As String
Dim tc As TIMECAPS

Private Sub cmdFor_Click()

   Dim lngStart As Long, lngEnd As Long
   Dim ctr As Integer, ctrStart As Integer, ctrEnd As Integer
   Dim sValue As String

   ctrStart = LBound(strArr)
   ctrEnd = UBound(strArr)

   lngStart = timeGetTime
   For ctr = ctrStart To ctrEnd
      sValue = strArr(ctr)
   Next
   lngEnd = timeGetTime
   If lngEnd >= lngStart Then
      txtFor.Text = lngEnd - lngStart
   Else
      txtFor.Text = lngEnd + (&HFFFF - lngStart)
   End If
End Sub

Private Sub cmdForNext_Click()

   Dim lngStart As Single, lngEnd As Single
   Dim mem As Variant
   Dim sValue As String

   If timeBeginPeriod(tc.wPeriodMin) = TIMERR_NOERROR Then
      lngStart = timeGetTime
      For Each mem In strArr
         sValue = mem
      Next
      lngEnd = timeGetTime
      timeEndPeriod tc.wPeriodMin
      If lngEnd >= lngStart Then
         txtForNext.Text = lngEnd - lngStart
      Else
         txtForNext.Text = lngEnd + (&HFFFF - lngStart)
      End If
   Else
      txtForNext.Text = "N/A"
   End If
End Sub

Private Sub Form_Load()

   Dim ctr As Integer
   
   If timeGetDevCaps(tc, Len(tc)) = TIMERR_NOERROR Then
      txtMin.Text = tc.wPeriodMin
      txtMax.Text = tc.wPeriodMax
   End If

   For ctr = LBound(strArr) To UBound(strArr)
      strArr(ctr) = "This is a short string."
   Next

End Sub

This produces a result like the one shown in Figure 2. Note that the execution of the For loop takes 3ms, while the For Each loop shows no elapsed time, evidently because it executes in under 1ms.

Figure 2
Figure 2. The result of the timeGetTime function

The High-Resolution Performance Counter

If the resolution offered by the multimedia timer is inadequate (as it is in the For Each loop of our previous code fragment), the performance timer used by the system for performance monitoring is also available. Since its resolution depends on the system (it is set when the system is started, and cannot be modified subsequently), you must first use the QueryPerformanceFrequency function to determine what the resolution of the system's performance timer is. Its syntax is:

Public Declare Function QueryPerformanceFrequency Lib "kernel32.dll" _
                        (ByRef lpFrequency As LARGE_INTEGER) As Boolean

The function returns a Boolean statement indicating whether the system supports a high-resolution performance counter.

Note that the function's single argument is a 64-bit integer that, when the function returns, contains the number of ticks per second. LARGE_INTEGER, the 64-bit integer, is actually a structure, defined as follows:

Public Type LARGE_INTEGER
   lowpart As Long
   highpart As Long
End Type

Related Reading

VBScript in a Nutshell
By Paul Lomax, Matt Childs, Ron Petrusha

Unfortunately, since Visual Basic in its pre-.NET versions doesn't offer native support for 64-bit integers, LARGE_INTEGER is cumbersome to work with. You can't simply assign it to an integer, or an overflow error results. You can't simply assign each of its members to a Single or Double, since the low-order integer will more often then not be interpreted as a negative number.

One viable suggestion (and certainly the easiest to implement) is to modify the function definition so that lpFrequency is of type Currency, which in Visual Basic is a 64-bit number. Because the decimal representation of currency values in Visual Basic has four decimal places, the value of lpFrequency should then be multiplied by 10,000 to get the number of ticks per second.

The alternative, which we'll adopt in our code example, is to work with the LARGE_INTEGER directly. This involves assigning the values of the LARGE_INTEGER to a Double using the following steps:

  1. Multiply the highpart member of LARGE_INTEGER by 2 ^ 32. This has the effect of shifting highpart to the left by 32 bits.
  2. Add the lower 31 bits of lowpart to the Double variable (or, to put it another way, mask out the sign bit from lowpart). You can do this by ANDing lowpart with &H7FFFFFFF, which is the hexadecimal representation of a 32-bit integer with its sign bit off.
  3. If the sign bit of lowpart is present, add &H80000000, or 231, to the Double variable. (&H80000000, or 23, is the value of an unsigned long integer with only its uppermost bit set on.)

The following ConvertLargeInt function handles this conversion of a LARGE_INTEGER to a Double:

Public Function ConvertLargeInt(li As LARGE_INTEGER) As Double
   Dim dbl As Double
   
   dbl = li.highpart * 2 ^ 32                 ' handle highpart
   dbl = dbl + (li.lowpart And &H7FFFFFFF)   ' handle all but sign bit of lowpart
   If li.lowpart And &H80000000 Then dbl = dbl + 2 ^ 31     ' handle sign bit

   ConvertLargeInt = dbl
End Function
Once we know the timer frequency, we can actually time code execution by calling the QueryPerformanceCounter function. Its syntax is: 
Public Declare Function QueryPerformanceCounter Lib "kernel32.dll" _
             (ByRef lpPerformanceCount As LARGE_INTEGER) As Boolean

Like the QueryPerformanceFrequency function, QueryPerformanceCounter has a single LARGE_INTEGER argument that, when the function returns, contains the current value of the counter. To determine elapsed time, we need to call the function when we want to start measuring code execution, then call it again when we have finished measuring code execution. Dividing the difference between the start and end times by the frequency should yield the number of seconds that the code has executed.

We can now rewrite our code example a third time to use a performance counter when comparing the time required for a For and a For Each loop to iterate an array of strings. The code is as follows:

Dim dblFreq As Double
Dim strArr(30000) As String

Private Sub Form_Load()
   Dim freq As LARGE_INTEGER
   Dim ctr As Integer

   If QueryPerformanceFrequency(freq) Then
      dblFreq = ConvertLargeInt(freq)
   End If
   QueryPerfFreq curFreq
   For ctr = LBound(strArr) To UBound(strArr)
      strArr(ctr) = "This is a short string."
   Next
End Sub

Private Sub cmdFor_Click()
   Dim liStart As LARGE_INTEGER, liEnd As LARGE_INTEGER
   Dim dblStart As Double, dblEnd As Double
   Dim ctr As Integer, ctrStart As Integer, ctrEnd As Integer
   Dim sValue As String

   ctrStart = LBound(strArr)
   ctrEnd = UBound(strArr)

   If QueryPerformanceCounter(liStart) Then
      For ctr = ctrStart To ctrEnd
         sValue = strArr(ctr)
      Next
      QueryPerformanceCounter liEnd
      dblStart = ConvertLargeInt(liStart)
      dblEnd = ConvertLargeInt(liEnd)
      txtFor.Text = Format((dblEnd - dblStart) / dblFreq, "0.0000")
   End If
End Sub

Private Sub cmdForNext_Click()

   Dim liStart As LARGE_INTEGER, liEnd As LARGE_INTEGER
   Dim dblStart As Double, dblEnd As Double
   Dim mem As Variant
   Dim sValue As String

   If QueryPerformanceCounter(liStart) Then
      For Each mem In strArr
         sValue = mem
      Next
      QueryPerformanceCounter liEnd
      dblStart = ConvertLargeInt(liStart)
      dblEnd = ConvertLargeInt(liEnd)
      txtForNext.Text = Format((dblEnd - dblStart) / dblFreq, "0.0000")
   End If
End Sub

The result of running this code is shown in Figure 3. Note that the performance counter has provided us with sufficient resolution to actually time the execution of the For Each loop, although in this version it appears to run slower than the For loop.

Figure 3
Figure 3. The result of the QueryPerformanceCounter function

Ron Petrusha is the author and coauthor of many books, including "VBScript in a Nutshell."

Return to the Windows DevCenter.

Copyright © 2009 O'Reilly Media, Inc.