Forum > LCL
Trying to understand timing
howardpc:
The attached simple project uses a TTimer and calls GetTickCount64 in the OnTimer event.
Typical output based on my (aging) hardware is
--- Code: Pascal [+][-]window.onload = function(){var x1 = document.getElementById("main_content_section"); if (x1) { var x = document.getElementsByClassName("geshi");for (var i = 0; i < x.length; i++) { x[i].style.maxHeight='none'; x[i].style.height = Math.min(x[i].clientHeight+15,306)+'px'; x[i].style.resize = "vertical";}};} ---timer.Interval: 100, timercount: 01, elapsed: 0100, diff: 100, modElapsed: 00, divElapsed: 100timer.Interval: 100, timercount: 02, elapsed: 0200, diff: 100, modElapsed: 00, divElapsed: 100timer.Interval: 100, timercount: 03, elapsed: 0301, diff: 101, modElapsed: 01, divElapsed: 100timer.Interval: 100, timercount: 04, elapsed: 0401, diff: 100, modElapsed: 01, divElapsed: 100timer.Interval: 100, timercount: 05, elapsed: 0502, diff: 101, modElapsed: 02, divElapsed: 100timer.Interval: 100, timercount: 06, elapsed: 0603, diff: 101, modElapsed: 03, divElapsed: 100timer.Interval: 100, timercount: 07, elapsed: 0704, diff: 101, modElapsed: 04, divElapsed: 100timer.Interval: 100, timercount: 08, elapsed: 0805, diff: 101, modElapsed: 05, divElapsed: 100timer.Interval: 100, timercount: 09, elapsed: 0905, diff: 100, modElapsed: 05, divElapsed: 100timer.Interval: 100, timercount: 10, elapsed: 1005, diff: 100, modElapsed: 05, divElapsed: 100timer.Interval: 100, timercount: 11, elapsed: 1106, diff: 101, modElapsed: 06, divElapsed: 100timer.Interval: 100, timercount: 12, elapsed: 1206, diff: 100, modElapsed: 06, divElapsed: 100timer.Interval: 100, timercount: 13, elapsed: 1307, diff: 101, modElapsed: 07, divElapsed: 100timer.Interval: 100, timercount: 14, elapsed: 1408, diff: 101, modElapsed: 08, divElapsed: 100timer.Interval: 100, timercount: 15, elapsed: 1508, diff: 100, modElapsed: 08, divElapsed: 100timer.Interval: 100, timercount: 16, elapsed: 1609, diff: 101, modElapsed: 09, divElapsed: 100timer.Interval: 100, timercount: 17, elapsed: 1709, diff: 100, modElapsed: 09, divElapsed: 100timer.Interval: 100, timercount: 18, elapsed: 1809, diff: 100, modElapsed: 09, divElapsed: 100timer.Interval: 100, timercount: 19, elapsed: 1910, diff: 101, modElapsed: 10, divElapsed: 100timer.Interval: 100, timercount: 20, elapsed: 2011, diff: 101, modElapsed: 11, divElapsed: 100timer.Interval: 100, timercount: 21, elapsed: 2111, diff: 100, modElapsed: 11, divElapsed: 100timer.Interval: 100, timercount: 22, elapsed: 2212, diff: 101, modElapsed: 12, divElapsed: 100timer.Interval: 100, timercount: 23, elapsed: 2312, diff: 100, modElapsed: 12, divElapsed: 100timer.Interval: 100, timercount: 24, elapsed: 2413, diff: 101, modElapsed: 13, divElapsed: 100timer.Interval: 100, timercount: 25, elapsed: 2513, diff: 100, modElapsed: 13, divElapsed: 100timer.Interval: 100, timercount: 26, elapsed: 2614, diff: 101, modElapsed: 14, divElapsed: 100timer.Interval: 100, timercount: 27, elapsed: 2714, diff: 100, modElapsed: 14, divElapsed: 100timer.Interval: 100, timercount: 28, elapsed: 2814, diff: 100, modElapsed: 14, divElapsed: 100timer.Interval: 100, timercount: 29, elapsed: 2914, diff: 100, modElapsed: 14, divElapsed: 100timer.Interval: 100, timercount: 30, elapsed: 3016, diff: 102, modElapsed: 16, divElapsed: 100timer.Interval: 100, timercount: 31, elapsed: 3116, diff: 100, modElapsed: 16, divElapsed: 100timer.Interval: 100, timercount: 32, elapsed: 3217, diff: 101, modElapsed: 17, divElapsed: 100timer.Interval: 100, timercount: 33, elapsed: 3318, diff: 101, modElapsed: 18, divElapsed: 100timer.Interval: 100, timercount: 34, elapsed: 3418, diff: 100, modElapsed: 18, divElapsed: 100timer.Interval: 100, timercount: 35, elapsed: 3519, diff: 101, modElapsed: 19, divElapsed: 100timer.Interval: 100, timercount: 36, elapsed: 3620, diff: 101, modElapsed: 20, divElapsed: 100timer.Interval: 100, timercount: 37, elapsed: 3720, diff: 100, modElapsed: 20, divElapsed: 100timer.Interval: 100, timercount: 38, elapsed: 3820, diff: 100, modElapsed: 20, divElapsed: 100timer.Interval: 100, timercount: 39, elapsed: 3921, diff: 101, modElapsed: 21, divElapsed: 100timer.Interval: 100, timercount: 40, elapsed: 4021, diff: 100, modElapsed: 21, divElapsed: 100 timer.Interval: 50, timercount: 01, elapsed: 0051, diff: 51, modElapsed: 00, divElapsed: 51timer.Interval: 50, timercount: 02, elapsed: 0101, diff: 50, modElapsed: 01, divElapsed: 50timer.Interval: 50, timercount: 03, elapsed: 0152, diff: 51, modElapsed: 02, divElapsed: 50timer.Interval: 50, timercount: 04, elapsed: 0202, diff: 50, modElapsed: 02, divElapsed: 50timer.Interval: 50, timercount: 05, elapsed: 0253, diff: 51, modElapsed: 03, divElapsed: 50timer.Interval: 50, timercount: 06, elapsed: 0304, diff: 51, modElapsed: 04, divElapsed: 50timer.Interval: 50, timercount: 07, elapsed: 0354, diff: 50, modElapsed: 04, divElapsed: 50timer.Interval: 50, timercount: 08, elapsed: 0405, diff: 51, modElapsed: 05, divElapsed: 50timer.Interval: 50, timercount: 09, elapsed: 0455, diff: 50, modElapsed: 05, divElapsed: 50timer.Interval: 50, timercount: 10, elapsed: 0506, diff: 51, modElapsed: 06, divElapsed: 50timer.Interval: 50, timercount: 11, elapsed: 0556, diff: 50, modElapsed: 06, divElapsed: 50timer.Interval: 50, timercount: 12, elapsed: 0607, diff: 51, modElapsed: 07, divElapsed: 50timer.Interval: 50, timercount: 13, elapsed: 0657, diff: 50, modElapsed: 07, divElapsed: 50timer.Interval: 50, timercount: 14, elapsed: 0707, diff: 50, modElapsed: 07, divElapsed: 50timer.Interval: 50, timercount: 15, elapsed: 0758, diff: 51, modElapsed: 08, divElapsed: 50timer.Interval: 50, timercount: 16, elapsed: 0809, diff: 51, modElapsed: 09, divElapsed: 50timer.Interval: 50, timercount: 17, elapsed: 0859, diff: 50, modElapsed: 09, divElapsed: 50timer.Interval: 50, timercount: 18, elapsed: 0910, diff: 51, modElapsed: 10, divElapsed: 50timer.Interval: 50, timercount: 19, elapsed: 0960, diff: 50, modElapsed: 10, divElapsed: 50timer.Interval: 50, timercount: 20, elapsed: 1010, diff: 50, modElapsed: 10, divElapsed: 50timer.Interval: 50, timercount: 21, elapsed: 1061, diff: 51, modElapsed: 11, divElapsed: 50timer.Interval: 50, timercount: 22, elapsed: 1111, diff: 50, modElapsed: 11, divElapsed: 50timer.Interval: 50, timercount: 23, elapsed: 1162, diff: 51, modElapsed: 12, divElapsed: 50timer.Interval: 50, timercount: 24, elapsed: 1212, diff: 50, modElapsed: 12, divElapsed: 50timer.Interval: 50, timercount: 25, elapsed: 1263, diff: 51, modElapsed: 13, divElapsed: 50timer.Interval: 50, timercount: 26, elapsed: 1313, diff: 50, modElapsed: 13, divElapsed: 50timer.Interval: 50, timercount: 27, elapsed: 1363, diff: 50, modElapsed: 13, divElapsed: 50timer.Interval: 50, timercount: 28, elapsed: 1414, diff: 51, modElapsed: 14, divElapsed: 50timer.Interval: 50, timercount: 29, elapsed: 1464, diff: 50, modElapsed: 14, divElapsed: 50timer.Interval: 50, timercount: 30, elapsed: 1514, diff: 50, modElapsed: 14, divElapsed: 50timer.Interval: 50, timercount: 31, elapsed: 1565, diff: 51, modElapsed: 15, divElapsed: 50timer.Interval: 50, timercount: 32, elapsed: 1616, diff: 51, modElapsed: 16, divElapsed: 50timer.Interval: 50, timercount: 33, elapsed: 1666, diff: 50, modElapsed: 16, divElapsed: 50timer.Interval: 50, timercount: 34, elapsed: 1717, diff: 51, modElapsed: 17, divElapsed: 50timer.Interval: 50, timercount: 35, elapsed: 1767, diff: 50, modElapsed: 17, divElapsed: 50timer.Interval: 50, timercount: 36, elapsed: 1818, diff: 51, modElapsed: 18, divElapsed: 50timer.Interval: 50, timercount: 37, elapsed: 1868, diff: 50, modElapsed: 18, divElapsed: 50timer.Interval: 50, timercount: 38, elapsed: 1919, diff: 51, modElapsed: 19, divElapsed: 50timer.Interval: 50, timercount: 39, elapsed: 1969, diff: 50, modElapsed: 19, divElapsed: 50timer.Interval: 50, timercount: 40, elapsed: 2019, diff: 50, modElapsed: 19, divElapsed: 50 timer.Interval: 10, timercount: 01, elapsed: 0010, diff: 10, modElapsed: 00, divElapsed: 10timer.Interval: 10, timercount: 02, elapsed: 0021, diff: 11, modElapsed: 01, divElapsed: 10timer.Interval: 10, timercount: 03, elapsed: 0031, diff: 10, modElapsed: 01, divElapsed: 10timer.Interval: 10, timercount: 04, elapsed: 0042, diff: 11, modElapsed: 02, divElapsed: 10timer.Interval: 10, timercount: 05, elapsed: 0052, diff: 10, modElapsed: 02, divElapsed: 10timer.Interval: 10, timercount: 06, elapsed: 0063, diff: 11, modElapsed: 03, divElapsed: 10timer.Interval: 10, timercount: 07, elapsed: 0073, diff: 10, modElapsed: 03, divElapsed: 10timer.Interval: 10, timercount: 08, elapsed: 0084, diff: 11, modElapsed: 04, divElapsed: 10timer.Interval: 10, timercount: 09, elapsed: 0094, diff: 10, modElapsed: 04, divElapsed: 10timer.Interval: 10, timercount: 10, elapsed: 0105, diff: 11, modElapsed: 05, divElapsed: 10timer.Interval: 10, timercount: 11, elapsed: 0115, diff: 10, modElapsed: 05, divElapsed: 10timer.Interval: 10, timercount: 12, elapsed: 0125, diff: 10, modElapsed: 05, divElapsed: 10timer.Interval: 10, timercount: 13, elapsed: 0136, diff: 11, modElapsed: 06, divElapsed: 10timer.Interval: 10, timercount: 14, elapsed: 0146, diff: 10, modElapsed: 06, divElapsed: 10timer.Interval: 10, timercount: 15, elapsed: 0157, diff: 11, modElapsed: 07, divElapsed: 10timer.Interval: 10, timercount: 16, elapsed: 0167, diff: 10, modElapsed: 07, divElapsed: 10timer.Interval: 10, timercount: 17, elapsed: 0178, diff: 11, modElapsed: 08, divElapsed: 10timer.Interval: 10, timercount: 18, elapsed: 0188, diff: 10, modElapsed: 08, divElapsed: 10timer.Interval: 10, timercount: 19, elapsed: 0199, diff: 11, modElapsed: 09, divElapsed: 10timer.Interval: 10, timercount: 20, elapsed: 0209, diff: 10, modElapsed: 09, divElapsed: 10timer.Interval: 10, timercount: 21, elapsed: 0220, diff: 11, modElapsed: 10, divElapsed: 10timer.Interval: 10, timercount: 22, elapsed: 0230, diff: 10, modElapsed: 10, divElapsed: 10timer.Interval: 10, timercount: 23, elapsed: 0241, diff: 11, modElapsed: 11, divElapsed: 10timer.Interval: 10, timercount: 24, elapsed: 0251, diff: 10, modElapsed: 11, divElapsed: 10timer.Interval: 10, timercount: 25, elapsed: 0262, diff: 11, modElapsed: 12, divElapsed: 10timer.Interval: 10, timercount: 26, elapsed: 0272, diff: 10, modElapsed: 12, divElapsed: 10timer.Interval: 10, timercount: 27, elapsed: 0283, diff: 11, modElapsed: 13, divElapsed: 10timer.Interval: 10, timercount: 28, elapsed: 0293, diff: 10, modElapsed: 13, divElapsed: 10timer.Interval: 10, timercount: 29, elapsed: 0304, diff: 11, modElapsed: 14, divElapsed: 10timer.Interval: 10, timercount: 30, elapsed: 0314, diff: 10, modElapsed: 14, divElapsed: 10timer.Interval: 10, timercount: 31, elapsed: 0325, diff: 11, modElapsed: 15, divElapsed: 10timer.Interval: 10, timercount: 32, elapsed: 0335, diff: 10, modElapsed: 15, divElapsed: 10timer.Interval: 10, timercount: 33, elapsed: 0345, diff: 10, modElapsed: 15, divElapsed: 10timer.Interval: 10, timercount: 34, elapsed: 0356, diff: 11, modElapsed: 16, divElapsed: 10timer.Interval: 10, timercount: 35, elapsed: 0366, diff: 10, modElapsed: 16, divElapsed: 10timer.Interval: 10, timercount: 36, elapsed: 0376, diff: 10, modElapsed: 16, divElapsed: 10timer.Interval: 10, timercount: 37, elapsed: 0387, diff: 11, modElapsed: 17, divElapsed: 10timer.Interval: 10, timercount: 38, elapsed: 0397, diff: 10, modElapsed: 17, divElapsed: 10timer.Interval: 10, timercount: 39, elapsed: 0408, diff: 11, modElapsed: 18, divElapsed: 10timer.Interval: 10, timercount: 40, elapsed: 0418, diff: 10, modElapsed: 18, divElapsed: 10Is the variation in the diff value, and the slow upward drift in modElapsed because of basic differences between the timing of TTimer and GetTickCount64, or because GetTickcount64 is taking into account the time taken by the OnTimer event itself? Or is there some other reason?
440bx:
I cannot give you a precise description of the reason because there are some details about GetTickCount64 that I don't recall exactly at this time but... here is the "gist" of the reason for the divergence between the two.
First, here is how GetTickCount64 is implemented:
--- Code: ASM [+][-]window.onload = function(){var x1 = document.getElementById("main_content_section"); if (x1) { var x = document.getElementsByClassName("geshi");for (var i = 0; i < x.length; i++) { x[i].style.maxHeight='none'; x[i].style.height = Math.min(x[i].clientHeight+15,306)+'px'; x[i].style.resize = "vertical";}};} ---.text:000000018004DC80 ; ULONGLONG __stdcall GetTickCount64().text:000000018004DC80 public GetTickCount64.text:000000018004DC80 GetTickCount64 proc near ; DATA XREF: .rdata:00000001801C04A3↓o.text:000000018004DC80 ; .rdata:off_180275008↓o.text:000000018004DC80 mov ecx, ds:7FFE0004h.text:000000018004DC87 mov eax, 7FFE0320h.text:000000018004DC8C shl rcx, 20h.text:000000018004DC90 mov rax, [rax].text:000000018004DC93 shl rax, 8.text:000000018004DC97 mul rcx.text:000000018004DC9A mov rax, rdx.text:000000018004DC9D retn.text:000000018004DC9D GetTickCount64 endp.text:000000018004DC9Din the above code, eax is an address into the USER_SHARED_DATA which among other things keeps a count that is set from kernel mode (ring-0), as you can see, some calculations using that value yield the tick count value returned by GetTickCount64. The important thing is, GetTickCount64 is almost independent of the Windows scheduler, something which the timer event isn't.
That combined with the fact that timer messages are _low_ priority is what accounts for most of the variation.
howardpc:
Does that mean that using GetTickCount64 to calculate elapsed times gives a more accurate result than using a message-based timer?
440bx:
--- Quote from: howardpc on May 02, 2022, 08:19:04 pm ---Does that mean that using GetTickCount64 to calculate elapsed times gives a more accurate result than using a message-based timer?
--- End quote ---
It should because there is less overhead involved and, calling GetTickCount64 isn't a "low priority" event (however, it is subject to thread scheduling.)
For most purposes, the precision of GetTickCount64 is quite acceptable. For really high resolution measurements, it is inadequate but not as inadequate as a timer event.
howardpc:
Thank you.
Navigation
[0] Message Index
[#] Next page