Interactivity suffers? #58

Closed
bitprophet opened this Issue Mar 23, 2013 · 27 comments

Projects

None yet

3 participants

@bitprophet
Member

When running run("python"):

  • >>> print 'hm' prints the next line's prompt + "hm" on the same line.
    • Implies mixing of stdout/err poorly still; using print >>sys.stderr, 'hm' correctly deals w/ newlines
  • Trying to hit up-arrow for shell history prints ^[[A (control chars) instead of interacting with readline.

Neither of these problems exist when pty=True. I feel like this is the same as in Fabric and any other solution where a pty is not the default behavior. At the very least we should make this explicit in the docs, probably by making an FAQ.

@geertj
geertj commented Jul 6, 2013

Should pty=True be the default behavior?

@bitprophet
Member

@geertj - Fabric waffled on this in the past (started out with pty=False, then since 1.0 has been pty=True) and it's been problematic either way. The breakdown, IIRC:

  • Pty enabled: impossible to differentiate stdout and stderr (big!), init scripts often silently fail (less big, but still annoying).
  • Pty 'disabled' (aka "actually talking to the subprocess" :)): programs written to assume a real interactive terminal (many! :() frequently misbehave.

It comes down to average use case: if you're using this kind of tool for its programmatic benefits, you're likely to want distinct stdout/stderr, which means pty=False is cleaner and more obvious.

But if you're using it as a Make/Rake/etc replacement, you'll expect it to behave more "shelly", which here means pty=True because we can't hook the process up to your terminal's pipes (or we lose ability to capture any output at all, perform output hiding, etc.)

I can't say offhand which is more likely in the intended userbase; my gut is honestly leaning towards the make/etc replacement, meaning pty=True, and practically it would also mean less of a break with Fabric 1.x (Fabric 2.x will build on Invoke). OTOH I value the ability to become "purer" with this kind of rewrite.


As things stand this ticket is here so I make sure the above duality is documented and in peoples' face first thing if they have problems; idea being that since neither choice is perfect, go with the cleaner one (pty=False) and require folks to identify truly interactive invocations & slap pty=True on them.

Will probably poll other smart people before I go 1.0 and see if they have angles I'm not seeing.

@bitprophet bitprophet added the Feature label Aug 25, 2014
@bitprophet
Member

This may be outdated now, can't remember when exactly we got hiding+capturing working with pty=True but it definitely does now (and may do so even more cleanly post-#235). Also wondering if I was conflating the pipe hookup with the fact that pexpect is simply using the pty module (i.e., both 'versions' of our command execution are technically using shells, so the difference truly is in the use of a PTY or not.)

@bitprophet
Member

Some possible hints in the (stdin-focused) fcntl additions from this Paramiko ticket.

@bitprophet
Member

Some notes about some of this are in #289 since that ticket's implementation changed more of how streams are handled.

@bitprophet
Member

#361 notes that the use cases they're having issues with worked better under Fabric, but I have a followup question for @hjc1710:

Re: Fabric handling it, did you mean local or run? Fabric's local was "just subprocess" so it behaved better on this front, but was significantly worse an API (no ability to intercept the streams and capture at the same time, etc). If you meant run then that is more interesting because run, at a high level, is similar to Invoke's run re: all streams being directly handled.

@hjc1710
hjc1710 commented Jun 17, 2016

In answer to your question, @bitprophet, my example of Fabric handling this better was using local and not run (I linked the repo I used in my Asciinema, which is the exact code run).

It makes since that the API's are significantly different, because I distinctly remember capture=True from Fabric, not having that print output, and then having to mirror my output myself.

As stated, #361 gives my primary use case, which is I want to wrap all my unit test running in invoke, and using interactive debuggers when Invoke is wrapping your unit tests is... pretty difficult right now.

Thanks for looking into this and let me know if there's any way I can help or test!

@bitprophet
Member

Adding a note here that my 'real complex and also a thing I want to be able to launch with Invoke pretty often' use case, vim, falls under this - specific notes from #289 are in this comment and subsequent.

@bitprophet
Member
bitprophet commented Nov 7, 2016 edited

Also, it's clear that (if possible with current architecture) there should be an option to completely circumvent the "smart passthrough/stream mirroring+capturing" behavior in some situations - e.g. to do what subprocess' default behavior is re: hooking up user's terminal pipes directly to the subprocess'.

This isn't ideal because it's only possible with truly local commands (remote ones cannot do this) but practicality needs to beat purity some of the time.

So while I very much want this generally solved, a partway workaround would be e.g. run('vim', capture=False), or direct=True, or similar.

@bitprophet
Member
bitprophet commented Nov 7, 2016 edited

Poking a little more at "why isn't our mirroring working quite right for vim"...

Don't think I recorded this before but I remember it happening before, and it's still a thing now: hitting up/down arrow acts like I'm hitting "A" and/or "B", and even stranger, it can get into this "delayed" state where switching directions is delayed by 1 keypress.

E.g. up-up-up-up ... will record stdin reads of 'A' over and over. Then 'down' will...still record a stdin read of 'A'. But then a subsequent 'down' will record 'B', and then all subsequent 'down' are 'B'. Vice versa for going back to 'up' - 1st 'up' still records 'B', only 2nd thru Nth record 'A'.

Suspect this has to do with what my terminal emulator (Terminal.app) does for arrow keys, and that might provide a clue re: our stdin read and/or write (as well as maybe stdout/err) doing wrong things, e.g. the "one byte at a time" approach. (Which is another knob to try conditionally turning, even though I still don't know of a graceful fix for the "must read SOME hardcoded chunk of stdin at a time because we can't afford to block forever if it's all done" problem.)

@bitprophet
Member
bitprophet commented Nov 8, 2016 edited

OK, part of the issue is ready_for_reading isn't always working right:

  • Load vim session
  • Hit down arrow
  • Down arrow evaluates to ^[OB (generally)
    • Of note, this also explains the 'AB' crap - combining various sequences of <Esc>, O and [AB] in vim will, of course, write out individual lines of A or B (because O in normal mode inserts a newline above cursor & enters insert mode)
  • What I see logged, is that the ^[ (rather, \x1b gets read from stdin (and written to proc stdin), but the OB don't show up - at all - until the next keypress.
  • And that next keypress also includes stdin reads up to the subsequent Escape character (which handily explains the 'delay' I see - each read is basically a 'backwards' character, with the crap after Escape followed by the next/current keypress' Escape).

So the question is why ready_for_reading isn't seeing the post-Escape bytes; if we can solve that it might make a lot of this stuff work better.


The main loop in this case is:

  • Runner.handle_stdin is the thread/controller
  • It context-manages character_buffered around a while True loop that calls Runner.read_our_stdin.
  • read_our_stdin calls the nonblocking ready_for_reading function on stdin, returning None if that is False, or a single read byte otherwise.
  • ready_for_reading is using select.select in this case, and the select call seems to be what is problematic, as it's not returning stdin as often as I think it should be.

Debug output of pressing down-arrow twice in a row after a vim session has loaded is below.

Note that I am only debugging when select returns non-empty readers list; I did check to make sure it's being called, and returning an empty readers list, when keys aren't pressed. That is of course super noisy so I then turned it off.

<press down arrow>

DEBUG:invoke:select.select came back with reads [<open file '<stdin>', mode 'r' at 0x101b7b0c0>]
DEBUG:invoke:stdin read: '\x1b'
DEBUG:invoke:...and decoded: u'\x1b'
DEBUG:invoke:stdin written: '\x1b'
DEBUG:invoke:stdout read: '\x07'

<everything stops here until I press down-arrow again...>

DEBUG:invoke:select.select came back with reads [<open file '<stdin>', mode 'r' at 0x101b7b0c0>]
DEBUG:invoke:stdin read: 'O'
DEBUG:invoke:...and decoded: u'O'
DEBUG:invoke:stdin written: 'O'
DEBUG:invoke:stdout read: '\x1b[?25l\x1b[1;40r\x1b[m\x1b[1;1H\x1b[L\x1b[1;41r\x1b[41;1H\x1b[K\x1b[1;1H\x1b[?12l\x1b[?25h'
DEBUG:invoke:select.select came back with reads [<open file '<stdin>', mode 'r' at 0x101b7b0c0>]
DEBUG:invoke:stdin read: 'B'
DEBUG:invoke:...and decoded: u'B'
DEBUG:invoke:stdin written: 'B'
DEBUG:invoke:stdout read: '\x1b[?25lB\x1b[?12l\x1b[?25h'
DEBUG:invoke:select.select came back with reads [<open file '<stdin>', mode 'r' at 0x101b7b0c0>]
DEBUG:invoke:stdin read: '\x1b'
DEBUG:invoke:...and decoded: u'\x1b'
DEBUG:invoke:stdin written: '\x1b'
DEBUG:invoke:stdout read: '\x08'

Condensed into just the stdin-read & stdout-read related bits:

<press down arrow>

DEBUG:invoke:select.select came back with reads [<open file '<stdin>', mode 'r' at 0x101b7b0c0>]
DEBUG:invoke:stdin read: '\x1b'
DEBUG:invoke:stdout read: '\x07'

<everything stops here until I press down-arrow again...>

DEBUG:invoke:select.select came back with reads [<open file '<stdin>', mode 'r' at 0x101b7b0c0>]
DEBUG:invoke:stdin read: 'O'
DEBUG:invoke:stdout read: '\x1b[?25l\x1b[1;40r\x1b[m\x1b[1;1H\x1b[L\x1b[1;41r\x1b[41;1H\x1b[K\x1b[1;1H\x1b[?12l\x1b[?25h'
DEBUG:invoke:select.select came back with reads [<open file '<stdin>', mode 'r' at 0x101b7b0c0>]
DEBUG:invoke:stdin read: 'B'
DEBUG:invoke:stdout read: '\x1b[?25lB\x1b[?12l\x1b[?25h'
DEBUG:invoke:select.select came back with reads [<open file '<stdin>', mode 'r' at 0x101b7b0c0>]
DEBUG:invoke:stdin read: '\x1b'
DEBUG:invoke:stdout read: '\x08'

So for some reason, select is only returning stdin in the readers list once initially, but does it three times on each subsequent keypress (i.e.: what I expected it to do on the first, and every, such keypress involving 3 bytes), leaving us in this shifted state.

What I don't recall clearly is the exact semantics of select and whether it acts as a solid "there's crap in your stdin buffer you could be reading" flag or if there's nuance.

@bitprophet
Member
bitprophet commented Nov 8, 2016 edited

I can recreate the same select behavior with a simple client program, like sleep 600, which rules out any sort of bizarro terminal capacity setting vim and friends might be doing. (Not that I expected such was the culprit, but, troubleshooting 101...).

Only real difference is that the input is appearing as ^[[B instead of ^[OB, but the actual behavior - select returning ready only on the initial ^[, and then on 2nd keypress, seeing [B^[ - is 100% identical.

Rummaging around docs, google, manpages etc hasn't helped me a ton so far re: pinning down exactly what select means when it thinks a given FD is "ready". As far as I recall this ought to all be pretty basic IPC/network like pipe bullshit where the keypress dumps bytes into my stdin pipe, that pipe is now holding (in this case) 3 bytes, and I assume select should be returning a ready-read status until all 3 bytes have been read.

Double-checked what I saw before re: the loop getting back a definitive "nope, nothing to read from stdin", and yes, it's definitely the case.

Wondering if this is ye olde buffering issues with Python processes & pipes...?

@bitprophet
Member

Brainstorm before I dig into that...possible reasons offhand:

  • I'm misunderstanding how select and/or pipes work, this is actually expected behavior, and we have to find some other workaround like reading multiple bytes at a time (... and somehow in a nonblocking fashion so that we can still submit them to our child process in a timely fashion).
  • select works fine but my terminal is in some mode causing it to behave oddly. E.g. some of the things we set at terminal startup time - or something we're not yet setting, ISTR some of those being a thing in TODOs - are to blame.
  • Similar to previous: something about the specific input it's getting is making it behave oddly, i.e. something in the nature of non-ascii or multibyte key input (arrow keys, etc) is triggering this.
  • Something Python specific like its buffering behavior - tho that is usually limited to stdout/stderr, not stdin, and usually its own emitted stdout/err, not what it takes in.
@bitprophet
Member

Some comments on some SO results from google (1, 2) imply the core problem of nonblockingly reading off stdin is unreliable. Not sure how much I trust that but it's interesting and would certainly explain this behavior (though I usually translate "unreliable" as "intermittent" and the behavior I'm getting is quite consistent, just wrong!)

Link 2 there does some wacky stuff with the terminal control structures which I should look into in case it's useful:

new_settings[3] = new_settings[3] & ~(termios.ECHO | termios.ICANON) # lflags
new_settings[6][termios.VMIN] = 0  # cc
new_settings[6][termios.VTIME] = 0 # cc

And a bunch of code in those and other results do basically what our character_buffered manager does, based around tty.setcbreak. So that's already in hand and not helping quite enough.

Some others use tty.setraw which I don't think we do, so I should look at it. My TODO does mention that pty and pexpect both use setraw and other tricks - so that is probably a good first area to examine.

@bitprophet
Member

Read/skimmed man termios. Nothing immediately jumped out at me re: the select behavior I'm seeing, but at least now I can mostly translate that above snippet:

  • Turns off echoing and canonical mode (aka linewise mode). We should already be in noncanonical mode due to setcbreak (tho I still have to see exactly how that relates) and I also don't think we're echoing by default. So neither of those matter a ton.
  • The 7th member of terminal attributes is the cc array, which mostly allows overriding a whole passle of special control characters if desired. But it sounds like most of the time, real world use is to set two members that aren't control chars but which are options for noncanonical processing - the two set here, VMIN and VTIME.
    • man termios goes into detail for these, you can get a bunch of different behaviors between them, but they mostly control how the num-bytes and timeout params to read calls are interpreted.
    • That snippet sets them both to 0 which means "just give me back the minimum number of bytes, between what was requested and what's in the queue".
    • At least on Darwin, the default is 1 and 0, meaning "block until at least 1 byte can be read".

Re: tty.setcbreak, it seems like it's just a convenient shorthand for passing a specific value to a specific flag via tcsetattr. Had to look at the source, but, surprise! It's basically the same shit as above, except VMIN=1 (i.e....back to the default):

def setcbreak(fd, when=TCSAFLUSH):              
    """Put terminal into a cbreak mode."""      
    mode = tcgetattr(fd)                        
    mode[LFLAG] = mode[LFLAG] & ~(ECHO | ICANON)
    mode[CC][VMIN] = 1                          
    mode[CC][VTIME] = 0                         
    tcsetattr(fd, when, mode)                   

So setcbreak basically does just translate as "turn off canonical mode". OK then.

None of this yet explains what the hell is up with select.

@bitprophet
Member
bitprophet commented Nov 8, 2016 edited

Confirmed that tty.setraw (which, viewing its source, disables a ton of other flags via tcsetattr, which I guess makes some sense) makes no difference re: select's behavior.

Also confirmed symptoms, & lack of efficacy of setraw, are identical on Linux.

@bitprophet
Member
bitprophet commented Nov 8, 2016 edited

More googlin' and I found this SO which sounds very similar, but the answer is seemingly unhelpful, since the asker is using getchar and, well, I'm not - I'm doing exactly what the answerer suggests (use read, not getchar, with select).

What is interesting is the asker mentions using ioctl to inspect the buffer/pipe/whatever, e.g. ioctl(0,FIONREAD,&n). (Yes, the fact that I'm still not 100% sure what's running behind the scenes, is dumb.)


Mucked around some more and got this to get me the FIONREAD value of stdin; sadly (?) it seems to map well to the select behavior, implying the issue is more on my side re: how I'm reading, or...something. After the select and irrespective of whether any reads exist, I did this:

wat = fcntl.ioctl(input_, termios.FIONREAD, "  ")              
doublewat = struct.unpack('h', wat)[0]                         
debug("FIONREAD result: {0!r} -> {1!r}".format(wat, doublewat))

(Translation: you have to specify the size of a buffer handed to ioctl, which in this case needs to be at least 2 bytes large to hold an int; the returned value is a string representing binary data, and struct.unpack is then told with a format string to expect a short int, which it then returns.)

Result:

...
DEBUG:invoke:FIONREAD result: '\x00\x00' -> 0
DEBUG:invoke:FIONREAD result: '\x00\x00' -> 0

<press down arrow>

DEBUG:invoke:FIONREAD result: '\x03\x00' -> 3
DEBUG:invoke:select.select came back with reads [<open file '<stdin>', mode 'r' at 0x104df50c0>]
DEBUG:invoke:stdin read: '\x1b'
DEBUG:invoke:...and decoded: u'\x1b'
DEBUG:invoke:stdin written: '\x1b'
DEBUG:invoke:stdout read: '^['
DEBUG:invoke:FIONREAD result: '\x00\x00' -> 0
DEBUG:invoke:FIONREAD result: '\x00\x00' -> 0
DEBUG:invoke:FIONREAD result: '\x00\x00' -> 0
...

So immediately after our read(1) call, FIONREAD returns to claiming 0 bytes immediately available for reading from the fd - even though there were 3 before and we've only read 1.

However...what this means is...we still have much more information than we had prior. We know how large we can make the read call! (and in fact, I now remember one of the pages I read describing this as a typical low level C read algorithm - select, FIONREAD, read).

So far, FIONREAD also seems pretty cross-platform (insofar as all of this is Unix specific anyways) - Solaris, BSD and Linux all appear to support it.

@bitprophet
Member

Existing tests pass with that fix in (I haven't put serious thought into how I could add new tests for this particular phenomenon, besides "ensure we call ioctl"...which had to suffice for the cbreak stuff, so...) given that I have it fallback to the 1-byte behavior for streams without a fileno. (Arguably, we could read much more at a time if we assume non-fileno-bearing streams are in-memory file-like objects...but that can wait.)

(I love parentheticals, apparently.)

More importantly, my by-hand tests with the arrow keys is smoother now - 3-byte reads and writes happen, and even with sleep as the subproc, the echoed characters are ^[OA and so on, instead of the slightly different ^[[A, which feels "right" somehow.

Even more importantly, vim now works flawlessly (well, except for Ctrl-C - my preferred vim mode-changer - exiting things out, but that's an orthogonal and known issue that can probably be fixed easily soon.)

@bitprophet
Member
bitprophet commented Nov 8, 2016 edited

TODO:

  • How's Python REPL?
  • How's iPython? (IIRC it hates test runners that muck with stdout/err, but in a non-test context, does it work better now?)
  • Whatever else has been raised in this or linked tickets
  • Tests for this...doubt anything more than "did you drink your Ovaltine try very hard to call ioctl for something that seemed to have a fileno?" is feasible, but better than having zero new tests...
  • Python 3 checkup
  • Windows checkup (via appveyor)
  • See how quickly I can knock out the Ctrl-C thing. I mean, while I'm in this rabbit hole...
  • Changelog entr(y|ies)
  • Quick check on Fabric 2, but since this is all on the local stdin side and writes are just writes, I remain hopeful it'll work just as well there (similar to how it works "pretty well" on Fab 1 because stdin isn't being fucked with there anyways).
@bitprophet
Member

IPython works way better now, .

@bitprophet
Member
bitprophet commented Nov 8, 2016 edited

Scanned other linked tickets, happy to report that #361 sounds exactly like the issue I was using as my troubleshoot base case yesterday (re: "delayed" behavior due to the problems with select), so I bet it's fixed now. Would be real surprised if some non-Python/iPython readline-using use case worked significantly differently than those REPLs do.

@hjc1710 if you're still following this and want to share the exact app you're using, I can confirm whether this fix applies to it. Otherwise tho, I'm expecting to merge this to master today and release soon. EDIT: I'm dumb, you provided that info originally. Will clone your repo and try to reproduce...

@bitprophet
Member

Yea, both of the tasks in that repo work great under the patch, both the REPL & pdb.

@bitprophet
Member

Works reasonably well under Fabric 2; color and such don't happen, but there are no problems with control codes, arrow keys, etc. Strangely - the same is true even with this fix temporarily reverted. Can't think offhand what would be different in this case to make the issue not present. Something to poke more later perhaps.

@bitprophet
Member

Hm, tests not failing under Windows (proof) despite not having added a Windows check to the newly updated FIONREAD bits. Wondering if this is because the Windows input streams lack fileno and thus always behave like vanilla in-memory buffers instead? If so, a happy coincidence.

@hjc1710
hjc1710 commented Nov 9, 2016

This is super exciting to read @bitprophet! I can't wait for this to get merged into master so I can test it out on my main app (proprietary) that initially caused me to open this issue up.

Thank you so much for your hard work, I sincerely appreciate it. We recently had to work on an old project that used Fabric and it made me miss Invoke sooooooooooo much. Returning to Invoke with this fixed will be like Christmas morning =).

If you want another test case, feel free to ping me when this goes to master and I'll grab it and run our test suite through it and a few other tasks to make sure everything looks great!

thats-awesome

(Also, I really enjoyed reading your thoughts as you fixed this! Learned a TON about stream handling.)

@bitprophet
Member

Sanity checked that the FIONREAD stuff does in fact work same on Linux (Ubuntu Trusty). Wasn't worried but while I was on there...

@bitprophet bitprophet added a commit that referenced this issue Nov 14, 2016
@bitprophet bitprophet Changelog re #58 49fff0b
@bitprophet
Member

Closed off #406 too, and this as well (added a changelog entry and such).

Have some invocations tire kicking to do but once happy with that crap, will push this out as part of 0.14.0.

@bitprophet bitprophet closed this Nov 15, 2016
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment