QueryPerformanceCounter *less* accurate?

In order to get high res timing, I'm using the timing method Stuart C demonstrates in this thread :

http://www.blitzbasic.com/Community/posts.php?topic=46443#516927

But I'm finding it's about half as accurate as milliseconds. Instead of seeing 1/1000th of a second before I get a timer update, I get the same time returned over and over until 2 milliseconds have passed.

It's pretty reliably bang on 2 milliseconds every time. Is there something inherently wrong with the way he uses QueryPerformanceCounter in there?

I was just reading about this the other day. Perhaps it's due to having a dual core processor?

haven't had any problems with the performance timer here, but then I don't have dual core.

anyway, here's my time code if that helps (with example)...

Strict

Extern "win32"
	Function QueryPerformanceFrequency(LARGE_INTEGER:Long Var)
	Function QueryPerformanceCounter(LARGE_INTEGER:Long Var)
EndExtern

' ----------------------------------------------------------------------------------------------

Local Timer:TPerformanceTime = New TPerformanceTime
Timer.Start()
Delay 1000
Print Timer.Stop() ' should print 1 (or so)

Graphics 640,480,32,85
Repeat
	Cls
	DrawText(Timer.Time(),10,10)
	Flip
Until KeyDown(KEY_ESCAPE)

' ----------------------------------------------------------------------------------------------

Type TPerformanceTime

	Global Frequency:Long
	Field StartTime:Long
	Field StopTime:Long

	Method New()
		If Not Frequency Then QueryPerformanceFrequency(Frequency)
	EndMethod

	' returns the current system time
	Method Time:Double()
		Local Time:Long
		QueryPerformanceCounter(Time)
		Return Double(Time)/Frequency
	EndMethod

	' start the stopwatch
	Method Start()
		QueryPerformanceCounter(StartTime)
	EndMethod
	
	' will return the stopwatch result, can be called more than once!
	Method Stop:Double()
		QueryPerformanceCounter(StopTime)
		Return Double(StopTime-StartTime)/Frequency
	EndMethod

EndType

*EDIT* tried it with this code...

Local Timer:TPerformanceTime = New TPerformanceTime
For Local n=0 To 100
	Print Timer.Time()+"   - "+MilliSecs()
Next

and got a different result on each line...

15468.774916085704   - 15468464
15468.774987882538   - 15468464
15468.775005761905   - 15468464
15468.775095158742   - 15468464
15468.775113038109   - 15468464
15468.775130638112   - 15468464
15468.775147120654   - 15468464
15468.775163323829   - 15468464
15468.775179527007   - 15468464
15468.775196009548   - 15468464
15468.775212492090   - 15468464
15468.775228415901   - 15468464
15468.775244898443   - 15468464
15468.775261101620   - 15468464
15468.775277584162   - 15468464
15468.775293787339   - 15468464
15468.775309990515   - 15468464
15468.775326473058   - 15468464
15468.775342955600   - 15468464
15468.775359158775   - 15468464
15468.775375361953   - 15468464
15468.775391844494   - 15468464
15468.775408327036   - 15468464
15468.775426485769   - 15468464
15468.775442968310   - 15468464
15468.775459171487   - 15468464
15468.775475374663   - 15468464
15468.775491577841   - 15468464
15468.775507501652   - 15468464
15468.775523704828   - 15468464
15468.775539628639   - 15468464
15468.775555831817   - 15468464
15468.775572314358   - 15468464
15468.775588238170   - 15468464
15468.775604161981   - 15468464
15468.775620365159   - 15468464
15468.775636568334   - 15468464
15468.775652212782   - 15468464
15468.775668695323   - 15468464
15468.775800835023   - 15468465
15468.775819831850   - 15468465
15468.775836593757   - 15468465
15468.775853076299   - 15468465
15468.775869558840   - 15468465
15468.775888555669   - 15468465
15468.775905038210   - 15468465
15468.775921520752   - 15468465
15468.775938282659   - 15468465
15468.775954485836   - 15468465
15468.775970968378   - 15468465
15468.775987450919   - 15468465
15468.776003654095   - 15468465
15468.776019577906   - 15468465
15468.776036060450   - 15468465
15468.776052263625   - 15468465
15468.776068466803   - 15468465
15468.776084669978   - 15468465
15468.776100873156   - 15468465
15468.776117076332   - 15468465
15468.776134117605   - 15468465
15468.776150320780   - 15468465
15468.776166523958   - 15468465
15468.776182727135   - 15468465
15468.776199209677   - 15468465
15468.776215412852   - 15468465
15468.776233571585   - 15468465
15468.776249774763   - 15468465
15468.776265698574   - 15468465
15468.776281901750   - 15468465
15468.776298104927   - 15468465
15468.776314308103   - 15468465
15468.776330231914   - 15468465
15468.776346714456   - 15468465
15468.776363196999   - 15468465
15468.776379400175   - 15468465
15468.776395603352   - 15468465
15468.776412085894   - 15468465
15468.776428289069   - 15468465
15468.776444771613   - 15468465
15468.776460974788   - 15468465
15468.776477736696   - 15468465
15468.776493939873   - 15468465
15468.776510701779   - 15468465
15468.776527184322   - 15468465
15468.776543387497   - 15468465
15468.776559870039   - 15468465
15468.776575793850   - 15468465
15468.776594790679   - 15468465
15468.776610714491   - 15468465
15468.776627197032   - 15468465
15468.776643679574   - 15468465
15468.776665190688   - 15468466
15468.776681952595   - 15468466
15468.776698155771   - 15468466
15468.776714358948   - 15468466
15468.776730841490   - 15468466
15468.776747044667   - 15468466
15468.776763247843   - 15468466
15468.776779730384   - 15468466
15468.776795933562   - 15468466
15468.776812136739   - 15468466

