I am experiencing issues setting up a Freeradius server that authenticates against PAM which in turn uses the Google Authenticator module to provide TOTP.
For this setup I need troubleshooting help, as it seems there is some issue between Freeradius and PAM.
I have loosely followed these instructions: https://networkjutsu.com/freeradius-google-authenticator/ and copied most of configuration over from an old production server that currently provides this exact setup.
The issue:
I can successfully authenticate via pamtester including TOTP. However, I cannot authenticate with radtest.
root@radius:/etc/freeradius/3.0# pamtester -v radiusd testuser authenticate
pamtester: invoking pam_start(radiusd, testuser, ...)
pamtester: performing operation - authenticate
Password:
Password & verification code:
pamtester: successfully authenticated
root@radius:/etc/freeradius/3.0# radtest testuser password139943 localhost 18210 testing123
Sent Access-Request Id 55 from 0.0.0.0:53891 to 127.0.0.1:1812 length 81
User-Name = "testuser"
User-Password = "password139943"
NAS-IP-Address = 10.10.10.6
NAS-Port = 18210
Message-Authenticator = 0x00
Cleartext-Password = "password139943"
Received Access-Reject Id 55 from 127.0.0.1:1812 to 127.0.0.1:53891 length 20
(0) -: Expected Access-Accept got Access-Reject
root@radius:/etc/freeradius/3.0#
Troubleshooting so far
System time is correct, as authentication with pamtester passes.
I have added debug options to my /etc/pam.d/radiusd. This results in me getting different outputs in journalctl between using pamtester and radtest.
This seems to me that freeradius is calling PAM somehow differently and NOT using the radiusd file, even though it is stated in the debug output.
This is the log output when authenticating via Radius with radtest:
May 16 13:04:04 radius freeradius[2153]: pam_unix(radiusd:auth): authentication failure; logname= uid=103 euid=103 tty= ruser= rhost= user=testuser
and this is with PAM only via pamtester:
May 16 13:02:50 radius pamtester[2288]: pam_faillock(radiusd:auth): Unknown option: onerr
May 16 13:02:50 radius pamtester[2288]: pam_faillock(radiusd:auth): Unknown option: debug
May 16 13:02:50 radius radiusd(pam_google_authenticator)[2288]: debug: start of google_authenticator for "testuser"
May 16 13:02:50 radius radiusd(pam_google_authenticator)[2288]: debug: Secret file permissions are 0400. Allowed permissions are 0600
May 16 13:02:50 radius radiusd(pam_google_authenticator)[2288]: debug: "/etc/freeradius/googleauthsecrets/testuser.secret" read
May 16 13:02:50 radius radiusd(pam_google_authenticator)[2288]: debug: shared secret in "/etc/freeradius/googleauthsecrets/testuser.secret" processed
May 16 13:02:50 radius radiusd(pam_google_authenticator)[2288]: debug: google_authenticator for host "(null)"
May 16 13:02:54 radius radiusd(pam_google_authenticator)[2288]: debug: no scratch code used from "/etc/freeradius/googleauthsecrets/testuser.secret"
May 16 13:02:54 radius radiusd(pam_google_authenticator)[2288]: Accepted google_authenticator for testuser
May 16 13:02:54 radius radiusd(pam_google_authenticator)[2288]: debug: "/etc/freeradius/googleauthsecrets/testuser.secret" written
May 16 13:02:54 radius radiusd(pam_google_authenticator)[2288]: debug: end of google_authenticator for "testuser". Result: Success
May 16 13:02:54 radius pamtester[2288]: pam_unix(radiusd:auth): username [testuser] obtained
Here is my /etc/pam.d/radiusd
#
# /etc/pam.d/radiusd - PAM configuration for FreeRADIUS
#
We fall back to the system default in /etc/pam.d/common-*
@include common-auth
@include common-account
@include common-password
@include common-session
Set up failed login counter
auth required pam_faillock.so preauth onerr=fail silent audit deny=5 unlock_time=300 debug
Check the TOTP code with the Google Authenticator module and
pass on the password to pam_unix.so if sucessfull
auth requisite /usr/lib/x86_64-linux-gnu/security/pam_google_authenticator.so forward_pass user=freerad secret=/etc/freeradius/googleauthsecrets/${USER}.secret debug
auth required pam_unix.so use_first_pass debug
Reset failed login counter on sucessful login
account required pam_faillock.so debug
This is the debug output of freeradius -X
(1) [chap] = noop
(1) [mschap] = noop
(1) [digest] = noop
(1) suffix: Checking for suffix after "@"
(1) suffix: No '@' in User-Name = "testuser", looking up realm NULL
(1) suffix: No such realm "NULL"
(1) [suffix] = noop
(1) eap: No EAP-Message, not doing EAP
(1) [eap] = noop
(1) files: Failed resolving GID: No error
(1) files: users: Matched entry DEFAULT at line 78
(1) [files] = ok
(1) [expiration] = noop
(1) [logintime] = noop
Not doing PAP as Auth-Type is already set.
(1) [pap] = noop
(1) } # authorize = ok
(1) Found Auth-Type = pam
(1) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
(1) authenticate {
(1) pam: Using pamauth string "radiusd" for pam.conf lookup
(1) pam: ERROR: pam_authenticate failed: Authentication failure
(1) [pam] = reject
(1) } # authenticate = reject
(1) Failed to authenticate the user
(1) Using Post-Auth-Type Reject
(1) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
(1) Post-Auth-Type REJECT {
(1) attr_filter.access_reject: EXPAND %{User-Name}
(1) attr_filter.access_reject: --> testuser
(1) attr_filter.access_reject: Matched entry DEFAULT at line 11
(1) [attr_filter.access_reject] = updated
(1) [eap] = noop
(1) policy remove_reply_message_if_eap {
(1) if (&reply:EAP-Message && &reply:Reply-Message) {
(1) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE
(1) else {
(1) [noop] = noop
(1) } # else = noop
(1) } # policy remove_reply_message_if_eap = noop
(1) } # Post-Auth-Type REJECT = updated
(1) Delaying response for 1.000000 seconds
Waking up in 0.9 seconds.
(1) Sending delayed response
(1) Sent Access-Reject Id 129 from 127.0.0.1:1812 to 127.0.0.1:46859 length 20
Waking up in 3.9 seconds.
Does anyone have an idea to further troubleshoot?
