tty-command icon indicating copy to clipboard operation
tty-command copied to clipboard

Streamed output printed on new lines with `pty` option since v0.8.0

Open thisismydesign opened this issue 7 years ago • 22 comments
trafficstars

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.

thisismydesign avatar Apr 24 '18 11:04 thisismydesign

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)

thisismydesign avatar Apr 24 '18 13:04 thisismydesign

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.

piotrmurach avatar Apr 25 '18 11:04 piotrmurach

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.

thisismydesign avatar Apr 25 '18 12:04 thisismydesign

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.

piotrmurach avatar Apr 26 '18 22:04 piotrmurach

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 avatar Apr 26 '18 22:04 jrochkind

@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 https://github.com/piotrmurach/tty-command/issues/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.

piotrmurach avatar May 20 '18 13:05 piotrmurach

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 avatar May 20 '18 14:05 jrochkind

@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.

piotrmurach avatar May 20 '18 14:05 piotrmurach

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.

jrochkind avatar May 20 '18 16:05 jrochkind

Hmmm streaming vs buffering printer... I suppose we could have :stream_output option by default set to true... Does anyone fancy submitting PR?

piotrmurach avatar May 20 '18 16:05 piotrmurach

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. :)

thisismydesign avatar May 24 '18 14:05 thisismydesign

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?

piotrmurach avatar May 24 '18 18:05 piotrmurach

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 avatar May 24 '18 19:05 jrochkind

@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....

piotrmurach avatar May 24 '18 19:05 piotrmurach

sorry, can you remind me the API for setting a custom printer?

jrochkind avatar May 24 '18 22:05 jrochkind

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 😉

piotrmurach avatar May 27 '18 13:05 piotrmurach

Congrats and have fun :)

thisismydesign avatar May 27 '18 13:05 thisismydesign

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.

thisismydesign avatar May 28 '18 13:05 thisismydesign

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.

jrochkind avatar May 28 '18 14:05 jrochkind

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 avatar Jun 04 '18 14:06 thisismydesign

@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 avatar Aug 10 '18 21:08 piotrmurach

@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.

thisismydesign avatar Jan 13 '19 20:01 thisismydesign