Most Apple iOS devices have issues moving from one wlan to another on the same Cisco WLC with the default ‘fast ssid change' configuration disabled.
The setting causes the controller to deauthenticate the client from the existing wlan once the client attempts to associate to another.
The typical result is an ‘unable to join the network’ message on the iOS device:
The following is a demonstration of an Ipad Mini attempting to move between WLC wlans ‘apple1’ and ‘apple2’.
The first test is with fast ssid change disabled, which causes the connection problem, then the second with fast ssid change enabled in which the client is able to successfullymove from one wlan to another.
WLC client debugs and ipad console logs are documented for both tests.
1) Fast SSID Change Disabled (default WLC value)
(jk-2504-116) >show wlan summary
Number of WLANs.................................. 2
WLAN ID WLAN Profile Name / SSID Status Interface Name
------- ------------------------------------- -------- --------------------
1 apple1 / apple1 Enabled management
2 apple2 / apple2 Enabled management
(jk-2504-116) >show network summary
<snip>
Fast SSID Change ........................... Disabled
The Ipad is initially authenticated to apple1:
(jk-2504-116) >show client summary
Number of Clients................................ 1
RLAN/
MAC Address AP Name Slot Status WLAN Auth Protocol Port Wired PMIPV6 Role
----------------- ----------------- ---- ------------- ----- ---- ---------------- ---- ----- ------ ----------------
1c:e6:2b:cd:da:9d 1131-17 1 Associated 1 Yes 802.11a 1 N/A No Local
With fast ssid change disabled, the ipad user will attempt to connect to wlan 'apple2'. It will fail to associate to ‘apple2’ and revert to ‘apple1’.
(jk-2504-116) >debug client 1c:e6:2b:cd:da:9d
(jk-2504-116) >*apfMsConnTask_7: Jan 30 21:33:14.544: 1c:e6:2b:cd:da:9d Association received from mobile on BSSID 00:21:a0:e3:fd:be
*apfMsConnTask_7: Jan 30 21:33:14.544: 1c:e6:2b:cd:da:9d Global 200 Clients are allowed to AP radio
*apfMsConnTask_7: Jan 30 21:33:14.544: 1c:e6:2b:cd:da:9d Max Client Trap Threshold: 0 cur: 1
*apfMsConnTask_7: Jan 30 21:33:14.544: 1c:e6:2b:cd:da:9d Rf profile 600 Clients are allowed to AP wlan
*apfMsConnTask_7: Jan 30 21:33:14.544: 1c:e6:2b:cd:da:9d Deleting client immediately since WLAN has changed
*apfMsConnTask_7: Jan 30 21:33:14.544: 1c:e6:2b:cd:da:9d Scheduling deletion of Mobile Station: (callerId: 50) in 1 seconds
*osapiBsnTimer: Jan 30 21:33:15.375: 1c:e6:2b:cd:da:9d apfMsExpireCallback (apf_ms.c:625) Expiring Mobile!
*apfReceiveTask: Jan 30 21:33:15.375: 1c:e6:2b:cd:da:9d apfMsExpireMobileStation (apf_ms.c:6632) Changing state for mobile 1c:e6:2b:cd:da:9d on AP 00:21:a0:e3:fd:b0 from Associated to Disassociated
*apfReceiveTask: Jan 30 21:33:15.375: 1c:e6:2b:cd:da:9d Sent Deauthenticate to mobile on BSSID 00:21:a0:e3:fd:b0 slot 1(caller apf_ms.c:6726)
*apfReceiveTask: Jan 30 21:33:15.375: 1c:e6:2b:cd:da:9d Found an cache entry for BSSID 00:21:a0:e3:fd:bf in PMKID cache at index 0 of station 1c:e6:2b:cd:da:9d
*apfReceiveTask: Jan 30 21:33:15.375: 1c:e6:2b:cd:da:9d Removing BSSID 00:21:a0:e3:fd:bf from PMKID cache of station 1c:e6:2b:cd:da:9d
*apfReceiveTask: Jan 30 21:33:15.375: 1c:e6:2b:cd:da:9d Resetting MSCB PMK Cache Entry 0 for station 1c:e6:2b:cd:da:9d
*apfReceiveTask: Jan 30 21:33:15.375: 1c:e6:2b:cd:da:9d Setting active key cache index 0 ---> 8
*apfReceiveTask: Jan 30 21:33:15.375: 1c:e6:2b:cd:da:9d Deleting the PMK cache when de-authenticating the client.
*apfReceiveTask: Jan 30 21:33:15.375: 1c:e6:2b:cd:da:9d Global PMK Cache deletion failed.
*apfReceiveTask: Jan 30 21:33:15.376: 1c:e6:2b:cd:da:9d apfMsAssoStateDec
*apfReceiveTask: Jan 30 21:33:15.376: 1c:e6:2b:cd:da:9d apfMsExpireMobileStation (apf_ms.c:6764) Changing state for mobile 1c:e6:2b:cd:da:9d on AP 00:21:a0:e3:fd:b0 from Disassociated to Idle
*apfReceiveTask: Jan 30 21:33:15.376: 1c:e6:2b:cd:da:9d pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.
*apfReceiveTask: Jan 30 21:33:15.376: 1c:e6:2b:cd:da:9d 192.168.165.31 START (0) Deleted mobile LWAPP rule on AP [00:21:a0:e3:fd:b0]
*apfReceiveTask: Jan 30 21:33:15.376: 1c:e6:2b:cd:da:9d Deleting mobile on AP 00:21:a0:e3:fd:b0(1)
*pemReceiveTask: Jan 30 21:33:15.377: 1c:e6:2b:cd:da:9d 192.168.165.31 Removed NPU entry.
*apfMsConnTask_7: Jan 30 21:33:23.890: 1c:e6:2b:cd:da:9d Adding mobile on LWAPP AP 00:21:a0:e3:fd:b0(1)
*apfMsConnTask_7: Jan 30 21:33:23.890: 1c:e6:2b:cd:da:9d Association received from mobile on BSSID 00:21:a0:e3:fd:bf
*apfMsConnTask_7: Jan 30 21:33:23.890: 1c:e6:2b:cd:da:9d Global 200 Clients are allowed to AP radio
*apfMsConnTask_7: Jan 30 21:33:23.890: 1c:e6:2b:cd:da:9d Max Client Trap Threshold: 0 cur: 0
*apfMsConnTask_7: Jan 30 21:33:23.890: 1c:e6:2b:cd:da:9d Rf profile 600 Clients are allowed to AP wlan
*apfMsConnTask_7: Jan 30 21:33:23.890: 1c:e6:2b:cd:da:9d Applying Interface policy on Mobile, role Unassociated. Ms NAC State 0 Quarantine Vlan 0 Access Vlan 0
*apfMsConnTask_7: Jan 30 21:33:23.890: 1c:e6:2b:cd:da:9d Re-applying interface policy for client
*apfMsConnTask_7: Jan 30 21:33:23.890: 1c:e6:2b:cd:da:9d 0.0.0.0 START (0) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2202)
*apfMsConnTask_7: Jan 30 21:33:23.890: 1c:e6:2b:cd:da:9d 0.0.0.0 START (0) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2223)
*apfMsConnTask_7: Jan 30 21:33:23.890: 1c:e6:2b:cd:da:9d apfApplyWlanPolicy: Apply WLAN Policy over PMIPv6 Client Mobility Type
*apfMsConnTask_7: Jan 30 21:33:23.890: 1c:e6:2b:cd:da:9d In processSsidIE:4795 setting Central switched to TRUE
*apfMsConnTask_7: Jan 30 21:33:23.890: 1c:e6:2b:cd:da:9d In processSsidIE:4798 apVapId = 1 and Split Acl Id = 65535
*apfMsConnTask_7: Jan 30 21:33:23.890: 1c:e6:2b:cd:da:9d Applying site-specific Local Bridging override for station 1c:e6:2b:cd:da:9d - vapId 1, site 'default-group', interface 'management'
*apfMsConnTask_7: Jan 30 21:33:23.891: 1c:e6:2b:cd:da:9d Applying Local Bridging Interface Policy for station 1c:e6:2b:cd:da:9d - vlan 0, interface id 0, interface 'management'
*apfMsConnTask_7: Jan 30 21:33:23.891: 1c:e6:2b:cd:da:9d processSsidIE statusCode is 0 and status is 0
*apfMsConnTask_7: Jan 30 21:33:23.891: 1c:e6:2b:cd:da:9d processSsidIE ssid_done_flag is 0 finish_flag is 0
*apfMsConnTask_7: Jan 30 21:33:23.891: 1c:e6:2b:cd:da:9d STA - rates (8): 140 18 152 36 176 72 96 108 0 0 0 0 0 0 0 0
*apfMsConnTask_7: Jan 30 21:33:23.891: 1c:e6:2b:cd:da:9d suppRates statusCode is 0 and gotSuppRatesElement is 1
*apfMsConnTask_7: Jan 30 21:33:23.891: 1c:e6:2b:cd:da:9d Processing RSN IE type 48, length 20 for mobile 1c:e6:2b:cd:da:9d
*apfMsConnTask_7: Jan 30 21:33:23.891: 1c:e6:2b:cd:da:9d Updating AID for REAP AP Client 00:21:a0:e3:fd:b0 - AID ===> 1
*apfMsConnTask_7: Jan 30 21:33:23.891: 1c:e6:2b:cd:da:9d 0.0.0.0 START (0) Initializing policy
*apfMsConnTask_7: Jan 30 21:33:23.891: 1c:e6:2b:cd:da:9d 0.0.0.0 START (0) Change state to AUTHCHECK (2) last state START (0)
*apfMsConnTask_7: Jan 30 21:33:23.891: 1c:e6:2b:cd:da:9d 0.0.0.0 AUTHCHECK (2) Change state to 8021X_REQD (3) last state AUTHCHECK (2)
*apfMsConnTask_7: Jan 30 21:33:23.891: 1c:e6:2b:cd:da:9d Central switch is TRUE
*apfMsConnTask_7: Jan 30 21:33:23.891: 1c:e6:2b:cd:da:9d Not Using WMM Compliance code qosCap 00
*apfMsConnTask_7: Jan 30 21:33:23.891: 1c:e6:2b:cd:da:9d 0.0.0.0 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 00:21:a0:e3:fd:b0 vapId 1 apVapId 1 flex-acl-name:
*apfMsConnTask_7: Jan 30 21:33:23.891: 1c:e6:2b:cd:da:9d apfMsAssoStateInc
*apfMsConnTask_7: Jan 30 21:33:23.891: 1c:e6:2b:cd:da:9d apfPemAddUser2 (apf_policy.c:333) Changing state for mobile 1c:e6:2b:cd:da:9d on AP 00:21:a0:e3:fd:b0 from Idle to Associated
*apfMsConnTask_7: Jan 30 21:33:23.891: 1c:e6:2b:cd:da:9d apfPemAddUser2:session timeout forstation 1c:e6:2b:cd:da:9d - Session Tout 1800, apfMsTimeOut '1800' and sessionTimerRunning flag is 0
*apfMsConnTask_7: Jan 30 21:33:23.891: 1c:e6:2b:cd:da:9d Scheduling deletion of Mobile Station: (callerId: 49) in 1800 seconds
*apfMsConnTask_7: Jan 30 21:33:23.891: 1c:e6:2b:cd:da:9d Func: apfPemAddUser2, Ms Timeout = 1800, Session Timeout = 1800
*apfMsConnTask_7: Jan 30 21:33:23.891: 1c:e6:2b:cd:da:9d Sending Assoc Response to station on BSSID 00:21:a0:e3:fd:bf (status 0) ApVapId 1 Slot 1
*apfMsConnTask_7: Jan 30 21:33:23.892: 1c:e6:2b:cd:da:9d apfProcessAssocReq (apf_80211.c:8292) Changing state for mobile 1c:e6:2b:cd:da:9d on AP 00:21:a0:e3:fd:b0 from Associated to Associated
*spamApTask7: Jan 30 21:33:23.894: 1c:e6:2b:cd:da:9d Sent 1x initiate message to multi thread task for mobile 1c:e6:2b:cd:da:9d
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.894: 1c:e6:2b:cd:da:9d Creating a PKC PMKID Cache entry for station 1c:e6:2b:cd:da:9d (RSN 2)
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.894: 1c:e6:2b:cd:da:9d Resetting MSCB PMK Cache Entry 0 for station 1c:e6:2b:cd:da:9d
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.894: 1c:e6:2b:cd:da:9d Setting active key cache index 8 ---> 8
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.894: 1c:e6:2b:cd:da:9d Setting active key cache index 8 ---> 0
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.894: 1c:e6:2b:cd:da:9d Adding BSSID 00:21:a0:e3:fd:bf to PMKID cache at index 0 for station 1c:e6:2b:cd:da:9d
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.894: New PMKID: (16)
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.894: [0000] 37 8e ed ac 2f 75 3e 85 fa 32 50 21 b4 44 b5 f9
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.894: 1c:e6:2b:cd:da:9d Initiating RSN PSK to mobile 1c:e6:2b:cd:da:9d
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.894: 1c:e6:2b:cd:da:9d EAP-PARAM Debug - eap-params for Wlan-Id :1 is disabled - applying Global eap timers and retries
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.895: 1c:e6:2b:cd:da:9d dot1x - moving mobile 1c:e6:2b:cd:da:9d into Force Auth state
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.895: 1c:e6:2b:cd:da:9d EAPOL Header:
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.895: 00000000: 02 03 00 5f ..._
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.895: 1c:e6:2b:cd:da:9d Found an cache entry for BSSID 00:21:a0:e3:fd:bf in PMKID cache at index 0 of station 1c:e6:2b:cd:da:9d
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.895: 1c:e6:2b:cd:da:9d Found an cache entry for BSSID 00:21:a0:e3:fd:bf in PMKID cache at index 0 of station 1c:e6:2b:cd:da:9d
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.895: Including PMKID in M1 (16)
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.895: [0000] 37 8e ed ac 2f 75 3e 85 fa 32 50 21 b4 44 b5 f9
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.895: 1c:e6:2b:cd:da:9d Starting key exchange to mobile 1c:e6:2b:cd:da:9d, data packets will be dropped
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.895: 1c:e6:2b:cd:da:9d Sending EAPOL-Key Message to mobile 1c:e6:2b:cd:da:9d
state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.895: 1c:e6:2b:cd:da:9d Sending EAPOL-Key Message to mobile 1c:e6:2b:cd:da:9d
state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.895: 1c:e6:2b:cd:da:9d Allocating EAP Pkt for retransmission to mobile 1c:e6:2b:cd:da:9d
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.895: 1c:e6:2b:cd:da:9d mscb->apfMsLwappLradNhMac = 00:23:33:bc:38:60 mscb->apfMsLradSlotId = 1 mscb->apfMsLradJumbo = 0 mscb->apfMsintIfNum = 1
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.895: 1c:e6:2b:cd:da:9d mscb->apfMsBssid = 00:21:a0:e3:fd:b0 mscb->apfMsAddress = 1c:e6:2b:cd:da:9d mscb->apfMsApVapId = 1
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.895: 1c:e6:2b:cd:da:9d dot1xcb->snapOrg = 00 00 00 dot1xcb->eapolWepBit = 0 mscb->apfMsLwappLradVlanId = 0 mscb->apfMsLwappMwarInet.ipv4.addr = -1062689420
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.895: 1c:e6:2b:cd:da:9d mscb->apfMsLwappMwarPort = 5246 mscb->apfMsLwappLradInet.ipv4.addr = -1062689464 mscb->apfMsLwappLradPort = 50055
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.897: 1c:e6:2b:cd:da:9d Received EAPOL-Key from mobile 1c:e6:2b:cd:da:9d
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.897: 1c:e6:2b:cd:da:9d Received EAPOL-key in PTK_START state (message 2) from mobile 1c:e6:2b:cd:da:9d
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.897: 1c:e6:2b:cd:da:9d Stopping retransmission timer for mobile 1c:e6:2b:cd:da:9d
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.897: 1c:e6:2b:cd:da:9d EAPOL Header:
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.898: 00000000: 02 03 00 5f ..._
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.898: 1c:e6:2b:cd:da:9d Sending EAPOL-Key Message to mobile 1c:e6:2b:cd:da:9d
state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.898: 1c:e6:2b:cd:da:9d Sending EAPOL-Key Message to mobile 1c:e6:2b:cd:da:9d
state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.898: 1c:e6:2b:cd:da:9d Reusing allocated memory for EAP Pkt for retransmission to mobile 1c:e6:2b:cd:da:9d
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.898: 1c:e6:2b:cd:da:9d mscb->apfMsLwappLradNhMac = 00:23:33:bc:38:60 mscb->apfMsLradSlotId = 1 mscb->apfMsLradJumbo = 0 mscb->apfMsintIfNum = 1
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.898: 1c:e6:2b:cd:da:9d mscb->apfMsBssid = 00:21:a0:e3:fd:b0 mscb->apfMsAddress = 1c:e6:2b:cd:da:9d mscb->apfMsApVapId = 1
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.898: 1c:e6:2b:cd:da:9d dot1xcb->snapOrg = 00 00 00 dot1xcb->eapolWepBit = 0 mscb->apfMsLwappLradVlanId = 0 mscb->apfMsLwappMwarInet.ipv4.addr = -1062689420
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.898: 1c:e6:2b:cd:da:9d mscb->apfMsLwappMwarPort = 5246 mscb->apfMsLwappLradInet.ipv4.addr = -1062689464 mscb->apfMsLwappLradPort = 50055
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.900: 1c:e6:2b:cd:da:9d Received EAPOL-Key from mobile 1c:e6:2b:cd:da:9d
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.900: 1c:e6:2b:cd:da:9d Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 1c:e6:2b:cd:da:9d
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.900: 1c:e6:2b:cd:da:9d Stopping retransmission timer for mobile 1c:e6:2b:cd:da:9d
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.900: 1c:e6:2b:cd:da:9d Freeing EAP Retransmit Bufer for mobile 1c:e6:2b:cd:da:9d
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.901: 1c:e6:2b:cd:da:9d apfMs1xStateInc
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.901: 1c:e6:2b:cd:da:9d 0.0.0.0 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state 8021X_REQD (3)
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.901: 1c:e6:2b:cd:da:9d Central switch is TRUE
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.901: 1c:e6:2b:cd:da:9d Not Using WMM Compliance code qosCap 00
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.901: 1c:e6:2b:cd:da:9d 0.0.0.0 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 00:21:a0:e3:fd:b0 vapId 1 apVapId 1 flex-acl-name:
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.901: 1c:e6:2b:cd:da:9d 0.0.0.0 L2AUTHCOMPLETE (4) Change state to DHCP_REQD (7) last state L2AUTHCOMPLETE (4)
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.901: 1c:e6:2b:cd:da:9d 0.0.0.0 DHCP_REQD (7) pemAdvanceState2 6157, Adding TMP rule
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.901: 1c:e6:2b:cd:da:9d 0.0.0.0 DHCP_REQD (7) Adding Fast Path rule
type = Airespace AP - Learn IP address
on AP 00:21:a0:e3:fd:b0, slot 1, interface = 1, QOS = 0
IPv4 ACL ID = 255, IPv
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.901: 1c:e6:2b:cd:da:9d 0.0.0.0 DHCP_REQD (7) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 15206 Local Bridging Vlan = 0, Local Bridging intf id = 0
*Dot1x_NW_MsgTask_5: Jan 30 21:33:23.901: 1c:e6:2b:cd:da:9d 0.0.0.0 DHCP_REQD (7) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255, L2 ACL ID 255)
*apfReceiveTask: Jan 30 21:33:23.901: 1c:e6:2b:cd:da:9d 0.0.0.0 DHCP_REQD (7) State Update from Mobility-Incomplete to Mobility-Complete, mobility role=Local, client state=APF_MS_STATE_ASSOCIATED
*apfReceiveTask: Jan 30 21:33:23.901: 1c:e6:2b:cd:da:9d 0.0.0.0 DHCP_REQD (7) pemAdvanceState2 5752, Adding TMP rule
*apfReceiveTask: Jan 30 21:33:23.901: 1c:e6:2b:cd:da:9d 0.0.0.0 DHCP_REQD (7) Replacing Fast Path rule
type = Airespace AP - Learn IP address
on AP 00:21:a0:e3:fd:b0, slot 1, interface = 1, QOS = 0
IPv4 ACL ID = 255,
*apfReceiveTask: Jan 30 21:33:23.901: 1c:e6:2b:cd:da:9d 0.0.0.0 DHCP_REQD (7) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 15206 Local Bridging Vlan = 0, Local Bridging intf id = 0
*apfReceiveTask: Jan 30 21:33:23.901: 1c:e6:2b:cd:da:9d 0.0.0.0 DHCP_REQD (7) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255, L2 ACL ID 255)
*pemReceiveTask: Jan 30 21:33:23.902: 1c:e6:2b:cd:da:9d 0.0.0.0 Added NPU entry of type 9, dtlFlags 0x0
*pemReceiveTask: Jan 30 21:33:23.902: 1c:e6:2b:cd:da:9d 0.0.0.0 Added NPU entry of type 9, dtlFlags 0x0
*pemReceiveTask: Jan 30 21:33:23.902: 1c:e6:2b:cd:da:9d Sent an XID frame
*IPv6_Msg_Task: Jan 30 21:33:23.902: 1c:e6:2b:cd:da:9d Pushing IPv6 Vlan Intf ID 0: fe80:0000:0000:0000:1ee6:2bff:fecd:da9d , and MAC: 1C:E6:2B:CD:DA:9D , Binding to Data Plane. SUCCESS !! dhcpv6bitmap 0
*IPv6_Msg_Task: Jan 30 21:33:23.902: 1c:e6:2b:cd:da:9d Link Local address fe80::1ee6:2bff:fecd:da9d updated to mscb. Not Advancing pem state.Current state: mscb in apfMsMmInitial mobility state and client state APF_MS_STATE_A
*DHCP Socket Task: Jan 30 21:33:23.920: 1c:e6:2b:cd:da:9d DHCP received op BOOTREQUEST (1) (len 308,vlan 0, port 1, encap 0xec03)
*DHCP Socket Task: Jan 30 21:33:23.920: 1c:e6:2b:cd:da:9d DHCP (encap type 0xec03) mstype 0ff:ff:ff:ff:ff:ff
*DHCP Socket Task: Jan 30 21:33:23.920: 1c:e6:2b:cd:da:9d DHCP selecting relay 1 - control block settings:
dhcpServer: 0.0.0.0, dhcpNetmask: 0.0.0.0,
dhcpGateway: 0.0.0.0, dhcpRelay: 0.0.0.0 VLAN: 0
*DHCP Socket Task: Jan 30 21:33:23.920: 1c:e6:2b:cd:da:9d DHCP selected relay 1 - 192.168.165.13 (local address 192.168.165.116, gateway 192.168.165.13, VLAN 0, port 1)
*DHCP Socket Task: Jan 30 21:33:23.920: 1c:e6:2b:cd:da:9d DHCP transmitting DHCP REQUEST (3)
*DHCP Socket Task: Jan 30 21:33:23.920: 1c:e6:2b:cd:da:9d DHCP op: BOOTREQUEST, htype: Ethernet, hlen: 6, hops: 1
*DHCP Socket Task: Jan 30 21:33:23.920: 1c:e6:2b:cd:da:9d DHCP xid: 0xa747e377 (2806506359), secs: 0, flags: 0
*DHCP Socket Task: Jan 30 21:33:23.920: 1c:e6:2b:cd:da:9d DHCP chaddr: 1c:e6:2b:cd:da:9d
*DHCP Socket Task: Jan 30 21:33:23.920: 1c:e6:2b:cd:da:9d DHCP ciaddr: 0.0.0.0, yiaddr: 0.0.0.0
*DHCP Socket Task: Jan 30 21:33:23.920: 1c:e6:2b:cd:da:9d DHCP siaddr: 0.0.0.0, giaddr: 192.168.165.116
*DHCP Socket Task: Jan 30 21:33:23.920: 1c:e6:2b:cd:da:9d DHCP requested ip: 192.168.165.31
*DHCP Socket Task: Jan 30 21:33:23.920: 1c:e6:2b:cd:da:9d DHCP sending REQUEST to 192.168.165.13 (len 346, port 1, vlan 0)
*DHCP Socket Task: Jan 30 21:33:23.920: 1c:e6:2b:cd:da:9d DHCP selecting relay 2 - control block settings:
dhcpServer: 0.0.0.0, dhcpNetmask: 0.0.0.0,
dhcpGateway: 0.0.0.0, dhcpRelay: 192.168.165.116 VLAN: 0
*DHCP Socket Task: Jan 30 21:33:23.920: 1c:e6:2b:cd:da:9d DHCP selected relay 2 - NONE (server address 0.0.0.0,local address 0.0.0.0, gateway 192.168.165.1, VLAN 0, port 1)
*DHCP Socket Task: Jan 30 21:33:23.921: 1c:e6:2b:cd:da:9d DHCP received op BOOTREPLY (2) (len 308,vlan 0, port 1, encap 0xec00)
*DHCP Socket Task: Jan 30 21:33:23.921: 1c:e6:2b:cd:da:9d DHCP setting server from ACK (server 192.168.165.13, yiaddr 192.168.165.31)
*DHCP Socket Task: Jan 30 21:33:23.921: 1c:e6:2b:cd:da:9d Static IP client associated to interface management which can support client subnet.
*DHCP Socket Task: Jan 30 21:33:23.922: 1c:e6:2b:cd:da:9d apfMsRunStateInc
*DHCP Socket Task: Jan 30 21:33:23.922: 1c:e6:2b:cd:da:9d 192.168.165.31 DHCP_REQD (7) Change state to RUN (20) last state DHCP_REQD (7)
*DHCP Socket Task: Jan 30 21:33:23.922: 1c:e6:2b:cd:da:9d 192.168.165.31 RUN (20) Reached PLUMBFASTPATH: from line 6822
*DHCP Socket Task: Jan 30 21:33:23.922: 1c:e6:2b:cd:da:9d 192.168.165.31 RUN (20) Replacing Fast Path rule
type = Airespace AP Client
on AP 00:21:a0:e3:fd:b0, slot 1, interface = 1, QOS = 0
IPv4 ACL ID = 255, IPv6 ACL I
*DHCP Socket Task: Jan 30 21:33:23.922: 1c:e6:2b:cd:da:9d 192.168.165.31 RUN (20) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 15206 Local Bridging Vlan = 0, Local Bridging intf id = 0
*DHCP Socket Task: Jan 30 21:33:23.922: 1c:e6:2b:cd:da:9d 192.168.165.31 RUN (20) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255, L2 ACL ID 255)
*DHCP Socket Task: Jan 30 21:33:23.922: 1c:e6:2b:cd:da:9d Assigning Address 192.168.165.31 to mobile
*DHCP Socket Task: Jan 30 21:33:23.922: 1c:e6:2b:cd:da:9d DHCP success event for client. Clearing dhcp failure count for interface management.
*DHCP Socket Task: Jan 30 21:33:23.922: 1c:e6:2b:cd:da:9d DHCP success event for client. Clearing dhcp failure count for interface management.
*DHCP Socket Task: Jan 30 21:33:23.922: 1c:e6:2b:cd:da:9d DHCP sending REPLY to STA (len 414, port 1, vlan 0)
*DHCP Socket Task: Jan 30 21:33:23.922: 1c:e6:2b:cd:da:9d DHCP transmitting DHCP ACK (5)
*DHCP Socket Task: Jan 30 21:33:23.922: 1c:e6:2b:cd:da:9d DHCP op: BOOTREPLY, htype: Ethernet, hlen: 6, hops: 0
*DHCP Socket Task: Jan 30 21:33:23.922: 1c:e6:2b:cd:da:9d DHCP xid: 0xa747e377 (2806506359), secs: 0, flags: 0
*DHCP Socket Task: Jan 30 21:33:23.922: 1c:e6:2b:cd:da:9d DHCP chaddr: 1c:e6:2b:cd:da:9d
*DHCP Socket Task: Jan 30 21:33:23.922: 1c:e6:2b:cd:da:9d DHCP ciaddr: 0.0.0.0, yiaddr: 192.168.165.31
*DHCP Socket Task: Jan 30 21:33:23.922: 1c:e6:2b:cd:da:9d DHCP siaddr: 0.0.0.0, giaddr: 0.0.0.0
*DHCP Socket Task: Jan 30 21:33:23.922: 1c:e6:2b:cd:da:9d DHCP server id: 1.1.1.1 rcvd server id: 192.168.165.13
*pemReceiveTask: Jan 30 21:33:23.923: 1c:e6:2b:cd:da:9d 192.168.165.31 Added NPU entry of type 1, dtlFlags 0x0
*pemReceiveTask: Jan 30 21:33:23.923: 1c:e6:2b:cd:da:9d Pushing IPv6: fe80:0000:0000:0000:1ee6:2bff:fecd:da9d , and MAC: 1C:E6:2B:CD:DA:9D , Binding to Data Plane. SUCCESS !!
*pemReceiveTask: Jan 30 21:33:23.923: 1c:e6:2b:cd:da:9d Sending a gratuitous ARP for 192.168.165.31, VLAN Id 0
*IPv6_Msg_Task: Jan 30 21:33:23.938: 1c:e6:2b:cd:da:9d Link Local address fe80::1ee6:2bff:fecd:da9d updated to mscb. Not Advancing pem state.Current state: mscb in apfMsMmInitial mobility state and client state APF_MS_STATE_A
Ipad Console Log:
Jan 30 16:42:09 iPadMini5 Preferences[153] <Warning>: -[VPNConnectionStore reloadVPN]: The active VPN configuration has changed from to (null)
Jan 30 16:42:09 iPadMini5 kernel[0] <Debug>: 017324.526803 wlan.N[11431] AppleBCMWLANCore::setDISASSOCIATE(): [wifid]:
Jan 30 16:42:09 iPadMini5 kernel[0] <Debug>: 017324.551763 wlan.N[11432] AppleBCMWLAN Left BSS: @ 0x80be3000, BSSID = 00:21:a0:e3:fd:bf, rssi = -50, rate = 54 (100%), channel = 161, encryption = 0x8, ap = 1, failures = 0, age = 153, ssid[ 6] = "apple1"
Jan 30 16:42:09 iPadMini5 kernel[0] <Debug>: 017324.551829 wlan.A[11433] AppleBCMWLANCore::deleteAllPktFilters(): Deleted IPv4/IPv6 and Magic packet filters
Jan 30 16:42:09 iPadMini5 kernel[0] <Debug>: AirPort: Link Down on en0. Reason 1 (Unspecified).
Jan 30 16:42:09 iPadMini5 kernel[0] <Debug>: en0::stopOutputQueues
Jan 30 16:42:09 iPadMini5 kernel[0] <Debug>: IO80211PeerManager::doDisable
Jan 30 16:42:09 iPadMini5 kernel[0] <Debug>: en0::IO80211Interface::postMessage bssid changed
Jan 30 16:42:09 iPadMini5 kernel[0] <Debug>: IO80211AWDLPeerManager::interfaceStateChange() reason Interface _enablingSynch 0 _syncState 0 force 0 num services 0 _infraChannel 0
Jan 30 16:42:09 iPadMini5 kernel[0] <Debug>: IO80211AWDLPeerManager::interfaceStateChange() _enablingSynch 0 _syncState 0 -> quit
Jan 30 16:42:09 iPadMini5 Preferences[153] <Warning>: -[VPNBundleController _vpnConfigurationChanged:] (0x20093900:<VPNBundleController: 0x20093900>): _serviceCount(0), serviceCount(0), toggleInRootMenu(0), RootMenuItem(1)
Jan 30 16:42:09 iPadMini5 configd[49] <Notice>: LINKLOCAL en0: parent has no IP
Jan 30 16:42:09 iPadMini5 kernel[0] <Debug>: IO80211AWDLPeerManager::setJoiningState disabling sync for association attempt
Jan 30 16:42:09 iPadMini5 kernel[0] <Debug>: 017324.648451 wlan.N[11434] AppleBCMWLANCore::setASSOCIATE(): [wifid]: lowerAuth = AUTHTYPE_OPEN, upperAuth = AUTHTYPE_WPA2_PSK, key = CIPHER_PMK .
Jan 30 16:42:09 iPadMini5 kernel[0] <Debug>: 017324.661180 wlan.N[11435] virtual SInt32 AppleBCMWLANCore::setupCountryCode(): AutoCountry:1, fDefaultCountryCode:XZ, fCurrentCountryCode:
Jan 30 16:42:09 iPadMini5 kernel[0] <Debug>: 017324.712604 wlan.A[11436] AppleBCMWLANNetManager::prepareToBringUpLink(): Delaying powersave entry in order to get an IP address
Jan 30 16:42:09 iPadMini5 kernel[0] <Debug>: 017324.712792 wlan.N[11437] AppleBCMWLAN Joined BSS: @ 0x80c99800, BSSID = 00:21:a0:e3:fd:be, rssi = -49, rate = 54 (100%), channel = 161, encryption = 0x8, ap = 1, failures = 0, age = 153, ssid[ 6] = "apple2"
Jan 30 16:42:09 iPadMini5 kernel[0] <Debug>: AirPort: Link Up on en0
Jan 30 16:42:09 iPadMini5 kernel[0] <Debug>: en0::startOutputQueues (0)
Jan 30 16:42:09 iPadMini5 kernel[0] <Debug>: IO80211PeerManager::doEnable
Jan 30 16:42:09 iPadMini5 kernel[0] <Debug>: en0: BSSID changed to 00:21:a0:e3:fd:be
Jan 30 16:42:09 iPadMini5 kernel[0] <Debug>: en0::IO80211Interface::postMessage bssid changed
Jan 30 16:42:09 iPadMini5 kernel[0] <Debug>: IO80211AWDLPeerManager::interfaceStateChange() reason Interface _enablingSynch 0 _syncState 0 force 0 num services 0 _infraChannel 0
Jan 30 16:42:09 iPadMini5 kernel[0] <Debug>: IO80211AWDLPeerManager::interfaceStateChange() _enablingSynch 0 _syncState 0 -> quit
Jan 30 16:42:09 iPadMini5 kernel[0] <Debug>: en0: BSSID changed to 00:21:a0:e3:fd:be
Jan 30 16:42:09 iPadMini5 kernel[0] <Debug>: en0::IO80211Interface::postMessage bssid changed
Jan 30 16:42:09 iPadMini5 kernel[0] <Debug>: IO80211AWDLPeerManager::interfaceStateChange() reason Interface _enablingSynch 0 _syncState 0 force 0 num services 0 _infraChannel 0
Jan 30 16:42:09 iPadMini5 kernel[0] <Debug>: IO80211AWDLPeerManager::interfaceStateChange() _enablingSynch 0 _syncState 0 -> quit
Jan 30 16:42:09 iPadMini5 kernel[0] <Debug>: 017324.732162 wlan.N[11438] AppleBCMWLANCore:startRoamScan(): 3365 Delaying RoamScan; because Join Mgr Busy 1 isWaitingforIP 1
Jan 30 16:42:09 iPadMini5 kernel[0] <Debug>: IO80211Peer::queuePacket ff:ff:ff:ff:ff:ff alllocate queue for ac 0
Jan 30 16:42:09 iPadMini5 configd[49] <Notice>: network changed: Proxy
Jan 30 16:42:11 iPadMini5 kernel[0] <Debug>: 017325.639047 wlan.N[11439] AppleBCMWLANJoinManager::handleSupplicantEvent(): status = 4, reason = 14, flags = 0x0, authtype = 0, addr = 00:00:48:01:3c:00
Jan 30 16:42:11 iPadMini5 kernel[0] <Debug>: 017325.639296 wlan.N[11440] AppleBCMWLANNetManager::handleDeauth(): status = 0, reason = 1, flags = 0x0, authtype = 0, addr = 00:21:a0:e3:fd:be
Jan 30 16:42:11 iPadMini5 kernel[0] <Debug>: 017325.645037 wlan.N[11441] AppleBCMWLANNetManager::leaveNetworkAsync(): kDeauthdCurrNetwork already set. Skipping call to leaveNetworkASync
Jan 30 16:42:11 iPadMini5 kernel[0] <Debug>: 017325.645232 wlan.N[11442] AppleBCMWLAN Left BSS: @ 0x80c99800, BSSID = 00:21:a0:e3:fd:be, rssi = -49, rate = 54 (100%), channel = 161, encryption = 0x8, ap = 1, failures = 0, age = 154, ssid[ 6] = "apple2"
Jan 30 16:42:11 iPadMini5 kernel[0] <Debug>: 017325.645347 wlan.A[11443] AppleBCMWLANCore::deleteAllPktFilters(): Deleted IPv4/IPv6 and Magic packet filters
Jan 30 16:42:11 iPadMini5 kernel[0] <Debug>: AirPort: Link Down on en0. Reason 1 (Unspecified).
Jan 30 16:42:11 iPadMini5 kernel[0] <Debug>: en0::stopOutputQueues
Jan 30 16:42:11 iPadMini5 kernel[0] <Debug>: IO80211PeerManager::doDisable
Jan 30 16:42:11 iPadMini5 kernel[0] <Debug>: en0::IO80211Interface::postMessage bssid changed
Jan 30 16:42:11 iPadMini5 kernel[0] <Debug>: IO80211AWDLPeerManager::interfaceStateChange() reason Interface _enablingSynch 0 _syncState 0 force 0 num services 0 _infraChannel 0
Jan 30 16:42:11 iPadMini5 kernel[0] <Debug>: IO80211AWDLPeerManager::interfaceStateChange() _enablingSynch 0 _syncState 0 -> quit
Jan 30 16:42:19 iPadMini5 Preferences[153] <Warning>: -[VPNConnectionStore reloadVPN]: The active VPN configuration has changed from to (null)
Jan 30 16:42:19 iPadMini5 Preferences[153] <Warning>: -[VPNBundleController _vpnConfigurationChanged:] (0x20093900:<VPNBundleController: 0x20093900>): _serviceCount(0), serviceCount(0), toggleInRootMenu(0), RootMenuItem(1)
Jan 30 16:42:19 iPadMini5 kernel[0] <Debug>: IO80211AWDLPeerManager::setJoiningState disabling sync for association attempt
Jan 30 16:42:19 iPadMini5 kernel[0] <Debug>: 017334.049068 wlan.N[11444] AppleBCMWLANCore::setASSOCIATE(): [wifid]: lowerAuth = AUTHTYPE_OPEN, upperAuth = AUTHTYPE_WPA2_PSK, key = CIPHER_PMK , don't disassociate .
Jan 30 16:42:19 iPadMini5 kernel[0] <Debug>: 017334.084886 wlan.N[11445] virtual SInt32 AppleBCMWLANCore::setupCountryCode(): AutoCountry:1, fDefaultCountryCode:XZ, fCurrentCountryCode:
Jan 30 16:42:19 iPadMini5 kernel[0] <Debug>: 017334.176085 wlan.A[11446] AppleBCMWLANNetManager::prepareToBringUpLink(): Delaying powersave entry in order to get an IP address
Jan 30 16:42:19 iPadMini5 kernel[0] <Debug>: 017334.176274 wlan.N[11447] AppleBCMWLAN Joined BSS: @ 0x8102f200, BSSID = 00:21:a0:e3:fd:b0, rssi = -50, rate = 54 (100%), channel = 11, encryption = 0x8, ap = 1, failures = 0, age = 0, ssid[ 6] = "apple1"
Jan 30 16:42:19 iPadMini5 kernel[0] <Debug>: AirPort: Link Up on en0
Jan 30 16:42:19 iPadMini5 kernel[0] <Debug>: en0::startOutputQueues (0)
Jan 30 16:42:19 iPadMini5 kernel[0] <Debug>: IO80211PeerManager::doEnable
Jan 30 16:42:19 iPadMini5 kernel[0] <Debug>: en0: BSSID changed to 00:21:a0:e3:fd:b0
Jan 30 16:42:19 iPadMini5 kernel[0] <Debug>: en0::IO80211Interface::postMessage bssid changed
Jan 30 16:42:19 iPadMini5 kernel[0] <Debug>: IO80211AWDLPeerManager::interfaceStateChange() reason Interface _enablingSynch 0 _syncState 0 force 0 num services 0 _infraChannel 11
Jan 30 16:42:19 iPadMini5 kernel[0] <Debug>: IO80211AWDLPeerManager::interfaceStateChange() _enablingSynch 0 _syncState 0 -> quit
Jan 30 16:42:19 iPadMini5 kernel[0] <Debug>: en0: BSSID changed to 00:21:a0:e3:fd:b0
Jan 30 16:42:19 iPadMini5 kernel[0] <Debug>: en0::IO80211Interface::postMessage bssid changed
Jan 30 16:42:19 iPadMini5 kernel[0] <Debug>: IO80211AWDLPeerManager::interfaceStateChange() reason Interface _enablingSynch 0 _syncState 0 force 0 num services 0 _infraChannel 11
Jan 30 16:42:19 iPadMini5 kernel[0] <Debug>: IO80211AWDLPeerManager::interfaceStateChange() _enablingSynch 0 _syncState 0 -> quit
Jan 30 16:42:19 iPadMini5 kernel[0] <Debug>: 017334.190399 wlan.N[11448] AppleBCMWLANJoinManager::handleSupplicantEvent(): status = 6, reason = 0, flags = 0x0, authtype = 0, addr = 00:00:00:00:c4:02
Jan 30 16:42:19 iPadMini5 kernel[0] <Debug>: IO80211Peer::queuePacket ff:ff:ff:ff:ff:ff alllocate queue for ac 0
Jan 30 16:42:19 iPadMini5 kernel[0] <Debug>: 017334.210455 wlan.N[11449] AppleBCMWLANCore:startRoamScan(): 3365 Delaying RoamScan; because Join Mgr Busy 0 isWaitingforIP 1
Jan 30 16:42:20 iPadMini5 kernel[0] <Debug>: 017335.272794 wlan.A[11450] AppleBCMWLANNetManager::receivedIPv4Address(): Received address 192.168.165.31, entering powersave mode 2
Jan 30 16:42:20 iPadMini5 kernel[0] <Debug>: 017335.272906 wlan.N[11451] AppleBCMWLANCore:startRoamScan(): 3379 starting RoamScan; MultiAPEnv:0 isdualBand:1 isOn5G:0
Jan 30 16:42:20 iPadMini5 configd[49] <Notice>: network changed: Proxy
Jan 30 16:42:23 iPadMini5 Preferences[153] <Warning>: -[VPNConnectionStore reloadVPN]: The active VPN configuration has changed from to (null)
Jan 30 16:42:23 iPadMini5 kernel[0] <Debug>: en0: BSSID changed to 00:21:a0:e3:fd:b0
Jan 30 16:42:23 iPadMini5 kernel[0] <Debug>: en0::IO80211Interface::postMessage bssid changed
Jan 30 16:42:23 iPadMini5 kernel[0] <Debug>: IO80211AWDLPeerManager::interfaceStateChange() reason Interface _enablingSynch 0 _syncState 0 force 0 num services 0 _infraChannel 11
Jan 30 16:42:23 iPadMini5 kernel[0] <Debug>: IO80211AWDLPeerManager::interfaceStateChange() _enablingSynch 0 _syncState 0 -> quit
Jan 30 16:42:23 iPadMini5 kernel[0] <Debug>: 017338.386543 wlan.N[11452] AppleBCMWLAN Left BSS: @ 0x8102f200, BSSID = 00:21:a0:e3:fd:b0, rssi = -50, rate = 54 (100%), channel = 11, encryption = 0x8, ap = 1, failures = 0, age = 4, ssid[ 6] = "apple1"
Jan 30 16:42:23 iPadMini5 kernel[0] <Debug>: 017338.386603 wlan.N[11453] AppleBCMWLAN Roamed to BSS: @ 0x8102e600, BSSID = 00:21:a0:e3:fd:bf, rssi = -57, rate = 54 (100%), channel = 161, encryption = 0x8, ap = 1, failures = 0, age = 0, ssid[ 6] = "apple1"
Jan 30 16:42:23 iPadMini5 kernel[0] <Debug>: en0: BSSID changed to 00:21:a0:e3:fd:bf
Jan 30 16:42:23 iPadMini5 kernel[0] <Debug>: en0::IO80211Interface::postMessage bssid changed
Jan 30 16:42:23 iPadMini5 kernel[0] <Debug>: IO80211AWDLPeerManager::interfaceStateChange() reason Interface _enablingSynch 0 _syncState 0 force 0 num services 0 _infraChannel 161
Jan 30 16:42:23 iPadMini5 kernel[0] <Debug>: IO80211AWDLPeerManager::interfaceStateChange() _enablingSynch 0 _syncState 0 -> quit
Jan 30 16:42:23 iPadMini5 Preferences[153] <Warning>: -[VPNBundleController _vpnConfigurationChanged:] (0x20093900:<VPNBundleController: 0x20093900>): _serviceCount(0), serviceCount(0), toggleInRootMenu(0), RootMenuItem(1)
Jan 30 16:42:25 iPadMini5 networkd[69] <Error>: client_connection_cellular_start no interface match
2) Fast SSID Change Enabled
With fast ssid change enabled, the ipad user will successfully connect to wlan 'apple2'.
(jk-2504-116) >config network fast-ssid-change enable
<snip>
Fast SSID Change ........................... Enabled
(jk-2504-116) >show client summary
Number of Clients................................ 1
RLAN/
MAC Address AP Name Slot Status WLAN Auth Protocol Port Wired PMIPV6 Role
----------------- ----------------- ---- ------------- ----- ---- ---------------- ---- ----- ------ ----------------
1c:e6:2b:cd:da:9d 1131-17 1 Associated 1 Yes 802.11a 1 N/A No Local
(jk-2504-116) >show debug
MAC Addr 1.................................. 1C:E6:2B:CD:DA:9D
Debug Flags Enabled:
dhcp packet enabled.
dot11 mobile enabled.
dot11 state enabled
dot1x events enabled.
dot1x states enabled.
FlexConnect ft enabled.
pem events enabled.
pem state enabled.
CCKM client debug enabled.
(jk-2504-116) >*apfMsConnTask_7: Jan 30 21:48:16.292: 1c:e6:2b:cd:da:9d Association received from mobile on BSSID 00:21:a0:e3:fd:be
*apfMsConnTask_7: Jan 30 21:48:16.292: 1c:e6:2b:cd:da:9d Global 200 Clients are allowed to AP radio
*apfMsConnTask_7: Jan 30 21:48:16.292: 1c:e6:2b:cd:da:9d Max Client Trap Threshold: 0 cur: 1
*apfMsConnTask_7: Jan 30 21:48:16.292: 1c:e6:2b:cd:da:9d Rf profile 600 Clients are allowed to AP wlan
*apfMsConnTask_7: Jan 30 21:48:16.293: 1c:e6:2b:cd:da:9d 192.168.165.31 RUN (20) Skipping TMP rule add
*apfMsConnTask_7: Jan 30 21:48:16.293: 1c:e6:2b:cd:da:9d apfMsRunStateDec
*apfMsConnTask_7: Jan 30 21:48:16.293: 1c:e6:2b:cd:da:9d 192.168.165.31 RUN (20) Change state to DHCP_REQD (7) last state RUN (20)
*apfMsConnTask_7: Jan 30 21:48:16.293: 1c:e6:2b:cd:da:9d 0.0.0.0 DHCP_REQD (7) State Update from Mobility-Complete to Mobility-Incomplete
*apfMsConnTask_7: Jan 30 21:48:16.293: 1c:e6:2b:cd:da:9d 0.0.0.0 DHCP_REQD (7) Reached ERROR: from line 6563
*apfMsConnTask_7: Jan 30 21:48:16.293: 1c:e6:2b:cd:da:9d pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.
*apfMsConnTask_7: Jan 30 21:48:16.293: 1c:e6:2b:cd:da:9d 0.0.0.0 DHCP_REQD (7) Deleted mobile LWAPP rule on AP [00:21:a0:e3:fd:b0]
*apfMsConnTask_7: Jan 30 21:48:16.293: 1c:e6:2b:cd:da:9d Applying Interface policy on Mobile, role Unassociated. Ms NAC State 2 Quarantine Vlan 0 Access Vlan 0
*apfMsConnTask_7: Jan 30 21:48:16.293: 1c:e6:2b:cd:da:9d Re-applying interface policy for client
*apfMsConnTask_7: Jan 30 21:48:16.293: 1c:e6:2b:cd:da:9d 0.0.0.0 DHCP_REQD (7) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2202)
*apfMsConnTask_7: Jan 30 21:48:16.293: 1c:e6:2b:cd:da:9d 0.0.0.0 DHCP_REQD (7) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2223)
*apfMsConnTask_7: Jan 30 21:48:16.293: 1c:e6:2b:cd:da:9d apfApplyWlanPolicy: Apply WLAN Policy over PMIPv6 Client Mobility Type
*apfMsConnTask_7: Jan 30 21:48:16.293: 1c:e6:2b:cd:da:9d In processSsidIE:4795 setting Central switched to TRUE
*apfMsConnTask_7: Jan 30 21:48:16.293: 1c:e6:2b:cd:da:9d In processSsidIE:4798 apVapId = 2 and Split Acl Id = 65535
*apfMsConnTask_7: Jan 30 21:48:16.293: 1c:e6:2b:cd:da:9d Applying site-specific Local Bridging override for station 1c:e6:2b:cd:da:9d - vapId 2, site 'default-group', interface 'management'
*apfMsConnTask_7: Jan 30 21:48:16.293: 1c:e6:2b:cd:da:9d Applying Local Bridging Interface Policy for station 1c:e6:2b:cd:da:9d - vlan 0, interface id 0, interface 'management'
*apfMsConnTask_7: Jan 30 21:48:16.293: 1c:e6:2b:cd:da:9d processSsidIE statusCode is 0 and status is 0
*apfMsConnTask_7: Jan 30 21:48:16.293: 1c:e6:2b:cd:da:9d processSsidIE ssid_done_flag is 0 finish_flag is 0
*apfMsConnTask_7: Jan 30 21:48:16.293: 1c:e6:2b:cd:da:9d STA - rates (8): 140 18 152 36 176 72 96 108 12 18 24 96 0 0 0 0
*apfMsConnTask_7: Jan 30 21:48:16.293: 1c:e6:2b:cd:da:9d suppRates statusCode is 0 and gotSuppRatesElement is 1
*apfMsConnTask_7: Jan 30 21:48:16.294: 1c:e6:2b:cd:da:9d Processing RSN IE type 48, length 20 for mobile 1c:e6:2b:cd:da:9d
*apfMsConnTask_7: Jan 30 21:48:16.294: 1c:e6:2b:cd:da:9d Updating AID for REAP AP Client 00:21:a0:e3:fd:b0 - AID ===> 1
*apfMsConnTask_7: Jan 30 21:48:16.294: 1c:e6:2b:cd:da:9d apfMs1xStateDec
*apfMsConnTask_7: Jan 30 21:48:16.294: 1c:e6:2b:cd:da:9d 0.0.0.0 DHCP_REQD (7) Change state to START (0) last state DHCP_REQD (7)
*apfMsConnTask_7: Jan 30 21:48:16.294: 1c:e6:2b:cd:da:9d pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.
*apfMsConnTask_7: Jan 30 21:48:16.294: 1c:e6:2b:cd:da:9d 0.0.0.0 START (0) Initializing policy
*apfMsConnTask_7: Jan 30 21:48:16.294: 1c:e6:2b:cd:da:9d 0.0.0.0 START (0) Change state to AUTHCHECK (2) last state START (0)
*apfMsConnTask_7: Jan 30 21:48:16.294: 1c:e6:2b:cd:da:9d 0.0.0.0 AUTHCHECK (2) Change state to 8021X_REQD (3) last state AUTHCHECK (2)
*apfMsConnTask_7: Jan 30 21:48:16.294: 1c:e6:2b:cd:da:9d Central switch is TRUE
*apfMsConnTask_7: Jan 30 21:48:16.294: 1c:e6:2b:cd:da:9d Not Using WMM Compliance code qosCap 00
*apfMsConnTask_7: Jan 30 21:48:16.294: 1c:e6:2b:cd:da:9d 0.0.0.0 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 00:21:a0:e3:fd:b0 vapId 2 apVapId 2 flex-acl-name:
*apfMsConnTask_7: Jan 30 21:48:16.294: 1c:e6:2b:cd:da:9d apfPemAddUser2 (apf_policy.c:333) Changing state for mobile 1c:e6:2b:cd:da:9d on AP 00:21:a0:e3:fd:b0 from Associated to Associated
*apfMsConnTask_7: Jan 30 21:48:16.294: 1c:e6:2b:cd:da:9d apfPemAddUser2:session timeout forstation 1c:e6:2b:cd:da:9d - Session Tout 1800, apfMsTimeOut '1800' and sessionTimerRunning flag is 0
*apfMsConnTask_7: Jan 30 21:48:16.294: 1c:e6:2b:cd:da:9d Scheduling deletion of Mobile Station: (callerId: 49) in 1800 seconds
*apfMsConnTask_7: Jan 30 21:48:16.294: 1c:e6:2b:cd:da:9d Func: apfPemAddUser2, Ms Timeout = 1800, Session Timeout = 1800
*apfMsConnTask_7: Jan 30 21:48:16.294: 1c:e6:2b:cd:da:9d Sending Assoc Response to station on BSSID 00:21:a0:e3:fd:be (status 0) ApVapId 2 Slot 1
*apfMsConnTask_7: Jan 30 21:48:16.294: 1c:e6:2b:cd:da:9d apfProcessAssocReq (apf_80211.c:8292) Changing state for mobile 1c:e6:2b:cd:da:9d on AP 00:21:a0:e3:fd:b0 from Associated to Associated
*pemReceiveTask: Jan 30 21:48:16.295: 1c:e6:2b:cd:da:9d 0.0.0.0 Removed NPU entry.
*spamApTask7: Jan 30 21:48:16.300: 1c:e6:2b:cd:da:9d Sent 1x initiate message to multi thread task for mobile 1c:e6:2b:cd:da:9d
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.300: 1c:e6:2b:cd:da:9d Creating a PKC PMKID Cache entry for station 1c:e6:2b:cd:da:9d (RSN 2)
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.300: 1c:e6:2b:cd:da:9d Resetting MSCB PMK Cache Entry 0 for station 1c:e6:2b:cd:da:9d
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.300: 1c:e6:2b:cd:da:9d Removing BSSID 00:21:a0:e3:fd:bf from PMKID cache of station 1c:e6:2b:cd:da:9d
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.300: 1c:e6:2b:cd:da:9d Setting active key cache index 0 ---> 8
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.300: 1c:e6:2b:cd:da:9d Setting active key cache index 8 ---> 0
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.300: 1c:e6:2b:cd:da:9d Adding BSSID 00:21:a0:e3:fd:be to PMKID cache at index 0 for station 1c:e6:2b:cd:da:9d
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.300: New PMKID: (16)
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.300: [0000] 8d 8c 79 7d 0e bf 6a 8b 9d e7 ca 24 53 9d eb b5
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.300: 1c:e6:2b:cd:da:9d Initiating RSN PSK to mobile 1c:e6:2b:cd:da:9d
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.300: 1c:e6:2b:cd:da:9d EAP-PARAM Debug - eap-params for Wlan-Id :2 is disabled - applying Global eap timers and retries
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.300: 1c:e6:2b:cd:da:9d dot1x - moving mobile 1c:e6:2b:cd:da:9d into Force Auth state
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.300: 1c:e6:2b:cd:da:9d EAPOL Header:
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.300: 00000000: 02 03 00 5f ..._
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.300: 1c:e6:2b:cd:da:9d Found an cache entry for BSSID 00:21:a0:e3:fd:be in PMKID cache at index 0 of station 1c:e6:2b:cd:da:9d
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.300: 1c:e6:2b:cd:da:9d Found an cache entry for BSSID 00:21:a0:e3:fd:be in PMKID cache at index 0 of station 1c:e6:2b:cd:da:9d
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.300: Including PMKID in M1 (16)
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.301: [0000] 8d 8c 79 7d 0e bf 6a 8b 9d e7 ca 24 53 9d eb b5
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.301: 1c:e6:2b:cd:da:9d Starting key exchange to mobile 1c:e6:2b:cd:da:9d, data packets will be dropped
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.301: 1c:e6:2b:cd:da:9d Sending EAPOL-Key Message to mobile 1c:e6:2b:cd:da:9d
state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.301: 1c:e6:2b:cd:da:9d Sending EAPOL-Key Message to mobile 1c:e6:2b:cd:da:9d
state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.301: 1c:e6:2b:cd:da:9d Allocating EAP Pkt for retransmission to mobile 1c:e6:2b:cd:da:9d
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.301: 1c:e6:2b:cd:da:9d mscb->apfMsLwappLradNhMac = 00:23:33:bc:38:60 mscb->apfMsLradSlotId = 1 mscb->apfMsLradJumbo = 0 mscb->apfMsintIfNum = 1
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.301: 1c:e6:2b:cd:da:9d mscb->apfMsBssid = 00:21:a0:e3:fd:b0 mscb->apfMsAddress = 1c:e6:2b:cd:da:9d mscb->apfMsApVapId = 2
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.301: 1c:e6:2b:cd:da:9d dot1xcb->snapOrg = 00 00 00 dot1xcb->eapolWepBit = 0 mscb->apfMsLwappLradVlanId = 0 mscb->apfMsLwappMwarInet.ipv4.addr = -1062689420
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.301: 1c:e6:2b:cd:da:9d mscb->apfMsLwappMwarPort = 5246 mscb->apfMsLwappLradInet.ipv4.addr = -1062689464 mscb->apfMsLwappLradPort = 50055
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.306: 1c:e6:2b:cd:da:9d Received EAPOL-Key from mobile 1c:e6:2b:cd:da:9d
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.307: 1c:e6:2b:cd:da:9d Received EAPOL-key in PTK_START state (message 2) from mobile 1c:e6:2b:cd:da:9d
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.307: 1c:e6:2b:cd:da:9d Stopping retransmission timer for mobile 1c:e6:2b:cd:da:9d
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.307: 1c:e6:2b:cd:da:9d EAPOL Header:
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.307: 00000000: 02 03 00 5f ..._
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.307: 1c:e6:2b:cd:da:9d Sending EAPOL-Key Message to mobile 1c:e6:2b:cd:da:9d
state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.307: 1c:e6:2b:cd:da:9d Sending EAPOL-Key Message to mobile 1c:e6:2b:cd:da:9d
state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.307: 1c:e6:2b:cd:da:9d Reusing allocated memory for EAP Pkt for retransmission to mobile 1c:e6:2b:cd:da:9d
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.307: 1c:e6:2b:cd:da:9d mscb->apfMsLwappLradNhMac = 00:23:33:bc:38:60 mscb->apfMsLradSlotId = 1 mscb->apfMsLradJumbo = 0 mscb->apfMsintIfNum = 1
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.307: 1c:e6:2b:cd:da:9d mscb->apfMsBssid = 00:21:a0:e3:fd:b0 mscb->apfMsAddress = 1c:e6:2b:cd:da:9d mscb->apfMsApVapId = 2
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.307: 1c:e6:2b:cd:da:9d dot1xcb->snapOrg = 00 00 00 dot1xcb->eapolWepBit = 0 mscb->apfMsLwappLradVlanId = 0 mscb->apfMsLwappMwarInet.ipv4.addr = -1062689420
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.307: 1c:e6:2b:cd:da:9d mscb->apfMsLwappMwarPort = 5246 mscb->apfMsLwappLradInet.ipv4.addr = -1062689464 mscb->apfMsLwappLradPort = 50055
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.310: 1c:e6:2b:cd:da:9d Received EAPOL-Key from mobile 1c:e6:2b:cd:da:9d
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.310: 1c:e6:2b:cd:da:9d Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 1c:e6:2b:cd:da:9d
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.310: 1c:e6:2b:cd:da:9d Stopping retransmission timer for mobile 1c:e6:2b:cd:da:9d
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.310: 1c:e6:2b:cd:da:9d Freeing EAP Retransmit Bufer for mobile 1c:e6:2b:cd:da:9d
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.310: 1c:e6:2b:cd:da:9d apfMs1xStateInc
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.310: 1c:e6:2b:cd:da:9d 0.0.0.0 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state 8021X_REQD (3)
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.310: 1c:e6:2b:cd:da:9d Central switch is TRUE
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.310: 1c:e6:2b:cd:da:9d Not Using WMM Compliance code qosCap 00
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.310: 1c:e6:2b:cd:da:9d 0.0.0.0 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 00:21:a0:e3:fd:b0 vapId 2 apVapId 2 flex-acl-name:
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.310: 1c:e6:2b:cd:da:9d 0.0.0.0 L2AUTHCOMPLETE (4) Change state to DHCP_REQD (7) last state L2AUTHCOMPLETE (4)
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.310: 1c:e6:2b:cd:da:9d 0.0.0.0 DHCP_REQD (7) pemAdvanceState2 6157, Adding TMP rule
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.310: 1c:e6:2b:cd:da:9d 0.0.0.0 DHCP_REQD (7) Adding Fast Path rule
type = Airespace AP - Learn IP address
on AP 00:21:a0:e3:fd:b0, slot 1, interface = 1, QOS = 0
IPv4 ACL ID = 255, IPv
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.310: 1c:e6:2b:cd:da:9d 0.0.0.0 DHCP_REQD (7) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 15206 Local Bridging Vlan = 0, Local Bridging intf id = 0
*Dot1x_NW_MsgTask_5: Jan 30 21:48:16.310: 1c:e6:2b:cd:da:9d 0.0.0.0 DHCP_REQD (7) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255, L2 ACL ID 255)
*apfReceiveTask: Jan 30 21:48:16.311: 1c:e6:2b:cd:da:9d 0.0.0.0 DHCP_REQD (7) State Update from Mobility-Incomplete to Mobility-Complete, mobility role=Local, client state=APF_MS_STATE_ASSOCIATED
*apfReceiveTask: Jan 30 21:48:16.311: 1c:e6:2b:cd:da:9d 0.0.0.0 DHCP_REQD (7) pemAdvanceState2 5752, Adding TMP rule
*apfReceiveTask: Jan 30 21:48:16.311: 1c:e6:2b:cd:da:9d 0.0.0.0 DHCP_REQD (7) Replacing Fast Path rule
type = Airespace AP - Learn IP address
on AP 00:21:a0:e3:fd:b0, slot 1, interface = 1, QOS = 0
IPv4 ACL ID = 255,
*apfReceiveTask: Jan 30 21:48:16.311: 1c:e6:2b:cd:da:9d 0.0.0.0 DHCP_REQD (7) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 15206 Local Bridging Vlan = 0, Local Bridging intf id = 0
*apfReceiveTask: Jan 30 21:48:16.311: 1c:e6:2b:cd:da:9d 0.0.0.0 DHCP_REQD (7) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255, L2 ACL ID 255)
*pemReceiveTask: Jan 30 21:48:16.311: 1c:e6:2b:cd:da:9d 0.0.0.0 Added NPU entry of type 9, dtlFlags 0x0
*pemReceiveTask: Jan 30 21:48:16.311: 1c:e6:2b:cd:da:9d 0.0.0.0 Added NPU entry of type 9, dtlFlags 0x0
*pemReceiveTask: Jan 30 21:48:16.311: 1c:e6:2b:cd:da:9d Sent an XID frame
*IPv6_Msg_Task: Jan 30 21:48:16.312: 1c:e6:2b:cd:da:9d Pushing IPv6 Vlan Intf ID 0: fe80:0000:0000:0000:1ee6:2bff:fecd:da9d , and MAC: 1C:E6:2B:CD:DA:9D , Binding to Data Plane. SUCCESS !! dhcpv6bitmap 0
*IPv6_Msg_Task: Jan 30 21:48:16.312: 1c:e6:2b:cd:da:9d Link Local address fe80::1ee6:2bff:fecd:da9d updated to mscb. Not Advancing pem state.Current state: mscb in apfMsMmInitial mobility state and client state APF_MS_STATE_A
*DHCP Socket Task: Jan 30 21:48:16.322: 1c:e6:2b:cd:da:9d DHCP received op BOOTREQUEST (1) (len 308,vlan 0, port 1, encap 0xec03)
*DHCP Socket Task: Jan 30 21:48:16.322: 1c:e6:2b:cd:da:9d DHCP (encap type 0xec03) mstype 0ff:ff:ff:ff:ff:ff
*DHCP Socket Task: Jan 30 21:48:16.322: 1c:e6:2b:cd:da:9d DHCP selecting relay 1 - control block settings:
dhcpServer: 0.0.0.0, dhcpNetmask: 0.0.0.0,
dhcpGateway: 0.0.0.0, dhcpRelay: 0.0.0.0 VLAN: 0
*DHCP Socket Task: Jan 30 21:48:16.322: 1c:e6:2b:cd:da:9d DHCP selected relay 1 - 192.168.165.13 (local address 192.168.165.116, gateway 192.168.165.13, VLAN 0, port 1)
*DHCP Socket Task: Jan 30 21:48:16.322: 1c:e6:2b:cd:da:9d DHCP transmitting DHCP REQUEST (3)
*DHCP Socket Task: Jan 30 21:48:16.322: 1c:e6:2b:cd:da:9d DHCP op: BOOTREQUEST, htype: Ethernet, hlen: 6, hops: 1
*DHCP Socket Task: Jan 30 21:48:16.322: 1c:e6:2b:cd:da:9d DHCP xid: 0xa747e37c (2806506364), secs: 0, flags: 0
*DHCP Socket Task: Jan 30 21:48:16.322: 1c:e6:2b:cd:da:9d DHCP chaddr: 1c:e6:2b:cd:da:9d
*DHCP Socket Task: Jan 30 21:48:16.322: 1c:e6:2b:cd:da:9d DHCP ciaddr: 0.0.0.0, yiaddr: 0.0.0.0
*DHCP Socket Task: Jan 30 21:48:16.322: 1c:e6:2b:cd:da:9d DHCP siaddr: 0.0.0.0, giaddr: 192.168.165.116
*DHCP Socket Task: Jan 30 21:48:16.322: 1c:e6:2b:cd:da:9d DHCP requested ip: 192.168.165.31
*DHCP Socket Task: Jan 30 21:48:16.322: 1c:e6:2b:cd:da:9d DHCP sending REQUEST to 192.168.165.13 (len 346, port 1, vlan 0)
*DHCP Socket Task: Jan 30 21:48:16.322: 1c:e6:2b:cd:da:9d DHCP selecting relay 2 - control block settings:
dhcpServer: 0.0.0.0, dhcpNetmask: 0.0.0.0,
dhcpGateway: 0.0.0.0, dhcpRelay: 192.168.165.116 VLAN: 0
*DHCP Socket Task: Jan 30 21:48:16.322: 1c:e6:2b:cd:da:9d DHCP selected relay 2 - NONE (server address 0.0.0.0,local address 0.0.0.0, gateway 192.168.165.1, VLAN 0, port 1)
*DHCP Socket Task: Jan 30 21:48:16.323: 1c:e6:2b:cd:da:9d DHCP received op BOOTREPLY (2) (len 308,vlan 0, port 1, encap 0xec00)
*DHCP Socket Task: Jan 30 21:48:16.323: 1c:e6:2b:cd:da:9d DHCP setting server from ACK (server 192.168.165.13, yiaddr 192.168.165.31)
*DHCP Socket Task: Jan 30 21:48:16.324: 1c:e6:2b:cd:da:9d Static IP client associated to interface management which can support client subnet.
*DHCP Socket Task: Jan 30 21:48:16.324: 1c:e6:2b:cd:da:9d apfMsRunStateInc
*DHCP Socket Task: Jan 30 21:48:16.324: 1c:e6:2b:cd:da:9d 192.168.165.31 DHCP_REQD (7) Change state to RUN (20) last state DHCP_REQD (7)
*DHCP Socket Task: Jan 30 21:48:16.324: 1c:e6:2b:cd:da:9d 192.168.165.31 RUN (20) Reached PLUMBFASTPATH: from line 6822
*DHCP Socket Task: Jan 30 21:48:16.324: 1c:e6:2b:cd:da:9d 192.168.165.31 RUN (20) Replacing Fast Path rule
type = Airespace AP Client
on AP 00:21:a0:e3:fd:b0, slot 1, interface = 1, QOS = 0
IPv4 ACL ID = 255, IPv6 ACL I
*DHCP Socket Task: Jan 30 21:48:16.324: 1c:e6:2b:cd:da:9d 192.168.165.31 RUN (20) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 15206 Local Bridging Vlan = 0, Local Bridging intf id = 0
*DHCP Socket Task: Jan 30 21:48:16.324: 1c:e6:2b:cd:da:9d 192.168.165.31 RUN (20) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255, L2 ACL ID 255)
*DHCP Socket Task: Jan 30 21:48:16.324: 1c:e6:2b:cd:da:9d Assigning Address 192.168.165.31 to mobile
*DHCP Socket Task: Jan 30 21:48:16.324: 1c:e6:2b:cd:da:9d DHCP success event for client. Clearing dhcp failure count for interface management.
*DHCP Socket Task: Jan 30 21:48:16.324: 1c:e6:2b:cd:da:9d DHCP success event for client. Clearing dhcp failure count for interface management.
*DHCP Socket Task: Jan 30 21:48:16.324: 1c:e6:2b:cd:da:9d DHCP sending REPLY to STA (len 414, port 1, vlan 0)
*DHCP Socket Task: Jan 30 21:48:16.324: 1c:e6:2b:cd:da:9d DHCP transmitting DHCP ACK (5)
*DHCP Socket Task: Jan 30 21:48:16.324: 1c:e6:2b:cd:da:9d DHCP op: BOOTREPLY, htype: Ethernet, hlen: 6, hops: 0
*DHCP Socket Task: Jan 30 21:48:16.324: 1c:e6:2b:cd:da:9d DHCP xid: 0xa747e37c (2806506364), secs: 0, flags: 0
*DHCP Socket Task: Jan 30 21:48:16.324: 1c:e6:2b:cd:da:9d DHCP chaddr: 1c:e6:2b:cd:da:9d
*DHCP Socket Task: Jan 30 21:48:16.324: 1c:e6:2b:cd:da:9d DHCP ciaddr: 0.0.0.0, yiaddr: 192.168.165.31
*DHCP Socket Task: Jan 30 21:48:16.324: 1c:e6:2b:cd:da:9d DHCP siaddr: 0.0.0.0, giaddr: 0.0.0.0
*DHCP Socket Task: Jan 30 21:48:16.324: 1c:e6:2b:cd:da:9d DHCP server id: 1.1.1.1 rcvd server id: 192.168.165.13
*pemReceiveTask: Jan 30 21:48:16.325: 1c:e6:2b:cd:da:9d 192.168.165.31 Added NPU entry of type 1, dtlFlags 0x0
*pemReceiveTask: Jan 30 21:48:16.325: 1c:e6:2b:cd:da:9d Pushing IPv6: fe80:0000:0000:0000:1ee6:2bff:fecd:da9d , and MAC: 1C:E6:2B:CD:DA:9D , Binding to Data Plane. SUCCESS !!
*pemReceiveTask: Jan 30 21:48:16.325: 1c:e6:2b:cd:da:9d Sending a gratuitous ARP for 192.168.165.31, VLAN Id 0
*IPv6_Msg_Task: Jan 30 21:48:16.328: 1c:e6:2b:cd:da:9d Link Local address fe80::1ee6:2bff:fecd:da9d updated to mscb. Not Advancing pem state.Current state: mscb in apfMsMmInitial mobility state and client state APF_MS_STATE_A
(jk-2504-116) >
(jk-2504-116) >show client summary
Number of Clients................................ 1
RLAN/
MAC Address AP Name Slot Status WLAN Auth Protocol Port Wired PMIPV6 Role
----------------- ----------------- ---- ------------- ----- ---- ---------------- ---- ----- ------ ----------------
1c:e6:2b:cd:da:9d 1131-17 1 Associated 2 Yes 802.11a 1 N/A No Local
Ipad Console Log:
Jan 30 16:54:36 iPadMini5 profiled[176] <Notice>: (Note ) profiled: Service starting...
Jan 30 16:54:37 iPadMini5 timed[16] <Notice>: (Note ) CoreTime: Received timezone "America/New_York" from "Location"
Jan 30 16:54:37 iPadMini5 timed[16] <Notice>: (Note ) CoreTime: Current mcc: '0' simulated:'0'.
Jan 30 16:54:37 iPadMini5 timed[16] <Notice>: (Note ) CoreTime: Not setting time zone to America/New_York from Location
Jan 30 16:54:46 iPadMini5 Preferences[153] <Warning>: -[APOtherNetworkController keyboardWillShow:]
Jan 30 16:54:51 iPadMini5 Preferences[153] <Warning>: -[VPNConnectionStore reloadVPN]: The active VPN configuration has changed from to (null)
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: 018086.633816 wlan.N[11476] AppleBCMWLANCore::setDISASSOCIATE(): [wifid]:
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: 018086.657909 wlan.N[11477] AppleBCMWLAN Left BSS: @ 0x8102e600, BSSID = 00:21:a0:e3:fd:bf, rssi = -57, rate = 54 (100%), channel = 161, encryption = 0x8, ap = 1, failures = 0, age = 13, ssid[ 6] = "apple1"
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: 018086.657976 wlan.A[11478] AppleBCMWLANCore::deleteAllPktFilters(): Deleted IPv4/IPv6 and Magic packet filters
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: AirPort: Link Down on en0. Reason 1 (Unspecified).
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: en0::stopOutputQueues
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: IO80211PeerManager::doDisable
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: en0::IO80211Interface::postMessage bssid changed
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: IO80211AWDLPeerManager::interfaceStateChange() reason Interface _enablingSynch 0 _syncState 0 force 0 num services 0 _infraChannel 0
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: IO80211AWDLPeerManager::interfaceStateChange() _enablingSynch 0 _syncState 0 -> quit
Jan 30 16:54:51 iPadMini5 Preferences[153] <Warning>: -[VPNBundleController _vpnConfigurationChanged:] (0x20093900:<VPNBundleController: 0x20093900>): _serviceCount(0), serviceCount(0), toggleInRootMenu(0), RootMenuItem(1)
Jan 30 16:54:51 iPadMini5 configd[49] <Notice>: LINKLOCAL en0: parent has no IP
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: IO80211AWDLPeerManager::setJoiningState disabling sync for association attempt
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: 018086.767177 wlan.N[11479] AppleBCMWLANCore::setASSOCIATE(): [wifid]: lowerAuth = AUTHTYPE_OPEN, upperAuth = AUTHTYPE_WPA2_PSK, key = CIPHER_PMK .
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: 018086.779680 wlan.N[11480] virtual SInt32 AppleBCMWLANCore::setupCountryCode(): AutoCountry:1, fDefaultCountryCode:XZ, fCurrentCountryCode:
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: 018086.816329 wlan.A[11481] AppleBCMWLANNetManager::prepareToBringUpLink(): Delaying powersave entry in order to get an IP address
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: 018086.816442 wlan.N[11482] AppleBCMWLAN Joined BSS: @ 0x80c99800, BSSID = 00:21:a0:e3:fd:be, rssi = -53, rate = 54 (100%), channel = 161, encryption = 0x8, ap = 1, failures = 0, age = 11, ssid[ 6] = "apple2"
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: AirPort: Link Up on en0
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: en0::startOutputQueues (0)
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: IO80211PeerManager::doEnable
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: en0: BSSID changed to 00:21:a0:e3:fd:be
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: en0::IO80211Interface::postMessage bssid changed
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: IO80211AWDLPeerManager::interfaceStateChange() reason Interface _enablingSynch 0 _syncState 0 force 0 num services 0 _infraChannel 0
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: IO80211AWDLPeerManager::interfaceStateChange() _enablingSynch 0 _syncState 0 -> quit
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: en0: BSSID changed to 00:21:a0:e3:fd:be
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: en0::IO80211Interface::postMessage bssid changed
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: IO80211AWDLPeerManager::interfaceStateChange() reason Interface _enablingSynch 0 _syncState 0 force 0 num services 0 _infraChannel 0
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: IO80211AWDLPeerManager::interfaceStateChange() _enablingSynch 0 _syncState 0 -> quit
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: 018086.828541 wlan.N[11483] AppleBCMWLANCore:startRoamScan(): 3365 Delaying RoamScan; because Join Mgr Busy 1 isWaitingforIP 1
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: 018086.833042 wlan.N[11484] AppleBCMWLANJoinManager::handleSupplicantEvent(): status = 6, reason = 0, flags = 0x0, authtype = 0, addr = 00:00:00:00:00:00
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: IO80211Peer::queuePacket ff:ff:ff:ff:ff:ff alllocate queue for ac 0
Jan 30 16:54:51 iPadMini5 configd[49] <Notice>: network changed: Proxy
Jan 30 16:54:52 iPadMini5 Preferences[153] <Warning>: WiFi: Joined apple2
Jan 30 16:54:52 iPadMini5 Preferences[153] <Warning>: -[VPNConnectionStore reloadVPN]: The active VPN configuration has changed from to (null)
Jan 30 16:54:52 iPadMini5 Preferences[153] <Warning>: -[VPNBundleController _vpnConfigurationChanged:] (0x20093900:<VPNBundleController: 0x20093900>): _serviceCount(0), serviceCount(0), toggleInRootMenu(0), RootMenuItem(1)
Jan 30 16:54:53 iPadMini5 kernel[0] <Debug>: 018087.969499 wlan.A[11485] AppleBCMWLANNetManager::receivedIPv4Address(): Received address 192.168.165.31, entering powersave mode 2
Jan 30 16:54:53 iPadMini5 kernel[0] <Debug>: 018087.969603 wlan.N[11486] AppleBCMWLANCore:startRoamScan(): 3379 starting RoamScan; MultiAPEnv:0 isdualBand:1 isOn5G:1
Jan 30 16:54:53 iPadMini5 configd[49] <Notice>: network changed: Proxy
Jan 30 16:54:57 iPadMini5 networkd[69] <Error>: client_connection_cellular_start no interface match
Jan 30 16:55:52 iPadMini5 profiled[176] <Notice>: (Note ) profiled: Idled.
Jan 30 16:55:52 iPadMini5 profiled[176] <Notice>: (Note ) profiled: Service stopping.
Ipad Console
Jan 30 16:54:36 iPadMini5 profiled[176] <Notice>: (Note ) profiled: Service starting...
Jan 30 16:54:37 iPadMini5 timed[16] <Notice>: (Note ) CoreTime: Received timezone "America/New_York" from "Location"
Jan 30 16:54:37 iPadMini5 timed[16] <Notice>: (Note ) CoreTime: Current mcc: '0' simulated:'0'.
Jan 30 16:54:37 iPadMini5 timed[16] <Notice>: (Note ) CoreTime: Not setting time zone to America/New_York from Location
Jan 30 16:54:46 iPadMini5 Preferences[153] <Warning>: -[APOtherNetworkController keyboardWillShow:]
Jan 30 16:54:51 iPadMini5 Preferences[153] <Warning>: -[VPNConnectionStore reloadVPN]: The active VPN configuration has changed from to (null)
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: 018086.633816 wlan.N[11476] AppleBCMWLANCore::setDISASSOCIATE(): [wifid]:
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: 018086.657909 wlan.N[11477] AppleBCMWLAN Left BSS: @ 0x8102e600, BSSID = 00:21:a0:e3:fd:bf, rssi = -57, rate = 54 (100%), channel = 161, encryption = 0x8, ap = 1, failures = 0, age = 13, ssid[ 6] = "apple1"
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: 018086.657976 wlan.A[11478] AppleBCMWLANCore::deleteAllPktFilters(): Deleted IPv4/IPv6 and Magic packet filters
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: AirPort: Link Down on en0. Reason 1 (Unspecified).
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: en0::stopOutputQueues
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: IO80211PeerManager::doDisable
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: en0::IO80211Interface::postMessage bssid changed
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: IO80211AWDLPeerManager::interfaceStateChange() reason Interface _enablingSynch 0 _syncState 0 force 0 num services 0 _infraChannel 0
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: IO80211AWDLPeerManager::interfaceStateChange() _enablingSynch 0 _syncState 0 -> quit
Jan 30 16:54:51 iPadMini5 Preferences[153] <Warning>: -[VPNBundleController _vpnConfigurationChanged:] (0x20093900:<VPNBundleController: 0x20093900>): _serviceCount(0), serviceCount(0), toggleInRootMenu(0), RootMenuItem(1)
Jan 30 16:54:51 iPadMini5 configd[49] <Notice>: LINKLOCAL en0: parent has no IP
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: IO80211AWDLPeerManager::setJoiningState disabling sync for association attempt
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: 018086.767177 wlan.N[11479] AppleBCMWLANCore::setASSOCIATE(): [wifid]: lowerAuth = AUTHTYPE_OPEN, upperAuth = AUTHTYPE_WPA2_PSK, key = CIPHER_PMK .
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: 018086.779680 wlan.N[11480] virtual SInt32 AppleBCMWLANCore::setupCountryCode(): AutoCountry:1, fDefaultCountryCode:XZ, fCurrentCountryCode:
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: 018086.816329 wlan.A[11481] AppleBCMWLANNetManager::prepareToBringUpLink(): Delaying powersave entry in order to get an IP address
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: 018086.816442 wlan.N[11482] AppleBCMWLAN Joined BSS: @ 0x80c99800, BSSID = 00:21:a0:e3:fd:be, rssi = -53, rate = 54 (100%), channel = 161, encryption = 0x8, ap = 1, failures = 0, age = 11, ssid[ 6] = "apple2"
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: AirPort: Link Up on en0
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: en0::startOutputQueues (0)
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: IO80211PeerManager::doEnable
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: en0: BSSID changed to 00:21:a0:e3:fd:be
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: en0::IO80211Interface::postMessage bssid changed
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: IO80211AWDLPeerManager::interfaceStateChange() reason Interface _enablingSynch 0 _syncState 0 force 0 num services 0 _infraChannel 0
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: IO80211AWDLPeerManager::interfaceStateChange() _enablingSynch 0 _syncState 0 -> quit
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: en0: BSSID changed to 00:21:a0:e3:fd:be
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: en0::IO80211Interface::postMessage bssid changed
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: IO80211AWDLPeerManager::interfaceStateChange() reason Interface _enablingSynch 0 _syncState 0 force 0 num services 0 _infraChannel 0
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: IO80211AWDLPeerManager::interfaceStateChange() _enablingSynch 0 _syncState 0 -> quit
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: 018086.828541 wlan.N[11483] AppleBCMWLANCore:startRoamScan(): 3365 Delaying RoamScan; because Join Mgr Busy 1 isWaitingforIP 1
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: 018086.833042 wlan.N[11484] AppleBCMWLANJoinManager::handleSupplicantEvent(): status = 6, reason = 0, flags = 0x0, authtype = 0, addr = 00:00:00:00:00:00
Jan 30 16:54:51 iPadMini5 kernel[0] <Debug>: IO80211Peer::queuePacket ff:ff:ff:ff:ff:ff alllocate queue for ac 0
Jan 30 16:54:51 iPadMini5 configd[49] <Notice>: network changed: Proxy
Jan 30 16:54:52 iPadMini5 Preferences[153] <Warning>: WiFi: Joined apple2
Jan 30 16:54:52 iPadMini5 Preferences[153] <Warning>: -[VPNConnectionStore reloadVPN]: The active VPN configuration has changed from to (null)
Jan 30 16:54:52 iPadMini5 Preferences[153] <Warning>: -[VPNBundleController _vpnConfigurationChanged:] (0x20093900:<VPNBundleController: 0x20093900>): _serviceCount(0), serviceCount(0), toggleInRootMenu(0), RootMenuItem(1)
Jan 30 16:54:53 iPadMini5 kernel[0] <Debug>: 018087.969499 wlan.A[11485] AppleBCMWLANNetManager::receivedIPv4Address(): Received address 192.168.165.31, entering powersave mode 2
Jan 30 16:54:53 iPadMini5 kernel[0] <Debug>: 018087.969603 wlan.N[11486] AppleBCMWLANCore:startRoamScan(): 3379 starting RoamScan; MultiAPEnv:0 isdualBand:1 isOn5G:1
Jan 30 16:54:53 iPadMini5 configd[49] <Notice>: network changed: Proxy
Jan 30 16:54:57 iPadMini5 networkd[69] <Error>: client_connection_cellular_start no interface match
Jan 30 16:55:52 iPadMini5 profiled[176] <Notice>: (Note ) profiled: Idled.
Jan 30 16:55:52 iPadMini5 profiled[176] <Notice>: (Note ) profiled: Service stopping.
