From ed9246f6fc5788154deedc943b985268fd0d09ea Mon Sep 17 00:00:00 2001
From: Colin Ihrig <cjihrig@gmail.com>
Date: Thu, 1 Dec 2022 22:12:07 -0500
Subject: [PATCH] test_runner: don't parse TAP from stderr

This commit stops the test runner CLI from parsing child
process stderr as TAP. Per the TAP spec, TAP can only come from
stdout. To avoid losing stderr data, those logs are injected
into the parser as unknown tokens so that they are output as
comments.

PR-URL: https://github.com/nodejs/node/pull/45618
Reviewed-By: Moshe Atlow <moshe@atlow.co.il>
---
 lib/internal/test_runner/runner.js     | 33 ++++++++++++++++----------
 lib/internal/util/inspector.js         |  2 +-
 test/fixtures/test-runner/user-logs.js | 20 ++++++++++++++++
 test/parallel/test-runner-cli.js       | 26 ++++++++++++++++++++
 4 files changed, 67 insertions(+), 14 deletions(-)
 create mode 100644 test/fixtures/test-runner/user-logs.js

diff --git a/lib/internal/test_runner/runner.js b/lib/internal/test_runner/runner.js
index 5fb20e3cbe5365..74cb4c150f9c5c 100644
--- a/lib/internal/test_runner/runner.js
+++ b/lib/internal/test_runner/runner.js
@@ -240,22 +240,29 @@ function runTestFile(path, root, inspectPort, filesWatcher) {
       err = error;
     });
 
-    if (isUsingInspector()) {
-      const rl = createInterface({ input: child.stderr });
-      rl.on('line', (line) => {
-        if (isInspectorMessage(line)) {
-          process.stderr.write(line + '\n');
-        }
-      });
-    }
-
-    const parser = new TapParser();
-    child.stderr.pipe(parser).on('data', (ast) => {
-      if (ast.lexeme && isInspectorMessage(ast.lexeme)) {
-        process.stderr.write(ast.lexeme + '\n');
+    const rl = createInterface({ input: child.stderr });
+    rl.on('line', (line) => {
+      if (isInspectorMessage(line)) {
+        process.stderr.write(line + '\n');
+        return;
       }
+
+      // stderr cannot be treated as TAP, per the spec. However, we want to
+      // surface stderr lines as TAP diagnostics to improve the DX. Inject
+      // each line into the test output as an unknown token as if it came
+      // from the TAP parser.
+      const node = {
+        kind: TokenKind.UNKNOWN,
+        node: {
+          value: line,
+        },
+      };
+
+      subtest.addToReport(node);
     });
 
+    const parser = new TapParser();
+
     child.stdout.pipe(parser).on('data', (ast) => {
       subtest.addToReport(ast);
     });
diff --git a/lib/internal/util/inspector.js b/lib/internal/util/inspector.js
index 038479b173ceaf..c7f18ffdb61a33 100644
--- a/lib/internal/util/inspector.js
+++ b/lib/internal/util/inspector.js
@@ -16,7 +16,7 @@ const { validatePort } = require('internal/validators');
 const kMinPort = 1024;
 const kMaxPort = 65535;
 const kInspectArgRegex = /--inspect(?:-brk|-port)?|--debug-port/;
-const kInspectMsgRegex = /Debugger listening on ws:\/\/\[?(.+?)\]?:(\d+)\/|Debugger attached|Waiting for the debugger to disconnect\.\.\./;
+const kInspectMsgRegex = /Debugger listening on ws:\/\/\[?(.+?)\]?:(\d+)\/|For help, see: https:\/\/nodejs\.org\/en\/docs\/inspector|Debugger attached|Waiting for the debugger to disconnect\.\.\./;
 
 const _isUsingInspector = new SafeWeakMap();
 function isUsingInspector(execArgv = process.execArgv) {
diff --git a/test/fixtures/test-runner/user-logs.js b/test/fixtures/test-runner/user-logs.js
new file mode 100644
index 00000000000000..c2d34328fa055d
--- /dev/null
+++ b/test/fixtures/test-runner/user-logs.js
@@ -0,0 +1,20 @@
+'use strict';
+const test = require('node:test');
+
+console.error('stderr', 1);
+
+test('a test', async () => {
+  console.error('stderr', 2);
+  await new Promise((resolve) => {
+    console.log('stdout', 3);
+    setTimeout(() => {
+      // This should not be sent to the TAP parser.
+      console.error('not ok 1 - fake test');
+      resolve();
+      console.log('stdout', 4);
+    }, 2);
+  });
+  console.error('stderr', 5);
+});
+
+console.error('stderr', 6);
diff --git a/test/parallel/test-runner-cli.js b/test/parallel/test-runner-cli.js
index ac8482c5ce69be..7407e03c875d10 100644
--- a/test/parallel/test-runner-cli.js
+++ b/test/parallel/test-runner-cli.js
@@ -168,3 +168,29 @@ const testFixtures = fixtures.path('test-runner');
   assert.match(stdout, /# pass 2/);
   assert.match(stdout, /# fail 1/);
 }
+
+{
+  // Test user logging in tests.
+  const args = [
+    '--test',
+    'test/fixtures/test-runner/user-logs.js',
+  ];
+  const child = spawnSync(process.execPath, args);
+
+  assert.strictEqual(child.status, 0);
+  assert.strictEqual(child.signal, null);
+  assert.strictEqual(child.stderr.toString(), '');
+  const stdout = child.stdout.toString();
+  assert.match(stdout, /# Subtest: .+user-logs\.js/);
+  assert.match(stdout, / {4}# stderr 1/);
+  assert.match(stdout, / {4}# stderr 2/);
+  assert.match(stdout, / {4}# stdout 3/);
+  assert.match(stdout, / {4}# stderr 6/);
+  assert.match(stdout, / {4}# not ok 1 - fake test/);
+  assert.match(stdout, / {4}# stderr 5/);
+  assert.match(stdout, / {4}# stdout 4/);
+  assert.match(stdout, / {4}# Subtest: a test/);
+  assert.match(stdout, / {4}ok 1 - a test/);
+  assert.match(stdout, /# tests 1/);
+  assert.match(stdout, /# pass 1/);
+}