GeezerVison is showing github.com — test_runner: publish to TracingChannel for OTel instrumentation · nodejs/node@39e0834
File treeExpand file treeCollapse file tree Open diff view settings Expand file treeCollapse file tree Open diff view settings Collapse file Copy file name to clipboardExpand all lines: doc/api/test.md +87Lines changed: 87 additions & 0 deletions - Display the source diff
- Display the rich diff
| Original file line number | Diff line number | Diff line change |
|---|
@@ -3701,6 +3701,91 @@ When called from within a hook (before, beforeEach, after, afterEach), this | 3701 | 3701 | function returns the context of the test or suite that the hook is associated | 3702 | 3702 | with. | 3703 | 3703 |
| | 3704 | +## Test instrumentation and OpenTelemetry | | 3705 | + | | 3706 | +<!-- YAML | | 3707 | +added: REPLACEME | | 3708 | +--> | | 3709 | + | | 3710 | +The test runner publishes test execution events through the Node.js | | 3711 | +[`diagnostics_channel`][] module, enabling integration with observability tools | | 3712 | +like OpenTelemetry without requiring changes to the test runner itself. | | 3713 | + | | 3714 | +### Tracing events | | 3715 | + | | 3716 | +The test runner publishes events to the `'node.test'` tracing channel. Subscribers | | 3717 | +can use the [`TracingChannel`][] API to bind context or perform custom | | 3718 | +instrumentation. | | 3719 | + | | 3720 | +#### Channel: `'tracing:node.test:start'` | | 3721 | + | | 3722 | +* `data` {Object} | | 3723 | + * `name` {string} The name of the test. | | 3724 | + * `nesting` {number} The nesting level of the test. | | 3725 | + * `file` {string|undefined} The path to the test file, or `undefined` when | | 3726 | + running in the REPL. | | 3727 | + * `type` {string} The type of test. Either `'test'` or `'suite'`. | | 3728 | + | | 3729 | +Emitted when a test or suite starts execution. The test's span encompasses all | | 3730 | +of its before, beforeEach, and afterEach hooks, as well as the test body. | | 3731 | + | | 3732 | +#### Channel: `'tracing:node.test:end'` | | 3733 | + | | 3734 | +* `data` {Object} | | 3735 | + * `name` {string} The name of the test. | | 3736 | + * `nesting` {number} The nesting level of the test. | | 3737 | + * `file` {string|undefined} The path to the test file, or `undefined` when | | 3738 | + running in the REPL. | | 3739 | + * `type` {string} The type of test. Either `'test'` or `'suite'`. | | 3740 | + | | 3741 | +Emitted when a test or suite finishes execution. | | 3742 | + | | 3743 | +#### Channel: `'tracing:node.test:error'` | | 3744 | + | | 3745 | +* `data` {Object} | | 3746 | + * `name` {string} The name of the test. | | 3747 | + * `nesting` {number} The nesting level of the test. | | 3748 | + * `file` {string|undefined} The path to the test file, or `undefined` when | | 3749 | + running in the REPL. | | 3750 | + * `type` {string} The type of test. Either `'test'` or `'suite'`. | | 3751 | + * `error` {Error} The error that was thrown. | | 3752 | + | | 3753 | +Emitted when a test or suite throws an error. | | 3754 | + | | 3755 | +### Context propagation with `bindStore()` | | 3756 | + | | 3757 | +The tracing channel can be used to propagate context through test execution by | | 3758 | +binding an `AsyncLocalStorage` instance. This allows context to be automatically | | 3759 | +available in the test function and all async operations within the test. | | 3760 | + | | 3761 | +```mjs | | 3762 | +import dc from 'node:diagnostics_channel'; | | 3763 | +import { AsyncLocalStorage } from 'node:async_hooks'; | | 3764 | + | | 3765 | +const testStorage = new AsyncLocalStorage(); | | 3766 | +const testChannel = dc.tracingChannel('node.test'); | | 3767 | + | | 3768 | +// Bind context to test execution — the returned value becomes the store | | 3769 | +testChannel.start.bindStore(testStorage, (data) => { | | 3770 | + return { testName: data.name, startTime: Date.now() }; | | 3771 | +}); | | 3772 | + | | 3773 | +// Optionally handle errors and cleanup | | 3774 | +testChannel.error.subscribe((data) => { | | 3775 | + const store = testStorage.getStore(); | | 3776 | + console.log(`Test "${data.name}" failed after ${Date.now() - store.startTime}ms`); | | 3777 | +}); | | 3778 | + | | 3779 | +testChannel.end.subscribe((data) => { | | 3780 | + const store = testStorage.getStore(); | | 3781 | + console.log(`Test "${data.name}" completed in ${Date.now() - store.startTime}ms`); | | 3782 | +}); | | 3783 | +``` | | 3784 | + | | 3785 | +When using `bindStore()`, the context provided will be automatically propagated | | 3786 | +to the test function and all async operations within the test, without requiring | | 3787 | +any additional instrumentation in the test code. | | 3788 | + | 3704 | 3789 | ## Class: `TestContext` | 3705 | 3790 |
| 3706 | 3791 | <!-- YAML | @@ -4433,11 +4518,13 @@ test.describe('my suite', (suite) => { | 4433 | 4518 | [`NODE_V8_COVERAGE`]: cli.md#node_v8_coveragedir | 4434 | 4519 | [`SuiteContext`]: #class-suitecontext | 4435 | 4520 | [`TestContext`]: #class-testcontext | | 4521 | +[`TracingChannel`]: diagnostics_channel.md#class-tracingchannel | 4436 | 4522 | [`assert.throws`]: assert.md#assertthrowsfn-error-message | 4437 | 4523 | [`context.diagnostic`]: #contextdiagnosticmessage | 4438 | 4524 | [`context.skip`]: #contextskipmessage | 4439 | 4525 | [`context.todo`]: #contexttodomessage | 4440 | 4526 | [`describe()`]: #describename-options-fn | | 4527 | +[`diagnostics_channel`]: diagnostics_channel.md | 4441 | 4528 | [`glob(7)`]: https://man7.org/linux/man-pages/man7/glob.7.html | 4442 | 4529 | [`it()`]: #itname-options-fn | 4443 | 4530 | [`run()`]: #runoptions | |
Collapse file Copy file name to clipboardExpand all lines: lib/internal/test_runner/test.js +65-2Lines changed: 65 additions & 2 deletions | Original file line number | Diff line number | Diff line change |
|---|
@@ -55,6 +55,7 @@ const { | 55 | 55 | countCompletedTest, | 56 | 56 | isTestFailureError, | 57 | 57 | reporterScope, | | 58 | + testChannel, | 58 | 59 | } = require('internal/test_runner/utils'); | 59 | 60 | const { | 60 | 61 | kEmptyObject, | @@ -1211,6 +1212,17 @@ class Test extends AsyncResource { | 1211 | 1212 | } | 1212 | 1213 | this.startTime ??= hrtime(); | 1213 | 1214 |
| | 1215 | + // Channel context object shared across all lifecycle events for this test run. | | 1216 | + // Only tests emit events; hooks do not. This way, the test's span encompasses | | 1217 | + // its before/beforeEach hooks, the test body, and its afterEach/after hooks. | | 1218 | + const channelContext = this.hookType === undefined ? { | | 1219 | + __proto__: null, | | 1220 | + name: this.name, | | 1221 | + nesting: this.nesting, | | 1222 | + file: this.entryFile, | | 1223 | + type: this.reportedType, | | 1224 | + } : null; | | 1225 | + | 1214 | 1226 | if (this[kShouldAbort]()) { | 1215 | 1227 | this.postRun(); | 1216 | 1228 | return; | @@ -1248,7 +1260,20 @@ class Test extends AsyncResource { | 1248 | 1260 | } | 1249 | 1261 | stopPromise = stopTest(this.timeout, this.signal); | 1250 | 1262 | const runArgs = ArrayPrototypeSlice(args); | 1251 | | - ArrayPrototypeUnshift(runArgs, this.fn, ctx); | | 1263 | + | | 1264 | + // Wrap the test function with runStores if the channel has subscribers. | | 1265 | + // The wrapped function is what gets passed to runInAsyncScope, ensuring that | | 1266 | + // the test runs within both the runStores context (for AsyncLocalStorage/bindStore) | | 1267 | + // AND the AsyncResource scope. It's critical that runStores wraps the function, | | 1268 | + // not the runInAsyncScope call itself, to maintain AsyncLocalStorage bindings. | | 1269 | + let testFn = this.fn; | | 1270 | + if (channelContext !== null && testChannel.start.hasSubscribers) { | | 1271 | + testFn = (...fnArgs) => testChannel.start.runStores(channelContext, | | 1272 | + () => ReflectApply(this.fn, this, fnArgs), | | 1273 | + ); | | 1274 | + } | | 1275 | + | | 1276 | + ArrayPrototypeUnshift(runArgs, testFn, ctx); | 1252 | 1277 |
| 1253 | 1278 | const promises = []; | 1254 | 1279 | if (this.fn.length === runArgs.length - 1) { | @@ -1297,6 +1322,10 @@ class Test extends AsyncResource { | 1297 | 1322 | await afterEach(); | 1298 | 1323 | await after(); | 1299 | 1324 | } catch (err) { | | 1325 | + // Publish diagnostics_channel error event if the channel has subscribers | | 1326 | + if (channelContext !== null && testChannel.error.hasSubscribers) { | | 1327 | + testChannel.error.publish({ __proto__: null, ...channelContext, error: err }); | | 1328 | + } | 1300 | 1329 | if (isTestFailureError(err)) { | 1301 | 1330 | if (err.failureType === kTestTimeoutFailure) { | 1302 | 1331 | this.#cancel(err); | @@ -1316,6 +1345,11 @@ class Test extends AsyncResource { | 1316 | 1345 | if (this.parent !== null) { | 1317 | 1346 | this.abortController.abort(); | 1318 | 1347 | } | | 1348 | + | | 1349 | + // Publish diagnostics_channel end event if the channel has subscribers (in both success and error cases) | | 1350 | + if (channelContext !== null && testChannel.end.hasSubscribers) { | | 1351 | + testChannel.end.publish(channelContext); | | 1352 | + } | 1319 | 1353 | } | 1320 | 1354 |
| 1321 | 1355 | if (this.parent !== null || typeof this.hookType === 'string') { | @@ -1643,13 +1677,42 @@ class Suite extends Test { | 1643 | 1677 | } | 1644 | 1678 |
| 1645 | 1679 | async createBuild() { | | 1680 | + const channelContext = { | | 1681 | + __proto__: null, | | 1682 | + name: this.name, | | 1683 | + nesting: this.nesting, | | 1684 | + file: this.entryFile, | | 1685 | + type: this.reportedType, | | 1686 | + }; | 1646 | 1687 | try { | 1647 | 1688 | const { ctx, args } = this.getRunArgs(); | 1648 | | - const runArgs = [this.fn, ctx]; | | 1689 | + | | 1690 | + // Wrap the suite function with runStores if the channel has subscribers. | | 1691 | + // The wrapped function is what gets passed to runInAsyncScope, ensuring that | | 1692 | + // the suite runs within both the runStores context (for AsyncLocalStorage/bindStore) | | 1693 | + // AND the AsyncResource scope. It's critical that runStores wraps the function, | | 1694 | + // not the runInAsyncScope call itself, to maintain AsyncLocalStorage bindings. | | 1695 | + let suiteFn = this.fn; | | 1696 | + if (testChannel.start.hasSubscribers) { | | 1697 | + const baseFn = this.fn; | | 1698 | + suiteFn = (...fnArgs) => testChannel.start.runStores(channelContext, | | 1699 | + () => ReflectApply(baseFn, this, fnArgs), | | 1700 | + ); | | 1701 | + } | | 1702 | + | | 1703 | + const runArgs = [suiteFn, ctx]; | 1649 | 1704 | ArrayPrototypePushApply(runArgs, args); | | 1705 | + | 1650 | 1706 | await ReflectApply(this.runInAsyncScope, this, runArgs); | 1651 | 1707 | } catch (err) { | | 1708 | + if (testChannel.error.hasSubscribers) { | | 1709 | + testChannel.error.publish({ __proto__: null, ...channelContext, error: err }); | | 1710 | + } | 1652 | 1711 | this.fail(new ERR_TEST_FAILURE(err, kTestCodeFailure)); | | 1712 | + } finally { | | 1713 | + if (testChannel.end.hasSubscribers) { | | 1714 | + testChannel.end.publish(channelContext); | | 1715 | + } | 1653 | 1716 | } | 1654 | 1717 |
| 1655 | 1718 | this.buildPhaseFinished = true; | |
Collapse file Copy file name to clipboardExpand all lines: lib/internal/test_runner/utils.js +3Lines changed: 3 additions & 0 deletions | Original file line number | Diff line number | Diff line change |
|---|
@@ -31,6 +31,7 @@ const { | 31 | 31 | } = primordials; | 32 | 32 |
| 33 | 33 | const { AsyncResource } = require('async_hooks'); | | 34 | +const { tracingChannel } = require('diagnostics_channel'); | 34 | 35 | const { relative, sep, resolve } = require('path'); | 35 | 36 | const { createWriteStream, readFileSync } = require('fs'); | 36 | 37 | const { pathToFileURL } = require('internal/url'); | @@ -256,6 +257,7 @@ async function getReportersMap(reporters, destinations) { | 256 | 257 | } | 257 | 258 |
| 258 | 259 | const reporterScope = new AsyncResource('TestReporterScope'); | | 260 | +const testChannel = tracingChannel('node.test'); | 259 | 261 | let globalTestOptions; | 260 | 262 |
| 261 | 263 | function parseCommandLine() { | @@ -730,4 +732,5 @@ module.exports = { | 730 | 732 | getCoverageReport, | 731 | 733 | setupGlobalSetupTeardownFunctions, | 732 | 734 | parsePreviousRuns, | | 735 | + testChannel, | 733 | 736 | }; |
Collapse file Copy file name to clipboard +17Lines changed: 17 additions & 0 deletions | Original file line number | Diff line number | Diff line change |
|---|
| | 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 | +}); |
Collapse file Copy file name to clipboard +137Lines changed: 137 additions & 0 deletions | Original file line number | Diff line number | Diff line change |
|---|
| | 1 | +'use strict'; | | 2 | +require('../common'); | | 3 | +const assert = require('node:assert'); | | 4 | +const { AsyncLocalStorage } = require('node:async_hooks'); | | 5 | +const dc = require('node:diagnostics_channel'); | | 6 | +const { describe, it, test } = require('node:test'); | | 7 | +const { spawnSync } = require('child_process'); | | 8 | +const { join } = require('path'); | | 9 | + | | 10 | +const events = []; | | 11 | + | | 12 | +dc.subscribe('tracing:node.test:start', (data) => events.push({ event: 'start', name: data.name })); | | 13 | +dc.subscribe('tracing:node.test:end', (data) => events.push({ event: 'end', name: data.name })); | | 14 | +dc.subscribe('tracing:node.test:error', (data) => events.push({ event: 'error', name: data.name })); | | 15 | + | | 16 | +test('passing test fires start and end', async () => {}); | | 17 | + | | 18 | +// Validate events were emitted (check after all tests via process.on('exit')) | | 19 | +process.on('exit', () => { | | 20 | + // Check passing test | | 21 | + const testName1 = 'passing test fires start and end'; | | 22 | + const startEvents = events.filter((e) => e.event === 'start' && e.name === testName1); | | 23 | + const endEvents = events.filter((e) => e.event === 'end' && e.name === testName1); | | 24 | + assert.strictEqual(startEvents.length, 1); | | 25 | + assert.strictEqual(endEvents.length, 1); | | 26 | + | | 27 | + // Check nested tests fire events | | 28 | + const nested1Start = events.filter((e) => e.event === 'start' && e.name === 'nested test 1'); | | 29 | + const nested1End = events.filter((e) => e.event === 'end' && e.name === 'nested test 1'); | | 30 | + const nested2Start = events.filter((e) => e.event === 'start' && e.name === 'nested test 2'); | | 31 | + const nested2End = events.filter((e) => e.event === 'end' && e.name === 'nested test 2'); | | 32 | + assert.strictEqual(nested1Start.length, 1); | | 33 | + assert.strictEqual(nested1End.length, 1); | | 34 | + assert.strictEqual(nested2Start.length, 1); | | 35 | + assert.strictEqual(nested2End.length, 1); | | 36 | + | | 37 | + // Check describe block tests fire events | | 38 | + const describeStart = events.filter((e) => e.event === 'start' && e.name === 'test inside describe'); | | 39 | + const describeEnd = events.filter((e) => e.event === 'end' && e.name === 'test inside describe'); | | 40 | + const describeStart2 = events.filter( | | 41 | + (e) => e.event === 'start' && e.name === 'another test inside describe', | | 42 | + ); | | 43 | + const describeEnd2 = events.filter( | | 44 | + (e) => e.event === 'end' && e.name === 'another test inside describe', | | 45 | + ); | | 46 | + assert.strictEqual(describeStart.length, 1); | | 47 | + assert.strictEqual(describeEnd.length, 1); | | 48 | + assert.strictEqual(describeStart2.length, 1); | | 49 | + assert.strictEqual(describeEnd2.length, 1); | | 50 | + | | 51 | + // Check async operations test fires events | | 52 | + const asyncTestName = 'context is available in async operations within test'; | | 53 | + const asyncStart = events.filter((e) => e.event === 'start' && e.name === asyncTestName); | | 54 | + const asyncEnd = events.filter((e) => e.event === 'end' && e.name === asyncTestName); | | 55 | + assert.strictEqual(asyncStart.length, 1); | | 56 | + assert.strictEqual(asyncEnd.length, 1); | | 57 | +}); | | 58 | + | | 59 | +// Test bindStore context propagation | | 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 | +const expectedName = 'bindStore propagates into test body via start channel'; | | 66 | +test(expectedName, async () => { | | 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 | +describe('describe block with tests', () => { | | 94 | + it('test inside describe', async () => { | | 95 | + const stored = testStorage.getStore(); | | 96 | + assert.strictEqual(stored, 'test inside describe'); | | 97 | + }); | | 98 | + | | 99 | + it('another test inside describe', async () => { | | 100 | + const stored = testStorage.getStore(); | | 101 | + assert.strictEqual(stored, 'another test inside describe'); | | 102 | + }); | | 103 | +}); | | 104 | + | | 105 | +test('context is available in async operations within test', async () => { | | 106 | + const testName = 'context is available in async operations within test'; | | 107 | + assert.strictEqual(testStorage.getStore(), testName); | | 108 | + | | 109 | + // Verify context is available in setImmediate | | 110 | + const valueInImmediate = await new Promise((resolve) => { | | 111 | + setImmediate(() => resolve(testStorage.getStore())); | | 112 | + }); | | 113 | + assert.strictEqual(valueInImmediate, testName); | | 114 | + | | 115 | + // Verify context is available in setTimeout | | 116 | + const valueInTimeout = await new Promise((resolve) => { | | 117 | + setTimeout(() => resolve(testStorage.getStore()), 0); | | 118 | + }); | | 119 | + assert.strictEqual(valueInTimeout, testName); | | 120 | +}); | | 121 | + | | 122 | +test('error events fire for failing tests in fixture', async () => { | | 123 | + // Run the fixture test that intentionally fails | | 124 | + const fixturePath = join(__dirname, '../fixtures/test-runner/diagnostics-channel-error-test.js'); | | 125 | + const result = spawnSync(process.execPath, [fixturePath], { encoding: 'utf8' }); | | 126 | + | | 127 | + // The fixture test intentionally fails, so exit code should be non-zero | | 128 | + assert.notStrictEqual(result.status, 0); | | 129 | + | | 130 | + // Extract and verify error events from fixture output | | 131 | + // The fixture outputs JSON with errorEvents array on exit | | 132 | + const lines = result.stdout.split('\n'); | | 133 | + const eventLine = lines.find((line) => line.includes('errorEvents')); | | 134 | + assert.ok(eventLine, 'Expected errorEvents line in fixture output'); | | 135 | + const { errorEvents } = JSON.parse(eventLine); | | 136 | + assert.strictEqual(errorEvents.includes('test that intentionally fails'), true); | | 137 | +}); |
|