Announcement

**Michael Mattias** · 25 Aug 2008, 08:08 AM

If you really want to get some indication of how long SLEEP or any other function takes to execute, you might just want to put it in its own procedure and enable PROFILE. That will tell you how many times and much total time your program spent in that procedure.

PROFILE is a terrific tool for optimization in that it tells you where your program is spending most of its time.... that is, where a little extra effort can actually deliver some benefit.

The caution here is, PROFILE itself requires some overhead, so what it tells you is the relative times each procedure of your program is taking.. not the absolute time when the program is run in production ("#TOOLS OFF") mode.

But as I said in the other forum, SLEEP() is not designed to be used as a timer, so the information you would gather from using PROFILE or any other tool in this exercise is meaningless.

MCM

**David Roberts** · 25 Aug 2008, 08:25 AM

> I'm looking at something else which seems to cast doubt on my using the frequency of the high resolution timer but I cannot quite get my head around the results yet.

Forget that - the method used is suspect.

Have a look at this:

Code:

#Compile  Exe
#Register None
#Dim      All
#TOOLS    OFF

%NOMMIDS = 1
%NOGDI = 1

#Include "WIN32API.INC"

'~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Global qFreq, qOverhead, qStart, qStop As Quad
Global f As String

Macro InitializeTimer
  f = "#####.##"
  QueryPerformanceFrequency qFreq 
  QueryPerformanceCounter qStart ' Intel suggestion. First use may be suspect 
  QueryPerformanceCounter qStart ' So, wack it twice <smile>
  QueryPerformanceCounter qStop
  qOverhead = qStop - qStart     ' Relatively small 
End Macro

Macro StartTimer = QueryPerformanceCounter qStart
Macro StopTimer = QueryPerformanceCounter qStop

Macro sTimeTaken = Using$(f,(qStop - qStart - qOverhead)*1000/qFreq) + "ms"
'~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

Function PBMain() As Long

  Local time1, time As Quad, hProcess As Dword, t As Dword Ptr
  
  InitializeTimer
  
  ' If you have single core remove the next two lines
  hProcess = GetCurrentProcess()
  SetProcessAffinityMask( hProcess, 1) ' ie CPU 0
  
  ' Time Stamp
  t = VarPtr(time)
  !dw &h310f
  !mov esi, t
  !mov [esi], eax
  !mov [esi+4],edx
  time1 = time
  
  Sleep 100000
  
  !dw &h310f
  !mov esi, t
  !mov [esi], eax
  !mov [esi+4],edx
  
  Print time - time1
  
  ' TIX
  TIX time
    Sleep 100000
  TIX End time
  
  Print time
  
  ' Performnce counters
  StartTimer
    Sleep 100000
  StopTimer
  
  Print qStop - qStart
    
  Waitkey$

End Function

I get:

266660772380
266664907340
266664675970

If we have a time of a few hundred milliseconds then using 'QueryPerformanceFrequency qFreq' instead of one of the above will 'throw' our timing out by a few hundredths of a millisecond. I won't be losing much Sleep over that.

**Paul Dixon** · 25 Aug 2008, 11:36 AM

David,
with PBCC5 you can use !RDTSC to read the time stamp counter instead of !DW &H310f. Much nicer!
TIX just reads the time stamp counter anyway and stores it in the specified QUAD so you no longer need the read it and store it explicitly in ASM, just use TIX/TIX END instead.

I don't like

CPUfreq = TSC/((cnt2-cnt1)/freq) ...... (1)

I wrote it that way because it's clearer.
Maybe I should have been more explicit and said:

Code:

TimeTaken=(cnt2-cnt1)/freq
CPUFreq=TSC/TimeTaken.

Paul.

**David Roberts** · 25 Aug 2008, 12:53 PM

Paul

!RDTSC - very posh!

I've rewritten the above - that 'time1 = time' was badly placed.

Added cpuid and threw in an #optimize speed.

Code:

Function PBMain() As Long

  Local time1, time2, time As Quad, hProcess As Dword, t1, t2 As Dword Ptr
  
  InitializeTimer
  
  ' If you have single core remove the next two lines
  hProcess = GetCurrentProcess()
  SetProcessAffinityMask( hProcess, 1) ' ie CPU 0
  
  ' Time Stamp
  t1 = VarPtr(time1)
  t2 = VarPtr(time2)

  !cpuid
  !RDTSC
  !mov esi, t1
  !mov [esi], eax
  !mov [esi+4], edx
    
  Sleep 100000
  
  !cpuid
  !RDTSC
  !mov esi, t2
  !mov [esi], eax
  !mov [esi+4],edx
  
  Print time2 - time1
  
  ' TIX
  TIX Time
    Sleep 100000
  TIX End time
  
  Print time
  
  ' Performnce counters
  StartTimer
    Sleep 100000
  StopTimer
  
  Print qStop - qStart
    
  Waitkey$

