diff --git a/doc/api/tracing.md b/doc/api/tracing.md index df76d985f71dbe..d63d9ee33df245 100644 --- a/doc/api/tracing.md +++ b/doc/api/tracing.md @@ -226,6 +226,61 @@ t2.enable(); console.log(trace_events.getEnabledCategories()); ``` +### `trace_events.trace(phase, category, name, id, data)` + + + +use `trace_events.trace` to product trace events data, then this data can be +collected by the `inspector` module or the `trace_events.createTracing` method. + +The following example is used to product custom trace event, and collect +the data by using the inspector. + +```js +'use strict'; + +const { + trace, + events: { + TRACE_EVENT_PHASE_NESTABLE_ASYNC_BEGIN: kBeforeEvent + }, +} = require('trace_events'); + +const { Session } = require('inspector'); + +const session = new Session(); + +function post(message, data) { + return new Promise((resolve, reject) => { + session.post(message, data, (err, result) => { + if (err) + reject(new Error(JSON.stringify(err))); + else + resolve(result); + }); + }); +} + +async function test() { + session.connect(); + const events = []; + session.on('NodeTracing.dataCollected', (n) => { + events.push(...n.params.value.filter((v) => v.cat !== '__metadata')); + }); + session.on('NodeTracing.tracingComplete', () => console.log(events)); + + const traceConfig = { includedCategories: ['custom'] }; + await post('NodeTracing.start', { traceConfig }); + trace(kBeforeEvent, 'custom', 'hello', 0, 'world'); + await post('NodeTracing.stop', { traceConfig }); + session.disconnect(); +} + +test(); +``` + [Performance API]: perf_hooks.md [V8]: v8.md [`Worker`]: worker_threads.md#class-worker diff --git a/lib/trace_events.js b/lib/trace_events.js index 5211f8b0b1fc74..5ef01de7b35322 100644 --- a/lib/trace_events.js +++ b/lib/trace_events.js @@ -11,7 +11,7 @@ const { hasTracing } = internalBinding('config'); const kHandle = Symbol('handle'); const kEnabled = Symbol('enabled'); const kCategories = Symbol('categories'); - +const { isMainThread } = require('worker_threads'); const kMaxTracingCount = 10; const { @@ -24,7 +24,8 @@ const { ownsProcessState } = require('internal/worker'); if (!hasTracing || !ownsProcessState) throw new ERR_TRACE_EVENTS_UNAVAILABLE(); -const { CategorySet, getEnabledCategories } = internalBinding('trace_events'); +const { CategorySet, getEnabledCategories, trace } = internalBinding('trace_events'); +const constants = internalBinding('constants'); const { customInspectSymbol } = require('internal/util'); const { format } = require('internal/util/inspect'); const { @@ -98,5 +99,7 @@ function createTracing(options) { module.exports = { createTracing, - getEnabledCategories + getEnabledCategories, + trace: isMainThread ? trace : null, + events: constants.trace }; diff --git a/test/parallel/test-trace-events-api-trace.js b/test/parallel/test-trace-events-api-trace.js new file mode 100644 index 00000000000000..b9474d53bd7356 --- /dev/null +++ b/test/parallel/test-trace-events-api-trace.js @@ -0,0 +1,54 @@ +'use strict'; + +const common = require('../common'); +common.skipIfWorker(); // https://github.com/nodejs/node/issues/22767 + +const assert = require('assert'); +const fs = require('fs'); +const path = require('path'); +const cp = require('child_process'); +const tmpdir = require('../common/tmpdir'); + +if (process.argv[2] === 'isChild') { + const { + createTracing, + trace, + events: { + TRACE_EVENT_PHASE_NESTABLE_ASYNC_BEGIN: kBeforeEvent, + TRACE_EVENT_PHASE_NESTABLE_ASYNC_END: kEndEvent + }, + } = require('trace_events'); + + const tracing = createTracing({ categories: [ 'custom' ] }); + tracing.enable(); + trace(kBeforeEvent, 'custom', 'hello', 0, 'world'); + setTimeout(() => { + trace(kEndEvent, 'custom', 'hello', 0, 'world'); + tracing.disable(); + }, 1); +} else { + tmpdir.refresh(); + const parentDir = process.cwd(); + process.chdir(tmpdir.path); + const proc = cp.fork(__filename, ['isChild'], { + execArgv: [ + '--trace-event-categories', + 'custom', + ] + }); + + proc.once('exit', common.mustCall(() => { + const file = path.join(tmpdir.path, 'node_trace.1.log'); + assert(fs.existsSync(file)); + fs.readFile(file, { encoding: 'utf-8' }, common.mustSucceed((data) => { + const traces = JSON.parse(data).traceEvents.filter((trace) => trace.cat !== '__metadata'); + assert.strictEqual(traces.length, 2); + traces.forEach((trace) => { + assert.strictEqual(trace.cat, 'custom'); + assert.strictEqual(trace.name, 'hello'); + assert.strictEqual(trace.args.data, 'world'); + }); + })); + process.chdir(parentDir); + })); +} diff --git a/test/parallel/test-trace-events-dynamic-enable.js b/test/parallel/test-trace-events-dynamic-enable.js index 237bb1de8df743..b1ee14cbef33e5 100644 --- a/test/parallel/test-trace-events-dynamic-enable.js +++ b/test/parallel/test-trace-events-dynamic-enable.js @@ -1,4 +1,3 @@ -// Flags: --expose-internals 'use strict'; const common = require('../common'); @@ -6,15 +5,12 @@ const common = require('../common'); common.skipIfInspectorDisabled(); common.skipIfWorker(); // https://github.com/nodejs/node/issues/22767 -const { internalBinding } = require('internal/test/binding'); - const { - trace: { + trace, + events: { TRACE_EVENT_PHASE_NESTABLE_ASYNC_BEGIN: kBeforeEvent - } -} = internalBinding('constants'); - -const { trace } = internalBinding('trace_events'); + }, +} = require('trace_events'); const assert = require('assert'); const { Session } = require('inspector'); @@ -37,11 +33,11 @@ async function test() { const events = []; let tracingComplete = false; - session.on('NodeTracing.dataCollected', (n) => { + session.on('NodeTracing.dataCollected', common.mustCallAtLeast((n) => { assert.ok(n && n.params && n.params.value); events.push(...n.params.value); // append the events. - }); - session.on('NodeTracing.tracingComplete', () => tracingComplete = true); + })); + session.on('NodeTracing.tracingComplete', common.mustCall(() => tracingComplete = true)); trace(kBeforeEvent, 'foo', 'test1', 0, 'test');