From ccbd8395f4a51f5b769998058006ed3d36823ace Mon Sep 17 00:00:00 2001 From: sebres Date: Tue, 23 May 2017 21:57:13 +0000 Subject: [win32] optimized calibration cycle (makes Tcl for windows "RTS" resp. NRT-capable): - the clock ticks never backwards (avoid it by negative drifts using comparison of times before and after calibration); - more precise, smooth/soft drifting (avoids too large drifts, already after 10 iterations the drift gets fewer as 0.1 microseconds); - because of more accurate drifting (aspire to the smallest difference), we can prolong calibration interval (up to 10 seconds by small tdiff-value); Closes ticket [b7b707a310ea42e9f1b29954ee8ca13ae91ccabe] "[win32] NRT-only - NativeGetTime backwards time-drifts bug" --- win/tclWinTime.c | 175 ++++++++++++++++++++++++++++++++++++++----------------- 1 file changed, 122 insertions(+), 53 deletions(-) diff --git a/win/tclWinTime.c b/win/tclWinTime.c index 374c41c..93f62b8 100644 --- a/win/tclWinTime.c +++ b/win/tclWinTime.c @@ -51,6 +51,7 @@ typedef struct TimeInfo { * initialized. */ int perfCounterAvailable; /* Flag == 1 if the hardware has a performance * counter. */ + DWORD calibrationInterv; /* Calibration interval in seconds (start 1 sec) */ HANDLE calibrationThread; /* Handle to the thread that keeps the virtual * clock calibrated. */ HANDLE readyEvent; /* System event used to trigger the requesting @@ -61,7 +62,6 @@ typedef struct TimeInfo { LARGE_INTEGER nominalFreq; /* Nominal frequency of the system performance * counter, that is, the value returned from * QueryPerformanceFrequency. */ - /* * The following values are used for calculating virtual time. Virtual * time is always equal to: @@ -74,6 +74,8 @@ typedef struct TimeInfo { ULARGE_INTEGER fileTimeLastCall; LARGE_INTEGER perfCounterLastCall; LARGE_INTEGER curCounterFreq; + LARGE_INTEGER posixEpoch; /* Posix epoch expressed as 100-ns ticks since + * the windows epoch. */ /* * Data used in developing the estimate of performance counter frequency @@ -87,9 +89,10 @@ typedef struct TimeInfo { } TimeInfo; static TimeInfo timeInfo = { - { NULL }, + { NULL, 0, 0, NULL, NULL, 0 }, 0, 0, + 1, (HANDLE) NULL, (HANDLE) NULL, (HANDLE) NULL, @@ -98,11 +101,13 @@ static TimeInfo timeInfo = { (ULARGE_INTEGER) (DWORDLONG) 0, (LARGE_INTEGER) (Tcl_WideInt) 0, (LARGE_INTEGER) (Tcl_WideInt) 0, + (LARGE_INTEGER) (Tcl_WideInt) 0, #else - 0, - 0, - 0, - 0, + {0, 0}, + {0, 0}, + {0, 0}, + {0, 0}, + {0, 0}, #endif { 0 }, { 0 }, @@ -464,12 +469,20 @@ NativeScaleTime( *---------------------------------------------------------------------- */ +static inline Tcl_WideInt +NativeCalc100NsTicks( + ULONGLONG fileTimeLastCall, + LONGLONG perfCounterLastCall, + LONGLONG curCounterFreq, + LONGLONG curCounter +) { + return fileTimeLastCall + + ((curCounter - perfCounterLastCall) * 10000000 / curCounterFreq); +} + static Tcl_WideInt NativeGetMicroseconds(void) { - static LARGE_INTEGER posixEpoch; - /* Posix epoch expressed as 100-ns ticks since - * the windows epoch. */ /* * Initialize static storage on the first trip through. * @@ -481,8 +494,8 @@ NativeGetMicroseconds(void) TclpInitLock(); if (!timeInfo.initialized) { - posixEpoch.LowPart = 0xD53E8000; - posixEpoch.HighPart = 0x019DB1DE; + timeInfo.posixEpoch.LowPart = 0xD53E8000; + timeInfo.posixEpoch.HighPart = 0x019DB1DE; timeInfo.perfCounterAvailable = QueryPerformanceFrequency(&timeInfo.nominalFreq); @@ -588,16 +601,12 @@ NativeGetMicroseconds(void) * time. */ - ULARGE_INTEGER fileTimeLastCall; - LARGE_INTEGER perfCounterLastCall, curCounterFreq; + ULONGLONG fileTimeLastCall; + LONGLONG perfCounterLastCall, curCounterFreq; /* Copy with current data of calibration cycle */ LARGE_INTEGER curCounter; /* Current performance counter. */ - Tcl_WideInt curFileTime;/* Current estimated time, expressed as 100-ns - * ticks since the Windows epoch. */ - Tcl_WideInt usecSincePosixEpoch; - /* Current microseconds since Posix epoch. */ QueryPerformanceCounter(&curCounter); @@ -606,19 +615,18 @@ NativeGetMicroseconds(void) */ EnterCriticalSection(&timeInfo.cs); - fileTimeLastCall.QuadPart = timeInfo.fileTimeLastCall.QuadPart; - perfCounterLastCall.QuadPart = timeInfo.perfCounterLastCall.QuadPart; - curCounterFreq.QuadPart = timeInfo.curCounterFreq.QuadPart; + fileTimeLastCall = timeInfo.fileTimeLastCall.QuadPart; + perfCounterLastCall = timeInfo.perfCounterLastCall.QuadPart; + curCounterFreq = timeInfo.curCounterFreq.QuadPart; LeaveCriticalSection(&timeInfo.cs); /* * If calibration cycle occurred after we get curCounter */ - if (curCounter.QuadPart <= perfCounterLastCall.QuadPart) { - usecSincePosixEpoch = - (fileTimeLastCall.QuadPart - posixEpoch.QuadPart) / 10; - return usecSincePosixEpoch; + if (curCounter.QuadPart <= perfCounterLastCall) { + /* Calibrated file-time is saved from posix in 100-ns ticks */ + return fileTimeLastCall / 10; } /* @@ -631,15 +639,12 @@ NativeGetMicroseconds(void) * loop should recover. */ - if (curCounter.QuadPart - perfCounterLastCall.QuadPart < - 11 * curCounterFreq.QuadPart / 10 + if (curCounter.QuadPart - perfCounterLastCall < + 11 * curCounterFreq * timeInfo.calibrationInterv / 10 ) { - curFileTime = fileTimeLastCall.QuadPart + - ((curCounter.QuadPart - perfCounterLastCall.QuadPart) - * 10000000 / curCounterFreq.QuadPart); - - usecSincePosixEpoch = (curFileTime - posixEpoch.QuadPart) / 10; - return usecSincePosixEpoch; + /* Calibrated file-time is saved from posix in 100-ns ticks */ + return NativeCalc100NsTicks(fileTimeLastCall, + perfCounterLastCall, curCounterFreq, curCounter.QuadPart) / 10; } } @@ -710,6 +715,8 @@ NativeGetTime( *---------------------------------------------------------------------- */ +void TclWinResetTimerResolution(void); + static void StopCalibration( ClientData unused) /* Client data is unused */ @@ -1076,6 +1083,8 @@ CalibrationThread( QueryPerformanceFrequency(&timeInfo.curCounterFreq); timeInfo.fileTimeLastCall.LowPart = curFileTime.dwLowDateTime; timeInfo.fileTimeLastCall.HighPart = curFileTime.dwHighDateTime; + /* Calibrated file-time will be saved from posix in 100-ns ticks */ + timeInfo.fileTimeLastCall.QuadPart -= timeInfo.posixEpoch.QuadPart; ResetCounterSamples(timeInfo.fileTimeLastCall.QuadPart, timeInfo.perfCounterLastCall.QuadPart, @@ -1135,6 +1144,7 @@ UpdateTimeEachSecond(void) /* Current value returned from * QueryPerformanceCounter. */ FILETIME curSysTime; /* Current system time. */ + static LARGE_INTEGER lastFileTime; /* File time of the previous calibration */ LARGE_INTEGER curFileTime; /* File time at the time this callback was * scheduled. */ Tcl_WideInt estFreq; /* Estimated perf counter frequency. */ @@ -1146,15 +1156,24 @@ UpdateTimeEachSecond(void) * step over 1 second. */ /* - * Sample performance counter and system time. + * Sample performance counter and system time (from posix epoch). */ - QueryPerformanceCounter(&curPerfCounter); GetSystemTimeAsFileTime(&curSysTime); curFileTime.LowPart = curSysTime.dwLowDateTime; curFileTime.HighPart = curSysTime.dwHighDateTime; - - EnterCriticalSection(&timeInfo.cs); + curFileTime.QuadPart -= timeInfo.posixEpoch.QuadPart; + /* If calibration still not needed (check for possible time switch) */ + if ( curFileTime.QuadPart > lastFileTime.QuadPart + && curFileTime.QuadPart < lastFileTime.QuadPart + + (timeInfo.calibrationInterv * 10000000) + ) { + /* again in next one second */ + return; + } + QueryPerformanceCounter(&curPerfCounter); + + lastFileTime.QuadPart = curFileTime.QuadPart; /* * We devide by timeInfo.curCounterFreq.QuadPart in several places. That @@ -1166,7 +1185,6 @@ UpdateTimeEachSecond(void) */ if (timeInfo.curCounterFreq.QuadPart == 0){ - LeaveCriticalSection(&timeInfo.cs); timeInfo.perfCounterAvailable = 0; return; } @@ -1185,7 +1203,7 @@ UpdateTimeEachSecond(void) * estimate the performance counter frequency. */ - estFreq = AccumulateSample(curPerfCounter.QuadPart, + estFreq = AccumulateSample(curPerfCounter.QuadPart, (Tcl_WideUInt) curFileTime.QuadPart); /* @@ -1205,12 +1223,9 @@ UpdateTimeEachSecond(void) * is estFreq * 20000000 / (vt1 - vt0) */ - vt0 = 10000000 * (curPerfCounter.QuadPart - - timeInfo.perfCounterLastCall.QuadPart) - / timeInfo.curCounterFreq.QuadPart - + timeInfo.fileTimeLastCall.QuadPart; - vt1 = 20000000 + curFileTime.QuadPart; - + vt0 = NativeCalc100NsTicks(timeInfo.fileTimeLastCall.QuadPart, + timeInfo.perfCounterLastCall.QuadPart, timeInfo.curCounterFreq.QuadPart, + curPerfCounter.QuadPart); /* * If we've gotten more than a second away from system time, then drifting * the clock is going to be pretty hopeless. Just let it jump. Otherwise, @@ -1219,21 +1234,75 @@ UpdateTimeEachSecond(void) tdiff = vt0 - curFileTime.QuadPart; if (tdiff > 10000000 || tdiff < -10000000) { - timeInfo.fileTimeLastCall.QuadPart = curFileTime.QuadPart; - timeInfo.curCounterFreq.QuadPart = estFreq; + /* jump to current system time, use curent estimated frequency */ + vt0 = curFileTime.QuadPart; } else { - driftFreq = estFreq * 20000000 / (vt1 - vt0); + /* calculate new frequency and estimate drift to the next second */ + vt1 = 20000000 + curFileTime.QuadPart; + driftFreq = (estFreq * 20000000 / (vt1 - vt0)); + /* + * Avoid too large drifts (only half of the current difference), + * that allows also be more accurate (aspire to the smallest tdiff), + * so then we can prolong calibration interval by tdiff < 100000 + */ + driftFreq = timeInfo.curCounterFreq.QuadPart + + (driftFreq - timeInfo.curCounterFreq.QuadPart) / 2; - if (driftFreq > 1003*estFreq/1000) { - driftFreq = 1003*estFreq/1000; - } else if (driftFreq < 997*estFreq/1000) { - driftFreq = 997*estFreq/1000; + /* + * Average between estimated, 2 current and 5 drifted frequencies, + * (do the soft drifting as possible) + */ + estFreq = (estFreq + 2 * timeInfo.curCounterFreq.QuadPart + 5 * driftFreq) / 8; + } + + /* Avoid too large discrepancy from nominal frequency */ + if (estFreq > 1003*timeInfo.nominalFreq.QuadPart/1000) { + estFreq = 1003*timeInfo.nominalFreq.QuadPart/1000; + vt0 = curFileTime.QuadPart; + } else if (estFreq < 997*timeInfo.nominalFreq.QuadPart/1000) { + estFreq = 997*timeInfo.nominalFreq.QuadPart/1000; + vt0 = curFileTime.QuadPart; + } else if (vt0 != curFileTime.QuadPart) { + /* + * Be sure the clock ticks never backwards (avoid it by negative drifting) + * just compare native time (in 100-ns) before and hereafter using + * new calibrated values) and do a small adjustment (short time freeze) + */ + LARGE_INTEGER newPerfCounter; + Tcl_WideInt nt0, nt1; + + QueryPerformanceCounter(&newPerfCounter); + nt0 = NativeCalc100NsTicks(timeInfo.fileTimeLastCall.QuadPart, + timeInfo.perfCounterLastCall.QuadPart, timeInfo.curCounterFreq.QuadPart, + newPerfCounter.QuadPart); + nt1 = NativeCalc100NsTicks(vt0, + curPerfCounter.QuadPart, estFreq, + newPerfCounter.QuadPart); + if (nt0 > nt1) { /* drifted backwards, try to compensate with new base */ + /* first adjust with a micro jump (short frozen time is acceptable) */ + vt0 += nt0 - nt1; + /* if drift unavoidable (e. g. we had a time switch), then reset it */ + vt1 = vt0 - curFileTime.QuadPart; + if (vt1 > 10000000 || vt1 < -10000000) { + /* larger jump resp. shift relative new file-time */ + vt0 = curFileTime.QuadPart; + } } + } + + /* In lock commit new values to timeInfo (hold lock as short as possible) */ + EnterCriticalSection(&timeInfo.cs); - timeInfo.fileTimeLastCall.QuadPart = vt0; - timeInfo.curCounterFreq.QuadPart = driftFreq; + /* grow calibration interval up to 10 seconds (if still precise enough) */ + if (tdiff < -100000 || tdiff > 100000) { + /* too long drift - reset calibration interval to 1000 second */ + timeInfo.calibrationInterv = 1; + } else if (timeInfo.calibrationInterv < 10) { + timeInfo.calibrationInterv++; } + timeInfo.fileTimeLastCall.QuadPart = vt0; + timeInfo.curCounterFreq.QuadPart = estFreq; timeInfo.perfCounterLastCall.QuadPart = curPerfCounter.QuadPart; LeaveCriticalSection(&timeInfo.cs); -- cgit v0.12 From 1890d482a7b98d4bf0f3e024c415a9b266e4f55e Mon Sep 17 00:00:00 2001 From: "sergey.brester" Date: Tue, 12 Feb 2019 19:35:37 +0000 Subject: cherrypick [8ad25ef9eb] from 8.6 - timerate: added dynamic factor by threshold calculation (avoid growing of the execution time if iterations are not consistent, e. g. wax continuously on time) --- generic/tclCmdMZ.c | 31 ++++++++++++++++++++++++------- 1 file changed, 24 insertions(+), 7 deletions(-) diff --git a/generic/tclCmdMZ.c b/generic/tclCmdMZ.c index 2786f0d..87504de 100644 --- a/generic/tclCmdMZ.c +++ b/generic/tclCmdMZ.c @@ -3985,13 +3985,15 @@ Tcl_TimeRateObjCmd( register Tcl_Obj *objPtr; register int result, i; Tcl_Obj *calibrate = NULL, *direct = NULL; - Tcl_WideInt count = 0; /* Holds repetition count */ + Tcl_WideUInt count = 0; /* Holds repetition count */ Tcl_WideInt maxms = -0x7FFFFFFFFFFFFFFFL; /* Maximal running time (in milliseconds) */ - Tcl_WideInt threshold = 1; /* Current threshold for check time (faster + Tcl_WideUInt threshold = 1; /* Current threshold for check time (faster * repeat count without time check) */ - Tcl_WideInt maxIterTm = 1; /* Max time of some iteration as max threshold + Tcl_WideUInt maxIterTm = 1; /* Max time of some iteration as max threshold * additionally avoid divide to zero (never < 1) */ + unsigned short factor = 50; /* Factor (4..50) limiting threshold to avoid + * growth of execution time. */ register Tcl_WideInt start, middle, stop; #ifndef TCL_WIDE_CLICKS Tcl_Time now; @@ -4184,8 +4186,8 @@ usage: break; } - /* don't calculate threshold by few iterations, because sometimes - * first iteration(s) can be too fast (cached, delayed clean up, etc) */ + /* don't calculate threshold by few iterations, because sometimes first + * iteration(s) can be too fast or slow (cached, delayed clean up, etc) */ if (count < 10) { threshold = 1; continue; } @@ -4194,9 +4196,24 @@ usage: threshold = (middle - start) / count; if (threshold > maxIterTm) { maxIterTm = threshold; + /* interations seems to be longer */ + if (threshold > (maxIterTm * 2)) { + if ((factor *= 2) > 50) factor = 50; + } else { + if (factor < 50) factor++; + } + } else if (factor > 4) { + /* interations seems to be shorter */ + if (threshold < (maxIterTm / 2)) { + if ((factor /= 2) < 4) factor = 4; + } else { + factor--; + } } - /* as relation between remaining time and time since last check */ - threshold = ((stop - middle) / maxIterTm) / 4; + /* as relation between remaining time and time since last check, + * maximal some % of time (by factor), so avoid growing of the execution time + * if iterations are not consistent, e. g. wax continuously on time) */ + threshold = ((stop - middle) / maxIterTm) / factor + 1; if (threshold > 100000) { /* fix for too large threshold */ threshold = 100000; } -- cgit v0.12 From 6a355b11a62eca55d96068c29b918339a100b467 Mon Sep 17 00:00:00 2001 From: "sergey.brester" Date: Tue, 12 Feb 2019 19:38:46 +0000 Subject: timerate: allow break from measurement cycle (usable to provide conditional stop possibility inside timerate) --- generic/tclCmdMZ.c | 9 ++++++++- 1 file changed, 8 insertions(+), 1 deletion(-) diff --git a/generic/tclCmdMZ.c b/generic/tclCmdMZ.c index 87504de..4ee43ea 100644 --- a/generic/tclCmdMZ.c +++ b/generic/tclCmdMZ.c @@ -4169,7 +4169,14 @@ usage: result = TclEvalObjEx(interp, objPtr, 0, NULL, 0); } if (result != TCL_OK) { - goto done; + /* allow break from measurement cycle (used for conditional stop) */ + if (result != TCL_BREAK) { + goto done; + } + /* force stop immediately */ + threshold = 1; + stop = -0x7FFFFFFFFFFFFFFFL; + result = TCL_OK; } /* don't check time up to threshold */ -- cgit v0.12 From e0587d15645be0b1c8a11d3b4ea82a23ecebf595 Mon Sep 17 00:00:00 2001 From: "sergey.brester" Date: Tue, 12 Feb 2019 19:46:29 +0000 Subject: fixes estimated time of too short execution considering calibrated overhead (it is 0us and not 1us, example: `timerate {break}` with and without calibration) --- generic/tclCmdMZ.c | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/generic/tclCmdMZ.c b/generic/tclCmdMZ.c index 4ee43ea..cb44e08 100644 --- a/generic/tclCmdMZ.c +++ b/generic/tclCmdMZ.c @@ -4243,11 +4243,11 @@ usage: /* minimize influence of measurement overhead */ if (overhead > 0) { /* estimate the time of overhead (microsecs) */ - Tcl_WideInt curOverhead = overhead * count; + Tcl_WideUInt curOverhead = overhead * count; if (middle > curOverhead) { middle -= curOverhead; } else { - middle = 1; + middle = 0; } } } else { -- cgit v0.12 From f7183b361eac28e93e37b226ab5fd1b1166b882c Mon Sep 17 00:00:00 2001 From: "sergey.brester" Date: Tue, 12 Feb 2019 20:37:11 +0000 Subject: few test cases for timerate command --- tests/cmdMZ.test | 45 +++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 45 insertions(+) diff --git a/tests/cmdMZ.test b/tests/cmdMZ.test index 7fe4fda..fcb09df 100644 --- a/tests/cmdMZ.test +++ b/tests/cmdMZ.test @@ -347,6 +347,51 @@ test cmdMZ-5.7 {Tcl_TimeObjCmd: errors generate right trace} { invoked from within "time {error foo}"}} +test cmdMZ-6.1 {Tcl_TimeRateObjCmd: basic format of command} { + list [catch {timerate} msg] $msg +} {1 {wrong # args: should be "timerate ?-direct? ?-calibrate? ?-overhead double? command ?time?"}} +test cmdMZ-6.2 {Tcl_TimeRateObjCmd: basic format of command} { + list [catch {timerate a b c} msg] $msg +} {1 {wrong # args: should be "timerate ?-direct? ?-calibrate? ?-overhead double? command ?time?"}} +test cmdMZ-6.3 {Tcl_TimeRateObjCmd: basic format of command} { + list [catch {timerate a b} msg] $msg +} {1 {expected integer but got "b"}} +test cmdMZ-6.4 {Tcl_TimeRateObjCmd: compile of script happens even with negative iteration counts} { + list [catch {timerate "foreach a {c d e} \{" -12456} msg] $msg +} {1 {missing close-brace}} +test cmdMZ-6.5 {Tcl_TimeRateObjCmd: result format and one iteration} { + regexp {^\d+.\d+ [.]s/# 1 # \d+ #/sec \d+.\d+ nett-ms$} [timerate {} 0] +} 1 +test cmdMZ-6.6 {Tcl_TimeRateObjCmd: slower commands take longer, but it remains almost the same time of measument} { + set m1 [timerate {after 0} 20] + set m2 [timerate {after 1} 20] + list \ + [expr {[lindex $m1 0] < [lindex $m2 0]}] \ + [expr {[lindex $m1 0] < 100}] \ + [expr {[lindex $m2 0] >= 500}] \ + [expr {[lindex $m1 2] > 1000}] \ + [expr {[lindex $m2 2] <= 50}] \ + [expr {[lindex $m1 4] > 10000}] \ + [expr {[lindex $m2 4] < 10000}] \ + [expr {[lindex $m1 6] > 10 && [lindex $m1 6] < 50}] \ + [expr {[lindex $m2 6] > 10 && [lindex $m2 6] < 50}] +} [lrepeat 9 1] +test cmdMZ-6.7 {Tcl_TimeRateObjCmd: errors generate right trace} { + list [catch {timerate {error foo} 1} msg] $msg $::errorInfo +} {1 foo {foo + while executing +"error foo" + invoked from within +"timerate {error foo} 1"}} +test cmdMZ-6.8 {Tcl_TimeRateObjCmd: allow (conditional) break from timerate} { + set m1 [timerate {break}] + list \ + [expr {[lindex $m1 0] < 1000}] \ + [expr {[lindex $m1 2] == 1}] \ + [expr {[lindex $m1 4] > 1000}] \ + [expr {[lindex $m1 6] < 10}] +} {1 1 1 1} + # The tests for Tcl_WhileObjCmd are in while.test # cleanup -- cgit v0.12 From 2d41d8b6e28534be5e6713250740a76e56d417ef Mon Sep 17 00:00:00 2001 From: "sergey.brester" Date: Tue, 12 Feb 2019 20:40:12 +0000 Subject: small amend (correct wrong utf-8 prevention for micro sign in RE of check test-case) --- tests/cmdMZ.test | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/tests/cmdMZ.test b/tests/cmdMZ.test index fcb09df..08f1ffe 100644 --- a/tests/cmdMZ.test +++ b/tests/cmdMZ.test @@ -360,7 +360,7 @@ test cmdMZ-6.4 {Tcl_TimeRateObjCmd: compile of script happens even with negative list [catch {timerate "foreach a {c d e} \{" -12456} msg] $msg } {1 {missing close-brace}} test cmdMZ-6.5 {Tcl_TimeRateObjCmd: result format and one iteration} { - regexp {^\d+.\d+ [.]s/# 1 # \d+ #/sec \d+.\d+ nett-ms$} [timerate {} 0] + regexp {^\d+.\d+ \ws/# 1 # \d+ #/sec \d+.\d+ nett-ms$} [timerate {} 0] } 1 test cmdMZ-6.6 {Tcl_TimeRateObjCmd: slower commands take longer, but it remains almost the same time of measument} { set m1 [timerate {after 0} 20] -- cgit v0.12 From 5add43aac85a1d21f7b0ee6b9c9f43eb0a747918 Mon Sep 17 00:00:00 2001 From: sebres Date: Wed, 13 Feb 2019 01:10:16 +0000 Subject: timerate: extended with ?max-count? optional parameter, code review and more tests --- generic/tclCmdMZ.c | 39 +++++++++++++++++++++++++++------------ generic/tclPort.h | 3 +++ tests/cmdMZ.test | 27 +++++++++++++++++++++++---- 3 files changed, 53 insertions(+), 16 deletions(-) diff --git a/generic/tclCmdMZ.c b/generic/tclCmdMZ.c index cb44e08..ba86203 100644 --- a/generic/tclCmdMZ.c +++ b/generic/tclCmdMZ.c @@ -3986,8 +3986,10 @@ Tcl_TimeRateObjCmd( register int result, i; Tcl_Obj *calibrate = NULL, *direct = NULL; Tcl_WideUInt count = 0; /* Holds repetition count */ - Tcl_WideInt maxms = -0x7FFFFFFFFFFFFFFFL; + Tcl_WideInt maxms = WIDE_MIN; /* Maximal running time (in milliseconds) */ + Tcl_WideUInt maxcnt = WIDE_MAX; + /* Maximal count of iterations. */ Tcl_WideUInt threshold = 1; /* Current threshold for check time (faster * repeat count without time check) */ Tcl_WideUInt maxIterTm = 1; /* Max time of some iteration as max threshold @@ -4036,24 +4038,32 @@ Tcl_TimeRateObjCmd( } } - if (i >= objc || i < objc-2) { + if (i >= objc || i < objc-3) { usage: - Tcl_WrongNumArgs(interp, 1, objv, "?-direct? ?-calibrate? ?-overhead double? command ?time?"); + Tcl_WrongNumArgs(interp, 1, objv, "?-direct? ?-calibrate? ?-overhead double? command ?time ?max-count??"); return TCL_ERROR; } objPtr = objv[i++]; - if (i < objc) { - result = Tcl_GetWideIntFromObj(interp, objv[i], &maxms); + if (i < objc) { /* max-time */ + result = Tcl_GetWideIntFromObj(interp, objv[i++], &maxms); if (result != TCL_OK) { return result; } + if (i < objc) { /* max-count*/ + Tcl_WideInt v; + result = Tcl_GetWideIntFromObj(interp, objv[i], &v); + if (result != TCL_OK) { + return result; + } + maxcnt = (v > 0) ? v : 0; + } } /* if calibrate */ if (calibrate) { /* if no time specified for the calibration */ - if (maxms == -0x7FFFFFFFFFFFFFFFL) { + if (maxms == WIDE_MIN) { Tcl_Obj *clobjv[6]; Tcl_WideInt maxCalTime = 5000; double lastMeasureOverhead = measureOverhead; @@ -4083,7 +4093,7 @@ usage: clobjv[i++] = objPtr; /* set last measurement overhead to max */ - measureOverhead = (double)0x7FFFFFFFFFFFFFFFL; + measureOverhead = (double)UWIDE_MAX; /* calibration cycle until it'll be preciser */ maxms = -1000; @@ -4117,14 +4127,14 @@ usage: /* if time is negative - make current overhead more precise */ if (maxms > 0) { /* set last measurement overhead to max */ - measureOverhead = (double)0x7FFFFFFFFFFFFFFFL; + measureOverhead = (double)UWIDE_MAX; } else { maxms = -maxms; } } - if (maxms == -0x7FFFFFFFFFFFFFFFL) { + if (maxms == WIDE_MIN) { maxms = 1000; } if (overhead == -1) { @@ -4157,6 +4167,7 @@ usage: #endif /* start measurement */ + if (maxcnt > 0) while (1) { /* eval single iteration */ count++; @@ -4175,7 +4186,7 @@ usage: } /* force stop immediately */ threshold = 1; - stop = -0x7FFFFFFFFFFFFFFFL; + maxcnt = 0; result = TCL_OK; } @@ -4189,7 +4200,7 @@ usage: Tcl_GetTime(&now); middle = now.sec; middle *= 1000000; middle += now.usec; #endif - if (middle >= stop) { + if (middle >= stop || count >= maxcnt) { break; } @@ -4224,6 +4235,10 @@ usage: if (threshold > 100000) { /* fix for too large threshold */ threshold = 100000; } + /* consider max-count */ + if (threshold > maxcnt - count) { + threshold = maxcnt - count; + } } { @@ -4276,7 +4291,7 @@ usage: /* calculate speed as rate (count) per sec */ if (!middle) middle++; /* +1 ms, just to avoid divide by zero */ - if (count < (0x7FFFFFFFFFFFFFFFL / 1000000)) { + if (count < (WIDE_MAX / 1000000)) { val = (count * 1000000) / middle; if (val < 100000) { if (val < 100) { fmt = "%.3f"; } else diff --git a/generic/tclPort.h b/generic/tclPort.h index 12a60db..9485567 100644 --- a/generic/tclPort.h +++ b/generic/tclPort.h @@ -39,5 +39,8 @@ # define LLONG_MAX (~LLONG_MIN) #endif +#define UWIDE_MAX ((Tcl_WideUInt)-1) +#define WIDE_MAX ((Tcl_WideInt)(UWIDE_MAX >> 1)) +#define WIDE_MIN ((Tcl_WideInt)((Tcl_WideUInt)WIDE_MAX+1)) #endif /* _TCLPORT */ diff --git a/tests/cmdMZ.test b/tests/cmdMZ.test index 08f1ffe..60f6236 100644 --- a/tests/cmdMZ.test +++ b/tests/cmdMZ.test @@ -349,13 +349,19 @@ test cmdMZ-5.7 {Tcl_TimeObjCmd: errors generate right trace} { test cmdMZ-6.1 {Tcl_TimeRateObjCmd: basic format of command} { list [catch {timerate} msg] $msg -} {1 {wrong # args: should be "timerate ?-direct? ?-calibrate? ?-overhead double? command ?time?"}} -test cmdMZ-6.2 {Tcl_TimeRateObjCmd: basic format of command} { +} {1 {wrong # args: should be "timerate ?-direct? ?-calibrate? ?-overhead double? command ?time ?max-count??"}} +test cmdMZ-6.2.1 {Tcl_TimeRateObjCmd: basic format of command} { + list [catch {timerate a b c d} msg] $msg +} {1 {wrong # args: should be "timerate ?-direct? ?-calibrate? ?-overhead double? command ?time ?max-count??"}} +test cmdMZ-6.2.2 {Tcl_TimeRateObjCmd: basic format of command} { list [catch {timerate a b c} msg] $msg -} {1 {wrong # args: should be "timerate ?-direct? ?-calibrate? ?-overhead double? command ?time?"}} -test cmdMZ-6.3 {Tcl_TimeRateObjCmd: basic format of command} { +} {1 {expected integer but got "b"}} +test cmdMZ-6.2.3 {Tcl_TimeRateObjCmd: basic format of command} { list [catch {timerate a b} msg] $msg } {1 {expected integer but got "b"}} +test cmdMZ-6.3 {Tcl_TimeRateObjCmd: basic format of command} { + list [catch {timerate -overhead b {} a b} msg] $msg +} {1 {expected floating-point number but got "b"}} test cmdMZ-6.4 {Tcl_TimeRateObjCmd: compile of script happens even with negative iteration counts} { list [catch {timerate "foreach a {c d e} \{" -12456} msg] $msg } {1 {missing close-brace}} @@ -391,6 +397,19 @@ test cmdMZ-6.8 {Tcl_TimeRateObjCmd: allow (conditional) break from timerate} { [expr {[lindex $m1 4] > 1000}] \ [expr {[lindex $m1 6] < 10}] } {1 1 1 1} +test cmdMZ-6.9 {Tcl_TimeRateObjCmd: max count of iterations} { + set m1 [timerate {} 1000 5]; # max-count wins + set m2 [timerate {after 20} 1 5]; # max-time wins + list [lindex $m1 2] [lindex $m2 2] +} {5 1} +test cmdMZ-6.10 {Tcl_TimeRateObjCmd: huge overhead cause 0us result} { + set m1 [timerate -overhead 1e6 {after 10} 100 1] + list \ + [expr {[lindex $m1 0] == 0.0}] \ + [expr {[lindex $m1 2] == 1}] \ + [expr {[lindex $m1 4] == 1000000}] \ + [expr {[lindex $m1 6] <= 0.001}] +} {1 1 1 1} # The tests for Tcl_WhileObjCmd are in while.test -- cgit v0.12 From 963cceee572b9eb7fca08a7401a07a5263f5dc40 Mon Sep 17 00:00:00 2001 From: sebres Date: Wed, 13 Feb 2019 01:22:07 +0000 Subject: timerate documentation extended --- doc/timerate.n | 11 +++++++---- 1 file changed, 7 insertions(+), 4 deletions(-) diff --git a/doc/timerate.n b/doc/timerate.n index df9a8f7..2380597 100644 --- a/doc/timerate.n +++ b/doc/timerate.n @@ -11,17 +11,20 @@ .SH NAME timerate \- Time-related execution resp. performance measurement of a script .SH SYNOPSIS -\fBtimerate \fIscript\fR \fI?time?\fR +\fBtimerate \fIscript\fR \fI?time ?max-count??\fR .sp -\fBtimerate \fI?-direct?\fR \fI?-overhead double?\fR \fIscript\fR \fI?time?\fR +\fBtimerate \fI?-direct?\fR \fI?-overhead double?\fR \fIscript\fR \fI?time ?max-count??\fR .sp -\fBtimerate \fI?-calibrate?\fR \fI?-direct?\fR \fIscript\fR \fI?time?\fR +\fBtimerate \fI?-calibrate?\fR \fI?-direct?\fR \fIscript\fR \fI?time ?max-count??\fR .BE .SH DESCRIPTION .PP The first and second form will evaluate \fIscript\fR until the interval \fItime\fR given in milliseconds elapses, or for 1000 milliseconds (1 second) -if \fItime\fR is not specified. +if \fItime\fR is not specified. +.sp +If \fImax-count\fR is specified, it imposes a further restriction by the maximal +number of iterations. .sp It will then return a canonical tcl-list of the form .PP -- cgit v0.12