Alter
Alter

Reputation: 3464

High resolution timer/code run time -> overhead?

I'm trying to find my Code run time using a high resolution timer, I've noticed that the timer has inconsistent results and I would like to find out why this is.

I found this article How do you test running time of VBA code?
and have implemented the top answer, I tried using it to find the run time of several functions and noticed that the results changed fairly drastically.

To see if this was a fault of the timer, i made a function where I just started and stopped the timer.

Public Sub test_ctimer()
    Dim results(0 To 4) As Double
    Dim t As CTimer: Set t = New CTimer
    Dim i As Integer

    'Removes msg box overhead
    MsgBox "about to start"

    For i = 0 To 4
        t.StartCounter
        results(i) = t.TimeElapsed

    Next i

    For i = 0 To 4
        MsgBox results(i)
    Next i
End Sub

The first measurement takes significantly more time (~ 1 magnitude greater) than any of the following measurements. Does anyone know why this is?

Below is the ctimer code from How do you test running time of VBA code?

Option Explicit

Private Type LARGE_INTEGER
    lowpart As Long
    highpart As Long
End Type

Private Declare Function QueryPerformanceCounter Lib "kernel32" (lpPerformanceCount As LARGE_INTEGER) As Long
Private Declare Function QueryPerformanceFrequency Lib "kernel32" (lpFrequency As LARGE_INTEGER) As Long

Private m_CounterStart As LARGE_INTEGER
Private m_CounterEnd As LARGE_INTEGER
Private m_crFrequency As Double

Private Const TWO_32 = 4294967296# ' = 256# * 256# * 256# * 256#

Private Function LI2Double(LI As LARGE_INTEGER) As Double
Dim Low As Double
    Low = LI.lowpart
    If Low < 0 Then
        Low = Low + TWO_32
    End If
    LI2Double = LI.highpart * TWO_32 + Low
End Function

Private Sub Class_Initialize()
Dim PerfFrequency As LARGE_INTEGER
    QueryPerformanceFrequency PerfFrequency
    m_crFrequency = LI2Double(PerfFrequency)
End Sub

Public Sub StartCounter()
    QueryPerformanceCounter m_CounterStart
End Sub

Property Get TimeElapsed() As Double
Dim crStart As Double
Dim crStop As Double
    QueryPerformanceCounter m_CounterEnd
    crStart = LI2Double(m_CounterStart)
    crStop = LI2Double(m_CounterEnd)
    TimeElapsed = 1000# * (crStop - crStart) / m_crFrequency
End Property

Upvotes: 2

Views: 782

Answers (1)

Cor_Blimey
Cor_Blimey

Reputation: 3310

The linked class is not great. There is an overhead associated with calling QueryPerformanceCounter it and that overhead should be determined first then used to adjust the subsequent calls. This would explain all results being slightly slower than expected, however it does not explain the first one being substantially slower. Anyway, see http://support.microsoft.com/kb/172338 describes an approach to adjust for it. The class I have implemented I do not have access to at this time so I cannot post the relevant parts.

Also for a read unrelated to your specific issue, but related to Timings on Windows in general, http://msdn.microsoft.com/en-gb/library/windows/desktop/dn553408%28v=vs.85%29.aspx is interesting.

As a workaround in the meantime, add a call to start then stop in the Class_Initialize.

This is not really an answer at all - more of an extended comment - so I will edit it if I ever find a conclusive reason ;)

To reiterate to those upvoting: I cannot explain the reason for the results the OP is querying. I hypothesise it is to do with the VBA interpreter (i.e. close to a JIT'er) but I cannot evidence either way. My commentary above is related to the functions the OP is using but are probably non sequitur.

Upvotes: 1

Related Questions