I'll preface this by admitting that I'm probably doing something I shouldn't be doing. But since I'm already this deep, I might as well understand why things are happening this way.
I am using Mocha to test some Node.js code. This code uses the Winston logging library, which directly calls process.stdout.write()
and process.stderr.write()
(source). It works well; I have no complaints about that behavior.
However, when I unit-test this code, the output of the Mocha test runner is occasionally interspersed with lines of log output, which is ugly in some reporters (dot
, bdd
) and downright invalid in others (xunit
). I wanted to block this output without modifying or subclassing Winston, and I wanted to avoid modifying the application itself if I could avoid it.
What I arrived at was a set of utility functions that can temporarily replace the Node builtins with a no-op function, and vice versa:
var stdout_write = process.stdout._write,
stderr_write = process.stderr._write;
function mute() {
process.stderr._write = process.stdout._write = function(chunk, encoding, callback) {
callback();
};
}
function unmute() {
process.stdout._write = stdout_write;
process.stderr._write = stderr_write;
}
Inside the various test specs, I called mute()
directly before any call or assertion that produced unwanted output, and unmute()
directly after. It felt a little hacky, but it worked -- not a single byte of unwanted output appeared on the console when running the tests.
Now it gets weird!
For the first time, I tried redirecting the output to a file:
mocha spec_file.js > output.txt
The unwanted output came back! Every piece of output that was sent to stdout appears in the file. Adding 2>&1
, I get stderr in the file too. Nothing appears on the console in either case, though.
Why would the test code behave so differently between the two invocations? My gut guess is that Mocha is doing some sort of test to determine whether or not it's writing to a TTY, but I couldn't spot an obvious place where it changes the behavior of its writes.
Also the broader question, is there any correct way to mute stdout/stderr during tests, without wrapping all potentially-logging app code in a conditional that checks for the test environment?
I discovered a likely cause for this behavior. It does indeed have to do with whether or not stdout/stderr is a TTY.
When the script runs in a console, these are both TTYs, and process.stdout
and process.stderr
appear to be instances of tty.WriteStream
and not, as I originally assumed, a stream.Writable
. As far as my interactions went, the two classes really weren't that different -- both had public write()
methods which called internal _write()
methods, and both shared the same method signatures.
When piped to a file, things got a little different. process.stdout
and process.stderr
were instances of a different class that wasn't immediately familiar. Best I can figure, it's a fs. SyncWriteStream
, but that's a stab in the dark. Anyway, this class doesn't have a _write()
method, so trying to override it was pointless.
The solution was to move one level higher and do my muting with write()
instead of _write()
. It does the same thing, and it does it consistently regardless of where the output is going.