Make stack sampling profiler sample beyond startup.

components/metrics/call_stack_profile_metrics_provider.cc

 // Copyright 2015 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/metrics/call_stack_profile_metrics_provider.h"
 
 #include <stddef.h>
 #include <stdint.h>
 
 #include <algorithm>
 #include <cstring>
 #include <map>
 #include <string>
 #include <utility>
 #include <vector>
 
 #include "base/bind.h"
 #include "base/location.h"
 #include "base/logging.h"
 #include "base/macros.h"
 #include "base/memory/singleton.h"
-#include "base/metrics/field_trial.h"
+#include "base/metrics/field_trial_params.h"
 #include "base/metrics/metrics_hashes.h"
 #include "base/profiler/stack_sampling_profiler.h"
 #include "base/single_thread_task_runner.h"
 #include "base/synchronization/lock.h"
 #include "base/threading/thread_task_runner_handle.h"
 #include "base/time/time.h"
 #include "components/metrics/proto/chrome_user_metrics_extension.pb.h"
 
 using base::StackSamplingProfiler;
 
 namespace metrics {
 
 namespace {
 
+// Interval for periodic (post-startup) sampling, when enabled.
+constexpr base::TimeDelta kPeriodicSamplingInterval =
+    base::TimeDelta::FromSeconds(1);
+
 // Provide a mapping from the C++ "enum" definition of various process mile-
 // stones to the equivalent protobuf "enum" definition. This table-lookup
 // conversion allows for the implementation to evolve and still be compatible
 // with the protobuf -- even if there are ever more than 32 defined proto
 // values, though never more than 32 could be in-use in a given C++ version
 // of the code.
 const ProcessPhase
     kProtoPhases[CallStackProfileMetricsProvider::MILESTONES_MAX_VALUE] = {
         ProcessPhase::MAIN_LOOP_START,
         ProcessPhase::MAIN_NAVIGATION_START,
         ProcessPhase::MAIN_NAVIGATION_FINISHED,
         ProcessPhase::FIRST_NONEMPTY_PAINT,
 
         ProcessPhase::SHUTDOWN_START,
 };
 
 // ProfilesState --------------------------------------------------------------
 
 // A set of profiles and the CallStackProfileMetricsProvider state associated
 // with them.
 struct ProfilesState {
   ProfilesState(const CallStackProfileParams& params,
-                StackSamplingProfiler::CallStackProfiles profiles,
-                base::TimeTicks start_timestamp);
+                StackSamplingProfiler::CallStackProfiles profiles);
   ProfilesState(ProfilesState&&);
   ProfilesState& operator=(ProfilesState&&);
 
   // The metrics-related parameters provided to
   // CallStackProfileMetricsProvider::GetProfilerCallback().
   CallStackProfileParams params;
 
   // The call stack profiles collected by the profiler.
   StackSamplingProfiler::CallStackProfiles profiles;
 
-  // The time at which the CallStackProfileMetricsProvider became aware of the
-  // request for profiling. In particular, this is when callback was requested
-  // via CallStackProfileMetricsProvider::GetProfilerCallback(). Used to
-  // determine if collection was disabled during the collection of the profile.
-  base::TimeTicks start_timestamp;
-
  private:
   DISALLOW_COPY_AND_ASSIGN(ProfilesState);
 };
 
 ProfilesState::ProfilesState(const CallStackProfileParams& params,
-                             StackSamplingProfiler::CallStackProfiles profiles,
-                             base::TimeTicks start_timestamp)
-    : params(params),
-      profiles(std::move(profiles)),
-      start_timestamp(start_timestamp) {}
+                             StackSamplingProfiler::CallStackProfiles profiles)
+    : params(params), profiles(std::move(profiles)) {}
 
 ProfilesState::ProfilesState(ProfilesState&&) = default;
 
 // Some versions of GCC need this for push_back to work with std::move.
 ProfilesState& ProfilesState::operator=(ProfilesState&&) = default;
 
 // PendingProfiles ------------------------------------------------------------
 
 // Singleton class responsible for retaining profiles received via the callback
 // created by CallStackProfileMetricsProvider::GetProfilerCallback(). These are
