Just how accruate is Millisecs() anyway?

Hmm, I wrote a fat alpha routine and tested it debug mode and got 108ms, then in non debug it gives 13ms. Fine. So I optimise it and in debug it gives 30 but STILL GIVES 13 in non-debug, hunh! Then I optimise some more and squeeze it down to 23ms in debug but is STILL GIVES 13 in non-debug. Either a) the opimisations I made only affect debug mode, weird or b) Millisecs is not so good sometimes.

Anyone shed any light?

In fact a while a go I asked if there was a more accurate timer (small increments) than Millisecs but was told, no, just loop the proc several times to get a bigger figure and average it.

some code maybe. I thought it based on the internal clock.

you maybe need to give it a break before you start measuring because right after the start of the exe windows still has to do some parallel threads / memorymanagement etc.

try Delay 1000

t1=millisecs()
...

Maybe you also need to do the optimized function multiple times to be able to measure it accurately.

Debug mode takes longer, thats why you DO NOT create executables in debug mode. It also does give wierd values from time to time. But the non-debug mode is obviously a WYSIWYG.

13 huh? i guess non-debug mode is unlucky in your case. :)

MilliSecs() is accurate to 1/1000th of a second ;]

I know debug mode is slower and that's why I don't make final releases with it. What I'm getting at is that consistant optimisation reduced the time taked by a function in debug mode by 4 times, yet in non debug mode the time always remained at 13. Maybe something other than the function was limiting the time such as accessing video ram or something.

13ms and the lack of change sounds suspiciously like you are actually measuring your screen refresh rate. Would that be 75Hz ?

1000 / 75 gives 13.3333 etc which means a measurement of 13 or occasionally 14.

If the measurement loop includes Flip then you could optimise the operation to nothing and the measurement would still be 13ms at 75Hz.

In Debug mode, the code is taking longer than one cycle so gets pushed to the next multiple. For 40ms this could be more than say 2 screen updates and so gives you 3 * 13.3 = 40ms. For the original at 108ms, 8 * 13.3333 gives 106. Not a perfect match but not too far away.

Just a guess.

Good theory PGF, I am running at 75Hz BUT the start and end times are around a single function that doesn't call flip. The time was fluctuating between 12 and 13 ms, this is in fullscreen mode. In windowed mode (with debug off) it only takes 2-3ms. This must mean that it is some kind of video buffer delay. I also noticed that the main game screen exhibits exactly the same thing i.e. full screen = 12-13ms, windowed mode a mere 0-1ms. My full screen is 800x600 32 colour on a Radeon 9800XT and windowed mode is the same size window on 32-bit desktop of 1024x768, so maybe the Radeon (or blitz) is faster at writing to a window than to full screen graphics, naff.

Whats worrying is that 13ms is close to 75fps so if a little bit of game logic pushes it up to 14ms, frames will be dropped which frankly stinks.

OK found out something SHOCKING. This function takes 12-13 ms

Function test()
	LockBuffer BackBuffer()
	UnlockBuffer BackBuffer()
End Function

So according to PGF's calcs, BlitzPlus (or the video card) must wait until the next refresh before performing the lock (or unlock). This stinks, because the whole reason of using LockBuffer is so you can use WritePixelFast to make mega optimised graphics routines, but if the minimum overhead is 13ms you might as well forget it!

Note that this code

SetBuffer ImageBuffer(CopyrightImage)
LockBuffer ImageBuffer(CopyrightImage)
UnlockBuffer ImageBuffer(CopyrightImage)
SetBuffer BackBuffer()

takes 0ms as expected!

Did some testing of a different nature in my game screen which runs at 13ms to draw (without a flip command) and found that if I cut out the drawing functions one by one, the time remains at 13ms and then suddenly drops to 1ms. It doesn't really matter what function I cut out! Seems that to draw to the buffer takes no time at all until you hit some kind of critical limit and then BAM it no takes 13ms! In windowed mode the time starts at 1ms and drops to 0ms. This is weird. Is it some kind of VRAM buffer thing? I don't know enough about the technical gubbins of video cards to understand why this is happening.

Can anyone shed anylight into this or the BackBuffer problem?

I get high millisecs per frame sometimes when using "Flip True". Changing to "VWait : Flip False" seems to be more accurate, for some reason.

sure, but I'm meauring stuff without any flip command. My games support both flip modes via an ini flag because flip false works better on systems than others.

It varies depending upon the operating system, and I should imagine, the hardware. Under Windows MilliSecs() is accurate to around 10ms, under Linux slightly more. I'm not sure about Macs.

