Bug 234793 - Failed unknown for $USER in sshd logs even if I got authenticated
Summary: Failed unknown for $USER in sshd logs even if I got authenticated
Status: New
Alias: None
Product: Base System
Classification: Unclassified
Component: bin (show other bugs)
Version: 12.0-RELEASE
Hardware: amd64 Any
: --- Affects Some People
Assignee: Ed Maste
Depends on:
Reported: 2019-01-09 16:24 UTC by Sverre
Modified: 2019-11-20 16:31 UTC (History)
29 users (show)

See Also:

client-ssh-verbose.md (12.00 KB, text/plain)
2019-01-13 10:47 UTC, Egbert Pot
no flags Details
server--auth.log (1.38 KB, text/plain)
2019-01-13 10:48 UTC, Egbert Pot
no flags Details
server--sshd_config (3.91 KB, text/plain)
2019-01-13 10:49 UTC, Egbert Pot
no flags Details
Auth.log, sshd_config and level 3 debug of client (14.09 KB, text/plain)
2019-01-27 23:07 UTC, holmez
no flags Details
sshd debug (19.58 KB, text/plain)
2019-02-05 12:49 UTC, David Froehlich
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Sverre 2019-01-09 16:24:10 UTC
If I ssh into a box with 12.0-RELEASE I get in fine, but the server logs that my attempt Failed for $USER ... Looks weird and I saw this one dude online that complained about this causing fail2ban to add him to the ban list. This is not an issue on 11.2 with exactly the same setup and keys and users.
Comment 1 Egbert Pot 2019-01-13 10:47:11 UTC
Created attachment 201093 [details]
Comment 2 Egbert Pot 2019-01-13 10:48:23 UTC
Created attachment 201094 [details]
Comment 3 Egbert Pot 2019-01-13 10:49:12 UTC
Created attachment 201095 [details]
Comment 4 Egbert Pot 2019-01-13 10:50:44 UTC
I I have the same issue as @Sverre. Due to this issue I cannot use Fail2Ban, since it also bans successful logins.

To help debugging this issue, I've added:
* SSH server configuration from /etc/ssh/sshd_config on the FreeBSD12 system; see server--sshd_config
* SSH server's authentication log output /var/log/auth.log; see server--auth.log
* Very verbose output of the SSH session initiated by the client; see client-ssh-verbose.md

Information on the SSH server - FreeBSD 12

$ uname -a
FreeBSD gatekeeper 12.0-RELEASE FreeBSD 12.0-RELEASE r341666 GENERIC  amd64

$ getconf LONG_BIT

$ uname -K

$ uname -U

$ sshd --help
sshd: illegal option -- -
OpenSSH_7.8p1, OpenSSL 1.1.1a-freebsd  20 Nov 2018

Information on the SSH client - OSx 10.14.2

$ sw_vers
ProductName:	Mac OS X
ProductVersion:	10.14.2
BuildVersion:	18C54

$ ssh -V
OpenSSH_7.9p1, LibreSSL 2.7.3
Comment 5 Ryan 2019-01-18 18:10:47 UTC
I'm also seeing this happening across multiple machines since updating to 12.0-RELEASE.  My sshd_config, auth.log, and client verbose log match the files uploaded by Egbert.

My server environment is:

$ uname -a
FreeBSD gateway 12.0-RELEASE-p2 FreeBSD 12.0-RELEASE-p2 GENERIC  amd64

$ getconf LONG_BIT

$ uname -K

$ uname -U

$ sshd --help
sshd: illegal option -- -
OpenSSH_7.8p1, OpenSSL 1.1.1a-freebsd  20 Nov 2018

I'm pretty confident saying that it's not a client issue, since I've tried all of the following and have received the same results with them all:

- The above mentioned FreeBSD server
- MacOS 10.14.2, OpenSSH_7.9p1, LibreSSL 2.7.3
- Blink for iOS v12.4.81
- PuTTY 0.69 on Windows 10
Comment 6 Morgan Vandagriff 2019-01-26 18:48:21 UTC
I can also confirm this on multiple amd64 machines upgraded to 12.0-RELEASE.
Comment 7 holmez 2019-01-27 23:07:29 UTC
Created attachment 201466 [details]
Auth.log, sshd_config and level 3 debug of client

same here on FreeBSD 12.0-STABLE (as of 2019-01-08)
Comment 8 David Froehlich 2019-02-05 12:49:47 UTC
Created attachment 201758 [details]
sshd debug

