Solved: Re: Problem with roamingin in VoIP SSID...

Petar Petrov · ‎11-30-2012

Hi guys,

My client has a WLC 5508 with a two dosens of 1262s. I set SSID for the VoIP but when the client roams there is a loss of packest. The client is using Cisco phones. Any help will be appreciated.

Pete

__________________________________________

(Cisco Controller) >show wlan 144

WLAN Identifier.................................. 144

Profile Name..................................... VoIP_Network

Network Name (SSID).............................. Inside_144

Status........................................... Enabled

MAC Filtering.................................... Disabled

Broadcast SSID................................... Enabled

AAA Policy Override.............................. Disabled

Network Admission Control

Radius-NAC State............................... Disabled

SNMP-NAC State................................. Disabled

Quarantine VLAN................................ 0

Maximum number of Associated Clients............. 0

Maximum number of Clients per AP Radio........... 200

Number of Active Clients......................... 10

Exclusionlist Timeout............................ 60 seconds

Session Timeout.................................. 1800 seconds

CHD per WLAN..................................... Enabled

Webauth DHCP exclusion........................... Disabled

Interface........................................ 144_v

Multicast Interface.............................. Not Configured

WLAN IPv4 ACL.................................... unconfigured

WLAN IPv6 ACL.................................... unconfigured

DHCP Server...................................... Default

DHCP Address Assignment Required................. Disabled

Static IP client tunneling....................... Disabled

Quality of Service............................... Platinum

Scan Defer Priority.............................. 4,5,6

Scan Defer Time.................................. 100 milliseconds

WMM.............................................. Allowed

WMM UAPSD Compliant Client Support............... Disabled

Media Stream Multicast-direct.................... Disabled

CCX - AironetIe Support.......................... Enabled

CCX - Gratuitous ProbeResponse (GPR)............. Disabled

CCX - Diagnostics Channel Capability............. Disabled

Dot11-Phone Mode (7920).......................... Disabled

Wired Protocol................................... None

Passive Client Feature........................... Disabled

Peer-to-Peer Blocking Action..................... Disabled

Radio Policy..................................... 802.11b and 802.11g only

DTIM period for 802.11a radio.................... 1

DTIM period for 802.11b radio.................... 1

Radius Servers

Authentication................................ Global Servers

Accounting.................................... Global Servers

Interim Update............................. Disabled

Dynamic Interface............................. Disabled

Local EAP Authentication......................... Disabled

Security

802.11 Authentication:........................ Open System

Static WEP Keys............................... Disabled

802.1X........................................ Disabled

Wi-Fi Protected Access (WPA/WPA2)............. Enabled

WPA (SSN IE)............................... Enabled

TKIP Cipher............................. Enabled

AES Cipher.............................. Disabled

WPA2 (RSN IE).............................. Disabled

Auth Key Management

802.1x.................................. Disabled

PSK..................................... Enabled

CCKM.................................... Disabled

FT(802.11r)............................. Disabled

FT-PSK(802.11r)......................... Disabled

FT Reassociation Timeout................... 20

FT Over-The-Air mode....................... Enabled

FT Over-The-Ds mode........................ Enabled

GTK Randomization.......................... Enabled

SKC Cache Support.......................... Disabled

CCKM TSF Tolerance......................... 1000

Wi-Fi Direct policy configured................ Disabled

EAP-Passthrough............................... Disabled

CKIP ......................................... Disabled

Web Based Authentication...................... Disabled

Web-Passthrough............................... Disabled

Conditional Web Redirect...................... Disabled

Splash-Page Web Redirect...................... Disabled

Auto Anchor................................... Disabled

FlexConnect Local Switching................... Disabled

FlexConnect Local Authentication.............. Disabled

FlexConnect Learn IP Address.................. Enabled

Client MFP.................................... Optional but inactive (WPA2 not configured)

Tkip MIC Countermeasure Hold-down Timer....... 60

Call Snooping.................................... Disabled

Roamed Call Re-Anchor Policy..................... Disabled

SIP CAC Fail Send-486-Busy Policy................ Enabled

SIP CAC Fail Send Dis-Association Policy......... Disabled

KTS based CAC Policy............................. Disabled

Band Select...................................... Disabled

Load Balancing................................... Disabled

Multicast Buffer................................. Disabled

Mobility Anchor List

WLAN ID IP Address Status

------- --------------- ------

802.11u........................................ Disabled

Access Network type............................ Not configured

Network Authentication type.................... Not configured

Internet service............................... Disabled

HESSID......................................... 00:00:00:00:00:00

Hotspot 2.0.................................... Disabled

WAN Metrics configuration

Link status.................................. 0

Link symmetry................................ 0

Downlink speed............................... 0

Uplink speed................................. 0

Mobility Services Advertisement Protocol....... Disabled

(Cisco Controller) >

_____________________________________________

(Cisco Controller) >debug client 2c:54:2d:ea:d4:0e

*apfMsConnTask_2: Nov 30 17:02:25.463: 2c:54:2d:ea:d4:0e Association received from mobile on AP 34:bd:c8:b2:b1:10

*apfMsConnTask_2: Nov 30 17:02:25.464: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1697)

*apfMsConnTask_2: Nov 30 17:02:25.464: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1864)

*apfMsConnTask_2: Nov 30 17:02:25.464: 2c:54:2d:ea:d4:0e Applying site-specific Local Bridging override for station 2c:54:2d:ea:d4:0e - vapId 144, site 'Floor_1', interface '144_v'

*apfMsConnTask_2: Nov 30 17:02:25.464: 2c:54:2d:ea:d4:0e Applying Local Bridging Interface Policy for station 2c:54:2d:ea:d4:0e - vlan 144, interface id 12, interface '144_v'

*apfMsConnTask_2: Nov 30 17:02:25.464: 2c:54:2d:ea:d4:0e Applying site-specific override for station 2c:54:2d:ea:d4:0e - vapId 144, site 'Floor_1', interface '144_v'

*apfMsConnTask_2: Nov 30 17:02:25.464: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1697)

*apfMsConnTask_2: Nov 30 17:02:25.464: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1864)

*apfMsConnTask_2: Nov 30 17:02:25.464: 2c:54:2d:ea:d4:0e processSsidIE statusCode is 0 and status is 0

*apfMsConnTask_2: Nov 30 17:02:25.464: 2c:54:2d:ea:d4:0e processSsidIE ssid_done_flag is 0 finish_flag is 0

*apfMsConnTask_2: Nov 30 17:02:25.464: 2c:54:2d:ea:d4:0e STA - rates (4): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*apfMsConnTask_2: Nov 30 17:02:25.464: 2c:54:2d:ea:d4:0e suppRates statusCode is 0 and gotSuppRatesElement is 1

*apfMsConnTask_2: Nov 30 17:02:25.464: 2c:54:2d:ea:d4:0e STA - rates (12): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*apfMsConnTask_2: Nov 30 17:02:25.464: 2c:54:2d:ea:d4:0e extSuppRates statusCode is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_2: Nov 30 17:02:25.464: 2c:54:2d:ea:d4:0e Processing WPA IE type 221, length 22 for mobile 2c:54:2d:ea:d4:0e

*apfMsConnTask_2: Nov 30 17:02:25.464: 2c:54:2d:ea:d4:0e apfMsRunStateDec

*apfMsConnTask_2: Nov 30 17:02:25.464: 2c:54:2d:ea:d4:0e apfMs1xStateDec

*apfMsConnTask_2: Nov 30 17:02:25.464: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Change state to START (0) last state RUN (20)

*apfMsConnTask_2: Nov 30 17:02:25.464: 2c:54:2d:ea:d4:0e pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_2: Nov 30 17:02:25.464: 2c:54:2d:ea:d4:0e 10.123.201.4 START (0) Initializing policy

*apfMsConnTask_2: Nov 30 17:02:25.464: 2c:54:2d:ea:d4:0e 10.123.201.4 START (0) Change state to AUTHCHECK (2) last state RUN (20)

*apfMsConnTask_2: Nov 30 17:02:25.464: 2c:54:2d:ea:d4:0e 10.123.201.4 AUTHCHECK (2) Change state to 8021X_REQD (3) last state RUN (20)

*pemReceiveTask: Nov 30 17:02:25.464: 2c:54:2d:ea:d4:0e 10.123.201.4 Removed NPU entry.

*apfMsConnTask_2: Nov 30 17:02:25.464: 2c:54:2d:ea:d4:0e 10.123.201.4 8021X_REQD (3) DHCP required on AP 34:bd:c8:b2:b1:10 vapId 144 apVapId 2for this client

*apfMsConnTask_2: Nov 30 17:02:25.465: 2c:54:2d:ea:d4:0e 10.123.201.4 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 34:bd:c8:b2:b1:10 vapId 144 apVapId 2

*apfMsConnTask_2: Nov 30 17:02:25.465: 2c:54:2d:ea:d4:0e apfPemAddUser2 (apf_policy.c:268) Changing state for mobile 2c:54:2d:ea:d4:0e on AP 34:bd:c8:b2:b1:10 from Associated to Associated

*apfMsConnTask_2: Nov 30 17:02:25.465: 2c:54:2d:ea:d4:0e Scheduling deletion of Mobile Station: (callerId: 49) in 1800 seconds

*apfMsConnTask_2: Nov 30 17:02:25.465: 2c:54:2d:ea:d4:0e Sending Assoc Response to station on BSSID 34:bd:c8:b2:b1:10 (status 0) ApVapId 2 Slot 0

*apfMsConnTask_2: Nov 30 17:02:25.465: 2c:54:2d:ea:d4:0e apfProcessAssocReq (apf_80211.c:6290) Changing state for mobile 2c:54:2d:ea:d4:0e on AP 34:bd:c8:b2:b1:10 from Associated to Associated

*dot1xMsgTask: Nov 30 17:02:25.466: 2c:54:2d:ea:d4:0e Creating a PKC PMKID Cache entry for station 2c:54:2d:ea:d4:0e (RSN 0)

*dot1xMsgTask: Nov 30 17:02:25.466: 2c:54:2d:ea:d4:0e Setting active key cache index 0 ---> 8

*dot1xMsgTask: Nov 30 17:02:25.466: 2c:54:2d:ea:d4:0e Setting active key cache index 8 ---> 0

*dot1xMsgTask: Nov 30 17:02:25.466: 2c:54:2d:ea:d4:0e Initiating WPA PSK to mobile 2c:54:2d:ea:d4:0e

*dot1xMsgTask: Nov 30 17:02:25.466: 2c:54:2d:ea:d4:0e dot1x - moving mobile 2c:54:2d:ea:d4:0e into Force Auth state

*dot1xMsgTask: Nov 30 17:02:25.466: 2c:54:2d:ea:d4:0e Skipping EAP-Success to mobile 2c:54:2d:ea:d4:0e

*dot1xMsgTask: Nov 30 17:02:25.466: 2c:54:2d:ea:d4:0e Starting key exchange to mobile 2c:54:2d:ea:d4:0e, data packets will be dropped

*dot1xMsgTask: Nov 30 17:02:25.466: 2c:54:2d:ea:d4:0e Sending EAPOL-Key Message to mobile 2c:54:2d:ea:d4:0e

state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Dot1x_NW_MsgTask_6: Nov 30 17:02:25.990: 2c:54:2d:ea:d4:0e Received EAPOL-Key from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Nov 30 17:02:25.990: 2c:54:2d:ea:d4:0e Received EAPOL-key in PTK_START state (message 2) from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Nov 30 17:02:25.990: 2c:54:2d:ea:d4:0e Stopping retransmission timer for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Nov 30 17:02:25.990: 2c:54:2d:ea:d4:0e Sending EAPOL-Key Message to mobile 2c:54:2d:ea:d4:0e

state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01

*Dot1x_NW_MsgTask_6: Nov 30 17:02:26.015: 2c:54:2d:ea:d4:0e Received EAPOL-Key from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Nov 30 17:02:26.015: 2c:54:2d:ea:d4:0e Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Nov 30 17:02:26.016: 2c:54:2d:ea:d4:0e apfMs1xStateInc

*Dot1x_NW_MsgTask_6: Nov 30 17:02:26.016: 2c:54:2d:ea:d4:0e 10.123.201.4 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Dot1x_NW_MsgTask_6: Nov 30 17:02:26.016: 2c:54:2d:ea:d4:0e 10.123.201.4 L2AUTHCOMPLETE (4) DHCP required on AP 34:bd:c8:b2:b1:10 vapId 144 apVapId 2for this client

