[tracing] Add a JSON consumer for Perfetto tracing data

We pretty much always want tracing data as a JSON file. Implement a
Consumer which converts protos to the JSON trace events format.

This duplicates a lot of the internals of TraceWriter in
trace-writer.cc but we will remove that eventually.

Cq-Include-Trybots: luci.v8.try:v8_linux64_perfetto_dbg_ng
Bug: v8:8339
Change-Id: I85f86562f1b3c4d24ecd755413d1c3f88b292adb
Reviewed-on: https://chromium-review.googlesource.com/c/v8/v8/+/1541042
Commit-Queue: Jakob Gruber <jgruber@chromium.org>
Reviewed-by: Jakob Gruber <jgruber@chromium.org>
Cr-Commit-Position: refs/heads/master@{#61366}

BUILD.gn

@@ -3630,7 +3630,8 @@ v8_component("v8_libplatform") {
   ]
   if (v8_use_perfetto) {
     sources += [
-      "src/libplatform/tracing/perfetto-consumer.h",
+      "src/libplatform/tracing/perfetto-json-consumer.cc",
+      "src/libplatform/tracing/perfetto-json-consumer.h",
       "src/libplatform/tracing/perfetto-producer.cc",
       "src/libplatform/tracing/perfetto-producer.h",
       "src/libplatform/tracing/perfetto-shared-memory.cc",
@@ -3640,7 +3641,10 @@ v8_component("v8_libplatform") {
       "src/libplatform/tracing/perfetto-tracing-controller.cc",
       "src/libplatform/tracing/perfetto-tracing-controller.h",
     ]
-    deps += [ "third_party/perfetto:libperfetto" ]
+    deps += [
+      "third_party/perfetto:libperfetto",
+      "third_party/perfetto/protos/perfetto/trace:lite",
+    ]
   }
 }
 

src/libplatform/tracing/perfetto-json-consumer.cc

@@ -0,0 +1,183 @@
+// Copyright 2019 the V8 project 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 "src/libplatform/tracing/perfetto-json-consumer.h"
+
+#include <cmath>
+
+#include "base/trace_event/common/trace_event_common.h"
+#include "perfetto/trace/trace_packet.pb.h"
+#include "perfetto/tracing/core/trace_packet.h"
+#include "src/base/logging.h"
+#include "src/base/macros.h"
+#include "src/base/platform/semaphore.h"
+
+namespace v8 {
+namespace platform {
+namespace tracing {
+
+PerfettoJSONConsumer::PerfettoJSONConsumer(std::ostream* stream,
+                                           base::Semaphore* finished)
+    : stream_(stream), finished_semaphore_(finished) {
+  *stream_ << "{\"traceEvents\":[";
+}
+
+PerfettoJSONConsumer::~PerfettoJSONConsumer() { *stream_ << "]}"; }
+
+void PerfettoJSONConsumer::OnTraceData(
+    std::vector<::perfetto::TracePacket> packets, bool has_more) {
+  for (const ::perfetto::TracePacket& packet : packets) {
+    ::perfetto::protos::TracePacket proto_packet;
+    bool success = packet.Decode(&proto_packet);
+    USE(success);
+    DCHECK(success);
+
+    ProcessPacket(proto_packet);
+  }
+  // Alert PerfettoTracingController that we are finished during StopTracing().
+  if (!has_more) finished_semaphore_->Signal();
+}
+
+// TODO(petermarshall): Clean up this code which was copied from trace-writer.cc
+// once we've removed that file.
+
+// Writes the given string, taking care to escape characters when necessary.
+void PerfettoJSONConsumer::AppendJSONString(const char* str) {
+  size_t len = strlen(str);
+  *stream_ << "\"";
+  for (size_t i = 0; i < len; ++i) {
+    // All of the permitted escape sequences in JSON strings, as per
+    // https://mathiasbynens.be/notes/javascript-escapes
+    switch (str[i]) {
+      case '\b':
+        *stream_ << "\\b";
+        break;
+      case '\f':
+        *stream_ << "\\f";
+        break;
+      case '\n':
+        *stream_ << "\\n";
+        break;
+      case '\r':
+        *stream_ << "\\r";
+        break;
+      case '\t':
+        *stream_ << "\\t";
+        break;
+      case '\"':
+        *stream_ << "\\\"";
+        break;
+      case '\\':
+        *stream_ << "\\\\";
+        break;
+      // Note that because we use double quotes for JSON strings,
+      // we don't need to escape single quotes.
+      default:
+        *stream_ << str[i];
+        break;
+    }
+  }
+  *stream_ << "\"";
+}
+
+void PerfettoJSONConsumer::AppendArgValue(
+    const ::perfetto::protos::ChromeTraceEvent_Arg& arg) {
+  if (arg.has_bool_value()) {
+    *stream_ << (arg.bool_value() ? "true" : "false");
+  } else if (arg.has_uint_value()) {
+    *stream_ << arg.uint_value();
+  } else if (arg.has_int_value()) {
+    *stream_ << arg.int_value();
+  } else if (arg.has_double_value()) {
+    std::string real;
+    double val = arg.double_value();
+    if (std::isfinite(val)) {
+      std::ostringstream convert_stream;
+      convert_stream << val;
+      real = convert_stream.str();
+      // Ensure that the number has a .0 if there's no decimal or 'e'.  This
+      // makes sure that when we read the JSON back, it's interpreted as a
+      // real rather than an int.
+      if (real.find('.') == std::string::npos &&
+          real.find('e') == std::string::npos &&
+          real.find('E') == std::string::npos) {
+        real += ".0";
+      }
+    } else if (std::isnan(val)) {
+      // The JSON spec doesn't allow NaN and Infinity (since these are
+      // objects in EcmaScript).  Use strings instead.
+      real = "\"NaN\"";
+    } else if (val < 0) {
+      real = "\"-Infinity\"";
+    } else {
+      real = "\"Infinity\"";
+    }
+    *stream_ << real;
+  } else if (arg.has_string_value()) {
+    AppendJSONString(arg.string_value().c_str());
+  } else if (arg.has_pointer_value()) {
+    // JSON only supports double and int numbers.
+    // So as not to lose bits from a 64-bit pointer, output as a hex string.
+    *stream_ << "\"0x" << std::hex << arg.pointer_value() << std::dec << "\"";
+  } else if (arg.has_json_value()) {
+    *stream_ << arg.json_value();
+  }
+  // V8 does not emit proto arguments currently.
+  CHECK(!arg.has_traced_value());
+}
+
+void PerfettoJSONConsumer::ProcessPacket(
+    const ::perfetto::protos::TracePacket& packet) {
+  for (const ::perfetto::protos::ChromeTraceEvent& event :
+       packet.chrome_events().trace_events()) {
+    if (append_comma_) *stream_ << ",";
+    append_comma_ = true;
+
+    // TODO(petermarshall): Handle int64 fields differently?
+    // clang-format off
+    *stream_ << "{\"pid\":" << event.process_id()
+            << ",\"tid\":" << event.thread_id()
+            << ",\"ts\":" << event.timestamp()
+            << ",\"tts\":" << event.thread_timestamp()
+            << ",\"ph\":\"" << static_cast<char>(event.phase())
+            << "\",\"cat\":\"" << event.category_group_name()
+            << "\",\"name\":\"" << event.name()
+            << "\",\"dur\":" << event.duration()
+            << ",\"tdur\":" << event.thread_duration();
+    // clang-format on
+
+    if (event.flags() &
+        (TRACE_EVENT_FLAG_FLOW_IN | TRACE_EVENT_FLAG_FLOW_OUT)) {
+      *stream_ << ",\"bind_id\":\"0x" << std::hex << event.bind_id() << "\""
+               << std::dec;
+      if (event.flags() & TRACE_EVENT_FLAG_FLOW_IN) {
+        *stream_ << ",\"flow_in\":true";
+      }
+      if (event.flags() & TRACE_EVENT_FLAG_FLOW_OUT) {
+        *stream_ << ",\"flow_out\":true";
+      }
+    }
+    if (event.flags() & TRACE_EVENT_FLAG_HAS_ID) {
+      if (event.has_scope()) {
+        *stream_ << ",\"scope\":\"" << event.scope() << "\"";
+      }
+      // So as not to lose bits from a 64-bit integer, output as a hex string.
+      *stream_ << ",\"id\":\"0x" << std::hex << event.id() << "\"" << std::dec;
+    }
+
+    *stream_ << ",\"args\":{";
+
+    int i = 0;
+    for (const ::perfetto::protos::ChromeTraceEvent_Arg& arg : event.args()) {
+      if (i++ > 0) *stream_ << ",";
+      *stream_ << "\"" << arg.name() << "\":";
+      AppendArgValue(arg);
+    }
+    *stream_ << "}}";
+  }
+}
+
+}  // namespace tracing
+}  // namespace platform
+}  // namespace v8

src/libplatform/tracing/perfetto-json-consumer.h

@@ -0,0 +1,86 @@
+// Copyright 2019 the V8 project authors. All rights reserved.
+// Use of this source code is governed by a BSD-style license that can be
+// found in the LICENSE file.
+
+#ifndef V8_LIBPLATFORM_TRACING_PERFETTO_JSON_CONSUMER_H_
+#define V8_LIBPLATFORM_TRACING_PERFETTO_JSON_CONSUMER_H_
+
+#include <ostream>
+
+#include "perfetto/tracing/core/consumer.h"
+#include "perfetto/tracing/core/tracing_service.h"
+#include "src/base/logging.h"
+
+namespace perfetto {
+class TraceConfig;
+class TracePacket;
+
+namespace protos {
+class ChromeTraceEvent_Arg;
+class TracePacket;
+}  // namespace protos
+}  // namespace perfetto
+
+namespace v8 {
+
+namespace base {
+class Semaphore;
+}
+
+namespace platform {
+namespace tracing {
+
+// A Perfetto Consumer gets streamed trace events from the Service via
+// OnTraceData(). A Consumer can be configured (via
+// service_endpoint()->EnableTracing()) to listen to various different types of
+// trace events. The Consumer is responsible for producing whatever tracing
+// output the system should have - in this case, converting the proto trace data
+// delivered via OnTraceData() to JSON and writing it to a file.
+class PerfettoJSONConsumer final : public ::perfetto::Consumer {
+ public:
+  explicit PerfettoJSONConsumer(std::ostream* stream,
+                                base::Semaphore* finished);
+  ~PerfettoJSONConsumer() override;
+
+  using ServiceEndpoint = ::perfetto::TracingService::ConsumerEndpoint;
+
+  ServiceEndpoint* service_endpoint() const { return service_endpoint_.get(); }
+  void set_service_endpoint(std::unique_ptr<ServiceEndpoint> endpoint) {
+    service_endpoint_ = std::move(endpoint);
+  }
+
+ private:
+  // ::perfetto::Consumer implementation
+  void OnConnect() override {}
+  void OnDisconnect() override {}
+  void OnTracingDisabled() override {}
+
+  void OnTraceData(std::vector<::perfetto::TracePacket> packets,
+                   bool has_more) override;
+
+  void OnDetach(bool success) override {}
+  void OnAttach(bool success, const ::perfetto::TraceConfig&) override {}
+  void OnTraceStats(bool success, const ::perfetto::TraceStats&) override {
+    UNREACHABLE();
+  }
+  void OnObservableEvents(const ::perfetto::ObservableEvents&) override {
+    UNREACHABLE();
+  }
+
+  // Internal implementation
+  void AppendJSONString(const char* str);
+  void AppendArgValue(const ::perfetto::protos::ChromeTraceEvent_Arg& arg);
+  void ProcessPacket(const ::perfetto::protos::TracePacket& packet);
+
+  std::ostream* stream_;
+  bool append_comma_ = false;
+  std::unique_ptr<ServiceEndpoint> service_endpoint_;
+
+  base::Semaphore* finished_semaphore_;
+};
+
+}  // namespace tracing
+}  // namespace platform
+}  // namespace v8
+
+#endif  // V8_LIBPLATFORM_TRACING_PERFETTO_JSON_CONSUMER_H_

src/libplatform/tracing/perfetto-tracing-controller.cc

@@ -7,7 +7,7 @@
 #include "perfetto/tracing/core/trace_config.h"
 #include "perfetto/tracing/core/trace_writer.h"
 #include "perfetto/tracing/core/tracing_service.h"
-#include "src/libplatform/tracing/perfetto-consumer.h"
+#include "src/libplatform/tracing/perfetto-json-consumer.h"
 #include "src/libplatform/tracing/perfetto-producer.h"
 #include "src/libplatform/tracing/perfetto-shared-memory.h"
 #include "src/libplatform/tracing/perfetto-tasks.h"
@@ -18,22 +18,28 @@ namespace tracing {
 
 PerfettoTracingController::PerfettoTracingController()
     : writer_key_(base::Thread::CreateThreadLocalKey()),
-      producer_ready_semaphore_(0) {}
+      producer_ready_semaphore_(0),
+      consumer_finished_semaphore_(0) {}
+
+void PerfettoTracingController::StartTracing(
+    const ::perfetto::TraceConfig& trace_config) {
+  DCHECK(!trace_file_.is_open());
+  trace_file_.open("v8_perfetto_trace.json");
+  CHECK(trace_file_.good());
 
-void PerfettoTracingController::StartTracingToFile(
-    int fd, const ::perfetto::TraceConfig& trace_config) {
   DCHECK(!task_runner_);
   task_runner_ = base::make_unique<PerfettoTaskRunner>();
   // The Perfetto service expects calls on the task runner thread which is why
   // the setup below occurs in posted tasks.
-  task_runner_->PostTask([fd, &trace_config, this] {
+  task_runner_->PostTask([&trace_config, this] {
     std::unique_ptr<::perfetto::SharedMemory::Factory> shmem_factory =
         base::make_unique<PerfettoSharedMemoryFactory>();
 
     service_ = ::perfetto::TracingService::CreateInstance(
         std::move(shmem_factory), task_runner_.get());
     producer_ = base::make_unique<PerfettoProducer>(this);
-    consumer_ = base::make_unique<PerfettoConsumer>();
+    consumer_ = base::make_unique<PerfettoJSONConsumer>(
+        &trace_file_, &consumer_finished_semaphore_);
 
     producer_->set_service_endpoint(service_->ConnectProducer(
         producer_.get(), 0, "v8.perfetto-producer", 0, true));
@@ -43,9 +49,7 @@ void PerfettoTracingController::StartTracingToFile(
 
     // We need to wait for the OnConnected() callbacks of the producer and
     // consumer to be called.
-    ::perfetto::base::ScopedFile scoped_file(fd);
-    consumer_->service_endpoint()->EnableTracing(trace_config,
-                                                 std::move(scoped_file));
+    consumer_->service_endpoint()->EnableTracing(trace_config);
   });
 
   producer_ready_semaphore_.Wait();
@@ -66,6 +70,16 @@ void PerfettoTracingController::StopTracing() {
     // all tracing threads here or use TLS destructors like Chrome.
     writers_to_finalize_.clear();
 
+    // Trigger the consumer to finish. This can trigger multiple calls to
+    // PerfettoJSONConsumer::OnTraceData(), with the final call passing has_more
+    // as false.
+    consumer_->service_endpoint()->ReadBuffers();
+  });
+
+  // Wait until the final OnTraceData() call with has_more=false has completed.
+  consumer_finished_semaphore_.Wait();
+
+  task_runner_->PostTask([this] {
     consumer_.reset();
     producer_.reset();
     service_.reset();
@@ -74,6 +88,9 @@ void PerfettoTracingController::StopTracing() {
   // Finish the above task, and any callbacks that were triggered.
   task_runner_->FinishImmediateTasks();
   task_runner_.reset();
+
+  DCHECK(trace_file_.is_open());
+  trace_file_.close();
 }
 
 PerfettoTracingController::~PerfettoTracingController() {

src/libplatform/tracing/perfetto-tracing-controller.h

@@ -6,11 +6,13 @@
 #define V8_LIBPLATFORM_TRACING_PERFETTO_TRACING_CONTROLLER_H_
 
 #include <atomic>
+#include <fstream>
 #include <memory>
 #include <vector>
 
 #include "src/base/platform/mutex.h"
 #include "src/base/platform/platform.h"
+#include "src/base/platform/semaphore.h"
 
 namespace perfetto {
 class TraceConfig;
@@ -22,12 +24,12 @@ namespace v8 {
 namespace platform {
 namespace tracing {
 
-class PerfettoConsumer;
+class PerfettoJSONConsumer;
 class PerfettoProducer;
 class PerfettoTaskRunner;
 
 // This is the top-level interface for performing tracing with perfetto. The
-// user of this class should call StartTracingToFile() to start tracing, and
+// user of this class should call StartTracing() to start tracing, and
 // StopTracing() to stop it. To write trace events, the user can obtain a
 // thread-local TraceWriter object using GetOrCreateThreadLocalWriter().
 class PerfettoTracingController {
@@ -37,7 +39,7 @@ class PerfettoTracingController {
   // Blocks and sets up all required data structures for tracing. It is safe to
   // call GetOrCreateThreadLocalWriter() to obtain thread-local TraceWriters for
   // writing trace events once this call returns.
-  void StartTracingToFile(int fd, const ::perfetto::TraceConfig& trace_config);
+  void StartTracing(const ::perfetto::TraceConfig& trace_config);
 
   // Blocks and finishes all existing AddTraceEvent tasks. Stops the tracing
   // thread.
@@ -58,15 +60,19 @@ class PerfettoTracingController {
 
   std::unique_ptr<::perfetto::TracingService> service_;
   std::unique_ptr<PerfettoProducer> producer_;
-  std::unique_ptr<PerfettoConsumer> consumer_;
+  std::unique_ptr<PerfettoJSONConsumer> consumer_;
   std::unique_ptr<PerfettoTaskRunner> task_runner_;
   base::Thread::LocalStorageKey writer_key_;
   base::Mutex writers_mutex_;
   std::vector<std::unique_ptr<::perfetto::TraceWriter>> writers_to_finalize_;
-  // A semaphore that is signalled when StartRecording is called.
-  // StartTracingToFile waits on this semaphore to be notified when the tracing
-  // service is ready to receive trace events.
+  // A semaphore that is signalled when StartRecording is called. StartTracing
+  // waits on this semaphore to be notified when the tracing service is ready to
+  // receive trace events.
   base::Semaphore producer_ready_semaphore_;
+  base::Semaphore consumer_finished_semaphore_;
+
+  // TODO(petermarshall): pass this in instead.
+  std::ofstream trace_file_;
 
   DISALLOW_COPY_AND_ASSIGN(PerfettoTracingController);
 };

src/libplatform/tracing/tracing-controller.cc

@@ -13,8 +13,6 @@
 #include "src/base/platform/time.h"
 
 #ifdef V8_USE_PERFETTO
-#include <fcntl.h>
-
 #include "base/trace_event/common/trace_event_common.h"
 #include "perfetto/trace/chrome/chrome_trace_event.pbzero.h"
 #include "perfetto/trace/trace_packet.pbzero.h"
@@ -272,18 +270,13 @@ void TracingController::StartTracing(TraceConfig* trace_config) {
   perfetto_tracing_controller_ = base::make_unique<PerfettoTracingController>();
 
   ::perfetto::TraceConfig perfetto_trace_config;
-  // Enable long tracing mode with continuous draining into file.
-  perfetto_trace_config.set_write_into_file(true);
-  perfetto_trace_config.set_file_write_period_ms(1000);
 
   perfetto_trace_config.add_buffers()->set_size_kb(4096);
   auto* ds_config = perfetto_trace_config.add_data_sources()->mutable_config();
   ds_config->set_name("v8.trace_events");
 
-  // TODO(petermarshall): Set all the params from |trace_config| and don't
-  // write to a file by default.
-  int fd = open("v8_trace.proto", O_RDWR | O_CREAT | O_TRUNC, 0644);
-  perfetto_tracing_controller_->StartTracingToFile(fd, perfetto_trace_config);
+  // TODO(petermarshall): Set all the params from |perfetto_trace_config|.
+  perfetto_tracing_controller_->StartTracing(perfetto_trace_config);
   perfetto_recording_.store(true);
 #endif  // V8_USE_PERFETTO