src: add tracing controller

This commit adds support for trace-event tracing to Node.js. It provides
a mechanism to centralize tracing information generated by V8, Node
core, and userspace code. It includes:

 - A trace writer responsible for serializing traces and cycling the
   output files so that no individual file becomes to large.
 - A buffer for aggregating traces to allow for batched flushes.
 - An agent which initializes the tracing controller and ensures that
   trace serialization is done on a separate thread.
 - A set of macros for generating trace events.
 - Tests and documentation.

Author: Raymond Kang <raymondksi@gmail.com>
Author: Kelvin Jin <kelvinjin@google.com>
Author: Matthew Loring <mattloring@google.com>
Author: Jason Ginchereau <jasongin@microsoft.com>

PR-URL: #11106
Reviewed-By: Josh Gavant <josh.gavant@outlook.com>

doc/api/cli.md

@@ -139,6 +139,20 @@ added: v2.1.0
 Prints a stack trace whenever synchronous I/O is detected after the first turn
 of the event loop.
 
+### `--trace-events-enabled`
+<!-- YAML
+added: REPLACEME
+-->
+
+Enables the collection of trace event tracing information.
+
+### `--trace-event-categories`
+<!-- YAML
+added: REPLACEME
+-->
+
+A comma separated list of categories that should be traced when trace event
+tracing is enabled using `--trace-events-enabled`.
 
 ### `--zero-fill-buffers`
 <!-- YAML

doc/api/debugger.md

@@ -201,4 +201,4 @@ To start debugging, open the following URL in Chrome:
     chrome-devtools://devtools/remote/serve_file/@60cd6e859b9f557d2312f5bf532f6aec5f284980/inspector.html?experiments=true&v8only=true&ws=localhost:9229/node
 ```
 
-[TCP-based protocol]: https://github.com/v8/v8/wiki/Debugging-Protocol
+[TCP-based protocol]: https://github.com/v8/v8/wiki/Debugging-Protocol

doc/api/tracing.md

@@ -0,0 +1,19 @@
+# Tracing
+
+Trace Event provides a mechanism to centralize tracing information generated by
+V8, Node core, and userspace code.
+
+Tracing can be enabled by passing the `--trace-events-enabled` flag when starting a
+Node.js application.
+
+The set of categories for which traces are recorded can be specified using the
+`--trace-event-categories` flag followed by a list of comma separated category names.
+By default the `node` and `v8` categories are enabled.
+
+```txt
+node --trace-events-enabled --trace-event-categories v8,node server.js
+```
+
+Running Node.js with tracing enabled will produce log files that can be opened
+in the [`chrome://tracing`](https://www.chromium.org/developers/how-tos/trace-event-profiling-tool)
+tab of Chrome.

node.gyp

