metrics: Add random delays to perf collection

chrome/browser/metrics/perf_provider_chromeos.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 <string>
 
 #include "base/bind.h"
 #include "base/bind_helpers.h"
 #include "base/callback.h"
 #include "base/command_line.h"
@@ skipping 36 matching lines @@
 // There may be too many session restores to collect a profile each time. Limit
 // the collection rate by collecting one per 10 restores. Adjust this number as
 // needed.
 const int kRestoreSessionSamplingFactor = 10;
 
 // This is used to space out session restore collections in the face of several
 // notifications in a short period of time. There should be no less than this
 // much time between collections. The current value is 30 seconds.
 const int kMinIntervalBetweenSessionRestoreCollectionsMs = 30 * 1000;
 
+// If collecting after a resume, add a random delay before collecting. The delay
+// should be randomly selected between 0 and this value. Currently the value is
+// equal to 5 seconds.
+const int kMaxResumeCollectionDelayMs = 5 * 1000;
+
+// If collecting after a session restore, add a random delay before collecting.
+// The delay should be randomly selected between 0 and this value. Currently the
+// value is equal to 10 seconds.
+const int kMaxRestoreSessionCollectionDelayMs = 10 * 1000;
+
 // Enumeration representing success and various failure modes for collecting and
 // sending perf data.
 enum GetPerfDataOutcome {
   SUCCESS,
   NOT_READY_TO_UPLOAD,
   NOT_READY_TO_COLLECT,
   INCOGNITO_ACTIVE,
   INCOGNITO_LAUNCHED,
   PROTOBUF_NOT_PARSED,
   NUM_OUTCOMES
@@ skipping 111 matching lines @@
   // canceled. Do not collect anything if that's the case.
   if (sleep_duration == base::TimeDelta())
     return;
 
   // Do not collect a profile unless logged in. The system behavior when closing
   // the lid or idling when not logged in is currently to shut down instead of
   // suspending. But it's good to enforce the rule here in case that changes.
   if (!IsNormalUserLoggedIn())
     return;
 
+  // Do not collect if there is an existing collection scheduled.
+  if (resume_timer_.IsRunning())
+    return;
+
   // Collect a profile only 1/|kResumeSamplingFactor| of the time, to avoid
   // collecting too much data.
   if (base::RandGenerator(kResumeSamplingFactor) != 0)
     return;
 
-  // Fill out a SampledProfile protobuf that will contain the collected data.
-  scoped_ptr<SampledProfile> sampled_profile(new SampledProfile);
-  sampled_profile->set_trigger_event(SampledProfile::RESUME_FROM_SUSPEND);
-  sampled_profile->set_suspend_duration_ms(sleep_duration.InMilliseconds());
-  // TODO(sque): Vary the time after resume at which to collect a profile.
-  // http://crbug.com/358778.
-  sampled_profile->set_ms_after_resume(0);
-  CollectIfNecessary(sampled_profile.Pass());
+  // Randomly pick a delay before doing the collection.
+  base::TimeDelta collection_delay =
+      base::TimeDelta::FromMilliseconds(
+          base::RandGenerator(kMaxResumeCollectionDelayMs));
+  resume_timer_.Start(FROM_HERE,
+                      collection_delay,
+                      base::Bind(&PerfProvider::CollectPerfDataAfterResume,
+                                 weak_factory_.GetWeakPtr(),
+                                 sleep_duration,
+                                 collection_delay));

[Ilya Sherman, 2014/07/08 00:06:40]

By the way, a timer set to run in 1250ms is not guaranteed to run precisely
1250ms later -- it might be delayed, e.g. because the UI thread is busy with
other tasks.  Is that something you want to account for in the metrics?  If not,
I'd recommend at least adding a comment to the proto file that this could be a
source of bias.

 }
 
 void PerfProvider::Observe(int type,
                            const content::NotificationSource& source,
                            const content::NotificationDetails& details) {
   // Only handle session restore notifications.
   DCHECK_EQ(type, chrome::NOTIFICATION_SESSION_RESTORE_DONE);
 
+  // Do not collect if there is an existing collection scheduled.
+  if (restore_session_timer_.IsRunning())
+    return;
+
+  // Do not collect a profile unless logged in as a normal user.
+  if (!IsNormalUserLoggedIn())
+    return;
+
   // Collect a profile only 1/|kRestoreSessionSamplingFactor| of the time, to
   // avoid collecting too much data and potentially causing UI latency.
   if (base::RandGenerator(kRestoreSessionSamplingFactor) != 0)
     return;
 
   const base::TimeDelta min_interval =
       base::TimeDelta::FromMilliseconds(
           kMinIntervalBetweenSessionRestoreCollectionsMs);
   const base::TimeDelta time_since_last_collection =
       (base::TimeTicks::Now() - last_session_restore_collection_time_);
   // Do not collect if there hasn't been enough elapsed time since the last
   // collection.
   if (!last_session_restore_collection_time_.is_null() &&
       time_since_last_collection < min_interval) {
     return;
   }
 
-  // Fill out a SampledProfile protobuf that will contain the collected data.
-  scoped_ptr<SampledProfile> sampled_profile(new SampledProfile);
-  sampled_profile->set_trigger_event(SampledProfile::RESTORE_SESSION);
-  // TODO(sque): Vary the time after restore at which to collect a profile,
-  // and find a way to determine the number of tabs restored.
-  // http://crbug.com/358778.
-  sampled_profile->set_ms_after_restore(0);
-
-  CollectIfNecessary(sampled_profile.Pass());
-  last_session_restore_collection_time_ = base::TimeTicks::Now();
+  // Randomly pick a delay before doing the collection.
+  base::TimeDelta collection_delay =
+      base::TimeDelta::FromMilliseconds(
+          base::RandGenerator(kMaxRestoreSessionCollectionDelayMs));
+  restore_session_timer_.Start(
+      FROM_HERE,
+      collection_delay,
+      base::Bind(&PerfProvider::CollectPerfDataAfterSessionRestore,
+                 weak_factory_.GetWeakPtr(),
+                 collection_delay));
 }
 
 void PerfProvider::OnUserLoggedIn() {
   login_time_ = base::TimeTicks::Now();
   ScheduleCollection();
 }
 
 void PerfProvider::Deactivate() {
-  // Stop the timer, but leave |cached_perf_data_| intact.
-  timer_.Stop();
+  // Stop the timers, but leave |cached_perf_data_| intact.
+  interval_timer_.Stop();
+  resume_timer_.Stop();
+  restore_session_timer_.Stop();
 }
 
 void PerfProvider::ScheduleCollection() {
   DCHECK(CalledOnValidThread());
-  if (timer_.IsRunning())
+  if (interval_timer_.IsRunning())
     return;
 
   // Pick a random time in the current interval.
   base::TimeTicks scheduled_time =
       next_profiling_interval_start_ +
       base::TimeDelta::FromMilliseconds(
           base::RandGenerator(kPerfProfilingIntervalMs));
 
   // If the scheduled time has already passed in the time it took to make the
   // above calculations, trigger the collection event immediately.
   base::TimeTicks now = base::TimeTicks::Now();
   if (scheduled_time < now)
     scheduled_time = now;
 
-  timer_.Start(FROM_HERE, scheduled_time - now, this,
-               &PerfProvider::DoPeriodicCollection);
+  interval_timer_.Start(FROM_HERE, scheduled_time - now, this,
+                        &PerfProvider::DoPeriodicCollection);
 
   // Update the profiling interval tracker to the start of the next interval.
   next_profiling_interval_start_ +=
       base::TimeDelta::FromMilliseconds(kPerfProfilingIntervalMs);
 }
 
 void PerfProvider::CollectIfNecessary(
     scoped_ptr<SampledProfile> sampled_profile) {
   DCHECK(CalledOnValidThread());
 
@@ skipping 32 matching lines @@
 }
 
 void PerfProvider::DoPeriodicCollection() {
   scoped_ptr<SampledProfile> sampled_profile(new SampledProfile);
   sampled_profile->set_trigger_event(SampledProfile::PERIODIC_COLLECTION);
 
   CollectIfNecessary(sampled_profile.Pass());
   ScheduleCollection();
 }
 
