[Sampling profiler] Reland "Add profiler browser tests"

Implements browser tests to verify that startup profiles taken in the
browser and child processes are received by the metrics provider.

To work within the test timeouts and to avoid non-determinism this
requires a couple adaptations to be made to the code when run under
these tests. The profiling period is reduced from 30 seconds to one
second, and profiles are taken in all renderer processes. The behavior
is enabled by providing a 'browser-test' argument to the existing
'start-stack-profiler' switch.

The main thread profiler for browser tests is moved later, after the
command line is set up, to be able to observe the added switch
argument. StackSamplingConfiguration is made responsible for the
sampling parameters, reusing the GetSamplingParamsForCurrentProcess()
function which was previously unused.

This reland of https://crrev.com/716372 gates the tests on channel
since the profiler is enabled only on trunk, canary, and dev, but
the official continuous builders build as stable channel.

Bug: 1011877, 1026575
Change-Id: I1cce130ff035007a2935dfccb2f7e2dca56880ef
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/1938077
Commit-Queue: Mike Wittman <wittman@chromium.org>
Reviewed-by: Etienne Pierre-Doray <etiennep@chromium.org>
Reviewed-by: Lei Zhang <thestig@chromium.org>
Auto-Submit: Mike Wittman <wittman@chromium.org>
Cr-Commit-Position: refs/heads/master@{#721741}

chrome/common/chrome_switches.cc

@@ -587,6 +587,10 @@ const char kStartMaximized[]                = "start-maximized";
 // Starts the stack sampling profiler in the child process.
 const char kStartStackProfiler[]            = "start-stack-profiler";
 
+// Browser test mode for the |kStartStackProfiler| switch. Limits the profile
+// durations to be significantly less than the test timeout.
+const char kStartStackProfilerBrowserTest[] = "browser-test";
+
 // Sets the supervised user ID for any loaded or newly created profile to the
 // given value. Pass an empty string to mark the profile as non-supervised.
 // Used for testing.

chrome/common/chrome_switches.h

@@ -174,6 +174,7 @@ extern const char kSSLVersionTLSv12[];
 extern const char kSSLVersionTLSv13[];
 extern const char kStartMaximized[];
 extern const char kStartStackProfiler[];
+extern const char kStartStackProfilerBrowserTest[];
 extern const char kSupervisedUserId[];
 extern const char kSystemLogUploadFrequency[];
 extern const char kTaskManagerShowExtraRenderers[];

chrome/common/profiler/stack_sampling_browsertest.cc

+// Copyright 2019 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 <vector>
+
+#include "base/bind.h"
+#include "base/no_destructor.h"
+#include "base/run_loop.h"
+#include "base/synchronization/lock.h"
+#include "base/thread_annotations.h"
+#include "base/threading/platform_thread.h"
+#include "chrome/common/channel_info.h"
+#include "chrome/common/chrome_switches.h"
+#include "chrome/test/base/in_process_browser_test.h"
+#include "components/metrics/call_stack_profile_metrics_provider.h"
+#include "components/version_info/channel.h"
+#include "third_party/metrics_proto/sampled_profile.pb.h"
+
+namespace {
+
+// Class that intercepts and stores profiles provided to the
+// CallStackProfileMetricsProvider. Intercept() is invoked on the profiler
+// thread while FetchProfiles() is invoked on the main thread.
+class ProfileInterceptor {
+ public:
+  // Get the static object instance. This object must leak because there is no
+  // synchronization between it and the profiler thread which can invoke
+  // Intercept at any time.
+  static ProfileInterceptor& GetInstance() {
+    static base::NoDestructor<ProfileInterceptor> instance;
+    return *instance;
+  }
+
+  void Intercept(metrics::SampledProfile profile) {
+    base::AutoLock lock(lock_);
+    profiles_.push_back(std::move(profile));
+  }
+
+  std::vector<metrics::SampledProfile> FetchProfiles() {
+    base::AutoLock lock(lock_);
+    std::vector<metrics::SampledProfile> profiles;
+    profiles.swap(profiles_);
+    return profiles;
+  }
+
+ private:
+  base::Lock lock_;
+  std::vector<metrics::SampledProfile> profiles_ GUARDED_BY(lock_);
+};
+
+class StackSamplingBrowserTest : public InProcessBrowserTest {
+ public:
+  void SetUp() override {
+    // Arrange to intercept the CPU profiles at the time they're provided to the
+    // metrics component.
+    metrics::CallStackProfileMetricsProvider::
+        SetCpuInterceptorCallbackForTesting(base::BindRepeating(
+            &ProfileInterceptor::Intercept,
+            base::Unretained(&ProfileInterceptor::GetInstance())));
+    InProcessBrowserTest::SetUp();
+  }
+
+  void SetUpCommandLine(base::CommandLine* command_line) override {
+    // Enable the special browser test mode.
+    command_line->AppendSwitchASCII(switches::kStartStackProfiler,
+                                    switches::kStartStackProfilerBrowserTest);
+  }
+};
+
+// Wait for a profile with the specified properties. Checks once per second
+// until the profile is seen or we time out.
+bool WaitForProfile(metrics::SampledProfile::TriggerEvent trigger_event,
+                    metrics::Process process,
+                    metrics::Thread thread) {
+  // Profiling is only enabled for trunk builds and canary and dev channels.
+  // Perform an early return and pass the test for the other channels.
+  switch (chrome::GetChannel()) {
+    case version_info::Channel::UNKNOWN:
+    case version_info::Channel::CANARY:
+    case version_info::Channel::DEV:
+      break;
+
+    default:
+      return true;
+  }
+
+  // The profiling duration is one second when enabling browser test mode via
+  // the kStartStackProfilerBrowserTest switch argument. We expect to see the
+  // profiles shortly thereafter, but wait up to 30 seconds to give ample time
+  // to avoid flaky failures.
+  int seconds_to_wait = 30;
+  do {
+    std::vector<metrics::SampledProfile> profiles =
+        ProfileInterceptor::GetInstance().FetchProfiles();
+    const bool was_received =
+        std::find_if(profiles.begin(), profiles.end(),
+                     [&](const metrics::SampledProfile& profile) {
+                       return profile.trigger_event() == trigger_event &&
+                              profile.process() == process &&
+                              profile.thread() == thread;
+                     }) != profiles.end();
+    if (was_received)
+      return true;
+    base::PlatformThread::Sleep(base::TimeDelta::FromSeconds(1));
+    // Manually spinning message loop is fine here because the main thread
+    // message loop will not be continuously busy at Chrome startup, and we will
+    // spin it enough over 30 seconds to ensure that any necessary processing is
+    // done.
+    base::RunLoop().RunUntilIdle();
+  } while (--seconds_to_wait > 0);
+
+  return false;
+}
+
+}  // namespace
+
+// Check that we receive startup profiles in the browser process for profiled
+// processes/threads. We've seen multiple breakages previously where profiles
+// were dropped as a result of bugs introduced by mojo refactorings.
+
+IN_PROC_BROWSER_TEST_F(StackSamplingBrowserTest, BrowserProcessMainThread) {
+  EXPECT_TRUE(WaitForProfile(metrics::SampledProfile::PROCESS_STARTUP,
+                             metrics::BROWSER_PROCESS, metrics::MAIN_THREAD));
+}
+
+IN_PROC_BROWSER_TEST_F(StackSamplingBrowserTest, BrowserProcessIOThread) {
+  EXPECT_TRUE(WaitForProfile(metrics::SampledProfile::PROCESS_STARTUP,
+                             metrics::BROWSER_PROCESS, metrics::IO_THREAD));
+}
+
+IN_PROC_BROWSER_TEST_F(StackSamplingBrowserTest, GpuProcessMainThread) {
+  EXPECT_TRUE(WaitForProfile(metrics::SampledProfile::PROCESS_STARTUP,
+                             metrics::GPU_PROCESS, metrics::MAIN_THREAD));
+}
+
+IN_PROC_BROWSER_TEST_F(StackSamplingBrowserTest, GpuProcessIOThread) {
+  EXPECT_TRUE(WaitForProfile(metrics::SampledProfile::PROCESS_STARTUP,
+                             metrics::GPU_PROCESS, metrics::IO_THREAD));
+}
+
+IN_PROC_BROWSER_TEST_F(StackSamplingBrowserTest, GpuProcessCompositorThread) {
+  EXPECT_TRUE(WaitForProfile(metrics::SampledProfile::PROCESS_STARTUP,
+                             metrics::GPU_PROCESS, metrics::COMPOSITOR_THREAD));
+}
+
+IN_PROC_BROWSER_TEST_F(StackSamplingBrowserTest, RendererProcessMainThread) {
+  EXPECT_TRUE(WaitForProfile(metrics::SampledProfile::PROCESS_STARTUP,
+                             metrics::RENDERER_PROCESS, metrics::MAIN_THREAD));
+}
+
+IN_PROC_BROWSER_TEST_F(StackSamplingBrowserTest, RendererProcessIOThread) {
+  EXPECT_TRUE(WaitForProfile(metrics::SampledProfile::PROCESS_STARTUP,
+                             metrics::RENDERER_PROCESS, metrics::IO_THREAD));
+}
+
+IN_PROC_BROWSER_TEST_F(StackSamplingBrowserTest,
+                       RendererProcessCompositorThread) {
+  EXPECT_TRUE(WaitForProfile(metrics::SampledProfile::PROCESS_STARTUP,
+                             metrics::RENDERER_PROCESS,
+                             metrics::COMPOSITOR_THREAD));
+}

chrome/common/profiler/stack_sampling_configuration.cc

@@ -66,7 +66,22 @@ bool IsExtensionRenderer(const base::CommandLine& command_line) {
 #endif
 }
 
+// Allows the profiler to be run in a special browser test mode for testing that
+// profiles are collected as expected, by providing a switch value. The test
+// mode reduces the profiling duration to ensure the startup profiles complete
+// well within the test timeout, and always profiles renderer processes.
+bool IsBrowserTestModeEnabled() {
+  const base::CommandLine* command_line =
+      base::CommandLine::ForCurrentProcess();
+  return command_line->GetSwitchValueASCII(switches::kStartStackProfiler) ==
+         switches::kStartStackProfilerBrowserTest;
+}
+
 bool ShouldEnableProfilerForNextRendererProcess() {
+  // Ensure deterministic behavior for testing the profiler itself.
+  if (IsBrowserTestModeEnabled())
+    return true;
+
   // Enable for every N-th renderer process, where N = 5.
   return base::RandInt(0, 4) == 0;
 }
@@ -92,17 +107,17 @@ StackSamplingConfiguration::StackSamplingConfiguration()
     : configuration_(GenerateConfiguration()) {}
 
 base::StackSamplingProfiler::SamplingParams
-StackSamplingConfiguration::GetSamplingParamsForCurrentProcess() const {
+StackSamplingConfiguration::GetSamplingParams() const {
   base::StackSamplingProfiler::SamplingParams params;
   params.initial_delay = base::TimeDelta::FromMilliseconds(0);
-  params.sampling_interval = base::TimeDelta::FromMilliseconds(0);
-  params.samples_per_profile = 0;
-
-  if (IsProfilerEnabledForCurrentProcess()) {
-    const base::TimeDelta duration = base::TimeDelta::FromSeconds(30);
-    params.sampling_interval = base::TimeDelta::FromMilliseconds(100);
-    params.samples_per_profile = duration / params.sampling_interval;
-  }
+  // Trim the sampling duration when testing the profiler using browser tests.
+  // The standard 30 second duration risks flaky timeouts since it's close to
+  // the test timeout of 45 seconds.
+  const base::TimeDelta duration =
+      base::TimeDelta::FromSeconds(IsBrowserTestModeEnabled() ? 1 : 30);
+  params.sampling_interval = base::TimeDelta::FromMilliseconds(100);
+  params.samples_per_profile = duration / params.sampling_interval;
+  params.keep_consistent_sampling_interval = true;
 
   return params;
 }
@@ -171,7 +186,13 @@ void StackSamplingConfiguration::AppendCommandLineSwitchForChildProcess(
        // compositor thread in them is not useful.
        !IsExtensionRenderer(*command_line) &&
        ShouldEnableProfilerForNextRendererProcess())) {
-    command_line->AppendSwitch(switches::kStartStackProfiler);
+    if (IsBrowserTestModeEnabled()) {
+      // Propagate the browser test mode switch argument to the child processes.
+      command_line->AppendSwitchASCII(switches::kStartStackProfiler,
+                                      switches::kStartStackProfilerBrowserTest);
+    } else {
+      command_line->AppendSwitch(switches::kStartStackProfiler);
+    }
   }
 }
 

