iPhone 7 802.11r debugs on Cisco

sample debugs

AP 3700 base radio mac - f4:0f:1b:99:4f:20
AP 3600 base radio mac - 3c:ce:73:39:40:90

(Cisco Controller) >debug client f4:0f:24:89:50:df

(Cisco Controller) >debug ft ?

events Configures debug of 802.11r events

(Cisco Controller) >debug ft events ?

disable Disables debug.
enable Enables debug.

(Cisco Controller) >debug ft events enable

(Cisco Controller) >*apfMsConnTask_6: Sep 22 21:25:09.566: f4:0f:24:89:50:df Updating 11r vendor IE

*pemReceiveTask: Sep 22 21:25:09.578: f4:0f:24:89:50:df 192.168.128.43 Removed NPU entry.
*spamApTask0: Sep 22 21:25:09.578: f4:0f:24:89:50:df Successful transmission of LWAPP Add-Mobile to AP
f4:0f:1b:99:4f:20
*apfMsConnTask_6: Sep 22 21:25:09.579: f4:0f:24:89:50:df Got action frame from this client.
*apfMsConnTask_6: Sep 22 21:25:09.579: f4:0f:24:89:50:df Station: F4:0F:24:89:50:DF sent 802.11K neighbor request to AP F4:0F:1B:99:4F:20
*apfMsConnTask_6: Sep 22 21:25:09.579: f4:0f:24:89:50:df Station: F4:0F:24:89:50:DF requested neighbors on non XOR roam capable AP F4:0F:1B:99:4F:20 Slot 1
*apfMsConnTask_6: Sep 22 21:25:09.579:
Ms with adaptive capability found

*spamApTask0: Sep 22 21:25:09.580: f4:0f:24:89:50:df Received ADD_MOBILE ack - Initiating 1x to STA f4:0f:24:89:50:df (idx 22)
*spamApTask0: Sep 22 21:25:09.580: f4:0f:24:89:50:df Sent dot1x auth initiate message for mobile f4:0f:24:89:50:df
*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.580: f4:0f:24:89:50:df reauth_sm state transition 1 ---> 0 for mobile f4:0f:24:89:50:df at 1x_reauth_sm.c:53
*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.580: f4:0f:24:89:50:df Creating a PKC PMKID Cache entry for station f4:0f:24:89:50:df (RSN 2)
*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.580: f4:0f:24:89:50:df Resetting MSCB PMK Cache Entry 0 for station f4:0f:24:89:50:df
*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.580: f4:0f:24:89:50:df Removing BSSID f4:0f:1b:99:4f:2f from PMKID cache of station f4:0f:24:89:50:df
*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.580: f4:0f:24:89:50:df Setting active key cache index 0 ---> 8
*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.580: f4:0f:24:89:50:df Setting active key cache index 8 ---> 0
*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.580: f4:0f:24:89:50:df Adding BSSID f4:0f:1b:99:4f:2f to PMKID cache at index 0 for station f4:0f:24:89:50:df
*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.580: New PMKID: (16)

*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.581: [0000] e7 ba d7 7a 0d d8 69 30 1b 66 ec c4 da 79 aa 54

*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.581: f4:0f:24:89:50:df Creating global PMK cache for this TGr client
*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.581: f4:0f:24:89:50:df Skipping cache delete as AP will get cache update.
*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.581: f4:0f:24:89:50:df Created PMK Cache Entry for TGr AKM:PSK f4:0f:24:89:50:df

*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.581: f4:0f:24:89:50:df R0KH-ID:192.168.128.250 R1KH-ID:50:06:04:ca:da:60 MSK Len:48
pmkValidTime:86400

*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.581: f4:0f:24:89:50:df Adding Audit session ID payload in Mobility handoff

*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.581: f4:0f:24:89:50:df 0 PMK-update groupcast messages sent
*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.581: f4:0f:24:89:50:df Initiating RSN PSK to mobile f4:0f:24:89:50:df
*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.581: f4:0f:24:89:50:df EAP-PARAM Debug - eap-params for Wlan-Id :1 is disabled - applying Global eap timers and retries
*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.581: f4:0f:24:89:50:df Disable re-auth, use PMK lifetime.
*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.581: f4:0f:24:89:50:df dot1x - moving mobile f4:0f:24:89:50:df into Force Auth state
*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.581: f4:0f:24:89:50:df Skipping EAP-Success to mobile f4:0f:24:89:50:df (encryptBit:0)
*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.581: f4:0f:24:89:50:df key Desc Version FT - 1

