We help IT Professionals succeed at work.
Get Started

Cisco vWLC DHCP issues

1,921 Views
Last Modified: 2017-03-08
For my setup I have a Cisco vWLC on a VMware vSphere machine, flexconnect enabled and a dhcp server specified. I can get my Win 10 laptop to connect to my test AP, but I can't get a DHCP address. After I'm connected I try an ipconfig /release /renew and I get a "unable to connect to your DHCP server".

The debug output from my laptop in the act of connecting to the AP, requesting DHCP, not getting DHCP, then me running the ipconfig /release /renew is below. Any help is appreciated.

(Cisco Controller) >*DHCP Socket Task: Mar 07 11:23:56.650: b4:ae:2b:ed:2c:9a DHCP received op BOOTREPLY (2) (len 334,<management VLAN #>, port 1, encap 0xec03)
*DHCP Socket Task: Mar 07 11:23:56.650: b4:ae:2b:ed:2c:9a DHCP processing DHCP ACK (5)
*DHCP Socket Task: Mar 07 11:23:56.650: b4:ae:2b:ed:2c:9a DHCP   op: BOOTREPLY, htype: Ethernet, hlen: 6, hops: 0
*DHCP Socket Task: Mar 07 11:23:56.650: b4:ae:2b:ed:2c:9a DHCP   xid: 0x3bd7043b (1003947067), secs: 0, flags: 0
*DHCP Socket Task: Mar 07 11:23:56.650: b4:ae:2b:ed:2c:9a DHCP   chaddr: b4:ae:2b:ed:2c:9a
*DHCP Socket Task: Mar 07 11:23:56.650: b4:ae:2b:ed:2c:9a DHCP   ciaddr: 0.0.0.0,  yiaddr: <valid wireless VLAN address>
*DHCP Socket Task: Mar 07 11:23:56.650: b4:ae:2b:ed:2c:9a DHCP   siaddr: 0.0.0.0,  giaddr: 0.0.0.0
*DHCP Socket Task: Mar 07 11:23:56.650: b4:ae:2b:ed:2c:9a DHCP   server id: <wireless VLAN DHCP address>  rcvd server id: <wireless VLAN DHCP address>
*DHCP Socket Task: Mar 07 11:23:56.655: b4:ae:2b:ed:2c:9a DHCP received op BOOTREPLY (2) (len 334,<management VLAN #>, port 1, encap 0xec03)
*DHCP Socket Task: Mar 07 11:23:56.655: b4:ae:2b:ed:2c:9a DHCP processing DHCP ACK (5)
*DHCP Socket Task: Mar 07 11:23:56.655: b4:ae:2b:ed:2c:9a DHCP   op: BOOTREPLY, htype: Ethernet, hlen: 6, hops: 0
*DHCP Socket Task: Mar 07 11:23:56.655: b4:ae:2b:ed:2c:9a DHCP   xid: 0x3bd7043b (1003947067), secs: 0, flags: 80
*DHCP Socket Task: Mar 07 11:23:56.655: b4:ae:2b:ed:2c:9a DHCP   chaddr: b4:ae:2b:ed:2c:9a
*DHCP Socket Task: Mar 07 11:23:56.656: b4:ae:2b:ed:2c:9a DHCP   ciaddr: 0.0.0.0,  yiaddr: <valid wireless VLAN address>
*DHCP Socket Task: Mar 07 11:23:56.656: b4:ae:2b:ed:2c:9a DHCP   siaddr: 0.0.0.0,  giaddr: <wireless VLAN interface address>
*DHCP Socket Task: Mar 07 11:23:56.656: b4:ae:2b:ed:2c:9a DHCP   server id: <wireless VLAN DHCP address>  rcvd server id: <wireless VLAN DHCP address>
*apfMsConnTask_3: Mar 07 11:24:04.296: b4:ae:2b:ed:2c:9a Processing assoc-req station:b4:ae:2b:ed:2c:9a AP:80:e8:6f:1e:da:80-00 thread:548c7a0
*apfMsConnTask_3: Mar 07 11:24:04.296: b4:ae:2b:ed:2c:9a Association received from mobile on BSSID 80:e8:6f:1e:da:cf AP AP80e0.1dfe.311b
*apfMsConnTask_3: Mar 07 11:24:04.297: b4:ae:2b:ed:2c:9a Global 200 Clients are allowed to AP radio

*apfMsConnTask_3: Mar 07 11:24:04.297: b4:ae:2b:ed:2c:9a Max Client Trap Threshold: 0  cur: 1

*apfMsConnTask_3: Mar 07 11:24:04.297: b4:ae:2b:ed:2c:9a Rf profile 600 Clients are allowed to AP wlan

*apfMsConnTask_3: Mar 07 11:24:04.297: b4:ae:2b:ed:2c:9a override for default ap group, marking intgrp NULL
*apfMsConnTask_3: Mar 07 11:24:04.297: b4:ae:2b:ed:2c:9a Applying Interface policy on Mobile, role Local. Ms NAC State 2 Quarantine Vlan 0 Access <wireless VLAN>

*apfMsConnTask_3: Mar 07 11:24:04.297: b4:ae:2b:ed:2c:9a Re-applying interface policy for client

*apfMsConnTask_3: Mar 07 11:24:04.298: b4:ae:2b:ed:2c:9a <valid wireless VLAN address> RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2399)
*apfMsConnTask_3: Mar 07 11:24:04.298: b4:ae:2b:ed:2c:9a <valid wireless VLAN address> RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2420)
*apfMsConnTask_3: Mar 07 11:24:04.298: b4:ae:2b:ed:2c:9a apfApplyWlanPolicy: Apply WLAN Policy over PMIPv6 Client Mobility Type
*apfMsConnTask_3: Mar 07 11:24:04.298: b4:ae:2b:ed:2c:9a In processSsidIE:5733 setting Central switched to FALSE
*apfMsConnTask_3: Mar 07 11:24:04.298: b4:ae:2b:ed:2c:9a Set Clinet MSCB as Central Association Disabled
*apfMsConnTask_3: Mar 07 11:24:04.298: b4:ae:2b:ed:2c:9a Setting the NAS Id to WLAN specific Id '<vWLC system name>'
*apfMsConnTask_3: Mar 07 11:24:04.299: b4:ae:2b:ed:2c:9a Applying site-specific Local Bridging override for station b4:ae:2b:ed:2c:9a - vapId 80, site '<AP group name>', interface '<wireless interface name>'
*apfMsConnTask_3: Mar 07 11:24:04.299: b4:ae:2b:ed:2c:9a Applying Local Bridging Interface Policy for station b4:ae:2b:ed:2c:9a - <wireless VLAN>, interface id 5, interface '<wireless interface name>'
*apfMsConnTask_3: Mar 07 11:24:04.299: b4:ae:2b:ed:2c:9a override from ap group, removing intf group from mscb
*apfMsConnTask_3: Mar 07 11:24:04.299: b4:ae:2b:ed:2c:9a Applying site-specific override for station b4:ae:2b:ed:2c:9a - vapId 80, site '<AP group name>', interface '<wireless interface name>'
*apfMsConnTask_3: Mar 07 11:24:04.299: b4:ae:2b:ed:2c:9a Applying Interface policy on Mobile, role Local. Ms NAC State 2 Quarantine Vlan 0 Access <management VLAN #>

