handover problem

[aricardor]

Hi!

I have a  WLC 5508 and 25  LAP 1041. I use two wifi, one with RADIUS for data and other with wpa-psk for voip. The problem is the voip conectivity is broken.

How can i improve the handover?

The NEC recomendation does not help me anything.

thanks!

[maldehne]

You have to make sure that you have overlapping of at least 20 % between Adjacent APs.

There are so many things to be checked, but for the time being please specify the model of phone

you are using.

[aricardor]

NEC MH240 wireless IP telephone. I think the overlap is less than 20%. The APs are LAP1041

[Saravanan Lakshmanan]

does nec do pkc or okc.

With voice it is expected to have roaming issue with psk only, it is recommeded to use WPA2 with 802.1X+CCKM for fast secure roaming. But NEC doesn't look like it supports cckm/ccx from below link.

http://www.cisco.com/web/partners/pr46/pr147/partners_pgm_partners_0900aecd800a7907.html

------

English version

http://www.necux5000.com/dealer_area/documents/mobility_solutions/wifi_handset/ubux5009003an.pdf

Known Service Conditions and/or Limitations

Service Conditions/Limitations that may affect voice quality:

1. CISCO does not support standard based CAC, a method to limit the maximum number of

clients (MH240 handsets) per radio. This could cause issues such as degradation to voice

quality if there are over subscriptions on a particular access point

answer

http://www.cisco.com/en/US/docs/wireless/controller/release/notes/crn7_2.html#wp912730

KTS-Based CAC Support for NEC

Key Telephone System (KTS)-based CAC is a protocol that is used in NEC MH240 wireless IP telephones. You can configure the controller to support CAC on KTS-based SIP clients to process bandwidth request messages from clients, to allocate the required bandwidth on the AP radio, and to handle other messages that are part of the protocol.

[aricardor]

I think the problem is the coverage and overlap. But, the NEC device, or any Smartphone, is associated with a AP (for example, in front of office on the first floor), When I enter the building, the NEC can not associate with other APs, or is slow to associate, until he entered the office, on the first floor.

Two differents wifi affects on the performance of associate or handover?

Thanks

[Saravanan Lakshmanan]

did you follow the nec reco guide for cisco gear.

in high density environment many client would roam between APs without an issue so two clients should not be an issue. Fix the coverage and overlap, it will help smooth rf roaming but can't help on smooth hand off, however psk is still quicker.

while reproducing the issue get the below output.

WLC>debug client

[aricardor]

Thank you!

i try to do the command "debug client". Two question: Where is the "KTS-Based CAC Support for NEC" option?

Is the handover/handoff affected by the two differents wifi broadcasting?

[maldehne]

When running the debug client

if you see reassociation sent from the client upon roaming there shouldn't be any overlapping issue

if you see association frame sent to the new ap from the target client , then yes there is coverage hole.

Cheers

[aricardor]

Thank you. Well, it's the first time i use that tool. How to i see the reassociation or frames?

[maldehne]

have the following command enabled:

debug client < mac address >

associate to AP1 then move toward AP2 while the debug is running to reproduce the problem.

Attach the resulting output here.

You should see the reassociation in the debug output.

Regards

[aricardor]

Hello:

I send you two logs.

First log:

(Cisco Controller) debug>*apfMsConnTask_6: Jun 27 11:27:36.722: 00:60:b9:0d:ec:1

f Reassociation received from mobile on AP 3c:ce:73:f9:2e:c0

*apfMsConnTask_6: Jun 27 11:27:36.722: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) C

hanging IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_po

licy.c:1697)

*apfMsConnTask_6: Jun 27 11:27:36.722: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) C

hanging IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_po

licy.c:1864)

*apfMsConnTask_6: Jun 27 11:27:36.722: 00:60:b9:0d:ec:1f Applying site-specific

Local Bridging override for station 00:60:b9:0d:ec:1f - vapId 2, site 'default-g

roup', interface 'pvoz'

*apfMsConnTask_6: Jun 27 11:27:36.722: 00:60:b9:0d:ec:1f Applying Local Bridging

Interface Policy for station 00:60:b9:0d:ec:1f - vlan 106, interface id 12, int

erface 'pvoz'

*apfMsConnTask_6: Jun 27 11:27:36.722: 00:60:b9:0d:ec:1f processSsidIE  statusCo

de is 0 and status is 0

*apfMsConnTask_6: Jun 27 11:27:36.722: 00:60:b9:0d:ec:1f processSsidIE  ssid_don

e_flag is 0 finish_flag is 0

*apfMsConnTask_6: Jun 27 11:27:36.722: 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 27 11:27:36.722: 00:60:b9:0d:ec:1f suppRates  statusCode i

s 0 and gotSuppRatesElement is 1

*apfMsConnTask_6: Jun 27 11:27:36.722: 00:60:b9:0d:ec:1f STA - rates (10): 139 2

2 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_6: Jun 27 11:27:36.722: 00:60:b9:0d:ec:1f extSuppRates  statusCod

e is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_6: Jun 27 11:27:36.722: 00:60:b9:0d:ec:1f Processing RSN IE type

48, length 20 for mobile 00:60:b9:0d:ec:1f

*apfMsConnTask_6: Jun 27 11:27:36.723: 00:60:b9:0d:ec:1f pemApfDeleteMobileStati

on2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_6: Jun 27 11:27:36.723: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) D

eleted mobile LWAPP rule on AP [3c:ce:73:f8:e1:00]

*pemReceiveTask: Jun 27 11:27:36.723: 00:60:b9:0d:ec:1f 10.160.91.51 Removed NPU

entry.

*apfMsConnTask_6: Jun 27 11:27:36.723: 00:60:b9:0d:ec:1f Updated location for st

ation old AP 3c:ce:73:f8:e1:00-0, new AP 3c:ce:73:f9:2e:c0-0

*apfMsConnTask_6: Jun 27 11:27:36.723: 00:60:b9:0d:ec:1f apfMsRunStateDec

*apfMsConnTask_6: Jun 27 11:27:36.723: 00:60:b9:0d:ec:1f apfMs1xStateDec

*apfMsConnTask_6: Jun 27 11:27:36.723: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) C

hange state to START (0) last state RUN (20)

*apfMsConnTask_6: Jun 27 11:27:36.723: 00:60:b9:0d:ec:1f pemApfAddMobileStation2

: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_6: Jun 27 11:27:36.723: 00:60:b9:0d:ec:1f 10.160.91.51 START (0)

Initializing policy

*apfMsConnTask_6: Jun 27 11:27:36.723: 00:60:b9:0d:ec:1f 10.160.91.51 START (0)

Change state to AUTHCHECK (2) last state RUN (20)

*apfMsConnTask_6: Jun 27 11:27:36.723: 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 27 11:27:36.723: 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 27 11:27:36.723: 00:60:b9:0d:ec:1f Not Using WMM Complianc

e code qosCap 00

*apfMsConnTask_6: Jun 27 11:27:36.723: 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 27 11:27:36.723: 00:60:b9:0d:ec:1f apfPemAddUser2 (apf_pol

icy.c:268) Changing state for mobile 00:60:b9:0d:ec:1f on AP 3c:ce:73:f9:2e:c0 f

rom Associated to Associated

*apfMsConnTask_6: Jun 27 11:27:36.723: 00:60:b9:0d:ec:1f Scheduling deletion of

Mobile Station:  (callerId: 49) in 1800 seconds

*apfMsConnTask_6: Jun 27 11:27:36.723: 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 27 11:27:36.723: 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 27 11:27:36.725: 00:60:b9:0d:ec:1f Creating a PKC PMKID Cache

entry for station 00:60:b9:0d:ec:1f (RSN 2)

*dot1xMsgTask: Jun 27 11:27:36.725: 00:60:b9:0d:ec:1f Resetting MSCB PMK Cache E

