-
-
Notifications
You must be signed in to change notification settings - Fork 35.2k
test_runner: publish to TracingChannel node.test for OTel instrumentation #62502
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
base: main
Are you sure you want to change the base?
Changes from all commits
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -3563,6 +3563,92 @@ Emitted when no more tests are queued for execution in watch mode. | |
|
|
||
| Emitted when one or more tests are restarted due to a file change in watch mode. | ||
|
|
||
| ## Test instrumentation and OpenTelemetry | ||
|
|
||
| <!-- YAML | ||
| added: REPLACEME | ||
| --> | ||
|
|
||
| The test runner publishes test execution events through the Node.js | ||
| [`diagnostics_channel`][] module, enabling integration with observability tools | ||
| like OpenTelemetry without requiring changes to the test runner itself. | ||
|
|
||
| ### Tracing events | ||
|
|
||
| The test runner publishes events to the `'node.test'` tracing channel. Subscribers | ||
| can use the [`TracingChannel`][] API to bind context or perform custom | ||
| instrumentation. | ||
|
|
||
| #### Channel: `'tracing:node.test:start'` | ||
|
|
||
| * `data` {Object} | ||
| * `name` {string} The name of the test. | ||
| * `nesting` {number} The nesting level of the test. | ||
| * `file` {string} The path to the test file. | ||
|
Member
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. in most places we also say something around the lines of "or undefined when in REPL", I think the 3 occurrences here should too? |
||
| * `type` {string} The type of test. Either `'test'` or `'suite'`. | ||
|
|
||
| Emitted when a test or suite starts execution. The test's span encompasses all | ||
| of its before, beforeEach, and afterEach hooks, as well as the test body. | ||
|
|
||
| #### Channel: `'tracing:node.test:end'` | ||
|
|
||
| * `data` {Object} | ||
| * `name` {string} The name of the test. | ||
| * `nesting` {number} The nesting level of the test. | ||
| * `file` {string} The path to the test file. | ||
| * `type` {string} The type of test. Either `'test'` or `'suite'`. | ||
|
|
||
| Emitted when a test or suite finishes execution. | ||
|
|
||
| #### Channel: `'tracing:node.test:error'` | ||
|
|
||
| * `data` {Object} | ||
| * `name` {string} The name of the test. | ||
| * `nesting` {number} The nesting level of the test. | ||
| * `file` {string} The path to the test file. | ||
| * `type` {string} The type of test. Either `'test'` or `'suite'`. | ||
| * `error` {Error} The error that was thrown. | ||
|
|
||
| Emitted when a test or suite throws an error. | ||
|
|
||
| ### OpenTelemetry integration | ||
|
|
||
| The tracing channel can be used to integrate with OpenTelemetry by binding | ||
| an `AsyncLocalStorage` instance. This allows OpenTelemetry context to be | ||
| automatically propagated through the test execution and all async operations | ||
| within the test. | ||
|
|
||
| ```mjs | ||
| import { diagnosticsChannel } from 'node:diagnostics_channel'; | ||
| import { AsyncLocalStorage } from 'node:async_hooks'; | ||
| import { context, trace } from '@opentelemetry/api'; | ||
|
Member
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Is it common/customary for the node docs to show examples with external libraries? |
||
|
|
||
| const testStorage = new AsyncLocalStorage(); | ||
| const testChannel = diagnosticsChannel.tracingChannel('node.test'); | ||
| const tracer = trace.getTracer('test-tracer'); | ||
|
Comment on lines
+3622
to
+3628
|
||
|
|
||
| // Bind OpenTelemetry context to test execution | ||
| testChannel.start.bindStore(testStorage, (data) => { | ||
| const span = tracer.startSpan(data.name); | ||
| return context.with(trace.setSpan(context.active(), span), () => { | ||
| return context.active(); | ||
| }); | ||
| }); | ||
|
|
||
| // Optionally handle errors and cleanup | ||
| testChannel.error.subscribe((data) => { | ||
| // Handle span errors | ||
| }); | ||
|
|
||
| testChannel.end.subscribe((data) => { | ||
| // Cleanup span | ||
| }); | ||
| ``` | ||
|
|
||
| When using `bindStore()`, the context provided will be automatically propagated | ||
| to the test function and all async operations within the test, without requiring | ||
| any additional instrumentation in the test code. | ||
|
|
||
| ## Class: `TestContext` | ||
|
|
||
| <!-- YAML | ||
|
|
@@ -4254,11 +4340,13 @@ Can be used to abort test subtasks when the test has been aborted. | |
| [`NODE_V8_COVERAGE`]: cli.md#node_v8_coveragedir | ||
| [`SuiteContext`]: #class-suitecontext | ||
| [`TestContext`]: #class-testcontext | ||
| [`TracingChannel`]: diagnostics_channel.md#class-tracingchannel | ||
| [`assert.throws`]: assert.md#assertthrowsfn-error-message | ||
| [`context.diagnostic`]: #contextdiagnosticmessage | ||
| [`context.skip`]: #contextskipmessage | ||
| [`context.todo`]: #contexttodomessage | ||
| [`describe()`]: #describename-options-fn | ||
| [`diagnostics_channel`]: diagnostics_channel.md | ||
| [`glob(7)`]: https://man7.org/linux/man-pages/man7/glob.7.html | ||
| [`it()`]: #itname-options-fn | ||
| [`run()`]: #runoptions | ||
|
|
||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -53,6 +53,7 @@ const { | |
| countCompletedTest, | ||
| isTestFailureError, | ||
| reporterScope, | ||
| testChannel, | ||
| } = require('internal/test_runner/utils'); | ||
| const { | ||
| kEmptyObject, | ||
|
|
@@ -1140,6 +1141,17 @@ class Test extends AsyncResource { | |
| } | ||
| this.startTime ??= hrtime(); | ||
|
|
||
| // Channel context object shared across all lifecycle events for this test run. | ||
| // Only tests emit events; hooks do not. This way, the test's span encompasses | ||
| // its before/beforeEach hooks, the test body, and its afterEach/after hooks. | ||
| const channelContext = this.hookType === undefined ? { | ||
| __proto__: null, | ||
| name: this.name, | ||
| nesting: this.nesting, | ||
| file: this.entryFile, | ||
| type: this.reportedType, | ||
| } : null; | ||
|
|
||
| if (this[kShouldAbort]()) { | ||
| this.postRun(); | ||
| return; | ||
|
|
@@ -1177,7 +1189,20 @@ class Test extends AsyncResource { | |
| } | ||
| stopPromise = stopTest(this.timeout, this.signal); | ||
| const runArgs = ArrayPrototypeSlice(args); | ||
| ArrayPrototypeUnshift(runArgs, this.fn, ctx); | ||
|
|
||
| // Wrap the test function with runStores if the channel has subscribers. | ||
| // The wrapped function is what gets passed to runInAsyncScope, ensuring that | ||
| // the test runs within both the runStores context (for AsyncLocalStorage/bindStore) | ||
| // AND the AsyncResource scope. It's critical that runStores wraps the function, | ||
| // not the runInAsyncScope call itself, to maintain AsyncLocalStorage bindings. | ||
| let testFn = this.fn; | ||
| if (channelContext !== null && testChannel.start.hasSubscribers) { | ||
| testFn = (...fnArgs) => testChannel.start.runStores(channelContext, | ||
| () => ReflectApply(this.fn, this, fnArgs), | ||
| ); | ||
| } | ||
|
|
||
| ArrayPrototypeUnshift(runArgs, testFn, ctx); | ||
|
|
||
| const promises = []; | ||
| if (this.fn.length === runArgs.length - 1) { | ||
|
|
@@ -1226,6 +1251,10 @@ class Test extends AsyncResource { | |
| await afterEach(); | ||
| await after(); | ||
| } catch (err) { | ||
| // Publish diagnostics_channel error event if the channel has subscribers | ||
| if (channelContext !== null && testChannel.error.hasSubscribers) { | ||
| testChannel.error.publish({ __proto__: null, ...channelContext, error: err }); | ||
| } | ||
| if (isTestFailureError(err)) { | ||
| if (err.failureType === kTestTimeoutFailure) { | ||
| this.#cancel(err); | ||
|
|
@@ -1245,6 +1274,11 @@ class Test extends AsyncResource { | |
| if (this.parent !== null) { | ||
| this.abortController.abort(); | ||
| } | ||
|
|
||
| // Publish diagnostics_channel end event if the channel has subscribers (in both success and error cases) | ||
| if (channelContext !== null && testChannel.end.hasSubscribers) { | ||
| testChannel.end.publish(channelContext); | ||
| } | ||
| } | ||
|
|
||
| if (this.parent !== null || typeof this.hookType === 'string') { | ||
|
|
@@ -1572,12 +1606,40 @@ class Suite extends Test { | |
| } | ||
|
|
||
| async createBuild() { | ||
| const channelContext = { | ||
| __proto__: null, | ||
| name: this.name, | ||
| nesting: this.nesting, | ||
| file: this.entryFile, | ||
| type: this.reportedType, | ||
| }; | ||
| try { | ||
| const { ctx, args } = this.getRunArgs(); | ||
| const runArgs = [this.fn, ctx]; | ||
|
|
||
| // Wrap the suite function with runStores if the channel has subscribers. | ||
| // The wrapped function is what gets passed to runInAsyncScope, ensuring that | ||
| // the suite runs within both the runStores context (for AsyncLocalStorage/bindStore) | ||
| // AND the AsyncResource scope. It's critical that runStores wraps the function, | ||
| // not the runInAsyncScope call itself, to maintain AsyncLocalStorage bindings. | ||
| let suiteFn = this.fn; | ||
| if (channelContext !== null && testChannel.start.hasSubscribers) { | ||
| suiteFn = (...fnArgs) => testChannel.start.runStores(channelContext, | ||
| () => ReflectApply(this.fn, this, fnArgs), | ||
| ); | ||
|
Comment on lines
+1624
to
+1628
|
||
| } | ||
|
|
||
| const runArgs = [suiteFn, ctx]; | ||
| ArrayPrototypePushApply(runArgs, args); | ||
|
|
||
| await ReflectApply(this.runInAsyncScope, this, runArgs); | ||
|
|
||
| if (channelContext !== null && testChannel.end.hasSubscribers) { | ||
| testChannel.end.publish(channelContext); | ||
| } | ||
| } catch (err) { | ||
| if (channelContext !== null && testChannel.error.hasSubscribers) { | ||
| testChannel.error.publish({ __proto__: null, ...channelContext, error: err }); | ||
| } | ||
| this.fail(new ERR_TEST_FAILURE(err, kTestCodeFailure)); | ||
| } | ||
|
Comment on lines
+1636
to
1644
|
||
|
|
||
|
|
||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,17 @@ | ||
| 'use strict'; | ||
| const dc = require('node:diagnostics_channel'); | ||
| const { test } = require('node:test'); | ||
|
|
||
| const events = []; | ||
| dc.subscribe('tracing:node.test:error', (data) => { | ||
| events.push(data.name); | ||
| }); | ||
|
|
||
| test('test that intentionally fails', async () => { | ||
| throw new Error('expected failure for error event testing'); | ||
| }); | ||
|
|
||
| // Report events on exit | ||
| process.on('exit', () => { | ||
| console.log(JSON.stringify({ errorEvents: events })); | ||
| }); |
| Original file line number | Diff line number | Diff line change | ||||||||
|---|---|---|---|---|---|---|---|---|---|---|
| @@ -0,0 +1,139 @@ | ||||||||||
| 'use strict'; | ||||||||||
| require('../common'); | ||||||||||
| const assert = require('node:assert'); | ||||||||||
| const dc = require('node:diagnostics_channel'); | ||||||||||
| const { test } = require('node:test'); | ||||||||||
| const { spawnSync } = require('child_process'); | ||||||||||
| const { join } = require('path'); | ||||||||||
|
|
||||||||||
| const events = []; | ||||||||||
|
|
||||||||||
| dc.subscribe('tracing:node.test:start', (data) => events.push({ event: 'start', name: data.name })); | ||||||||||
| dc.subscribe('tracing:node.test:end', (data) => events.push({ event: 'end', name: data.name })); | ||||||||||
| dc.subscribe('tracing:node.test:error', (data) => events.push({ event: 'error', name: data.name })); | ||||||||||
|
|
||||||||||
| test('passing test fires start and end', async () => {}); | ||||||||||
|
|
||||||||||
| // Validate events were emitted (check after all tests via process.on('exit')) | ||||||||||
| process.on('exit', () => { | ||||||||||
| // Check passing test | ||||||||||
| const testName1 = 'passing test fires start and end'; | ||||||||||
| const startEvents = events.filter((e) => e.event === 'start' && e.name === testName1); | ||||||||||
| const endEvents = events.filter((e) => e.event === 'end' && e.name === testName1); | ||||||||||
| assert.strictEqual(startEvents.length, 1); | ||||||||||
| assert.strictEqual(endEvents.length, 1); | ||||||||||
|
|
||||||||||
| // Check nested tests fire events | ||||||||||
| const nested1Start = events.filter((e) => e.event === 'start' && e.name === 'nested test 1'); | ||||||||||
| const nested1End = events.filter((e) => e.event === 'end' && e.name === 'nested test 1'); | ||||||||||
| const nested2Start = events.filter((e) => e.event === 'start' && e.name === 'nested test 2'); | ||||||||||
| const nested2End = events.filter((e) => e.event === 'end' && e.name === 'nested test 2'); | ||||||||||
| assert.strictEqual(nested1Start.length, 1); | ||||||||||
| assert.strictEqual(nested1End.length, 1); | ||||||||||
| assert.strictEqual(nested2Start.length, 1); | ||||||||||
| assert.strictEqual(nested2End.length, 1); | ||||||||||
|
|
||||||||||
| // Check describe block tests fire events | ||||||||||
| const describeStart = events.filter((e) => e.event === 'start' && e.name === 'test inside describe'); | ||||||||||
| const describeEnd = events.filter((e) => e.event === 'end' && e.name === 'test inside describe'); | ||||||||||
| const describeStart2 = events.filter( | ||||||||||
| (e) => e.event === 'start' && e.name === 'another test inside describe', | ||||||||||
| ); | ||||||||||
| const describeEnd2 = events.filter( | ||||||||||
| (e) => e.event === 'end' && e.name === 'another test inside describe', | ||||||||||
| ); | ||||||||||
| assert.strictEqual(describeStart.length, 1); | ||||||||||
| assert.strictEqual(describeEnd.length, 1); | ||||||||||
| assert.strictEqual(describeStart2.length, 1); | ||||||||||
| assert.strictEqual(describeEnd2.length, 1); | ||||||||||
|
|
||||||||||
| // Check async operations test fires events | ||||||||||
| const asyncTestName = 'context is available in async operations within test'; | ||||||||||
| const asyncStart = events.filter((e) => e.event === 'start' && e.name === asyncTestName); | ||||||||||
| const asyncEnd = events.filter((e) => e.event === 'end' && e.name === asyncTestName); | ||||||||||
| assert.strictEqual(asyncStart.length, 1); | ||||||||||
| assert.strictEqual(asyncEnd.length, 1); | ||||||||||
| }); | ||||||||||
|
|
||||||||||
| // Test bindStore context propagation | ||||||||||
| const { AsyncLocalStorage } = require('node:async_hooks'); | ||||||||||
| const testStorage = new AsyncLocalStorage(); | ||||||||||
|
|
||||||||||
| // bindStore on the start channel: whenever a test fn runs, set testStorage to the test name | ||||||||||
| dc.channel('tracing:node.test:start').bindStore(testStorage, (data) => data.name); | ||||||||||
|
|
||||||||||
| test('bindStore propagates into test body via start channel', async () => { | ||||||||||
| const expectedName = 'bindStore propagates into test body via start channel'; | ||||||||||
|
Comment on lines
+65
to
+66
Member
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. why not:
Suggested change
|
||||||||||
| const storedValueDuringTest = testStorage.getStore(); | ||||||||||
| assert.strictEqual(storedValueDuringTest, expectedName); | ||||||||||
|
|
||||||||||
| // Propagates into async operations inside the test | ||||||||||
| const valueInSetImmediate = await new Promise((resolve) => { | ||||||||||
| setImmediate(() => resolve(testStorage.getStore())); | ||||||||||
| }); | ||||||||||
| assert.strictEqual(valueInSetImmediate, expectedName); | ||||||||||
| }); | ||||||||||
|
|
||||||||||
| test('bindStore value is isolated between tests', async () => { | ||||||||||
| assert.strictEqual(testStorage.getStore(), 'bindStore value is isolated between tests'); | ||||||||||
| }); | ||||||||||
|
|
||||||||||
| test('nested tests fire events with correct names', async (t) => { | ||||||||||
| await t.test('nested test 1', async () => { | ||||||||||
| const stored = testStorage.getStore(); | ||||||||||
| assert.strictEqual(stored, 'nested test 1'); | ||||||||||
| }); | ||||||||||
|
|
||||||||||
| await t.test('nested test 2', async () => { | ||||||||||
| const stored = testStorage.getStore(); | ||||||||||
| assert.strictEqual(stored, 'nested test 2'); | ||||||||||
| }); | ||||||||||
| }); | ||||||||||
|
|
||||||||||
| const { describe, it } = require('node:test'); | ||||||||||
|
Member
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Any reason for this to be down here and not alongside the |
||||||||||
|
|
||||||||||
| describe('describe block with tests', () => { | ||||||||||
| it('test inside describe', async () => { | ||||||||||
| const stored = testStorage.getStore(); | ||||||||||
| assert.strictEqual(stored, 'test inside describe'); | ||||||||||
| }); | ||||||||||
|
|
||||||||||
| it('another test inside describe', async () => { | ||||||||||
| const stored = testStorage.getStore(); | ||||||||||
| assert.strictEqual(stored, 'another test inside describe'); | ||||||||||
| }); | ||||||||||
| }); | ||||||||||
|
|
||||||||||
| test('context is available in async operations within test', async () => { | ||||||||||
| const testName = 'context is available in async operations within test'; | ||||||||||
| assert.strictEqual(testStorage.getStore(), testName); | ||||||||||
|
|
||||||||||
| // Verify context is available in setImmediate | ||||||||||
| const valueInImmediate = await new Promise((resolve) => { | ||||||||||
| setImmediate(() => resolve(testStorage.getStore())); | ||||||||||
| }); | ||||||||||
| assert.strictEqual(valueInImmediate, testName); | ||||||||||
|
|
||||||||||
| // Verify context is available in setTimeout | ||||||||||
| const valueInTimeout = await new Promise((resolve) => { | ||||||||||
| setTimeout(() => resolve(testStorage.getStore()), 0); | ||||||||||
| }); | ||||||||||
| assert.strictEqual(valueInTimeout, testName); | ||||||||||
| }); | ||||||||||
|
|
||||||||||
| test('error events fire for failing tests in fixture', async () => { | ||||||||||
| // Run the fixture test that intentionally fails | ||||||||||
| const fixturePath = join(__dirname, '../fixtures/test-runner/diagnostics-channel-error-test.js'); | ||||||||||
| const result = spawnSync(process.execPath, [fixturePath], { encoding: 'utf8' }); | ||||||||||
|
|
||||||||||
| // The fixture test intentionally fails, so exit code should be non-zero | ||||||||||
| assert.notStrictEqual(result.status, 0); | ||||||||||
|
|
||||||||||
| // Extract and verify error events from fixture output | ||||||||||
| // The fixture outputs JSON with errorEvents array on exit | ||||||||||
| const lines = result.stdout.split('\n'); | ||||||||||
| const eventLine = lines.find((line) => line.includes('errorEvents')); | ||||||||||
| assert.ok(eventLine, 'Expected errorEvents line in fixture output'); | ||||||||||
| const { errorEvents } = JSON.parse(eventLine); | ||||||||||
| assert.strictEqual(errorEvents.includes('test that intentionally fails'), true); | ||||||||||
| }); | ||||||||||
Uh oh!
There was an error while loading. Please reload this page.