Same issue here.
I have attached a debug of the sshd.
The spurious errors are in line 171 and 209.
Comment 9 Thomas Guymer 2019-02-10 12:38:13 UTC
I too am also getting these lines in my logs since updating to 12.0-RELEASE yesterday. I too can no longer use "sshguard" as it is blocking *all* machines that connect, even the ones that are allowed.
Comment 10 Peter Putzer 2019-02-22 20:12:05 UTC
Same problem here (amd64 server upgraded from FreeBSD 11.2), including the trouble with Sshguard :(
Comment 11 Rihad 2019-02-23 16:45:27 UTC
Same problem here on 12.0-RELEASE-p3. The lines appear in "daily security run output" as login failures, which they aren't really.
Comment 12 Peter Putzer 2019-02-23 22:21:55 UTC
For now, I've worked around the issue by switching to openssh-portable from ports.
Comment 13 Trev 2019-02-24 05:46:39 UTC
Same problem here on 12.0-RELEASE-p3. The lines appear in "daily security run output" as login failures but they're not.
Comment 14 Jamie Baxter 2019-04-06 21:22:58 UTC
Seeing the same issue here on all FreeBSD 12.0 machines. Seeing 3 "Failed unknown for $USER from $IP port $PORT ssh2" strings on each connection showing up in auth.log at VERBOSE level or higher.

Three machines were updated from 11.2 -> 12.0 and all demonstrate this behavior. It also occurs with a new machine that installed 12.0 fresh. Had to disable sshguard on all machines until I found the number of failures in auth.log (they all locked me out after upgrade, and the new 12.0 installation locked me out after sshguard was started).

(In reply to Thomas Guymer from comment #9)
(In reply to Peter Putzer from comment #10)

With regard to sshguard problems, you should be able to get circumvent this by adjusting THRESHOLD in sshguard.conf to some value higher than 30 (if you utilize BLACKLIST_FILE, also ensure that threshold is raised to match). Do ensure your client IP is not already committed to any blacklist sshguard may use.
Comment 15 Jamie Baxter 2019-04-06 21:43:55 UTC
(In reply to Jamie Baxter from comment #14)
Or instead of touching the sshguard.conf file, you can just set the rc.conf variable sshguard_danger_thresh to something greater than 30.
Comment 16 Vincent Bentley 2019-05-17 13:21:00 UTC
Issue still present on 12.0-RELEASE-p5
Comment 17 Egbert Pot 2019-07-14 10:48:58 UTC
Issue still present on 12.0-RELEASE-p7

Is there a possibility to upgrade the OpenSSH package to version 7.9 or 8.0?
Comment 18 Rob Belics 2019-10-15 12:07:04 UTC
Just ditto'ing the same issue here.
Comment 19 mike 2019-10-18 14:08:07 UTC
Same issue here. I tried running through Truss, and I dont understand what its actually failing on

debug3: mm_answer_login_getpwclass: sending MONITOR_ANS_GETPWCLASS
write(2,"debug3: mm_answer_login_getpwcla"...,68) = 68 (0x44)
debug3: mm_request_send entering: type 51
write(2,"debug3: mm_request_send entering"...,43) = 43 (0x2b)
write(5,"\0\0\^BY3",5)                           = 5 (0x5)
write(5,"\^A\0\0\0\bstandard\0\0\^BCstand"...,600) = 600 (0x258)
Failed unknown for mdt from 192.168.xx.xx port 56886 ssh2
write(2,"Failed unknown for mdt from"...,64) = 64 (0x40)
auditon(0x25,0x7fffffffd1d4,0x4)                 = 0 (0x0)
poll({ 5/POLLIN 6/POLLIN },2,-1)                 = 1 (0x1)
read(6,"\0\0\0*",4)                              = 4 (0x4)
read(6,"\0\0\0\^C\0\0\0"user mdt lo"...,42) = 42 (0x2a)
user mdt login class standard [preauth]
write(2,"user mdt login class standa"...,46) = 46 (0x2e)
poll({ 5/POLLIN 6/POLLIN },2,-1)                 = 1 (0x1)
read(6,"\0\0\0/",4)                              = 4 (0x4)
read(6,"\0\0\0\^F\0\0\0'input_userauth_r"...,47) = 47 (0x2f)
debug2: input_userauth_request: try method none [preauth]
write(2,"debug2: input_userauth_request: "...,59) = 59 (0x3b)
Comment 20 lysfjord.daniel 2019-10-18 17:53:00 UTC
Just chiming in..

It has been like this for a good while:
SELECT COUNT(1) FROM logs WHERE program = 'sshd' AND msg like 'Failed unknown for %';
| COUNT(1) |
|    17695 |

First entry: 2019-01-07 17:33:52 (aka the same day as I upgraded to 12.0 on that server).

Full sshd.conf:

PermitRootLogin no
StrictModes yes
MaxAuthTries 2 
AllowGroups sshlogin
AuthorizedKeysFile	.ssh/authorized_keys
ChallengeResponseAuthentication yes
UsePAM yes
UseDNS no
Subsystem	sftp	/usr/libexec/sftp-server
AuthenticationMethods publickey,keyboard-interactive

auth            required        /usr/local/lib/pam_google_authenticator.so nullok
auth            required        /usr/local/lib/pam_ldap.so
account         required        pam_nologin.so
account         required        pam_login_access.so
account         sufficient        /usr/local/lib/pam_ldap.so      no_warn ignore_authinfo_unavail ignore_unknown_user
account         required        pam_unix.so
session         required        pam_permit.so
password        sufficient      /usr/local/lib/pam_ldap.so      no_warn ignore_authinfo_unavail ignore_unknown_user
password        required        pam_unix.so

I may have missed something glaringly obvious, but so far, I've just put the line "Failed unknown for" on whitelists.. The config, both for sshd and pam, is an almost word-for-word copy from the linux install the server used to have, where this message did not occur.
Comment 21 Ryan 2019-11-09 06:15:53 UTC
The issue is still present on 12.1-RELEASE.
Comment 22 xsan 2019-11-15 10:17:59 UTC
It happend on all my 3 FreeBSD 12.1-RELEASE machine. But strange is two machine only show Failed log when I have open sshd debug on inetd service, only one always show this Failed log.

There is another verion 11.2 in FreeNAS jail is Okay.
Comment 23 Henry Hu 2019-11-16 03:53:19 UTC
This bug was introduced in https://reviews.freebsd.org/rS339216. In this commit, a wrapper was added for login_getpwclass. The line in the dispatch table says:
    {MONITOR_REQ_GETPWCLASS, MON_AUTH, mm_answer_login_getpwclass},

Because the flag is MON_AUTH, which includes MON_AUTHDECIDE, which means
#define MON_AUTHDECIDE	0x0008	/* Decides Authentication */
So the result of this wrapped call is recorded through auth_log() at line 339 of monitor.c: https://svnweb.freebsd.org/base/head/crypto/openssh/monitor.c?view=markup#l343

mm_answer_login_getpwclass only retrieves some information from logincap, so it does not decide the authentication result, and it always returns 0. Thus, I think that the flag is incorrectly set. I think that the correct value should be MON_ISAUTH.
Comment 24 Yuichiro NAITO 2019-11-20 01:36:02 UTC
Henry gave us perfect answer.

I thought login_getpwclass(3) was used to decide authentication,
so I set MON_AUTH flag. But it's a mistake as Henry says.

Ssh authentication is checked by child process that is capsicumized.
Login_getpwclass(3) can not be used in capability mode (of capsicum),
so parent process proxies its execution.

mm_answer_login_getpwclass() is a proxy function in parent process.
It doesn't need to decide authentication,
is enough to return the login class information.

Changing MON_AUTH flag to MON_ISAUTH is correct fix.
Comment 25 Ed Maste freebsd_committer 2019-11-20 14:32:47 UTC
I have the change staged in my WIP tree:
(will add Reviewed by: Yuichiro NAITO upon commit to svn.)

We still receive the "user %s login class %s" message from input_userauth_request added in r314527 that I think should be revisited, but that's independent of this issue.

Nov 20 14:24:12 twelve sshd[XXXX]: user root login class  [preauth]
Nov 20 14:24:12 twelve syslogd: last message repeated 4 times
Nov 20 14:24:12 twelve sshd[XXXX]: Accepted publickey for root from XX.X.XX.XX port XXXXX ssh2: ED25519 SHA256:/...
Comment 26 commit-hook freebsd_committer 2019-11-20 16:31:34 UTC
A commit references this bug:

Author: emaste
Date: Wed Nov 20 16:30:37 UTC 2019
New revision: 354897
URL: https://svnweb.freebsd.org/changeset/base/354897

  sshd: make getpwclass wrapper MON_ISAUTH not MON_AUTH

  In r339216 a privsep wrapper was added for login_getpwclass to address
  PR 231172.  Unfortunately the change used the MON_AUTH flag in the
  wrapper, and MON_AUTH includes MON_AUTHDECIDE which triggers an
  auth_log() on each invocation.  getpwclass() does not participate in the
  authentication decision, so should be MON_ISAUTH instead.

  PR:		234793
  Submitted by:	Henry Hu
  Reviewed by:	Yuichiro NAITO
  MFC after:	1 week