ntry 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:27:36.725: 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 27 11:27:36.725: 00:60:b9:0d:ec:1f Setting active key cache i

ndex 0 ---> 8

*dot1xMsgTask: Jun 27 11:27:36.725: 00:60:b9:0d:ec:1f Setting active key cache i

ndex 8 ---> 0

*dot1xMsgTask: Jun 27 11:27:36.725: 00:60:b9:0d:ec:1f Adding BSSID 3c:ce:73:f9:2

e:c1 to PMKID cache at index 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:27:36.725: New PMKID: (16)

*dot1xMsgTask: Jun 27 11:27:36.725:      [0000] 74 1f ee 29 2e 8d fc df 33 97 9a

33 d6 57 d8 be

*dot1xMsgTask: Jun 27 11:27:36.725: 00:60:b9:0d:ec:1f Initiating RSN PSK to mobi

le 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:27:36.726: 00:60:b9:0d:ec:1f dot1x - moving mobile 00:6

0:b9:0d:ec:1f into Force Auth state

*dot1xMsgTask: Jun 27 11:27:36.726: 00:60:b9:0d:ec:1f Skipping EAP-Success to mo

bile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:27:36.726: 00:60:b9:0d:ec:1f Found an cache entry for B

SSID 3c:ce:73:f9:2e:c1 in PMKID cache at index 0 of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:27:36.726: 00:60:b9:0d:ec:1f Found an cache entry for B

SSID 3c:ce:73:f9:2e:c1 in PMKID cache at index 0 of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:27:36.726: Including PMKID in M1  (16)

*dot1xMsgTask: Jun 27 11:27:36.726:      [0000] 74 1f ee 29 2e 8d fc df 33 97 9a

33 d6 57 d8 be

*dot1xMsgTask: Jun 27 11:27:36.726: 00:60:b9:0d:ec:1f Starting key exchange to m

obile 00:60:b9:0d:ec:1f, data packets will be dropped

*dot1xMsgTask: Jun 27 11:27:36.726: 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 27 11:27:36.767: 00:60:b9:0d:ec:1f Received EAPOL-Key f

rom mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:27:36.767: 00:60:b9:0d:ec:1f Received EAPOL-key i

n PTK_START state (message 2) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:27:36.767: 00:60:b9:0d:ec:1f Stopping retransmiss

ion timer for mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:27:36.767: 00:60:b9:0d:ec:1f Sending the random G

TK in M3 for WPA2 client  00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:27:36.767: 00:60:b9:0d:ec:1f Sending EAPOL-Key Me

ssage 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 27 11:27:36.771: 00:60:b9:0d:ec:1f Received EAPOL-Key f

rom mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:27:36.771: 00:60:b9:0d:ec:1f Received EAPOL-key i

n PTKINITNEGOTIATING state (message 4) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:27:36.771: 00:60:b9:0d:ec:1f apfMs1xStateInc

*Dot1x_NW_MsgTask_7: Jun 27 11:27:36.771: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_R

EQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 27 11:27:36.772: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHC

OMPLETE (4) DHCP required on AP 3c:ce:73:f9:2e:c0 vapId 2 apVapId 2for this clie

nt

*Dot1x_NW_MsgTask_7: Jun 27 11:27:36.772: 00:60:b9:0d:ec:1f Not Using WMM Compli

ance code qosCap 00

*Dot1x_NW_MsgTask_7: Jun 27 11:27:36.772: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHC

OMPLETE (4) Plumbed mobile LWAPP rule on AP 3c:ce:73:f9:2e:c0 vapId 2 apVapId 2

*Dot1x_NW_MsgTask_7: Jun 27 11:27:36.772: 00:60:b9:0d:ec:1f apfMsRunStateInc

*Dot1x_NW_MsgTask_7: Jun 27 11:27:36.772: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHC

OMPLETE (4) Change state to RUN (20) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 27 11:27:36.772: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20

) Reached PLUMBFASTPATH: from line 5362

*Dot1x_: Jun 27 11:27:36.772: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Adding Fas

t 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 27 11:27:36.772: 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 27 11:27:36.772: 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 27 11:27:36.772: 00:60:b9:0d:ec:1f Stopping retransmiss

ion timer for mobile 00:60:b9:0d:ec:1f

*pemReceiveTask: Jun 27 11:27:36.772: 00:60:b9:0d:ec:1f 10.160.91.51 Added NPU e

ntry of type 1, dtlFlags 0x0

*apfMsConnTask_3: Jun 27 11:29:25.570: 00:60:b9:0d:ec:1f Reassociation received

from mobile on AP 3c:ce:73:f9:13:e0

*apfMsConnTask_3: Jun 27 11:29:25.570: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) C

hanging IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_po

licy.c:1697)

*apfMsConnTask_3: Jun 27 11:29:25.570: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) C

hanging IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_po

licy.c:1864)

*apfMsConnTask_3: Jun 27 11:29:25.570: 00:60:b9:0d:ec:1f Applying site-specific

Local Bridging override for station 00:60:b9:0d:ec:1f - vapId 2, site 'default-g

roup', interface 'pvoz'

*apfMsConnTask_3: Jun 27 11:29:25.570: 00:60:b9:0d:ec:1f Applying Local Bridging

Interface Policy for station 00:60:b9:0d:ec:1f - vlan 106, interface id 12, int

erface 'pvoz'

*apfMsConnTask_3: Jun 27 11:29:25.570: 00:60:b9:0d:ec:1f processSsidIE  statusCo

de is 0 and status is 0

*apfMsConnTask_3: Jun 27 11:29:25.570: 00:60:b9:0d:ec:1f processSsidIE  ssid_don

e_flag is 0 finish_flag is 0

*apfMsConnTask_3: Jun 27 11:29:25.570: 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 27 11:29:25.570: 00:60:b9:0d:ec:1f suppRates  statusCode i

s 0 and gotSuppRatesElement is 1

*apfMsConnTask_3: Jun 27 11:29:25.570: 00:60:b9:0d:ec:1f STA - rates (10): 139 2

2 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_3: Jun 27 11:29:25.570: 00:60:b9:0d:ec:1f extSuppRates  statusCod

e is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_3: Jun 27 11:29:25.571: 00:60:b9:0d:ec:1f Processing RSN IE type

48, length 20 for mobile 00:60:b9:0d:ec:1f

*apfMsConnTask_3: Jun 27 11:29:25.571: 00:60:b9:0d:ec:1f pemApfDeleteMobileStati

on2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_3: Jun 27 11:29:25.571: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) D

eleted mobile LWAPP rule on AP [3c:ce:73:f9:2e:c0]

*pemReceiveTask: Jun 27 11:29:25.571: 00:60:b9:0d:ec:1f 10.160.91.51 Removed NPU

entry.

*apfMsConnTask_3: Jun 27 11:29:25.571: 00:60:b9:0d:ec:1f Updated location for st

ation old AP 3c:ce:73:f9:2e:c0-0, new AP 3c:ce:73:f9:13:e0-0

*apfMsConnTask_3: Jun 27 11:29:25.571: 00:60:b9:0d:ec:1f apfMsRunStateDec

*apfMsConnTask_3: Jun 27 11:29:25.571: 00:60:b9:0d:ec:1f apfMs1xStateDec

*apfMsConnTask_3: Jun 27 11:29:25.571: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) C

hange state to START (0) last state RUN (20)

*apfMsConnTask_3: Jun 27 11:29:25.571: 00:60:b9:0d:ec:1f pemApfAddMobileStation2

: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_3: Jun 27 11:29:25.571: 00:60:b9:0d:ec:1f 10.160.91.51 START (0)

Initializing policy

*apfMsConnTask_3: Jun 27 11:29:25.571: 00:60:b9:0d:ec:1f 10.160.91.51 START (0)

Change state to AUTHCHECK (2) last state RUN (20)

*apfMsConnTask_3: Jun 27 11:29:25.571: 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 27 11:29:25.571: 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 27 11:29:25.571: 00:60:b9:0d:ec:1f Not Using WMM Complianc

