Measure time between secure time queries

components/network_time/network_time_tracker_unittest.cc

 // Copyright 2014 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 "components/network_time/network_time_tracker.h"
 
 #include <memory>
 #include <string>
 #include <utility>
 
@@ skipping 20 matching lines @@
 namespace {
 const uint32_t kOneDayInSeconds = 86400;
 const char kFetchFailedHistogram[] = "NetworkTimeTracker.UpdateTimeFetchFailed";
 const char kFetchValidHistogram[] = "NetworkTimeTracker.UpdateTimeFetchValid";
 const char kClockDivergencePositiveHistogram[] =
     "NetworkTimeTracker.ClockDivergence.Positive";
 const char kClockDivergenceNegativeHistogram[] =
     "NetworkTimeTracker.ClockDivergence.Negative";
 const char kWallClockBackwardsHistogram[] =
     "NetworkTimeTracker.WallClockRanBackwards";
+const char kTimeBetweenFetchesHistogram[] =
+    "NetworkTimeTracker.TimeBetweenFetches";
 }  // namespace
 
 class NetworkTimeTrackerTest : public ::testing::Test {
  public:
   ~NetworkTimeTrackerTest() override {}
 
   NetworkTimeTrackerTest()
       : io_thread_("IO thread"),
         field_trial_test_(FieldTrialTest::CreateForUnitTest()),
         clock_(new base::SimpleTestClock),
@@ skipping 755 matching lines @@
   EXPECT_TRUE(tracker_->QueryTimeServiceForTesting());
   EXPECT_EQ(NetworkTimeTracker::NETWORK_TIME_SUBSEQUENT_SYNC_PENDING,
             tracker_->GetNetworkTime(&out_network_time, nullptr));
   histograms.ExpectTotalCount(kFetchFailedHistogram, 0);
   histograms.ExpectTotalCount(kFetchValidHistogram, 1);
   histograms.ExpectBucketCount(kFetchValidHistogram, false, 1);
 
   tracker_->WaitForFetchForTesting(123123123);
 }
 
+namespace {
+
+// 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);
+
+  // Returns the time that is returned in the (i-1)'th response handled by
+  // ResponseHandler(), or null base::Time() if too many responses have been
+  // handled.
+  base::Time GetTimeAtIndex(unsigned int i);
+
+ private:
+  // |kJsTimes|, |kTimeResponseBodies|, and |kTimeProofHeaders| contain signed
+  // responses for three subsequent time queries served by
+  // MultipleGoodTimeResponseHandler. (That is, kJsTimes[i] is the timestamp
+  // contained in kTimeResponseBodies[i] with signature in kTimeProofHeader[i].)
+  // NetworkTimeTrackerTest.TimeBetweenFetchesHistogram 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|.
+  static const double kJsTimes[];
+  static const char* kTimeResponseBodies[];
+  static const char* kTimeProofHeaders[];
+
+  // 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);
+};
+
+const double MultipleGoodTimeResponseHandler::kJsTimes[] = {1481653709754,
+                                                            1481653820879};
+const char* MultipleGoodTimeResponseHandler::kTimeResponseBodies[] = {
+    ")]}'\n"
+    "{\"current_time_millis\":1481653709754,\"server_nonce\":-2."
+    "7144232419525693E172}",
+    ")]}'\n"
+    "{\"current_time_millis\":1481653820879,\"server_nonce\":1."
+    "8874633267958474E185}"};
+const char* MultipleGoodTimeResponseHandler::kTimeProofHeaders[] = {
+    "3045022006fdfa882460cd43e15b11d7d35cfc3805b0662c558f6efe54f9bf0c38e80650"
+    "0221009777817152b6cc1c2b2ea765104a1ab6b87a4da1e87686ae0641c25b23161ea8:"
+    "e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855",
+    "3045022100b6ebcf0f2f5c42bb18bd097a60c4204dd2ed29cad4992b5fdfcf1b32bdfdc6"
+    "58022005b378c27dd3ddb6edacce39edc8b4ecf189dff5b64ce99975859f6cdc984e20:"
+    "e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855"};
+
+std::unique_ptr<net::test_server::HttpResponse>
+MultipleGoodTimeResponseHandler::ResponseHandler(
+    const net::test_server::HttpRequest& request) {
+  net::test_server::BasicHttpResponse* response =
+      new net::test_server::BasicHttpResponse();
+
+  if (next_time_index_ >=
+      arraysize(MultipleGoodTimeResponseHandler::kJsTimes)) {
+    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 MultipleGoodTimeResponseHandler::GetTimeAtIndex(unsigned int i) {
+  if (i >= arraysize(kJsTimes))
+    return base::Time();
+  return base::Time::FromJsTime(kJsTimes[i]);
+}
+
+}  // namespace
+
+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);
+}
+
 }  // namespace network_time