*Dot1x_NW_MsgTask_6: Nov 30 17:02:26.016: 2c:54:2d:ea:d4:0e 10.123.201.4 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 34:bd:c8:b2:b1:10 vapId 144 apVapId 2

*Dot1x_NW_MsgTask_6: Nov 30 17:02:26.016: 2c:54:2d:ea:d4:0e apfMsRunStateInc

*Dot1x_NW_MsgTask_6: Nov 30 17:02:26.016: 2c:54:2d:ea:d4:0e 10.123.201.4 L2AUTHCOMPLETE (4) Change state to RUN (20) last state RUN (20)

*Dot1x_NW_MsgTask_6: Nov 30 17:02:26.017: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Reached PLUMBFASTPATH: from line 5362

*Dot1x: Nov 30 17:02:26.017: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Adding Fast Path rule

type = Airespace AP Client

on AP 34:bd:c8:b2:b1:10, slot 0, interface = 1, QOS = 2

IPv4 ACL ID = 255, IPv6 ACL ID = 2

*Dot1x_NW_MsgTask_6: Nov 30 17:02:26.017: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 7006 Local Bridging Vlan = 144, Local Bridging intf id = 12

*Dot1x_NW_MsgTask_6: Nov 30 17:02:26.017: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255)

*Dot1x_NW_MsgTask_6: Nov 30 17:02:26.017: 2c:54:2d:ea:d4:0e Stopping retransmission timer for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Nov 30 17:02:26.017: 2c:54:2d:ea:d4:0e Key exchange done, data packets from mobile 2c:54:2d:ea:d4:0e should be forwarded shortly

*Dot1x_NW_MsgTask_6: Nov 30 17:02:26.017: 2c:54:2d:ea:d4:0e Sending EAPOL-Key Message to mobile 2c:54:2d:ea:d4:0e

state PTKINITDONE (message 5 - group), replay counter 00.00.00.00.00.00.00.02

*spamApTask5: Nov 30 17:02:26.017: 2c:54:2d:ea:d4:0e Sent EAPOL-Key M5 for mobile 2c:54:2d:ea:d4:0e

*pemReceiveTask: Nov 30 17:02:26.017: 2c:54:2d:ea:d4:0e 10.123.201.4 Added NPU entry of type 1, dtlFlags 0x0

*Dot1x_NW_MsgTask_6: Nov 30 17:02:26.036: 2c:54:2d:ea:d4:0e Received EAPOL-Key from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Nov 30 17:02:26.036: 2c:54:2d:ea:d4:0e Received EAPOL-key in REKEYNEGOTIATING state (message 6) from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Nov 30 17:02:26.036: 2c:54:2d:ea:d4:0e Stopping retransmission timer for mobile 2c:54:2d:ea:d4:0e

*apfMsConnTask_2: Nov 30 17:03:17.385: 2c:54:2d:ea:d4:0e Association received from mobile on AP 34:bd:c8:b2:b1:10

*apfMsConnTask_2: Nov 30 17:03:17.385: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1697)

*apfMsConnTask_2: Nov 30 17:03:17.385: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1864)

*apfMsConnTask_2: Nov 30 17:03:17.385: 2c:54:2d:ea:d4:0e Applying site-specific Local Bridging override for station 2c:54:2d:ea:d4:0e - vapId 144, site 'Floor_1', interface '144_v'

*apfMsConnTask_2: Nov 30 17:03:17.385: 2c:54:2d:ea:d4:0e Applying Local Bridging Interface Policy for station 2c:54:2d:ea:d4:0e - vlan 144, interface id 12, interface '144_v'

*apfMsConnTask_2: Nov 30 17:03:17.385: 2c:54:2d:ea:d4:0e Applying site-specific override for station 2c:54:2d:ea:d4:0e - vapId 144, site 'Floor_1', interface '144_v'

*apfMsConnTask_2: Nov 30 17:03:17.385: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1697)

*apfMsConnTask_2: Nov 30 17:03:17.385: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1864)

*apfMsConnTask_2: Nov 30 17:03:17.385: 2c:54:2d:ea:d4:0e processSsidIE statusCode is 0 and status is 0

*apfMsConnTask_2: Nov 30 17:03:17.385: 2c:54:2d:ea:d4:0e processSsidIE ssid_done_flag is 0 finish_flag is 0

*apfMsConnTask_2: Nov 30 17:03:17.386: 2c:54:2d:ea:d4:0e STA - rates (4): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*apfMsConnTask_2: Nov 30 17:03:17.386: 2c:54:2d:ea:d4:0e suppRates statusCode is 0 and gotSuppRatesElement is 1

*apfMsConnTask_2: Nov 30 17:03:17.386: 2c:54:2d:ea:d4:0e STA - rates (12): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*apfMsConnTask_2: Nov 30 17:03:17.386: 2c:54:2d:ea:d4:0e extSuppRates statusCode is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_2: Nov 30 17:03:17.386: 2c:54:2d:ea:d4:0e Processing WPA IE type 221, length 22 for mobile 2c:54:2d:ea:d4:0e

*apfMsConnTask_2: Nov 30 17:03:17.386: 2c:54:2d:ea:d4:0e apfMsRunStateDec

*apfMsConnTask_2: Nov 30 17:03:17.386: 2c:54:2d:ea:d4:0e apfMs1xStateDec

*apfMsConnTask_2: Nov 30 17:03:17.386: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Change state to START (0) last state RUN (20)

*apfMsConnTask_2: Nov 30 17:03:17.386: 2c:54:2d:ea:d4:0e pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_2: Nov 30 17:03:17.386: 2c:54:2d:ea:d4:0e 10.123.201.4 START (0) Initializing policy

*apfMsConnTask_2: Nov 30 17:03:17.386: 2c:54:2d:ea:d4:0e 10.123.201.4 START (0) Change state to AUTHCHECK (2) last state RUN (20)

*apfMsConnTask_2: Nov 30 17:03:17.386: 2c:54:2d:ea:d4:0e 10.123.201.4 AUTHCHECK (2) Change state to 8021X_REQD (3) last state RUN (20)

*pemReceiveTask: Nov 30 17:03:17.386: 2c:54:2d:ea:d4:0e 10.123.201.4 Removed NPU entry.

*apfMsConnTask_2: Nov 30 17:03:17.386: 2c:54:2d:ea:d4:0e 10.123.201.4 8021X_REQD (3) DHCP required on AP 34:bd:c8:b2:b1:10 vapId 144 apVapId 2for this client

*apfMsConnTask_2: Nov 30 17:03:17.386: 2c:54:2d:ea:d4:0e 10.123.201.4 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 34:bd:c8:b2:b1:10 vapId 144 apVapId 2

*apfMsConnTask_2: Nov 30 17:03:17.386: 2c:54:2d:ea:d4:0e apfPemAddUser2 (apf_policy.c:268) Changing state for mobile 2c:54:2d:ea:d4:0e on AP 34:bd:c8:b2:b1:10 from Associated to Associated

*apfMsConnTask_2: Nov 30 17:03:17.386: 2c:54:2d:ea:d4:0e Scheduling deletion of Mobile Station: (callerId: 49) in 1800 seconds

*apfMsConnTask_2: Nov 30 17:03:17.386: 2c:54:2d:ea:d4:0e Sending Assoc Response to station on BSSID 34:bd:c8:b2:b1:10 (status 0) ApVapId 2 Slot 0

*apfMsConnTask_2: Nov 30 17:03:17.386: 2c:54:2d:ea:d4:0e apfProcessAssocReq (apf_80211.c:6290) Changing state for mobile 2c:54:2d:ea:d4:0e on AP 34:bd:c8:b2:b1:10 from Associated to Associated

*dot1xMsgTask: Nov 30 17:03:17.389: 2c:54:2d:ea:d4:0e Creating a PKC PMKID Cache entry for station 2c:54:2d:ea:d4:0e (RSN 0)

*dot1xMsgTask: Nov 30 17:03:17.389: 2c:54:2d:ea:d4:0e Setting active key cache index 0 ---> 8

*dot1xMsgTask: Nov 30 17:03:17.389: 2c:54:2d:ea:d4:0e Setting active key cache index 8 ---> 0

*dot1xMsgTask: Nov 30 17:03:17.389: 2c:54:2d:ea:d4:0e Initiating WPA PSK to mobile 2c:54:2d:ea:d4:0e

*dot1xMsgTask: Nov 30 17:03:17.389: 2c:54:2d:ea:d4:0e dot1x - moving mobile 2c:54:2d:ea:d4:0e into Force Auth state

*dot1xMsgTask: Nov 30 17:03:17.389: 2c:54:2d:ea:d4:0e Skipping EAP-Success to mobile 2c:54:2d:ea:d4:0e

*dot1xMsgTask: Nov 30 17:03:17.389: 2c:54:2d:ea:d4:0e Starting key exchange to mobile 2c:54:2d:ea:d4:0e, data packets will be dropped

*dot1xMsgTask: Nov 30 17:03:17.389: 2c:54:2d:ea:d4:0e Sending EAPOL-Key Message to mobile 2c:54:2d:ea:d4:0e

state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Dot1x_NW_MsgTask_6: Nov 30 17:03:17.422: 2c:54:2d:ea:d4:0e Received EAPOL-Key from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Nov 30 17:03:17.422: 2c:54:2d:ea:d4:0e Received EAPOL-key in PTK_START state (message 2) from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Nov 30 17:03:17.422: 2c:54:2d:ea:d4:0e Stopping retransmission timer for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Nov 30 17:03:17.423: 2c:54:2d:ea:d4:0e Sending EAPOL-Key Message to mobile 2c:54:2d:ea:d4:0e

state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01

*Dot1x_NW_MsgTask_6: Nov 30 17:03:17.433: 2c:54:2d:ea:d4:0e Received EAPOL-Key from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Nov 30 17:03:17.433: 2c:54:2d:ea:d4:0e Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Nov 30 17:03:17.433: 2c:54:2d:ea:d4:0e apfMs1xStateInc

*Dot1x_NW_MsgTask_6: Nov 30 17:03:17.433: 2c:54:2d:ea:d4:0e 10.123.201.4 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Dot1x_NW_MsgTask_6: Nov 30 17:03:17.433: 2c:54:2d:ea:d4:0e 10.123.201.4 L2AUTHCOMPLETE (4) DHCP required on AP 34:bd:c8:b2:b1:10 vapId 144 apVapId 2for this client

*Dot1x_NW_MsgTask_6: Nov 30 17:03:17.433: 2c:54:2d:ea:d4:0e 10.123.201.4 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 34:bd:c8:b2:b1:10 vapId 144 apVapId 2

*Dot1x_NW_MsgTask_6: Nov 30 17:03:17.433: 2c:54:2d:ea:d4:0e apfMsRunStateInc

*Dot1x_NW_MsgTask_6: Nov 30 17:03:17.433: 2c:54:2d:ea:d4:0e 10.123.201.4 L2AUTHCOMPLETE (4) Change state to RUN (20) last state RUN (20)

*Dot1x_NW_MsgTask_6: Nov 30 17:03:17.435: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Reached PLUMBFASTPATH: from line 5362

*Dot1x: Nov 30 17:03:17.435: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Adding Fast Path rule

type = Airespace AP Client

on AP 34:bd:c8:b2:b1:10, slot 0, interface = 1, QOS = 2

IPv4 ACL ID = 255, IPv6 ACL ID = 2

*Dot1x_NW_MsgTask_6: Nov 30 17:03:17.435: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 7006 Local Bridging Vlan = 144, Local Bridging intf id = 12

*Dot1x_NW_MsgTask_6: Nov 30 17:03:17.435: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255)

*Dot1x_NW_MsgTask_6: Nov 30 17:03:17.435: 2c:54:2d:ea:d4:0e Stopping retransmission timer for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Nov 30 17:03:17.435: 2c:54:2d:ea:d4:0e Key exchange done, data packets from mobile 2c:54:2d:ea:d4:0e should be forwarded shortly

*Dot1x_NW_MsgTask_6: Nov 30 17:03:17.435: 2c:54:2d:ea:d4:0e Sending EAPOL-Key Message to mobile 2c:54:2d:ea:d4:0e

state PTKINITDONE (message 5 - group), replay counter 00.00.00.00.00.00.00.02