how do you know that?
If you notice my other posts, they also discuss the fact that my problem was actually not down to MS but down to graphics card or something else anoying.

Even if the function being measured does not perform a Flip, the fact that it is performing drawing or buffer locking means that you are quite probably synced to the refresh rate.

I struck this once while profiling some code. It is not the Flip command that sees the delay but some later graphics operation. I put it down to something internal to the card or driver.

Quite possibly the card can be told to swap the buffers at the next screen interval and reports that this has been performed immediately. Then you want to draw to the other buffer which is still actually being displayed. It blocks you until the flip occurs and the old front buffer is free to use.

And in Window mode the Flip is actually a copy of your buffer to the Windows buffer (which it will display when good and ready).

Simple test - Change your refresh rate to say 60Hz but keep the same resolution and depth. See if the magic time changes to 16/17ms. Change the refresh rate to 100Hz (or whatever your highest is) and see if the time changes accordingly.

This is speculation but I have observed that the screen sync delay does not happen in the Flip command itself but in a later drawing command.

Using the screen buffer is slow. I'm sure sswift did test to show that. Best to copy the screen contents to a texture, then working on them. I think it's actually quickier, depending on the amount of work you need to do to it. Try using the 256 flag with the texture if your working on it.

Also, have you tried running that code in fullscreen mode? with flip false?

Grey - locking and unlocking the backbuffer in fullscreen mode doesn't take 12ms on my machine, it took 0ms. DX 9.a, Win98, Radeon 9200se.

So it must be a video card thing then. In the end I remade the routine so that it wrote to an image then I called DrawImage instead of using lockbuffer backbuffer() this dropped the time to 0-1 ms.

I think PGFs speculation could be corect but obviously it varies depending on video card. I'll try the refresh rate test later AND I'll time how long flip and flip false take to see if they are 0ms which would point at the actuall vwait happening elsewhere!

Then there's the point I made about the time suddenly going up to 13ms after a certain number of draw commands, it doesn't matter what they are.

Grey - in that example you posted, note: Functions require the overhead and use up that time. Try the same code with GOSUBs instead.

+BlackD

BlackD: You mean the test function in this thread? Yeah, thanks for the gosub info but no way calling that little function above takes 13m, it's the LockBuffer BackBuffer causing the delay.

OK, based on PGF's idea and some testing I have the answer ...

When you call LockBuffer BackBuffer() and UnlockBuffer BackBuffer and later on use a Flip command, the Lock/Unlock waits for VSync thus takes 13ms in 75Hz and 17ms in 60Hz and 12ms in 85Hz and the Flip takes 0ms!

If however, you use VWait and Flip False, the Lock/Unlock drops to 0ms and the VWait/Flip False takes 13ms as expected! This is how I thought it would work when using plain Flip but it seems it's not the case. It also explains why in the past I was getting some weird debug times displayed on one of my other games.

Luckily my games support both Flip and VWait/Flip False via an .ini setting. A while ago I read you should always use the VWait/Flip Flase method anyway and did for ages on my PC fine, but noticed that it wasn't that reliable on some other PCs which is why I think the option is important. It's just a shame it's not the same on all PCs, like Amigas!

Thanks to all for the help, hope you've learnt something too. And to answer my original questions, it seems that Millisecs IS very reliable, but knowing when Vsync occurs is not!

All this time, I had no idea. For those that don't believe me...

For i=0 to 1000
  debuglog millisecs()
next
debugstop

Maybe the debugger is interfering with the loop, I don't know, but some times there's a difference a 1 between the values, sometimes there's a difference of 10 and a lot fo the time there's a difference of 100. I sure hope it is the debugger interfering because... that's rediculously inaccurate.

I seem to get pretty good results with Millisecs for example I store the max millisecs of logic and drawing in my game and it never peaks to 10 or 100ms ever! so it must be the debug log and windows OS interfereing or something.

When I looked at this before (when I was converting my timing code with the BMX demo) I got quite different results from both B3D and BMX.

B3D gave a pretty smooth ramp of Millisecs, which was good :-)

BMX however gave some pretty weird results, in the debuglog I'd get a few dozen iterations at one value (say 10012345) then a few dozen at the next value (say 10012346) - that I could understand (BMX was just being very fast). But then interspersed there'd be jumps of things like 30 and 90, which was more worrying.

At the time I found that pretty weird, but as I was just trying the BMX demo and my game is in B3D I wasn't too worried :-)

Like I said, it's more likely to be windows than millisecs. What you should really do is write the millisec values into memory and after a few seconds of save that in a file, then you eliminate the OS as an interfering factor.