Invoke==0.12 waits for keypress and gets Broken Pipe when invoking another invoke command through run() #308

Closed
tuukkamustonen opened this Issue Jan 18, 2016 · 22 comments

Projects

None yet

3 participants

@tuukkamustonen

On linux, python 2.7 and invoke==0.12:

from invoke.collection import Collection
from invoke.tasks import ctask

@ctask
def sub(ctx):
    ctx.run('inv hello')

@ctask
def hello(ctx):
    ctx.run('echo hello')

ns = Collection(sub, hello)

Works:

$ inv hello
hello

Fails:

$ inv sub
hello
<stops to wait for a keypress here...>
Traceback (most recent call last):
  File "/home/musttu/.virtualenvs/pyinv/bin/inv", line 11, in <module>
    sys.exit(program.run())
  File "/home/user/.virtualenvs/pyinv/local/lib/python2.7/site-packages/invoke/program.py", line 270, in run
    self.execute()
  File "/home/musttu/.virtualenvs/pyinv/local/lib/python2.7/site-packages/invoke/program.py", line 379, in execute
    executor.execute(*self.tasks)
  File "/home/musttu/.virtualenvs/pyinv/local/lib/python2.7/site-packages/invoke/executor.py", line 114, in execute
    result = call.task(*args, **call.kwargs)
  File "/home/musttu/.virtualenvs/pyinv/local/lib/python2.7/site-packages/invoke/tasks.py", line 113, in __call__
    result = self.body(*args, **kwargs)
  File "/home/musttu/Temp/tasks.py", line 12, in hello
    ctx.run('echo hello')
  File "/home/musttu/.virtualenvs/pyinv/local/lib/python2.7/site-packages/invoke/context.py", line 53, in run
    return runner_class(context=self).run(command, **kwargs)
  File "/home/musttu/.virtualenvs/pyinv/local/lib/python2.7/site-packages/invoke/runners.py", line 232, in run
    raise ThreadException(exceptions)
invoke.exceptions.ThreadException: 
Saw 1 exceptions within threads (OSError):


Thread args: {'kwargs': {'input_': <open file '<stdin>', mode 'r' at 0x7fee83ac00c0>},
 'target': <bound method Local.handle_stdin of <invoke.runners.Local object at 0x7fee81e7d390>>}

Traceback (most recent call last):

  File "/home/musttu/.virtualenvs/pyinv/local/lib/python2.7/site-packages/invoke/runners.py", line 804, in run
    super(_IOThread, self).run()

  File "/usr/lib/python2.7/threading.py", line 763, in run
    self.__target(*self.__args, **self.__kwargs)

  File "/home/musttu/.virtualenvs/pyinv/local/lib/python2.7/site-packages/invoke/runners.py", line 433, in handle_stdin
    self.write_stdin(self.encode(data))

  File "/home/musttu/.virtualenvs/pyinv/local/lib/python2.7/site-packages/invoke/runners.py", line 653, in write_stdin
    return os.write(fd, data)

OSError: [Errno 32] Broken pipe

In 0.11.1 it works just ok.

The use case: While this example doesn't make much sense, in the real world, I'm invoking another invoke commands in sub-directories from a "master" tasks.py.

@presidento
Contributor

It is the same in Win64 with Python 3.4, except I got the exception using inv hello, and inv sub cannot be killed with Ctrl+C.

C:\Users\user\temp\pyinvoke test>inv hello
hello
Traceback (most recent call last):
  File "c:\programs\python34\lib\runpy.py", line 170, in _run_module_as_main
    "__main__", mod_spec)
  File "c:\programs\python34\lib\runpy.py", line 85, in _run_code
    exec(code, run_globals)
  File "C:\Programs\Python34\Scripts\inv.exe\__main__.py", line 9, in <module>
  File "c:\programs\python34\lib\site-packages\invoke\program.py", line 270, in run
    self.execute()
  File "c:\programs\python34\lib\site-packages\invoke\program.py", line 379, in execute
    executor.execute(*self.tasks)
  File "c:\programs\python34\lib\site-packages\invoke\executor.py", line 114, in execute
    result = call.task(*args, **call.kwargs)
  File "c:\programs\python34\lib\site-packages\invoke\tasks.py", line 113, in __call__
    result = self.body(*args, **kwargs)
  File "C:\Users\user\temp\pyinvoke test\tasks.py", line 10, in hello
    ctx.run('echo hello', shell=True)
  File "c:\programs\python34\lib\site-packages\invoke\context.py", line 53, in run
    return runner_class(context=self).run(command, **kwargs)
  File "c:\programs\python34\lib\site-packages\invoke\runners.py", line 232, in run
    raise ThreadException(exceptions)