*spamApTask5: Nov 30 17:03:17.435: 2c:54:2d:ea:d4:0e Sent EAPOL-Key M5 for mobile 2c:54:2d:ea:d4:0e

*pemReceiveTask: Nov 30 17:03:17.435: 2c:54:2d:ea:d4:0e 10.123.201.4 Added NPU entry of type 1, dtlFlags 0x0

*Dot1x_NW_MsgTask_6: Nov 30 17:03:17.447: 2c:54:2d:ea:d4:0e Received EAPOL-Key from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Nov 30 17:03:17.447: 2c:54:2d:ea:d4:0e Received EAPOL-key in REKEYNEGOTIATING state (message 6) from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Nov 30 17:03:17.447: 2c:54:2d:ea:d4:0e Stopping retransmission timer for mobile 2c:54:2d:ea:d4:0e

*emWeb: Nov 30 17:03:46.162: Configuring IPv6 ACL for WLAN:144, aclName passed is NULL

*apfReceiveTask: Nov 30 17:03:46.173: 2c:54:2d:ea:d4:0e apfSendDisAssocMsgDebug (apf_80211.c:2162) Changing state for mobile 2c:54:2d:ea:d4:0e on AP 34:bd:c8:b2:b1:10 from Associated to Disassociated

*apfReceiveTask: Nov 30 17:03:46.178: 2c:54:2d:ea:d4:0e Sent Disassociate to mobile on AP 34:bd:c8:b2:b1:10-0 (reason 1, caller apf_ms.c:5558)

*apfReceiveTask: Nov 30 17:03:46.183: 2c:54:2d:ea:d4:0e Sent Deauthenticate to mobile on BSSID 34:bd:c8:b2:b1:10 slot 0(caller apf_ms.c:5678)

*apfReceiveTask: Nov 30 17:03:46.183: 2c:54:2d:ea:d4:0e apfMsAssoStateDec

*apfReceiveTask: Nov 30 17:03:46.183: 2c:54:2d:ea:d4:0e apfMsExpireMobileStation (apf_ms.c:5716) Changing state for mobile 2c:54:2d:ea:d4:0e on AP 34:bd:c8:b2:b1:10 from Disassociated to Idle

*apfReceiveTask: Nov 30 17:03:46.183: 2c:54:2d:ea:d4:0e pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfReceiveTask: Nov 30 17:03:46.183: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Deleted mobile LWAPP rule on AP [34:bd:c8:b2:b1:10]

*pemReceiveTask: Nov 30 17:03:46.183: 2c:54:2d:ea:d4:0e 10.123.201.4 Removed NPU entry.

*apfReceiveTask: Nov 30 17:03:46.183: 2c:54:2d:ea:d4:0e apfMsRunStateDec

*apfReceiveTask: Nov 30 17:03:46.183: 2c:54:2d:ea:d4:0e apfMs1xStateDec

*apfReceiveTask: Nov 30 17:03:46.183: 2c:54:2d:ea:d4:0e Deleting mobile on AP 34:bd:c8:b2:b1:10(0)

Saravanan Lakshmanan · ‎12-03-2012

Guess i've confused you

configuration is per WLAN but effect is only at per AP. if no client is connected to that AP then no need for rotation so the time ticks as soon as first client connects to the AP that uses WPA is what i believe.

AP uses broadcast encryption key to encrypt broadcast and multicast that sent to clients. wireless client always sends the broadcast and multicast packet as 802.11 unicast packet to AP. so it require broadcast key only to decrypt the broadcast and multicast received from AP. client(s) can't rotate/request for new broadcast key, however only AP can rotate/refresh the broacast key and push it to clients periodically for security reasons.

It is my thinking that it rotates per AP(AP keeps an individual timer) for that WLAN every 1hr by default, it doesn't make sense to rotate on all APs for that WLAN. Also broadcast key can't be same for all APs.

Bottom line: AP has to kick the timer as soon as first client connected and start refreshing the key every one hr until all clients get disconnected.

View solution in original post

Scott Fella · ‎11-30-2012

Peter,

Take a look at this document as it explains how to make you voice more reliable. The other thing is to run your config through the Config Analyzer and see what the analyzer tells you.

https://supportforums.cisco.com/docs/DOC-26863

Config Analyzer:
https://supportforums.cisco.com/docs/DOC-1373

Sent from Cisco Technical Support iPhone App

-Scott
*** Please rate helpful posts ***

Petar Petrov · ‎11-30-2012

Thanks Scott...

Scott Fella · ‎11-30-2012

No problem. Hopefully you figure out the issue.

Sent from Cisco Technical Support iPhone App

-Scott
*** Please rate helpful posts ***

Saravanan Lakshmanan · ‎12-01-2012

Awesome that you posted the wlan config and debug output.

here you go.

GTK Randomization.......................... Enabled

*Dot1x_NW_MsgTask_6: Nov 30 17:03:17.435: 2c:54:2d:ea:d4:0e Sending EAPOL-Key Message to mobile 2c:54:2d:ea:d4:0e

state PTKINITDONE (message 5 - group), replay counter 00.00.00.00.00.00.00.02

Enabling GTK randomization will break the wireless broadcast and multicast, disable this option and you don't see the disconnection issue. With this option enabled there will be disconnection every 1hr where braodcst key rotates and whenever AP pushes the broadcast key to its connect clients on that wlan.

General suggestion:-

currently the session timeout is set to 1800 sec, you can expect disconnection every 30mins for sure.

to achieve fast roaming use 802.1x+cckm instead psk.

Below config is not needed since 792X phones doesn't support 802.11r yet. assuming you're using w.less 792X phones.

FT Reassociation Timeout................... 20

FT Over-The-Air mode....................... Enabled

FT Over-The-Ds mode........................ Enabled

Let know how it goes.

George Stefanick · ‎12-01-2012

Saravanan

What is the default gtk refresh, not using gtk randomizer.

Sent from Cisco Technical Support iPad App

"Satisfaction does not come from knowing the solution, it comes from knowing why." - Rosalind Franklin
___________________________________________________________

Saravanan Lakshmanan · ‎12-03-2012

on WLC, Default broadcast key rotation is 3600secs upto 7.0.98.X.

#Default session timeout 1800 refreshes the broadcast key due to fresh connect.

#Broadcast key rotation support is added from WLC code - 7.0.116.0.

http://tools.cisco.com/Support/BugToolKit/search/getBugDetails.do?method=fetchBugDetails&bugId=CSCsi27596

WLC>config advanced eap bcast-key-interval

George Stefanick · ‎12-03-2012

The broadcast key is shared among all devices on an ap. are you sure the broadcast key gets changed and repopulated when session timeout is hit on a single device ? That doesn't sound right to me ..

Sent from Cisco Technical Support iPhone App

"Satisfaction does not come from knowing the solution, it comes from knowing why." - Rosalind Franklin
___________________________________________________________

Saravanan Lakshmanan · ‎12-03-2012

Thanks George.

broadcast key is per wlan, yes i should have said the client gets same bcast key after fresh connection and gets new key only if the default 1hr or configured timer expires for that wlan on that AP.

George Stefanick · ‎12-03-2012

Really, per WLAN and not per AP? Thanks for the points .. Back at ya .. Keep the info coming !

__________________________________________________________________________________________
"Satisfaction does not come from knowing the solution, it comes from knowing why." - Rosalind Franklin
__________________________________________________________________________________________
‎"I'm in a serious relationship with my Wi-Fi. You could say we have a connection."

"Satisfaction does not come from knowing the solution, it comes from knowing why." - Rosalind Franklin
___________________________________________________________

Saravanan Lakshmanan · ‎12-03-2012

Guess i've confused you

configuration is per WLAN but effect is only at per AP. if no client is connected to that AP then no need for rotation so the time ticks as soon as first client connects to the AP that uses WPA is what i believe.

AP uses broadcast encryption key to encrypt broadcast and multicast that sent to clients. wireless client always sends the broadcast and multicast packet as 802.11 unicast packet to AP. so it require broadcast key only to decrypt the broadcast and multicast received from AP. client(s) can't rotate/request for new broadcast key, however only AP can rotate/refresh the broacast key and push it to clients periodically for security reasons.

It is my thinking that it rotates per AP(AP keeps an individual timer) for that WLAN every 1hr by default, it doesn't make sense to rotate on all APs for that WLAN. Also broadcast key can't be same for all APs.

Bottom line: AP has to kick the timer as soon as first client connected and start refreshing the key every one hr until all clients get disconnected.

Saravanan Lakshmanan · ‎12-03-2012

George, Congratulations!!!

I see that you're little short to enroll on Leaderboard. Will add you to that bin with this +5.

Thanks

Saravanan

George Stefanick · ‎12-04-2012

Good post .. Details .. VIP Endorsed

__________________________________________________________________________________________
"Satisfaction does not come from knowing the solution, it comes from knowing why." - Rosalind Franklin
__________________________________________________________________________________________
‎"I'm in a serious relationship with my Wi-Fi. You could say we have a connection."

"Satisfaction does not come from knowing the solution, it comes from knowing why." - Rosalind Franklin
___________________________________________________________

Petar Petrov · ‎12-07-2012

Hi guys and Saravanan thank for the ideas....

the qualituy is getting better, not satisfactory for the customer though...

I have upgraded the firware as advised to 1.4.3 - I forgot to mention I have 7925g wifi phonee

I set the 802.1x + cckm with eap-fast and WPA2 and definately the quality of the calls got a huge improvement but still not enough. What can be the reason for the confinuing problems during roaming?

Guys, is it possible to set the CCKM without ACS (or WDS - i think that was the second option)

here is some output:

(Cisco Controller) show>wlan 3

WLAN Identifier.................................. 3

Profile Name..................................... test_wifi_144

Network Name (SSID).............................. test144

Status........................................... Enabled

MAC Filtering.................................... Disabled

Broadcast SSID................................... Enabled

AAA Policy Override.............................. Disabled

Network Admission Control

Radius-NAC State............................... Disabled

SNMP-NAC State................................. Disabled

Quarantine VLAN................................ 0

Maximum number of Associated Clients............. 0

Maximum number of Clients per AP Radio........... 200

Number of Active Clients......................... 1

Exclusionlist.................................... Disabled

Session Timeout.................................. 65535 seconds

CHD per WLAN..................................... Enabled

Webauth DHCP exclusion........................... Disabled

Interface........................................ 144_v

--More-- or (q)uit

Multicast Interface.............................. Not Configured

WLAN IPv4 ACL.................................... unconfigured

WLAN IPv6 ACL.................................... unconfigured

DHCP Server...................................... Default

DHCP Address Assignment Required................. Disabled

Static IP client tunneling....................... Disabled

Quality of Service............................... Platinum

Scan Defer Priority.............................. 4,5,6

Scan Defer Time.................................. 100 milliseconds

WMM.............................................. Required

WMM UAPSD Compliant Client Support............... Disabled

Media Stream Multicast-direct.................... Disabled

CCX - AironetIe Support.......................... Enabled

CCX - Gratuitous ProbeResponse (GPR)............. Disabled

CCX - Diagnostics Channel Capability............. Disabled

Dot11-Phone Mode (7920).......................... ap-cac-limit

Wired Protocol................................... None

Passive Client Feature........................... Disabled

Peer-to-Peer Blocking Action..................... Disabled

Radio Policy..................................... 802.11b and 802.11g only

DTIM period for 802.11a radio.................... 2

DTIM period for 802.11b radio.................... 2

Radius Servers

--More-- or (q)uit

Authentication................................ 172.16.106.53 1645

Accounting.................................... Disabled

Dynamic Interface............................. Disabled

Local EAP Authentication......................... Disabled

Security

802.11 Authentication:........................ Open System

Static WEP Keys............................... Disabled

802.1X........................................ Disabled

Wi-Fi Protected Access (WPA/WPA2)............. Enabled

WPA (SSN IE)............................... Disabled

WPA2 (RSN IE).............................. Enabled

TKIP Cipher............................. Disabled

AES Cipher.............................. Enabled

Auth Key Management

802.1x.................................. Enabled

PSK..................................... Disabled

CCKM.................................... Enabled

FT(802.11r)............................. Disabled

FT-PSK(802.11r)......................... Disabled

FT Reassociation Timeout................... 20

FT Over-The-Air mode....................... Enabled

FT Over-The-Ds mode........................ Enabled

--More-- or (q)uit

GTK Randomization.......................... Disabled

