Re: How up or down threshold?

aricardor · ‎06-28-2012

Hi:

In WLC i see the roaming option to controller the handover.

As the accompanying graph (http://es.wikipedia.org/wiki/Archivo:Punto_handover.jpg
), how do I up or down the threshold of the handover? or, How do I more sensitive to IP phone(NEC model MH240)?

I don't understand the four textfield of the roaming options (http://www.cisco.com/en/US/docs/wireless/controller/7.2/configuration/guide/cg_controller_setting.html#wp2293998
).

Thanks!

Scott Fella · ‎06-28-2012

The main thing you need to understand is how well was your site survey done. A good site survey that meets the RSSI and SNR along with the overlap required, you really don't need to change these values. When you start changing these values, you need to understand your environment and how those phones are working. If you increase sensitivity, your phone can roam too aggressively especially if you don't have that RSSI value everywhere. This is a global change and affects roaming for all devices on that radio band.

Sent from Cisco Technical Support iPhone App

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

aricardor · ‎06-28-2012

Thank you!

I changed some values in the section of the RF (the threshold for voice I have set at -50 dB), and paragraph roaming client I have that the minimum is -57. coverage has been increased, and even the handover seems to work better.

Sometimes the following happens: The NEC phone is associated with an Access Point, I walk, I stand in front of another access point and takes time to turn blue, or not turn blue until I make a call.

Another question about AP, model LAP1041N:

How does the AP work? How does the AP broadcast?. Is It a circle and the AP is the center? Does the AP broadcast more front than back? Have any blind spot?

I put logs.

First log

(Cisco Controller) >*pemReceiveTask: Jun 27 11:45:46.177: 00:60:b9:0d:ec:1f 10.160.91.51 Added NPU entry of type 1, dtlFlags 0x0

*apfMsConnTask_1: Jun 28 10:39:17.850: 00:60:b9:0d:ec:1f Reassociation received from mobile on AP c8:f9:f9:5b:12:10

*apfMsConnTask_1: Jun 28 10:39:17.850: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1697)

*apfMsConnTask_1: Jun 28 10:39:17.850: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1864)

*apfMsConnTask_1: Jun 28 10:39:17.850: 00:60:b9:0d:ec:1f Applying site-specific Local Bridging override for station 00:60:b9:0d:ec:1f - vapId 2, site 'default-group', interface 'pvoz'

*apfMsConnTask_1: Jun 28 10:39:17.850: 00:60:b9:0d:ec:1f Applying Local Bridging Interface Policy for station 00:60:b9:0d:ec:1f - vlan 106, interface id 12, interface 'pvoz'

*apfMsConnTask_1: Jun 28 10:39:17.850: 00:60:b9:0d:ec:1f processSsidIE statusCode is 0 and status is 0

*apfMsConnTask_1: Jun 28 10:39:17.850: 00:60:b9:0d:ec:1f processSsidIE ssid_done_flag is 0 finish_flag is 0

*apfMsConnTask_1: Jun 28 10:39:17.850: 00:60:b9:0d:ec:1f STA - rates (8): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_1: Jun 28 10:39:17.850: 00:60:b9:0d:ec:1f suppRates statusCode is 0 and gotSuppRatesElement is 1

*apfMsConnTask_1: Jun 28 10:39:17.850: 00:60:b9:0d:ec:1f STA - rates (10): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_1: Jun 28 10:39:17.851: 00:60:b9:0d:ec:1f extSuppRates statusCode is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_1: Jun 28 10:39:17.851: 00:60:b9:0d:ec:1f Processing RSN IE type 48, length 20 for mobile 00:60:b9:0d:ec:1f

*apfMsConnTask_1: Jun 28 10:39:17.851: 00:60:b9:0d:ec:1f pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_1: Jun 28 10:39:17.851: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Deleted mobile LWAPP rule on AP [3c:ce:73:f8:e1:00]

*pemReceiveTask: Jun 28 10:39:17.851: 00:60:b9:0d:ec:1f 10.160.91.51 Removed NPU entry.

*apfMsConnTask_1: Jun 28 10:39:17.851: 00:60:b9:0d:ec:1f Updated location for station old AP 3c:ce:73:f8:e1:00-0, new AP c8:f9:f9:5b:12:10-0

*apfMsConnTask_1: Jun 28 10:39:17.851: 00:60:b9:0d:ec:1f apfMsRunStateDec

*apfMsConnTask_1: Jun 28 10:39:17.851: 00:60:b9:0d:ec:1f apfMs1xStateDec

*apfMsConnTask_1: Jun 28 10:39:17.851: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Change state to START (0) last state RUN (20)

*apfMsConnTask_1: Jun 28 10:39:17.852: 00:60:b9:0d:ec:1f pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_1: Jun 28 10:39:17.852: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Initializing policy

*apfMsConnTask_1: Jun 28 10:39:17.852: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Change state to AUTHCHECK (2) last state RUN (20)

*apfMsConnTask_1: Jun 28 10:39:17.852: 00:60:b9:0d:ec:1f 10.160.91.51 AUTHCHECK (2) Change state to 8021X_REQD (3) last state RUN (20)

*apfMsConnTask_1: Jun 28 10:39:17.852: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) DHCP required on AP c8:f9:f9:5b:12:10 vapId 2 apVapId 2for this client

*apfMsConnTask_1: Jun 28 10:39:17.852: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*apfMsConnTask_1: Jun 28 10:39:17.852: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Plumbed mobile LWAPP rule on AP c8:f9:f9:5b:12:10 vapId 2 apVapId 2

*apfMsConnTask_1: Jun 28 10:39:17.852: 00:60:b9:0d:ec:1f apfPemAddUser2 (apf_policy.c:268) Changing state for mobile 00:60:b9:0d:ec:1f on AP c8:f9:f9:5b:12:10 from Associated to Associated

*apfMsConnTask_1: Jun 28 10:39:17.852: 00:60:b9:0d:ec:1f Scheduling deletion of Mobile Station: (callerId: 49) in 1800 seconds

*apfMsConnTask_1: Jun 28 10:39:17.853: 00:60:b9:0d:ec:1f Sending Assoc Response to station on BSSID c8:f9:f9:5b:12:10 (status 0) ApVapId 2 Slot 0

*apfMsConnTask_1: Jun 28 10:39:17.853: 00:60:b9:0d:ec:1f apfProcessAssocReq (apf_80211.c:6290) Changing state for mobile 00:60:b9:0d:ec:1f on AP c8:f9:f9:5b:12:10 from Associated to Associated

*dot1xMsgTask: Jun 28 10:39:17.854: 00:60:b9:0d:ec:1f Creating a PKC PMKID Cache entry for station 00:60:b9:0d:ec:1f (RSN 2)

*dot1xMsgTask: Jun 28 10:39:17.854: 00:60:b9:0d:ec:1f Resetting MSCB PMK Cache Entry 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 10:39:17.854: 00:60:b9:0d:ec:1f Removing BSSID 3c:ce:73:f8:e1:01 from PMKID cache of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 10:39:17.854: 00:60:b9:0d:ec:1f Setting active key cache index 0 ---> 8

*dot1xMsgTask: Jun 28 10:39:17.854: 00:60:b9:0d:ec:1f Setting active key cache index 8 ---> 0

*dot1xMsgTask: Jun 28 10:39:17.855: 00:60:b9:0d:ec:1f Adding BSSID c8:f9:f9:5b:12:11 to PMKID cache at index 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 10:39:17.855: New PMKID: (16)

*dot1xMsgTask: Jun 28 10:39:17.855: [0000] bb 36 2c 2a e6 49 d5 39 af 0e 23 7b 64 9b ae 5b

*dot1xMsgTask: Jun 28 10:39:17.855: 00:60:b9:0d:ec:1f Initiating RSN PSK to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 10:39:17.855: 00:60:b9:0d:ec:1f dot1x - moving mobile 00:60:b9:0d:ec:1f into Force Auth state

*dot1xMsgTask: Jun 28 10:39:17.855: 00:60:b9:0d:ec:1f Skipping EAP-Success to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 10:39:17.855: 00:60:b9:0d:ec:1f Found an cache entry for BSSID c8:f9:f9:5b:12:11 in PMKID cache at index 0 of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 10:39:17.855: Including PMKID in M1 (16)

*dot1xMsgTask: Jun 28 10:39:17.855: [0000] bb 36 2c 2a e6 49 d5 39 af 0e 23 7b 64 9b ae 5b

*dot1xMsgTask: Jun 28 10:39:17.855: 00:60:b9:0d:ec:1f Starting key exchange to mobile 00:60:b9:0d:ec:1f, data packets will be dropped

*dot1xMsgTask: Jun 28 10:39:17.855: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Dot1x_NW_MsgTask_7: Jun 28 10:39:17.911: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 10:39:17.911: 00:60:b9:0d:ec:1f Received EAPOL-key in PTK_START state (message 2) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 10:39:17.912: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 10:39:17.912: 00:60:b9:0d:ec:1f Sending the random GTK in M3 for WPA2 client 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 10:39:17.912: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01

*Dot1x_NW_MsgTask_7: Jun 28 10:39:17.915: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 10:39:17.915: 00:60:b9:0d:ec:1f Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 10:39:17.915: 00:60:b9:0d:ec:1f apfMs1xStateInc

*Dot1x_NW_MsgTask_7: Jun 28 10:39:17.915: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 10:39:17.915: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) DHCP required on AP c8:f9:f9:5b:12:10 vapId 2 apVapId 2for this client

*Dot1x_NW_MsgTask_7: Jun 28 10:39:17.916: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*Dot1x_NW_MsgTask_7: Jun 28 10:39:17.916: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP c8:f9:f9:5b:12:10 vapId 2 apVapId 2

*Dot1x_NW_MsgTask_7: Jun 28 10:39:17.916: 00:60:b9:0d:ec:1f apfMsRunStateInc

*Dot1x_NW_MsgTask_7: Jun 28 10:39:17.916: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Change state to RUN (20) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 10:39:17.916: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Reached PLUMBFASTPATH: from line 5362

*Dot1x_: Jun 28 10:39:17.916: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Adding Fast Path rule

type = Airespace AP Client

on AP c8:f9:f9:5b:12:10, slot 0, interface = 13, QOS = 2

IPv4 ACL ID = 255, IPv6 ACL ID =

*Dot1x_NW_MsgTask_7: Jun 28 10:39:17.916: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 7006 Local Bridging Vlan = 106, Local Bridging intf id = 12

*Dot1x_NW_MsgTask_7: Jun 28 10:39:17.916: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255)

*Dot1x_NW_MsgTask_7: Jun 28 10:39:17.916: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

*pemReceiveTask: Jun 28 10:39:17.916: 00:60:b9:0d:ec:1f 10.160.91.51 Added NPU entry of type 1, dtlFlags 0x0

*apfMsConnTask_2: Jun 28 10:39:29.027: 00:60:b9:0d:ec:1f Reassociation received from mobile on AP c8:f9:f9:5a:80:80

*apfMsConnTask_2: Jun 28 10:39:29.027: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1697)

*apfMsConnTask_2: Jun 28 10:39:29.027: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1864)

*apfMsConnTask_2: Jun 28 10:39:29.027: 00:60:b9:0d:ec:1f Applying site-specific Local Bridging override for station 00:60:b9:0d:ec:1f - vapId 2, site 'default-group', interface 'pvoz'

*apfMsConnTask_2: Jun 28 10:39:29.027: 00:60:b9:0d:ec:1f Applying Local Bridging Interface Policy for station 00:60:b9:0d:ec:1f - vlan 106, interface id 12, interface 'pvoz'

*apfMsConnTask_2: Jun 28 10:39:29.027: 00:60:b9:0d:ec:1f processSsidIE statusCode is 0 and status is 0

*apfMsConnTask_2: Jun 28 10:39:29.027: 00:60:b9:0d:ec:1f processSsidIE ssid_done_flag is 0 finish_flag is 0

*apfMsConnTask_2: Jun 28 10:39:29.027: 00:60:b9:0d:ec:1f STA - rates (8): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_2: Jun 28 10:39:29.027: 00:60:b9:0d:ec:1f suppRates statusCode is 0 and gotSuppRatesElement is 1

*apfMsConnTask_2: Jun 28 10:39:29.027: 00:60:b9:0d:ec:1f STA - rates (10): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_2: Jun 28 10:39:29.027: 00:60:b9:0d:ec:1f extSuppRates statusCode is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_2: Jun 28 10:39:29.027: 00:60:b9:0d:ec:1f Processing RSN IE type 48, length 20 for mobile 00:60:b9:0d:ec:1f

*apfMsConnTask_2: Jun 28 10:39:29.027: 00:60:b9:0d:ec:1f pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_2: Jun 28 10:39:29.028: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Deleted mobile LWAPP rule on AP [c8:f9:f9:5b:12:10]

*pemReceiveTask: Jun 28 10:39:29.028: 00:60:b9:0d:ec:1f 10.160.91.51 Removed NPU entry.

*apfMsConnTask_2: Jun 28 10:39:29.028: 00:60:b9:0d:ec:1f Updated location for station old AP c8:f9:f9:5b:12:10-0, new AP c8:f9:f9:5a:80:80-0

*apfMsConnTask_2: Jun 28 10:39:29.028: 00:60:b9:0d:ec:1f apfMsRunStateDec

*apfMsConnTask_2: Jun 28 10:39:29.028: 00:60:b9:0d:ec:1f apfMs1xStateDec

*apfMsConnTask_2: Jun 28 10:39:29.028: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Change state to START (0) last state RUN (20)

*apfMsConnTask_2: Jun 28 10:39:29.028: 00:60:b9:0d:ec:1f pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_2: Jun 28 10:39:29.028: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Initializing policy

*apfMsConnTask_2: Jun 28 10:39:29.028: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Change state to AUTHCHECK (2) last state RUN (20)

*apfMsConnTask_2: Jun 28 10:39:29.028: 00:60:b9:0d:ec:1f 10.160.91.51 AUTHCHECK (2) Change state to 8021X_REQD (3) last state RUN (20)

*apfMsConnTask_2: Jun 28 10:39:29.028: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) DHCP required on AP c8:f9:f9:5a:80:80 vapId 2 apVapId 2for this client

*apfMsConnTask_2: Jun 28 10:39:29.028: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*apfMsConnTask_2: Jun 28 10:39:29.028: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Plumbed mobile LWAPP rule on AP c8:f9:f9:5a:80:80 vapId 2 apVapId 2

*apfMsConnTask_2: Jun 28 10:39:29.028: 00:60:b9:0d:ec:1f apfPemAddUser2 (apf_policy.c:268) Changing state for mobile 00:60:b9:0d:ec:1f on AP c8:f9:f9:5a:80:80 from Associated to Associated

*apfMsConnTask_2: Jun 28 10:39:29.028: 00:60:b9:0d:ec:1f Scheduling deletion of Mobile Station: (callerId: 49) in 1800 seconds

*apfMsConnTask_2: Jun 28 10:39:29.028: 00:60:b9:0d:ec:1f Sending Assoc Response to station on BSSID c8:f9:f9:5a:80:80 (status 0) ApVapId 2 Slot 0

*apfMsConnTask_2: Jun 28 10:39:29.028: 00:60:b9:0d:ec:1f apfProcessAssocReq (apf_80211.c:6290) Changing state for mobile 00:60:b9:0d:ec:1f on AP c8:f9:f9:5a:80:80 from Associated to Associated

*dot1xMsgTask: Jun 28 10:39:29.030: 00:60:b9:0d:ec:1f Creating a PKC PMKID Cache entry for station 00:60:b9:0d:ec:1f (RSN 2)

*dot1xMsgTask: Jun 28 10:39:29.030: 00:60:b9:0d:ec:1f Resetting MSCB PMK Cache Entry 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 10:39:29.030: 00:60:b9:0d:ec:1f Removing BSSID c8:f9:f9:5b:12:11 from PMKID cache of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 10:39:29.030: 00:60:b9:0d:ec:1f Setting active key cache index 0 ---> 8

*dot1xMsgTask: Jun 28 10:39:29.030: 00:60:b9:0d:ec:1f Setting active key cache index 8 ---> 0

*dot1xMsgTask: Jun 28 10:39:29.030: 00:60:b9:0d:ec:1f Adding BSSID c8:f9:f9:5a:80:81 to PMKID cache at index 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 10:39:29.030: New PMKID: (16)

*dot1xMsgTask: Jun 28 10:39:29.030: [0000] e4 40 26 0e d5 70 ea 0f 0d 45 09 72 4f bc 00 71

*dot1xMsgTask: Jun 28 10:39:29.030: 00:60:b9:0d:ec:1f Initiating RSN PSK to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 10:39:29.030: 00:60:b9:0d:ec:1f dot1x - moving mobile 00:60:b9:0d:ec:1f into Force Auth state

*dot1xMsgTask: Jun 28 10:39:29.030: 00:60:b9:0d:ec:1f Skipping EAP-Success to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 10:39:29.030: 00:60:b9:0d:ec:1f Found an cache entry for BSSID c8:f9:f9:5a:80:81 in PMKID cache at index 0 of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 10:39:29.030: Including PMKID in M1 (16)

*dot1xMsgTask: Jun 28 10:39:29.030: [0000] e4 40 26 0e d5 70 ea 0f 0d 45 09 72 4f bc 00 71

*dot1xMsgTask: Jun 28 10:39:29.031: 00:60:b9:0d:ec:1f Starting key exchange to mobile 00:60:b9:0d:ec:1f, data packets will be dropped

*dot1xMsgTask: Jun 28 10:39:29.031: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Dot1x_NW_MsgTask_7: Jun 28 10:39:29.070: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 10:39:29.070: 00:60:b9:0d:ec:1f Received EAPOL-key in PTK_START state (message 2) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 10:39:29.070: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 10:39:29.070: 00:60:b9:0d:ec:1f Sending the random GTK in M3 for WPA2 client 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 10:39:29.071: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01

*Dot1x_NW_MsgTask_7: Jun 28 10:39:29.075: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 10:39:29.076: 00:60:b9:0d:ec:1f Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 10:39:29.076: 00:60:b9:0d:ec:1f apfMs1xStateInc

*Dot1x_NW_MsgTask_7: Jun 28 10:39:29.076: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 10:39:29.076: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) DHCP required on AP c8:f9:f9:5a:80:80 vapId 2 apVapId 2for this client

*Dot1x_NW_MsgTask_7: Jun 28 10:39:29.076: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*Dot1x_NW_MsgTask_7: Jun 28 10:39:29.076: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP c8:f9:f9:5a:80:80 vapId 2 apVapId 2

*Dot1x_NW_MsgTask_7: Jun 28 10:39:29.076: 00:60:b9:0d:ec:1f apfMsRunStateInc

*Dot1x_NW_MsgTask_7: Jun 28 10:39:29.076: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Change state to RUN (20) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 10:39:29.076: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Reached PLUMBFASTPATH: from line 5362

*Dot1x_: Jun 28 10:39:29.076: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Adding Fast Path rule

type = Airespace AP Client

on AP c8:f9:f9:5a:80:80, slot 0, interface = 13, QOS = 2

IPv4 ACL ID = 255, IPv6 ACL ID =

*Dot1x_NW_MsgTask_7: Jun 28 10:39:29.076: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 7006 Local Bridging Vlan = 106, Local Bridging intf id = 12

*Dot1x_NW_MsgTask_7: Jun 28 10:39:29.076: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255)

*Dot1x_NW_MsgTask_7: Jun 28 10:39:29.076: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

*pemReceiveTask: Jun 28 10:39:29.076: 00:60:b9:0d:ec:1f 10.160.91.51 Added NPU entry of type 1, dtlFlags 0x0