so seems to work ok here

Thanks Redi, I get a different result on each line too, so it must be something inherent within Stuart's code and not within yours. I'll have a fiddle and see if I can spot the differences. The one thing which stands out immediately is that he divides the frequency by 1000 to return values in milliseconds instead of nanoseconds. Perhaps it would be wiser to do that when returning the timer. I'll try that first.

My code returns the time in seconds, to change it to milliseconds you'll just need to multiply it by 1000, but whats the point? ;)

I cant see any reason for dividing the frequency by 1000, as frequency is the number of ticks per second, could be wrong tho :)

I'm guessing his assumption was that he could avoid the multiplication by 1000 to convert to milliseconds if he divided the frequency by 1000. When you divide the counter by the frequency, you're implicitly multiplying by 1000 because the frequency is already 1/1000th of what it would be.

At first I thought this might have been the cause of the problem, but it's not. Your code too returns the same time frame after frame if I plug it into my game. So evidently there is something in my game that the timers just don't like. Bugger.

:( Good luck mate!

In case your system has speedstep / AMD64 of newer generations, then most likely a loop that raises CPU usage from 30 - 80 might be a reason, as the stepping is changing that drastically that aboves value gets totally useless.

Do a high speed loop (1000000 steps and measuring in that time) at the beginning and use that to calculate the steps but do not use anything more precise than ms on intelligent CPUs in realtime ... that just won't work without strange and (for us notebook users) annoying glitches ... Its no fun if we get annoyed by "please disable speedstep to run this blabla" as some games do ^^

I don't have a system with speedstep, so that's not it. A millisecs resolution timer is not really sufficient for very smooth game timing.

Hmm.. this is strange. The time between updates on the timer is always 0.0039062500000000000 ( which I think is 1/256. ) Just thought I'd post that in case it means anything to anyone. Seems like such a precise value might be a clue to the issue, since it doesn't happen if I just run Redi's example above.

EDIT: And Millisecs() is returning values with the same step. What the heck is causing this? ;/

Ok, here's my debuglog, where it shows that the division is the problem. The value returned by QueryPerformanceCounter() is changing but the result of the division remains the same frame after frame.

DebugLog:155440113948855/3000460000=51805.429687500000
DebugLog:155440114599592/3000460000=51805.429687500000
DebugLog:155440115241945/3000460000=51805.429687500000
DebugLog:155440115880840/3000460000=51805.429687500000
DebugLog:155440116515760/3000460000=51805.429687500000
DebugLog:155440117174807/3000460000=51805.429687500000
DebugLog:155440117826407/3000460000=51805.429687500000
DebugLog:155440118557050/3000460000=51805.429687500000
DebugLog:155440119350047/3000460000=51805.429687500000
DebugLog:155440120107652/3000460000=51805.429687500000
DebugLog:155440120871160/3000460000=51805.429687500000
DebugLog:155440121631645/3000460000=51805.429687500000
DebugLog:155440122398310/3000460000=51805.429687500000
DebugLog:155440123184812/3000460000=51805.429687500000
DebugLog:155440123942830/3000460000=51805.429687500000

I'm none too clear why BMax is returning inaccurate results here, nor how to fix it. Doesn't make any sense. I'm using Return Double(Time)/Frequency, just as Redi does.

Those values have been coverted to single precision and back to double, losing many digits of accuracy.

You probably have an incorrect return type for a function or method, or perhaps temporarily stored the value in a float variable.

Ok, thanks. I've been staring at the code for best part of a day, and I can't see where I'm implicitly converting to a float. There definitely aren't any variables declared as floats, so it must be an implicit conversion I'm missing. I think the best solution at this point will be to just rip out all the timing code and start over. If nothing else, it'll be a lot more readable, if I have to post it.

Any chance to see the code for above division.
Just to make sure there is not some kind of type problem (not defined variables are 32bit accuracy and you most likely would need to cast to double anything before division, BM has no long math when I'm not totally wrong. just "int" float double)

If you have a full test routine etc which saves you data I could do a test for you on core duo T2500 with dynamic stepping to show you how accurate the data are on current CPUs and what kind of impact it would give. (from experience: more precise than ms can be nice but can give worse results. Thats my experience from Torque whichs collision and physics can miss events on dynamic stepping systems if the cpu frequency dynamically changes by a factor of 2 - 3 which is normal on P-M / Core Duo T