Give access to a network time kept in the variation service.

chrome/browser/metrics/variations/variations_service.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 "chrome/browser/metrics/variations/variations_service.h"
 
 #include <set>
 
 #include "base/base64.h"
 #include "base/build_time.h"
@@ skipping 23 matching lines @@
 namespace {
 
 // Default server of Variations seed info.
 const char kDefaultVariationsServerURL[] =
     "https://clients4.google.com/chrome-variations/seed";
 const int kMaxRetrySeedFetch = 5;
 
 // Time between seed fetches, in hours.
 const int kSeedFetchPeriodHours = 5;
 
+// TODO(mad): To be moved to NetworkTimeService when available.
+// base::TimeTicks::Now() is documented to have a resolution of
+// ~1-15ms.
+const int64 kTicksResolutionMs = 15;
+
+// For the sources that are supported (HTTP date headers, TLS
+// handshake), the resolution of the server time is 1 second.
+const int64 kServerTimeResolutionMs = 1000;
+
 // Maps Study_Channel enum values to corresponding chrome::VersionInfo::Channel
 // enum values.
 chrome::VersionInfo::Channel ConvertStudyChannelToVersionChannel(
     Study_Channel study_channel) {
   switch (study_channel) {
     case Study_Channel_CANARY:
       return chrome::VersionInfo::CHANNEL_CANARY;
     case Study_Channel_DEV:
       return chrome::VersionInfo::CHANNEL_DEV;
     case Study_Channel_BETA:
@@ skipping 126 matching lines @@
   DCHECK(create_trials_from_seed_called_);
 
   // Perform the first fetch.
   FetchVariationsSeed();
 
   // Repeat this periodically.
   timer_.Start(FROM_HERE, base::TimeDelta::FromHours(kSeedFetchPeriodHours),
                this, &VariationsService::FetchVariationsSeed);
 }
 
+bool VariationsService::GetNetworkTime(base::Time* network_time,
+                                       base::TimeDelta* uncertainty) const {
+  if (network_time_.is_null())
+    return false;
+  DCHECK(!network_time_ticks_.is_null());
+  DCHECK(network_time);
+  *network_time = network_time_ + (base::TimeTicks::Now() -
+                                   network_time_ticks_);
+  if (uncertainty)
+    *uncertainty = network_time_uncertainty_;
+  return true;
+}
+
 #if defined(OS_WIN)
 void VariationsService::StartGoogleUpdateRegistrySync() {
   registry_syncer_.RequestRegistrySync();
 }
 #endif
 
 void VariationsService::SetCreateTrialsFromSeedCalledForTesting(bool called) {
   create_trials_from_seed_called_ = called;
 }
 
@@ skipping 49 matching lines @@
   DCHECK_EQ(pending_seed_request_.get(), source);
   // The fetcher will be deleted when the request is handled.
   scoped_ptr<const net::URLFetcher> request(
       pending_seed_request_.release());
   if (request->GetStatus().status() != net::URLRequestStatus::SUCCESS) {
     DVLOG(1) << "Variations server request failed.";
     return;
   }
 
   // Log the response code.
+  int response_code = request->GetResponseCode();

[Alexei Svitkine (slow), 2013/02/01 19:38:55]

Nit: const

[MAD, 2013/02/01 22:01:41]

Done.

   UMA_HISTOGRAM_CUSTOM_ENUMERATION("Variations.SeedFetchResponseCode",
-      net::HttpUtil::MapStatusCodeForHistogram(request->GetResponseCode()),
+      net::HttpUtil::MapStatusCodeForHistogram(response_code),
       net::HttpUtil::GetStatusCodesForHistogram());
 
   const base::TimeDelta latency =
       base::TimeTicks::Now() - last_request_started_time_;
 
-  if (request->GetResponseCode() != 200) {
+  base::Time response_date;
+  if (response_code == 200 || response_code == 304) {

[Alexei Svitkine (slow), 2013/02/01 19:38:55]

Can you change the code to use the constants from net/http/http_status_code.h?

[MAD, 2013/02/01 22:01:41]

Done.

[MAD, 2013/02/01 22:01:41]

Done.

+    bool success = request->GetResponseHeaders()->GetDateValue(&response_date);
+    DCHECK(success || response_date.is_null());
+
+    if (!response_date.is_null()) {
+#ifndef NDEBUG
+      if (!network_time_.is_null()) {
+        // Check that we are tracking time correctly.
+        base::Time current_network_time;
+        base::TimeDelta uncertainty;
+        success = GetNetworkTime(&current_network_time, &uncertainty);
+        DCHECK(success);
+        // Account for response_date; s own innaccuracy.
+        uncertainty +=
+            base::TimeDelta::FromMilliseconds(kServerTimeResolutionMs) +
+            latency + 2 * base::TimeDelta::FromMilliseconds(kTicksResolutionMs);
+        DCHECK(current_network_time >= response_date - uncertainty);
+        DCHECK(current_network_time <= response_date + uncertainty);
+        DVLOG(1) << current_network_time.ToInternalValue() << " VS "
+                 << response_date.ToInternalValue() << ", is within: "
+                 << uncertainty.ToInternalValue();
+      }
+#endif  // ifndef NDEBUG
+      // Update network time on every request to limit dependency on ticks lag.
+      // TODO(mad): Find a heuristic to avoid augmenting the
+      // network_time_uncertainty_ too much by a particularly long latency.
+      // Maybe only update when we either improve accuracy or drifted too far
+      // from response_date.
+      network_time_ = response_date;
+      // Estimate that the time was set midway through the latency time.
+      network_time_ticks_ = base::TimeTicks::Now() - latency / 2;
+      // We can't assume a better time than the resolution of the server time
+      // and we involve 4 ticks value, each with their own uncertainty, 1 & 2
+      // are the ones used to compute the latency, 3 is the Now() above and 4
+      // will be the Now() used in GetNetworkTime().
+      network_time_uncertainty_ =
+          base::TimeDelta::FromMilliseconds(kServerTimeResolutionMs) +
+          latency + 4 * base::TimeDelta::FromMilliseconds(kTicksResolutionMs);
+    }  // if (!response_date.is_null())
+  } else if (response_code != 200) {
     DVLOG(1) << "Variations server request returned non-200 response code: "
-             << request->GetResponseCode();
-    if (request->GetResponseCode() == 304)
+             << response_code;
+    if (response_code == 304)
       UMA_HISTOGRAM_MEDIUM_TIMES("Variations.FetchNotModifiedLatency", latency);
     else
       UMA_HISTOGRAM_MEDIUM_TIMES("Variations.FetchOtherLatency", latency);
     return;
   }
   UMA_HISTOGRAM_MEDIUM_TIMES("Variations.FetchSuccessLatency", latency);
 
   std::string seed_data;
   bool success = request->GetResponseAsString(&seed_data);
   DCHECK(success);
 
-  base::Time response_date;
-  success = request->GetResponseHeaders()->GetDateValue(&response_date);
-  DCHECK(success || response_date.is_null());
-
   StoreSeedData(seed_data, response_date, g_browser_process->local_state());
 }
 
 void VariationsService::OnResourceRequestsAllowed() {
   // Note that this only attempts to fetch the seed at most once per period
   // (kSeedFetchPeriodHours). This works because
   // |resource_request_allowed_notifier_| only calls this method if an
   // attempt was made earlier that fails (which implies that the period had
   // elapsed). After a successful attempt is made, the notifier will know not
   // to call this method again until another failed attempt occurs.
@@ skipping 264 matching lines @@
                                       variation_id);
     }
   }
 
   trial->SetForced();
   if (IsStudyExpired(study, reference_date))
     trial->Disable();
 }
 
 }  // namespace chrome_variations