rad_recv: Access-Request packet from host 10.200.0.2 port 32832, id=203, length=238
User-Name = "xxx@sabanciuniv.edu.tr"
NAS-IP-Address = 10.200.0.2
NAS-Port = 0
NAS-Identifier = "10.200.0.2"
NAS-Port-Type = Wireless-802.11
Calling-Station-Id = "1C659DA0C84D"
Called-Station-Id = "000B8661DFC4"
Service-Type = Login-User
Framed-MTU = 1100
EAP-Message = 0x020a002401676f6b68616e67756e796f6c40736162616e6369756e69762e6564752e7472
Aruba-Essid-Name = "eduroam"
Aruba-Location-Id = "BM_IT_Net_Sys_3c:02"
Aruba-Attr-10 = 0x424d5f62696e617369
Message-Authenticator = 0x7bde0503caf078e16964c30bb649186a
Thu Jul 12 08:50:06 2012 : Info: server eduroam {
Thu Jul 12 08:50:06 2012 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/eduroam
Thu Jul 12 08:50:06 2012 : Info: +- entering group authorize {...}
Thu Jul 12 08:50:06 2012 : Info: ++[preprocess] returns ok
Thu Jul 12 08:50:06 2012 : Info: [auth_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/10.200.0.2/auth-detail-20120712
Thu Jul 12 08:50:06 2012 : Info: [auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/10.200.0.2/auth-detail-20120712
Thu Jul 12 08:50:06 2012 : Info: [auth_log] expand: %t -> Thu Jul 12 08:50:06 2012
Thu Jul 12 08:50:06 2012 : Info: ++[auth_log] returns ok
Thu Jul 12 08:50:06 2012 : Info: ++[mschap] returns noop
Thu Jul 12 08:50:06 2012 : Info: [suffix] Looking up realm "sabanciuniv.edu.tr" for User-Name = "xxx@sabanciuniv.edu.tr"
Thu Jul 12 08:50:06 2012 : Info: [suffix] Found realm "sabanciuniv.edu.tr"
Thu Jul 12 08:50:06 2012 : Info: [suffix] Adding Stripped-User-Name = "xxx"
Thu Jul 12 08:50:06 2012 : Info: [suffix] Adding Realm = "sabanciuniv.edu.tr"
Thu Jul 12 08:50:06 2012 : Info: [suffix] Authentication realm is LOCAL.
Thu Jul 12 08:50:06 2012 : Info: ++[suffix] returns ok
Thu Jul 12 08:50:06 2012 : Info: [eap] EAP packet type response id 10 length 36
Thu Jul 12 08:50:06 2012 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Thu Jul 12 08:50:06 2012 : Info: ++[eap] returns updated
Thu Jul 12 08:50:06 2012 : Info: ++[files] returns noop
Thu Jul 12 08:50:06 2012 : Info: ++[expiration] returns noop
Thu Jul 12 08:50:06 2012 : Info: ++[logintime] returns noop
Thu Jul 12 08:50:06 2012 : Info: Found Auth-Type = EAP
Thu Jul 12 08:50:06 2012 : Info: # Executing group from file /etc/raddb/sites-enabled/eduroam
Thu Jul 12 08:50:06 2012 : Info: +- entering group authenticate {...}
Thu Jul 12 08:50:06 2012 : Info: [eap] EAP Identity
Thu Jul 12 08:50:06 2012 : Info: [eap] processing type tls
Thu Jul 12 08:50:06 2012 : Info: [tls] Initiate
Thu Jul 12 08:50:06 2012 : Info: [tls] Start returned 1
Thu Jul 12 08:50:06 2012 : Info: ++[eap] returns handled
Thu Jul 12 08:50:06 2012 : Info: } # server eduroam
Sending Access-Challenge of id 203 to 10.200.0.2 port 32832
EAP-Message = 0x010b00061920
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x470f24c947043df52dda4e1a3d9334ec
Thu Jul 12 08:50:06 2012 : Info: Finished request 61.
Thu Jul 12 08:50:06 2012 : Debug: Going to the next request
Thu Jul 12 08:50:06 2012 : Debug: Waking up in 4.9 seconds.
Thu Jul 12 08:50:11 2012 : Info: Cleaning up request 61 ID 203 with timestamp +434
Thu Jul 12 08:50:11 2012 : Debug: WARNING: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Thu Jul 12 08:50:11 2012 : Debug: WARNING: !! EAP session for state 0x470f24c947043df5 did not finish!
Thu Jul 12 08:50:11 2012 : Debug: WARNING: !! Please read http://wiki.freeradius.org/Certificate_Compatibility
Thu Jul 12 08:50:11 2012 : Debug: WARNING: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Case2:
rad_recv: Access-Request packet from host 10.200.0.2 port 32832, id=215, length=263
User-Name = "xxx@sabanciuniv.edu.tr"
NAS-IP-Address = 10.200.0.2
NAS-Port = 0
NAS-Identifier = "10.200.0.2"
NAS-Port-Type = Wireless-802.11
Calling-Station-Id = "1C659DA0C84D"
Called-Station-Id = "000B8661DFC4"
Service-Type = Login-User
Framed-MTU = 1100
EAP-Message = 0x0216002b190017030100205cd73791c5a16b72af7729c38c0070ead9b5365d5c59a3cbf94d2d04ab1c88f0
State = 0x933acfe09a2cd6ffa50d9682f870ed3a
Aruba-Essid-Name = "eduroam"
Aruba-Location-Id = "BM_IT_Net_Sys_3c:02"
Aruba-Attr-10 = 0x424d5f62696e617369
Message-Authenticator = 0xee1ce87a79d10bcd3aab616fdf41e564
Thu Jul 12 08:50:20 2012 : Info: server eduroam {
Thu Jul 12 08:50:20 2012 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/eduroam
Thu Jul 12 08:50:20 2012 : Info: +- entering group authorize {...}
Thu Jul 12 08:50:20 2012 : Info: ++[preprocess] returns ok
Thu Jul 12 08:50:20 2012 : Info: [auth_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/10.200.0.2/auth-detail-20120712
Thu Jul 12 08:50:20 2012 : Info: [auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/10.200.0.2/auth-detail-20120712
Thu Jul 12 08:50:20 2012 : Info: [auth_log] expand: %t -> Thu Jul 12 08:50:20 2012
Thu Jul 12 08:50:20 2012 : Info: ++[auth_log] returns ok
Thu Jul 12 08:50:20 2012 : Info: ++[mschap] returns noop
Thu Jul 12 08:50:20 2012 : Info: [suffix] Looking up realm "sabanciuniv.edu.tr" for User-Name = "xxx@sabanciuniv.edu.tr"
Thu Jul 12 08:50:20 2012 : Info: [suffix] Found realm "sabanciuniv.edu.tr"
Thu Jul 12 08:50:20 2012 : Info: [suffix] Adding Stripped-User-Name = "xxx"
Thu Jul 12 08:50:20 2012 : Info: [suffix] Adding Realm = "sabanciuniv.edu.tr"
Thu Jul 12 08:50:20 2012 : Info: [suffix] Authentication realm is LOCAL.
Thu Jul 12 08:50:20 2012 : Info: ++[suffix] returns ok
Thu Jul 12 08:50:20 2012 : Info: [eap] EAP packet type response id 22 length 43
Thu Jul 12 08:50:20 2012 : Info: [eap] Continuing tunnel setup.
Thu Jul 12 08:50:20 2012 : Info: ++[eap] returns ok
Thu Jul 12 08:50:20 2012 : Info: ++[files] returns noop
Thu Jul 12 08:50:20 2012 : Info: ++[expiration] returns noop
Thu Jul 12 08:50:20 2012 : Info: ++[logintime] returns noop
Thu Jul 12 08:50:20 2012 : Info: Found Auth-Type = EAP
Thu Jul 12 08:50:20 2012 : Info: # Executing group from file /etc/raddb/sites-enabled/eduroam
Thu Jul 12 08:50:20 2012 : Info: +- entering group authenticate {...}
Thu Jul 12 08:50:20 2012 : Info: [eap] Request found, released from the list
Thu Jul 12 08:50:20 2012 : Info: [eap] EAP/peap
Thu Jul 12 08:50:20 2012 : Info: [eap] processing type peap
Thu Jul 12 08:50:20 2012 : Info: [peap] processing EAP-TLS
Thu Jul 12 08:50:20 2012 : Info: [peap] eaptls_verify returned 7
Thu Jul 12 08:50:20 2012 : Info: [peap] Done initial handshake
Thu Jul 12 08:50:20 2012 : Info: [peap] eaptls_process returned 7
Thu Jul 12 08:50:20 2012 : Info: [peap] EAPTLS_OK
Thu Jul 12 08:50:20 2012 : Info: [peap] Session established. Decoding tunneled attributes.
Thu Jul 12 08:50:20 2012 : Info: [peap] Peap state send tlv success
Thu Jul 12 08:50:20 2012 : Info: [peap] Received EAP-TLV response.
Thu Jul 12 08:50:20 2012 : Info: [peap] Success
Thu Jul 12 08:50:20 2012 : Info: [peap] Using saved attributes from the original Access-Accept
Cisco-AVPair = "ssid=sunet-staff-wpa2"
User-Name = "xxx"
Thu Jul 12 08:50:20 2012 : Info: [eap] Freeing handler
Thu Jul 12 08:50:20 2012 : Info: ++[eap] returns ok
Thu Jul 12 08:50:20 2012 : Info: # Executing section post-auth from file /etc/raddb/sites-enabled/eduroam
Thu Jul 12 08:50:20 2012 : Info: +- entering group post-auth {...}
Thu Jul 12 08:50:20 2012 : Info: ++[exec] returns noop
Thu Jul 12 08:50:20 2012 : Info: } # server eduroam
Sending Access-Accept of id 215 to 10.200.0.2 port 32832
Cisco-AVPair = "ssid=sunet-staff-wpa2"
User-Name = "xxx"
MS-MPPE-Recv-Key = 0xaea8b6a844f0e161871649d32f4ead36d6441f8b878fe3e4052b2eb5a2ea7346
MS-MPPE-Send-Key = 0xb17c40cb6eed240c390bbe4ffbbe3ee66d5244b2b6390c3e2fe11844b239e89c
EAP-Message = 0x03160004
Message-Authenticator = 0x00000000000000000000000000000000
Thu Jul 12 08:50:20 2012 : Info: Finished request 72.
Thu Jul 12 08:50:20 2012 : Debug: Going to the next request
Thu Jul 12 08:50:20 2012 : Debug: Waking up in 3.2 seconds.
Thu Jul 12 08:50:23 2012 : Info: Cleaning up request 62 ID 205 with timestamp +446
Thu Jul 12 08:50:23 2012 : Info: Cleaning up request 63 ID 206 with timestamp +446
Thu Jul 12 08:50:23 2012 : Info: Cleaning up request 64 ID 207 with timestamp +446
Thu Jul 12 08:50:23 2012 : Info: Cleaning up request 65 ID 208 with timestamp +446
Thu Jul 12 08:50:23 2012 : Info: Cleaning up request 66 ID 209 with timestamp +446
Thu Jul 12 08:50:23 2012 : Info: Cleaning up request 67 ID 210 with timestamp +446
Thu Jul 12 08:50:23 2012 : Debug: Waking up in 1.6 seconds.
Thu Jul 12 08:50:25 2012 : Info: Cleaning up request 68 ID 211 with timestamp +448
Thu Jul 12 08:50:25 2012 : Info: Cleaning up request 69 ID 212 with timestamp +448
Thu Jul 12 08:50:25 2012 : Info: Cleaning up request 70 ID 213 with timestamp +448
Thu Jul 12 08:50:25 2012 : Info: Cleaning up request 71 ID 214 with timestamp +448
Thu Jul 12 08:50:25 2012 : Info: Cleaning up request 72 ID 215 with timestamp +448
Thu Jul 12 08:50:25 2012 : Info: Ready to process requests.
thanks,