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 kbase::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,
-    StackSamplingProfiler::CallStackProfiles profiles) {
+bool ReceiveCompletedProfilesImpl(
+    CallStackProfileParams* params,
+    StackSamplingProfiler::CallStackProfiles profiles,
+    StackSamplingProfiler::SamplingParams* sampling_params) {
   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.
+  if (sampling_params &&
+      CallStackProfileMetricsProvider::IsPeriodicSamplingEnabled() &&
+      params->process == CallStackProfileParams::BROWSER_PROCESS &&
+      params->thread == CallStackProfileParams::UI_THREAD) {
+    params->trigger = metrics::CallStackProfileParams::PERIODIC_COLLECTION;
+    params->start_timestamp = base::TimeTicks::Now();
+    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 true;
+  }
+  return false;
 }
 
 // Invoked on an arbitrary thread. Ignores the provided profiles.
-void IgnoreCompletedProfiles(
-    StackSamplingProfiler::CallStackProfiles profiles) {}
+bool IgnoreCompletedProfiles(
+    StackSamplingProfiler::CallStackProfiles profiles,
+    StackSamplingProfiler::SamplingParams* sampling_params) {
+  return false;
+}
 
 // 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 91 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());
+
+  int64_t sampling_period_ms = profile.sampling_period.InMilliseconds();
+  DCHECK(proto_profile->has_trigger_event());
+  if (proto_profile->trigger_event() == SampledProfile::PERIODIC_COLLECTION)
+    sampling_period_ms += kPeriodicSampling.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), nullptr);
+}
+
+// static
+bool CallStackProfileMetricsProvider::IsPeriodicSamplingEnabled() {
+  return base::GetFieldTrialParamByFeatureAsBool(kEnableReporting, "periodic",

[Mike Wittman, 2017/07/01 02:44:06]

Will this function execute properly and return something sensible if invoked
before the metrics service is initialized?

[Alexei Svitkine (slow), 2017/07/06 15:51:09]

It doesn't care about metrics service being initialized.

However, it does care about VariationsService::CreateTrialsFromSeed having
already been called. Which happens during single-threaded startup shortly after
reading the local state file. That's when base::FeatureList is initialized and
it's forbidden to call into base::FeatureList::IsEnabled() before then (which
the called function does).

I guess the concern is if we get the callback call before that point? It should
be very unlikely ... but I guess not impossible - e.g. if machine got suspended
or something during Chrome startup.

OK, given the above, added a check that feature list has been initialized with a
comment.

[Mike Wittman, 2017/07/06 17:25:52]

It should be pretty rare, but I've seen cases where startup hangs for the better
part of the 30 seconds in one function (e.g. due to waiting for files to load
from a network filesystem). So I also would not be surprised if it happens from
time to time.

+                                                 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));
       CopyProfileToProto(profile, profiles_state.params.ordering_spec,
                          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