End Function

I now get:

266684375520
266664862270
266664661980

That Time Stamp figure is edging toward the figure got from 'QueryPerformanceFrequency qFreq' at 266688000000 for a 'perfect' Sleep 100000.

Added: The last two figures are pushing seven significant figure coincidence. I reckon that TIX is not reading the Time Stamp but is using the Performance counters.

**Paul Dixon** · 25 Aug 2008, 01:36 PM

David,
TIX definitely uses the time stamp counter.
TIX QuadVal reads the time stamp counter into QuadVal giving the number of CPU ticks since the CPU was last reset.
TIX END QuadVal reads the timestamp counter, subracts QuadVal and puts the result back into QuadVal so giving the elapsed number of CPU ticks.

Paul.
Edit: most clocks in the computer apart from the Real Time Clock are derived from the same crystal so it wouldn't be surprising if you eliminated all the errors and found that TIX and Performance counters kept step with each other.

**David Roberts** · 27 Aug 2008, 12:00 PM

Thanks Paul.

> ... so it wouldn't be surprising if you eliminated all the errors and found that TIX and Performance counters kept step with each other.

It seems to be so with my system.

The following code takes a stab at getting the frequency of the Time Stamp Counter. It simply takes a snapshot of the Time Stamp Counter, runs with the Performance Counter for 10 seconds and then takes another snapshot of the Time Stamp Counter. Other code that I have seen uses a one second interval. Completion is determined when a target counter is passed and there may be a small 'overshoot'. With a 10 second span divided by 10 this 'overshoot' will be reduced by a factor of 10. 24 tests are carried out, with a pause of one and two seconds between tests, and the two largest and the two smallest are discarded. The code will, then take between four and five minutes to run.

With one trial I got a TSC frequency of 2666870024 compared with a PC frequency of 2666870000. I had rebooted since my earlier posts which had a PC frequency of 2666880000.

Here's a couple more, after reboots, 2666899823/2666900000 and 2666939894/2666940000.

On my system, then I can use the Performance Counter frequency to convert TIX returns to time as in the Source Code forum. This is recommended if timing code is to be used in different Window's sessions as we may get different tick counts.

In view of your comments it may be worthwhile for folks to run the following before accepting my 'PBWin9 & PBCC5 version' of my timer macros.

Added:
> TIX definitely uses the time stamp counter.
I, how can I put it, had a close 'look' and indeed it does.

Code:

' PBCC 5
#Compile  Exe
#Optimize speed
#Register None
#Dim      All
#Tools    Off

%NOMMIDS = 1
%NOGDI = 1

#Include "WIN32API.INC"

Function PBMain() As Long
Local qPerfFreq, qTSFreq, qTargetPerfCtr, qCurrentPerfCtr, qTSCbegin, qTSCend, Tot As Quad
Local i As Long
Dim x(1 To 24) As Quad

' If you have a single core remove the next three lines
Local hProcess As Dword
  hProcess = GetCurrentProcess()
  SetProcessAffinityMask( hProcess, 1) ' ie CPU 0
  
  QueryPerformanceFrequency qPerfFreq
  
  For i = 1 To 24 ' We will only use 20
  
    QueryPerformanceCounter qTargetPerfCtr
    ' Determine Performance Counter in 10 seconds time
    qTargetPerfCtr = qTargetPerfCtr + qPerfFreq*10
    
    ' Take a snapshot of Time Stamp Counter
    !RDTSC
    !lea esi, qTSCbegin
    !mov [esi], eax
    !mov [esi+4], edx
    
    Do
      QueryPerformanceCounter qCurrentPerfCtr
    Loop While qCurrentPerfCtr < qTargetPerfCtr ' We pull out then when qCurrentPerfCtr >= qTargetPerfCtr
      
    ' Take another snapshot at, or earliest after, qTargetPerfCtr
    !RDTSC
    !lea esi, qTSCend
    !mov [esi], eax
    !mov [esi+4], edx
    
    x(i) = (qTSCend - qTSCbegin)\10 ' Our 10 seconds again
    
    Sleep Rnd(1000,2000) ' Avoid looping 'back to back'
        
  Next
  
  Array Sort x()
  
  For i = 3 To 22 ' Throw out the two largest and the two smallest
    Tot = Tot + x(i)
  Next
  
  qTSFreq = Tot/20
  
  Print "Time Stamp Counters per second ";qTSFreq
  Print "Performance Counters per second";qPerfFreq
  Print "Difference"; Abs(qTSFreq - qPerfFreq)
  
  Waitkey$