e code qosCap 00

*apfMsConnTask_3: Jun 27 11:29:25.571: 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 27 11:29:25.571: 00:60:b9:0d:ec:1f apfPemAddUser2 (apf_pol

icy.c:268) Changing state for mobile 00:60:b9:0d:ec:1f on AP 3c:ce:73:f9:13:e0 f

rom Associated to Associated

*apfMsConnTask_3: Jun 27 11:29:25.571: 00:60:b9:0d:ec:1f Scheduling deletion of

Mobile Station:  (callerId: 49) in 1800 seconds

*apfMsConnTask_3: Jun 27 11:29:25.571: 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 27 11:29:25.571: 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 27 11:29:25.573: 00:60:b9:0d:ec:1f Creating a PKC PMKID Cache

entry for station 00:60:b9:0d:ec:1f (RSN 2)

*dot1xMsgTask: Jun 27 11:29:25.573: 00:60:b9:0d:ec:1f Resetting MSCB PMK Cache E

ntry 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:29:25.573: 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 27 11:29:25.573: 00:60:b9:0d:ec:1f Setting active key cache i

ndex 0 ---> 8

*dot1xMsgTask: Jun 27 11:29:25.573: 00:60:b9:0d:ec:1f Setting active key cache i

ndex 8 ---> 0

*dot1xMsgTask: Jun 27 11:29:25.573: 00:60:b9:0d:ec:1f Adding BSSID 3c:ce:73:f9:1

3:e1 to PMKID cache at index 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:29:25.573: New PMKID: (16)

*dot1xMsgTask: Jun 27 11:29:25.573:      [0000] 8e d8 80 65 d2 75 1e 24 a7 a1 ab

8b 7e 72 e1 6a

*dot1xMsgTask: Jun 27 11:29:25.573: 00:60:b9:0d:ec:1f Initiating RSN PSK to mobi

le 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:29:25.573: 00:60:b9:0d:ec:1f dot1x - moving mobile 00:6

0:b9:0d:ec:1f into Force Auth state

*dot1xMsgTask: Jun 27 11:29:25.574: 00:60:b9:0d:ec:1f Skipping EAP-Success to mo

bile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:29:25.574: 00:60:b9:0d:ec:1f Found an cache entry for B

SSID 3c:ce:73:f9:13:e1 in PMKID cache at index 0 of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:29:25.574: 00:60:b9:0d:ec:1f Found an cache entry for B

SSID 3c:ce:73:f9:13:e1 in PMKID cache at index 0 of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:29:25.574: Including PMKID in M1  (16)

*dot1xMsgTask: Jun 27 11:29:25.574:      [0000] 8e d8 80 65 d2 75 1e 24 a7 a1 ab

8b 7e 72 e1 6a

*dot1xMsgTask: Jun 27 11:29:25.574: 00:60:b9:0d:ec:1f Starting key exchange to m

obile 00:60:b9:0d:ec:1f, data packets will be dropped

*dot1xMsgTask: Jun 27 11:29:25.574: 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 27 11:29:25.634: 00:60:b9:0d:ec:1f Received EAPOL-Key f

rom mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:29:25.634: 00:60:b9:0d:ec:1f Received EAPOL-key i

n PTK_START state (message 2) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:29:25.634: 00:60:b9:0d:ec:1f Stopping retransmiss

ion timer for mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:29:25.634: 00:60:b9:0d:ec:1f Sending the random G

TK in M3 for WPA2 client  00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:29:25.634: 00:60:b9:0d:ec:1f Sending EAPOL-Key Me

ssage 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 27 11:29:25.645: 00:60:b9:0d:ec:1f Received EAPOL-Key f

rom mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:29:25.645: 00:60:b9:0d:ec:1f Received EAPOL-key i

n PTKINITNEGOTIATING state (message 4) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:29:25.645: 00:60:b9:0d:ec:1f apfMs1xStateInc

*Dot1x_NW_MsgTask_7: Jun 27 11:29:25.645: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_R

EQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 27 11:29:25.645: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHC

OMPLETE (4) DHCP required on AP 3c:ce:73:f9:13:e0 vapId 2 apVapId 2for this clie

nt

*Dot1x_NW_MsgTask_7: Jun 27 11:29:25.645: 00:60:b9:0d:ec:1f Not Using WMM Compli

ance code qosCap 00

*Dot1x_NW_MsgTask_7: Jun 27 11:29:25.645: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHC

OMPLETE (4) Plumbed mobile LWAPP rule on AP 3c:ce:73:f9:13:e0 vapId 2 apVapId 2

*Dot1x_NW_MsgTask_7: Jun 27 11:29:25.645: 00:60:b9:0d:ec:1f apfMsRunStateInc

*Dot1x_NW_MsgTask_7: Jun 27 11:29:25.645: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHC

OMPLETE (4) Change state to RUN (20) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 27 11:29:25.646: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20

) Reached PLUMBFASTPATH: from line 5362

*Dot1x_: Jun 27 11:29:25.646: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Adding Fas

t 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 27 11:29:25.646: 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 27 11:29:25.646: 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 27 11:29:25.646: 00:60:b9:0d:ec:1f Stopping retransmiss

ion timer for mobile 00:60:b9:0d:ec:1f

*pemReceiveTask: Jun 27 11:29:25.646: 00:60:b9:0d:ec:1f 10.160.91.51 Added NPU e

ntry of type 1, dtlFlags 0x0

*apfMsConnTask_0: Jun 27 11:29:36.736: 00:60:b9:0d:ec:1f Reassociation received

from mobile on AP 2c:36:f8:e9:8b:70

*apfMsConnTask_0: Jun 27 11:29:36.736: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) C

hanging IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_po

licy.c:1697)

*apfMsConnTask_0: Jun 27 11:29:36.736: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) C

hanging IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_po

licy.c:1864)

*apfMsConnTask_0: Jun 27 11:29:36.736: 00:60:b9:0d:ec:1f Applying site-specific

Local Bridging override for station 00:60:b9:0d:ec:1f - vapId 2, site 'default-g

roup', interface 'pvoz'

*apfMsConnTask_0: Jun 27 11:29:36.736: 00:60:b9:0d:ec:1f Applying Local Bridging

Interface Policy for station 00:60:b9:0d:ec:1f - vlan 106, interface id 12, int

erface 'pvoz'

*apfMsConnTask_0: Jun 27 11:29:36.736: 00:60:b9:0d:ec:1f processSsidIE  statusCo

de is 0 and status is 0

*apfMsConnTask_0: Jun 27 11:29:36.736: 00:60:b9:0d:ec:1f processSsidIE  ssid_don

e_flag is 0 finish_flag is 0

*apfMsConnTask_0: Jun 27 11:29:36.736: 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 27 11:29:36.736: 00:60:b9:0d:ec:1f suppRates  statusCode i

s 0 and gotSuppRatesElement is 1

*apfMsConnTask_0: Jun 27 11:29:36.736: 00:60:b9:0d:ec:1f STA - rates (10): 139 2

2 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_0: Jun 27 11:29:36.736: 00:60:b9:0d:ec:1f extSuppRates  statusCod

e is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_0: Jun 27 11:29:36.736: 00:60:b9:0d:ec:1f Processing RSN IE type

48, length 20 for mobile 00:60:b9:0d:ec:1f

*apfMsConnTask_0: Jun 27 11:29:36.736: 00:60:b9:0d:ec:1f pemApfDeleteMobileStati

on2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_0: Jun 27 11:29:36.736: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) D

eleted mobile LWAPP rule on AP [3c:ce:73:f9:13:e0]

*pemReceiveTask: Jun 27 11:29:36.736: 00:60:b9:0d:ec:1f 10.160.91.51 Removed NPU

entry.

*apfMsConnTask_0: Jun 27 11:29:36.737: 00:60:b9:0d:ec:1f Updated location for st