*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.581: f4:0f:24:89:50:df Found an cache entry for BSSID f4:0f:1b:99:4f:2f in PMKID cache at index 0 of station f4:0f:24:89:50:df
*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.581: f4:0f:24:89:50:df Found an cache entry for BSSID f4:0f:1b:99:4f:2f in PMKID cache at index 0 of station f4:0f:24:89:50:df
*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.581: Including PMKID in M1 (16)

*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.581: [0000] e7 ba d7 7a 0d d8 69 30 1b 66 ec c4 da 79 aa 54

*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.581: M1 - Key Data: (22)

*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.581: [0000] dd 14 00 0f ac 04 e7 ba d7 7a 0d d8 69 30 1b 66

*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.581: [0016] ec c4 da 79 aa 54

*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.581: f4:0f:24:89:50:df Starting key exchange to mobile f4:0f:24:89:50:df, data packets will be dropped
*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.581: f4:0f:24:89:50:df Sending EAPOL-Key Message to mobile f4:0f:24:89:50:df
state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00
*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.581: f4:0f:24:89:50:df Allocating EAP Pkt for retransmission to mobile f4:0f:24:89:50:df
*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.587: f4:0f:24:89:50:df Received EAPOL-Key from mobile f4:0f:24:89:50:df
*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.587: f4:0f:24:89:50:df key Desc Version FT - 1

*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.587: f4:0f:24:89:50:df Received EAPOL-key in PTK_START state (message 2) from mobile f4:0f:24:89:50:df
*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.587: f4:0f:24:89:50:df Encryption Policy: 4, PTK Key Length: 48
*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.588: 00000000: 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 0...............
*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.588: 00000010: 00 0f ac 04 0c 00 ......
*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.588: 00000000: 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ................
*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.588: 00000010: ac 04 0c 00 01 00 6c 30 5a 4d d4 3b 29 ff ac 6e ......l0ZM.;)..n
*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.588: 00000020: 42 ff 1c 72 1b bc B..r..
*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.588: f4:0f:24:89:50:df Calculating PMKR0Name
*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.588: f4:0f:24:89:50:df Not Flex client. Do not distribute dot11r Key cache.
*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.588: f4:0f:24:89:50:df Stopping retransmission timer for mobile f4:0f:24:89:50:df
*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.588: f4:0f:24:89:50:df key Desc Version FT - 1

*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.588: f4:0f:24:89:50:df key Desc Version FT - 1