@@ skipping 76 matching lines @@
 }
 
 void PendingProfiles::CollectProfilesIfCollectionEnabled(
     ProfilesState profiles) {
   base::AutoLock scoped_lock(lock_);
 
   // Only collect if collection is not disabled and hasn't been disabled
   // since the start of collection for this profile.
   if (!collection_enabled_ ||
       (!last_collection_disable_time_.is_null() &&
-       last_collection_disable_time_ >= profiles.start_timestamp)) {
+       last_collection_disable_time_ >= profiles.params.start_timestamp)) {
     return;
   }
 
   profiles_.push_back(std::move(profiles));
 }
 
 void PendingProfiles::ResetToDefaultStateForTesting() {
   base::AutoLock scoped_lock(lock_);
 
   collection_enabled_ = true;
   last_collection_disable_time_ = base::TimeTicks();
   profiles_.clear();
 }
 
 // |collection_enabled_| is initialized to true to collect any profiles that are
 // generated prior to creation of the CallStackProfileMetricsProvider. The
 // ultimate disposition of these pre-creation collected profiles will be
 // determined by the initial recording state provided to
 // CallStackProfileMetricsProvider.
 PendingProfiles::PendingProfiles() : collection_enabled_(true) {}
 
 PendingProfiles::~PendingProfiles() {}
 
 // Functions to process completed profiles ------------------------------------
 
 // Will be invoked on either the main thread or the profiler's thread. Provides
 // the profiles to PendingProfiles to append, if the collecting state allows.
-void ReceiveCompletedProfilesImpl(
-    const CallStackProfileParams& params,
-    base::TimeTicks start_timestamp,
+base::Optional<StackSamplingProfiler::SamplingParams>
+ReceiveCompletedProfilesImpl(
+    CallStackProfileParams* params,
     StackSamplingProfiler::CallStackProfiles profiles) {
   PendingProfiles::GetInstance()->CollectProfilesIfCollectionEnabled(
-      ProfilesState(params, std::move(profiles), start_timestamp));
+      ProfilesState(*params, std::move(profiles)));
+
+  // Now, schedule periodic sampling every 1s, if enabled by trial.
+  // TODO(asvitkine): Support periodic sampling for non-browser processes.
+  if (CallStackProfileMetricsProvider::IsPeriodicSamplingEnabled() &&
+      params->process == CallStackProfileParams::BROWSER_PROCESS &&
+      params->thread == CallStackProfileParams::UI_THREAD) {
+    params->trigger = metrics::CallStackProfileParams::PERIODIC_COLLECTION;
+    params->start_timestamp = base::TimeTicks::Now();
+
+    StackSamplingProfiler::SamplingParams sampling_params;
+    sampling_params.initial_delay = kPeriodicSamplingInterval;
+    sampling_params.bursts = 1;
+    sampling_params.samples_per_burst = 1;
+    // Below are unused:
+    sampling_params.burst_interval = base::TimeDelta::FromMilliseconds(0);
+    sampling_params.sampling_interval = base::TimeDelta::FromMilliseconds(0);
+    return sampling_params;
+  }
+  return base::Optional<StackSamplingProfiler::SamplingParams>();
 }
 
 // Invoked on an arbitrary thread. Ignores the provided profiles.