ation old AP 3c:ce:73:f9:13:e0-0, new AP 2c:36:f8:e9:8b:70-0

*apfMsConnTask_0: Jun 27 11:29:36.737: 00:60:b9:0d:ec:1f apfMsRunStateDec

*apfMsConnTask_0: Jun 27 11:29:36.737: 00:60:b9:0d:ec:1f apfMs1xStateDec

*apfMsConnTask_0: Jun 27 11:29:36.737: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) C

hange state to START (0) last state RUN (20)

*apfMsConnTask_0: Jun 27 11:29:36.737: 00:60:b9:0d:ec:1f pemApfAddMobileStation2

: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_0: Jun 27 11:29:36.737: 00:60:b9:0d:ec:1f 10.160.91.51 START (0)

Initializing policy

*apfMsConnTask_0: Jun 27 11:29:36.737: 00:60:b9:0d:ec:1f 10.160.91.51 START (0)

Change state to AUTHCHECK (2) last state RUN (20)

*apfMsConnTask_0: Jun 27 11:29:36.737: 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 27 11:29:36.737: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD

(3) DHCP required on AP 2c:36:f8:e9:8b:70 vapId 2 apVapId 2for this client

*apfMsConnTask_0: Jun 27 11:29:36.737: 00:60:b9:0d:ec:1f Not Using WMM Complianc

e code qosCap 00

*apfMsConnTask_0: Jun 27 11:29:36.737: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD

(3) Plumbed mobile LWAPP rule on AP 2c:36:f8:e9:8b:70 vapId 2 apVapId 2

*apfMsConnTask_0: Jun 27 11:29:36.737: 00:60:b9:0d:ec:1f apfPemAddUser2 (apf_pol

icy.c:268) Changing state for mobile 00:60:b9:0d:ec:1f on AP 2c:36:f8:e9:8b:70 f

rom Associated to Associated

*apfMsConnTask_0: Jun 27 11:29:36.737: 00:60:b9:0d:ec:1f Scheduling deletion of

Mobile Station:  (callerId: 49) in 1800 seconds

*apfMsConnTask_0: Jun 27 11:29:36.737: 00:60:b9:0d:ec:1f Sending Assoc Response

to station on BSSID 2c:36:f8:e9:8b:70 (status 0) ApVapId 2 Slot 0

*apfMsConnTask_0: Jun 27 11:29:36.737: 00:60:b9:0d:ec:1f apfProcessAssocReq (apf

_80211.c:6290) Changing state for mobile 00:60:b9:0d:ec:1f on AP 2c:36:f8:e9:8b:

70 from Associated to Associated

*dot1xMsgTask: Jun 27 11:29:36.739: 00:60:b9:0d:ec:1f Creating a PKC PMKID Cache

entry for station 00:60:b9:0d:ec:1f (RSN 2)

*dot1xMsgTask: Jun 27 11:29:36.739: 00:60:b9:0d:ec:1f Resetting MSCB PMK Cache E

ntry 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:29:36.739: 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 27 11:29:36.739: 00:60:b9:0d:ec:1f Setting active key cache i

ndex 0 ---> 8

*dot1xMsgTask: Jun 27 11:29:36.739: 00:60:b9:0d:ec:1f Setting active key cache i

ndex 8 ---> 0

*dot1xMsgTask: Jun 27 11:29:36.739: 00:60:b9:0d:ec:1f Adding BSSID 2c:36:f8:e9:8

b:71 to PMKID cache at index 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:29:36.739: New PMKID: (16)

*dot1xMsgTask: Jun 27 11:29:36.739:      [0000] e1 7e 9b 2b fe 9d 4f 61 52 08 05

70 9e 9d 5a 8c

*dot1xMsgTask: Jun 27 11:29:36.739: 00:60:b9:0d:ec:1f Initiating RSN PSK to mobi

le 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:29:36.739: 00:60:b9:0d:ec:1f dot1x - moving mobile 00:6

0:b9:0d:ec:1f into Force Auth state

*dot1xMsgTask: Jun 27 11:29:36.739: 00:60:b9:0d:ec:1f Skipping EAP-Success to mo

bile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:29:36.739: 00:60:b9:0d:ec:1f Found an cache entry for B

SSID 2c:36:f8:e9:8b:71 in PMKID cache at index 0 of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:29:36.739: 00:60:b9:0d:ec:1f Found an cache entry for B

SSID 2c:36:f8:e9:8b:71 in PMKID cache at index 0 of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:29:36.739: Including PMKID in M1  (16)

*dot1xMsgTask: Jun 27 11:29:36.739:      [0000] e1 7e 9b 2b fe 9d 4f 61 52 08 05

70 9e 9d 5a 8c

*dot1xMsgTask: Jun 27 11:29:36.739: 00:60:b9:0d:ec:1f Starting key exchange to m

obile 00:60:b9:0d:ec:1f, data packets will be dropped

*dot1xMsgTask: Jun 27 11:29:36.739: 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 27 11:29:36.781: 00:60:b9:0d:ec:1f Received EAPOL-Key f

rom mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:29:36.781: 00:60:b9:0d:ec:1f Received EAPOL-key i

n PTK_START state (message 2) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:29:36.781: 00:60:b9:0d:ec:1f Stopping retransmiss

ion timer for mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:29:36.781: 00:60:b9:0d:ec:1f Sending the random G

TK in M3 for WPA2 client  00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:29:36.781: 00:60:b9:0d:ec:1f Sending EAPOL-Key Me

ssage 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 27 11:29:36.785: 00:60:b9:0d:ec:1f Received EAPOL-Key f

rom mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:29:36.785: 00:60:b9:0d:ec:1f Received EAPOL-key i

n PTKINITNEGOTIATING state (message 4) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:29:36.785: 00:60:b9:0d:ec:1f apfMs1xStateInc

*Dot1x_NW_MsgTask_7: Jun 27 11:29:36.785: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_R

EQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 27 11:29:36.785: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHC

OMPLETE (4) DHCP required on AP 2c:36:f8:e9:8b:70 vapId 2 apVapId 2for this clie

nt

*Dot1x_NW_MsgTask_7: Jun 27 11:29:36.785: 00:60:b9:0d:ec:1f Not Using WMM Compli

ance code qosCap 00

*Dot1x_NW_MsgTask_7: Jun 27 11:29:36.785: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHC

OMPLETE (4) Plumbed mobile LWAPP rule on AP 2c:36:f8:e9:8b:70 vapId 2 apVapId 2

*Dot1x_NW_MsgTask_7: Jun 27 11:29:36.786: 00:60:b9:0d:ec:1f apfMsRunStateInc

*Dot1x_NW_MsgTask_7: Jun 27 11:29:36.786: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHC

OMPLETE (4) Change state to RUN (20) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 27 11:29:36.786: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20

) Reached PLUMBFASTPATH: from line 5362

*Dot1x_: Jun 27 11:29:36.786: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Adding Fas

t Path rule

  type = Airespace AP Client

  on AP 2c:36:f8:e9:8b:70, slot 0, interface = 13, QOS = 2

  IPv4 ACL ID = 255, IPv6 ACL ID =

*Dot1x_NW_MsgTask_7: Jun 27 11:29:36.786: 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 27 11:29:36.786: 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 27 11:29:36.786: 00:60:b9:0d:ec:1f Stopping retransmiss

ion timer for mobile 00:60:b9:0d:ec:1f

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

Second log:

bile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:43:35.430: 00:60:b9:0d:ec:1f Found an cache entry for B

SSID 3c:ce:73:95:40:01 in PMKID cache at index 0 of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:43:35.430: 00:60:b9:0d:ec:1f Found an cache entry for B

SSID 3c:ce:73:95:40:01 in PMKID cache at index 0 of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:43:35.430: Including PMKID in M1  (16)