SKC Cache Support.......................... Disabled

CCKM TSF Tolerance......................... 1000

Wi-Fi Direct policy configured................ Disabled

EAP-Passthrough............................... Disabled

CKIP ......................................... Disabled

Web Based Authentication...................... Disabled

Web-Passthrough............................... Disabled

Conditional Web Redirect...................... Disabled

Splash-Page Web Redirect...................... Disabled

Auto Anchor................................... Disabled

FlexConnect Local Switching................... Disabled

FlexConnect Local Authentication.............. Disabled

FlexConnect Learn IP Address.................. Enabled

Client MFP.................................... Optional

Tkip MIC Countermeasure Hold-down Timer....... 60

Call Snooping.................................... Disabled

Roamed Call Re-Anchor Policy..................... Disabled

SIP CAC Fail Send-486-Busy Policy................ Enabled

SIP CAC Fail Send Dis-Association Policy......... Disabled

KTS based CAC Policy............................. Disabled

Band Select...................................... Disabled

Load Balancing................................... Disabled

--More-- or (q)uit

Multicast Buffer................................. Disabled

Mobility Anchor List

WLAN ID IP Address Status

------- --------------- ------

802.11u........................................ Disabled

Access Network type............................ Not configured

Network Authentication type.................... Not configured

Internet service............................... Disabled

HESSID......................................... 00:00:00:00:00:00

Hotspot 2.0.................................... Disabled

WAN Metrics configuration

Link status.................................. 0

Link symmetry................................ 0

Downlink speed............................... 0

Uplink speed................................. 0

Mobility Services Advertisement Protocol....... Disabled

(Cisco Controller) >debug client 2C542DEAD40E

*apfMsConnTask_3: Dec 07 13:55:49.522: 2c:54:2d:ea:d4:0e Adding mobile on LWAPP AP 34:bd:c8:b3:d9:f0(0)

*apfMsConnTask_3: Dec 07 13:55:49.522: 2c:54:2d:ea:d4:0e Association received from mobile on AP 34:bd:c8:b3:d9:f0

*apfMsConnTask_3: Dec 07 13:55:49.523: 2c:54:2d:ea:d4:0e 0.0.0.0 START (0) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1697)

*apfMsConnTask_3: Dec 07 13:55:49.523: 2c:54:2d:ea:d4:0e 0.0.0.0 START (0) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1864)

*apfMsConnTask_3: Dec 07 13:55:49.523: 2c:54:2d:ea:d4:0e Applying site-specific Local Bridging override for station 2c:54:2d:ea:d4:0e - vapId 3, site 'Floor_1', interface '144_v'

*apfMsConnTask_3: Dec 07 13:55:49.523: 2c:54:2d:ea:d4:0e Applying Local Bridging Interface Policy for station 2c:54:2d:ea:d4:0e - vlan 144, interface id 12, interface '144_v'

*apfMsConnTask_3: Dec 07 13:55:49.523: 2c:54:2d:ea:d4:0e Applying site-specific override for station 2c:54:2d:ea:d4:0e - vapId 3, site 'Floor_1', interface '144_v'

*apfMsConnTask_3: Dec 07 13:55:49.523: 2c:54:2d:ea:d4:0e 0.0.0.0 START (0) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1697)

*apfMsConnTask_3: Dec 07 13:55:49.523: 2c:54:2d:ea:d4:0e 0.0.0.0 START (0) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1864)

*apfMsConnTask_3: Dec 07 13:55:49.523: 2c:54:2d:ea:d4:0e processSsidIE statusCode is 0 and status is 0

*apfMsConnTask_3: Dec 07 13:55:49.523: 2c:54:2d:ea:d4:0e processSsidIE ssid_done_flag is 0 finish_flag is 0

*apfMsConnTask_3: Dec 07 13:55:49.523: 2c:54:2d:ea:d4:0e STA - rates (4): 130 132 139 150 0 0 0 0 0 0 0 0 0 0 0 0

*apfMsConnTask_3: Dec 07 13:55:49.523: 2c:54:2d:ea:d4:0e suppRates statusCode is 0 and gotSuppRatesElement is 1

*apfMsConnTask_3: Dec 07 13:55:49.523: 2c:54:2d:ea:d4:0e STA - rates (12): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*apfMsConnTask_3: Dec 07 13:55:49.523: 2c:54:2d:ea:d4:0e extSuppRates statusCode is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_3: Dec 07 13:55:49.523: 2c:54:2d:ea:d4:0e Processing RSN IE type 48, length 22 for mobile 2c:54:2d:ea:d4:0e

*apfMsConnTask_3: Dec 07 13:55:49.523: 2c:54:2d:ea:d4:0e CCKM: Mobile is using CCKM

*apfMsConnTask_3: Dec 07 13:55:49.523: 2c:54:2d:ea:d4:0e Received RSN IE with 0 PMKIDs from mobile 2c:54:2d:ea:d4:0e

*apfMsConnTask_3: Dec 07 13:55:49.523: 2c:54:2d:ea:d4:0e Setting active key cache index 8 ---> 8

*apfMsConnTask_3: Dec 07 13:55:49.523: 2c:54:2d:ea:d4:0e unsetting PmkIdValidatedByAp

*apfMsConnTask_3: Dec 07 13:55:49.523: 2c:54:2d:ea:d4:0e 0.0.0.0 START (0) Initializing policy

*apfMsConnTask_3: Dec 07 13:55:49.523: 2c:54:2d:ea:d4:0e 0.0.0.0 START (0) Change state to AUTHCHECK (2) last state AUTHCHECK (2)

*apfMsConnTask_3: Dec 07 13:55:49.523: 2c:54:2d:ea:d4:0e 0.0.0.0 AUTHCHECK (2) Change state to 8021X_REQD (3) last state 8021X_REQD (3)

*apfMsConnTask_3: Dec 07 13:55:49.523: 2c:54:2d:ea:d4:0e 0.0.0.0 8021X_REQD (3) DHCP Not required on AP 34:bd:c8:b3:d9:f0 vapId 3 apVapId 1for this client

*apfMsConnTask_3: Dec 07 13:55:49.524: 2c:54:2d:ea:d4:0e 0.0.0.0 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 34:bd:c8:b3:d9:f0 vapId 3 apVapId 1

*apfMsConnTask_3: Dec 07 13:55:49.524: 2c:54:2d:ea:d4:0e apfMsAssoStateInc

*apfMsConnTask_3: Dec 07 13:55:49.524: 2c:54:2d:ea:d4:0e apfPemAddUser2 (apf_policy.c:268) Changing state for mobile 2c:54:2d:ea:d4:0e on AP 34:bd:c8:b3:d9:f0 from Idle to Associated

*apfMsConnTask_3: Dec 07 13:55:49.524: 2c:54:2d:ea:d4:0e Stopping deletion of Mobile Station: (callerId: 48)

*apfMsConnTask_3: Dec 07 13:55:49.524: 2c:54:2d:ea:d4:0e Sending Assoc Response to station on BSSID 34:bd:c8:b3:d9:f0 (status 0) ApVapId 1 Slot 0

*apfMsConnTask_3: Dec 07 13:55:49.524: 2c:54:2d:ea:d4:0e apfProcessAssocReq (apf_80211.c:6290) Changing state for mobile 2c:54:2d:ea:d4:0e on AP 34:bd:c8:b3:d9:f0 from Associated to Associated

*dot1xMsgTask: Dec 07 13:55:49.525: 2c:54:2d:ea:d4:0e Disable re-auth, use PMK lifetime.

*dot1xMsgTask: Dec 07 13:55:49.525: 2c:54:2d:ea:d4:0e Station 2c:54:2d:ea:d4:0e setting dot1x reauth timeout = 65535

*dot1xMsgTask: Dec 07 13:55:49.525: 2c:54:2d:ea:d4:0e dot1x - moving mobile 2c:54:2d:ea:d4:0e into Connecting state

*dot1xMsgTask: Dec 07 13:55:49.525: 2c:54:2d:ea:d4:0e Sending EAP-Request/Identity to mobile 2c:54:2d:ea:d4:0e (EAP Id 1)

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.574: 2c:54:2d:ea:d4:0e Received EAPOL EAPPKT from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.574: 2c:54:2d:ea:d4:0e Received Identity Response (count=1) from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.574: 2c:54:2d:ea:d4:0e EAP State update from Connecting to Authenticating for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.574: 2c:54:2d:ea:d4:0e dot1x - moving mobile 2c:54:2d:ea:d4:0e into Authenticating state

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.574: 2c:54:2d:ea:d4:0e Entering Backend Auth Response state for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.583: 2c:54:2d:ea:d4:0e Processing Access-Challenge for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.583: 2c:54:2d:ea:d4:0e Entering Backend Auth Req state (id=85) for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.583: 2c:54:2d:ea:d4:0e WARNING: updated EAP-Identifier 1 ===> 85 for STA 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.583: 2c:54:2d:ea:d4:0e Sending EAP Request from AAA to mobile 2c:54:2d:ea:d4:0e (EAP Id 85)

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.591: 2c:54:2d:ea:d4:0e Received EAPOL EAPPKT from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.591: 2c:54:2d:ea:d4:0e Received EAP Response from mobile 2c:54:2d:ea:d4:0e (EAP Id 85, EAP Type 3)

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.591: 2c:54:2d:ea:d4:0e Entering Backend Auth Response state for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.602: 2c:54:2d:ea:d4:0e Processing Access-Challenge for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.602: 2c:54:2d:ea:d4:0e Entering Backend Auth Req state (id=86) for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.602: 2c:54:2d:ea:d4:0e Sending EAP Request from AAA to mobile 2c:54:2d:ea:d4:0e (EAP Id 86)

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.621: 2c:54:2d:ea:d4:0e Received EAPOL EAPPKT from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.621: 2c:54:2d:ea:d4:0e Received EAP Response from mobile 2c:54:2d:ea:d4:0e (EAP Id 86, EAP Type 43)

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.621: 2c:54:2d:ea:d4:0e Entering Backend Auth Response state for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.625: 2c:54:2d:ea:d4:0e Processing Access-Challenge for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.625: 2c:54:2d:ea:d4:0e Entering Backend Auth Req state (id=87) for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.625: 2c:54:2d:ea:d4:0e Sending EAP Request from AAA to mobile 2c:54:2d:ea:d4:0e (EAP Id 87)

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.653: 2c:54:2d:ea:d4:0e Received EAPOL EAPPKT from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.653: 2c:54:2d:ea:d4:0e Received EAP Response from mobile 2c:54:2d:ea:d4:0e (EAP Id 87, EAP Type 43)

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.653: 2c:54:2d:ea:d4:0e Entering Backend Auth Response state for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.655: 2c:54:2d:ea:d4:0e Processing Access-Challenge for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.655: 2c:54:2d:ea:d4:0e Entering Backend Auth Req state (id=89) for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.655: 2c:54:2d:ea:d4:0e WARNING: updated EAP-Identifier 87 ===> 89 for STA 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.655: 2c:54:2d:ea:d4:0e Sending EAP Request from AAA to mobile 2c:54:2d:ea:d4:0e (EAP Id 89)

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.671: 2c:54:2d:ea:d4:0e Received EAPOL EAPPKT from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.671: 2c:54:2d:ea:d4:0e Received EAP Response from mobile 2c:54:2d:ea:d4:0e (EAP Id 89, EAP Type 43)

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.671: 2c:54:2d:ea:d4:0e Entering Backend Auth Response state for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.676: 2c:54:2d:ea:d4:0e Processing Access-Challenge for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.676: 2c:54:2d:ea:d4:0e Entering Backend Auth Req state (id=90) for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.676: 2c:54:2d:ea:d4:0e Sending EAP Request from AAA to mobile 2c:54:2d:ea:d4:0e (EAP Id 90)

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.691: 2c:54:2d:ea:d4:0e Received EAPOL EAPPKT from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.691: 2c:54:2d:ea:d4:0e Received EAP Response from mobile 2c:54:2d:ea:d4:0e (EAP Id 90, EAP Type 43)

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.691: 2c:54:2d:ea:d4:0e Entering Backend Auth Response state for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.702: 2c:54:2d:ea:d4:0e Processing Access-Accept for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.703: 2c:54:2d:ea:d4:0e Resetting web IPv4 acl from 255 to 255

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.703: 2c:54:2d:ea:d4:0e Username entry (test960) created for mobile, length = 253

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.703: 2c:54:2d:ea:d4:0e Username entry (test960) created in mscb for mobile, length = 253

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.703: 2c:54:2d:ea:d4:0e Setting re-auth timeout to 65535 seconds, got from WLAN config.

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.703: 2c:54:2d:ea:d4:0e Station 2c:54:2d:ea:d4:0e setting dot1x reauth timeout = 65535

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.703: 2c:54:2d:ea:d4:0e Creating a PKC PMKID Cache entry for station 2c:54:2d:ea:d4:0e (RSN 2)

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.703: 2c:54:2d:ea:d4:0e Resetting MSCB PMK Cache Entry 0 for station 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.703: 2c:54:2d:ea:d4:0e Setting active key cache index 8 ---> 8

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.703: 2c:54:2d:ea:d4:0e Setting active key cache index 8 ---> 0

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.703: 2c:54:2d:ea:d4:0e Adding BSSID 34:bd:c8:b3:d9:f0 to PMKID cache at index 0 for station 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.703: New PMKID: (16)

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.703: [0000] ab 8f b5 75 ad c5 8e af 50 0d ce 4a f1 7b 16 9e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.703: 2c:54:2d:ea:d4:0e Disabling re-auth since PMK lifetime can take care of same.

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.703: 2c:54:2d:ea:d4:0e CCKM: Create a global PMK cache entry

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.703: 2c:54:2d:ea:d4:0e unsetting PmkIdValidatedByAp

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.703: 2c:54:2d:ea:d4:0e Sending EAP-Success to mobile 2c:54:2d:ea:d4:0e (EAP Id 90)

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.703: 2c:54:2d:ea:d4:0e Found an cache entry for BSSID 34:bd:c8:b3:d9:f0 in PMKID cache at index 0 of station 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.703: Including PMKID in M1 (16)

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.703: [0000] ab 8f b5 75 ad c5 8e af 50 0d ce 4a f1 7b 16 9e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.703: 2c:54:2d:ea:d4:0e Starting key exchange to mobile 2c:54:2d:ea:d4:0e, data packets will be dropped

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.703: 2c:54:2d:ea:d4:0e Sending EAPOL-Key Message to mobile 2c:54:2d:ea:d4:0e

