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