*apfMsConnTask_3: Mar 07 11:24:04.299: b4:ae:2b:ed:2c:9a Re-applying interface policy for client

*apfMsConnTask_3: Mar 07 11:24:04.299: b4:ae:2b:ed:2c:9a <valid wireless VLAN address> RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2399)
*apfMsConnTask_3: Mar 07 11:24:04.299: b4:ae:2b:ed:2c:9a <valid wireless VLAN address> RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2420)
*apfMsConnTask_3: Mar 07 11:24:04.299: b4:ae:2b:ed:2c:9a Set Clinet Non AP specific apfMsAccessVlan = <wireless VLAN>
*apfMsConnTask_3: Mar 07 11:24:04.300: b4:ae:2b:ed:2c:9a This apfMsAccessVlan may be changed later from AAA after L2 Auth
*apfMsConnTask_3: Mar 07 11:24:04.300: b4:ae:2b:ed:2c:9a processSsidIE  statusCode is 0 and status is 0
*apfMsConnTask_3: Mar 07 11:24:04.300: b4:ae:2b:ed:2c:9a processSsidIE  ssid_done_flag is 0 finish_flag is 0
*apfMsConnTask_3: Mar 07 11:24:04.300: b4:ae:2b:ed:2c:9a STA - rates (8): 2 4 11 22 12 18 24 36 48 72 96 108 0 0 0 0
*apfMsConnTask_3: Mar 07 11:24:04.300: b4:ae:2b:ed:2c:9a suppRates  statusCode is 0 and gotSuppRatesElement is 1
*apfMsConnTask_3: Mar 07 11:24:04.300: b4:ae:2b:ed:2c:9a STA - rates (12): 2 4 11 22 12 18 24 36 48 72 96 108 0 0 0 0
*apfMsConnTask_3: Mar 07 11:24:04.300: b4:ae:2b:ed:2c:9a extSuppRates  statusCode is 0 and gotExtSuppRatesElement is 1
*apfMsConnTask_3: Mar 07 11:24:04.301: RSNIE in Assoc. Req.: (20)