*dot1xMsgTask: Jun 27 11:43:35.430:      [0000] ac 0b 62 a3 0d cd 4f 08 5c 29 2d

d0 10 7c a8 e5

*dot1xMsgTask: Jun 27 11:43:35.430: 00:60:b9:0d:ec:1f Starting key exchange to m

obile 00:60:b9:0d:ec:1f, data packets will be dropped

*dot1xMsgTask: Jun 27 11:43:35.430: 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 27 11:43:35.470: 00:60:b9:0d:ec:1f Received EAPOL-Key f

rom mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:43:35.470: 00:60:b9:0d:ec:1f Received EAPOL-key i

n PTK_START state (message 2) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:43:35.470: 00:60:b9:0d:ec:1f Stopping retransmiss

ion timer for mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:43:35.470: 00:60:b9:0d:ec:1f Sending the random G

TK in M3 for WPA2 client  00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:43:35.470: 00:60:b9:0d:ec:1f Sending EAPOL-Key Me

ssage 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 27 11:43:35.474: 00:60:b9:0d:ec:1f Received EAPOL-Key f

rom mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:43:35.474: 00:60:b9:0d:ec:1f Received EAPOL-key i

n PTKINITNEGOTIATING state (message 4) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:43:35.474: 00:60:b9:0d:ec:1f apfMs1xStateInc

*Dot1x_NW_MsgTask_7: Jun 27 11:43:35.474: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_R

EQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 27 11:43:35.474: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHC

OMPLETE (4) DHCP required on AP 3c:ce:73:95:40:00 vapId 2 apVapId 2for this clie

nt

*Dot1x_NW_MsgTask_7: Jun 27 11:43:35.474: 00:60:b9:0d:ec:1f Not Using WMM Compli

ance code qosCap 00

*Dot1x_NW_MsgTask_7: Jun 27 11:43:35.474: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHC

OMPLETE (4) Plumbed mobile LWAPP rule on AP 3c:ce:73:95:40:00 vapId 2 apVapId 2

*Dot1x_NW_MsgTask_7: Jun 27 11:43:35.474: 00:60:b9:0d:ec:1f apfMsRunStateInc

*Dot1x_NW_MsgTask_7: Jun 27 11:43:35.474: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHC

OMPLETE (4) Change state to RUN (20) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 27 11:43:35.474: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20

) Reached PLUMBFASTPATH: from line 5362

*Dot1x_: Jun 27 11:43:35.474: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Adding Fas

t Path rule

  type = Airespace AP Client

  on AP 3c:ce:73:95:40:00, slot 0, interface = 13, QOS = 2

  IPv4 ACL ID = 255, IPv6 ACL ID =

*Dot1x_NW_MsgTask_7: Jun 27 11:43:35.474: 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 27 11:43:35.474: 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 27 11:43:35.474: 00:60:b9:0d:ec:1f Stopping retransmiss

ion timer for mobile 00:60:b9:0d:ec:1f

*pemReceiveTask: Jun 27 11:43:35.475: 00:60:b9:0d:ec:1f 10.160.91.51 Added NPU e

ntry of type 1, dtlFlags 0x0

*apfMsConnTask_5: Jun 27 11:45:13.475: 00:60:b9:0d:ec:1f Reassociation received

from mobile on AP c8:f9:f9:5b:0e:e0

*apfMsConnTask_5: Jun 27 11:45:13.475: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) C

hanging IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_po

licy.c:1697)

*apfMsConnTask_5: Jun 27 11:45:13.475: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) C

hanging IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_po

licy.c:1864)

*apfMsConnTask_5: Jun 27 11:45:13.475: 00:60:b9:0d:ec:1f Applying site-specific

Local Bridging override for station 00:60:b9:0d:ec:1f - vapId 2, site 'default-g

roup', interface 'pvoz'

*apfMsConnTask_5: Jun 27 11:45:13.475: 00:60:b9:0d:ec:1f Applying Local Bridging

Interface Policy for station 00:60:b9:0d:ec:1f - vlan 106, interface id 12, int

erface 'pvoz'

*apfMsConnTask_5: Jun 27 11:45:13.475: 00:60:b9:0d:ec:1f processSsidIE  statusCo

de is 0 and status is 0

*apfMsConnTask_5: Jun 27 11:45:13.475: 00:60:b9:0d:ec:1f processSsidIE  ssid_don

e_flag is 0 finish_flag is 0

*apfMsConnTask_5: Jun 27 11:45:13.475: 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 27 11:45:13.475: 00:60:b9:0d:ec:1f suppRates  statusCode i

s 0 and gotSuppRatesElement is 1

*apfMsConnTask_5: Jun 27 11:45:13.475: 00:60:b9:0d:ec:1f STA - rates (10): 139 2

2 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_5: Jun 27 11:45:13.475: 00:60:b9:0d:ec:1f extSuppRates  statusCod

e is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_5: Jun 27 11:45:13.475: 00:60:b9:0d:ec:1f Processing RSN IE type

48, length 20 for mobile 00:60:b9:0d:ec:1f

*apfMsConnTask_5: Jun 27 11:45:13.475: 00:60:b9:0d:ec:1f pemApfDeleteMobileStati

on2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_5: Jun 27 11:45:13.475: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) D

eleted mobile LWAPP rule on AP [3c:ce:73:95:40:00]

*pemReceiveTask: Jun 27 11:45:13.476: 00:60:b9:0d:ec:1f 10.160.91.51 Removed NPU

entry.

*apfMsConnTask_5: Jun 27 11:45:13.476: 00:60:b9:0d:ec:1f Updated location for st

ation old AP 3c:ce:73:95:40:00-0, new AP c8:f9:f9:5b:0e:e0-0

*apfMsConnTask_5: Jun 27 11:45:13.476: 00:60:b9:0d:ec:1f apfMsRunStateDec

*apfMsConnTask_5: Jun 27 11:45:13.476: 00:60:b9:0d:ec:1f apfMs1xStateDec

*apfMsConnTask_5: Jun 27 11:45:13.476: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) C

hange state to START (0) last state RUN (20)

*apfMsConnTask_5: Jun 27 11:45:13.476: 00:60:b9:0d:ec:1f pemApfAddMobileStation2

: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_5: Jun 27 11:45:13.476: 00:60:b9:0d:ec:1f 10.160.91.51 START (0)

Initializing policy

*apfMsConnTask_5: Jun 27 11:45:13.476: 00:60:b9:0d:ec:1f 10.160.91.51 START (0)

Change state to AUTHCHECK (2) last state RUN (20)

*apfMsConnTask_5: Jun 27 11:45:13.476: 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 27 11:45:13.476: 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 27 11:45:13.476: 00:60:b9:0d:ec:1f Not Using WMM Complianc

e code qosCap 00

*apfMsConnTask_5: Jun 27 11:45:13.476: 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 27 11:45:13.476: 00:60:b9:0d:ec:1f apfPemAddUser2 (apf_pol

icy.c:268) Changing state for mobile 00:60:b9:0d:ec:1f on AP c8:f9:f9:5b:0e:e0 f

rom Associated to Associated

*apfMsConnTask_5: Jun 27 11:45:13.476: 00:60:b9:0d:ec:1f Scheduling deletion of

Mobile Station:  (callerId: 49) in 1800 seconds

*apfMsConnTask_5: Jun 27 11:45:13.476: 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 27 11:45:13.476: 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 27 11:45:13.478: 00:60:b9:0d:ec:1f Creating a PKC PMKID Cache

entry for station 00:60:b9:0d:ec:1f (RSN 2)

*dot1xMsgTask: Jun 27 11:45:13.478: 00:60:b9:0d:ec:1f Resetting MSCB PMK Cache E

ntry 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:45:13.478: 00:60:b9:0d:ec:1f Removing BSSID 3c:ce:73:95

:40:01 from PMKID cache of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:45:13.478: 00:60:b9:0d:ec:1f Setting active key cache i

ndex 0 ---> 8

