Freeradius with Windbind and Google authenticator issues with Cisco Anyconnect VPN
Nawaz Hosany
mnhosany at gmail.com
Thu Sep 22 22:03:05 CEST 2016
Hi Guys
I am trying to configure Google Authenticator to work with Windbind for VPN
using Cisco Anyconnect on Ubuntu . Windbind works fine without Google
Authenticator., but combined it does not work.
I would need some help from the community. Here below are my configs and
debugs/errors i am seeing:
# /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
auth requisite pam_google_authenticator.so forward_pass
auth required pam_winbind.so use_first_pass
account required pam_permit.so
#
# /etc/pam.d/common-auth - authentication settings common to all services
#
# This file is included from other service-specific PAM config files,
# and should contain a list of the authentication modules that define
# the central authentication scheme for use on the system
# (e.g., /etc/shadow, LDAP, Kerberos, etc.). The default is to use the
# traditional Unix authentication mechanisms.
#
# As of pam 1.0.1-6, this file is managed by pam-auth-update by default.
# To take advantage of this, it is recommended that you configure any
# local modules either before or after the default block, and use
# pam-auth-update to manage selection of other modules. See
# pam-auth-update(8) for details.
# here are the per-package modules (the "Primary" block)
auth [success=1 default=ignore] pam_winbind.so krb5_auth
krb5_ccache_type=FILE cached_login
# here's the fallback if no module succeeds
# prime the stack with a positive return value if there isn't one already;
# this avoids us returning an error just because nothing sets a success code
# since the modules above will each just jump around
auth required pam_google_authenticator.so
auth required pam_winbind.so
auth required pam_permit.so
auth requisite pam_deny.so
# and here are more per-package modules (the "Additional" block)
# end of pam-auth-update config
Below is the error message i am getting when trying to authenticate, i am
using <AD password><google-authenticator-token>:
User-Name = "testuser"
User-Password = "4c330e at 3O7K5401206"
NAS-Port = 577536
Called-Station-Id = "10.33.3.100"
Calling-Station-Id = "10.1.3.10"
NAS-Port-Type = Virtual
Tunnel-Client-Endpoint:0 = "10.1.3.10"
Cisco-AVPair = "mdm-tlv=device-platform=win"
Cisco-AVPair = "mdm-tlv=device-mac=02-00-4c-4f-4f-50"
Cisco-AVPair = "mdm-tlv=device-mac=f0-1f-af-3c-1d-b0"
Cisco-AVPair = "mdm-tlv=device-type=Dell Inc. XPS L421X"
Cisco-AVPair = "mdm-tlv=ac-user-agent=AnyConnect Windows 4.2.03013"
Cisco-AVPair = "mdm-tlv=device-platform-version=6.1.7601 Service
Pack 1"
Cisco-AVPair =
"mdm-tlv=device-uid=26CC5FF8D17E0CF5A9DDDBA2E53009E17488F0B66E780F33A635AA1A7ABC26B9"
NAS-IP-Address = 10.33.4.100
Cisco-AVPair = "audit-session-id=0a2103640008d00057bdf75b"
Cisco-AVPair = "ip:source-ip=10.1.3.10"
Vendor-3076-Attr-146 = 0x4f414e444174657374
Vendor-3076-Attr-150 = 0x00000002
Cisco-AVPair = "coa-push=true"
Wed Aug 24 15:43:43 2016 : Info: # Executing section authorize from file
/etc/freeradius/sites-enabled/default
Wed Aug 24 15:43:43 2016 : Info: +- entering group authorize {...}
Wed Aug 24 15:43:43 2016 : Info: ++[preprocess] returns ok
Wed Aug 24 15:43:43 2016 : Info: ++[chap] returns noop
Wed Aug 24 15:43:43 2016 : Info: ++[mschap] returns noop
Wed Aug 24 15:43:43 2016 : Info: ++[digest] returns noop
Wed Aug 24 15:43:43 2016 : Info: [suffix] No '@' in User-Name = "testuser",
looking up realm NULL
Wed Aug 24 15:43:43 2016 : Info: [suffix] No such realm "NULL"
Wed Aug 24 15:43:43 2016 : Info: ++[suffix] returns noop
Wed Aug 24 15:43:43 2016 : Info: [eap] No EAP-Message, not doing EAP
Wed Aug 24 15:43:43 2016 : Info: ++[eap] returns noop
Wed Aug 24 15:43:43 2016 : Info: [files] users: Matched entry DEFAULT at
line 58
Wed Aug 24 15:43:43 2016 : Info: ++[files] returns ok
Wed Aug 24 15:43:43 2016 : Info: ++[expiration] returns noop
Wed Aug 24 15:43:43 2016 : Info: ++[logintime] returns noop
Wed Aug 24 15:43:43 2016 : Info: [pap] WARNING! No "known good" password
found for the user. Authentication may fail because of this.
Wed Aug 24 15:43:43 2016 : Info: ++[pap] returns noop
Wed Aug 24 15:43:43 2016 : Info: Found Auth-Type = PAM
Wed Aug 24 15:43:43 2016 : Info: # Executing group from file
/etc/freeradius/sites-enabled/default
Wed Aug 24 15:43:43 2016 : Info: +- entering group authenticate {...}
Wed Aug 24 15:43:43 2016 : Debug: pam_pass: using pamauth string <radiusd>
for pam.conf lookup
Wed Aug 24 15:43:44 2016 : Debug: pam_pass: function pam_authenticate
FAILED for <testuser>. Reason: Cannot make/remove an entry for the
specified session
Wed Aug 24 15:43:44 2016 : Info: ++[pam] returns reject
Wed Aug 24 15:43:44 2016 : Info: Failed to authenticate the user.
Wed Aug 24 15:43:44 2016 : Info: Using Post-Auth-Type Reject
Wed Aug 24 15:43:44 2016 : Info: # Executing group from file
/etc/freeradius/sites-enabled/default
Wed Aug 24 15:43:44 2016 : Info: +- entering group REJECT {...}
Wed Aug 24 15:43:44 2016 : Info: [attr_filter.access_reject] expand:
%{User-Name} -> testuser
Wed Aug 24 15:43:44 2016 : Debug: attr_filter: Matched entry DEFAULT at
line 11
Wed Aug 24 15:43:44 2016 : Info: ++[attr_filter.access_reject] returns
updated
Wed Aug 24 15:43:44 2016 : Info: Delaying reject of request 0 for 1 seconds
Wed Aug 24 15:43:44 2016 : Debug: Going to the next request
Wed Aug 24 15:43:44 2016 : Debug: Waking up in 0.8 seconds.
Wed Aug 24 15:43:44 2016 : Info: Sending delayed reject for request 0
Sending Access-Reject of id 180 to 10.33.4.100 port 29288
Wed Aug 24 15:43:44 2016 : Debug: Waking up in 4.9 seconds.
Wed Aug 24 15:43:49 2016 : Info: Cleaning up request 0 ID 180 with
timestamp +23
Wed Aug 24 15:43:49 2016 : Info: Ready to process requests.
Below is the log from
var/log/auth.log:
Aug 24 15:43:43 oatr2radius01 freeradius: pam_winbind(radiusd:auth):
getting password (0x00000380)
Aug 24 15:43:44 oatr2radius01 freeradius: pam_winbind(radiusd:auth):
request wbcLogonUser failed: WBC_ERR_AUTH_ERROR, PAM error: PAM_AUTH_ERR
(7), NTSTATUS: NT_STATUS_LOGON_FAILURE, Error message was: Logon failure
Aug 24 15:43:44 oatr2radius01 freeradius: pam_winbind(radiusd:auth): user
'testuser' denied access (incorrect password or invalid membership)
Aug 24 15:43:44 oatr2radius01 radiusd(pam_google_authenticator)[10570]:
Invalid verification code
Aug 24 15:43:44 oatr2radius01 freeradius[10570]: pam_winbind(radiusd:auth):
getting password (0x00000000)
Aug 24 15:43:44 oatr2radius01 freeradius[10570]: pam_winbind(radiusd:auth):
request wbcLogonUser failed: WBC_ERR_AUTH_ERROR, PAM error: PAM_AUTH_ERR
(7), NTSTATUS: NT_STATUS_WRONG_PASSWORD, Error message was: Wrong Password
Aug 24 15:43:44 oatr2radius01 freeradius[10570]: pam_winbind(radiusd:auth):
user 'testuser' denied access (incorrect password or invalid membership)
However, i noticed when I only enter the AD password instead of AD
Password+token, i get the following output:
rad_recv: Access-Request packet from host 10.33.4.100 port 29288, id=181,
length=612
User-Name = "testuser"
User-Password = "4c330e at 3O7K5"
NAS-Port = 581632
Called-Station-Id = "10.33.3.100"
Calling-Station-Id = "10.1.3.10"
NAS-Port-Type = Virtual
Tunnel-Client-Endpoint:0 = "10.1.3.10"
Cisco-AVPair = "mdm-tlv=device-platform=win"
Cisco-AVPair = "mdm-tlv=device-mac=02-00-4c-4f-4f-50"
Cisco-AVPair = "mdm-tlv=device-mac=f0-1f-af-3c-1d-b0"
Cisco-AVPair = "mdm-tlv=device-type=Dell Inc. XPS L421X"
Cisco-AVPair = "mdm-tlv=ac-user-agent=AnyConnect Windows 4.2.03013"
Cisco-AVPair = "mdm-tlv=device-platform-version=6.1.7601 Service
Pack 1"
Cisco-AVPair =
"mdm-tlv=device-uid=26CC5FF8D17E0CF5A9DDDBA2E53009E17488F0B66E780F33A635AA1A7ABC26B9"
NAS-IP-Address = 10.33.4.100
Cisco-AVPair = "audit-session-id=0a2103640008e00057bdf9bc"
Cisco-AVPair = "ip:source-ip=10.1.3.10"
Vendor-3076-Attr-146 = 0x4f414e444174657374
Vendor-3076-Attr-150 = 0x00000002
Cisco-AVPair = "coa-push=true"
Wed Aug 24 15:53:53 2016 : Info: # Executing section authorize from file
/etc/freeradius/sites-enabled/default
Wed Aug 24 15:53:53 2016 : Info: +- entering group authorize {...}
Wed Aug 24 15:53:53 2016 : Info: ++[preprocess] returns ok
Wed Aug 24 15:53:53 2016 : Info: ++[chap] returns noop
Wed Aug 24 15:53:53 2016 : Info: ++[mschap] returns noop
Wed Aug 24 15:53:53 2016 : Info: ++[digest] returns noop
Wed Aug 24 15:53:53 2016 : Info: [suffix] No '@' in User-Name = "testuser",
looking up realm NULL
Wed Aug 24 15:53:53 2016 : Info: [suffix] No such realm "NULL"
Wed Aug 24 15:53:53 2016 : Info: ++[suffix] returns noop
Wed Aug 24 15:53:53 2016 : Info: [eap] No EAP-Message, not doing EAP
Wed Aug 24 15:53:53 2016 : Info: ++[eap] returns noop
Wed Aug 24 15:53:53 2016 : Info: [files] users: Matched entry DEFAULT at
line 58
Wed Aug 24 15:53:53 2016 : Info: ++[files] returns ok
Wed Aug 24 15:53:53 2016 : Info: ++[expiration] returns noop
Wed Aug 24 15:53:53 2016 : Info: ++[logintime] returns noop
Wed Aug 24 15:53:53 2016 : Info: [pap] WARNING! No "known good" password
found for the user. Authentication may fail because of this.
Wed Aug 24 15:53:53 2016 : Info: ++[pap] returns noop
Wed Aug 24 15:53:53 2016 : Info: Found Auth-Type = PAM
Wed Aug 24 15:53:53 2016 : Info: # Executing group from file
/etc/freeradius/sites-enabled/default
Wed Aug 24 15:53:53 2016 : Info: +- entering group authenticate {...}
Wed Aug 24 15:53:53 2016 : Debug: pam_pass: using pamauth string <radiusd>
for pam.conf lookup
Wed Aug 24 15:53:53 2016 : Debug: pam_pass: function pam_authenticate
FAILED for <testuser>. Reason: Authentication failure
Wed Aug 24 15:53:53 2016 : Info: ++[pam] returns reject
Wed Aug 24 15:53:53 2016 : Info: Failed to authenticate the user.
Wed Aug 24 15:53:53 2016 : Info: Using Post-Auth-Type Reject
Wed Aug 24 15:53:53 2016 : Info: # Executing group from file
/etc/freeradius/sites-enabled/default
Wed Aug 24 15:53:53 2016 : Info: +- entering group REJECT {...}
Wed Aug 24 15:53:53 2016 : Info: [attr_filter.access_reject] expand:
%{User-Name} -> testuser
Wed Aug 24 15:53:53 2016 : Debug: attr_filter: Matched entry DEFAULT at
line 11
Wed Aug 24 15:53:53 2016 : Info: ++[attr_filter.access_reject] returns
updated
Wed Aug 24 15:53:53 2016 : Info: Delaying reject of request 1 for 1 seconds
Wed Aug 24 15:53:53 2016 : Debug: Going to the next request
Wed Aug 24 15:53:53 2016 : Debug: Waking up in 0.6 seconds.
Wed Aug 24 15:53:54 2016 : Info: Sending delayed reject for request 1
Sending Access-Reject of id 181 to 10.33.4.100 port 29288
Wed Aug 24 15:53:54 2016 : Debug: Waking up in 4.9 seconds.
Wed Aug 24 15:53:59 2016 : Info: Cleaning up request 1 ID 181 with
timestamp +633
Wed Aug 24 15:53:59 2016 : Info: Ready to process requests.
And /var/log/auth.log shows:
Aug 24 15:53:53 oatr2radius01 freeradius[10570]: pam_winbind(radiusd:auth):
getting password (0x00000380)
Aug 24 15:53:53 oatr2radius01 freeradius[10570]: pam_winbind(radiusd:auth):
user 'testuser' granted access
Aug 24 15:53:53 oatr2radius01 freeradius[10570]: pam_winbind(radiusd:auth):
getting password (0x00000000)
Aug 24 15:53:53 oatr2radius01 freeradius[10570]: pam_winbind(radiusd:auth):
user 'testuser' granted access
I sincerely hope that someone can help me out
Thanks Guys!
More information about the Freeradius-Users
mailing list