[Bug]: `FORCE_COLOR` set internally leaks through to tests on Windows after upgrade to Node.js v18.17.0

[aweebit]

Version

29.6.2

Steps to reproduce

1. Install Node.js v18.17.0 on Windows.
2. Run the following commands in Git Bash:

mkdir jest-force-color
cd jest-force-color
npm install -D jest
echo 'test("color", () => expect(process.env.FORCE_COLOR).toBeUndefined());' > first.test.js
cp first.test.js second.test.js

3. Open either Git Bash, cmd or PowerShell.
4. Make sure the FORCE_COLOR environment variable is unset.
5. Run the following command:

npx jest --no-cache

Expected behavior

I expect the tests to pass.

Actual behavior

Instead, both of them fail because the value of process.env.FORCE_COLOR is '1'.

Additional context

The issue is not present when using Node.js versions prior to v18.17.0. I believe the fact it appears after the upgrade is due to nodejs/node#48034.

The upgrade broke tests in tj/commander.js checking the output of node child processes, and it was quite hard to figure out what the reason was.

Environment

System:
  OS: Windows 10 10.0.19045
  CPU: (8) x64 Intel(R) Core(TM) i7-8550U CPU @ 1.80GHz
Binaries:
  Node: 18.17.0 - C:\Program Files\nodejs\node.EXE
  Yarn: 1.22.19 - C:\Program Files (x86)\Yarn\bin\yarn.CMD
  npm: 9.8.1 - C:\Program Files\nodejs\npm.CMD
npmPackages:
  jest: ^29.6.2 => 29.6.2

[shadowspawn]

I was able to reproduce some unexpected test failures on Mac too, when I upgraded Node to v18.17.0.

A trigger might be tests running in parallel. The failures I was seeing went away when I tried npx jest --runInBand.

[mrazauskas]

--runInBand is not using workers, so I guess the problem originates from these lines:

jest/packages/jest-worker/src/workers/ChildProcessWorker.ts

Line 11 in 0fd5b1c

import {stdout as stdoutSupportsColor} from 'supports-color';

jest/packages/jest-worker/src/workers/ChildProcessWorker.ts

Line 116 in 0fd5b1c

const forceColor = stdoutSupportsColor ? {FORCE_COLOR: '1'} : {};

jest/packages/jest-worker/src/workers/ChildProcessWorker.ts

Lines 130 to 145 in 0fd5b1c

	const options: ForkOptions = {
	cwd: process.cwd(),
	env: {
	...process.env,
	JEST_WORKER_ID: String(this._options.workerId + 1), // 0-indexed workerId, 1-indexed JEST_WORKER_ID
	...forceColor,
	},
	// Suppress --debug / --inspect flags while preserving others (like --harmony).
	execArgv: process.execArgv.filter(v => !/^--(debug|inspect)/.test(v)),
	// default to advanced serialization in order to match worker threads
	serialization: 'advanced',
	silent,
	...this._options.forkOptions,
	};
	this._child = fork(this._childWorkerPath, [], options);

I had similar issue while testing a CLI tool. If I recall it right, all this is needed because of limitations of child process and chalk. argv is not passed to child processes, so this mechanism is here to pass the --colors flag to chalk. (Jest does not consume --colors internally.)

The problem I was facing: supports-color does not respect NO_COLOR environment variable, which is respected by Node.

At first I thought it would be enough to use worker threads (argv is not an issue in this case). This is why the workerThreads configuration option was added in #13939. Experimental! Use with caution.

---

Other part of issue was related with vscode-jest. See jest-community/vscode-jest#971. Mentioning it here because of tj/commander.js#1950 (comment).

---

In the end my solution was to use MYAPP_NO_COLOR environment variable. This always works. Not sure if that is helpful for you.

[mrazauskas]

Probably it would be the best to remove --color and --colors flags and the logic around supports-color in the next major. This would allow keeping environment variables untouched.

EDIT More motivation: color support is about the environment and this piece of data must be known before the app starts. E.g., jest --no-colrs will throw validation error. Should the message use colors or not?

[aweebit]

Probably it would be the best to remove --color and --colors flags and the logic around supports-color in the next major. This would allow keeping environment variables untouched.

From a quick look at just the ChildProcessWorker.ts file, it might be a better idea to move the logic around supports-color to the place where the worker is constructed and set JEST_FORCE_COLOR instead of FORCE_COLOR there, then use the value in the child process to decide whether to pass --colors to chalk.

[mrazauskas]

The trick is that --colors is not passed anywhere and does not exist in Jest’s logic at all. chalk simply checks if --colors (or any numerous variation of it) is present in process.argv. It is using supports-color to do that, if I am not mistaken.

[aweebit]

chalk.level could be used then.

This seems to work perfectly:

// program.js
console.log([ 123, 'abc', () => {} ]);

// child.mjs
import { execFile } from 'node:child_process';
import { promisify } from 'node:util';
const execFileAsync = promisify(execFile);

import { Chalk } from 'chalk';

const { JEST_CHALK_LEVEL } = process.env;
const chalk = new Chalk({ level: +JEST_CHALK_LEVEL });

console.log(chalk.blue('Hello world!'));
const { stdout } = await execFileAsync('node', ['program.js']);
console.log(stdout);

// parent.mjs
import { fork } from 'node:child_process';
import { supportsColor } from 'chalk';

const JEST_CHALK_LEVEL = supportsColor ? String(supportsColor.level) : '0';
const env = { ...process.env, JEST_CHALK_LEVEL };
fork('child.mjs', [], { env });

Tested with:

node parent.mjs # 'Hello world!' in color
FORCE_COLOR=1 node parent.mjs # everything in color
node parent.mjs --no-color # no color

[aweebit]

Could even do

delete process.env.JEST_WORKER_ID;
delete process.env.JEST_CHALK_LEVEL;

after using the values to leave the environment untouched for tests and child processes spawned from them.

[github-actions]

This issue is stale because it has been open 30 days with no activity. Remove stale label or comment or this will be closed in 30 days.

[shadowspawn]

I'll expand a bit on the failing tests I am seeing in Commander. We do not use Chalk or any ascii text colouring in Commander or in the tests. However, stdout from executing a fixture in a child process contains the ascii escape sequence to turn the text green, which was presumably inherited somehow from Jest and/or node.

The failing test looks like

const execFileAsync = util.promisify(childProcess.execFile);

test('example failing test', async() => {
  const { stdout } = await execFileAsync('node', ['--inspect-port=9270', fixture, 'sub']);
  expect(stdout).toBe("[ '--inspect-port=127.0.0.1:9271' ]\n");
});

The fixture effectively does this:

childProcess.spawn('node', [ '--inspect-port=127.0.0.1:9271', 'sub.js'], { stdio: 'inherit' })

The final file is just:

console.log(process.execArgv);

I have not been able to reproduce the failure in a smaller setup, so I might be missing some critical step or parallel test to trigger the problem condition.