state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.703: 2c:54:2d:ea:d4:0e Entering Backend Auth Success state (id=90) for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.703: 2c:54:2d:ea:d4:0e Received Auth Success while in Authenticating state for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.704: 2c:54:2d:ea:d4:0e dot1x - moving mobile 2c:54:2d:ea:d4:0e into Authenticated state

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.721: 2c:54:2d:ea:d4:0e Received EAPOL-Key from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.721: 2c:54:2d:ea:d4:0e Received EAPOL-key in PTK_START state (message 2) from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.721: 2c:54:2d:ea:d4:0e CCKM: Sending cache add

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.721: CCKM: Sending CCKM PMK (Version_1) information to mobility group

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.721: CCKM: Sending CCKM PMK (Version_2) information to mobility group

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.721: 2c:54:2d:ea:d4:0e Stopping retransmission timer for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.721: 2c:54:2d:ea:d4:0e Sending EAPOL-Key Message to mobile 2c:54:2d:ea:d4:0e

state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.741: 2c:54:2d:ea:d4:0e Received EAPOL-Key from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.741: 2c:54:2d:ea:d4:0e Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.741: 2c:54:2d:ea:d4:0e apfMs1xStateInc

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.741: 2c:54:2d:ea:d4:0e 0.0.0.0 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state L2AUTHCOMPLETE (4)

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.741: 2c:54:2d:ea:d4:0e 0.0.0.0 L2AUTHCOMPLETE (4) DHCP Not required on AP 34:bd:c8:b3:d9:f0 vapId 3 apVapId 1for this client

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.741: 2c:54:2d:ea:d4:0e 0.0.0.0 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 34:bd:c8:b3:d9:f0 vapId 3 apVapId 1

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.741: 2c:54:2d:ea:d4:0e 0.0.0.0 L2AUTHCOMPLETE (4) Change state to DHCP_REQD (7) last state DHCP_REQD (7)

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.741: 2c:54:2d:ea:d4:0e 0.0.0.0 DHCP_REQD (7) pemAdvanceState2 5253, Adding TMP rule

*Dot1x_NW_MsgTask_: Dec 07 13:55:49.741: 2c:54:2d:ea:d4:0e 0.0.0.0 DHCP_REQD (7) Adding Fast Path rule

type = Airespace AP - Learn IP address

on AP 34:bd:c8:b3:d9:f0, slot 0, interface = 1, QOS = 2

IPv4 ACL ID = 255, IPv

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.741: 2c:54:2d:ea:d4:0e 0.0.0.0 DHCP_REQD (7) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 7006 Local Bridging Vlan = 144, Local Bridging intf id = 12

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.741: 2c:54:2d:ea:d4:0e 0.0.0.0 DHCP_REQD (7) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255)

*Dot1x_NW_MsgTask_6: Dec 07 13:55:49.741: 2c:54:2d:ea:d4:0e Stopping retransmission timer for mobile 2c:54:2d:ea:d4:0e

*apfReceiveTask: Dec 07 13:55:49.741: 2c:54:2d:ea:d4:0e 0.0.0.0 DHCP_REQD (7) State Update from Mobility-Incomplete to Mobility-Complete, mobility role=Local, client state=APF_MS_STATE_ASSOCIATED

*apfReceiveTask: Dec 07 13:55:49.741: 2c:54:2d:ea:d4:0e 0.0.0.0 DHCP_REQD (7) pemAdvanceState2 4891, Adding TMP rule

*apfReceiveTask: Dec 07 13:55:49.742: 2c:54:2d:ea:d4:0e 0.0.0.0 DHCP_REQD (7) Replacing Fast Path rule

type = Airespace AP - Learn IP address

on AP 34:bd:c8:b3:d9:f0, slot 0, interface = 1, QOS = 2

IPv4 ACL ID = 255,

*apfReceiveTask: Dec 07 13:55:49.742: 2c:54:2d:ea:d4:0e 0.0.0.0 DHCP_REQD (7) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 7006 Local Bridging Vlan = 144, Local Bridging intf id = 12

*apfReceiveTask: Dec 07 13:55:49.742: 2c:54:2d:ea:d4:0e 0.0.0.0 DHCP_REQD (7) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255)

*pemReceiveTask: Dec 07 13:55:49.742: 2c:54:2d:ea:d4:0e 0.0.0.0 Added NPU entry of type 9, dtlFlags 0x0

*pemReceiveTask: Dec 07 13:55:49.742: 2c:54:2d:ea:d4:0e Sent an XID frame

*pemReceiveTask: Dec 07 13:55:49.742: 2c:54:2d:ea:d4:0e 0.0.0.0 Added NPU entry of type 9, dtlFlags 0x0

*pemReceiveTask: Dec 07 13:55:49.742: 2c:54:2d:ea:d4:0e Sent an XID frame

*DHCP Socket Task: Dec 07 13:55:50.513: 2c:54:2d:ea:d4:0e DHCP received op BOOTREQUEST (1) (len 556,vlan 0, port 1, encap 0xec03)

*DHCP Socket Task: Dec 07 13:55:50.513: 2c:54:2d:ea:d4:0e DHCP selecting relay 1 - control block settings:

dhcpServer: 0.0.0.0, dhcpNetmask: 0.0.0.0,

dhcpGateway: 0.0.0.0, dhcpRelay: 0.0.0.0 VLAN: 0

*DHCP Socket Task: Dec 07 13:55:50.513: 2c:54:2d:ea:d4:0e DHCP selected relay 1 - 172.16.100.121 (local address 10.123.200.15, gateway 10.123.200.1, VLAN 144, port 1)

*DHCP Socket Task: Dec 07 13:55:50.513: 2c:54:2d:ea:d4:0e DHCP transmitting DHCP DISCOVER (1)

*DHCP Socket Task: Dec 07 13:55:50.513: 2c:54:2d:ea:d4:0e DHCP op: BOOTREQUEST, htype: Ethernet, hlen: 6, hops: 1

*DHCP Socket Task: Dec 07 13:55:50.513: 2c:54:2d:ea:d4:0e DHCP xid: 0xf12d461 (252892257), secs: 0, flags: 0

*DHCP Socket Task: Dec 07 13:55:50.514: 2c:54:2d:ea:d4:0e DHCP chaddr: 2c:54:2d:ea:d4:0e

*DHCP Socket Task: Dec 07 13:55:50.514: 2c:54:2d:ea:d4:0e DHCP ciaddr: 0.0.0.0, yiaddr: 0.0.0.0

*DHCP Socket Task: Dec 07 13:55:50.514: 2c:54:2d:ea:d4:0e DHCP siaddr: 0.0.0.0, giaddr: 10.123.200.15

*DHCP Socket Task: Dec 07 13:55:50.514: 2c:54:2d:ea:d4:0e DHCP requested ip: 10.123.205.33

*DHCP Socket Task: Dec 07 13:55:50.514: 2c:54:2d:ea:d4:0e DHCP ARPing for 10.123.200.1 (SPA 10.123.200.15, vlanId 144)

*DHCP Socket Task: Dec 07 13:55:50.514: 2c:54:2d:ea:d4:0e DHCP selecting relay 2 - control block settings:

dhcpServer: 0.0.0.0, dhcpNetmask: 0.0.0.0,

dhcpGateway: 0.0.0.0, dhcpRelay: 10.123.200.15 VLAN: 144

*DHCP Socket Task: Dec 07 13:55:50.514: 2c:54:2d:ea:d4:0e DHCP selected relay 2 - 172.16.100.122 (local address 10.123.200.15, gateway 10.123.200.1, VLAN 144, port 1)

*DHCP Socket Task: Dec 07 13:55:50.514: 2c:54:2d:ea:d4:0e DHCP transmitting DHCP DISCOVER (1)

*DHCP Socket Task: Dec 07 13:55:50.514: 2c:54:2d:ea:d4:0e DHCP op: BOOTREQUEST, htype: Ethernet, hlen: 6, hops: 2

*DHCP Socket Task: Dec 07 13:55:50.514: 2c:54:2d:ea:d4:0e DHCP xid: 0xf12d461 (252892257), secs: 0, flags: 0

*DHCP Socket Task: Dec 07 13:55:50.514: 2c:54:2d:ea:d4:0e DHCP chaddr: 2c:54:2d:ea:d4:0e

*DHCP Socket Task: Dec 07 13:55:50.514: 2c:54:2d:ea:d4:0e DHCP ciaddr: 0.0.0.0, yiaddr: 0.0.0.0

*DHCP Socket Task: Dec 07 13:55:50.514: 2c:54:2d:ea:d4:0e DHCP siaddr: 0.0.0.0, giaddr: 10.123.200.15

*DHCP Socket Task: Dec 07 13:55:50.514: 2c:54:2d:ea:d4:0e DHCP requested ip: 10.123.205.33

*DHCP Socket Task: Dec 07 13:55:50.514: 2c:54:2d:ea:d4:0e DHCP ARPing for 10.123.200.1 (SPA 10.123.200.15, vlanId 144)

*DHCP Socket Task: Dec 07 13:55:52.512: 2c:54:2d:ea:d4:0e DHCP received op BOOTREQUEST (1) (len 556,vlan 0, port 1, encap 0xec03)

*DHCP Socket Task: Dec 07 13:55:52.512: 2c:54:2d:ea:d4:0e DHCP selecting relay 1 - control block settings:

dhcpServer: 0.0.0.0, dhcpNetmask: 0.0.0.0,

dhcpGateway: 0.0.0.0, dhcpRelay: 10.123.200.15 VLAN: 144

*DHCP Socket Task: Dec 07 13:55:52.512: 2c:54:2d:ea:d4:0e DHCP selected relay 1 - 172.16.100.121 (local address 10.123.200.15, gateway 10.123.200.1, VLAN 144, port 1)

*DHCP Socket Task: Dec 07 13:55:52.512: 2c:54:2d:ea:d4:0e DHCP transmitting DHCP DISCOVER (1)

*DHCP Socket Task: Dec 07 13:55:52.512: 2c:54:2d:ea:d4:0e DHCP op: BOOTREQUEST, htype: Ethernet, hlen: 6, hops: 1

*DHCP Socket Task: Dec 07 13:55:52.512: 2c:54:2d:ea:d4:0e DHCP xid: 0xf12d461 (252892257), secs: 0, flags: 0

