Skip to content

Commit 75fe3a3

Browse files
committed
test_runner: publish to TracingChannel node.test for instrumentation
1 parent d9645d7 commit 75fe3a3

File tree

5 files changed

+311
-2
lines changed

5 files changed

+311
-2
lines changed

doc/api/test.md

Lines changed: 88 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -3563,6 +3563,92 @@ Emitted when no more tests are queued for execution in watch mode.
35633563

35643564
Emitted when one or more tests are restarted due to a file change in watch mode.
35653565

3566+
## Test instrumentation and OpenTelemetry
3567+
3568+
<!-- YAML
3569+
added: REPLACEME
3570+
-->
3571+
3572+
The test runner publishes test execution events through the Node.js
3573+
[`diagnostics_channel`][] module, enabling integration with observability tools
3574+
like OpenTelemetry without requiring changes to the test runner itself.
3575+
3576+
### Tracing events
3577+
3578+
The test runner publishes events to the `'node.test'` tracing channel. Subscribers
3579+
can use the [`TracingChannel`][] API to bind context or perform custom
3580+
instrumentation.
3581+
3582+
#### Channel: `'tracing:node.test:start'`
3583+
3584+
* `data` {Object}
3585+
* `name` {string} The name of the test.
3586+
* `nesting` {number} The nesting level of the test.
3587+
* `file` {string} The path to the test file.
3588+
* `type` {string} The type of test. Either `'test'` or `'suite'`.
3589+
3590+
Emitted when a test or suite starts execution. The test's span encompasses all
3591+
of its before, beforeEach, and afterEach hooks, as well as the test body.
3592+
3593+
#### Channel: `'tracing:node.test:end'`
3594+
3595+
* `data` {Object}
3596+
* `name` {string} The name of the test.
3597+
* `nesting` {number} The nesting level of the test.
3598+
* `file` {string} The path to the test file.
3599+
* `type` {string} The type of test. Either `'test'` or `'suite'`.
3600+
3601+
Emitted when a test or suite finishes execution.
3602+
3603+
#### Channel: `'tracing:node.test:error'`
3604+
3605+
* `data` {Object}
3606+
* `name` {string} The name of the test.
3607+
* `nesting` {number} The nesting level of the test.
3608+
* `file` {string} The path to the test file.
3609+
* `type` {string} The type of test. Either `'test'` or `'suite'`.
3610+
* `error` {Error} The error that was thrown.
3611+
3612+
Emitted when a test or suite throws an error.
3613+
3614+
### OpenTelemetry integration
3615+
3616+
The tracing channel can be used to integrate with OpenTelemetry by binding
3617+
an `AsyncLocalStorage` instance. This allows OpenTelemetry context to be
3618+
automatically propagated through the test execution and all async operations
3619+
within the test.
3620+
3621+
```mjs
3622+
import { diagnosticsChannel } from 'node:diagnostics_channel';
3623+
import { AsyncLocalStorage } from 'node:async_hooks';
3624+
import { context, trace } from '@opentelemetry/api';
3625+
3626+
const testStorage = new AsyncLocalStorage();
3627+
const testChannel = diagnosticsChannel.tracingChannel('node.test');
3628+
const tracer = trace.getTracer('test-tracer');
3629+
3630+
// Bind OpenTelemetry context to test execution
3631+
testChannel.start.bindStore(testStorage, (data) => {
3632+
const span = tracer.startSpan(data.name);
3633+
return context.with(trace.setSpan(context.active(), span), () => {
3634+
return context.active();
3635+
});
3636+
});
3637+
3638+
// Optionally handle errors and cleanup
3639+
testChannel.error.subscribe((data) => {
3640+
// Handle span errors
3641+
});
3642+
3643+
testChannel.end.subscribe((data) => {
3644+
// Cleanup span
3645+
});
3646+
```
3647+
3648+
When using `bindStore()`, the context provided will be automatically propagated
3649+
to the test function and all async operations within the test, without requiring
3650+
any additional instrumentation in the test code.
3651+
35663652
## Class: `TestContext`
35673653

35683654
<!-- YAML
@@ -4254,11 +4340,13 @@ Can be used to abort test subtasks when the test has been aborted.
42544340
[`NODE_V8_COVERAGE`]: cli.md#node_v8_coveragedir
42554341
[`SuiteContext`]: #class-suitecontext
42564342
[`TestContext`]: #class-testcontext
4343+
[`TracingChannel`]: diagnostics_channel.md#class-tracingchannel
42574344
[`assert.throws`]: assert.md#assertthrowsfn-error-message
42584345
[`context.diagnostic`]: #contextdiagnosticmessage
42594346
[`context.skip`]: #contextskipmessage
42604347
[`context.todo`]: #contexttodomessage
42614348
[`describe()`]: #describename-options-fn
4349+
[`diagnostics_channel`]: diagnostics_channel.md
42624350
[`glob(7)`]: https://man7.org/linux/man-pages/man7/glob.7.html
42634351
[`it()`]: #itname-options-fn
42644352
[`run()`]: #runoptions

