[Windows] One TimeTicks clock: efficient/reliable high-res, with low-res fallback.

base/time/time_win_unittest.cc

 // Copyright (c) 2012 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include <windows.h>
 #include <mmsystem.h>
 #include <process.h>
 
+#include <cmath>
+
 #include "base/threading/platform_thread.h"
 #include "base/time/time.h"
 #include "testing/gtest/include/gtest/gtest.h"
 
 using base::Time;
 using base::TimeDelta;
 using base::TimeTicks;
 
 namespace {
 
@@ skipping 88 matching lines @@
     CloseHandle(g_rollover_test_start);
 
     // Teardown
     MockTimeTicks::UninstallTicker();
   }
 }
 
 TEST(TimeTicks, SubMillisecondTimers) {
   // HighResNow doesn't work on some systems.  Since the product still works
   // even if it doesn't work, it makes this entire test questionable.
-  if (!TimeTicks::IsHighResClockWorking())
+  if (!TimeTicks::IsHighResolution())
     return;
 
   const int kRetries = 1000;
   bool saw_submillisecond_timer = false;
 
   // Run kRetries attempts to see a sub-millisecond timer.
   for (int index = 0; index < kRetries; index++) {
     TimeTicks last_time = TimeTicks::HighResNow();
     TimeDelta delta;
     // Spin until the clock has detected a change.
@@ skipping 48 matching lines @@
     TestFunc func;
     const char *description;
   };
   // Cheating a bit here:  assumes sizeof(TimeTicks) == sizeof(Time)
   // in order to create a single test case list.
   COMPILE_ASSERT(sizeof(TimeTicks) == sizeof(Time),
                  test_only_works_with_same_sizes);
   TestCase cases[] = {
     { reinterpret_cast<TestFunc>(Time::Now), "Time::Now" },
     { TimeTicks::Now, "TimeTicks::Now" },
-    { TimeTicks::HighResNow, "TimeTicks::HighResNow" },
+    { TimeTicks::NowFromSystemTraceTime, "TimeTicks::NowFromSystemTraceTime" },
     { NULL, "" }
   };
 
   int test_case = 0;
   while (cases[test_case].func) {
     TimeTicks start = TimeTicks::HighResNow();
     for (int index = 0; index < kLoops; index++)
       cases[test_case].func();
     TimeTicks stop = TimeTicks::HighResNow();
     // Turning off the check for acceptible delays.  Without this check,
     // the test really doesn't do much other than measure.  But the
     // measurements are still useful for testing timers on various platforms.
     // The reason to remove the check is because the tests run on many
     // buildbots, some of which are VMs.  These machines can run horribly
     // slow, and there is really no value for checking against a max timer.
     //const int kMaxTime = 35;  // Maximum acceptible milliseconds for test.
     //EXPECT_LT((stop - start).InMilliseconds(), kMaxTime);
     printf("%s: %1.2fus per call\n", cases[test_case].description,
       (stop - start).InMillisecondsF() * 1000 / kLoops);
     test_case++;
   }
 }
 