@@ -152,6 +152,10 @@
       ],
 
       'sources': [
+        'src/tracing/agent.cc',
+        'src/tracing/node_trace_buffer.cc',
+        'src/tracing/node_trace_writer.cc',
+        'src/tracing/trace_event.cc',
         'src/async-wrap.cc',
         'src/cares_wrap.cc',
         'src/connection_wrap.cc',
@@ -230,6 +234,7 @@
         'src/stream_base.h',
         'src/stream_base-inl.h',
         'src/stream_wrap.h',
+        'src/tracing/trace_event.h'
         'src/tree.h',
         'src/util.h',
         'src/util-inl.h',

src/node.cc

@@ -38,6 +38,7 @@
 #include "req-wrap.h"
 #include "req-wrap-inl.h"
 #include "string_bytes.h"
+#include "tracing/agent.h"
 #include "util.h"
 #include "uv.h"
 #if NODE_USE_V8_PLATFORM
@@ -151,6 +152,8 @@ static node_module* modpending;
 static node_module* modlist_builtin;
 static node_module* modlist_linked;
 static node_module* modlist_addon;
+static bool trace_enabled = false;
+static const char* trace_enabled_categories = nullptr;
 
 #if defined(NODE_HAVE_I18N_SUPPORT)
 // Path to ICU data (for i18n / Intl)
@@ -195,6 +198,7 @@ static uv_async_t dispatch_debug_messages_async;
 
 static Mutex node_isolate_mutex;
 static v8::Isolate* node_isolate;
+static tracing::Agent* tracing_agent;
 
 static node::DebugOptions debug_options;
 
@@ -203,6 +207,7 @@ static struct {
   void Initialize(int thread_pool_size) {
     platform_ = v8::platform::CreateDefaultPlatform(thread_pool_size);
     V8::InitializePlatform(platform_);
+    tracing::TraceEventHelper::SetCurrentPlatform(platform_);
   }
 
   void PumpMessageLoop(Isolate* isolate) {
@@ -3369,6 +3374,9 @@ void SetupProcessObject(Environment* env,
 
 void SignalExit(int signo) {
   uv_tty_reset_mode();
+  if (trace_enabled) {
+    tracing_agent->Stop();
+  }
 #ifdef __FreeBSD__
   // FreeBSD has a nasty bug, see RegisterSignalHandler for details
   struct sigaction sa;
@@ -3655,6 +3663,16 @@ static void ParseArgs(int* argc,
       trace_deprecation = true;
     } else if (strcmp(arg, "--trace-sync-io") == 0) {
       trace_sync_io = true;
+    } else if (strcmp(arg, "--trace-events-enabled") == 0) {
+      trace_enabled = true;
+    } else if (strcmp(arg, "--trace-event-categories") == 0) {
+      const char* categories = argv[index + 1];
+      if (categories == nullptr) {
+        fprintf(stderr, "%s: %s requires an argument\n", argv[0], arg);
+        exit(9);
+      }
+      args_consumed += 1;
+      trace_enabled_categories = categories;
     } else if (strcmp(arg, "--track-heap-objects") == 0) {
       track_heap_objects = true;
     } else if (strcmp(arg, "--throw-deprecation") == 0) {
@@ -4499,10 +4517,20 @@ int Start(int argc, char** argv) {
 #endif  // HAVE_OPENSSL
 
   v8_platform.Initialize(v8_thread_pool_size);
+  // Enable tracing when argv has --trace-events-enabled.
+  if (trace_enabled) {
+    fprintf(stderr, "Warning: Trace event is an experimental feature "
+            "and could change at any time.\n");
+    tracing_agent = new tracing::Agent();
+    tracing_agent->Start(v8_platform.platform_, trace_enabled_categories);
+  }
   V8::Initialize();
   v8_initialized = true;
   const int exit_code =
       Start(uv_default_loop(), argc, argv, exec_argc, exec_argv);
+  if (trace_enabled) {
+    tracing_agent->Stop();
+  }
   v8_initialized = false;
   V8::Dispose();
 

src/node.h

@@ -41,6 +41,7 @@
 
 #include "v8.h"  // NOLINT(build/include_order)
 #include "node_version.h"  // NODE_MODULE_VERSION
+#include "tracing/trace_event.h"
 
 #define NODE_MAKE_VERSION(major, minor, patch)                                \
   ((major) * 0x1000 + (minor) * 0x100 + (patch))

src/tracing/agent.cc

@@ -0,0 +1,72 @@
+#include "tracing/agent.h"
+
+#include <sstream>
+#include <string>
+
+#include "env-inl.h"
+#include "libplatform/libplatform.h"
+
+namespace node {
+namespace tracing {
+
+using v8::platform::tracing::TraceConfig;
+
+Agent::Agent() {}
+
+void Agent::Start(v8::Platform* platform, const char* enabled_categories) {
+  platform_ = platform;
+
+  int err = uv_loop_init(&tracing_loop_);
+  CHECK_EQ(err, 0);
+
+  NodeTraceWriter* trace_writer = new NodeTraceWriter(&tracing_loop_);
+  TraceBuffer* trace_buffer = new NodeTraceBuffer(
+      NodeTraceBuffer::kBufferChunks, trace_writer, &tracing_loop_);
+
+  tracing_controller_ = new TracingController();
+
+  TraceConfig* trace_config = new TraceConfig();
+  if (enabled_categories) {
+    std::stringstream category_list(enabled_categories);
+    while (category_list.good()) {
+      std::string category;
+      getline(category_list, category, ',');
+      trace_config->AddIncludedCategory(category.c_str());
+    }
+  } else {
+    trace_config->AddIncludedCategory("v8");
+    trace_config->AddIncludedCategory("node");
+  }
+
+  // This thread should be created *after* async handles are created
+  // (within NodeTraceWriter and NodeTraceBuffer constructors).
+  // Otherwise the thread could shut down prematurely.
+  err = uv_thread_create(&thread_, ThreadCb, this);
+  CHECK_EQ(err, 0);
+
+  tracing_controller_->Initialize(trace_buffer);
+  tracing_controller_->StartTracing(trace_config);
+  v8::platform::SetTracingController(platform, tracing_controller_);
+}
+
+void Agent::Stop() {
+  if (!IsStarted()) {
+    return;
+  }
+  // Perform final Flush on TraceBuffer. We don't want the tracing controller
+  // to flush the buffer again on destruction of the V8::Platform.
+  tracing_controller_->StopTracing();
+  delete tracing_controller_;
+  // Thread should finish when the tracing loop is stopped.
+  uv_thread_join(&thread_);
+  v8::platform::SetTracingController(platform_, nullptr);
+}
+
+// static
+void Agent::ThreadCb(void* arg) {
+  Agent* agent = static_cast<Agent*>(arg);
+  uv_run(&agent->tracing_loop_, UV_RUN_DEFAULT);
+}
+
+}  // namespace tracing
+}  // namespace node

src/tracing/agent.h

@@ -0,0 +1,31 @@
+#ifndef SRC_TRACING_AGENT_H_
+#define SRC_TRACING_AGENT_H_
+
+#include "tracing/node_trace_buffer.h"
+#include "tracing/node_trace_writer.h"
+#include "uv.h"
+#include "v8.h"
+
+namespace node {
+namespace tracing {
+
+class Agent {
+ public:
+  explicit Agent();
+  void Start(v8::Platform* platform, const char* enabled_categories);
+  void Stop();
+
+ private:
+  bool IsStarted() { return platform_ != nullptr; }
+  static void ThreadCb(void* arg);
+
+  uv_thread_t thread_;
+  uv_loop_t tracing_loop_;
+  v8::Platform* platform_ = nullptr;
+  TracingController* tracing_controller_;
+};
+
+}  // namespace tracing
+}  // namespace node
+
+#endif  // SRC_TRACING_AGENT_H_