*apfMsConnTask_4: Jun 28 10:41:06.675: 00:60:b9:0d:ec:1f Reassociation received from mobile on AP 3c:ce:73:f7:62:10

*apfMsConnTask_4: Jun 28 10:41:06.675: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1697)

*apfMsConnTask_4: Jun 28 10:41:06.675: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1864)

*apfMsConnTask_4: Jun 28 10:41:06.675: 00:60:b9:0d:ec:1f Applying site-specific Local Bridging override for station 00:60:b9:0d:ec:1f - vapId 2, site 'default-group', interface 'pvoz'

*apfMsConnTask_4: Jun 28 10:41:06.676: 00:60:b9:0d:ec:1f Applying Local Bridging Interface Policy for station 00:60:b9:0d:ec:1f - vlan 106, interface id 12, interface 'pvoz'

*apfMsConnTask_4: Jun 28 10:41:06.676: 00:60:b9:0d:ec:1f processSsidIE statusCode is 0 and status is 0

*apfMsConnTask_4: Jun 28 10:41:06.676: 00:60:b9:0d:ec:1f processSsidIE ssid_done_flag is 0 finish_flag is 0

*apfMsConnTask_4: Jun 28 10:41:06.676: 00:60:b9:0d:ec:1f STA - rates (8): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_4: Jun 28 10:41:06.676: 00:60:b9:0d:ec:1f suppRates statusCode is 0 and gotSuppRatesElement is 1

*apfMsConnTask_4: Jun 28 10:41:06.676: 00:60:b9:0d:ec:1f STA - rates (10): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_4: Jun 28 10:41:06.676: 00:60:b9:0d:ec:1f extSuppRates statusCode is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_4: Jun 28 10:41:06.676: 00:60:b9:0d:ec:1f Processing RSN IE type 48, length 20 for mobile 00:60:b9:0d:ec:1f

*apfMsConnTask_4: Jun 28 10:41:06.676: 00:60:b9:0d:ec:1f pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_4: Jun 28 10:41:06.676: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Deleted mobile LWAPP rule on AP [c8:f9:f9:5a:80:80]

*pemReceiveTask: Jun 28 10:41:06.676: 00:60:b9:0d:ec:1f 10.160.91.51 Removed NPU entry.

*apfMsConnTask_4: Jun 28 10:41:06.676: 00:60:b9:0d:ec:1f Updated location for station old AP c8:f9:f9:5a:80:80-0, new AP 3c:ce:73:f7:62:10-0

*apfMsConnTask_4: Jun 28 10:41:06.676: 00:60:b9:0d:ec:1f apfMsRunStateDec

*apfMsConnTask_4: Jun 28 10:41:06.676: 00:60:b9:0d:ec:1f apfMs1xStateDec

*apfMsConnTask_4: Jun 28 10:41:06.676: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Change state to START (0) last state RUN (20)

*apfMsConnTask_4: Jun 28 10:41:06.676: 00:60:b9:0d:ec:1f pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_4: Jun 28 10:41:06.676: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Initializing policy

*apfMsConnTask_4: Jun 28 10:41:06.676: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Change state to AUTHCHECK (2) last state RUN (20)

*apfMsConnTask_4: Jun 28 10:41:06.676: 00:60:b9:0d:ec:1f 10.160.91.51 AUTHCHECK (2) Change state to 8021X_REQD (3) last state RUN (20)

*apfMsConnTask_4: Jun 28 10:41:06.676: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) DHCP required on AP 3c:ce:73:f7:62:10 vapId 2 apVapId 2for this client

*apfMsConnTask_4: Jun 28 10:41:06.676: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*apfMsConnTask_4: Jun 28 10:41:06.676: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 3c:ce:73:f7:62:10 vapId 2 apVapId 2

*apfMsConnTask_4: Jun 28 10:41:06.676: 00:60:b9:0d:ec:1f apfPemAddUser2 (apf_policy.c:268) Changing state for mobile 00:60:b9:0d:ec:1f on AP 3c:ce:73:f7:62:10 from Associated to Associated

*apfMsConnTask_4: Jun 28 10:41:06.677: 00:60:b9:0d:ec:1f Scheduling deletion of Mobile Station: (callerId: 49) in 1800 seconds

*apfMsConnTask_4: Jun 28 10:41:06.677: 00:60:b9:0d:ec:1f Sending Assoc Response to station on BSSID 3c:ce:73:f7:62:10 (status 0) ApVapId 2 Slot 0

*apfMsConnTask_4: Jun 28 10:41:06.677: 00:60:b9:0d:ec:1f apfProcessAssocReq (apf_80211.c:6290) Changing state for mobile 00:60:b9:0d:ec:1f on AP 3c:ce:73:f7:62:10 from Associated to Associated

*dot1xMsgTask: Jun 28 10:41:06.678: 00:60:b9:0d:ec:1f Creating a PKC PMKID Cache entry for station 00:60:b9:0d:ec:1f (RSN 2)

*dot1xMsgTask: Jun 28 10:41:06.678: 00:60:b9:0d:ec:1f Resetting MSCB PMK Cache Entry 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 10:41:06.679: 00:60:b9:0d:ec:1f Removing BSSID c8:f9:f9:5a:80:81 from PMKID cache of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 10:41:06.679: 00:60:b9:0d:ec:1f Setting active key cache index 0 ---> 8

*dot1xMsgTask: Jun 28 10:41:06.679: 00:60:b9:0d:ec:1f Setting active key cache index 8 ---> 0

*dot1xMsgTask: Jun 28 10:41:06.679: 00:60:b9:0d:ec:1f Adding BSSID 3c:ce:73:f7:62:11 to PMKID cache at index 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 10:41:06.679: New PMKID: (16)

*dot1xMsgTask: Jun 28 10:41:06.679: [0000] 03 12 c0 c5 10 08 ab 14 77 76 f5 62 92 95 82 5a

*dot1xMsgTask: Jun 28 10:41:06.679: 00:60:b9:0d:ec:1f Initiating RSN PSK to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 10:41:06.679: 00:60:b9:0d:ec:1f dot1x - moving mobile 00:60:b9:0d:ec:1f into Force Auth state

*dot1xMsgTask: Jun 28 10:41:06.679: 00:60:b9:0d:ec:1f Skipping EAP-Success to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 10:41:06.679: 00:60:b9:0d:ec:1f Found an cache entry for BSSID 3c:ce:73:f7:62:11 in PMKID cache at index 0 of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 10:41:06.679: Including PMKID in M1 (16)

*dot1xMsgTask: Jun 28 10:41:06.679: [0000] 03 12 c0 c5 10 08 ab 14 77 76 f5 62 92 95 82 5a

*dot1xMsgTask: Jun 28 10:41:06.679: 00:60:b9:0d:ec:1f Starting key exchange to mobile 00:60:b9:0d:ec:1f, data packets will be dropped

*dot1xMsgTask: Jun 28 10:41:06.679: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Dot1x_NW_MsgTask_7: Jun 28 10:41:06.737: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 10:41:06.737: 00:60:b9:0d:ec:1f Received EAPOL-key in PTK_START state (message 2) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 10:41:06.738: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 10:41:06.738: 00:60:b9:0d:ec:1f Sending the random GTK in M3 for WPA2 client 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 10:41:06.738: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01

*Dot1x_NW_MsgTask_7: Jun 28 10:41:06.741: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 10:41:06.741: 00:60:b9:0d:ec:1f Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 10:41:06.742: 00:60:b9:0d:ec:1f apfMs1xStateInc

*Dot1x_NW_MsgTask_7: Jun 28 10:41:06.742: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 10:41:06.742: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) DHCP required on AP 3c:ce:73:f7:62:10 vapId 2 apVapId 2for this client

*Dot1x_NW_MsgTask_7: Jun 28 10:41:06.742: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*Dot1x_NW_MsgTask_7: Jun 28 10:41:06.742: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 3c:ce:73:f7:62:10 vapId 2 apVapId 2

*Dot1x_NW_MsgTask_7: Jun 28 10:41:06.742: 00:60:b9:0d:ec:1f apfMsRunStateInc

*Dot1x_NW_MsgTask_7: Jun 28 10:41:06.742: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Change state to RUN (20) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 10:41:06.742: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Reached PLUMBFASTPATH: from line 5362

*Dot1x_: Jun 28 10:41:06.742: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Adding Fast Path rule

type = Airespace AP Client

on AP 3c:ce:73:f7:62:10, slot 0, interface = 13, QOS = 2

IPv4 ACL ID = 255, IPv6 ACL ID =

*Dot1x_NW_MsgTask_7: Jun 28 10:41:06.742: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 7006 Local Bridging Vlan = 106, Local Bridging intf id = 12

*Dot1x_NW_MsgTask_7: Jun 28 10:41:06.742: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255)

*Dot1x_NW_MsgTask_7: Jun 28 10:41:06.742: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

*pemReceiveTask: Jun 28 10:41:06.742: 00:60:b9:0d:ec:1f 10.160.91.51 Added NPU entry of type 1, dtlFlags 0x0

*apfMsConnTask_5: Jun 28 10:41:44.174: 00:60:b9:0d:ec:1f Reassociation received from mobile on AP c8:f9:f9:5b:0e:e0

*apfMsConnTask_5: Jun 28 10:41:44.174: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1697)

*apfMsConnTask_5: Jun 28 10:41:44.175: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1864)

*apfMsConnTask_5: Jun 28 10:41:44.175: 00:60:b9:0d:ec:1f Applying site-specific Local Bridging override for station 00:60:b9:0d:ec:1f - vapId 2, site 'default-group', interface 'pvoz'

*apfMsConnTask_5: Jun 28 10:41:44.175: 00:60:b9:0d:ec:1f Applying Local Bridging Interface Policy for station 00:60:b9:0d:ec:1f - vlan 106, interface id 12, interface 'pvoz'

*apfMsConnTask_5: Jun 28 10:41:44.175: 00:60:b9:0d:ec:1f processSsidIE statusCode is 0 and status is 0

*apfMsConnTask_5: Jun 28 10:41:44.175: 00:60:b9:0d:ec:1f processSsidIE ssid_done_flag is 0 finish_flag is 0

*apfMsConnTask_5: Jun 28 10:41:44.175: 00:60:b9:0d:ec:1f STA - rates (8): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_5: Jun 28 10:41:44.175: 00:60:b9:0d:ec:1f suppRates statusCode is 0 and gotSuppRatesElement is 1

*apfMsConnTask_5: Jun 28 10:41:44.175: 00:60:b9:0d:ec:1f STA - rates (10): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_5: Jun 28 10:41:44.175: 00:60:b9:0d:ec:1f extSuppRates statusCode is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_5: Jun 28 10:41:44.175: 00:60:b9:0d:ec:1f Processing RSN IE type 48, length 20 for mobile 00:60:b9:0d:ec:1f

*apfMsConnTask_5: Jun 28 10:41:44.175: 00:60:b9:0d:ec:1f pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_5: Jun 28 10:41:44.175: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Deleted mobile LWAPP rule on AP [3c:ce:73:f7:62:10]

*pemReceiveTask: Jun 28 10:41:44.175: 00:60:b9:0d:ec:1f 10.160.91.51 Removed NPU entry.

*apfMsConnTask_5: Jun 28 10:41:44.175: 00:60:b9:0d:ec:1f Updated location for station old AP 3c:ce:73:f7:62:10-0, new AP c8:f9:f9:5b:0e:e0-0

*apfMsConnTask_5: Jun 28 10:41:44.175: 00:60:b9:0d:ec:1f apfMsRunStateDec

*apfMsConnTask_5: Jun 28 10:41:44.175: 00:60:b9:0d:ec:1f apfMs1xStateDec

*apfMsConnTask_5: Jun 28 10:41:44.175: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Change state to START (0) last state RUN (20)

*apfMsConnTask_5: Jun 28 10:41:44.175: 00:60:b9:0d:ec:1f pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_5: Jun 28 10:41:44.175: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Initializing policy

*apfMsConnTask_5: Jun 28 10:41:44.175: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Change state to AUTHCHECK (2) last state RUN (20)

*apfMsConnTask_5: Jun 28 10:41:44.175: 00:60:b9:0d:ec:1f 10.160.91.51 AUTHCHECK (2) Change state to 8021X_REQD (3) last state RUN (20)

*apfMsConnTask_5: Jun 28 10:41:44.175: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) DHCP required on AP c8:f9:f9:5b:0e:e0 vapId 2 apVapId 2for this client

*apfMsConnTask_5: Jun 28 10:41:44.175: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*apfMsConnTask_5: Jun 28 10:41:44.176: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Plumbed mobile LWAPP rule on AP c8:f9:f9:5b:0e:e0 vapId 2 apVapId 2

*apfMsConnTask_5: Jun 28 10:41:44.176: 00:60:b9:0d:ec:1f apfPemAddUser2 (apf_policy.c:268) Changing state for mobile 00:60:b9:0d:ec:1f on AP c8:f9:f9:5b:0e:e0 from Associated to Associated

*apfMsConnTask_5: Jun 28 10:41:44.176: 00:60:b9:0d:ec:1f Scheduling deletion of Mobile Station: (callerId: 49) in 1800 seconds

*apfMsConnTask_5: Jun 28 10:41:44.176: 00:60:b9:0d:ec:1f Sending Assoc Response to station on BSSID c8:f9:f9:5b:0e:e0 (status 0) ApVapId 2 Slot 0

*apfMsConnTask_5: Jun 28 10:41:44.176: 00:60:b9:0d:ec:1f apfProcessAssocReq (apf_80211.c:6290) Changing state for mobile 00:60:b9:0d:ec:1f on AP c8:f9:f9:5b:0e:e0 from Associated to Associated

*dot1xMsgTask: Jun 28 10:41:44.177: 00:60:b9:0d:ec:1f Creating a PKC PMKID Cache entry for station 00:60:b9:0d:ec:1f (RSN 2)

*dot1xMsgTask: Jun 28 10:41:44.177: 00:60:b9:0d:ec:1f Resetting MSCB PMK Cache Entry 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 10:41:44.178: 00:60:b9:0d:ec:1f Removing BSSID 3c:ce:73:f7:62:11 from PMKID cache of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 10:41:44.178: 00:60:b9:0d:ec:1f Setting active key cache index 0 ---> 8

*dot1xMsgTask: Jun 28 10:41:44.178: 00:60:b9:0d:ec:1f Setting active key cache index 8 ---> 0

*dot1xMsgTask: Jun 28 10:41:44.178: 00:60:b9:0d:ec:1f Adding BSSID c8:f9:f9:5b:0e:e1 to PMKID cache at index 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 10:41:44.178: New PMKID: (16)

*dot1xMsgTask: Jun 28 10:41:44.178: [0000] 09 1d 27 25 44 d4 32 7b 4a dc d8 46 6d 8a d4 92

*dot1xMsgTask: Jun 28 10:41:44.178: 00:60:b9:0d:ec:1f Initiating RSN PSK to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 10:41:44.178: 00:60:b9:0d:ec:1f dot1x - moving mobile 00:60:b9:0d:ec:1f into Force Auth state

*dot1xMsgTask: Jun 28 10:41:44.178: 00:60:b9:0d:ec:1f Skipping EAP-Success to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 10:41:44.178: 00:60:b9:0d:ec:1f Found an cache entry for BSSID c8:f9:f9:5b:0e:e1 in PMKID cache at index 0 of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 10:41:44.178: Including PMKID in M1 (16)

*dot1xMsgTask: Jun 28 10:41:44.178: [0000] 09 1d 27 25 44 d4 32 7b 4a dc d8 46 6d 8a d4 92

*dot1xMsgTask: Jun 28 10:41:44.178: 00:60:b9:0d:ec:1f Starting key exchange to mobile 00:60:b9:0d:ec:1f, data packets will be dropped

*dot1xMsgTask: Jun 28 10:41:44.178: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*osapiBsnTimer: Jun 28 10:41:45.219: 00:60:b9:0d:ec:1f 802.1x 'timeoutEvt' Timer expired for station 00:60:b9:0d:ec:1f and for message = M2

*dot1xMsgTask: Jun 28 10:41:45.219: 00:60:b9:0d:ec:1f Retransmit 1 of EAPOL-Key M1 (length 121) for mobile 00:60:b9:0d:ec:1f

*osapiBsnTimer: Jun 28 10:41:46.219: 00:60:b9:0d:ec:1f 802.1x 'timeoutEvt' Timer expired for station 00:60:b9:0d:ec:1f and for message = M2

*dot1xMsgTask: Jun 28 10:41:46.219: 00:60:b9:0d:ec:1f Retransmit 2 of EAPOL-Key M1 (length 121) for mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 10:41:46.226: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 10:41:46.226: 00:60:b9:0d:ec:1f Received EAPOL-key in PTK_START state (message 2) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 10:41:46.226: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 10:41:46.226: 00:60:b9:0d:ec:1f Sending the random GTK in M3 for WPA2 client 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 10:41:46.226: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.03

*Dot1x_NW_MsgTask_7: Jun 28 10:41:46.230: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 10:41:46.230: 00:60:b9:0d:ec:1f Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 10:41:46.230: 00:60:b9:0d:ec:1f apfMs1xStateInc

*Dot1x_NW_MsgTask_7: Jun 28 10:41:46.230: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 10:41:46.230: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) DHCP required on AP c8:f9:f9:5b:0e:e0 vapId 2 apVapId 2for this client

*Dot1x_NW_MsgTask_7: Jun 28 10:41:46.230: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*Dot1x_NW_MsgTask_7: Jun 28 10:41:46.230: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP c8:f9:f9:5b:0e:e0 vapId 2 apVapId 2

*Dot1x_NW_MsgTask_7: Jun 28 10:41:46.230: 00:60:b9:0d:ec:1f apfMsRunStateInc

*Dot1x_NW_MsgTask_7: Jun 28 10:41:46.230: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Change state to RUN (20) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 10:41:46.230: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Reached PLUMBFASTPATH: from line 5362

*Dot1x_: Jun 28 10:41:46.230: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Adding Fast Path rule

type = Airespace AP Client

on AP c8:f9:f9:5b:0e:e0, slot 0, interface = 13, QOS = 2

IPv4 ACL ID = 255, IPv6 ACL ID =

*Dot1x_NW_MsgTask_7: Jun 28 10:41:46.230: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 7006 Local Bridging Vlan = 106, Local Bridging intf id = 12

*Dot1x_NW_MsgTask_7: Jun 28 10:41:46.230: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255)

*Dot1x_NW_MsgTask_7: Jun 28 10:41:46.230: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

(Cisco Controller)

User: admin1

Password:*********

(Cisco Controller) >

(Cisco Controller)

User: logout

Password:*

User:admin

Password:*********

User:admin1

Password:*********

(Cisco Controller) >

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

Second log

debug client 00:60:B9:0D:EC:1F

(Cisco Controller) >debug client 00:60:B9:0D:EC:1F

(Cisco Controller) >*apfMsConnTask_6: Jun 28 11:57:06.181: 00:60:b9:0d:ec:1f Reassociation received from mobile on AP 3c:ce:73:f9:2e:c0

*apfMsConnTask_6: Jun 28 11:57:06.181: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1697)

*apfMsConnTask_6: Jun 28 11:57:06.181: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1864)

*apfMsConnTask_6: Jun 28 11:57:06.181: 00:60:b9:0d:ec:1f Applying site-specific Local Bridging override for station 00:60:b9:0d:ec:1f - vapId 2, site 'default-group', interface 'pvoz'

