When network time is unavailable, record the reason in UMA

Network time is frequently unavailable when we hit certificate date
errors. This CL histograms additional information about why network time
is unavailable (specifically, whether no time query has been made or
whether the system clock lost sync since the last time query).

To do so, I deprecated the old network time histogram that shared an
enum with the build time histogram, and introduced a new network
time histogram with a network time enum (rather than adding more
network-specific values to the enum that is shared with the build time
histogram).

BUG=

Review-Url: https://codereview.chromium.org/2254433003
Cr-Commit-Position: refs/heads/master@{#415244}

chrome/browser/upgrade_detector_impl.cc

@@ -417,8 +417,9 @@ bool UpgradeDetectorImpl::DetectOutdatedInstall() {
 
   base::Time network_time;
   base::TimeDelta uncertainty;
-  if (!g_browser_process->network_time_tracker()->GetNetworkTime(
-          &network_time, &uncertainty)) {
+  if (g_browser_process->network_time_tracker()->GetNetworkTime(&network_time,
+                                                                &uncertainty) !=
+      network_time::NetworkTimeTracker::NETWORK_TIME_AVAILABLE) {
     // When network time has not been initialized yet, simply rely on the
     // machine's current time.
     network_time = base::Time::Now();

components/network_time/network_time_tracker.cc

@@ -306,12 +306,13 @@ base::TimeDelta NetworkTimeTracker::GetTimerDelayForTesting() const {
   return timer_.GetCurrentDelay();
 }
 
-bool NetworkTimeTracker::GetNetworkTime(base::Time* network_time,
-                                        base::TimeDelta* uncertainty) const {
+NetworkTimeTracker::NetworkTimeResult NetworkTimeTracker::GetNetworkTime(
+    base::Time* network_time,
+    base::TimeDelta* uncertainty) const {
   DCHECK(thread_checker_.CalledOnValidThread());
   DCHECK(network_time);
   if (network_time_at_last_measurement_.is_null()) {
-    return false;
+    return NETWORK_TIME_NO_SYNC;
   }
   DCHECK(!ticks_at_last_measurement_.is_null());
   DCHECK(!time_at_last_measurement_.is_null());
@@ -320,23 +321,41 @@ bool NetworkTimeTracker::GetNetworkTime(base::Time* network_time,
   base::TimeDelta time_delta = clock_->Now() - time_at_last_measurement_;
   if (time_delta.InMilliseconds() < 0) {  // Has wall clock run backward?
     DVLOG(1) << "Discarding network time due to wall clock running backward";
+    UMA_HISTOGRAM_CUSTOM_TIMES(
+        "NetworkTimeTracker.WallClockRanBackwards", time_delta.magnitude(),
+        base::TimeDelta::FromSeconds(1), base::TimeDelta::FromDays(7), 50);
     network_time_at_last_measurement_ = base::Time();
-    return false;
+    return NETWORK_TIME_SYNC_LOST;
   }
   // Now we know that both |tick_delta| and |time_delta| are positive.
-  base::TimeDelta divergence = (tick_delta - time_delta).magnitude();
-  if (divergence > base::TimeDelta::FromSeconds(kClockDivergenceSeconds)) {
+  base::TimeDelta divergence = tick_delta - time_delta;
+  if (divergence.magnitude() >
+      base::TimeDelta::FromSeconds(kClockDivergenceSeconds)) {
     // Most likely either the machine has suspended, or the wall clock has been
     // reset.
     DVLOG(1) << "Discarding network time due to clocks diverging";
+
+    // The below histograms do not use |kClockDivergenceSeconds| as the
+    // lower-bound, so that |kClockDivergenceSeconds| can be changed
+    // without causing the buckets to change and making data from
+    // old/new clients incompatible.
+    if (divergence.InMilliseconds() < 0) {
+      UMA_HISTOGRAM_CUSTOM_TIMES(
+          "NetworkTimeTracker.ClockDivergence.Negative", divergence.magnitude(),
+          base::TimeDelta::FromSeconds(60), base::TimeDelta::FromDays(7), 50);
+    } else {
+      UMA_HISTOGRAM_CUSTOM_TIMES(
+          "NetworkTimeTracker.ClockDivergence.Positive", divergence.magnitude(),
+          base::TimeDelta::FromSeconds(60), base::TimeDelta::FromDays(7), 50);
+    }
     network_time_at_last_measurement_ = base::Time();
-    return false;
+    return NETWORK_TIME_SYNC_LOST;
   }
   *network_time = network_time_at_last_measurement_ + tick_delta;
   if (uncertainty) {
     *uncertainty = network_time_uncertainty_ + divergence;
   }
-  return true;
+  return NETWORK_TIME_AVAILABLE;
 }
 
 void NetworkTimeTracker::CheckTime() {
@@ -469,10 +488,10 @@ bool NetworkTimeTracker::ShouldIssueTimeQuery() {
     return false;
   }
 
-  // If GetNetworkTime() returns false, synchronization has been lost
-  // and a query is needed.
+  // If GetNetworkTime() does not return NETWORK_TIME_AVAILABLE,
+  // synchronization has been lost and a query is needed.
   base::Time network_time;
-  if (!GetNetworkTime(&network_time, nullptr)) {
+  if (GetNetworkTime(&network_time, nullptr) != NETWORK_TIME_AVAILABLE) {
     return true;
   }
 

components/network_time/network_time_tracker.h

@@ -48,6 +48,20 @@ const int64_t kTicksResolutionMs = 1;  // Assume 1ms for non-windows platforms.
 // for a corresponding local time. This class is not thread safe.
 class NetworkTimeTracker : public net::URLFetcherDelegate {
  public:
+  // Describes the result of a GetNetworkTime() call, describing whether
+  // network time was available and if not, why not.
+  enum NetworkTimeResult {
+    // Network time is available.
+    NETWORK_TIME_AVAILABLE,
+    // A time has been retrieved from the network in the past, but
+    // network time is no longer available because the tracker fell out
+    // of sync due to, for example, a suspend/resume.
+    NETWORK_TIME_SYNC_LOST,
+    // Network time is unavailable because the tracker has not yet
+    // retrieved a time from the network.
+    NETWORK_TIME_NO_SYNC,
+  };
+
   static void RegisterPrefs(PrefRegistrySimple* registry);
 
   // Constructor.  Arguments may be stubbed out for tests.  |getter|, if not
@@ -59,9 +73,13 @@ class NetworkTimeTracker : public net::URLFetcherDelegate {
                      scoped_refptr<net::URLRequestContextGetter> getter);
   ~NetworkTimeTracker() override;
 
-  // Sets |network_time| to an estimate of the true time.  Returns true if time
-  // is available, and false otherwise.  If |uncertainty| is non-NULL, it will
-  // be set to an estimate of the error range.
+  // Sets |network_time| to an estimate of the true time.  Returns
+  // NETWORK_TIME_AVAILABLE if time is available. If |uncertainty| is
+  // non-NULL, it will be set to an estimate of the error range.
+  //
+  // If network time is unavailable, this method returns
+  // NETWORK_TIME_SYNC_LOST or NETWORK_TIME_NO_SYNC to indicate the
+  // reason.
   //
   // Network time may be available on startup if deserialized from a pref.
   // Failing that, a call to |UpdateNetworkTime| is required to make time
@@ -69,8 +87,8 @@ class NetworkTimeTracker : public net::URLFetcherDelegate {
   // become unavailable if |NetworkTimeTracker| has reason to believe it is no
   // longer accurate.  Consumers should even be prepared to handle the case
   // where calls to |GetNetworkTime| never once succeeds.
-  bool GetNetworkTime(base::Time* network_time,
-                      base::TimeDelta* uncertainty) const;
+  NetworkTimeResult GetNetworkTime(base::Time* network_time,
+                                   base::TimeDelta* uncertainty) const;
 
   // Calculates corresponding time ticks according to the given parameters.
   // The provided |network_time| is precise at the given |resolution| and

components/ssl_errors/error_classification.cc

@@ -38,6 +38,26 @@ using base::TimeDelta;
 namespace ssl_errors {
 namespace {
 
+// Describes the result of getting network time and if it was
+// unavailable, why it was unavailable. This enum is being histogrammed
+// so do not reorder or remove values.
+enum NetworkClockState {
+  // The clock state relative to network time is unknown because the
+  // NetworkTimeTracker has no information from the network.
+  NETWORK_CLOCK_STATE_UNKNOWN_NO_SYNC = 0,
+  // The clock state relative to network time is unknown because the
+  // user's clock has fallen out of sync with the latest information
+  // from the network (due to e.g. suspend/resume).
+  NETWORK_CLOCK_STATE_UNKNOWN_SYNC_LOST,
+  // The clock is "close enough" to the network time.
+  NETWORK_CLOCK_STATE_OK,
+  // The clock is in the past relative to network time.
+  NETWORK_CLOCK_STATE_CLOCK_IN_PAST,
+  // The clock is in the future relative to network time.
+  NETWORK_CLOCK_STATE_CLOCK_IN_FUTURE,
+  NETWORK_CLOCK_STATE_MAX
+};
+
 // Events for UMA. Do not reorder or change!
 enum SSLInterstitialCause {
   CLOCK_PAST,
@@ -207,15 +227,25 @@ ClockState GetClockState(
   base::Time now_network;
   base::TimeDelta uncertainty;
   const base::TimeDelta kNetworkTimeFudge = base::TimeDelta::FromMinutes(5);
-  ClockState network_state = CLOCK_STATE_UNKNOWN;
-  if (network_time_tracker->GetNetworkTime(&now_network, &uncertainty)) {
-    if (now_system < now_network - uncertainty - kNetworkTimeFudge) {
-      network_state = CLOCK_STATE_PAST;
-    } else if (now_system > now_network + uncertainty + kNetworkTimeFudge) {
-      network_state = CLOCK_STATE_FUTURE;
-    } else {
-      network_state = CLOCK_STATE_OK;
-    }
+  NetworkClockState network_state = NETWORK_CLOCK_STATE_MAX;
+  network_time::NetworkTimeTracker::NetworkTimeResult network_time_result =
+      network_time_tracker->GetNetworkTime(&now_network, &uncertainty);
+  switch (network_time_result) {
+    case network_time::NetworkTimeTracker::NETWORK_TIME_AVAILABLE:
+      if (now_system < now_network - uncertainty - kNetworkTimeFudge) {
+        network_state = NETWORK_CLOCK_STATE_CLOCK_IN_PAST;
+      } else if (now_system > now_network + uncertainty + kNetworkTimeFudge) {
+        network_state = NETWORK_CLOCK_STATE_CLOCK_IN_FUTURE;
+      } else {
+        network_state = NETWORK_CLOCK_STATE_OK;
+      }
+      break;
+    case network_time::NetworkTimeTracker::NETWORK_TIME_SYNC_LOST:
+      network_state = NETWORK_CLOCK_STATE_UNKNOWN_SYNC_LOST;
+      break;
+    case network_time::NetworkTimeTracker::NETWORK_TIME_NO_SYNC:
+      network_state = NETWORK_CLOCK_STATE_UNKNOWN_NO_SYNC;
+      break;
   }
 
   ClockState build_time_state = CLOCK_STATE_UNKNOWN;
@@ -228,13 +258,28 @@ ClockState GetClockState(
     build_time_state = CLOCK_STATE_FUTURE;
   }
 
-  UMA_HISTOGRAM_ENUMERATION("interstitial.ssl.clockstate.network",
-                            network_state, CLOCK_STATE_MAX);
+  UMA_HISTOGRAM_ENUMERATION("interstitial.ssl.clockstate.network2",
+                            network_time_result, NETWORK_CLOCK_STATE_MAX);
   UMA_HISTOGRAM_ENUMERATION("interstitial.ssl.clockstate.build_time",
                             build_time_state, CLOCK_STATE_MAX);
 
-  return network_state == CLOCK_STATE_UNKNOWN ? build_time_state
-                                              : network_state;
+  switch (network_state) {
+    case NETWORK_CLOCK_STATE_UNKNOWN_NO_SYNC:
+    case NETWORK_CLOCK_STATE_UNKNOWN_SYNC_LOST:
+      return build_time_state;
+    case NETWORK_CLOCK_STATE_OK:
+      return CLOCK_STATE_OK;
+    case NETWORK_CLOCK_STATE_CLOCK_IN_PAST:
+      return CLOCK_STATE_PAST;
+    case NETWORK_CLOCK_STATE_CLOCK_IN_FUTURE:
+      return CLOCK_STATE_FUTURE;
+    case NETWORK_CLOCK_STATE_MAX:
+      NOTREACHED();
+      return CLOCK_STATE_UNKNOWN;
+  }
+
+  NOTREACHED();
+  return CLOCK_STATE_UNKNOWN;
 }
 
 void SetBuildTimeForTesting(const base::Time& testing_time) {

tools/metrics/histograms/histograms.xml

@@ -20504,6 +20504,20 @@ http://cs/file:chrome/histograms.xml - but prefer this file for new entries.
 </histogram>
 
 <histogram name="interstitial.ssl.clockstate.network" enum="ClockStates">
+  <obsolete>
+    Deprecated August 2016. Replaced with interstitial.ssl.clockstate.network2,
+    which records reasons why network time might be unavailable.
+  </obsolete>
+  <owner>mab@chromium.org</owner>
+  <summary>
+    State of the system clock, relative to network time, when an SSL
+    CERT_INVALID_DATE error is seen.
+  </summary>
+</histogram>
+
+<histogram name="interstitial.ssl.clockstate.network2"
+    enum="NetworkClockStates">
+  <owner>estark@chromium.org</owner>
   <owner>mab@chromium.org</owner>
   <summary>
     State of the system clock, relative to network time, when an SSL
@@ -35620,6 +35634,40 @@ http://cs/file:chrome/histograms.xml - but prefer this file for new entries.
   </summary>
 </histogram>
 
+<histogram name="NetworkTimeTracker.ClockDivergence.Negative" units="seconds">
+  <owner>estark@chromium.org</owner>
+  <owner>mab@chromium.org</owner>
+  <summary>
+    NetworkTimeTracker observes a tick clock and a wall clock to determine
+    whether a timestamp retrieved from the network in the past can be used to
+    compute a current timestamp. When the tick clock and wall clock diverge from
+    each other, the NetworkTimeTracker must discard the network timestamp
+    because it has no way to compute a reliable current timestamp. Whenever the
+    NetworkTimeTracker discards a network timestamp due to the tick and wall
+    clocks diverging, this histogram records the difference of the tick clock's
+    delta minus the wall clock's delta since the network timestamp was
+    retrieved. For cases where the the tick clock delta is bigger than the wall
+    clock delta, see NetworkTimeTracker.ClockDivergence.Positive.
+  </summary>
+</histogram>
+
+<histogram name="NetworkTimeTracker.ClockDivergence.Positive" units="seconds">
+  <owner>estark@chromium.org</owner>
+  <owner>mab@chromium.org</owner>
+  <summary>
+    NetworkTimeTracker observes a tick clock and a wall clock to determine
+    whether a timestamp retrieved from the network in the past can be used to
+    compute a current timestamp. When the tick clock and wall clock diverge from
+    each other, the NetworkTimeTracker must discard the network timestamp
+    because it has no way to compute a reliable current timestamp. Whenever the
+    NetworkTimeTracker discards a network timestamp due to the tick and wall
+    clocks diverging, this histogram records the difference of the tick clock's
+    delta minus the wall clock's delta since the network timestamp was
+    retrieved. For cases where the the wall clock delta is bigger than the tick
+    clock delta, see NetworkTimeTracker.ClockDivergence.Negative.
+  </summary>
+</histogram>
+
 <histogram name="NetworkTimeTracker.UpdateTimeFetchAttempted">
   <obsolete>
     Deprecated 08/2016 because it does not provide additional information beyond
@@ -35656,6 +35704,22 @@ http://cs/file:chrome/histograms.xml - but prefer this file for new entries.
   </summary>
 </histogram>
 
+<histogram name="NetworkTimeTracker.WallClockRanBackwards" units="seconds">
+  <owner>estark@chromium.org</owner>
+  <owner>mab@chromium.org</owner>
+  <summary>
+    NetworkTimeTracker observes a tick clock and a wall clock to determine
+    whether a timestamp retrieved from the network in the past can be used to
+    compute a current timestamp. When the NetworkTimeTracker observes that the
+    wall clock ran backwards, the NetworkTimeTracker must discard the network
+    timestamp because it has no way to compute a reliable current timestamp.
+    Whenever the NetworkTimeTracker discards a network timestamp due to the wall
+    clock running backwards, this histogram records the magnitude of the
+    difference of the current wall clock time minus the wall clock time when the
+    network timestamp was retrieved.
+  </summary>
+</histogram>
+
 <histogram name="NewTabPage.ActionAndroid" enum="NewTabPageActionAndroid">
   <owner>newt@chromium.org</owner>
   <summary>
@@ -87689,6 +87753,26 @@ To add a new entry, add it with any value and run test to compute valid value.
   <int value="42" label="5230"/>
 </enum>
 
+<enum name="NetworkClockStates" type="int">
+  <int value="0"
+      label="NETWORK_CLOCK_STATE_UNKNOWN_NO_SYNC: accuracy of system clock is
+             unknown because there is no information available from the
+             network about what time it is"/>
+  <int value="1"
+      label="NETWORK_CLOCK_STATE_UNKNOWN_SYNC_LOST: system clock is unknown
+             because the system clock has fallen out of sync with the network
+             clock since the last time that network time was retrieved"/>
+  <int value="2"
+      label="NETWORK_CLOCK_STATE_OK: system clock is roughly accurate
+             relative to network time"/>
+  <int value="3"
+      label="NETWORK_CLOCK_STATE_CLOCK_IN_PAST: system clock is in the past
+             relative to network time"/>
+  <int value="4"
+      label="NETWORK_CLOCK_STATE_CLOCK_IN_FUTURE: system clock is in the
+             future relative to network time"/>
+</enum>
+
 <enum name="NetworkConnectionIPType" type="int">
   <int value="0" label="IPv4"/>
   <int value="1" label="IPv6"/>