comment to bug about logging.
[monkeysphere.git] / website / bugs / monkeysphere-ssh-proxycommand-quiet-option.mdwn
index 028c8f9dd98a4906f3520cc84ef4b60e28418419..4070d0a2f907b3b1161be7d89ba800f4b0988585 100644 (file)
@@ -13,7 +13,8 @@ And like this for a server participating:
                ms:   * acceptable key found.
                ms: known_hosts file updated.
 
-However, I have some batch scripts that run ssh that also provide output, so the monkeysphere output clutters things up.
+However, I have some batch scripts that run ssh that also provide
+output, so the monkeysphere output clutters things up.
 
 I would really like to either have a -q/--quiet option, or, preferable for me
 at least, would be for silent output to be the default and have a -v/--verbose
@@ -32,3 +33,215 @@ personally.  It's more in keeping with the model we've used in general
 so far.
 
 --dkg
+
+------
+
+I just completed this feature. I published it to a separate branch
+(called quiet-mode). I haven't committed it to my master branch for a
+couple reasons:
+
+ * I made some significant changes and wanted to ask Big Jimmy to take
+ a look since it's mostly his stuff I mucked about with.
+
+ * Sometime between starting my hacking and mid-way through, my
+ ~.ssh/known_hosts file got truncted to nothing. I recovered from a
+ backup. I couldn't figure out what caused that to happen and couldn't
+ replicate it. I was debugging my bash and what I was debugging
+ involved bash redirection, so it's reasonable to think that something
+ I did caused the problem. However, before committing we incorporate
+ this, I would appreciate another set of eyes on my code to make sure
+ I'm not doing something dangerous or just dumb :).
+
+Here's an overview of what I did: 
+
+There were two function defined in common that handle sending messages
+to the user: log and loge. They both echo the argument passed to
+standard error. The first one also echo's "ms: " (as a preface to the
+message).  loge was only called in two places and I think is left over
+cruft (let me know if I'm wrong please!).
+
+I've added drop in replacement functions: notice, info, and
+debug. I've replaced all instances of log and loge with info.
+
+If you use notice, your message will always be sent to standard error.
+If you use info, it will be sent to standard error if the env variable
+`MONKEYSPHERE_OUTPUT_QUIET` is set to off (it is off by default).  If
+you use debug, it will be sent to standard error only if
+`MONKEYSPHERE_OUTPUT_DEBUG` is set to on (it's off by default).
+
+Lastly, in monkeysphere-ssh-proxycommand, I've set
+`MONKEYSPHERE_QUIET_MODE` to on by default.
+
+So the result is: when using monkeysphere-ssh-proxycommand, you will
+not get any output unless you set `MONEKYSPHERE_OUTPUT_QUIET` to off
+or `MONKEYSPHERE_OUTPUT_DEBUG` to on. All other commands should work
+exactly like they did in the past.
+
+And... we can go through the code and change calls to the info
+function to either notice (if we want them to be sent regardless of
+the `QUIET` variable) or debug (if we want it only sent if `DEBUG` is
+set).
+
+I'm open to suggestions, problems, etc :).
+
+-- SJJ
+
+------
+
+Hey, your Royal Highness.  I do think it's good that I look over these
+changes, because there are definitely some stuff (ie. key processing)
+that requires that things go to stderr and definitely not to stdout.
+I can see that if that were changed, it's possible that things could
+go wrong (ie. cause a `known_hosts` file to get truncated maybe).
+
+I have to say that I'm still not sure I totally see why it's necessary
+to implement such nuanced output switches.  All of the stuff you were
+worried about when you reported this bug, and all the stuff that
+starts with "ms:", goes to stderr.  If you didn't want to see it, can
+you not just redirect stderr to /dev/null?
+
+For what it's worth, I'm not sure *I* can ever imagine *not* wanting
+to see that stuff, since it effectively reports on whether the host
+you're connecting to is acceptable or not.  I feel like I would always
+want to see that.  I guess that's neither here nor there, though,
+cause if a user thinks it would be a good switch to have, and it's not
+too difficult to implement (as this is), then it's worth implementing.
+
+I think before we really start trying to tackle this, though, we
+should outline what is the behavior we ultimately want.  What output
+do we want to go to stdout, and do we want to be able to turn that off
+or on?  What output do we want to go to stderr, and do we want to be
+able to turn that off or on?  At the moment, most output is really
+just info for the user, which is why I was sending it all to stderr.
+Should all output then just go to stderr, with a switch to either turn
+it off or on?
+
+I should point out that we're sort of hitting a bit of a bash
+limitation here.  Some monkeysphere internal functions pass info on to
+other stuff via stdout, but also need to report stuff to the user as
+well, which means this stuff can only be passed to the user via
+stderr.
+
+In any event, I just want to outline a straightforward policy about
+output so we can know how to best handle it.
+
+-- Big Jimmy.
+
+-----
+
+I think it's important to be able to suppress "normal operation,
+everything is fine" messages *without* directing stderr to
+`/dev/null`.  This is the normal state of UNIX-style tools, especially
+tools like SSH which are used as piece of a larger toolchain.  If
+every tool in a toolchain emitted some output during successful
+operation, many scripts would be hopeless seas of noise, as it's not
+unusual for even a simple backup script to make use of a half-dozen
+separate tools.
+
+What you really want is to see some output from when a tool knows
+something is wrong.  With the proxycommand, the job of complaining
+will often be left up to `ssh` itself, after `~/.ssh/known_hosts` has
+been appropriately modified.  But sometimes, the proxycommand itself
+will fail, and if you've already directed stderr to `/dev/null` you
+won't get any reasonable information about the failure at the time it
+happens.
+
+As for the interface to adjust the verbosity, HRH SJJ's current
+proposal with a large number of environment variables seems confusing
+and overly-complex to me.
+
+i think we should follow OpenSSH's lead (since all monkeysphere users
+are likely to be somewhat familiar with it) and use a single variable
+that is set to a level.  For example, see `LogLevel` in
+`ssh_config(5)`.  It should probably default to `INFO`, same as
+`/usr/bin/ssh`.  If there was a way to extract this value from the
+user's SSH configuration/invocation itself and adopt it in the
+ProxyCommand, that would be even better, but i don't think that's a
+possibility with OpenSSH 5.1p1 at this point.
+
+Also, i agree with HRH SJJ that the distinction in the monkeysphere
+source between `log` and `loge` is unclear, and one of them should be
+dropped (or they should be better-documented in `/src/common`).
+
+       --dkg
+
+----
+
+Thanks Big Jimmy and dkg all for the good feedback.
+
+I think you're right Big Jimmy about the sterr/stout. I may have
+accidentally output to stout instead of sterr. In any event - I think
+all of the logging should go to sterr to avoid that.
+
+Here's a proposed fix based on both of your responses - it tries to make
+my changes a bit simpler and more consistent with ssh behavior:
+
+ * Use on environmental variable: `MONKEYSPHERE_LOG_LEVEL` that can be set
+ to `ERROR` or `INFO`, with the default being `INFO`.
+ `monkeysphere-ssh-proxycommand`, however, will set the
+ `MONKEYSPHERE_LOG_LEVEL` to `ERROR` unless the user overrides that setting.
+
+ * Use two functions for reporting messages to the user via sterr that
+ will replace the existing log/loge functions: info (for outputting
+ "normal operation, everything's fine" messages) and error (for
+ outputting messages that indicate a problem that we think a user should
+ know about). Reporting a message to the user with the info function
+ will only be sent if the `MONKEYSPHERE_LOG_LEVEL` setting is `INFO`.
+ Reporting a message to the user with the error function will always be
+ output regardless of the `MONKEYSPHERE_LOG_LEVEL` value.
+
+ * Go through the code and, for each use of the current log/loge
+ function, determine if they should be replaced with info or error 
+ depending on how critical we think the message is.
+
+How does that sound? 
+
+  --Sir Jam Jam
+
+-----
+
+Sir Jam Jam's proposal sounds good to me, but why make it two separate
+functions?  Given the number of log levels used by OpenSSH, i'd prefer
+to make a single function that takes two arguments: the first argument
+is the level of the log, and the second argument is the data to be
+logged itself.  So you'd say:
+
+  log error "This is really terrible and broken!"
+  log info "The fuzzy bunny just smiled at you and nodded."
+
+Is that a reasonable amendment?  It seems like it will make it easier
+to add more levels if we find we need them, and it makes it easy to
+find every single log message in the source code at the same time.
+
+  --dkg
+
+-----
+
+I just implemented the proposal (incorporating dkg's suggestion about
+only having one function). It's committed in my quiet-mode branch (still
+not merged with master - pending review). 
+
+Thanks for all the feedback!
+
+-- SJJ
+
+----
+
+Ok, this plans makes sense.  I'll merge SJJ's patches as soon as I get
+the chance.
+
+-- BJ
+
+----
+
+I implemented a variant of SJJ's proposed changes in
+bb2427c28bf40179c4881b22c23f23f9bea78f55 (0.12 pre).  I tried to make
+it so that we could more easily expand the number of levels if need
+be.  I made a first pass at specifying which output is what priority,
+but folks should please speak up if they think the priority of any
+particular output should be changed.
+
+I'll leave the bug open for a bit until it get more tested and 0.12
+gets pushed out.
+
+-- BJ