*apfMsConnTask_6: Jun 28 11:57:06.181: 00:60:b9:0d:ec:1f Applying Local Bridging Interface Policy for station 00:60:b9:0d:ec:1f - vlan 106, interface id 12, interface 'pvoz'

*apfMsConnTask_6: Jun 28 11:57:06.182: 00:60:b9:0d:ec:1f processSsidIE statusCode is 0 and status is 0

*apfMsConnTask_6: Jun 28 11:57:06.182: 00:60:b9:0d:ec:1f processSsidIE ssid_done_flag is 0 finish_flag is 0

*apfMsConnTask_6: Jun 28 11:57:06.182: 00:60:b9:0d:ec:1f STA - rates (8): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_6: Jun 28 11:57:06.182: 00:60:b9:0d:ec:1f suppRates statusCode is 0 and gotSuppRatesElement is 1

*apfMsConnTask_6: Jun 28 11:57:06.182: 00:60:b9:0d:ec:1f STA - rates (10): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_6: Jun 28 11:57:06.182: 00:60:b9:0d:ec:1f extSuppRates statusCode is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_6: Jun 28 11:57:06.182: 00:60:b9:0d:ec:1f Processing RSN IE type 48, length 20 for mobile 00:60:b9:0d:ec:1f

*apfMsConnTask_6: Jun 28 11:57:06.182: 00:60:b9:0d:ec:1f pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_6: Jun 28 11:57:06.182: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Deleted mobile LWAPP rule on AP [c8:f9:f9:5b:0f:70]

*pemReceiveTask: Jun 28 11:57:06.182: 00:60:b9:0d:ec:1f 10.160.91.51 Removed NPU entry.

*apfMsConnTask_6: Jun 28 11:57:06.182: 00:60:b9:0d:ec:1f Updated location for station old AP c8:f9:f9:5b:0f:70-0, new AP 3c:ce:73:f9:2e:c0-0

*apfMsConnTask_6: Jun 28 11:57:06.182: 00:60:b9:0d:ec:1f apfMsRunStateDec

*apfMsConnTask_6: Jun 28 11:57:06.182: 00:60:b9:0d:ec:1f apfMs1xStateDec

*apfMsConnTask_6: Jun 28 11:57:06.182: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Change state to START (0) last state RUN (20)

*apfMsConnTask_6: Jun 28 11:57:06.182: 00:60:b9:0d:ec:1f pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_6: Jun 28 11:57:06.182: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Initializing policy

*apfMsConnTask_6: Jun 28 11:57:06.182: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Change state to AUTHCHECK (2) last state RUN (20)

*apfMsConnTask_6: Jun 28 11:57:06.182: 00:60:b9:0d:ec:1f 10.160.91.51 AUTHCHECK (2) Change state to 8021X_REQD (3) last state RUN (20)

*apfMsConnTask_6: Jun 28 11:57:06.182: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) DHCP required on AP 3c:ce:73:f9:2e:c0 vapId 2 apVapId 2for this client

*apfMsConnTask_6: Jun 28 11:57:06.182: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*apfMsConnTask_6: Jun 28 11:57:06.182: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 3c:ce:73:f9:2e:c0 vapId 2 apVapId 2

*apfMsConnTask_6: Jun 28 11:57:06.182: 00:60:b9:0d:ec:1f apfPemAddUser2 (apf_policy.c:268) Changing state for mobile 00:60:b9:0d:ec:1f on AP 3c:ce:73:f9:2e:c0 from Associated to Associated

*apfMsConnTask_6: Jun 28 11:57:06.183: 00:60:b9:0d:ec:1f Scheduling deletion of Mobile Station: (callerId: 49) in 1800 seconds

*apfMsConnTask_6: Jun 28 11:57:06.183: 00:60:b9:0d:ec:1f Sending Assoc Response to station on BSSID 3c:ce:73:f9:2e:c0 (status 0) ApVapId 2 Slot 0

*apfMsConnTask_6: Jun 28 11:57:06.183: 00:60:b9:0d:ec:1f apfProcessAssocReq (apf_80211.c:6290) Changing state for mobile 00:60:b9:0d:ec:1f on AP 3c:ce:73:f9:2e:c0 from Associated to Associated

*dot1xMsgTask: Jun 28 11:57:06.184: 00:60:b9:0d:ec:1f Creating a PKC PMKID Cache entry for station 00:60:b9:0d:ec:1f (RSN 2)

*dot1xMsgTask: Jun 28 11:57:06.184: 00:60:b9:0d:ec:1f Resetting MSCB PMK Cache Entry 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 11:57:06.185: 00:60:b9:0d:ec:1f Removing BSSID c8:f9:f9:5b:0f:71 from PMKID cache of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 11:57:06.185: 00:60:b9:0d:ec:1f Setting active key cache index 0 ---> 8

*dot1xMsgTask: Jun 28 11:57:06.185: 00:60:b9:0d:ec:1f Setting active key cache index 8 ---> 0

*dot1xMsgTask: Jun 28 11:57:06.185: 00:60:b9:0d:ec:1f Adding BSSID 3c:ce:73:f9:2e:c1 to PMKID cache at index 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 11:57:06.185: New PMKID: (16)

*dot1xMsgTask: Jun 28 11:57:06.185: [0000] 74 1f ee 29 2e 8d fc df 33 97 9a 33 d6 57 d8 be

*dot1xMsgTask: Jun 28 11:57:06.185: 00:60:b9:0d:ec:1f Initiating RSN PSK to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 11:57:06.185: 00:60:b9:0d:ec:1f dot1x - moving mobile 00:60:b9:0d:ec:1f into Force Auth state

*dot1xMsgTask: Jun 28 11:57:06.185: 00:60:b9:0d:ec:1f Skipping EAP-Success to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 11:57:06.185: 00:60:b9:0d:ec:1f Found an cache entry for BSSID 3c:ce:73:f9:2e:c1 in PMKID cache at index 0 of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 11:57:06.185: Including PMKID in M1 (16)

*dot1xMsgTask: Jun 28 11:57:06.185: [0000] 74 1f ee 29 2e 8d fc df 33 97 9a 33 d6 57 d8 be

*dot1xMsgTask: Jun 28 11:57:06.185: 00:60:b9:0d:ec:1f Starting key exchange to mobile 00:60:b9:0d:ec:1f, data packets will be dropped

*dot1xMsgTask: Jun 28 11:57:06.185: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Dot1x_NW_MsgTask_7: Jun 28 11:57:06.236: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 11:57:06.236: 00:60:b9:0d:ec:1f Received EAPOL-key in PTK_START state (message 2) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 11:57:06.236: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 11:57:06.237: 00:60:b9:0d:ec:1f Sending the random GTK in M3 for WPA2 client 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 11:57:06.237: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01

*Dot1x_NW_MsgTask_7: Jun 28 11:57:06.241: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 11:57:06.241: 00:60:b9:0d:ec:1f Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 11:57:06.241: 00:60:b9:0d:ec:1f apfMs1xStateInc

*Dot1x_NW_MsgTask_7: Jun 28 11:57:06.241: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 11:57:06.241: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) DHCP required on AP 3c:ce:73:f9:2e:c0 vapId 2 apVapId 2for this client

*Dot1x_NW_MsgTask_7: Jun 28 11:57:06.241: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*Dot1x_NW_MsgTask_7: Jun 28 11:57:06.241: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 3c:ce:73:f9:2e:c0 vapId 2 apVapId 2

*Dot1x_NW_MsgTask_7: Jun 28 11:57:06.241: 00:60:b9:0d:ec:1f apfMsRunStateInc

*Dot1x_NW_MsgTask_7: Jun 28 11:57:06.241: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Change state to RUN (20) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 11:57:06.241: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Reached PLUMBFASTPATH: from line 5362

*Dot1x_: Jun 28 11:57:06.241: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Adding Fast Path rule

type = Airespace AP Client

on AP 3c:ce:73:f9:2e:c0, slot 0, interface = 13, QOS = 2

IPv4 ACL ID = 255, IPv6 ACL ID =

*Dot1x_NW_MsgTask_7: Jun 28 11:57:06.241: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 7006 Local Bridging Vlan = 106, Local Bridging intf id = 12

*Dot1x_NW_MsgTask_7: Jun 28 11:57:06.241: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255)

*Dot1x_NW_MsgTask_7: Jun 28 11:57:06.241: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

*pemReceiveTask: Jun 28 11:57:06.242: 00:60:b9:0d:ec:1f 10.160.91.51 Added NPU entry of type 1, dtlFlags 0x0

*apfMsConnTask_6: Jun 28 11:58:05.342: 00:60:b9:0d:ec:1f Reassociation received from mobile on AP 3c:ce:73:f9:06:50

*apfMsConnTask_6: Jun 28 11:58:05.342: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1697)

*apfMsConnTask_6: Jun 28 11:58:05.342: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1864)

*apfMsConnTask_6: Jun 28 11:58:05.342: 00:60:b9:0d:ec:1f Applying site-specific Local Bridging override for station 00:60:b9:0d:ec:1f - vapId 2, site 'default-group', interface 'pvoz'

*apfMsConnTask_6: Jun 28 11:58:05.342: 00:60:b9:0d:ec:1f Applying Local Bridging Interface Policy for station 00:60:b9:0d:ec:1f - vlan 106, interface id 12, interface 'pvoz'

*apfMsConnTask_6: Jun 28 11:58:05.342: 00:60:b9:0d:ec:1f processSsidIE statusCode is 0 and status is 0

*apfMsConnTask_6: Jun 28 11:58:05.342: 00:60:b9:0d:ec:1f processSsidIE ssid_done_flag is 0 finish_flag is 0

*apfMsConnTask_6: Jun 28 11:58:05.342: 00:60:b9:0d:ec:1f STA - rates (8): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_6: Jun 28 11:58:05.342: 00:60:b9:0d:ec:1f suppRates statusCode is 0 and gotSuppRatesElement is 1

*apfMsConnTask_6: Jun 28 11:58:05.342: 00:60:b9:0d:ec:1f STA - rates (10): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_6: Jun 28 11:58:05.342: 00:60:b9:0d:ec:1f extSuppRates statusCode is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_6: Jun 28 11:58:05.343: 00:60:b9:0d:ec:1f Processing RSN IE type 48, length 20 for mobile 00:60:b9:0d:ec:1f

*apfMsConnTask_6: Jun 28 11:58:05.343: 00:60:b9:0d:ec:1f pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_6: Jun 28 11:58:05.343: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Deleted mobile LWAPP rule on AP [3c:ce:73:f9:2e:c0]

*pemReceiveTask: Jun 28 11:58:05.343: 00:60:b9:0d:ec:1f 10.160.91.51 Removed NPU entry.

*apfMsConnTask_6: Jun 28 11:58:05.343: 00:60:b9:0d:ec:1f Updated location for station old AP 3c:ce:73:f9:2e:c0-0, new AP 3c:ce:73:f9:06:50-0

*apfMsConnTask_6: Jun 28 11:58:05.343: 00:60:b9:0d:ec:1f apfMsRunStateDec

*apfMsConnTask_6: Jun 28 11:58:05.343: 00:60:b9:0d:ec:1f apfMs1xStateDec

*apfMsConnTask_6: Jun 28 11:58:05.343: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Change state to START (0) last state RUN (20)

*apfMsConnTask_6: Jun 28 11:58:05.343: 00:60:b9:0d:ec:1f pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_6: Jun 28 11:58:05.343: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Initializing policy

*apfMsConnTask_6: Jun 28 11:58:05.343: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Change state to AUTHCHECK (2) last state RUN (20)

*apfMsConnTask_6: Jun 28 11:58:05.343: 00:60:b9:0d:ec:1f 10.160.91.51 AUTHCHECK (2) Change state to 8021X_REQD (3) last state RUN (20)

*apfMsConnTask_6: Jun 28 11:58:05.343: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) DHCP required on AP 3c:ce:73:f9:06:50 vapId 2 apVapId 2for this client

*apfMsConnTask_6: Jun 28 11:58:05.343: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*apfMsConnTask_6: Jun 28 11:58:05.343: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 3c:ce:73:f9:06:50 vapId 2 apVapId 2

*apfMsConnTask_6: Jun 28 11:58:05.343: 00:60:b9:0d:ec:1f apfPemAddUser2 (apf_policy.c:268) Changing state for mobile 00:60:b9:0d:ec:1f on AP 3c:ce:73:f9:06:50 from Associated to Associated

*apfMsConnTask_6: Jun 28 11:58:05.343: 00:60:b9:0d:ec:1f Scheduling deletion of Mobile Station: (callerId: 49) in 1800 seconds

*apfMsConnTask_6: Jun 28 11:58:05.343: 00:60:b9:0d:ec:1f Sending Assoc Response to station on BSSID 3c:ce:73:f9:06:50 (status 0) ApVapId 2 Slot 0

*apfMsConnTask_6: Jun 28 11:58:05.343: 00:60:b9:0d:ec:1f apfProcessAssocReq (apf_80211.c:6290) Changing state for mobile 00:60:b9:0d:ec:1f on AP 3c:ce:73:f9:06:50 from Associated to Associated

*dot1xMsgTask: Jun 28 11:58:05.346: 00:60:b9:0d:ec:1f Creating a PKC PMKID Cache entry for station 00:60:b9:0d:ec:1f (RSN 2)

*dot1xMsgTask: Jun 28 11:58:05.346: 00:60:b9:0d:ec:1f Resetting MSCB PMK Cache Entry 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 11:58:05.346: 00:60:b9:0d:ec:1f Removing BSSID 3c:ce:73:f9:2e:c1 from PMKID cache of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 11:58:05.346: 00:60:b9:0d:ec:1f Setting active key cache index 0 ---> 8

*dot1xMsgTask: Jun 28 11:58:05.346: 00:60:b9:0d:ec:1f Setting active key cache index 8 ---> 0

*dot1xMsgTask: Jun 28 11:58:05.346: 00:60:b9:0d:ec:1f Adding BSSID 3c:ce:73:f9:06:51 to PMKID cache at index 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 11:58:05.346: New PMKID: (16)

*dot1xMsgTask: Jun 28 11:58:05.346: [0000] 2c de dd 37 b5 fb 3c 2d 0e a4 47 e2 fd 62 19 fe

*dot1xMsgTask: Jun 28 11:58:05.346: 00:60:b9:0d:ec:1f Initiating RSN PSK to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 11:58:05.346: 00:60:b9:0d:ec:1f dot1x - moving mobile 00:60:b9:0d:ec:1f into Force Auth state

*dot1xMsgTask: Jun 28 11:58:05.346: 00:60:b9:0d:ec:1f Skipping EAP-Success to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 11:58:05.346: 00:60:b9:0d:ec:1f Found an cache entry for BSSID 3c:ce:73:f9:06:51 in PMKID cache at index 0 of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 11:58:05.346: Including PMKID in M1 (16)

*dot1xMsgTask: Jun 28 11:58:05.346: [0000] 2c de dd 37 b5 fb 3c 2d 0e a4 47 e2 fd 62 19 fe

*dot1xMsgTask: Jun 28 11:58:05.346: 00:60:b9:0d:ec:1f Starting key exchange to mobile 00:60:b9:0d:ec:1f, data packets will be dropped

*dot1xMsgTask: Jun 28 11:58:05.346: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Dot1x_NW_MsgTask_7: Jun 28 11:58:05.404: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 11:58:05.404: 00:60:b9:0d:ec:1f Received EAPOL-key in PTK_START state (message 2) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 11:58:05.404: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 11:58:05.404: 00:60:b9:0d:ec:1f Sending the random GTK in M3 for WPA2 client 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 11:58:05.405: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01

*Dot1x_NW_MsgTask_7: Jun 28 11:58:05.412: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 11:58:05.413: 00:60:b9:0d:ec:1f Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 11:58:05.413: 00:60:b9:0d:ec:1f apfMs1xStateInc

*Dot1x_NW_MsgTask_7: Jun 28 11:58:05.413: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 11:58:05.413: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) DHCP required on AP 3c:ce:73:f9:06:50 vapId 2 apVapId 2for this client

*Dot1x_NW_MsgTask_7: Jun 28 11:58:05.413: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*Dot1x_NW_MsgTask_7: Jun 28 11:58:05.413: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 3c:ce:73:f9:06:50 vapId 2 apVapId 2

*Dot1x_NW_MsgTask_7: Jun 28 11:58:05.413: 00:60:b9:0d:ec:1f apfMsRunStateInc

*Dot1x_NW_MsgTask_7: Jun 28 11:58:05.413: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Change state to RUN (20) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 11:58:05.413: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Reached PLUMBFASTPATH: from line 5362

*Dot1x_: Jun 28 11:58:05.413: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Adding Fast Path rule

type = Airespace AP Client

on AP 3c:ce:73:f9:06:50, slot 0, interface = 13, QOS = 2

IPv4 ACL ID = 255, IPv6 ACL ID =

*Dot1x_NW_MsgTask_7: Jun 28 11:58:05.413: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 7006 Local Bridging Vlan = 106, Local Bridging intf id = 12

*Dot1x_NW_MsgTask_7: Jun 28 11:58:05.413: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255)

*Dot1x_NW_MsgTask_7: Jun 28 11:58:05.413: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

*pemReceiveTask: Jun 28 11:58:05.413: 00:60:b9:0d:ec:1f 10.160.91.51 Added NPU entry of type 1, dtlFlags 0x0

*apfMsConnTask_4: Jun 28 11:58:16.473: 00:60:b9:0d:ec:1f Reassociation received from mobile on AP 3c:ce:73:f7:62:10

*apfMsConnTask_4: Jun 28 11:58:16.473: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1697)

*apfMsConnTask_4: Jun 28 11:58:16.473: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1864)

*apfMsConnTask_4: Jun 28 11:58:16.473: 00:60:b9:0d:ec:1f Applying site-specific Local Bridging override for station 00:60:b9:0d:ec:1f - vapId 2, site 'default-group', interface 'pvoz'

*apfMsConnTask_4: Jun 28 11:58:16.473: 00:60:b9:0d:ec:1f Applying Local Bridging Interface Policy for station 00:60:b9:0d:ec:1f - vlan 106, interface id 12, interface 'pvoz'

*apfMsConnTask_4: Jun 28 11:58:16.473: 00:60:b9:0d:ec:1f processSsidIE statusCode is 0 and status is 0

*apfMsConnTask_4: Jun 28 11:58:16.473: 00:60:b9:0d:ec:1f processSsidIE ssid_done_flag is 0 finish_flag is 0

*apfMsConnTask_4: Jun 28 11:58:16.473: 00:60:b9:0d:ec:1f STA - rates (8): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_4: Jun 28 11:58:16.474: 00:60:b9:0d:ec:1f suppRates statusCode is 0 and gotSuppRatesElement is 1

*apfMsConnTask_4: Jun 28 11:58:16.474: 00:60:b9:0d:ec:1f STA - rates (10): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_4: Jun 28 11:58:16.474: 00:60:b9:0d:ec:1f extSuppRates statusCode is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_4: Jun 28 11:58:16.474: 00:60:b9:0d:ec:1f Processing RSN IE type 48, length 20 for mobile 00:60:b9:0d:ec:1f

*apfMsConnTask_4: Jun 28 11:58:16.474: 00:60:b9:0d:ec:1f pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_4: Jun 28 11:58:16.474: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Deleted mobile LWAPP rule on AP [3c:ce:73:f9:06:50]

*pemReceiveTask: Jun 28 11:58:16.474: 00:60:b9:0d:ec:1f 10.160.91.51 Removed NPU entry.

*apfMsConnTask_4: Jun 28 11:58:16.474: 00:60:b9:0d:ec:1f Updated location for station old AP 3c:ce:73:f9:06:50-0, new AP 3c:ce:73:f7:62:10-0

