FreeRADIUS Google Dual Factor Authenticator

Question

I've been trying to setup FreeRADIUS Google Dual Factor Authenticator on a Cent OS 6.3 box. I've got everything installed.

my /etc/pam.d/raduis file looks like this

#%PAM-1.0
#auth       include     password-auth
#account    required    pam_nologin.so
#account    include     password-auth
#password   include     password-auth
#session    include     password-auth

auth requisite pam_google_authenticator.so forward_pass
auth required pam_unix.so use_first_pass debug

however if I remove the last two lines and un-comment the other ones, this setup seems to work and I get the following message

[root@PCPRADIUSTEST ~]# radtest juanr pass localhost 18120 letmein123
Sending Access-Request of id 184 to 127.0.0.1 port 1812
        User-Name = "juanr"
        User-Password = "pass"
        NAS-IP-Address = 10.3.80.169
        NAS-Port = 18120
        Message-Authenticator = 0x00000000000000000000000000000000
rad_recv: Access-Accept packet from host 127.0.0.1 port 1812, id=184, length=20

However what currently get with those two lines is

[root@PCPRADIUSTEST ~]# radtest juanr pass localhost 18120 letmein123
Sending Access-Request of id 41 to 127.0.0.1 port 1812
        User-Name = "juanr"
        User-Password = "pass"
        NAS-IP-Address = 10.3.80.169
        NAS-Port = 18120
        Message-Authenticator = 0x00000000000000000000000000000000
rad_recv: Access-Reject packet from host 127.0.0.1 port 1812, id=41, length=20

Then I stopped the radius service and started it like radius -XXX and got the output

rad_recv: Access-Request packet from host 127.0.0.1 port 37599, id=41, length=75
        User-Name = "juanr"
        User-Password = "pass"
        NAS-IP-Address = 10.3.80.169
        NAS-Port = 18120
        Message-Authenticator = 0x4f0c83f91dd3abc99f89952bb82de085
Thu Sep 12 16:33:10 2013 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default
Thu Sep 12 16:33:10 2013 : Info: +- entering group authorize {...}
Thu Sep 12 16:33:10 2013 : Info: ++[preprocess] returns ok
Thu Sep 12 16:33:10 2013 : Info: ++[chap] returns noop
Thu Sep 12 16:33:10 2013 : Info: ++[mschap] returns noop
Thu Sep 12 16:33:10 2013 : Info: ++[digest] returns noop
Thu Sep 12 16:33:10 2013 : Info: [suffix] No '@' in User-Name = "juanr", looking up realm NULL
Thu Sep 12 16:33:10 2013 : Info: [suffix] No such realm "NULL"
Thu Sep 12 16:33:10 2013 : Info: ++[suffix] returns noop
Thu Sep 12 16:33:10 2013 : Info: [eap] No EAP-Message, not doing EAP
Thu Sep 12 16:33:10 2013 : Info: ++[eap] returns noop
Thu Sep 12 16:33:10 2013 : Info: [files] users: Matched entry DEFAULT at line 74
Thu Sep 12 16:33:10 2013 : Info: ++[files] returns ok
Thu Sep 12 16:33:10 2013 : Info: ++[expiration] returns noop
Thu Sep 12 16:33:10 2013 : Info: ++[logintime] returns noop
Thu Sep 12 16:33:10 2013 : Info: [pap] WARNING! No "known good" password found for the user.  Authentication may fail because of this.
Thu Sep 12 16:33:10 2013 : Info: ++[pap] returns noop
Thu Sep 12 16:33:10 2013 : Info: Found Auth-Type = PAM
Thu Sep 12 16:33:10 2013 : Info: # Executing group from file /etc/raddb/sites-enabled/default
Thu Sep 12 16:33:10 2013 : Info: +- entering group authenticate {...}
Thu Sep 12 16:33:10 2013 : Debug: pam_pass: using pamauth string <radiusd> for pam.conf lookup
Thu Sep 12 16:33:10 2013 : Debug: pam_pass: function pam_acct_mgmt FAILED for <juanr>. Reason: Authentication failure
Thu Sep 12 16:33:10 2013 : Info: ++[pam] returns reject
Thu Sep 12 16:33:10 2013 : Info: Failed to authenticate the user.
Thu Sep 12 16:33:10 2013 : Info: Using Post-Auth-Type Reject
Thu Sep 12 16:33:10 2013 : Info: # Executing group from file /etc/raddb/sites-enabled/default
Thu Sep 12 16:33:10 2013 : Info: +- entering group REJECT {...}
Thu Sep 12 16:33:10 2013 : Info: [attr_filter.access_reject]    expand: %{User-Name} -> juanr
Thu Sep 12 16:33:10 2013 : Debug: attr_filter: Matched entry DEFAULT at line 11
Thu Sep 12 16:33:10 2013 : Info: ++[attr_filter.access_reject] returns updated
Thu Sep 12 16:33:10 2013 : Info: Delaying reject of request 1 for 1 seconds
Thu Sep 12 16:33:10 2013 : Debug: Going to the next request
Thu Sep 12 16:33:10 2013 : Debug: Waking up in 0.9 seconds.
Thu Sep 12 16:33:11 2013 : Info: Sending delayed reject for request 1
Sending Access-Reject of id 41 to 127.0.0.1 port 37599
Thu Sep 12 16:33:11 2013 : Debug: Waking up in 4.9 seconds.

I was following the instruction from http://www.supertechguy.com/help/security/freeradius-google-auth to set this up.

Can you please advice?

Many thanks.

Answer 1

After so much internet surfing and forum hunting I manage to fix this problem. If anyone else having this issue this might help them :)

Thu Sep 26 16:38:19 2013 : Debug: pam_pass: using pamauth string <radiusd> for pam.conf lookup
Thu Sep 26 16:38:19 2013 : Debug: pam_pass: function pam_authenticate FAILED for <test>. Reason: Cannot make/remove an entry for the specified session

The above line actually means a auth fail, even though it doesn't sound like it, also it could mean that .google_authenticator file in the user's home directory isn't accessible.

FreeRadius log file not help you much with this issue, but have a look through /var/log/secure on CentOS and /var/log/auth.log in Ubuntu. This will explain which is the issue.

Issue with my system was my time was out and my random generated number by Google Dual Factor Authenticator application on my iPhone wasn't valid. I had to install NTP and change my servers time to the correct time which fixed the issue!!!!

hope this help someone else :)