[profiler] Provide line-level info in streaming profiles

The line number is associated with each sample along with pointer
to the ProfileNode and timeDelta. Once collected line numbers are
streamed as an array of integers in "ProfileChunk" trace events.

If all the line numbers are zero, the array may be omitted. Otherwise
the array length matches length of samples and timeDeltas arrays.

BUG=chromium:925089

Change-Id: I1ef5cd1b208b03bb127f4d17b1efa74c01959542
Reviewed-on: https://chromium-review.googlesource.com/c/1459739Reviewed-by: Peter Marshall <petermarshall@chromium.org>
Commit-Queue: Alexei Filippov <alph@chromium.org>
Cr-Commit-Position: refs/heads/master@{#59514}

src/api.cc

@@ -9990,13 +9990,13 @@ const CpuProfileNode* CpuProfile::GetTopDownRoot() const {
 
 const CpuProfileNode* CpuProfile::GetSample(int index) const {
   const i::CpuProfile* profile = reinterpret_cast<const i::CpuProfile*>(this);
-  return reinterpret_cast<const CpuProfileNode*>(profile->sample(index));
+  return reinterpret_cast<const CpuProfileNode*>(profile->sample(index).node);
 }
 
 
 int64_t CpuProfile::GetSampleTimestamp(int index) const {
   const i::CpuProfile* profile = reinterpret_cast<const i::CpuProfile*>(this);
-  return (profile->sample_timestamp(index) - base::TimeTicks())
+  return (profile->sample(index).timestamp - base::TimeTicks())
       .InMicroseconds();
 }
 

src/profiler/profile-generator.cc

@@ -493,8 +493,7 @@ void CpuProfile::AddPath(base::TimeTicks timestamp,
       top_down_.AddPathFromEnd(path, src_line, update_stats, mode_);
 
   if (record_samples_ && !timestamp.IsNull()) {
-    timestamps_.push_back(timestamp);
-    samples_.push_back(top_frame_node);
+    samples_.push_back({top_frame_node, timestamp, src_line});
   }
 
   const int kSamplesFlushCount = 100;
@@ -553,7 +552,7 @@ void CpuProfile::StreamPendingTraceEvents() {
     if (streaming_next_sample_ != samples_.size()) {
       value->BeginArray("samples");
       for (size_t i = streaming_next_sample_; i < samples_.size(); ++i) {
-        value->AppendInteger(samples_[i]->id());
+        value->AppendInteger(samples_[i].node->id());
       }
       value->EndArray();
     }
@@ -562,15 +561,24 @@ void CpuProfile::StreamPendingTraceEvents() {
   if (streaming_next_sample_ != samples_.size()) {
     value->BeginArray("timeDeltas");
     base::TimeTicks lastTimestamp =
-        streaming_next_sample_ ? timestamps_[streaming_next_sample_ - 1]
+        streaming_next_sample_ ? samples_[streaming_next_sample_ - 1].timestamp
                                : start_time();
-    for (size_t i = streaming_next_sample_; i < timestamps_.size(); ++i) {
-      value->AppendInteger(
-          static_cast<int>((timestamps_[i] - lastTimestamp).InMicroseconds()));
-      lastTimestamp = timestamps_[i];
+    for (size_t i = streaming_next_sample_; i < samples_.size(); ++i) {
+      value->AppendInteger(static_cast<int>(
+          (samples_[i].timestamp - lastTimestamp).InMicroseconds()));
+      lastTimestamp = samples_[i].timestamp;
     }
     value->EndArray();
-    DCHECK_EQ(samples_.size(), timestamps_.size());
+    bool has_non_zero_lines =
+        std::any_of(samples_.begin() + streaming_next_sample_, samples_.end(),
+                    [](const SampleInfo& sample) { return sample.line != 0; });
+    if (has_non_zero_lines) {
+      value->BeginArray("lines");
+      for (size_t i = streaming_next_sample_; i < samples_.size(); ++i) {
+        value->AppendInteger(samples_[i].line);
+      }
+      value->EndArray();
+    }
     streaming_next_sample_ = samples_.size();
   }
 

src/profiler/profile-generator.h

@@ -344,6 +344,12 @@ class CpuProfile {
  public:
   typedef v8::CpuProfilingMode ProfilingMode;
 
+  struct SampleInfo {
+    ProfileNode* node;
+    base::TimeTicks timestamp;
+    int line;
+  };
+
   CpuProfile(CpuProfiler* profiler, const char* title, bool record_samples,
              ProfilingMode mode);
 
@@ -356,10 +362,7 @@ class CpuProfile {
   const ProfileTree* top_down() const { return &top_down_; }
 
   int samples_count() const { return static_cast<int>(samples_.size()); }
-  ProfileNode* sample(int index) const { return samples_.at(index); }
-  base::TimeTicks sample_timestamp(int index) const {
-    return timestamps_.at(index);
-  }
+  const SampleInfo& sample(int index) const { return samples_[index]; }
 
   base::TimeTicks start_time() const { return start_time_; }
   base::TimeTicks end_time() const { return end_time_; }
@@ -377,8 +380,7 @@ class CpuProfile {
   ProfilingMode mode_;
   base::TimeTicks start_time_;
   base::TimeTicks end_time_;
-  std::vector<ProfileNode*> samples_;
-  std::vector<base::TimeTicks> timestamps_;
+  std::deque<SampleInfo> samples_;
   ProfileTree top_down_;
   CpuProfiler* const profiler_;
   size_t streaming_next_sample_;

test/cctest/cctest.status

@@ -90,7 +90,6 @@
   'test-cpu-profiler/JsNativeJsSample': [SKIP],
   'test-cpu-profiler/NativeAccessorUninitializedIC': [SKIP],
   'test-cpu-profiler/SampleWhenFrameIsNotSetup': [SKIP],
-  'test-cpu-profiler/TracingCpuProfiler': [SKIP],
   'test-sampler/LibSamplerCollectSample': [SKIP],
 
   # BUG(7202). The test is flaky.

test/cctest/test-cpu-profiler.cc

@@ -41,6 +41,7 @@
 #include "src/objects-inl.h"
 #include "src/profiler/cpu-profiler-inl.h"
 #include "src/profiler/profiler-listener.h"
+#include "src/profiler/tracing-cpu-profiler.h"
 #include "src/source-position-table.h"
 #include "src/utils.h"
 #include "test/cctest/cctest.h"
@@ -2405,11 +2406,16 @@ class CpuProfileEventChecker : public v8::platform::tracing::TraceWriter {
     profile_id_ = trace_event->id();
     v8::ConvertableToTraceFormat* arg =
         trace_event->arg_convertables()[0].get();
+    result_json_ += result_json_.empty() ? "[" : ",\n";
     arg->AppendAsTraceFormat(&result_json_);
   }
-  void Flush() override {}
+  void Flush() override { result_json_ += "]"; }
 
-  std::string result_json() const { return result_json_; }
+  const std::string& result_json() const { return result_json_; }
+  void Reset() {
+    result_json_.clear();
+    profile_id_ = 0;
+  }
 
  private:
   std::string result_json_;
@@ -2419,50 +2425,61 @@ class CpuProfileEventChecker : public v8::platform::tracing::TraceWriter {
 }  // namespace
 
 TEST(TracingCpuProfiler) {
-  v8::Platform* old_platform = i::V8::GetCurrentPlatform();
-  std::unique_ptr<v8::Platform> default_platform =
-      v8::platform::NewDefaultPlatform();
-  i::V8::SetPlatformForTesting(default_platform.get());
-
-  auto tracing = base::make_unique<v8::platform::tracing::TracingController>();
-  v8::platform::tracing::TracingController* tracing_controller = tracing.get();
-  static_cast<v8::platform::DefaultPlatform*>(default_platform.get())
-      ->SetTracingController(std::move(tracing));
+  v8::HandleScope scope(CcTest::isolate());
+  v8::Local<v8::Context> env = CcTest::NewContext({PROFILER_EXTENSION_ID});
+  v8::Context::Scope context_scope(env);
 
   CpuProfileEventChecker* event_checker = new CpuProfileEventChecker();
   TraceBuffer* ring_buffer =
       TraceBuffer::CreateTraceBufferRingBuffer(1, event_checker);
+  auto* tracing_controller =
+      static_cast<v8::platform::tracing::TracingController*>(
+          i::V8::GetCurrentPlatform()->GetTracingController());
   tracing_controller->Initialize(ring_buffer);
-  TraceConfig* trace_config = new TraceConfig();
-  trace_config->AddIncludedCategory(
-      TRACE_DISABLED_BY_DEFAULT("v8.cpu_profiler"));
 
-  LocalContext env;
-  v8::HandleScope scope(env->GetIsolate());
-  {
+  bool result = false;
+  for (int run_duration = 50; !result; run_duration += 50) {
+    TraceConfig* trace_config = new TraceConfig();
+    trace_config->AddIncludedCategory(
+        TRACE_DISABLED_BY_DEFAULT("v8.cpu_profiler"));
+    trace_config->AddIncludedCategory(
+        TRACE_DISABLED_BY_DEFAULT("v8.cpu_profiler.hires"));
+
+    std::string test_code = R"(
+        function foo() {
+          let s = 0;
+          const endTime = Date.now() + )" +
+                            std::to_string(run_duration) + R"(
+          while (Date.now() < endTime) s += Math.cos(s);
+          return s;
+        }
+        foo();)";
+
     tracing_controller->StartTracing(trace_config);
-    CompileRun("function foo() { } foo();");
+    CompileRun(test_code.c_str());
     tracing_controller->StopTracing();
-    CompileRun("function bar() { } bar();");
+
+    std::string profile_json = event_checker->result_json();
+    event_checker->Reset();
+    CHECK_LT(0u, profile_json.length());
+    printf("Profile JSON: %s\n", profile_json.c_str());
+
+    std::string profile_checker_code = R"(
+        function checkProfile(json) {
+          const profile_header = json[0];
+          if (typeof profile_header['startTime'] !== 'number')
+            return false;
+          return json.some(event => (event.lines || []).some(line => line));
+        }
+        checkProfile()" + profile_json +
+                                       ")";
+    result = CompileRunChecked(CcTest::isolate(), profile_checker_code.c_str())
+                 ->IsTrue();
   }
 
-  const char* profile_checker =
-      "function checkProfile(profile) {\n"
-      "  if (typeof profile['startTime'] !== 'number') return 'startTime';\n"
-      "  return '';\n"
-      "}\n"
-      "checkProfile(";
-  std::string profile_json = event_checker->result_json();
-  CHECK_LT(0u, profile_json.length());
-  printf("Profile JSON: %s\n", profile_json.c_str());
-  std::string code = profile_checker + profile_json + ")";
-  v8::Local<v8::Value> result =
-      CompileRunChecked(CcTest::isolate(), code.c_str());
-  v8::String::Utf8Value value(CcTest::isolate(), result);
-  printf("Check result: %*s\n", value.length(), *value);
-  CHECK_EQ(0, value.length());
-
-  i::V8::SetPlatformForTesting(old_platform);
+  static_cast<v8::platform::tracing::TracingController*>(
+      i::V8::GetCurrentPlatform()->GetTracingController())
+      ->Initialize(nullptr);
 }
 
 TEST(Issue763073) {

test/cctest/test-profile-generator.cc

@@ -491,7 +491,7 @@ TEST(SampleIds) {
   CHECK_EQ(3, profile->samples_count());
   unsigned expected_id[] = {3, 5, 7};
   for (int i = 0; i < 3; i++) {
-    CHECK_EQ(expected_id[i], profile->sample(i)->id());
+    CHECK_EQ(expected_id[i], profile->sample(i).node->id());
   }
 }