*apfMsConnTask_3: Mar 07 11:24:04.301:      [0000] 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f

*apfMsConnTask_3: Mar 07 11:24:04.301:      [0016] ac 01 00 00

*apfMsConnTask_3: Mar 07 11:24:04.301: b4:ae:2b:ed:2c:9a Processing RSN IE type 48, length 20 for mobile b4:ae:2b:ed:2c:9a
*apfMsConnTask_3: Mar 07 11:24:04.301: b4:ae:2b:ed:2c:9a Received 802.11i 802.1X key management suite, enabling dot1x Authentication
*apfMsConnTask_3: Mar 07 11:24:04.301: b4:ae:2b:ed:2c:9a RSN Capabilities:  0
*apfMsConnTask_3: Mar 07 11:24:04.301: b4:ae:2b:ed:2c:9a apfValidateDot11iCapabilities:1286 Received RSNIE with Capabilities with STA MFPC: 0, STA MFPR:0, & AP MFPC:0MFPR:0
*apfMsConnTask_3: Mar 07 11:24:04.301: b4:ae:2b:ed:2c:9a Marking Mobile as non-11w Capable
*apfMsConnTask_3: Mar 07 11:24:04.301: b4:ae:2b:ed:2c:9a Received RSN IE with 0 PMKIDs from mobile b4:ae:2b:ed:2c:9a
*apfMsConnTask_3: Mar 07 11:24:04.301: b4:ae:2b:ed:2c:9a Found an cache entry for BSSID 80:e8:6f:1e:da:80 in PMKID cache at index 0 of station b4:ae:2b:ed:2c:9a
*apfMsConnTask_3: Mar 07 11:24:04.302: b4:ae:2b:ed:2c:9a Removing BSSID 80:e8:6f:1e:da:80 from PMKID cache of station b4:ae:2b:ed:2c:9a
*apfMsConnTask_3: Mar 07 11:24:04.302: b4:ae:2b:ed:2c:9a Resetting MSCB PMK Cache Entry 0 for station b4:ae:2b:ed:2c:9a
*apfMsConnTask_3: Mar 07 11:24:04.302: b4:ae:2b:ed:2c:9a Setting active key cache index 0 ---> 8
*apfMsConnTask_3: Mar 07 11:24:04.302: b4:ae:2b:ed:2c:9a unsetting PmkIdValidatedByAp
*apfMsConnTask_3: Mar 07 11:24:04.302: b4:ae:2b:ed:2c:9a apfValidateDot11wGroupMgmtCipher:1716, Received NULL 11w Group Mgmt Cipher Suite for STA, hence returning

