Hello everybody. We got a setup which does work in authenticating 812.1x users over a wired network by using EAP-MD5, checking authorization and authentication of the supplicant over a LDAP directory. What we do find strange (and pretty annoying, indeed) is that the we feel that the LDAP server does get contacted more than necessary, read: twice. Being more specific, when the freeradius server gets an ACCESS-REQUEST from the NAS, then radiusd does contact the LDAP server three times. The first time it does check for the existance of the user authenticating. The second, it checks if the users belong to a certain group specified with the Ldap-Group option. The third time it does grab the password from the user entry in the LDAP field and add it to the check item list.. So long, so well. What happens next? Next step is about the ACCESS-CHALLENGE. When radiusd is about to send it, it first checks the LDAP again. The same three times. Check for the users in the whole directory, check the belonging to the group, check the password again to calculate the hash. That results in six LDAP queries, we suspect that those can be reduced down to half but we can't find the point out. Thank you very much in advance. Here's the radiusd debug log (radiusd -X): rad_recv: Access-Request packet from host ********:37540, id=1, length=161 Message-Authenticator = 0x******** User-Name = "********" NAS-IP-Address = ******** Called-Station-Id = "********" NAS-Port = 21001 NAS-Port-Id = "fe.2.1" NAS-Port-Type = Ethernet Service-Type = Framed-User Calling-Station-Id = "********" EAP-Message = 0x******** Framed-MTU = 1300 Processing the authorize section of radiusd.conf modcall: entering group authorize for request 0 modcall[authorize]: module "preprocess" returns ok for request 0 radius_xlat: '/var/log/radius/radacct/********/auth-detail-20070209' rlm_detail: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/********/auth-detail-20070209 modcall[authorize]: module "auth_log" returns ok for request 0 modcall[authorize]: module "chap" returns noop for request 0 modcall[authorize]: module "mschap" returns noop for request 0 rlm_eap: EAP packet type response id 1 length 24 rlm_eap: No EAP Start, assuming it's an on-going EAP conversation modcall[authorize]: module "eap" returns updated for request 0 users: Matched DEFAULT at 8 users: Matched DEFAULT at 103 users: Matched DEFAULT at 105 rlm_ldap: Entering ldap_groupcmp() radius_xlat: 'dc=********,dc=********' radius_xlat: '(uid=********)' rlm_ldap: ldap_get_conn: Checking Id: 0 rlm_ldap: ldap_get_conn: Got Id: 0 rlm_ldap: attempting LDAP reconnection rlm_ldap: (re)connect to ********:389, authentication 0 rlm_ldap: bind as cn=********,ou=********,dc=********,dc=********/******** to ********:389 rlm_ldap: waiting for bind result ... rlm_ldap: Bind was successful rlm_ldap: performing search in dc=********,dc=********, with filter (uid=********) rlm_ldap: ldap_release_conn: Release Id: 0 radius_xlat: '(&(objectClass=GroupOfNames)(member=uid=********, ou=users, dc=********,dc=********))' rlm_ldap: ldap_get_conn: Checking Id: 0 rlm_ldap: ldap_get_conn: Got Id: 0 rlm_ldap: performing search in dc=********,dc=********, with filter (&(cn= 802.1xwired)(&(objectClass=GroupOfNames)(member=uid=********, ou=users, dc=********,dc=********))) rlm_ldap::ldap_groupcmp: User found in group 802.1xwired rlm_ldap: ldap_release_conn: Release Id: 0 users: Matched DEFAULT at 121 modcall[authorize]: module "files" returns ok for request 0 modcall: group authorize returns updated for request 0 Processing the authorize section of radiusd.conf modcall: entering group Autz-Type for request 0 rlm_ldap: - authorize rlm_ldap: performing user authorization for ******** radius_xlat: '(uid=********)' radius_xlat: 'dc=********,dc=********' rlm_ldap: ldap_get_conn: Checking Id: 0 rlm_ldap: ldap_get_conn: Got Id: 0 rlm_ldap: performing search in dc=********,dc=********, with filter (uid=********) rlm_ldap: Added password a in check items rlm_ldap: looking for check items in directory... rlm_ldap: looking for reply items in directory... rlm_ldap: user ******** authorized to use remote access rlm_ldap: ldap_release_conn: Release Id: 0 modcall[authorize]: module "ldap" returns ok for request 0 modcall: group Autz-Type returns ok for request 0 rad_check_password: Found Auth-Type EAP auth: type "EAP" Processing the authenticate section of radiusd.conf modcall: entering group authenticate for request 0 rlm_eap: EAP Identity rlm_eap: processing type md5 rlm_eap_md5: Issuing Challenge modcall[authenticate]: module "eap" returns handled for request 0 modcall: group authenticate returns handled for request 0 Sending Access-Challenge of id 1 to ********:37540 Framed-IP-Address = 255.255.255.254 Framed-MTU = 576 Service-Type = Framed-User Framed-Filter-Id = "Enterasys:version=1:mgmt=su:policy=admin" EAP-Message = 0x******** Message-Authenticator = 0x00000000000000000000000000000000 State = 0x******** Finished request 0 Going to the next request --- Walking the entire request list --- Waking up in 6 seconds... rad_recv: Access-Request packet from host ********:37540, id=2, length=196 Message-Authenticator = 0x91c3c6cfd386855dc73803c5a3670318 User-Name = "********" State = 0xb9e826259b6a63f5c103fd209ffde50b NAS-IP-Address = ******** Called-Station-Id = "********" NAS-Port = 21001 NAS-Port-Id = "fe.2.1" NAS-Port-Type = Ethernet Framed-MTU = 1300 Service-Type = Framed-User Calling-Station-Id = "********" EAP-Message = 0x******** Processing the authorize section of radiusd.conf modcall: entering group authorize for request 1 modcall[authorize]: module "preprocess" returns ok for request 1 radius_xlat: '/var/log/radius/radacct/********/auth-detail-20070209' rlm_detail: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/********/auth-detail-20070209 modcall[authorize]: module "auth_log" returns ok for request 1 modcall[authorize]: module "chap" returns noop for request 1 modcall[authorize]: module "mschap" returns noop for request 1 rlm_eap: EAP packet type response id 2 length 41 rlm_eap: No EAP Start, assuming it's an on-going EAP conversation modcall[authorize]: module "eap" returns updated for request 1 users: Matched DEFAULT at 8 users: Matched DEFAULT at 103 users: Matched DEFAULT at 105 rlm_ldap: Entering ldap_groupcmp() radius_xlat: 'dc=********,dc=********' radius_xlat: '(uid=********)' rlm_ldap: ldap_get_conn: Checking Id: 0 rlm_ldap: ldap_get_conn: Got Id: 0 rlm_ldap: performing search in dc=********,dc=********, with filter (uid=********) rlm_ldap: ldap_release_conn: Release Id: 0 radius_xlat: '(&(objectClass=GroupOfNames)(member=uid=********, ou=users, dc=********,dc=********))' rlm_ldap: ldap_get_conn: Checking Id: 0 rlm_ldap: ldap_get_conn: Got Id: 0 rlm_ldap: performing search in dc=********,dc=********, with filter (&(cn= 802.1xwired)(&(objectClass=GroupOfNames)(member=uid=********, ou=users, dc=********,dc=********))) rlm_ldap::ldap_groupcmp: User found in group 802.1xwired rlm_ldap: ldap_release_conn: Release Id: 0 users: Matched DEFAULT at 121 modcall[authorize]: module "files" returns ok for request 1 modcall: group authorize returns updated for request 1 Processing the authorize section of radiusd.conf modcall: entering group Autz-Type for request 1 rlm_ldap: - authorize rlm_ldap: performing user authorization for ******** radius_xlat: '(uid=********)' radius_xlat: 'dc=********,dc=********' rlm_ldap: ldap_get_conn: Checking Id: 0 rlm_ldap: ldap_get_conn: Got Id: 0 rlm_ldap: performing search in dc=********,dc=********, with filter (uid=********) rlm_ldap: Added password a in check items rlm_ldap: looking for check items in directory... rlm_ldap: looking for reply items in directory... rlm_ldap: user ******** authorized to use remote access rlm_ldap: ldap_release_conn: Release Id: 0 modcall[authorize]: module "ldap" returns ok for request 1 modcall: group Autz-Type returns ok for request 1 rad_check_password: Found Auth-Type EAP auth: type "EAP" Processing the authenticate section of radiusd.conf modcall: entering group authenticate for request 1 rlm_eap: Request found, released from the list rlm_eap: EAP/md5 rlm_eap: processing type md5 rlm_eap: Freeing handler modcall[authenticate]: module "eap" returns ok for request 1 modcall: group authenticate returns ok for request 1 Processing the post-auth section of radiusd.conf modcall: entering group post-auth for request 1 radius_xlat: '/var/log/radius/radacct/********/reply-detail-20070209' rlm_detail: /var/log/radius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d expands to /var/log/radius/radacct/********/reply-detail-20070209 modcall[post-auth]: module "reply_log" returns ok for request 1 rlm_sql (sql): Processing sql_postauth radius_xlat: '********' rlm_sql (sql): sql_set_user escaped user --> '********' radius_xlat: 'INSERT into radpostauth (id, user, pass, reply, date) values ('', '********', 'Chap-Password', 'Access-Accept', NOW())' rlm_sql (sql) in sql_postauth: query is INSERT into radpostauth (id, user, pass, reply, date) values ('', '********', 'Chap-Password', 'Access-Accept', NOW()) rlm_sql (sql): Reserving sql socket id: 4 rlm_sql (sql): Released sql socket id: 4 modcall[post-auth]: module "sql" returns ok for request 1 modcall: group post-auth returns ok for request 1 Sending Access-Accept of id 2 to ********:37540 Framed-IP-Address = 255.255.255.254 Framed-MTU = 576 Service-Type = Framed-User Framed-Filter-Id = "Enterasys:version=1:mgmt=su:policy=admin" EAP-Message = 0x******** Message-Authenticator = 0x00000000000000000000000000000000 User-Name = "********" Finished request 1 Going to the next request --- Walking the entire request list --- Cleaning up request 0 ID 1 with timestamp 45cc6700 Waking up in 6 seconds... rad_recv: Accounting-Request packet from host ********:37541, id=1, length=100 Acct-Status-Type = Start User-Name = "********" Calling-Station-Id = "********" NAS-IP-Address = ******** NAS-Port = 21001 Acct-Delay-Time = 0 Acct-Session-Id = "1000004F" Acct-Authentic = RADIUS Processing the preacct section of radiusd.conf modcall: entering group preacct for request 2 modcall[preacct]: module "preprocess" returns noop for request 2 rlm_acct_unique: Hashing 'NAS-Port = 21001,Client-IP-Address = ********,NAS-IP-Address = ********,Acct-Session-Id = "1000004F",User-Name = "********"' rlm_acct_unique: Acct-Unique-Session-ID = "3974eb0b2b9f763c". modcall[preacct]: module "acct_unique" returns ok for request 2 rlm_realm: Looking up realm "********" for User-Name = "********" rlm_realm: No such realm "********" modcall[preacct]: module "suffix" returns noop for request 2 acct_users: Matched DEFAULT at 7 modcall[preacct]: module "files" returns ok for request 2 modcall: group preacct returns ok for request 2 Processing the accounting section of radiusd.conf modcall: entering group accounting for request 2 modcall[accounting]: module "acct_unique" returns noop for request 2 radius_xlat: '/var/log/radius/radacct/********/detail-20070209' rlm_detail: /var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /var/log/radius/radacct/********/detail-20070209 modcall[accounting]: module "detail" returns ok for request 2 modcall[accounting]: module "unix" returns ok for request 2 radius_xlat: '/var/log/radius/radutmp' radius_xlat: ********' modcall[accounting]: module "radutmp" returns ok for request 2 radius_xlat: '********' rlm_sql (sql): sql_set_user escaped user --> '********' radius_xlat: 'INSERT into radacct ***************** rlm_sql (sql): Reserving sql socket id: 3 rlm_sql (sql): Released sql socket id: 3 modcall[accounting]: module "sql" returns ok for request 2 modcall: group accounting returns ok for request 2 Sending Accounting-Response of id 1 to ********:37541 Finished request 2 -- Fabio