*dot1xMsgTask: Jun 27 11:45:13.478: 00:60:b9:0d:ec:1f Setting active key cache i

ndex 8 ---> 0

*dot1xMsgTask: Jun 27 11:45:13.478: 00:60:b9:0d:ec:1f Adding BSSID c8:f9:f9:5b:0

e:e1 to PMKID cache at index 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:45:13.478: New PMKID: (16)

*dot1xMsgTask: Jun 27 11:45:13.478:      [0000] 09 1d 27 25 44 d4 32 7b 4a dc d8

46 6d 8a d4 92

*dot1xMsgTask: Jun 27 11:45:13.478: 00:60:b9:0d:ec:1f Initiating RSN PSK to mobi

le 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:45:13.478: 00:60:b9:0d:ec:1f dot1x - moving mobile 00:6

0:b9:0d:ec:1f into Force Auth state

*dot1xMsgTask: Jun 27 11:45:13.479: 00:60:b9:0d:ec:1f Skipping EAP-Success to mo

bile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:45:13.479: 00:60:b9:0d:ec:1f Found an cache entry for B

SSID c8:f9:f9:5b:0e:e1 in PMKID cache at index 0 of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:45:13.479: 00:60:b9:0d:ec:1f Found an cache entry for B

SSID c8:f9:f9:5b:0e:e1 in PMKID cache at index 0 of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:45:13.479: Including PMKID in M1  (16)

*dot1xMsgTask: Jun 27 11:45:13.479:      [0000] 09 1d 27 25 44 d4 32 7b 4a dc d8

46 6d 8a d4 92

*dot1xMsgTask: Jun 27 11:45:13.479: 00:60:b9:0d:ec:1f Starting key exchange to m

obile 00:60:b9:0d:ec:1f, data packets will be dropped

*dot1xMsgTask: Jun 27 11:45:13.479: 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 27 11:45:13.536: 00:60:b9:0d:ec:1f Received EAPOL-Key f

rom mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:45:13.536: 00:60:b9:0d:ec:1f Received EAPOL-key i

n PTK_START state (message 2) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:45:13.536: 00:60:b9:0d:ec:1f Stopping retransmiss

ion timer for mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:45:13.537: 00:60:b9:0d:ec:1f Sending the random G

TK in M3 for WPA2 client  00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:45:13.537: 00:60:b9:0d:ec:1f Sending EAPOL-Key Me

ssage 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 27 11:45:13.541: 00:60:b9:0d:ec:1f Received EAPOL-Key f

rom mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:45:13.541: 00:60:b9:0d:ec:1f Received EAPOL-key i

n PTKINITNEGOTIATING state (message 4) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:45:13.541: 00:60:b9:0d:ec:1f apfMs1xStateInc

*Dot1x_NW_MsgTask_7: Jun 27 11:45:13.541: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_R

EQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 27 11:45:13.541: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHC

OMPLETE (4) DHCP required on AP c8:f9:f9:5b:0e:e0 vapId 2 apVapId 2for this clie

nt

*Dot1x_NW_MsgTask_7: Jun 27 11:45:13.541: 00:60:b9:0d:ec:1f Not Using WMM Compli

ance code qosCap 00

*Dot1x_NW_MsgTask_7: Jun 27 11:45:13.541: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHC

OMPLETE (4) Plumbed mobile LWAPP rule on AP c8:f9:f9:5b:0e:e0 vapId 2 apVapId 2

*Dot1x_NW_MsgTask_7: Jun 27 11:45:13.541: 00:60:b9:0d:ec:1f apfMsRunStateInc

*Dot1x_NW_MsgTask_7: Jun 27 11:45:13.541: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHC

OMPLETE (4) Change state to RUN (20) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 27 11:45:13.541: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20

) Reached PLUMBFASTPATH: from line 5362

*Dot1x_: Jun 27 11:45:13.541: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Adding Fas

t 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 27 11:45:13.541: 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 27 11:45:13.541: 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 27 11:45:13.542: 00:60:b9:0d:ec:1f Stopping retransmiss

ion timer for mobile 00:60:b9:0d:ec:1f

*pemReceiveTask: Jun 27 11:45:13.543: 00:60:b9:0d:ec:1f 10.160.91.51 Added NPU e

ntry of type 1, dtlFlags 0x0

*apfMsConnTask_2: Jun 27 11:45:34.850: 00:60:b9:0d:ec:1f Reassociation received

from mobile on AP c8:f9:f9:2b:69:20

*apfMsConnTask_2: Jun 27 11:45:34.851: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) C

hanging IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_po

licy.c:1697)

*apfMsConnTask_2: Jun 27 11:45:34.851: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) C

hanging IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_po

licy.c:1864)

*apfMsConnTask_2: Jun 27 11:45:34.851: 00:60:b9:0d:ec:1f Applying site-specific

Local Bridging override for station 00:60:b9:0d:ec:1f - vapId 2, site 'default-g

roup', interface 'pvoz'

*apfMsConnTask_2: Jun 27 11:45:34.851: 00:60:b9:0d:ec:1f Applying Local Bridging

Interface Policy for station 00:60:b9:0d:ec:1f - vlan 106, interface id 12, int

erface 'pvoz'

*apfMsConnTask_2: Jun 27 11:45:34.851: 00:60:b9:0d:ec:1f processSsidIE  statusCo

de is 0 and status is 0

*apfMsConnTask_2: Jun 27 11:45:34.851: 00:60:b9:0d:ec:1f processSsidIE  ssid_don

e_flag is 0 finish_flag is 0

*apfMsConnTask_2: Jun 27 11:45:34.851: 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 27 11:45:34.851: 00:60:b9:0d:ec:1f suppRates  statusCode i

s 0 and gotSuppRatesElement is 1

*apfMsConnTask_2: Jun 27 11:45:34.851: 00:60:b9:0d:ec:1f STA - rates (10): 139 2

2 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_2: Jun 27 11:45:34.851: 00:60:b9:0d:ec:1f extSuppRates  statusCod

e is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_2: Jun 27 11:45:34.851: 00:60:b9:0d:ec:1f Processing RSN IE type

48, length 20 for mobile 00:60:b9:0d:ec:1f

*apfMsConnTask_2: Jun 27 11:45:34.851: 00:60:b9:0d:ec:1f pemApfDeleteMobileStati

on2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_2: Jun 27 11:45:34.851: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) D

eleted mobile LWAPP rule on AP [c8:f9:f9:5b:0e:e0]

*pemReceiveTask: Jun 27 11:45:34.851: 00:60:b9:0d:ec:1f 10.160.91.51 Removed NPU

entry.

*apfMsConnTask_2: Jun 27 11:45:34.851: 00:60:b9:0d:ec:1f Updated location for st

ation old AP c8:f9:f9:5b:0e:e0-0, new AP c8:f9:f9:2b:69:20-0

*apfMsConnTask_2: Jun 27 11:45:34.851: 00:60:b9:0d:ec:1f apfMsRunStateDec

*apfMsConnTask_2: Jun 27 11:45:34.851: 00:60:b9:0d:ec:1f apfMs1xStateDec

*apfMsConnTask_2: Jun 27 11:45:34.851: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) C

hange state to START (0) last state RUN (20)

*apfMsConnTask_2: Jun 27 11:45:34.851: 00:60:b9:0d:ec:1f pemApfAddMobileStation2

: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_2: Jun 27 11:45:34.851: 00:60:b9:0d:ec:1f 10.160.91.51 START (0)

Initializing policy

*apfMsConnTask_2: Jun 27 11:45:34.851: 00:60:b9:0d:ec:1f 10.160.91.51 START (0)

Change state to AUTHCHECK (2) last state RUN (20)

*apfMsConnTask_2: Jun 27 11:45:34.851: 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 27 11:45:34.851: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD

(3) DHCP required on AP c8:f9:f9:2b:69:20 vapId 2 apVapId 2for this client

