Bug#1035754: openssh-server: PermitEmptyPasswords=yes causes login to take 2-4s by enabling PAM password check
Package: openssh-server
Version: 1:8.4p1-5+deb11u1
Severity: normal
X-Debbugs-Cc: za3k@za3k.com
Dear Maintainer,
* What led up to the situation?
Enable the following options in sshd_config:
PermitEmptyPasswords yes
PasswordAuthentication no # Also the default. Confirming order doesn't matter.
Log in using an ssh key.
* What was the outcome of this action?
This takes 2000-4000ms on my server. I suspect the slowness is from PAM checking passwords somehow.
The relevant log lines from the server:
May 08 13:53:48 germinate sshd[2561718]: debug1: Forked child 3847417.
May 08 13:53:48 germinate sshd[3847417]: debug1: Set /proc/self/oom_score_adj to 0
May 08 13:53:48 germinate sshd[3847417]: debug1: rexec start in 5 out 5 newsock 5 pipe 7 sock 8
May 08 13:53:48 germinate sshd[3847417]: debug1: inetd sockets after dupping: 4, 4
May 08 13:53:48 germinate sshd[3847417]: Connection from 192.168.1.100 port 54350 on 192.168.1.17 port 22 rdomain ""
May 08 13:53:48 germinate sshd[3847417]: debug1: Local version string SSH-2.0-OpenSSH_8.4p1 Debian-5+deb11u1
May 08 13:53:48 germinate sshd[3847417]: debug1: Remote protocol version 2.0, remote software version OpenSSH_9.3
May 08 13:53:48 germinate sshd[3847417]: debug1: match: OpenSSH_9.3 pat OpenSSH* compat 0x04000000
May 08 13:53:48 germinate sshd[3847417]: debug1: permanently_set_uid: 106/65534 [preauth]
May 08 13:53:48 germinate sshd[3847417]: debug1: list_hostkey_types: rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
May 08 13:53:48 germinate sshd[3847417]: debug1: SSH2_MSG_KEXINIT sent [preauth]
May 08 13:53:48 germinate sshd[3847417]: debug1: SSH2_MSG_KEXINIT received [preauth]
May 08 13:53:48 germinate sshd[3847417]: debug1: kex: algorithm: curve25519-sha256 [preauth]
May 08 13:53:48 germinate sshd[3847417]: debug1: kex: host key algorithm: ecdsa-sha2-nistp256 [preauth]
May 08 13:53:48 germinate sshd[3847417]: debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: none [preauth]
May 08 13:53:48 germinate sshd[3847417]: debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: none [preauth]
May 08 13:53:48 germinate sshd[3847417]: debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth]
May 08 13:53:48 germinate sshd[3847417]: debug1: rekey out after 134217728 blocks [preauth]
May 08 13:53:48 germinate sshd[3847417]: debug1: SSH2_MSG_NEWKEYS sent [preauth]
May 08 13:53:48 germinate sshd[3847417]: debug1: Sending SSH2_MSG_EXT_INFO [preauth]
May 08 13:53:48 germinate sshd[3847417]: debug1: expecting SSH2_MSG_NEWKEYS [preauth]
May 08 13:53:48 germinate sshd[3847417]: debug1: SSH2_MSG_NEWKEYS received [preauth]
May 08 13:53:48 germinate sshd[3847417]: debug1: rekey in after 134217728 blocks [preauth]
May 08 13:53:48 germinate sshd[3847417]: debug1: KEX done [preauth]
May 08 13:53:48 germinate sshd[3847417]: debug1: userauth-request for user zachary service ssh-connection method none [preauth]
May 08 13:53:48 germinate sshd[3847417]: debug1: attempt 0 failures 0 [preauth]
May 08 13:53:48 germinate sshd[3847417]: debug1: user zachary matched 'User zachary' at line 133
May 08 13:53:48 germinate sshd[3847417]: debug1: PAM: initializing for "zachary"
May 08 13:53:48 germinate sshd[3847417]: debug1: PAM: setting PAM_RHOST to "192.168.1.100"
May 08 13:53:48 germinate sshd[3847417]: debug1: PAM: setting PAM_TTY to "ssh"
May 08 13:53:48 germinate sshd[3847417]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=192.168.1.100 user=zachary
May 08 13:53:50 germinate sshd[3847417]: debug1: PAM: password authentication failed for zachary: Authentication failure
May 08 13:53:50 germinate sshd[3847417]: Failed none for zachary from 192.168.1.100 port 54350 ssh2
May 08 13:53:51 germinate sshd[3847417]: debug1: userauth-request for user zachary service ssh-connection method publickey [preauth]
May 08 13:53:51 germinate sshd[3847417]: debug1: attempt 1 failures 0 [preauth]
May 08 13:53:51 germinate sshd[3847417]: debug1: userauth_pubkey: test pkalg rsa-sha2-512 pkblob RSA SHA256:Zt8jjAh4Z8iQ1+219IV7eNmSnQ154QbBoJ947jVEDDk [preauth]
May 08 13:53:51 germinate sshd[3847417]: debug1: temporarily_use_uid: 1000/1000 (e=0/0)
May 08 13:53:51 germinate sshd[3847417]: debug1: trying public key file /home/zachary/.ssh/authorized_keys
May 08 13:53:51 germinate sshd[3847417]: debug1: fd 5 clearing O_NONBLOCK
May 08 13:53:51 germinate sshd[3847417]: debug1: /home/zachary/.ssh/authorized_keys:1: matching key found: RSA SHA256:Zt8jjAh4Z8iQ1+219IV7eNmSnQ154QbBoJ947jVEDDk
May 08 13:53:51 germinate sshd[3847417]: debug1: /home/zachary/.ssh/authorized_keys:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
May 08 13:53:51 germinate sshd[3847417]: Accepted key RSA SHA256:Zt8jjAh4Z8iQ1+219IV7eNmSnQ154QbBoJ947jVEDDk found at /home/zachary/.ssh/authorized_keys:1
May 08 13:53:51 germinate sshd[3847417]: debug1: restore_uid: 0/0
May 08 13:53:51 germinate sshd[3847417]: Postponed publickey for zachary from 192.168.1.100 port 54350 ssh2 [preauth]
May 08 13:53:51 germinate sshd[3847417]: debug1: userauth-request for user zachary service ssh-connection method publickey [preauth]
May 08 13:53:51 germinate sshd[3847417]: debug1: attempt 2 failures 0 [preauth]
May 08 13:53:51 germinate sshd[3847417]: debug1: temporarily_use_uid: 1000/1000 (e=0/0)
May 08 13:53:51 germinate sshd[3847417]: debug1: trying public key file /home/zachary/.ssh/authorized_keys
May 08 13:53:51 germinate sshd[3847417]: debug1: fd 5 clearing O_NONBLOCK
May 08 13:53:51 germinate sshd[3847417]: debug1: /home/zachary/.ssh/authorized_keys:1: matching key found: RSA SHA256:Zt8jjAh4Z8iQ1+219IV7eNmSnQ154QbBoJ947jVEDDk
May 08 13:53:51 germinate sshd[3847417]: debug1: /home/zachary/.ssh/authorized_keys:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
May 08 13:53:51 germinate sshd[3847417]: Accepted key RSA SHA256:Zt8jjAh4Z8iQ1+219IV7eNmSnQ154QbBoJ947jVEDDk found at /home/zachary/.ssh/authorized_keys:1
May 08 13:53:51 germinate sshd[3847417]: debug1: restore_uid: 0/0
May 08 13:53:51 germinate sshd[3847417]: debug1: auth_activate_options: setting new authentication options
May 08 13:53:51 germinate sshd[3847417]: debug1: do_pam_account: called
May 08 13:53:51 germinate sshd[3847417]: Accepted publickey for zachary from 192.168.1.100 port 54350 ssh2: RSA SHA256:Zt8jjAh4Z8iQ1+219IV7eNmSnQ154QbBoJ947jVEDDk
May 08 13:53:51 germinate sshd[3847417]: debug1: monitor_child_preauth: zachary has been authenticated by privileged process
May 08 13:53:51 germinate sshd[3847417]: debug1: auth_activate_options: setting new authentication options [preauth]
May 08 13:53:51 germinate sshd[3847417]: debug1: monitor_read_log: child log fd closed
May 08 13:53:51 germinate sshd[3847417]: debug1: PAM: establishing credentials
May 08 13:53:51 germinate sshd[3847417]: debug1: PAM: pam_setcred(): Failure setting user credentials
May 08 13:53:51 germinate sshd[3847417]: pam_unix(sshd:session): session opened for user zachary(uid=1000) by (uid=0)
May 08 13:53:51 germinate sshd[3847417]: User child is on pid 3868868
* What exactly did you do (or not do) that was effective (or ineffective)?
Adding -o PasswordAuthentication=no to the ssh client invocation has no effect, nor does manually specifying -i.
Removing the line PermitEmptyPasswords, it takes ~250ms on my server.
* What outcome did you expect instead?
I expect "PasswordAuthentication no" to mean PAM does not check anything about passwords, and to override "PermitEmptyPasswords yes"
I believe this would affect upstream, but I can't confirm.
-- System Information:
Debian Release: 11.7
APT prefers stable-updates
APT policy: (500, 'stable-updates'), (500, 'stable')
Architecture: amd64 (x86_64)
Foreign Architectures: i386
Kernel: Linux 5.10.0-20-amd64 (SMP w/4 CPU threads)
Kernel taint flags: TAINT_PROPRIETARY_MODULE, TAINT_WARN, TAINT_OOT_MODULE, TAINT_UNSIGNED_MODULE
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8), LANGUAGE not set
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)
LSM: AppArmor: enabled
Versions of packages openssh-server depends on:
ii adduser 3.118
ii debconf [debconf-2.0] 1.5.77
ii dpkg 1.20.12
ii libaudit1 1:3.0-2
ii libc6 2.31-13+deb11u6
ii libcom-err2 1.46.2-2
ii libcrypt1 1:4.4.18-4
ii libgssapi-krb5-2 1.18.3-6+deb11u3
ii libkrb5-3 1.18.3-6+deb11u3
ii libpam-modules 1.4.0-9+deb11u1
ii libpam-runtime 1.4.0-9+deb11u1
ii libpam0g 1.4.0-9+deb11u1
ii libselinux1 3.1-3
ii libssl1.1 1.1.1n-0+deb11u4
ii libsystemd0 247.3-7+deb11u2
ii libwrap0 7.6.q-31
ii lsb-base 11.1.0
ii openssh-client 1:8.4p1-5+deb11u1
ii openssh-sftp-server 1:8.4p1-5+deb11u1
ii procps 2:3.3.17-5
ii runit-helper 2.10.3
ii ucf 3.0043
ii zlib1g 1:1.2.11.dfsg-2+deb11u2
Versions of packages openssh-server recommends:
ii libpam-systemd [logind] 247.3-7+deb11u2
ii ncurses-term 6.2+20201114-2+deb11u1
ii xauth 1:1.1-1
Versions of packages openssh-server suggests:
pn molly-guard <none>
pn monkeysphere <none>
pn ssh-askpass <none>
pn ufw <none>
-- debconf information excluded
Reply to: