stderr and stdout interweave when written to different streams of the same file

[ORESoftware]

On version 6.7.x of Node.js and a new Macbook

Always had this problem, where stderr and stdout mix in the terminal, like this:

(Stdout is black, and stderr is red)

I have noticed that if I do this:

const proc = cp.spawn('node',[.]);

const strm = fs.createWriteStream('some-file-path.log');

proc.stdout.pipe(strm);
proc.stderr.pipe(strm);

then the streams don't get mixed up in the log file, since both stdout and stderr have to through the same stream before they get written, so I assume it creates more or less a single-file line before getting written out :)

Is there way to achieve that when running node how and perhaps putting stdout and stderr through the same bottleneck or something?

[Fishrock123]

aaaarrrrrgggghhhh

@ORESoftware what is stdout and stderr when this happens? a TTY (Terminal)? a Pipe? or a File?

How large is the output? Has anything set NODE_TTY_UNSAFE_ASYNC=1? (Please do not set that, it will make your problems worse.)

See #6980 for this long stream of related and largely known problems.

[ORESoftware]

it's a terminal, but I have seen the same with files (.log files). And TMK nothing has set
NODE_TTY_UNSAFE_ASYNC=1...never heard of that option.

if I do this

const strm = fs.createWriteStream('some-file-path.log');

proc.stdout.pipe(strm);
proc.stderr.pipe(strm);

then it seems to be much more consistent.

whereas if I do this:

const stdoutDest = fs.createWriteStream('some-file-path.log');
const stderrDest = fs.createWriteStream('some-file-path.log');
proc.stdout.pipe(stdoutDest);
proc.stderr.pipe(stderrDest);

output in the log file then becomes inconsistent and messed up.

I simply don't know how Node.js sets up stdout and stderr to write to the terminal, otherwise I could give you more info maybe.

[Fishrock123]

Interesting, so... that's a File, not a Terminal. I think I see what is going on though.

cc @saghul ... creating two write streams seems to chunk and interleave to the same file.

[Fishrock123]

I'll do more investigation as to the exact trigger for this but that may take a day or two.

[bnoordhuis]

creating two write streams seems to chunk and interleave to the same file.

The streams race each other unless UV_THREADPOOL_SIZE is set to 1.

[ORESoftware]

ok, I have a lead.

this only seems to happen when I use Webstorm built-in terminal

Webstorm highlights stderr as red.

Maybe I can alert them of this problem. If I see it happen in a more standard terminal, will letchall know.

[Fishrock123]

What @bnoordhuis said is about as far as we'll get. If you use separate streams to the same file, they will race eachother and you'll get this.

I think ensuring that writes are ordered though arbitrary piped streams is out of scope for node core.

[ORESoftware]

Ok, I have decided that this should be easy to fix :)

My guess is that Webstorm's built-in IDE terminal is not a proper TTY, so what happens is that stdout and stderr don't block and therefore may interleave, according to the Node.js docs.

So maybe the folks at Webstorm can somehow fake being a TTY or tell NodeJS that their built-in IDE terminal is a real TTY when it's not one.

If you think this makes sense, then maybe we can move forward to help out Webstorm users.

I have to say, built-in terminals are extremely useful, in my experience, I strongly prefer using IDEs over text editors for this reason more than any other.

[Fishrock123]

If webstorm has a terminal is needs to ensure that it makes that a pseudo tty, that is, it needs to look like a terminal to libuv.

[ORESoftware]

for sure, do you have quick links to create a pseudo TTY recognizable by Node.js / Libuv that I can share with Jetbrains so they can work on this?

[sam-github]

@ORESoftware http://man7.org/linux/man-pages/man3/openpty.3.html

[ORESoftware]

alrighty then :)