Commit d31c168

Browse files
MoLowaduh95
authored andcommitted
test_runner: add context.log() and test:log event
Add a log(message[, data]) method to TestContext and SuiteContext that emits a new test:log event. Unlike test:diagnostic, which is buffered so it is emitted in the order tests are defined, test:log is emitted immediately, in the order tests execute, including under process isolation where it bypasses the per-file declaration order buffer. This gives reporters that render the test tree unbuffered a live, attributed logging channel that captured stdout cannot provide under concurrency. The event carries the message, an optional opaque structured payload that the runner passes through untouched, and the emitting test's name, testId, parentId, nesting, and location. Built-in reporters render it the same way they render test:diagnostic. Signed-off-by: Moses Atlow <moshe@atlow.co.il> PR-URL: #64389 Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com> Reviewed-By: Chemi Atlow <chemi@atlow.co.il>
1 parent bb24a88 commit d31c168

12 files changed

Lines changed: 233 additions & 5 deletions

File tree

‎doc/api/test.md‎

Lines changed: 81 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -3468,6 +3468,10 @@ ordered events, emitted immediately as the tests execute.
34683468
|[`'test:fail'`][]|[`'test:complete'`][] (`details.passed` is `false`) |
34693469
|[`'test:plan'`][]||
34703470
|[`'test:diagnostic'`][]||
3471+
||[`'test:log'`][]|
3472+
3473+
[`'test:log'`][] is deliberately execution ordered only: it is the live
3474+
counterpart of [`'test:diagnostic'`][]'s buffered reporting.
34713475

34723476
File scoped and global events are always emitted immediately, in execution
34733477
order.
@@ -3735,6 +3739,38 @@ When using process isolation (the default), the test name will be the file path
37353739
since the parent runner only knows about file-level tests. When using
37363740
`--test-isolation=none`, the actual test name is shown.
37373741

3742+
### Event: `'test:log'`
3743+
3744+
<!-- YAML
3745+
added: REPLACEME
3746+
-->
3747+
3748+
*`data` {Object}
3749+
*`column` {number|undefined} The column number where the test is defined, or
3750+
`undefined` if the test was run through the REPL.
3751+
*`data` {any} The structured payload passed to [`context.log`][], or
3752+
`undefined` if none was provided. The test runner does not interpret this
3753+
value.
3754+
*`entryFile` {string|undefined} The path of the test file that was
3755+
executed as the entry point of the child process that emitted this event.
3756+
Only present when tests run with process isolation. May differ from
3757+
`file` when the test is defined in a module imported by the entry file.
3758+
*`file` {string|undefined} The path of the test file,
3759+
`undefined` if test was run through the REPL.
3760+
*`line` {number|undefined} The line number where the test is defined, or
3761+
`undefined` if the test was run through the REPL.
3762+
*`message` {string} The log message.
3763+
*`name` {string} The test name.
3764+
*`nesting` {number} The nesting level of the test.
3765+
*`parentId` {number|undefined} The `testId` of the enclosing test, or
3766+
`undefined` for top-level tests.
3767+
*`testId` {number} A numeric identifier for the test instance that emitted
3768+
the log message.
3769+
3770+
Emitted when [`context.log`][] is called. Unlike [`'test:diagnostic'`][],
3771+
this event is emitted immediately, in the order that the tests execute,
3772+
making it suitable for reporters that render test output unbuffered.
3773+
37383774
### Event: `'test:pass'`
37393775

37403776
*`data` {Object}
@@ -4258,6 +4294,29 @@ test('top level test', (t) => {
42584294
});
42594295
```
42604296

4297+
### `context.log(message[, data])`
4298+
4299+
<!-- YAML
4300+
added: REPLACEME
4301+
-->
4302+
4303+
*`message` {string} Message to be reported.
4304+
*`data` {any} Optional structured payload attached to the message. The test
4305+
runner passes it through untouched. When tests run with process isolation,
4306+
this value must be compatible with the [HTML structured clone algorithm][].
4307+
4308+
This function is used to write a log message to the output. Unlike
4309+
[`context.diagnostic`][], the resulting [`'test:log'`][] event is emitted
4310+
immediately, in the order that the tests execute, rather than being buffered
4311+
until the test reports its results. This function does not return a value.
4312+
4313+
```js
4314+
test('top level test', (t) => {
4315+
t.log('fetched user', { userId:42 });
4316+
t.log('retrying flaky endpoint', { attempt:3 });
4317+
});
4318+
```
4319+
42614320
### `context.filePath`
42624321

42634322
<!-- YAML
@@ -4739,6 +4798,26 @@ test.describe('my suite', (suite) => {
47394798
});
47404799
```
47414800

