GetTickCount granularity & synchronisation

[jj2007]

Inspired by MichaelW's post on how to reduce GetTickCount granularity by half, I have made some tests.

Code Select Expand

203      expected: 200, abs(diff)=3
203      expected: 190, abs(diff)=13
188      expected: 180, abs(diff)=8
172      expected: 170, abs(diff)=2
172      expected: 160, abs(diff)=12
157      expected: 150, abs(diff)=7
141      expected: 140, abs(diff)=1
140      expected: 130, abs(diff)=10
125      expected: 120, abs(diff)=5
125      expected: 110, abs(diff)=15
109      expected: 100, abs(diff)=9
94       expected: 90, abs(diff)=4
94       expected: 80, abs(diff)=14
78       expected: 70, abs(diff)=8
62       expected: 60, abs(diff)=2
62       expected: 50, abs(diff)=12
47       expected: 40, abs(diff)=7
32       expected: 30, abs(diff)=2
31       expected: 20, abs(diff)=11
16       expected: 10, abs(diff)=6
Overall difference: 151

The problem is that there is absolutely no difference between using and not using initial sync. This is what I use:

  invoke GetTickCount
      if sync
      push eax
      .Repeat
         invoke GetTickCount
         inc gtcloops
      .Until eax!=[esp]
      pop edx      ; don't trash eax
      endif

gtcloops is over 50 Mio with sync = 1, but it doesn't change anything. Where am I wrong...?
::)

[japheth]

The results of Win32 API GetSystemTimeAdjustments() suggest that timer interrupt interval is 15 ms, not 10 ms.

This is my test prog:

Code Select Expand


;--- test GetSystemTimeAdjustment()

.386
.model flat, stdcall
option casemap:none

WIN32_LEAN_AND_MEAN equ 1
.nolist
.nocref
include windows.inc
include macros.inc
include stdio.inc
.cref
.list

.code

main proc c

local dw1:dword
local dw2:dword
local dw3:dword

invoke GetSystemTimeAdjustment, addr dw1, addr dw2, addr dw3
.if ( eax )
mov eax, dw1
xor edx, edx
mov ecx, 10000 ;100ns -> ms
div ecx
invoke printf, CStr(<"GetSystemTimeAdjustment(): size adjustment=%u 100ns [%u ms]",10>), dw1, eax
mov eax, dw2
xor edx, edx
mov ecx, 10000 ;100ns -> ms
div ecx
invoke printf, CStr(<"GetSystemTimeAdjustment(): increment=%u 100ns [%u ms]",10>), dw2, eax
invoke printf, CStr(<"GetSystemTimeAdjustment(): periodic time adjustment disabled=%u",10>), dw3
.else
invoke GetLastError
invoke printf, CStr(<"GetSystemTimeAdjustment() failed [%X]",10>), eax
.endif
ret

main endp

end


and this is the program's display

Code Select Expand


GetSystemTimeAdjustment(): size adjustment=156250 100ns [15 ms]
GetSystemTimeAdjustment(): increment=156250 100ns [15 ms]
GetSystemTimeAdjustment(): periodic time adjustment disabled=1


[hutch--]

JJ,

15 ms granularity matches my timings over the years. Its a very ordinary technique but in ring3 nothing appears to be much better. Just run the test long enough and the error margin drops down under 1%.

[jj2007]

This is not the point, folks. Michael had suggested that you can cut granularity by half simply by waiting, in a loop before start, until the value of GetTickCount advances. My code should do that but I can't get any improvement...

[MichaelW]

Timing the tick count update period against the high-resolution performance counter I get a period close to 10ms, and this has been so for every system that I have tested using this basic method. I seem to recall seeing Microsoft documentation somewhere that specifically stated that the period was 10ms, but this may have applied only to the NT-based versions.

Code Select Expand


;==============================================================================
    include \masm32\include\masm32rt.inc
;==============================================================================

timer MACRO
    .IF timer_initialized == 0
        invoke QueryPerformanceFrequency, ADDR timer_pc_frequency
        inc timer_initialized
    .ENDIF
    invoke QueryPerformanceCounter, ADDR timer_pc_count
    fild timer_pc_count
    fild timer_pc_frequency
    fdiv
    fstp timer_elapsed_seconds
    EXITM <timer_elapsed_seconds>
ENDM

;==============================================================================
    .data

        timer_pc_frequency    dq 0
        timer_pc_count        dq 0
        timer_elapsed_seconds dq 0
        timer_initialized     dd 0

        times   dq 50 dup(0)

    .code
;==============================================================================
start:
;==============================================================================

    invoke Sleep, 3000

    ;---------------------------------------------------------------
    ; Verify that the timer resolution is in the microsecond range.
    ;---------------------------------------------------------------

    N=0
    REPEAT 50
        fld timer()
        fstp times+N*8
        N=N+1
    ENDM
    N=0
    REPEAT 50
        invoke crt_printf, cfm$("%f\n"), times+N*8
        N=N+1
    ENDM

    invoke Sleep, 1000

    ;----------------------------------------------------
    ; Sample the effective resolution of the tick count.
    ;----------------------------------------------------

    N=0
    REPEAT 50
        fld timer()
        invoke GetTickCount
        push eax
        .WHILE eax == [esp]
            invoke GetTickCount
        .ENDW
        pop eax
        fld timer()
        fsubr
        fstp times+N*8
        N=N+1
    ENDM
    N=0
    REPEAT 50
        invoke crt_printf, cfm$("%f\n"), times+N*8
        N=N+1
    ENDM

    inkey "Press any key to exit..."
    exit

