<br><br><div><span class="gmail_quote">On 5/8/07, <b class="gmail_sendername">Alan DeKok</b> <<a href="mailto:aland@deployingradius.com" target="_blank" onclick="return top.js.OpenExtLink(window,event,this)">aland@deployingradius.com
</a>> wrote:</span><blockquote class="gmail_quote" style="border-left: 1px solid rgb(204, 204, 204); margin: 0pt 0pt 0pt 0.8ex; padding-left: 1ex;">
<br> Perhaps you could explain what you mean by that. What's a "long<br>access time"?</blockquote><div><br>Excuse my english. I mean the time that passed between the user sends login information and the success authentication by the supplicant.
<br>
</div><br><blockquote class="gmail_quote" style="border-left: 1px solid rgb(204, 204, 204); margin: 0pt 0pt 0pt 0.8ex; padding-left: 1ex;"> Which doesn't include the debug output from the server.</blockquote><div><br>
<br>rad_recv: Access-Request packet from host <a href="http://192.168.181.1:32806">192.168.181.1:32806</a>, id=241, length=134<br> User-Name = "luca.tar"<br> EAP-Message = 0x02000012016c7563612e74617264656c6c61
<br> Message-Authenticator = 0x52d025161d172ba39e1692bef02ef0af<br> Calling-Station-Id = "00-1B-63-00-0C-DE"<br> Called-Station-Id = "00-13-D4-CF-C5-1B"<br> NAS-Port-Type = Wireless-802.11<br>
NAS-Port = 0<br> NAS-IP-Address = <a href="http://0.0.0.0">0.0.0.0</a><br> NAS-Identifier = "14"<br>Tue May 8 10:29:53 2007 : Debug: Processing the authorize section of radiusd.conf<br>Tue May 8 10:29:53 2007 : Debug: modcall: entering group authorize for request 497
<br>Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 497<br>Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 497
<br>Tue May 8 10:29:53 2007 : Debug: modcall[authorize]: module "preprocess" returns ok for request 497<br>Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 497<br>
Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 497<br>Tue May 8 10:29:53 2007 : Debug: modcall[authorize]: module "chap" returns noop for request 497<br>Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 497
<br>Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 497<br>Tue May 8 10:29:53 2007 : Debug: modcall[authorize]: module "mschap" returns noop for request 497
<br>Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 497<br>Tue May 8 10:29:53 2007 : Debug: rlm_realm: No '@' in User-Name = "luca.tar", looking up realm NULL
<br>Tue May 8 10:29:53 2007 : Debug: rlm_realm: Found realm "NULL"<br>Tue May 8 10:29:53 2007 : Debug: rlm_realm: Adding Stripped-User-Name = "luca.tar"<br>Tue May 8 10:29:53 2007 : Debug: rlm_realm: Proxying request from user
luca.tar to realm NULL<br>Tue May 8 10:29:53 2007 : Debug: rlm_realm: Adding Realm = "NULL"<br>Tue May 8 10:29:53 2007 : Debug: rlm_realm: Authentication realm is LOCAL.<br>Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 497
<br>Tue May 8 10:29:53 2007 : Debug: modcall[authorize]: module "suffix" returns noop for request 497<br>Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 497<br>Tue May 8 10:29:53 2007 : Debug: rlm_eap: EAP packet type response id 0 length 18
<br>Tue May 8 10:29:53 2007 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation<br>Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 497<br>Tue May 8 10:29:53 2007 : Debug: modcall[authorize]: module "eap" returns updated for request 497
<br>Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: calling files (rlm_files) for request 497<br>Tue May 8 10:29:53 2007 : Debug: users: Matched entry DEFAULT at line 154<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: Entering ldap_groupcmp()
<br>Tue May 8 10:29:53 2007 : Debug: radius_xlat: 'ou=stat,dc=univ,dc=il'<br>Tue May 8 10:29:53 2007 : Debug: radius_xlat: '(uid=luca.tar)'<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0
<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: performing search in ou=stat,dc=univ,dc=il, with filter (uid=luca.tar)<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0
<br>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)))'
<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0<br>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))))
<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: object not found or got ambiguous search result<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0
<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0<br>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=*)
<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap::ldap_groupcmp: User found in group professor<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0<br>Tue May 8 10:29:53 2007 : Debug: users: Matched entry DEFAULT at line 176
<br>Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 497<br>Tue May 8 10:29:53 2007 : Debug: modcall[authorize]: module "files" returns ok for request 497<br>
Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: calling ldap (rlm_ldap) for request 497<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: - authorize<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: performing user authorization for
luca.tar<br>Tue May 8 10:29:53 2007 : Debug: radius_xlat: '(uid=luca.tar)'<br>Tue May 8 10:29:53 2007 : Debug: radius_xlat: 'ou=stat,dc=univ,dc=il'<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0
<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: performing search in ou=stat,dc=univ,dc=il, with filter (uid=luca.tar)<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: checking if remote access for
luca.tar is allowed by userPassword<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: Added password PASSWORD in check items<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: looking for check items in directory...<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: Adding radiusGroupName as Ldap-Group, value professor & op=21
<br>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<br>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
<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: Adding userPassword as User-Password, value PASSWORD & op=21<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: looking for reply items in directory...<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: Adding radiusFilterId as Filter-Id, value 98 & op=11
<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: user luca.tar authorized to use remote access<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0<br>Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: returned from ldap (rlm_ldap) for request 497
<br>Tue May 8 10:29:53 2007 : Debug: modcall[authorize]: module "ldap" returns ok for request 497<br>Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: calling checkval (rlm_checkval) for request 497<br>
Tue May 8 10:29:53 2007 : Debug: rlm_checkval: Item Name: Calling-Station-Id, Value: 00-1B-63-00-0C-DE<br>Tue May 8 10:29:53 2007 : Debug: rlm_checkval: Value Name: Calling-Station-Id, Value: 00-0C-F1-18-64-E5<br>Tue May 8 10:29:53 2007 : Debug: rlm_checkval: Value Name: Calling-Station-Id, Value: 00-1B-63-00-0C-DE
<br>Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: returned from checkval (rlm_checkval) for request 497<br>Tue May 8 10:29:53 2007 : Debug: modcall[authorize]: module "checkval" returns ok for request 497
<br>Tue May 8 10:29:53 2007 : Debug: modcall: leaving group authorize (returns updated) for request 497<br>Tue May 8 10:29:53 2007 : Debug: rad_check_password: Found Auth-Type EAP<br>Tue May 8 10:29:53 2007 : Debug: auth: type "EAP"
<br>Tue May 8 10:29:53 2007 : Debug: Processing the authenticate section of radiusd.conf<br>Tue May 8 10:29:53 2007 : Debug: modcall: entering group authenticate for request 497<br>Tue May 8 10:29:53 2007 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 497
<br>Tue May 8 10:29:53 2007 : Debug: rlm_eap: EAP Identity<br>Tue May 8 10:29:53 2007 : Debug: rlm_eap: processing type tls<br>Tue May 8 10:29:53 2007 : Debug: rlm_eap_tls: Initiate<br>Tue May 8 10:29:53 2007 : Debug: rlm_eap_tls: Start returned 1
<br>Tue May 8 10:29:53 2007 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 497<br>Tue May 8 10:29:53 2007 : Debug: modcall[authenticate]: module "eap" returns handled for request 497
<br>Tue May 8 10:29:53 2007 : Debug: modcall: leaving group authenticate (returns handled) for request 497<br>Sending Access-Challenge of id 241 to <a href="http://192.168.181.1">192.168.181.1</a> port 32806<br> Service-Type == Framed-User
<br> Filter-Id = "98"<br> EAP-Message = 0x010100061920<br> Message-Authenticator = 0x00000000000000000000000000000000<br> State = 0x2db3a8c4fdfacad0a63ed88cb91f69a9<br>Tue May 8 10:29:53 2007 : Debug: Finished request 497
<br>Tue May 8 10:29:53 2007 : Debug: Going to the next request<br>Tue May 8 10:29:53 2007 : Debug: --- Walking the entire request list ---<br>Tue May 8 10:29:53 2007 : Debug: Waking up in 6 seconds...<br>rad_recv: Access-Request packet from host
<a href="http://192.168.181.1:32806">192.168.181.1:32806</a>, id=242, length=284<br> User-Name = "luca.tar"<br> State = 0x2db3a8c4fdfacad0a63ed88cb91f69a9<br> EAP-Message = 0x0201009619800000008c1603010087010000830301464035e41ea33c0757d3137d926f9650e52bb43eb4f95e02971d6cf5b3e53740204162bc29a02118b82d65caf9b96ef014362bd9cf2a87224606e7ce317c99fd91003c002f000500040035000aff830009ff82000300080006ff8000320033003400380039003a0016001500140013001200110018001b001a0017001900010100
<br> Message-Authenticator = 0x9fbe0741fb651146f161e55908be0246<br> Calling-Station-Id = "00-1B-63-00-0C-DE"<br> Called-Station-Id = "00-13-D4-CF-C5-1B"<br> NAS-Port-Type = Wireless-802.11<br>
NAS-Port = 0<br> NAS-IP-Address = <a href="http://0.0.0.0">0.0.0.0</a><br> NAS-Identifier = "14"<br>Tue May 8 10:29:53 2007 : Debug: Processing the authorize section of radiusd.conf<br>Tue May 8 10:29:53 2007 : Debug: modcall: entering group authorize for request 498
<br>Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 498<br>Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 498
<br>Tue May 8 10:29:53 2007 : Debug: modcall[authorize]: module "preprocess" returns ok for request 498<br>Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 498<br>
Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 498<br>Tue May 8 10:29:53 2007 : Debug: modcall[authorize]: module "chap" returns noop for request 498<br>Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 498
<br>Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 498<br>Tue May 8 10:29:53 2007 : Debug: modcall[authorize]: module "mschap" returns noop for request 498
<br>Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 498<br>Tue May 8 10:29:53 2007 : Debug: rlm_realm: No '@' in User-Name = "luca.tar", looking up realm NULL
<br>Tue May 8 10:29:53 2007 : Debug: rlm_realm: Found realm "NULL"<br>Tue May 8 10:29:53 2007 : Debug: rlm_realm: Adding Stripped-User-Name = "luca.tar"<br>Tue May 8 10:29:53 2007 : Debug: rlm_realm: Proxying request from user
luca.tar to realm NULL<br>Tue May 8 10:29:53 2007 : Debug: rlm_realm: Adding Realm = "NULL"<br>Tue May 8 10:29:53 2007 : Debug: rlm_realm: Authentication realm is LOCAL.<br>Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 498
<br>Tue May 8 10:29:53 2007 : Debug: modcall[authorize]: module "suffix" returns noop for request 498<br>Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 498<br>Tue May 8 10:29:53 2007 : Debug: rlm_eap: EAP packet type response id 1 length 150
<br>Tue May 8 10:29:53 2007 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation<br>Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 498<br>Tue May 8 10:29:53 2007 : Debug: modcall[authorize]: module "eap" returns updated for request 498
<br>Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: calling files (rlm_files) for request 498<br>Tue May 8 10:29:53 2007 : Debug: users: Matched entry DEFAULT at line 154<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: Entering ldap_groupcmp()
<br>Tue May 8 10:29:53 2007 : Debug: radius_xlat: 'ou=stat,dc=univ,dc=il'<br>Tue May 8 10:29:53 2007 : Debug: radius_xlat: '(uid=luca.tar)'<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0
<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: performing search in ou=stat,dc=univ,dc=il, with filter (uid=luca.tar)<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0
<br>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)))'
<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0<br>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))))
<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: object not found or got ambiguous search result<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0
<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0<br>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=*)
<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap::ldap_groupcmp: User found in group professor<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0<br>Tue May 8 10:29:53 2007 : Debug: users: Matched entry DEFAULT at line 176
<br>Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 498<br>Tue May 8 10:29:53 2007 : Debug: modcall[authorize]: module "files" returns ok for request 498<br>
Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: calling ldap (rlm_ldap) for request 498<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: - authorize<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: performing user authorization for
luca.tar<br>Tue May 8 10:29:53 2007 : Debug: radius_xlat: '(uid=luca.tar)'<br>Tue May 8 10:29:53 2007 : Debug: radius_xlat: 'ou=stat,dc=univ,dc=il'<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0
<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: performing search in ou=stat,dc=univ,dc=il, with filter (uid=luca.tar)<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: checking if remote access for
luca.tar is allowed by userPassword<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: Added password PASSWORD in check items<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: looking for check items in directory...<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: Adding radiusGroupName as Ldap-Group, value professor & op=21
<br>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<br>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
<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: Adding userPassword as User-Password, value PASSWORD & op=21<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: looking for reply items in directory...<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: Adding radiusFilterId as Filter-Id, value 98 & op=11
<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: user luca.tar authorized to use remote access<br>Tue May 8 10:29:53 2007 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0<br>Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: returned from ldap (rlm_ldap) for request 498
<br>Tue May 8 10:29:53 2007 : Debug: modcall[authorize]: module "ldap" returns ok for request 498<br>Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: calling checkval (rlm_checkval) for request 498<br>
Tue May 8 10:29:53 2007 : Debug: rlm_checkval: Item Name: Calling-Station-Id, Value: 00-1B-63-00-0C-DE<br>Tue May 8 10:29:53 2007 : Debug: rlm_checkval: Value Name: Calling-Station-Id, Value: 00-0C-F1-18-64-E5<br>Tue May 8 10:29:53 2007 : Debug: rlm_checkval: Value Name: Calling-Station-Id, Value: 00-1B-63-00-0C-DE
<br>Tue May 8 10:29:53 2007 : Debug: modsingle[authorize]: returned from checkval (rlm_checkval) for request 498<br>Tue May 8 10:29:53 2007 : Debug: modcall[authorize]: module "checkval" returns ok for request 498
<br>Tue May 8 10:29:53 2007 : Debug: modcall: leaving group authorize (returns updated) for request 498<br>Tue May 8 10:29:53 2007 : Debug: rad_check_password: Found Auth-Type EAP<br>Tue May 8 10:29:53 2007 : Debug: auth: type "EAP"
<br>Tue May 8 10:29:53 2007 : Debug: Processing the authenticate section of radiusd.conf<br>Tue May 8 10:29:53 2007 : Debug: modcall: entering group authenticate for request 498<br>Tue May 8 10:29:53 2007 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 498
<br>Tue May 8 10:29:53 2007 : Debug: rlm_eap: Request found, released from the list<br>Tue May 8 10:29:53 2007 : Debug: rlm_eap: EAP/peap<br>Tue May 8 10:29:53 2007 : Debug: rlm_eap: processing type peap<br>Tue May 8 10:29:53 2007 : Debug: rlm_eap_peap: Authenticate
<br>Tue May 8 10:29:53 2007 : Debug: rlm_eap_tls: processing TLS<br>Tue May 8 10:29:53 2007 : Debug: rlm_eap_tls: Length Included<br>Tue May 8 10:29:53 2007 : Debug: eaptls_verify returned 11 <br>Tue May 8 10:29:53 2007 : Debug: (other): before/accept initialization
<br>Tue May 8 10:29:53 2007 : Debug: TLS_accept: before/accept initialization <br>Tue May 8 10:29:53 2007 : Debug: rlm_eap_tls: <<< TLS 1.0 Handshake [length 0087], ClientHello <br>Tue May 8 10:29:53 2007 : Debug: TLS_accept: SSLv3 read client hello A
<br>Tue May 8 10:29:53 2007 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 004a], ServerHello <br>Tue May 8 10:29:53 2007 : Debug: TLS_accept: SSLv3 write server hello A <br>Tue May 8 10:29:53 2007 : Debug: rlm_eap_tls: >>> TLS
1.0 Handshake [length 0641], Certificate <br>Tue May 8 10:29:53 2007 : Debug: TLS_accept: SSLv3 write certificate A <br>Tue May 8 10:29:53 2007 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 0004], ServerHelloDone
<br>Tue May 8 10:29:53 2007 : Debug: TLS_accept: SSLv3 write server done A <br>Tue May 8 10:29:53 2007 : Debug: TLS_accept: SSLv3 flush data <br>Tue May 8 10:29:53 2007 : Debug: TLS_accept: Need to read more data: SSLv3 read client certificate A
<br>Tue May 8 10:29:53 2007 : Debug: In SSL Handshake Phase <br>Tue May 8 10:29:53 2007 : Debug: In SSL Accept mode <br>Tue May 8 10:29:53 2007 : Debug: eaptls_process returned 13 <br>Tue May 8 10:29:53 2007 : Debug: rlm_eap_peap: EAPTLS_HANDLED
<br>Tue May 8 10:29:53 2007 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 498<br>Tue May 8 10:29:53 2007 : Debug: modcall[authenticate]: module "eap" returns handled for request 498
<br>Tue May 8 10:29:53 2007 : Debug: modcall: leaving group authenticate (returns handled) for request 498<br>Sending Access-Challenge of id 242 to <a href="http://192.168.181.1">192.168.181.1</a> port 32806<br> Service-Type == Framed-User
<br> Filter-Id = "98"<br> EAP-Message = 0x0102040a19c00000069e160301004a020000460301464035013422c1c8ee0915e7d8316210df5d51e664d663b43340bb2872c73fc02040af0cceb7d93c433de2b180d3aec3e26711ef612403a44f27a0cd0f0f3e7b9d002f0016030106410b00063d00063a0002a9308202a53082020ea003020102020900ca3ef53cca0b2a55300d06092a864886f70d010104050030818a310b3009060355040613024954310e300c060355040813054c617a696f310d300b06035504071304526f6d6531153013060355040a130c4f7267616e697a6174696f6e311b301906035504031312436c69656e742063657274696669636174653128302606092a864886f7
<br> EAP-Message = 0x0d01090116196e69636f6c612e6e6f7669656c6c6f40676d61696c2e636f6d301e170d3036313132313131313430315a170d3037313132313131313430315a308184310b3009060355040613024954310e300c060355040813054c617a696f310d300b06035504071304526f6d6531153013060355040a130c4f7267616e697a6174696f6e3119301706035504031310526f6f742063657274696669636174653124302206092a864886f70d0109011615617263636173406c75672d6973636869612e6f726730819f300d06092a864886f70d010101050003818d0030818902818100c789a0bd5d6467d61d71a7d4c82b2a3a8b9b81a5d91729c9fbda
<br> EAP-Message = 0x45665740fce1c201534ca6875147be2963dfb5b5fb47d86fe063f1d00c544a604ca005a0adc875eef5d6f0fb246320c5029708c041dbb1d27f26814997813afff69b64679cc4beec97fb3645932ee5b7ca64a56c896f4b43d9d4fb3da8ee8191e455be23c6e30203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d010104050003818100674941ba438233287efc08a1095bfd4ecd565ae3d7ba3e319ced3ca3c0ddfd2bc0ccd0aa11315dfca9fe4c53ab946fe4dee893007981cf69d8c7a237697ff61234f39089e1309c9c1c722206ae3c3db21a045fcc3cd6308cc9265bbfc5467ead15fc3957d6ce
<br> EAP-Message = 0x0074ab8e6876412b7125e5b5829de0bc58f36814ab5000f68bec00038b30820387308202f0a003020102020900ca3ef53cca0b2a53300d06092a864886f70d010104050030818a310b3009060355040613024954310e300c060355040813054c617a696f310d300b06035504071304526f6d6531153013060355040a130c4f7267616e697a6174696f6e311b301906035504031312436c69656e742063657274696669636174653128302606092a864886f70d01090116196e69636f6c612e6e6f7669656c6c6f40676d61696c2e636f6d301e170d3036313132313131313430305a170d3136303632313131313430305a30818a310b30090603550406
<br> EAP-Message = 0x13024954310e300c060355040813054c617a696f310d<br> Message-Authenticator = 0x00000000000000000000000000000000<br> State = 0x97a53de462e11aaa37c84d623f825ef1<br>Tue May 8 10:29:53 2007 : Debug: Finished request 498
<br>Tue May 8 10:29:53 2007 : Debug: Going to the next request<br>Tue May 8 10:29:53 2007 : Debug: Waking up in 6 seconds...<br><br>And continue in the same mode.....<br>Reading the log seems that some operations are repeated many time before the user can obtain the access to the network.
<br>Thanks<br>
<br> </div><br></div><br>