Reland "Support startup tracing for sampling profiler"

This reverts commit 11db5550.

Reason for revert: Fix tests

Original change's description:
> Revert "Support startup tracing for sampling profiler"
>
> This reverts commit 21db0fea.
>
> Reason for revert: Likely reason for  deterministically failing
> TracingSampleProfilerTest.TestStartupTracing on Mac ASan 64 bot.
>
> Bug: 987615
>
> Original change's description:
> > Support startup tracing for sampling profiler
> >
> > The profiler buffers events and adds to trace when enabled.
> >
> > Change-Id: I0291b83379cae5192fe08c545709a59dd1c8704c
> > Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/1717684
> > Commit-Queue: ssid <ssid@chromium.org>
> > Reviewed-by: oysteine <oysteine@chromium.org>
> > Cr-Commit-Position: refs/heads/master@{#680740}
>
> TBR=oysteine@chromium.org,ssid@chromium.org
>
> Change-Id: I073798fd81482b2356f8588242b48769bf1f4e0f
> No-Presubmit: true
> No-Tree-Checks: true
> No-Try: true
> Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/1718106
> Reviewed-by: Friedrich [CET] <fhorschig@chromium.org>
> Commit-Queue: Friedrich [CET] <fhorschig@chromium.org>
> Cr-Commit-Position: refs/heads/master@{#680817}

TBR=oysteine@chromium.org,ssid@chromium.org,fhorschig@chromium.org

Change-Id: I66afe6ba6dc6158f0f18677b92f539ed2e3e8781
Bug: 987615
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/1719305
Commit-Queue: ssid <ssid@chromium.org>
Reviewed-by: ssid <ssid@chromium.org>
Reviewed-by: oysteine <oysteine@chromium.org>
Cr-Commit-Position: refs/heads/master@{#681103}

services/tracing/public/cpp/stack_sampling/tracing_sampler_profiler.cc

@@ -61,25 +61,41 @@ class TracingSamplerProfilerDataSource
 
   void RegisterProfiler(TracingSamplerProfiler* profiler) {
     base::AutoLock lock(lock_);
-    if (!profilers_.insert(profiler).second || !is_started_) {
+    if (!profilers_.insert(profiler).second) {
       return;
     }
 
-    profiler->StartTracing(
-        perfetto_producer_->CreateTraceWriter(
-            data_source_config_.target_buffer()),
-        data_source_config_.chrome_config().privacy_filtering_enabled());
+    if (is_started_) {
+      profiler->StartTracing(
+          perfetto_producer_->CreateTraceWriter(
+              data_source_config_.target_buffer()),
+          data_source_config_.chrome_config().privacy_filtering_enabled());
+    } else if (is_startup_tracing_) {
+      profiler->StartTracing(nullptr, /*should_enable_filtering=*/true);
+    }
   }
 
   void UnregisterProfiler(TracingSamplerProfiler* profiler) {
     base::AutoLock lock(lock_);
-    if (!profilers_.erase(profiler) || !is_started_) {
+    if (!profilers_.erase(profiler) || !(is_started_ || is_startup_tracing_)) {
       return;
     }
 
     profiler->StopTracing();
   }
 
+  void SetupStartupTracing() {
+    base::AutoLock lock(lock_);
+    if (is_started_) {
+      return;
+    }
+    is_startup_tracing_ = true;
+    for (auto* profiler : profilers_) {
+      // Enable filtering for startup tracing always to be safe.
+      profiler->StartTracing(nullptr, /*should_enable_filtering=*/true);
+    }
+  }
+
   // PerfettoTracedProcess::DataSourceBase implementation, called by
   // ProducerClient.
   void StartTracing(
@@ -88,6 +104,7 @@ class TracingSamplerProfilerDataSource
     base::AutoLock lock(lock_);
     DCHECK(!is_started_);
     is_started_ = true;
+    is_startup_tracing_ = false;
     perfetto_producer_ = producer;
     data_source_config_ = data_source_config;
 
@@ -105,6 +122,7 @@ class TracingSamplerProfilerDataSource
     base::AutoLock lock(lock_);
     DCHECK(is_started_);
     is_started_ = false;
+    is_startup_tracing_ = false;
     perfetto_producer_ = nullptr;
 
     for (auto* profiler : profilers_) {
@@ -129,6 +147,7 @@ class TracingSamplerProfilerDataSource
  private:
   base::Lock lock_;  // Protects subsequent members.
   std::set<TracingSamplerProfiler*> profilers_;
+  bool is_startup_tracing_ = false;
   bool is_started_ = false;
   PerfettoProducer* perfetto_producer_ = nullptr;
   perfetto::DataSourceConfig data_source_config_;
@@ -151,6 +170,18 @@ base::ThreadLocalStorage::Slot* GetThreadLocalStorageProfilerSlot() {
 
 }  // namespace
 
+TracingSamplerProfiler::TracingProfileBuilder::BufferedSample::BufferedSample(
+    base::TimeTicks ts,
+    std::vector<base::Frame>&& s)
+    : timestamp(ts), sample(std::move(s)) {}
+
+TracingSamplerProfiler::TracingProfileBuilder::BufferedSample::
+    ~BufferedSample() = default;
+
+TracingSamplerProfiler::TracingProfileBuilder::BufferedSample::BufferedSample(
+    TracingSamplerProfiler::TracingProfileBuilder::BufferedSample&& other)
+    : BufferedSample(other.timestamp, std::move(other.sample)) {}
+
 TracingSamplerProfiler::TracingProfileBuilder::TracingProfileBuilder(
     base::PlatformThreadId sampled_thread_id,
     std::unique_ptr<perfetto::TraceWriter> trace_writer,
@@ -182,6 +213,27 @@ TracingSamplerProfiler::TracingProfileBuilder::GetModuleCache() {
 
 void TracingSamplerProfiler::TracingProfileBuilder::OnSampleCompleted(
     std::vector<base::Frame> frames) {
+  base::AutoLock l(trace_writer_lock_);
+  if (!trace_writer_) {
+    if (buffered_samples_.size() < kMaxBufferedSamples) {
+      buffered_samples_.emplace_back(
+          BufferedSample(TRACE_TIME_TICKS_NOW(), std::move(frames)));
+    }
+    return;
+  }
+  if (!buffered_samples_.empty()) {
+    for (const auto& sample : buffered_samples_) {
+      WriteSampleToTrace(sample);
+    }
+    buffered_samples_.clear();
+  }
+  WriteSampleToTrace(BufferedSample(TRACE_TIME_TICKS_NOW(), std::move(frames)));
+}
+
+void TracingSamplerProfiler::TracingProfileBuilder::WriteSampleToTrace(
+    const TracingSamplerProfiler::TracingProfileBuilder::BufferedSample&
+        sample) {
+  const auto& frames = sample.sample;
   auto reset_id =
       TracingSamplerProfilerDataSource::GetIncrementalStateResetID();
   if (reset_id != last_incremental_state_reset_id_) {
@@ -206,13 +258,12 @@ void TracingSamplerProfiler::TracingProfileBuilder::OnSampleCompleted(
     auto* thread_descriptor = trace_packet->set_thread_descriptor();
     thread_descriptor->set_pid(base::GetCurrentProcId());
     thread_descriptor->set_tid(sampled_thread_id_);
-    last_timestamp_ = TRACE_TIME_TICKS_NOW();
+    last_timestamp_ = sample.timestamp;
     thread_descriptor->set_reference_timestamp_us(
         last_timestamp_.since_origin().InMicroseconds());
     reset_incremental_state_ = false;
   }
 
-  auto time_now = TRACE_TIME_TICKS_NOW();
   int32_t current_process_priority = base::Process::Current().GetPriority();
   if (current_process_priority != last_emitted_process_priority_) {
     last_emitted_process_priority_ = current_process_priority;
@@ -227,8 +278,14 @@ void TracingSamplerProfiler::TracingProfileBuilder::OnSampleCompleted(
   auto* streaming_profile_packet = trace_packet->set_streaming_profile_packet();
   streaming_profile_packet->add_callstack_iid(callstack_id);
   streaming_profile_packet->add_timestamp_delta_us(
-      (time_now - last_timestamp_).InMicroseconds());
-  last_timestamp_ = time_now;
+      (sample.timestamp - last_timestamp_).InMicroseconds());
+  last_timestamp_ = sample.timestamp;
+}
+
+void TracingSamplerProfiler::TracingProfileBuilder::SetTraceWriter(
+    std::unique_ptr<perfetto::TraceWriter> writer) {
+  base::AutoLock l(trace_writer_lock_);
+  trace_writer_ = std::move(writer);
 }
 
 InterningID
@@ -435,6 +492,11 @@ void TracingSamplerProfiler::StartTracingForTesting(
       producer, perfetto::DataSourceConfig());
 }
 
+// static
+void TracingSamplerProfiler::SetupStartupTracing() {
+  TracingSamplerProfilerDataSource::Get()->SetupStartupTracing();
+}
+
 // static
 void TracingSamplerProfiler::StopTracingForTesting() {
   TracingSamplerProfilerDataSource::Get()->StopTracing(base::DoNothing());
@@ -455,7 +517,12 @@ void TracingSamplerProfiler::StartTracing(
     std::unique_ptr<perfetto::TraceWriter> trace_writer,
     bool should_enable_filtering) {
   base::AutoLock lock(lock_);
-  DCHECK(!profiler_.get());
+  if (profiler_) {
+    if (trace_writer) {
+      profile_builder_->SetTraceWriter(std::move(trace_writer));
+    }
+    return;
+  }
 
 #if defined(OS_ANDROID)
   // The sampler profiler would conflict with the reached code profiler if they
@@ -472,11 +539,12 @@ void TracingSamplerProfiler::StartTracing(
   // metrics when looking at traces.
   params.keep_consistent_sampling_interval = false;
 
+  auto profile_builder = std::make_unique<TracingProfileBuilder>(
+      sampled_thread_id_, std::move(trace_writer), should_enable_filtering);
+  profile_builder_ = profile_builder.get();
   // Create and start the stack sampling profiler.
 #if defined(OS_ANDROID) && BUILDFLAG(CAN_UNWIND_WITH_CFI_TABLE) && \
     defined(OFFICIAL_BUILD)
-  auto profile_builder = std::make_unique<TracingProfileBuilder>(
-      sampled_thread_id_, std::move(trace_writer), should_enable_filtering);
   auto* module_cache = profile_builder->GetModuleCache();
   profiler_ = std::make_unique<base::StackSamplingProfiler>(
       sampled_thread_id_, params, std::move(profile_builder),
@@ -484,10 +552,7 @@ void TracingSamplerProfiler::StartTracing(
 
 #else
   profiler_ = std::make_unique<base::StackSamplingProfiler>(
-      sampled_thread_id_, params,
-      std::make_unique<TracingProfileBuilder>(sampled_thread_id_,
-                                              std::move(trace_writer),
-                                              should_enable_filtering));
+      sampled_thread_id_, params, std::move(profile_builder));
 #endif
 
   profiler_->Start();
@@ -495,10 +560,13 @@ void TracingSamplerProfiler::StartTracing(
 
 void TracingSamplerProfiler::StopTracing() {
   base::AutoLock lock(lock_);
-  DCHECK(profiler_.get());
+  if (!profiler_) {
+    return;
+  }
 
   // Stop and release the stack sampling profiler.
   profiler_->Stop();
+  profile_builder_ = nullptr;
   profiler_.reset();
 }
 

services/tracing/public/cpp/stack_sampling/tracing_sampler_profiler.h

@@ -50,13 +50,33 @@ class COMPONENT_EXPORT(TRACING_CPP) TracingSamplerProfiler {
     void OnProfileCompleted(base::TimeDelta profile_duration,
                             base::TimeDelta sampling_period) override {}
 
+    void SetTraceWriter(std::unique_ptr<perfetto::TraceWriter> trace_writer);
+
    private:
+    struct BufferedSample {
+      BufferedSample(base::TimeTicks, std::vector<base::Frame>&&);
+      BufferedSample(BufferedSample&& other);
+      ~BufferedSample();
+
+      base::TimeTicks timestamp;
+      std::vector<base::Frame> sample;
+
+      DISALLOW_COPY_AND_ASSIGN(BufferedSample);
+    };
+
     InterningID GetCallstackIDAndMaybeEmit(
         const std::vector<base::Frame>& frames,
         perfetto::TraceWriter::TracePacketHandle* trace_packet);
+    void WriteSampleToTrace(const BufferedSample& sample);
+
+    // We usually sample at 50ms, and expect that tracing should have started in
+    // 10s.
+    constexpr static size_t kMaxBufferedSamples = 200;
+    std::vector<BufferedSample> buffered_samples_;
 
     base::ModuleCache module_cache_;
     const base::PlatformThreadId sampled_thread_id_;
+    base::Lock trace_writer_lock_;
     std::unique_ptr<perfetto::TraceWriter> trace_writer_;
     InterningIndex<size_t> interned_callstacks_{1000};
     InterningIndex<std::pair<std::string, std::string>,
@@ -79,6 +99,8 @@ class COMPONENT_EXPORT(TRACING_CPP) TracingSamplerProfiler {
   static void CreateForCurrentThread();
   static void RegisterDataSource();
 
+  static void SetupStartupTracing();
+
   // For tests.
   static void DeleteForCurrentThreadForTesting();
   static void StartTracingForTesting(tracing::PerfettoProducer* producer);
@@ -97,6 +119,7 @@ class COMPONENT_EXPORT(TRACING_CPP) TracingSamplerProfiler {
 
   base::Lock lock_;
   std::unique_ptr<base::StackSamplingProfiler> profiler_;  // under |lock_|
+  TracingProfileBuilder* profile_builder_ = nullptr;
 
   DISALLOW_COPY_AND_ASSIGN(TracingSamplerProfiler);
 };

services/tracing/public/cpp/stack_sampling/tracing_sampler_profiler_unittest.cc

@@ -3,6 +3,7 @@
 // found in the LICENSE file.
 
 #include "services/tracing/public/cpp/stack_sampling/tracing_sampler_profiler.h"
+#include <limits>
 
 #include "base/at_exit.h"
 #include "base/bind.h"
@@ -12,6 +13,7 @@
 #include "base/test/bind_test_util.h"
 #include "base/test/scoped_task_environment.h"
 #include "base/threading/thread.h"
+#include "base/time/time.h"
 #include "base/trace_event/trace_buffer.h"
 #include "base/trace_event/trace_event.h"
 #include "build/build_config.h"
@@ -193,6 +195,21 @@ class TracingSampleProfilerTest : public testing::Test {
     }
   }
 
+  uint32_t FindProfilerSequenceId() {
+    uint32_t profile_sequence_id = std::numeric_limits<uint32_t>::max();
+    auto& packets = producer_->finalized_packets();
+    for (auto& packet : packets) {
+      if (packet->has_streaming_profile_packet()) {
+        profile_sequence_id = packet->trusted_packet_sequence_id();
+        break;
+      }
+    }
+    EXPECT_NE(profile_sequence_id, std::numeric_limits<uint32_t>::max());
+    return profile_sequence_id;
+  }
+
+  const MockPerfettoProducer* producer() const { return producer_.get(); }
+
  private:
   base::test::ScopedTaskEnvironment scoped_task_environment_;
 
@@ -251,6 +268,76 @@ TEST_F(TracingSampleProfilerTest, JoinRunningTracing) {
   TracingSamplerProfiler::DeleteForCurrentThreadForTesting();
 }
 
+TEST_F(TracingSampleProfilerTest, TestStartupTracing) {
+  TracingSamplerProfiler::CreateForCurrentThread();
+  TracingSamplerProfiler::SetupStartupTracing();
+  base::RunLoop().RunUntilIdle();
+  WaitForEvents();
+  auto start_tracing_ts = TRACE_TIME_TICKS_NOW();
+  BeginTrace();
+  base::RunLoop().RunUntilIdle();
+  WaitForEvents();
+  EndTracing();
+  base::RunLoop().RunUntilIdle();
+  if (IsStackUnwindingSupported()) {
+    uint32_t seq_id = FindProfilerSequenceId();
+    auto& packets = producer()->finalized_packets();
+    int64_t reference_ts = 0;
+    int64_t first_profile_ts = 0;
+    for (auto& packet : packets) {
+      if (packet->trusted_packet_sequence_id() == seq_id) {
+        if (packet->has_thread_descriptor()) {
+          reference_ts = packet->thread_descriptor().reference_timestamp_us();
+        } else if (packet->has_streaming_profile_packet()) {
+          first_profile_ts =
+              reference_ts +
+              packet->streaming_profile_packet().timestamp_delta_us(0);
+          break;
+        }
+      }
+    }
+    // Expect first sample before tracing started.
+    EXPECT_LT(first_profile_ts,
+              start_tracing_ts.since_origin().InMicroseconds());
+  }
+  TracingSamplerProfiler::DeleteForCurrentThreadForTesting();
+}
+
+TEST_F(TracingSampleProfilerTest, JoinStartupTracing) {
+  TracingSamplerProfiler::SetupStartupTracing();
+  base::RunLoop().RunUntilIdle();
+  TracingSamplerProfiler::CreateForCurrentThread();
+  WaitForEvents();
+  auto start_tracing_ts = TRACE_TIME_TICKS_NOW();
+  BeginTrace();
+  base::RunLoop().RunUntilIdle();
+  WaitForEvents();
+  EndTracing();
+  base::RunLoop().RunUntilIdle();
+  if (IsStackUnwindingSupported()) {
+    uint32_t seq_id = FindProfilerSequenceId();
+    auto& packets = producer()->finalized_packets();
+    int64_t reference_ts = 0;
+    int64_t first_profile_ts = 0;
+    for (auto& packet : packets) {
+      if (packet->trusted_packet_sequence_id() == seq_id) {
+        if (packet->has_thread_descriptor()) {
+          reference_ts = packet->thread_descriptor().reference_timestamp_us();
+        } else if (packet->has_streaming_profile_packet()) {
+          first_profile_ts =
+              reference_ts +
+              packet->streaming_profile_packet().timestamp_delta_us(0);
+          break;
+        }
+      }
+    }
+    // Expect first sample before tracing started.
+    EXPECT_LT(first_profile_ts,
+              start_tracing_ts.since_origin().InMicroseconds());
+  }
+  TracingSamplerProfiler::DeleteForCurrentThreadForTesting();
+}
+
 TEST_F(TracingSampleProfilerTest, SamplingChildThread) {
   base::Thread sampled_thread("sampling_profiler_test");
   sampled_thread.Start();

services/tracing/public/cpp/trace_startup.cc

@@ -11,6 +11,7 @@
 #include "components/tracing/common/trace_to_console.h"
 #include "components/tracing/common/tracing_switches.h"
 #include "services/tracing/public/cpp/perfetto/trace_event_data_source.h"
+#include "services/tracing/public/cpp/stack_sampling/tracing_sampler_profiler.h"
 #include "services/tracing/public/cpp/tracing_features.h"
 
 namespace tracing {
@@ -37,6 +38,7 @@ void EnableStartupTracingIfNeeded() {
 
   if (startup_config->IsEnabled()) {
     if (TracingUsesPerfettoBackend()) {
+      TracingSamplerProfiler::SetupStartupTracing();
       TraceEventDataSource::GetInstance()->SetupStartupTracing(
           startup_config->GetSessionOwner() ==
           TraceStartupConfig::SessionOwner::kBackgroundTracing);