*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.588: f4:0f:24:89:50:df Sending EAPOL-Key Message to mobile f4:0f:24:89:50:df
state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01
*Dot1x_NW_MsgTask_7: Sep 22 21:25:09.588: f4:0f:24:89:50:df Reusing allocated memory for EAP Pkt for retransmission to mobile f4:0f:24:89:50:df
*DHCP Socket Task: Sep 22 21:25:09.657: f4:0f:24:89:50:df DHCP received op BOOTREQUEST (1) (len 308,vlan 0, port 4, encap 0xec03, xid 0xf9a6976c)
*DHCP Socket Task: Sep 22 21:25:09.657: f4:0f:24:89:50:df DHCP (encap type 0xec03) mstype 0ff:ff:ff:ff:ff:ff
*DHCP Socket Task: Sep 22 21:25:09.657: f4:0f:24:89:50:df DHCP processing DHCP REQUEST (3)
*DHCP Socket Task: Sep 22 21:25:09.657: f4:0f:24:89:50:df DHCP op: BOOTREQUEST, htype: Ethernet, hlen: 6, hops: 0
*DHCP Socket Task: Sep 22 21:25:09.657: f4:0f:24:89:50:df DHCP xid: 0xf9a6976c (4188444524), secs: 0, flags: 0
*DHCP Socket Task: Sep 22 21:25:09.657: f4:0f:24:89:50:df DHCP chaddr: f4:0f:24:89:50:df
*DHCP Socket Task: Sep 22 21:25:09.657: f4:0f:24:89:50:df DHCP ciaddr: 0.0.0.0, yiaddr: 0.0.0.0
*DHCP Socket Task: Sep 22 21:25:09.657: f4:0f:24:89:50:df DHCP siaddr: 0.0.0.0, giaddr: 0.0.0.0
*DHCP Socket Task: Sep 22 21:25:09.657: f4:0f:24:89:50:df DHCP requested ip: 192.168.128.43
*DHCP Socket Task: Sep 22 21:25:09.657: f4:0f:24:89:50:df DHCP Opt82 bridge mode insertion enabled, inserts opt82 if opt82 is enabled vlan=0, datalen =14, optlen=64
*DHCP Socket Task: Sep 22 21:25:09.657: f4:0f:24:89:50:df DHCP successfully bridged packet to DS
*DHCP Socket Task: Sep 22 21:25:09.660: f4:0f:24:89:50:df DHCP received op BOOTREPLY (2) (len 308,vlan 0, port 1, encap 0xec00, xid 0xf9a6976c)
*DHCP Socket Task: Sep 22 21:25:09.660: f4:0f:24:89:50:df DHCP processing DHCP ACK (5)
*DHCP Socket Task: Sep 22 21:25:09.660: f4:0f:24:89:50:df DHCP op: BOOTREPLY, htype: Ethernet, hlen: 6, hops: 0
*DHCP Socket Task: Sep 22 21:25:09.660: f4:0f:24:89:50:df DHCP xid: 0xf9a6976c (4188444524), secs: 0, flags: 0
*DHCP Socket Task: Sep 22 21:25:09.660: f4:0f:24:89:50:df DHCP chaddr: f4:0f:24:89:50:df
*DHCP Socket Task: Sep 22 21:25:09.660: f4:0f:24:89:50:df DHCP ciaddr: 0.0.0.0, yiaddr: 192.168.128.43
*DHCP Socket Task: Sep 22 21:25:09.660: f4:0f:24:89:50:df DHCP siaddr: 0.0.0.0, giaddr: 0.0.0.0
*DHCP Socket Task: Sep 22 21:25:09.660: f4:0f:24:89:50:df DHCP server id: 192.168.128.1 rcvd server id: 192.168.128.1
*DHCP Socket Task: Sep 22 21:25:09.660: f4:0f:24:89:50:df DHCP successfully bridged packet to STA

roam from 3700 to 3600

(Cisco Controller) >
(Cisco Controller) >*apfMsConnTask_6: Sep 22 21:26:04.520: f4:0f:24:89:50:df Got action frame from this client.
*apfMsConnTask_6: Sep 22 21:26:04.520: f4:0f:24:89:50:df
Doing preauth for this client over the DS
*apfMsConnTask_6: Sep 22 21:26:04.520: f4:0f:24:89:50:df Doing local roaming for destination address f4:0f:1b:99:4f:2f
*apfMsConnTask_6: Sep 22 21:26:04.520: f4:0f:24:89:50:df Got 1 AKMs in RSNIE
*apfMsConnTask_6: Sep 22 21:26:04.520: f4:0f:24:89:50:df
RSNIE AKM matches with PMK cache entry :0x4
*apfMsConnTask_6: Sep 22 21:26:04.521: f4:0f:24:89:50:df pmkRoName derived sucessfully
*apfMsConnTask_6: Sep 22 21:26:04.521: f4:0f:24:89:50:df Validate FTIE for R0KH-ID, Store SNonce passed
*apfMsConnTask_6: Sep 22 21:26:04.521: f4:0f:24:89:50:df
Created a new preauth entry for AP:3c:ce:73:39:40:9f
*apfMsConnTask_6: Sep 22 21:26:04.521: f4:0f:24:89:50:df FT Auth Resp: Setting adaptive AKM 4 into RSN Data at 19

*apfMsConnTask_0: Sep 22 21:26:04.557: f4:0f:24:89:50:df Updating 11r vendor IE