*apfMsConnTask_4: Jun 28 11:58:16.474: 00:60:b9:0d:ec:1f apfMsRunStateDec

*apfMsConnTask_4: Jun 28 11:58:16.474: 00:60:b9:0d:ec:1f apfMs1xStateDec

*apfMsConnTask_4: Jun 28 11:58:16.474: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Change state to START (0) last state RUN (20)

*apfMsConnTask_4: Jun 28 11:58:16.474: 00:60:b9:0d:ec:1f pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_4: Jun 28 11:58:16.474: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Initializing policy

*apfMsConnTask_4: Jun 28 11:58:16.474: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Change state to AUTHCHECK (2) last state RUN (20)

*apfMsConnTask_4: Jun 28 11:58:16.474: 00:60:b9:0d:ec:1f 10.160.91.51 AUTHCHECK (2) Change state to 8021X_REQD (3) last state RUN (20)

*apfMsConnTask_4: Jun 28 11:58:16.474: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) DHCP required on AP 3c:ce:73:f7:62:10 vapId 2 apVapId 2for this client

*apfMsConnTask_4: Jun 28 11:58:16.474: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*apfMsConnTask_4: Jun 28 11:58:16.474: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 3c:ce:73:f7:62:10 vapId 2 apVapId 2

*apfMsConnTask_4: Jun 28 11:58:16.474: 00:60:b9:0d:ec:1f apfPemAddUser2 (apf_policy.c:268) Changing state for mobile 00:60:b9:0d:ec:1f on AP 3c:ce:73:f7:62:10 from Associated to Associated

*apfMsConnTask_4: Jun 28 11:58:16.474: 00:60:b9:0d:ec:1f Scheduling deletion of Mobile Station: (callerId: 49) in 1800 seconds

*apfMsConnTask_4: Jun 28 11:58:16.474: 00:60:b9:0d:ec:1f Sending Assoc Response to station on BSSID 3c:ce:73:f7:62:10 (status 0) ApVapId 2 Slot 0

*apfMsConnTask_4: Jun 28 11:58:16.475: 00:60:b9:0d:ec:1f apfProcessAssocReq (apf_80211.c:6290) Changing state for mobile 00:60:b9:0d:ec:1f on AP 3c:ce:73:f7:62:10 from Associated to Associated

*dot1xMsgTask: Jun 28 11:58:16.476: 00:60:b9:0d:ec:1f Creating a PKC PMKID Cache entry for station 00:60:b9:0d:ec:1f (RSN 2)

*dot1xMsgTask: Jun 28 11:58:16.476: 00:60:b9:0d:ec:1f Resetting MSCB PMK Cache Entry 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 11:58:16.476: 00:60:b9:0d:ec:1f Removing BSSID 3c:ce:73:f9:06:51 from PMKID cache of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 11:58:16.476: 00:60:b9:0d:ec:1f Setting active key cache index 0 ---> 8

*dot1xMsgTask: Jun 28 11:58:16.476: 00:60:b9:0d:ec:1f Setting active key cache index 8 ---> 0

*dot1xMsgTask: Jun 28 11:58:16.476: 00:60:b9:0d:ec:1f Adding BSSID 3c:ce:73:f7:62:11 to PMKID cache at index 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 11:58:16.476: New PMKID: (16)

*dot1xMsgTask: Jun 28 11:58:16.476: [0000] 03 12 c0 c5 10 08 ab 14 77 76 f5 62 92 95 82 5a

*dot1xMsgTask: Jun 28 11:58:16.476: 00:60:b9:0d:ec:1f Initiating RSN PSK to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 11:58:16.476: 00:60:b9:0d:ec:1f dot1x - moving mobile 00:60:b9:0d:ec:1f into Force Auth state

*dot1xMsgTask: Jun 28 11:58:16.477: 00:60:b9:0d:ec:1f Skipping EAP-Success to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 11:58:16.477: 00:60:b9:0d:ec:1f Found an cache entry for BSSID 3c:ce:73:f7:62:11 in PMKID cache at index 0 of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 11:58:16.477: Including PMKID in M1 (16)

*dot1xMsgTask: Jun 28 11:58:16.477: [0000] 03 12 c0 c5 10 08 ab 14 77 76 f5 62 92 95 82 5a

*dot1xMsgTask: Jun 28 11:58:16.477: 00:60:b9:0d:ec:1f Starting key exchange to mobile 00:60:b9:0d:ec:1f, data packets will be dropped

*dot1xMsgTask: Jun 28 11:58:16.477: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Dot1x_NW_MsgTask_7: Jun 28 11:58:16.532: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 11:58:16.532: 00:60:b9:0d:ec:1f Received EAPOL-key in PTK_START state (message 2) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 11:58:16.532: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 11:58:16.532: 00:60:b9:0d:ec:1f Sending the random GTK in M3 for WPA2 client 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 11:58:16.532: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01

*Dot1x_NW_MsgTask_7: Jun 28 11:58:16.537: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 11:58:16.537: 00:60:b9:0d:ec:1f Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 11:58:16.537: 00:60:b9:0d:ec:1f apfMs1xStateInc

*Dot1x_NW_MsgTask_7: Jun 28 11:58:16.537: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 11:58:16.537: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) DHCP required on AP 3c:ce:73:f7:62:10 vapId 2 apVapId 2for this client

*Dot1x_NW_MsgTask_7: Jun 28 11:58:16.537: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*Dot1x_NW_MsgTask_7: Jun 28 11:58:16.537: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 3c:ce:73:f7:62:10 vapId 2 apVapId 2

*Dot1x_NW_MsgTask_7: Jun 28 11:58:16.537: 00:60:b9:0d:ec:1f apfMsRunStateInc

*Dot1x_NW_MsgTask_7: Jun 28 11:58:16.537: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Change state to RUN (20) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 11:58:16.537: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Reached PLUMBFASTPATH: from line 5362

*Dot1x_: Jun 28 11:58:16.537: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Adding Fast Path rule

type = Airespace AP Client

on AP 3c:ce:73:f7:62:10, slot 0, interface = 13, QOS = 2

IPv4 ACL ID = 255, IPv6 ACL ID =

*Dot1x_NW_MsgTask_7: Jun 28 11:58:16.537: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 7006 Local Bridging Vlan = 106, Local Bridging intf id = 12

*Dot1x_NW_MsgTask_7: Jun 28 11:58:16.538: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255)

*Dot1x_NW_MsgTask_7: Jun 28 11:58:16.538: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

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

Third log:

debug client 00:60:B9:0D:EC:!F 1F

(Cisco Controller) >*pemReceiveTask: Jun 28 11:58:16.538: 00:60:b9:0d:ec:1f 10.160.91.51 Added NPU entry of type 1, dtlFlags 0x0

*apfMsConnTask_6: Jun 28 12:08:12.696: 00:60:b9:0d:ec:1f Reassociation received from mobile on AP 3c:ce:73:f9:2e:c0

*apfMsConnTask_6: Jun 28 12:08:12.696: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1697)

*apfMsConnTask_6: Jun 28 12:08:12.696: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1864)

*apfMsConnTask_6: Jun 28 12:08:12.696: 00:60:b9:0d:ec:1f Applying site-specific Local Bridging override for station 00:60:b9:0d:ec:1f - vapId 2, site 'default-group', interface 'pvoz'

*apfMsConnTask_6: Jun 28 12:08:12.696: 00:60:b9:0d:ec:1f Applying Local Bridging Interface Policy for station 00:60:b9:0d:ec:1f - vlan 106, interface id 12, interface 'pvoz'

*apfMsConnTask_6: Jun 28 12:08:12.696: 00:60:b9:0d:ec:1f processSsidIE statusCode is 0 and status is 0

*apfMsConnTask_6: Jun 28 12:08:12.696: 00:60:b9:0d:ec:1f processSsidIE ssid_done_flag is 0 finish_flag is 0

*apfMsConnTask_6: Jun 28 12:08:12.696: 00:60:b9:0d:ec:1f STA - rates (8): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_6: Jun 28 12:08:12.696: 00:60:b9:0d:ec:1f suppRates statusCode is 0 and gotSuppRatesElement is 1

*apfMsConnTask_6: Jun 28 12:08:12.696: 00:60:b9:0d:ec:1f STA - rates (10): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_6: Jun 28 12:08:12.696: 00:60:b9:0d:ec:1f extSuppRates statusCode is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_6: Jun 28 12:08:12.696: 00:60:b9:0d:ec:1f Processing RSN IE type 48, length 20 for mobile 00:60:b9:0d:ec:1f

*apfMsConnTask_6: Jun 28 12:08:12.696: 00:60:b9:0d:ec:1f pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_6: Jun 28 12:08:12.697: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Deleted mobile LWAPP rule on AP [3c:ce:73:f8:e1:00]

*pemReceiveTask: Jun 28 12:08:12.697: 00:60:b9:0d:ec:1f 10.160.91.51 Removed NPU entry.

*apfMsConnTask_6: Jun 28 12:08:12.697: 00:60:b9:0d:ec:1f Updated location for station old AP 3c:ce:73:f8:e1:00-0, new AP 3c:ce:73:f9:2e:c0-0

*apfMsConnTask_6: Jun 28 12:08:12.697: 00:60:b9:0d:ec:1f apfMsRunStateDec

*apfMsConnTask_6: Jun 28 12:08:12.697: 00:60:b9:0d:ec:1f apfMs1xStateDec

*apfMsConnTask_6: Jun 28 12:08:12.697: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Change state to START (0) last state RUN (20)

*apfMsConnTask_6: Jun 28 12:08:12.697: 00:60:b9:0d:ec:1f pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_6: Jun 28 12:08:12.697: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Initializing policy

*apfMsConnTask_6: Jun 28 12:08:12.697: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Change state to AUTHCHECK (2) last state RUN (20)

*apfMsConnTask_6: Jun 28 12:08:12.697: 00:60:b9:0d:ec:1f 10.160.91.51 AUTHCHECK (2) Change state to 8021X_REQD (3) last state RUN (20)

*apfMsConnTask_6: Jun 28 12:08:12.697: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) DHCP required on AP 3c:ce:73:f9:2e:c0 vapId 2 apVapId 2for this client

*apfMsConnTask_6: Jun 28 12:08:12.697: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*apfMsConnTask_6: Jun 28 12:08:12.697: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 3c:ce:73:f9:2e:c0 vapId 2 apVapId 2

*apfMsConnTask_6: Jun 28 12:08:12.697: 00:60:b9:0d:ec:1f apfPemAddUser2 (apf_policy.c:268) Changing state for mobile 00:60:b9:0d:ec:1f on AP 3c:ce:73:f9:2e:c0 from Associated to Associated

*apfMsConnTask_6: Jun 28 12:08:12.697: 00:60:b9:0d:ec:1f Scheduling deletion of Mobile Station: (callerId: 49) in 1800 seconds

*apfMsConnTask_6: Jun 28 12:08:12.697: 00:60:b9:0d:ec:1f Sending Assoc Response to station on BSSID 3c:ce:73:f9:2e:c0 (status 0) ApVapId 2 Slot 0

*apfMsConnTask_6: Jun 28 12:08:12.697: 00:60:b9:0d:ec:1f apfProcessAssocReq (apf_80211.c:6290) Changing state for mobile 00:60:b9:0d:ec:1f on AP 3c:ce:73:f9:2e:c0 from Associated to Associated

*dot1xMsgTask: Jun 28 12:08:12.699: 00:60:b9:0d:ec:1f Creating a PKC PMKID Cache entry for station 00:60:b9:0d:ec:1f (RSN 2)

*dot1xMsgTask: Jun 28 12:08:12.700: 00:60:b9:0d:ec:1f Resetting MSCB PMK Cache Entry 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:08:12.700: 00:60:b9:0d:ec:1f Removing BSSID 3c:ce:73:f8:e1:01 from PMKID cache of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:08:12.700: 00:60:b9:0d:ec:1f Setting active key cache index 0 ---> 8

*dot1xMsgTask: Jun 28 12:08:12.700: 00:60:b9:0d:ec:1f Setting active key cache index 8 ---> 0

*dot1xMsgTask: Jun 28 12:08:12.700: 00:60:b9:0d:ec:1f Adding BSSID 3c:ce:73:f9:2e:c1 to PMKID cache at index 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:08:12.700: New PMKID: (16)

*dot1xMsgTask: Jun 28 12:08:12.700: [0000] 74 1f ee 29 2e 8d fc df 33 97 9a 33 d6 57 d8 be

*dot1xMsgTask: Jun 28 12:08:12.700: 00:60:b9:0d:ec:1f Initiating RSN PSK to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:08:12.700: 00:60:b9:0d:ec:1f dot1x - moving mobile 00:60:b9:0d:ec:1f into Force Auth state

*dot1xMsgTask: Jun 28 12:08:12.700: 00:60:b9:0d:ec:1f Skipping EAP-Success to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:08:12.700: 00:60:b9:0d:ec:1f Found an cache entry for BSSID 3c:ce:73:f9:2e:c1 in PMKID cache at index 0 of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:08:12.700: Including PMKID in M1 (16)

*dot1xMsgTask: Jun 28 12:08:12.700: [0000] 74 1f ee 29 2e 8d fc df 33 97 9a 33 d6 57 d8 be

*dot1xMsgTask: Jun 28 12:08:12.700: 00:60:b9:0d:ec:1f Starting key exchange to mobile 00:60:b9:0d:ec:1f, data packets will be dropped

*dot1xMsgTask: Jun 28 12:08:12.700: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Dot1x_NW_MsgTask_7: Jun 28 12:08:12.728: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:08:12.728: 00:60:b9:0d:ec:1f Received EAPOL-key in PTK_START state (message 2) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:08:12.729: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:08:12.729: 00:60:b9:0d:ec:1f Sending the random GTK in M3 for WPA2 client 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:08:12.729: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01

*Dot1x_NW_MsgTask_7: Jun 28 12:08:12.734: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:08:12.734: 00:60:b9:0d:ec:1f Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:08:12.734: 00:60:b9:0d:ec:1f apfMs1xStateInc

*Dot1x_NW_MsgTask_7: Jun 28 12:08:12.734: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 12:08:12.734: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) DHCP required on AP 3c:ce:73:f9:2e:c0 vapId 2 apVapId 2for this client

*Dot1x_NW_MsgTask_7: Jun 28 12:08:12.734: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*Dot1x_NW_MsgTask_7: Jun 28 12:08:12.734: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 3c:ce:73:f9:2e:c0 vapId 2 apVapId 2

*Dot1x_NW_MsgTask_7: Jun 28 12:08:12.734: 00:60:b9:0d:ec:1f apfMsRunStateInc

*Dot1x_NW_MsgTask_7: Jun 28 12:08:12.734: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Change state to RUN (20) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 12:08:12.734: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Reached PLUMBFASTPATH: from line 5362

*Dot1x_: Jun 28 12:08:12.734: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Adding Fast Path rule

type = Airespace AP Client

on AP 3c:ce:73:f9:2e:c0, slot 0, interface = 13, QOS = 2

IPv4 ACL ID = 255, IPv6 ACL ID =

*Dot1x_NW_MsgTask_7: Jun 28 12:08:12.734: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 7006 Local Bridging Vlan = 106, Local Bridging intf id = 12

*Dot1x_NW_MsgTask_7: Jun 28 12:08:12.734: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255)

*Dot1x_NW_MsgTask_7: Jun 28 12:08:12.734: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

*pemReceiveTask: Jun 28 12:08:12.735: 00:60:b9:0d:ec:1f 10.160.91.51 Added NPU entry of type 1, dtlFlags 0x0

*apfMsConnTask_4: Jun 28 12:08:39.132: 00:60:b9:0d:ec:1f Reassociation received from mobile on AP 3c:ce:73:f7:62:10

*apfMsConnTask_4: Jun 28 12:08:39.132: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1697)

*apfMsConnTask_4: Jun 28 12:08:39.132: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1864)

*apfMsConnTask_4: Jun 28 12:08:39.132: 00:60:b9:0d:ec:1f Applying site-specific Local Bridging override for station 00:60:b9:0d:ec:1f - vapId 2, site 'default-group', interface 'pvoz'

*apfMsConnTask_4: Jun 28 12:08:39.132: 00:60:b9:0d:ec:1f Applying Local Bridging Interface Policy for station 00:60:b9:0d:ec:1f - vlan 106, interface id 12, interface 'pvoz'

*apfMsConnTask_4: Jun 28 12:08:39.132: 00:60:b9:0d:ec:1f processSsidIE statusCode is 0 and status is 0

*apfMsConnTask_4: Jun 28 12:08:39.132: 00:60:b9:0d:ec:1f processSsidIE ssid_done_flag is 0 finish_flag is 0

*apfMsConnTask_4: Jun 28 12:08:39.132: 00:60:b9:0d:ec:1f STA - rates (8): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_4: Jun 28 12:08:39.132: 00:60:b9:0d:ec:1f suppRates statusCode is 0 and gotSuppRatesElement is 1

*apfMsConnTask_4: Jun 28 12:08:39.132: 00:60:b9:0d:ec:1f STA - rates (10): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_4: Jun 28 12:08:39.132: 00:60:b9:0d:ec:1f extSuppRates statusCode is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_4: Jun 28 12:08:39.132: 00:60:b9:0d:ec:1f Processing RSN IE type 48, length 20 for mobile 00:60:b9:0d:ec:1f

*apfMsConnTask_4: Jun 28 12:08:39.132: 00:60:b9:0d:ec:1f pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_4: Jun 28 12:08:39.132: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Deleted mobile LWAPP rule on AP [3c:ce:73:f9:2e:c0]

*apfMsConnTask_4: Jun 28 12:08:39.132: 00:60:b9:0d:ec:1f Updated location for station old AP 3c:ce:73:f9:2e:c0-0, new AP 3c:ce:73:f7:62:10-0

*apfMsConnTask_4: Jun 28 12:08:39.132: 00:60:b9:0d:ec:1f apfMsRunStateDec

*apfMsConnTask_4: Jun 28 12:08:39.133: 00:60:b9:0d:ec:1f apfMs1xStateDec

*apfMsConnTask_4: Jun 28 12:08:39.133: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Change state to START (0) last state RUN (20)

*apfMsConnTask_4: Jun 28 12:08:39.133: 00:60:b9:0d:ec:1f pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_4: Jun 28 12:08:39.133: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Initializing policy

*apfMsConnTask_4: Jun 28 12:08:39.133: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Change state to AUTHCHECK (2) last state RUN (20)

*apfMsConnTask_4: Jun 28 12:08:39.133: 00:60:b9:0d:ec:1f 10.160.91.51 AUTHCHECK (2) Change state to 8021X_REQD (3) last state RUN (20)

*apfMsConnTask_4: Jun 28 12:08:39.133: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) DHCP required on AP 3c:ce:73:f7:62:10 vapId 2 apVapId 2for this client

*apfMsConnTask_4: Jun 28 12:08:39.133: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*apfMsConnTask_4: Jun 28 12:08:39.133: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 3c:ce:73:f7:62:10 vapId 2 apVapId 2

*apfMsConnTask_4: Jun 28 12:08:39.133: 00:60:b9:0d:ec:1f apfPemAddUser2 (apf_policy.c:268) Changing state for mobile 00:60:b9:0d:ec:1f on AP 3c:ce:73:f7:62:10 from Associated to Associated

*apfMsConnTask_4: Jun 28 12:08:39.133: 00:60:b9:0d:ec:1f Scheduling deletion of Mobile Station: (callerId: 49) in 1800 seconds