*apfMsConnTask_3: Mar 07 11:24:04.302: b4:ae:2b:ed:2c:9a AID 1 in Assoc Req from flex AP 80:e8:6f:1e:da:80 is same as in mscb b4:ae:2b:ed:2c:9a
*apfMsConnTask_3: Mar 07 11:24:04.302: b4:ae:2b:ed:2c:9a apfMsRunStateDec
*apfMsConnTask_3: Mar 07 11:24:04.303: b4:ae:2b:ed:2c:9a apfMs1xStateDec
*apfMsConnTask_3: Mar 07 11:24:04.303: b4:ae:2b:ed:2c:9a <valid wireless VLAN address> RUN (20) Change state to START (0) last state RUN (20)

*apfMsConnTask_3: Mar 07 11:24:04.303: b4:ae:2b:ed:2c:9a pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.
*apfMsConnTask_3: Mar 07 11:24:04.303: b4:ae:2b:ed:2c:9a <valid wireless VLAN address> START (0) Initializing policy
*apfMsConnTask_3: Mar 07 11:24:04.303: b4:ae:2b:ed:2c:9a <valid wireless VLAN address> START (0) Change state to AUTHCHECK (2) last state START (0)

*apfMsConnTask_3: Mar 07 11:24:04.304: b4:ae:2b:ed:2c:9a <valid wireless VLAN address> AUTHCHECK (2) Change state to 8021X_REQD (3) last state AUTHCHECK (2)

*apfMsConnTask_3: Mar 07 11:24:04.304: b4:ae:2b:ed:2c:9a Encryption policy is set to 0x80000001
*apfMsConnTask_3: Mar 07 11:24:04.304: b4:ae:2b:ed:2c:9a <valid wireless VLAN address> 8021X_REQD (3) DHCP required on AP 80:e8:6f:1e:da:80 vapId 80 apVapId 1for this client
*apfMsConnTask_3: Mar 07 11:24:04.304: b4:ae:2b:ed:2c:9a Not Using WMM Compliance code qosCap 00
*apfMsConnTask_3: Mar 07 11:24:04.304: b4:ae:2b:ed:2c:9a Sending 11w Flag 0 for Client B4:AE:2B:ED:2C:9A
*apfMsConnTask_3: Mar 07 11:24:04.304: b4:ae:2b:ed:2c:9a <valid wireless VLAN address> 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 80:e8:6f:1e:da:80 vapId 80 apVapId 1 flex-acl-name:
*apfMsConnTask_3: Mar 07 11:24:04.305: b4:ae:2b:ed:2c:9a apfPemAddUser2 (apf_policy.c:352) Changing state for mobile b4:ae:2b:ed:2c:9a on AP 80:e8:6f:1e:da:80 from Associated to Associated

*apfMsConnTask_3: Mar 07 11:24:04.305: b4:ae:2b:ed:2c:9a apfPemAddUser2:session timeout forstation b4:ae:2b:ed:2c:9a - Session Tout 0, apfMsTimeOut '0' and sessionTimerRunning flag is  0
*apfMsConnTask_3: Mar 07 11:24:04.305: b4:ae:2b:ed:2c:9a Stopping deletion of Mobile Station: (callerId: 48)
*apfMsConnTask_3: Mar 07 11:24:04.305: b4:ae:2b:ed:2c:9a Func: apfPemAddUser2, Ms Timeout = 0, Session Timeout = 0

*apfMsConnTask_3: Mar 07 11:24:04.305: b4:ae:2b:ed:2c:9a Sending assoc-resp with status 0 station:b4:ae:2b:ed:2c:9a AP:80:e8:6f:1e:da:80-00 on apVapId 1
*apfMsConnTask_3: Mar 07 11:24:04.305: b4:ae:2b:ed:2c:9a Sending Assoc Response to station on BSSID 80:e8:6f:1e:da:80 (status 0) ApVapId 1 Slot 0
*apfMsConnTask_3: Mar 07 11:24:04.306: b4:ae:2b:ed:2c:9a apfProcessAssocReq (apf_80211.c:9463) Changing state for mobile b4:ae:2b:ed:2c:9a on AP 80:e8:6f:1e:da:80 from Associated to Associated