-void IgnoreCompletedProfiles(
-    StackSamplingProfiler::CallStackProfiles profiles) {}
+base::Optional<StackSamplingProfiler::SamplingParams> IgnoreCompletedProfiles(
+    StackSamplingProfiler::CallStackProfiles profiles) {
+  return base::Optional<StackSamplingProfiler::SamplingParams>();
+}
 
 // Functions to encode protobufs ----------------------------------------------
 
 // The protobuf expects the MD5 checksum prefix of the module name.
 uint64_t HashModuleFilename(const base::FilePath& filename) {
   const base::FilePath::StringType basename = filename.BaseName().value();
   // Copy the bytes in basename into a string buffer.
   size_t basename_length_in_bytes =
       basename.size() * sizeof(base::FilePath::CharType);
   std::string name_bytes(basename_length_in_bytes, '\0');
@@ skipping 41 matching lines @@
       sample_proto->add_process_phase(kProtoPhases[bit]);
       new_milestones ^= flag;  // Bit is set so XOR will clear it.
     }
   }
 }
 
 // Transcode |profile| into |proto_profile|.
 void CopyProfileToProto(
     const StackSamplingProfiler::CallStackProfile& profile,
     CallStackProfileParams::SampleOrderingSpec ordering_spec,
+    int64_t sampling_period_ms,
     CallStackProfile* proto_profile) {
   if (profile.samples.empty())
     return;
 
   const bool preserve_order =
       (ordering_spec == CallStackProfileParams::PRESERVE_ORDER);
 
   std::map<StackSamplingProfiler::Sample, int> sample_index;
   uint32_t milestones = 0;
   for (auto it = profile.samples.begin(); it != profile.samples.end(); ++it) {
@@ skipping 30 matching lines @@
 
   for (const StackSamplingProfiler::Module& module : profile.modules) {
     CallStackProfile::ModuleIdentifier* module_id =
         proto_profile->add_module_id();
     module_id->set_build_id(module.id);
     module_id->set_name_md5_prefix(HashModuleFilename(module.filename));
   }
 
   proto_profile->set_profile_duration_ms(
       profile.profile_duration.InMilliseconds());
-  proto_profile->set_sampling_period_ms(
-      profile.sampling_period.InMilliseconds());
+  proto_profile->set_sampling_period_ms(sampling_period_ms);
 }
 
 // Translates CallStackProfileParams's process to the corresponding
 // execution context Process.
 Process ToExecutionContextProcess(CallStackProfileParams::Process process) {
   switch (process) {
     case CallStackProfileParams::UNKNOWN_PROCESS:
       return UNKNOWN_PROCESS;
     case CallStackProfileParams::BROWSER_PROCESS:
       return BROWSER_PROCESS;
@@ skipping 53 matching lines @@
     CallStackProfileParams::Trigger trigger) {
   switch (trigger) {
     case CallStackProfileParams::UNKNOWN:
       return SampledProfile::UNKNOWN_TRIGGER_EVENT;
     case CallStackProfileParams::PROCESS_STARTUP:
       return SampledProfile::PROCESS_STARTUP;
     case CallStackProfileParams::JANKY_TASK:
       return SampledProfile::JANKY_TASK;
     case CallStackProfileParams::THREAD_HUNG:
       return SampledProfile::THREAD_HUNG;
+    case CallStackProfileParams::PERIODIC_COLLECTION:
+      return SampledProfile::PERIODIC_COLLECTION;
   }
   NOTREACHED();
   return SampledProfile::UNKNOWN_TRIGGER_EVENT;
 }
 
 }  // namespace
 
 // CallStackProfileMetricsProvider --------------------------------------------
 
-const char CallStackProfileMetricsProvider::kFieldTrialName[] =
-    "StackProfiling";
-const char CallStackProfileMetricsProvider::kReportProfilesGroupName[] =
-    "Report profiles";
+const base::Feature CallStackProfileMetricsProvider::kEnableReporting = {
+    "SamplingProfilerReporting", base::FEATURE_DISABLED_BY_DEFAULT};
 
 CallStackProfileMetricsProvider::CallStackProfileMetricsProvider() {
 }
 
 CallStackProfileMetricsProvider::~CallStackProfileMetricsProvider() {
 }
 
 // This function can be invoked on an abitrary thread.
 StackSamplingProfiler::CompletedCallback
 CallStackProfileMetricsProvider::GetProfilerCallback(
-    const CallStackProfileParams& params) {
+    CallStackProfileParams* params) {
   // Ignore the profiles if the collection is disabled. If the collection state
   // changes while collecting, this will be detected by the callback and
   // profiles will be ignored at that point.
   if (!PendingProfiles::GetInstance()->IsCollectionEnabled())
     return base::Bind(&IgnoreCompletedProfiles);
 
-  return base::Bind(&ReceiveCompletedProfilesImpl, params,
-                    base::TimeTicks::Now());
+  params->start_timestamp = base::TimeTicks::Now();
+  return base::Bind(&ReceiveCompletedProfilesImpl, params);
 }
 
 // static
 void CallStackProfileMetricsProvider::ReceiveCompletedProfiles(
-    const CallStackProfileParams& params,
-    base::TimeTicks start_timestamp,
-    StackSamplingProfiler::CallStackProfiles profiles) {
-  ReceiveCompletedProfilesImpl(params, start_timestamp, std::move(profiles));
+    CallStackProfileParams* params,
+    base::StackSamplingProfiler::CallStackProfiles profiles) {
+  ReceiveCompletedProfilesImpl(params, std::move(profiles));
+}
+
+// static
+bool CallStackProfileMetricsProvider::IsPeriodicSamplingEnabled() {
+  // Ensure FeatureList has been initialized before calling into an API that
+  // calls base::FeatureList::IsEnabled() internally. While extremely unlikely,
+  // it is possible that the profiler callback and therefore this function get
+  // called before FeatureList initialization (e.g. if machine was suspended).
+  return base::FeatureList::GetInstance() != nullptr &&
+         base::GetFieldTrialParamByFeatureAsBool(kEnableReporting, "periodic",
+                                                 false);
 }
 
 void CallStackProfileMetricsProvider::OnRecordingEnabled() {
   PendingProfiles::GetInstance()->SetCollectionEnabled(true);
 }
 
 void CallStackProfileMetricsProvider::OnRecordingDisabled() {
   PendingProfiles::GetInstance()->SetCollectionEnabled(false);
 }
 
 void CallStackProfileMetricsProvider::ProvideGeneralMetrics(
     ChromeUserMetricsExtension* uma_proto) {
   std::vector<ProfilesState> pending_profiles;
   PendingProfiles::GetInstance()->Swap(&pending_profiles);
 
   DCHECK(IsReportingEnabledByFieldTrial() || pending_profiles.empty());
 
+  // TODO(asvitkine): For post-startup periodic samples, this is currently
+  // wasteful as each sample is reported in its own profile. We should attempt
+  // to merge profiles to save bandwidth.
   for (const ProfilesState& profiles_state : pending_profiles) {
     for (const StackSamplingProfiler::CallStackProfile& profile :
              profiles_state.profiles) {
       SampledProfile* sampled_profile = uma_proto->add_sampled_profile();
-      sampled_profile->set_process(ToExecutionContextProcess(
-          profiles_state.params.process));
-      sampled_profile->set_thread(ToExecutionContextThread(
-          profiles_state.params.thread));
-      sampled_profile->set_trigger_event(ToSampledProfileTriggerEvent(
-          profiles_state.params.trigger));
+      sampled_profile->set_process(
+          ToExecutionContextProcess(profiles_state.params.process));
+      sampled_profile->set_thread(
+          ToExecutionContextThread(profiles_state.params.thread));
+      sampled_profile->set_trigger_event(
+          ToSampledProfileTriggerEvent(profiles_state.params.trigger));
+
+      int64_t sampling_period_ms = profile.sampling_period.InMilliseconds();
+      if (sampled_profile->trigger_event() ==
+          SampledProfile::PERIODIC_COLLECTION) {
+        sampling_period_ms += kPeriodicSamplingInterval.InMilliseconds();

[Mike Wittman, 2017/07/07 21:01:11]

Sorry, overlooked this change earlier. We actually need to add
1*sampling_interval to the profile_duration when it is set in
StackSamplingProfiler to account for the duration of the last sample (this
should only affect the non-continuous case, actually).

In the continuous case, we'll need to use sampling_period_ms in the proto to
represent the inter-profile interval. This code is pretty much doing that,
except that we can assign directly from
kPeriodicSamplingInterval.InMilliseconds() rather than adding the value.

And also in the continuous case, we probably should use the proto's
profile_duration_ms to represent the time since startup. I suspect we may want
to do time-dependent analyses using that value, either to separately consider
execution from short-running users vs. long-running users, or to consider
execution during specific time periods post-startup. Without it, I suspect the
samples from long-running users will tend to dominate the results and possibly
wash out other interesting effects.

[Alexei Svitkine (slow), 2017/07/10 22:05:37]

Done. Moved the logic to CollectProfilesIfCollectionEnabled() now (since we need
uptime at the time of receiving the profile), so this loop body is reverted to
how it was before.

+      }
       CopyProfileToProto(profile, profiles_state.params.ordering_spec,
+                         sampling_period_ms,
                          sampled_profile->mutable_call_stack_profile());
     }
   }
 }
 
 // static
 void CallStackProfileMetricsProvider::ResetStaticStateForTesting() {
   PendingProfiles::GetInstance()->ResetToDefaultStateForTesting();
 }
 
 // static
 bool CallStackProfileMetricsProvider::IsReportingEnabledByFieldTrial() {
-  const std::string group_name = base::FieldTrialList::FindFullName(
-      CallStackProfileMetricsProvider::kFieldTrialName);
-  return group_name ==
-      CallStackProfileMetricsProvider::kReportProfilesGroupName;
+  return base::FeatureList::IsEnabled(kEnableReporting);
 }
 
 }  // namespace metrics