lib/internal/test_runner/test.js

Lines changed: 64 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -53,6 +53,7 @@ const {
5353
countCompletedTest,
5454
isTestFailureError,
5555
reporterScope,
56+
testChannel,
5657
} = require('internal/test_runner/utils');
5758
const {
5859
kEmptyObject,
@@ -1140,6 +1141,17 @@ class Test extends AsyncResource {
11401141
}
11411142
this.startTime ??= hrtime();
11421143

1144+
// Channel context object shared across all lifecycle events for this test run.
1145+
// Only tests emit events; hooks do not. This way, the test's span encompasses
1146+
// its before/beforeEach hooks, the test body, and its afterEach/after hooks.
1147+
const channelContext = this.hookType === undefined ? {
1148+
__proto__: null,
1149+
name: this.name,
1150+
nesting: this.nesting,
1151+
file: this.entryFile,
1152+
type: this.reportedType,
1153+
} : null;
1154+
11431155
if (this[kShouldAbort]()) {
11441156
this.postRun();
11451157
return;
@@ -1177,7 +1189,20 @@ class Test extends AsyncResource {
11771189
}
11781190
stopPromise = stopTest(this.timeout, this.signal);
11791191
const runArgs = ArrayPrototypeSlice(args);
1180-
ArrayPrototypeUnshift(runArgs, this.fn, ctx);
1192+
1193+
// Wrap the test function with runStores if the channel has subscribers.
1194+
// The wrapped function is what gets passed to runInAsyncScope, ensuring that
1195+
// the test runs within both the runStores context (for AsyncLocalStorage/bindStore)
1196+
// AND the AsyncResource scope. It's critical that runStores wraps the function,
1197+
// not the runInAsyncScope call itself, to maintain AsyncLocalStorage bindings.
1198+
let testFn = this.fn;
1199+
if (channelContext !== null && testChannel.start.hasSubscribers) {
1200+
testFn = (...fnArgs) => testChannel.start.runStores(channelContext,
1201+
() => ReflectApply(this.fn, this, fnArgs),
1202+
);
1203+
}
1204+
1205+
ArrayPrototypeUnshift(runArgs, testFn, ctx);
11811206

11821207
const promises = [];
11831208
if (this.fn.length === runArgs.length - 1) {
@@ -1226,6 +1251,10 @@ class Test extends AsyncResource {
12261251
await afterEach();
12271252
await after();
12281253
} catch (err) {
1254+
// Publish diagnostics_channel error event if the channel has subscribers
1255+
if (channelContext !== null && testChannel.error.hasSubscribers) {
1256+
testChannel.error.publish({ __proto__: null, ...channelContext, error: err });
1257+
}
12291258
if (isTestFailureError(err)) {
12301259
if (err.failureType === kTestTimeoutFailure) {
12311260
this.#cancel(err);
@@ -1245,6 +1274,11 @@ class Test extends AsyncResource {
12451274
if (this.parent !== null) {
12461275
this.abortController.abort();
12471276
}
1277+
1278+
// Publish diagnostics_channel end event if the channel has subscribers (in both success and error cases)
1279+
if (channelContext !== null && testChannel.end.hasSubscribers) {
1280+
testChannel.end.publish(channelContext);
1281+
}
12481282
}
12491283

12501284
if (this.parent !== null || typeof this.hookType === 'string') {
@@ -1572,12 +1606,40 @@ class Suite extends Test {
15721606
}
15731607

15741608
async createBuild() {
1609+
const channelContext = {
1610+
__proto__: null,
1611+
name: this.name,
1612+
nesting: this.nesting,
1613+
file: this.entryFile,
1614+
type: this.reportedType,
1615+
};
15751616
try {
15761617
const { ctx, args } = this.getRunArgs();
1577-
const runArgs = [this.fn, ctx];
1618+
1619+
// Wrap the suite function with runStores if the channel has subscribers.
1620+
// The wrapped function is what gets passed to runInAsyncScope, ensuring that
1621+
// the suite runs within both the runStores context (for AsyncLocalStorage/bindStore)
1622+
// AND the AsyncResource scope. It's critical that runStores wraps the function,
1623+
// not the runInAsyncScope call itself, to maintain AsyncLocalStorage bindings.
1624+
let suiteFn = this.fn;
1625+
if (channelContext !== null && testChannel.start.hasSubscribers) {
1626+
suiteFn = (...fnArgs) => testChannel.start.runStores(channelContext,
1627+
() => ReflectApply(this.fn, this, fnArgs),
1628+
);
1629+
}
1630+
1631+
const runArgs = [suiteFn, ctx];
15781632
ArrayPrototypePushApply(runArgs, args);
1633+
15791634
await ReflectApply(this.runInAsyncScope, this, runArgs);
1635+
1636+
if (channelContext !== null && testChannel.end.hasSubscribers) {
1637+
testChannel.end.publish(channelContext);
1638+
}
15801639
} catch (err) {
1640+
if (channelContext !== null && testChannel.error.hasSubscribers) {
1641+
testChannel.error.publish({ __proto__: null, ...channelContext, error: err });
1642+
}
15811643
this.fail(new ERR_TEST_FAILURE(err, kTestCodeFailure));
15821644
}
15831645

lib/internal/test_runner/utils.js

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -28,6 +28,7 @@ const {
2828
} = primordials;
2929

3030
const { AsyncResource } = require('async_hooks');
31+
const { tracingChannel } = require('diagnostics_channel');
3132
const { relative, sep, resolve } = require('path');
3233
const { createWriteStream, readFileSync } = require('fs');
3334
const { pathToFileURL } = require('internal/url');
@@ -203,6 +204,7 @@ async function getReportersMap(reporters, destinations) {
203204
}
204205

205206
const reporterScope = new AsyncResource('TestReporterScope');
207+
const testChannel = tracingChannel('node.test');
206208
let globalTestOptions;
207209

208210
function parseCommandLine() {
@@ -661,4 +663,5 @@ module.exports = {
661663
getCoverageReport,
662664
setupGlobalSetupTeardownFunctions,
663665
parsePreviousRuns,
666+
testChannel,
664667
};
Lines changed: 17 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,17 @@
1+
'use strict';
2+
const dc = require('node:diagnostics_channel');
3+
const { test } = require('node:test');
4+
5+
const events = [];
6+
dc.subscribe('tracing:node.test:error', (data) => {
7+
events.push(data.name);
8+
});
9+
10+
test('test that intentionally fails', async () => {
11+
throw new Error('expected failure for error event testing');
12+
});
13+
14+
// Report events on exit
15+
process.on('exit', () => {
16+
console.log(JSON.stringify({ errorEvents: events }));
17+
});
Lines changed: 139 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,139 @@
1+
'use strict';
2+
require('../common');
3+
const assert = require('node:assert');
4+
const dc = require('node:diagnostics_channel');
5+
const { test } = require('node:test');
6+
const { spawnSync } = require('child_process');
7+
const { join } = require('path');
8+
9+
const events = [];
10+
11+
dc.subscribe('tracing:node.test:start', (data) => events.push({ event: 'start', name: data.name }));
12+
dc.subscribe('tracing:node.test:end', (data) => events.push({ event: 'end', name: data.name }));
13+
dc.subscribe('tracing:node.test:error', (data) => events.push({ event: 'error', name: data.name }));
14+
15+
test('passing test fires start and end', async () => {});
16+
17+
// Validate events were emitted (check after all tests via process.on('exit'))
18+
process.on('exit', () => {
19+
// Check passing test
20+
const testName1 = 'passing test fires start and end';
21+
const startEvents = events.filter((e) => e.event === 'start' && e.name === testName1);
22+
const endEvents = events.filter((e) => e.event === 'end' && e.name === testName1);
23+
assert.strictEqual(startEvents.length, 1);
24+
assert.strictEqual(endEvents.length, 1);
25+
26+
// Check nested tests fire events
27+
const nested1Start = events.filter((e) => e.event === 'start' && e.name === 'nested test 1');
28+
const nested1End = events.filter((e) => e.event === 'end' && e.name === 'nested test 1');
29+
const nested2Start = events.filter((e) => e.event === 'start' && e.name === 'nested test 2');
30+
const nested2End = events.filter((e) => e.event === 'end' && e.name === 'nested test 2');
31+
assert.strictEqual(nested1Start.length, 1);
32+
assert.strictEqual(nested1End.length, 1);
33+
assert.strictEqual(nested2Start.length, 1);
34+
assert.strictEqual(nested2End.length, 1);
35+
36+
// Check describe block tests fire events
37+
const describeStart = events.filter((e) => e.event === 'start' && e.name === 'test inside describe');
38+
const describeEnd = events.filter((e) => e.event === 'end' && e.name === 'test inside describe');
39+
const describeStart2 = events.filter(
40+
(e) => e.event === 'start' && e.name === 'another test inside describe',
41+
);
42+
const describeEnd2 = events.filter(
43+
(e) => e.event === 'end' && e.name === 'another test inside describe',
44+
);
45+
assert.strictEqual(describeStart.length, 1);
46+
assert.strictEqual(describeEnd.length, 1);
47+
assert.strictEqual(describeStart2.length, 1);
48+
assert.strictEqual(describeEnd2.length, 1);
49+
50+
// Check async operations test fires events
51+
const asyncTestName = 'context is available in async operations within test';
52+
const asyncStart = events.filter((e) => e.event === 'start' && e.name === asyncTestName);
53+
const asyncEnd = events.filter((e) => e.event === 'end' && e.name === asyncTestName);
54+
assert.strictEqual(asyncStart.length, 1);
55+
assert.strictEqual(asyncEnd.length, 1);
56+
});
57+
58+
// Test bindStore context propagation
59+
const { AsyncLocalStorage } = require('node:async_hooks');
60+
const testStorage = new AsyncLocalStorage();
61+
62+
// bindStore on the start channel: whenever a test fn runs, set testStorage to the test name
63+
dc.channel('tracing:node.test:start').bindStore(testStorage, (data) => data.name);
64+
65+
test('bindStore propagates into test body via start channel', async () => {
66+
const expectedName = 'bindStore propagates into test body via start channel';
67+
const storedValueDuringTest = testStorage.getStore();
68+
assert.strictEqual(storedValueDuringTest, expectedName);
69+
70+
// Propagates into async operations inside the test
71+
const valueInSetImmediate = await new Promise((resolve) => {
72+
setImmediate(() => resolve(testStorage.getStore()));
73+
});
74+
assert.strictEqual(valueInSetImmediate, expectedName);
75+
});
76+
77+
test('bindStore value is isolated between tests', async () => {
78+
assert.strictEqual(testStorage.getStore(), 'bindStore value is isolated between tests');
79+
});
80+
81+
test('nested tests fire events with correct names', async (t) => {
82+
await t.test('nested test 1', async () => {
83+
const stored = testStorage.getStore();
84+
assert.strictEqual(stored, 'nested test 1');
85+
});
86+
87+
await t.test('nested test 2', async () => {
88+
const stored = testStorage.getStore();
89+
assert.strictEqual(stored, 'nested test 2');
90+
});
91+
});
92+
93+
const { describe, it } = require('node:test');
94+
95+
describe('describe block with tests', () => {
96+
it('test inside describe', async () => {
97+
const stored = testStorage.getStore();
98+
assert.strictEqual(stored, 'test inside describe');
99+
});
100+
101+
it('another test inside describe', async () => {
102+
const stored = testStorage.getStore();
103+
assert.strictEqual(stored, 'another test inside describe');
104+
});
105+
});
106+
107+
test('context is available in async operations within test', async () => {
108+
const testName = 'context is available in async operations within test';
109+
assert.strictEqual(testStorage.getStore(), testName);
110+
111+
// Verify context is available in setImmediate
112+
const valueInImmediate = await new Promise((resolve) => {
113+
setImmediate(() => resolve(testStorage.getStore()));
114+
});
115+
assert.strictEqual(valueInImmediate, testName);
116+
117+
// Verify context is available in setTimeout
118+
const valueInTimeout = await new Promise((resolve) => {
119+
setTimeout(() => resolve(testStorage.getStore()), 0);
120+
});
121+
assert.strictEqual(valueInTimeout, testName);
122+
});
123+
124+
test('error events fire for failing tests in fixture', async () => {
125+
// Run the fixture test that intentionally fails
126+
const fixturePath = join(__dirname, '../fixtures/test-runner/diagnostics-channel-error-test.js');
127+
const result = spawnSync(process.execPath, [fixturePath], { encoding: 'utf8' });
128+
129+
// The fixture test intentionally fails, so exit code should be non-zero
130+
assert.notStrictEqual(result.status, 0);
131+
132+
// Extract and verify error events from fixture output
133+
// The fixture outputs JSON with errorEvents array on exit
134+
const lines = result.stdout.split('\n');
135+
const eventLine = lines.find((line) => line.includes('errorEvents'));
136+
assert.ok(eventLine, 'Expected errorEvents line in fixture output');
137+
const { errorEvents } = JSON.parse(eventLine);
138+
assert.strictEqual(errorEvents.includes('test that intentionally fails'), true);
139+
});

0 commit comments

Comments
 (0)