/* -*- Mode: C++; tab-width: 2; indent-tabs-mode: nil; c-basic-offset: 2 -*- */ /* vim:set ts=2 sw=2 sts=2 et cindent: */ /* This Source Code Form is subject to the terms of the Mozilla Public * License, v. 2.0. If a copy of the MPL was not distributed with this * file, You can obtain one at http://mozilla.org/MPL/2.0/. */ // Implement TimeStamp::Now() with QueryPerformanceCounter() controlled with // values of GetTickCount(). // XXX Forcing log to be able to catch issues in the field. Should be removed // before this reaches the Release or even Beta channel. #define FORCE_PR_LOG #include "mozilla/TimeStamp.h" #include "mozilla/Mutex.h" #include "mozilla/Services.h" #include "nsIObserver.h" #include "nsIObserverService.h" #include "nsThreadUtils.h" #include "nsAutoPtr.h" #include #include #include "prlog.h" #include #if defined(PR_LOGGING) // Log module for mozilla::TimeStamp for Windows logging... // // To enable logging (see prlog.h for full details): // // set NSPR_LOG_MODULES=TimeStampWindows:5 // set NSPR_LOG_FILE=nspr.log // // this enables PR_LOG_DEBUG level information and places all output in // the file nspr.log PRLogModuleInfo* timeStampLog = PR_NewLogModule("TimeStampWindows"); #define LOG(x) PR_LOG(timeStampLog, PR_LOG_DEBUG, x) #else #define LOG(x) #endif /* PR_LOGGING */ // Estimate of the smallest duration of time we can measure. static volatile ULONGLONG sResolution; static volatile ULONGLONG sResolutionSigDigs; static const double kNsPerSecd = 1000000000.0; static const LONGLONG kNsPerSec = 1000000000; static const LONGLONG kNsPerMillisec = 1000000; // ---------------------------------------------------------------------------- // Global constants // ---------------------------------------------------------------------------- // After this time we always recalibrate the skew. // // On most platforms QPC and GTC have not quit the same slope, so after some // time the two values will disperse. The 4s calibration interval has been // chosen mostly arbitrarily based on tests. // // Mostly, 4 seconds has been chosen based on the sleep/wake issue - timers // shift after wakeup. I wanted to make the time as reasonably short as // possible to always recalibrate after even a very short standby time (quit // reasonable test case). So, there is a lot of space to prolong it // to say 20 seconds or even more, needs testing in the field, though. // // Value is number of [ms]. static const ULONGLONG kCalibrationInterval = 4000; // On every read of QPC we check the overflow of skew difference doesn't go // over this number of milliseconds. Both timer functions jitter so we have // to have some limit. The value is based on tests. // // Changing kCalibrationInterval influences this limit: prolonging // just kCalibrationInterval means to be more sensitive to threshold overflows. // // How this constant is used (also see CheckCalibration function): // First, adjust the limit linearly to the calibration interval: // LIMIT = (GTC_now - GTC_calib) / kCalibrationInterval // Then, check the skew difference overflow is in this adjusted limit: // ABS((QPC_now - GTC_now) - (QPC_calib - GTC_calib)) - THRESHOLD < LIMIT // // Thresholds are calculated dynamically, see sUnderrunThreshold and // sOverrunThreshold below. // // Value is number of [ms]. static const ULONGLONG kOverflowLimit = 100; // If we are not able to get the value of GTC time increment, use this value // which is the most usual increment. static const DWORD kDefaultTimeIncrement = 156001; // ---------------------------------------------------------------------------- // Global variables, not changing at runtime // ---------------------------------------------------------------------------- /** * The [mt] unit: * * Many values are kept in ticks of the Performance Coutner x 1000, * further just referred as [mt], meaning milli-ticks. * * This is needed to preserve maximum precision of the performance frequency * representation. GetTickCount values in milliseconds are multiplied with * frequency per second. Therefor we need to multiply QPC value by 1000 to * have the same units to allow simple arithmentic with both QPC and GTC. */ #define ms2mt(x) ((x) * sFrequencyPerSec) #define mt2ms(x) ((x) / sFrequencyPerSec) #define mt2ms_d(x) (double(x) / sFrequencyPerSec) // Result of QueryPerformanceFrequency static LONGLONG sFrequencyPerSec = 0; // Lower and upper bound that QueryPerformanceCounter - GetTickCount must not // go under or over when compared to the calibrated QPC - GTC difference (skew) // Values are based on the GetTickCount update interval. // // Schematically, QPC works correctly if ((QPC_now - GTC_now) - // (QPC_calib - GTC_calib)) is in [sUnderrunThreshold, sOverrunThreshold] // interval every time we access them. // // Kept in [mt] static LONGLONG sUnderrunThreshold; static LONGLONG sOverrunThreshold; // ---------------------------------------------------------------------------- // Global lock // ---------------------------------------------------------------------------- // Thread spin count before entering the full wait state for sTimeStampLock. // Inspired by Rob Arnold's work on PRMJ_Now(). static const DWORD kLockSpinCount = 4096; // Common mutex (thanks the relative complexity of the logic, this is better // then using CMPXCHG8B.) // It is protecting the globals bellow. CRITICAL_SECTION sTimeStampLock; // ---------------------------------------------------------------------------- // Globals heavily chaning at runtime, protected with sTimeStampLock mutex // ---------------------------------------------------------------------------- // The calibrated difference between QPC and GTC. // // Kept in [mt] static LONGLONG sSkew = 0; // Keeps the last result we have returned from TickCount64 (bellow). Protects // from roll over and going backward. // // Kept in [ms] static ULONGLONG sLastGTCResult = 0; // Holder of the last result of our main hi-res function. Protects from going // backward. // // Kept in [mt] static ULONGLONG sLastResult = 0; // Time of the last performed calibration. // // Kept in [ms] static ULONGLONG sLastCalibrated; // After we have detected a run out of bounderies set this to true. This // then disallows use of QPC result for the hi-res timer. static bool sFallBackToGTC = false; // Set to true to force recalibration on QPC read. This is generally set after // system wake up, during which skew can change a lot. static bool sForceRecalibrate = false; namespace mozilla { static ULONGLONG CalibratedPerformanceCounter(); // ---------------------------------------------------------------------------- // Critical Section helper class // ---------------------------------------------------------------------------- class AutoCriticalSection { public: AutoCriticalSection(LPCRITICAL_SECTION section) : mSection(section) { ::EnterCriticalSection(mSection); } ~AutoCriticalSection() { ::LeaveCriticalSection(mSection); } private: LPCRITICAL_SECTION mSection; }; // ---------------------------------------------------------------------------- // System standby and wakeup status observer. Needed to ignore skew jump after // the system has been woken up, happens mostly on XP. // ---------------------------------------------------------------------------- class StandbyObserver : public nsIObserver { NS_DECL_ISUPPORTS NS_DECL_NSIOBSERVER public: StandbyObserver() { LOG(("TimeStamp: StandByObserver::StandByObserver()")); } ~StandbyObserver() { LOG(("TimeStamp: StandByObserver::~StandByObserver()")); } static inline void Ensure() { if (sInitialized) return; // Not available to init on other then the main thread since using // the ObserverService. if (!NS_IsMainThread()) return; nsCOMPtr obs = services::GetObserverService(); if (!obs) return; // Too soon... sInitialized = true; nsRefPtr observer = new StandbyObserver(); obs->AddObserver(observer, "wake_notification", false); // There is no need to remove the observer, observer service is the only // referer and we don't hold reference back to the observer service. } private: static bool sInitialized; }; NS_IMPL_THREADSAFE_ISUPPORTS1(StandbyObserver, nsIObserver) bool StandbyObserver::sInitialized = false; NS_IMETHODIMP StandbyObserver::Observe(nsISupports *subject, const char *topic, const PRUnichar *data) { AutoCriticalSection lock(&sTimeStampLock); // Clear the potentiall fallback flag now and try using // QPC again after wake up. sFallBackToGTC = false; sForceRecalibrate = true; LOG(("TimeStamp: system has woken up, reset GTC fallback")); return NS_OK; } // ---------------------------------------------------------------------------- // The timer core implementation // ---------------------------------------------------------------------------- static void InitThresholds() { DWORD timeAdjustment = 0, timeIncrement = 0; BOOL timeAdjustmentDisabled; GetSystemTimeAdjustment(&timeAdjustment, &timeIncrement, &timeAdjustmentDisabled); if (!timeIncrement) timeIncrement = kDefaultTimeIncrement; // Ceiling to a millisecond // Example values: 156001, 210000 DWORD timeIncrementCeil = timeIncrement; // Don't want to round up if already rounded, values will be: 156000, 209999 timeIncrementCeil -= 1; // Convert to ms, values will be: 15, 20 timeIncrementCeil /= 10000; // Round up, values will be: 16, 21 timeIncrementCeil += 1; // Convert back to 100ns, values will be: 160000, 210000 timeIncrementCeil *= 10000; // How many milli-ticks has the interval LONGLONG ticksPerGetTickCountResolution = (int64_t(timeIncrement) * sFrequencyPerSec) / 10000LL; // How many milli-ticks has the interval rounded up LONGLONG ticksPerGetTickCountResolutionCeiling = (int64_t(timeIncrementCeil) * sFrequencyPerSec) / 10000LL; // I observed differences about 2 times of the GTC resolution. GTC may // jump by 32 ms in two steps, therefor use the ceiling value. sUnderrunThreshold = LONGLONG((-2) * ticksPerGetTickCountResolutionCeiling); // QPC should go no further then 2 * GTC resolution sOverrunThreshold = LONGLONG((+2) * ticksPerGetTickCountResolution); } static void InitResolution() { // 10 total trials is arbitrary: what we're trying to avoid by // looping is getting unlucky and being interrupted by a context // switch or signal, or being bitten by paging/cache effects ULONGLONG minres = ~0ULL; int loops = 10; do { ULONGLONG start = CalibratedPerformanceCounter(); ULONGLONG end = CalibratedPerformanceCounter(); ULONGLONG candidate = (end - start); if (candidate < minres) minres = candidate; } while (--loops && minres); if (0 == minres) { minres = 1; } // Converting minres that is in [mt] to nanosecods, multiplicating // the argument to preserve resolution. ULONGLONG result = mt2ms(minres * kNsPerMillisec); if (0 == result) { result = 1; } sResolution = result; // find the number of significant digits in mResolution, for the // sake of ToSecondsSigDigits() ULONGLONG sigDigs; for (sigDigs = 1; !(sigDigs == result || 10*sigDigs > result); sigDigs *= 10); sResolutionSigDigs = sigDigs; } // Function protecting GetTickCount result from rolling over, result is in [ms] // @param gtc // Result of GetTickCount(). Passing it as an arg lets us call it out // of the common mutex. static inline ULONGLONG TickCount64(DWORD now) { ULONGLONG lastResultHiPart = sLastGTCResult & (~0ULL << 32); ULONGLONG result = lastResultHiPart | ULONGLONG(now); // It may happen that when accessing GTC on multiple threads the results // may differ (GTC value may be lower due to running before the others // right around the overflow moment). That falsely shifts the high part. // Easiest solution is to check for a significant difference. if (sLastGTCResult > result) { if ((sLastGTCResult - result) > (1ULL << 31)) result += 1ULL << 32; else result = sLastGTCResult; } sLastGTCResult = result; return result; } // Result is in [mt] static inline ULONGLONG PerformanceCounter() { LARGE_INTEGER pc; ::QueryPerformanceCounter(&pc); return pc.QuadPart * 1000ULL; } // Called when we detect a larger deviation of QPC to disable it. static inline void RecordFlaw() { sFallBackToGTC = true; LOG(("TimeStamp: falling back to GTC :(")); #if 0 // This code has been disabled, because we: // 0. InitResolution must not be called under the lock (would reenter) while // we shouldn't release it here just to allow it // 1. may return back to using QPC after system wake up // 2. InitResolution for GTC will probably return 0 anyway (increments // only every 15 or 16 ms.) // // There is no need to drop sFrequencyPerSec to 1, result of TickCount64 // is multiplied and later divided with sFrequencyPerSec. Changing it // here may introduce sync problems. Syncing access to sFrequencyPerSec // is overkill. Drawback is we loose some bits from the upper bound of // the 64 bits timer value, usualy up to 7, it means the app cannot run // more then some 4'000'000 years :) InitResolution(); #endif } // Check the current skew is in bounderies and occasionally recalculate it. // Return true if QPC is OK to use, return false to use GTC only. // // Arguments: // overflow - the calculated overflow out of the bounderies for skew difference // qpc - current value of QueryPerformanceCounter // gtc - current value of GetTickCount, more actual according possible system // sleep between read of QPC and GTC static inline bool CheckCalibration(LONGLONG overflow, ULONGLONG qpc, ULONGLONG gtc) { if (sFallBackToGTC) { // We are forbidden to use QPC return false; } ULONGLONG sinceLastCalibration = gtc - sLastCalibrated; if (overflow && !sForceRecalibrate) { // Calculate trend of the overflow to correspond to the calibration // interval, we may get here long after the last calibration because we // either didn't read the hi-res function or the system was suspended. ULONGLONG trend = LONGLONG(overflow * (double(kCalibrationInterval) / sinceLastCalibration)); LOG(("TimeStamp: calibration after %llus with overflow %1.4fms" ", adjusted trend per calibration interval is %1.4fms", sinceLastCalibration / 1000, mt2ms_d(overflow), mt2ms_d(trend))); if (trend > ms2mt(kOverflowLimit)) { // This sets sFallBackToGTC, we have detected // an unreliability of QPC, stop using it. RecordFlaw(); return false; } } if (sinceLastCalibration > kCalibrationInterval || sForceRecalibrate) { // Recalculate the skew now sSkew = qpc - ms2mt(gtc); sLastCalibrated = gtc; LOG(("TimeStamp: new skew is %1.2fms (force:%d)", mt2ms_d(sSkew), sForceRecalibrate)); sForceRecalibrate = false; } return true; } // The main function. Result is in [mt] ensuring to not go back and be mostly // reliable with highest possible resolution. static ULONGLONG CalibratedPerformanceCounter() { // XXX This is using ObserverService, cannot instantiate in the static // startup, really needs a better initation code here. StandbyObserver::Ensure(); // Don't hold the lock over call to QueryPerformanceCounter, since it is // the largest bottleneck, let threads read the value concurently to have // possibly a better performance. ULONGLONG qpc = PerformanceCounter(); DWORD gtcw = GetTickCount(); AutoCriticalSection lock(&sTimeStampLock); // Rollover protection ULONGLONG gtc = TickCount64(gtcw); LONGLONG diff = qpc - ms2mt(gtc) - sSkew; LONGLONG overflow = 0; if (diff < sUnderrunThreshold) { overflow = sUnderrunThreshold - diff; } else if (diff > sOverrunThreshold) { overflow = diff - sOverrunThreshold; } ULONGLONG result = qpc; if (!CheckCalibration(overflow, qpc, gtc)) { // We are back on GTC, QPC has been observed unreliable result = ms2mt(gtc) + sSkew; } #if 0 LOG(("TimeStamp: result = %1.2fms, diff = %1.4fms", mt2ms_d(result), mt2ms_d(diff))); #endif if (result > sLastResult) sLastResult = result; return sLastResult; } // ---------------------------------------------------------------------------- // TimeDuration and TimeStamp implementation // ---------------------------------------------------------------------------- double TimeDuration::ToSeconds() const { // Converting before arithmetic avoids blocked store forward return double(mValue) / (double(sFrequencyPerSec) * 1000.0); } double TimeDuration::ToSecondsSigDigits() const { AutoCriticalSection lock(&sTimeStampLock); // don't report a value < mResolution ... LONGLONG resolution = sResolution; LONGLONG resolutionSigDigs = sResolutionSigDigs; LONGLONG valueSigDigs = resolution * (mValue / resolution); // and chop off insignificant digits valueSigDigs = resolutionSigDigs * (valueSigDigs / resolutionSigDigs); return double(valueSigDigs) / kNsPerSecd; } TimeDuration TimeDuration::FromMilliseconds(double aMilliseconds) { return TimeDuration::FromTicks(int64_t(ms2mt(aMilliseconds))); } TimeDuration TimeDuration::Resolution() { AutoCriticalSection lock(&sTimeStampLock); return TimeDuration::FromTicks(int64_t(sResolution)); } struct TimeStampInitialization { TimeStampInitialization() { TimeStamp::Startup(); } ~TimeStampInitialization() { TimeStamp::Shutdown(); } }; static TimeStampInitialization initOnce; nsresult TimeStamp::Startup() { // Decide which implementation to use for the high-performance timer. InitializeCriticalSectionAndSpinCount(&sTimeStampLock, kLockSpinCount); LARGE_INTEGER freq; BOOL QPCAvailable = ::QueryPerformanceFrequency(&freq); if (!QPCAvailable) { // No Performance Counter. Fall back to use GetTickCount. sFrequencyPerSec = 1; sFallBackToGTC = true; InitResolution(); LOG(("TimeStamp: using GetTickCount")); return NS_OK; } sFrequencyPerSec = freq.QuadPart; ULONGLONG qpc = PerformanceCounter(); sLastCalibrated = TickCount64(::GetTickCount()); sSkew = qpc - ms2mt(sLastCalibrated); InitThresholds(); InitResolution(); LOG(("TimeStamp: initial skew is %1.2fms", mt2ms_d(sSkew))); return NS_OK; } void TimeStamp::Shutdown() { DeleteCriticalSection(&sTimeStampLock); } TimeStamp TimeStamp::Now() { return TimeStamp(uint64_t(CalibratedPerformanceCounter())); } } // namespace mozilla