Hi all, I have implemented Freeradius with LDAP, all works without error but when the user log in the access time is too log (about 3,5 minutes). This access time isn't platform depended (we use Windows and Mac client). These are the log: proxy.conf proxy server { synchronous = yes retry_delay = 0 retry_count = 0 dead_time = 0 default_fallback = yes post_proxy_authorize = no } realm LOCAL { type = radius authhost = LOCAL accthost = LOCAL } realm NULL { type = radius authhost = LOCAL accthost = LOCAL } realm localhost { type = radius authhost = 192.168.181.1:1645 accthost = 192.168.181.1:1646 secret = PASSWORD nostrip } ------------------------ RADLAST user3 000:chilli 192.168.182.123 Tue May 8 10:57 - 11:09 (00:12) user3 000:chilli 192.168.182.123 Tue May 8 10:57 - 10:57 (00:00) user3 000:chilli 192.168.182.123 Tue May 8 10:56 - 10:57 (00:00) user3 000:chilli 192.168.182.123 Tue May 8 10:56 - 10:56 (00:00) luca.tar 000:chilli 192.168.182.120 Tue May 8 10:43 - 10:49 (00:05) luca.tar 000:chilli 192.168.182.120 Tue May 8 10:43 - 10:43 (00:00) user3 000:chilli 192.168.182.119 Tue May 8 10:36 - 10:40 (00:03) user3 000:chilli 192.168.182.119 Tue May 8 10:36 - 10:36 (00:00) user3 000:chilli 192.168.182.119 Tue May 8 10:35 - 10:36 (00:00) user3 000:chilli 192.168.182.119 Tue May 8 10:35 - 10:35 (00:00) luca.tar 000:chilli 192.168.182.117 Tue May 8 10:35 - 10:35 (00:00) luca.tar 000:chilli 192.168.182.117 Tue May 8 10:34 - 10:35 (00:00) luca.tar 000:chilli 192.168.182.116 Tue May 8 10:33 - 10:34 (00:00) luca.tar 000:chilli 192.168.182.116 Tue May 8 10:33 - 10:33 (00:00) luca.tar 000:chilli 192.168.182.116 Tue May 8 10:32 - 10:33 (00:00) luca.tar 000:chilli 192.168.182.116 Tue May 8 10:32 - 10:32 (00:00) luca.tar 000:chilli 192.168.182.116 Tue May 8 10:31 - 10:32 (00:00) luca.tar 000:chilli 192.168.182.116 Tue May 8 10:31 - 10:31 (00:00) luca.tar 000:chilli 192.168.182.116 Tue May 8 10:30 - 10:31 (00:00) luca.tar 000:chilli 192.168.182.116 Tue May 8 10:30 - 10:30 (00:00) luca.tar 000:chilli 192.168.182.116 Tue May 8 10:29 - 10:30 (00:00) luca.tar 000:chilli 192.168.182.113 Tue May 8 10:11 - 10:15 (00:03) luca.tar 000:chilli 192.168.182.113 Tue May 8 10:11 - 10:11 (00:00) luca.tar 000:chilli 192.168.182.113 Tue May 8 10:10 - 10:11 (00:00) luca.tar 000:chilli 192.168.182.109 Tue May 8 09:45 - 09:52 (00:07) luca.tar 000:chilli 192.168.182.109 Tue May 8 09:44 - 09:45 (00:00) luca.tar 000:chilli 192.168.182.108 Tue May 8 09:43 - 09:44 (00:00) luca.tar 000:chilli 192.168.182.108 Tue May 8 09:43 - 09:43 (00:00) luca.tar 000:chilli 192.168.182.108 Tue May 8 09:42 - 09:43 (00:00) luca.tar 000:chilli 192.168.182.108 Tue May 8 09:42 - 09:42 (00:00) luca.tar 000:chilli 192.168.182.108 Tue May 8 09:41 - 09:42 (00:00) luca.tar 000:chilli 192.168.182.108 Tue May 8 09:41 - 09:41 (00:00) luca.tar 000:chilli 192.168.182.108 Tue May 8 09:40 - 09:41 (00:00) luca.tar 000:chilli 192.168.182.108 Tue May 8 09:40 - 09:40 (00:00) user2 000:chilli 192.168.182.101 Tue May 8 08:42 - 09:40 (00:57) ---------------------------------------------- This is the client's log: Macintosh:~ luca$ tail -f /var/log/system.log system.log system.log.0.gz system.log.1.gz system.log.2.gz Macintosh:~ luca$ tail -f /var/log/system.log May 8 10:35:08 Macintosh lookupd[1969]: lookupd (version 369.6) starting - Tue May 8 10:35:08 2007 May 8 10:35:11 Macintosh kernel[0]: 11D beacon causing regdomain change to CC 826 May 8 10:35:11 Macintosh kernel[0]: en1: 802.11d country code set to 'GB'. May 8 10:35:11 Macintosh kernel[0]: en1: Supported channels 1 2 3 4 5 6 7 8 9 10 11 12 13 36 40 44 48 52 56 60 64 100 104 108 112 116 120 124 128 132 136 140 May 8 10:35:14 Macintosh eapolclient[243]: eapmschapv2_success_request: successfully authenticated May 8 10:35:18 Macintosh mDNSResponder: Repeated transitions for interface en1 (FE80:0000:0000:0000:021B:63FF :FE00:0CDE); delaying packets by 5 seconds May 8 10:35:20 Macintosh configd[35]: posting notification com.apple.system.config.network_change May 8 10:35:20 Macintosh lookupd[1971]: lookupd (version 369.6) starting - Tue May 8 10:35:20 2007 May 8 10:35:22 Macintosh mDNSResponder: Repeated transitions for interface en1 ( 169.254.95.177); delaying packets by 5 seconds May 8 10:35:44 Macintosh eapolclient[243]: eapmschapv2_success_request: successfully authenticated May 8 10:36:15 Macintosh eapolclient[243]: eapmschapv2_success_request: successfully authenticated May 8 10:36:45 Macintosh eapolclient[243]: eapmschapv2_success_request: successfully authenticated May 8 10:37:15 Macintosh eapolclient[243]: eapmschapv2_success_request: successfully authenticated May 8 10:37:45 Macintosh eapolclient[243]: eapmschapv2_success_request: successfully authenticated May 8 10:38:16 Macintosh eapolclient[243]: eapmschapv2_success_request: successfully authenticated May 8 10:38:47 Macintosh eapolclient[243]: eapmschapv2_success_request: successfully authenticated May 8 10:38:53 Macintosh configd[35]: posting notification com.apple.system.config.network_change May 8 10:38:53 Macintosh lookupd[1983]: lookupd (version 369.6) starting - Tue May 8 10:38:53 2007 -------------------------------- Thanks! Josh
Josh Shamir wrote:
I have implemented Freeradius with LDAP, all works without error but when the user log in the access time is too log (about 3,5 minutes).
Perhaps you could explain what you mean by that. What's a "long access time"?
This access time isn't platform depended (we use Windows and Mac client). These are the log:
Which doesn't include the debug output from the server. Alan DeKok. -- http://deployingradius.com - The web site of the book http://deployingradius.com/blog/ - The blog
On 5/8/07, Alan DeKok <aland@deployingradius.com> wrote:
Perhaps you could explain what you mean by that. What's a "long access time"?
Excuse my english. I mean the time that passed between the user sends login information and the success authentication by the supplicant. Which doesn't include the debug output from the server. rad_recv: Access-Request packet from host 192.168.181.1:32806, id=241, length=134 User-Name = "luca.tar" EAP-Message = 0x02000012016c7563612e74617264656c6c61 Message-Authenticator = 0x52d025161d172ba39e1692bef02ef0af Calling-Station-Id = "00-1B-63-00-0C-DE" Called-Station-Id = "00-13-D4-CF-C5-1B" NAS-Port-Type = Wireless-802.11 NAS-Port = 0 NAS-IP-Address = 0.0.0.0 NAS-Identifier = "14" Tue May 8 10:29:53 2007 : Debug: Processing the authorize section of radiusd.conf Tue May 8 10:29:53 2007 : Debug: modcall: entering group authorize for request 497 Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 497 Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 497 Tue May 8 10:29:53 2007 : Debug: modcall[authorize]: module "preprocess" returns ok for request 497 Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 497 Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 497 Tue May 8 10:29:53 2007 : Debug: modcall[authorize]: module "chap" returns noop for request 497 Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 497 Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 497 Tue May 8 10:29:53 2007 : Debug: modcall[authorize]: module "mschap" returns noop for request 497 Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 497 Tue May 8 10:29:53 2007 : Debug: rlm_realm: No '@' in User-Name = " luca.tar", looking up realm NULL Tue May 8 10:29:53 2007 : Debug: rlm_realm: Found realm "NULL" Tue May 8 10:29:53 2007 : Debug: rlm_realm: Adding Stripped-User-Name = "luca.tar" Tue May 8 10:29:53 2007 : Debug: rlm_realm: Proxying request from user luca.tar to realm NULL Tue May 8 10:29:53 2007 : Debug: rlm_realm: Adding Realm = "NULL" Tue May 8 10:29:53 2007 : Debug: rlm_realm: Authentication realm is LOCAL. Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 497 Tue May 8 10:29:53 2007 : Debug: modcall[authorize]: module "suffix" returns noop for request 497 Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 497 Tue May 8 10:29:53 2007 : Debug: rlm_eap: EAP packet type response id 0 length 18 Tue May 8 10:29:53 2007 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 497 Tue May 8 10:29:53 2007 : Debug: modcall[authorize]: module "eap" returns updated for request 497 Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: calling files (rlm_files) for request 497 Tue May 8 10:29:53 2007 : Debug: users: Matched entry DEFAULT at line 154 Tue May 8 10:29:53 2007 : Debug: rlm_ldap: Entering ldap_groupcmp() Tue May 8 10:29:53 2007 : Debug: radius_xlat: 'ou=stat,dc=univ,dc=il' Tue May 8 10:29:53 2007 : Debug: radius_xlat: '(uid=luca.tar)' Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0 Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0 Tue May 8 10:29:53 2007 : Debug: rlm_ldap: performing search in ou=stat,dc=univ,dc=il, with filter (uid=luca.tar) Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0 Tue May 8 10:29:53 2007 : Debug: radius_xlat: '(|(&(objectClass=GroupOfNames)(member=cn\3dLuca tar\2cou\3dfaculty\2cou\3ddspsa\2cou\3dstat\2cdc\3duniv\2cdc\3dil))(&(objectClass=GroupOfUniqueNames)(uniquemember=cn\3dLuca tar\2cou\3dfaculty\2cou\3ddspsa\2cou\3dstat\2cdc\3duniv\2cdc\3dil)))' Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0 Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0 Tue May 8 10:29:53 2007 : Debug: rlm_ldap: performing search in ou=stat,dc=univ,dc=il, with filter (&(cn=professor)(|(&(objectClass=GroupOfNames)(member=cn\3dLuca tar\2cou\3dfaculty\2cou\3ddspsa\2cou\3dstat\2cdc\3duniv\2cdc\3dil))(&(objectClass=GroupOfUniqueNames)(uniquemember=cn\3dLuca tar\2cou\3dfaculty\2cou\3ddspsa\2cou\3dstat\2cdc\3duniv\2cdc\3dil)))) Tue May 8 10:29:53 2007 : Debug: rlm_ldap: object not found or got ambiguous search result Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0 Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0 Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0 Tue May 8 10:29:53 2007 : Debug: rlm_ldap: performing search in cn=Luca tar,ou=faculty,ou=dspsa,ou=stat,dc=univ,dc=il, with filter (objectclass=*) Tue May 8 10:29:53 2007 : Debug: rlm_ldap::ldap_groupcmp: User found in group professor Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0 Tue May 8 10:29:53 2007 : Debug: users: Matched entry DEFAULT at line 176 Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 497 Tue May 8 10:29:53 2007 : Debug: modcall[authorize]: module "files" returns ok for request 497 Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: calling ldap (rlm_ldap) for request 497 Tue May 8 10:29:53 2007 : Debug: rlm_ldap: - authorize Tue May 8 10:29:53 2007 : Debug: rlm_ldap: performing user authorization for luca.tar Tue May 8 10:29:53 2007 : Debug: radius_xlat: '(uid=luca.tar)' Tue May 8 10:29:53 2007 : Debug: radius_xlat: 'ou=stat,dc=univ,dc=il' Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0 Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0 Tue May 8 10:29:53 2007 : Debug: rlm_ldap: performing search in ou=stat,dc=univ,dc=il, with filter (uid=luca.tar) Tue May 8 10:29:53 2007 : Debug: rlm_ldap: checking if remote access for luca.tar is allowed by userPassword Tue May 8 10:29:53 2007 : Debug: rlm_ldap: Added password PASSWORD in check items Tue May 8 10:29:53 2007 : Debug: rlm_ldap: looking for check items in directory... Tue May 8 10:29:53 2007 : Debug: rlm_ldap: Adding radiusGroupName as Ldap-Group, value professor & op=21 Tue May 8 10:29:53 2007 : Debug: rlm_ldap: Adding radiusCallingStationId as Calling-Station-Id, value 00-0C-F1-18-64-E5 & op=21 Tue May 8 10:29:53 2007 : Debug: rlm_ldap: Adding radiusCallingStationId as Calling-Station-Id, value 00-1B-63-00-0C-DE & op=21 Tue May 8 10:29:53 2007 : Debug: rlm_ldap: Adding userPassword as User-Password, value PASSWORD & op=21 Tue May 8 10:29:53 2007 : Debug: rlm_ldap: looking for reply items in directory... Tue May 8 10:29:53 2007 : Debug: rlm_ldap: Adding radiusFilterId as Filter-Id, value 98 & op=11 Tue May 8 10:29:53 2007 : Debug: rlm_ldap: user luca.tar authorized to use remote access Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0 Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: returned from ldap (rlm_ldap) for request 497 Tue May 8 10:29:53 2007 : Debug: modcall[authorize]: module "ldap" returns ok for request 497 Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: calling checkval (rlm_checkval) for request 497 Tue May 8 10:29:53 2007 : Debug: rlm_checkval: Item Name: Calling-Station-Id, Value: 00-1B-63-00-0C-DE Tue May 8 10:29:53 2007 : Debug: rlm_checkval: Value Name: Calling-Station-Id, Value: 00-0C-F1-18-64-E5 Tue May 8 10:29:53 2007 : Debug: rlm_checkval: Value Name: Calling-Station-Id, Value: 00-1B-63-00-0C-DE Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: returned from checkval (rlm_checkval) for request 497 Tue May 8 10:29:53 2007 : Debug: modcall[authorize]: module "checkval" returns ok for request 497 Tue May 8 10:29:53 2007 : Debug: modcall: leaving group authorize (returns updated) for request 497 Tue May 8 10:29:53 2007 : Debug: rad_check_password: Found Auth-Type EAP Tue May 8 10:29:53 2007 : Debug: auth: type "EAP" Tue May 8 10:29:53 2007 : Debug: Processing the authenticate section of radiusd.conf Tue May 8 10:29:53 2007 : Debug: modcall: entering group authenticate for request 497 Tue May 8 10:29:53 2007 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 497 Tue May 8 10:29:53 2007 : Debug: rlm_eap: EAP Identity Tue May 8 10:29:53 2007 : Debug: rlm_eap: processing type tls Tue May 8 10:29:53 2007 : Debug: rlm_eap_tls: Initiate Tue May 8 10:29:53 2007 : Debug: rlm_eap_tls: Start returned 1 Tue May 8 10:29:53 2007 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 497 Tue May 8 10:29:53 2007 : Debug: modcall[authenticate]: module "eap" returns handled for request 497 Tue May 8 10:29:53 2007 : Debug: modcall: leaving group authenticate (returns handled) for request 497 Sending Access-Challenge of id 241 to 192.168.181.1 port 32806 Service-Type == Framed-User Filter-Id = "98" EAP-Message = 0x010100061920 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x2db3a8c4fdfacad0a63ed88cb91f69a9 Tue May 8 10:29:53 2007 : Debug: Finished request 497 Tue May 8 10:29:53 2007 : Debug: Going to the next request Tue May 8 10:29:53 2007 : Debug: --- Walking the entire request list --- Tue May 8 10:29:53 2007 : Debug: Waking up in 6 seconds... rad_recv: Access-Request packet from host 192.168.181.1:32806, id=242, length=284 User-Name = "luca.tar" State = 0x2db3a8c4fdfacad0a63ed88cb91f69a9 EAP-Message = 0x0201009619800000008c1603010087010000830301464035e41ea33c0757d3137d926f9650e52bb43eb4f95e02971d6cf5b3e53740204162bc29a02118b82d65caf9b96ef014362bd9cf2a87224606e7ce317c99fd91003c002f000500040035000aff830009ff82000300080006ff8000320033003400380039003a0016001500140013001200110018001b001a0017001900010100 Message-Authenticator = 0x9fbe0741fb651146f161e55908be0246 Calling-Station-Id = "00-1B-63-00-0C-DE" Called-Station-Id = "00-13-D4-CF-C5-1B" NAS-Port-Type = Wireless-802.11 NAS-Port = 0 NAS-IP-Address = 0.0.0.0 NAS-Identifier = "14" Tue May 8 10:29:53 2007 : Debug: Processing the authorize section of radiusd.conf Tue May 8 10:29:53 2007 : Debug: modcall: entering group authorize for request 498 Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 498 Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 498 Tue May 8 10:29:53 2007 : Debug: modcall[authorize]: module "preprocess" returns ok for request 498 Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 498 Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 498 Tue May 8 10:29:53 2007 : Debug: modcall[authorize]: module "chap" returns noop for request 498 Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 498 Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 498 Tue May 8 10:29:53 2007 : Debug: modcall[authorize]: module "mschap" returns noop for request 498 Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 498 Tue May 8 10:29:53 2007 : Debug: rlm_realm: No '@' in User-Name = " luca.tar", looking up realm NULL Tue May 8 10:29:53 2007 : Debug: rlm_realm: Found realm "NULL" Tue May 8 10:29:53 2007 : Debug: rlm_realm: Adding Stripped-User-Name = "luca.tar" Tue May 8 10:29:53 2007 : Debug: rlm_realm: Proxying request from user luca.tar to realm NULL Tue May 8 10:29:53 2007 : Debug: rlm_realm: Adding Realm = "NULL" Tue May 8 10:29:53 2007 : Debug: rlm_realm: Authentication realm is LOCAL. Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 498 Tue May 8 10:29:53 2007 : Debug: modcall[authorize]: module "suffix" returns noop for request 498 Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 498 Tue May 8 10:29:53 2007 : Debug: rlm_eap: EAP packet type response id 1 length 150 Tue May 8 10:29:53 2007 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 498 Tue May 8 10:29:53 2007 : Debug: modcall[authorize]: module "eap" returns updated for request 498 Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: calling files (rlm_files) for request 498 Tue May 8 10:29:53 2007 : Debug: users: Matched entry DEFAULT at line 154 Tue May 8 10:29:53 2007 : Debug: rlm_ldap: Entering ldap_groupcmp() Tue May 8 10:29:53 2007 : Debug: radius_xlat: 'ou=stat,dc=univ,dc=il' Tue May 8 10:29:53 2007 : Debug: radius_xlat: '(uid=luca.tar)' Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0 Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0 Tue May 8 10:29:53 2007 : Debug: rlm_ldap: performing search in ou=stat,dc=univ,dc=il, with filter (uid=luca.tar) Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0 Tue May 8 10:29:53 2007 : Debug: radius_xlat: '(|(&(objectClass=GroupOfNames)(member=cn\3dLuca tar\2cou\3dfaculty\2cou\3ddspsa\2cou\3dstat\2cdc\3duniv\2cdc\3dil))(&(objectClass=GroupOfUniqueNames)(uniquemember=cn\3dLuca tar\2cou\3dfaculty\2cou\3ddspsa\2cou\3dstat\2cdc\3duniv\2cdc\3dil)))' Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0 Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0 Tue May 8 10:29:53 2007 : Debug: rlm_ldap: performing search in ou=stat,dc=univ,dc=il, with filter (&(cn=professor)(|(&(objectClass=GroupOfNames)(member=cn\3dLuca tar\2cou\3dfaculty\2cou\3ddspsa\2cou\3dstat\2cdc\3duniv\2cdc\3dil))(&(objectClass=GroupOfUniqueNames)(uniquemember=cn\3dLuca tar\2cou\3dfaculty\2cou\3ddspsa\2cou\3dstat\2cdc\3duniv\2cdc\3dil)))) Tue May 8 10:29:53 2007 : Debug: rlm_ldap: object not found or got ambiguous search result Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0 Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0 Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0 Tue May 8 10:29:53 2007 : Debug: rlm_ldap: performing search in cn=Luca tar,ou=faculty,ou=dspsa,ou=stat,dc=univ,dc=il, with filter (objectclass=*) Tue May 8 10:29:53 2007 : Debug: rlm_ldap::ldap_groupcmp: User found in group professor Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0 Tue May 8 10:29:53 2007 : Debug: users: Matched entry DEFAULT at line 176 Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 498 Tue May 8 10:29:53 2007 : Debug: modcall[authorize]: module "files" returns ok for request 498 Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: calling ldap (rlm_ldap) for request 498 Tue May 8 10:29:53 2007 : Debug: rlm_ldap: - authorize Tue May 8 10:29:53 2007 : Debug: rlm_ldap: performing user authorization for luca.tar Tue May 8 10:29:53 2007 : Debug: radius_xlat: '(uid=luca.tar)' Tue May 8 10:29:53 2007 : Debug: radius_xlat: 'ou=stat,dc=univ,dc=il' Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0 Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0 Tue May 8 10:29:53 2007 : Debug: rlm_ldap: performing search in ou=stat,dc=univ,dc=il, with filter (uid=luca.tar) Tue May 8 10:29:53 2007 : Debug: rlm_ldap: checking if remote access for luca.tar is allowed by userPassword Tue May 8 10:29:53 2007 : Debug: rlm_ldap: Added password PASSWORD in check items Tue May 8 10:29:53 2007 : Debug: rlm_ldap: looking for check items in directory... Tue May 8 10:29:53 2007 : Debug: rlm_ldap: Adding radiusGroupName as Ldap-Group, value professor & op=21 Tue May 8 10:29:53 2007 : Debug: rlm_ldap: Adding radiusCallingStationId as Calling-Station-Id, value 00-0C-F1-18-64-E5 & op=21 Tue May 8 10:29:53 2007 : Debug: rlm_ldap: Adding radiusCallingStationId as Calling-Station-Id, value 00-1B-63-00-0C-DE & op=21 Tue May 8 10:29:53 2007 : Debug: rlm_ldap: Adding userPassword as User-Password, value PASSWORD & op=21 Tue May 8 10:29:53 2007 : Debug: rlm_ldap: looking for reply items in directory... Tue May 8 10:29:53 2007 : Debug: rlm_ldap: Adding radiusFilterId as Filter-Id, value 98 & op=11 Tue May 8 10:29:53 2007 : Debug: rlm_ldap: user luca.tar authorized to use remote access Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0 Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: returned from ldap (rlm_ldap) for request 498 Tue May 8 10:29:53 2007 : Debug: modcall[authorize]: module "ldap" returns ok for request 498 Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: calling checkval (rlm_checkval) for request 498 Tue May 8 10:29:53 2007 : Debug: rlm_checkval: Item Name: Calling-Station-Id, Value: 00-1B-63-00-0C-DE Tue May 8 10:29:53 2007 : Debug: rlm_checkval: Value Name: Calling-Station-Id, Value: 00-0C-F1-18-64-E5 Tue May 8 10:29:53 2007 : Debug: rlm_checkval: Value Name: Calling-Station-Id, Value: 00-1B-63-00-0C-DE Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: returned from checkval (rlm_checkval) for request 498 Tue May 8 10:29:53 2007 : Debug: modcall[authorize]: module "checkval" returns ok for request 498 Tue May 8 10:29:53 2007 : Debug: modcall: leaving group authorize (returns updated) for request 498 Tue May 8 10:29:53 2007 : Debug: rad_check_password: Found Auth-Type EAP Tue May 8 10:29:53 2007 : Debug: auth: type "EAP" Tue May 8 10:29:53 2007 : Debug: Processing the authenticate section of radiusd.conf Tue May 8 10:29:53 2007 : Debug: modcall: entering group authenticate for request 498 Tue May 8 10:29:53 2007 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 498 Tue May 8 10:29:53 2007 : Debug: rlm_eap: Request found, released from the list Tue May 8 10:29:53 2007 : Debug: rlm_eap: EAP/peap Tue May 8 10:29:53 2007 : Debug: rlm_eap: processing type peap Tue May 8 10:29:53 2007 : Debug: rlm_eap_peap: Authenticate Tue May 8 10:29:53 2007 : Debug: rlm_eap_tls: processing TLS Tue May 8 10:29:53 2007 : Debug: rlm_eap_tls: Length Included Tue May 8 10:29:53 2007 : Debug: eaptls_verify returned 11 Tue May 8 10:29:53 2007 : Debug: (other): before/accept initialization Tue May 8 10:29:53 2007 : Debug: TLS_accept: before/accept initialization Tue May 8 10:29:53 2007 : Debug: rlm_eap_tls: <<< TLS 1.0 Handshake [length 0087], ClientHello Tue May 8 10:29:53 2007 : Debug: TLS_accept: SSLv3 read client hello A Tue May 8 10:29:53 2007 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 004a], ServerHello Tue May 8 10:29:53 2007 : Debug: TLS_accept: SSLv3 write server hello A Tue May 8 10:29:53 2007 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 0641], Certificate Tue May 8 10:29:53 2007 : Debug: TLS_accept: SSLv3 write certificate A Tue May 8 10:29:53 2007 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 0004], ServerHelloDone Tue May 8 10:29:53 2007 : Debug: TLS_accept: SSLv3 write server done A Tue May 8 10:29:53 2007 : Debug: TLS_accept: SSLv3 flush data Tue May 8 10:29:53 2007 : Debug: TLS_accept: Need to read more data: SSLv3 read client certificate A Tue May 8 10:29:53 2007 : Debug: In SSL Handshake Phase Tue May 8 10:29:53 2007 : Debug: In SSL Accept mode Tue May 8 10:29:53 2007 : Debug: eaptls_process returned 13 Tue May 8 10:29:53 2007 : Debug: rlm_eap_peap: EAPTLS_HANDLED Tue May 8 10:29:53 2007 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 498 Tue May 8 10:29:53 2007 : Debug: modcall[authenticate]: module "eap" returns handled for request 498 Tue May 8 10:29:53 2007 : Debug: modcall: leaving group authenticate (returns handled) for request 498 Sending Access-Challenge of id 242 to 192.168.181.1 port 32806 Service-Type == Framed-User Filter-Id = "98" EAP-Message = 0x0102040a19c00000069e160301004a020000460301464035013422c1c8ee0915e7d8316210df5d51e664d663b43340bb2872c73fc02040af0cceb7d93c433de2b180d3aec3e26711ef612403a44f27a0cd0f0f3e7b9d002f0016030106410b00063d00063a0002a9308202a53082020ea003020102020900ca3ef53cca0b2a55300d06092a864886f70d010104050030818a310b3009060355040613024954310e300c060355040813054c617a696f310d300b06035504071304526f6d6531153013060355040a130c4f7267616e697a6174696f6e311b301906035504031312436c69656e742063657274696669636174653128302606092a864886f7 EAP-Message = 0x0d01090116196e69636f6c612e6e6f7669656c6c6f40676d61696c2e636f6d301e170d3036313132313131313430315a170d3037313132313131313430315a308184310b3009060355040613024954310e300c060355040813054c617a696f310d300b06035504071304526f6d6531153013060355040a130c4f7267616e697a6174696f6e3119301706035504031310526f6f742063657274696669636174653124302206092a864886f70d0109011615617263636173406c75672d6973636869612e6f726730819f300d06092a864886f70d010101050003818d0030818902818100c789a0bd5d6467d61d71a7d4c82b2a3a8b9b81a5d91729c9fbda EAP-Message = 0x45665740fce1c201534ca6875147be2963dfb5b5fb47d86fe063f1d00c544a604ca005a0adc875eef5d6f0fb246320c5029708c041dbb1d27f26814997813afff69b64679cc4beec97fb3645932ee5b7ca64a56c896f4b43d9d4fb3da8ee8191e455be23c6e30203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d010104050003818100674941ba438233287efc08a1095bfd4ecd565ae3d7ba3e319ced3ca3c0ddfd2bc0ccd0aa11315dfca9fe4c53ab946fe4dee893007981cf69d8c7a237697ff61234f39089e1309c9c1c722206ae3c3db21a045fcc3cd6308cc9265bbfc5467ead15fc3957d6ce EAP-Message = 0x0074ab8e6876412b7125e5b5829de0bc58f36814ab5000f68bec00038b30820387308202f0a003020102020900ca3ef53cca0b2a53300d06092a864886f70d010104050030818a310b3009060355040613024954310e300c060355040813054c617a696f310d300b06035504071304526f6d6531153013060355040a130c4f7267616e697a6174696f6e311b301906035504031312436c69656e742063657274696669636174653128302606092a864886f70d01090116196e69636f6c612e6e6f7669656c6c6f40676d61696c2e636f6d301e170d3036313132313131313430305a170d3136303632313131313430305a30818a310b30090603550406 EAP-Message = 0x13024954310e300c060355040813054c617a696f310d Message-Authenticator = 0x00000000000000000000000000000000 State = 0x97a53de462e11aaa37c84d623f825ef1 Tue May 8 10:29:53 2007 : Debug: Finished request 498 Tue May 8 10:29:53 2007 : Debug: Going to the next request Tue May 8 10:29:53 2007 : Debug: Waking up in 6 seconds... And continue in the same mode..... Reading the log seems that some operations are repeated many time before the user can obtain the access to the network. Thanks
Josh Shamir wrote:
Excuse my english. I mean the time that passed between the user sends login information and the success authentication by the supplicant.
Sounds like the supplicant or access point has issues.
rad_recv: Access-Request packet from host 192.168.181.1:32806 ...
Which doesn't include a final Access-Accept, or Access-Reject. The supplicant is setting up the SSL tunnel, and then giving up at the last minute, before the user is authenticated.
And continue in the same mode..... Reading the log seems that some operations are repeated many time before the user can obtain the access to the network.
So what's different about the session that finally gets authenticated? I don't know why this would be happening. I haven't seen it happen on various MAC's I have access to. Alan DeKok. -- http://deployingradius.com - The web site of the book http://deployingradius.com/blog/ - The blog
On 5/8/07, Alan DeKok <aland@deployingradius.com> wrote:
Sounds like the supplicant or access point has issues.
It can be an access point problem? About the communication with Coovachilli or Radius? Or proxy.conf bad configured?
Which doesn't include a final Access-Accept, or Access-Reject.
Here it is: rad_recv: Access-Request packet from host 192.168.181.1:32806, id=249, length=177 User-Name = "luca.tar" State = 0x6e06a4c26ade18c076519b870babcfa0 EAP-Message = 0x0208002b19001703010020a756da39e479810ae0a78707912f9ed7c572929c37cdbdf2d725c2f2571be6c0 Message-Authenticator = 0xc1ea0ec6b1b52c6afd928b12970dbd09 Calling-Station-Id = "00-1B-63-00-0C-DE" Called-Station-Id = "00-13-D4-CF-C5-1B" NAS-Port-Type = Wireless-802.11 NAS-Port = 0 NAS-IP-Address = 0.0.0.0 NAS-Identifier = "14" Tue May 8 10:29:54 2007 : Debug: Processing the authorize section of radiusd.conf Tue May 8 10:29:54 2007 : Debug: modcall: entering group authorize for request 505 Tue May 8 10:29:54 2007 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 505 Tue May 8 10:29:54 2007 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 505 Tue May 8 10:29:54 2007 : Debug: modcall[authorize]: module "preprocess" returns ok for request 505 Tue May 8 10:29:54 2007 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 505 Tue May 8 10:29:54 2007 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 505 Tue May 8 10:29:54 2007 : Debug: modcall[authorize]: module "chap" returns noop for request 505 Tue May 8 10:29:54 2007 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 505 Tue May 8 10:29:54 2007 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 505 Tue May 8 10:29:54 2007 : Debug: modcall[authorize]: module "mschap" returns noop for request 505 Tue May 8 10:29:54 2007 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 505 Tue May 8 10:29:54 2007 : Debug: rlm_realm: No '@' in User-Name = "luca.tar", looking up realm NULL Tue May 8 10:29:54 2007 : Debug: rlm_realm: Found realm "NULL" Tue May 8 10:29:54 2007 : Debug: rlm_realm: Adding Stripped-User-Name = "luca.tar" Tue May 8 10:29:54 2007 : Debug: rlm_realm: Proxying request from user luca.tar to realm NULL Tue May 8 10:29:54 2007 : Debug: rlm_realm: Adding Realm = "NULL" Tue May 8 10:29:54 2007 : Debug: rlm_realm: Authentication realm is LOCAL. Tue May 8 10:29:54 2007 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 505 Tue May 8 10:29:54 2007 : Debug: modcall[authorize]: module "suffix" returns noop for request 505 Tue May 8 10:29:54 2007 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 505 Tue May 8 10:29:54 2007 : Debug: rlm_eap: EAP packet type response id 8 length 43 Tue May 8 10:29:54 2007 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Tue May 8 10:29:54 2007 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 505 Tue May 8 10:29:54 2007 : Debug: modcall[authorize]: module "eap" returns updated for request 505 Tue May 8 10:29:54 2007 : Debug: modsingle[authorize]: calling files (rlm_files) for request 505 Tue May 8 10:29:54 2007 : Debug: users: Matched entry DEFAULT at line 154 Tue May 8 10:29:54 2007 : Debug: rlm_ldap: Entering ldap_groupcmp() Tue May 8 10:29:54 2007 : Debug: radius_xlat: 'ou=stat,dc=univ,dc=il' Tue May 8 10:29:54 2007 : Debug: radius_xlat: '(uid=luca.tar)' Tue May 8 10:29:54 2007 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0 Tue May 8 10:29:54 2007 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0 Tue May 8 10:29:54 2007 : Debug: rlm_ldap: performing search in ou=stat,dc=univ,dc=it, with filter (uid=luca.tar) Tue May 8 10:29:54 2007 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0 Tue May 8 10:29:54 2007 : Debug: radius_xlat: '(|(&(objectClass=GroupOfNames)(member=cn\3dLuca Tar\2cou\3dfaculty\2cou\3ddspsa\2cou\3dstat\2cdc\3duniv\2 cdc\3dil))(&(objectClass=GroupOfUniqueNames)(uniquemember=cn\3dLuca Tar\2cou\3dfaculty\2cou\3ddspsa\2cou\3dstat\2cdc\3duniv\2cdc\3dil)))' Tue May 8 10:29:54 2007 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0 Tue May 8 10:29:54 2007 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0 Tue May 8 10:29:54 2007 : Debug: rlm_ldap: performing search in ou=stat,dc=univ,dc=it, with filter (&(cn=professor)(|(&(objectClass=GroupOfNames)(member=cn\3d Luca Tar\2cou\3dfaculty\2cou\3ddspsa\2cou\3dstat\2cdc\3duniv\2cdc\3dil))(&(objectClass=GroupOfUniqueNames)(uniquemember=cn\3dLuca Tar\2cou\3dfaculty\ 2cou\3ddspsa\2cou\3dstat\2cdc\3duniv\2cdc\3dil)))) Tue May 8 10:29:54 2007 : Debug: rlm_ldap: object not found or got ambiguous search result Tue May 8 10:29:54 2007 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0 Tue May 8 10:29:54 2007 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0 Tue May 8 10:29:54 2007 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0 Tue May 8 10:29:54 2007 : Debug: rlm_ldap: performing search in cn=Luca Tar,ou=faculty,ou=dspsa,ou=stat,dc=univ,dc=il, with filter (objectclass=*) Tue May 8 10:29:54 2007 : Debug: rlm_ldap::ldap_groupcmp: User found in group professor Tue May 8 10:29:54 2007 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0 Tue May 8 10:29:54 2007 : Debug: users: Matched entry DEFAULT at line 176 Tue May 8 10:29:54 2007 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 505 Tue May 8 10:29:54 2007 : Debug: modcall[authorize]: module "files" returns ok for request 505 Tue May 8 10:29:54 2007 : Debug: modsingle[authorize]: calling ldap (rlm_ldap) for request 505 Tue May 8 10:29:54 2007 : Debug: rlm_ldap: - authorize Tue May 8 10:29:54 2007 : Debug: rlm_ldap: performing user authorization for luca.tar Tue May 8 10:29:54 2007 : Debug: radius_xlat: '(uid=luca.tar)' Tue May 8 10:29:54 2007 : Debug: radius_xlat: 'ou=stat,dc=univ,dc=il' Tue May 8 10:29:54 2007 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0 Tue May 8 10:29:54 2007 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0 Tue May 8 10:29:54 2007 : Debug: rlm_ldap: performing search in ou=stat,dc=univ,dc=il, with filter (uid=luca.tar) Tue May 8 10:29:54 2007 : Debug: rlm_ldap: checking if remote access for luca.tar is allowed by userPassword Tue May 8 10:29:54 2007 : Debug: rlm_ldap: Added password PASSWORD in check items Tue May 8 10:29:54 2007 : Debug: rlm_ldap: looking for check items in directory... Tue May 8 10:29:54 2007 : Debug: rlm_ldap: Adding radiusGroupName as Ldap-Group, value professor & op=21 Tue May 8 10:29:54 2007 : Debug: rlm_ldap: Adding radiusCallingStationId as Calling-Station-Id, value 00-0C-F1-18-64-E5 & op=21 Tue May 8 10:29:54 2007 : Debug: rlm_ldap: Adding radiusCallingStationId as Calling-Station-Id, value 00-1B-63-00-0C-DE & op=21 Tue May 8 10:29:54 2007 : Debug: rlm_ldap: Adding userPassword as User-Password, value PASSWORD & op=21 Tue May 8 10:29:54 2007 : Debug: rlm_ldap: looking for reply items in directory... Tue May 8 10:29:54 2007 : Debug: rlm_ldap: Adding radiusFilterId as Filter-Id, value 98 & op=11 Tue May 8 10:29:54 2007 : Debug: rlm_ldap: user luca.tar authorized to use remote access Tue May 8 10:29:54 2007 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0 Tue May 8 10:29:54 2007 : Debug: modsingle[authorize]: returned from ldap (rlm_ldap) for request 505 Tue May 8 10:29:54 2007 : Debug: modcall[authorize]: module "ldap" returns ok for request 505 Tue May 8 10:29:54 2007 : Debug: modsingle[authorize]: calling checkval (rlm_checkval) for request 505 Tue May 8 10:29:54 2007 : Debug: rlm_checkval: Item Name: Calling-Station-Id, Value: 00-1B-63-00-0C-DE Tue May 8 10:29:54 2007 : Debug: rlm_checkval: Value Name: Calling-Station-Id, Value: 00-0C-F1-18-64-E5 Tue May 8 10:29:54 2007 : Debug: rlm_checkval: Value Name: Calling-Station-Id, Value: 00-1B-63-00-0C-DE Tue May 8 10:29:54 2007 : Debug: modsingle[authorize]: returned from checkval (rlm_checkval) for request 505 Tue May 8 10:29:54 2007 : Debug: modcall[authorize]: module "checkval" returns ok for request 505 Tue May 8 10:29:54 2007 : Debug: modcall: leaving group authorize (returns updated) for request 505 Tue May 8 10:29:54 2007 : Debug: rad_check_password: Found Auth-Type EAP Tue May 8 10:29:54 2007 : Debug: auth: type "EAP" Tue May 8 10:29:54 2007 : Debug: Processing the authenticate section of radiusd.conf Tue May 8 10:29:54 2007 : Debug: modcall: entering group authenticate for request 505 Tue May 8 10:29:54 2007 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 505 Tue May 8 10:29:54 2007 : Debug: rlm_eap: Request found, released from the list Tue May 8 10:29:54 2007 : Debug: rlm_eap: EAP/peap Tue May 8 10:29:54 2007 : Debug: rlm_eap: processing type peap Tue May 8 10:29:54 2007 : Debug: rlm_eap_peap: Authenticate Tue May 8 10:29:54 2007 : Debug: rlm_eap_tls: processing TLS Tue May 8 10:29:54 2007 : Debug: eaptls_verify returned 7 Tue May 8 10:29:54 2007 : Debug: rlm_eap_tls: Done initial handshake Tue May 8 10:29:54 2007 : Debug: eaptls_process returned 7 Tue May 8 10:29:54 2007 : Debug: rlm_eap_peap: EAPTLS_OK Tue May 8 10:29:54 2007 : Debug: rlm_eap_peap: Session established. Decoding tunneled attributes. PEAP tunnel data in 0000: 02 08 00 0b 21 00 03 00 02 00 01 Tue May 8 10:29:54 2007 : Debug: rlm_eap_peap: Received EAP-TLV response. Tue May 8 10:29:54 2007 : Debug: rlm_eap_peap: Tunneled data is valid. Tue May 8 10:29:54 2007 : Debug: rlm_eap_peap: Success Tue May 8 10:29:54 2007 : Debug: rlm_eap: Freeing handler Tue May 8 10:29:54 2007 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 505 Tue May 8 10:29:54 2007 : Debug: modcall[authenticate]: module "eap" returns ok for request 505 Tue May 8 10:29:54 2007 : Debug: modcall: leaving group authenticate (returns ok) for request 505 Tue May 8 10:29:54 2007 : Auth: Login OK: [luca.tar/<no User-Password attribute>] (from client chilli port 0 cli 00-1B-63-00-0C-DE) Sending Access-Accept of id 249 to 192.168.181.1 port 32806 Service-Type == Framed-User Filter-Id = "98" MS-MPPE-Recv-Key = 0xf3e32519ac70611ad1e77ff451de9cbd1b505f0107bc55a34a6fca9b8a295bf4 MS-MPPE-Send-Key = 0x4b66b29e9f0570d621bd6e059e447ce157b2f6290a4a3cdfdf90f8f1f1bd0458 EAP-Message = 0x03080004 Message-Authenticator = 0x00000000000000000000000000000000 User-Name = "luca.tar" Tue May 8 10:29:54 2007 : Debug: Finished request 505 Tue May 8 10:29:54 2007 : Debug: Going to the next request Tue May 8 10:29:54 2007 : Debug: Waking up in 5 seconds...
I don't know why this would be happening. I haven't seen it happen on various MAC's I have access to.
:) Best regards. Josh
Josh Shamir wrote:
It can be an access point problem? About the communication with Coovachilli or Radius?
The packets are making it to the supplicant, so I don't think there's a problem with the AP or anything else. It's a supplicant issue.
Or proxy.conf bad configured?
The requests aren't being proxied, so proxy.conf doesn't affect anything. Alan DeKok. -- http://deployingradius.com - The web site of the book http://deployingradius.com/blog/ - The blog
The packets are making it to the supplicant, so I don't think there's a problem with the AP or anything else. It's a supplicant issue.
The strange problem is that the long authentication time are about the same for Win XP build-in supplicant and MAC OS X supplicant. What kind of changes can i made in supplicant configuration to try to minimize authentication time?
The requests aren't being proxied, so proxy.conf doesn't affect anything.
Ok, but could I improve the system performance setting up in appropriate way those attribute : retry_delay dead_time retry_count ? As always, thanks a lot Josh
Josh Shamir wrote:
The strange problem is that the long authentication time are about the same for Win XP build-in supplicant and MAC OS X supplicant. What kind of changes can i made in supplicant configuration to try to minimize authentication time?
I don't know.
Ok, but could I improve the system performance setting up in appropriate way those attribute :
retry_delay dead_time retry_count
No. Read the extended debug log (-xX). Odds are that the successful authentications take 1-2 seconds from start to finish. If that's true, then everything would seem to be working properly. Look at the unsuccessful authentications. If they go on for 1-2 seconds and then stop, then they're mostly working correctly, too. The problem may be in the AP, or in the radio spectrum. Try a different AP. Alan DeKok. -- http://deployingradius.com - The web site of the book http://deployingradius.com/blog/ - The blog
participants (2)
-
Alan DeKok -
Josh Shamir