*apfMsConnTask_2: Jun 27 11:45:34.851: 00:60:b9:0d:ec:1f Not Using WMM Complianc

e code qosCap 00

*apfMsConnTask_2: Jun 27 11:45:34.852: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_REQD

(3) Plumbed mobile LWAPP rule on AP c8:f9:f9:2b:69:20 vapId 2 apVapId 2

*apfMsConnTask_2: Jun 27 11:45:34.852: 00:60:b9:0d:ec:1f apfPemAddUser2 (apf_pol

icy.c:268) Changing state for mobile 00:60:b9:0d:ec:1f on AP c8:f9:f9:2b:69:20 f

rom Associated to Associated

*apfMsConnTask_2: Jun 27 11:45:34.852: 00:60:b9:0d:ec:1f Scheduling deletion of

Mobile Station:  (callerId: 49) in 1800 seconds

*apfMsConnTask_2: Jun 27 11:45:34.852: 00:60:b9:0d:ec:1f Sending Assoc Response

to station on BSSID c8:f9:f9:2b:69:20 (status 0) ApVapId 2 Slot 0

*apfMsConnTask_2: Jun 27 11:45:34.852: 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:69:

20 from Associated to Associated

*dot1xMsgTask: Jun 27 11:45:34.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 27 11:45:34.854: 00:60:b9:0d:ec:1f Resetting MSCB PMK Cache E

ntry 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:45:34.854: 00:60:b9:0d:ec:1f Removing BSSID c8:f9:f9:5b

:0e:e1 from PMKID cache of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:45:34.854: 00:60:b9:0d:ec:1f Setting active key cache i

ndex 0 ---> 8

*dot1xMsgTask: Jun 27 11:45:34.854: 00:60:b9:0d:ec:1f Setting active key cache i

ndex 8 ---> 0

*dot1xMsgTask: Jun 27 11:45:34.854: 00:60:b9:0d:ec:1f Adding BSSID c8:f9:f9:2b:6

9:21 to PMKID cache at index 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:45:34.854: New PMKID: (16)

*dot1xMsgTask: Jun 27 11:45:34.854:      [0000] 9f c0 6d 61 b8 cc 1a 53 0f 7d 74

3f 25 9f b8 14

*dot1xMsgTask: Jun 27 11:45:34.854: 00:60:b9:0d:ec:1f Initiating RSN PSK to mobi

le 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:45:34.854: 00:60:b9:0d:ec:1f dot1x - moving mobile 00:6

0:b9:0d:ec:1f into Force Auth state

*dot1xMsgTask: Jun 27 11:45:34.855: 00:60:b9:0d:ec:1f Skipping EAP-Success to mo

bile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:45:34.855: 00:60:b9:0d:ec:1f Found an cache entry for B

SSID c8:f9:f9:2b:69:21 in PMKID cache at index 0 of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:45:34.855: 00:60:b9:0d:ec:1f Found an cache entry for B

SSID c8:f9:f9:2b:69:21 in PMKID cache at index 0 of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:45:34.855: Including PMKID in M1  (16)

*dot1xMsgTask: Jun 27 11:45:34.855:      [0000] 9f c0 6d 61 b8 cc 1a 53 0f 7d 74

3f 25 9f b8 14

*dot1xMsgTask: Jun 27 11:45:34.855: 00:60:b9:0d:ec:1f Starting key exchange to m

obile 00:60:b9:0d:ec:1f, data packets will be dropped

*dot1xMsgTask: Jun 27 11:45:34.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 27 11:45:34.916: 00:60:b9:0d:ec:1f Received EAPOL-Key f

rom mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:45:34.916: 00:60:b9:0d:ec:1f Received EAPOL-key i

n PTK_START state (message 2) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:45:34.916: 00:60:b9:0d:ec:1f Stopping retransmiss

ion timer for mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:45:34.916: 00:60:b9:0d:ec:1f Sending the random G

TK in M3 for WPA2 client  00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:45:34.916: 00:60:b9:0d:ec:1f Sending EAPOL-Key Me

ssage 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 27 11:45:34.922: 00:60:b9:0d:ec:1f Received EAPOL-Key f

rom mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:45:34.922: 00:60:b9:0d:ec:1f Received EAPOL-key i

n PTKINITNEGOTIATING state (message 4) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:45:34.922: 00:60:b9:0d:ec:1f apfMs1xStateInc

*Dot1x_NW_MsgTask_7: Jun 27 11:45:34.922: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_R

EQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 27 11:45:34.922: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHC

OMPLETE (4) DHCP required on AP c8:f9:f9:2b:69:20 vapId 2 apVapId 2for this clie

nt

*Dot1x_NW_MsgTask_7: Jun 27 11:45:34.922: 00:60:b9:0d:ec:1f Not Using WMM Compli

ance code qosCap 00

*Dot1x_NW_MsgTask_7: Jun 27 11:45:34.922: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHC

OMPLETE (4) Plumbed mobile LWAPP rule on AP c8:f9:f9:2b:69:20 vapId 2 apVapId 2

*Dot1x_NW_MsgTask_7: Jun 27 11:45:34.922: 00:60:b9:0d:ec:1f apfMsRunStateInc

*Dot1x_NW_MsgTask_7: Jun 27 11:45:34.922: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHC

OMPLETE (4) Change state to RUN (20) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 27 11:45:34.922: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20

) Reached PLUMBFASTPATH: from line 5362

*Dot1x_: Jun 27 11:45:34.922: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Adding Fas

t Path rule

  type = Airespace AP Client

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

  IPv4 ACL ID = 255, IPv6 ACL ID =

*Dot1x_NW_MsgTask_7: Jun 27 11:45:34.922: 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 27 11:45:34.922: 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 27 11:45:34.922: 00:60:b9:0d:ec:1f Stopping retransmiss

ion timer for mobile 00:60:b9:0d:ec:1f

*pemReceiveTask: Jun 27 11:45:34.923: 00:60:b9:0d:ec:1f 10.160.91.51 Added NPU e

ntry of type 1, dtlFlags 0x0

*apfMsConnTask_6: Jun 27 11:45:46.092: 00:60:b9:0d:ec:1f Reassociation received

from mobile on AP 3c:ce:73:f9:06:50

*apfMsConnTask_6: Jun 27 11:45:46.092: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) C

hanging IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_po

licy.c:1697)

*apfMsConnTask_6: Jun 27 11:45:46.093: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) C

hanging IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_po

licy.c:1864)

*apfMsConnTask_6: Jun 27 11:45:46.093: 00:60:b9:0d:ec:1f Applying site-specific

Local Bridging override for station 00:60:b9:0d:ec:1f - vapId 2, site 'default-g

roup', interface 'pvoz'

*apfMsConnTask_6: Jun 27 11:45:46.093: 00:60:b9:0d:ec:1f Applying Local Bridging

Interface Policy for station 00:60:b9:0d:ec:1f - vlan 106, interface id 12, int

erface 'pvoz'

*apfMsConnTask_6: Jun 27 11:45:46.093: 00:60:b9:0d:ec:1f processSsidIE  statusCo

de is 0 and status is 0

*apfMsConnTask_6: Jun 27 11:45:46.093: 00:60:b9:0d:ec:1f processSsidIE  ssid_don

e_flag is 0 finish_flag is 0

*apfMsConnTask_6: Jun 27 11:45:46.093: 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 27 11:45:46.093: 00:60:b9:0d:ec:1f suppRates  statusCode i

s 0 and gotSuppRatesElement is 1

*apfMsConnTask_6: Jun 27 11:45:46.093: 00:60:b9:0d:ec:1f STA - rates (10): 139 2

2 24 36 48 72 96 108 12 18 0 0 0 0 0 0

*apfMsConnTask_6: Jun 27 11:45:46.093: 00:60:b9:0d:ec:1f extSuppRates  statusCod

