PAM: Authentication failure for root from xxx.xx.x.x

[apr94]

Hello,

I am using v1.0.7 and am getting authentication failure error with the following sshd logs

debug1: auth2_challenge_start: trying authentication method 'pam' [preauth]
Postponed keyboard-interactive for root from xxx.xx.x.x port xxxxx ssh2:
PAM: Authentication failure for root from xxxx.xx.x.x
Failed keyboard-interactive/pam for root from xxx.xx.xx.x port xxxx ssh2
debug1: userauth-request for user root service ssh-connection method keyboard-interactive [preauth]

I have generated the code many times and have commented out the following line in /etc/pam.d/sshd: @include common-auth

I am sure that pam_google_authenticator is called because it display my custom prompt

Does anybody have an idea on what might be causing this? I am running ubuntu 16.04 and OpenSSH_7.2p2. Happy to give more information if needed.

[ThomasHabets]

Please provide both the full PAM config you do have for SSH, and any log lines provided not just by SSH, but also by the PAM module. Add debug to the pam_google_authenticator PAM line to get more debug output.

[apr94]

Thanks a lot for replying. Here are some updates.

I added debug to pam_google_authenticator and this was the debug output

Dec 11 19:55:55 62763fb62f43 sshd[25706]: debug1: sshd version OpenSSH_7.2, OpenSSL 1.0.2g  1 Mar 2016
Dec 11 19:55:55 62763fb62f43 sshd[25706]: debug1: private host key #0: [redacted]
Dec 11 19:55:55 62763fb62f43 sshd[25706]: debug1: private host key #1: [redacted]
Dec 11 19:55:55 62763fb62f43 sshd[25706]: debug1: private host key #2: [redacted]
Dec 11 19:55:55 62763fb62f43 sshd[25706]: debug1: private host key #3: [redacted]
Dec 11 19:55:55 62763fb62f43 sshd(pam_google_authenticator)[25708]: debug: start of google_authenticator for "root"
Dec 11 19:55:55 62763fb62f43 sshd(pam_google_authenticator)[25708]: debug: Secret file permissions are 0600. Allowed permissions are 0600
Dec 11 19:55:55 62763fb62f43 sshd(pam_google_authenticator)[25708]: debug: "/root/.google_authenticator" read
Dec 11 19:55:55 62763fb62f43 sshd(pam_google_authenticator)[25708]: debug: shared secret in "/root/.google_authenticator" processed
Dec 11 19:55:55 62763fb62f43 sshd(pam_google_authenticator)[25708]: debug: google_authenticator for host "xxx.xx.x.x"
Dec 11 19:56:04 62763fb62f43 sshd(pam_google_authenticator)[25708]: Dummy password supplied by PAM. Did OpenSSH 'PermitRootLogin <anything but yes>' or some other config block this login?
Dec 11 19:56:04 62763fb62f43 sshd(pam_google_authenticator)[25708]: Dummy password supplied by PAM. Did OpenSSH 'PermitRootLogin <anything but yes>' or some other config block this login?
Dec 11 19:56:04 62763fb62f43 sshd(pam_google_authenticator)[25708]: Invalid verification code for root
Dec 11 19:56:04 62763fb62f43 sshd(pam_google_authenticator)[25708]: debug: end of google_authenticator for "root". Result: Authentication failure

So it seemed like the verification token was incorrect. This was surprising since I had enabled the 4 minute intervals and verified the qr code matched the secret by entering both of them in my GA app. These lines caught my attention:

Dec 11 19:56:04 62763fb62f43 sshd(pam_google_authenticator)[25708]: Dummy password supplied by PAM. Did OpenSSH 'PermitRootLogin <anything but yes>' or some other config block this login?
Dec 11 19:56:04 62763fb62f43 sshd(pam_google_authenticator)[25708]: Dummy password supplied by PAM. Did OpenSSH 'PermitRootLogin <anything but yes>' or some other config block this login?

So I opened /etc/ssh/sshd and changed PermitRootLogin prohibit-password to PermitRootLogin yes

After that, I got the following debug logs

Dec 11 20:18:11 62763fb62f43 sshd(pam_google_authenticator)[25729]: debug: start of google_authenticator for "root"
Dec 11 20:18:11 62763fb62f43 sshd(pam_google_authenticator)[25729]: debug: Secret file permissions are 0600. Allowed permissions are 0600
Dec 11 20:18:11 62763fb62f43 sshd(pam_google_authenticator)[25729]: debug: "/root/.google_authenticator" read
Dec 11 20:18:11 62763fb62f43 sshd(pam_google_authenticator)[25729]: debug: shared secret in "/root/.google_authenticator" processed
Dec 11 20:18:11 62763fb62f43 sshd(pam_google_authenticator)[25729]: debug: google_authenticator for host "xxx.xx.x.x"
Dec 11 20:18:21 62763fb62f43 sshd(pam_google_authenticator)[25729]: debug: no scratch code used from "/root/.google_authenticator"
Dec 11 20:18:21 62763fb62f43 sshd(pam_google_authenticator)[25729]: Accepted google_authenticator for root
Dec 11 20:18:21 62763fb62f43 sshd(pam_google_authenticator)[25729]: debug: end of google_authenticator for "root". Result: Success

I was then able to ssh in successfully. For posterity, here is my /etc/pam.d/sshd file

# PAM configuration for the Secure Shell service

# Standard Un*x authentication.
auth required pam_google_authenticator.so debug
# @include common-auth

# Disallow non-root logins when /etc/nologin exists.
account    required     pam_nologin.so

# Uncomment and edit /etc/security/access.conf if you need to set complex
# access limits that are hard to express in sshd_config.
# account  required     pam_access.so

# Standard Un*x authorization.
@include common-account

# SELinux needs to be the first session rule.  This ensures that any
# lingering context has been cleared.  Without this it is possible that a
# module could execute code in the wrong domain.
session [success=ok ignore=ignore module_unknown=ignore default=bad]        pam_selinux.so close

# Set the loginuid process attribute.
session    required     pam_loginuid.so

# Create a new session keyring.
session    optional     pam_keyinit.so force revoke

# Standard Un*x session setup and teardown.
@include common-session

# Print the message of the day upon successful login.
# This includes a dynamically generated part from /run/motd.dynamic
# and a static (admin-editable) part from /etc/motd.
session    optional     pam_motd.so  motd=/run/motd.dynamic
session    optional     pam_motd.so noupdate

# Print the status of the user's mailbox upon successful login.
session    optional     pam_mail.so standard noenv # [1]

# Set up user limits from /etc/security/limits.conf.
session    required     pam_limits.so

# Read environment variables from /etc/environment and
# /etc/security/pam_env.conf.
session    required     pam_env.so # [1]
# In Debian 4.0 (etch), locale-related environment variables were moved to
# /etc/default/locale, so read that as well.
session    required     pam_env.so user_readenv=1 envfile=/etc/default/locale

# SELinux needs to intervene at login time to ensure that the process starts
# in the proper default security context.  Only sessions which are intended
# to run in the user's context should be run after this.
session [success=ok ignore=ignore module_unknown=ignore default=bad]        pam_selinux.so open

# Standard Un*x password updating.
# @include common-password

The only changes I have made are to comment out common-auth and common-password and add auth required pam_google_authenticator.so debug

Thanks for the help :) I am going to close this issue now.

[ThomasHabets]

Yup, that'll do it. OpenSSH needs to allow root logins using passwords for PAM auth to work with any sort of password, including OTP. debug isn't needed to see that helpful error message.

Glad I could help.