Color not enabled when in a Node Worker

[ibc]

This is related to an ongoing issue/discussion in Node.js related to process.stdout and process.stderr not having isTTY === true when in a Node.js Worker thread.

This means that, if debug is used within a Worker thread, it does not print colors nor ms diff (but timestamps).

Code to reproduce it (requires Node >= 12 or Node 10 with node --experimental-worker flag):

foo.js:

process.env.DEBUG = '*';

const { Worker, parentPort, threadId, isMainThread } = require('worker_threads');
const tty = require('tty');
const debug = require('debug');

async function run()
{
	if (isMainThread)
	{
		const logger = debug('[parent]');

		logger(
			'run() in main thread [process.stderr.isTTY:%s, tty.isatty():%s]',
			process.stderr.isTTY,
			tty.isatty(process.stderr.fd));

		const worker = new Worker(__filename);

		worker.once('message', message => logger('message from child: %o', message));
		worker.postMessage('hi child!');
	}
	else
	{
		const logger = debug('[child]');

		logger(
			'run() in child thread [process.stderr.isTTY:%s, tty.isatty():%s]',
			process.stderr.isTTY,
			tty.isatty(process.stderr.fd));

		parentPort.once('message', message => logger('message from parent: %o', message));
		parentPort.postMessage('hi dad!');
	}
}

run();

Output:

$ node --experimental-worker foo.js

  [parent] run() in main thread [process.stderr.isTTY:true, tty.isatty():true] +0ms
2020-01-12T15:22:36.083Z [child] run() in child thread [process.stderr.isTTY:undefined, tty.isatty():false]
  [parent] message from child: 'hi dad!' +33ms
2020-01-12T15:22:36.085Z [child] message from parent: 'hi child!'

Of course it works if I set DEBUG_COLORS=true environment variable. Just wondering if a debug instance may expose a method to set "tty" mode.

[Qix-]

Just wondering if a debug instance may expose a method to set "tty" mode.

This is an anti-pattern, debug isn't meant to be used like this. I'd say this is a fringe case and Node should fix it on their end, not here.

[ibc]

The problem is that this may not even be "fixed" in Node. From the referenced issue:

IMO it make sense for .isTTY to be undefined because process.stdout and process.stderr in worker threads don't actually write to the TTY. They postMessage() the data to the main thread which then writes it out on the worker thread's behalf.

We could copy the .isTTY values from the main thread but that breaks the idiom where if (process.stdout.isTTY) guards are used around calls to process.stdout.setRawMode(true) or process.stdout.cursorTo() - and you can't reasonably support those APIs in worker threads because the TTY is a per-process resource.

I'd be happy by just manually setting process.stderr.isTTY = true in the Worker thread. However this won't make debug module produce colors since it looks at tty.isatty().

And another super ugly workaround is (in the top of the app):

// before loading debug and before creating Workers that also use debug.

const tty = require('tty');
if (tty.isatty(process.stderr.fd)) {
  process.env.DEBUG_COLORS = 'true';
}

[Qix-]

Why not just set your main process's environment variable to DEBUG_COLORS from outside your application? debug isn't meant to be a general purpose logging framework. It's meant to be used as an internal, switchable, runtime-configurable debug output module.

[ibc]

Right now I do NOT need to set DEBUG_COLORS. If logging to stdout, debug will produce colors (unless in Workers). If logging to a file or Docker, it won't produce colors. That's great.

So instead of setting DEBUG_COLORS externally, I must do the above hack to make colors work in Workers.

[Qix-]

Not really sure how to fix this elegantly, honestly. You have a very specific use-case where you want threads to include colors but Node is not properly forwarding the correct signals to tell the threads they can safely output escape codes. This isn't something debug can solve in a safe, general way - especially since the Node team has states they don't care to forward the isatty results to the worker threads.

Your "hack" is not a workaround for debug, but instead for node. This is their incompatibility, not ours.

[ibc]

I 100% agree this is a bug in Node, I know that. And I do not even understand their rationale to not forward the isTTY value to Workers.

Your "hack" is not a workaround for debug, but instead for node.

Right.

[Qix-]

I understand their reasoning, I just think it's a weak reason. They created a tight coupling between the environment and their code and they don't seem to want to fix it.

However, the blame isn't entirely on them. TTYs are some of the last remaining truly archaic software mechanisms still in prominent use today. I call them "archaic" because they were built in a time of serial lines, baud rates, parallel ports and dialup. The reason why your terminal is called a "terminal emulator" is because they were originally made to emulate old real terminal machines like the VT100.

Since then, not much has been done to change this in order to maintain compatibility with old systems running other, equally archaic software. Unix is a huge culprit behind this. It also leaves maintainers of TTY-related software with their hands a bit tied. It also makes output streams a living nightmare to deal with in an elegant and developer-friendly way.

Usually, a potential "solution" (such as one proposed above) will cause many others to break. It's the sad state of things, unfortunately :|

[ibc]

Thanks for the explanation.