SSH debugging sucks

How much human productivity is lost every day due to the horrible debugging messages in SSH? I bet it is thousands of hours world-wide. It isn't just sysadmins: programmers, web developers, and many non-technical users are frustrated by this.

I'm pretty good at debugging ssh authentication problems. The sad fact is that most of my methodology involves ignoring the debug messages and just "knowing" what to check. That's a sad state of affairs.

The debug messages for "ssh -v" should look like this:

HELLO!
I AM TRYING TO LOG IN. I'VE TOLD THE SERVER I CAN USE (method,method,method).
I AM NOW TRYING TO LOG IN VIA (method).
I AM SENDING (public key).
THAT DID NOT WORK. I AM SAD.
I AM NOW TRYING TO LOG IN VIA (method).
I AM SENDING USERNAME foo AND a password of length x.
THAT DID WORK. I AM LOGGING IN.  I AM HAPPY.</code>

Similarly on the server side, "ssd -d" should look more like:

HELLO!
SOMEONE HAS CONTACTED ME FROM IP ADDRESS 1.1.1.1.
THEY HAVE TOLD ME THEY CAN LOG IN USING THE FOLLOWING METHODS: (method1,method2,method3).
THEY ARE NOW TRYING (method)
THEY GAVE ME (first 100 bytes of base64 of public key)
THAT DID NOT WORK.
TIME TO TRY THE NEXT METHOD.
THEY ARE NOW TRYING (method)
THEY GAVE ME A PASSWORD OF LENGTH x
THAT DID WORK.
I WILL LET THEM LOG IN NOW.

Instead we have to look at messages like:

debug1: monitor_child_preauth: tal has been authenticated by privileged process
debug3: mm_get_keystate: Waiting for new keys
debug3: mm_request_receive_expect entering: type 26
debug3: mm_request_receive entering
debug3: mm_newkeys_from_blob: 0x801410a80(150)
debug2: mac_setup: found [email protected]
debug3: mm_get_keystate: Waiting for second key
debug3: mm_newkeys_from_blob: 0x801410a80(150)

Sigh.

I actually started looking at the source code to OpenSSH today to see how difficult this would be. It doesn't look too difficult. Sadly I had to stop myself because I was procrastinating from the project I really needed to be working on.

I'd consider paying a "bounty" to someone that would submit a patch to OpenSSH that would make the debug logs dead simple to understand. Maybe a kickstarter would be a better idea.

The hard part would be deciding what the messages should be. I like the Kibo-esque (well, actually B1FF-esque) version above. I hope you do too.

If anyone is interested in working on this, I'd be glad to give input. If someone wants to do a kickstarter I promise to be the first to donate.

Posted by Tom Limoncelli in Rants

No TrackBacks

TrackBack URL: http://everythingsysadmin.com/cgi-bin/mt-tb.cgi/1702

4 Comments | Leave a comment

I'd donate to a project that made it unnecessary to debug ssh or sshd, or read these messages in either form. No, I don't know how to go about it.

I somewhat agree; however, I wish the best of luck wanting to submit those patches to Theo de Raadt.

I think I understand your point - which I think has to do with how people need to understand both protocol and program intent to get anything useful done.

But one issue might be that changing these messages could easily break systems (for example, where ssh runs under expect with verbose on to, to test that remote systems are configured properly). This seems unlikely but there are a ton of tech outfits out there nowadays and I feel very uncomfortable overgeneralizing about them.

Another issue, of course, is the whole "if it's not broke, don't fix it". You've argued here - validly - that the incomprehensibility of the messages means that it's broken. But going back to the hypothetical example of wrapping ssh in "expect", we can imagine fixing this issue without touching the ssh code at all, by wrapping it and treating it as a module with a well defined interface. (Of course, this also has some security implications. But they might be unavoidable.)

On the other hand, these existing messages are good search engine fodder, precisely because they are [currently] arbitrary. And that's something you lose when you go to common english words and phrases for diagnostic messages. Just changing the messages disconnects you from a wealth of historical information.

That said, this sounds like it might be a fun project, and I am debating with myself whether implementing this has enough entertainment value (for myself) to be worth spending the time on it. And, if nothing else, this was fun to read.

That's an interesting point about "expect" and similar systems. However the debug messages that I'm talking about are only visible when "-d" (debug) mode is on, and the source code shows these messages as the result of calls to debug(), debug2() and debug3(), which indicates to me that they could change at any time. I've written many "expect" scripts for ssh and I've never had "-d" enabled. I think depending on those would be trouble.

One thing I realized after writing the original post was that the messages are definitely written for developers debugging code, not users debugging configurations.

I agree that this would be a fun project. Just adding new calls that announce which auth method is being tried and what the parameters are (except, of course, PII) would be a major win.

For example, I don't think the messages ever say "That failed! Trying next method!" It was an "ah ha!" moment for me to realize that if it was trying the next method that could only mean that the previous method had failed. I had been looking for positive confirmation that there was a failure, instead I had to look for the absence of evidence. There was no "grocery store conveyor belt divider" between attempts.

I look forward to your results!

Leave a comment