e is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_6: Jun 27 11:45:46.093: 00:60:b9:0d:ec:1f Processing RSN IE type

48, length 20 for mobile 00:60:b9:0d:ec:1f

*apfMsConnTask_6: Jun 27 11:45:46.093: 00:60:b9:0d:ec:1f pemApfDeleteMobileStati

on2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_6: Jun 27 11:45:46.093: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) D

eleted mobile LWAPP rule on AP [c8:f9:f9:2b:69:20]

*apfMsConnTask_6: Jun 27 11:45:46.093: 00:60:b9:0d:ec:1f Updated location for st

ation old AP c8:f9:f9:2b:69:20-0, new AP 3c:ce:73:f9:06:50-0

*apfMsConnTask_6: Jun 27 11:45:46.093: 00:60:b9:0d:ec:1f apfMsRunStateDec

*apfMsConnTask_6: Jun 27 11:45:46.093: 00:60:b9:0d:ec:1f apfMs1xStateDec

*apfMsConnTask_6: Jun 27 11:45:46.093: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) C

hange state to START (0) last state RUN (20)

*apfMsConnTask_6: Jun 27 11:45:46.093: 00:60:b9:0d:ec:1f pemApfAddMobileStation2

: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfMsConnTask_6: Jun 27 11:45:46.093: 00:60:b9:0d:ec:1f 10.160.91.51 START (0)

Initializing policy

*apfMsConnTask_6: Jun 27 11:45:46.093: 00:60:b9:0d:ec:1f 10.160.91.51 START (0)

Change state to AUTHCHECK (2) last state RUN (20)

*apfMsConnTask_6: Jun 27 11:45:46.093: 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 27 11:45:46.093: 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 27 11:45:46.093: 00:60:b9:0d:ec:1f Not Using WMM Complianc

e code qosCap 00

*apfMsConnTask_6: Jun 27 11:45:46.093: 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 27 11:45:46.094: 00:60:b9:0d:ec:1f apfPemAddUser2 (apf_pol

icy.c:268) Changing state for mobile 00:60:b9:0d:ec:1f on AP 3c:ce:73:f9:06:50 f

rom Associated to Associated

*apfMsConnTask_6: Jun 27 11:45:46.094: 00:60:b9:0d:ec:1f Scheduling deletion of

Mobile Station:  (callerId: 49) in 1800 seconds

*apfMsConnTask_6: Jun 27 11:45:46.094: 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 27 11:45:46.094: 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 27 11:45:46.094: 00:60:b9:0d:ec:1f 10.160.91.51 Removed NPU

entry.

*dot1xMsgTask: Jun 27 11:45:46.096: 00:60:b9:0d:ec:1f Creating a PKC PMKID Cache

entry for station 00:60:b9:0d:ec:1f (RSN 2)

*dot1xMsgTask: Jun 27 11:45:46.096: 00:60:b9:0d:ec:1f Resetting MSCB PMK Cache E

ntry 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:45:46.096: 00:60:b9:0d:ec:1f Removing BSSID c8:f9:f9:2b

:69:21 from PMKID cache of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:45:46.096: 00:60:b9:0d:ec:1f Setting active key cache i

ndex 0 ---> 8

*dot1xMsgTask: Jun 27 11:45:46.096: 00:60:b9:0d:ec:1f Setting active key cache i

ndex 8 ---> 0

*dot1xMsgTask: Jun 27 11:45:46.096: 00:60:b9:0d:ec:1f Adding BSSID 3c:ce:73:f9:0

6:51 to PMKID cache at index 0 for station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:45:46.096: New PMKID: (16)

*dot1xMsgTask: Jun 27 11:45:46.096:      [0000] 2c de dd 37 b5 fb 3c 2d 0e a4 47

e2 fd 62 19 fe

*dot1xMsgTask: Jun 27 11:45:46.096: 00:60:b9:0d:ec:1f Initiating RSN PSK to mobi

le 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:45:46.096: 00:60:b9:0d:ec:1f dot1x - moving mobile 00:6

0:b9:0d:ec:1f into Force Auth state

*dot1xMsgTask: Jun 27 11:45:46.096: 00:60:b9:0d:ec:1f Skipping EAP-Success to mo

bile 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:45:46.096: 00:60:b9:0d:ec:1f Found an cache entry for B

SSID 3c:ce:73:f9:06:51 in PMKID cache at index 0 of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:45:46.096: 00:60:b9:0d:ec:1f Found an cache entry for B

SSID 3c:ce:73:f9:06:51 in PMKID cache at index 0 of station 00:60:b9:0d:ec:1f

*dot1xMsgTask: Jun 27 11:45:46.096: Including PMKID in M1  (16)

*dot1xMsgTask: Jun 27 11:45:46.096:      [0000] 2c de dd 37 b5 fb 3c 2d 0e a4 47

e2 fd 62 19 fe

*dot1xMsgTask: Jun 27 11:45:46.096: 00:60:b9:0d:ec:1f Starting key exchange to m

obile 00:60:b9:0d:ec:1f, data packets will be dropped

*dot1xMsgTask: Jun 27 11:45:46.096: 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 27 11:45:46.172: 00:60:b9:0d:ec:1f Received EAPOL-Key f

rom mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:45:46.172: 00:60:b9:0d:ec:1f Received EAPOL-key i

n PTK_START state (message 2) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:45:46.172: 00:60:b9:0d:ec:1f Stopping retransmiss

ion timer for mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:45:46.172: 00:60:b9:0d:ec:1f Sending the random G

TK in M3 for WPA2 client  00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:45:46.172: 00:60:b9:0d:ec:1f Sending EAPOL-Key Me

ssage 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 27 11:45:46.176: 00:60:b9:0d:ec:1f Received EAPOL-Key f

rom mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:45:46.176: 00:60:b9:0d:ec:1f Received EAPOL-key i

n PTKINITNEGOTIATING state (message 4) from mobile 00:60:b9:0d:ec:1f

*Dot1x_NW_MsgTask_7: Jun 27 11:45:46.176: 00:60:b9:0d:ec:1f apfMs1xStateInc

*Dot1x_NW_MsgTask_7: Jun 27 11:45:46.176: 00:60:b9:0d:ec:1f 10.160.91.51 8021X_R

EQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 27 11:45:46.176: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHC

OMPLETE (4) DHCP required on AP 3c:ce:73:f9:06:50 vapId 2 apVapId 2for this clie

nt

*Dot1x_NW_MsgTask_7: Jun 27 11:45:46.176: 00:60:b9:0d:ec:1f Not Using WMM Compli

ance code qosCap 00

*Dot1x_NW_MsgTask_7: Jun 27 11:45:46.176: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHC

OMPLETE (4) Plumbed mobile LWAPP rule on AP 3c:ce:73:f9:06:50 vapId 2 apVapId 2

*Dot1x_NW_MsgTask_7: Jun 27 11:45:46.176: 00:60:b9:0d:ec:1f apfMsRunStateInc

*Dot1x_NW_MsgTask_7: Jun 27 11:45:46.176: 00:60:b9:0d:ec:1f 10.160.91.51 L2AUTHC

OMPLETE (4) Change state to RUN (20) last state RUN (20)

*Dot1x_NW_MsgTask_7: Jun 27 11:45:46.176: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20

) Reached PLUMBFASTPATH: from line 5362

*Dot1x_: Jun 27 11:45:46.176: 00:60:b9:0d:ec:1f 10.160.91.51 RUN (20) Adding Fas

t 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 27 11:45:46.176: 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 27 11:45:46.176: 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 27 11:45:46.177: 00:60:b9:0d:ec:1f Stopping retransmiss

ion timer for mobile 00:60:b9:0d:ec:1f

thank you!

[maldehne · Accepted solution]

well In the debugs we have reassociation frames sent by the client upon romaing in both cases which reduces the chance of having coverage hole issues.

Also I can see that we don't have reauth again , the PKC seems to be working very well.