*spamApTask7: Mar 07 11:24:04.308: b4:ae:2b:ed:2c:9a Sent 1x initiate message to multi thread task for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.308: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:53
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.308: b4:ae:2b:ed:2c:9a EAP-PARAM Debug - eap-params for Wlan-Id :<wireless VLAN> is disabled - applying Global eap timers and retries
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.308: b4:ae:2b:ed:2c:9a Disable re-auth, use PMK lifetime.
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.308: b4:ae:2b:ed:2c:9a dot1x - moving mobile b4:ae:2b:ed:2c:9a into Connecting state
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.308: b4:ae:2b:ed:2c:9a Sending EAP-Request/Identity to mobile b4:ae:2b:ed:2c:9a (EAP Id 1)
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.317: b4:ae:2b:ed:2c:9a Reset the reauth counter since EAPOL START has been received!!!
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.317: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:53
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.317: b4:ae:2b:ed:2c:9a Received EAPOL START from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.317: b4:ae:2b:ed:2c:9a dot1x - moving mobile b4:ae:2b:ed:2c:9a into Connecting state
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.317: b4:ae:2b:ed:2c:9a Sending EAP-Request/Identity to mobile b4:ae:2b:ed:2c:9a (EAP Id 2)
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.317: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.321: b4:ae:2b:ed:2c:9a Received EAPOL EAPPKT from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.321: b4:ae:2b:ed:2c:9a Received EAP Response packet with mismatching id (currentid=2, eapid=1) from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.321: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.323: b4:ae:2b:ed:2c:9a Received EAPOL EAPPKT from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.323: b4:ae:2b:ed:2c:9a Received Identity Response (count=1) from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.323: b4:ae:2b:ed:2c:9a Resetting reauth count 1 to 0 for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.323: b4:ae:2b:ed:2c:9a EAP State update from Connecting to Authenticating for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.323: b4:ae:2b:ed:2c:9a dot1x - moving mobile b4:ae:2b:ed:2c:9a into Authenticating state
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.323: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.323: b4:ae:2b:ed:2c:9a Entering Backend Auth Response state for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.323: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.329: b4:ae:2b:ed:2c:9a Processing Access-Challenge for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.329: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.329: b4:ae:2b:ed:2c:9a Entering Backend Auth Req state (id=3) for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.329: b4:ae:2b:ed:2c:9a Sending EAP Request from AAA to mobile b4:ae:2b:ed:2c:9a (EAP Id 3)
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.329: b4:ae:2b:ed:2c:9a Allocating EAP Pkt for retransmission to mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.329: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.334: b4:ae:2b:ed:2c:9a Received EAPOL EAPPKT from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.334: b4:ae:2b:ed:2c:9a Received EAP Response from mobile b4:ae:2b:ed:2c:9a (EAP Id 3, EAP Type 25)
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.334: b4:ae:2b:ed:2c:9a Resetting reauth count 0 to 0 for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.334: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.334: b4:ae:2b:ed:2c:9a Entering Backend Auth Response state for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.334: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.336: b4:ae:2b:ed:2c:9a Processing Access-Challenge for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.336: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.336: b4:ae:2b:ed:2c:9a Entering Backend Auth Req state (id=4) for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.336: b4:ae:2b:ed:2c:9a Sending EAP Request from AAA to mobile b4:ae:2b:ed:2c:9a (EAP Id 4)
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.336: b4:ae:2b:ed:2c:9a Reusing allocated memory for  EAP Pkt for retransmission to mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.336: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.342: b4:ae:2b:ed:2c:9a Received EAPOL EAPPKT from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.342: b4:ae:2b:ed:2c:9a Received EAP Response from mobile b4:ae:2b:ed:2c:9a (EAP Id 4, EAP Type 25)
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.342: b4:ae:2b:ed:2c:9a Resetting reauth count 0 to 0 for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.342: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.342: b4:ae:2b:ed:2c:9a Entering Backend Auth Response state for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.342: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.469: b4:ae:2b:ed:2c:9a Processing Access-Challenge for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.469: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.469: b4:ae:2b:ed:2c:9a Entering Backend Auth Req state (id=7) for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.469: b4:ae:2b:ed:2c:9a WARNING: updated EAP-Identifier 4 ===> 7 for STA b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.469: b4:ae:2b:ed:2c:9a Sending EAP Request from AAA to mobile b4:ae:2b:ed:2c:9a (EAP Id 7)
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.469: b4:ae:2b:ed:2c:9a Reusing allocated memory for  EAP Pkt for retransmission to mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.469: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.476: b4:ae:2b:ed:2c:9a Received EAPOL EAPPKT from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.476: b4:ae:2b:ed:2c:9a Received EAP Response from mobile b4:ae:2b:ed:2c:9a (EAP Id 7, EAP Type 25)
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.476: b4:ae:2b:ed:2c:9a Resetting reauth count 0 to 0 for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.476: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.476: b4:ae:2b:ed:2c:9a Entering Backend Auth Response state for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.476: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.478: b4:ae:2b:ed:2c:9a Processing Access-Accept for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.478: b4:ae:2b:ed:2c:9a Resetting web IPv4 acl from 255 to 255