*apfMsConnTask_0: Sep 22 21:26:04.557: f4:0f:24:89:50:df
Processing assoc-req station:f4:0f:24:89:50:df AP:3c:ce:73:39:40:90-01 thread:1a8cf910
*apfMsConnTask_0: Sep 22 21:26:04.557: f4:0f:24:89:50:df Station: F4:0F:24:89:50:DF trying to join WLAN with RSSI 232. Checking for XOR roam conditions on AP: 3C:CE:73:39:40:90 Slot: 1
*apfMsConnTask_0: Sep 22 21:26:04.557: f4:0f:24:89:50:df Station: F4:0F:24:89:50:DF is associating to AP 3C:CE:73:39:40:90 which is not XOR roam capable
*apfMsConnTask_0:
Sep 22 21:26:04.557: f4:0f:24:89:50:df Reassociation received from mobile on BSSID 3c:ce:73:39:40:9f AP Viten_3600_1
*apfMsConnTask_0: Sep 22 21:26:04.557: f4:0f:24:89:50:df Station: F4:0F:24:89:50:DF trying to join WLAN with RSSI 232. Checking for XOR roam conditions on AP: 3C:CE:73:39:40:90 Slot: 1
*apfMsConnTask_0: Sep 22 21:26:04.557: f4:0f:24:89:50:df Station: F4:0F:24:89:50:DF is associating to AP 3C:CE:73:39:40:90 which is not XOR roam capable
*apfMsConnTask_0: Sep 22 21:26:04.557: f4:0f:24:89:50:df Global 200 Clients are allowed to AP radio

*apfMsConnTask_0: Sep 22 21:26:04.557: f4:0f:24:89:50:df Max Client Trap Threshold: 0 cur: 3

*apfMsConnTask_0: Sep 22 21:26:04.557: f4:0f:24:89:50:df Rf profile 600 Clients are allowed to AP wlan

*apfMsConnTask_0: Sep 22 21:26:04.557: f4:0f:24:89:50:df FT Adaptive AKM not negotiated
*apfMsConnTask_0: Sep 22 21:26:04.557: f4:0f:24:89:50:df override for default ap group, marking intgrp NULL
*apfMsConnTask_0: Sep 22 21:26:04.558: f4:0f:24:89:50:df Applying Interface(management) policy on Mobile, role Local. Ms NAC State 2 Quarantine Vlan 0 Access Vlan 0

*apfMsConnTask_0: Sep 22 21:26:04.558: f4:0f:24:89:50:df Re-applying interface policy for client

*apfMsConnTask_0: Sep 22 21:26:04.558: f4:0f:24:89:50:df 192.168.128.43 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2931)
*apfMsConnTask_0: Sep 22 21:26:04.558: f4:0f:24:89:50:df 192.168.128.43 RUN (20) Changing Url ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2951)
*apfMsConnTask_0: Sep 22 21:26:04.558: f4:0f:24:89:50:df 192.168.128.43 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2972)
*apfMsConnTask_0: Sep 22 21:26:04.558: f4:0f:24:89:50:df apfApplyWlanPolicy: Apply WLAN Policy over PMIPv6 Client Mobility Type, Tunnel User - 0
*apfMsConnTask_0: Sep 22 21:26:04.558: f4:0f:24:89:50:df In processSsidIE:6444 setting Central switched to TRUE
*apfMsConnTask_0: Sep 22 21:26:04.558: f4:0f:24:89:50:df In processSsidIE:6447 apVapId = 1 and Split Acl Id = 65535
*apfMsConnTask_0: Sep 22 21:26:04.558: f4:0f:24:89:50:df Applying site-specific Local Bridging override for station f4:0f:24:89:50:df - vapId 1, site 'default-group', interface 'management'
*apfMsConnTask_0: Sep 22 21:26:04.558: f4:0f:24:89:50:df Applying Local Bridging Interface Policy for station f4:0f:24:89:50:df - vlan 0, interface id 0, interface 'management'
*apfMsConnTask_0: Sep 22 21:26:04.558: f4:0f:24:89:50:df processSsidIE statusCode is 0 and status is 0
*apfMsConnTask_0: Sep 22 21:26:04.558: f4:0f:24:89:50:df processSsidIE ssid_done_flag is 0 finish_flag is 0
*apfMsConnTask_0: Sep 22 21:26:04.558: f4:0f:24:89:50:df STA - rates (4): 176 72 96 108 0 0 0 0 0 0 0 0 0 0 0 0
*apfMsConnTask_0: Sep 22 21:26:04.558: f4:0f:24:89:50:df suppRates statusCode is 0 and gotSuppRatesElement is 1
*apfMsConnTask_0: Sep 22 21:26:04.558: f4:0f:24:89:50:df Marking this mobile as TGr capable.
*apfMsConnTask_0: Sep 22 21:26:04.558: RSNIE in Assoc. Req.: (38)