*apfMsConnTask_4: Jun 28 12:08:39.133: 00:60:b9:0d:ec:1f Sending Assoc Response to station on BSSID 3c:ce:73:f7:62:10 (status 0) ApVapId 2 Slot 0

*apfMsConnTask_4: Jun 28 12:08:39.133: 00:60:b9:0d:ec:1f apfProcessAssocReq (apf_80211.c:6290) Changing state for mobile 00:60:b9:0d:ec:1f on AP 3c:ce:73:f7:62:10 from Associated to Associated

*pemReceiveTask: Jun 28 12:08:39.133: 00:60:b9:0d:ec:1f 10.160.91.51 Removed NPU entry.

*dot1xMsgTask: Jun 28 12:08:39.135: 00:60:b9:0d:ec:1f Creating a PKC PMKID Cache entry for station 00:60:b9:0d:ec:1f (RSN 2)

*dot1xMsgTask: Jun 28 12:08:39.135: 00:60:b9:0d:ec:1f Resetting MSCB PMK Cache Entry 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:08:39.135: 00:60:b9:0d:ec:1f Removing BSSID 3c:ce:73:f9:2e:c1 from PMKID cache of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:08:39.135: 00:60:b9:0d:ec:1f Setting active key cache index 0 ---> 8

*dot1xMsgTask: Jun 28 12:08:39.135: 00:60:b9:0d:ec:1f Setting active key cache index 8 ---> 0

*dot1xMsgTask: Jun 28 12:08:39.135: 00:60:b9:0d:ec:1f Adding BSSID 3c:ce:73:f7:62:11 to PMKID cache at index 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:08:39.135: New PMKID: (16)

*dot1xMsgTask: Jun 28 12:08:39.135: [0000] 03 12 c0 c5 10 08 ab 14 77 76 f5 62 92 95 82 5a

*dot1xMsgTask: Jun 28 12:08:39.135: 00:60:b9:0d:ec:1f Initiating RSN PSK to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:08:39.135: 00:60:b9:0d:ec:1f dot1x - moving mobile 00:60:b9:0d:ec:1f into Force Auth state

*dot1xMsgTask: Jun 28 12:08:39.135: 00:60:b9:0d:ec:1f Skipping EAP-Success to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:08:39.136: 00:60:b9:0d:ec:1f Found an cache entry for BSSID 3c:ce:73:f7:62:11 in PMKID cache at index 0 of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:08:39.136: Including PMKID in M1 (16)

*dot1xMsgTask: Jun 28 12:08:39.136: [0000] 03 12 c0 c5 10 08 ab 14 77 76 f5 62 92 95 82 5a

*dot1xMsgTask: Jun 28 12:08:39.136: 00:60:b9:0d:ec:1f Starting key exchange to mobile 00:60:b9:0d:ec:1f, data packets will be dropped

*dot1xMsgTask: Jun 28 12:08:39.136: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Dot1x_NW_MsgTask_7: Jun 28 12:08:39.213: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:08:39.213: 00:60:b9:0d:ec:1f Received EAPOL-key in PTK_START state (message 2) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:08:39.213: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:08:39.213: 00:60:b9:0d:ec:1f Sending the random GTK in M3 for WPA2 client 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:08:39.213: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01

*Dot1x_NW_MsgTask_7: Jun 28 12:08:39.220: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:08:39.220: 00:60:b9:0d:ec:1f Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:08:39.220: 00:60:b9:0d:ec:1f apfMs1xStateInc

*Dot1x_NW_MsgTask_7: Jun 28 12:08:39.220: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 12:08:39.220: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) DHCP required on AP 3c:ce:73:f7:62:10 vapId 2 apVapId 2for this client

*Dot1x_NW_MsgTask_7: Jun 28 12:08:39.220: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*Dot1x_NW_MsgTask_7: Jun 28 12:08:39.220: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 3c:ce:73:f7:62:10 vapId 2 apVapId 2

*Dot1x_NW_MsgTask_7: Jun 28 12:08:39.220: 00:60:b9:0d:ec:1f apfMsRunStateInc

*Dot1x_NW_MsgTask_7: Jun 28 12:08:39.220: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Change state to RUN (20) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 12:08:39.220: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Reached PLUMBFASTPATH: from line 5362

*Dot1x_: Jun 28 12:08:39.220: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Adding Fast Path rule

type = Airespace AP Client

on AP 3c:ce:73:f7:62:10, slot 0, interface = 13, QOS = 2

IPv4 ACL ID = 255, IPv6 ACL ID =

*Dot1x_NW_MsgTask_7: Jun 28 12:08:39.220: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 7006 Local Bridging Vlan = 106, Local Bridging intf id = 12

*Dot1x_NW_MsgTask_7: Jun 28 12:08:39.220: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255)

*Dot1x_NW_MsgTask_7: Jun 28 12:08:39.220: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

*pemReceiveTask: Jun 28 12:08:39.221: 00:60:b9:0d:ec:1f 10.160.91.51 Added NPU entry of type 1, dtlFlags 0x0

*apfMsConnTask_1: Jun 28 12:10:07.011: 00:60:b9:0d:ec:1f Reassociation received from mobile on AP c8:f9:f9:2b:42:d0

*apfMsConnTask_1: Jun 28 12:10:07.011: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1697)

*apfMsConnTask_1: Jun 28 12:10:07.011: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1864)

*apfMsConnTask_1: Jun 28 12:10:07.011: 00:60:b9:0d:ec:1f Applying site-specific Local Bridging override for station 00:60:b9:0d:ec:1f - vapId 2, site 'default-group', interface 'pvoz'

*apfMsConnTask_1: Jun 28 12:10:07.011: 00:60:b9:0d:ec:1f Applying Local Bridging Interface Policy for station 00:60:b9:0d:ec:1f - vlan 106, interface id 12, interface 'pvoz'

*apfMsConnTask_1: Jun 28 12:10:07.011: 00:60:b9:0d:ec:1f processSsidIE statusCode is 0 and status is 0

*apfMsConnTask_1: Jun 28 12:10:07.011: 00:60:b9:0d:ec:1f processSsidIE ssid_done_flag is 0 finish_flag is 0

*apfMsConnTask_1: Jun 28 12:10:07.011: 00:60:b9:0d:ec:1f STA - rates (8): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_1: Jun 28 12:10:07.011: 00:60:b9:0d:ec:1f suppRates statusCode is 0 and gotSuppRatesElement is 1

*apfMsConnTask_1: Jun 28 12:10:07.011: 00:60:b9:0d:ec:1f STA - rates (10): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_1: Jun 28 12:10:07.011: 00:60:b9:0d:ec:1f extSuppRates statusCode is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_1: Jun 28 12:10:07.011: 00:60:b9:0d:ec:1f Processing RSN IE type 48, length 20 for mobile 00:60:b9:0d:ec:1f

*apfMsConnTask_1: Jun 28 12:10:07.011: 00:60:b9:0d:ec:1f pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_1: Jun 28 12:10:07.011: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Deleted mobile LWAPP rule on AP [3c:ce:73:f7:62:10]

*apfMsConnTask_1: Jun 28 12:10:07.011: 00:60:b9:0d:ec:1f Updated location for station old AP 3c:ce:73:f7:62:10-0, new AP c8:f9:f9:2b:42:d0-0

*apfMsConnTask_1: Jun 28 12:10:07.011: 00:60:b9:0d:ec:1f apfMsRunStateDec

*apfMsConnTask_1: Jun 28 12:10:07.012: 00:60:b9:0d:ec:1f apfMs1xStateDec

*apfMsConnTask_1: Jun 28 12:10:07.012: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Change state to START (0) last state RUN (20)

*apfMsConnTask_1: Jun 28 12:10:07.012: 00:60:b9:0d:ec:1f pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_1: Jun 28 12:10:07.012: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Initializing policy

*apfMsConnTask_1: Jun 28 12:10:07.012: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Change state to AUTHCHECK (2) last state RUN (20)

*apfMsConnTask_1: Jun 28 12:10:07.012: 00:60:b9:0d:ec:1f 10.160.91.51 AUTHCHECK (2) Change state to 8021X_REQD (3) last state RUN (20)

*apfMsConnTask_1: Jun 28 12:10:07.012: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) DHCP required on AP c8:f9:f9:2b:42:d0 vapId 2 apVapId 2for this client

*apfMsConnTask_1: Jun 28 12:10:07.012: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*apfMsConnTask_1: Jun 28 12:10:07.012: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Plumbed mobile LWAPP rule on AP c8:f9:f9:2b:42:d0 vapId 2 apVapId 2

*apfMsConnTask_1: Jun 28 12:10:07.012: 00:60:b9:0d:ec:1f apfPemAddUser2 (apf_policy.c:268) Changing state for mobile 00:60:b9:0d:ec:1f on AP c8:f9:f9:2b:42:d0 from Associated to Associated

*pemReceiveTask: Jun 28 12:10:07.012: 00:60:b9:0d:ec:1f 10.160.91.51 Removed NPU entry.

*apfMsConnTask_1: Jun 28 12:10:07.012: 00:60:b9:0d:ec:1f Scheduling deletion of Mobile Station: (callerId: 49) in 1800 seconds

*apfMsConnTask_1: Jun 28 12:10:07.012: 00:60:b9:0d:ec:1f Sending Assoc Response to station on BSSID c8:f9:f9:2b:42:d0 (status 0) ApVapId 2 Slot 0

*apfMsConnTask_1: Jun 28 12:10:07.012: 00:60:b9:0d:ec:1f apfProcessAssocReq (apf_80211.c:6290) Changing state for mobile 00:60:b9:0d:ec:1f on AP c8:f9:f9:2b:42:d0 from Associated to Associated

*dot1xMsgTask: Jun 28 12:10:07.014: 00:60:b9:0d:ec:1f Creating a PKC PMKID Cache entry for station 00:60:b9:0d:ec:1f (RSN 2)

*dot1xMsgTask: Jun 28 12:10:07.014: 00:60:b9:0d:ec:1f Resetting MSCB PMK Cache Entry 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:10:07.014: 00:60:b9:0d:ec:1f Removing BSSID 3c:ce:73:f7:62:11 from PMKID cache of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:10:07.014: 00:60:b9:0d:ec:1f Setting active key cache index 0 ---> 8

*dot1xMsgTask: Jun 28 12:10:07.014: 00:60:b9:0d:ec:1f Setting active key cache index 8 ---> 0

*dot1xMsgTask: Jun 28 12:10:07.014: 00:60:b9:0d:ec:1f Adding BSSID c8:f9:f9:2b:42:d1 to PMKID cache at index 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:10:07.014: New PMKID: (16)

*dot1xMsgTask: Jun 28 12:10:07.014: [0000] bf 62 c5 bb 99 b4 f0 33 cf 37 03 18 3b 1c 80 6a

*dot1xMsgTask: Jun 28 12:10:07.014: 00:60:b9:0d:ec:1f Initiating RSN PSK to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:10:07.014: 00:60:b9:0d:ec:1f dot1x - moving mobile 00:60:b9:0d:ec:1f into Force Auth state

*dot1xMsgTask: Jun 28 12:10:07.014: 00:60:b9:0d:ec:1f Skipping EAP-Success to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:10:07.014: 00:60:b9:0d:ec:1f Found an cache entry for BSSID c8:f9:f9:2b:42:d1 in PMKID cache at index 0 of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:10:07.014: Including PMKID in M1 (16)

*dot1xMsgTask: Jun 28 12:10:07.014: [0000] bf 62 c5 bb 99 b4 f0 33 cf 37 03 18 3b 1c 80 6a

*dot1xMsgTask: Jun 28 12:10:07.014: 00:60:b9:0d:ec:1f Starting key exchange to mobile 00:60:b9:0d:ec:1f, data packets will be dropped

*dot1xMsgTask: Jun 28 12:10:07.014: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Dot1x_NW_MsgTask_7: Jun 28 12:10:07.076: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:10:07.076: 00:60:b9:0d:ec:1f Received EAPOL-key in PTK_START state (message 2) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:10:07.076: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:10:07.076: 00:60:b9:0d:ec:1f Sending the random GTK in M3 for WPA2 client 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:10:07.076: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01

*Dot1x_NW_MsgTask_7: Jun 28 12:10:07.081: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:10:07.081: 00:60:b9:0d:ec:1f Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:10:07.081: 00:60:b9:0d:ec:1f apfMs1xStateInc

*Dot1x_NW_MsgTask_7: Jun 28 12:10:07.081: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 12:10:07.081: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) DHCP required on AP c8:f9:f9:2b:42:d0 vapId 2 apVapId 2for this client

*Dot1x_NW_MsgTask_7: Jun 28 12:10:07.081: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*Dot1x_NW_MsgTask_7: Jun 28 12:10:07.081: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP c8:f9:f9:2b:42:d0 vapId 2 apVapId 2

*Dot1x_NW_MsgTask_7: Jun 28 12:10:07.081: 00:60:b9:0d:ec:1f apfMsRunStateInc

*Dot1x_NW_MsgTask_7: Jun 28 12:10:07.082: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Change state to RUN (20) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 12:10:07.082: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Reached PLUMBFASTPATH: from line 5362

*Dot1x_: Jun 28 12:10:07.082: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Adding Fast Path rule

type = Airespace AP Client

on AP c8:f9:f9:2b:42:d0, slot 0, interface = 13, QOS = 2

IPv4 ACL ID = 255, IPv6 ACL ID =

*Dot1x_NW_MsgTask_7: Jun 28 12:10:07.082: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 7006 Local Bridging Vlan = 106, Local Bridging intf id = 12

*Dot1x_NW_MsgTask_7: Jun 28 12:10:07.082: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255)

*Dot1x_NW_MsgTask_7: Jun 28 12:10:07.082: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

*pemReceiveTask: Jun 28 12:10:07.082: 00:60:b9:0d:ec:1f 10.160.91.51 Added NPU entry of type 1, dtlFlags 0x0

*apfMsConnTask_3: Jun 28 12:10:32.555: 00:60:b9:0d:ec:1f Reassociation received from mobile on AP c8:f9:f9:5b:20:f0

*apfMsConnTask_3: Jun 28 12:10:32.555: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1697)

*apfMsConnTask_3: Jun 28 12:10:32.555: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1864)

*apfMsConnTask_3: Jun 28 12:10:32.555: 00:60:b9:0d:ec:1f Applying site-specific Local Bridging override for station 00:60:b9:0d:ec:1f - vapId 2, site 'default-group', interface 'pvoz'

*apfMsConnTask_3: Jun 28 12:10:32.555: 00:60:b9:0d:ec:1f Applying Local Bridging Interface Policy for station 00:60:b9:0d:ec:1f - vlan 106, interface id 12, interface 'pvoz'

*apfMsConnTask_3: Jun 28 12:10:32.555: 00:60:b9:0d:ec:1f processSsidIE statusCode is 0 and status is 0

*apfMsConnTask_3: Jun 28 12:10:32.555: 00:60:b9:0d:ec:1f processSsidIE ssid_done_flag is 0 finish_flag is 0

*apfMsConnTask_3: Jun 28 12:10:32.555: 00:60:b9:0d:ec:1f STA - rates (8): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_3: Jun 28 12:10:32.555: 00:60:b9:0d:ec:1f suppRates statusCode is 0 and gotSuppRatesElement is 1

*apfMsConnTask_3: Jun 28 12:10:32.555: 00:60:b9:0d:ec:1f STA - rates (10): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_3: Jun 28 12:10:32.555: 00:60:b9:0d:ec:1f extSuppRates statusCode is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_3: Jun 28 12:10:32.555: 00:60:b9:0d:ec:1f Processing RSN IE type 48, length 20 for mobile 00:60:b9:0d:ec:1f

*apfMsConnTask_3: Jun 28 12:10:32.555: 00:60:b9:0d:ec:1f pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_3: Jun 28 12:10:32.555: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Deleted mobile LWAPP rule on AP [c8:f9:f9:2b:42:d0]

*pemReceiveTask: Jun 28 12:10:32.555: 00:60:b9:0d:ec:1f 10.160.91.51 Removed NPU entry.

*apfMsConnTask_3: Jun 28 12:10:32.555: 00:60:b9:0d:ec:1f Updated location for station old AP c8:f9:f9:2b:42:d0-0, new AP c8:f9:f9:5b:20:f0-0

*apfMsConnTask_3: Jun 28 12:10:32.555: 00:60:b9:0d:ec:1f apfMsRunStateDec

*apfMsConnTask_3: Jun 28 12:10:32.555: 00:60:b9:0d:ec:1f apfMs1xStateDec

*apfMsConnTask_3: Jun 28 12:10:32.555: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Change state to START (0) last state RUN (20)

*apfMsConnTask_3: Jun 28 12:10:32.555: 00:60:b9:0d:ec:1f pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_3: Jun 28 12:10:32.555: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Initializing policy

*apfMsConnTask_3: Jun 28 12:10:32.555: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Change state to AUTHCHECK (2) last state RUN (20)

*apfMsConnTask_3: Jun 28 12:10:32.555: 00:60:b9:0d:ec:1f 10.160.91.51 AUTHCHECK (2) Change state to 8021X_REQD (3) last state RUN (20)

*apfMsConnTask_3: Jun 28 12:10:32.556: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) DHCP required on AP c8:f9:f9:5b:20:f0 vapId 2 apVapId 2for this client

*apfMsConnTask_3: Jun 28 12:10:32.556: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*apfMsConnTask_3: Jun 28 12:10:32.556: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Plumbed mobile LWAPP rule on AP c8:f9:f9:5b:20:f0 vapId 2 apVapId 2

*apfMsConnTask_3: Jun 28 12:10:32.556: 00:60:b9:0d:ec:1f apfPemAddUser2 (apf_policy.c:268) Changing state for mobile 00:60:b9:0d:ec:1f on AP c8:f9:f9:5b:20:f0 from Associated to Associated

*apfMsConnTask_3: Jun 28 12:10:32.556: 00:60:b9:0d:ec:1f Scheduling deletion of Mobile Station: (callerId: 49) in 1800 seconds

*apfMsConnTask_3: Jun 28 12:10:32.556: 00:60:b9:0d:ec:1f Sending Assoc Response to station on BSSID c8:f9:f9:5b:20:f0 (status 0) ApVapId 2 Slot 0

*apfMsConnTask_3: Jun 28 12:10:32.556: 00:60:b9:0d:ec:1f apfProcessAssocReq (apf_80211.c:6290) Changing state for mobile 00:60:b9:0d:ec:1f on AP c8:f9:f9:5b:20:f0 from Associated to Associated

*dot1xMsgTask: Jun 28 12:10:32.557: 00:60:b9:0d:ec:1f Creating a PKC PMKID Cache entry for station 00:60:b9:0d:ec:1f (RSN 2)

*dot1xMsgTask: Jun 28 12:10:32.558: 00:60:b9:0d:ec:1f Resetting MSCB PMK Cache Entry 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:10:32.558: 00:60:b9:0d:ec:1f Removing BSSID c8:f9:f9:2b:42:d1 from PMKID cache of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:10:32.558: 00:60:b9:0d:ec:1f Setting active key cache index 0 ---> 8

*dot1xMsgTask: Jun 28 12:10:32.558: 00:60:b9:0d:ec:1f Setting active key cache index 8 ---> 0

*dot1xMsgTask: Jun 28 12:10:32.558: 00:60:b9:0d:ec:1f Adding BSSID c8:f9:f9:5b:20:f1 to PMKID cache at index 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:10:32.558: New PMKID: (16)

*dot1xMsgTask: Jun 28 12:10:32.558: [0000] 4d 80 29 c7 23 1c cb 26 9f 77 8d 66 63 bc 7b b9