invoke.exceptions.ThreadException:
Saw 1 exceptions within threads (OSError):


Thread args: {'kwargs': {'input_': <_io.TextIOWrapper name='<stdin>' mode='r' encoding='cp852'>},
 'target': <bound method Local.handle_stdin of <invoke.runners.Local object at 0x02EF6230>>}

Traceback (most recent call last):

  File "c:\programs\python34\lib\site-packages\invoke\runners.py", line 804, in run
    super(_IOThread, self).run()

  File "c:\programs\python34\lib\threading.py", line 868, in run
    self._target(*self._args, **self._kwargs)

  File "c:\programs\python34\lib\site-packages\invoke\runners.py", line 411, in handle_stdin
    reads, _, _ = select.select([input_], [], [], 0.0)

OSError: [WinError 10093] Either the application has not called WSAStartup, or WSAStartup failed
@tuukkamustonen

I can kill inv sub with Ctrl+C but if I do that, I get into situation reported in #303.

@bitprophet bitprophet added the Bug label Jan 20, 2016
@bitprophet bitprophet added this to the 0.12.1 milestone Jan 20, 2016
@bitprophet
Member

Thanks for the reports! Confirm I can reproduce locally.

On poking, noted that the ThreadError/OSError is in the "inner" invoke process (hello, not sub).

Also noted that the behavior is improved if sub uses run(pty=True); or, unsurprisingly, if both do (can't just put it on hello only though - the inner Invoke will notice the outer isn't a pty and fallback to non-pty execution, as expected).

Handing in_stream=StringIO("") to sub only changes things insofar as sending the real-stdin newline now makes no difference and one is forced to Ctrl-C.

So far I'm assuming there's a race condition or other stupidity going on wrt the input mirror loop (which loops until it receives the signal from another thread that the subprocess has exited). Why this is only triggered by nesting is unclear offhand. Will dig.

@bitprophet
Member

Also linking this explicitly to #289 since it came out of that feature.

@bitprophet
Member

