Bunyan CLI weirdly suppresses output from node's readline.prompt() - mute-stream and read therefore don't work correctly with bunyan

[sentisso]

I'm using a npm package called read for silently reading passwords from stdin. When bunyan CLI is used for parsing the output, it gets a little bit broken

Code to reprouce:

import {createLogger} from 'bunyan';
import read from "read"

export const logger = createLogger({name: 'read'})

logger.info("1) Now trying to get password via read")

read({
    prompt: "Enter password",
    silent: true // this should make sure that the text the user types remains hidden
}, (err, res) => {
    logger.info(`2) Entered password: ${res}`)
    logger.info(`3) Password has been entered`)
})

The incorrect output of the code above (notice the visible passw0rd123):

$ node build/test.js | bunyan
[2022-02-08T16:27:54.668Z] INFO: read/70020 on asd: 1) Now trying to get password via read
passw0rd123
Enter password {"name":"read","hostname":"asd","pid":70020,"level":30,"msg":"2) Entered password: passw0rd123","time":"2022-02-08T16:28:00.026Z","v":0}
[2022-02-08T16:28:00.026Z] INFO: read/70020 on asd: 3) Password has been entered

The expected output:

$ node build/test.js | bunyan
[2022-02-08T16:27:54.668Z] INFO: read/70020 on asd: 1) Now trying to get password via read
Enter password
[2022-02-08T16:28:00.026Z] INFO: read/70020 on asd: 2) Entered password: passw0rd123
[2022-02-08T16:28:00.026Z] INFO: read/70020 on asd: 3) Password has been entered

What breaks bunyan

I've looked into the read's source code and found out what part actually breaks bunyan: node's readline - .prompt().

The "error" can be reproduced with this code:

import {createLogger} from 'bunyan';
import readline from 'readline'

export const logger = createLogger({name: 'read'})

logger.info("1) Before readline")

const rl = readline.createInterface({
    input: process.stdin,
    output: process.stdout
})
rl.setPrompt("prompt text via readline")
rl.prompt()

logger.info("2) After readline")

The incorrect output of the code above:

$ node build/test.js | bunyan
[2022-02-08T16:24:55.667Z] INFO: read/69721 on asd: 1) Before readline
prompt text via readline{"name":"read","hostname":"asd","pid":69721,"level":30,"msg":"2) After readline","time":"2022-02-08T16:24:55.669Z","v":0}

The expected output:

$ node build/test.js | bunyan
[2022-02-08T16:24:55.667Z] INFO: read/69721 on asd: 1) Before readline
prompt text via readline
[2022-02-08T16:24:55.669Z] INFO: read/69721 on asd: 2) After readline

[sentisso]

Found the problem that's causing it in the bunyan CLI (bin/bunyan).

1. When the process.stdin's "data" event is fired (line 1148)
2. the line chunk that is received is split by newlines (\n or \r\n) (line 1149)
3. and then it is determined how many lines the chunk has (line 1150)
4. but the problem is when the chunk has no newlines in it (see (1) below). These "no newline chunks" get added to a "leftover" (line 1152) that will get processed somewhere in the future when the next chunk has newlines in it (line 1156 to 1163) (see (2) below).

What is the purpose of the leftover?

(1) no newline chunks are generated by readline.prompt by design because we want to let the user write in the console right after the output of the prompt, not below it
(2) chunks with a newline in them generates for example a simple console.log("asd") or bunyan's logger.info("asd") etc.

[sentisso]

A way to fix it?

Created a PR #683

1. What is the reason for the leftover when processing a stdin? I removed it in my PR, because in order to process prompts correctly, the leftover wouldn't get used at all, since we have to process the newline-less chunks immediately, please correct me if leftovers are actually needed in some cases when processing stdin.
2. I removed the forced \n's everywhere when the input is not a valid JSON nor a valid bunyan record, cause the developer may have intended not to include the newline at the end of the message that he tried to log to console
3. on the other hand I included \n's when calling handleLogLine because they got removed by the split(/\r\n|\n/), so when the line is not a valid bunyan record, there's still a newline after it when it gets emitted, because it was there originally (and if it is a valid bunyan record, it doesn't matter, cause JSON.parse will ignore the newline).

Results

var read = require('read');

const logger = bunyan.createLogger({name: 'read'})

logger.info("1) Before read")

read({
    prompt: "Enter password:",
    silent: true // this should make sure that the text the user types remains hidden
}, (err, res) => {
    logger.info(`2) Entered password: ${res}`)
    logger.info(`3) Password has been entered`)
})

The above code now performs better than before:

$ node test.js | ../bin/bunyan
[2022-02-09T20:31:27.225Z] INFO: read/57815 on asd: 1) Before read
Enter password: asd
[2022-02-09T20:31:27.882Z] INFO: read/57815 on asd: 2) Entered password: asd
[2022-02-09T20:31:27.882Z] INFO: read/57815 on asd: 3) Password has been entered

Although the password (asd) that is supposed to be hidden is still visible. This problem is a bit deeper and currently above my capacity.