*dot1xMsgTask: Jun 28 12:10:32.558: 00:60:b9:0d:ec:1f Initiating RSN PSK to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:10:32.558: 00:60:b9:0d:ec:1f dot1x - moving mobile 00:60:b9:0d:ec:1f into Force Auth state

*dot1xMsgTask: Jun 28 12:10:32.558: 00:60:b9:0d:ec:1f Skipping EAP-Success to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:10:32.558: 00:60:b9:0d:ec:1f Found an cache entry for BSSID c8:f9:f9:5b:20:f1 in PMKID cache at index 0 of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:10:32.558: Including PMKID in M1 (16)

*dot1xMsgTask: Jun 28 12:10:32.558: [0000] 4d 80 29 c7 23 1c cb 26 9f 77 8d 66 63 bc 7b b9

*dot1xMsgTask: Jun 28 12:10:32.558: 00:60:b9:0d:ec:1f Starting key exchange to mobile 00:60:b9:0d:ec:1f, data packets will be dropped

*dot1xMsgTask: Jun 28 12:10:32.558: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Dot1x_NW_MsgTask_7: Jun 28 12:10:32.604: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:10:32.604: 00:60:b9:0d:ec:1f Received EAPOL-key in PTK_START state (message 2) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:10:32.604: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:10:32.604: 00:60:b9:0d:ec:1f Sending the random GTK in M3 for WPA2 client 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:10:32.604: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01

*Dot1x_NW_MsgTask_7: Jun 28 12:10:32.610: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:10:32.610: 00:60:b9:0d:ec:1f Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:10:32.610: 00:60:b9:0d:ec:1f apfMs1xStateInc

*Dot1x_NW_MsgTask_7: Jun 28 12:10:32.610: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 12:10:32.610: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) DHCP required on AP c8:f9:f9:5b:20:f0 vapId 2 apVapId 2for this client

*Dot1x_NW_MsgTask_7: Jun 28 12:10:32.610: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*Dot1x_NW_MsgTask_7: Jun 28 12:10:32.610: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP c8:f9:f9:5b:20:f0 vapId 2 apVapId 2

*Dot1x_NW_MsgTask_7: Jun 28 12:10:32.610: 00:60:b9:0d:ec:1f apfMsRunStateInc

*Dot1x_NW_MsgTask_7: Jun 28 12:10:32.611: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Change state to RUN (20) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 12:10:32.611: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Reached PLUMBFASTPATH: from line 5362

*Dot1x_: Jun 28 12:10:32.611: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Adding Fast Path rule

type = Airespace AP Client

on AP c8:f9:f9:5b:20:f0, slot 0, interface = 13, QOS = 2

IPv4 ACL ID = 255, IPv6 ACL ID =

*Dot1x_NW_MsgTask_7: Jun 28 12:10:32.611: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 7006 Local Bridging Vlan = 106, Local Bridging intf id = 12

*Dot1x_NW_MsgTask_7: Jun 28 12:10:32.611: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255)

*Dot1x_NW_MsgTask_7: Jun 28 12:10:32.611: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

*pemReceiveTask: Jun 28 12:10:32.611: 00:60:b9:0d:ec:1f 10.160.91.51 Added NPU entry of type 1, dtlFlags 0x0

*apfMsConnTask_6: Jun 28 12:11:48.799: 00:60:b9:0d:ec:1f Reassociation received from mobile on AP 3c:ce:73:f9:06:50

*apfMsConnTask_6: Jun 28 12:11:48.799: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1697)

*apfMsConnTask_6: Jun 28 12:11:48.800: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1864)

*apfMsConnTask_6: Jun 28 12:11:48.800: 00:60:b9:0d:ec:1f Applying site-specific Local Bridging override for station 00:60:b9:0d:ec:1f - vapId 2, site 'default-group', interface 'pvoz'

*apfMsConnTask_6: Jun 28 12:11:48.800: 00:60:b9:0d:ec:1f Applying Local Bridging Interface Policy for station 00:60:b9:0d:ec:1f - vlan 106, interface id 12, interface 'pvoz'

*apfMsConnTask_6: Jun 28 12:11:48.800: 00:60:b9:0d:ec:1f processSsidIE statusCode is 0 and status is 0

*apfMsConnTask_6: Jun 28 12:11:48.800: 00:60:b9:0d:ec:1f processSsidIE ssid_done_flag is 0 finish_flag is 0

*apfMsConnTask_6: Jun 28 12:11:48.800: 00:60:b9:0d:ec:1f STA - rates (8): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_6: Jun 28 12:11:48.800: 00:60:b9:0d:ec:1f suppRates statusCode is 0 and gotSuppRatesElement is 1

*apfMsConnTask_6: Jun 28 12:11:48.800: 00:60:b9:0d:ec:1f STA - rates (10): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_6: Jun 28 12:11:48.800: 00:60:b9:0d:ec:1f extSuppRates statusCode is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_6: Jun 28 12:11:48.800: 00:60:b9:0d:ec:1f Processing RSN IE type 48, length 20 for mobile 00:60:b9:0d:ec:1f

*apfMsConnTask_6: Jun 28 12:11:48.800: 00:60:b9:0d:ec:1f pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_6: Jun 28 12:11:48.800: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Deleted mobile LWAPP rule on AP [c8:f9:f9:5b:20:f0]

*apfMsConnTask_6: Jun 28 12:11:48.800: 00:60:b9:0d:ec:1f Updated location for station old AP c8:f9:f9:5b:20:f0-0, new AP 3c:ce:73:f9:06:50-0

*apfMsConnTask_6: Jun 28 12:11:48.800: 00:60:b9:0d:ec:1f apfMsRunStateDec

*apfMsConnTask_6: Jun 28 12:11:48.800: 00:60:b9:0d:ec:1f apfMs1xStateDec

*apfMsConnTask_6: Jun 28 12:11:48.800: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Change state to START (0) last state RUN (20)

*apfMsConnTask_6: Jun 28 12:11:48.800: 00:60:b9:0d:ec:1f pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_6: Jun 28 12:11:48.800: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Initializing policy

*apfMsConnTask_6: Jun 28 12:11:48.800: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Change state to AUTHCHECK (2) last state RUN (20)

*apfMsConnTask_6: Jun 28 12:11:48.800: 00:60:b9:0d:ec:1f 10.160.91.51 AUTHCHECK (2) Change state to 8021X_REQD (3) last state RUN (20)

*apfMsConnTask_6: Jun 28 12:11:48.800: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) DHCP required on AP 3c:ce:73:f9:06:50 vapId 2 apVapId 2for this client

*apfMsConnTask_6: Jun 28 12:11:48.800: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*apfMsConnTask_6: Jun 28 12:11:48.800: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 3c:ce:73:f9:06:50 vapId 2 apVapId 2

*apfMsConnTask_6: Jun 28 12:11:48.801: 00:60:b9:0d:ec:1f apfPemAddUser2 (apf_policy.c:268) Changing state for mobile 00:60:b9:0d:ec:1f on AP 3c:ce:73:f9:06:50 from Associated to Associated

*apfMsConnTask_6: Jun 28 12:11:48.801: 00:60:b9:0d:ec:1f Scheduling deletion of Mobile Station: (callerId: 49) in 1800 seconds

*apfMsConnTask_6: Jun 28 12:11:48.801: 00:60:b9:0d:ec:1f Sending Assoc Response to station on BSSID 3c:ce:73:f9:06:50 (status 0) ApVapId 2 Slot 0

*apfMsConnTask_6: Jun 28 12:11:48.801: 00:60:b9:0d:ec:1f apfProcessAssocReq (apf_80211.c:6290) Changing state for mobile 00:60:b9:0d:ec:1f on AP 3c:ce:73:f9:06:50 from Associated to Associated

*pemReceiveTask: Jun 28 12:11:48.801: 00:60:b9:0d:ec:1f 10.160.91.51 Removed NPU entry.

*dot1xMsgTask: Jun 28 12:11:48.803: 00:60:b9:0d:ec:1f Creating a PKC PMKID Cache entry for station 00:60:b9:0d:ec:1f (RSN 2)

*dot1xMsgTask: Jun 28 12:11:48.803: 00:60:b9:0d:ec:1f Resetting MSCB PMK Cache Entry 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:11:48.803: 00:60:b9:0d:ec:1f Removing BSSID c8:f9:f9:5b:20:f1 from PMKID cache of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:11:48.803: 00:60:b9:0d:ec:1f Setting active key cache index 0 ---> 8

*dot1xMsgTask: Jun 28 12:11:48.803: 00:60:b9:0d:ec:1f Setting active key cache index 8 ---> 0

*dot1xMsgTask: Jun 28 12:11:48.803: 00:60:b9:0d:ec:1f Adding BSSID 3c:ce:73:f9:06:51 to PMKID cache at index 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:11:48.803: New PMKID: (16)

*dot1xMsgTask: Jun 28 12:11:48.803: [0000] 2c de dd 37 b5 fb 3c 2d 0e a4 47 e2 fd 62 19 fe

*dot1xMsgTask: Jun 28 12:11:48.803: 00:60:b9:0d:ec:1f Initiating RSN PSK to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:11:48.803: 00:60:b9:0d:ec:1f dot1x - moving mobile 00:60:b9:0d:ec:1f into Force Auth state

*dot1xMsgTask: Jun 28 12:11:48.803: 00:60:b9:0d:ec:1f Skipping EAP-Success to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:11:48.803: 00:60:b9:0d:ec:1f Found an cache entry for BSSID 3c:ce:73:f9:06:51 in PMKID cache at index 0 of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:11:48.803: Including PMKID in M1 (16)

*dot1xMsgTask: Jun 28 12:11:48.803: [0000] 2c de dd 37 b5 fb 3c 2d 0e a4 47 e2 fd 62 19 fe

*dot1xMsgTask: Jun 28 12:11:48.803: 00:60:b9:0d:ec:1f Starting key exchange to mobile 00:60:b9:0d:ec:1f, data packets will be dropped

*dot1xMsgTask: Jun 28 12:11:48.803: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Dot1x_NW_MsgTask_7: Jun 28 12:11:48.845: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:11:48.845: 00:60:b9:0d:ec:1f Received EAPOL-key in PTK_START state (message 2) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:11:48.845: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:11:48.845: 00:60:b9:0d:ec:1f Sending the random GTK in M3 for WPA2 client 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:11:48.845: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01

*Dot1x_NW_MsgTask_7: Jun 28 12:11:48.850: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:11:48.850: 00:60:b9:0d:ec:1f Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:11:48.850: 00:60:b9:0d:ec:1f apfMs1xStateInc

*Dot1x_NW_MsgTask_7: Jun 28 12:11:48.850: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 12:11:48.850: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) DHCP required on AP 3c:ce:73:f9:06:50 vapId 2 apVapId 2for this client

*Dot1x_NW_MsgTask_7: Jun 28 12:11:48.850: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*Dot1x_NW_MsgTask_7: Jun 28 12:11:48.850: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 3c:ce:73:f9:06:50 vapId 2 apVapId 2

*Dot1x_NW_MsgTask_7: Jun 28 12:11:48.850: 00:60:b9:0d:ec:1f apfMsRunStateInc

*Dot1x_NW_MsgTask_7: Jun 28 12:11:48.850: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Change state to RUN (20) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 12:11:48.850: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Reached PLUMBFASTPATH: from line 5362

*Dot1x_: Jun 28 12:11:48.850: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Adding Fast Path rule

type = Airespace AP Client

on AP 3c:ce:73:f9:06:50, slot 0, interface = 13, QOS = 2

IPv4 ACL ID = 255, IPv6 ACL ID =

*Dot1x_NW_MsgTask_7: Jun 28 12:11:48.850: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 7006 Local Bridging Vlan = 106, Local Bridging intf id = 12

*Dot1x_NW_MsgTask_7: Jun 28 12:11:48.850: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255)

*Dot1x_NW_MsgTask_7: Jun 28 12:11:48.850: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

*pemReceiveTask: Jun 28 12:11:48.850: 00:60:b9:0d:ec:1f 10.160.91.51 Added NPU entry of type 1, dtlFlags 0x0

(Cisco Controller)

User:

(Cisco Controller)

User:

(Cisco Controller)

User:

(Cisco Controller)

User:

(Cisco Controller)

User:

(Cisco Controller)

User: adn min1

Password:*********

(Cisco Controller) >debug client show

(Cisco Controller) show>exit

(Cisco Controller) >debug client 3C 00:60:B9:0D:EC:1F

(Cisco Controller) >*apfMsConnTask_6: Jun 28 12:17:10.281: 00:60:b9:0d:ec:1f Reassociation received from mobile on AP 3c:ce:73:f9:2e:c0

*apfMsConnTask_6: Jun 28 12:17:10.281: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1697)

*apfMsConnTask_6: Jun 28 12:17:10.281: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1864)

*apfMsConnTask_6: Jun 28 12:17:10.281: 00:60:b9:0d:ec:1f Applying site-specific Local Bridging override for station 00:60:b9:0d:ec:1f - vapId 2, site 'default-group', interface 'pvoz'

*apfMsConnTask_6: Jun 28 12:17:10.281: 00:60:b9:0d:ec:1f Applying Local Bridging Interface Policy for station 00:60:b9:0d:ec:1f - vlan 106, interface id 12, interface 'pvoz'

*apfMsConnTask_6: Jun 28 12:17:10.281: 00:60:b9:0d:ec:1f processSsidIE statusCode is 0 and status is 0

*apfMsConnTask_6: Jun 28 12:17:10.281: 00:60:b9:0d:ec:1f processSsidIE ssid_done_flag is 0 finish_flag is 0

*apfMsConnTask_6: Jun 28 12:17:10.281: 00:60:b9:0d:ec:1f STA - rates (8): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_6: Jun 28 12:17:10.281: 00:60:b9:0d:ec:1f suppRates statusCode is 0 and gotSuppRatesElement is 1

*apfMsConnTask_6: Jun 28 12:17:10.281: 00:60:b9:0d:ec:1f STA - rates (10): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_6: Jun 28 12:17:10.281: 00:60:b9:0d:ec:1f extSuppRates statusCode is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_6: Jun 28 12:17:10.281: 00:60:b9:0d:ec:1f Processing RSN IE type 48, length 20 for mobile 00:60:b9:0d:ec:1f

*apfMsConnTask_6: Jun 28 12:17:10.281: 00:60:b9:0d:ec:1f pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_6: Jun 28 12:17:10.281: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Deleted mobile LWAPP rule on AP [3c:ce:73:f8:e1:00]

*pemReceiveTask: Jun 28 12:17:10.281: 00:60:b9:0d:ec:1f 10.160.91.51 Removed NPU entry.

*apfMsConnTask_6: Jun 28 12:17:10.281: 00:60:b9:0d:ec:1f Updated location for station old AP 3c:ce:73:f8:e1:00-0, new AP 3c:ce:73:f9:2e:c0-0

*apfMsConnTask_6: Jun 28 12:17:10.281: 00:60:b9:0d:ec:1f apfMsRunStateDec

*apfMsConnTask_6: Jun 28 12:17:10.282: 00:60:b9:0d:ec:1f apfMs1xStateDec

*apfMsConnTask_6: Jun 28 12:17:10.282: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Change state to START (0) last state RUN (20)

*apfMsConnTask_6: Jun 28 12:17:10.282: 00:60:b9:0d:ec:1f pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_6: Jun 28 12:17:10.282: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Initializing policy

*apfMsConnTask_6: Jun 28 12:17:10.282: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Change state to AUTHCHECK (2) last state RUN (20)

*apfMsConnTask_6: Jun 28 12:17:10.282: 00:60:b9:0d:ec:1f 10.160.91.51 AUTHCHECK (2) Change state to 8021X_REQD (3) last state RUN (20)

*apfMsConnTask_6: Jun 28 12:17:10.282: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) DHCP required on AP 3c:ce:73:f9:2e:c0 vapId 2 apVapId 2for this client

*apfMsConnTask_6: Jun 28 12:17:10.282: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*apfMsConnTask_6: Jun 28 12:17:10.282: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 3c:ce:73:f9:2e:c0 vapId 2 apVapId 2

*apfMsConnTask_6: Jun 28 12:17:10.282: 00:60:b9:0d:ec:1f apfPemAddUser2 (apf_policy.c:268) Changing state for mobile 00:60:b9:0d:ec:1f on AP 3c:ce:73:f9:2e:c0 from Associated to Associated

*apfMsConnTask_6: Jun 28 12:17:10.282: 00:60:b9:0d:ec:1f Scheduling deletion of Mobile Station: (callerId: 49) in 1800 seconds

*apfMsConnTask_6: Jun 28 12:17:10.282: 00:60:b9:0d:ec:1f Sending Assoc Response to station on BSSID 3c:ce:73:f9:2e:c0 (status 0) ApVapId 2 Slot 0

*apfMsConnTask_6: Jun 28 12:17:10.282: 00:60:b9:0d:ec:1f apfProcessAssocReq (apf_80211.c:6290) Changing state for mobile 00:60:b9:0d:ec:1f on AP 3c:ce:73:f9:2e:c0 from Associated to Associated

*dot1xMsgTask: Jun 28 12:17:10.286: 00:60:b9:0d:ec:1f Creating a PKC PMKID Cache entry for station 00:60:b9:0d:ec:1f (RSN 2)

*dot1xMsgTask: Jun 28 12:17:10.286: 00:60:b9:0d:ec:1f Resetting MSCB PMK Cache Entry 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:17:10.286: 00:60:b9:0d:ec:1f Removing BSSID 3c:ce:73:f8:e1:01 from PMKID cache of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:17:10.286: 00:60:b9:0d:ec:1f Setting active key cache index 0 ---> 8

*dot1xMsgTask: Jun 28 12:17:10.286: 00:60:b9:0d:ec:1f Setting active key cache index 8 ---> 0

*dot1xMsgTask: Jun 28 12:17:10.286: 00:60:b9:0d:ec:1f Adding BSSID 3c:ce:73:f9:2e:c1 to PMKID cache at index 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:17:10.286: New PMKID: (16)

*dot1xMsgTask: Jun 28 12:17:10.286: [0000] 74 1f ee 29 2e 8d fc df 33 97 9a 33 d6 57 d8 be

*dot1xMsgTask: Jun 28 12:17:10.286: 00:60:b9:0d:ec:1f Initiating RSN PSK to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:17:10.286: 00:60:b9:0d:ec:1f dot1x - moving mobile 00:60:b9:0d:ec:1f into Force Auth state

*dot1xMsgTask: Jun 28 12:17:10.286: 00:60:b9:0d:ec:1f Skipping EAP-Success to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:17:10.286: 00:60:b9:0d:ec:1f Found an cache entry for BSSID 3c:ce:73:f9:2e:c1 in PMKID cache at index 0 of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:17:10.286: Including PMKID in M1 (16)

*dot1xMsgTask: Jun 28 12:17:10.286: [0000] 74 1f ee 29 2e 8d fc df 33 97 9a 33 d6 57 d8 be

*dot1xMsgTask: Jun 28 12:17:10.286: 00:60:b9:0d:ec:1f Starting key exchange to mobile 00:60:b9:0d:ec:1f, data packets will be dropped

*dot1xMsgTask: Jun 28 12:17:10.286: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Dot1x_NW_MsgTask_7: Jun 28 12:17:10.336: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:17:10.336: 00:60:b9:0d:ec:1f Received EAPOL-key in PTK_START state (message 2) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:17:10.336: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:17:10.336: 00:60:b9:0d:ec:1f Sending the random GTK in M3 for WPA2 client 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:17:10.336: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01