*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.478: b4:ae:2b:ed:2c:9a Resetting web IPv4 Flex acl from 65535 to 65535

*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.478: b4:ae:2b:ed:2c:9a Setting re-auth timeout to 1800 seconds, got from WLAN config.
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.478: b4:ae:2b:ed:2c:9a Station b4:ae:2b:ed:2c:9a setting dot1x reauth timeout = 1800
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.478: b4:ae:2b:ed:2c:9a Creating a PKC PMKID Cache entry for station b4:ae:2b:ed:2c:9a (RSN 2)
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.478: b4:ae:2b:ed:2c:9a Resetting MSCB PMK Cache Entry 0 for station b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.478: b4:ae:2b:ed:2c:9a Setting active key cache index 8 ---> 8
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.478: b4:ae:2b:ed:2c:9a Setting active key cache index 8 ---> 0
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a Adding BSSID 80:e8:6f:1e:da:80 to PMKID cache at index 0 for station b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: New PMKID: (16)

*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479:      [0000] 25 bc 73 11 75 a0 63 d3 0e 25 1b 37 33 14 57 63

*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a Disabling re-auth since PMK lifetime can take care of same.
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a PMK: Sending cache delete
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a unsetting PmkIdValidatedByAp
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a Zeroize AAA Overrides from local for station
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a 0 PMK-update groupcast messages sent
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a PMK sent to mobility group
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a Sending EAP-Success to mobile b4:ae:2b:ed:2c:9a (EAP Id 7)
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a Freeing AAACB from Dot1xCB as AAA auth is done for  mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a Found an cache entry for BSSID 80:e8:6f:1e:da:80 in PMKID cache at index 0 of station b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a Found an cache entry for BSSID 80:e8:6f:1e:da:80 in PMKID cache at index 0 of station b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: Including PMKID in M1  (16)

*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479:      [0000] 25 bc 73 11 75 a0 63 d3 0e 25 1b 37 33 14 57 63