Right - it's because Invoke doesn't appear to be a terminal when not in pty mode (because...it's not), and Invoke checks its own stdin for terminal-ness when deciding how to 'wait' on stdin during the stdin read loop: https://github.com/pyinvoke/invoke/blob/7fe2750cd1863c15c3cc92c390dee479dce96534/invoke/runners.py#L413-L447

When a real pty is present (again, this is the case if one uses pty=True in the outer invocation) the "is stdin ready for reading?" function at the top of said loop will never block: it uses select (or Windows equiv), returning False immediately, forever; the loop is thus "hot" (except it doesn't actually chew CPU due to a sleep call 😸).

In the case under test, where there is no intended stdin data, this means everything lines up well: that loop runs often, eventually the "is the subprocess done?" test triggers, the loop exits, everything closes up shop, we're done.

In the error case, when the input stream doesn't appear to be a terminal (via our custom isatty function) ready_for_reading() always returns True on the presumption that the stream is an in-process Python object or similar finite-length file-like object that can be read(1) from.

So we end up sitting in read_byte, where input_ is an actually-kinda-real sys.stdin, until a byte appears in the stream (this is where 'hitting a key' enters the picture). But at this point in time, the echo subprocess has already exited, thus the OSError on broken pipe when the inner Invoke tries mirroring this read byte into it.


tl;dr: we need at least one of the following:

  • Invoke needs to pass isatty tests from the perspective of its subprocesses, at least when it's mirroring a real TTY.
    • This is probably difficult or impossible? but I need to think about it because it'd be "nice" for things to be that transparent - I've always seen the ideal here for Invoke to be indistinguishable from lower-level C-based programs that do similar stuff.
  • Or, the stdin mirroring functionality needs to modify its assumptions about the stdin stream object involved, such that it is able to detect this sort of "is still a real-enough tty that may never have actual data coming through it" situation.
    • This presumes that using select/getch against an outer Invoke process (one not using pty=True) even works, which depends in part on what subprocess is doing exactly...
      • If they don't work in this case, we may be just screwed, since neither blocking nor nonblocking reads would then be possible, unless I'm blind to something.
    • If they do, we need to figure out the gap that exists here re: TTY detection, which currently is "does it have an .isatty? and if not does it have a .fileno?".
      • Alternately, we need to alter ready_for_reading in similar fashion, tho that brings us back to "what other ways are there to determine if there's data in this pipe?", and we need something that can accurately answer "No" without blocking.

To be continued...

@bitprophet
Member

Examining the state of my local setup, I found that while sys.stdin.isatty is False, sys.stdin.fileno is 0. Right now, our isatty test prefers .isatty and completely disregards .fileno if .isatty is callable. However, the case under consideration is exactly the kind of valid setup the code disregards.

It should be the same as some other non-Invoke program piped as stdin to Invoke, which is another case I think we have bug reports for (from earlier) as well. Sure enough, echo 'lolnope' | inv hello yields the exact same set of errors.

So our fixation on "tty-ness" for purposes of how to read from stdin is misguided and needs fixing.

Offhand I am thinking making it "either-or" should suffice (says it's a tty? cool! says it's not a tty, but has a fileno? also cool!) but I need to revisit the reasons why we made it the way it is now (I recall other edge/corner cases being involved).

May also involve splitting the method up a bit - some cases we really do care if it's a TTY, IIRC.

EDIT: yea, here's all calls to utils.isatty at present:

  • Within char_buffered (since that involves using termios etc) - this is a real, useful/full use of the func, presumably.
  • Within handle_stdin, similar to the other uses at hand in this ticket: it's trying to test whether the stream is a finite file-like object or not so it knows whether an empty byte means EOF.
    • Though now that I think on it, an empty read byte should always imply EOF; a real stdin stream would never yield one...
  • Local pty fallback cares, so it doesn't try to allocate a pty when there isn't one on the stdin side to hook it up to.
    • Think this falls under the same category as char_buffered, but not sure.

What I need to do:

  • Ensure we have integration suite tests (possibly extending to "shit run in .travis.yml itself" to avoid this kind of invoke-within-invoke problem?) testing scenarios like this one & the 'normal pipe to stdin' version
  • See how bad our existing tests blow up if I just change utils.isatty to be more expansive in scope
  • Assuming it does, examine recent history re: that function (I know pfmoore and I kicked it around a bit re: Windows behavior, for example) to determine best way to split it up so we can ask these semi-separate questions at appropriate times:
    • Can I use select/getch on you (for nonblocking reads)?
    • Can I call termios on you (to set character-buffered stdin)?
    • Can I use the pty & fcntl modules on you (and also termios actually) (to spawn a pty for running the subprocess within)?
@bitprophet
Member

Minor update, I read isatty slightly too fast, the fallback test isn't "does it have a real fileno?" but "does it have a real fileno and is that fileno a tty according to os.isatty?". Which is of course, still False in this particular scenario (both cases).

Also, FTR, the reason it's always false here, but fileno itself is "okay", is because we're just inheriting file handles all the way down; so sys.stdin.fileno() is still 0, like "normal" ("normal" being "a Python process with nothing else in the way of standard input"). But it's not a TTY because either the pipe, or Invoke, is in the way, depending. (N.B. there's now one test for each situation in the integration suite.)

This is definitely hedging me further towards "we need to separate the questions of TTY-ness and select-ability", which I think will solve this pretty well.

@bitprophet
Member

So yea, re: previous comment, updating isatty to be either-or doesn't help any, as the os.isatty test around the stream's fileno() still fails. Definitely do need separate functions. Working on that now.

@bitprophet
Member

Dug a little deeper into our use of isatty and friends:

  • The select/getch from ready_for_reading is both the heart of the issue here & the most straightforward, it should boil down to "can I get a numeric fileno from the stream?", so e.g. an inherited sys.stdin fd of 0 ought to be happy here.
  • character_buffered uses two calls:
    • termios.tcgetattr(stream) - all termios calls also want a working fileno (either an object w/ a .fileno() returning an int, or just the int) so again, inherited sys.stdin good, StringIO instance bad.
    • tty.setcbreak(stream) - says it wants an 'fd' and also mentions termios, so presumably same deal here - only cares about fd.
      • However! This is one that might be slightly pissy with something that fails stream.isatty(), will have to test.
  • The stuff in Local is all predicated on self.using_pty, whose fallback functionality is what asks isatty(sys.stdin). The calls made if self.using_pty is True are:
    • pty_size() which asks sys.stdout (NOT sys.stdin) if it's a tty, using sys.stdout.isatty
      • Shouldn't this be using out_stream instead? Hrm.
      • EDIT: well, but the windows branch of the code doesn't touch sys.stdout at all - there'd be nothing to parameterize on. Also seems unlikely that someone would pass in a real terminal stream for out_stream that somehow isn't sys.__stdout__. Punting =/
    • fcntl.ioctl(sys.stdout.fileno()) - presumably still good with "fd OK, even if isatty false"
    • pty.fork - this presumably cares about actual tty-ness, but need to test

Need to doublecheck to make sure I'm not missing anything, but so far, it does feel like the majority of these actually just care about fileno not isatty - need to check git history too because I'm pretty sure isatty() used to care more about fileno so if so, I wonder why things changed - suspect Windows related?

@bitprophet
Member

Doublechecked, everything should be listed above now.

Re: git history, we did previously rely mostly on fileno (though this was prior to implementing the stdin mirroring so was mostly used for the Local pty stuff I think), then in 57f7f42 it got changed to prefer isatty (and then later in 61feb22 we expanded to the current setup of "isatty, then fileno").

I still think that this back & forth is due to the two different questions involved re: Local pty execution jazz vs the concerns about reading from stdin, so I'm gonna steam ahead with that and hope anything it breaks bubbles up quickly.

@bitprophet
Member

Poked a bit re: above:

  • When Python is running inside an Invoke run(pty=False), sys.stdout behaves same as sys.stdin, insofar as .fileno() works happily (& returns 1) but .isatty() is False.
    • When run(pty=True), isatty is True, as expected
  • Replacing the outer Invoke's sys.stdin and sys.stdout doesn't impact the inner Python process at all, re: obtaining filenos.
  • Whether isatty is True or False in the inner Python process depends solely on whether the outer Invoke makes use of pty.fork or not - expectedly.
  • Forcing pty=True, fallback=False with StringIOs as sys.stdin/out causes things to blow up (again, expected) when fcntl.ioctl runs (in Local.start) and finds out StringIO lacks fileno. This isn't strictly related but eh. Poked it anyways.
  • pty.fork() actually doesn't seem to care about isatty-ness either; it's happy to execute even if sys.stdin or sys.stdout are isatty==False. This is more fuel for "caring about fileno is the only thing that really matters" I think.
@bitprophet
Member

Grump, went ahead and tried flipping everything back to fileno-only testing, but I obviously didn't test enough. Even though we have useful fileno on sys.stdin in a nested-Invoke situation, character_buffered's call to termios.tcgetattr gets upset and throws Inappropriate ioctl for device.

So we probably do still need a mixture of isatty and fileno checks...testing. EDIT: yup, if we update character_buffered to test isatty but leave everything else testing fileno, the test case here (re: inv sub) now works for me.

@bitprophet
Member

Test suites now finding some more quirks I hadn't run into yet, firstly: an integration test that incidentally calls invoke-from-invoke (testing --help output) yields an IOError of Inappropriate ioctl for device in pty_size's use of fcntl.ioctl.

  • In this case, sys.stdout has fileno 1 but isatty says False.
  • Implication is thus that my guess above about "fileno is sufficient" doesn't play true here either.
  • Could switch this spot back to checking isatty, though I do wonder if there are situations where "has fileno, is not tty" would work.
  • Perhaps the right thing for this particular method is to employ EAFP - in fact, we do already wrap the breaking lines in try/except, we just only check for AttributeError, and going by its comments that's actually a holdover from earlier lack of rigorous fileno/isatty checking. So we may just want to add/change the except to look for IOError...
@bitprophet
Member

Have everything passing now except for the echo 'lol' | invoke sometask integration test (this wasn't reported initially but it's a legit use case) which seems to be encountering a race condition - the waiting for the subprocess (which is simply echo meh) finishes before the stdin mirroring completes.

In most real-world x | y cases this isn't an issue; AFAIK the shell simply discards anything in the pipe if the receiving end closes "early". In our case, what's really happening is more akin to x | invoke | y, and so it's up to us to notice this problem & deal accordingly.

Presumably we simply need to capture this OSError and just close up shop; now that we've solved the similar issue of "don't try to get at least one read() from a stream with nothing in it", this situation should be the only cause of broken-pipe OSErrors. Hopefully.

@bitprophet
Member

This makes me wonder if for "best behavior" we should disable the stdin mirroring IO sleep when stdin fails isatty testing. E.g. cat /usr/share/dict/web2 | echo wut (that dict file is 2.4MB of text) takes 0.005s to run on my i7-based Macbook Air, but obviously significantly longer when polling stdin 1 byte at a time with a 0.01s sleep.

I also ran into the part where we always echo stdin when using_pty is false; that functionality also needs to check whether the input is running in a pty, because otherwise it tries to write to our stdout even though we're running it via a pipe - that's incorrect.

Terminals are great fun.

@bitprophet
Member

Tackling the echoing/mirroring (I really need to get better at consistent vocabulary with this shit) first:

  • When Invoke is the recipient of a pipe, it should not echo
  • When Invoke is simply being run 'nested' (e.g. inside another Invoke, or whatnot) and the outer process is a tty, it should echo
    • If we can correctly detect this - which may be impossible, now that I think on it
    • It also opens up bigger questions about if/how to present "as" a tty when the outer invoke is run from a terminal (think this came up above too).
  • If I'm right that we can't reliably tell these two scenarios apart, probably best to just make the echoing an option (good anyway really) and default to not echoing, since piping to Invoke feels likelier than nesting Invokes (esp given once we improve calling tasks from other tasks, nesting Invoke sessions should not really be necessary ever).
@bitprophet
Member

Hrm. So...we can sorta detect a pipe vs nested situation by testing both stdout and stdin:

  • In all situations, both have a fileno, due to inheritance.
  • Vanilla single invoke, both pass isatty
  • Pipe to invoke, stdin is not a tty, stdout is a tty (which makes sense; only stdin is being replaced)
  • Nested invoke, neither is a tty (because both streams are being replaced)

But that doesn't really help, because the point of this is to echo a real user's typing back to them.

Given how much dumb time I've sunk into this, going with option 3 from previous comment - add an option to control the echoing, have it default to "only if stdin passes isatty and subprocess isn't running in a pty".

@bitprophet
Member

While it didn't take the whole 6 hours since last note, it still took longer than it should have to finished getting that working (mostly due to testing related concerns). I'm bad at computers, folks :(

On the plus side we now have yet another run kwarg/config option controlling stdin echoing.

Re: the other side note of disabling IO sleep, I am punting on that because of aforementioned difficulty in telling apart a pipe from a nested session (& also just time).

Flake8 and Python 3 are satisfied locally; time to see if my integration tests for the greater issue here, works on Travis or not. I bet they don't. If they don't I am probably just going to tell them to skip on Travis, again because JFC I need to wrap this up.

@bitprophet bitprophet added a commit that referenced this issue Feb 4, 2016
@bitprophet bitprophet Failing tests re #308 62bb80d
@bitprophet bitprophet added a commit that referenced this issue Feb 4, 2016
@bitprophet bitprophet Update impl & tests re: stdin mirroring.
All seems to work now?

Re #308
3da823c
@bitprophet
Member

Incredibly, I was wrong, the tests seem to pass on Travis. Suppose maybe it's a false positive, but meh.

Uh...I think this and all its attendant sub-problems are now Fixed Enough, writing a changelog entry and merging. Sorry for the chatter @tuukkamustonen and @presidento !

@bitprophet bitprophet closed this Feb 4, 2016
This was referenced Feb 4, 2016
@tuukkamustonen

@bitprophet That's some incredible work there. The way you summarize the thought-process into tickets for others to follow and collaborate is exceptional and I'm just happy about the lenghty "chatter". That being said, you lost me halfway through (if not earlier, this stuff is way out of my knowledge) but I do really appreciate the effort you're putting into the project(s)!

@presidento
Contributor

I agree with @tuukkamustonen, thank @bitprophet for the summaries. I have read it as was posted.

@bitprophet
Member

❤️

@wooyek wooyek added a commit to wooyek/django-pascal-templates that referenced this issue Apr 4, 2016
@wooyek wooyek pyinvoke/invoke#308 fd9c893
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment