Losing keystrokes when using tty.ReadStream() over process.stdin

[piranna]

• Version: checked on v0.12.10 and v4.3.2
• Platform: Ubuntu Mate 15.10, x86 32bits
• Subsystem: tty

I'm rewriting nsh as a POSIX shell for NodeOS. I create a tty.ReadStream instance using file descriptor from Readline.input, that at the same time it's initialized with process.stdin. Later I pause Readline.input, and although it doesn't emit 'data' events, if I exec an interactive command like nano or an instance of Node.js (or a recursive execution of the shell), some of the keystrokes are losed about 50% of the times (but it's random) and need to press them twice. Seems like there are several readers of stdin and someone is capturing the keystrokes that sbould end on the final command...

[jbergstroem]

Can you perhaps create a test case that applies to last 0.12.x and 4.x (branches you can reproduce on) we then can add to the test suite or similar?

[piranna]

Here you have a minimal test where you can be able to replicate the problem:

var Interface  = require('readline').Interface
var ReadStream = require('tty').ReadStream
var spawn      = require('child_process').spawn


var rl = Interface(process.stdin, process.stdout)
rl.prompt()

var input = rl.input
var stdin = ReadStream(input.fd)
input.pause()

var stdio = [stdin, rl.output]

var cp = spawn('cat', [], {stdio: stdio})

When you run it forget about the readline prompt and just start to press some keystrokes, they will go directly to the cat spawned process. As you'll see, some of them are losed and not shown, as if they has been readed by readline input stream (although it's paused). I've tried to duplicate the file descriptor using the dup function provided by src-unistd module without luck, since it seems it's already duplicated (ReadStream _handler.fd is 12).

[piranna]

I've done some more tests and simplified a little bit the test to replicate the problem:

var Interface  = require('readline').Interface
var ReadStream = require('tty').ReadStream
var spawn      = require('child_process').spawn

Interface(process.stdin, process.stdout)

var stdin = ReadStream(process.stdin.fd)
process.stdin.pause()

var stdio = [stdin, process.stdout]

spawn('cat', [], {stdio: stdio})

Things I've found so far:

• if you comment the Interface(process.stdin, process.stdout) line the code works as expected (no keystrokes are losed and cat command correctly replicates its stdin, also exit when Ctrl+D) so definitely the problem is caused by readline and probably the data event it register on its input stream, but I didn't get luck trying to inspect this (maybe it's needed some traces to exactly what data events is fetching).
• although process.stdin is paused, if you set it as stdin for the spawn function the cat command still gets its input.

[Fishrock123]

Hmmm, not seeing anything as far as I can tell. v5.7.1 & OS X 10.10.5

[stevenzeck]

Sounds similar to #5384

[piranna]

I've done some more tests: if I don't create the instance of ReadStream and instead I use process.stdin on the spawn stdio cat can be able to receive the keystrokes without problems except the control ones like new line or EOF.

It seems that we have here two important bugs, maybe related between them:

1. keystrokes can be consumed from process.stdin also if it's paused, probably because it's being directly used the file descriptor 0 bypassing the process.stdio ReadStream instance mechanism
2. readline.Interface does "something" with the input stream that makes it to consume the keystrokes although the stream it's paused and the ReadStream class duplicate the file descriptor

I was thinking in my use case to do a backup of the file descriptor 0, use it and later restore it, but probably it will not work due to ReadStream class internal status, but maybe it would be a solution for the pause problem to change the file handler for another one pointing to a closed or non existent file descriptor and later restore it when unpaused...

Hmmm, not seeing anything as far as I can tell. v5.7.1 & OS X 10.10.5

I have just checked it with Node.js v5.7.1 on Ubuntu 15.10 32 bits and I got still the problem... :-(

Sounds similar to #5384

Seems similar, but there they are loosing the first input line on Windows and here I'm losing some random chars and keystrokes on Linux. On nsh, one level works fine, if I launch inside it another one or any other interactive cli (like nano) drops are about 50% (sometimes I can write correctly 9 kyestrokes without loses, other times it doesn't get anyone), and if I launch inside a third level shell (inception ;-) ) I hardly get any keystroke at all and need to kill the process from outside.

[piranna]

Checked that the problem also exists on Node.js v4.3.2 on OS X 10.11.3 (15D21) "El Capitan", so it's not a Linux-only bug.

[piranna]

I've been able to recreate the problem in an automated test at https://gist.github.com/piranna/7dc47f387ecdcf739a19. It works by spawning a process with the code from the previous snippets and pipping to its stdin a readable stream that send characters from a string at a normal typing rate of 240 keystrokes per minute (the frequency doesn't matter, the problem happens both as slow as 60 keystrokes per minute or as fast as 120 keystrokes per second). If you exec it several times, you'll see that on each of them some random characters from the inital string (Habia una vez un circo que siempre alegraba el corazon, from a spanish popular childs song) are lost, for example i've got the next output:

 vez un circo ue siempre alegraba el corazon