;==============================================================================
end start


Code Select Expand


53848.210525
53848.210530
53848.210532
53848.210534
53848.210536
53848.210538
53848.210540
53848.210542
53848.210544
53848.210546
53848.210548
53848.210549
53848.210551
53848.210553
53848.210555
53848.210557
53848.210559
53848.210561
53848.210563
53848.210565
53848.210567
53848.210569
53848.210571
53848.210573
53848.210575
53848.210577
53848.210579
53848.210581
53848.210583
53848.210585
53848.210587
53848.210589
53848.210591
53848.210592
53848.210594
53848.210597
53848.210599
53848.210601
53848.210602
53848.210605
53848.210606
53848.210608
53848.210611
53848.210613
53848.210614
53848.210616
53848.210618
53848.210620
53848.210622
53848.210624
0.009993
0.010016
0.010010
0.010009
0.010156
0.009949
0.010124
0.009896
0.009943
0.010004
0.010107
0.012297
0.007721
0.009997
0.010019
0.010076
0.011600
0.008369
0.009993
0.010018
0.010018
0.010116
0.009999
0.009931
0.010003
0.010026
0.010150
0.009866
0.010006
0.010048
0.009979
0.010048
0.009979
0.010004
0.010000
0.012231
0.007960
0.009853
0.010017
0.009999
0.010164
0.009945
0.009935
0.010064
0.009963
0.010000
0.010193
0.009848
0.010009
0.010059


[japheth]

This is not the point, folks. Michael had suggested that you can cut granularity by half simply by waiting, in a loop before start, until the value of GetTickCount advances. My code should do that but I can't get any improvement...

I guess you're right, JJ, but I'm interested only in this little side aspect of your scientific research. Sorry!

[MichaelW]

My statement about the uncertainty is based on simple logic. For an isolated call to GetTickCount you have no way of knowing where in its cycle the timer is. At the extremes you could be calling it just after the update or just before.

[jj2007]

My statement about the uncertainty is based on simple logic. For an isolated call to GetTickCount you have no way of knowing where in its cycle the timer is. At the extremes you could be calling it just after the update or just before.

Michael,
Your logic regarding advantages of synchronising seems correct to me. That's why I tested it. What I don't understand is why there is no improvement...

[BasilYercin]

and this one ?

200      expected: 200, abs(diff)=0
191      expected: 190, abs(diff)=1
180      expected: 180, abs(diff)=0
171      expected: 170, abs(diff)=1
160      expected: 160, abs(diff)=0
151      expected: 150, abs(diff)=1
140      expected: 140, abs(diff)=0
131      expected: 130, abs(diff)=1
120      expected: 120, abs(diff)=0
111      expected: 110, abs(diff)=1
101      expected: 100, abs(diff)=1
91       expected: 90, abs(diff)=1
80       expected: 80, abs(diff)=0
70       expected: 70, abs(diff)=0
61       expected: 60, abs(diff)=1
50       expected: 50, abs(diff)=0
40       expected: 40, abs(diff)=0
31       expected: 30, abs(diff)=1
20       expected: 20, abs(diff)=0
11       expected: 10, abs(diff)=1
Overall difference: 10
wait loops: 265615

[jj2007]

Interesting, thanks. Definitely a lot more accurate. But still, no difference between sync = 1 and sync = 0... ::)

[MichaelW]

The code in the attachment shows the effect. For a timed period I used a random value in the range 0 to 9ms to ensure that the entire loop cannot run in sync with the timer, biasing the results.

[hutch--]

And the magic expression is "RING3".

Now the profundity of this comment lies in processor privelege levels and why you will never get really accurate timing at low durations with GetTickCount. Michael has a valid point in that you don't know what the spacing is in milliseconds to the next result from GetTickCount but even if you can get around this problem, there are too many OS RING0 operations that will mess it up for you.

You can improve the resolution by use a multimedia timer that also appears to raise the priority but you do it at an increase in processor load that gets higher as the interval gets lower. You can come close to 1ms duration but watch your processor workload go up.

[jj2007]

But still, no difference between sync = 1 and sync = 0... ::)

I withdraw that statement, because at a granularity of 1 ms for timeGetTime, there should be no need to sync.
There is an interesting debate at Larry Osterman's web log, where he claims that GetTickCount and timeGetTime do the same but gets, ehm, challenged on that statement.

Michael's approach via QPC was on my agenda for MasmBasic, too. One disadvantage is that it doesn't yield cycles... oh well.
:wink

[MichaelW]

The results of Win32 API GetSystemTimeAdjustments() suggest that timer interrupt interval is 15 ms, not 10 ms.

On my 10-year old system running Windows 2000, and a 12-year old system running Windows XP Pro I get:

Code Select Expand


GetSystemTimeAdjustment(): size adjustment=100144 100ns [10 ms]
GetSystemTimeAdjustment(): increment=100144 100ns [10 ms]
GetSystemTimeAdjustment(): periodic time adjustment disabled=1


And the 10ms value matches my test results on the systems.

[japheth]

Ok. 15.625 ms is somewhat regarded as "standard", but it may be changed. I found this:

http://forum.sysinternals.com/topic16229.html