*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a Starting key exchange to mobile b4:ae:2b:ed:2c:9a, data packets will be dropped
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a Sending EAPOL-Key Message to mobile b4:ae:2b:ed:2c:9a
                                                                                                                    state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a Reusing allocated memory for  EAP Pkt for retransmission to mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a Entering Backend Auth Success state (id=7) for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a Received Auth Success while in Authenticating state for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a dot1x - moving mobile b4:ae:2b:ed:2c:9a into Authenticated state
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.491: b4:ae:2b:ed:2c:9a Received EAPOL-Key from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.491: b4:ae:2b:ed:2c:9a Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.491: b4:ae:2b:ed:2c:9a Received EAPOL-key in PTK_START state (message 2) from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.491: b4:ae:2b:ed:2c:9a Dumping RSNIE received in Association request:
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.491: 00000000: 30 14 01 00 00 0f ac 04  01 00 00 0f ac 04 01 00  0...............
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.491: 00000010: 00 0f ac 01 00 00                                 ......
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.491: b4:ae:2b:ed:2c:9a Dumping RSNIE received in EAPOL M2 :
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.491: 00000000: 01 00 00 0f ac 04 01 00  00 0f ac 04 01 00 00 0f  ................
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.491: 00000010: ac 01 00 00                                       ....
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.491: b4:ae:2b:ed:2c:9a PMK: Sending cache add
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.491: b4:ae:2b:ed:2c:9a Stopping retransmission timer for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.491: b4:ae:2b:ed:2c:9a Sending EAPOL-Key Message to mobile b4:ae:2b:ed:2c:9a
                                                                                                                    state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.491: b4:ae:2b:ed:2c:9a Reusing allocated memory for  EAP Pkt for retransmission to mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a Received EAPOL-Key from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a Stopping retransmission timer for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a Freeing EAP Retransmit Bufer for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a apfMs1xStateInc
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a apfMsPeapSimReqCntInc
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a apfMsPeapSimReqSuccessCntInc
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a <valid wireless VLAN address> 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state 8021X_REQD (3)

*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a <valid wireless VLAN address> L2AUTHCOMPLETE (4) DHCP required on AP 80:e8:6f:1e:da:80 vapId 80 apVapId 1for this client
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a Not Using WMM Compliance code qosCap 00
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a Sending 11w Flag 0 for Client B4:AE:2B:ED:2C:9A
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a <valid wireless VLAN address> L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 80:e8:6f:1e:da:80 vapId 80 apVapId 1 flex-acl-name:
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a apfMsRunStateInc
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a <valid wireless VLAN address> L2AUTHCOMPLETE (4) Change state to RUN (20) last state L2AUTHCOMPLETE (4)

*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a <valid wireless VLAN address> RUN (20) Reached PLUMBFASTPATH: from line 6649
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a <valid wireless VLAN address> RUN (20) Change state to RUN (20) last state RUN (20)

*DHCP Socket Task: Mar 07 11:24:04.537: b4:ae:2b:ed:2c:9a DHCP received op BOOTREQUEST (1) (len 308,<management VLAN #>, port 1, encap 0xec00)
*DHCP Socket Task: Mar 07 11:24:04.537: b4:ae:2b:ed:2c:9a DHCP (encap type 0xec00) mstype 0ff:ff:ff:ff:ff:ff
*DHCP Socket Task: Mar 07 11:24:04.537: b4:ae:2b:ed:2c:9a DHCP dropping looped REQUEST from DS (encap type 0xec00)
*DHCP Socket Task: Mar 07 11:24:08.019: b4:ae:2b:ed:2c:9a DHCP received op BOOTREQUEST (1) (len 308,<management VLAN #>, port 1, encap 0xec00)
*DHCP Socket Task: Mar 07 11:24:08.019: b4:ae:2b:ed:2c:9a DHCP (encap type 0xec00) mstype 0ff:ff:ff:ff:ff:ff
*DHCP Socket Task: Mar 07 11:24:08.019: b4:ae:2b:ed:2c:9a DHCP dropping looped REQUEST from DS (encap type 0xec00)
Comment
Watch Question
Network Architect
CERTIFIED EXPERT
Top Expert 2014
Commented:
This problem has been solved!
Unlock 1 Answer and 36 Comments.
See Answer
Why Experts Exchange?

Experts Exchange always has the answer, or at the least points me in the correct direction! It is like having another employee that is extremely experienced.

Jim Murphy
Programmer at Smart IT Solutions

When asked, what has been your best career decision?

Deciding to stick with EE.

Mohamed Asif
Technical Department Head

Being involved with EE helped me to grow personally and professionally.

Carl Webster
CTP, Sr Infrastructure Consultant
Ask ANY Question

Connect with Certified Experts to gain insight and support on specific technology challenges including:

  • Troubleshooting
  • Research
  • Professional Opinions
Did You Know?

We've partnered with two important charities to provide clean water and computer science education to those who need it most. READ MORE