Introduce explicit command logging methods and deprecate stdout / stderr Command attrs

[robd]

At the moment, one of the hardest bits of code to understand, and the source of some historical bugs, is the @stdout, @stderr attributes on command. These are used as a temporary buffer of the latest unconsumed output lines by the formatters. The backends append to the buffer (netssh, local) via the on_stdout and on_stderr methods, and then the pretty formatter clears the buffers via the clear_stdout_lines and clear_stderr_lines methods.

As well as being hard to understand, it makes integrating with SSHKit harder. For example, Airbrussh has to dup the Command in order to make sure that stdout/stderr are not cleared by the pretty formatter.

In order to fix this, I propose to widen the Formatter API and include 3 specific methods (log_command_start, log_command_data, log_command_exit) for logging the different command states rather than switching on the internal state in Command.

The other state on Command (ie :started_at, :started, :exit_status, :full_stdout, :full_stderr) is less confusing because at least this state is all being set by the backends, and simply read by the formatters (rather than mutated). I propose to leave these for the moment.

As part of this, I'd like to deprecate @stdout and @stderr on Command to explain the changes to people who use the stdout / stderr accessors. (I deleted these previously, but I will reinstate them with deprecation warnings). In order to do this, I am intending to write a de-duplicating deprecator and introduce a new config option - SSHKit.config.deprecation_output which takes the same sort of object as the normal output (ie one which implements <<). By default, I propose to log deprecation directly to stderr. This means deprecation errors will show up for people using formatters which hide normal warnings (eg Dot or BlackHole). Deprecation warnings can easily be disabled:

# Supress deprecation warnings
SSHKit.config.deprecation_output = nil

SSHKit.config.deprecation_output = File.open('log/dep_warnings.log', 'wb')

@mattbrictson I discussed I had some ideas for this a while ago. If you don't mind, can you look at the new formatter methods and see what you think?

@leehambley Would value your thoughts on this as always.

[leehambley]

@robd the two methods clear_stdout_lines and clear_stderr_lines existed as a horrible way to try and clear the duplicate content that was sometimes seen in the race condition which was recently fixed regarding receiving the :on_exit event before the last chunk of data (where maybe the last chunk was whitespace) it's quite some time since I wrote that part though, so it's entirely possible I'm mis-remembering.

I'd be thrilled to see this merged, it's a drastic clean up, and I like the deprecation solution you've proposed, let's build it.

[mattbrictson]

@robd This looks very nice. 👍 to merge.

My only nitpick would be I think the meta-programming you've used to define methods in abstract.rb might be a little too "fancy". The primary purpose of abstract is to serve as documentation for extension authors, so I think sacrificing some DRY-ness for readability may be warranted here.

Edit: I realize this is not ready to merge yet, but I like the direction it is going!

[robd]

OK great.

Re the clear_stdout_lines and clear_stderr_lines, I added these to replace the stdout="", stderr="" writers which were there before. However I now think this was a bit dangerous, because other formatters may be relying on these writers (in fact we saw this with Airbrussh, but I wasn't thinking properly about deprecation at that point). Therefore, I propose to reinstate command.stdout= and command.stdout= with deprecation warnings, to be removed next major release.

I think it would be OK to just delete the new clear_stdout_lines and clear_stderr_lines methods I added which are now no longer needed, because these haven't ever been released. No one will be using these (unless they are developing against master). @mattbrictson there will be rework needed for Aribrussh, but I will try to put together a PR once the API changes have landed. (Welcome feedback about fancy dynamic methods. These things are a bit hard to call when you're working by yourself - will fix).

First of all I want to add support for showing deprecation warnings safely as a separate PR. I propose to add this as a separate logger to the main formatter for the following reasons:

• I tried a solution to add a warn_deprecated method to Formatter, but I ended up with an infinite loop because the method I was deprecating was being called as part of logging the deprecation warning!
• People may want to disable deprecation logging without affecting the normal logging (eg if they don't have time to fix deprecation problems)
• I want to only show each deprecation warning once per run, and I don't want the de-duping to get tangled up with the main formatters.
• We should show people deprecation warnings (which they can disable) even if they have a formatter which hides normal warnings (eg Dot) so that things don't just break without warning in a subsequent release.

I will rework the existing deprecation call we have and update the docs.

[robd]

OK, I have incorporated the feedback, deprecated the old std_out, std_err accessors and updated the docs.

From my perspective this is ready to merge.

@mattbrictson Do you want me to look at integrating this into Airbrussh? Once this PR is merged, Airbrussh will be broken again against master. I'm not quite sure what your policy is on SSHKit version support, but I think the CommandOutput facade might not be needed any more, since the version of SSHKit master with clear_#{stream}_lines was never released.

I guess we will want to override log_command_start, log_command_data and log_command_exit in the Airbrussh Formatter where appropriate, but obviously old versions of SSHKit won't call these.

Let me know if I can help.

[mattbrictson]

@robd if you want to take a stab at a PR for airbrussh, that would be fantastic. Ideally I would like airbrussh to continue working with any version of sshkit >= 1.6.1. But if the conditional code to do that is too complicated (i.e. worse than CommandOutput), I'll consider revising the minimum sshkit requirement.

[robd]

@mattbrictson No probs - I'll see what I can do :)

[robd]

The necessary Airbrussh changes are in mattbrictson/airbrussh#17.

@leehambley I wondered, would you be up for merging the Airbrussh formatter into SSHKit? This would dramatically ease maintenance of Airbrussh, because at the moment trying to support various versions of SSHKit as the formatter API changes requires quite a bit of care and effort. I don't propose to do this right now, because I want to get back to finishing up support for interactive sudo, but I wanted to find out your thoughts on this..

[leehambley]

I'd be more than happy to make it the default formatter, but I wouldn't want to put @mattbrictson in a position where his work is under appreciated, and he's insufficiently credited for it.

Open to anything, give me a break though, I'm travelling a lot this week, and next week when I'm back we're launching a new company >_<, but yeah - would love to if @mattbrictson is up for it.

@mattbrictson actually heads-up I'm in SFO the next 4 days for IO if you feel like letting me buy you a beer.

[robd]

@leehambley OK great. I don't think the Airbrussh merge is urgent - we can pick this up at some later stage once things have calmed down at your end. Have a good IO and good luck with the launch.