*DHCP Socket Task: Dec 07 13:55:52.512: 2c:54:2d:ea:d4:0e DHCP chaddr: 2c:54:2d:ea:d4:0e

*DHCP Socket Task: Dec 07 13:55:52.512: 2c:54:2d:ea:d4:0e DHCP ciaddr: 0.0.0.0, yiaddr: 0.0.0.0

*DHCP Socket Task: Dec 07 13:55:52.512: 2c:54:2d:ea:d4:0e DHCP siaddr: 0.0.0.0, giaddr: 10.123.200.15

*DHCP Socket Task: Dec 07 13:55:52.512: 2c:54:2d:ea:d4:0e DHCP requested ip: 10.123.205.33

*DHCP Socket Task: Dec 07 13:55:52.513: 2c:54:2d:ea:d4:0e DHCP sending REQUEST to 10.123.200.1 (len 374, port 1, vlan 144)

*DHCP Socket Task: Dec 07 13:55:52.513: 2c:54:2d:ea:d4:0e DHCP selecting relay 2 - control block settings:

dhcpServer: 0.0.0.0, dhcpNetmask: 0.0.0.0,

dhcpGateway: 0.0.0.0, dhcpRelay: 10.123.200.15 VLAN: 144

*DHCP Socket Task: Dec 07 13:55:52.513: 2c:54:2d:ea:d4:0e DHCP selected relay 2 - 172.16.100.122 (local address 10.123.200.15, gateway 10.123.200.1, VLAN 144, port 1)

*DHCP Socket Task: Dec 07 13:55:52.513: 2c:54:2d:ea:d4:0e DHCP transmitting DHCP DISCOVER (1)

*DHCP Socket Task: Dec 07 13:55:52.513: 2c:54:2d:ea:d4:0e DHCP op: BOOTREQUEST, htype: Ethernet, hlen: 6, hops: 2

*DHCP Socket Task: Dec 07 13:55:52.513: 2c:54:2d:ea:d4:0e DHCP xid: 0xf12d461 (252892257), secs: 0, flags: 0

*DHCP Socket Task: Dec 07 13:55:52.513: 2c:54:2d:ea:d4:0e DHCP chaddr: 2c:54:2d:ea:d4:0e

*DHCP Socket Task: Dec 07 13:55:52.513: 2c:54:2d:ea:d4:0e DHCP ciaddr: 0.0.0.0, yiaddr: 0.0.0.0

*DHCP Socket Task: Dec 07 13:55:52.513: 2c:54:2d:ea:d4:0e DHCP siaddr: 0.0.0.0, giaddr: 10.123.200.15

*DHCP Socket Task: Dec 07 13:55:52.513: 2c:54:2d:ea:d4:0e DHCP requested ip: 10.123.205.33

*DHCP Socket Task: Dec 07 13:55:52.513: 2c:54:2d:ea:d4:0e DHCP sending REQUEST to 10.123.200.1 (len 374, port 1, vlan 144)

*DHCP Socket Task: Dec 07 13:55:52.513: 2c:54:2d:ea:d4:0e DHCP received op BOOTREPLY (2) (len 322,vlan 144, port 1, encap 0xec00)

*DHCP Socket Task: Dec 07 13:55:52.513: 2c:54:2d:ea:d4:0e DHCP setting server from OFFER (server 172.16.100.121, yiaddr 10.123.201.4)

*DHCP Socket Task: Dec 07 13:55:52.513: 2c:54:2d:ea:d4:0e DHCP sending REPLY to STA (len 430, port 1, vlan 0)

*DHCP Socket Task: Dec 07 13:55:52.513: 2c:54:2d:ea:d4:0e DHCP transmitting DHCP OFFER (2)

*DHCP Socket Task: Dec 07 13:55:52.513: 2c:54:2d:ea:d4:0e DHCP op: BOOTREPLY, htype: Ethernet, hlen: 6, hops: 0

*DHCP Socket Task: Dec 07 13:55:52.513: 2c:54:2d:ea:d4:0e DHCP xid: 0xf12d461 (252892257), secs: 0, flags: 0

*DHCP Socket Task: Dec 07 13:55:52.513: 2c:54:2d:ea:d4:0e DHCP chaddr: 2c:54:2d:ea:d4:0e

*DHCP Socket Task: Dec 07 13:55:52.513: 2c:54:2d:ea:d4:0e DHCP ciaddr: 0.0.0.0, yiaddr: 10.123.201.4

*DHCP Socket Task: Dec 07 13:55:52.513: 2c:54:2d:ea:d4:0e DHCP siaddr: 0.0.0.0, giaddr: 0.0.0.0

*DHCP Socket Task: Dec 07 13:55:52.513: 2c:54:2d:ea:d4:0e DHCP server id: 1.1.1.1 rcvd server id: 172.16.100.121

*DHCP Socket Task: Dec 07 13:55:52.514: 2c:54:2d:ea:d4:0e DHCP received op BOOTREPLY (2) (len 322,vlan 144, port 1, encap 0xec00)

*DHCP Socket Task: Dec 07 13:55:52.514: 2c:54:2d:ea:d4:0e DHCP dropping OFFER from 172.16.100.122 (yiaddr 10.123.205.33)

*DHCP Socket Task: Dec 07 13:55:52.523: 2c:54:2d:ea:d4:0e DHCP received op BOOTREQUEST (1) (len 556,vlan 0, port 1, encap 0xec03)

*DHCP Socket Task: Dec 07 13:55:52.523: 2c:54:2d:ea:d4:0e DHCP selecting relay 1 - control block settings:

dhcpServer: 172.16.100.121, dhcpNetmask: 0.0.0.0,

dhcpGateway: 0.0.0.0, dhcpRelay: 10.123.200.15 VLAN: 144

*DHCP Socket Task: Dec 07 13:55:52.523: 2c:54:2d:ea:d4:0e DHCP selected relay 1 - 172.16.100.121 (local address 10.123.200.15, gateway 10.123.200.1, VLAN 144, port 1)

*DHCP Socket Task: Dec 07 13:55:52.523: 2c:54:2d:ea:d4:0e DHCP transmitting DHCP REQUEST (3)

*DHCP Socket Task: Dec 07 13:55:52.524: 2c:54:2d:ea:d4:0e DHCP op: BOOTREQUEST, htype: Ethernet, hlen: 6, hops: 1

*DHCP Socket Task: Dec 07 13:55:52.524: 2c:54:2d:ea:d4:0e DHCP xid: 0xf12d461 (252892257), secs: 0, flags: 0

*DHCP Socket Task: Dec 07 13:55:52.524: 2c:54:2d:ea:d4:0e DHCP chaddr: 2c:54:2d:ea:d4:0e

*DHCP Socket Task: Dec 07 13:55:52.524: 2c:54:2d:ea:d4:0e DHCP ciaddr: 0.0.0.0, yiaddr: 0.0.0.0

*DHCP Socket Task: Dec 07 13:55:52.524: 2c:54:2d:ea:d4:0e DHCP siaddr: 0.0.0.0, giaddr: 10.123.200.15

*DHCP Socket Task: Dec 07 13:55:52.524: 2c:54:2d:ea:d4:0e DHCP requested ip: 10.123.201.4

*DHCP Socket Task: Dec 07 13:55:52.524: 2c:54:2d:ea:d4:0e DHCP server id: 172.16.100.121 rcvd server id: 1.1.1.1

*DHCP Socket Task: Dec 07 13:55:52.524: 2c:54:2d:ea:d4:0e DHCP sending REQUEST to 10.123.200.1 (len 382, port 1, vlan 144)

*DHCP Socket Task: Dec 07 13:55:52.524: 2c:54:2d:ea:d4:0e DHCP selecting relay 2 - control block settings:

dhcpServer: 172.16.100.121, dhcpNetmask: 0.0.0.0,

dhcpGateway: 0.0.0.0, dhcpRelay: 10.123.200.15 VLAN: 144

*DHCP Socket Task: Dec 07 13:55:52.524: 2c:54:2d:ea:d4:0e DHCP selected relay 2 - NONE

*DHCP Socket Task: Dec 07 13:55:52.524: 2c:54:2d:ea:d4:0e DHCP received op BOOTREPLY (2) (len 322,vlan 144, port 1, encap 0xec00)

*DHCP Socket Task: Dec 07 13:55:52.525: 2c:54:2d:ea:d4:0e Static IP client associated to interface 144_v which can support client subnet.

*DHCP Socket Task: Dec 07 13:55:52.525: 2c:54:2d:ea:d4:0e apfMsRunStateInc

*DHCP Socket Task: Dec 07 13:55:52.525: 2c:54:2d:ea:d4:0e 10.123.201.4 DHCP_REQD (7) Change state to RUN (20) last state RUN (20)

*DHCP Socket Task: Dec 07 13:55:52.526: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Reached PLUMBFASTPATH: from line 5776

*DHCP Soc: Dec 07 13:55:52.526: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Replacing Fast Path rule

type = Airespace AP Client

on AP 34:bd:c8:b3:d9:f0, slot 0, interface = 1, QOS = 2

IPv4 ACL ID = 255, IPv6 ACL ID

*DHCP Socket Task: Dec 07 13:55:52.526: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 7006 Local Bridging Vlan = 144, Local Bridging intf id = 12

*DHCP Socket Task: Dec 07 13:55:52.526: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255)

*DHCP Socket Task: Dec 07 13:55:52.526: 2c:54:2d:ea:d4:0e Assigning Address 10.123.201.4 to mobile

*DHCP Socket Task: Dec 07 13:55:52.526: 2c:54:2d:ea:d4:0e DHCP success event for client. Clearing dhcp failure count for interface 144_v.

*DHCP Socket Task: Dec 07 13:55:52.526: 2c:54:2d:ea:d4:0e DHCP sending REPLY to STA (len 430, port 1, vlan 0)

*DHCP Socket Task: Dec 07 13:55:52.526: 2c:54:2d:ea:d4:0e DHCP transmitting DHCP ACK (5)

*DHCP Socket Task: Dec 07 13:55:52.526: 2c:54:2d:ea:d4:0e DHCP op: BOOTREPLY, htype: Ethernet, hlen: 6, hops: 0

*DHCP Socket Task: Dec 07 13:55:52.526: 2c:54:2d:ea:d4:0e DHCP xid: 0xf12d461 (252892257), secs: 0, flags: 0

*DHCP Socket Task: Dec 07 13:55:52.526: 2c:54:2d:ea:d4:0e DHCP chaddr: 2c:54:2d:ea:d4:0e

*DHCP Socket Task: Dec 07 13:55:52.526: 2c:54:2d:ea:d4:0e DHCP ciaddr: 0.0.0.0, yiaddr: 10.123.201.4

*DHCP Socket Task: Dec 07 13:55:52.526: 2c:54:2d:ea:d4:0e DHCP siaddr: 0.0.0.0, giaddr: 0.0.0.0

*DHCP Socket Task: Dec 07 13:55:52.527: 2c:54:2d:ea:d4:0e DHCP server id: 1.1.1.1 rcvd server id: 172.16.100.121

*pemReceiveTask: Dec 07 13:55:52.527: 2c:54:2d:ea:d4:0e 10.123.201.4 Added NPU entry of type 1, dtlFlags 0x10

*pemReceiveTask: Dec 07 13:55:52.527: 2c:54:2d:ea:d4:0e Sending a gratuitous ARP for 10.123.201.4, VLAN Id 144

*apfMsConnTask_3: Dec 07 13:57:01.509: 2c:54:2d:ea:d4:0e Association received from mobile on AP 34:bd:c8:b3:d9:f0

*apfMsConnTask_3: Dec 07 13:57:01.509: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1697)

*apfMsConnTask_3: Dec 07 13:57:01.509: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1864)

*apfMsConnTask_3: Dec 07 13:57:01.509: 2c:54:2d:ea:d4:0e Applying site-specific Local Bridging override for station 2c:54:2d:ea:d4:0e - vapId 3, site 'Floor_1', interface '144_v'

*apfMsConnTask_3: Dec 07 13:57:01.509: 2c:54:2d:ea:d4:0e Applying Local Bridging Interface Policy for station 2c:54:2d:ea:d4:0e - vlan 144, interface id 12, interface '144_v'

*apfMsConnTask_3: Dec 07 13:57:01.509: 2c:54:2d:ea:d4:0e Applying site-specific override for station 2c:54:2d:ea:d4:0e - vapId 3, site 'Floor_1', interface '144_v'

