Alternate timing method for Win 10

[hutch--]

This is a test piece for a late Win 10 API function, QueryUnbiasedInterruptTime. It is supposed to have slightly better precision due to not counting system delays.


; ¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤

    include \masm32\include64\masm64rt.inc

    .data?
      QueryUnbiasedInterruptTime dq ?

    .code

; ¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤

entry_point proc

    USING r12,r13
    LOCAL krnl  :QWORD
    LOCAL rslt1 :REAL8
    LOCAL rslt2 :REAL8
    LOCAL var   :REAL8
    LOCAL text  :QWORD

    LOCAL buff[64]:BYTE
    LOCAL pbuf  :QWORD

    SaveRegs

    HighPriority

    sas text,"1234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890"

    mov krnl, rvcall(GetModuleHandle,"kernel32.dll")
    mov QueryUnbiasedInterruptTime, rvcall(GetProcAddress,krnl,"QueryUnbiasedInterruptTime")

    conout "Output is in seconds",lf,lf

    mov pbuf, ptr$(buff)                                ; get pointer to buffer

    mov r12, 10                                         ; the iteration counter

  ; *********************************

  lbl:
    rcall QueryUnbiasedInterruptTime,ptr$(rslt1)

    cpuid

  ; =================================

    mov r13, 80000000                                   ; inner loop counter
  cnlp:

  ; ---------------------------------
    rcall StrLen,text                                   ; time StrLen algorithm
  ; ---------------------------------

    sub r13, 1
    jnz cnlp

  ; =================================

    rcall QueryUnbiasedInterruptTime,ptr$(rslt2)

    mov rax, rslt1                                      ; sub result 1 from result 2
    sub rslt2, rax

    cvtsi2sd xmm0, rslt2                                ; convert into to scalar double
    divsd xmm0, AFL8(10000000.0)                        ; divide result by 10 million to get seconds
    movsd var, xmm0                                     ; store the result in the REAL8 variable
    rcall fptoa,var,pbuf                                ; convert result to string
    rcall truncate,pbuf,6                               ; truncate decinal places
    conout "  ",pbuf,lf                                 ; display result

    sub r12, 1
    jnz lbl

  ; *********************************

    conout lf,"Thats all folks ....",lf,lf

    NormalPriority

    waitkey
    RestoreRegs
    .exit

entry_point endp

; ¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤¤

    end

[Siekmanski]

It also runs onder Windows 8.1, don't know if the timings are correct?

Code Select Expand

Output is in seconds

  1.524531
  1.519529
  1.520529
  1.519530
  1.520529
  1.520530
  1.519529
  1.519529
  1.520530
  1.519529

Thats all folks ....

Press any key to continue...


[TimoVJL]

QueryUnbiasedInterruptTime function

Minimum supported client   Windows 7, Windows 8 [desktop apps | UWP apps]


BTW: msvcrt.dll have a _gcvt() function.

Code Select Expand

#pragma comment(lib, "msvcrt.lib")
char *_gcvt(double value, int digits, char *buffer);

int __cdecl main(void)
{
double d = 1.23456;
char buf[100];
puts(_gcvt(d, 16, buf));
return 0;
}


[hutch--]

Yes, that makes sense, its a lot more useful if it runs on Win7 upwards.

[jj2007]

Granularity problem?

Code Select Expand

  1.749100
  1.737099
  1.785102
  1.729098  <-------
  1.729098  <-------
  1.735099
  1.727098  <-------
  1.779101
  1.752100
  1.734099

Second run:

Code Select Expand

  2.107120
  2.106120
  2.106120
  2.105120
  2.105120
  2.105120
  2.105120
  2.105120
  2.105120
  2.105120

Third run:

Code Select Expand

  2.116121
  2.106120
  2.106120
  2.106120
  2.106120
  2.105120
  2.105120
  2.106120
  2.106120
  2.105120


https://docs.microsoft.com/en-us/windows/win32/api/realtimeapiset/nf-realtimeapiset-queryunbiasedinterrupttime

Applications can use the interrupt-time count to measure finer durations than are possible with system time. Applications that require greater precision than the interrupt-time count should use a high-resolution timer. Use the QueryPerformanceFrequency function to retrieve the frequency of the high-resolution timer and the QueryPerformanceCounter function to retrieve the counter's value.

[hutch--]

> Granularity problem?

  1.785102
  1.729098  <-------
  1.729098  <-------
  1.735099
  1.727098  <-------
  1.779101

Probably not, it is fluctuation at a depth of 4 decimal places. The API is still subject to ring0 interference and with much shorter durations it becomes very obvious. The advantage the API is supposed to have is a gain in accuracy by not counting system based pauses and other similar OS based overhead.

[aw27]

May you need QueryUnbiasedInterruptTimePrecise instead   

[aw27]

Actually this QueryUnbiasedInterruptTime, and its cousin QueryUnbiasedInterruptTimePrecise, are not for measuring the time taken by an activity(*) but for measuring the time the system is up discounting Hibernation/Sleep periods.

This can be seen from this code, where the programs sleeps for 1 second with the Sleep function API before calling again QueryUnbiasedInterruptTime:

Code Select Expand


OPTION WIN64:11
OPTION LITERALS:ON
option casemap:none

LPVOID typedef ptr void
TQueryUnbiasedInterruptTime typedef proto :ptr
includelib \masm32\lib64\kernel32.lib
Sleep proto :dword
GetModuleHandleA proto :ptr
GetProcAddress proto :ptr, :ptr
ExitProcess proto :dword
includelib \masm32\lib64\msvcrt.lib
printf proto :ptr, :vararg

.data
KernMod  qword 0
UnbiasedTime qword 0
QueryUnbiasedInterruptTime LPVOID 0
TheTime db "%lld\n",0

.code

main proc
invoke GetModuleHandleA, CSTR("kernel32.dll")
mov KernMod, rax
invoke GetProcAddress, KernMod, CSTR("QueryUnbiasedInterruptTime")
mov r13, rax
mov r12d,0
.while r12d<20
assume r13 : ptr TQueryUnbiasedInterruptTime
invoke r13, addr UnbiasedTime
mov rax, UnbiasedTime
mov rcx, 10000000
mov rdx,0
div rcx
printf("%lld\n", rax)
Sleep(1000)
inc r12d
.endw
invoke ExitProcess,0
main endp

end


177234
177235
177236
177237
177238
177239
177240
177241
177242
177243
177244
177245
177246
177247
177248
177249
177250
177251
177252
177253

(*) Of course, it can be used to measure the time taken by an activity by subtracting the counter before from the counter after but I don't think is the best function for that. Anyway, it can be tested further and may be there are hidden treasures inside it.