*apfMsConnTask_0: Sep 22 21:26:04.558: [0000] 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f

*apfMsConnTask_0: Sep 22 21:26:04.558: [0016] ac 04 0c 00 01 00 6c 30 5a 4d d4 3b 29 ff ac 6e

*apfMsConnTask_0: Sep 22 21:26:04.558: [0032] 42 ff 1c 72 1b bc

*apfMsConnTask_0: Sep 22 21:26:04.558: f4:0f:24:89:50:df Processing RSN IE type 48, length 38 for mobile f4:0f:24:89:50:df
*apfMsConnTask_0: Sep 22 21:26:04.558: f4:0f:24:89:50:df
ccmp128 is enabled
*apfMsConnTask_0: Sep 22 21:26:04.558: f4:0f:24:89:50:df RSN Capabilities: 12
*apfMsConnTask_0: Sep 22 21:26:04.558: f4:0f:24:89:50:df Marking Mobile as non-11w Capable
*apfMsConnTask_0: Sep 22 21:26:04.558: f4:0f:24:89:50:df Validating FT AKM's on WLAN
*apfMsConnTask_0: Sep 22 21:26:04.558: f4:0f:24:89:50:df Setting adaptive AKM 4 into RSN Data at 19

*apfMsConnTask_0: Sep 22 21:26:04.559: f4:0f:24:89:50:df
Roaming succeed for this client.
*apfMsConnTask_0: Sep 22 21:26:04.559: f4:0f:24:89:50:df pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.
*apfMsConnTask_0: Sep 22 21:26:04.559: f4:0f:24:89:50:df 192.168.128.43 RUN (20) Deleted mobile LWAPP rule on AP [f4:0f:1b:99:4f:20]
*apfMsConnTask_0: Sep 22 21:26:04.559: f4:0f:24:89:50:df
Updated location for station old AP f4:0f:1b:99:4f:20-1, new AP 3c:ce:73:39:40:90-1
*apfMsConnTask_0: Sep 22 21:26:04.559: f4:0f:24:89:50:df apfMsRunStateDec
*apfMsConnTask_0: Sep 22 21:26:04.559: f4:0f:24:89:50:df apfMs1xStateDec
*apfMsConnTask_0: Sep 22 21:26:04.559: f4:0f:24:89:50:df 192.168.128.43 RUN (20) Change state to START (0) last state RUN (20)

*apfMsConnTask_0: Sep 22 21:26:04.559: f4:0f:24:89:50:df pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.
*apfMsConnTask_0: Sep 22 21:26:04.559: f4:0f:24:89:50:df 192.168.128.43 START (0) Initializing policy
*apfMsConnTask_0: Sep 22 21:26:04.559: f4:0f:24:89:50:df 192.168.128.43 START (0) Change state to AUTHCHECK (2) last state START (0)

*apfMsConnTask_0: Sep 22 21:26:04.559: f4:0f:24:89:50:df 192.168.128.43 AUTHCHECK (2) Change state to 8021X_REQD (3) last state AUTHCHECK (2)

*apfMsConnTask_0: Sep 22 21:26:04.559: f4:0f:24:89:50:df Encryption policy is set to 0x80000004
*apfMsConnTask_0: Sep 22 21:26:04.559: f4:0f:24:89:50:df Not Using WMM Compliance code qosCap 00
*apfMsConnTask_0: Sep 22 21:26:04.559: f4:0f:24:89:50:df 192.168.128.43 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 3c:ce:73:39:40:90 vapId 1 apVapId 1 flex-acl-name:
*apfMsConnTask_0: Sep 22 21:26:04.559: f4:0f:24:89:50:df apfPemAddUser2 (apf_policy.c:437) Changing state for mobile f4:0f:24:89:50:df on AP 3c:ce:73:39:40:90 from Associated to Associated

