Measure time between secure time queries

components/network_time/network_time_tracker_unittest.cc

Index: components/network_time/network_time_tracker_unittest.cc
diff --git a/components/network_time/network_time_tracker_unittest.cc b/components/network_time/network_time_tracker_unittest.cc
index 391d87a3e4a375ea8d321afb9d2a52438a947de3..2b8c0c0757423c9dea126d9ff587185fc20c9384 100644
--- a/components/network_time/network_time_tracker_unittest.cc
+++ b/components/network_time/network_time_tracker_unittest.cc
@@ -38,6 +38,8 @@ const char kClockDivergenceNegativeHistogram[] =
     "NetworkTimeTracker.ClockDivergence.Negative";
 const char kWallClockBackwardsHistogram[] =
     "NetworkTimeTracker.WallClockRanBackwards";
+const char kTimeBetweenFetchesHistogram[] =
+    "NetworkTimeTracker.TimeBetweenFetchedTimes";
 }  // namespace
 
 class NetworkTimeTrackerTest : public ::testing::Test {
@@ -813,4 +815,136 @@ TEST_F(NetworkTimeTrackerTest, UpdateFromNetworkSubseqeuntSyncPending) {
   tracker_->WaitForFetchForTesting(123123123);
 }
 
+// NetworkTimeTrackerTest.TimeBetweenFetchesHistogram needs to make
+// several time queries that return different
+// times. MultipleGoodTimeResponseHandler is like
+// GoodTimeResponseHandler, but returning different times on each of
+// three requests that happen in sequence.
+//
+// See comments inline for how to update the times that are returned.
+class MultipleGoodTimeResponseHandler {
+ public:
+  MultipleGoodTimeResponseHandler() {}
+  ~MultipleGoodTimeResponseHandler() {}
+
+  std::unique_ptr<net::test_server::HttpResponse> ResponseHandler(
+      const net::test_server::HttpRequest& request) {
+    net::test_server::BasicHttpResponse* response =
+        new net::test_server::BasicHttpResponse();
+
+    unsigned int num_responses = sizeof(kJsTimes) / sizeof(double);
+    if (next_time_index_ >= num_responses) {
+      response->set_code(net::HTTP_BAD_REQUEST);
+      return std::unique_ptr<net::test_server::HttpResponse>(response);
+    }
+
+    response->set_code(net::HTTP_OK);
+    response->set_content(kTimeResponseBodies[next_time_index_]);
+    response->AddCustomHeader("x-cup-server-proof",
+                              kTimeProofHeaders[next_time_index_]);
+    next_time_index_++;
+    return std::unique_ptr<net::test_server::HttpResponse>(response);
+  }
+
+  base::Time GetTimeAtIndex(unsigned int i) {
+    if (i >= sizeof(kJsTimes) / sizeof(double))
+      return base::Time();
+    return base::Time::FromJsTime(kJsTimes[i]);
+  }
+
+ private:
+  // |kJsTimes|, |kTimeResponseBodies|, and |kTimeProofHeaders| contain
+  // signed responses for three subsequent time queries. (That is,
+  // kJsTimes[i] is the timestamp contained in kTimeResponseBodies[i]
+  // with signature in kTimeProofHeader[i].) The test expects that each
+  // timestamp is greater than the one before it.
+  //
+  // Update as follows:
+  //
+  // curl -v http://clients2.google.com/time/1/current?cup2key=1:123123123
+  //
+  // where 1 is the key version and 123123123 is the nonce.  Copy the
+  // response and the x-cup-server-proof header into
+  // |kTimeResponseBodies| and |kTimeProofHeaders| respectively, and the
+  // 'current_time_millis' value of the response into |kJsTimes|.
+  const double kJsTimes[3] = {1481653709754, 1481653820879, 1481653880185};

[meacer, 2016/12/14 01:44:38]

You can make these static.

[estark, 2016/12/14 02:31:15]

Done.

+  const std::string kTimeResponseBodies[3] = {
+      ")]}'\n"
+      "{\"current_time_millis\":1481653709754,\"server_nonce\":-2."
+      "7144232419525693E172}",
+      ")]}'\n"
+      "{\"current_time_millis\":1481653820879,\"server_nonce\":1."
+      "8874633267958474E185}",
+      ")]}'\n"
+      "{\"current_time_millis\":1481653880185,\"server_nonce\":1."
+      "4121510557411994E-89}"};
+  const std::string kTimeProofHeaders[3] = {
+      "3045022006fdfa882460cd43e15b11d7d35cfc3805b0662c558f6efe54f9bf0c38e80650"
+      "0221009777817152b6cc1c2b2ea765104a1ab6b87a4da1e87686ae0641c25b23161ea8:"
+      "e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855",
+      "3045022100b6ebcf0f2f5c42bb18bd097a60c4204dd2ed29cad4992b5fdfcf1b32bdfdc6"
+      "58022005b378c27dd3ddb6edacce39edc8b4ecf189dff5b64ce99975859f6cdc984e20:"
+      "e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855",
+      "304502203911ca3e728adb9da575949a248284018ffa56640761e7a71652cc3fbf772a10"
+      "022100cc70de806d804ee4d85cf7be8979e41de62e7965b34e76254678a3536debfccb:"
+      "e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855"};
+
+  // The index into |kJsTimes|, |kTimeResponseBodies|, and
+  // |kTimeProofHeaders| that will be used in the response in the next
+  // ResponseHandler() call.
+  unsigned int next_time_index_ = 0;
+
+  DISALLOW_COPY_AND_ASSIGN(MultipleGoodTimeResponseHandler);
+};
+
+TEST_F(NetworkTimeTrackerTest, TimeBetweenFetchesHistogram) {
+  MultipleGoodTimeResponseHandler response_handler;
+  base::HistogramTester histograms;
+  histograms.ExpectTotalCount(kTimeBetweenFetchesHistogram, 0);
+
+  test_server_->RegisterRequestHandler(
+      base::Bind(&MultipleGoodTimeResponseHandler::ResponseHandler,
+                 base::Unretained(&response_handler)));
+  EXPECT_TRUE(test_server_->Start());
+  tracker_->SetTimeServerURLForTesting(test_server_->GetURL("/"));
+  EXPECT_TRUE(tracker_->QueryTimeServiceForTesting());
+  tracker_->WaitForFetchForTesting(123123123);
+
+  base::Time out_network_time;
+  EXPECT_EQ(NetworkTimeTracker::NETWORK_TIME_AVAILABLE,
+            tracker_->GetNetworkTime(&out_network_time, nullptr));
+  // After the first query, there should be no histogram value because
+  // there was no delta to record.
+  histograms.ExpectTotalCount(kTimeBetweenFetchesHistogram, 0);
+
+  // Trigger a second query, which should cause the delta from the first
+  // query to be recorded.
+  clock_->Advance(base::TimeDelta::FromHours(1));
+  EXPECT_TRUE(tracker_->QueryTimeServiceForTesting());
+  tracker_->WaitForFetchForTesting(123123123);
+  EXPECT_EQ(NetworkTimeTracker::NETWORK_TIME_AVAILABLE,
+            tracker_->GetNetworkTime(&out_network_time, nullptr));
+  histograms.ExpectTotalCount(kTimeBetweenFetchesHistogram, 1);
+  histograms.ExpectBucketCount(
+      kTimeBetweenFetchesHistogram,
+      (response_handler.GetTimeAtIndex(1) - response_handler.GetTimeAtIndex(0))
+          .InMilliseconds(),
+      1);
+
+  // Trigger a third query, which should cause the delta from the second query
+  // to be recorded.
+  base::HistogramTester histograms2;
+  clock_->Advance(base::TimeDelta::FromHours(1));
+  EXPECT_TRUE(tracker_->QueryTimeServiceForTesting());
+  tracker_->WaitForFetchForTesting(123123123);
+  EXPECT_EQ(NetworkTimeTracker::NETWORK_TIME_AVAILABLE,
+            tracker_->GetNetworkTime(&out_network_time, nullptr));
+  histograms2.ExpectTotalCount(kTimeBetweenFetchesHistogram, 1);
+  histograms2.ExpectBucketCount(
+      kTimeBetweenFetchesHistogram,
+      (response_handler.GetTimeAtIndex(2) - response_handler.GetTimeAtIndex(1))
+          .InMilliseconds(),
+      1);
+}
+
 }  // namespace network_time