Hi, I've been successfully using FreeRADIUS 1.1.4 to authenticate users against Active Directory using LDAP and a plaintext password.
In the authorize section FreeRADIUS anonymously binds to our LDAP server (Active Directory) and searches for the user identified in the Access-Request (in my case we change the default search filter to 'sAMAccountName' as our AD doesn't contain 'uid'). If a match is found I think the user's full Distinguised Name (e.g. CN=bill,DC=foo,DC=ac,DC=uk) is added to the list of check items, and Auth-Type is set to 'ldap'. In the authenticate section, FreeRADIUS binds to the LDAP server using the user's full DN and the password supplied in the Access-Request. If the bind is successful, the user is authenticated because the password must have been correct. I've recently updated a server to FreeRADIUS 2.1.3 and all authentications now fail. LDAP is not set as the authentication method during the authorize section. I don't know why as I can't seen any configuration options which I've set differently between the two versions. I still get the debug message "Info: [ldap] user <username> authorized to use remote access" in the authorize section, so this suggests that the anonymous bind and search work ok. Does any one have any ideas? Have I made a stupid configuration error, or did I miss something in the latest documentation? Thanks in advance for any help, Mark. This is the debug output for version 1.1.4... rad_recv: Access-Request packet from host 127.0.0.1:56359, id=216, length=45 User-Name = "bill" User-Password = "blahblah" Sun Mar 15 18:07:11 2009 : Debug: Processing the authorize section of radiusd.conf Sun Mar 15 18:07:11 2009 : Debug: modcall: entering group authorize for request 0 Sun Mar 15 18:07:11 2009 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 0 Sun Mar 15 18:07:11 2009 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 0 Sun Mar 15 18:07:11 2009 : Debug: modcall[authorize]: module "preprocess" returns ok for request 0 Sun Mar 15 18:07:11 2009 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 0 Sun Mar 15 18:07:11 2009 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 0 Sun Mar 15 18:07:11 2009 : Debug: modcall[authorize]: module "chap" returns noop for request 0 Sun Mar 15 18:07:11 2009 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 0 Sun Mar 15 18:07:11 2009 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 0 Sun Mar 15 18:07:11 2009 : Debug: modcall[authorize]: module "mschap" returns noop for request 0 Sun Mar 15 18:07:11 2009 : Debug: modsingle[authorize]: calling digest (rlm_digest) for request 0 Sun Mar 15 18:07:11 2009 : Debug: modsingle[authorize]: returned from digest (rlm_digest) for request 0 Sun Mar 15 18:07:11 2009 : Debug: modcall[authorize]: module "digest" returns noop for request 0 Sun Mar 15 18:07:11 2009 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 0 Sun Mar 15 18:07:11 2009 : Debug: rlm_eap: No EAP-Message, not doing EAP Sun Mar 15 18:07:11 2009 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 0 Sun Mar 15 18:07:11 2009 : Debug: modcall[authorize]: module "eap" returns noop for request 0 Sun Mar 15 18:07:11 2009 : Debug: modsingle[authorize]: calling ldap (rlm_ldap) for request 0 Sun Mar 15 18:07:11 2009 : Debug: rlm_ldap: - authorize Sun Mar 15 18:07:11 2009 : Debug: rlm_ldap: performing user authorization for bill Sun Mar 15 18:07:11 2009 : Debug: radius_xlat: '(sAMAccountName=bill)' Sun Mar 15 18:07:11 2009 : Debug: radius_xlat: 'dc=foo,dc=ac,dc=uk' Sun Mar 15 18:07:11 2009 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0 Sun Mar 15 18:07:11 2009 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0 Sun Mar 15 18:07:11 2009 : Debug: rlm_ldap: attempting LDAP reconnection Sun Mar 15 18:07:11 2009 : Debug: rlm_ldap: (re)connect to ad.foo.ac.uk:389, authentication 0 Sun Mar 15 18:07:11 2009 : Debug: rlm_ldap: bind as / to ad.foo.ac.uk:389 Sun Mar 15 18:07:11 2009 : Debug: rlm_ldap: waiting for bind result ... Sun Mar 15 18:07:11 2009 : Debug: rlm_ldap: Bind was successful Sun Mar 15 18:07:11 2009 : Debug: rlm_ldap: performing search in dc=foo,dc=ac,dc=uk, with filter (sAMAccountName=bill) Sun Mar 15 18:07:11 2009 : Debug: rlm_ldap: looking for check items in directory... Sun Mar 15 18:07:11 2009 : Debug: rlm_ldap: looking for reply items in directory... Sun Mar 15 18:07:11 2009 : Debug: rlm_ldap: Setting Auth-Type = ldap Sun Mar 15 18:07:11 2009 : Debug: rlm_ldap: user bill authorized to use remote access Sun Mar 15 18:07:11 2009 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0 Sun Mar 15 18:07:11 2009 : Debug: modsingle[authorize]: returned from ldap (rlm_ldap) for request 0 Sun Mar 15 18:07:11 2009 : Debug: modcall[authorize]: module "ldap" returns ok for request 0 Sun Mar 15 18:07:11 2009 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 0 Sun Mar 15 18:07:11 2009 : Debug: rlm_pap: WARNING! No "known good" password found for the user. Authentication may fail because of this. Sun Mar 15 18:07:11 2009 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 0 Sun Mar 15 18:07:11 2009 : Debug: modcall[authorize]: module "pap" returns noop for request 0 Sun Mar 15 18:07:11 2009 : Debug: modcall: leaving group authorize (returns ok) for request 0 Sun Mar 15 18:07:11 2009 : Debug: rad_check_password: Found Auth-Type ldap Sun Mar 15 18:07:11 2009 : Debug: auth: type "LDAP" Sun Mar 15 18:07:11 2009 : Debug: Processing the authenticate section of radiusd.conf Sun Mar 15 18:07:11 2009 : Debug: modcall: entering group LDAP for request 0 Sun Mar 15 18:07:11 2009 : Debug: modsingle[authenticate]: calling ldap (rlm_ldap) for request 0 Sun Mar 15 18:07:11 2009 : Debug: rlm_ldap: - authenticate Sun Mar 15 18:07:11 2009 : Debug: rlm_ldap: login attempt by "bill" with password "blahblah" Sun Mar 15 18:07:11 2009 : Debug: rlm_ldap: user DN: CN=bill,dc=foo,dc=ac,dc=uk Sun Mar 15 18:07:11 2009 : Debug: rlm_ldap: (re)connect to ad.foo.ac.uk:389, authentication 1 Sun Mar 15 18:07:11 2009 : Debug: rlm_ldap: bind as CN=bill,dc=foo,dc=ac,dc=uk/blahblah to ad.foo.ac.uk:389 Sun Mar 15 18:07:11 2009 : Debug: rlm_ldap: waiting for bind result ... Sun Mar 15 18:07:11 2009 : Debug: rlm_ldap: Bind was successful Sun Mar 15 18:07:11 2009 : Debug: rlm_ldap: user bill authenticated succesfully Sun Mar 15 18:07:11 2009 : Debug: modsingle[authenticate]: returned from ldap (rlm_ldap) for request 0 Sun Mar 15 18:07:11 2009 : Debug: modcall[authenticate]: module "ldap" returns ok for request 0 Sun Mar 15 18:07:11 2009 : Debug: modcall: leaving group LDAP (returns ok) for request 0 Sun Mar 15 18:07:11 2009 : Auth: Login OK: [bill] (from client localNas port 0) Sending Access-Accept of id 216 to 127.0.0.1 port 56359 Sun Mar 15 18:07:11 2009 : Debug: Finished request 0 Sun Mar 15 18:07:11 2009 : Debug: Going to the next request Sun Mar 15 18:07:11 2009 : Debug: --- Walking the entire request list --- Sun Mar 15 18:07:11 2009 : Debug: Waking up in 6 seconds... Sun Mar 15 18:07:17 2009 : Debug: --- Walking the entire request list --- Sun Mar 15 18:07:17 2009 : Debug: Cleaning up request 0 ID 216 with timestamp 49bd43cf Sun Mar 15 18:07:17 2009 : Debug: Nothing to do. Sleeping until we see a request. And this is the debug output for version 2.1.3... rad_recv: Access-Request packet from host 127.0.0.1 port 32787, id=186, length=27 User-Name = "bill" Sun Mar 15 17:59:37 2009 : Info: +- entering group authorize {...} Sun Mar 15 17:59:37 2009 : Info: ++[preprocess] returns ok Sun Mar 15 17:59:37 2009 : Info: [auth_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/127.0.0.1/auth-detail-20090315 Sun Mar 15 17:59:37 2009 : Info: [auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/127.0.0.1/auth-detail-20090315 Sun Mar 15 17:59:37 2009 : Info: [auth_log] expand: %t -> Sun Mar 15 17:59:37 2009 Sun Mar 15 17:59:37 2009 : Info: ++[auth_log] returns ok Sun Mar 15 17:59:37 2009 : Info: [ldap] performing user authorization for bill Sun Mar 15 17:59:37 2009 : Info: [ldap] WARNING: Deprecated conditional expansion ":-". See "man unlang" for details Sun Mar 15 17:59:37 2009 : Info: [ldap] expand: (sAMAccountName=%{Stripped-User-Name:-%{User-Name}}) -> (sAMAccountName=bill) Sun Mar 15 17:59:37 2009 : Info: [ldap] expand: dc=foo,dc=ac,dc=uk -> dc=foo,dc=ac,dc=uk Sun Mar 15 17:59:37 2009 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0 Sun Mar 15 17:59:37 2009 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0 Sun Mar 15 17:59:37 2009 : Debug: rlm_ldap: attempting LDAP reconnection Sun Mar 15 17:59:37 2009 : Debug: rlm_ldap: (re)connect to logon02.fed.cclrc.ac.uk:389, authentication 0 Sun Mar 15 17:59:38 2009 : Debug: rlm_ldap: bind as / to logon02.fed.cclrc.ac.uk:389 Sun Mar 15 17:59:38 2009 : Debug: rlm_ldap: waiting for bind result ... Sun Mar 15 17:59:38 2009 : Debug: rlm_ldap: Bind was successful Sun Mar 15 17:59:38 2009 : Debug: rlm_ldap: performing search in dc=foo,dc=ac,dc=uk, with filter (sAMAccountName=bill) Sun Mar 15 17:59:38 2009 : Info: [ldap] looking for check items in directory... Sun Mar 15 17:59:38 2009 : Info: [ldap] looking for reply items in directory... Sun Mar 15 17:59:38 2009 : Debug: WARNING: No "known good" password was found in LDAP. Are you sure that the user is configured correctly? Sun Mar 15 17:59:38 2009 : Info: [ldap] user bill authorized to use remote access Sun Mar 15 17:59:38 2009 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0 Sun Mar 15 17:59:38 2009 : Info: ++[ldap] returns ok Sun Mar 15 17:59:38 2009 : Info: ++[expiration] returns noop Sun Mar 15 17:59:38 2009 : Info: ++[logintime] returns noop Sun Mar 15 17:59:38 2009 : Info: No authenticate method (Auth-Type) configuration found for the request: Rejecting the user Sun Mar 15 17:59:38 2009 : Info: Failed to authenticate the user. Sun Mar 15 17:59:38 2009 : Auth: Login incorrect: [bill] (from client localNas port 0) Sun Mar 15 17:59:38 2009 : Info: Using Post-Auth-Type Reject Sun Mar 15 17:59:38 2009 : Info: +- entering group REJECT {...} Sun Mar 15 17:59:38 2009 : Info: [attr_filter.access_reject] expand: %{User-Name} -> bill Sun Mar 15 17:59:38 2009 : Debug: attr_filter: Matched entry DEFAULT at line 11 Sun Mar 15 17:59:38 2009 : Info: ++[attr_filter.access_reject] returns updated Sun Mar 15 17:59:38 2009 : Info: Delaying reject of request 0 for 1 seconds Sun Mar 15 17:59:38 2009 : Debug: Going to the next request Sun Mar 15 17:59:38 2009 : Debug: Waking up in 0.9 seconds. Sun Mar 15 17:59:38 2009 : Info: Sending delayed reject for request 0 Sending Access-Reject of id 186 to 127.0.0.1 port 32787 Sun Mar 15 17:59:38 2009 : Debug: Waking up in 4.9 seconds. Sun Mar 15 17:59:43 2009 : Info: Cleaning up request 0 ID 186 with timestamp +91 Sun Mar 15 17:59:43 2009 : Debug: Ready to process requests. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html