*apfMsConnTask_3: Dec 07 13:57:01.509: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1697)

*apfMsConnTask_3: Dec 07 13:57:01.509: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1864)

*apfMsConnTask_3: Dec 07 13:57:01.509: 2c:54:2d:ea:d4:0e processSsidIE statusCode is 0 and status is 0

*apfMsConnTask_3: Dec 07 13:57:01.509: 2c:54:2d:ea:d4:0e processSsidIE ssid_done_flag is 0 finish_flag is 0

*apfMsConnTask_3: Dec 07 13:57:01.509: 2c:54:2d:ea:d4:0e STA - rates (4): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*apfMsConnTask_3: Dec 07 13:57:01.509: 2c:54:2d:ea:d4:0e suppRates statusCode is 0 and gotSuppRatesElement is 1

*apfMsConnTask_3: Dec 07 13:57:01.509: 2c:54:2d:ea:d4:0e STA - rates (12): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*apfMsConnTask_3: Dec 07 13:57:01.509: 2c:54:2d:ea:d4:0e extSuppRates statusCode is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_3: Dec 07 13:57:01.509: 2c:54:2d:ea:d4:0e Processing RSN IE type 48, length 22 for mobile 2c:54:2d:ea:d4:0e

*apfMsConnTask_3: Dec 07 13:57:01.509: 2c:54:2d:ea:d4:0e CCKM: Mobile is using CCKM

*apfMsConnTask_3: Dec 07 13:57:01.509: 2c:54:2d:ea:d4:0e Received RSN IE with 0 PMKIDs from mobile 2c:54:2d:ea:d4:0e

*apfMsConnTask_3: Dec 07 13:57:01.509: 2c:54:2d:ea:d4:0e Found an cache entry for BSSID 34:bd:c8:b3:d9:f0 in PMKID cache at index 0 of station 2c:54:2d:ea:d4:0e

*apfMsConnTask_3: Dec 07 13:57:01.509: 2c:54:2d:ea:d4:0e Removing BSSID 34:bd:c8:b3:d9:f0 from PMKID cache of station 2c:54:2d:ea:d4:0e

*apfMsConnTask_3: Dec 07 13:57:01.509: 2c:54:2d:ea:d4:0e Resetting MSCB PMK Cache Entry 0 for station 2c:54:2d:ea:d4:0e

*apfMsConnTask_3: Dec 07 13:57:01.509: 2c:54:2d:ea:d4:0e Setting active key cache index 0 ---> 8

*apfMsConnTask_3: Dec 07 13:57:01.510: 2c:54:2d:ea:d4:0e unsetting PmkIdValidatedByAp

*apfMsConnTask_3: Dec 07 13:57:01.510: 2c:54:2d:ea:d4:0e apfMsRunStateDec

*apfMsConnTask_3: Dec 07 13:57:01.510: 2c:54:2d:ea:d4:0e apfMs1xStateDec

*apfMsConnTask_3: Dec 07 13:57:01.510: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Change state to START (0) last state RUN (20)

*apfMsConnTask_3: Dec 07 13:57:01.510: 2c:54:2d:ea:d4:0e pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_3: Dec 07 13:57:01.510: 2c:54:2d:ea:d4:0e 10.123.201.4 START (0) Initializing policy

*apfMsConnTask_3: Dec 07 13:57:01.510: 2c:54:2d:ea:d4:0e 10.123.201.4 START (0) Change state to AUTHCHECK (2) last state RUN (20)

*apfMsConnTask_3: Dec 07 13:57:01.510: 2c:54:2d:ea:d4:0e 10.123.201.4 AUTHCHECK (2) Change state to 8021X_REQD (3) last state RUN (20)

*apfMsConnTask_3: Dec 07 13:57:01.510: 2c:54:2d:ea:d4:0e 10.123.201.4 8021X_REQD (3) DHCP required on AP 34:bd:c8:b3:d9:f0 vapId 3 apVapId 1for this client

*apfMsConnTask_3: Dec 07 13:57:01.510: 2c:54:2d:ea:d4:0e 10.123.201.4 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 34:bd:c8:b3:d9:f0 vapId 3 apVapId 1

*apfMsConnTask_3: Dec 07 13:57:01.510: 2c:54:2d:ea:d4:0e apfPemAddUser2 (apf_policy.c:268) Changing state for mobile 2c:54:2d:ea:d4:0e on AP 34:bd:c8:b3:d9:f0 from Associated to Associated

*apfMsConnTask_3: Dec 07 13:57:01.510: 2c:54:2d:ea:d4:0e Stopping deletion of Mobile Station: (callerId: 48)

*apfMsConnTask_3: Dec 07 13:57:01.510: 2c:54:2d:ea:d4:0e Sending Assoc Response to station on BSSID 34:bd:c8:b3:d9:f0 (status 0) ApVapId 1 Slot 0

*apfMsConnTask_3: Dec 07 13:57:01.510: 2c:54:2d:ea:d4:0e apfProcessAssocReq (apf_80211.c:6290) Changing state for mobile 2c:54:2d:ea:d4:0e on AP 34:bd:c8:b3:d9:f0 from Associated to Associated

*dot1xMsgTask: Dec 07 13:57:01.512: 2c:54:2d:ea:d4:0e Disable re-auth, use PMK lifetime.

*dot1xMsgTask: Dec 07 13:57:01.512: 2c:54:2d:ea:d4:0e dot1x - moving mobile 2c:54:2d:ea:d4:0e into Connecting state

*dot1xMsgTask: Dec 07 13:57:01.512: 2c:54:2d:ea:d4:0e Sending EAP-Request/Identity to mobile 2c:54:2d:ea:d4:0e (EAP Id 1)

*pemReceiveTask: Dec 07 13:57:01.513: 2c:54:2d:ea:d4:0e 10.123.201.4 Removed NPU entry.

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.654: 2c:54:2d:ea:d4:0e Received EAPOL EAPPKT from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.654: 2c:54:2d:ea:d4:0e Received Identity Response (count=1) from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.654: 2c:54:2d:ea:d4:0e EAP State update from Connecting to Authenticating for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.654: 2c:54:2d:ea:d4:0e dot1x - moving mobile 2c:54:2d:ea:d4:0e into Authenticating state

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.654: 2c:54:2d:ea:d4:0e Entering Backend Auth Response state for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.684: 2c:54:2d:ea:d4:0e Processing Access-Challenge for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.684: 2c:54:2d:ea:d4:0e Entering Backend Auth Req state (id=86) for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.684: 2c:54:2d:ea:d4:0e WARNING: updated EAP-Identifier 1 ===> 86 for STA 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.684: 2c:54:2d:ea:d4:0e Sending EAP Request from AAA to mobile 2c:54:2d:ea:d4:0e (EAP Id 86)

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.695: 2c:54:2d:ea:d4:0e Received EAPOL EAPPKT from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.695: 2c:54:2d:ea:d4:0e Received EAP Response from mobile 2c:54:2d:ea:d4:0e (EAP Id 86, EAP Type 3)

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.695: 2c:54:2d:ea:d4:0e Entering Backend Auth Response state for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.699: 2c:54:2d:ea:d4:0e Processing Access-Challenge for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.699: 2c:54:2d:ea:d4:0e Entering Backend Auth Req state (id=87) for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.699: 2c:54:2d:ea:d4:0e Sending EAP Request from AAA to mobile 2c:54:2d:ea:d4:0e (EAP Id 87)

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.806: 2c:54:2d:ea:d4:0e Received EAPOL EAPPKT from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.806: 2c:54:2d:ea:d4:0e Received EAP Response from mobile 2c:54:2d:ea:d4:0e (EAP Id 87, EAP Type 43)

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.806: 2c:54:2d:ea:d4:0e Entering Backend Auth Response state for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.809: 2c:54:2d:ea:d4:0e Processing Access-Challenge for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.809: 2c:54:2d:ea:d4:0e Entering Backend Auth Req state (id=88) for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.809: 2c:54:2d:ea:d4:0e Sending EAP Request from AAA to mobile 2c:54:2d:ea:d4:0e (EAP Id 88)

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.874: 2c:54:2d:ea:d4:0e Received EAPOL EAPPKT from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.874: 2c:54:2d:ea:d4:0e Received EAP Response from mobile 2c:54:2d:ea:d4:0e (EAP Id 88, EAP Type 43)

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.874: 2c:54:2d:ea:d4:0e Entering Backend Auth Response state for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.880: 2c:54:2d:ea:d4:0e Processing Access-Challenge for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.880: 2c:54:2d:ea:d4:0e Entering Backend Auth Req state (id=90) for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.880: 2c:54:2d:ea:d4:0e WARNING: updated EAP-Identifier 88 ===> 90 for STA 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.880: 2c:54:2d:ea:d4:0e Sending EAP Request from AAA to mobile 2c:54:2d:ea:d4:0e (EAP Id 90)

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.903: 2c:54:2d:ea:d4:0e Received EAPOL EAPPKT from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.903: 2c:54:2d:ea:d4:0e Received EAP Response from mobile 2c:54:2d:ea:d4:0e (EAP Id 90, EAP Type 43)

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.903: 2c:54:2d:ea:d4:0e Entering Backend Auth Response state for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.909: 2c:54:2d:ea:d4:0e Processing Access-Challenge for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.909: 2c:54:2d:ea:d4:0e Entering Backend Auth Req state (id=91) for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:01.909: 2c:54:2d:ea:d4:0e Sending EAP Request from AAA to mobile 2c:54:2d:ea:d4:0e (EAP Id 91)

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.061: 2c:54:2d:ea:d4:0e Received EAPOL EAPPKT from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.061: 2c:54:2d:ea:d4:0e Received EAP Response from mobile 2c:54:2d:ea:d4:0e (EAP Id 91, EAP Type 43)

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.061: 2c:54:2d:ea:d4:0e Entering Backend Auth Response state for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.076: 2c:54:2d:ea:d4:0e Processing Access-Accept for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.076: 2c:54:2d:ea:d4:0e Resetting web IPv4 acl from 255 to 255

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.076: 2c:54:2d:ea:d4:0e Setting re-auth timeout to 65535 seconds, got from WLAN config.

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.077: 2c:54:2d:ea:d4:0e Station 2c:54:2d:ea:d4:0e setting dot1x reauth timeout = 65535

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.077: 2c:54:2d:ea:d4:0e Creating a PKC PMKID Cache entry for station 2c:54:2d:ea:d4:0e (RSN 2)

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.077: 2c:54:2d:ea:d4:0e Resetting MSCB PMK Cache Entry 0 for station 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.077: 2c:54:2d:ea:d4:0e Setting active key cache index 8 ---> 8

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.077: 2c:54:2d:ea:d4:0e Setting active key cache index 8 ---> 0

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.077: 2c:54:2d:ea:d4:0e Adding BSSID 34:bd:c8:b3:d9:f0 to PMKID cache at index 0 for station 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.077: New PMKID: (16)

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.077: [0000] 16 bf c0 3e 07 00 79 b1 51 ca d3 47 44 69 1b a1

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.077: 2c:54:2d:ea:d4:0e Disabling re-auth since PMK lifetime can take care of same.

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.077: 2c:54:2d:ea:d4:0e CCKM: Create a global PMK cache entry

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.077: 2c:54:2d:ea:d4:0e unsetting PmkIdValidatedByAp

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.077: 2c:54:2d:ea:d4:0e Sending EAP-Success to mobile 2c:54:2d:ea:d4:0e (EAP Id 91)

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.077: 2c:54:2d:ea:d4:0e Found an cache entry for BSSID 34:bd:c8:b3:d9:f0 in PMKID cache at index 0 of station 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.077: Including PMKID in M1 (16)

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.077: [0000] 16 bf c0 3e 07 00 79 b1 51 ca d3 47 44 69 1b a1

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.077: 2c:54:2d:ea:d4:0e Starting key exchange to mobile 2c:54:2d:ea:d4:0e, data packets will be dropped

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.077: 2c:54:2d:ea:d4:0e Sending EAPOL-Key Message to mobile 2c:54:2d:ea:d4:0e

