lib: add perfetto support

Signed-off-by: Chengzhong Wu <cwu631@bloomberg.net>
PR-URL: #64565
Refs: nodejs/diagnostics#654
Reviewed-By: James M Snell <jasnell@gmail.com>
Reviewed-By: Ryuhei Shima <shimaryuhei@gmail.com>

Author: legendecas

lib/internal/console/constructor.js

@@ -35,7 +35,7 @@ const {
   SymbolToStringTag,
 } = primordials;
 
-const { trace } = internalBinding('trace_events');
+const { trace, nodeTraceEventCategory, kTraceCount } = require('internal/trace_events');
 const {
   codes: {
     ERR_CONSOLE_WRITABLE_STREAM,
@@ -59,9 +59,6 @@ const {
 const {
   isTypedArray, isSet, isMap, isSetIterator, isMapIterator,
 } = require('internal/util/types');
-const {
-  CHAR_UPPERCASE_C: kTraceCount,
-} = require('internal/constants');
 const kCounts = Symbol('counts');
 const { time, timeLog, timeEnd, kNone } = require('internal/util/debuglog');
 const { channel } = require('diagnostics_channel');
@@ -72,7 +69,7 @@ const onError = channel('console.error');
 const onInfo = channel('console.info');
 const onDebug = channel('console.debug');
 
-const kTraceConsoleCategory = 'node,node.console';
+const kTraceConsoleCategory = nodeTraceEventCategory('node.console');
 
 const kMaxGroupIndentation = 1000;
 

lib/internal/constants.js

@@ -9,7 +9,9 @@ module.exports = {
   CHAR_UPPERCASE_Z: 90, /* Z */
   CHAR_LOWERCASE_Z: 122, /* z */
   CHAR_UPPERCASE_C: 67, /* C */
+  CHAR_UPPERCASE_B: 66, /* B */
   CHAR_LOWERCASE_B: 98, /* b */
+  CHAR_UPPERCASE_E: 69, /* E */
   CHAR_LOWERCASE_E: 101, /* e */
   CHAR_LOWERCASE_N: 110, /* n */
 

lib/internal/http.js

@@ -9,11 +9,13 @@ const {
 } = primordials;
 
 const { setUnrefTimeout } = require('internal/timers');
-const { getCategoryEnabledBuffer, trace } = internalBinding('trace_events');
 const {
-  CHAR_LOWERCASE_B,
-  CHAR_LOWERCASE_E,
-} = require('internal/constants');
+  getCategoryEnabledBuffer,
+  trace,
+  nodeTraceEventCategory,
+  kAsyncBegin,
+  kAsyncEnd,
+} = require('internal/trace_events');
 
 const { URL } = require('internal/url');
 const { Buffer } = require('buffer');
@@ -48,14 +50,14 @@ function isTraceHTTPEnabled() {
   return httpEnabled[0] > 0;
 }
 
-const traceEventCategory = 'node,node.http';
+const traceEventCategory = nodeTraceEventCategory('node.http');
 
 function traceBegin(...args) {
-  trace(CHAR_LOWERCASE_B, traceEventCategory, ...args);
+  trace(kAsyncBegin, traceEventCategory, ...args);
 }
 
 function traceEnd(...args) {
-  trace(CHAR_LOWERCASE_E, traceEventCategory, ...args);
+  trace(kAsyncEnd, traceEventCategory, ...args);
 }
 
 function ipToInt(ip) {

lib/internal/trace_events.js

@@ -0,0 +1,56 @@
+'use strict';
+
+const { getCategoryEnabledBuffer, trace, usePerfetto } = internalBinding('trace_events');
+const {
+  CHAR_UPPERCASE_B,
+  CHAR_LOWERCASE_B,
+  CHAR_UPPERCASE_C,
+  CHAR_LOWERCASE_E,
+  CHAR_UPPERCASE_E,
+  CHAR_LOWERCASE_N,
+} = require('internal/constants');
+
+let nodeTraceEventCategory;
+if (usePerfetto) {
+  nodeTraceEventCategory = (category) => `${category}`;
+} else {
+  nodeTraceEventCategory = (category) => `node,${category}`;
+}
+
+// The async events describe the execution of a single asynchronous operation, and are
+// used to measure the time spent in a single asynchronous operation.
+// Async events may overlap with each other. Different events do not have
+// to be nested, or FILO (first in last out).
+// TODO(legendecas): V8 `trace` API does not support async marks in perfetto yet.
+const kAsyncBegin = usePerfetto ? CHAR_UPPERCASE_B : CHAR_LOWERCASE_B;
+const kAsyncEnd = usePerfetto ? CHAR_UPPERCASE_E : CHAR_LOWERCASE_E;
+
+// The sync events describe the execution of a single thread, and are
+// used to measure the time spent in a function.
+// Sync events must be nested, and are FILO (first in last out), in a stack
+// manner.
+const kSyncBegin = CHAR_UPPERCASE_B;
+const kSyncEnd = CHAR_UPPERCASE_E;
+
+// Counter events track a named numeric value as it changes over time. Each
+// event records the value at a point in time, and the trace viewer renders the
+// series as a graph.
+// TODO(legendecas): V8 `trace` API does not support count marks in perfetto yet.
+const kTraceCount = usePerfetto ? CHAR_LOWERCASE_N : CHAR_UPPERCASE_C;
+
+// Instant events mark a single moment in time. They have no duration and do
+// not need to be paired or nested.
+const kTraceInstant = CHAR_LOWERCASE_N;
+
+module.exports = {
+  usePerfetto,
+  getCategoryEnabledBuffer,
+  trace,
+  nodeTraceEventCategory,
+  kAsyncBegin,
+  kAsyncEnd,
+  kSyncBegin,
+  kSyncEnd,
+  kTraceCount,
+  kTraceInstant,
+};

lib/internal/trace_events_async_hooks.js

@@ -7,20 +7,18 @@ const {
   Symbol,
 } = primordials;
 
-const { trace } = internalBinding('trace_events');
+const {
+  trace,
+  nodeTraceEventCategory,
+  kAsyncBegin,
+  kAsyncEnd,
+  kSyncBegin,
+  kSyncEnd,
+} = require('internal/trace_events');
 const async_wrap = internalBinding('async_wrap');
 const async_hooks = require('async_hooks');
-const {
-  CHAR_LOWERCASE_B,
-  CHAR_LOWERCASE_E,
-} = require('internal/constants');
 
-// Use small letters such that chrome://tracing groups by the name.
-// The behavior is not only useful but the same as the events emitted using
-// the specific C++ macros.
-const kBeforeEvent = CHAR_LOWERCASE_B;
-const kEndEvent = CHAR_LOWERCASE_E;
-const kTraceEventCategory = 'node,node.async_hooks';
+const kTraceEventCategory = nodeTraceEventCategory('node.async_hooks');
 
 const kEnabled = Symbol('enabled');
 
@@ -45,7 +43,7 @@ function createHook() {
       if (nativeProviders.has(type)) return;
 
       typeMemory.set(asyncId, type);
-      trace(kBeforeEvent, kTraceEventCategory,
+      trace(kAsyncBegin, kTraceEventCategory,
             type, asyncId,
             {
               triggerAsyncId,
@@ -57,21 +55,21 @@ function createHook() {
       const type = typeMemory.get(asyncId);
       if (type === undefined) return;
 
-      trace(kBeforeEvent, kTraceEventCategory, `${type}_CALLBACK`, asyncId);
+      trace(kSyncBegin, kTraceEventCategory, `${type}_CALLBACK`, asyncId);
     },
 
     after(asyncId) {
       const type = typeMemory.get(asyncId);
       if (type === undefined) return;
 
-      trace(kEndEvent, kTraceEventCategory, `${type}_CALLBACK`, asyncId);
+      trace(kSyncEnd, kTraceEventCategory, `${type}_CALLBACK`, asyncId);
     },
 
     destroy(asyncId) {
       const type = typeMemory.get(asyncId);
       if (type === undefined) return;
 
-      trace(kEndEvent, kTraceEventCategory, type, asyncId);
+      trace(kAsyncEnd, kTraceEventCategory, type, asyncId);
 
       // Cleanup asyncId to type map
       typeMemory.delete(asyncId);

lib/internal/util/debuglog.js

@@ -14,13 +14,15 @@ const {
   StringPrototypeToLowerCase,
   StringPrototypeToUpperCase,
 } = primordials;
-const {
-  CHAR_LOWERCASE_B: kTraceBegin,
-  CHAR_LOWERCASE_E: kTraceEnd,
-  CHAR_LOWERCASE_N: kTraceInstant,
-} = require('internal/constants');
 const { inspect, format, formatWithOptions } = require('internal/util/inspect');
-const { getCategoryEnabledBuffer, trace } = internalBinding('trace_events');
+const {
+  getCategoryEnabledBuffer,
+  trace,
+  nodeTraceEventCategory,
+  kAsyncBegin,
+  kAsyncEnd,
+  kTraceInstant,
+} = require('internal/trace_events');
 
 // `debugImpls` and `testEnabled` are deliberately not initialized so any call
 // to `debuglog()` before `initializeDebugEnv()` is called will throw.
@@ -246,7 +248,7 @@ function time(timesStore, traceCategory, implementation, timerFlags, logLabel =
 
   if ((timerFlags & kSkipTrace) === 0) {
     traceLabel = safeTraceLabel(traceLabel);
-    trace(kTraceBegin, traceCategory, traceLabel, 0);
+    trace(kAsyncBegin, traceCategory, traceLabel, 0);
   }
 
   timesStore.set(logLabel, process.hrtime());
@@ -286,7 +288,7 @@ function timeEnd(
 
   if ((timerFlags & kSkipTrace) === 0) {
     traceLabel = safeTraceLabel(traceLabel);
-    trace(kTraceEnd, traceCategory, traceLabel, 0);
+    trace(kAsyncEnd, traceCategory, traceLabel, 0);
   }
 
   timesStore.delete(logLabel);
@@ -385,7 +387,7 @@ function debugWithTimer(set, cb) {
       );
   }
 
-  const traceCategory = `node,node.${StringPrototypeToLowerCase(set)}`;
+  const traceCategory = nodeTraceEventCategory(`node.${StringPrototypeToLowerCase(set)}`);
   let traceCategoryBuffer;
   let debugLogCategoryEnabled = false;
   let timerFlags = kNone;

src/node_constants.cc

@@ -1322,9 +1322,6 @@ void DefineTraceConstants(Local<Object> target) {
   NODE_DEFINE_CONSTANT(target, TRACE_EVENT_PHASE_MEMORY_DUMP);
   NODE_DEFINE_CONSTANT(target, TRACE_EVENT_PHASE_MARK);
   NODE_DEFINE_CONSTANT(target, TRACE_EVENT_PHASE_CLOCK_SYNC);
-  NODE_DEFINE_CONSTANT(target, TRACE_EVENT_PHASE_ENTER_CONTEXT);
-  NODE_DEFINE_CONSTANT(target, TRACE_EVENT_PHASE_LEAVE_CONTEXT);
-  NODE_DEFINE_CONSTANT(target, TRACE_EVENT_PHASE_LINK_IDS);
 }
 
 void CreatePerContextProperties(Local<Object> target,

src/node_trace_events.cc

@@ -188,6 +188,14 @@ void NodeCategorySet::Initialize(Local<Object> target,
                   .Check();
   target->Set(context, trace,
               binding->Get(context, trace).ToLocalChecked()).Check();
+
+  Local<String> use_perfetto =
+      FIXED_ONE_BYTE_STRING(env->isolate(), "usePerfetto");
+#if defined(V8_USE_PERFETTO)
+  target->Set(context, use_perfetto, v8::True(isolate)).Check();
+#else
+  target->Set(context, use_perfetto, v8::False(isolate)).Check();
+#endif
 }
 
 void NodeCategorySet::RegisterExternalReferences(

test/parallel/test-bootstrap-modules.js

@@ -118,6 +118,7 @@ expected.beforePreExec = new Set([
   'NativeModule internal/net',
   'NativeModule internal/dns/utils',
   'NativeModule internal/modules/esm/get_format',
+  'NativeModule internal/trace_events',
 ]);
 
 expected.atRunTime = new Set([