Re: AD Authentication using PAM_winbind.so succeeds, but FreeRadius 3.0.4 rejects with "Failed to Authenticate User"
Hello, I am attempting to configure 2 factor authentication using Google Authenticator + AD (Winbind), ultimately for use in my Cisco and Windows VPN environment. The environment is as follows: -Fedora 22 -Freeradius 3.0.4 -Samba 4.2.2 Authentication using Winbind is successful and the journalCTL log files verifies this as you will see below. For testing purposes, I've disabled Google Authenticator line in the /etc/pam.d/radiusd config file so I can focus on PAM_Winbind functionality. This is the only line that I'm using. ---------------------- #/etc/pam.d/radius auth required /usr/lib64/security/pam_winbind.so debug ---------------------- When I authenticate via radtest I get rejected: ------------ [root@hlsfreeradius01 ~]# radtest -x -t pap test-user-123 test-password localhost 1812 testing123 Sending Access-Request Id 172 from 0.0.0.0:55300 to 127.0.0.1:1812 User-Name = 'test-user-123' User-Password = 'test-password' NAS-IP-Address = 10.101.1.8 NAS-Port = 1812 Message-Authenticator = 0x00 Received Access-Reject Id 172 from 127.0.0.1:1812 to 127.0.0.1:55300 length 20 (0) -: Expected Access-Accept got Access-Reject -------------- Here is the JournalCTL output from Fedora that proves the winbind was successful: ---------------------- Jul 24 16:37:25 hlsfreeradius01 radiusd[2995]: pam_winbind(radiusd:auth): [pamh: 0x7f0bff4029c0] ENTER: pam_sm_authenticate (flags: 0x0000) J ul 24 16:37:25 hlsfreeradius01 radiusd[2995]: pam_winbind(radiusd:auth): getting password (0x00000001) Jul 24 16:37:25 hlsfreeradius01 radiusd[2995]: pam_winbind(radiusd:auth): Verify user 'test-user-123' Jul 24 16:37:25 hlsfreeradius01 radiusd[2995]: pam_winbind(radiusd:auth): request wbcLogonUser succeeded Jul 24 16:37:25 hlsfreeradius01 radiusd[2995]: pam_winbind(radiusd:auth): user 'test-user-123' granted access Jul 24 16:37:25 hlsfreeradius01 radiusd[2995]: pam_winbind(radiusd:auth): Returned user was 'test-user-123' Jul 24 16:37:25 hlsfreeradius01 radiusd[2995]: pam_winbind(radiusd:auth): [pamh: 0x7f0bff4029c0] LEAVE: pam_sm_authenticate returning 0 (PAM_SUCCESS) Jul 24 16:37:25 hlsfreeradius01 audit[2995]: <audit-1100> pid=2995 uid=0 auid=0 ses=2 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg='op=PAM:authentication grantors=pam_winbind acct="test-user-123" exe="/usr/sbin/radiusd" hostname=? addr=? terminal=pts/1 res=success' Jul 24 16:37:25 hlsfreeradius01 audit[2995]: <audit-1101> pid=2995 uid=0 auid=0 ses=2 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg='op=PAM:accounting grantors=? acct="test-user-123" exe="/usr/sbin/radiusd" hostname=? addr=? terminal=pts/1 res=failed' ----------------------- Specific radiusd -XXX log output showing the PAM user authentication rejected: ----------------------- Received Access-Request Id 172 from 127.0.0.1:55300 to 127.0.0.1:1812 length 78 User-Name = 'test-user-123' User-Password = 'test-password' NAS-IP-Address = 10.101.1.8 NAS-Port = 1812 Message-Authenticator = 0x82a2d0ae5c2192628b6263c968890117 Fri Jul 24 16:37:25 2015 : Debug: (0) Received Access-Request packet from host 127.0.0.1 port 55300, id=172, length=78 Fri Jul 24 16:37:25 2015 : Debug: (0) User-Name = 'test-user-123' Fri Jul 24 16:37:25 2015 : Debug: (0) User-Password = 'test-password' Fri Jul 24 16:37:25 2015 : Debug: (0) NAS-IP-Address = 10.101.1.8 Fri Jul 24 16:37:25 2015 : Debug: (0) NAS-Port = 1812 Fri Jul 24 16:37:25 2015 : Debug: (0) Message-Authenticator = 0x82a2d0ae5c2192628b6263c968890117 Fri Jul 24 16:37:25 2015 : Debug: (0) # Executing section authorize from file /etc/raddb/sites-enabled/default Fri Jul 24 16:37:25 2015 : Debug: (0) authorize { Fri Jul 24 16:37:25 2015 : Debug: (0) filter_username filter_username { Fri Jul 24 16:37:25 2015 : Debug: (0) if (!&User-Name) Fri Jul 24 16:37:25 2015 : Debug: (0) if (!&User-Name) -> FALSE Fri Jul 24 16:37:25 2015 : Debug: (0) if (&User-Name =~ / /) Fri Jul 24 16:37:25 2015 : Debug: (0) if (&User-Name =~ / /) -> FALSE Fri Jul 24 16:37:25 2015 : Debug: (0) if (&User-Name =~ /@.*@/ ) Fri Jul 24 16:37:25 2015 : Debug: (0) if (&User-Name =~ /@.*@/ ) -> FALSE Fri Jul 24 16:37:25 2015 : Debug: (0) if (&User-Name =~ /\\.\\./ ) Fri Jul 24 16:37:25 2015 : Debug: (0) if (&User-Name =~ /\\.\\./ ) -> FALSE Fri Jul 24 16:37:25 2015 : Debug: (0) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\\.(.+)$/)) Fri Jul 24 16:37:25 2015 : Debug: (0) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\\.(.+)$/)) -> FALSE Fri Jul 24 16:37:25 2015 : Debug: (0) if (&User-Name =~ /\\.$/) Fri Jul 24 16:37:25 2015 : Debug: (0) if (&User-Name =~ /\\.$/) -> FALSE Fri Jul 24 16:37:25 2015 : Debug: (0) if (&User-Name =~ /@\\./) Fri Jul 24 16:37:25 2015 : Debug: (0) if (&User-Name =~ /@\\./) -> FALSE Fri Jul 24 16:37:25 2015 : Debug: (0) } # filter_username filter_username = notfound Fri Jul 24 16:37:25 2015 : Debug: (0) modsingle[authorize]: calling preprocess (rlm_preprocess) for request 0 Fri Jul 24 16:37:25 2015 : Debug: (0) modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 0 Fri Jul 24 16:37:25 2015 : Debug: (0) [preprocess] = ok Fri Jul 24 16:37:25 2015 : Debug: (0) modsingle[authorize]: calling chap (rlm_chap) for request 0 Fri Jul 24 16:37:25 2015 : Debug: (0) modsingle[authorize]: returned from chap (rlm_chap) for request 0 Fri Jul 24 16:37:25 2015 : Debug: (0) [chap] = noop Fri Jul 24 16:37:25 2015 : Debug: (0) modsingle[authorize]: calling mschap (rlm_mschap) for request 0 Fri Jul 24 16:37:25 2015 : Debug: (0) modsingle[authorize]: returned from mschap (rlm_mschap) for request 0 Fri Jul 24 16:37:25 2015 : Debug: (0) [mschap] = noop Fri Jul 24 16:37:25 2015 : Debug: (0) modsingle[authorize]: calling suffix (rlm_realm) for request 0 Fri Jul 24 16:37:25 2015 : Debug: (0) suffix : Checking for suffix after "@" Fri Jul 24 16:37:25 2015 : Debug: (0) suffix : No '@' in User-Name = "test-user-123", looking up realm NULL Fri Jul 24 16:37:25 2015 : Debug: (0) suffix : No such realm "NULL" Fri Jul 24 16:37:25 2015 : Debug: (0) modsingle[authorize]: returned from suffix (rlm_realm) for request 0 Fri Jul 24 16:37:25 2015 : Debug: (0) [suffix] = noop Fri Jul 24 16:37:25 2015 : Debug: (0) modsingle[authorize]: calling eap (rlm_eap) for request 0 Fri Jul 24 16:37:25 2015 : Debug: (0) eap : No EAP-Message, not doing EAP Fri Jul 24 16:37:25 2015 : Debug: (0) modsingle[authorize]: returned from eap (rlm_eap) for request 0 Fri Jul 24 16:37:25 2015 : Debug: (0) [eap] = noop Fri Jul 24 16:37:25 2015 : Debug: (0) modsingle[authorize]: calling files (rlm_files) for request 0 Fri Jul 24 16:37:25 2015 : Debug: (0) files : users: Matched entry DEFAULT at line 182 Fri Jul 24 16:37:25 2015 : Debug: (0) files : ::: FROM 0 TO 0 MAX 0 Fri Jul 24 16:37:25 2015 : Debug: (0) files : ::: TO in 0 out 0 Fri Jul 24 16:37:25 2015 : Debug: (0) modsingle[authorize]: returned from files (rlm_files) for request 0 Fri Jul 24 16:37:25 2015 : Debug: (0) [files] = ok Fri Jul 24 16:37:25 2015 : Debug: (0) modsingle[authorize]: calling expiration (rlm_expiration) for request 0 Fri Jul 24 16:37:25 2015 : Debug: (0) modsingle[authorize]: returned from expiration (rlm_expiration) for request 0 Fri Jul 24 16:37:25 2015 : Debug: (0) [expiration] = noop Fri Jul 24 16:37:25 2015 : Debug: (0) modsingle[authorize]: calling logintime (rlm_logintime) for request 0 Fri Jul 24 16:37:25 2015 : Debug: (0) modsingle[authorize]: returned from logintime (rlm_logintime) for request 0 Fri Jul 24 16:37:25 2015 : Debug: (0) [logintime] = noop Fri Jul 24 16:37:25 2015 : Debug: (0) modsingle[authorize]: calling pap (rlm_pap) for request 0 Fri Jul 24 16:37:25 2015 : WARNING: (0) pap : No "known good" password found for the user. Not setting Auth-Type Fri Jul 24 16:37:25 2015 : WARNING: (0) pap : Authentication will fail unless a "known good" password is available Fri Jul 24 16:37:25 2015 : Debug: (0) modsingle[authorize]: returned from pap (rlm_pap) for request 0 Fri Jul 24 16:37:25 2015 : Debug: (0) [pap] = noop Fri Jul 24 16:37:25 2015 : Debug: (0) } # authorize = ok #PAM authentication sequence begins Fri Jul 24 16:37:25 2015 : Debug: (0) Found Auth-Type = PAM Fri Jul 24 16:37:25 2015 : Debug: (0) # Executing group from file /etc/raddb/sites-enabled/default Fri Jul 24 16:37:25 2015 : Debug: (0) authenticate { Fri Jul 24 16:37:25 2015 : Debug: (0) modsingle[authenticate]: calling pam (rlm_pam) for request 0 Fri Jul 24 16:37:25 2015 : Debug: pam_pass: using pamauth string <radiusd> for pam.conf lookup Fri Jul 24 16:37:25 2015 : Debug: pam_pass: function pam_acct_mgmt FAILED for <test-user-123>. Reason: Authentication failure Fri Jul 24 16:37:25 2015 : Debug: (0) modsingle[authenticate]: returned from pam (rlm_pam) for request 0 Fri Jul 24 16:37:25 2015 : Debug: (0) [pam] = reject Fri Jul 24 16:37:25 2015 : Debug: (0) } # authenticate = reject Fri Jul 24 16:37:25 2015 : Debug: (0) Failed to authenticate the user Fri Jul 24 16:37:25 2015 : Auth: (0) Login incorrect: [test-user-123/test-password] (from client localhost port 1812) Fri Jul 24 16:37:25 2015 : Debug: (0) Using Post-Auth-Type Reject Fri Jul 24 16:37:25 2015 : Debug: (0) # Executing group from file /etc/raddb/sites-enabled/default Fri Jul 24 16:37:25 2015 : Debug: (0) Post-Auth-Type REJECT { Fri Jul 24 16:37:25 2015 : Debug: (0) modsingle[post-auth]: calling attr_filter.access_reject (rlm_attr_filter) for request 0 Fri Jul 24 16:37:25 2015 : Debug: %{User-Name} Fri Jul 24 16:37:25 2015 : Debug: Parsed xlat tree: Fri Jul 24 16:37:25 2015 : Debug: attribute --> User-Name Fri Jul 24 16:37:25 2015 : Debug: (0) attr_filter.access_reject : EXPAND %{User-Name} Fri Jul 24 16:37:25 2015 : Debug: (0) attr_filter.access_reject : --> test-user-123 Fri Jul 24 16:37:25 2015 : Debug: (0) attr_filter.access_reject : Matched entry DEFAULT at line 11 Fri Jul 24 16:37:25 2015 : Debug: (0) modsingle[post-auth]: returned from attr_filter.access_reject (rlm_attr_filter) for request 0 Fri Jul 24 16:37:25 2015 : Debug: (0) [attr_filter.access_reject] = updated # Ends Fri Jul 24 16:37:25 2015 : Debug: (0) modsingle[post-auth]: calling eap (rlm_eap) for request 0 Fri Jul 24 16:37:25 2015 : Debug: (0) eap : Request didn't contain an EAP-Message, not inserting EAP-Failure Fri Jul 24 16:37:25 2015 : Debug: (0) modsingle[post-auth]: returned from eap (rlm_eap) for request 0 Fri Jul 24 16:37:25 2015 : Debug: (0) [eap] = noop Fri Jul 24 16:37:25 2015 : Debug: (0) remove_reply_message_if_eap remove_reply_message_if_eap { Fri Jul 24 16:37:25 2015 : Debug: (0) if (&reply:EAP-Message && &reply:Reply-Message) Fri Jul 24 16:37:25 2015 : Debug: (0) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE Fri Jul 24 16:37:25 2015 : Debug: (0) else else { Fri Jul 24 16:37:25 2015 : Debug: (0) modsingle[post-auth]: calling noop (rlm_always) for request 0 Fri Jul 24 16:37:25 2015 : Debug: (0) modsingle[post-auth]: returned from noop (rlm_always) for request 0 Fri Jul 24 16:37:25 2015 : Debug: (0) [noop] = noop Fri Jul 24 16:37:25 2015 : Debug: (0) } # else else = noop Fri Jul 24 16:37:25 2015 : Debug: (0) } # remove_reply_message_if_eap remove_reply_message_if_eap = noop Fri Jul 24 16:37:25 2015 : Debug: (0) } # Post-Auth-Type REJECT = updated Fri Jul 24 16:37:25 2015 : Debug: (0) Delaying response for 1 seconds Fri Jul 24 16:37:25 2015 : Debug: Waking up in 0.2 seconds. Fri Jul 24 16:37:26 2015 : Debug: Waking up in 0.7 seconds. Fri Jul 24 16:37:26 2015 : Debug: (0) Sending delayed response Fri Jul 24 16:37:26 2015 : Debug: (0) Sending Access-Reject packet to host 127.0.0.1 port 55300, id=172, length=0 Sending Access-Reject Id 172 from 127.0.0.1:1812 to 127.0.0.1:55300 Fri Jul 24 16:37:26 2015 : Debug: Waking up in 3.9 seconds. Fri Jul 24 16:37:30 2015 : Debug: (0) Cleaning up request packet ID 172 with timestamp +26 Fri Jul 24 16:37:30 2015 : Info: Ready to process requests ---------------- Standard NTLM via AD works very well, but utilizing the PAM module is creating a whole new can of worms. My use case for PAM is 2 factor authentication with Google Authenticator, but if there is a better way to do this while still utilizing FreeRadius, then I am very interested. However, at this point I have not been unable to find another authentication methodology for Google OTP without the PAM component. If anyone is able to shed some light on the existing authentication issue I described, or even suggest a better way of doing this 2FA sequence in question, I would be extremely grateful. Also attaching the, radius -XXX startup output separately. Have a great weekend. -Josh
On Jul 24, 2015, at 9:28 PM, Josh Miller <jmills5901@gmail.com> wrote:
I am attempting to configure 2 factor authentication using Google Authenticator + AD (Winbind), ultimately for use in my Cisco and Windows VPN environment.
That should work.
The environment is as follows:
-Fedora 22 -Freeradius 3.0.4 -Samba 4.2.2
I'd suggest using 3.0.9.
---------------------- #/etc/pam.d/radius
auth required /usr/lib64/security/pam_winbind.so debug ----------------------
Don't use PAM. It's not just horrible, it's designed to be used once by an application, and then never again. It will likely leak memory, cause performance issues, etc. I would suggest using the ntlm_auth program. It's documented, and it works.
Standard NTLM via AD works very well, but utilizing the PAM module is creating a whole new can of worms.
Don't use PAM. It's almost impossible to understand. And almost impossible to debug.
My use case for PAM is 2 factor authentication with Google Authenticator, but if there is a better way to do this while still utilizing FreeRadius, then I am very interested.
You can run Perl scripts directly from FreeRADIUS. That should help.
However, at this point I have not been unable to find another authentication methodology for Google OTP without the PAM component.
I don't see why PAM is necessary.
Also attaching the, radius -XXX startup output separately.
<sigh> Please use "radiusd -X". Not "-XXXXXXXXXXX". It doesn't help. Following directions is good. And the directions say "-X". Alan DeKok.
participants (2)
-
Alan DeKok -
Josh Miller