state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.077: 2c:54:2d:ea:d4:0e Entering Backend Auth Success state (id=91) for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.077: 2c:54:2d:ea:d4:0e Received Auth Success while in Authenticating state for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.077: 2c:54:2d:ea:d4:0e dot1x - moving mobile 2c:54:2d:ea:d4:0e into Authenticated state

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.113: 2c:54:2d:ea:d4:0e Received EAPOL-Key from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.113: 2c:54:2d:ea:d4:0e Received EAPOL-key in PTK_START state (message 2) from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.113: 2c:54:2d:ea:d4:0e CCKM: Sending cache add

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.113: CCKM: Sending CCKM PMK (Version_1) information to mobility group

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.113: CCKM: Sending CCKM PMK (Version_2) information to mobility group

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.113: 2c:54:2d:ea:d4:0e Stopping retransmission timer for mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.113: 2c:54:2d:ea:d4:0e Sending EAPOL-Key Message to mobile 2c:54:2d:ea:d4:0e

state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.164: 2c:54:2d:ea:d4:0e Received EAPOL-Key from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.164: 2c:54:2d:ea:d4:0e Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 2c:54:2d:ea:d4:0e

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.164: 2c:54:2d:ea:d4:0e apfMs1xStateInc

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.164: 2c:54:2d:ea:d4:0e 10.123.201.4 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.164: 2c:54:2d:ea:d4:0e 10.123.201.4 L2AUTHCOMPLETE (4) DHCP required on AP 34:bd:c8:b3:d9:f0 vapId 3 apVapId 1for this client

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.164: 2c:54:2d:ea:d4:0e 10.123.201.4 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 34:bd:c8:b3:d9:f0 vapId 3 apVapId 1

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.164: 2c:54:2d:ea:d4:0e apfMsRunStateInc

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.164: 2c:54:2d:ea:d4:0e 10.123.201.4 L2AUTHCOMPLETE (4) Change state to RUN (20) last state RUN (20)

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.166: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Reached PLUMBFASTPATH: from line 5362

*Dot1x: Dec 07 13:57:02.166: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Adding Fast Path rule

type = Airespace AP Client

on AP 34:bd:c8:b3:d9:f0, slot 0, interface = 1, QOS = 2

IPv4 ACL ID = 255, IPv6 ACL ID = 2

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.166: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 7006 Local Bridging Vlan = 144, Local Bridging intf id = 12

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.166: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255)

*Dot1x_NW_MsgTask_6: Dec 07 13:57:02.166: 2c:54:2d:ea:d4:0e Stopping retransmission timer for mobile 2c:54:2d:ea:d4:0e

*pemReceiveTask: Dec 07 13:57:02.166: 2c:54:2d:ea:d4:0e 10.123.201.4 Added NPU entry of type 1, dtlFlags 0x0

*apfMsConnTask_2: Dec 07 13:57:03.265: 2c:54:2d:ea:d4:0e CCKM: Received REASSOC REQ IE

*apfMsConnTask_2: Dec 07 13:57:03.265: 2c:54:2d:ea:d4:0e Reassociation received from mobile on AP 34:bd:c8:b2:b1:10

*apfMsConnTask_2: Dec 07 13:57:03.265: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1697)

*apfMsConnTask_2: Dec 07 13:57:03.265: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1864)

*apfMsConnTask_2: Dec 07 13:57:03.265: 2c:54:2d:ea:d4:0e Applying site-specific Local Bridging override for station 2c:54:2d:ea:d4:0e - vapId 3, site 'Floor_1', interface '144_v'

*apfMsConnTask_2: Dec 07 13:57:03.265: 2c:54:2d:ea:d4:0e Applying Local Bridging Interface Policy for station 2c:54:2d:ea:d4:0e - vlan 144, interface id 12, interface '144_v'

*apfMsConnTask_2: Dec 07 13:57:03.265: 2c:54:2d:ea:d4:0e Applying site-specific override for station 2c:54:2d:ea:d4:0e - vapId 3, site 'Floor_1', interface '144_v'

*apfMsConnTask_2: Dec 07 13:57:03.265: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1697)

*apfMsConnTask_2: Dec 07 13:57:03.265: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1864)

*apfMsConnTask_2: Dec 07 13:57:03.265: 2c:54:2d:ea:d4:0e processSsidIE statusCode is 0 and status is 0

*apfMsConnTask_2: Dec 07 13:57:03.265: 2c:54:2d:ea:d4:0e processSsidIE ssid_done_flag is 0 finish_flag is 0

*apfMsConnTask_2: Dec 07 13:57:03.266: 2c:54:2d:ea:d4:0e STA - rates (4): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*apfMsConnTask_2: Dec 07 13:57:03.266: 2c:54:2d:ea:d4:0e suppRates statusCode is 0 and gotSuppRatesElement is 1

*apfMsConnTask_2: Dec 07 13:57:03.266: 2c:54:2d:ea:d4:0e STA - rates (12): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*apfMsConnTask_2: Dec 07 13:57:03.266: 2c:54:2d:ea:d4:0e extSuppRates statusCode is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_2: Dec 07 13:57:03.266: 2c:54:2d:ea:d4:0e Processing RSN IE type 48, length 22 for mobile 2c:54:2d:ea:d4:0e

*apfMsConnTask_2: Dec 07 13:57:03.266: 2c:54:2d:ea:d4:0e CCKM: Mobile is using CCKM

*apfMsConnTask_2: Dec 07 13:57:03.266: 2c:54:2d:ea:d4:0e Received RSN IE with 0 PMKIDs from mobile 2c:54:2d:ea:d4:0e

*apfMsConnTask_2: Dec 07 13:57:03.266: 2c:54:2d:ea:d4:0e Found an cache entry for BSSID 34:bd:c8:b3:d9:f0 in PMKID cache at index 0 of station 2c:54:2d:ea:d4:0e

*apfMsConnTask_2: Dec 07 13:57:03.266: 2c:54:2d:ea:d4:0e Removing BSSID 34:bd:c8:b3:d9:f0 from PMKID cache of station 2c:54:2d:ea:d4:0e

*apfMsConnTask_2: Dec 07 13:57:03.266: 2c:54:2d:ea:d4:0e Resetting MSCB PMK Cache Entry 0 for station 2c:54:2d:ea:d4:0e

*apfMsConnTask_2: Dec 07 13:57:03.266: 2c:54:2d:ea:d4:0e Setting active key cache index 0 ---> 8

*apfMsConnTask_2: Dec 07 13:57:03.266: 2c:54:2d:ea:d4:0e unsetting PmkIdValidatedByAp

*apfMsConnTask_2: Dec 07 13:57:03.266: 2c:54:2d:ea:d4:0e CCKM: Processing REASSOC REQ IE

*apfMsConnTask_2: Dec 07 13:57:03.266: 2c:54:2d:ea:d4:0e CCKM: using HMAC SHA1 to compute MIC

*apfMsConnTask_2: Dec 07 13:57:03.266: 2c:54:2d:ea:d4:0e CCKM: Received a valid REASSOC REQ IE

*apfMsConnTask_2: Dec 07 13:57:03.267: 2c:54:2d:ea:d4:0e CCKM: Initializing PMK cache entry with a new PTK

*apfMsConnTask_2: Dec 07 13:57:03.267: 2c:54:2d:ea:d4:0e Setting active key cache index 8 ---> 8

*apfMsConnTask_2: Dec 07 13:57:03.267: 2c:54:2d:ea:d4:0e Resetting MSCB PMK Cache Entry 0 for station 2c:54:2d:ea:d4:0e

*apfMsConnTask_2: Dec 07 13:57:03.267: 2c:54:2d:ea:d4:0e Setting active key cache index 8 ---> 8

*apfMsConnTask_2: Dec 07 13:57:03.267: 2c:54:2d:ea:d4:0e Setting active key cache index 8 ---> 0

*apfMsConnTask_2: Dec 07 13:57:03.267: 2c:54:2d:ea:d4:0e Creating a PKC PMKID Cache entry for station 2c:54:2d:ea:d4:0e (RSN 2) on BSSID 34:bd:c8:b3:d9:f0

*apfMsConnTask_2: Dec 07 13:57:03.267: 2c:54:2d:ea:d4:0e Setting active key cache index 0 ---> 8

*apfMsConnTask_2: Dec 07 13:57:03.267: 2c:54:2d:ea:d4:0e CCKM: using HMAC SHA1 to compute MIC

*apfMsConnTask_2: Dec 07 13:57:03.267: 2c:54:2d:ea:d4:0e Including CCKM Response IE (length 54) in Assoc Resp to mobile

*apfMsConnTask_2: Dec 07 13:57:03.267: 2c:54:2d:ea:d4:0e Sending Assoc Response to station on BSSID 34:bd:c8:b2:b1:10 (status 202) ApVapId 1 Slot 0

*apfMsConnTask_2: Dec 07 13:57:03.267: 2c:54:2d:ea:d4:0e Scheduling deletion of Mobile Station: (callerId: 22) in 3 seconds

*apfMsConnTask_3: Dec 07 13:57:04.925: 2c:54:2d:ea:d4:0e Association received from mobile on AP 34:bd:c8:b3:d9:f0

*apfMsConnTask_3: Dec 07 13:57:04.925: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1697)

*apfMsConnTask_3: Dec 07 13:57:04.925: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1864)

*apfMsConnTask_3: Dec 07 13:57:04.925: 2c:54:2d:ea:d4:0e Applying site-specific Local Bridging override for station 2c:54:2d:ea:d4:0e - vapId 3, site 'Floor_1', interface '144_v'

*apfMsConnTask_3: Dec 07 13:57:04.925: 2c:54:2d:ea:d4:0e Applying Local Bridging Interface Policy for station 2c:54:2d:ea:d4:0e - vlan 144, interface id 12, interface '144_v'

*apfMsConnTask_3: Dec 07 13:57:04.925: 2c:54:2d:ea:d4:0e Applying site-specific override for station 2c:54:2d:ea:d4:0e - vapId 3, site 'Floor_1', interface '144_v'

*apfMsConnTask_3: Dec 07 13:57:04.925: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1697)

*apfMsConnTask_3: Dec 07 13:57:04.925: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1864)

*apfMsConnTask_3: Dec 07 13:57:04.925: 2c:54:2d:ea:d4:0e processSsidIE statusCode is 0 and status is 0

*apfMsConnTask_3: Dec 07 13:57:04.925: 2c:54:2d:ea:d4:0e processSsidIE ssid_done_flag is 0 finish_flag is 0

*apfMsConnTask_3: Dec 07 13:57:04.925: 2c:54:2d:ea:d4:0e STA - rates (4): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*apfMsConnTask_3: Dec 07 13:57:04.925: 2c:54:2d:ea:d4:0e suppRates statusCode is 0 and gotSuppRatesElement is 1

*apfMsConnTask_3: Dec 07 13:57:04.925: 2c:54:2d:ea:d4:0e STA - rates (12): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*apfMsConnTask_3: Dec 07 13:57:04.925: 2c:54:2d:ea:d4:0e extSuppRates statusCode is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_3: Dec 07 13:57:04.925: 2c:54:2d:ea:d4:0e Processing RSN IE type 48, length 22 for mobile 2c:54:2d:ea:d4:0e

*apfMsConnTask_3: Dec 07 13:57:04.925: 2c:54:2d:ea:d4:0e CCKM: Mobile is using CCKM

*apfMsConnTask_3: Dec 07 13:57:04.925: 2c:54:2d:ea:d4:0e Received RSN IE with 0 PMKIDs from mobile 2c:54:2d:ea:d4:0e

*apfMsConnTask_3: Dec 07 13:57:04.925: 2c:54:2d:ea:d4:0e Setting active key cache index 8 ---> 8

*apfMsConnTask_3: Dec 07 13:57:04.925: 2c:54:2d:ea:d4:0e unsetting PmkIdValidatedByAp

*apfMsConnTask_3: Dec 07 13:57:04.925: 2c:54:2d:ea:d4:0e apfMsRunStateDec

*apfMsConnTask_3: Dec 07 13:57:04.926: 2c:54:2d:ea:d4:0e apfMs1xStateDec

*apfMsConnTask_3: Dec 07 13:57:04.926: 2c:54:2d:ea:d4:0e 10.123.201.4 RUN (20) Change state to START (0) last state RUN (20)

George Stefanick · ‎12-08-2012

If I were you .. I would configure a test said no security and test it. See what happens and then start to layer security back on .. See where she starts to break.

Sent from Cisco Technical Support iPad App

"Satisfaction does not come from knowing the solution, it comes from knowing why." - Rosalind Franklin
___________________________________________________________