metrics: Use absolute interval-based perf collection

Replace the old CWP collection scheme with a new scheme:
- Divide post-login time into four-hour intervals.
- Randomly select a time in each interval to collect a perf profile. The
  probability distribution should be even across that interval.
- Use the new SampledProfile protobuf to store the collected data.

Note that since this patch still collects only perf data, the module
perf_provider_chromeos is not renamed to reflect something more generic.
We would like to introduce other types of data collection in the future
but they may be in other modules, or we may create a new generic module
for data collection.

BUG=chromium:358778
TEST=The interval is too long to directly test. Shorten it to something
on the order of a minute and rebuild and deploy Chrome. Should be getting
some profile collections.
I added some logging to print the collected data size. It's around 12 kB,
and I get the same size data from running quipper manually:
quipper 2 `which perf` record -a -e cycles -c 1000003 > /usr/local/perf.proto
Signed-off-by: Simon Que <sque@chromium.org>

Review URL: https://codereview.chromium.org/282093011

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@273971 0039d316-1c4b-4281-b951-d872f2087c98

chrome/browser/metrics/chromeos_metrics_provider.cc

@@ -27,7 +27,7 @@
 #endif  // defined(USE_X11)
 
 using metrics::ChromeUserMetricsExtension;
-using metrics::PerfDataProto;
+using metrics::SampledProfile;
 using metrics::SystemProfileProto;
 typedef SystemProfileProto::Hardware::Bluetooth::PairedDevice PairedDevice;
 