*apfMsConnTask_0: Sep 22 21:26:04.559: f4:0f:24:89:50:df apfPemAddUser2:session timeout forstation f4:0f:24:89:50:df - Session Tout 0, apfMsTimeOut '0' and sessionTimerRunning flag is 0
*apfMsConnTask_0: Sep 22 21:26:04.559: f4:0f:24:89:50:df Stopping deletion of Mobile Station: (callerId: 48)
*apfMsConnTask_0: Sep 22 21:26:04.559: f4:0f:24:89:50:df Func: apfPemAddUser2, Ms Timeout = 0, Session Timeout = 0

*apfMsConnTask_0: Sep 22 21:26:04.559: f4:0f:24:89:50:df Sending assoc-resp with status 0 station:f4:0f:24:89:50:df AP:3c:ce:73:39:40:90-01 on apVapId 1
*apfMsConnTask_0: Sep 22 21:26:04.559: f4:0f:24:89:50:df Including FT Mobility Domain IE (length 5) in reassociation assoc Resp to mobile
*apfMsConnTask_0: Sep 22 21:26:04.560: f4:0f:24:89:50:df Sending Assoc Response to station on BSSID 3c:ce:73:39:40:9f (status 0) ApVapId 1 Slot 1
*apfMsConnTask_0: Sep 22 21:26:04.560: f4:0f:24:89:50:df apfProcessAssocReq (apf_80211.c:10863) Changing state for mobile f4:0f:24:89:50:df on AP 3c:ce:73:39:40:90 from Associated to Associated

*pemReceiveTask: Sep 22 21:26:04.562: f4:0f:24:89:50:df 192.168.128.43 Removed NPU entry.
*spamApTask0: Sep 22 21:26:04.562: f4:0f:24:89:50:df Delete Mobile request sent to the AP 192.168.128.32:57576

*spamApTask7: Sep 22 21:26:04.563: f4:0f:24:89:50:df Successful transmission of LWAPP Add-Mobile to AP 3c:ce:73:39:40:90
*apfMsConnTask_0: Sep 22 21:26:04.565: f4:0f:24:89:50:df Got action frame from this client.
*apfMsConnTask_0: Sep 22 21:26:04.565: f4:0f:24:89:50:df Station: F4:0F:24:89:50:DF sent 802.11K neighbor request to AP 3C:CE:73:39:40:90
*apfMsConnTask_0: Sep 22 21:26:04.565: f4:0f:24:89:50:df Station: F4:0F:24:89:50:DF requested neighbors on non XOR roam capable AP 3C:CE:73:39:40:90 Slot 1
*apfMsConnTask_0: Sep 22 21:26:04.565: Ms with adaptive capability found

*spamApTask7: Sep 22 21:26:04.567: f4:0f:24:89:50:df Received ADD_MOBILE ack - Initiating 1x to STA f4:0f:24:89:50:df (idx 8)
*spamApTask7: Sep 22 21:26:04.567: f4:0f:24:89:50:df Sent dot1x auth initiate message for mobile f4:0f:24:89:50:df
*Dot1x_NW_MsgTask_7: Sep 22 21:26:04.567: f4:0f:24:89:50:df reauth_sm state transition 0 ---> 0 for mobile f4:0f:24:89:50:df at 1x_reauth_sm.c:53
*Dot1x_NW_MsgTask_7: Sep 22 21:26:04.567: f4:0f:24:89:50:df Finishing FT roaming for mobile f4:0f:24:89:50:df
*Dot1x_NW_MsgTask_7: Sep 22 21:26:04.567: f4:0f:24:89:50:df EAP-PARAM Debug - eap-params for Wlan-Id :1 is disabled - applying Global eap timers and retries
*Dot1x_NW_MsgTask_7: Sep 22 21:26:04.567: f4:0f:24:89:50:df Disable re-auth, use PMK lifetime.
*Dot1x_NW_MsgTask_7: Sep 22 21:26:04.567: f4:0f:24:89:50:df dot1x - moving mobile f4:0f:24:89:50:df into Force Auth state
*Dot1x_NW_MsgTask_7: Sep 22 21:26:04.567: f4:0f:24:89:50:df Skipping EAP-Success to mobile f4:0f:24:89:50:df (encryptBit:0)
*Dot1x_NW_MsgTask_7: Sep 22 21:26:04.567: f4:0f:24:89:50:df apfMs1xStateInc
*Dot1x_NW_MsgTask_7: Sep 22 21:26:04.567: f4:0f:24:89:50:df 192.168.128.43 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state 8021X_REQD (3)

