Over the years, I've certainly seen an awful lot of horribly lame methods to time VB code. The most common mistakes include:
- Using VB's own Timer function, with its clock-tick resolution of ~55ms,
- Timing too few iterations to make for meaningful comparisons,
- Including non-critical code that shouldn't be timed,
- Failing to subtract the time of loop overhead and other code that couldn't be eliminated, and
- Testing in the IDE rather than from a compiled EXE.
Published results that don't account for the above are worse than worthless. I've used the CStopWatch class for many years now, and would encourage others to use it as well, for consistent benchmarks. CStopWatch provides millisecond resolution on most PCs, by employing the multimedia timer call timeGetTime. Using it is almost too easy! Check out this example:
A complete project, benchmarking the difference between 100,000 calls to
Unicode and ANSI versions of GetWindowsDirectory.
Option Explicit Private Declare Function GetWindowsDirectoryA Lib "kernel32" _ (lpBuffer As Any, ByVal nSize As Long) As Long Private Declare Function GetWindowsDirectoryW Lib "kernel32" _ (lpBuffer As Any, ByVal nSize As Long) As Long Private Sub Form_Click() Dim tmr As CStopWatch Dim tL As Long Dim t1 As Long, t2 As Long Dim i As Long Dim BufferA As String Dim BufferW() As Byte Const Loops As Long = 100000 Const MAX_PATH As Long = 260 ' Create instance of stopwatch class Set tmr = New CStopWatch ' Determine overhead of looping tmr.Reset For i = 1 To Loops Next i tL = tmr.Elapsed ' See how long it takes to make (Loops) calls ' to an ANSI function BufferA = Space$(MAX_PATH) tmr.Reset For i = 1 To Loops Call GetWindowsDirectoryA(ByVal BufferA, MAX_PATH) Next i t1 = tmr.Elapsed ' See how long it takes to make (Loops) calls ' to Unicode version of same function ReDim BufferW(0 To (MAX_PATH * 2) - 1) As Byte tmr.Reset For i = 1 To Loops Call GetWindowsDirectoryW(BufferW(0), MAX_PATH) Next i t2 = tmr.Elapsed ' Output results, subtracting loop overhead Me.Cls Me.Print "Loop Overhead:", tL; " ms" Me.Print "ANSI Calls:", , t1 - tL; " ms" Me.Print "Unicode Calls:", t2 - tL; " ms" Debug.Print "Loop Overhead:", tL; " ms" Debug.Print "ANSI Calls:", , t1 - tL; " ms" Debug.Print "Unicode Calls:", t2 - tL; " ms" End Sub
IDE Results: EXE Results: Loop Overhead: 16 ms ANSI Calls: 1672 ms Unicode Calls: 109 ms Loop Overhead: 0 ms ANSI Calls: 1422 ms Unicode Calls: 78 ms Tests conducted on a dual-P6/200, with 128Mb RAM,
running NT4/SP3 and VB5/SP2.
Amazing what a difference there is between making Unicode and ANSI calls, isn't there?
The results returned by CStopWatch are all in milliseconds, of course. Not a unit of measure humans often think in. To convert milliseconds to more intuitive output, especially for longer time periods, you could use a function such as this:
Public Function FormatHMS(Optional ShowDecimal As Boolean) As String Dim Rtn As String Dim e As Long ' This routine is useful to get a nicely formatted display of ' elapsed time for reports and such. Not a good one to call ' within tight loops, of course! e = Me.Elapsed Rtn = Format$(DateAdd("s", (e \ 1000), #12:00:00 AM#), "HH:MM:SS") If ShowDecimal Then Rtn = Rtn & "." & Format$(e Mod 1000, "000") FormatHMS = Rtn End Function
I've actually added this function to the base class, on the recommendation of a reader, to make it easier to use. Many happy benchmarks!
This sample, or the one from which it originally derived, was published (or at least peripherally mentioned) in the following article(s):
This sample uses the following API calls:
Module Library Function CStopWatch.cls winmm timeBeginPeriod
Don't see what you're looking for? Here's a complete API cross-reference.
Please, enjoy and learn from this sample. Include its code within your own projects, if you wish. But, in order to insure only the most recent code is available to all, I ask that you don't share the sample by any form of mass distribution.
Download StopWatch.zip, 19Kb, Last Updated: Monday, April 26, 2010