time_win_unittest.cc 15 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426
  1. // Copyright (c) 2012 The Chromium Authors. All rights reserved.
  2. // Use of this source code is governed by a BSD-style license that can be
  3. // found in the LICENSE file.
  4. #include <windows.h>
  5. #include <mmsystem.h>
  6. #include <process.h>
  7. #include <stdint.h>
  8. #include <windows.foundation.h>
  9. #include <algorithm>
  10. #include <cmath>
  11. #include <limits>
  12. #include <vector>
  13. #include "base/strings/string_piece.h"
  14. #include "base/threading/platform_thread.h"
  15. #include "base/time/time.h"
  16. #include "base/win/registry.h"
  17. #include "build/build_config.h"
  18. #include "testing/gtest/include/gtest/gtest.h"
  19. namespace base {
  20. namespace {
  21. // For TimeDelta::ConstexprInitialization
  22. constexpr int kExpectedDeltaInMilliseconds = 10;
  23. constexpr TimeDelta kConstexprTimeDelta =
  24. Milliseconds(kExpectedDeltaInMilliseconds);
  25. class MockTimeTicks : public TimeTicks {
  26. public:
  27. static DWORD Ticker() {
  28. return static_cast<int>(InterlockedIncrement(&ticker_));
  29. }
  30. static void InstallTicker() {
  31. old_tick_function_ = SetMockTickFunction(&Ticker);
  32. ticker_ = -5;
  33. }
  34. static void UninstallTicker() { SetMockTickFunction(old_tick_function_); }
  35. private:
  36. static volatile LONG ticker_;
  37. static TickFunctionType old_tick_function_;
  38. };
  39. volatile LONG MockTimeTicks::ticker_;
  40. MockTimeTicks::TickFunctionType MockTimeTicks::old_tick_function_;
  41. HANDLE g_rollover_test_start;
  42. unsigned __stdcall RolloverTestThreadMain(void* param) {
  43. int64_t counter = reinterpret_cast<int64_t>(param);
  44. DWORD rv = WaitForSingleObject(g_rollover_test_start, INFINITE);
  45. EXPECT_EQ(rv, WAIT_OBJECT_0);
  46. TimeTicks last = TimeTicks::Now();
  47. for (int index = 0; index < counter; index++) {
  48. TimeTicks now = TimeTicks::Now();
  49. int64_t milliseconds = (now - last).InMilliseconds();
  50. // This is a tight loop; we could have looped faster than our
  51. // measurements, so the time might be 0 millis.
  52. EXPECT_GE(milliseconds, 0);
  53. EXPECT_LT(milliseconds, 250);
  54. last = now;
  55. }
  56. return 0;
  57. }
  58. #if defined(_M_ARM64) && defined(__clang__)
  59. #define ReadCycleCounter() _ReadStatusReg(ARM64_PMCCNTR_EL0)
  60. #else
  61. #define ReadCycleCounter() __rdtsc()
  62. #endif
  63. // Measure the performance of the CPU cycle counter so that we can compare it to
  64. // the overhead of QueryPerformanceCounter. A hard-coded frequency is used
  65. // because we don't care about the accuracy of the results, we just need to do
  66. // the work. The amount of work is not exactly the same as in TimeTicks::Now
  67. // (some steps are skipped) but that doesn't seem to materially affect the
  68. // results.
  69. TimeTicks GetTSC() {
  70. // Using a fake cycle counter frequency for test purposes.
  71. return TimeTicks() + Microseconds(ReadCycleCounter() *
  72. Time::kMicrosecondsPerSecond / 10000000);
  73. }
  74. } // namespace
  75. // This test spawns many threads, and can occasionally fail due to resource
  76. // exhaustion in the presence of ASan.
  77. #if defined(ADDRESS_SANITIZER)
  78. #define MAYBE_WinRollover DISABLED_WinRollover
  79. #else
  80. #define MAYBE_WinRollover WinRollover
  81. #endif
  82. TEST(TimeTicks, MAYBE_WinRollover) {
  83. // The internal counter rolls over at ~49days. We'll use a mock
  84. // timer to test this case.
  85. // Basic test algorithm:
  86. // 1) Set clock to rollover - N
  87. // 2) Create N threads
  88. // 3) Start the threads
  89. // 4) Each thread loops through TimeTicks() N times
  90. // 5) Each thread verifies integrity of result.
  91. const int kThreads = 8;
  92. // Use int64_t so we can cast into a void* without a compiler warning.
  93. const int64_t kChecks = 10;
  94. // It takes a lot of iterations to reproduce the bug!
  95. // (See bug 1081395)
  96. for (int loop = 0; loop < 4096; loop++) {
  97. // Setup
  98. MockTimeTicks::InstallTicker();
  99. g_rollover_test_start = CreateEvent(0, TRUE, FALSE, 0);
  100. HANDLE threads[kThreads];
  101. for (int index = 0; index < kThreads; index++) {
  102. void* argument = reinterpret_cast<void*>(kChecks);
  103. unsigned thread_id;
  104. threads[index] = reinterpret_cast<HANDLE>(_beginthreadex(
  105. NULL, 0, RolloverTestThreadMain, argument, 0, &thread_id));
  106. EXPECT_NE((HANDLE)NULL, threads[index]);
  107. }
  108. // Start!
  109. SetEvent(g_rollover_test_start);
  110. // Wait for threads to finish
  111. for (int index = 0; index < kThreads; index++) {
  112. DWORD rv = WaitForSingleObject(threads[index], INFINITE);
  113. EXPECT_EQ(rv, WAIT_OBJECT_0);
  114. // Since using _beginthreadex() (as opposed to _beginthread),
  115. // an explicit CloseHandle() is supposed to be called.
  116. CloseHandle(threads[index]);
  117. }
  118. CloseHandle(g_rollover_test_start);
  119. // Teardown
  120. MockTimeTicks::UninstallTicker();
  121. }
  122. }
  123. TEST(TimeTicks, SubMillisecondTimers) {
  124. // IsHighResolution() is false on some systems. Since the product still works
  125. // even if it's false, it makes this entire test questionable.
  126. if (!TimeTicks::IsHighResolution())
  127. return;
  128. // Run kRetries attempts to see a sub-millisecond timer.
  129. constexpr int kRetries = 1000;
  130. for (int index = 0; index < kRetries; index++) {
  131. const TimeTicks start_time = TimeTicks::Now();
  132. TimeDelta delta;
  133. // Spin until the clock has detected a change.
  134. do {
  135. delta = TimeTicks::Now() - start_time;
  136. } while (delta.is_zero());
  137. if (!delta.InMilliseconds())
  138. return;
  139. }
  140. ADD_FAILURE() << "Never saw a sub-millisecond timer.";
  141. }
  142. TEST(TimeTicks, TimeGetTimeCaps) {
  143. // Test some basic assumptions that we expect about how timeGetDevCaps works.
  144. TIMECAPS caps;
  145. MMRESULT status = timeGetDevCaps(&caps, sizeof(caps));
  146. ASSERT_EQ(static_cast<MMRESULT>(MMSYSERR_NOERROR), status);
  147. EXPECT_GE(static_cast<int>(caps.wPeriodMin), 1);
  148. EXPECT_GT(static_cast<int>(caps.wPeriodMax), 1);
  149. EXPECT_GE(static_cast<int>(caps.wPeriodMin), 1);
  150. EXPECT_GT(static_cast<int>(caps.wPeriodMax), 1);
  151. printf("timeGetTime range is %d to %dms\n", caps.wPeriodMin, caps.wPeriodMax);
  152. }
  153. TEST(TimeTicks, QueryPerformanceFrequency) {
  154. // Test some basic assumptions that we expect about QPC.
  155. LARGE_INTEGER frequency;
  156. BOOL rv = QueryPerformanceFrequency(&frequency);
  157. EXPECT_EQ(TRUE, rv);
  158. EXPECT_GT(frequency.QuadPart, 1000000); // Expect at least 1MHz
  159. printf("QueryPerformanceFrequency is %5.2fMHz\n",
  160. frequency.QuadPart / 1000000.0);
  161. }
  162. TEST(TimeTicks, TimerPerformance) {
  163. // Verify that various timer mechanisms can always complete quickly.
  164. // Note: This is a somewhat arbitrary test.
  165. const int kLoops = 500000;
  166. typedef TimeTicks (*TestFunc)();
  167. struct TestCase {
  168. TestFunc func;
  169. const char* description;
  170. };
  171. // Cheating a bit here: assumes sizeof(TimeTicks) == sizeof(Time)
  172. // in order to create a single test case list.
  173. static_assert(sizeof(TimeTicks) == sizeof(Time),
  174. "TimeTicks and Time must be the same size");
  175. std::vector<TestCase> cases;
  176. cases.push_back({reinterpret_cast<TestFunc>(&Time::Now), "Time::Now"});
  177. cases.push_back({&TimeTicks::Now, "TimeTicks::Now"});
  178. cases.push_back({&GetTSC, "CPUCycleCounter"});
  179. if (ThreadTicks::IsSupported()) {
  180. ThreadTicks::WaitUntilInitialized();
  181. cases.push_back(
  182. {reinterpret_cast<TestFunc>(&ThreadTicks::Now), "ThreadTicks::Now"});
  183. }
  184. // Warm up the CPU to its full clock rate so that we get accurate timing
  185. // information.
  186. DWORD start_tick = GetTickCount();
  187. const DWORD kWarmupMs = 50;
  188. for (;;) {
  189. DWORD elapsed = GetTickCount() - start_tick;
  190. if (elapsed > kWarmupMs)
  191. break;
  192. }
  193. for (const auto& test_case : cases) {
  194. TimeTicks start = TimeTicks::Now();
  195. for (int index = 0; index < kLoops; index++)
  196. test_case.func();
  197. TimeTicks stop = TimeTicks::Now();
  198. // Turning off the check for acceptible delays. Without this check,
  199. // the test really doesn't do much other than measure. But the
  200. // measurements are still useful for testing timers on various platforms.
  201. // The reason to remove the check is because the tests run on many
  202. // buildbots, some of which are VMs. These machines can run horribly
  203. // slow, and there is really no value for checking against a max timer.
  204. // const int kMaxTime = 35; // Maximum acceptible milliseconds for test.
  205. // EXPECT_LT((stop - start).InMilliseconds(), kMaxTime);
  206. printf("%s: %1.2fus per call\n", test_case.description,
  207. (stop - start).InMillisecondsF() * 1000 / kLoops);
  208. }
  209. }
  210. #if !defined(ARCH_CPU_ARM64)
  211. // This test is disabled on Windows ARM64 systems because TSCTicksPerSecond is
  212. // only used in Chromium for QueryThreadCycleTime, and QueryThreadCycleTime
  213. // doesn't use a constant-rate timer on ARM64.
  214. TEST(TimeTicks, TSCTicksPerSecond) {
  215. if (time_internal::HasConstantRateTSC()) {
  216. ThreadTicks::WaitUntilInitialized();
  217. // Read the CPU frequency from the registry.
  218. base::win::RegKey processor_key(
  219. HKEY_LOCAL_MACHINE,
  220. L"Hardware\\Description\\System\\CentralProcessor\\0", KEY_QUERY_VALUE);
  221. ASSERT_TRUE(processor_key.Valid());
  222. DWORD processor_mhz_from_registry;
  223. ASSERT_EQ(ERROR_SUCCESS,
  224. processor_key.ReadValueDW(L"~MHz", &processor_mhz_from_registry));
  225. // Expect the measured TSC frequency to be similar to the processor
  226. // frequency from the registry (0.5% error).
  227. double tsc_mhz_measured = time_internal::TSCTicksPerSecond() / 1e6;
  228. EXPECT_NEAR(tsc_mhz_measured, processor_mhz_from_registry,
  229. 0.005 * processor_mhz_from_registry);
  230. }
  231. }
  232. #endif
  233. TEST(TimeTicks, FromQPCValue) {
  234. if (!TimeTicks::IsHighResolution())
  235. return;
  236. LARGE_INTEGER frequency;
  237. ASSERT_TRUE(QueryPerformanceFrequency(&frequency));
  238. const int64_t ticks_per_second = frequency.QuadPart;
  239. ASSERT_GT(ticks_per_second, 0);
  240. // Generate the tick values to convert, advancing the tick count by varying
  241. // amounts. These values will ensure that both the fast and overflow-safe
  242. // conversion logic in FromQPCValue() is tested, and across the entire range
  243. // of possible QPC tick values.
  244. std::vector<int64_t> test_cases;
  245. test_cases.push_back(0);
  246. // Build the test cases.
  247. {
  248. const int kNumAdvancements = 100;
  249. int64_t ticks = 0;
  250. int64_t ticks_increment = 10;
  251. for (int i = 0; i < kNumAdvancements; ++i) {
  252. test_cases.push_back(ticks);
  253. ticks += ticks_increment;
  254. ticks_increment = ticks_increment * 6 / 5;
  255. }
  256. test_cases.push_back(Time::kQPCOverflowThreshold - 1);
  257. test_cases.push_back(Time::kQPCOverflowThreshold);
  258. test_cases.push_back(Time::kQPCOverflowThreshold + 1);
  259. ticks = Time::kQPCOverflowThreshold + 10;
  260. ticks_increment = 10;
  261. for (int i = 0; i < kNumAdvancements; ++i) {
  262. test_cases.push_back(ticks);
  263. ticks += ticks_increment;
  264. ticks_increment = ticks_increment * 6 / 5;
  265. }
  266. test_cases.push_back(std::numeric_limits<int64_t>::max());
  267. }
  268. // Test that the conversions using FromQPCValue() match those computed here
  269. // using simple floating-point arithmetic. The floating-point math provides
  270. // enough precision for all reasonable values to confirm that the
  271. // implementation is correct to the microsecond, and for "very large" values
  272. // it confirms that the answer is very close to correct.
  273. for (int64_t ticks : test_cases) {
  274. const double expected_microseconds_since_origin =
  275. (static_cast<double>(ticks) * Time::kMicrosecondsPerSecond) /
  276. ticks_per_second;
  277. const TimeTicks converted_value = TimeTicks::FromQPCValue(ticks);
  278. const double converted_microseconds_since_origin =
  279. (converted_value - TimeTicks()).InMicrosecondsF();
  280. // When we test with very large numbers we end up in a range where adjacent
  281. // double values are far apart - 512.0 apart in one test failure. In that
  282. // situation it makes no sense for our epsilon to be 1.0 - it should be
  283. // the difference between adjacent doubles.
  284. double epsilon = nextafter(expected_microseconds_since_origin, INFINITY) -
  285. expected_microseconds_since_origin;
  286. // Epsilon must be at least 1.0 because converted_microseconds_since_origin
  287. // comes from an integral value, and expected_microseconds_since_origin is
  288. // a double that is expected to be up to 0.999 larger. In addition, due to
  289. // multiple roundings in the double calculation the actual error can be
  290. // slightly larger than 1.0, even when the converted value is perfect. This
  291. // epsilon value was chosen because it is slightly larger than the error
  292. // seen in a test failure caused by the double rounding.
  293. epsilon = std::max(epsilon, 1.002);
  294. EXPECT_NEAR(expected_microseconds_since_origin,
  295. converted_microseconds_since_origin, epsilon)
  296. << "ticks=" << ticks << ", to be converted via logic path: "
  297. << (ticks < Time::kQPCOverflowThreshold ? "FAST" : "SAFE");
  298. }
  299. }
  300. TEST(TimeDelta, ConstexprInitialization) {
  301. // Make sure that TimeDelta works around crbug.com/635974
  302. EXPECT_EQ(kExpectedDeltaInMilliseconds, kConstexprTimeDelta.InMilliseconds());
  303. }
  304. TEST(TimeDelta, FromFileTime) {
  305. FILETIME ft;
  306. ft.dwLowDateTime = 1001;
  307. ft.dwHighDateTime = 0;
  308. // 100100 ns ~= 100 us.
  309. EXPECT_EQ(Microseconds(100), TimeDelta::FromFileTime(ft));
  310. ft.dwLowDateTime = 0;
  311. ft.dwHighDateTime = 1;
  312. // 2^32 * 100 ns ~= 2^32 * 10 us.
  313. EXPECT_EQ(Microseconds((1ull << 32) / 10), TimeDelta::FromFileTime(ft));
  314. }
  315. TEST(TimeDelta, FromWinrtDateTime) {
  316. ABI::Windows::Foundation::DateTime dt;
  317. dt.UniversalTime = 0;
  318. // 0 UniversalTime = no delta since epoch.
  319. EXPECT_EQ(TimeDelta(), TimeDelta::FromWinrtDateTime(dt));
  320. dt.UniversalTime = 101;
  321. // 101 * 100 ns ~= 10.1 microseconds.
  322. EXPECT_EQ(Microseconds(10.1), TimeDelta::FromWinrtDateTime(dt));
  323. }
  324. TEST(TimeDelta, ToWinrtDateTime) {
  325. auto time_delta = Seconds(0);
  326. // No delta since epoch = 0 DateTime.
  327. EXPECT_EQ(0, time_delta.ToWinrtDateTime().UniversalTime);
  328. time_delta = Microseconds(10);
  329. // 10 microseconds = 100 * 100 ns.
  330. EXPECT_EQ(100, time_delta.ToWinrtDateTime().UniversalTime);
  331. }
  332. TEST(HighResolutionTimer, GetUsage) {
  333. Time::ResetHighResolutionTimerUsage();
  334. // 0% usage since the timer isn't activated regardless of how much time has
  335. // elapsed.
  336. EXPECT_EQ(0.0, Time::GetHighResolutionTimerUsage());
  337. Sleep(10);
  338. EXPECT_EQ(0.0, Time::GetHighResolutionTimerUsage());
  339. Time::ActivateHighResolutionTimer(true);
  340. Time::ResetHighResolutionTimerUsage();
  341. Sleep(20);
  342. // 100% usage since the timer has been activated entire time.
  343. EXPECT_EQ(100.0, Time::GetHighResolutionTimerUsage());
  344. Time::ActivateHighResolutionTimer(false);
  345. Sleep(20);
  346. double usage1 = Time::GetHighResolutionTimerUsage();
  347. // usage1 should be about 50%.
  348. EXPECT_LT(usage1, 100.0);
  349. EXPECT_GT(usage1, 0.0);
  350. Time::ActivateHighResolutionTimer(true);
  351. Sleep(10);
  352. Time::ActivateHighResolutionTimer(false);
  353. double usage2 = Time::GetHighResolutionTimerUsage();
  354. // usage2 should be about 60%.
  355. EXPECT_LT(usage2, 100.0);
  356. EXPECT_GT(usage2, usage1);
  357. Time::ResetHighResolutionTimerUsage();
  358. EXPECT_EQ(0.0, Time::GetHighResolutionTimerUsage());
  359. }
  360. } // namespace base