*Dot1x_NW_MsgTask_7: Sep 22 21:26:04.567: f4:0f:24:89:50:df Not Using WMM Compliance code qosCap 00
*Dot1x_NW_MsgTask_7: Sep 22 21:26:04.567: f4:0f:24:89:50:df 192.168.128.43 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 3c:ce:73:39:40:90 vapId 1 apVapId 1 flex-acl-name:
*Dot1x_NW_MsgTask_7: Sep 22 21:26:04.567: f4:0f:24:89:50:df apfMsRunStateInc
*Dot1x_NW_MsgTask_7:
Sep 22 21:26:04.567: f4:0f:24:89:50:df 192.168.128.43 L2AUTHCOMPLETE (4) Change state to RUN (20) last state L2AUTHCOMPLETE (4)

roam time approx 21:26:04.567 minus 21:26:04.557 ~ 10ms

*Dot1x_NW_MsgTask_7: Sep 22 21:26:04.568: f4:0f:24:89:50:df 192.168.128.43 RUN (20) Reached PLUMBFASTPATH: from line 6818, null
*Dot1x_NW_MsgTask_7: Sep 22 21:26:04.568: f4:0f:24:89:50:df 192.168.128.43 RUN (20) Adding Fast Path rule
type = Airespace AP Client
on AP 3c:ce:73:39:40:90, slot 1, interface = 4, QOS = 2
IPv4 ACL ID = 255, IPv6 ACL ID =
*Dot1x_NW_MsgTask_7: Sep 22 21:26:04.568: f4:0f:24:89:50:df 192.168.128.43 RUN (20) Fast Path rule (contd...) 802.1P = 5, DSCP = 0, TokenID = 15206, IntfId = 0 Local Bridging Vlan = 0, Local Bridging intf id = 0
*Dot1x_NW_MsgTask_7: Sep 22 21:26:04.568: f4:0f:24:89:50:df 192.168.128.43 RUN (20) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 4, AppToken = 15206 AverageRate = 0, BurstRate = 0

*Dot1x_NW_MsgTask_7: Sep 22 21:26:04.568: f4:0f:24:89:50:df 192.168.128.43 RUN (20) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 4, AppToken = 15206 AverageRate = 0, BurstRate = 0

*Dot1x_NW_MsgTask_7: Sep 22 21:26:04.568: f4:0f:24:89:50:df 192.168.128.43 RUN (20) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 4, AppToken = 15206 AverageRate = 0, BurstRate = 0

*Dot1x_NW_MsgTask_7: Sep 22 21:26:04.568: f4:0f:24:89:50:df 192.168.128.43 RUN (20) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255, L2 ACL ID 255,URL ACL ID 255)
*Dot1x_NW_MsgTask_7: Sep 22 21:26:04.568: f4:0f:24:89:50:df 192.168.128.43 RUN (20) No 11v BTM
*Dot1x_NW_MsgTask_7: Sep 22 21:26:04.568: f4:0f:24:89:50:df 192.168.128.43 RUN (20) NO release MSCB
*pemReceiveTask: Sep 22 21:26:04.568: f4:0f:24:89:50:df 192.168.128.43 Added NPU entry of type 1, dtlFlags 0x0
*spamApTask7: Sep 22 21:26:04.569: f4:0f:24:89:50:df Successful transmission of LWAPP Add-Mobile to AP 3c:ce:73:39:40:90

comments powered by Disqus