+void PerfProvider::CollectPerfDataAfterResume(
+    const base::TimeDelta& sleep_duration,
+    const base::TimeDelta& time_after_resume) {
+  // Fill out a SampledProfile protobuf that will contain the collected data.
+  scoped_ptr<SampledProfile> sampled_profile(new SampledProfile);
+  sampled_profile->set_trigger_event(SampledProfile::RESUME_FROM_SUSPEND);
+  sampled_profile->set_suspend_duration_ms(sleep_duration.InMilliseconds());
+  sampled_profile->set_ms_after_resume(time_after_resume.InMilliseconds());
+
+  CollectIfNecessary(sampled_profile.Pass());
+}
+
+void PerfProvider::CollectPerfDataAfterSessionRestore(
+    const base::TimeDelta& time_after_restore) {
+  // Fill out a SampledProfile protobuf that will contain the collected data.
+  scoped_ptr<SampledProfile> sampled_profile(new SampledProfile);
+  sampled_profile->set_trigger_event(SampledProfile::RESTORE_SESSION);
+  sampled_profile->set_ms_after_restore(time_after_restore.InMilliseconds());
+
+  CollectIfNecessary(sampled_profile.Pass());
+  last_session_restore_collection_time_ = base::TimeTicks::Now();
+}
+
 void PerfProvider::ParseProtoIfValid(
     scoped_ptr<WindowedIncognitoObserver> incognito_observer,
     scoped_ptr<SampledProfile> sampled_profile,
     const std::vector<uint8>& data) {
   DCHECK(CalledOnValidThread());
 
   if (incognito_observer->incognito_launched()) {
     AddToPerfHistogram(INCOGNITO_LAUNCHED);
     return;
   }
@@ skipping 17 matching lines @@
   DCHECK(!login_time_.is_null());
   collection_data.
       set_ms_after_login((base::TimeTicks::Now() - login_time_)
           .InMilliseconds());
 
   // Finally, store the perf data itself.
   collection_data.mutable_perf_data()->Swap(&perf_data_proto);
 }
 
 }  // namespace metrics