Testing Code Execution Performance
You may be familiar with the coverage profiler which does a pretty good job of giving you the time it takes for a particular piece of code to run (even better if you’re using VFP9 or have written some custom queries for the coverage log).  This is preferred if you are diagnosing a lag somewhere in your application and/or need to eek out that last bit of performance.  I won’t be going over the coverage profiler today, but want to speak instead to the times when you just want to test a small snippet of code.  This is usually compared to another snippet of code to find out which is faster.

For example, let’s say you wanted to find out how Transform(lnVar) compares to ALLTRIM(STR(lnVar)) for 100000 iterations.  Well, you’d be able to easily find out that ALLTRIM(STR()) is significantly faster if you used one of the methods below.

Some things to bear in mind when testing snippet execution speed
VFP will sometimes cache certain things from the first run and this can greatly effect the execution speed of subsequent code that is similar and being tested at the same time.  Also, processes running on your machine can also vary results.  If you end task on the unnecessary processes running on your computer your results will be more accurate.  It is always best to run your tests several times and differ the order in which they execute (check transform() first and Alltrim(str()) second and then switch so Alltrim(str()) runs first).  Also, using an average of multiple runs can increase the accuracy of your results as well.

A couple of quick notes on the code below
There are three basic methods outlined below in a runnable example (feel free to insert your code snippet you want analyzed in the For…Loops).  The code is runnable as is, though it doesn’t actually compare anything.  I’ve left it up to you to create the additional loops and provide the snippets of code you want tested.  Basically you’ll just pick one of the methods outlined and create two loops, one with your first snippet and then another with an additional snippet you are doing comparisons with.  Hopefully that’s self-explanatory, but just in case it wasn’t I thought I’d take a SECOND to point it out.

The first method is the most commonly used one by VFP developers – Seconds().  Seconds() is a fast and easy way to get the number of milliseconds for a snippet of code to execute.  There are drawbacks to this approach.  Seconds() only has a resolution of either 1 or 10 milliseconds and it resets itself after midnight, as Seconds() returns the number of seconds since midnight.  The latter of these drawbacks can really give an odd result if the clock strikes midnight during your tests.

Using GetTickCount()
The next method explored is the GetTickCount API function.  It does not have the drawback of resetting at midnight.  In fact, it only resets if your machine runs for 49.7 consecutive days without a reboot.  It has a resolution of 1 milisecond, which makes it pretty accurate.  However, that accuracy is nothing compared to the third method outlined in the code below.

Using the High-Resolution Performance Counter
The third method uses the High-Resolution Performance Counter on your system.  I should say it uses it, if your system has one, but I have yet to run into a system that doesn’t using this method.  The accuracy of this method can vary from system to system, but just to give you some idea of what we’re talking about here in terms of accuracy, on my system it is accurate to 1/3579545 of a second.  That’s pretty accurate, even for code that runs so fast it’s virtually unreccordable using one of the first two methods I’ve described here.

Parting Shot
There is more I could say on this subject and definitely other ideas (timer objects for instance), but I think I’ll leave that one for now as the methods outlined below should cover most situations that a developer is likely to ever run into. Just cut-n-paste the code below into a VFP prg and execute it.

SET DECIMALS TO 18 && maximum number of places
********* USING SECONDS() **************
LOCAL lnCurrentTickCount
lnCurrentTickCount = SECONDS() && Click stop watch on
*!* Pretend code running
FOR i = 1 TO 100000
*!* Command(s)
?”Elapsed time in seconds: ” + TRANSFORM(SECONDS() – lnCurrentTickCount) && Click stop watch off and report
********** USING GetTickCount() ***********
LOCAL lnCurrentTickCount
DECLARE INTEGER GetTickCount IN kernel32
lnCurrentTickCount = GetTickCount() && Click stop watch on
*!* Pretend code running
FOR i = 1 TO 100000
*!* Command(s)
?”Elapsed time in seconds: ” + TRANSFORM((GetTickCount() – lnCurrentTickCount)/1000) && Click stop watch off and report
*** USING high-resolution performance counter ***
LOCAL lcBuffer1, lcBuffer2, lnTicksPerSecond, lnCurrentTickCount
DECLARE INTEGER QueryPerformanceFrequency IN kernel32 STRING @lpFrequency
DECLARE INTEGER QueryPerformanceCounter IN kernel32 STRING @lpPerformanceCount
lcBuffer1 = SPACE(8)
lcBuffer2 = SPACE(8)
lnTicksPerSecond = buf2num(SUBSTR(lcBuffer1, 1,4)) + buf2num(SUBSTR(lcBuffer1, 5,4)) * 2^32
=QueryPerformanceCounter(@lcBuffer1) && Click stop watch on
*!* Pretend code running
FOR i = 1 TO 100000
*!* Command(s)
=QueryPerformanceCounter(@lcBuffer2) && Click stop watch off
lnCurrentTickCount = buf2num(SUBSTR(lcBuffer1, 1,4)) + buf2num(SUBSTR(lcBuffer1, 5,4)) * 2^32
lnCurrentTickCount = (buf2num(SUBSTR(lcBuffer2, 1,4)) + buf2num(SUBSTR(lcBuffer2, 5,4)) * 2^32) – lnCurrentTickCount
? “Elapsed time in seconds: ” + TRANSFORM(lnCurrentTickCount/lnTicksPerSecond)
? “HR Performance counter accurate to 1/” + TRANSFORM(lnTicksPerSecond) + ” of a second”


FUNCTION buf2num(tcBuffer)
RETURN ASC(SUBSTR(tcBuffer, 1,1)) + ;
ASC(SUBSTR(tcBuffer, 2,1)) * 2^8 + ;
ASC(SUBSTR(tcBuffer, 3,1)) * 2^16 + ;
ASC(SUBSTR(tcBuffer, 4,1)) * 2^24