Jeff_Nanney
asked on
802.1X roaming disconnects issue
We've started testing a new 802.1X-enabled SSID and users are reporting that their Apple devices are disconnecting when they roam between AP. We have hundreds of MBP, Air, and iPhones, 50 Cisco 1142 AP and two Cisco 5508 WLC in HA mode.
I created a new 802.1X-enabled SSID which authenticates back to FreeRadius and OpenLDAP servers. It works except when users roam between AP their connection drops for about 10 seconds. Voice and video calls will drop and I lose about a dozen pings before it re-authenticates. Under Prefs -> Network on my laptop, I can see 802.1X go into an authenticating state. I've replicated the problem on laptops running both 10.9.1 and 10.8. It also happens on iOS devices but the disconnect is only 5 seconds instead of 10.
To try and resolve the issue, I reviewed Cisco's best practices for Apple devices and then I tried the following fixes. I re-tested between enabling each feature.
1. 802.11r & 802.11k
2. Fast transition, fast transition over-the-DS, and FT 802.1X
3. CCKM
4. SKC
5. Increased the EAP timeout values
6. Disabled client load balancing
It appears that OS X is not sending cached credentials (PMKID) and the Cisco 5508 WLC is forcing the Apple laptops to go thru the full 802.1X authentication process each time they roam.
Is there a way to require OS X to use 802.11r and 802.11k?
I'd be grateful for any assistance or advice that you can offer.
show-tech-support---Cisco-WLC.rtf
show-traplog---Cisco-WLC.rtf
debug-client-loaner-c8-bc-c8-ee-.rtf
show-run-config---Cisco-WLC.rtf
show-msglog---Cisco-WLC.rtf
I created a new 802.1X-enabled SSID which authenticates back to FreeRadius and OpenLDAP servers. It works except when users roam between AP their connection drops for about 10 seconds. Voice and video calls will drop and I lose about a dozen pings before it re-authenticates. Under Prefs -> Network on my laptop, I can see 802.1X go into an authenticating state. I've replicated the problem on laptops running both 10.9.1 and 10.8. It also happens on iOS devices but the disconnect is only 5 seconds instead of 10.
To try and resolve the issue, I reviewed Cisco's best practices for Apple devices and then I tried the following fixes. I re-tested between enabling each feature.
1. 802.11r & 802.11k
2. Fast transition, fast transition over-the-DS, and FT 802.1X
3. CCKM
4. SKC
5. Increased the EAP timeout values
6. Disabled client load balancing
It appears that OS X is not sending cached credentials (PMKID) and the Cisco 5508 WLC is forcing the Apple laptops to go thru the full 802.1X authentication process each time they roam.
Is there a way to require OS X to use 802.11r and 802.11k?
I'd be grateful for any assistance or advice that you can offer.
show-tech-support---Cisco-WLC.rtf
show-traplog---Cisco-WLC.rtf
debug-client-loaner-c8-bc-c8-ee-.rtf
show-run-config---Cisco-WLC.rtf
show-msglog---Cisco-WLC.rtf
The access points need to support WMM. This feature allows to roam credentials between access points. It surely works on spa or wpa2 authentication. For RADIUS authentication you'll need a perfect RADIUS setup which most of the systems don't provide.
However, if your RADIUS works ok, you have roaming credentials between Access points. Thisfeature had been developed for voice over IP.
All current Apple cpu's and all iOS devices since iphone 4S support this feature. Now you need to check your access points... ;o)
However, if your RADIUS works ok, you have roaming credentials between Access points. Thisfeature had been developed for voice over IP.
All current Apple cpu's and all iOS devices since iphone 4S support this feature. Now you need to check your access points... ;o)
This should just 'work' using 802.1x on a Cisco WLC.
I had a quick look through the files you attached. Are you using the 'DHCP Addr. Assignment required' feature? If so, this will dramatically affect roaming and is probably causing your issue.
For info, this feature is the switch version of DHCP snooping in the WLC. If this is enabled your clients will have to do a full DHCP renew each time they move between APs or they'll remain in the DHCP_REQD state and never transition into the RUN state.
I had a quick look through the files you attached. Are you using the 'DHCP Addr. Assignment required' feature? If so, this will dramatically affect roaming and is probably causing your issue.
For info, this feature is the switch version of DHCP snooping in the WLC. If this is enabled your clients will have to do a full DHCP renew each time they move between APs or they'll remain in the DHCP_REQD state and never transition into the RUN state.
ASKER
Thanks for your advice. We're still experiencing the problem. I've answered your questions below:
Yes. The SSID has only WPA2 and AES enabled.
I've verified our Cisco 5508 WLC supports WMM. I've also tested with WMM enabled and disabled.
DHCP Addr. Assignment is unchecked, meaning that it's not required.
I've also tried:
1. Upgraded to the latest software (AIR-CT5500-K9-7-6-110-0.a
2. Enabled Fast Transition, FT over-the-DS, FT 802.1X, Cisco Centralized Key Management (CCKM), Sticky Key Caching (SKC)
3. Increased EAP timeout values
4. Disabled client load balancing
5. Disabled OCSP and CRL checking in Keychain Access preferences.
6. Installed Apple combo fix update for both OS X 10.9.2 and 10.8.5.
7. Tested with both OS. Problem recurred on both.
Have you tried setting it up with just WPA2 + AES enabled?
Yes. The SSID has only WPA2 and AES enabled.
The access points need to support WMM.
I've verified our Cisco 5508 WLC supports WMM. I've also tested with WMM enabled and disabled.
Are you using the 'DHCP Addr. Assignment required' feature?
DHCP Addr. Assignment is unchecked, meaning that it's not required.
I've also tried:
1. Upgraded to the latest software (AIR-CT5500-K9-7-6-110-0.a
2. Enabled Fast Transition, FT over-the-DS, FT 802.1X, Cisco Centralized Key Management (CCKM), Sticky Key Caching (SKC)
3. Increased EAP timeout values
4. Disabled client load balancing
5. Disabled OCSP and CRL checking in Keychain Access preferences.
6. Installed Apple combo fix update for both OS X 10.9.2 and 10.8.5.
7. Tested with both OS. Problem recurred on both.
Really, you don't need to do anything to enable roaming between APs on the same SSID in a Cisco WLC deployment. WMM, CCKM and everything else are not a 'requirement' to make this work.
I notice this...
That means there's a lot of co-channel interference. You have lots of APs all close together, all with relatively strong signal strengths between them. To be seeing 12 APs all with values above -60dBm is bad. You only have 3 non-overlapping channels. This will definitely be a contributing factor in roaming issues and apart from creating lots of noise, this may also give the client a headache when trying to decide which is the best AP to roam to, thus increasing the time taken to actually 'jump' to another AP.
It looks to me like your deployment was probably geared towards the 5GHz band. All of the 5GHz radios are looking great from the output you posted. Maybe you need to just turn the 2.4GHz radio off in a few of your APs to reduce the effects of co-channel interference. I know it might sound counter-intuitive, but it's definitely something I'd suggest.
I notice this...
Nearby APsCisco recommend a cell-overlap of around 20% at -75dBm for a data-ready deployment to be successful, and -67dBm for a voice-ready network. That means though you should only have 3 APs visible as neighbours within these parameters - not 12!
AP 08:cc:68:0a:94:10 slot 0.................. -52 dBm on 1 (10.1.2.2)
AP 0c:68:03:38:61:b0 slot 0.................. -56 dBm on 11 (10.1.2.2)
AP 0c:68:03:af:7e:70 slot 0.................. -36 dBm on 1 (10.1.2.2)
AP 20:bb:c0:e5:d7:70 slot 0.................. -45 dBm on 11 (10.1.2.2)
AP 70:10:5c:db:f3:00 slot 0.................. -57 dBm on 11 (10.1.2.2)
AP 70:10:5c:db:f4:00 slot 0.................. -58 dBm on 6 (10.1.2.2)
AP 70:10:5c:db:f8:90 slot 0.................. -45 dBm on 11 (10.1.2.2)
AP 70:10:5c:e6:93:10 slot 0.................. -58 dBm on 6 (10.1.2.2)
AP b4:e9:b0:33:49:30 slot 0.................. -45 dBm on 1 (10.1.2.2)
AP b4:e9:b0:33:d7:e0 slot 0.................. -56 dBm on 1 (10.1.2.2)
AP d0:c7:89:c6:6d:f0 slot 0.................. -60 dBm on 1 (10.1.2.2)
AP f0:29:29:4c:5d:30 slot 0.................. -47 dBm on 6 (10.1.2.2)
That means there's a lot of co-channel interference. You have lots of APs all close together, all with relatively strong signal strengths between them. To be seeing 12 APs all with values above -60dBm is bad. You only have 3 non-overlapping channels. This will definitely be a contributing factor in roaming issues and apart from creating lots of noise, this may also give the client a headache when trying to decide which is the best AP to roam to, thus increasing the time taken to actually 'jump' to another AP.
It looks to me like your deployment was probably geared towards the 5GHz band. All of the 5GHz radios are looking great from the output you posted. Maybe you need to just turn the 2.4GHz radio off in a few of your APs to reduce the effects of co-channel interference. I know it might sound counter-intuitive, but it's definitely something I'd suggest.
Can't the WLC reduce power on the 2.4GHz radios individually to adjust the overlap, too?
You're right, Darr, it can. However, I'd guess it's already done that.
RRM will reduce the power as soon as it sees the 4th AP (well if not instantly, within around 10 mins max.) so if we assume that this has been like this for longer than that I'd say it's already taken all (or most of) the APs down to power-level 1.
RRM will reduce the power as soon as it sees the 4th AP (well if not instantly, within around 10 mins max.) so if we assume that this has been like this for longer than that I'd say it's already taken all (or most of) the APs down to power-level 1.
ASKER
With the help of Cisco TAC, I tried all of the following without success. I tested after each step to confirm the wireless roaming disconnect issue was still occurring.
1. Disabled all but two adjacent AP then re-enabled two more
2. Tested each band 2.4 & 5GHz individually by disabling one at a time
3. Adjusted 802.11a/n channel width from 40 to 20MHz
4. Switched to Coverage Optimal Mode (TPCv1)
5. Adjusted power threshold from -67 to -80 to decrease transmit power for all AP
6. Enabled Persistent Non-WiFi Interference for 802.11b/g.
7. Enabled client band select on the 802.1x-based SSID.
8. Enabled RSSI Low Check.
9. Removed our secondary RADIUS server
10. Changed NAC State from “RADIUS Nac” to None.
11. Disabled “Allow AAA Override.”
12. Disabled Client Exclusion.
I also walked around the office with my MacBook Pro running Windows 8.1 in boot camp. It dropped a couple of ping packets twice but the rest of the time it roamed flawlessly.
Apple enterprise support said there's a known bug in OS X security that causes a 10 second delay when processing certificates using EAP-TLS authentication. We're using EAP-TTLS and PAP. "It is likely that you are seeing an issue that product engineering is currently investigating. To see if this is the issue you are seeing, can you try enabling an EAP type that doesn’t require validation of the RADIUS server certificate, such as LEAP or EAP-FAST?" We're planning to test LEAP shortly.
1. Disabled all but two adjacent AP then re-enabled two more
2. Tested each band 2.4 & 5GHz individually by disabling one at a time
3. Adjusted 802.11a/n channel width from 40 to 20MHz
4. Switched to Coverage Optimal Mode (TPCv1)
5. Adjusted power threshold from -67 to -80 to decrease transmit power for all AP
6. Enabled Persistent Non-WiFi Interference for 802.11b/g.
7. Enabled client band select on the 802.1x-based SSID.
8. Enabled RSSI Low Check.
9. Removed our secondary RADIUS server
10. Changed NAC State from “RADIUS Nac” to None.
11. Disabled “Allow AAA Override.”
12. Disabled Client Exclusion.
I also walked around the office with my MacBook Pro running Windows 8.1 in boot camp. It dropped a couple of ping packets twice but the rest of the time it roamed flawlessly.
Apple enterprise support said there's a known bug in OS X security that causes a 10 second delay when processing certificates using EAP-TLS authentication. We're using EAP-TTLS and PAP. "It is likely that you are seeing an issue that product engineering is currently investigating. To see if this is the issue you are seeing, can you try enabling an EAP type that doesn’t require validation of the RADIUS server certificate, such as LEAP or EAP-FAST?" We're planning to test LEAP shortly.
I'd go with EAP-FAST instead of LEAP. You could just use PEAP-MSChapV2 though.
ASKER
Last night, we tried PEAP and MS-CHAPv2 as well as PEAP with MD5 but neither would authenticate users. We were able to authenticate to just fine using eapol_test but not thru the test SSID. Through debugs, we can
1. Test 1 - PEAP and MS-CHAPv2. Test_clear user has a password stored in clear text. It seemed to fail with the following error in the FreeRADIUS debug log:
[mschapv2] # Executing group from file /etc/freeradius/sites-enab
[mschapv2] +- entering group MS-CHAP {...}
[mschap] No Cleartext-Password configured. Cannot create LM-Password.
[mschap] No Cleartext-Password configured. Cannot create NT-Password.
[mschap] Creating challenge hash with username: test_clear
[mschap] Told to do MS-CHAPv2 for test_clear with NT-Password
[mschap] FAILED: No NT/LM-Password. Cannot perform authentication.
[mschap] FAILED: MS-CHAP2-Response is incorrect
Full FreeRADIUS debug below
2. Test 2 - PEAP and MD5. Test user with password stored using salted SHA. The relevant error from the FreeRADIUS debugs seems to be:
[EAP_WIFI] EAP/md5
[EAP_WIFI] processing type md5
rlm_eap_md5: Cleartext-Password is required for EAP-MD5 authentication
[EAP_WIFI] Handler failed in EAP/md5
[EAP_WIFI] Failed in EAP select
Full FreeRADIUS debug log below:
1. Test 1 - PEAP and MS-CHAPv2. Test_clear user has a password stored in clear text. It seemed to fail with the following error in the FreeRADIUS debug log:
[mschapv2] # Executing group from file /etc/freeradius/sites-enab
[mschapv2] +- entering group MS-CHAP {...}
[mschap] No Cleartext-Password configured. Cannot create LM-Password.
[mschap] No Cleartext-Password configured. Cannot create NT-Password.
[mschap] Creating challenge hash with username: test_clear
[mschap] Told to do MS-CHAPv2 for test_clear with NT-Password
[mschap] FAILED: No NT/LM-Password. Cannot perform authentication.
[mschap] FAILED: MS-CHAP2-Response is incorrect
Full FreeRADIUS debug below
Going to the next request
Waking up in 4.9 seconds.
Cleaning up request 0 ID 96 with timestamp +29
Cleaning up request 1 ID 97 with timestamp +29
Cleaning up request 2 ID 98 with timestamp +29
Cleaning up request 3 ID 99 with timestamp +29
Cleaning up request 4 ID 100 with timestamp +29
WARNING: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
WARNING: !! EAP session for state 0x4e8fbd6a4a89a4ec did not finish!
WARNING: !! Please read http://wiki.freeradius.org/Certificate_Compatibility
WARNING: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Ready to process requests.
rad_recv: Access-Request packet from host 10.1.2.2 port 32770, id=101, length=246
User-Name = "test_clear"
Chargeable-User-Identity = ""
X-Ascend-Dialout-Allowed = Dialout-Allowed
Calling-Station-Id = "78:31:c1:c0:55:f4"
Called-Station-Id = "f0:29:29:4c:6b:d0:Test2"
NAS-Port = 13
Cisco-AVPair = "audit-session-id=0a0102020000da9c533e4daf"
NAS-IP-Address = 10.1.2.2
NAS-Identifier = "SFO_HQ_WCON_5508"
Airespace-Wlan-Id = 7
Service-Type = Framed-User
Framed-MTU = 1300
NAS-Port-Type = Wireless-802.11
Tunnel-Type:0 = VLAN
Tunnel-Medium-Type:0 = IEEE-802
Tunnel-Private-Group-Id:0 = "144"
EAP-Message = 0x0201000f01746573745f636c656172
Message-Authenticator = 0x84f5a2ff25a555952eee08cc026eeaf9
server Test_Wifi_Outer {
# Executing section authorize from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] expand: %t -> Thu Apr 3 23:13:50 2014
++[auth_log] returns ok
[EAP_WIFI] EAP packet type response id 1 length 15
[EAP_WIFI] No EAP Start, assuming it's an on-going EAP conversation
++[EAP_WIFI] returns updated
++[expiration] returns noop
++[logintime] returns noop
Found Auth-Type = EAP_WIFI
# Executing group from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authenticate {...}
[EAP_WIFI] EAP Identity
[EAP_WIFI] processing type tls
[tls] Initiate
[tls] Start returned 1
++[EAP_WIFI] returns handled
} # server Test_Wifi_Outer
Sending Access-Challenge of id 101 to 10.1.2.2 port 32770
EAP-Message = 0x010200061920
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x163f61d8163d786d9edf10fb24c294e9
Finished request 5.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.1.2.2 port 32770, id=102, length=401
User-Name = "test_clear"
Chargeable-User-Identity = ""
X-Ascend-Dialout-Allowed = Dialout-Allowed
Calling-Station-Id = "78:31:c1:c0:55:f4"
Called-Station-Id = "f0:29:29:4c:6b:d0:Test2"
NAS-Port = 13
Cisco-AVPair = "audit-session-id=0a0102020000da9c533e4daf"
NAS-IP-Address = 10.1.2.2
NAS-Identifier = "SFO_HQ_WCON_5508"
Airespace-Wlan-Id = 7
Service-Type = Framed-User
Framed-MTU = 1300
NAS-Port-Type = Wireless-802.11
Tunnel-Type:0 = VLAN
Tunnel-Medium-Type:0 = IEEE-802
Tunnel-Private-Group-Id:0 = "144"
EAP-Message = 0x0202009819800000008e1603010089010000850301533e4d9e245d863b7467e0f0e8c002f2c130022cf161604204806d7c95d3241500004a00ffc024c023c00ac009c007c008c028c027c014c013c011c012c026c025c02ac029c005c004c002c003c00fc00ec00cc00d003d003c002f000500040035000a0067006b00330039001601000012000a00080006001700180019000b00020100
State = 0x163f61d8163d786d9edf10fb24c294e9
Message-Authenticator = 0x02dada7dc5ca8d89f27af75cdda5ef23
server Test_Wifi_Outer {
# Executing section authorize from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] expand: %t -> Thu Apr 3 23:13:50 2014
++[auth_log] returns ok
[EAP_WIFI] EAP packet type response id 2 length 152
[EAP_WIFI] Continuing tunnel setup.
++[EAP_WIFI] returns ok
Found Auth-Type = EAP_WIFI
# Executing group from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authenticate {...}
[EAP_WIFI] Request found, released from the list
[EAP_WIFI] EAP/peap
[EAP_WIFI] processing type peap
[peap] processing EAP-TLS
TLS Length 142
[peap] Length Included
[peap] eaptls_verify returned 11
[peap] (other): before/accept initialization
[peap] TLS_accept: before/accept initialization
[peap] <<< TLS 1.0 Handshake [length 0089], ClientHello
[peap] TLS_accept: SSLv3 read client hello A
[peap] >>> TLS 1.0 Handshake [length 0031], ServerHello
[peap] TLS_accept: SSLv3 write server hello A
[peap] >>> TLS 1.0 Handshake [length 0e2e], Certificate
[peap] TLS_accept: SSLv3 write certificate A
[peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone
[peap] TLS_accept: SSLv3 write server done A
[peap] TLS_accept: SSLv3 flush data
[peap] TLS_accept: Need to read more data: SSLv3 read client certificate A
In SSL Handshake Phase
In SSL Accept mode
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[EAP_WIFI] returns handled
} # server Test_Wifi_Outer
Sending Access-Challenge of id 102 to 10.1.2.2 port 32770
EAP-Message = 0x0103040019c000000e7216030100310200002d0301533e4d9ea06dfbd0c28cdd0c4ff63aef1fc9f9facec41e68fc8c0ae1a24da98a00002f000005ff010001001603010e2e0b000e2a000e270004fe308204fa308203e2a003020102021100f69e47b6852c6714a75b4f84f5ecee35300d06092a864886f70d01010505003070310b3009060355040613024742311b30190603550408131247726561746572204d616e636865737465723110300e0603550407130753616c666f7264311a3018060355040a1311434f4d4f444f204341204c696d69746564311630140603550403130d434f4d4f444f2053534c204341301e170d313331323137303030
EAP-Message = 0x3030305a170d3134313231373233353935395a30533121301f060355040b1318446f6d61696e20436f6e74726f6c2056616c69646174656431133011060355040b130a434f4d4f444f2053534c31193017060355040313107261646975732e61697267632e6e657430820122300d06092a864886f70d01010105000382010f003082010a0282010100cc3b800180c335d8132e628428041f463c47f47771b701d3db53965a2c26638c3db956dbd240fbc7f9ddcd5ee91464d596b5c7185ddddd4e6b8b5e2a738f36e690b2d5a7401b27316efa31df34f3784b2cfe271804132c090f53c1f72bfa6c5a602c37e9922a635ed84453dfa9ae9b62865948b1
EAP-Message = 0x1934875f9b7c88abc611a727e62654dd9fe55d63bfd61aeb9c361799c2eee0f38e01dfc9758a25c1347d79e384d7ed3a7bd71fa408417466b97d9d4c54bcca1e56ee6b84fd5b1fb6aeb40f4fce973d41519ed7f5fee2ab47f2174ae3b0fc34a6e3a5f77655ae967423e4c28fdb2336255babd87a7e2b76102e1790354c77607a1a92a0eb84cea6d513a2946b0203010001a38201aa308201a6301f0603551d230418301680141b6bbd1f8a491894543755b42017ed37b977187d301d0603551d0e04160414c4bce01b4b9c94f877b71a4c6b55e95308e58359300e0603551d0f0101ff0404030205a0300c0603551d130101ff04023000301d0603551d
EAP-Message = 0x250416301406082b0601050507030106082b06010505070302304f0603551d2004483046303a060b2b06010401b23101020207302b302906082b06010505070201161d68747470733a2f2f7365637572652e636f6d6f646f2e636f6d2f4350533008060667810c01020130380603551d1f0431302f302da02ba0298627687474703a2f2f63726c2e636f6d6f646f63612e636f6d2f434f4d4f444f53534c43412e63726c306906082b06010505070101045d305b303306082b060105050730028627687474703a2f2f6372742e636f6d6f646f63612e636f6d2f434f4d4f444f53534c43412e637274302406082b060105050730018618687474703a2f
EAP-Message = 0x2f6f6373702e636f6d6f646f
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x163f61d8173c786d9edf10fb24c294e9
Finished request 6.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.1.2.2 port 32770, id=103, length=255
User-Name = "test_clear"
Chargeable-User-Identity = ""
X-Ascend-Dialout-Allowed = Dialout-Allowed
Calling-Station-Id = "78:31:c1:c0:55:f4"
Called-Station-Id = "f0:29:29:4c:6b:d0:Test2"
NAS-Port = 13
Cisco-AVPair = "audit-session-id=0a0102020000da9c533e4daf"
NAS-IP-Address = 10.1.2.2
NAS-Identifier = "SFO_HQ_WCON_5508"
Airespace-Wlan-Id = 7
Service-Type = Framed-User
Framed-MTU = 1300
NAS-Port-Type = Wireless-802.11
Tunnel-Type:0 = VLAN
Tunnel-Medium-Type:0 = IEEE-802
Tunnel-Private-Group-Id:0 = "144"
EAP-Message = 0x020300061900
State = 0x163f61d8173c786d9edf10fb24c294e9
Message-Authenticator = 0x1fa94bc010b62f773c22fbb69575f955
server Test_Wifi_Outer {
# Executing section authorize from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] expand: %t -> Thu Apr 3 23:13:50 2014
++[auth_log] returns ok
[EAP_WIFI] EAP packet type response id 3 length 6
[EAP_WIFI] Continuing tunnel setup.
++[EAP_WIFI] returns ok
Found Auth-Type = EAP_WIFI
# Executing group from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authenticate {...}
[EAP_WIFI] Request found, released from the list
[EAP_WIFI] EAP/peap
[EAP_WIFI] processing type peap
[peap] processing EAP-TLS
[peap] Received TLS ACK
[peap] ACK handshake fragment handler
[peap] eaptls_verify returned 1
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[EAP_WIFI] returns handled
} # server Test_Wifi_Outer
Sending Access-Challenge of id 103 to 10.1.2.2 port 32770
EAP-Message = 0x010403fc194063612e636f6d30310603551d11042a302882107261646975732e61697267632e6e657482147777772e7261646975732e61697267632e6e6574300d06092a864886f70d0101050500038201010097cc409026a38cb327dd6e1d3c32d27ec6d180e3b30c13252dc2e5631da1a51fdc0666b05a3df1414a9356357434338b5dab034fe305cea0868c7719a38a682db8728540f11f4583e45eeb154715d7e24edc14399ac1f80d0ee06178d1df2e7c0b06308564cc15c72b7b516ecca2b54ddf49a1b7cb6333db8d9c79739cc2348b1984262c967a5e1785d32f6b26b9913d6e574953f5a85e2be8f568635c96c6538894f3936ac9550b4f45
EAP-Message = 0x2b6415f13df580e5bd901ac2cc83d3f8d203b11c0061e9d7fd8fe1d3c9b84e3f4392518e2eea92263bc8f74b6a002167bb48831eff8630518a1c57a0dc32a5b52ef02f54940a15fb85f8129fd18178840a83bdb8a6040004e6308204e2308203caa00302010202106ebaf08f7983fa9de1b26f96fc6e98bf300d06092a864886f70d0101050500306f310b300906035504061302534531143012060355040a130b416464547275737420414231263024060355040b131d41646454727573742045787465726e616c20545450204e6574776f726b312230200603550403131941646454727573742045787465726e616c20434120526f6f74301e170d31
EAP-Message = 0x31303832333030303030305a170d3230303533303130343833385a3070310b3009060355040613024742311b30190603550408131247726561746572204d616e636865737465723110300e0603550407130753616c666f7264311a3018060355040a1311434f4d4f444f204341204c696d69746564311630140603550403130d434f4d4f444f2053534c20434130820122300d06092a864886f70d01010105000382010f003082010a0282010100d42b2e1cd2a3f87f551440def744dd8455f7857b556669a7e559eb6583f4f376b166c34f4e989309b740b3d117a01209a880e1296397028c319d0a02e0595bbbed30b5ef7e5daf084e8d8bc2395616
EAP-Message = 0x987394780ac9a64f28b7a83437db2521b13c99f6e0123e73ea64329f42063c19d80a047a4c57492bd2777ad000bc5efa8eeeccc2e4136e255fdc3ca488a3dc49c7bcc70fdd19c0b172ed78ef38830a45171bc97d9deddfab2c2ca375ae5b821d88838dce08650c66265705a10cdfe607840b84a3c8abd59547bfdcdcfe1dfc02934401cae6b5b76b1630015de98909959ef85e295cddc7558cf28e204e407ae4f54503b4982bc4807e53876fc2d257b0e90203010001a382017730820173301f0603551d23041830168014adbd987a34b426f7fac42654ef03bde024cb541a301d0603551d0e041604141b6bbd1f8a491894543755b42017ed37b97718
EAP-Message = 0x7d300e0603551d0f
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x163f61d8143b786d9edf10fb24c294e9
Finished request 7.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.1.2.2 port 32770, id=104, length=255
User-Name = "test_clear"
Chargeable-User-Identity = ""
X-Ascend-Dialout-Allowed = Dialout-Allowed
Calling-Station-Id = "78:31:c1:c0:55:f4"
Called-Station-Id = "f0:29:29:4c:6b:d0:Test2"
NAS-Port = 13
Cisco-AVPair = "audit-session-id=0a0102020000da9c533e4daf"
NAS-IP-Address = 10.1.2.2
NAS-Identifier = "SFO_HQ_WCON_5508"
Airespace-Wlan-Id = 7
Service-Type = Framed-User
Framed-MTU = 1300
NAS-Port-Type = Wireless-802.11
Tunnel-Type:0 = VLAN
Tunnel-Medium-Type:0 = IEEE-802
Tunnel-Private-Group-Id:0 = "144"
EAP-Message = 0x020400061900
State = 0x163f61d8143b786d9edf10fb24c294e9
Message-Authenticator = 0xa5a43a99e990ece2af322c05f970c4bb
server Test_Wifi_Outer {
# Executing section authorize from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] expand: %t -> Thu Apr 3 23:13:50 2014
++[auth_log] returns ok
[EAP_WIFI] EAP packet type response id 4 length 6
[EAP_WIFI] Continuing tunnel setup.
++[EAP_WIFI] returns ok
Found Auth-Type = EAP_WIFI
# Executing group from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authenticate {...}
[EAP_WIFI] Request found, released from the list
[EAP_WIFI] EAP/peap
[EAP_WIFI] processing type peap
[peap] processing EAP-TLS
[peap] Received TLS ACK
[peap] ACK handshake fragment handler
[peap] eaptls_verify returned 1
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[EAP_WIFI] returns handled
} # server Test_Wifi_Outer
Sending Access-Challenge of id 104 to 10.1.2.2 port 32770
EAP-Message = 0x010503fc19400101ff04040302010630120603551d130101ff040830060101ff02010030110603551d20040a300830060604551d200030440603551d1f043d303b3039a037a0358633687474703a2f2f63726c2e7573657274727573742e636f6d2f416464547275737445787465726e616c4341526f6f742e63726c3081b306082b060105050701010481a63081a3303f06082b060105050730028633687474703a2f2f6372742e7573657274727573742e636f6d2f416464547275737445787465726e616c4341526f6f742e703763303906082b06010505073002862d687474703a2f2f6372742e7573657274727573742e636f6d2f416464547275
EAP-Message = 0x737455544e53474343412e637274302506082b060105050730018619687474703a2f2f6f6373702e7573657274727573742e636f6d300d06092a864886f70d01010505000382010100432539230704ac995d59673de62f617d5a567bfc068db34b9dfad5054c0d66b5bd3cc7a22a6bb5cfe6ba833e6090360cd5c2ed8a95d99242231c03763ec248f175729db38ccfb3583456491da12e2b3db2e85a1046de64b54dae4b6efc01b72110d595b7eb2cbe1406cc412ee46ce24690ffc6287e73fee517ba82c310058166c28b2838a0443ee9e4ce33b07cf8e1539db8b4cbdac92ed993708e7c0be3733e99998febe1114435d860816245d4de455b902e49
EAP-Message = 0x1b1bdba40f8062217369f1e3de6dd8487c56122622114701c65e19c2b49597ee610055f10438fc84e678b40d43be4333dd68d3225b00fb1482e84b627930cfd3959fb3b98401d4ddcf2312f800043a308204363082031ea003020102020101300d06092a864886f70d0101050500306f310b300906035504061302534531143012060355040a130b416464547275737420414231263024060355040b131d41646454727573742045787465726e616c20545450204e6574776f726b312230200603550403131941646454727573742045787465726e616c20434120526f6f74301e170d3030303533303130343833385a170d3230303533303130343833
EAP-Message = 0x385a306f310b300906035504061302534531143012060355040a130b416464547275737420414231263024060355040b131d41646454727573742045787465726e616c20545450204e6574776f726b312230200603550403131941646454727573742045787465726e616c20434120526f6f7430820122300d06092a864886f70d01010105000382010f003082010a0282010100b7f71a33e6f200042d39e04e5bed1fbc6c0fcdb5fa23b6cede9b113397a4294c7d939fbd4abc93ed031ae38fcfe56d505ad69729945a80b0497adb2e95fdb8cabf37382d1e3e9141ad7056c7f04f3fe8329e74cac89054e9c65f0f789d9a403c0eac61aa5e148f9e87
EAP-Message = 0xa16a50dcd79a4eaf
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x163f61d8153a786d9edf10fb24c294e9
Finished request 8.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.1.2.2 port 32770, id=105, length=255
User-Name = "test_clear"
Chargeable-User-Identity = ""
X-Ascend-Dialout-Allowed = Dialout-Allowed
Calling-Station-Id = "78:31:c1:c0:55:f4"
Called-Station-Id = "f0:29:29:4c:6b:d0:Test2"
NAS-Port = 13
Cisco-AVPair = "audit-session-id=0a0102020000da9c533e4daf"
NAS-IP-Address = 10.1.2.2
NAS-Identifier = "SFO_HQ_WCON_5508"
Airespace-Wlan-Id = 7
Service-Type = Framed-User
Framed-MTU = 1300
NAS-Port-Type = Wireless-802.11
Tunnel-Type:0 = VLAN
Tunnel-Medium-Type:0 = IEEE-802
Tunnel-Private-Group-Id:0 = "144"
EAP-Message = 0x020500061900
State = 0x163f61d8153a786d9edf10fb24c294e9
Message-Authenticator = 0x5305baf462a669248319835f270b86e4
server Test_Wifi_Outer {
# Executing section authorize from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] expand: %t -> Thu Apr 3 23:13:50 2014
++[auth_log] returns ok
[EAP_WIFI] EAP packet type response id 5 length 6
[EAP_WIFI] Continuing tunnel setup.
++[EAP_WIFI] returns ok
Found Auth-Type = EAP_WIFI
# Executing group from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authenticate {...}
[EAP_WIFI] Request found, released from the list
[EAP_WIFI] EAP/peap
[EAP_WIFI] processing type peap
[peap] processing EAP-TLS
[peap] Received TLS ACK
[peap] ACK handshake fragment handler
[peap] eaptls_verify returned 1
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[EAP_WIFI] returns handled
} # server Test_Wifi_Outer
Sending Access-Challenge of id 105 to 10.1.2.2 port 32770
EAP-Message = 0x01060296190005b3a671949c71b350600ac7139d38078602a8e9a869261890ab4cb04f23ab3a4f84d8dfce9fe1696fbbd742d76b44e4c7adee6d415f725a710837b37965a459a09437f7002f0dc29272dad03872db14a845c45d2a7db7b4d6c4eeaccd1344b7c92bdd430025fa61b9696a582311b7a7338f567559f5cd29d746b70a2b65b6d3426f15b2b87bfbefe95d53d5345a270203010001a381dc3081d9301d0603551d0e04160414adbd987a34b426f7fac42654ef03bde024cb541a300b0603551d0f040403020106300f0603551d130101ff040530030101ff3081990603551d2304819130818e8014adbd987a34b426f7fac42654ef03bde0
EAP-Message = 0x24cb541aa173a471306f310b300906035504061302534531143012060355040a130b416464547275737420414231263024060355040b131d41646454727573742045787465726e616c20545450204e6574776f726b312230200603550403131941646454727573742045787465726e616c20434120526f6f74820101300d06092a864886f70d01010505000382010100b09be08525c2d623e20f9606929d41989cd9847981d91e5b14072336658fb0d877bbac416c47608351b0f9323de7fcf62613c78016a5bf5afc87cf787989219ae24c070a8635bcf2de51c4d296b7dc7e4eee70fd1c39eb0c0251142d8ebd16e0c1df4675e724adecf442b48593
EAP-Message = 0x701067ba9d06354a18d32b7acc5142a17a63d1e6bba1c52bc236be130de6bd637e797ba7090d40ab6add8f8ac3f6f68c1a420551d445f59fa76221681520433c99e77cbd24d8a9911773883f561b313818b4710f9acdc80e9e8e2e1be18c9883cb1f31f1444cc604734976600fc7f8bd17806b2ee9cc4c0e5a9a790f200a2ed59e63261e559294d882175a7bd0bcc78f4e860416030100040e000000
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x163f61d81239786d9edf10fb24c294e9
Finished request 9.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.1.2.2 port 32770, id=106, length=587
User-Name = "test_clear"
Chargeable-User-Identity = ""
X-Ascend-Dialout-Allowed = Dialout-Allowed
Calling-Station-Id = "78:31:c1:c0:55:f4"
Called-Station-Id = "f0:29:29:4c:6b:d0:Test2"
NAS-Port = 13
Cisco-AVPair = "audit-session-id=0a0102020000da9c533e4daf"
NAS-IP-Address = 10.1.2.2
NAS-Identifier = "SFO_HQ_WCON_5508"
Airespace-Wlan-Id = 7
Service-Type = Framed-User
Framed-MTU = 1300
NAS-Port-Type = Wireless-802.11
Tunnel-Type:0 = VLAN
Tunnel-Medium-Type:0 = IEEE-802
Tunnel-Private-Group-Id:0 = "144"
EAP-Message = 0x0206015019800000014616030101061000010201002d31c2713ac6fca9b7217927326c21653d71ccec2ff039b5f44015fd73315138bf6adb3258784aba87fcf59855c8350d9c548fae22072e40057b6b87382be477ecfbd9ad36f955a0e3ebd5bd7d681aac6ea124426d19c127282c1d726ac1092c1d7c574e9c7e84ef58f9c991c84378db3113ffa0379c696380e2307742efc69d2ddcdf818c88460776f567924d11705d793956301433b42d882975381629768984c4e401a3abad6a4c09e3d45acd80b2498724d52d053c8a3f3222083b272d9a65e65f35c27d5f31b422901a16f15c0c02a42cb9bfad08ff5eb430207360542bb91af9b76b6cd355
EAP-Message = 0x1325f28b9174051038c84554bf78171b57c0ce7ca9ca74cd1403010001011603010030b93061bdf2cff76519018ef92570aba208da097cd604c77a9364ec8aa368bce7c7c7c240907c9034b310357f9f48a486
State = 0x163f61d81239786d9edf10fb24c294e9
Message-Authenticator = 0x6d2d7e34d91c7e90f673b48d11e2cac6
server Test_Wifi_Outer {
# Executing section authorize from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] expand: %t -> Thu Apr 3 23:13:50 2014
++[auth_log] returns ok
[EAP_WIFI] EAP packet type response id 6 length 253
[EAP_WIFI] Continuing tunnel setup.
++[EAP_WIFI] returns ok
Found Auth-Type = EAP_WIFI
# Executing group from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authenticate {...}
[EAP_WIFI] Request found, released from the list
[EAP_WIFI] EAP/peap
[EAP_WIFI] processing type peap
[peap] processing EAP-TLS
TLS Length 326
[peap] Length Included
[peap] eaptls_verify returned 11
[peap] <<< TLS 1.0 Handshake [length 0106], ClientKeyExchange
[peap] TLS_accept: SSLv3 read client key exchange A
[peap] <<< TLS 1.0 ChangeCipherSpec [length 0001]
[peap] <<< TLS 1.0 Handshake [length 0010], Finished
[peap] TLS_accept: SSLv3 read finished A
[peap] >>> TLS 1.0 ChangeCipherSpec [length 0001]
[peap] TLS_accept: SSLv3 write change cipher spec A
[peap] >>> TLS 1.0 Handshake [length 0010], Finished
[peap] TLS_accept: SSLv3 write finished A
[peap] TLS_accept: SSLv3 flush data
[peap] (other): SSL negotiation finished successfully
SSL Connection Established
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[EAP_WIFI] returns handled
} # server Test_Wifi_Outer
Sending Access-Challenge of id 106 to 10.1.2.2 port 32770
EAP-Message = 0x0107004119001403010001011603010030815346ec6949ee2424761471a80bc72f319afccd8d8e63edeafedf33328fe904dc85331148cc0ce1f82702856754c2c1
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x163f61d81338786d9edf10fb24c294e9
Finished request 10.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.1.2.2 port 32770, id=107, length=255
User-Name = "test_clear"
Chargeable-User-Identity = ""
X-Ascend-Dialout-Allowed = Dialout-Allowed
Calling-Station-Id = "78:31:c1:c0:55:f4"
Called-Station-Id = "f0:29:29:4c:6b:d0:Test2"
NAS-Port = 13
Cisco-AVPair = "audit-session-id=0a0102020000da9c533e4daf"
NAS-IP-Address = 10.1.2.2
NAS-Identifier = "SFO_HQ_WCON_5508"
Airespace-Wlan-Id = 7
Service-Type = Framed-User
Framed-MTU = 1300
NAS-Port-Type = Wireless-802.11
Tunnel-Type:0 = VLAN
Tunnel-Medium-Type:0 = IEEE-802
Tunnel-Private-Group-Id:0 = "144"
EAP-Message = 0x020700061900
State = 0x163f61d81338786d9edf10fb24c294e9
Message-Authenticator = 0xc5704867e5c6ea7742bfa1f2c457758d
server Test_Wifi_Outer {
# Executing section authorize from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] expand: %t -> Thu Apr 3 23:13:50 2014
++[auth_log] returns ok
[EAP_WIFI] EAP packet type response id 7 length 6
[EAP_WIFI] Continuing tunnel setup.
++[EAP_WIFI] returns ok
Found Auth-Type = EAP_WIFI
# Executing group from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authenticate {...}
[EAP_WIFI] Request found, released from the list
[EAP_WIFI] EAP/peap
[EAP_WIFI] processing type peap
[peap] processing EAP-TLS
[peap] Received TLS ACK
[peap] ACK handshake is finished
[peap] eaptls_verify returned 3
[peap] eaptls_process returned 3
[peap] EAPTLS_SUCCESS
[peap] Session established. Decoding tunneled attributes.
[peap] Peap state TUNNEL ESTABLISHED
++[EAP_WIFI] returns handled
} # server Test_Wifi_Outer
Sending Access-Challenge of id 107 to 10.1.2.2 port 32770
EAP-Message = 0x0108002b1900170301002038ffa9f37f9e8acc0dc944e94b1fe129e7483c67f54dcc636e9eaf3ccaac1117
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x163f61d81037786d9edf10fb24c294e9
Finished request 11.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.1.2.2 port 32770, id=108, length=292
User-Name = "test_clear"
Chargeable-User-Identity = ""
X-Ascend-Dialout-Allowed = Dialout-Allowed
Calling-Station-Id = "78:31:c1:c0:55:f4"
Called-Station-Id = "f0:29:29:4c:6b:d0:Test2"
NAS-Port = 13
Cisco-AVPair = "audit-session-id=0a0102020000da9c533e4daf"
NAS-IP-Address = 10.1.2.2
NAS-Identifier = "SFO_HQ_WCON_5508"
Airespace-Wlan-Id = 7
Service-Type = Framed-User
Framed-MTU = 1300
NAS-Port-Type = Wireless-802.11
Tunnel-Type:0 = VLAN
Tunnel-Medium-Type:0 = IEEE-802
Tunnel-Private-Group-Id:0 = "144"
EAP-Message = 0x0208002b1900170301002093ee2332cbdea996cf1561910b29ed217dabc1ad5228fde00d12e6582e6b14e5
State = 0x163f61d81037786d9edf10fb24c294e9
Message-Authenticator = 0xaeb4a83f51dc52392ce163eb9c8509dc
server Test_Wifi_Outer {
# Executing section authorize from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] expand: %t -> Thu Apr 3 23:13:50 2014
++[auth_log] returns ok
[EAP_WIFI] EAP packet type response id 8 length 43
[EAP_WIFI] Continuing tunnel setup.
++[EAP_WIFI] returns ok
Found Auth-Type = EAP_WIFI
# Executing group from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authenticate {...}
[EAP_WIFI] Request found, released from the list
[EAP_WIFI] EAP/peap
[EAP_WIFI] processing type peap
[peap] processing EAP-TLS
[peap] eaptls_verify returned 7
[peap] Done initial handshake
[peap] eaptls_process returned 7
[peap] EAPTLS_OK
[peap] Session established. Decoding tunneled attributes.
[peap] Peap state WAITING FOR INNER IDENTITY
[peap] Identity - test_clear
[peap] Got inner identity 'test_clear'
[peap] Setting default EAP type for tunneled EAP session.
[peap] Got tunneled request
EAP-Message = 0x0208000f01746573745f636c656172
server Test_Wifi_Outer {
PEAP: Setting User-Name to test_clear
Sending tunneled request
EAP-Message = 0x0208000f01746573745f636c656172
FreeRADIUS-Proxied-To = 127.0.0.1
User-Name = "test_clear"
server Test_Wifi_Outer {
# Executing section authorize from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] expand: %t -> Thu Apr 3 23:13:50 2014
++[auth_log] returns ok
[EAP_WIFI] EAP packet type response id 8 length 15
[EAP_WIFI] No EAP Start, assuming it's an on-going EAP conversation
++[EAP_WIFI] returns updated
++[expiration] returns noop
++[logintime] returns noop
Found Auth-Type = EAP_WIFI
# Executing group from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authenticate {...}
[EAP_WIFI] EAP Identity
[EAP_WIFI] processing type mschapv2
rlm_eap_mschapv2: Issuing Challenge
++[EAP_WIFI] returns handled
} # server Test_Wifi_Outer
[peap] Got tunneled reply code 11
EAP-Message = 0x010900241a0109001f10da4bb3a8141a6335b4fcc1fde5accc54746573745f636c656172
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x92a8ceed92a1d4e2dbdb7b49ab8db848
[peap] Got tunneled reply RADIUS code 11
EAP-Message = 0x010900241a0109001f10da4bb3a8141a6335b4fcc1fde5accc54746573745f636c656172
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x92a8ceed92a1d4e2dbdb7b49ab8db848
[peap] Got tunneled Access-Challenge
++[EAP_WIFI] returns handled
} # server Test_Wifi_Outer
Sending Access-Challenge of id 108 to 10.1.2.2 port 32770
EAP-Message = 0x0109004b1900170301004075d7e9b5e3e52cf879a67dbabbf50265f3920d18f01cab342e77d1c1b7afd38f15a249285ca43be9dd353e564ede0bc082c3206f6ce8ff0ca75ffbc52620a36b
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x163f61d81136786d9edf10fb24c294e9
Finished request 12.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.1.2.2 port 32770, id=109, length=356
User-Name = "test_clear"
Chargeable-User-Identity = ""
X-Ascend-Dialout-Allowed = Dialout-Allowed
Calling-Station-Id = "78:31:c1:c0:55:f4"
Called-Station-Id = "f0:29:29:4c:6b:d0:Test2"
NAS-Port = 13
Cisco-AVPair = "audit-session-id=0a0102020000da9c533e4daf"
NAS-IP-Address = 10.1.2.2
NAS-Identifier = "SFO_HQ_WCON_5508"
Airespace-Wlan-Id = 7
Service-Type = Framed-User
Framed-MTU = 1300
NAS-Port-Type = Wireless-802.11
Tunnel-Type:0 = VLAN
Tunnel-Medium-Type:0 = IEEE-802
Tunnel-Private-Group-Id:0 = "144"
EAP-Message = 0x0209006b190017030100600ba1659435b92f5699e2a59245edd9159f7dceb62f59d372593b1862b38b095ce8b68249f1e1b38e9c34d793348d28ff9a62ede0ba11f39b3dc71179942815cd07111ff3d8617024218477c43f4e44be04a7481dba34a8dd08bc72e684af7f44
State = 0x163f61d81136786d9edf10fb24c294e9
Message-Authenticator = 0xdd4146fa392ba0bc49ee95bee3b5f236
server Test_Wifi_Outer {
# Executing section authorize from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] expand: %t -> Thu Apr 3 23:13:50 2014
++[auth_log] returns ok
[EAP_WIFI] EAP packet type response id 9 length 107
[EAP_WIFI] Continuing tunnel setup.
++[EAP_WIFI] returns ok
Found Auth-Type = EAP_WIFI
# Executing group from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authenticate {...}
[EAP_WIFI] Request found, released from the list
[EAP_WIFI] EAP/peap
[EAP_WIFI] processing type peap
[peap] processing EAP-TLS
[peap] eaptls_verify returned 7
[peap] Done initial handshake
[peap] eaptls_process returned 7
[peap] EAPTLS_OK
[peap] Session established. Decoding tunneled attributes.
[peap] Peap state phase2
[peap] EAP type mschapv2
[peap] Got tunneled request
EAP-Message = 0x020900451a0209004031a2cf3137e625447514cb066b961aee85000000000000000024c8e9551e7303f488fac93e009e560eb5b6ca8ed94cbde500746573745f636c656172
server Test_Wifi_Outer {
PEAP: Setting User-Name to test_clear
Sending tunneled request
EAP-Message = 0x020900451a0209004031a2cf3137e625447514cb066b961aee85000000000000000024c8e9551e7303f488fac93e009e560eb5b6ca8ed94cbde500746573745f636c656172
FreeRADIUS-Proxied-To = 127.0.0.1
User-Name = "test_clear"
State = 0x92a8ceed92a1d4e2dbdb7b49ab8db848
server Test_Wifi_Outer {
# Executing section authorize from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] expand: %t -> Thu Apr 3 23:13:50 2014
++[auth_log] returns ok
[EAP_WIFI] EAP packet type response id 9 length 69
[EAP_WIFI] No EAP Start, assuming it's an on-going EAP conversation
++[EAP_WIFI] returns updated
++[expiration] returns noop
++[logintime] returns noop
Found Auth-Type = EAP_WIFI
# Executing group from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authenticate {...}
[EAP_WIFI] Request found, released from the list
[EAP_WIFI] EAP/mschapv2
[EAP_WIFI] processing type mschapv2
[mschapv2] # Executing group from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
[mschapv2] +- entering group MS-CHAP {...}
[mschap] No Cleartext-Password configured. Cannot create LM-Password.
[mschap] No Cleartext-Password configured. Cannot create NT-Password.
[mschap] Creating challenge hash with username: test_clear
[mschap] Told to do MS-CHAPv2 for test_clear with NT-Password
[mschap] FAILED: No NT/LM-Password. Cannot perform authentication.
[mschap] FAILED: MS-CHAP2-Response is incorrect
++[mschap] returns reject
[EAP_WIFI] Freeing handler
++[EAP_WIFI] returns reject
Failed to authenticate the user.
} # server Test_Wifi_Outer
[peap] Got tunneled reply code 3
MS-CHAP-Error = "\tE=691 R=1"
EAP-Message = 0x04090004
Message-Authenticator = 0x00000000000000000000000000000000
[peap] Got tunneled reply RADIUS code 3
MS-CHAP-Error = "\tE=691 R=1"
EAP-Message = 0x04090004
Message-Authenticator = 0x00000000000000000000000000000000
[peap] Tunneled authentication was rejected.
[peap] FAILURE
++[EAP_WIFI] returns handled
} # server Test_Wifi_Outer
Sending Access-Challenge of id 109 to 10.1.2.2 port 32770
EAP-Message = 0x010a002b190017030100205e4b63a117aefa8b0c04c948bb6462ecbb3cf27cfb011bee6ce70f84d0564930
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x163f61d81e35786d9edf10fb24c294e9
Finished request 13.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.1.2.2 port 32770, id=110, length=292
User-Name = "test_clear"
Chargeable-User-Identity = ""
X-Ascend-Dialout-Allowed = Dialout-Allowed
Calling-Station-Id = "78:31:c1:c0:55:f4"
Called-Station-Id = "f0:29:29:4c:6b:d0:Test2"
NAS-Port = 13
Cisco-AVPair = "audit-session-id=0a0102020000da9c533e4daf"
NAS-IP-Address = 10.1.2.2
NAS-Identifier = "SFO_HQ_WCON_5508"
Airespace-Wlan-Id = 7
Service-Type = Framed-User
Framed-MTU = 1300
NAS-Port-Type = Wireless-802.11
Tunnel-Type:0 = VLAN
Tunnel-Medium-Type:0 = IEEE-802
Tunnel-Private-Group-Id:0 = "144"
EAP-Message = 0x020a002b190017030100206a6a1e18f4f01a02dcc1d25f30b0c0c99578486368d6aa3b2aa511f57a2ee03f
State = 0x163f61d81e35786d9edf10fb24c294e9
Message-Authenticator = 0x831e84d437a8ae9f6dece3b241bf7edc
server Test_Wifi_Outer {
# Executing section authorize from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] expand: %t -> Thu Apr 3 23:13:50 2014
++[auth_log] returns ok
[EAP_WIFI] EAP packet type response id 10 length 43
[EAP_WIFI] Continuing tunnel setup.
++[EAP_WIFI] returns ok
Found Auth-Type = EAP_WIFI
# Executing group from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authenticate {...}
[EAP_WIFI] Request found, released from the list
[EAP_WIFI] EAP/peap
[EAP_WIFI] processing type peap
[peap] processing EAP-TLS
[peap] eaptls_verify returned 7
[peap] Done initial handshake
[peap] eaptls_process returned 7
[peap] EAPTLS_OK
[peap] Session established. Decoding tunneled attributes.
[peap] Peap state send tlv failure
[peap] Received EAP-TLV response.
[peap] The users session was previously rejected: returning reject (again.)
[peap] *** This means you need to read the PREVIOUS messages in the debug output
[peap] *** to find out the reason why the user was rejected.
[peap] *** Look for "reject" or "fail". Those earlier messages will tell you.
[peap] *** what went wrong, and how to fix the problem.
[EAP_WIFI] Handler failed in EAP/peap
[EAP_WIFI] Failed in EAP select
++[EAP_WIFI] returns invalid
Failed to authenticate the user.
} # server Test_Wifi_Outer
Using Post-Auth-Type Reject
# Executing group from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group REJECT {...}
[attr_filter.access_reject] expand: %{User-Name} -> test_clear
attr_filter: Matched entry DEFAULT at line 11
++[attr_filter.access_reject] returns updated
Delaying reject of request 14 for 1 seconds
Going to the next request
Waking up in 0.9 seconds.
Sending delayed reject for request 14
Sending Access-Reject of id 110 to 10.1.2.2 port 32770
EAP-Message = 0x040a0004
Message-Authenticator = 0x00000000000000000000000000000000
Waking up in 3.9 seconds.
Cleaning up request 5 ID 101 with timestamp +49
Cleaning up request 6 ID 102 with timestamp +49
Cleaning up request 7 ID 103 with timestamp +49
Cleaning up request 8 ID 104 with timestamp +49
Cleaning up request 9 ID 105 with timestamp +49
Cleaning up request 10 ID 106 with timestamp +49
Cleaning up request 11 ID 107 with timestamp +49
Cleaning up request 12 ID 108 with timestamp +49
Cleaning up request 13 ID 109 with timestamp +49
Waking up in 1.0 seconds.
Cleaning up request 14 ID 110 with timestamp +49
Ready to process requests.2. Test 2 - PEAP and MD5. Test user with password stored using salted SHA. The relevant error from the FreeRADIUS debugs seems to be:
[EAP_WIFI] EAP/md5
[EAP_WIFI] processing type md5
rlm_eap_md5: Cleartext-Password is required for EAP-MD5 authentication
[EAP_WIFI] Handler failed in EAP/md5
[EAP_WIFI] Failed in EAP select
Full FreeRADIUS debug log below:
rad_recv: Access-Request packet from host 10.1.2.2 port 32770, id=246, length=233
User-Name = "test"
Chargeable-User-Identity = ""
X-Ascend-Dialout-Allowed = Dialout-Allowed
Calling-Station-Id = "64:76:ba:8a:67:a4"
Called-Station-Id = "f0:29:29:92:3e:e0:Test"
NAS-Port = 13
Cisco-AVPair = "audit-session-id=0a0102020000d9e4533e3bb8"
NAS-IP-Address = 10.1.2.2
NAS-Identifier = "SFO_HQ_WCON_5508"
Airespace-Wlan-Id = 20
Service-Type = Framed-User
Framed-MTU = 1300
NAS-Port-Type = Wireless-802.11
Tunnel-Type:0 = VLAN
Tunnel-Medium-Type:0 = IEEE-802
Tunnel-Private-Group-Id:0 = "144"
EAP-Message = 0x020600090174657374
Message-Authenticator = 0x5b0b12b00f94589ad877af0649d65428
server Test_Wifi_Outer {
# Executing section authorize from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] expand: %t -> Thu Apr 3 21:57:17 2014
++[auth_log] returns ok
[EAP_WIFI] EAP packet type response id 6 length 9
[EAP_WIFI] No EAP Start, assuming it's an on-going EAP conversation
++[EAP_WIFI] returns updated
++[expiration] returns noop
++[logintime] returns noop
Found Auth-Type = EAP_WIFI
# Executing group from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authenticate {...}
[EAP_WIFI] EAP Identity
[EAP_WIFI] processing type tls
[tls] Initiate
[tls] Start returned 1
++[EAP_WIFI] returns handled
} # server Test_Wifi_Outer
Sending Access-Challenge of id 246 to 10.1.2.2 port 32770
EAP-Message = 0x010700061920
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xe9361abbe9310321c39e914db7f2689c
Finished request 0.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.1.2.2 port 32770, id=247, length=394
User-Name = "test"
Chargeable-User-Identity = ""
X-Ascend-Dialout-Allowed = Dialout-Allowed
Calling-Station-Id = "64:76:ba:8a:67:a4"
Called-Station-Id = "f0:29:29:92:3e:e0:Test"
NAS-Port = 13
Cisco-AVPair = "audit-session-id=0a0102020000d9e4533e3bb8"
NAS-IP-Address = 10.1.2.2
NAS-Identifier = "SFO_HQ_WCON_5508"
Airespace-Wlan-Id = 20
Service-Type = Framed-User
Framed-MTU = 1300
NAS-Port-Type = Wireless-802.11
Tunnel-Type:0 = VLAN
Tunnel-Medium-Type:0 = IEEE-802
Tunnel-Private-Group-Id:0 = "144"
EAP-Message = 0x0207009819800000008e1603010089010000850301533e3bad1d1bad9a9ceacd32dd530397c943a57d8194118a9914bad89c64c76900004a00ffc024c023c00ac009c007c008c028c027c014c013c011c012c026c025c02ac029c005c004c002c003c00fc00ec00cc00d003d003c002f000500040035000a0067006b00330039001601000012000a00080006001700180019000b00020100
State = 0xe9361abbe9310321c39e914db7f2689c
Message-Authenticator = 0x36a24b65b306b55730e8bc29d27c51a0
server Test_Wifi_Outer {
# Executing section authorize from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] expand: %t -> Thu Apr 3 21:57:17 2014
++[auth_log] returns ok
[EAP_WIFI] EAP packet type response id 7 length 152
[EAP_WIFI] Continuing tunnel setup.
++[EAP_WIFI] returns ok
Found Auth-Type = EAP_WIFI
# Executing group from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authenticate {...}
[EAP_WIFI] Request found, released from the list
[EAP_WIFI] EAP/peap
[EAP_WIFI] processing type peap
[peap] processing EAP-TLS
TLS Length 142
[peap] Length Included
[peap] eaptls_verify returned 11
[peap] (other): before/accept initialization
[peap] TLS_accept: before/accept initialization
[peap] <<< TLS 1.0 Handshake [length 0089], ClientHello
[peap] TLS_accept: SSLv3 read client hello A
[peap] >>> TLS 1.0 Handshake [length 0031], ServerHello
[peap] TLS_accept: SSLv3 write server hello A
[peap] >>> TLS 1.0 Handshake [length 0e2e], Certificate
[peap] TLS_accept: SSLv3 write certificate A
[peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone
[peap] TLS_accept: SSLv3 write server done A
[peap] TLS_accept: SSLv3 flush data
[peap] TLS_accept: Need to read more data: SSLv3 read client certificate A
In SSL Handshake Phase
In SSL Accept mode
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[EAP_WIFI] returns handled
} # server Test_Wifi_Outer
Sending Access-Challenge of id 247 to 10.1.2.2 port 32770
EAP-Message = 0x0108040019c000000e7216030100310200002d0301533e3bad1655f6985caf985059c1ea40ea9455fe4abdf5b12e3c213aa8d8150600002f000005ff010001001603010e2e0b000e2a000e270004fe308204fa308203e2a003020102021100f69e47b6852c6714a75b4f84f5ecee35300d06092a864886f70d01010505003070310b3009060355040613024742311b30190603550408131247726561746572204d616e636865737465723110300e0603550407130753616c666f7264311a3018060355040a1311434f4d4f444f204341204c696d69746564311630140603550403130d434f4d4f444f2053534c204341301e170d313331323137303030
EAP-Message = 0x3030305a170d3134313231373233353935395a30533121301f060355040b1318446f6d61696e20436f6e74726f6c2056616c69646174656431133011060355040b130a434f4d4f444f2053534c31193017060355040313107261646975732e61697267632e6e657430820122300d06092a864886f70d01010105000382010f003082010a0282010100cc3b800180c335d8132e628428041f463c47f47771b701d3db53965a2c26638c3db956dbd240fbc7f9ddcd5ee91464d596b5c7185ddddd4e6b8b5e2a738f36e690b2d5a7401b27316efa31df34f3784b2cfe271804132c090f53c1f72bfa6c5a602c37e9922a635ed84453dfa9ae9b62865948b1
EAP-Message = 0x1934875f9b7c88abc611a727e62654dd9fe55d63bfd61aeb9c361799c2eee0f38e01dfc9758a25c1347d79e384d7ed3a7bd71fa408417466b97d9d4c54bcca1e56ee6b84fd5b1fb6aeb40f4fce973d41519ed7f5fee2ab47f2174ae3b0fc34a6e3a5f77655ae967423e4c28fdb2336255babd87a7e2b76102e1790354c77607a1a92a0eb84cea6d513a2946b0203010001a38201aa308201a6301f0603551d230418301680141b6bbd1f8a491894543755b42017ed37b977187d301d0603551d0e04160414c4bce01b4b9c94f877b71a4c6b55e95308e58359300e0603551d0f0101ff0404030205a0300c0603551d130101ff04023000301d0603551d
EAP-Message = 0x250416301406082b0601050507030106082b06010505070302304f0603551d2004483046303a060b2b06010401b23101020207302b302906082b06010505070201161d68747470733a2f2f7365637572652e636f6d6f646f2e636f6d2f4350533008060667810c01020130380603551d1f0431302f302da02ba0298627687474703a2f2f63726c2e636f6d6f646f63612e636f6d2f434f4d4f444f53534c43412e63726c306906082b06010505070101045d305b303306082b060105050730028627687474703a2f2f6372742e636f6d6f646f63612e636f6d2f434f4d4f444f53534c43412e637274302406082b060105050730018618687474703a2f
EAP-Message = 0x2f6f6373702e636f6d6f646f
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xe9361abbe83e0321c39e914db7f2689c
Finished request 1.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.1.2.2 port 32770, id=248, length=248
User-Name = "test"
Chargeable-User-Identity = ""
X-Ascend-Dialout-Allowed = Dialout-Allowed
Calling-Station-Id = "64:76:ba:8a:67:a4"
Called-Station-Id = "f0:29:29:92:3e:e0:Test"
NAS-Port = 13
Cisco-AVPair = "audit-session-id=0a0102020000d9e4533e3bb8"
NAS-IP-Address = 10.1.2.2
NAS-Identifier = "SFO_HQ_WCON_5508"
Airespace-Wlan-Id = 20
Service-Type = Framed-User
Framed-MTU = 1300
NAS-Port-Type = Wireless-802.11
Tunnel-Type:0 = VLAN
Tunnel-Medium-Type:0 = IEEE-802
Tunnel-Private-Group-Id:0 = "144"
EAP-Message = 0x020800061900
State = 0xe9361abbe83e0321c39e914db7f2689c
Message-Authenticator = 0xf9d011a3bcdb1f786c9ca23f96e8590b
server Test_Wifi_Outer {
# Executing section authorize from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] expand: %t -> Thu Apr 3 21:57:17 2014
++[auth_log] returns ok
[EAP_WIFI] EAP packet type response id 8 length 6
[EAP_WIFI] Continuing tunnel setup.
++[EAP_WIFI] returns ok
Found Auth-Type = EAP_WIFI
# Executing group from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authenticate {...}
[EAP_WIFI] Request found, released from the list
[EAP_WIFI] EAP/peap
[EAP_WIFI] processing type peap
[peap] processing EAP-TLS
[peap] Received TLS ACK
[peap] ACK handshake fragment handler
[peap] eaptls_verify returned 1
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[EAP_WIFI] returns handled
} # server Test_Wifi_Outer
Sending Access-Challenge of id 248 to 10.1.2.2 port 32770
EAP-Message = 0x010903fc194063612e636f6d30310603551d11042a302882107261646975732e61697267632e6e657482147777772e7261646975732e61697267632e6e6574300d06092a864886f70d0101050500038201010097cc409026a38cb327dd6e1d3c32d27ec6d180e3b30c13252dc2e5631da1a51fdc0666b05a3df1414a9356357434338b5dab034fe305cea0868c7719a38a682db8728540f11f4583e45eeb154715d7e24edc14399ac1f80d0ee06178d1df2e7c0b06308564cc15c72b7b516ecca2b54ddf49a1b7cb6333db8d9c79739cc2348b1984262c967a5e1785d32f6b26b9913d6e574953f5a85e2be8f568635c96c6538894f3936ac9550b4f45
EAP-Message = 0x2b6415f13df580e5bd901ac2cc83d3f8d203b11c0061e9d7fd8fe1d3c9b84e3f4392518e2eea92263bc8f74b6a002167bb48831eff8630518a1c57a0dc32a5b52ef02f54940a15fb85f8129fd18178840a83bdb8a6040004e6308204e2308203caa00302010202106ebaf08f7983fa9de1b26f96fc6e98bf300d06092a864886f70d0101050500306f310b300906035504061302534531143012060355040a130b416464547275737420414231263024060355040b131d41646454727573742045787465726e616c20545450204e6574776f726b312230200603550403131941646454727573742045787465726e616c20434120526f6f74301e170d31
EAP-Message = 0x31303832333030303030305a170d3230303533303130343833385a3070310b3009060355040613024742311b30190603550408131247726561746572204d616e636865737465723110300e0603550407130753616c666f7264311a3018060355040a1311434f4d4f444f204341204c696d69746564311630140603550403130d434f4d4f444f2053534c20434130820122300d06092a864886f70d01010105000382010f003082010a0282010100d42b2e1cd2a3f87f551440def744dd8455f7857b556669a7e559eb6583f4f376b166c34f4e989309b740b3d117a01209a880e1296397028c319d0a02e0595bbbed30b5ef7e5daf084e8d8bc2395616
EAP-Message = 0x987394780ac9a64f28b7a83437db2521b13c99f6e0123e73ea64329f42063c19d80a047a4c57492bd2777ad000bc5efa8eeeccc2e4136e255fdc3ca488a3dc49c7bcc70fdd19c0b172ed78ef38830a45171bc97d9deddfab2c2ca375ae5b821d88838dce08650c66265705a10cdfe607840b84a3c8abd59547bfdcdcfe1dfc02934401cae6b5b76b1630015de98909959ef85e295cddc7558cf28e204e407ae4f54503b4982bc4807e53876fc2d257b0e90203010001a382017730820173301f0603551d23041830168014adbd987a34b426f7fac42654ef03bde024cb541a301d0603551d0e041604141b6bbd1f8a491894543755b42017ed37b97718
EAP-Message = 0x7d300e0603551d0f
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xe9361abbeb3f0321c39e914db7f2689c
Finished request 2.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.1.2.2 port 32770, id=249, length=248
User-Name = "test"
Chargeable-User-Identity = ""
X-Ascend-Dialout-Allowed = Dialout-Allowed
Calling-Station-Id = "64:76:ba:8a:67:a4"
Called-Station-Id = "f0:29:29:92:3e:e0:Test"
NAS-Port = 13
Cisco-AVPair = "audit-session-id=0a0102020000d9e4533e3bb8"
NAS-IP-Address = 10.1.2.2
NAS-Identifier = "SFO_HQ_WCON_5508"
Airespace-Wlan-Id = 20
Service-Type = Framed-User
Framed-MTU = 1300
NAS-Port-Type = Wireless-802.11
Tunnel-Type:0 = VLAN
Tunnel-Medium-Type:0 = IEEE-802
Tunnel-Private-Group-Id:0 = "144"
EAP-Message = 0x020900061900
State = 0xe9361abbeb3f0321c39e914db7f2689c
Message-Authenticator = 0x423d553a7715644df3ea63d93728900c
server Test_Wifi_Outer {
# Executing section authorize from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] expand: %t -> Thu Apr 3 21:57:17 2014
++[auth_log] returns ok
[EAP_WIFI] EAP packet type response id 9 length 6
[EAP_WIFI] Continuing tunnel setup.
++[EAP_WIFI] returns ok
Found Auth-Type = EAP_WIFI
# Executing group from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authenticate {...}
[EAP_WIFI] Request found, released from the list
[EAP_WIFI] EAP/peap
[EAP_WIFI] processing type peap
[peap] processing EAP-TLS
[peap] Received TLS ACK
[peap] ACK handshake fragment handler
[peap] eaptls_verify returned 1
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[EAP_WIFI] returns handled
} # server Test_Wifi_Outer
Sending Access-Challenge of id 249 to 10.1.2.2 port 32770
EAP-Message = 0x010a03fc19400101ff04040302010630120603551d130101ff040830060101ff02010030110603551d20040a300830060604551d200030440603551d1f043d303b3039a037a0358633687474703a2f2f63726c2e7573657274727573742e636f6d2f416464547275737445787465726e616c4341526f6f742e63726c3081b306082b060105050701010481a63081a3303f06082b060105050730028633687474703a2f2f6372742e7573657274727573742e636f6d2f416464547275737445787465726e616c4341526f6f742e703763303906082b06010505073002862d687474703a2f2f6372742e7573657274727573742e636f6d2f416464547275
EAP-Message = 0x737455544e53474343412e637274302506082b060105050730018619687474703a2f2f6f6373702e7573657274727573742e636f6d300d06092a864886f70d01010505000382010100432539230704ac995d59673de62f617d5a567bfc068db34b9dfad5054c0d66b5bd3cc7a22a6bb5cfe6ba833e6090360cd5c2ed8a95d99242231c03763ec248f175729db38ccfb3583456491da12e2b3db2e85a1046de64b54dae4b6efc01b72110d595b7eb2cbe1406cc412ee46ce24690ffc6287e73fee517ba82c310058166c28b2838a0443ee9e4ce33b07cf8e1539db8b4cbdac92ed993708e7c0be3733e99998febe1114435d860816245d4de455b902e49
EAP-Message = 0x1b1bdba40f8062217369f1e3de6dd8487c56122622114701c65e19c2b49597ee610055f10438fc84e678b40d43be4333dd68d3225b00fb1482e84b627930cfd3959fb3b98401d4ddcf2312f800043a308204363082031ea003020102020101300d06092a864886f70d0101050500306f310b300906035504061302534531143012060355040a130b416464547275737420414231263024060355040b131d41646454727573742045787465726e616c20545450204e6574776f726b312230200603550403131941646454727573742045787465726e616c20434120526f6f74301e170d3030303533303130343833385a170d3230303533303130343833
EAP-Message = 0x385a306f310b300906035504061302534531143012060355040a130b416464547275737420414231263024060355040b131d41646454727573742045787465726e616c20545450204e6574776f726b312230200603550403131941646454727573742045787465726e616c20434120526f6f7430820122300d06092a864886f70d01010105000382010f003082010a0282010100b7f71a33e6f200042d39e04e5bed1fbc6c0fcdb5fa23b6cede9b113397a4294c7d939fbd4abc93ed031ae38fcfe56d505ad69729945a80b0497adb2e95fdb8cabf37382d1e3e9141ad7056c7f04f3fe8329e74cac89054e9c65f0f789d9a403c0eac61aa5e148f9e87
EAP-Message = 0xa16a50dcd79a4eaf
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xe9361abbea3c0321c39e914db7f2689c
Finished request 3.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.1.2.2 port 32770, id=250, length=248
User-Name = "test"
Chargeable-User-Identity = ""
X-Ascend-Dialout-Allowed = Dialout-Allowed
Calling-Station-Id = "64:76:ba:8a:67:a4"
Called-Station-Id = "f0:29:29:92:3e:e0:Test"
NAS-Port = 13
Cisco-AVPair = "audit-session-id=0a0102020000d9e4533e3bb8"
NAS-IP-Address = 10.1.2.2
NAS-Identifier = "SFO_HQ_WCON_5508"
Airespace-Wlan-Id = 20
Service-Type = Framed-User
Framed-MTU = 1300
NAS-Port-Type = Wireless-802.11
Tunnel-Type:0 = VLAN
Tunnel-Medium-Type:0 = IEEE-802
Tunnel-Private-Group-Id:0 = "144"
EAP-Message = 0x020a00061900
State = 0xe9361abbea3c0321c39e914db7f2689c
Message-Authenticator = 0x26cb5cf9b9f5f425cddf175822c5e268
server Test_Wifi_Outer {
# Executing section authorize from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] expand: %t -> Thu Apr 3 21:57:17 2014
++[auth_log] returns ok
[EAP_WIFI] EAP packet type response id 10 length 6
[EAP_WIFI] Continuing tunnel setup.
++[EAP_WIFI] returns ok
Found Auth-Type = EAP_WIFI
# Executing group from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authenticate {...}
[EAP_WIFI] Request found, released from the list
[EAP_WIFI] EAP/peap
[EAP_WIFI] processing type peap
[peap] processing EAP-TLS
[peap] Received TLS ACK
[peap] ACK handshake fragment handler
[peap] eaptls_verify returned 1
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[EAP_WIFI] returns handled
} # server Test_Wifi_Outer
Sending Access-Challenge of id 250 to 10.1.2.2 port 32770
EAP-Message = 0x010b0296190005b3a671949c71b350600ac7139d38078602a8e9a869261890ab4cb04f23ab3a4f84d8dfce9fe1696fbbd742d76b44e4c7adee6d415f725a710837b37965a459a09437f7002f0dc29272dad03872db14a845c45d2a7db7b4d6c4eeaccd1344b7c92bdd430025fa61b9696a582311b7a7338f567559f5cd29d746b70a2b65b6d3426f15b2b87bfbefe95d53d5345a270203010001a381dc3081d9301d0603551d0e04160414adbd987a34b426f7fac42654ef03bde024cb541a300b0603551d0f040403020106300f0603551d130101ff040530030101ff3081990603551d2304819130818e8014adbd987a34b426f7fac42654ef03bde0
EAP-Message = 0x24cb541aa173a471306f310b300906035504061302534531143012060355040a130b416464547275737420414231263024060355040b131d41646454727573742045787465726e616c20545450204e6574776f726b312230200603550403131941646454727573742045787465726e616c20434120526f6f74820101300d06092a864886f70d01010505000382010100b09be08525c2d623e20f9606929d41989cd9847981d91e5b14072336658fb0d877bbac416c47608351b0f9323de7fcf62613c78016a5bf5afc87cf787989219ae24c070a8635bcf2de51c4d296b7dc7e4eee70fd1c39eb0c0251142d8ebd16e0c1df4675e724adecf442b48593
EAP-Message = 0x701067ba9d06354a18d32b7acc5142a17a63d1e6bba1c52bc236be130de6bd637e797ba7090d40ab6add8f8ac3f6f68c1a420551d445f59fa76221681520433c99e77cbd24d8a9911773883f561b313818b4710f9acdc80e9e8e2e1be18c9883cb1f31f1444cc604734976600fc7f8bd17806b2ee9cc4c0e5a9a790f200a2ed59e63261e559294d882175a7bd0bcc78f4e860416030100040e000000
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xe9361abbed3d0321c39e914db7f2689c
Finished request 4.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.1.2.2 port 32770, id=251, length=580
User-Name = "test"
Chargeable-User-Identity = ""
X-Ascend-Dialout-Allowed = Dialout-Allowed
Calling-Station-Id = "64:76:ba:8a:67:a4"
Called-Station-Id = "f0:29:29:92:3e:e0:Test"
NAS-Port = 13
Cisco-AVPair = "audit-session-id=0a0102020000d9e4533e3bb8"
NAS-IP-Address = 10.1.2.2
NAS-Identifier = "SFO_HQ_WCON_5508"
Airespace-Wlan-Id = 20
Service-Type = Framed-User
Framed-MTU = 1300
NAS-Port-Type = Wireless-802.11
Tunnel-Type:0 = VLAN
Tunnel-Medium-Type:0 = IEEE-802
Tunnel-Private-Group-Id:0 = "144"
EAP-Message = 0x020b015019800000014616030101061000010201007c7125342f657d7e249021ef7b74528b257ad7f9b0340380cc9b8a89b9d0abc9159a61f8358a4cddfe44b0ac10e751893790204d73b7b2419618ad18d6d617d12da34e7a8da8047f71eaa91757d80dd7b6f95cf0534e664f086a94a62f05fd2769b1b2546fab1d033251b7c46d379da9c9c984a58b3557007616793c7ffd0abc6fca3b51d493ddd5dfb0b1f7f237f77c4c429331cefbf160616fbd9c43d6ad772a033ba4ff6dbe5f0d8358f87c212eb51845ec9e624c73efcd17e9b505eb99cf851d7f122f2df3bcf1392cd187a66637176672d0dc85a9eceb2f137f8786eba39b824a1ac8b140e6
EAP-Message = 0x424b01dd4fbcc7e2382165c5181fe07c7e0b165f08e9c3041403010001011603010030f67be50bd84899948b23199ad436a5b2cc6f51961be88d64ce4313549452936048671b9313c0cef4f14a5f0f7130f661
State = 0xe9361abbed3d0321c39e914db7f2689c
Message-Authenticator = 0xfd41ca8355ea8a6a1f4752239225ee90
server Test_Wifi_Outer {
# Executing section authorize from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] expand: %t -> Thu Apr 3 21:57:18 2014
++[auth_log] returns ok
[EAP_WIFI] EAP packet type response id 11 length 253
[EAP_WIFI] Continuing tunnel setup.
++[EAP_WIFI] returns ok
Found Auth-Type = EAP_WIFI
# Executing group from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authenticate {...}
[EAP_WIFI] Request found, released from the list
[EAP_WIFI] EAP/peap
[EAP_WIFI] processing type peap
[peap] processing EAP-TLS
TLS Length 326
[peap] Length Included
[peap] eaptls_verify returned 11
[peap] <<< TLS 1.0 Handshake [length 0106], ClientKeyExchange
[peap] TLS_accept: SSLv3 read client key exchange A
[peap] <<< TLS 1.0 ChangeCipherSpec [length 0001]
[peap] <<< TLS 1.0 Handshake [length 0010], Finished
[peap] TLS_accept: SSLv3 read finished A
[peap] >>> TLS 1.0 ChangeCipherSpec [length 0001]
[peap] TLS_accept: SSLv3 write change cipher spec A
[peap] >>> TLS 1.0 Handshake [length 0010], Finished
[peap] TLS_accept: SSLv3 write finished A
[peap] TLS_accept: SSLv3 flush data
[peap] (other): SSL negotiation finished successfully
SSL Connection Established
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[EAP_WIFI] returns handled
} # server Test_Wifi_Outer
Sending Access-Challenge of id 251 to 10.1.2.2 port 32770
EAP-Message = 0x010c0041190014030100010116030100301e77ed3182e7850d8ca0975fecc0c4e5b917a5858177e28398b05ff51e5998ee50dc77602f13d7a2785f4d88260771bf
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xe9361abbec3a0321c39e914db7f2689c
Finished request 5.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.1.2.2 port 32770, id=252, length=248
User-Name = "test"
Chargeable-User-Identity = ""
X-Ascend-Dialout-Allowed = Dialout-Allowed
Calling-Station-Id = "64:76:ba:8a:67:a4"
Called-Station-Id = "f0:29:29:92:3e:e0:Test"
NAS-Port = 13
Cisco-AVPair = "audit-session-id=0a0102020000d9e4533e3bb8"
NAS-IP-Address = 10.1.2.2
NAS-Identifier = "SFO_HQ_WCON_5508"
Airespace-Wlan-Id = 20
Service-Type = Framed-User
Framed-MTU = 1300
NAS-Port-Type = Wireless-802.11
Tunnel-Type:0 = VLAN
Tunnel-Medium-Type:0 = IEEE-802
Tunnel-Private-Group-Id:0 = "144"
EAP-Message = 0x020c00061900
State = 0xe9361abbec3a0321c39e914db7f2689c
Message-Authenticator = 0x7525af6e0106390c69bde4ded6de619b
server Test_Wifi_Outer {
# Executing section authorize from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] expand: %t -> Thu Apr 3 21:57:18 2014
++[auth_log] returns ok
[EAP_WIFI] EAP packet type response id 12 length 6
[EAP_WIFI] Continuing tunnel setup.
++[EAP_WIFI] returns ok
Found Auth-Type = EAP_WIFI
# Executing group from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authenticate {...}
[EAP_WIFI] Request found, released from the list
[EAP_WIFI] EAP/peap
[EAP_WIFI] processing type peap
[peap] processing EAP-TLS
[peap] Received TLS ACK
[peap] ACK handshake is finished
[peap] eaptls_verify returned 3
[peap] eaptls_process returned 3
[peap] EAPTLS_SUCCESS
[peap] Session established. Decoding tunneled attributes.
[peap] Peap state TUNNEL ESTABLISHED
++[EAP_WIFI] returns handled
} # server Test_Wifi_Outer
Sending Access-Challenge of id 252 to 10.1.2.2 port 32770
EAP-Message = 0x010d002b190017030100202ffb32273304bbcc1e03f14960daca34d94af0829146049e0370308a8073fb4a
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xe9361abbef3b0321c39e914db7f2689c
Finished request 6.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.1.2.2 port 32770, id=253, length=285
User-Name = "test"
Chargeable-User-Identity = ""
X-Ascend-Dialout-Allowed = Dialout-Allowed
Calling-Station-Id = "64:76:ba:8a:67:a4"
Called-Station-Id = "f0:29:29:92:3e:e0:Test"
NAS-Port = 13
Cisco-AVPair = "audit-session-id=0a0102020000d9e4533e3bb8"
NAS-IP-Address = 10.1.2.2
NAS-Identifier = "SFO_HQ_WCON_5508"
Airespace-Wlan-Id = 20
Service-Type = Framed-User
Framed-MTU = 1300
NAS-Port-Type = Wireless-802.11
Tunnel-Type:0 = VLAN
Tunnel-Medium-Type:0 = IEEE-802
Tunnel-Private-Group-Id:0 = "144"
EAP-Message = 0x020d002b19001703010020fa14c806ae3d791247f07c252372bcb0a1220a0a61a7bdafc49dd4a141f74c85
State = 0xe9361abbef3b0321c39e914db7f2689c
Message-Authenticator = 0xbd3c518bdf2698e02620ccbc08587d15
server Test_Wifi_Outer {
# Executing section authorize from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] expand: %t -> Thu Apr 3 21:57:18 2014
++[auth_log] returns ok
[EAP_WIFI] EAP packet type response id 13 length 43
[EAP_WIFI] Continuing tunnel setup.
++[EAP_WIFI] returns ok
Found Auth-Type = EAP_WIFI
# Executing group from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authenticate {...}
[EAP_WIFI] Request found, released from the list
[EAP_WIFI] EAP/peap
[EAP_WIFI] processing type peap
[peap] processing EAP-TLS
[peap] eaptls_verify returned 7
[peap] Done initial handshake
[peap] eaptls_process returned 7
[peap] EAPTLS_OK
[peap] Session established. Decoding tunneled attributes.
[peap] Peap state WAITING FOR INNER IDENTITY
[peap] Identity - test
[peap] Got inner identity 'test'
[peap] Setting default EAP type for tunneled EAP session.
[peap] Got tunneled request
EAP-Message = 0x020d00090174657374
server Test_Wifi_Outer {
PEAP: Setting User-Name to test
Sending tunneled request
EAP-Message = 0x020d00090174657374
FreeRADIUS-Proxied-To = 127.0.0.1
User-Name = "test"
server Test_Wifi_Outer {
# Executing section authorize from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] expand: %t -> Thu Apr 3 21:57:18 2014
++[auth_log] returns ok
[EAP_WIFI] EAP packet type response id 13 length 9
[EAP_WIFI] No EAP Start, assuming it's an on-going EAP conversation
++[EAP_WIFI] returns updated
++[expiration] returns noop
++[logintime] returns noop
Found Auth-Type = EAP_WIFI
# Executing group from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authenticate {...}
[EAP_WIFI] EAP Identity
[EAP_WIFI] processing type md5
rlm_eap_md5: Issuing Challenge
++[EAP_WIFI] returns handled
} # server Test_Wifi_Outer
[peap] Got tunneled reply code 11
EAP-Message = 0x010e00160410eb69f6b5aa05ba08ef163da85f96022c
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x667146b3667f42142507a8b2d2101c2a
[peap] Got tunneled reply RADIUS code 11
EAP-Message = 0x010e00160410eb69f6b5aa05ba08ef163da85f96022c
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x667146b3667f42142507a8b2d2101c2a
[peap] Got tunneled Access-Challenge
++[EAP_WIFI] returns handled
} # server Test_Wifi_Outer
Sending Access-Challenge of id 253 to 10.1.2.2 port 32770
EAP-Message = 0x010e003b190017030100306040fb9af6908ecb61667ab41eccf395e7d7b8982a2d3ccefb7565dcf551a615e43074de303144070a741b89652323e2
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xe9361abbee380321c39e914db7f2689c
Finished request 7.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.1.2.2 port 32770, id=254, length=301
User-Name = "test"
Chargeable-User-Identity = ""
X-Ascend-Dialout-Allowed = Dialout-Allowed
Calling-Station-Id = "64:76:ba:8a:67:a4"
Called-Station-Id = "f0:29:29:92:3e:e0:Test"
NAS-Port = 13
Cisco-AVPair = "audit-session-id=0a0102020000d9e4533e3bb8"
NAS-IP-Address = 10.1.2.2
NAS-Identifier = "SFO_HQ_WCON_5508"
Airespace-Wlan-Id = 20
Service-Type = Framed-User
Framed-MTU = 1300
NAS-Port-Type = Wireless-802.11
Tunnel-Type:0 = VLAN
Tunnel-Medium-Type:0 = IEEE-802
Tunnel-Private-Group-Id:0 = "144"
EAP-Message = 0x020e003b19001703010030421366f2ba7c7c4c5615ddb1be79cd1e89263712feec9c9db29f208fc22211d011e9a0a1cdd63fb26da8448edc014dd1
State = 0xe9361abbee380321c39e914db7f2689c
Message-Authenticator = 0xe1bd63f176d9b420f680926949f07a44
server Test_Wifi_Outer {
# Executing section authorize from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] expand: %t -> Thu Apr 3 21:57:18 2014
++[auth_log] returns ok
[EAP_WIFI] EAP packet type response id 14 length 59
[EAP_WIFI] Continuing tunnel setup.
++[EAP_WIFI] returns ok
Found Auth-Type = EAP_WIFI
# Executing group from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authenticate {...}
[EAP_WIFI] Request found, released from the list
[EAP_WIFI] EAP/peap
[EAP_WIFI] processing type peap
[peap] processing EAP-TLS
[peap] eaptls_verify returned 7
[peap] Done initial handshake
[peap] eaptls_process returned 7
[peap] EAPTLS_OK
[peap] Session established. Decoding tunneled attributes.
[peap] Peap state phase2
[peap] EAP type md5
[peap] Got tunneled request
EAP-Message = 0x020e001a0410e5567defef977e2b8fb12ed2c531403874657374
server Test_Wifi_Outer {
PEAP: Setting User-Name to test
Sending tunneled request
EAP-Message = 0x020e001a0410e5567defef977e2b8fb12ed2c531403874657374
FreeRADIUS-Proxied-To = 127.0.0.1
User-Name = "test"
State = 0x667146b3667f42142507a8b2d2101c2a
server Test_Wifi_Outer {
# Executing section authorize from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] expand: %t -> Thu Apr 3 21:57:18 2014
++[auth_log] returns ok
[EAP_WIFI] EAP packet type response id 14 length 26
[EAP_WIFI] No EAP Start, assuming it's an on-going EAP conversation
++[EAP_WIFI] returns updated
++[expiration] returns noop
++[logintime] returns noop
Found Auth-Type = EAP_WIFI
# Executing group from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authenticate {...}
[EAP_WIFI] Request found, released from the list
[EAP_WIFI] EAP/md5
[EAP_WIFI] processing type md5
rlm_eap_md5: Cleartext-Password is required for EAP-MD5 authentication
[EAP_WIFI] Handler failed in EAP/md5
[EAP_WIFI] Failed in EAP select
++[EAP_WIFI] returns invalid
Failed to authenticate the user.
} # server Test_Wifi_Outer
[peap] Got tunneled reply code 3
EAP-Message = 0x040e0004
Message-Authenticator = 0x00000000000000000000000000000000
[peap] Got tunneled reply RADIUS code 3
EAP-Message = 0x040e0004
Message-Authenticator = 0x00000000000000000000000000000000
[peap] Tunneled authentication was rejected.
[peap] FAILURE
++[EAP_WIFI] returns handled
} # server Test_Wifi_Outer
Sending Access-Challenge of id 254 to 10.1.2.2 port 32770
EAP-Message = 0x010f002b190017030100202832a9825d903c13c464ae448a28155e737c4758e55cc8997251a74af384056b
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xe9361abbe1390321c39e914db7f2689c
Finished request 8.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.1.2.2 port 32770, id=255, length=285
User-Name = "test"
Chargeable-User-Identity = ""
X-Ascend-Dialout-Allowed = Dialout-Allowed
Calling-Station-Id = "64:76:ba:8a:67:a4"
Called-Station-Id = "f0:29:29:92:3e:e0:Test"
NAS-Port = 13
Cisco-AVPair = "audit-session-id=0a0102020000d9e4533e3bb8"
NAS-IP-Address = 10.1.2.2
NAS-Identifier = "SFO_HQ_WCON_5508"
Airespace-Wlan-Id = 20
Service-Type = Framed-User
Framed-MTU = 1300
NAS-Port-Type = Wireless-802.11
Tunnel-Type:0 = VLAN
Tunnel-Medium-Type:0 = IEEE-802
Tunnel-Private-Group-Id:0 = "144"
EAP-Message = 0x020f002b19001703010020ca0a424a400030926056758f4e1af8ec6b3801ec0bd8ed604bcd0295d6eabfde
State = 0xe9361abbe1390321c39e914db7f2689c
Message-Authenticator = 0x8b49c79799c8bd67ac22b34f3f2cf7a1
server Test_Wifi_Outer {
# Executing section authorize from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.1.2.2/auth-detail-20140403
[auth_log] expand: %t -> Thu Apr 3 21:57:18 2014
++[auth_log] returns ok
[EAP_WIFI] EAP packet type response id 15 length 43
[EAP_WIFI] Continuing tunnel setup.
++[EAP_WIFI] returns ok
Found Auth-Type = EAP_WIFI
# Executing group from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group authenticate {...}
[EAP_WIFI] Request found, released from the list
[EAP_WIFI] EAP/peap
[EAP_WIFI] processing type peap
[peap] processing EAP-TLS
[peap] eaptls_verify returned 7
[peap] Done initial handshake
[peap] eaptls_process returned 7
[peap] EAPTLS_OK
[peap] Session established. Decoding tunneled attributes.
[peap] Peap state send tlv failure
[peap] Received EAP-TLV response.
[peap] The users session was previously rejected: returning reject (again.)
[peap] *** This means you need to read the PREVIOUS messages in the debug output
[peap] *** to find out the reason why the user was rejected.
[peap] *** Look for "reject" or "fail". Those earlier messages will tell you.
[peap] *** what went wrong, and how to fix the problem.
[EAP_WIFI] Handler failed in EAP/peap
[EAP_WIFI] Failed in EAP select
++[EAP_WIFI] returns invalid
Failed to authenticate the user.
} # server Test_Wifi_Outer
Using Post-Auth-Type Reject
# Executing group from file /etc/freeradius/sites-enabled/Test_Wifi_Outer
+- entering group REJECT {...}
[attr_filter.access_reject] expand: %{User-Name} -> test
attr_filter: Matched entry DEFAULT at line 11
++[attr_filter.access_reject] returns updated
Delaying reject of request 9 for 1 seconds
Going to the next request
Waking up in 0.9 seconds.
To me, that looks like you're trying to use PEAP-EAP-TLS.
Can you post the output from show run-config commands on the WLC, and the EAP profile configuration in FreeRADIUS?
Try a plain authentication policy, without extra attributes such as VLAN ID. It shouldn't matter but the WLC might not like the contents of the response if you're unticking the 'Allow AAA-Override' box.
Can you post the output from show run-config commands on the WLC, and the EAP profile configuration in FreeRADIUS?
Try a plain authentication policy, without extra attributes such as VLAN ID. It shouldn't matter but the WLC might not like the contents of the response if you're unticking the 'Allow AAA-Override' box.
Jeff,
did you ever find a solution? we are having the same exact problem and right now cisco support has not been able to find a proper solution.
for us only mac computers are having issues. Iphone and ipad are ok.
thx
Gaetan
did you ever find a solution? we are having the same exact problem and right now cisco support has not been able to find a proper solution.
for us only mac computers are having issues. Iphone and ipad are ok.
thx
Gaetan
Jeff, I've just responded to odewulf's question at https://www.experts-exchange.com/questions/28399538/Roaming-issue-with-cisco-WLC-and-radius-wireless.html?anchorAnswerId=40165835#a40165835, but the solution can be found here...
http://support.apple.com/kb/TS5258
http://support.apple.com/kb/TS5258
ASKER CERTIFIED SOLUTION
membership
This solution is only available to members.
To access this solution, you must be a member of Experts Exchange.
ASKER
We upgraded to 10.9.4 and we're no longer experiencing the issue.
When fast roaming is working correctly in OSX 10.6.5 and higher, it should drop the weaker and connect to the stronger in less than half a second (between 20 ms and 500 ms).
Have you tried setting it up with just WPA2 + AES enabled?