<div class="gmail_quote">Hi,</div><div class="gmail_quote"><br></div><div class="gmail_quote">We are using freeradius2-2.1.12-3.el5 on RHEL 5.8 for eduroaming. Sometimes we are getting "EAP session for state ... did not finish!" warning as you can see on case 1. We can successfully login after every three or four tries without error (case 2). </div>
<div class="gmail_quote"><br></div><div class="gmail_quote">How can I overcome this problem?</div><div class="gmail_quote"><br></div><div class="gmail_quote">PS: I think it is more problem on windows 7.<br><br>Case 1:<br>
<div lang="TR" link="blue" vlink="purple"><p class="MsoNormal">rad_recv: Access-Request packet from host 10.200.0.2 port 32832, id=203, length=238</p><p class="MsoNormal"> User-Name = "<a href="mailto:xxx@sabanciuniv.edu.tr">xxx@sabanciuniv.edu.tr</a>"</p>
<p class="MsoNormal"> NAS-IP-Address = 10.200.0.2</p><p class="MsoNormal"> NAS-Port = 0</p><p class="MsoNormal"> NAS-Identifier = "10.200.0.2"</p><p class="MsoNormal">
NAS-Port-Type = Wireless-802.11</p><p class="MsoNormal"> Calling-Station-Id = "1C659DA0C84D"</p><p class="MsoNormal"> Called-Station-Id = "000B8661DFC4"</p>
<p class="MsoNormal"> Service-Type = Login-User</p><p class="MsoNormal"> Framed-MTU = 1100</p><p class="MsoNormal"> EAP-Message = 0x020a002401676f6b68616e67756e796f6c40736162616e6369756e69762e6564752e7472</p>
<p class="MsoNormal"> Aruba-Essid-Name = "eduroam"</p><p class="MsoNormal"> Aruba-Location-Id = "BM_IT_Net_Sys_3c:02"</p><p class="MsoNormal"> Aruba-Attr-10 = 0x424d5f62696e617369</p>
<p class="MsoNormal"> Message-Authenticator = 0x7bde0503caf078e16964c30bb649186a</p><p class="MsoNormal">Thu Jul 12 08:50:06 2012 : Info: server eduroam {</p><p class="MsoNormal">Thu Jul 12 08:50:06 2012 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/eduroam</p>
<p class="MsoNormal">Thu Jul 12 08:50:06 2012 : Info: +- entering group authorize {...}</p><p class="MsoNormal">Thu Jul 12 08:50:06 2012 : Info: ++[preprocess] returns ok</p><p class="MsoNormal">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/<a href="http://10.200.0.2/auth-detail-20120712" target="_blank">10.200.0.2/auth-detail-20120712</a></p>
<p class="MsoNormal">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/<a href="http://10.200.0.2/auth-detail-20120712" target="_blank">10.200.0.2/auth-detail-20120712</a></p>
<p class="MsoNormal">Thu Jul 12 08:50:06 2012 : Info: [auth_log] expand: %t -> Thu Jul 12 08:50:06 2012</p><p class="MsoNormal">Thu Jul 12 08:50:06 2012 : Info: ++[auth_log] returns ok</p><p class="MsoNormal">
Thu Jul 12 08:50:06 2012 : Info: ++[mschap] returns noop</p><p class="MsoNormal">Thu Jul 12 08:50:06 2012 : Info: [suffix] Looking up realm "<a href="http://sabanciuniv.edu.tr">sabanciuniv.edu.tr</a>" for User-Name = "<a href="mailto:xxx@sabanciuniv.edu.tr">xxx@sabanciuniv.edu.tr</a>"</p>
<p class="MsoNormal">Thu Jul 12 08:50:06 2012 : Info: [suffix] Found realm "<a href="http://sabanciuniv.edu.tr">sabanciuniv.edu.tr</a>"</p><p class="MsoNormal">Thu Jul 12 08:50:06 2012 : Info: [suffix] Adding Stripped-User-Name = "xxx"</p>
<p class="MsoNormal">Thu Jul 12 08:50:06 2012 : Info: [suffix] Adding Realm = "<a href="http://sabanciuniv.edu.tr">sabanciuniv.edu.tr</a>"</p><p class="MsoNormal">Thu Jul 12 08:50:06 2012 : Info: [suffix] Authentication realm is LOCAL.</p>
<p class="MsoNormal">Thu Jul 12 08:50:06 2012 : Info: ++[suffix] returns ok</p><p class="MsoNormal">Thu Jul 12 08:50:06 2012 : Info: [eap] EAP packet type response id 10 length 36</p><p class="MsoNormal">Thu Jul 12 08:50:06 2012 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation</p>
<p class="MsoNormal">Thu Jul 12 08:50:06 2012 : Info: ++[eap] returns updated</p><p class="MsoNormal">Thu Jul 12 08:50:06 2012 : Info: ++[files] returns noop</p><p class="MsoNormal">Thu Jul 12 08:50:06 2012 : Info: ++[expiration] returns noop</p>
<p class="MsoNormal">Thu Jul 12 08:50:06 2012 : Info: ++[logintime] returns noop</p><p class="MsoNormal">Thu Jul 12 08:50:06 2012 : Info: Found Auth-Type = EAP</p><p class="MsoNormal">Thu Jul 12 08:50:06 2012 : Info: # Executing group from file /etc/raddb/sites-enabled/eduroam</p>
<p class="MsoNormal">Thu Jul 12 08:50:06 2012 : Info: +- entering group authenticate {...}</p><p class="MsoNormal">Thu Jul 12 08:50:06 2012 : Info: [eap] EAP Identity</p><p class="MsoNormal">Thu Jul 12 08:50:06 2012 : Info: [eap] processing type tls</p>
<p class="MsoNormal">Thu Jul 12 08:50:06 2012 : Info: [tls] Initiate</p><p class="MsoNormal">Thu Jul 12 08:50:06 2012 : Info: [tls] Start returned 1</p><p class="MsoNormal">Thu Jul 12 08:50:06 2012 : Info: ++[eap] returns handled</p>
<p class="MsoNormal">Thu Jul 12 08:50:06 2012 : Info: } # server eduroam</p><p class="MsoNormal">Sending Access-Challenge of id 203 to 10.200.0.2 port 32832</p><p class="MsoNormal"> EAP-Message = 0x010b00061920</p>
<p class="MsoNormal"> Message-Authenticator = 0x00000000000000000000000000000000</p><p class="MsoNormal"> State = 0x470f24c947043df52dda4e1a3d9334ec</p><p class="MsoNormal">Thu Jul 12 08:50:06 2012 : Info: Finished request 61.</p>
<p class="MsoNormal">Thu Jul 12 08:50:06 2012 : Debug: Going to the next request</p><p class="MsoNormal">Thu Jul 12 08:50:06 2012 : Debug: Waking up in 4.9 seconds.</p><p class="MsoNormal">Thu Jul 12 08:50:11 2012 : Info: Cleaning up request 61 ID 203 with timestamp +434</p>
<p class="MsoNormal">Thu Jul 12 08:50:11 2012 : Debug: WARNING: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!</p><p class="MsoNormal">Thu Jul 12 08:50:11 2012 : Debug: WARNING: !! EAP session for state 0x470f24c947043df5 did not finish!</p>
<p class="MsoNormal">Thu Jul 12 08:50:11 2012 : Debug: WARNING: !! Please read <a href="http://wiki.freeradius.org/Certificate_Compatibility" target="_blank">http://wiki.freeradius.org/Certificate_Compatibility</a></p><p class="MsoNormal">
Thu Jul 12 08:50:11 2012 : Debug: WARNING: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!</p><p class="MsoNormal"> </p><p class="MsoNormal"> </p><p class="MsoNormal"> </p><p class="MsoNormal"> </p>
<p class="MsoNormal"> </p><p class="MsoNormal"> </p><p class="MsoNormal"> </p><p class="MsoNormal">Case2:</p><p class="MsoNormal">rad_recv: Access-Request packet from host 10.200.0.2 port 32832, id=215, length=263</p>
<p class="MsoNormal"> User-Name = "<a href="mailto:xxx@sabanciuniv.edu.tr">xxx@sabanciuniv.edu.tr</a>"</p><p class="MsoNormal"> NAS-IP-Address = 10.200.0.2</p><p class="MsoNormal">
NAS-Port = 0</p><p class="MsoNormal"> NAS-Identifier = "10.200.0.2"</p><p class="MsoNormal"> NAS-Port-Type = Wireless-802.11</p><p class="MsoNormal"> Calling-Station-Id = "1C659DA0C84D"</p>
<p class="MsoNormal"> Called-Station-Id = "000B8661DFC4"</p><p class="MsoNormal"> Service-Type = Login-User</p><p class="MsoNormal"> Framed-MTU = 1100</p><p class="MsoNormal">
EAP-Message = 0x0216002b190017030100205cd73791c5a16b72af7729c38c0070ead9b5365d5c59a3cbf94d2d04ab1c88f0</p><p class="MsoNormal"> State = 0x933acfe09a2cd6ffa50d9682f870ed3a</p><p class="MsoNormal">
Aruba-Essid-Name = "eduroam"</p><p class="MsoNormal"> Aruba-Location-Id = "BM_IT_Net_Sys_3c:02"</p><p class="MsoNormal"> Aruba-Attr-10 = 0x424d5f62696e617369</p>
<p class="MsoNormal"> Message-Authenticator = 0xee1ce87a79d10bcd3aab616fdf41e564</p><p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: server eduroam {</p><p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/eduroam</p>
<p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: +- entering group authorize {...}</p><p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: ++[preprocess] returns ok</p><p class="MsoNormal">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/<a href="http://10.200.0.2/auth-detail-20120712" target="_blank">10.200.0.2/auth-detail-20120712</a></p>
<p class="MsoNormal">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/<a href="http://10.200.0.2/auth-detail-20120712" target="_blank">10.200.0.2/auth-detail-20120712</a></p>
<p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: [auth_log] expand: %t -> Thu Jul 12 08:50:20 2012</p><p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: ++[auth_log] returns ok</p><p class="MsoNormal">
Thu Jul 12 08:50:20 2012 : Info: ++[mschap] returns noop</p><p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: [suffix] Looking up realm "<a href="http://sabanciuniv.edu.tr">sabanciuniv.edu.tr</a>" for User-Name = "<a href="mailto:xxx@sabanciuniv.edu.tr">xxx@sabanciuniv.edu.tr</a>"</p>
<p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: [suffix] Found realm "<a href="http://sabanciuniv.edu.tr">sabanciuniv.edu.tr</a>"</p><p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: [suffix] Adding Stripped-User-Name = "xxx"</p>
<p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: [suffix] Adding Realm = "<a href="http://sabanciuniv.edu.tr">sabanciuniv.edu.tr</a>"</p><p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: [suffix] Authentication realm is LOCAL.</p>
<p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: ++[suffix] returns ok</p><p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: [eap] EAP packet type response id 22 length 43</p><p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: [eap] Continuing tunnel setup.</p>
<p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: ++[eap] returns ok</p><p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: ++[files] returns noop</p><p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: ++[expiration] returns noop</p>
<p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: ++[logintime] returns noop</p><p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: Found Auth-Type = EAP</p><p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: # Executing group from file /etc/raddb/sites-enabled/eduroam</p>
<p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: +- entering group authenticate {...}</p><p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: [eap] Request found, released from the list</p><p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: [eap] EAP/peap</p>
<p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: [eap] processing type peap</p><p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: [peap] processing EAP-TLS</p><p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: [peap] eaptls_verify returned 7 </p>
<p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: [peap] Done initial handshake</p><p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: [peap] eaptls_process returned 7 </p><p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: [peap] EAPTLS_OK</p>
<p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: [peap] Session established. Decoding tunneled attributes.</p><p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: [peap] Peap state send tlv success</p><p class="MsoNormal">
Thu Jul 12 08:50:20 2012 : Info: [peap] Received EAP-TLV response.</p><p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: [peap] Success</p><p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: [peap] Using saved attributes from the original Access-Accept</p>
<p class="MsoNormal"> Cisco-AVPair = "ssid=sunet-staff-wpa2"</p><p class="MsoNormal"> User-Name = "xxx"</p><p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: [eap] Freeing handler</p>
<p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: ++[eap] returns ok</p><p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: # Executing section post-auth from file /etc/raddb/sites-enabled/eduroam</p><p class="MsoNormal">
Thu Jul 12 08:50:20 2012 : Info: +- entering group post-auth {...}</p><p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: ++[exec] returns noop</p><p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: } # server eduroam</p>
<p class="MsoNormal">Sending Access-Accept of id 215 to 10.200.0.2 port 32832</p><p class="MsoNormal"> Cisco-AVPair = "ssid=sunet-staff-wpa2"</p><p class="MsoNormal"> User-Name = "xxx"</p>
<p class="MsoNormal"> MS-MPPE-Recv-Key = 0xaea8b6a844f0e161871649d32f4ead36d6441f8b878fe3e4052b2eb5a2ea7346</p><p class="MsoNormal"> MS-MPPE-Send-Key = 0xb17c40cb6eed240c390bbe4ffbbe3ee66d5244b2b6390c3e2fe11844b239e89c</p>
<p class="MsoNormal"> EAP-Message = 0x03160004</p><p class="MsoNormal"> Message-Authenticator = 0x00000000000000000000000000000000</p><p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Info: Finished request 72.</p>
<p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Debug: Going to the next request</p><p class="MsoNormal">Thu Jul 12 08:50:20 2012 : Debug: Waking up in 3.2 seconds.</p><p class="MsoNormal">Thu Jul 12 08:50:23 2012 : Info: Cleaning up request 62 ID 205 with timestamp +446</p>
<p class="MsoNormal">Thu Jul 12 08:50:23 2012 : Info: Cleaning up request 63 ID 206 with timestamp +446</p><p class="MsoNormal">Thu Jul 12 08:50:23 2012 : Info: Cleaning up request 64 ID 207 with timestamp +446</p><p class="MsoNormal">
Thu Jul 12 08:50:23 2012 : Info: Cleaning up request 65 ID 208 with timestamp +446</p><p class="MsoNormal">Thu Jul 12 08:50:23 2012 : Info: Cleaning up request 66 ID 209 with timestamp +446</p><p class="MsoNormal">Thu Jul 12 08:50:23 2012 : Info: Cleaning up request 67 ID 210 with timestamp +446</p>
<p class="MsoNormal">Thu Jul 12 08:50:23 2012 : Debug: Waking up in 1.6 seconds.</p><p class="MsoNormal">Thu Jul 12 08:50:25 2012 : Info: Cleaning up request 68 ID 211 with timestamp +448</p><p class="MsoNormal">Thu Jul 12 08:50:25 2012 : Info: Cleaning up request 69 ID 212 with timestamp +448</p>
<p class="MsoNormal">Thu Jul 12 08:50:25 2012 : Info: Cleaning up request 70 ID 213 with timestamp +448</p><p class="MsoNormal">Thu Jul 12 08:50:25 2012 : Info: Cleaning up request 71 ID 214 with timestamp +448</p><p class="MsoNormal">
Thu Jul 12 08:50:25 2012 : Info: Cleaning up request 72 ID 215 with timestamp +448</p><p class="MsoNormal">Thu Jul 12 08:50:25 2012 : Info: Ready to process requests.</p><p class="MsoNormal"> </p><p class="MsoNormal"> </p>
<p class="MsoNormal"> </p><p class="MsoNormal">thanks,</p><p class="MsoNormal"> </p></div></div>