@@ -195,12 +195,12 @@ void ChromeOSMetricsProvider::ProvideStabilityMetrics(
 
 void ChromeOSMetricsProvider::ProvideGeneralMetrics(
     metrics::ChromeUserMetricsExtension* uma_proto) {
-  std::vector<PerfDataProto> perf_data;
-  if (perf_provider_.GetPerfData(&perf_data)) {
-    for (std::vector<PerfDataProto>::iterator iter = perf_data.begin();
-         iter != perf_data.end();
+  std::vector<SampledProfile> sampled_profiles;
+  if (perf_provider_.GetSampledProfiles(&sampled_profiles)) {
+    for (std::vector<SampledProfile>::iterator iter = sampled_profiles.begin();
+         iter != sampled_profiles.end();
          ++iter) {
-      uma_proto->add_perf_data()->Swap(&(*iter));
+      uma_proto->add_sampled_profile()->Swap(&(*iter));
     }
   }
 }

chrome/browser/metrics/perf_provider_chromeos.cc

@@ -24,26 +24,10 @@
 
 namespace {
 
-// Default time in seconds between invocations of perf.
-// This period is roughly 6.5 hours.
-// This is chosen to be relatively prime with the number of seconds in:
-// - one minute (60)
-// - one hour (3600)
-// - one day (86400)
-const size_t kPerfCommandIntervalDefaultSeconds = 23093;
-
-// The first collection interval is different from the interval above. This is
-// because we want to collect the first profile quickly after Chrome is started.
-// If this period is too long, the user will log off and Chrome will be killed
-// before it is triggered. The following 2 variables determine the upper and
-// lower bound on the interval.
-// The reason we do not always want to collect the initial profile after a fixed
-// period is to not over-represent task X in the profile where task X always
-// runs at a fixed period after start-up. By selecting a period randomly between
-// a lower and upper bound, we will hopefully collect a more fair profile.
-const size_t kPerfCommandStartIntervalLowerBoundMinutes = 10;
-
-const size_t kPerfCommandStartIntervalUpperBoundMinutes = 20;
+// Partition time since login into successive intervals of this size. In each
+// interval, pick a random time to collect a profile.
+// This interval is twenty-four hours.
+const size_t kPerfProfilingIntervalMs = 24 * 60 * 60 * 1000;
 
 // Default time in seconds perf is run for.
 const size_t kPerfCommandDurationDefaultSeconds = 2;
@@ -119,6 +103,7 @@ class WindowedIncognitoObserver : public chrome::BrowserListObserver {
 
 PerfProvider::PerfProvider()
       : login_observer_(this),
+        next_profiling_interval_start_(base::TimeTicks::Now()),
         weak_factory_(this) {
   // Register the login observer with LoginState.
   chromeos::LoginState::Get()->AddObserver(&login_observer_);
@@ -135,14 +120,15 @@ PerfProvider::~PerfProvider() {
   chromeos::LoginState::Get()->RemoveObserver(&login_observer_);
 }
 
-bool PerfProvider::GetPerfData(std::vector<PerfDataProto>* perf_data) {
+bool PerfProvider::GetSampledProfiles(
+    std::vector<SampledProfile>* sampled_profiles) {
   DCHECK(CalledOnValidThread());
   if (cached_perf_data_.empty()) {
     AddToPerfHistogram(NOT_READY_TO_UPLOAD);
     return false;
   }
 
-  perf_data->swap(cached_perf_data_);
+  sampled_profiles->swap(cached_perf_data_);
   cached_perf_data_.clear();
 
   AddToPerfHistogram(SUCCESS);
@@ -154,16 +140,14 @@ PerfProvider::LoginObserver::LoginObserver(PerfProvider* perf_provider)
 
 void PerfProvider::LoginObserver::LoggedInStateChanged() {
   if (IsNormalUserLoggedIn())
-    perf_provider_->Activate();
+    perf_provider_->OnUserLoggedIn();
   else
     perf_provider_->Deactivate();
 }
 
-void PerfProvider::Activate() {
-  size_t collection_interval_minutes = base::RandInt(
-      kPerfCommandStartIntervalLowerBoundMinutes,
-      kPerfCommandStartIntervalUpperBoundMinutes);
-  ScheduleCollection(base::TimeDelta::FromMinutes(collection_interval_minutes));
+void PerfProvider::OnUserLoggedIn() {
+  login_time_ = base::TimeTicks::Now();
+  ScheduleCollection();
 }
 
 void PerfProvider::Deactivate() {
@@ -171,16 +155,33 @@ void PerfProvider::Deactivate() {
   timer_.Stop();
 }
 
-void PerfProvider::ScheduleCollection(const base::TimeDelta& interval) {
+void PerfProvider::ScheduleCollection() {
   DCHECK(CalledOnValidThread());
   if (timer_.IsRunning())
     return;
 
-  timer_.Start(FROM_HERE, interval, this,
-               &PerfProvider::CollectIfNecessaryAndReschedule);
+  // 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);
+
+  // Update the profiling interval tracker to the start of the next interval.
+  next_profiling_interval_start_ +=
+      base::TimeDelta::FromMilliseconds(kPerfProfilingIntervalMs);
 }
 
-void PerfProvider::CollectIfNecessary() {
+void PerfProvider::CollectIfNecessary(
+    SampledProfile::TriggerEvent trigger_event) {
   DCHECK(CalledOnValidThread());
 
   // Do not collect further data if we've already collected a substantial amount
@@ -213,17 +214,18 @@ void PerfProvider::CollectIfNecessary() {
   client->GetPerfData(collection_duration.InSeconds(),
                       base::Bind(&PerfProvider::ParseProtoIfValid,
                                  weak_factory_.GetWeakPtr(),
-                                 base::Passed(&incognito_observer)));
+                                 base::Passed(&incognito_observer),
+                                 trigger_event));
 }
 
-void PerfProvider::CollectIfNecessaryAndReschedule() {
-  CollectIfNecessary();
-  ScheduleCollection(
-      base::TimeDelta::FromSeconds(kPerfCommandIntervalDefaultSeconds));
+void PerfProvider::DoPeriodicCollection() {
+  CollectIfNecessary(SampledProfile::PERIODIC_COLLECTION);
+  ScheduleCollection();
 }
 
 void PerfProvider::ParseProtoIfValid(
     scoped_ptr<WindowedIncognitoObserver> incognito_observer,
+    SampledProfile::TriggerEvent trigger_event,
     const std::vector<uint8>& data) {
   DCHECK(CalledOnValidThread());
 
@@ -238,10 +240,19 @@ void PerfProvider::ParseProtoIfValid(
     return;
   }
 
-  // Append a new PerfDataProto to the |cached_perf_data_| vector and swap in
-  // the contents.
+  // Populate a profile collection protobuf with the collected perf data and
+  // extra metadata.
   cached_perf_data_.resize(cached_perf_data_.size() + 1);
-  cached_perf_data_.back().Swap(&perf_data_proto);
+  SampledProfile& collection_data = cached_perf_data_.back();
+  collection_data.set_trigger_event(trigger_event);
+  collection_data.set_ms_after_boot(
+      perf_data_proto.timestamp_sec() * base::Time::kMillisecondsPerSecond);
+
+  DCHECK(!login_time_.is_null());
+  collection_data.
+      set_ms_after_login((base::TimeTicks::Now() - login_time_)
+          .InMilliseconds());
+  *collection_data.mutable_perf_data() = perf_data_proto;
 }
 
 }  // namespace metrics

chrome/browser/metrics/perf_provider_chromeos.h

@@ -13,7 +13,7 @@
 #include "base/time/time.h"
 #include "base/timer/timer.h"
 #include "chromeos/login/login_state.h"
-#include "components/metrics/proto/perf_data.pb.h"
+#include "components/metrics/proto/sampled_profile.pb.h"
 
 namespace metrics {
 
@@ -27,9 +27,9 @@ class PerfProvider : public base::NonThreadSafe {
   PerfProvider();
   ~PerfProvider();
 
-  // Writes collected perf data protobufs to |perf_data|. Clears all the stored
-  // perf data. Returns true if it wrote to |perf_data|.
-  bool GetPerfData(std::vector<PerfDataProto>* perf_data);
+  // Stores collected perf data protobufs in |sampled_profiles|. Clears all the
+  // stored profile data. Returns true if it wrote to |sampled_profiles|.
+  bool GetSampledProfiles(std::vector<SampledProfile>* sampled_profiles);
 
  private:
   // Class that listens for changes to the login state. When a normal user logs
@@ -48,35 +48,38 @@ class PerfProvider : public base::NonThreadSafe {
     PerfProvider* perf_provider_;
   };
 
-  // Turns on perf collection. Resets the timer that's used to schedule
+  // Turns on perf collection. Starts the timer that's used to schedule
   // collections.
-  void Activate();
+  void OnUserLoggedIn();
 
   // Turns off perf collection. Does not delete any data that was already
   // collected and stored in |cached_perf_data_|.
   void Deactivate();
 
-  // Starts an internal timer to start collecting perf data. The timer is set to
-  // trigger |interval| after this function call.
-  void ScheduleCollection(const base::TimeDelta& interval);
+  // Selects a random time in the upcoming profiling interval that begins at
+  // |next_profiling_interval_start_|. Schedules |timer_| to invoke
+  // DoPeriodicCollection() when that time comes.
+  void ScheduleCollection();
 
-  // Collects perf data if it has not been consumed by calling GetPerfData()
-  // (see above).
-  void CollectIfNecessary();
+  // Collects perf data for a given |trigger_event|. Calls perf via the ChromeOS
+  // debug daemon's dbus interface.
+  void CollectIfNecessary(SampledProfile::TriggerEvent trigger_event);
 
-  // Collects perf data by calling CollectIfNecessary() and reschedules it to be
-  // collected again.
-  void CollectIfNecessaryAndReschedule();
+  // Collects perf data on a repeating basis by calling CollectIfNecessary() and
+  // reschedules it to be collected again.
+  void DoPeriodicCollection();
 
-  // Parses a protobuf from the |data| passed in only if the
+  // Parses a perf data protobuf from the |data| passed in only if the
   // |incognito_observer| indicates that no incognito window had been opened
   // during the profile collection period.
+  // |trigger_event| is the cause of the perf data collection.
   void ParseProtoIfValid(
       scoped_ptr<WindowedIncognitoObserver> incognito_observer,
+      SampledProfile::TriggerEvent trigger_event,
       const std::vector<uint8>& data);
 
-  // Vector of perf data protobufs.
-  std::vector<PerfDataProto> cached_perf_data_;
+  // Vector of SampledProfile protobufs containing perf profiles.
+  std::vector<SampledProfile> cached_perf_data_;
 
   // For scheduling collection of perf data.
   base::OneShotTimer<PerfProvider> timer_;
@@ -84,6 +87,12 @@ class PerfProvider : public base::NonThreadSafe {
   // For detecting when changes to the login state.
   LoginObserver login_observer_;
 
+  // Record of the last login time.
+  base::TimeTicks login_time_;
+
+  // Record of the start of the upcoming profiling interval.
+  base::TimeTicks next_profiling_interval_start_;
+
   // To pass around the "this" pointer across threads safely.
   base::WeakPtrFactory<PerfProvider> weak_factory_;