Habia una vez un circo que siempe alegraba el corazon
Habia una vez un circo que sempr alegraba el corazon
Habia una vez un circo ue siempre alegraba el corazon
a vez un circo que siempre alegraba el coraon
Habia una vez un circo que siepre alegraba l crazon
Habia una vez un circo que siempre aegraba el corazon

I've also seen that although I'm sending null to set the EOS signal of the stream the test execution doesn't end because the fixture (the previous snippets code) don't allow to capture the EOS signal, so you need to end its execution by using Ctrl+C to finish the process.

Could/should this automated test be included on Node.js ones?

[santigimeno]

@piranna is the problem fixed by #5776? Also, having a test that reproduces the issue would be great.

[piranna]

@piranna is the problem fixed by #5776?

How could I do? Checkout that pull-request and compile it myself to see if it works (It's not a problem for me, just want to be sure if that's what you say)?

Also, having a test that reproduces the issue would be great.

The gist I've put in the previous comment is an automated test, although I'm not using the assert module, just checking by eye on the output that the input and output strings are different. What do you mean by "having a test"? Is it just enough to use the assert module, or do I need to do something different like include the test in Node.js unit tests and do a pull-request?

[jbergstroem]

@piranna: Yes, that's what @santigimeno is suggesting. A guide on how to apply a PR as patch can be found here (stop after patch): https://github.com/nodejs/node/blob/master/COLLABORATOR_GUIDE.md#technical-howto

..after that, compile as needed and run your code again.

[santigimeno]

How could I do? Checkout that pull-request and compile it myself to see if it works (It's not a problem for me, just want to be sure if that's what you say)?

Yes, what @jbergstroem said.

What do you mean by "having a test"? Is it just enough to use the assert module, or do I need to do something different like include the test in Node.js unit tests and do a pull-request?

I would create a new test in test/parallel folder. I would use only one file: I think https://github.com/nodejs/node/blob/master/test/parallel/test-child-process-stdio-inherit.js could be a good starting point. Notice that the common module must always be included even if it's not used. Just let me know if you need further assistance.

[piranna]

@piranna is the problem fixed by #5776?

I've follow your instruction and seems to be fixedon OS X, the string gets printed correctly without loosing any characters and the test finish itself (noCtrl+C`), but two times the last word was not written at all, that's suspicious... One thing I've seen I get the next error message:

Assertion failed: (loop->watchers[w->fd] == w), function uv__io_stop, file ../deps/uv/src/unix/core.c, line 864.

I'll try later to test it with a longer text and with the master branch to compare and be sure this behaviour is directly related to the pull-request.

[piranna]

Confirmed, #5776 fix this problem too :-D I didn't test it with a long test, but until that I'll request them to backport it to Node.js v.4.x

[piranna]

I've open a pull-request with the test for this use case.

[piranna]

I have just checked this on Ubuntu 15.10 32 bits on an Intel Core2 Duo machine with the code on master having the fix #5776 and the test on my pull-request #5841 and this error still arises... :-(

[piranna@Latitude:~/Proyectos/node/test/parallel]
 (5574) > node test-readline-interface-tty-readstream.js 
node: ../deps/uv/src/unix/core.c:864: uv__io_stop: Assertion `loop->watchers[w->fd] == w' failed.

assert.js:89
  throw new assert.AssertionError({
  ^
AssertionError: null === 0
    at ChildProcess.<anonymous> (/home/piranna/Proyectos/node/test/parallel/test-readline-interface-tty-readstream.js:57:5)
    at ChildProcess.<anonymous> (/home/piranna/Proyectos/node/test/common.js:385:15)
    at emitTwo (events.js:101:13)
    at ChildProcess.emit (events.js:186:7)
    at maybeClose (internal/child_process.js:850:16)
    at Socket.<anonymous> (internal/child_process.js:323:11)
    at emitOne (events.js:91:13)
    at Socket.emit (events.js:183:7)
    at Pipe._onclose (net.js:477:12)

[piranna@Latitude:~/Proyectos/node/test/parallel]
 (5574) > node -v
v6.0.0-pre

My previous checks where on MacOS X "El Capitan" 64 bits, so I'm not sure if it's a Linux-only issue or a 32 bits one, I'm going to do more checks to see if I'm able to replicate it on other systems to be sure.

[piranna]

Any update on this? This is still happening on Node.js v6.3.0...

[Trott]

/ping @Fishrock123. Still working on this? If not, should we un-assign it so someone else might pick it up?

[Trott]

I'm able to reproduce this problem in latest Current (11.9.0) but not on the master branch. @piranna Any chance this is fixed if you use one of the recent nightly builds? If so, then we can at least expect this to be fixed in 12.0.0.

[jasnell]

Unable to reproduce the issue now. Closing. Can reopen if necessary