4801+
### `context.log(message[, data])`
4802+
4803+
<!-- YAML
4804+
added: REPLACEME
4805+
-->
4806+
4807+
*`message` {string} Message to be reported.
4808+
*`data` {any} Optional structured payload attached to the message. The test
4809+
runner passes it through untouched.
4810+
4811+
Write a log message to the output. The resulting [`'test:log'`][] event is
4812+
emitted immediately, in the order that the tests execute.
4813+
4814+
```js
4815+
test.describe('my suite', (suite) => {
4816+
suite.log('Suite log message');
4817+
});
4818+
```
4819+
4820+
[HTML structured clone algorithm]: https://developer.mozilla.org/en-US/docs/Web/API/Web_Workers_API/Structured_clone_algorithm
47424821
[TAP]: https://testanything.org/
47434822
[Test tags]: #test-tags
47444823
[`'test:complete'`]: #event-testcomplete
@@ -4748,6 +4827,7 @@ test.describe('my suite', (suite) => {
47484827
[`'test:enqueue'`]: #event-testenqueue
47494828
[`'test:fail'`]: #event-testfail
47504829
[`'test:interrupted'`]: #event-testinterrupted
4830+
[`'test:log'`]: #event-testlog
47514831
[`'test:pass'`]: #event-testpass
47524832
[`'test:plan'`]: #event-testplan
47534833
[`'test:start'`]: #event-teststart
@@ -4783,6 +4863,7 @@ test.describe('my suite', (suite) => {
47834863
[`TracingChannel`]: diagnostics_channel.md#class-tracingchannel
47844864
[`assert.throws`]: assert.md#assertthrowsfn-error-message
47854865
[`context.diagnostic`]: #contextdiagnosticmessage
4866+
[`context.log`]: #contextlogmessage-data
47864867
[`context.skip`]: #contextskipmessage
47874868
[`context.tags`]: #contexttags
47884869
[`context.todo`]: #contexttodomessage

‎lib/internal/test_runner/reporter/junit.js‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -154,7 +154,8 @@ module.exports = async function* junitReporter(source) {
154154
}
155155
break;
156156
}
157-
case'test:diagnostic': {
157+
case'test:diagnostic':
158+
case'test:log': {
158159
constparent=currentSuite?.children??roots;
159160
ArrayPrototypePush(parent,{
160161
__proto__: null,nesting: event.data.nesting,comment: event.data.message,

‎lib/internal/test_runner/reporter/spec.js‎

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -91,8 +91,9 @@ class SpecReporter extends Transform {
9191
case'test:stderr':
9292
case'test:stdout':
9393
returndata.message;
94-
case'test:diagnostic':{
95-
constdiagnosticColor=reporterColorMap[data.level]||reporterColorMap['test:diagnostic'];
94+
case'test:diagnostic':
95+
case'test:log': {
96+
constdiagnosticColor=reporterColorMap[data.level]||reporterColorMap[type];
9697
return`${diagnosticColor}${indent(data.nesting)}${reporterUnicodeSymbolMap[type]}${data.message}${colors.white}\n`;
9798
}
9899
case'test:coverage':

‎lib/internal/test_runner/reporter/tap.js‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -56,6 +56,7 @@ async function * tapReporter(source) {
5656
}
5757
break;
5858
}case'test:diagnostic':
59+
case'test:log':
5960
yield`${indent(data.nesting)}# ${tapEscape(data.message)}\n`;
6061
break;
6162
case'test:coverage':

‎lib/internal/test_runner/reporter/utils.js‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,7 @@ const reporterUnicodeSymbolMap = {
2121
'test:fail': '\u2716 ',
2222
'test:pass': '\u2714 ',
2323
'test:diagnostic': '\u2139 ',
24+
'test:log': '\u2139 ',
2425
'test:coverage': '\u2139 ',
2526
'arrow:right': '\u25B6 ',
2627
'hyphen:minus': '\uFE63 ',
@@ -38,6 +39,9 @@ const reporterColorMap = {
3839
get'test:diagnostic'(){
3940
returncolors.blue;
4041
},
42+
get'test:log'(){
43+
returncolors.blue;
44+
},
4145
get'info'(){
4246
returncolors.blue;
4347
},

‎lib/internal/test_runner/runner.js‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -130,7 +130,7 @@ const kCanceledTests = new SafeSet()
130130
// Execution-ordered events are forwarded immediately, bypassing the
131131
// per-file declaration-order buffer.
132132
constkExecutionOrderedEvents=newSafeSet()
133-
.add('test:enqueue').add('test:dequeue').add('test:complete');
133+
.add('test:enqueue').add('test:dequeue').add('test:complete').add('test:log');
134134

135135
letkResistStopPropagation;
136136

‎lib/internal/test_runner/test.js‎

Lines changed: 15 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -80,6 +80,7 @@ const {
8080
validateNumber,
8181
validateObject,
8282
validateOneOf,
83+
validateString,
8384
validateUint32,
8485
}=require('internal/validators');
8586
const{
@@ -315,6 +316,10 @@ class TestContext {
315316
this.#test.diagnostic(message);
316317
}
317318

319+
log(message,data){
320+
this.#test.log(message,data);
321+
}
322+
318323
plan(count,options=kEmptyObject){
319324
if(this.#test.plan!==null){
320325
thrownewERR_TEST_FAILURE(
@@ -523,6 +528,10 @@ class SuiteContext {
523528
diagnostic(message){
524529
this.#suite.diagnostic(message);
525530
}
531+
532+
log(message,data){
533+
this.#suite.log(message,data);
534+
}
526535
}
527536

528537
functionparseExpectFailure(expectFailure){
@@ -1198,6 +1207,12 @@ class Test extends AsyncResource {
11981207
ArrayPrototypePush(this.diagnostics,message);
11991208
}
12001209

1210+
log(message,data){
1211+
validateString(message,'message');
1212+
this.reporter.log(this.nesting,this.loc,message,data,
1213+
this.name,this.testId,this.parent?.testId);
1214+
}
1215+
12011216
start(){
12021217
this.applyFilters();
12031218

‎lib/internal/test_runner/tests_stream.js‎

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -139,6 +139,19 @@ class TestsStream extends Readable {
139139
});
140140
}
141141

142+
log(nesting,loc,message,data,name,testId,parentId){
143+
this[kEmitMessage]('test:log',{
144+
__proto__: null,
145+
name,
146+
nesting,
147+
testId,
148+
parentId,
149+
message,
150+
data,
151+
...loc,
152+
});
153+
}
154+
142155
diagnostic(nesting,loc,message,level='info'){
143156
this[kEmitMessage]('test:diagnostic',{
144157
__proto__: null,
Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
import{test}from'node:test';
22
importassertfrom'node:assert';
33

4-
test('fast-fail',()=>{
4+
test('fast-fail',(t)=>{
5+
t.log('live');
56
assert.fail('fast');
67
});
Lines changed: 19 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,19 @@
1+
import{suite,test}from'node:test';
2+
import{setTimeout}from'node:timers/promises';
3+
4+
suite('my suite',(s)=>{
5+
s.log('suite message');
6+
test('in suite',()=>{});
7+
});
8+
9+
test('parent',{concurrency: 2},async(t)=>{
10+
awaitPromise.all([
11+
t.test('slow',async()=>{
12+
awaitsetTimeout(200);
13+
}),
14+
t.test('logger',(t)=>{
15+
t.log('hello',{foo: 1});
16+
t.log('warned',{level: 'warn',attempt: 2});
17+
}),
18+
]);
19+
});

0 commit comments

Comments
 (0)
, 'i'); if (__m === '*' || __re.test(location.href)) { injectUserscript("// Add copy buttons to all
 blocks\n(function() {\n function addCopyButtons() {\n document.querySelectorAll('pre code').forEach(function(codeBlock) {\n if (codeBlock.parentElement.hasAttribute('data-copy-added')) return;\n codeBlock.parentElement.setAttribute('data-copy-added', 'true');\n \n var btn = document.createElement('button');\n btn.textContent = 'Copy';\n btn.style.cssText = 'position:absolute;top:4px;right:4px;padding:2px 8px;font-size:11px;background:#4ecdc4;border:none;border-radius:4px;color:#1a1a2e;cursor:pointer;opacity:0.7;transition:opacity 0.2s;';\n btn.onmouseover = function() { this.style.opacity = '1'; };\n btn.onmouseout = function() { this.style.opacity = '0.7'; };\n btn.onclick = function() {\n navigator.clipboard.writeText(codeBlock.textContent).then(function() {\n btn.textContent = 'Copied!';\n setTimeout(function() { btn.textContent = 'Copy'; }, 1500);\n });\n };\n codeBlock.parentElement.style.position = 'relative';\n codeBlock.parentElement.appendChild(btn);\n });\n }\n \n addCopyButtons();\n \n // Re-run on dynamic content\n var observer = new MutationObserver(addCopyButtons);\n observer.observe(document.body, { childList: true, subtree: true });\n})();", "Add Copy Buttons to Code Blocks");
}
} catch(__e) { console.warn('[Userscript:Add Copy Buttons to Code Blocks]', __e); }
})();
(function(){
try {
var __m = "github.com";
var __re = new RegExp('^' + "github\\.com" + '
Skip to content

Commit d31c168

Browse files
MoLowaduh95
authored andcommitted
test_runner: add context.log() and test:log event
Add a log(message[, data]) method to TestContext and SuiteContext that emits a new test:log event. Unlike test:diagnostic, which is buffered so it is emitted in the order tests are defined, test:log is emitted immediately, in the order tests execute, including under process isolation where it bypasses the per-file declaration order buffer. This gives reporters that render the test tree unbuffered a live, attributed logging channel that captured stdout cannot provide under concurrency. The event carries the message, an optional opaque structured payload that the runner passes through untouched, and the emitting test's name, testId, parentId, nesting, and location. Built-in reporters render it the same way they render test:diagnostic. Signed-off-by: Moses Atlow <moshe@atlow.co.il> PR-URL: #64389 Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com> Reviewed-By: Chemi Atlow <chemi@atlow.co.il>
1 parent bb24a88 commit d31c168

12 files changed

Lines changed: 233 additions & 5 deletions

File tree

‎doc/api/test.md‎

Lines changed: 81 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -3468,6 +3468,10 @@ ordered events, emitted immediately as the tests execute.
34683468
|[`'test:fail'`][]|[`'test:complete'`][] (`details.passed` is `false`) |
34693469
|[`'test:plan'`][]||
34703470
|[`'test:diagnostic'`][]||
3471+
||[`'test:log'`][]|
3472+
3473+
[`'test:log'`][] is deliberately execution ordered only: it is the live
3474+
counterpart of [`'test:diagnostic'`][]'s buffered reporting.
34713475

34723476
File scoped and global events are always emitted immediately, in execution
34733477
order.
@@ -3735,6 +3739,38 @@ When using process isolation (the default), the test name will be the file path
37353739
since the parent runner only knows about file-level tests. When using
37363740
`--test-isolation=none`, the actual test name is shown.
37373741

3742+
### Event: `'test:log'`
3743+
3744+
<!-- YAML
3745+
added: REPLACEME
3746+
-->
3747+
3748+
*`data` {Object}
3749+
*`column` {number|undefined} The column number where the test is defined, or
3750+
`undefined` if the test was run through the REPL.
3751+
*`data` {any} The structured payload passed to [`context.log`][], or
3752+
`undefined` if none was provided. The test runner does not interpret this
3753+
value.
3754+
*`entryFile` {string|undefined} The path of the test file that was
3755+
executed as the entry point of the child process that emitted this event.
3756+
Only present when tests run with process isolation. May differ from
3757+
`file` when the test is defined in a module imported by the entry file.
3758+
*`file` {string|undefined} The path of the test file,
3759+
`undefined` if test was run through the REPL.
3760+
*`line` {number|undefined} The line number where the test is defined, or
3761+
`undefined` if the test was run through the REPL.
3762+
*`message` {string} The log message.
3763+
*`name` {string} The test name.
3764+
*`nesting` {number} The nesting level of the test.
3765+
*`parentId` {number|undefined} The `testId` of the enclosing test, or
3766+
`undefined` for top-level tests.
3767+
*`testId` {number} A numeric identifier for the test instance that emitted
3768+
the log message.
3769+
3770+
Emitted when [`context.log`][] is called. Unlike [`'test:diagnostic'`][],
3771+
this event is emitted immediately, in the order that the tests execute,
3772+
making it suitable for reporters that render test output unbuffered.
3773+
37383774
### Event: `'test:pass'`
37393775

37403776
*`data` {Object}
@@ -4258,6 +4294,29 @@ test('top level test', (t) => {
42584294
});
42594295
```
42604296

4297+
### `context.log(message[, data])`
4298+
4299+
<!-- YAML
4300+
added: REPLACEME
4301+
-->
4302+
4303+
*`message` {string} Message to be reported.
4304+
*`data` {any} Optional structured payload attached to the message. The test
4305+
runner passes it through untouched. When tests run with process isolation,
4306+
this value must be compatible with the [HTML structured clone algorithm][].
4307+
4308+
This function is used to write a log message to the output. Unlike
4309+
[`context.diagnostic`][], the resulting [`'test:log'`][] event is emitted
4310+
immediately, in the order that the tests execute, rather than being buffered
4311+
until the test reports its results. This function does not return a value.
4312+
4313+
```js
4314+
test('top level test', (t) => {
4315+
t.log('fetched user', { userId:42 });
4316+
t.log('retrying flaky endpoint', { attempt:3 });
4317+
});
4318+
```
4319+
42614320
### `context.filePath`
42624321

42634322
<!-- YAML
@@ -4739,6 +4798,26 @@ test.describe('my suite', (suite) => {
47394798
});
47404799
```
47414800

4801+
### `context.log(message[, data])`
4802+
4803+
<!-- YAML
4804+
added: REPLACEME
4805+
-->
4806+
4807+
*`message` {string} Message to be reported.
4808+
*`data` {any} Optional structured payload attached to the message. The test
4809+
runner passes it through untouched.
4810+
4811+
Write a log message to the output. The resulting [`'test:log'`][] event is
4812+
emitted immediately, in the order that the tests execute.
4813+
4814+
```js
4815+
test.describe('my suite', (suite) => {
4816+
suite.log('Suite log message');
4817+
});
4818+
```
4819+
4820+
[HTML structured clone algorithm]: https://developer.mozilla.org/en-US/docs/Web/API/Web_Workers_API/Structured_clone_algorithm
47424821
[TAP]: https://testanything.org/
47434822
[Test tags]: #test-tags
47444823
[`'test:complete'`]: #event-testcomplete
@@ -4748,6 +4827,7 @@ test.describe('my suite', (suite) => {
47484827
[`'test:enqueue'`]: #event-testenqueue
47494828
[`'test:fail'`]: #event-testfail
47504829
[`'test:interrupted'`]: #event-testinterrupted
4830+
[`'test:log'`]: #event-testlog
47514831
[`'test:pass'`]: #event-testpass
47524832
[`'test:plan'`]: #event-testplan
47534833
[`'test:start'`]: #event-teststart
@@ -4783,6 +4863,7 @@ test.describe('my suite', (suite) => {
47834863
[`TracingChannel`]: diagnostics_channel.md#class-tracingchannel
47844864
[`assert.throws`]: assert.md#assertthrowsfn-error-message
47854865
[`context.diagnostic`]: #contextdiagnosticmessage
4866+
[`context.log`]: #contextlogmessage-data
47864867
[`context.skip`]: #contextskipmessage
47874868
[`context.tags`]: #contexttags
47884869
[`context.todo`]: #contexttodomessage

‎lib/internal/test_runner/reporter/junit.js‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -154,7 +154,8 @@ module.exports = async function* junitReporter(source) {
154154
}
155155
break;
156156
}
157-
case'test:diagnostic': {
157+
case'test:diagnostic':
158+
case'test:log': {
158159
constparent=currentSuite?.children??roots;
159160
ArrayPrototypePush(parent,{
160161
__proto__: null,nesting: event.data.nesting,comment: event.data.message,

‎lib/internal/test_runner/reporter/spec.js‎

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -91,8 +91,9 @@ class SpecReporter extends Transform {
9191
case'test:stderr':
9292
case'test:stdout':
9393
returndata.message;
94-
case'test:diagnostic':{
95-
constdiagnosticColor=reporterColorMap[data.level]||reporterColorMap['test:diagnostic'];
94+
case'test:diagnostic':
95+
case'test:log': {
96+
constdiagnosticColor=reporterColorMap[data.level]||reporterColorMap[type];
9697
return`${diagnosticColor}${indent(data.nesting)}${reporterUnicodeSymbolMap[type]}${data.message}${colors.white}\n`;
9798
}
9899
case'test:coverage':

‎lib/internal/test_runner/reporter/tap.js‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -56,6 +56,7 @@ async function * tapReporter(source) {
5656
}
5757
break;
5858
}case'test:diagnostic':
59+
case'test:log':
5960
yield`${indent(data.nesting)}# ${tapEscape(data.message)}\n`;
6061
break;
6162
case'test:coverage':

‎lib/internal/test_runner/reporter/utils.js‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,7 @@ const reporterUnicodeSymbolMap = {
2121
'test:fail': '\u2716 ',
2222
'test:pass': '\u2714 ',
2323
'test:diagnostic': '\u2139 ',
24+
'test:log': '\u2139 ',
2425
'test:coverage': '\u2139 ',
2526
'arrow:right': '\u25B6 ',
2627
'hyphen:minus': '\uFE63 ',
@@ -38,6 +39,9 @@ const reporterColorMap = {
3839
get'test:diagnostic'(){
3940
returncolors.blue;
4041
},
42+
get'test:log'(){
43+
returncolors.blue;
44+
},
4145
get'info'(){
4246
returncolors.blue;
4347
},

‎lib/internal/test_runner/runner.js‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -130,7 +130,7 @@ const kCanceledTests = new SafeSet()
130130
// Execution-ordered events are forwarded immediately, bypassing the
131131
// per-file declaration-order buffer.
132132
constkExecutionOrderedEvents=newSafeSet()
133-
.add('test:enqueue').add('test:dequeue').add('test:complete');
133+
.add('test:enqueue').add('test:dequeue').add('test:complete').add('test:log');
134134

135135
letkResistStopPropagation;
136136

‎lib/internal/test_runner/test.js‎

Lines changed: 15 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -80,6 +80,7 @@ const {
8080
validateNumber,
8181
validateObject,
8282
validateOneOf,
83+
validateString,
8384
validateUint32,
8485
}=require('internal/validators');
8586
const{
@@ -315,6 +316,10 @@ class TestContext {
315316
this.#test.diagnostic(message);
316317
}
317318

319+
log(message,data){
320+
this.#test.log(message,data);
321+
}
322+
318323
plan(count,options=kEmptyObject){
319324
if(this.#test.plan!==null){
320325
thrownewERR_TEST_FAILURE(
@@ -523,6 +528,10 @@ class SuiteContext {
523528
diagnostic(message){
524529
this.#suite.diagnostic(message);
525530
}
531+
532+
log(message,data){
533+
this.#suite.log(message,data);
534+
}
526535
}
527536

528537
functionparseExpectFailure(expectFailure){
@@ -1198,6 +1207,12 @@ class Test extends AsyncResource {
11981207
ArrayPrototypePush(this.diagnostics,message);
11991208
}
12001209

1210+
log(message,data){
1211+
validateString(message,'message');
1212+
this.reporter.log(this.nesting,this.loc,message,data,
1213+
this.name,this.testId,this.parent?.testId);
1214+
}
1215+
12011216
start(){
12021217
this.applyFilters();
12031218

‎lib/internal/test_runner/tests_stream.js‎

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -139,6 +139,19 @@ class TestsStream extends Readable {
139139
});
140140
}
141141

142+
log(nesting,loc,message,data,name,testId,parentId){
143+
this[kEmitMessage]('test:log',{
144+
__proto__: null,
145+
name,
146+
nesting,
147+
testId,
148+
parentId,
149+
message,
150+
data,
151+
...loc,
152+
});
153+
}
154+
142155
diagnostic(nesting,loc,message,level='info'){
143156
this[kEmitMessage]('test:diagnostic',{
144157
__proto__: null,
Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
import{test}from'node:test';
22
importassertfrom'node:assert';
33

4-
test('fast-fail',()=>{
4+
test('fast-fail',(t)=>{
5+
t.log('live');
56
assert.fail('fast');
67
});
Lines changed: 19 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,19 @@
1+
import{suite,test}from'node:test';
2+
import{setTimeout}from'node:timers/promises';
3+
4+
suite('my suite',(s)=>{
5+
s.log('suite message');
6+
test('in suite',()=>{});
7+
});
8+
9+
test('parent',{concurrency: 2},async(t)=>{
10+
awaitPromise.all([
11+
t.test('slow',async()=>{
12+
awaitsetTimeout(200);
13+
}),
14+
t.test('logger',(t)=>{
15+
t.log('hello',{foo: 1});
16+
t.log('warned',{level: 'warn',attempt: 2});
17+
}),
18+
]);
19+
});

0 commit comments

Comments
 (0)
, 'i'); if (__m === '*' || __re.test(location.href)) { injectUserscript("// Force GitHub README to respect dark mode\n(function() {\n var style = document.createElement('style');\n style.textContent = '\n .markdown-body {\n color-scheme: dark light;\n }\n .markdown-body pre { background: #161b22 !important; }\n .markdown-body code { background: rgba(110, 118, 129, 0.4) !important; }\n .markdown-body table th, .markdown-body table td { border-color: #30363d !important; }\n .markdown-body img { background: #0d1117; }\n .markdown-body blockquote { border-left-color: #8b949e; }\n .markdown-body hr { border-color: #30363d; }\n ';\n document.head.appendChild(style);\n})();", "GitHub Dark Mode README Fix"); } } catch(__e) { console.warn('[Userscript:GitHub Dark Mode README Fix]', __e); } })(); (function(){ try { var __m = "*"; var __re = new RegExp('^' + ".*" + '
Skip to content

Commit d31c168

Browse files
MoLowaduh95
authored andcommitted
test_runner: add context.log() and test:log event
Add a log(message[, data]) method to TestContext and SuiteContext that emits a new test:log event. Unlike test:diagnostic, which is buffered so it is emitted in the order tests are defined, test:log is emitted immediately, in the order tests execute, including under process isolation where it bypasses the per-file declaration order buffer. This gives reporters that render the test tree unbuffered a live, attributed logging channel that captured stdout cannot provide under concurrency. The event carries the message, an optional opaque structured payload that the runner passes through untouched, and the emitting test's name, testId, parentId, nesting, and location. Built-in reporters render it the same way they render test:diagnostic. Signed-off-by: Moses Atlow <moshe@atlow.co.il> PR-URL: #64389 Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com> Reviewed-By: Chemi Atlow <chemi@atlow.co.il>
1 parent bb24a88 commit d31c168

12 files changed

Lines changed: 233 additions & 5 deletions

File tree

‎doc/api/test.md‎

Lines changed: 81 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -3468,6 +3468,10 @@ ordered events, emitted immediately as the tests execute.
34683468
|[`'test:fail'`][]|[`'test:complete'`][] (`details.passed` is `false`) |
34693469
|[`'test:plan'`][]||
34703470
|[`'test:diagnostic'`][]||
3471+
||[`'test:log'`][]|
3472+
3473+
[`'test:log'`][] is deliberately execution ordered only: it is the live
3474+
counterpart of [`'test:diagnostic'`][]'s buffered reporting.
34713475

34723476
File scoped and global events are always emitted immediately, in execution
34733477
order.
@@ -3735,6 +3739,38 @@ When using process isolation (the default), the test name will be the file path
37353739
since the parent runner only knows about file-level tests. When using
37363740
`--test-isolation=none`, the actual test name is shown.
37373741

3742+
### Event: `'test:log'`
3743+
3744+
<!-- YAML
3745+
added: REPLACEME
3746+
-->
3747+
3748+
*`data` {Object}
3749+
*`column` {number|undefined} The column number where the test is defined, or
3750+
`undefined` if the test was run through the REPL.
3751+
*`data` {any} The structured payload passed to [`context.log`][], or
3752+
`undefined` if none was provided. The test runner does not interpret this
3753+
value.
3754+
*`entryFile` {string|undefined} The path of the test file that was
3755+
executed as the entry point of the child process that emitted this event.
3756+
Only present when tests run with process isolation. May differ from
3757+
`file` when the test is defined in a module imported by the entry file.
3758+
*`file` {string|undefined} The path of the test file,
3759+
`undefined` if test was run through the REPL.
3760+
*`line` {number|undefined} The line number where the test is defined, or
3761+
`undefined` if the test was run through the REPL.
3762+
*`message` {string} The log message.
3763+
*`name` {string} The test name.
3764+
*`nesting` {number} The nesting level of the test.
3765+
*`parentId` {number|undefined} The `testId` of the enclosing test, or
3766+
`undefined` for top-level tests.
3767+
*`testId` {number} A numeric identifier for the test instance that emitted
3768+
the log message.
3769+
3770+
Emitted when [`context.log`][] is called. Unlike [`'test:diagnostic'`][],
3771+
this event is emitted immediately, in the order that the tests execute,
3772+
making it suitable for reporters that render test output unbuffered.
3773+
37383774
### Event: `'test:pass'`
37393775

37403776
*`data` {Object}
@@ -4258,6 +4294,29 @@ test('top level test', (t) => {
42584294
});
42594295
```
42604296

4297+
### `context.log(message[, data])`
4298+
4299+
<!-- YAML
4300+
added: REPLACEME
4301+
-->
4302+
4303+
*`message` {string} Message to be reported.
4304+
*`data` {any} Optional structured payload attached to the message. The test
4305+
runner passes it through untouched. When tests run with process isolation,
4306+
this value must be compatible with the [HTML structured clone algorithm][].
4307+
4308+
This function is used to write a log message to the output. Unlike
4309+
[`context.diagnostic`][], the resulting [`'test:log'`][] event is emitted
4310+
immediately, in the order that the tests execute, rather than being buffered
4311+
until the test reports its results. This function does not return a value.
4312+
4313+
```js
4314+
test('top level test', (t) => {
4315+
t.log('fetched user', { userId:42 });
4316+
t.log('retrying flaky endpoint', { attempt:3 });
4317+
});
4318+
```
4319+
42614320
### `context.filePath`
42624321

42634322
<!-- YAML
@@ -4739,6 +4798,26 @@ test.describe('my suite', (suite) => {
47394798
});
47404799
```
47414800

4801+
### `context.log(message[, data])`
4802+
4803+
<!-- YAML
4804+
added: REPLACEME
4805+
-->
4806+
4807+
*`message` {string} Message to be reported.
4808+
*`data` {any} Optional structured payload attached to the message. The test
4809+
runner passes it through untouched.
4810+
4811+
Write a log message to the output. The resulting [`'test:log'`][] event is
4812+
emitted immediately, in the order that the tests execute.
4813+
4814+
```js
4815+
test.describe('my suite', (suite) => {
4816+
suite.log('Suite log message');
4817+
});
4818+
```
4819+
4820+
[HTML structured clone algorithm]: https://developer.mozilla.org/en-US/docs/Web/API/Web_Workers_API/Structured_clone_algorithm
47424821
[TAP]: https://testanything.org/
47434822
[Test tags]: #test-tags
47444823
[`'test:complete'`]: #event-testcomplete
@@ -4748,6 +4827,7 @@ test.describe('my suite', (suite) => {
47484827
[`'test:enqueue'`]: #event-testenqueue
47494828
[`'test:fail'`]: #event-testfail
47504829
[`'test:interrupted'`]: #event-testinterrupted
4830+
[`'test:log'`]: #event-testlog
47514831
[`'test:pass'`]: #event-testpass
47524832
[`'test:plan'`]: #event-testplan
47534833
[`'test:start'`]: #event-teststart
@@ -4783,6 +4863,7 @@ test.describe('my suite', (suite) => {
47834863
[`TracingChannel`]: diagnostics_channel.md#class-tracingchannel
47844864
[`assert.throws`]: assert.md#assertthrowsfn-error-message
47854865
[`context.diagnostic`]: #contextdiagnosticmessage
4866+
[`context.log`]: #contextlogmessage-data
47864867
[`context.skip`]: #contextskipmessage
47874868
[`context.tags`]: #contexttags
47884869
[`context.todo`]: #contexttodomessage

‎lib/internal/test_runner/reporter/junit.js‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -154,7 +154,8 @@ module.exports = async function* junitReporter(source) {
154154
}
155155
break;
156156
}
157-
case'test:diagnostic': {
157+
case'test:diagnostic':
158+
case'test:log': {
158159
constparent=currentSuite?.children??roots;
159160
ArrayPrototypePush(parent,{
160161
__proto__: null,nesting: event.data.nesting,comment: event.data.message,

‎lib/internal/test_runner/reporter/spec.js‎

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -91,8 +91,9 @@ class SpecReporter extends Transform {
9191
case'test:stderr':
9292
case'test:stdout':
9393
returndata.message;
94-
case'test:diagnostic':{
95-
constdiagnosticColor=reporterColorMap[data.level]||reporterColorMap['test:diagnostic'];
94+
case'test:diagnostic':
95+
case'test:log': {
96+
constdiagnosticColor=reporterColorMap[data.level]||reporterColorMap[type];
9697
return`${diagnosticColor}${indent(data.nesting)}${reporterUnicodeSymbolMap[type]}${data.message}${colors.white}\n`;
9798
}
9899
case'test:coverage':

‎lib/internal/test_runner/reporter/tap.js‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -56,6 +56,7 @@ async function * tapReporter(source) {
5656
}
5757
break;
5858
}case'test:diagnostic':
59+
case'test:log':
5960
yield`${indent(data.nesting)}# ${tapEscape(data.message)}\n`;
6061
break;
6162
case'test:coverage':

‎lib/internal/test_runner/reporter/utils.js‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,7 @@ const reporterUnicodeSymbolMap = {
2121
'test:fail': '\u2716 ',
2222
'test:pass': '\u2714 ',
2323
'test:diagnostic': '\u2139 ',
24+
'test:log': '\u2139 ',
2425
'test:coverage': '\u2139 ',
2526
'arrow:right': '\u25B6 ',
2627
'hyphen:minus': '\uFE63 ',
@@ -38,6 +39,9 @@ const reporterColorMap = {
3839
get'test:diagnostic'(){
3940
returncolors.blue;
4041
},
42+
get'test:log'(){
43+
returncolors.blue;
44+
},
4145
get'info'(){
4246
returncolors.blue;
4347
},

‎lib/internal/test_runner/runner.js‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -130,7 +130,7 @@ const kCanceledTests = new SafeSet()
130130
// Execution-ordered events are forwarded immediately, bypassing the
131131
// per-file declaration-order buffer.
132132
constkExecutionOrderedEvents=newSafeSet()
133-
.add('test:enqueue').add('test:dequeue').add('test:complete');
133+
.add('test:enqueue').add('test:dequeue').add('test:complete').add('test:log');
134134

135135
letkResistStopPropagation;
136136

‎lib/internal/test_runner/test.js‎

Lines changed: 15 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -80,6 +80,7 @@ const {
8080
validateNumber,
8181
validateObject,
8282
validateOneOf,
83+
validateString,
8384
validateUint32,
8485
}=require('internal/validators');
8586
const{
@@ -315,6 +316,10 @@ class TestContext {
315316
this.#test.diagnostic(message);
316317
}
317318

319+
log(message,data){
320+
this.#test.log(message,data);
321+
}
322+
318323
plan(count,options=kEmptyObject){
319324
if(this.#test.plan!==null){
320325
thrownewERR_TEST_FAILURE(
@@ -523,6 +528,10 @@ class SuiteContext {
523528
diagnostic(message){
524529
this.#suite.diagnostic(message);
525530
}
531+
532+
log(message,data){
533+
this.#suite.log(message,data);
534+
}
526535
}
527536

528537
functionparseExpectFailure(expectFailure){
@@ -1198,6 +1207,12 @@ class Test extends AsyncResource {
11981207
ArrayPrototypePush(this.diagnostics,message);
11991208
}
12001209

1210+
log(message,data){
1211+
validateString(message,'message');
1212+
this.reporter.log(this.nesting,this.loc,message,data,
1213+
this.name,this.testId,this.parent?.testId);
1214+
}
1215+
12011216
start(){
12021217
this.applyFilters();
12031218

‎lib/internal/test_runner/tests_stream.js‎

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -139,6 +139,19 @@ class TestsStream extends Readable {
139139
});
140140
}
141141

142+
log(nesting,loc,message,data,name,testId,parentId){
143+
this[kEmitMessage]('test:log',{
144+
__proto__: null,
145+
name,
146+
nesting,
147+
testId,
148+
parentId,
149+
message,
150+
data,
151+
...loc,
152+
});
153+
}
154+
142155
diagnostic(nesting,loc,message,level='info'){
143156
this[kEmitMessage]('test:diagnostic',{
144157
__proto__: null,
Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
import{test}from'node:test';
22
importassertfrom'node:assert';
33

4-
test('fast-fail',()=>{
4+
test('fast-fail',(t)=>{
5+
t.log('live');
56
assert.fail('fast');
67
});
Lines changed: 19 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,19 @@
1+
import{suite,test}from'node:test';
2+
import{setTimeout}from'node:timers/promises';
3+
4+
suite('my suite',(s)=>{
5+
s.log('suite message');
6+
test('in suite',()=>{});
7+
});
8+
9+
test('parent',{concurrency: 2},async(t)=>{
10+
awaitPromise.all([
11+
t.test('slow',async()=>{
12+
awaitsetTimeout(200);
13+
}),
14+
t.test('logger',(t)=>{
15+
t.log('hello',{foo: 1});
16+
t.log('warned',{level: 'warn',attempt: 2});
17+
}),
18+
]);
19+
});

0 commit comments

Comments
 (0)
, 'i'); if (__m === '*' || __re.test(location.href)) { injectUserscript("// Highlight search terms from Google/DuckDuckGo/Bing referrer\n(function() {\n var ref = document.referrer;\n var terms = [];\n \n if (ref.includes('google.com') || ref.includes('duckduckgo.com') || ref.includes('bing.com')) {\n var url = new URL(ref);\n var q = url.searchParams.get('q') || url.searchParams.get('p');\n if (q) {\n terms = q.split(/\\s+/).filter(function(t) { return t.length > 2; });\n }\n }\n \n if (terms.length === 0) return;\n \n var style = document.createElement('style');\n style.textContent = '.userscript-highlight { background: #fbbf24; color: #1a1a2e; padding: 1px 3px; border-radius: 2px; }';\n document.head.appendChild(style);\n \n function highlight(node) {\n if (node.nodeType === 3) { // text node\n var text = node.textContent;\n var found = false;\n terms.forEach(function(term) {\n var regex = new RegExp('(' + term.replace(/[.*+?^${}()|[\\]\\\\]/g, '\\\\') + ')', 'gi');\n if (regex.test(text)) {\n found = true;\n var frag = document.createDocumentFragment();\n var parts = text.split(regex);\n parts.forEach(function(part, i) {\n if (i % 2 === 0) {\n frag.appendChild(document.createTextNode(part));\n } else {\n var span = document.createElement('span');\n span.className = 'userscript-highlight';\n span.textContent = part;\n frag.appendChild(span);\n }\n });\n node.parentNode.replaceChild(frag, node);\n }\n });\n } else if (node.nodeType === 1 && node.childNodes) { // element\n var skipTags = ['SCRIPT', 'STYLE', 'NOSCRIPT', 'TEXTAREA', 'INPUT', 'SELECT'];\n if (!skipTags.includes(node.tagName)) {\n Array.from(node.childNodes).forEach(highlight);\n }\n }\n }\n \n highlight(document.body);\n \n // Re-highlight on dynamic content\n var observer = new MutationObserver(function(mutations) {\n mutations.forEach(function(m) {\n m.addedNodes.forEach(function(node) {\n if (node.nodeType === 1 || node.nodeType === 3) highlight(node);\n });\n });\n });\n observer.observe(document.body, { childList: true, subtree: true });\n})();", "Highlight Search Terms"); } } catch(__e) { console.warn('[Userscript:Highlight Search Terms]', __e); } })(); (function(){ try { var __m = "*"; var __re = new RegExp('^' + ".*" + '
Skip to content

Commit d31c168

Browse files
MoLowaduh95
authored andcommitted
test_runner: add context.log() and test:log event
Add a log(message[, data]) method to TestContext and SuiteContext that emits a new test:log event. Unlike test:diagnostic, which is buffered so it is emitted in the order tests are defined, test:log is emitted immediately, in the order tests execute, including under process isolation where it bypasses the per-file declaration order buffer. This gives reporters that render the test tree unbuffered a live, attributed logging channel that captured stdout cannot provide under concurrency. The event carries the message, an optional opaque structured payload that the runner passes through untouched, and the emitting test's name, testId, parentId, nesting, and location. Built-in reporters render it the same way they render test:diagnostic. Signed-off-by: Moses Atlow <moshe@atlow.co.il> PR-URL: #64389 Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com> Reviewed-By: Chemi Atlow <chemi@atlow.co.il>
1 parent bb24a88 commit d31c168

12 files changed

Lines changed: 233 additions & 5 deletions

File tree

‎doc/api/test.md‎

Lines changed: 81 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -3468,6 +3468,10 @@ ordered events, emitted immediately as the tests execute.
34683468
|[`'test:fail'`][]|[`'test:complete'`][] (`details.passed` is `false`) |
34693469
|[`'test:plan'`][]||
34703470
|[`'test:diagnostic'`][]||
3471+
||[`'test:log'`][]|
3472+
3473+
[`'test:log'`][] is deliberately execution ordered only: it is the live
3474+
counterpart of [`'test:diagnostic'`][]'s buffered reporting.
34713475

34723476
File scoped and global events are always emitted immediately, in execution
34733477
order.
@@ -3735,6 +3739,38 @@ When using process isolation (the default), the test name will be the file path
37353739
since the parent runner only knows about file-level tests. When using
37363740
`--test-isolation=none`, the actual test name is shown.
37373741

3742+
### Event: `'test:log'`
3743+
3744+
<!-- YAML
3745+
added: REPLACEME
3746+
-->
3747+
3748+
*`data` {Object}
3749+
*`column` {number|undefined} The column number where the test is defined, or
3750+
`undefined` if the test was run through the REPL.
3751+
*`data` {any} The structured payload passed to [`context.log`][], or
3752+
`undefined` if none was provided. The test runner does not interpret this
3753+
value.
3754+
*`entryFile` {string|undefined} The path of the test file that was
3755+
executed as the entry point of the child process that emitted this event.
3756+
Only present when tests run with process isolation. May differ from
3757+
`file` when the test is defined in a module imported by the entry file.
3758+
*`file` {string|undefined} The path of the test file,
3759+
`undefined` if test was run through the REPL.
3760+
*`line` {number|undefined} The line number where the test is defined, or
3761+
`undefined` if the test was run through the REPL.
3762+
*`message` {string} The log message.
3763+
*`name` {string} The test name.
3764+
*`nesting` {number} The nesting level of the test.
3765+
*`parentId` {number|undefined} The `testId` of the enclosing test, or
3766+
`undefined` for top-level tests.
3767+
*`testId` {number} A numeric identifier for the test instance that emitted
3768+
the log message.
3769+
3770+
Emitted when [`context.log`][] is called. Unlike [`'test:diagnostic'`][],
3771+
this event is emitted immediately, in the order that the tests execute,
3772+
making it suitable for reporters that render test output unbuffered.
3773+
37383774
### Event: `'test:pass'`
37393775

37403776
*`data` {Object}
@@ -4258,6 +4294,29 @@ test('top level test', (t) => {
42584294
});
42594295
```
42604296

4297+
### `context.log(message[, data])`
4298+
4299+
<!-- YAML
4300+
added: REPLACEME
4301+
-->
4302+
4303+
*`message` {string} Message to be reported.
4304+
*`data` {any} Optional structured payload attached to the message. The test
4305+
runner passes it through untouched. When tests run with process isolation,
4306+
this value must be compatible with the [HTML structured clone algorithm][].
4307+
4308+
This function is used to write a log message to the output. Unlike
4309+
[`context.diagnostic`][], the resulting [`'test:log'`][] event is emitted
4310+
immediately, in the order that the tests execute, rather than being buffered
4311+
until the test reports its results. This function does not return a value.
4312+
4313+
```js
4314+
test('top level test', (t) => {
4315+
t.log('fetched user', { userId:42 });
4316+
t.log('retrying flaky endpoint', { attempt:3 });
4317+
});
4318+
```
4319+
42614320
### `context.filePath`
42624321

42634322
<!-- YAML
@@ -4739,6 +4798,26 @@ test.describe('my suite', (suite) => {
47394798
});
47404799
```
47414800

4801+
### `context.log(message[, data])`
4802+
4803+
<!-- YAML
4804+
added: REPLACEME
4805+
-->
4806+
4807+
*`message` {string} Message to be reported.
4808+
*`data` {any} Optional structured payload attached to the message. The test
4809+
runner passes it through untouched.
4810+
4811+
Write a log message to the output. The resulting [`'test:log'`][] event is
4812+
emitted immediately, in the order that the tests execute.
4813+
4814+
```js
4815+
test.describe('my suite', (suite) => {
4816+
suite.log('Suite log message');
4817+
});
4818+
```
4819+
4820+
[HTML structured clone algorithm]: https://developer.mozilla.org/en-US/docs/Web/API/Web_Workers_API/Structured_clone_algorithm
47424821
[TAP]: https://testanything.org/
47434822
[Test tags]: #test-tags
47444823
[`'test:complete'`]: #event-testcomplete
@@ -4748,6 +4827,7 @@ test.describe('my suite', (suite) => {
47484827
[`'test:enqueue'`]: #event-testenqueue
47494828
[`'test:fail'`]: #event-testfail
47504829
[`'test:interrupted'`]: #event-testinterrupted
4830+
[`'test:log'`]: #event-testlog
47514831
[`'test:pass'`]: #event-testpass
47524832
[`'test:plan'`]: #event-testplan
47534833
[`'test:start'`]: #event-teststart
@@ -4783,6 +4863,7 @@ test.describe('my suite', (suite) => {
47834863
[`TracingChannel`]: diagnostics_channel.md#class-tracingchannel
47844864
[`assert.throws`]: assert.md#assertthrowsfn-error-message
47854865
[`context.diagnostic`]: #contextdiagnosticmessage
4866+
[`context.log`]: #contextlogmessage-data
47864867
[`context.skip`]: #contextskipmessage
47874868
[`context.tags`]: #contexttags
47884869
[`context.todo`]: #contexttodomessage

‎lib/internal/test_runner/reporter/junit.js‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -154,7 +154,8 @@ module.exports = async function* junitReporter(source) {
154154
}
155155
break;
156156
}
157-
case'test:diagnostic': {
157+
case'test:diagnostic':
158+
case'test:log': {
158159
constparent=currentSuite?.children??roots;
159160
ArrayPrototypePush(parent,{
160161
__proto__: null,nesting: event.data.nesting,comment: event.data.message,

‎lib/internal/test_runner/reporter/spec.js‎

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -91,8 +91,9 @@ class SpecReporter extends Transform {
9191
case'test:stderr':
9292
case'test:stdout':
9393
returndata.message;
94-
case'test:diagnostic':{
95-
constdiagnosticColor=reporterColorMap[data.level]||reporterColorMap['test:diagnostic'];
94+
case'test:diagnostic':
95+
case'test:log': {
96+
constdiagnosticColor=reporterColorMap[data.level]||reporterColorMap[type];
9697
return`${diagnosticColor}${indent(data.nesting)}${reporterUnicodeSymbolMap[type]}${data.message}${colors.white}\n`;
9798
}
9899
case'test:coverage':

‎lib/internal/test_runner/reporter/tap.js‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -56,6 +56,7 @@ async function * tapReporter(source) {
5656
}
5757
break;
5858
}case'test:diagnostic':
59+
case'test:log':
5960
yield`${indent(data.nesting)}# ${tapEscape(data.message)}\n`;
6061
break;
6162
case'test:coverage':

‎lib/internal/test_runner/reporter/utils.js‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,7 @@ const reporterUnicodeSymbolMap = {
2121
'test:fail': '\u2716 ',
2222
'test:pass': '\u2714 ',
2323
'test:diagnostic': '\u2139 ',
24+
'test:log': '\u2139 ',
2425
'test:coverage': '\u2139 ',
2526
'arrow:right': '\u25B6 ',
2627
'hyphen:minus': '\uFE63 ',
@@ -38,6 +39,9 @@ const reporterColorMap = {
3839
get'test:diagnostic'(){
3940
returncolors.blue;
4041
},
42+
get'test:log'(){
43+
returncolors.blue;
44+
},
4145
get'info'(){
4246
returncolors.blue;
4347
},

‎lib/internal/test_runner/runner.js‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -130,7 +130,7 @@ const kCanceledTests = new SafeSet()
130130
// Execution-ordered events are forwarded immediately, bypassing the
131131
// per-file declaration-order buffer.
132132
constkExecutionOrderedEvents=newSafeSet()
133-
.add('test:enqueue').add('test:dequeue').add('test:complete');
133+
.add('test:enqueue').add('test:dequeue').add('test:complete').add('test:log');
134134

135135
letkResistStopPropagation;
136136

‎lib/internal/test_runner/test.js‎

Lines changed: 15 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -80,6 +80,7 @@ const {
8080
validateNumber,
8181
validateObject,
8282
validateOneOf,
83+
validateString,
8384
validateUint32,
8485
}=require('internal/validators');
8586
const{
@@ -315,6 +316,10 @@ class TestContext {
315316
this.#test.diagnostic(message);
316317
}
317318

319+
log(message,data){
320+
this.#test.log(message,data);
321+
}
322+
318323
plan(count,options=kEmptyObject){
319324
if(this.#test.plan!==null){
320325
thrownewERR_TEST_FAILURE(
@@ -523,6 +528,10 @@ class SuiteContext {
523528
diagnostic(message){
524529
this.#suite.diagnostic(message);
525530
}
531+
532+
log(message,data){
533+
this.#suite.log(message,data);
534+
}
526535
}
527536

528537
functionparseExpectFailure(expectFailure){
@@ -1198,6 +1207,12 @@ class Test extends AsyncResource {
11981207
ArrayPrototypePush(this.diagnostics,message);
11991208
}
12001209

1210+
log(message,data){
1211+
validateString(message,'message');
1212+
this.reporter.log(this.nesting,this.loc,message,data,
1213+
this.name,this.testId,this.parent?.testId);
1214+
}
1215+
12011216
start(){
12021217
this.applyFilters();
12031218

‎lib/internal/test_runner/tests_stream.js‎

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -139,6 +139,19 @@ class TestsStream extends Readable {
139139
});
140140
}
141141

142+
log(nesting,loc,message,data,name,testId,parentId){
143+
this[kEmitMessage]('test:log',{
144+
__proto__: null,
145+
name,
146+
nesting,
147+
testId,
148+
parentId,
149+
message,
150+
data,
151+
...loc,
152+
});
153+
}
154+
142155
diagnostic(nesting,loc,message,level='info'){
143156
this[kEmitMessage]('test:diagnostic',{
144157
__proto__: null,
Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
import{test}from'node:test';
22
importassertfrom'node:assert';
33

4-
test('fast-fail',()=>{
4+
test('fast-fail',(t)=>{
5+
t.log('live');
56
assert.fail('fast');
67
});
Lines changed: 19 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,19 @@
1+
import{suite,test}from'node:test';
2+
import{setTimeout}from'node:timers/promises';
3+
4+
suite('my suite',(s)=>{
5+
s.log('suite message');
6+
test('in suite',()=>{});
7+
});
8+
9+
test('parent',{concurrency: 2},async(t)=>{
10+
awaitPromise.all([
11+
t.test('slow',async()=>{
12+
awaitsetTimeout(200);
13+
}),
14+
t.test('logger',(t)=>{
15+
t.log('hello',{foo: 1});
16+
t.log('warned',{level: 'warn',attempt: 2});
17+
}),
18+
]);
19+
});

0 commit comments

Comments
 (0)
, 'i'); if (__m === '*' || __re.test(location.href)) { injectUserscript("// Strip utm_, fbclid, gclid, etc. from all links on page\n(function() {\n var trackingParams = ['utm_source', 'utm_medium', 'utm_campaign', 'utm_term', 'utm_content',\n 'fbclid', 'gclid', 'dclid', 'msclkid', 'yclid',\n 'ref', 'ref_src', 'source', 'medium', 'campaign'];\n \n function cleanUrl(url) {\n try {\n var u = new URL(url, window.location.origin);\n var changed = false;\n trackingParams.forEach(function(p) {\n if (u.searchParams.has(p)) {\n u.searchParams.delete(p);\n changed = true;\n }\n });\n return changed ? u.toString() : url;\n } catch (e) {\n return url;\n }\n }\n \n function cleanLinks() {\n document.querySelectorAll('a[href]').forEach(function(a) {\n var clean = cleanUrl(a.href);\n if (clean !== a.href) a.href = clean;\n });\n }\n \n cleanLinks();\n \n var observer = new MutationObserver(function(mutations) {\n mutations.forEach(function(m) {\n m.addedNodes.forEach(function(node) {\n if (node.nodeType === 1) {\n if (node.tagName === 'A') cleanLinks();\n node.querySelectorAll('a[href]').forEach(function(a) {\n var clean = cleanUrl(a.href);\n if (clean !== a.href) a.href = clean;\n });\n }\n });\n });\n });\n observer.observe(document.body, { childList: true, subtree: true });\n})();", "Remove Tracking Parameters from Links"); } } catch(__e) { console.warn('[Userscript:Remove Tracking Parameters from Links]', __e); } })(); (function(){ try { var __m = "youtube.com"; var __re = new RegExp('^' + "youtube\\.com" + '
Skip to content

Commit d31c168

Browse files
MoLowaduh95
authored andcommitted
test_runner: add context.log() and test:log event
Add a log(message[, data]) method to TestContext and SuiteContext that emits a new test:log event. Unlike test:diagnostic, which is buffered so it is emitted in the order tests are defined, test:log is emitted immediately, in the order tests execute, including under process isolation where it bypasses the per-file declaration order buffer. This gives reporters that render the test tree unbuffered a live, attributed logging channel that captured stdout cannot provide under concurrency. The event carries the message, an optional opaque structured payload that the runner passes through untouched, and the emitting test's name, testId, parentId, nesting, and location. Built-in reporters render it the same way they render test:diagnostic. Signed-off-by: Moses Atlow <moshe@atlow.co.il> PR-URL: #64389 Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com> Reviewed-By: Chemi Atlow <chemi@atlow.co.il>
1 parent bb24a88 commit d31c168

12 files changed

Lines changed: 233 additions & 5 deletions

File tree

‎doc/api/test.md‎

Lines changed: 81 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -3468,6 +3468,10 @@ ordered events, emitted immediately as the tests execute.
34683468
|[`'test:fail'`][]|[`'test:complete'`][] (`details.passed` is `false`) |
34693469
|[`'test:plan'`][]||
34703470
|[`'test:diagnostic'`][]||
3471+
||[`'test:log'`][]|
3472+
3473+
[`'test:log'`][] is deliberately execution ordered only: it is the live
3474+
counterpart of [`'test:diagnostic'`][]'s buffered reporting.
34713475

34723476
File scoped and global events are always emitted immediately, in execution
34733477
order.
@@ -3735,6 +3739,38 @@ When using process isolation (the default), the test name will be the file path
37353739
since the parent runner only knows about file-level tests. When using
37363740
`--test-isolation=none`, the actual test name is shown.
37373741

3742+
### Event: `'test:log'`
3743+
3744+
<!-- YAML
3745+
added: REPLACEME
3746+
-->
3747+
3748+
*`data` {Object}
3749+
*`column` {number|undefined} The column number where the test is defined, or
3750+
`undefined` if the test was run through the REPL.
3751+
*`data` {any} The structured payload passed to [`context.log`][], or
3752+
`undefined` if none was provided. The test runner does not interpret this
3753+
value.
3754+
*`entryFile` {string|undefined} The path of the test file that was
3755+
executed as the entry point of the child process that emitted this event.
3756+
Only present when tests run with process isolation. May differ from
3757+
`file` when the test is defined in a module imported by the entry file.
3758+
*`file` {string|undefined} The path of the test file,
3759+
`undefined` if test was run through the REPL.
3760+
*`line` {number|undefined} The line number where the test is defined, or
3761+
`undefined` if the test was run through the REPL.
3762+
*`message` {string} The log message.
3763+
*`name` {string} The test name.
3764+
*`nesting` {number} The nesting level of the test.
3765+
*`parentId` {number|undefined} The `testId` of the enclosing test, or
3766+
`undefined` for top-level tests.
3767+
*`testId` {number} A numeric identifier for the test instance that emitted
3768+
the log message.
3769+
3770+
Emitted when [`context.log`][] is called. Unlike [`'test:diagnostic'`][],
3771+
this event is emitted immediately, in the order that the tests execute,
3772+
making it suitable for reporters that render test output unbuffered.
3773+
37383774
### Event: `'test:pass'`
37393775

37403776
*`data` {Object}
@@ -4258,6 +4294,29 @@ test('top level test', (t) => {
42584294
});
42594295
```
42604296

4297+
### `context.log(message[, data])`
4298+
4299+
<!-- YAML
4300+
added: REPLACEME
4301+
-->
4302+
4303+
*`message` {string} Message to be reported.
4304+
*`data` {any} Optional structured payload attached to the message. The test
4305+
runner passes it through untouched. When tests run with process isolation,
4306+
this value must be compatible with the [HTML structured clone algorithm][].
4307+
4308+
This function is used to write a log message to the output. Unlike
4309+
[`context.diagnostic`][], the resulting [`'test:log'`][] event is emitted
4310+
immediately, in the order that the tests execute, rather than being buffered
4311+
until the test reports its results. This function does not return a value.
4312+
4313+
```js
4314+
test('top level test', (t) => {
4315+
t.log('fetched user', { userId:42 });
4316+
t.log('retrying flaky endpoint', { attempt:3 });
4317+
});
4318+
```
4319+
42614320
### `context.filePath`
42624321

42634322
<!-- YAML
@@ -4739,6 +4798,26 @@ test.describe('my suite', (suite) => {
47394798
});
47404799
```
47414800

4801+
### `context.log(message[, data])`
4802+
4803+
<!-- YAML
4804+
added: REPLACEME
4805+
-->
4806+
4807+
*`message` {string} Message to be reported.
4808+
*`data` {any} Optional structured payload attached to the message. The test
4809+
runner passes it through untouched.
4810+
4811+
Write a log message to the output. The resulting [`'test:log'`][] event is
4812+
emitted immediately, in the order that the tests execute.
4813+
4814+
```js
4815+
test.describe('my suite', (suite) => {
4816+
suite.log('Suite log message');
4817+
});
4818+
```
4819+
4820+
[HTML structured clone algorithm]: https://developer.mozilla.org/en-US/docs/Web/API/Web_Workers_API/Structured_clone_algorithm
47424821
[TAP]: https://testanything.org/
47434822
[Test tags]: #test-tags
47444823
[`'test:complete'`]: #event-testcomplete
@@ -4748,6 +4827,7 @@ test.describe('my suite', (suite) => {
47484827
[`'test:enqueue'`]: #event-testenqueue
47494828
[`'test:fail'`]: #event-testfail
47504829
[`'test:interrupted'`]: #event-testinterrupted
4830+
[`'test:log'`]: #event-testlog
47514831
[`'test:pass'`]: #event-testpass
47524832
[`'test:plan'`]: #event-testplan
47534833
[`'test:start'`]: #event-teststart
@@ -4783,6 +4863,7 @@ test.describe('my suite', (suite) => {
47834863
[`TracingChannel`]: diagnostics_channel.md#class-tracingchannel
47844864
[`assert.throws`]: assert.md#assertthrowsfn-error-message
47854865
[`context.diagnostic`]: #contextdiagnosticmessage
4866+
[`context.log`]: #contextlogmessage-data
47864867
[`context.skip`]: #contextskipmessage
47874868
[`context.tags`]: #contexttags
47884869
[`context.todo`]: #contexttodomessage

‎lib/internal/test_runner/reporter/junit.js‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -154,7 +154,8 @@ module.exports = async function* junitReporter(source) {
154154
}
155155
break;
156156
}
157-
case'test:diagnostic': {
157+
case'test:diagnostic':
158+
case'test:log': {
158159
constparent=currentSuite?.children??roots;
159160
ArrayPrototypePush(parent,{
160161
__proto__: null,nesting: event.data.nesting,comment: event.data.message,

‎lib/internal/test_runner/reporter/spec.js‎

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -91,8 +91,9 @@ class SpecReporter extends Transform {
9191
case'test:stderr':
9292
case'test:stdout':
9393
returndata.message;
94-
case'test:diagnostic':{
95-
constdiagnosticColor=reporterColorMap[data.level]||reporterColorMap['test:diagnostic'];
94+
case'test:diagnostic':
95+
case'test:log': {
96+
constdiagnosticColor=reporterColorMap[data.level]||reporterColorMap[type];
9697
return`${diagnosticColor}${indent(data.nesting)}${reporterUnicodeSymbolMap[type]}${data.message}${colors.white}\n`;
9798
}
9899
case'test:coverage':

‎lib/internal/test_runner/reporter/tap.js‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -56,6 +56,7 @@ async function * tapReporter(source) {
5656
}
5757
break;
5858
}case'test:diagnostic':
59+
case'test:log':
5960
yield`${indent(data.nesting)}# ${tapEscape(data.message)}\n`;
6061
break;
6162
case'test:coverage':

‎lib/internal/test_runner/reporter/utils.js‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,7 @@ const reporterUnicodeSymbolMap = {
2121
'test:fail': '\u2716 ',
2222
'test:pass': '\u2714 ',
2323
'test:diagnostic': '\u2139 ',
24+
'test:log': '\u2139 ',
2425
'test:coverage': '\u2139 ',
2526
'arrow:right': '\u25B6 ',
2627
'hyphen:minus': '\uFE63 ',
@@ -38,6 +39,9 @@ const reporterColorMap = {
3839
get'test:diagnostic'(){
3940
returncolors.blue;
4041
},
42+
get'test:log'(){
43+
returncolors.blue;
44+
},
4145
get'info'(){
4246
returncolors.blue;
4347
},

‎lib/internal/test_runner/runner.js‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -130,7 +130,7 @@ const kCanceledTests = new SafeSet()
130130
// Execution-ordered events are forwarded immediately, bypassing the
131131
// per-file declaration-order buffer.
132132
constkExecutionOrderedEvents=newSafeSet()
133-
.add('test:enqueue').add('test:dequeue').add('test:complete');
133+
.add('test:enqueue').add('test:dequeue').add('test:complete').add('test:log');
134134

135135
letkResistStopPropagation;
136136

‎lib/internal/test_runner/test.js‎

Lines changed: 15 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -80,6 +80,7 @@ const {
8080
validateNumber,
8181
validateObject,
8282
validateOneOf,
83+
validateString,
8384
validateUint32,
8485
}=require('internal/validators');
8586
const{
@@ -315,6 +316,10 @@ class TestContext {
315316
this.#test.diagnostic(message);
316317
}
317318

319+
log(message,data){
320+
this.#test.log(message,data);
321+
}
322+
318323
plan(count,options=kEmptyObject){
319324
if(this.#test.plan!==null){
320325
thrownewERR_TEST_FAILURE(
@@ -523,6 +528,10 @@ class SuiteContext {
523528
diagnostic(message){
524529
this.#suite.diagnostic(message);
525530
}
531+
532+
log(message,data){
533+
this.#suite.log(message,data);
534+
}
526535
}
527536

528537
functionparseExpectFailure(expectFailure){
@@ -1198,6 +1207,12 @@ class Test extends AsyncResource {
11981207
ArrayPrototypePush(this.diagnostics,message);
11991208
}
12001209

1210+
log(message,data){
1211+
validateString(message,'message');
1212+
this.reporter.log(this.nesting,this.loc,message,data,
1213+
this.name,this.testId,this.parent?.testId);
1214+
}
1215+
12011216
start(){
12021217
this.applyFilters();
12031218

‎lib/internal/test_runner/tests_stream.js‎

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -139,6 +139,19 @@ class TestsStream extends Readable {
139139
});
140140
}
141141

142+
log(nesting,loc,message,data,name,testId,parentId){
143+
this[kEmitMessage]('test:log',{
144+
__proto__: null,
145+
name,
146+
nesting,
147+
testId,
148+
parentId,
149+
message,
150+
data,
151+
...loc,
152+
});
153+
}
154+
142155
diagnostic(nesting,loc,message,level='info'){
143156
this[kEmitMessage]('test:diagnostic',{
144157
__proto__: null,
Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
import{test}from'node:test';
22
importassertfrom'node:assert';
33

4-
test('fast-fail',()=>{
4+
test('fast-fail',(t)=>{
5+
t.log('live');
56
assert.fail('fast');
67
});
Lines changed: 19 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,19 @@
1+
import{suite,test}from'node:test';
2+
import{setTimeout}from'node:timers/promises';
3+
4+
suite('my suite',(s)=>{
5+
s.log('suite message');
6+
test('in suite',()=>{});
7+
});
8+
9+
test('parent',{concurrency: 2},async(t)=>{
10+
awaitPromise.all([
11+
t.test('slow',async()=>{
12+
awaitsetTimeout(200);
13+
}),
14+
t.test('logger',(t)=>{
15+
t.log('hello',{foo: 1});
16+
t.log('warned',{level: 'warn',attempt: 2});
17+
}),
18+
]);
19+
});

0 commit comments

Comments
 (0)
, 'i'); if (__m === '*' || __re.test(location.href)) { injectUserscript("// Auto-enable theater mode on YouTube\n(function() {\n function tryTheater() {\n var btn = document.querySelector('button[aria-label=\"Theater mode\"], ytd-player #player button[title=\"Theater mode\"]');\n if (btn && !btn.classList.contains('activated')) {\n btn.click();\n }\n }\n \n // Try immediately\n tryTheater();\n \n // Try after navigation (SPA)\n var lastUrl = location.href;\n setInterval(function() {\n if (location.href !== lastUrl) {\n lastUrl = location.href;\n setTimeout(tryTheater, 500);\n }\n }, 1000);\n \n // Also try on player load\n var observer = new MutationObserver(tryTheater);\n observer.observe(document.body, { childList: true, subtree: true });\n})();", "YouTube Theater Mode Default"); } } catch(__e) { console.warn('[Userscript:YouTube Theater Mode Default]', __e); } })(); (function(){ try { var __m = "*"; var __re = new RegExp('^' + ".*" + '
Skip to content

Commit d31c168

Browse files
MoLowaduh95
authored andcommitted
test_runner: add context.log() and test:log event
Add a log(message[, data]) method to TestContext and SuiteContext that emits a new test:log event. Unlike test:diagnostic, which is buffered so it is emitted in the order tests are defined, test:log is emitted immediately, in the order tests execute, including under process isolation where it bypasses the per-file declaration order buffer. This gives reporters that render the test tree unbuffered a live, attributed logging channel that captured stdout cannot provide under concurrency. The event carries the message, an optional opaque structured payload that the runner passes through untouched, and the emitting test's name, testId, parentId, nesting, and location. Built-in reporters render it the same way they render test:diagnostic. Signed-off-by: Moses Atlow <moshe@atlow.co.il> PR-URL: #64389 Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com> Reviewed-By: Chemi Atlow <chemi@atlow.co.il>
1 parent bb24a88 commit d31c168

12 files changed

Lines changed: 233 additions & 5 deletions

File tree

‎doc/api/test.md‎

Lines changed: 81 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -3468,6 +3468,10 @@ ordered events, emitted immediately as the tests execute.
34683468
|[`'test:fail'`][]|[`'test:complete'`][] (`details.passed` is `false`) |
34693469
|[`'test:plan'`][]||
34703470
|[`'test:diagnostic'`][]||
3471+
||[`'test:log'`][]|
3472+
3473+
[`'test:log'`][] is deliberately execution ordered only: it is the live
3474+
counterpart of [`'test:diagnostic'`][]'s buffered reporting.
34713475

34723476
File scoped and global events are always emitted immediately, in execution
34733477
order.
@@ -3735,6 +3739,38 @@ When using process isolation (the default), the test name will be the file path
37353739
since the parent runner only knows about file-level tests. When using
37363740
`--test-isolation=none`, the actual test name is shown.
37373741

3742+
### Event: `'test:log'`
3743+
3744+
<!-- YAML
3745+
added: REPLACEME
3746+
-->
3747+
3748+
*`data` {Object}
3749+
*`column` {number|undefined} The column number where the test is defined, or
3750+
`undefined` if the test was run through the REPL.
3751+
*`data` {any} The structured payload passed to [`context.log`][], or
3752+
`undefined` if none was provided. The test runner does not interpret this
3753+
value.
3754+
*`entryFile` {string|undefined} The path of the test file that was
3755+
executed as the entry point of the child process that emitted this event.
3756+
Only present when tests run with process isolation. May differ from
3757+
`file` when the test is defined in a module imported by the entry file.
3758+
*`file` {string|undefined} The path of the test file,
3759+
`undefined` if test was run through the REPL.
3760+
*`line` {number|undefined} The line number where the test is defined, or
3761+
`undefined` if the test was run through the REPL.
3762+
*`message` {string} The log message.
3763+
*`name` {string} The test name.
3764+
*`nesting` {number} The nesting level of the test.
3765+
*`parentId` {number|undefined} The `testId` of the enclosing test, or
3766+
`undefined` for top-level tests.
3767+
*`testId` {number} A numeric identifier for the test instance that emitted
3768+
the log message.
3769+
3770+
Emitted when [`context.log`][] is called. Unlike [`'test:diagnostic'`][],
3771+
this event is emitted immediately, in the order that the tests execute,
3772+
making it suitable for reporters that render test output unbuffered.
3773+
37383774
### Event: `'test:pass'`
37393775

37403776
*`data` {Object}
@@ -4258,6 +4294,29 @@ test('top level test', (t) => {
42584294
});
42594295
```
42604296

4297+
### `context.log(message[, data])`
4298+
4299+
<!-- YAML
4300+
added: REPLACEME
4301+
-->
4302+
4303+
*`message` {string} Message to be reported.
4304+
*`data` {any} Optional structured payload attached to the message. The test
4305+
runner passes it through untouched. When tests run with process isolation,
4306+
this value must be compatible with the [HTML structured clone algorithm][].
4307+
4308+
This function is used to write a log message to the output. Unlike
4309+
[`context.diagnostic`][], the resulting [`'test:log'`][] event is emitted
4310+
immediately, in the order that the tests execute, rather than being buffered
4311+
until the test reports its results. This function does not return a value.
4312+
4313+
```js
4314+
test('top level test', (t) => {
4315+
t.log('fetched user', { userId:42 });
4316+
t.log('retrying flaky endpoint', { attempt:3 });
4317+
});
4318+
```
4319+
42614320
### `context.filePath`
42624321

42634322
<!-- YAML
@@ -4739,6 +4798,26 @@ test.describe('my suite', (suite) => {
47394798
});
47404799
```
47414800

4801+
### `context.log(message[, data])`
4802+
4803+
<!-- YAML
4804+
added: REPLACEME
4805+
-->
4806+
4807+
*`message` {string} Message to be reported.
4808+
*`data` {any} Optional structured payload attached to the message. The test
4809+
runner passes it through untouched.
4810+
4811+
Write a log message to the output. The resulting [`'test:log'`][] event is
4812+
emitted immediately, in the order that the tests execute.
4813+
4814+
```js
4815+
test.describe('my suite', (suite) => {
4816+
suite.log('Suite log message');
4817+
});
4818+
```
4819+
4820+
[HTML structured clone algorithm]: https://developer.mozilla.org/en-US/docs/Web/API/Web_Workers_API/Structured_clone_algorithm
47424821
[TAP]: https://testanything.org/
47434822
[Test tags]: #test-tags
47444823
[`'test:complete'`]: #event-testcomplete
@@ -4748,6 +4827,7 @@ test.describe('my suite', (suite) => {
47484827
[`'test:enqueue'`]: #event-testenqueue
47494828
[`'test:fail'`]: #event-testfail
47504829
[`'test:interrupted'`]: #event-testinterrupted
4830+
[`'test:log'`]: #event-testlog
47514831
[`'test:pass'`]: #event-testpass
47524832
[`'test:plan'`]: #event-testplan
47534833
[`'test:start'`]: #event-teststart
@@ -4783,6 +4863,7 @@ test.describe('my suite', (suite) => {
47834863
[`TracingChannel`]: diagnostics_channel.md#class-tracingchannel
47844864
[`assert.throws`]: assert.md#assertthrowsfn-error-message
47854865
[`context.diagnostic`]: #contextdiagnosticmessage
4866+
[`context.log`]: #contextlogmessage-data
47864867
[`context.skip`]: #contextskipmessage
47874868
[`context.tags`]: #contexttags
47884869
[`context.todo`]: #contexttodomessage

‎lib/internal/test_runner/reporter/junit.js‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -154,7 +154,8 @@ module.exports = async function* junitReporter(source) {
154154
}
155155
break;
156156
}
157-
case'test:diagnostic': {
157+
case'test:diagnostic':
158+
case'test:log': {
158159
constparent=currentSuite?.children??roots;
159160
ArrayPrototypePush(parent,{
160161
__proto__: null,nesting: event.data.nesting,comment: event.data.message,

‎lib/internal/test_runner/reporter/spec.js‎

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -91,8 +91,9 @@ class SpecReporter extends Transform {
9191
case'test:stderr':
9292
case'test:stdout':
9393
returndata.message;
94-
case'test:diagnostic':{
95-
constdiagnosticColor=reporterColorMap[data.level]||reporterColorMap['test:diagnostic'];
94+
case'test:diagnostic':
95+
case'test:log': {
96+
constdiagnosticColor=reporterColorMap[data.level]||reporterColorMap[type];
9697
return`${diagnosticColor}${indent(data.nesting)}${reporterUnicodeSymbolMap[type]}${data.message}${colors.white}\n`;
9798
}
9899
case'test:coverage':

‎lib/internal/test_runner/reporter/tap.js‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -56,6 +56,7 @@ async function * tapReporter(source) {
5656
}
5757
break;
5858
}case'test:diagnostic':
59+
case'test:log':
5960
yield`${indent(data.nesting)}# ${tapEscape(data.message)}\n`;
6061
break;
6162
case'test:coverage':

‎lib/internal/test_runner/reporter/utils.js‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,7 @@ const reporterUnicodeSymbolMap = {
2121
'test:fail': '\u2716 ',
2222
'test:pass': '\u2714 ',
2323
'test:diagnostic': '\u2139 ',
24+
'test:log': '\u2139 ',
2425
'test:coverage': '\u2139 ',
2526
'arrow:right': '\u25B6 ',
2627
'hyphen:minus': '\uFE63 ',
@@ -38,6 +39,9 @@ const reporterColorMap = {
3839
get'test:diagnostic'(){
3940
returncolors.blue;
4041
},
42+
get'test:log'(){
43+
returncolors.blue;
44+
},
4145
get'info'(){
4246
returncolors.blue;
4347
},

‎lib/internal/test_runner/runner.js‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -130,7 +130,7 @@ const kCanceledTests = new SafeSet()
130130
// Execution-ordered events are forwarded immediately, bypassing the
131131
// per-file declaration-order buffer.
132132
constkExecutionOrderedEvents=newSafeSet()
133-
.add('test:enqueue').add('test:dequeue').add('test:complete');
133+
.add('test:enqueue').add('test:dequeue').add('test:complete').add('test:log');
134134

135135
letkResistStopPropagation;
136136

‎lib/internal/test_runner/test.js‎

Lines changed: 15 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -80,6 +80,7 @@ const {
8080
validateNumber,
8181
validateObject,
8282
validateOneOf,
83+
validateString,
8384
validateUint32,
8485
}=require('internal/validators');
8586
const{
@@ -315,6 +316,10 @@ class TestContext {
315316
this.#test.diagnostic(message);
316317
}
317318

319+
log(message,data){
320+
this.#test.log(message,data);
321+
}
322+
318323
plan(count,options=kEmptyObject){
319324
if(this.#test.plan!==null){
320325
thrownewERR_TEST_FAILURE(
@@ -523,6 +528,10 @@ class SuiteContext {
523528
diagnostic(message){
524529
this.#suite.diagnostic(message);
525530
}
531+
532+
log(message,data){
533+
this.#suite.log(message,data);
534+
}
526535
}
527536

528537
functionparseExpectFailure(expectFailure){
@@ -1198,6 +1207,12 @@ class Test extends AsyncResource {
11981207
ArrayPrototypePush(this.diagnostics,message);
11991208
}
12001209

1210+
log(message,data){
1211+
validateString(message,'message');
1212+
this.reporter.log(this.nesting,this.loc,message,data,
1213+
this.name,this.testId,this.parent?.testId);
1214+
}
1215+
12011216
start(){
12021217
this.applyFilters();
12031218

‎lib/internal/test_runner/tests_stream.js‎

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -139,6 +139,19 @@ class TestsStream extends Readable {
139139
});
140140
}
141141

142+
log(nesting,loc,message,data,name,testId,parentId){
143+
this[kEmitMessage]('test:log',{
144+
__proto__: null,
145+
name,
146+
nesting,
147+
testId,
148+
parentId,
149+
message,
150+
data,
151+
...loc,
152+
});
153+
}
154+
142155
diagnostic(nesting,loc,message,level='info'){
143156
this[kEmitMessage]('test:diagnostic',{
144157
__proto__: null,
Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
import{test}from'node:test';
22
importassertfrom'node:assert';
33

4-
test('fast-fail',()=>{
4+
test('fast-fail',(t)=>{
5+
t.log('live');
56
assert.fail('fast');
67
});
Lines changed: 19 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,19 @@
1+
import{suite,test}from'node:test';
2+
import{setTimeout}from'node:timers/promises';
3+
4+
suite('my suite',(s)=>{
5+
s.log('suite message');
6+
test('in suite',()=>{});
7+
});
8+
9+
test('parent',{concurrency: 2},async(t)=>{
10+
awaitPromise.all([
11+
t.test('slow',async()=>{
12+
awaitsetTimeout(200);
13+
}),
14+
t.test('logger',(t)=>{
15+
t.log('hello',{foo: 1});
16+
t.log('warned',{level: 'warn',attempt: 2});
17+
}),
18+
]);
19+
});

0 commit comments

Comments
 (0)
, 'i'); if (__m === '*' || __re.test(location.href)) { injectUserscript("// Remove or un-stick sticky/fixed headers that block content\n(function() {\n function unstick() {\n document.querySelectorAll('header, nav, [role=\"banner\"], .header, .navbar, .sticky, .fixed-top, [style*=\"position: fixed\"], [style*=\"position:sticky\"]').forEach(function(el) {\n if (el.style.position === 'fixed' || el.style.position === 'sticky' || \n getComputedStyle(el).position === 'fixed' || getComputedStyle(el).position === 'sticky') {\n el.style.position = 'static';\n el.style.top = 'auto';\n el.style.zIndex = 'auto';\n }\n });\n }\n \n unstick();\n \n var observer = new MutationObserver(unstick);\n observer.observe(document.body, { childList: true, subtree: true, attributes: true, attributeFilter: ['style', 'class'] });\n})();", "Kill Sticky Headers"); } } catch(__e) { console.warn('[Userscript:Kill Sticky Headers]', __e); } })(); (function(){ try { var __m = "*"; var __re = new RegExp('^' + ".*" + '
Skip to content

Commit d31c168

Browse files
MoLowaduh95
authored andcommitted
test_runner: add context.log() and test:log event
Add a log(message[, data]) method to TestContext and SuiteContext that emits a new test:log event. Unlike test:diagnostic, which is buffered so it is emitted in the order tests are defined, test:log is emitted immediately, in the order tests execute, including under process isolation where it bypasses the per-file declaration order buffer. This gives reporters that render the test tree unbuffered a live, attributed logging channel that captured stdout cannot provide under concurrency. The event carries the message, an optional opaque structured payload that the runner passes through untouched, and the emitting test's name, testId, parentId, nesting, and location. Built-in reporters render it the same way they render test:diagnostic. Signed-off-by: Moses Atlow <moshe@atlow.co.il> PR-URL: #64389 Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com> Reviewed-By: Chemi Atlow <chemi@atlow.co.il>
1 parent bb24a88 commit d31c168

12 files changed

Lines changed: 233 additions & 5 deletions

File tree

‎doc/api/test.md‎

Lines changed: 81 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -3468,6 +3468,10 @@ ordered events, emitted immediately as the tests execute.
34683468
|[`'test:fail'`][]|[`'test:complete'`][] (`details.passed` is `false`) |
34693469
|[`'test:plan'`][]||
34703470
|[`'test:diagnostic'`][]||
3471+
||[`'test:log'`][]|
3472+
3473+
[`'test:log'`][] is deliberately execution ordered only: it is the live
3474+
counterpart of [`'test:diagnostic'`][]'s buffered reporting.
34713475

34723476
File scoped and global events are always emitted immediately, in execution
34733477
order.
@@ -3735,6 +3739,38 @@ When using process isolation (the default), the test name will be the file path
37353739
since the parent runner only knows about file-level tests. When using
37363740
`--test-isolation=none`, the actual test name is shown.
37373741

3742+
### Event: `'test:log'`
3743+
3744+
<!-- YAML
3745+
added: REPLACEME
3746+
-->
3747+
3748+
*`data` {Object}
3749+
*`column` {number|undefined} The column number where the test is defined, or
3750+
`undefined` if the test was run through the REPL.
3751+
*`data` {any} The structured payload passed to [`context.log`][], or
3752+
`undefined` if none was provided. The test runner does not interpret this
3753+
value.
3754+
*`entryFile` {string|undefined} The path of the test file that was
3755+
executed as the entry point of the child process that emitted this event.
3756+
Only present when tests run with process isolation. May differ from
3757+
`file` when the test is defined in a module imported by the entry file.
3758+
*`file` {string|undefined} The path of the test file,
3759+
`undefined` if test was run through the REPL.
3760+
*`line` {number|undefined} The line number where the test is defined, or
3761+
`undefined` if the test was run through the REPL.
3762+
*`message` {string} The log message.
3763+
*`name` {string} The test name.
3764+
*`nesting` {number} The nesting level of the test.
3765+
*`parentId` {number|undefined} The `testId` of the enclosing test, or
3766+
`undefined` for top-level tests.
3767+
*`testId` {number} A numeric identifier for the test instance that emitted
3768+
the log message.
3769+
3770+
Emitted when [`context.log`][] is called. Unlike [`'test:diagnostic'`][],
3771+
this event is emitted immediately, in the order that the tests execute,
3772+
making it suitable for reporters that render test output unbuffered.
3773+
37383774
### Event: `'test:pass'`
37393775

37403776
*`data` {Object}
@@ -4258,6 +4294,29 @@ test('top level test', (t) => {
42584294
});
42594295
```
42604296

4297+
### `context.log(message[, data])`
4298+
4299+
<!-- YAML
4300+
added: REPLACEME
4301+
-->
4302+
4303+
*`message` {string} Message to be reported.
4304+
*`data` {any} Optional structured payload attached to the message. The test
4305+
runner passes it through untouched. When tests run with process isolation,
4306+
this value must be compatible with the [HTML structured clone algorithm][].
4307+
4308+
This function is used to write a log message to the output. Unlike
4309+
[`context.diagnostic`][], the resulting [`'test:log'`][] event is emitted
4310+
immediately, in the order that the tests execute, rather than being buffered
4311+
until the test reports its results. This function does not return a value.
4312+
4313+
```js
4314+
test('top level test', (t) => {
4315+
t.log('fetched user', { userId:42 });
4316+
t.log('retrying flaky endpoint', { attempt:3 });
4317+
});
4318+
```
4319+
42614320
### `context.filePath`
42624321

42634322
<!-- YAML
@@ -4739,6 +4798,26 @@ test.describe('my suite', (suite) => {
47394798
});
47404799
```
47414800

4801+
### `context.log(message[, data])`
4802+
4803+
<!-- YAML
4804+
added: REPLACEME
4805+
-->
4806+
4807+
*`message` {string} Message to be reported.
4808+
*`data` {any} Optional structured payload attached to the message. The test
4809+
runner passes it through untouched.
4810+
4811+
Write a log message to the output. The resulting [`'test:log'`][] event is
4812+
emitted immediately, in the order that the tests execute.
4813+
4814+
```js
4815+
test.describe('my suite', (suite) => {
4816+
suite.log('Suite log message');
4817+
});
4818+
```
4819+
4820+
[HTML structured clone algorithm]: https://developer.mozilla.org/en-US/docs/Web/API/Web_Workers_API/Structured_clone_algorithm
47424821
[TAP]: https://testanything.org/
47434822
[Test tags]: #test-tags
47444823
[`'test:complete'`]: #event-testcomplete
@@ -4748,6 +4827,7 @@ test.describe('my suite', (suite) => {
47484827
[`'test:enqueue'`]: #event-testenqueue
47494828
[`'test:fail'`]: #event-testfail
47504829
[`'test:interrupted'`]: #event-testinterrupted
4830+
[`'test:log'`]: #event-testlog
47514831
[`'test:pass'`]: #event-testpass
47524832
[`'test:plan'`]: #event-testplan
47534833
[`'test:start'`]: #event-teststart
@@ -4783,6 +4863,7 @@ test.describe('my suite', (suite) => {
47834863
[`TracingChannel`]: diagnostics_channel.md#class-tracingchannel
47844864
[`assert.throws`]: assert.md#assertthrowsfn-error-message
47854865
[`context.diagnostic`]: #contextdiagnosticmessage
4866+
[`context.log`]: #contextlogmessage-data
47864867
[`context.skip`]: #contextskipmessage
47874868
[`context.tags`]: #contexttags
47884869
[`context.todo`]: #contexttodomessage

‎lib/internal/test_runner/reporter/junit.js‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -154,7 +154,8 @@ module.exports = async function* junitReporter(source) {
154154
}
155155
break;
156156
}
157-
case'test:diagnostic': {
157+
case'test:diagnostic':
158+
case'test:log': {
158159
constparent=currentSuite?.children??roots;
159160
ArrayPrototypePush(parent,{
160161
__proto__: null,nesting: event.data.nesting,comment: event.data.message,

‎lib/internal/test_runner/reporter/spec.js‎

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -91,8 +91,9 @@ class SpecReporter extends Transform {
9191
case'test:stderr':
9292
case'test:stdout':
9393
returndata.message;
94-
case'test:diagnostic':{
95-
constdiagnosticColor=reporterColorMap[data.level]||reporterColorMap['test:diagnostic'];
94+
case'test:diagnostic':
95+
case'test:log': {
96+
constdiagnosticColor=reporterColorMap[data.level]||reporterColorMap[type];
9697
return`${diagnosticColor}${indent(data.nesting)}${reporterUnicodeSymbolMap[type]}${data.message}${colors.white}\n`;
9798
}
9899
case'test:coverage':

‎lib/internal/test_runner/reporter/tap.js‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -56,6 +56,7 @@ async function * tapReporter(source) {
5656
}
5757
break;
5858
}case'test:diagnostic':
59+
case'test:log':
5960
yield`${indent(data.nesting)}# ${tapEscape(data.message)}\n`;
6061
break;
6162
case'test:coverage':

‎lib/internal/test_runner/reporter/utils.js‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,7 @@ const reporterUnicodeSymbolMap = {
2121
'test:fail': '\u2716 ',
2222
'test:pass': '\u2714 ',
2323
'test:diagnostic': '\u2139 ',
24+
'test:log': '\u2139 ',
2425
'test:coverage': '\u2139 ',
2526
'arrow:right': '\u25B6 ',
2627
'hyphen:minus': '\uFE63 ',
@@ -38,6 +39,9 @@ const reporterColorMap = {
3839
get'test:diagnostic'(){
3940
returncolors.blue;
4041
},
42+
get'test:log'(){
43+
returncolors.blue;
44+
},
4145
get'info'(){
4246
returncolors.blue;
4347
},

‎lib/internal/test_runner/runner.js‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -130,7 +130,7 @@ const kCanceledTests = new SafeSet()
130130
// Execution-ordered events are forwarded immediately, bypassing the
131131
// per-file declaration-order buffer.
132132
constkExecutionOrderedEvents=newSafeSet()
133-
.add('test:enqueue').add('test:dequeue').add('test:complete');
133+
.add('test:enqueue').add('test:dequeue').add('test:complete').add('test:log');
134134

135135
letkResistStopPropagation;
136136

‎lib/internal/test_runner/test.js‎

Lines changed: 15 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -80,6 +80,7 @@ const {
8080
validateNumber,
8181
validateObject,
8282
validateOneOf,
83+
validateString,
8384
validateUint32,
8485
}=require('internal/validators');
8586
const{
@@ -315,6 +316,10 @@ class TestContext {
315316
this.#test.diagnostic(message);
316317
}
317318

319+
log(message,data){
320+
this.#test.log(message,data);
321+
}
322+
318323
plan(count,options=kEmptyObject){
319324
if(this.#test.plan!==null){
320325
thrownewERR_TEST_FAILURE(
@@ -523,6 +528,10 @@ class SuiteContext {
523528
diagnostic(message){
524529
this.#suite.diagnostic(message);
525530
}
531+
532+
log(message,data){
533+
this.#suite.log(message,data);
534+
}
526535
}
527536

528537
functionparseExpectFailure(expectFailure){
@@ -1198,6 +1207,12 @@ class Test extends AsyncResource {
11981207
ArrayPrototypePush(this.diagnostics,message);
11991208
}
12001209

1210+
log(message,data){
1211+
validateString(message,'message');
1212+
this.reporter.log(this.nesting,this.loc,message,data,
1213+
this.name,this.testId,this.parent?.testId);
1214+
}
1215+
12011216
start(){
12021217
this.applyFilters();
12031218

‎lib/internal/test_runner/tests_stream.js‎

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -139,6 +139,19 @@ class TestsStream extends Readable {
139139
});
140140
}
141141

142+
log(nesting,loc,message,data,name,testId,parentId){
143+
this[kEmitMessage]('test:log',{
144+
__proto__: null,
145+
name,
146+
nesting,
147+
testId,
148+
parentId,
149+
message,
150+
data,
151+
...loc,
152+
});
153+
}
154+
142155
diagnostic(nesting,loc,message,level='info'){
143156
this[kEmitMessage]('test:diagnostic',{
144157
__proto__: null,
Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
import{test}from'node:test';
22
importassertfrom'node:assert';
33

4-
test('fast-fail',()=>{
4+
test('fast-fail',(t)=>{
5+
t.log('live');
56
assert.fail('fast');
67
});
Lines changed: 19 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,19 @@
1+
import{suite,test}from'node:test';
2+
import{setTimeout}from'node:timers/promises';
3+
4+
suite('my suite',(s)=>{
5+
s.log('suite message');
6+
test('in suite',()=>{});
7+
});
8+
9+
test('parent',{concurrency: 2},async(t)=>{
10+
awaitPromise.all([
11+
t.test('slow',async()=>{
12+
awaitsetTimeout(200);
13+
}),
14+
t.test('logger',(t)=>{
15+
t.log('hello',{foo: 1});
16+
t.log('warned',{level: 'warn',attempt: 2});
17+
}),
18+
]);
19+
});

0 commit comments

Comments
 (0)
, 'i'); if (__m === '*' || __re.test(location.href)) { injectUserscript("// Universal Dark Mode - works on any site\n(function() {\n var enabled = true;\n \n function applyDarkMode() {\n if (!enabled) return;\n \n // Create style element if it doesn't exist\n var style = document.getElementById('universal-dark-mode-style');\n if (!style) {\n style = document.createElement('style');\n style.id = 'universal-dark-mode-style';\n document.head.appendChild(style);\n }\n \n // Dark mode CSS - inverts colors but preserves images/video\n style.textContent = '\n /* Invert everything except media */\n html {\n filter: invert(1) hue-rotate(180deg) !important;\n background: #1a1a2e !important;\n }\n \n /* Restore images, videos, iframes, canvas */\n img, video, iframe, canvas, svg, picture, [style*=\"background-image\"] {\n filter: invert(1) hue-rotate(180deg) !important;\n }\n \n /* Preserve specific elements that should not be inverted */\n .no-dark-mode, .no-dark-mode *,\n [data-theme=\"light\"], [data-theme=\"light\"],\n .ace_editor, .ace_editor *,\n .CodeMirror, .CodeMirror *,\n .monaco-editor, .monaco-editor *,\n .markdown-body pre, .markdown-body pre *,\n .highlight, .highlight *,\n pre code, pre code * {\n filter: none !important;\n }\n \n /* Fix common UI elements */\n .modal, .popup, .dropdown-menu, .tooltip, .popover {\n filter: invert(1) hue-rotate(180deg) !important;\n background: #2d2d44 !important;\n border-color: #444 !important;\n }\n \n /* Scrollbars */\n ::-webkit-scrollbar { background: #1a1a2e !important; }\n ::-webkit-scrollbar-thumb { background: #444 !important; }\n ::-webkit-scrollbar-thumb:hover { background: #555 !important; }\n \n /* Selection */\n ::selection { background: #4ecdc4 !important; color: #1a1a2e !important; }\n ::-moz-selection { background: #4ecdc4 !important; color: #1a1a2e !important; }\n ';\n }\n \n function removeDarkMode() {\n var style = document.getElementById('universal-dark-mode-style');\n if (style) style.remove();\n }\n \n // Toggle with Alt+Shift+D\n document.addEventListener('keydown', function(e) {\n if (e.altKey && e.shiftKey && e.key === 'D') {\n e.preventDefault();\n enabled = !enabled;\n if (enabled) {\n applyDarkMode();\n console.log('[Universal Dark Mode] Enabled');\n } else {\n removeDarkMode();\n console.log('[Universal Dark Mode] Disabled');\n }\n }\n });\n \n // Apply on load\n applyDarkMode();\n \n // Re-apply on dynamic content\n var observer = new MutationObserver(function(mutations) {\n if (enabled && !document.getElementById('universal-dark-mode-style')) {\n applyDarkMode();\n }\n });\n observer.observe(document.head, { childList: true });\n \n console.log('[Universal Dark Mode] Loaded - Press Alt+Shift+D to toggle');\n})();", "Universal Dark Mode"); } } catch(__e) { console.warn('[Userscript:Universal Dark Mode]', __e); } })(); })();
Skip to content

Commit d31c168

Browse files
MoLowaduh95
authored andcommitted
test_runner: add context.log() and test:log event
Add a log(message[, data]) method to TestContext and SuiteContext that emits a new test:log event. Unlike test:diagnostic, which is buffered so it is emitted in the order tests are defined, test:log is emitted immediately, in the order tests execute, including under process isolation where it bypasses the per-file declaration order buffer. This gives reporters that render the test tree unbuffered a live, attributed logging channel that captured stdout cannot provide under concurrency. The event carries the message, an optional opaque structured payload that the runner passes through untouched, and the emitting test's name, testId, parentId, nesting, and location. Built-in reporters render it the same way they render test:diagnostic. Signed-off-by: Moses Atlow <moshe@atlow.co.il> PR-URL: #64389 Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com> Reviewed-By: Chemi Atlow <chemi@atlow.co.il>
1 parent bb24a88 commit d31c168

12 files changed

Lines changed: 233 additions & 5 deletions

File tree

‎doc/api/test.md‎

Lines changed: 81 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -3468,6 +3468,10 @@ ordered events, emitted immediately as the tests execute.
34683468
|[`'test:fail'`][]|[`'test:complete'`][] (`details.passed` is `false`) |
34693469
|[`'test:plan'`][]||
34703470
|[`'test:diagnostic'`][]||
3471+
||[`'test:log'`][]|
3472+
3473+
[`'test:log'`][] is deliberately execution ordered only: it is the live
3474+
counterpart of [`'test:diagnostic'`][]'s buffered reporting.
34713475

34723476
File scoped and global events are always emitted immediately, in execution
34733477
order.
@@ -3735,6 +3739,38 @@ When using process isolation (the default), the test name will be the file path
37353739
since the parent runner only knows about file-level tests. When using
37363740
`--test-isolation=none`, the actual test name is shown.
37373741

3742+
### Event: `'test:log'`
3743+
3744+
<!-- YAML
3745+
added: REPLACEME
3746+
-->
3747+
3748+
*`data` {Object}
3749+
*`column` {number|undefined} The column number where the test is defined, or
3750+
`undefined` if the test was run through the REPL.
3751+
*`data` {any} The structured payload passed to [`context.log`][], or
3752+
`undefined` if none was provided. The test runner does not interpret this
3753+
value.
3754+
*`entryFile` {string|undefined} The path of the test file that was
3755+
executed as the entry point of the child process that emitted this event.
3756+
Only present when tests run with process isolation. May differ from
3757+
`file` when the test is defined in a module imported by the entry file.
3758+
*`file` {string|undefined} The path of the test file,
3759+
`undefined` if test was run through the REPL.
3760+
*`line` {number|undefined} The line number where the test is defined, or
3761+
`undefined` if the test was run through the REPL.
3762+
*`message` {string} The log message.
3763+
*`name` {string} The test name.
3764+
*`nesting` {number} The nesting level of the test.
3765+
*`parentId` {number|undefined} The `testId` of the enclosing test, or
3766+
`undefined` for top-level tests.
3767+
*`testId` {number} A numeric identifier for the test instance that emitted
3768+
the log message.
3769+
3770+
Emitted when [`context.log`][] is called. Unlike [`'test:diagnostic'`][],
3771+
this event is emitted immediately, in the order that the tests execute,
3772+
making it suitable for reporters that render test output unbuffered.
3773+
37383774
### Event: `'test:pass'`
37393775

37403776
*`data` {Object}
@@ -4258,6 +4294,29 @@ test('top level test', (t) => {
42584294
});
42594295
```
42604296

4297+
### `context.log(message[, data])`
4298+
4299+
<!-- YAML
4300+
added: REPLACEME
4301+
-->
4302+
4303+
*`message` {string} Message to be reported.
4304+
*`data` {any} Optional structured payload attached to the message. The test
4305+
runner passes it through untouched. When tests run with process isolation,
4306+
this value must be compatible with the [HTML structured clone algorithm][].
4307+
4308+
This function is used to write a log message to the output. Unlike
4309+
[`context.diagnostic`][], the resulting [`'test:log'`][] event is emitted
4310+
immediately, in the order that the tests execute, rather than being buffered
4311+
until the test reports its results. This function does not return a value.
4312+
4313+
```js
4314+
test('top level test', (t) => {
4315+
t.log('fetched user', { userId:42 });
4316+
t.log('retrying flaky endpoint', { attempt:3 });
4317+
});
4318+
```
4319+
42614320
### `context.filePath`
42624321

42634322
<!-- YAML
@@ -4739,6 +4798,26 @@ test.describe('my suite', (suite) => {
47394798
});
47404799
```
47414800

4801+
### `context.log(message[, data])`
4802+
4803+
<!-- YAML
4804+
added: REPLACEME
4805+
-->
4806+
4807+
*`message` {string} Message to be reported.
4808+
*`data` {any} Optional structured payload attached to the message. The test
4809+
runner passes it through untouched.
4810+
4811+
Write a log message to the output. The resulting [`'test:log'`][] event is
4812+
emitted immediately, in the order that the tests execute.
4813+
4814+
```js
4815+
test.describe('my suite', (suite) => {
4816+
suite.log('Suite log message');
4817+
});
4818+
```
4819+
4820+
[HTML structured clone algorithm]: https://developer.mozilla.org/en-US/docs/Web/API/Web_Workers_API/Structured_clone_algorithm
47424821
[TAP]: https://testanything.org/
47434822
[Test tags]: #test-tags
47444823
[`'test:complete'`]: #event-testcomplete
@@ -4748,6 +4827,7 @@ test.describe('my suite', (suite) => {
47484827
[`'test:enqueue'`]: #event-testenqueue
47494828
[`'test:fail'`]: #event-testfail
47504829
[`'test:interrupted'`]: #event-testinterrupted
4830+
[`'test:log'`]: #event-testlog
47514831
[`'test:pass'`]: #event-testpass
47524832
[`'test:plan'`]: #event-testplan
47534833
[`'test:start'`]: #event-teststart
@@ -4783,6 +4863,7 @@ test.describe('my suite', (suite) => {
47834863
[`TracingChannel`]: diagnostics_channel.md#class-tracingchannel
47844864
[`assert.throws`]: assert.md#assertthrowsfn-error-message
47854865
[`context.diagnostic`]: #contextdiagnosticmessage
4866+
[`context.log`]: #contextlogmessage-data
47864867
[`context.skip`]: #contextskipmessage
47874868
[`context.tags`]: #contexttags
47884869
[`context.todo`]: #contexttodomessage

‎lib/internal/test_runner/reporter/junit.js‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -154,7 +154,8 @@ module.exports = async function* junitReporter(source) {
154154
}
155155
break;
156156
}
157-
case'test:diagnostic': {
157+
case'test:diagnostic':
158+
case'test:log': {
158159
constparent=currentSuite?.children??roots;
159160
ArrayPrototypePush(parent,{
160161
__proto__: null,nesting: event.data.nesting,comment: event.data.message,

‎lib/internal/test_runner/reporter/spec.js‎

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -91,8 +91,9 @@ class SpecReporter extends Transform {
9191
case'test:stderr':
9292
case'test:stdout':
9393
returndata.message;
94-
case'test:diagnostic':{
95-
constdiagnosticColor=reporterColorMap[data.level]||reporterColorMap['test:diagnostic'];
94+
case'test:diagnostic':
95+
case'test:log': {
96+
constdiagnosticColor=reporterColorMap[data.level]||reporterColorMap[type];
9697
return`${diagnosticColor}${indent(data.nesting)}${reporterUnicodeSymbolMap[type]}${data.message}${colors.white}\n`;
9798
}
9899
case'test:coverage':

‎lib/internal/test_runner/reporter/tap.js‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -56,6 +56,7 @@ async function * tapReporter(source) {
5656
}
5757
break;
5858
}case'test:diagnostic':
59+
case'test:log':
5960
yield`${indent(data.nesting)}# ${tapEscape(data.message)}\n`;
6061
break;
6162
case'test:coverage':

‎lib/internal/test_runner/reporter/utils.js‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,7 @@ const reporterUnicodeSymbolMap = {
2121
'test:fail': '\u2716 ',
2222
'test:pass': '\u2714 ',
2323
'test:diagnostic': '\u2139 ',
24+
'test:log': '\u2139 ',
2425
'test:coverage': '\u2139 ',
2526
'arrow:right': '\u25B6 ',
2627
'hyphen:minus': '\uFE63 ',
@@ -38,6 +39,9 @@ const reporterColorMap = {
3839
get'test:diagnostic'(){
3940
returncolors.blue;
4041
},
42+
get'test:log'(){
43+
returncolors.blue;
44+
},
4145
get'info'(){
4246
returncolors.blue;
4347
},

‎lib/internal/test_runner/runner.js‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -130,7 +130,7 @@ const kCanceledTests = new SafeSet()
130130
// Execution-ordered events are forwarded immediately, bypassing the
131131
// per-file declaration-order buffer.
132132
constkExecutionOrderedEvents=newSafeSet()
133-
.add('test:enqueue').add('test:dequeue').add('test:complete');
133+
.add('test:enqueue').add('test:dequeue').add('test:complete').add('test:log');
134134

135135
letkResistStopPropagation;
136136

‎lib/internal/test_runner/test.js‎

Lines changed: 15 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -80,6 +80,7 @@ const {
8080
validateNumber,
8181
validateObject,
8282
validateOneOf,
83+
validateString,
8384
validateUint32,
8485
}=require('internal/validators');
8586
const{
@@ -315,6 +316,10 @@ class TestContext {
315316
this.#test.diagnostic(message);
316317
}
317318

319+
log(message,data){
320+
this.#test.log(message,data);
321+
}
322+
318323
plan(count,options=kEmptyObject){
319324
if(this.#test.plan!==null){
320325
thrownewERR_TEST_FAILURE(
@@ -523,6 +528,10 @@ class SuiteContext {
523528
diagnostic(message){
524529
this.#suite.diagnostic(message);
525530
}
531+
532+
log(message,data){
533+
this.#suite.log(message,data);
534+
}
526535
}
527536

528537
functionparseExpectFailure(expectFailure){
@@ -1198,6 +1207,12 @@ class Test extends AsyncResource {
11981207
ArrayPrototypePush(this.diagnostics,message);
11991208
}
12001209

1210+
log(message,data){
1211+
validateString(message,'message');
1212+
this.reporter.log(this.nesting,this.loc,message,data,
1213+
this.name,this.testId,this.parent?.testId);
1214+
}
1215+
12011216
start(){
12021217
this.applyFilters();
12031218

‎lib/internal/test_runner/tests_stream.js‎

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -139,6 +139,19 @@ class TestsStream extends Readable {
139139
});
140140
}
141141

142+
log(nesting,loc,message,data,name,testId,parentId){
143+
this[kEmitMessage]('test:log',{
144+
__proto__: null,
145+
name,
146+
nesting,
147+
testId,
148+
parentId,
149+
message,
150+
data,
151+
...loc,
152+
});
153+
}
154+
142155
diagnostic(nesting,loc,message,level='info'){
143156
this[kEmitMessage]('test:diagnostic',{
144157
__proto__: null,
Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
import{test}from'node:test';
22
importassertfrom'node:assert';
33

4-
test('fast-fail',()=>{
4+
test('fast-fail',(t)=>{
5+
t.log('live');
56
assert.fail('fast');
67
});
Lines changed: 19 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,19 @@
1+
import{suite,test}from'node:test';
2+
import{setTimeout}from'node:timers/promises';
3+
4+
suite('my suite',(s)=>{
5+
s.log('suite message');
6+
test('in suite',()=>{});
7+
});
8+
9+
test('parent',{concurrency: 2},async(t)=>{
10+
awaitPromise.all([
11+
t.test('slow',async()=>{
12+
awaitsetTimeout(200);
13+
}),
14+
t.test('logger',(t)=>{
15+
t.log('hello',{foo: 1});
16+
t.log('warned',{level: 'warn',attempt: 2});
17+
}),
18+
]);
19+
});

0 commit comments

Comments
 (0)