-// http://crbug.com/396384
-TEST(TimeTicks, DISABLED_Drift) {
-  // If QPC is disabled, this isn't measuring anything.
-  if (!TimeTicks::IsHighResClockWorking())
+TEST(TimeTicks, FromQPCValue) {
+  if (!TimeTicks::IsHighResolution())
     return;
 
   const int kIterations = 100;
-  int64 total_drift = 0;
+
+  LARGE_INTEGER frequency;
+  ASSERT_TRUE(QueryPerformanceFrequency(&frequency));
+  const int64 ticks_per_second = frequency.QuadPart;
+  ASSERT_GT(ticks_per_second, 0);
+
+  // Tolerance between the TimeTicks values computed by this test versus those
+  // computed using FromQCPValue().  On most systems, this will be 1us.
+  // However, when the QPC frequency is less than 1 MHz, the tolerance needs to
+  // be greater.
+  const int64 tolerance_us = static_cast<int64>(
+      std::ceil((1.0 / ticks_per_second) * Time::kMicrosecondsPerSecond));
+
+  int64 ticks_increment = 10;  // Changes with each loop iteration.
+  LARGE_INTEGER start_ticks;
+  // The start value is chosen such that part of the test will make
+  // FromQPCValue() use the faster conversion logic, and part will make it use
+  // the overflow-safe logic.
+  start_ticks.QuadPart =
+      Time::kQPCOverflowThreshold - (ticks_increment * kIterations / 2);
+  LARGE_INTEGER ticks = start_ticks;
+  TimeTicks start_time = TimeTicks() + TimeDelta::FromMicroseconds(
+      start_ticks.QuadPart * Time::kMicrosecondsPerSecond / ticks_per_second);
 
   for (int i = 0; i < kIterations; ++i) {

[brianderson, 2015/01/09 00:02:02]

I don't think this for loop tests the 3 corner cases of
QPCOverflowThreshold+(-1,0,+1) that the old test had. Maybe have a vector of
test cases and push those on at the end?

[miu, 2015/01/14 02:12:24]

Done.

-    int64 drift_microseconds = TimeTicks::GetQPCDriftMicroseconds();
+    ticks.QuadPart += ticks_increment;
+    ticks_increment = ticks_increment * 6 / 5;
 
-    // Make sure the drift never exceeds our limit.
-    EXPECT_LT(drift_microseconds, 50000);
-
-    // Sleep for a few milliseconds (note that it means 1000 microseconds).
-    // If we check the drift too frequently, it's going to increase
-    // monotonically, making our measurement less realistic.
-    base::PlatformThread::Sleep(
-        base::TimeDelta::FromMilliseconds((i % 2 == 0) ? 1 : 2));
-
-    total_drift += drift_microseconds;
+    const int64 ticks_advanced = ticks.QuadPart - start_ticks.QuadPart;
+    const TimeTicks expected_value = start_time +

[brianderson, 2015/01/09 00:02:02]

This test rounds to microseconds twice (here and in the calculation of
start_time), whereas the real implementation only rounds once. Is that why the
tolerance_us is needed? If so, can you add a comment because it's not clear why
a tolerance is needed.

Alternatively, find a way to get rid of the tolerance. Two options:
1) It would be nice if base had a BigInt of some sort, but I could only find
ones outside of base. @hendrikw mentions there's a __int128 on Windows, can we
use that?
2) Can we rely on the fact that subtracting to "de-overflow" an overflowed
multiplication of an unsigned value still results in the correct value? As a
sanity check:

TEST(TimeTicks, SubtractToUnoverflowAfterMultiplyOverflowIsOkay) {
  uint8 a8 = 3;
  uint32 a32 = 3;

  for (uint8 b8 = 255u / a8; b8 !=0; b8++) {
    uint32 b32 = b8;

    for (uint8 c8 = (a32 * b32) - 255; c8 != 0; c8++) {
      uint32 c32 = c8;

      // m8 will overflow, but m32 will not.
      uint8 m8 = a8 * b8;
      uint32 m32 = a32 * b32;

      // Verifies that there was overflow.
      EXPECT_NE(uint32(m8), m32);
      EXPECT_EQ(m8, uint8(m32));

      // Only checks cases where subtracting will deoverflow.
      if (m32 - c32 <= 255u) {
        // Verify that "de overflowing" works.
        EXPECT_EQ(uint32(uint8(m8 - c8)), m32 - c32);

        // For some reason this fails. My understanding of order of operations
when it comes to casting is clearly lacking.
        //EXPECT_EQ(uint32((m8 - c8)), m32 - c32);
      }
    }
  }
}

[miu, 2015/01/14 02:12:24]

I looked into 128-bit integers, but didn't like what I found.  One show-stopper:
There don't seem to be any intrinsics to do 128-bit divide, and I didn't want to
write my own function.

However, I came up with a simple solution to get the job done: Just use
straightforward floating-point math.  Double-precision is "precise enough" to
test the logic down to the microsecond.  Note: I purposely DO NOT test 64-bit
values that cannot be represented.

[brianderson, 2015/01/14 02:31:42]

Thanks for looking into that. It would have been nice to test without a
tolerance, but within a microsecond is more than good enough and this approach
is better than what we had before, which wasn't testing values over the
threshold well.

lgtm!

+        TimeDelta::FromMicroseconds(
+            ticks_advanced * Time::kMicrosecondsPerSecond / ticks_per_second);
+    const TimeTicks value = TimeTicks::FromQPCValue(ticks.QuadPart);
+    EXPECT_GE(tolerance_us,
+              (value - expected_value).magnitude().InMicroseconds())
+        << "iteration: " << i << ", logic path: "
+        << (ticks.QuadPart < Time::kQPCOverflowThreshold ? "FAST" : "SAFE");
   }
-
-  // Sanity check. We expect some time drift to occur, especially across
-  // the number of iterations we do.
-  EXPECT_LT(0, total_drift);
-
-  printf("average time drift in microseconds: %lld\n",
-         total_drift / kIterations);
 }
-
-int64 QPCValueToMicrosecondsSafely(LONGLONG qpc_value,
-                                   int64 ticks_per_second) {
-  int64 whole_seconds = qpc_value / ticks_per_second;
-  int64 leftover_ticks = qpc_value % ticks_per_second;
-  int64 microseconds = (whole_seconds * Time::kMicrosecondsPerSecond) +
-                       ((leftover_ticks * Time::kMicrosecondsPerSecond) /
-                        ticks_per_second);
-  return microseconds;
-}
-
-TEST(TimeTicks, FromQPCValue) {
-  if (!TimeTicks::IsHighResClockWorking())
-    return;
-  LARGE_INTEGER frequency;
-  QueryPerformanceFrequency(&frequency);
-  int64 ticks_per_second = frequency.QuadPart;
-  LONGLONG qpc_value = Time::kQPCOverflowThreshold;
-  TimeTicks expected_value = TimeTicks::FromInternalValue(
-    QPCValueToMicrosecondsSafely(qpc_value + 1, ticks_per_second));
-  EXPECT_EQ(expected_value,
-            TimeTicks::FromQPCValue(qpc_value + 1));
-  expected_value = TimeTicks::FromInternalValue(
-    QPCValueToMicrosecondsSafely(qpc_value, ticks_per_second));
-  EXPECT_EQ(expected_value,
-            TimeTicks::FromQPCValue(qpc_value));
-  expected_value = TimeTicks::FromInternalValue(
-    QPCValueToMicrosecondsSafely(qpc_value - 1, ticks_per_second));
-  EXPECT_EQ(expected_value,
-            TimeTicks::FromQPCValue(qpc_value - 1));
-}