End Function

**Paul Dixon** · 28 Aug 2008, 07:07 AM

David,
The Performance Counters generally run at 3.579545MHz (or sometimes half that, 1.789772.5MHz) which is derived from the original timers of the PC from years ago. The cheapest clock crystal around was the NTSC colour burst frequency crystal so to save a few pennies that was used in the PC.

Your code precalculates the result of the performance counter because you use:

Code:

qTargetPerfCtr = qTargetPerfCtr + qPerfFreq*10

You aren't checking the performance counter at all, you're just fixing the end of the timing interval to coincide with exactly the expected result. It's like using a stop watch to time itself. If the watch runs at twice normal speed it'll still time 1 second = 1 second even though in the real world only 0.5 seconds passed.
You could use the performance counter as a base for timing the CPU but if they're both derived from the same crystal then that doesn't give a very useful result either although it could tell you the multiplier used inside the PC.
Your measurements come out around 2.6669GHz for the CPU. 2666900000 / 3579545 = 745.03 so it's likely that your internal multiplier is 745 and that your CPU is really running at 745*3.579545MHz = 2.666761GHz.

In order to determine real frequency you'll need a known independent clock. The only one in the PC is the real time clock which has its own crystal.

Paul.

**David Roberts** · 28 Aug 2008, 08:52 AM

Hi Paul

For me, what the crystal oscillates at and what multiplier is used is academic. The system tells me what the Performance Counter frequency is from QueryPerformanceFrequency.

All I'm doing is to take a snapshot of the Time Stamp Counter, let the Performance Counter run for 10 seconds, according to the frequency, and then take another snapshot of the Time Stamp Counter. All the tests that I have done show that the Performance Counter and the Time Stamp Counter are 'ticking' over at the same rate; or differ by an insignificant amount for the purposes of comparing code snippets.

> but if they're both derived from the same crystal then that doesn't give a very useful result

Well, actually it does.

The issue in the Source Code forum is can I use TIX and the frequency of the Performance Counter in the same breath, so to speak.

Well, I cannot find any evidence to suggest that I should not use

Code:

Tix qTimer
  For i = 1 To 10000000
    t = Rnd
  Next
Tix End qTimer
sTimeTaken = Using$("#####.##",qTimer*1000/qFreq) + "ms"

where qFreq is got from QueryPerformanceFrequency qFreq.

I found an interesting discussion here and downloaded CpuClockSpeed.zip. The Preformance Counter is used here as well.

This gave 2666.91Mhz. My Performance Counter frequency for this Window's session is 2666910000.

If the code two posts back gives widely differing frequencies then the Performance Counter frequency should not be used in the snippet above as we may not get accurate millisecond results; we would have to determine a multiplier.

For comparing code it depends how we make the comparison. If we are concerned about overhead then it will be eliminated by subtracting results. If we are concerned about the ticks to time conversion this will be eliminated on division since '1000/qFreq' will be in both the numerator and denominator.

I think that our discussion has drifted somewhat - getting an accurate figure for the CPU speed has not being my concern - the relationship between the two Counters is what I've been concerned about.

David,
that won't work. TIX is counting CPU clock cycles, QueryPerformanceFrequency is getting the frequency of the high speed timer which is a different timer running a lot slower than the CPU.

That is what I've been concerned about.

the CPU and the high performance counters have the same base crystal.

from the other discussion mentioned and written by yourself a few posts back.

**Arthur Gomide** · 6 Mar 2011, 02:39 PM

Originally posted by Paul Dixon View Post

In order to determine real frequency you'll need a known independent clock. The only one in the PC is the real time clock which has its own crystal.

Paul,

I think this clock is running at about 32767 hertz, or I'm wrong?

**Paul Dixon** · 6 Mar 2011, 03:01 PM

Arthur,
the real time clock could be run from any frequency of crystal but 32,768Hz is the most common because it's cheap, low frequency (and therefore low power) and divides easily to give seconds.

Paul.

Announcement

Discussion of 'Timer Macros' in Source Code forum

Discussion of 'Timer Macros' in Source Code forum

Comment

Comment

Comment

Comment

Comment

Comment

Comment

Comment

Comment

Comment