*Dot1x_NW_MsgTask_7: Jun 28 12:17:10.341: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:17:10.341: 00:60:b9:0d:ec:1f Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:17:10.341: 00:60:b9:0d:ec:1f apfMs1xStateInc

*Dot1x_NW_MsgTask_7: Jun 28 12:17:10.341: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 12:17:10.341: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) DHCP required on AP 3c:ce:73:f9:2e:c0 vapId 2 apVapId 2for this client

*Dot1x_NW_MsgTask_7: Jun 28 12:17:10.341: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*Dot1x_NW_MsgTask_7: Jun 28 12:17:10.341: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 3c:ce:73:f9:2e:c0 vapId 2 apVapId 2

*Dot1x_NW_MsgTask_7: Jun 28 12:17:10.341: 00:60:b9:0d:ec:1f apfMsRunStateInc

*Dot1x_NW_MsgTask_7: Jun 28 12:17:10.341: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Change state to RUN (20) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 12:17:10.341: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Reached PLUMBFASTPATH: from line 5362

*Dot1x_: Jun 28 12:17:10.341: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Adding Fast Path rule

type = Airespace AP Client

on AP 3c:ce:73:f9:2e:c0, slot 0, interface = 13, QOS = 2

IPv4 ACL ID = 255, IPv6 ACL ID =

*Dot1x_NW_MsgTask_7: Jun 28 12:17:10.341: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 7006 Local Bridging Vlan = 106, Local Bridging intf id = 12

*Dot1x_NW_MsgTask_7: Jun 28 12:17:10.341: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255)

*Dot1x_NW_MsgTask_7: Jun 28 12:17:10.341: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

*pemReceiveTask: Jun 28 12:17:10.342: 00:60:b9:0d:ec:1f 10.160.91.51 Added NPU entry of type 1, dtlFlags 0x0

*apfMsConnTask_4: Jun 28 12:17:47.887: 00:60:b9:0d:ec:1f Reassociation received from mobile on AP c8:f9:f9:5b:0f:70

*apfMsConnTask_4: Jun 28 12:17:47.887: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1697)

*apfMsConnTask_4: Jun 28 12:17:47.887: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1864)

*apfMsConnTask_4: Jun 28 12:17:47.887: 00:60:b9:0d:ec:1f Applying site-specific Local Bridging override for station 00:60:b9:0d:ec:1f - vapId 2, site 'default-group', interface 'pvoz'

*apfMsConnTask_4: Jun 28 12:17:47.887: 00:60:b9:0d:ec:1f Applying Local Bridging Interface Policy for station 00:60:b9:0d:ec:1f - vlan 106, interface id 12, interface 'pvoz'

*apfMsConnTask_4: Jun 28 12:17:47.887: 00:60:b9:0d:ec:1f processSsidIE statusCode is 0 and status is 0

*apfMsConnTask_4: Jun 28 12:17:47.887: 00:60:b9:0d:ec:1f processSsidIE ssid_done_flag is 0 finish_flag is 0

*apfMsConnTask_4: Jun 28 12:17:47.887: 00:60:b9:0d:ec:1f STA - rates (8): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_4: Jun 28 12:17:47.888: 00:60:b9:0d:ec:1f suppRates statusCode is 0 and gotSuppRatesElement is 1

*apfMsConnTask_4: Jun 28 12:17:47.888: 00:60:b9:0d:ec:1f STA - rates (10): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_4: Jun 28 12:17:47.888: 00:60:b9:0d:ec:1f extSuppRates statusCode is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_4: Jun 28 12:17:47.888: 00:60:b9:0d:ec:1f Processing RSN IE type 48, length 20 for mobile 00:60:b9:0d:ec:1f

*apfMsConnTask_4: Jun 28 12:17:47.888: 00:60:b9:0d:ec:1f pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_4: Jun 28 12:17:47.888: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Deleted mobile LWAPP rule on AP [3c:ce:73:f9:2e:c0]

*pemReceiveTask: Jun 28 12:17:47.888: 00:60:b9:0d:ec:1f 10.160.91.51 Removed NPU entry.

*apfMsConnTask_4: Jun 28 12:17:47.888: 00:60:b9:0d:ec:1f Updated location for station old AP 3c:ce:73:f9:2e:c0-0, new AP c8:f9:f9:5b:0f:70-0

*apfMsConnTask_4: Jun 28 12:17:47.888: 00:60:b9:0d:ec:1f apfMsRunStateDec

*apfMsConnTask_4: Jun 28 12:17:47.888: 00:60:b9:0d:ec:1f apfMs1xStateDec

*apfMsConnTask_4: Jun 28 12:17:47.888: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Change state to START (0) last state RUN (20)

*apfMsConnTask_4: Jun 28 12:17:47.888: 00:60:b9:0d:ec:1f pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_4: Jun 28 12:17:47.888: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Initializing policy

*apfMsConnTask_4: Jun 28 12:17:47.888: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Change state to AUTHCHECK (2) last state RUN (20)

*apfMsConnTask_4: Jun 28 12:17:47.888: 00:60:b9:0d:ec:1f 10.160.91.51 AUTHCHECK (2) Change state to 8021X_REQD (3) last state RUN (20)

*apfMsConnTask_4: Jun 28 12:17:47.888: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) DHCP required on AP c8:f9:f9:5b:0f:70 vapId 2 apVapId 2for this client

*apfMsConnTask_4: Jun 28 12:17:47.888: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*apfMsConnTask_4: Jun 28 12:17:47.888: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Plumbed mobile LWAPP rule on AP c8:f9:f9:5b:0f:70 vapId 2 apVapId 2

*apfMsConnTask_4: Jun 28 12:17:47.888: 00:60:b9:0d:ec:1f apfPemAddUser2 (apf_policy.c:268) Changing state for mobile 00:60:b9:0d:ec:1f on AP c8:f9:f9:5b:0f:70 from Associated to Associated

*apfMsConnTask_4: Jun 28 12:17:47.888: 00:60:b9:0d:ec:1f Scheduling deletion of Mobile Station: (callerId: 49) in 1800 seconds

*apfMsConnTask_4: Jun 28 12:17:47.889: 00:60:b9:0d:ec:1f Sending Assoc Response to station on BSSID c8:f9:f9:5b:0f:70 (status 0) ApVapId 2 Slot 0

*apfMsConnTask_4: Jun 28 12:17:47.889: 00:60:b9:0d:ec:1f apfProcessAssocReq (apf_80211.c:6290) Changing state for mobile 00:60:b9:0d:ec:1f on AP c8:f9:f9:5b:0f:70 from Associated to Associated

*dot1xMsgTask: Jun 28 12:17:47.890: 00:60:b9:0d:ec:1f Creating a PKC PMKID Cache entry for station 00:60:b9:0d:ec:1f (RSN 2)

*dot1xMsgTask: Jun 28 12:17:47.890: 00:60:b9:0d:ec:1f Resetting MSCB PMK Cache Entry 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:17:47.890: 00:60:b9:0d:ec:1f Removing BSSID 3c:ce:73:f9:2e:c1 from PMKID cache of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:17:47.890: 00:60:b9:0d:ec:1f Setting active key cache index 0 ---> 8

*dot1xMsgTask: Jun 28 12:17:47.890: 00:60:b9:0d:ec:1f Setting active key cache index 8 ---> 0

*dot1xMsgTask: Jun 28 12:17:47.890: 00:60:b9:0d:ec:1f Adding BSSID c8:f9:f9:5b:0f:71 to PMKID cache at index 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:17:47.890: New PMKID: (16)

*dot1xMsgTask: Jun 28 12:17:47.890: [0000] 4a ed 4a f8 37 9c f3 ab ac 44 4a 01 f9 7c 4e 46

*dot1xMsgTask: Jun 28 12:17:47.890: 00:60:b9:0d:ec:1f Initiating RSN PSK to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:17:47.890: 00:60:b9:0d:ec:1f dot1x - moving mobile 00:60:b9:0d:ec:1f into Force Auth state

*dot1xMsgTask: Jun 28 12:17:47.890: 00:60:b9:0d:ec:1f Skipping EAP-Success to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:17:47.891: 00:60:b9:0d:ec:1f Found an cache entry for BSSID c8:f9:f9:5b:0f:71 in PMKID cache at index 0 of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:17:47.891: Including PMKID in M1 (16)

*dot1xMsgTask: Jun 28 12:17:47.891: [0000] 4a ed 4a f8 37 9c f3 ab ac 44 4a 01 f9 7c 4e 46

*dot1xMsgTask: Jun 28 12:17:47.891: 00:60:b9:0d:ec:1f Starting key exchange to mobile 00:60:b9:0d:ec:1f, data packets will be dropped

*dot1xMsgTask: Jun 28 12:17:47.891: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Dot1x_NW_MsgTask_7: Jun 28 12:17:47.947: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:17:47.947: 00:60:b9:0d:ec:1f Received EAPOL-key in PTK_START state (message 2) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:17:47.947: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:17:47.947: 00:60:b9:0d:ec:1f Sending the random GTK in M3 for WPA2 client 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:17:47.947: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01

*Dot1x_NW_MsgTask_7: Jun 28 12:17:47.952: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:17:47.952: 00:60:b9:0d:ec:1f Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:17:47.952: 00:60:b9:0d:ec:1f apfMs1xStateInc

*Dot1x_NW_MsgTask_7: Jun 28 12:17:47.952: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 12:17:47.952: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) DHCP required on AP c8:f9:f9:5b:0f:70 vapId 2 apVapId 2for this client

*Dot1x_NW_MsgTask_7: Jun 28 12:17:47.952: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*Dot1x_NW_MsgTask_7: Jun 28 12:17:47.952: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP c8:f9:f9:5b:0f:70 vapId 2 apVapId 2

*Dot1x_NW_MsgTask_7: Jun 28 12:17:47.952: 00:60:b9:0d:ec:1f apfMsRunStateInc

*Dot1x_NW_MsgTask_7: Jun 28 12:17:47.952: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Change state to RUN (20) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 12:17:47.952: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Reached PLUMBFASTPATH: from line 5362

*Dot1x_: Jun 28 12:17:47.952: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Adding Fast Path rule

type = Airespace AP Client

on AP c8:f9:f9:5b:0f:70, slot 0, interface = 13, QOS = 2

IPv4 ACL ID = 255, IPv6 ACL ID =

*Dot1x_NW_MsgTask_7: Jun 28 12:17:47.952: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 7006 Local Bridging Vlan = 106, Local Bridging intf id = 12

*Dot1x_NW_MsgTask_7: Jun 28 12:17:47.952: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255)

*Dot1x_NW_MsgTask_7: Jun 28 12:17:47.953: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

*pemReceiveTask: Jun 28 12:17:47.953: 00:60:b9:0d:ec:1f 10.160.91.51 Added NPU entry of type 1, dtlFlags 0x0

*apfMsConnTask_3: Jun 28 12:18:15.346: 00:60:b9:0d:ec:1f Reassociation received from mobile on AP 3c:ce:73:f9:13:e0

*apfMsConnTask_3: Jun 28 12:18:15.346: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1697)

*apfMsConnTask_3: Jun 28 12:18:15.346: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1864)

*apfMsConnTask_3: Jun 28 12:18:15.346: 00:60:b9:0d:ec:1f Applying site-specific Local Bridging override for station 00:60:b9:0d:ec:1f - vapId 2, site 'default-group', interface 'pvoz'

*apfMsConnTask_3: Jun 28 12:18:15.346: 00:60:b9:0d:ec:1f Applying Local Bridging Interface Policy for station 00:60:b9:0d:ec:1f - vlan 106, interface id 12, interface 'pvoz'

*apfMsConnTask_3: Jun 28 12:18:15.346: 00:60:b9:0d:ec:1f processSsidIE statusCode is 0 and status is 0

*apfMsConnTask_3: Jun 28 12:18:15.346: 00:60:b9:0d:ec:1f processSsidIE ssid_done_flag is 0 finish_flag is 0

*apfMsConnTask_3: Jun 28 12:18:15.347: 00:60:b9:0d:ec:1f STA - rates (8): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_3: Jun 28 12:18:15.347: 00:60:b9:0d:ec:1f suppRates statusCode is 0 and gotSuppRatesElement is 1

*apfMsConnTask_3: Jun 28 12:18:15.347: 00:60:b9:0d:ec:1f STA - rates (10): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_3: Jun 28 12:18:15.347: 00:60:b9:0d:ec:1f extSuppRates statusCode is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_3: Jun 28 12:18:15.347: 00:60:b9:0d:ec:1f Processing RSN IE type 48, length 20 for mobile 00:60:b9:0d:ec:1f

*apfMsConnTask_3: Jun 28 12:18:15.347: 00:60:b9:0d:ec:1f pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_3: Jun 28 12:18:15.347: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Deleted mobile LWAPP rule on AP [c8:f9:f9:5b:0f:70]

*pemReceiveTask: Jun 28 12:18:15.347: 00:60:b9:0d:ec:1f 10.160.91.51 Removed NPU entry.

*apfMsConnTask_3: Jun 28 12:18:15.347: 00:60:b9:0d:ec:1f Updated location for station old AP c8:f9:f9:5b:0f:70-0, new AP 3c:ce:73:f9:13:e0-0

*apfMsConnTask_3: Jun 28 12:18:15.347: 00:60:b9:0d:ec:1f apfMsRunStateDec

*apfMsConnTask_3: Jun 28 12:18:15.347: 00:60:b9:0d:ec:1f apfMs1xStateDec

*apfMsConnTask_3: Jun 28 12:18:15.347: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Change state to START (0) last state RUN (20)

*apfMsConnTask_3: Jun 28 12:18:15.347: 00:60:b9:0d:ec:1f pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_3: Jun 28 12:18:15.347: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Initializing policy

*apfMsConnTask_3: Jun 28 12:18:15.347: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Change state to AUTHCHECK (2) last state RUN (20)

*apfMsConnTask_3: Jun 28 12:18:15.347: 00:60:b9:0d:ec:1f 10.160.91.51 AUTHCHECK (2) Change state to 8021X_REQD (3) last state RUN (20)

*apfMsConnTask_3: Jun 28 12:18:15.347: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) DHCP required on AP 3c:ce:73:f9:13:e0 vapId 2 apVapId 2for this client

*apfMsConnTask_3: Jun 28 12:18:15.347: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*apfMsConnTask_3: Jun 28 12:18:15.347: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 3c:ce:73:f9:13:e0 vapId 2 apVapId 2

*apfMsConnTask_3: Jun 28 12:18:15.347: 00:60:b9:0d:ec:1f apfPemAddUser2 (apf_policy.c:268) Changing state for mobile 00:60:b9:0d:ec:1f on AP 3c:ce:73:f9:13:e0 from Associated to Associated

*apfMsConnTask_3: Jun 28 12:18:15.347: 00:60:b9:0d:ec:1f Scheduling deletion of Mobile Station: (callerId: 49) in 1800 seconds

*apfMsConnTask_3: Jun 28 12:18:15.348: 00:60:b9:0d:ec:1f Sending Assoc Response to station on BSSID 3c:ce:73:f9:13:e0 (status 0) ApVapId 2 Slot 0

*apfMsConnTask_3: Jun 28 12:18:15.348: 00:60:b9:0d:ec:1f apfProcessAssocReq (apf_80211.c:6290) Changing state for mobile 00:60:b9:0d:ec:1f on AP 3c:ce:73:f9:13:e0 from Associated to Associated

*dot1xMsgTask: Jun 28 12:18:15.349: 00:60:b9:0d:ec:1f Creating a PKC PMKID Cache entry for station 00:60:b9:0d:ec:1f (RSN 2)

*dot1xMsgTask: Jun 28 12:18:15.349: 00:60:b9:0d:ec:1f Resetting MSCB PMK Cache Entry 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:18:15.349: 00:60:b9:0d:ec:1f Removing BSSID c8:f9:f9:5b:0f:71 from PMKID cache of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:18:15.349: 00:60:b9:0d:ec:1f Setting active key cache index 0 ---> 8

*dot1xMsgTask: Jun 28 12:18:15.349: 00:60:b9:0d:ec:1f Setting active key cache index 8 ---> 0

*dot1xMsgTask: Jun 28 12:18:15.349: 00:60:b9:0d:ec:1f Adding BSSID 3c:ce:73:f9:13:e1 to PMKID cache at index 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:18:15.349: New PMKID: (16)

*dot1xMsgTask: Jun 28 12:18:15.349: [0000] 8e d8 80 65 d2 75 1e 24 a7 a1 ab 8b 7e 72 e1 6a

*dot1xMsgTask: Jun 28 12:18:15.350: 00:60:b9:0d:ec:1f Initiating RSN PSK to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:18:15.350: 00:60:b9:0d:ec:1f dot1x - moving mobile 00:60:b9:0d:ec:1f into Force Auth state

*dot1xMsgTask: Jun 28 12:18:15.350: 00:60:b9:0d:ec:1f Skipping EAP-Success to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:18:15.350: 00:60:b9:0d:ec:1f Found an cache entry for BSSID 3c:ce:73:f9:13:e1 in PMKID cache at index 0 of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:18:15.350: Including PMKID in M1 (16)

*dot1xMsgTask: Jun 28 12:18:15.350: [0000] 8e d8 80 65 d2 75 1e 24 a7 a1 ab 8b 7e 72 e1 6a

*dot1xMsgTask: Jun 28 12:18:15.350: 00:60:b9:0d:ec:1f Starting key exchange to mobile 00:60:b9:0d:ec:1f, data packets will be dropped

*dot1xMsgTask: Jun 28 12:18:15.350: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Dot1x_NW_MsgTask_7: Jun 28 12:18:15.411: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:18:15.411: 00:60:b9:0d:ec:1f Received EAPOL-key in PTK_START state (message 2) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:18:15.411: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:18:15.411: 00:60:b9:0d:ec:1f Sending the random GTK in M3 for WPA2 client 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:18:15.411: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01

*Dot1x_NW_MsgTask_7: Jun 28 12:18:15.416: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:18:15.416: 00:60:b9:0d:ec:1f Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:18:15.416: 00:60:b9:0d:ec:1f apfMs1xStateInc

*Dot1x_NW_MsgTask_7: Jun 28 12:18:15.416: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 12:18:15.416: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) DHCP required on AP 3c:ce:73:f9:13:e0 vapId 2 apVapId 2for this client

*Dot1x_NW_MsgTask_7: Jun 28 12:18:15.416: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*Dot1x_NW_MsgTask_7: Jun 28 12:18:15.417: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 3c:ce:73:f9:13:e0 vapId 2 apVapId 2

*Dot1x_NW_MsgTask_7: Jun 28 12:18:15.417: 00:60:b9:0d:ec:1f apfMsRunStateInc

*Dot1x_NW_MsgTask_7: Jun 28 12:18:15.417: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Change state to RUN (20) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 12:18:15.417: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Reached PLUMBFASTPATH: from line 5362

*Dot1x_: Jun 28 12:18:15.417: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Adding Fast Path rule

type = Airespace AP Client

on AP 3c:ce:73:f9:13:e0, slot 0, interface = 13, QOS = 2

IPv4 ACL ID = 255, IPv6 ACL ID =

*Dot1x_NW_MsgTask_7: Jun 28 12:18:15.417: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 7006 Local Bridging Vlan = 106, Local Bridging intf id = 12

*Dot1x_NW_MsgTask_7: Jun 28 12:18:15.417: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255)

*Dot1x_NW_MsgTask_7: Jun 28 12:18:15.417: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

