Streamed output printed on new lines with `pty` option since v0.8.0
thisismydesign opened this issue · 22 comments
Hey, it's me again! :D
I noticed this behaviour with v0.8.0:
irb
require "tty-command"
cmd = TTY::Command.new(pty: true)
cmd.run('rubocop')
=>
8908f6bb] Running rubocop
[8908f6bb] .rubocop.yml: Lint/EndAlignment has the wrong namespace - should be Layout
[8908f6bb] Inspecting 28 files
[8908f6bb] .
[8908f6bb] .
[8908f6bb] .
[8908f6bb] .
[8908f6bb] .
[8908f6bb] .
[8908f6bb] .
[8908f6bb] .
[8908f6bb] .
[8908f6bb] .
[8908f6bb] .
[8908f6bb] .
[8908f6bb] .
[8908f6bb] .
[8908f6bb] .
[8908f6bb] .
[8908f6bb] .
[8908f6bb] .
[8908f6bb] .
[8908f6bb] .
[8908f6bb] .
[8908f6bb] .
[8908f6bb] .
[8908f6bb] .
[8908f6bb] .
[8908f6bb] .
[8908f6bb] .
[8908f6bb] .
[8908f6bb]
[8908f6bb] 28 files inspected, no offenses detected
[8908f6bb] Finished in 1.704 seconds with exit status 0 (successful)
Without the pty option it works fine, in v0.7.0 both with or without works fine.
For clarity's sake the previous behaviour:
[452673d4] Running rubocop --parallel
[452673d4] Inspecting 184 files
[452673d4] ........................................................................................................................................................................................
[452673d4]
[452673d4] 184 files inspected, no offenses detected
[452673d4] Finished in 2.154 seconds with exit status 0 (successful)
I rewrote how streams reading is done. The major issue was that it was a blocking call that expected a new line input in order to consume output. This was problematic in many ways, including the fact that it was hard/impossible to interrupt the child process 'cleanly' and timeout operations.
Therefore, what is probably happening now with pty is that once any output becomes available it is consumed using unix select from underlying system and straight away printed out. In many ways this is what you would expect. I actually don't know how to fix this at this moment as it maybe a Ruby thing and how it deals with non-blocking stream reads when PTY terminal is used. I really need to get on with other projects but if you have time to investigate and submit PR I will review asap and release new version. This is one of those things that can 'consume' hours to figure out which I don't have at the moment.
Fair enough, thanks for explaining. I'm unsure if/when I'd look more into it. Feel free to close the issue if you don't want to keep it around.
I don't think this will ever be fixed. Before the change, I was calling gets on the output streams. That's pretty dangerous in many instances. Firstly, it always waits for a newline input, which in your case made things look good when logging but is a rather seriously flawed. In other words, unless a newline is provided on the output the whole reading will be blocked and no output provided. More importantly, there is no 'clean' way to break such reading in cases when script actually hungs. By reading output as we get it and bufferring it, we get output straight away.
What I found testing example case is that the pty is much slower than regular unix pipe, it is an actually full blown terminal emulator! That's why when running command without pty you get all output for the inspected files on one line as there is no overhead. I have run small simulation just printing dots and noticed that sometimes when I run it in pty mode they all get printed on one line, and sometimes they don't, but given sufficient delay between prints the dots are always printed on individual lines. Does that make sense?
I do believe that current implementation is far superior to previous as it allows for proper timeouts and most importantly reads output as it becomes avilable without hanging. I will investigate further if there is a way to have a whole line output but I wouldn't hold your hopes.
By reading output as we get it and bufferring it
Would it make sense to buffer it until a newline is received? As an option?
@jrochkind It's not necessarily a matter of receiving a newline character. gets stops reading also when the scripts exist or the writing pipe is closed. Most importantly, the colouring output works and this only affects the :pty option, which is not even supported on Windows, in a stylistic output way. The current implementation is beneficial in many ways, apart from having timeouts, it gets me closer to implementing #34.
@thisismydesign Given that this is purely an output issue I think you could solve it by using @jrochkind suggestion of bufferring output. However, I believe this could and should be done at the printer level. There are already vars for storring both outputs. You could buffer the output and print it only on successful exit. I stick to semantic versoninig so I won't break any printers in 0.8.* verisions and probably going forward. The command parameter gives me more all the flexibility.
Hmm, a new buffering printer (or an option in the current printer) might be useful, without breaking semantic versioning? Perhaps options to buffer only until a newline (as well as termination), as well as an option to buffer until termination.
(Although you know technically semver places virtually no restrictions on pre-1.0 versions -- and also argues strongly that once it's being used in production, it should be 1.0. Avoiding breaking changes between minor versions in pre-1.0 may not be unreasonable, but actually isn't the semver.org spec).
@jrochkind I really don't think an option is a right way to go. That would blossom the complexity of pretty printer even further and would only work in rare cases of streaming dots together with :pty option set, which is not enabled by default. If @thisismydesign could adjust his printer based on the pretty printer that would be my preferred way to go. Are you experiencing similar issues with your script?
That's one of the reasons I hold off releasing v1.0.0 to retain the flexibility to change api and allow the gem to mature like wine by being heavily used. More importantly to me v1.0 is a sign that I've finished designing an API which in this case I haven't. However, this is not to say that I intentionally will keep breaking things without a rhyme or reason. I may even write a blog article this year about my weird reasoning.
I have experienced similar issues in the past, and would love a generalized solution, but I didn't really dig into it at the time.
Hmmm streaming vs buffering printer... I suppose we could have :stream_output option by default set to true... Does anyone fancy submitting PR?
Here's a simplified printer that solves my issue: https://github.com/thisismydesign/autowow/blob/ff4da5eb98acfa30e3c9731e3ab3179f8a9bee79/lib/autowow/executor.rb#L22-L47
I used a new, common aggregator instead of the vars @piotrmurach mentioned because 1, I'm not sure whether it'd mess with other features of Pretty and 2, I want to keep the order of output regardless stdout/stderr.
Output:
[fea3fa12] Running rubocop --parallel
[fea3fa12] .rubocop.yml: Lint/EndAlignment has the wrong namespace - should be Layout
[fea3fa12] Inspecting 28 files
[fea3fa12] ............................
[fea3fa12]
[fea3fa12] 28 files inspected, no offenses detected
[fea3fa12] Finished in 1.357 seconds with exit status 0 (successful)
Would a PR along these lines (with an option as discussed) work for you?
On a side note I noticed that stderr is printed in red which I think should not be the case with :pty. But this is something to be addressed separately if at all. :)
I like it! The only thing I'm still unsure is how to handle the option. I'm swaying more in the direction of having an actual new printer called pretty_bufferred or similar which would basically indicate to people that they are using a different printer rather than setting & changing how tty-command works internally. This would avoid the idea that there maybe a mode of running commands that streams vs buffers output, which wouldn't be true. Any thoughts? Once we have a solution I definietly would encourage a PR!
As far as I know, stderr is not different from stdout in the way it handles escape codes and as such should work fine with/without :pty option. Not sure I fully appreciate why would that be a problem?
Different printer seems fine if there's an easy way set it.
It could also be an option on the printer, you'd still have to set the printer explicitly, cause you'd have to set it to one with this option set.
@jrochkind The reason I thought about having a new printer type as opposed to an extra option that applies neither to the command logic nor to all printers, it is only specific to a pretty printer, in which case a specific printer type kind of makes sense. However, as you say having :pretty type with streaming: false has also an appeal to it....
sorry, can you remind me the API for setting a custom printer?
Sorry, I've had a full day travel to Japan and soon will be speaking at RubyKaigi about tty libs etc.... This is just to say that I may be a bit less responsive due to general awesomeness of Japan 😉
Congrats and have fun :)
I'm also on the side of a new printer because (as you mentioned) it better communicates what's really happening, also less config clutter.
Another note on my implementation: it doesn't print on newline character but aggregates the whole output. It'd make more sense to print on newline.
I actually have a use case (with capistrano) where aggregating the whole output might make sense. If it's easy, it could be configurable? (as an initialization option to the writer? If that makes sense for how you set custom writers) I agree if only one is to to be done, it's printing on newlines.
Improved the buffering printer to print finished lines: https://github.com/thisismydesign/autowow/blob/52339c3c6e7496eeea7863476c0ca9ef99169ccb/lib/autowow/executor.rb#L22-L59
This + the option to aggregate output is what I'd put in the PR. Just sharing my (rather slow) progress in the meanwhile.
@thisismydesign I'd like to resolve this issue... I know it's been a while... do you have time to submit PR with your suggestion?
@piotrmurach Calling this a late response is not even in the same universe, sorry. Feel free to close this issue, unfortunately I don't have the time to work on it.