chrome/common/profiler/stack_sampling_configuration.h

@@ -23,9 +23,8 @@ class StackSamplingConfiguration {
  public:
   StackSamplingConfiguration();
 
-  // Get the stack sampling params to use for this process.
-  base::StackSamplingProfiler::SamplingParams
-  GetSamplingParamsForCurrentProcess() const;
+  // Get the stack sampling params to use.
+  base::StackSamplingProfiler::SamplingParams GetSamplingParams() const;
 
   // Returns true if the profiler should be started for the current process.
   bool IsProfilerEnabledForCurrentProcess() const;

chrome/common/profiler/thread_profiler.cc

@@ -40,12 +40,6 @@ ThreadProfiler* g_main_thread_instance = nullptr;
 // Run continuous profiling 2% of the time.
 constexpr const double kFractionOfExecutionTimeToSample = 0.02;
 
-constexpr struct StackSamplingProfiler::SamplingParams kSamplingParams = {
-    /* initial_delay= */ base::TimeDelta::FromMilliseconds(0),
-    /* samples_per_profile= */ 300,
-    /* sampling_interval= */ base::TimeDelta::FromMilliseconds(100),
-    /* keep_consistent_sampling_interval= */ true};
-
 CallStackProfileParams::Process GetProcess() {
   const base::CommandLine* command_line =
       base::CommandLine::ForCurrentProcess();
@@ -238,8 +232,10 @@ ThreadProfiler::ThreadProfiler(
   if (!StackSamplingConfiguration::Get()->IsProfilerEnabledForCurrentProcess())
     return;
 
+  const base::StackSamplingProfiler::SamplingParams sampling_params =
+      StackSamplingConfiguration::Get()->GetSamplingParams();
   startup_profiler_ = std::make_unique<StackSamplingProfiler>(
-      base::GetSamplingProfilerCurrentThreadToken(), kSamplingParams,
+      base::GetSamplingProfilerCurrentThreadToken(), sampling_params,
       std::make_unique<CallStackProfileBuilder>(
           CallStackProfileParams(GetProcess(), thread,
                                  CallStackProfileParams::PROCESS_STARTUP),
@@ -253,10 +249,10 @@ ThreadProfiler::ThreadProfiler(
   // profiling.
   base::TimeTicks startup_profiling_completion_time =
       base::TimeTicks::Now() +
-      kSamplingParams.samples_per_profile * kSamplingParams.sampling_interval;
+      sampling_params.samples_per_profile * sampling_params.sampling_interval;
 
   periodic_sampling_scheduler_ = std::make_unique<PeriodicSamplingScheduler>(
-      kSamplingParams.samples_per_profile * kSamplingParams.sampling_interval,
+      sampling_params.samples_per_profile * sampling_params.sampling_interval,
       kFractionOfExecutionTimeToSample, startup_profiling_completion_time);
 
   if (owning_thread_task_runner_)
@@ -299,7 +295,8 @@ void ThreadProfiler::StartPeriodicSamplingCollection() {
   DCHECK_CALLED_ON_VALID_THREAD(thread_checker_);
   // NB: Destroys the previous profiler as side effect.
   periodic_profiler_ = std::make_unique<StackSamplingProfiler>(
-      base::GetSamplingProfilerCurrentThreadToken(), kSamplingParams,
+      base::GetSamplingProfilerCurrentThreadToken(),
+      StackSamplingConfiguration::Get()->GetSamplingParams(),
       std::make_unique<CallStackProfileBuilder>(
           CallStackProfileParams(GetProcess(), thread_,
                                  CallStackProfileParams::PERIODIC_COLLECTION),

chrome/test/BUILD.gn

@@ -2530,6 +2530,7 @@ if (!is_android) {
         "../browser/ui/cocoa/touchbar/browser_window_touch_bar_controller_browsertest.mm",
         "../browser/ui/views/certificate_viewer_mac_browsertest.mm",
         "../browser/ui/views/ssl_client_certificate_selector_mac_browsertest.mm",
+        "../common/profiler/stack_sampling_browsertest.cc",
 
         # TODO(crbug/845389): Re-Enable the following, which were temporarily
         # omitted from the build, but are still in use.
@@ -2565,6 +2566,10 @@ if (!is_android) {
         "../browser/ui/views/uninstall_view_browsertest.cc",
       ]
 
+      if (target_cpu == "x64") {
+        sources += [ "../common/profiler/stack_sampling_browsertest.cc" ]
+      }
+
       configs += [ "//build/config/win:delayloads" ]
 
       deps += [

chrome/test/base/in_process_browser_test.cc

@@ -194,11 +194,6 @@ void InProcessBrowserTest::SetUp() {
   // Browser tests will create their own g_browser_process later.
   DCHECK(!g_browser_process);
 
-  // Initialize sampling profiler in browser tests. This mimics the behavior
-  // in standalone Chrome, where this is done in chrome/app/chrome_main.cc,
-  // which does not get called by browser tests.
-  sampling_profiler_ = std::make_unique<MainThreadStackSamplingProfiler>();
-
   base::CommandLine* command_line = base::CommandLine::ForCurrentProcess();
 
   // Auto-reload breaks many browser tests, which assume error pages won't be
@@ -211,6 +206,11 @@ void InProcessBrowserTest::SetUp() {
   // Add command line arguments that are used by all InProcessBrowserTests.
   SetUpDefaultCommandLine(command_line);
 
+  // Initialize sampling profiler in browser tests. This mimics the behavior
+  // in standalone Chrome, where this is done in chrome/app/chrome_main.cc,
+  // which does not get called by browser tests.
+  sampling_profiler_ = std::make_unique<MainThreadStackSamplingProfiler>();
+
   // Create a temporary user data directory if required.
   ASSERT_TRUE(test_launcher_utils::CreateUserDataDir(&temp_user_data_dir_))
       << "Could not create user data directory.";

components/metrics/call_stack_profile_metrics_provider.cc

@@ -29,6 +29,17 @@ namespace {
 // TODO(wittman): Remove this threshold after crbug.com/903972 is fixed.
 const size_t kMaxPendingProfiles = 1250;
 
+// Provides access to the singleton interceptor callback instance for CPU
+// profiles. Accessed asynchronously on the profiling thread after profiling has
+// been started.
+CallStackProfileMetricsProvider::InterceptorCallback&
+GetCpuInterceptorCallbackInstance() {
+  static base::NoDestructor<
+      CallStackProfileMetricsProvider::InterceptorCallback>
+      instance;
+  return *instance;
+}
+
 // PendingProfiles ------------------------------------------------------------
 
 // Singleton class responsible for retaining profiles received from
@@ -232,6 +243,13 @@ CallStackProfileMetricsProvider::~CallStackProfileMetricsProvider() = default;
 void CallStackProfileMetricsProvider::ReceiveProfile(
     base::TimeTicks profile_start_time,
     SampledProfile profile) {
+  if (GetCpuInterceptorCallbackInstance() &&
+      (profile.trigger_event() == SampledProfile::PROCESS_STARTUP ||
+       profile.trigger_event() == SampledProfile::PERIODIC_COLLECTION)) {
+    GetCpuInterceptorCallbackInstance().Run(std::move(profile));
+    return;
+  }
+
   const base::Feature& feature =
       profile.trigger_event() == SampledProfile::PERIODIC_HEAP_COLLECTION
           ? kHeapProfilerReporting
@@ -248,12 +266,29 @@ void CallStackProfileMetricsProvider::ReceiveSerializedProfile(
     std::string serialized_profile) {
   // Heap profiler does not use this path as it only reports profiles
   // from the browser process.
+  if (GetCpuInterceptorCallbackInstance()) {
+    SampledProfile profile;
+    if (profile.ParseFromArray(serialized_profile.data(),
+                               serialized_profile.size())) {
+      DCHECK(profile.trigger_event() == SampledProfile::PROCESS_STARTUP ||
+             profile.trigger_event() == SampledProfile::PERIODIC_COLLECTION);
+      GetCpuInterceptorCallbackInstance().Run(std::move(profile));
+    }
+    return;
+  }
+
   if (!base::FeatureList::IsEnabled(kSamplingProfilerReporting))
     return;
   PendingProfiles::GetInstance()->MaybeCollectSerializedProfile(
       profile_start_time, std::move(serialized_profile));
 }
 
+// static
+void CallStackProfileMetricsProvider::SetCpuInterceptorCallbackForTesting(
+    InterceptorCallback callback) {
+  GetCpuInterceptorCallbackInstance() = std::move(callback);
+}
+
 void CallStackProfileMetricsProvider::OnRecordingEnabled() {
   PendingProfiles::GetInstance()->SetCollectionEnabled(true);
 }

components/metrics/call_stack_profile_metrics_provider.h

@@ -7,6 +7,7 @@
 
 #include <string>
 
+#include "base/callback.h"
 #include "base/feature_list.h"
 #include "base/macros.h"
 #include "base/time/time.h"
@@ -20,6 +21,11 @@ class ChromeUserMetricsExtension;
 // Performs metrics logging for the stack sampling profiler.
 class CallStackProfileMetricsProvider : public MetricsProvider {
  public:
+  // A callback type that can be registered to intercept profiles, for testing
+  // purposes.
+  using InterceptorCallback =
+      base::RepeatingCallback<void(SampledProfile profile)>;
+
   CallStackProfileMetricsProvider();
   ~CallStackProfileMetricsProvider() override;
 
@@ -36,6 +42,12 @@ class CallStackProfileMetricsProvider : public MetricsProvider {
   static void ReceiveSerializedProfile(base::TimeTicks profile_start_time,
                                        std::string serialized_sampled_profile);
 
+  // Allows tests to intercept received CPU profiles, to validate that the
+  // expected profiles are received. This function must be invoked prior to
+  // starting any profiling since the callback is accessed asynchronously on the
+  // profiling thread.
+  static void SetCpuInterceptorCallbackForTesting(InterceptorCallback callback);
+
   // MetricsProvider:
   void OnRecordingEnabled() override;
   void OnRecordingDisabled() override;