From 3e485365ec04d2539bbf60a9db1296efc737a9f7 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 3f7134c6cd30cc..731f94e5b6b8f7 100644
--- a/lib/internal/test_runner/runner.js
+++ b/lib/internal/test_runner/runner.js
@@ -241,22 +241,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/);
+}