The Performance Counter has come a long way since it's introduction. Earlier incarnations were only guaranteed to be invariant during a Windows session. There was no synchronisation between cores giving rise to issues during context switching. With modern Windows systems these 'problems' are no more.
There are 16 timers from 0 to 15 and the principle use is for timing sections of code anywhere in our applications. We may have a routine called many times and need a section of it to be a tad faster. We may rewrite the code and hope that it will be faster. By timing the section in question we will know whether we have an improvement or not. One of the great things about peer support forums is that we can post some code and ask "Can anyone get more speed out of this?". We may, of course, have to put our ASM hat on if BASIC is not up to what we want.
The simplest method in the include file is a single pass timer used like this:
StartTimer(0)
' Code to be timed'
StopTimer(0)
We get a simple result from:
Print sTimeTaken(0, 3, False)
The first parameter is the timer index used for the timing.
The second parameter sets the number of decimal places to output:
0 to 3 for 0 to 3 decimal places in milliseconds - ms
4 to 7 for 0 to 3 decimal places in microseconds - us
If the second parameter is negative then we get the full non-formated output in milliseconds.
The third parameter is for choosing between a simple output (False) or a verbose output (True).
For example, a simple output will look like this: 501.246ms
A verbose output will look like this: [1] in MYROUTINE Single: 20.6ms
This tells us that timer 1 in the routine MyRoutine reports 20.6ms for a single pass.
Using sTimetaken() may be delayed until just prior to an applications closure. On executing sTimeTaken, and all the other print routines, the variables used are reset, releasing the index used for further use. Using an index which has not been released will give unpredictable results.
The next type of method is for multiple passes of the section in question.
There is a variety of analyses: Fastest time, Slowest time, Total time, Fast/Slow time and Average time.
Here is an example of Total time:
StartTimer(0)
' Code to time
StopTimer_UpdateTotalTime(0)
and we get a simle result from:
Print sTotalTimeTaken(0,3,False)
A simple output will look like the example above.
A verbose output will look liike this: [0] in RANDOMTIMES Total(10): 83.96ms
Just after Total is the number of times the code in question was timed. More often than not, in my case, I know how many passes there will be. However, we may have a section of code in a routine where we do not know how many times it will be passed.
The StopTimer* macros have a corresponding print routine:
sTimeTaken -> StopTimer
sTotalTimeTaken -> StopTimer_UpdateTotalTime
sFastestTimeTaken -> StopTimer_UpdateFastestTime
sSlowestTimeTaken -> StopTimer_UpdateSlowestTime
sFastSlowTimeTaken -> StopTimer_UpdateFastSlowTime
sAverageTimeTaken -> StopTimer_UpdateTotalTime
The average time print routine needs StopTimer_UpdateTotalTime since the average is, of course, simply the total time divided by the number of passes.
The last statement in StartTimer() is a QueryPerformanceCounter and the first statement of all the StopTimer* macros is a QueryPerformanceCounter. This ensures the best possible timing. The statements before and after these QueryPerformanceCounters obviously take time but it is small and does not appear to have any adverse effects on the surrounding code. However, they will play an adverse role on timings if the timers are nested or interleaved.
There are some miscellaneous macros.
sPerformanceCounterFrequency returns precisely that. When I upgraded from Windows 7 to Windows 10 my default frequency was 3,417,991 or thereabouts. However, enabling HPET in the BIOS and using 'bcdedit /set useplatformclock true' at the Command prompt/PowerShell prompt gets me 14,318,180. I used the HPET with Windows 7 for years without any apparent issues although some gamers prefer not to use it. With the lower frequency it was too slow to detect an API overhead but with the higher frequency it can, although, on my machine, it is only 10 ticks. 10 ticks is only 0.7 microseconds so I don't bother to compensate for that in the macros.
StartHiResClock/StopHiResClock will increase and restore the system clock's default 64Hz to 1000Hz and vice versa respectively giving Timer and Sleep(n,1) a resolution of one millisecond. I normally don't use StopHiResClock in applications in the knowledge that Windows will restore the default at the termination of an application session.
MacroTimersQPC.inc will add about 51KB to an application but, of course, it should not be left in production code.
I have also included a TimerUsage.bas with some examples.
The Timers may be used with either the 32-bit or 64-bit compilers.
Have fun.
David Roberts
MacroTimersQPC.inc
Code: Select all
#Include Once "windows.bi"
#Include Once "string.bi"
#Include Once "win\mmsystem.bi"
Dim Shared As Large_Integer liFreq
Dim Shared As Large_Integer liStart(0 To 15), liStop(0 To 15)
Dim Shared As Large_Integer liTotalTime( 0 To 15 )
Dim Shared As Large_Integer liFastestTime( 0 To 15)
Dim Shared As Large_Integer liSlowestTime( 0 To 15)
Dim Shared As Large_Integer liTimerCallCount( 0 To 15 )
Dim Shared As String sFuncName( 0 To 15 )
QueryPerformanceFrequency @liFreq
#Define sPerformanceCounterFrequency LTrim(Format(liFreq.QuadPart, "###,###,###,###"))
#Macro StartHiResClock ' Timer & Sleep(n,1) will have a 1ms resolution
Scope
Dim As TIMECAPS tc
TimeGetDevCaps( @tc, SizeOf(tc) )
TimeBeginPeriod(tc.wPeriodMin)
End Scope
Sleep (16,1) ' Tests have shown that the new resolution will not 'bite' until next 'old' tick
#EndMacro
#Macro StopHiResClock
Scope
Dim As TIMECAPS tc
TimeGetDevCaps( @tc, SizeOf(tc) )
TimeEndPeriod(tc.wPeriodMin)
End Scope
Sleep (2,1) ' Tests have shown that the new resolution will not 'bite' until next 'old' tick
#EndMacro
#Macro StartTimer(i)
sFuncName(i) = __FUNCTION__
QueryPerformanceCounter @liStart(i)
#EndMacro
#Define StopTimer(i) QueryPerformanceCounter @liStop(i)
#Macro StopTimer_UpdateTotalTime(i)
QueryPerformanceCounter @liStop(i)
liTotalTime(i).QuadPart += ( liStop(i).QuadPart - liStart(i).QuadPart )
liTimerCallCount(i).QuadPart += 1
#EndMacro
#Macro StopTimer_UpdateFastestTime(i)
QueryPerformanceCounter @liStop(i)
If liTimerCallCount(i).QuadPart = 0 Then
liFastestTime(i).QuadPart = liStop(i).QuadPart - liStart(i).QuadPart
Else
liFastestTime(i).QuadPart = Min( liFastestTime(i).QuadPart, liStop(i).QuadPart - liStart(i).QuadPart )
End If
liTimerCallCount(i).QuadPart += 1
#EndMacro
#Macro StopTimer_UpdateSlowestTime(i)
QueryPerformanceCounter @liStop(i)
liSlowestTime(i).QuadPart = Max( liSlowestTime(i).QuadPart, liStop(i).QuadPart - liStart(i).QuadPart )
liTimerCallCount(i).QuadPart += 1
#EndMacro
#Macro StopTimer_UpdateFastSlowTime(i)
Scope
Dim As Large_Integer liDummy
QueryPerformanceCounter @liStop(i)
liDummy.QuadPart = liStop(i).QuadPart - liStart(i).QuadPart
If liTimerCallCount(i).QuadPart = 0 Then
liFastestTime(i).QuadPart = liDummy.QuadPart
liSlowestTime(i).QuadPart = liDummy.QuadPart
Else
liFastestTime(i).QuadPart = Min( liFastestTime(i).QuadPart, liDummy.QuadPart )
liSlowestTime(i).QuadPart = Max( liSlowestTime(i).QuadPart, liDummy.QuadPart )
End If
End Scope
liTimerCallCount(i).QuadPart += 1
#EndMacro
#Macro SetDecimalPlaces( a )
Select Case a+4*(a>3)+1
Case 1
s = "######"
Case 2
s = "######.#"
Case 3
s = "######.##"
Case 4
s = "######.###"
End Select
#Endmacro
Declare Function sTimeTaken( As Long, As Long, As Long ) As String
Declare Function sTotalTimeTaken( As Long, As Long, As Long ) As String
Declare Function sFastestTimeTaken( As Long, As Long, As Long ) As String
Declare Function sSlowestTimeTaken( As Long, As Long, As Long ) As String
Declare Function sFastSlowTimeTaken( As Long, As Long, As Long ) As String
Declare Function sAverageTimeTaken( As Long, As Long, As Long ) As String
Declare Function FormatOutput( As Long, As ULongLong, As String, As String, As ULongLong, As Long, flag As Long ) As String
' ~~~~~~~~~~
Public Function sTimeTaken( i As Long, j As Long, flag As Long) As String
Dim s As String
Dim k As Long
If j>= 0 Then
k = Min(j,7)
SetDecimalPlaces( k )
s = " " + Format( (liStop(i).QuadPart - liStart(i).QuadPart) * _
IIf(k<4, 1000, 1000000)/liFreq.QuadPart, s) + IIf(k<4, "ms", "us")
Else
s = str( (liStop(i).QuadPart - liStart(i).QuadPart) * 1000/liFreq.QuadPart ) + "ms"
EndIf
If flag = True Then
s = "[" + LTrim(Str(i)) + "] in " + sFuncName(i) + " Single:" + s
EndIf
liStart(i).QuadPart = 0
Return s
End Function
' ~~~~~~~~~~
Public Function sFastestTimeTaken( i As Long, j As Long, flag As Long ) As String
Dim s As String
s = FormatOutPut( i, liFastestTime(i).QuadPart, " Fastest(", sFuncName(i), liTimerCallCount(i).QuadPart, j, flag )
liStart(i).QuadPart = 0
liTimerCallCount(i).QuadPart = 0
liFastestTime(i).QuadPart = 0
Return s
End Function
' ~~~~~~~~~~
Public Function sSlowestTimeTaken( i As Long, j As Long, flag As Long ) As String
Dim s As String
s = FormatOutput( i, liSlowestTime(i).QuadPart, " Slowest(", sFuncName(i), liTimerCallCount(i).QuadPart, j, flag )
liStart(i).QuadPart = 0
liTimerCallCount(i).QuadPart = 0
liSlowestTime(i).QuadPart = 0
Return s
End Function
' ~~~~~~~~~~
Public Function sFastSlowTimeTaken( i As Long, j As Long, flag As Long ) As String
Dim s As String
Dim k As Long
If j >= 0 Then
k = Min(j,7)
SetDecimalPlaces$(k)
s = " " + Format( liFastestTime(i).QuadPart * IIf(k<4, 1000, 1000000)/liFreq.QuadPart, s ) + "~" + _
Format( liSlowestTime(i).QuadPart* IIf(k<4, 1000, 1000000)/liFreq.QuadPart, s) + IIf(k<4, "ms", "µs")
Else
s = Str( liFastestTime(i).QuadPart*1000/liFreq.QuadPart ) + "~" + LTrim(Str( liSlowestTime(i).QuadPart*1000/liFreq.QuadPart )) + "ms"
End If
If flag = True Then
s = "[" + LTrim(Str(i)) + "] in " + sFuncName(i) + " FastSlow(" + LTrim(Str(liTimerCallCount(i).QuadPart)) + "):" + s
End If
liStart(i).QuadPart = 0
liTimerCallCount(i).QuadPart = 0
liFastestTime(i).QuadPart = 0
liSlowestTime(i).QuadPart = 0
Return s
End Function
' ~~~~~~~~~~
Public Function sTotalTimeTaken( i As Long, j As Long, flag As Long ) As String
Dim s As String
s = FormatOutput( i, liTotalTime(i).QuadPart, " Total(", sFuncName(i), liTimerCallCount(i).QuadPart, j, flag )
liStart(i).Quadpart = 0
liTotalTime(i).QuadPart = 0
liTimerCallCount(i).QuadPart = 0
Return s
End Function
' ~~~~~~~~~~
Public Function sAverageTimeTaken( i As Long, j As Long, flag As Long ) As String
Dim s As String
Dim k As Long
If j >= 0 Then
k = Min(j,7)
SetDecimalPlaces$(k)
s = " " + Format( liTotalTime(i).QuadPart * IIf(k<4, 1000, 1000000)/(liFreq.QuadPart * liTimerCallCount(i).QuadPart), s) + IIf(k<4, "ms", "us")
Else
s = Str(liTotalTime(i).QuadPart*1000/(liFreq.QuadPart * liTimerCallCount(i).QuadPart)) + "ms"
End If
If flag = True Then
s = "[" + LTrim(Str(i)) + "] in " + sFuncName(i) + " Average(" + LTrim(Str(liTimerCallCount(i).QuadPart)) + "):" + s
End If
liStart(i).QuadPart = 0
liTotalTime(i).QuadPart = 0
liTimerCallCount(i).QuadPart = 0
Return s
End Function
' ~~~~~~~~~~
Public Function FormatOutput( ourTimer As Long, Scheme as ULongLong, sScheme As String, _
FuncName As String, Counter as ULonglong , j As Long, flag As Long ) As String
Dim k As Long
Dim s As String
If j >= 0 Then
k = Min( j, 7 )
SetDecimalPlaces( k )
s = " " + Format(Scheme * IIf(k<4, 1000, 1000000)/liFreq.QuadPart, s) + IIf(k<4, "ms", "us")
Else
s = Str(Scheme*1000/liFreq.QuadPart) + "ms"
End If
If flag = True Then
s = "[" + LTrim(Str(ourTimer)) + "] in " + FuncName + sScheme + LTrim(Str(Counter)) + "):" + s
End If
Return s
End Function
' ~~~~~~~~~~
Code: Select all
#Include Once "MacroTimersQPC.inc"
Declare Sub MyRoutine()
Declare Sub RandomTimes()
Randomize
Print sPerformanceCounterFrequency
StartTImer(0)
Sleep (500,1)
StopTimer(0)
Print sTimeTaken(0, 3, False)
StartTImer(0)
Sleep (100,1)
StopTimer(0)
Print sTimeTaken(0, -1, False) ' No formatting
MyRoutine
Print sTimeTaken(0, 2, True)
Print sTimeTaken(1, 2, True)
Dim i as Long
For i = 1 to 10
RandomTimes
Next
Print sTotalTimeTaken(0, 5, True)
'Print sFastestTimeTaken(0, 5, True)
'Print sSlowestTimeTaken(0, 5, True)
'Print sFastSlowTimeTaken(0, 5, True)
'Print sAverageTimeTaken(0, 3, True)
' ~~~~~~~~~~
Sub MyRoutine()
StartHiResClock
StartTimer(0)
Sleep (20,1)
StopTimer(0)
StartTimer(1)
Sleep (5,1)
StopTimer(1)
StopHiResClock
End Sub
' ~~~~~~~~~~
Sub RandomTimes()
Dim i As Long
Dim x As Single
StartTimer(0)
For i = 1 to Rnd*50000
x = Sin(0.3)
Next
StopTimer_UpdateTotalTime(0)
' StopTimer_UpdateFastestTime(0)
' StopTimer_UpdateSlowestTime(0)
' StopTimer_UpdateFastSlowTime(0)
' StopTimer_UpdateTotalTime(0)
End Sub
' ~~~~~~~~~~
Sleep