openssh bugs - Jun 2015 - [Bug 2415] New: Public key failures are not counted and therefore not logged into syslog

https://bugzilla.mindrot.org/show_bug.cgi?id=2415

            Bug ID: 2415
           Summary: Public key failures are not counted and therefore not
                    logged into syslog
           Product: Portable OpenSSH
           Version: 6.8p1
          Hardware: Other
                OS: Linux
            Status: NEW
          Severity: normal
          Priority: P5
         Component: sshd
          Assignee: unassigned-bugs at mindrot.org
          Reporter: jjelen at redhat.com

Our customer found out that public key failures are not logged and
before turning VERBOSE log level, the only message you see in syslog is
> Jun 17 08:39:12 vm183 sshd[90005]: Connection closed by 10.65.x.x [preauth]
which is different to normal password authentication.

Further code reading led me to function auth_log() in auth.c:286 where
you can see that the other methods than password should be logged only
if you exceed the half of max_authtries option. That makes sense since
many people just throw their public keys everywhere therefore logging
every failure doesn't make sense.

But as I tried to push more keys to switch on this knob on, it appeared
that in this context, authctxt->failures variable is ALWAYS zero for
pubkey authentication! This is caused by the fact, that this log
message is issued only from monitor process, but pubkey failures are
counted ONLY in preauth child's authctxt. I was browsing through the
git history, but I didn't find any moment when it could have been
working (maybe before implementation of privilege separation, when
there was only one authctxt?).

The difference between password authentication and pubkey is, that this
log is called from mm_answer_keyallowed instead of standard cycle
monitor_child_preauth.

Fix is pretty easy, just increment failures value before (or after as
other log calls?) calling the log function in monitor.c, but of course
I want to make sure that I didn't miss something from protocol
specification. But everything looks like prepared for this, except it
doesn't work.

diff --git a/monitor.c b/monitor.c
--- a/monitor.c
+++ b/monitor.c
@@ -1267,6 +1267,7 @@ mm_answer_keyallowed(int sock, Buffer *m)
         hostbased_chost = chost;
     } else {
         /* Log failed attempt */
+        authctxt->failures++;
         auth_log(authctxt, 0, 0, auth_method, NULL);
         free(blob);
         free(cuser);

-- 
You are receiving this mail because:
You are watching the assignee of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=2415

Damien Miller <djm at mindrot.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |djm at mindrot.org

--- Comment #1 from Damien Miller <djm at mindrot.org> ---
We intentionally don't count as failures publickey "queries" that
ask
whether a key would be successful without actually sending a private
key signature. These are short-circuited by authctxt->postponed in
userauth_finish(), but they are logged at level verbose(), e.g.

Jun 19 09:44:18 fuyu sshd[28116]: Failed publickey for djm from
192.168.0.1 port 41044 ssh2: ECDSA
SHA256:7cx+uylHKpQJ+82IFYk7bKj/E0qWJv/m4PzvsKMkHNy

-- 
You are receiving this mail because:
You are watching someone on the CC list of the bug.
You are watching the assignee of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=2415

--- Comment #2 from Jakub Jelen <jjelen at redhat.com> ---
Yes, I got the point about verbose. I believe that these messages are
not much useful, especially the first few of them and if it fails in
this early phase of checking public key.

But when I was debugging this issue, the failures were counted in child
as I stated above. It is pretty confusing that there is the same
variable authctxt->failures used in different contexts. Especially when
you watch this variable in auth_log function, it is once 0 and once
non-zero (as progressing with different keys), depending on who calls
it.

The line in auth_log()
>         authctxt->failures >= options.max_authtries / 2 ||
led me to the question if it is really expected to have this value
always-zero in context of public key authentication. Yes, it doesn't
make sense to log every attempt. But repetitive attempts can be
potentially threat.

-- 
You are receiving this mail because:
You are watching the assignee of the bug.
You are watching someone on the CC list of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=2415

--- Comment #3 from Damien Miller <djm at mindrot.org> ---
Right, but SSH2_MSG_USERAUTH_PK_OK tests are not really "authentication
attempts" because they don't include a signature.

Attempts that do include a signature are treated like every other
authentication attempt wrt logging and maxauthtries handling. In the
monitor, authctxt->failures gets incremented in the main
monitor_child_preauth() after mm_answer_keyverify() returns without
completing authentication.

The monitor and preauth privsep process failures counter should not be
out of sync, but keyallowed isn't the right place to increment it
because it will put it out of sync in a different way :/

I just noticed that the increment in monitor.c is wrong in a different
way though, it fails to account for partial authentication that
shouldn't increment the counter.

-- 
You are receiving this mail because:
You are watching the assignee of the bug.
You are watching someone on the CC list of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=2415

--- Comment #4 from Damien Miller <djm at mindrot.org> ---
btw, the partial authentication increment problem was fixed a couple of
releases ago in commit 9488538a726951e82b3a4374f3c558d72c80a89b

-- 
You are receiving this mail because:
You are watching someone on the CC list of the bug.
You are watching the assignee of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=2415

--- Comment #5 from Damien Miller <djm at mindrot.org> ---
Is there anything left to do on this bug, given that not treating
signature-less PK queries as auth attempts is intended behaviour?

-- 
You are receiving this mail because:
You are watching the assignee of the bug.
You are watching someone on the CC list of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=2415

Jakub Jelen <jjelen at redhat.com> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
         Resolution|---                         |INVALID
             Status|NEW                         |RESOLVED

--- Comment #6 from Jakub Jelen <jjelen at redhat.com> ---
Thank you for explaining the details I was missing in the start. It
looks good to me now.

-- 
You are receiving this mail because:
You are watching someone on the CC list of the bug.
You are watching the assignee of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=2415

Damien Miller <djm at mindrot.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|RESOLVED                    |CLOSED

--- Comment #7 from Damien Miller <djm at mindrot.org> ---
Close all resolved bugs after release of OpenSSH 7.7.

-- 
You are receiving this mail because:
You are watching the assignee of the bug.
You are watching someone on the CC list of the bug.