Bug 2709 - Permission Error logged at Debug
Summary: Permission Error logged at Debug
Status: CLOSED FIXED
Alias: None
Product: Portable OpenSSH
Classification: Unclassified
Component: sshd (show other bugs)
Version: 7.2p2
Hardware: 68k Linux
: P5 enhancement
Assignee: Damien Miller
URL:
Keywords:
Depends on:
Blocks: V_7_6
  Show dependency treegraph
 
Reported: 2017-04-15 05:44 AEST by Clay Gerrard
Modified: 2021-04-23 15:03 AEST (History)
2 users (show)

See Also:


Attachments
more manual text about debugging failed public key authentication (636 bytes, patch)
2017-06-02 15:48 AEST, Damien Miller
dtucker: ok+
Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Clay Gerrard 2017-04-15 05:44:22 AEST
Took me an extra few minutes to get my aws instance setup because the error message I needed was logged at DEBUG instead instead of >INFO

https://github.com/openssh/openssh-portable/blob/2f2ffa4fbe4b671bbffa0611f15ba44cff64d58e/auth.c#L578

The users authorized_keys file was 700 and had the right key - but owned by root :P

The client show'd it was trying the right private key, sshd in auth.log just said:

Apr 14 19:02:49 ip-172-30-0-16 sshd[1638]: Connection closed by 38.140.31.130 port 59865 [preauth]

When I bumped the log level and restarted sshd it was obvious:

Apr 14 19:24:37 ip-172-30-0-16 sshd[2756]: debug1: Could not open authorized keys '/home/clayg/.ssh/authorized_keys': Permission denied

<shrug>

Not complaining!  Very glad the log message was there at debug!

Thanks!
Comment 1 Damien Miller 2017-06-02 15:48:48 AEST
Created attachment 2988 [details]
more manual text about debugging failed public key authentication

I don't think I want to change the loglevel from debug, because it is IMO debugging information. We have a bit in the manual recommending running ssh with -v or LogLevel elevated to debug authentication problems, but I note that we don't repeat this in the AUTHENTICATION section of the ssh(1) manual. This patch repeats the advice there.
Comment 2 Clay Gerrard 2017-06-03 02:19:03 AEST
You're probably right.  But please consider...

Unlike ENOENT - the permissions error is not really an expected normal condition.  Consider when the permissions are *too* permissive:

Jun  2 16:05:44 localhost sshd[3343]: Authentication refused: bad ownership or modes for file /home/ubuntu/.ssh/authorized_keys

Or this message when the file is a directory:

Jun  2 16:14:17 localhost sshd[3421]: User ubuntu authorized keys /home/ubuntu/.ssh/authorized_keys is not a regular file

Where as when the user/owner is wrong (which causes an error trying to read the file) - AFAICT there is no helpful/clarifying message printed unless the log level is DEBUG.

Which is *fine* - but I think this EPERM is hardly something you would expect to be any more unlikely/common than the file's mode, or it being a non-regular file.

OTOH, if there was some more esoteric error reading the file.... well that might be *very* interesting/noteworthy.

/me shrugs

Thanks for the response and suggested doc patch, very helpful/responsive.  I appreciate your maintenance/service.  Thank you!
Comment 3 Damien Miller 2017-06-09 16:44:46 AEST
Unfortunately the mechanism used to transmit this information to the client is a general transport-level debugging message. There's no way to distinguish between something that the server is sending to indicate an error condition and other debug messages.

Anyway, I've committed the manual bit.
Comment 4 Damien Miller 2021-04-23 15:03:56 AEST
closing resolved bugs as of 8.6p1 release