*pemReceiveTask: Jun 28 12:18:15.417: 00:60:b9:0d:ec:1f 10.160.91.51 Added NPU entry of type 1, dtlFlags 0x0

*apfMsConnTask_4: Jun 28 12:19:06.181: 00:60:b9:0d:ec:1f Association received from mobile on AP c8:f9:f9:5b:0f:70

*apfMsConnTask_4: Jun 28 12:19:06.181: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1697)

*apfMsConnTask_4: Jun 28 12:19:06.181: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1864)

*apfMsConnTask_4: Jun 28 12:19:06.181: 00:60:b9:0d:ec:1f Applying site-specific Local Bridging override for station 00:60:b9:0d:ec:1f - vapId 2, site 'default-group', interface 'pvoz'

*apfMsConnTask_4: Jun 28 12:19:06.181: 00:60:b9:0d:ec:1f Applying Local Bridging Interface Policy for station 00:60:b9:0d:ec:1f - vlan 106, interface id 12, interface 'pvoz'

*apfMsConnTask_4: Jun 28 12:19:06.181: 00:60:b9:0d:ec:1f processSsidIE statusCode is 0 and status is 0

*apfMsConnTask_4: Jun 28 12:19:06.181: 00:60:b9:0d:ec:1f processSsidIE ssid_done_flag is 0 finish_flag is 0

*apfMsConnTask_4: Jun 28 12:19:06.181: 00:60:b9:0d:ec:1f STA - rates (8): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_4: Jun 28 12:19:06.181: 00:60:b9:0d:ec:1f suppRates statusCode is 0 and gotSuppRatesElement is 1

*apfMsConnTask_4: Jun 28 12:19:06.181: 00:60:b9:0d:ec:1f STA - rates (10): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_4: Jun 28 12:19:06.181: 00:60:b9:0d:ec:1f extSuppRates statusCode is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_4: Jun 28 12:19:06.181: 00:60:b9:0d:ec:1f Processing RSN IE type 48, length 20 for mobile 00:60:b9:0d:ec:1f

*apfMsConnTask_4: Jun 28 12:19:06.181: 00:60:b9:0d:ec:1f pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_4: Jun 28 12:19:06.181: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Deleted mobile LWAPP rule on AP [3c:ce:73:f9:13:e0]

*apfMsConnTask_4: Jun 28 12:19:06.181: 00:60:b9:0d:ec:1f Updated location for station old AP 3c:ce:73:f9:13:e0-0, new AP c8:f9:f9:5b:0f:70-0

*apfMsConnTask_4: Jun 28 12:19:06.181: 00:60:b9:0d:ec:1f apfMsRunStateDec

*apfMsConnTask_4: Jun 28 12:19:06.182: 00:60:b9:0d:ec:1f apfMs1xStateDec

*apfMsConnTask_4: Jun 28 12:19:06.182: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Change state to START (0) last state RUN (20)

*apfMsConnTask_4: Jun 28 12:19:06.182: 00:60:b9:0d:ec:1f pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_4: Jun 28 12:19:06.182: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Initializing policy

*apfMsConnTask_4: Jun 28 12:19:06.182: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Change state to AUTHCHECK (2) last state RUN (20)

*apfMsConnTask_4: Jun 28 12:19:06.182: 00:60:b9:0d:ec:1f 10.160.91.51 AUTHCHECK (2) Change state to 8021X_REQD (3) last state RUN (20)

*apfMsConnTask_4: Jun 28 12:19:06.182: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) DHCP required on AP c8:f9:f9:5b:0f:70 vapId 2 apVapId 2for this client

*apfMsConnTask_4: Jun 28 12:19:06.182: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*apfMsConnTask_4: Jun 28 12:19:06.182: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Plumbed mobile LWAPP rule on AP c8:f9:f9:5b:0f:70 vapId 2 apVapId 2

*apfMsConnTask_4: Jun 28 12:19:06.182: 00:60:b9:0d:ec:1f apfPemAddUser2 (apf_policy.c:268) Changing state for mobile 00:60:b9:0d:ec:1f on AP c8:f9:f9:5b:0f:70 from Associated to Associated

*apfMsConnTask_4: Jun 28 12:19:06.182: 00:60:b9:0d:ec:1f Scheduling deletion of Mobile Station: (callerId: 49) in 1800 seconds

*apfMsConnTask_4: Jun 28 12:19:06.182: 00:60:b9:0d:ec:1f Sending Assoc Response to station on BSSID c8:f9:f9:5b:0f:70 (status 0) ApVapId 2 Slot 0

*apfMsConnTask_4: Jun 28 12:19:06.182: 00:60:b9:0d:ec:1f apfProcessAssocReq (apf_80211.c:6290) Changing state for mobile 00:60:b9:0d:ec:1f on AP c8:f9:f9:5b:0f:70 from Associated to Associated

*pemReceiveTask: Jun 28 12:19:06.184: 00:60:b9:0d:ec:1f 10.160.91.51 Removed NPU entry.

*dot1xMsgTask: Jun 28 12:19:06.186: 00:60:b9:0d:ec:1f Creating a PKC PMKID Cache entry for station 00:60:b9:0d:ec:1f (RSN 2)

*dot1xMsgTask: Jun 28 12:19:06.186: 00:60:b9:0d:ec:1f Resetting MSCB PMK Cache Entry 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:19:06.186: 00:60:b9:0d:ec:1f Removing BSSID 3c:ce:73:f9:13:e1 from PMKID cache of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:19:06.186: 00:60:b9:0d:ec:1f Setting active key cache index 0 ---> 8

*dot1xMsgTask: Jun 28 12:19:06.186: 00:60:b9:0d:ec:1f Setting active key cache index 8 ---> 0

*dot1xMsgTask: Jun 28 12:19:06.186: 00:60:b9:0d:ec:1f Adding BSSID c8:f9:f9:5b:0f:71 to PMKID cache at index 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:19:06.186: New PMKID: (16)

*dot1xMsgTask: Jun 28 12:19:06.186: [0000] 4a ed 4a f8 37 9c f3 ab ac 44 4a 01 f9 7c 4e 46

*dot1xMsgTask: Jun 28 12:19:06.186: 00:60:b9:0d:ec:1f Initiating RSN PSK to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:19:06.186: 00:60:b9:0d:ec:1f dot1x - moving mobile 00:60:b9:0d:ec:1f into Force Auth state

*dot1xMsgTask: Jun 28 12:19:06.186: 00:60:b9:0d:ec:1f Skipping EAP-Success to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:19:06.186: 00:60:b9:0d:ec:1f Found an cache entry for BSSID c8:f9:f9:5b:0f:71 in PMKID cache at index 0 of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:19:06.186: Including PMKID in M1 (16)

*dot1xMsgTask: Jun 28 12:19:06.186: [0000] 4a ed 4a f8 37 9c f3 ab ac 44 4a 01 f9 7c 4e 46

*dot1xMsgTask: Jun 28 12:19:06.186: 00:60:b9:0d:ec:1f Starting key exchange to mobile 00:60:b9:0d:ec:1f, data packets will be dropped

*dot1xMsgTask: Jun 28 12:19:06.186: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Dot1x_NW_MsgTask_7: Jun 28 12:19:06.205: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:19:06.205: 00:60:b9:0d:ec:1f Received EAPOL-key in PTK_START state (message 2) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:19:06.205: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:19:06.205: 00:60:b9:0d:ec:1f Sending the random GTK in M3 for WPA2 client 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:19:06.205: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01

*Dot1x_NW_MsgTask_7: Jun 28 12:19:06.209: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:19:06.209: 00:60:b9:0d:ec:1f Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:19:06.209: 00:60:b9:0d:ec:1f apfMs1xStateInc

*Dot1x_NW_MsgTask_7: Jun 28 12:19:06.209: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 12:19:06.209: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) DHCP required on AP c8:f9:f9:5b:0f:70 vapId 2 apVapId 2for this client

*Dot1x_NW_MsgTask_7: Jun 28 12:19:06.209: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*Dot1x_NW_MsgTask_7: Jun 28 12:19:06.209: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP c8:f9:f9:5b:0f:70 vapId 2 apVapId 2

*Dot1x_NW_MsgTask_7: Jun 28 12:19:06.209: 00:60:b9:0d:ec:1f apfMsRunStateInc

*Dot1x_NW_MsgTask_7: Jun 28 12:19:06.209: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Change state to RUN (20) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 12:19:06.209: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Reached PLUMBFASTPATH: from line 5362

*Dot1x_: Jun 28 12:19:06.209: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Adding Fast Path rule

type = Airespace AP Client

on AP c8:f9:f9:5b:0f:70, slot 0, interface = 13, QOS = 2

IPv4 ACL ID = 255, IPv6 ACL ID =

*Dot1x_NW_MsgTask_7: Jun 28 12:19:06.210: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 7006 Local Bridging Vlan = 106, Local Bridging intf id = 12

*Dot1x_NW_MsgTask_7: Jun 28 12:19:06.210: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255)

*Dot1x_NW_MsgTask_7: Jun 28 12:19:06.210: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

*pemReceiveTask: Jun 28 12:19:06.210: 00:60:b9:0d:ec:1f 10.160.91.51 Added NPU entry of type 1, dtlFlags 0x0

*apfMsConnTask_0: Jun 28 12:19:38.015: 00:60:b9:0d:ec:1f Reassociation received from mobile on AP 3c:ce:73:f8:e1:00

*apfMsConnTask_0: Jun 28 12:19:38.016: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1697)

*apfMsConnTask_0: Jun 28 12:19:38.016: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1864)

*apfMsConnTask_0: Jun 28 12:19:38.016: 00:60:b9:0d:ec:1f Applying site-specific Local Bridging override for station 00:60:b9:0d:ec:1f - vapId 2, site 'default-group', interface 'pvoz'

*apfMsConnTask_0: Jun 28 12:19:38.016: 00:60:b9:0d:ec:1f Applying Local Bridging Interface Policy for station 00:60:b9:0d:ec:1f - vlan 106, interface id 12, interface 'pvoz'

*apfMsConnTask_0: Jun 28 12:19:38.016: 00:60:b9:0d:ec:1f processSsidIE statusCode is 0 and status is 0

*apfMsConnTask_0: Jun 28 12:19:38.016: 00:60:b9:0d:ec:1f processSsidIE ssid_done_flag is 0 finish_flag is 0

*apfMsConnTask_0: Jun 28 12:19:38.016: 00:60:b9:0d:ec:1f STA - rates (8): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_0: Jun 28 12:19:38.016: 00:60:b9:0d:ec:1f suppRates statusCode is 0 and gotSuppRatesElement is 1

*apfMsConnTask_0: Jun 28 12:19:38.016: 00:60:b9:0d:ec:1f STA - rates (10): 139 22 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_0: Jun 28 12:19:38.016: 00:60:b9:0d:ec:1f extSuppRates statusCode is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_0: Jun 28 12:19:38.016: 00:60:b9:0d:ec:1f Processing RSN IE type 48, length 20 for mobile 00:60:b9:0d:ec:1f

*apfMsConnTask_0: Jun 28 12:19:38.016: 00:60:b9:0d:ec:1f pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_0: Jun 28 12:19:38.016: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Deleted mobile LWAPP rule on AP [c8:f9:f9:5b:0f:70]

*pemReceiveTask: Jun 28 12:19:38.016: 00:60:b9:0d:ec:1f 10.160.91.51 Removed NPU entry.

*apfMsConnTask_0: Jun 28 12:19:38.016: 00:60:b9:0d:ec:1f Updated location for station old AP c8:f9:f9:5b:0f:70-0, new AP 3c:ce:73:f8:e1:00-0

*apfMsConnTask_0: Jun 28 12:19:38.016: 00:60:b9:0d:ec:1f apfMsRunStateDec

*apfMsConnTask_0: Jun 28 12:19:38.016: 00:60:b9:0d:ec:1f apfMs1xStateDec

*apfMsConnTask_0: Jun 28 12:19:38.016: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Change state to START (0) last state RUN (20)

*apfMsConnTask_0: Jun 28 12:19:38.016: 00:60:b9:0d:ec:1f pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_0: Jun 28 12:19:38.016: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Initializing policy

*apfMsConnTask_0: Jun 28 12:19:38.016: 00:60:b9:0d:ec:1f 10.160.91.51 START (0) Change state to AUTHCHECK (2) last state RUN (20)

*apfMsConnTask_0: Jun 28 12:19:38.016: 00:60:b9:0d:ec:1f 10.160.91.51 AUTHCHECK (2) Change state to 8021X_REQD (3) last state RUN (20)

*apfMsConnTask_0: Jun 28 12:19:38.017: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) DHCP required on AP 3c:ce:73:f8:e1:00 vapId 2 apVapId 2for this client

*apfMsConnTask_0: Jun 28 12:19:38.017: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*apfMsConnTask_0: Jun 28 12:19:38.017: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 3c:ce:73:f8:e1:00 vapId 2 apVapId 2

*apfMsConnTask_0: Jun 28 12:19:38.017: 00:60:b9:0d:ec:1f apfPemAddUser2 (apf_policy.c:268) Changing state for mobile 00:60:b9:0d:ec:1f on AP 3c:ce:73:f8:e1:00 from Associated to Associated

*apfMsConnTask_0: Jun 28 12:19:38.017: 00:60:b9:0d:ec:1f Scheduling deletion of Mobile Station: (callerId: 49) in 1800 seconds

*apfMsConnTask_0: Jun 28 12:19:38.017: 00:60:b9:0d:ec:1f Sending Assoc Response to station on BSSID 3c:ce:73:f8:e1:00 (status 0) ApVapId 2 Slot 0

*apfMsConnTask_0: Jun 28 12:19:38.017: 00:60:b9:0d:ec:1f apfProcessAssocReq (apf_80211.c:6290) Changing state for mobile 00:60:b9:0d:ec:1f on AP 3c:ce:73:f8:e1:00 from Associated to Associated

*dot1xMsgTask: Jun 28 12:19:38.019: 00:60:b9:0d:ec:1f Creating a PKC PMKID Cache entry for station 00:60:b9:0d:ec:1f (RSN 2)

*dot1xMsgTask: Jun 28 12:19:38.019: 00:60:b9:0d:ec:1f Resetting MSCB PMK Cache Entry 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:19:38.019: 00:60:b9:0d:ec:1f Removing BSSID c8:f9:f9:5b:0f:71 from PMKID cache of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:19:38.019: 00:60:b9:0d:ec:1f Setting active key cache index 0 ---> 8

*dot1xMsgTask: Jun 28 12:19:38.019: 00:60:b9:0d:ec:1f Setting active key cache index 8 ---> 0

*dot1xMsgTask: Jun 28 12:19:38.019: 00:60:b9:0d:ec:1f Adding BSSID 3c:ce:73:f8:e1:01 to PMKID cache at index 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:19:38.019: New PMKID: (16)

*dot1xMsgTask: Jun 28 12:19:38.019: [0000] 45 62 00 8d ff f9 49 d4 7c bd 6e cd c2 16 8f de

*dot1xMsgTask: Jun 28 12:19:38.019: 00:60:b9:0d:ec:1f Initiating RSN PSK to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:19:38.019: 00:60:b9:0d:ec:1f dot1x - moving mobile 00:60:b9:0d:ec:1f into Force Auth state

*dot1xMsgTask: Jun 28 12:19:38.019: 00:60:b9:0d:ec:1f Skipping EAP-Success to mobile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:19:38.019: 00:60:b9:0d:ec:1f Found an cache entry for BSSID 3c:ce:73:f8:e1:01 in PMKID cache at index 0 of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 28 12:19:38.019: Including PMKID in M1 (16)

*dot1xMsgTask: Jun 28 12:19:38.019: [0000] 45 62 00 8d ff f9 49 d4 7c bd 6e cd c2 16 8f de

*dot1xMsgTask: Jun 28 12:19:38.019: 00:60:b9:0d:ec:1f Starting key exchange to mobile 00:60:b9:0d:ec:1f, data packets will be dropped

*dot1xMsgTask: Jun 28 12:19:38.019: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Dot1x_NW_MsgTask_7: Jun 28 12:19:38.056: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:19:38.056: 00:60:b9:0d:ec:1f Received EAPOL-key in PTK_START state (message 2) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:19:38.056: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:19:38.056: 00:60:b9:0d:ec:1f Sending the random GTK in M3 for WPA2 client 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:19:38.056: 00:60:b9:0d:ec:1f Sending EAPOL-Key Message to mobile 00:60:b9:0d:ec:1f

state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01

*Dot1x_NW_MsgTask_7: Jun 28 12:19:38.062: 00:60:b9:0d:ec:1f Received EAPOL-Key from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:19:38.062: 00:60:b9:0d:ec:1f Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 28 12:19:38.062: 00:60:b9:0d:ec:1f apfMs1xStateInc

*Dot1x_NW_MsgTask_7: Jun 28 12:19:38.062: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 12:19:38.062: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) DHCP required on AP 3c:ce:73:f8:e1:00 vapId 2 apVapId 2for this client

*Dot1x_NW_MsgTask_7: Jun 28 12:19:38.062: 00:60:b9:0d:ec:1f Not Using WMM Compliance code qosCap 00

*Dot1x_NW_MsgTask_7: Jun 28 12:19:38.062: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 3c:ce:73:f8:e1:00 vapId 2 apVapId 2

*Dot1x_NW_MsgTask_7: Jun 28 12:19:38.062: 00:60:b9:0d:ec:1f apfMsRunStateInc

*Dot1x_NW_MsgTask_7: Jun 28 12:19:38.062: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHCOMPLETE (4) Change state to RUN (20) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 28 12:19:38.062: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Reached PLUMBFASTPATH: from line 5362

*Dot1x_: Jun 28 12:19:38.062: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Adding Fast Path rule

type = Airespace AP Client

on AP 3c:ce:73:f8:e1:00, slot 0, interface = 13, QOS = 2

IPv4 ACL ID = 255, IPv6 ACL ID =

*Dot1x_NW_MsgTask_7: Jun 28 12:19:38.062: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 7006 Local Bridging Vlan = 106, Local Bridging intf id = 12

*Dot1x_NW_MsgTask_7: Jun 28 12:19:38.062: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255)

*Dot1x_NW_MsgTask_7: Jun 28 12:19:38.062: 00:60:b9:0d:ec:1f Stopping retransmission timer for mobile 00:60:b9:0d:ec:1f

j

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

Scott Fella · ‎06-28-2012

Sometimes the following happens: The NEC phone is associated with an Access Point, I walk, I stand in front of another access point and takes time to turn blue, or not turn blue until I make a call.

What does Blue mean? If you still have good signal from the ap the deivce was associated to, you don't need to roam. Clients will make the final decision on roaming. You really made roaming aggressive with the values yyou entered.

Another question about AP, model LAP1041N:

How does the AP work? How does the AP broadcast?. Is It a circle and the AP is the center? Does the AP broadcast more front than back? Have any blind spot?

This depend on your floor layout and what there. A post survey can let you know how your coverage is to date. A 1042 that is mounted correctly (horizontal) will have a uniform oval shape (donut). Take a look at this guide:

http://www.cisco.com/en/US/prod/collateral/wireless/ps7183/ps469/product_data_sheet09186a008008883b.html

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

Scott Fella · ‎06-28-2012

Are you having issues with Voice or are you questioning why the device doesn't roam when you are closer to a different AP?

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

aricardor · ‎06-28-2012

Thanks you!

Perhaps the second question.

A curious case:

I leave the building, I lose the coverage. That is normal, but I entered and it's slow to associate, or it doesn't associate until i come to the office.

Saravanan Lakshmanan · ‎06-28-2012

is the issue specific to phone only or other wireless devices as well, can you check.