src: trace_event: secondary storage for metadata

Metadata trace-events should be held in secondary storage so that they
can be periodically reemitted. This change establishes the secondary
storage and ensures that events are reemitted on each flush.

PR-URL: #20900
Reviewed-By: James M Snell <[email protected]>
Reviewed-By: Anna Henningsen <[email protected]>

src/node.cc

@@ -271,9 +271,9 @@ static struct {
 #if NODE_USE_V8_PLATFORM
   void Initialize(int thread_pool_size) {
     tracing_agent_.reset(new tracing::Agent());
+    node::tracing::TraceEventHelper::SetAgent(tracing_agent_.get());
     auto controller = tracing_agent_->GetTracingController();
     controller->AddTraceStateObserver(new NodeTraceStateObserver(controller));
-    tracing::TraceEventHelper::SetTracingController(controller);
     StartTracingAgent();
     // Tracing must be initialized before platform threads are created.
     platform_ = new NodePlatform(thread_pool_size, controller);
@@ -2763,7 +2763,7 @@ MultiIsolatePlatform* GetMainThreadMultiIsolatePlatform() {
 
 MultiIsolatePlatform* CreatePlatform(
     int thread_pool_size,
-    TracingController* tracing_controller) {
+    node::tracing::TracingController* tracing_controller) {
   return new NodePlatform(thread_pool_size, tracing_controller);
 }
 

src/node_platform.cc

@@ -14,7 +14,7 @@ using v8::Local;
 using v8::Object;
 using v8::Platform;
 using v8::Task;
-using v8::TracingController;
+using node::tracing::TracingController;
 
 namespace {
 

src/node_platform.h

@@ -11,6 +11,7 @@
 #include "libplatform/libplatform.h"
 #include "node.h"
 #include "node_mutex.h"
+#include "tracing/agent.h"
 #include "uv.h"
 
 namespace node {
@@ -124,7 +125,8 @@ class WorkerThreadsTaskRunner {
 
 class NodePlatform : public MultiIsolatePlatform {
  public:
-  NodePlatform(int thread_pool_size, v8::TracingController* tracing_controller);
+  NodePlatform(int thread_pool_size,
+               node::tracing::TracingController* tracing_controller);
   virtual ~NodePlatform() {}
 
   void DrainTasks(v8::Isolate* isolate) override;
@@ -142,7 +144,7 @@ class NodePlatform : public MultiIsolatePlatform {
   bool IdleTasksEnabled(v8::Isolate* isolate) override;
   double MonotonicallyIncreasingTime() override;
   double CurrentClockTimeMillis() override;
-  v8::TracingController* GetTracingController() override;
+  node::tracing::TracingController* GetTracingController() override;
   bool FlushForegroundTasks(v8::Isolate* isolate) override;
 
   void RegisterIsolate(v8::Isolate* isolate, uv_loop_t* loop) override;
@@ -158,7 +160,7 @@ class NodePlatform : public MultiIsolatePlatform {
   std::unordered_map<v8::Isolate*,
                      std::shared_ptr<PerIsolatePlatformData>> per_isolate_;
 
-  v8::TracingController* tracing_controller_;
+  node::tracing::TracingController* tracing_controller_;
   std::shared_ptr<WorkerThreadsTaskRunner> worker_thread_task_runner_;
 };
 

src/tracing/agent.cc

@@ -1,6 +1,7 @@
 #include "tracing/agent.h"
 
 #include <string>
+#include "trace_event.h"
 #include "tracing/node_trace_buffer.h"
 #include "debug_utils.h"
 #include "env-inl.h"
@@ -207,9 +208,35 @@ void Agent::AppendTraceEvent(TraceObject* trace_event) {
 }
 
 void Agent::Flush(bool blocking) {
+  for (const auto& event : metadata_events_)
+    AppendTraceEvent(event.get());
+
   for (const auto& id_writer : writers_)
     id_writer.second->Flush(blocking);
 }
 
+void TracingController::AddMetadataEvent(
+    const unsigned char* category_group_enabled,
+    const char* name,
+    int num_args,
+    const char** arg_names,
+    const unsigned char* arg_types,
+    const uint64_t* arg_values,
+    std::unique_ptr<v8::ConvertableToTraceFormat>* convertable_values,
+    unsigned int flags) {
+  std::unique_ptr<TraceObject> trace_event(new TraceObject);
+  trace_event->Initialize(
+      TRACE_EVENT_PHASE_METADATA, category_group_enabled, name,
+      node::tracing::kGlobalScope,  // scope
+      node::tracing::kNoId,         // id
+      node::tracing::kNoId,         // bind_id
+      num_args, arg_names, arg_types, arg_values, convertable_values,
+      TRACE_EVENT_FLAG_NONE,
+      CurrentTimestampMicroseconds(),
+      CurrentCpuTimestampMicroseconds());
+  node::tracing::TraceEventHelper::GetAgent()->AddMetadataEvent(
+      std::move(trace_event));
+}
+
 }  // namespace tracing
 }  // namespace node

src/tracing/agent.h

@@ -7,6 +7,7 @@
 #include "util.h"
 #include "node_mutex.h"
 
+#include <list>
 #include <set>
 #include <string>
 #include <unordered_map>
@@ -34,6 +35,15 @@ class TracingController : public v8::platform::tracing::TracingController {
   int64_t CurrentTimestampMicroseconds() override {
     return uv_hrtime() / 1000;
   }
+  void AddMetadataEvent(
+      const unsigned char* category_group_enabled,
+      const char* name,
+      int num_args,
+      const char** arg_names,
+      const unsigned char* arg_types,
+      const uint64_t* arg_values,
+      std::unique_ptr<v8::ConvertableToTraceFormat>* convertable_values,
+      unsigned int flags);
 };
 
 class AgentWriterHandle {
@@ -93,6 +103,10 @@ class Agent {
 
   // Writes to all writers registered through AddClient().
   void AppendTraceEvent(TraceObject* trace_event);
+
+  void AddMetadataEvent(std::unique_ptr<TraceObject> event) {
+    metadata_events_.push_back(std::move(event));
+  }
   // Flushes all writers registered through AddClient().
   void Flush(bool blocking);
 
@@ -131,6 +145,7 @@ class Agent {
   ConditionVariable initialize_writer_condvar_;
   uv_async_t initialize_writer_async_;
   std::set<AsyncTraceWriter*> to_be_initialized_;
+  std::list<std::unique_ptr<TraceObject>> metadata_events_;
 };
 
 void AgentWriterHandle::reset() {

src/tracing/trace_event.cc

@@ -3,14 +3,18 @@
 namespace node {
 namespace tracing {
 
-v8::TracingController* g_controller = nullptr;
+Agent* g_agent = nullptr;
 
-void TraceEventHelper::SetTracingController(v8::TracingController* controller) {
-  g_controller = controller;
+void TraceEventHelper::SetAgent(Agent* agent) {
+  g_agent = agent;
 }
 
-v8::TracingController* TraceEventHelper::GetTracingController() {
-  return g_controller;
+Agent* TraceEventHelper::GetAgent() {
+  return g_agent;
+}
+
+TracingController* TraceEventHelper::GetTracingController() {
+  return g_agent->GetTracingController();
 }
 
 }  // namespace tracing

src/tracing/trace_event.h

@@ -310,8 +310,9 @@ const uint64_t kNoId = 0;
 
 class TraceEventHelper {
  public:
-  static v8::TracingController* GetTracingController();
-  static void SetTracingController(v8::TracingController* controller);
+  static TracingController* GetTracingController();
+  static Agent* GetAgent();
+  static void SetAgent(Agent* agent);
 };
 
 // TraceID encapsulates an ID that can either be an integer or pointer. Pointers
@@ -487,6 +488,26 @@ static V8_INLINE uint64_t AddTraceEventWithTimestampImpl(
       arg_names, arg_types, arg_values, arg_convertables, flags, timestamp);
 }
 
+static V8_INLINE void AddMetadataEventImpl(
+    const uint8_t* category_group_enabled, const char* name, int32_t num_args,
+    const char** arg_names, const uint8_t* arg_types,
+    const uint64_t* arg_values, unsigned int flags) {
+  std::unique_ptr<v8::ConvertableToTraceFormat> arg_convertibles[2];
+  if (num_args > 0 && arg_types[0] == TRACE_VALUE_TYPE_CONVERTABLE) {
+    arg_convertibles[0].reset(reinterpret_cast<v8::ConvertableToTraceFormat*>(
+        static_cast<intptr_t>(arg_values[0])));
+  }
+  if (num_args > 1 && arg_types[1] == TRACE_VALUE_TYPE_CONVERTABLE) {
+    arg_convertibles[1].reset(reinterpret_cast<v8::ConvertableToTraceFormat*>(
+        static_cast<intptr_t>(arg_values[1])));
+  }
+  node::tracing::TracingController* controller =
+      node::tracing::TraceEventHelper::GetTracingController();
+  return controller->AddMetadataEvent(
+      category_group_enabled, name, num_args, arg_names, arg_types, arg_values,
+      arg_convertibles, flags);
+}
+
 // Define SetTraceValue for each allowed type. It stores the type and
 // value in the return arguments. This allows this API to avoid declaring any
 // structures so that it is portable to third_party libraries.
@@ -632,23 +653,16 @@ static V8_INLINE uint64_t AddTraceEventWithTimestamp(
 }
 
 template <class ARG1_TYPE>
-static V8_INLINE uint64_t AddMetadataEvent(
+static V8_INLINE void AddMetadataEvent(
     const uint8_t* category_group_enabled, const char* name,
     const char* arg1_name, ARG1_TYPE&& arg1_val) {
   const int num_args = 1;
   uint8_t arg_type;
   uint64_t arg_value;
   SetTraceValue(std::forward<ARG1_TYPE>(arg1_val), &arg_type, &arg_value);
-  // TODO(ofrobots): It would be good to add metadata events to a separate
-  // buffer so that they can be periodically reemitted. For now, we have a
-  // single buffer, so we just add them to the main buffer.
-  return TRACE_EVENT_API_ADD_TRACE_EVENT(
-      TRACE_EVENT_PHASE_METADATA,
-      category_group_enabled, name,
-      node::tracing::kGlobalScope,  // scope
-      node::tracing::kNoId,         // id
-      node::tracing::kNoId,         // bind_id
-      num_args, &arg1_name, &arg_type, &arg_value, TRACE_EVENT_FLAG_NONE);
+  AddMetadataEventImpl(
+      category_group_enabled, name, num_args, &arg1_name, &arg_type, &arg_value,
+      TRACE_EVENT_FLAG_NONE);
 }
 
 // Used by TRACE_EVENTx macros. Do not use directly.

test/cctest/node_test_fixture.cc

@@ -3,4 +3,4 @@
 ArrayBufferUniquePtr NodeTestFixture::allocator{nullptr, nullptr};
 uv_loop_t NodeTestFixture::current_loop;
 NodePlatformUniquePtr NodeTestFixture::platform;
-TracingControllerUniquePtr NodeTestFixture::tracing_controller;
+TracingAgentUniquePtr NodeTestFixture::tracing_agent;

test/cctest/node_test_fixture.h

@@ -55,21 +55,20 @@ struct Argv {
 
 using ArrayBufferUniquePtr = std::unique_ptr<node::ArrayBufferAllocator,
       decltype(&node::FreeArrayBufferAllocator)>;
-using TracingControllerUniquePtr = std::unique_ptr<v8::TracingController>;
+using TracingAgentUniquePtr = std::unique_ptr<node::tracing::Agent>;
 using NodePlatformUniquePtr = std::unique_ptr<node::NodePlatform>;
 
 class NodeTestFixture : public ::testing::Test {
  protected:
   static ArrayBufferUniquePtr allocator;
-  static TracingControllerUniquePtr tracing_controller;
+  static TracingAgentUniquePtr tracing_agent;
   static NodePlatformUniquePtr platform;
   static uv_loop_t current_loop;
   v8::Isolate* isolate_;
 
   static void SetUpTestCase() {
-    tracing_controller.reset(new v8::TracingController());
-    node::tracing::TraceEventHelper::SetTracingController(
-        tracing_controller.get());
+    tracing_agent.reset(new node::tracing::Agent());
+    node::tracing::TraceEventHelper::SetAgent(tracing_agent.get());
     CHECK_EQ(0, uv_loop_init(&current_loop));
     platform.reset(static_cast<node::NodePlatform*>(
           node::InitializeV8Platform(4)));

test/parallel/test-trace-events-dynamic-enable.js

@@ -25,9 +25,12 @@ function post(message, data) {
 async function test() {
   session.connect();
 
-  let traceNotification = null;
+  const events = [];
   let tracingComplete = false;
-  session.on('NodeTracing.dataCollected', (n) => traceNotification = n);
+  session.on('NodeTracing.dataCollected', (n) => {
+    assert.ok(n && n.data && n.data.value);
+    events.push(...n.data.value);  // append the events.
+  });
   session.on('NodeTracing.tracingComplete', () => tracingComplete = true);
 
   // Generate a node.perf event before tracing is enabled.
@@ -47,10 +50,7 @@ async function test() {
   session.disconnect();
 
   assert.ok(tracingComplete);
-  assert.ok(traceNotification);
-  assert.ok(traceNotification.data && traceNotification.data.value);
 
-  const events = traceNotification.data.value;
   const marks = events.filter((t) => null !== /node\.perf\.usertim/.exec(t.cat));
   assert.strictEqual(marks.length, 1);
   assert.strictEqual(marks[0].name, 'mark2');