External RADIUS Server EAP Authentication with 5760/3850 WLC Configuration Example

Available Languages

Download Options

PDF (1.5 MB)
View with Adobe Reader on a variety of devices

Updated:October 21, 2013

Document ID:116600

Bias-Free Language

The documentation set for this product strives to use bias-free language. For the purposes of this documentation set, bias-free is defined as language that does not imply discrimination based on age, disability, gender, racial identity, ethnic identity, sexual orientation, socioeconomic status, and intersectionality. Exceptions may be present in the documentation due to language that is hardcoded in the user interfaces of the product software, language used based on RFP documentation, or language that is used by a referenced third-party product. Learn more about how Cisco is using Inclusive Language.

Introduction

Prerequisites

Requirements

Components Used

Configure

Network Diagram

Overview

Configure WLC 5760/3850 with CLI

Configure WLC 5760/3850 with GUI

Configure ACS 5.2 (RADIUS Server)

Verify

Troubleshoot

Introduction

This document explains how to configure the wireless LAN (WLAN) controller (WLC) for Extensible Authentication Protocol (EAP)-Flexible Authentication via Secure Tunneling (FAST) authentication with the use of an external RADIUS server. This configuration example uses the Cisco Secure Access Control Server (ACS) as the external RADIUS server in order to authenticate the wireless client.

Prerequisites

Requirements

Cisco recommends that you have knowledge of these topics:

Basic knowledge of the configuration of lightweight access points (LAPs), Cisco 5760 Wireless LAN Controller, and Cisco Catalyst 3850 Series Switch.
Basic knowledge of Lightweight Access Point Protocol (LWAPP).
Knowledge of how to configure an external RADIUS server, such as the Cisco Secure ACS 5.2. This configuration example is for EAP-FAST.
Functional knowledge on general EAP framework.
Basic knowledge of security protocols, such as Microsoft Challenge Handshake Authentication Protocol Version 2 (MS-CHAPv2) and EAP-Generic Token Card (EAP-GTC).
Basic knowledge of digital certificates.

Components Used

The information in this document is based on these software and hardware versions:

Cisco Wireless LAN Controller 5760 Release 3.2.2 (Next Generation Wiring Closet [NGWC])
Cisco 3602 Series Lightweight Access Point
Microsoft Windows XP with Intel PROset Supplicant
Cisco Secure Access Control Server Release 5.2
Cisco Catalyst 3560 Series Switch

The information in this document was created from the devices in a specific lab environment. All of the devices used in this document started with a cleared (default) configuration. If your network is live, make sure that you understand the potential impact of any command.

Configure

Note: Use the Command Lookup Tool (registered customers only) in order to obtain more information on the commands used in this section.

Network Diagram

This image provides an example of a network diagram:

Overview

This configuration is done in two steps.

Configure WLC 5760/3850 with the command-line interface (CLI) or GUI.
Configure ACS 5.2 (RADIUS server).

Configure WLC 5760/3850 with CLI

This procedure describes how to use the CLI in order to configure the WLAN for the required client VLAN and map it to the authentication method list:

wlan EAPFAST 4 EAPFAST
    client vlan VLAN0020
    security dot1x authentication-list ACS
    session-timeout 1800
    no shutdown


   aaa new-model
   !
   !
   aaa group server radius ACS
    server name ACS
   !
   aaa authentication dot1x ACS group ACS

   radius server ACS
    address ipv4 10.106.102.50 auth-port 1645 acct-port 1646
    key Cisco123


 dot1x system-auth-contro

Configure WLC 5760/3850 with GUI

This procedure describes how to configure the 5760 controller and 3850 switch with the GUI:

In order to add the RADIUS server, navigate to Configuration > Security > AAA:
Navigate to Server Groups > Radius, and create a Radius Server Group with the name 'ACS':
Navigate to RADIUS > Services, and configure the 'ACS' RADIUS server:

This is an example of the complete configuration:
Navigate to Method Lists > General, and enable Dot1x System Auth Control (802.1X System Auth Control). Otherwise, authentication might fail:
Navigate to Method Lists > Authentication, and map the configured 'ACS' RADIUS server to the Method List, which, in turn, is mapped to the WLAN under the Authentication, Authorization, and Accounting (AAA) server:

This is how 'ACS' looks on the Method List:
In order to configure the WLAN and map the ACS, open the GUI access on the WLC, and navigate to Configuration > Wireless >WLAN > WLANs.
On the WLAN page, click NEW, and navigate to the General tab.Create a WLAN with 802.1X, and map the RADIUS server:
Navigate to the Security Tab > Layer 2 Tab, and ensure there is WPA/WPA2 with 802.1X enabled:
Navigate to the AAA Server tab, and map the Authentication Method List for this 'ACS' WLAN:

Configure ACS 5.2 (RADIUS Server)

This procedure describes how to configure the RADIUS server. Assume that the 5760 WLC and 3850 switch are already added on the ACS under AAA clients.

Navigate to Users and Identity Stores > Internal Identity Stores > Users, and configure the users and user database on the ACS:
Navigate to Access Policies > Access Services > Default Network Access, and enable the required authentication protocols. Be sure to enable EAP-FAST:
Navigate to Default Network Access > Identity, and configure the Identity Sequence rules for EAP-FAST:
Navigate to Default Network Access > Authorization, and see the authorization rules that grant access to EAP clients after successful authentication:

Verify

Use this section to confirm that your configuration works properly. Connect the client to the WLAN EAP-FAST.

Troubleshoot

This section provides information you can use to troubleshoot your configuration.

Note: Refer to Important Information on Debug Commands before you use debug commands.

Controller#sh debugging 

Nova Platform:
  dot11/state debugging is on 
  pem/events debugging is on 
  client/mac-addr debugging is on 
  dot11/detail debugging is on 
  mac/ filters[string 0021.5c8c.c761] debugging is on 
  dot11/error debugging is on 
  dot11/mobile debugging is on 
  pem/state debugging is on 

set trace group-wireless-client filter mac 0021.5c8c.c761
set trace wcm-dot1x event filter mac 0021.5c8c.c761
set trace wcm-dot1x aaa filter mac 0021.5c8c.c761
set trace aaa wireless events filter mac 0021.5c8c.c761
set trace access-session core sm filter mac 0021.5c8c.c761
set trace access-session method dot1x filter 0021.5c8c.c761

Controller#
*Sep  1 06:00:18.282: 0021.5C8C.C761 Association received from mobile on AP  
   C8F9.F983.4260  1 wcm:  .D^Iw for client 0:21:5c:t! w\2105HnJ^Iwy_status 
   0 attr len^G$8\227v^K
*Sep  1 06:00:18.282: 0021.5C8C.C761 qos upstream policy is unknown and 
   downstream policy is unknown 1 wcm: r client 0:21:5c:t! w\2105HnJ^Iwy_status 
   0 attr len^G$8\227v^K
*Sep  1 06:00:18.282: 0021.5C8C.C761 apChanged 0 wlanChanged 1 mscb ipAddr 
   20.20.20.3, apf RadiusOverride 0x0, numIPv6Addr=0 1 wcm: nJ^Iwy_status 0 attr 
   len^G$8\227v^K
*Sep  1 06:00:18.282: 0021.5C8C.C761 Applying WLAN policy on MSCB. 1 wcm:  
   ipAddr 20.20.20.3, apf RadiusOverride 0x0, numIPv6Addr=0
*Sep  1 06:00:18.282: 0021.5C8C.C761 Scheduling deletion of Mobile Station: 
   1 wcm:   (callerId: 50) in 1 seconds
*Sep  1 06:00:18.282: 0021.5C8C.C761 Disconnecting client due to switch of WLANs 
   from 1(wpa2psk) to 4(EAPFAST) 1 wcm: numIPv6Addr=0
*Sep  1 06:00:19.174: 0021.5C8C.C761 apfMsExpireCallback (apf_ms.c: 1 wcm: 664) 
   Expiring Mobile!
*Sep  1 06:00:19.174: 0021.5C8C.C761 apfMsExpireMobileStation (apf_ms.c: 1 wcm: 
   6953) Changing state for mobile  0021.5C8C.C761  on AP  C8F9.F983.4260  from 
   Associated to Disassociated 
*Sep  1 06:00:19.174: 0021.5C8C.C761 Sent Deauthenticate to mobile on BSSID  
   C8F9.F983.4260  slot 1(caller apf_ms.c: 1 wcm: 7036)
*Sep  1 06:00:19.174: 0021.5C8C.C761 apfMsExpireMobileStation (apf_ms.c: 1 wcm: 
   7092) Changing state for mobile  0021.5C8C.C761  on AP  C8F9.F983.4260  from 
   Disassociated to Idle 
*Sep  1 06:00:19.174:  0021.5C8C.C761  20.20.20.3 RUN (20) Deleted mobile LWAPP 
   rule on AP [ C8F9.F983.4260 ] 1 wcm: 5C8C.C761  on AP  C8F9.F983.4260  from 
   Disassociated to Idle 
*Sep  1 06:00:19.174: PEM recv processing msg Del SCB(4)  1 wcm:  Deleted mobile 
*Sep  1 06:00:19.174:  0021.5C8C.C761  20.20.20.3 RUN (20) FastSSID for the client 
   [ C8F9.F983.4260 ] NOTENABLED 1 wcm: C.C761  on AP  C8F9.F983.4260  from 
   Disassociated to Idle 
*Sep  1 06:00:19.174: 0021.5C8C.C761 Incrementing the Reassociation Count 1 for 
   client (of interface VLAN0020) 1 wcm: D
*Sep  1 06:00:19.174: 0021.5C8C.C761 Clearing Address 20.20.20.3 on mobile  1 wcm: 
   for client (of interface VLAN0020)
*Sep  1 06:00:19.174:  0021.5C8C.C761  20.20.20.3 RUN (20) Skipping TMP rule add 1 
   wcm: lient (of interface VLAN0020)
*Sep  1 06:00:19.174:  0021.5C8C.C761  20.20.20.3 RUN (20) Change state to 
   DHCP_REQD (7) last state RUN (20) 1 wcm: 
*Sep  1 06:00:19.174: 0021.5C8C.C761 WCDB_CHANGE: 1 wcm:  Client 1 m_vlan 20 Radio 
   iif id 0xbfcdc00000003a bssid iif id 0x8a3a8000000043, bssid C8F9.F983.4260
*Sep  1 06:00:19.174: 0021.5C8C.C761 WCDB_AUTH: 1 wcm:  Adding opt82 len 0
*Sep  1 06:00:19.174: 0021.5C8C.C761 WCDB_CHANGE: 1 wcm:  Suppressing SPI (client 
   pending deletion) pemstate 7 state LEARN_IP(2) vlan 20 client_id 0x8006400000004e 
   mob=Local(1) ackflag 2 dropd 0, delete 1
*Sep  1 06:00:19.174: 0021.5C8C.C761 Sending SPI spi_epm_epm_terminate_session 
   successfull 1 wcm:  pemstate 7 state LEARN_IP(2) vlan 20 client_id 
   0x8006400000004e mob=Local(1) ackflag 2 dropd 0, delete 1
*Sep  1 06:00:19.175: 0021.5C8C.C761 Sending SPI spi_epm_epm_terminate_session 
   successfull 1 wcm:  pemstate 7 state LEARN_IP(2) vlan 20 client_id 
   0x8006400000004e mob=Local(1) ackflag 2 dropd 0, delete 1
*Sep  1 06:00:19.175: 0021.5C8C.C761 Deleting wireless client; Reason code 0, 
   Preset 1, AAA cause 1 1 wcm:  7 state LEARN_IP(2) vlan 20 client_id 
   0x8006400000004e mob=Local(1) ackflag 2 dropd 0, delete 1
*Sep  1 06:00:19.175: 0021.5C8C.C761 WCDB_DEL: 1 wcm:  Successfully sent
*Sep  1 06:00:19.175: 0021.5C8C.C761  Expiring mobile state delete 1 wcm: on code 
   0, Preset 1, AAA cause 1
*Sep  1 06:00:19.175:  0021.5C8C.C761  0.0.0.0 DHCP_REQD (7) Handling pemDelScb 
   Event skipping delete 1 wcm:  state LEARN_IP(2) vlan 20 client_id 0x8006400000004e 
   mob=Local(1) ackflag 2 dropd 0, delete 1
*Sep  1 06:00:19.178: 0021.5C8C.C761 WCDB SPI response msg handler client code 1 
   mob state 1 1 wcm: g delete
*Sep  1 06:00:19.178: 0021.5C8C.C761 apfProcessWcdbClientDelete: 1 wcm:  Delete 
   ACK from WCDB.
*Sep  1 06:00:19.178: 0021.5C8C.C761 WCDB_DELACK: 1 wcm:  wcdbAckRecvdFlag updated
*Sep  1 06:00:19.178: 0021.5C8C.C761 WCDB_DELACK: 1 wcm:  Client IIF Id dealloc 
   SUCCESS w/ 0x8006400000004e.
*Sep  1 06:00:19.178: 0021.5C8C.C761 Invoked platform delete and cleared handle 1 
   wcm: w/ 0x8006400000004e.
*Sep  1 06:00:19.178: 0021.5C8C.C761 Deleting mobile on AP  C8F9.F983.4260 (1)  1 
   wcm: w/ 0x8006400000004e.
*Sep  1 06:00:19.178: 0021.5C8C.C761 Unlinked and freed mscb 1 wcm: 8F9.F983.4260 
   (1)   
*Sep  1 06:00:19.178: WCDB_IIF: 1 wcm:  Ack Message ID: 0x8006400000004e code 1003
*Sep  1 06:00:19.361: 0021.5C8C.C761 Adding mobile on LWAPP AP  C8F9.F983.4260 (1)  
   1 wcm: x800640000.D^Iwe.
*Sep  1 06:00:19.361: 0021.5C8C.C761  Creating WL station entry for client -  rc 
   0 1 wcm: 
*Sep  1 06:00:19.361: 0021.5C8C.C761 Association received from mobile on AP  
   C8F9.F983.4260  1 wcm: 0.D^Iwe.
*Sep  1 06:00:19.361: 0021.5C8C.C761 qos upstream policy is unknown and downstream 
   policy is unknown 1 wcm: 
*Sep  1 06:00:19.361: 0021.5C8C.C761 apChanged 0 wlanChanged 0 mscb ipAddr 
   0.0.0.0, apf RadiusOverride 0x0, numIPv6Addr=0 1 wcm: 
   \2105HnJ^Iwlient_id 0x80064000^G$8\227v^K
*Sep  1 06:00:19.361: 0021.5C8C.C761 Applying WLAN policy on MSCB. 1 wcm:  ipAddr 
   0.0.0.0, apf RadiusOverride 0x0, numIPv6Addr=0
*Sep  1 06:00:19.361: 0021.5C8C.C761 Applying WLAN ACL policies to client 1 wcm:  
   0.0.0.0, apf RadiusOverride 0x0, numIPv6Addr=0
*Sep  1 06:00:19.361: 0021.5C8C.C761 No Interface ACL used for Wireless client in 
   WCM(NGWC) 1 wcm: usOverride 0x0, numIPv6Addr=0
*Sep  1 06:00:19.361: 0021.5C8C.C761 Applying site-specific IPv6 override for 
   station  0021.5C8C.C761  - vapId 4, site 'default-group', interface 'VLAN0020' 
   1 wcm: 
*Sep  1 06:00:19.361: 0021.5C8C.C761 Applying local bridging Interface Policy for 
   station  0021.5C8C.C761  - vlan 20, interface 'VLAN0020' 1 wcm: erface 'VLAN0020'
*Sep  1 06:00:19.361: 0021.5C8C.C761 STA - rates (8): 1 wcm:  140 18 152 36 176 72 
   96 108 0 0 0 0 0 0 0 0
*Sep  1 06:00:19.361: 0021.5C8C.C761 new capwap_wtp_iif_id b6818000000038, sm 
   capwap_wtp_iif_id 0 1 wcm: 8C.C761  - vlan 20, interface 'VLAN0020'
*Sep  1 06:00:19.361: 0021.5C8C.C761 WCDB_ADD: 1 wcm:  Radio IIFID 
   0xbfcdc00000003a, BSSID IIF Id 0x81fac000000041, COS 4
*Sep  1 06:00:19.361: Load Balancer: 1 wcm:  Success, Resource allocated are: 
   Active Switch number: 1, Active Asic number : 0, Reserve Switch number 0 Reserve 
   Asic number 0. AP Asic num 0
*Sep  1 06:00:19.361: 0021.5C8C.C761 WCDB_ADD: 1 wcm:  Anchor Sw  1, Doppler 0
*Sep  1 06:00:19.361: 0021.5C8C.C761 WCDB_ALLOCATE: 1 wcm:  Client IIF Id alloc 
   SUCCESS w/ client 84fd0000000050 (state 0).
*Sep  1 06:00:19.361: 0021.5C8C.C761 iifid Clearing Ack flag 1 wcm: F Id alloc 
   SUCCESS w/ client 84fd0000000050 (state 0).
*Sep  1 06:00:19.361: 0021.5C8C.C761 WCDB_ADD: 1 wcm:  Adding opt82 len 0
*Sep  1 06:00:19.361: 0021.5C8C.C761 WCDB_ADD: 1 wcm:  Cleaering Ack flag
*Sep  1 06:00:19.361: 0021.5C8C.C761 WCDB_ADD: 1 wcm:  ssid EAPFAST bssid 
   C8F9.F983.4260 vlan 20 auth=ASSOCIATION(0) wlan(ap-group/global) 4/4 client 0 
   assoc 3 mob=Unassoc(0) radio 1 m_vlan 20 ip 0.0.0.0 src 0xb6818000000038 dst 0x0 
   cid 0x84fd0000000050 glob rsc id 16dhcpsrv  0.0.0.0 
*Sep  1 06:00:19.361: 0021.5C8C.C761 WCDB_ADD: 1 wcm:  mscb iifid 0x84fd0000000050 
   msinfo iifid 0x0
*Sep  1 06:00:19.361:  0021.5C8C.C761  0.0.0.0 START (0) Initializing policy 1 
   wcm: info iifid 0x0
*Sep  1 06:00:19.361:  0021.5C8C.C761  0.0.0.0 START (0) Change state to AUTHCHECK 
   (2) last state AUTHCHECK (2) 1 wcm: (ap-group/global) 4/4 client 0 assoc 3 
   mob=Unassoc(0) radio 1 m_vlan 20 ip 0.0.0.0 src 0xb6818000000038 dst 0x0 cid 
   0x84fd0000000050 glob rsc id 16dhcpsrv  0.0.0.0 
*Sep  1 06:00:19.361:  0021.5C8C.C761  0.0.0.0 AUTHCHECK (2) Change state to 
   8021X_REQD (3) last state 8021X_REQD (3) 1 wcm: oup/global) 4/4 client 0 assoc 3 
   mob=Unassoc(0) radio 1 m_vlan 20 ip 0.0.0.0 src 0xb6818000000038 dst 0x0 cid 
   0x84fd0000000050 glob rsc id 16dhcpsrv  0.0.0.0 
*Sep  1 06:00:19.361:  0021.5C8C.C761  0.0.0.0 8021X_REQD (3) DHCP Not required on 
   AP  C8F9.F983.4260  vapId 4 apVapId 4for this client 1 wcm: lient 0 assoc 3 
   mob=Unassoc(0) radio 1 m_vlan 20 ip 0.0.0.0 src 0xb6818000000038 dst 0x0 cid 
   0x84fd0000000050 glob rsc id 16dhcpsrv  0.0.0.0 
*Sep  1 06:00:19.361: 0021.5C8C.C761 Not Using WMM Compliance code qosCap 00 1 
   wcm: ed on AP  C8F9.F983.4260  vapId 4 apVapId 4for this client
*Sep  1 06:00:19.361:  0021.5C8C.C761  0.0.0.0 8021X_REQD (3) Plumbed mobile LWAPP 
   rule on AP  C8F9.F983.4260  vapId 4 apVapId 4 1 wcm: client
*Sep  1 06:00:19.361: 0021.5C8C.C761 apfPemAddUser2 (apf_policy.c: 1 wcm: 161) 
   Changing state for mobile  0021.5C8C.C761  on AP  C8F9.F983.4260  from Idle to 
   Associated 
*Sep  1 06:00:19.361: 0021.5C8C.C761 Stopping deletion of Mobile Station: 1 wcm:  
   (callerId: 48)
*Sep  1 06:00:19.361: 0021.5C8C.C761 Ms Timeout = 0, Session Timeout = 1800 1 wcm: 
   llerId: 48)
*Sep  1 06:00:19.361: 0021.5C8C.C761 Sending Assoc Response to station on BSSID  
   C8F9.F983.4260  (status 0) ApVapId 4 Slot 1 1 wcm: .F983.4260  from Idle to 
   Associated 
*Sep  1 06:00:19.362: 0021.5C8C.C761 apfProcessAssocReq (apf_80211.c: 1 wcm: 5260) 
   Changing state for mobile  0021.5C8C.C761  on AP  C8F9.F983.4260  from Associated 
   to Associated 
*Sep  1 06:00:19.362: WCDB_IIF: 1 wcm:  Ack Message ID: 0x84fd0000000050 code 1001
*Sep  1 06:00:21.239: 0021.5C8C.C761 client incoming attribute size are 485 1 wcm: 
   anging state for .D^Iwle  0021.5C8C.C761  t! w\2105HnJ^IwF983.4260  from 
   Ass^G$8\227v^K
*Sep  1 06:00:21.258:  0021.5C8C.C761  0.0.0.0 8021X_REQD (3) Change state to 
   L2AUTHCOMPLETE (4) last state L2AUTHCOMPLETE (4) 1 wcm: ^IwF983.4260  from 
   Ass^G$8\227v^K
*Sep  1 06:00:21.258: 0021.5C8C.C761 WCDB_CHANGE: 1 wcm:  Client 1 m_vlan 20 Radio 
   iif id 0xbfcdc00000003a bssid iif id 0x81fac000000041, bssid C8F9.F983.4260
*Sep  1 06:00:21.258: 0021.5C8C.C761 WCDB_AUTH: 1 wcm:  Adding opt82 len 0
*Sep  1 06:00:21.258: 0021.5C8C.C761 WCDB_LLM: 1 wcm:  NoRun Prev Mob 0, Curr Mob 
   0 llmReq 1, return False
*Sep  1 06:00:21.258: 0021.5C8C.C761 auth state 1 mob state 0 setWme 0 wme 1 
   roam_sent 0 1 wcm: rn False
*Sep  1 06:00:21.258: 0021.5C8C.C761 WCDB_CHANGE: 1 wcm:  auth=L2_AUTH(1) vlan 20 
   radio 1 client_id 0x84fd0000000050 mobility=Unassoc(0) src_int 0xb6818000000038 
   dst_int 0x0 ackflag 0 reassoc_client 0 llm_notif 0 ip  0.0.0.0 ip_learn_type 
   UNKNOWN
*Sep  1 06:00:21.258: 0021.5C8C.C761 WCDB_CHANGE: 1 wcm:  In L2 auth but l2ack 
   waiting lfag not set,so set
*Sep  1 06:00:21.258:  0021.5C8C.C761  0.0.0.0 L2AUTHCOMPLETE (4) 
   pemAdvanceState2: 1 wcm:  MOBILITY-INCOMPLETE with state 4. 
*Sep  1 06:00:21.258:  0021.5C8C.C761  0.0.0.0 L2AUTHCOMPLETE (4) 
   pemAdvanceState2: 1 wcm:  MOBILITY-INCOMPLETE with state 4. 
*Sep  1 06:00:21.258:  0021.5C8C.C761  0.0.0.0 L2AUTHCOMPLETE (4) DHCP Not 
   required on AP  C8F9.F983.4260  vapId 4 apVapId 4for this client 1 wcm: 
   6818000000038 dst_int 0x0 ackflag 0 reassoc_client 0 llm_notif 0 ip  0.0.0.0 
   ip_learn_type UNKNOWN
*Sep  1 06:00:21.258: 0021.5C8C.C761 Not Using WMM Compliance code qosCap 00 1 
   wcm: quired on AP  C8F9.F983.4260  vapId 4 apVapId 4for this client
*Sep  1 06:00:21.258:  0021.5C8C.C761  0.0.0.0 L2AUTHCOMPLETE (4) Plumbed mobile 
   LWAPP rule on AP  C8F9.F983.4260  vapId 4 apVapId 4 1 wcm: client
*Sep  1 06:00:21.258:  0021.5C8C.C761  0.0.0.0 L2AUTHCOMPLETE (4) Change state to 
   DHCP_REQD (7) last state DHCP_REQD (7) 1 wcm:  apVapId 4
*Sep  1 06:00:21.258: 0021.5C8C.C761 WCDB_CHANGE: 1 wcm:  Client 1 m_vlan 20 Radio 
   iif id 0xbfcdc00000003a bssid iif id 0x81fac000000041, bssid C8F9.F983.4260
*Sep  1 06:00:21.258: 0021.5C8C.C761 WCDB_AUTH: 1 wcm:  Adding opt82 len 0
*Sep  1 06:00:21.258: 0021.5C8C.C761 WCDB_CHANGE: 1 wcm:  Suppressing SPI 
   (Mobility state not known) pemstate 7 state LEARN_IP(2) vlan 20 client_id 
   0x84fd0000000050 mob=Unassoc(0) ackflag 1 dropd 0
*Sep  1 06:00:21.258:  0021.5C8C.C761  0.0.0.0 DHCP_REQD (7) pemAdvanceState2 
   4001, Adding TMP rule 1 wcm: e 7 state LEARN_IP(2) vlan 20 client_id 
   0x84fd0000000050 mob=Unassoc(0) ackflag 1 dropd 0
*Sep  1 06:00:21.258:  0021.5C8C.C761  0.0.0.0 DHCP_REQD (7) Adding Fast Path rule  
   on AP  C8F9.F983.4260 , slot 1 802.1P = 0 1 wcm: client_id 0x84fd0000000050 
   mob=Unassoc(0) ackflag 1 dropd 0
*Sep  1 06:00:21.258:  0021.5C8C.C761  0.0.0.0 DHCP_REQD (7) Successfully plumbed 
   mobile rule  1 wcm: F9.F983.4260 , slot 1 802.1P = 0^M 
*Sep  1 06:00:21.258: PEM recv processing msg Add SCB(3)  1 wcm: 7) Successfully 
   plumbed mobile rule 
*Sep  1 06:00:21.258: 0021.5C8C.C761 Incrementing the Reassociation Count 1 for 
   client (of interface VLAN0020) 1 wcm: lot 1 802.1P = 0^M 
*Sep  1 06:00:21.258: 0021.5C8C.C761 0.0.0.0, auth_state 7 mmRole Unassoc !!! 1 
   wcm: r client (of interface VLAN0020)
*Sep  1 06:00:21.258: 0021.5C8C.C761 0.0.0.0, auth_state 7 mmRole Unassoc, 
   updating wcdb not needed 1 wcm:  VLAN0020)
*Sep  1 06:00:21.258: 0021.5C8C.C761 Tclas Plumb needed: 1 wcm:  0
*Sep  1 06:00:21.258:  0021.5C8C.C761  0.0.0.0 DHCP_REQD (7) pemAdvanceState2: 1 
   wcm:  MOBILITY-COMPLETE with state 7. 
*Sep  1 06:00:21.258:  0021.5C8C.C761  0.0.0.0 DHCP_REQD (7) State Update from 
   Mobility-Incomplete to Mobility-Complete, mobility role=Local, client 
   state=APF_MS_STATE_ASSOCIATED 1 wcm:  1 dropd 0
*Sep  1 06:00:21.258:  0021.5C8C.C761  0.0.0.0 DHCP_REQD (7) pemAdvanceState2 
   3611, Adding TMP rule 1 wcm: o Mobility-Complete, mobility role=Local, client 
   state=APF_MS_STATE_ASSOCIATED
*Sep  1 06:00:21.258:  0021.5C8C.C761  0.0.0.0 DHCP_REQD (7) Replacing Fast Path 
   rule  on AP  C8F9.F983.4260 , slot 1 802.1P = 0 1 wcm: e=Local, client 
   state=APF_MS_STATE_ASSOCIATED
*Sep  1 06:00:21.258:  0021.5C8C.C761  0.0.0.0 DHCP_REQD (7) Successfully plumbed 
   mobile rule  1 wcm:  C8F9.F983.4260 , slot 1 802.1P = 0^M 
*Sep  1 06:00:21.258: 0021.5C8C.C761 WCDB_CHANGE: 1 wcm:  Client 1 m_vlan 20 Radio 
   iif id 0xbfcdc00000003a bssid iif id 0x81fac000000041, bssid C8F9.F983.4260
*Sep  1 06:00:21.258: 0021.5C8C.C761 WCDB_AUTH: 1 wcm:  Adding opt82 len 0
*Sep  1 06:00:21.258: 0021.5C8C.C761 WCDB_LLM: 1 wcm:  NoRun Prev Mob 0, Curr 
   Mob 1 llmReq 1, return False
*Sep  1 06:00:21.258: 0021.5C8C.C761 WCDB_CHANGE: 1 wcm:  Suppressing SPI (ACK 
   message not recvd) pemstate 7 state LEARN_IP(2) vlan 20 client_id 0x84fd0000000050 
   mob=Local(1) ackflag 1 dropd 1
*Sep  1 06:00:21.258: 0021.5C8C.C761 Error updating wcdb on mobility complete  1 
   wcm: not recvd) pemstate 7 state LEARN_IP(2) vlan 20 client_id 0x84fd0000000050 
   mob=Local(1) ackflag 1 dropd 1
*Sep  1 06:00:21.258: PEM recv processing msg Epm spi response(12)  1 wcm:  
   complete 
*Sep  1 06:00:21.258: 0021.5C8C.C761 aaa attribute list length is 79 1 wcm: 
   complete 
*Sep  1 06:00:21.258: 0021.5C8C.C761 Sending SPI spi_epm_epm_session_create 
   successfull 1 wcm: ) pemstate 7 state LEARN_IP(2) vlan 20 client_id 
   0x84fd0000000050 mob=Local(1) ackflag 1 dropd 1
*Sep  1 06:00:21.258: PEM recv processing msg Add SCB(3)  1 wcm: pm_session_create 
   successfull
*Sep  1 06:00:21.259: 0021.5C8C.C761 0.0.0.0, auth_state 7 mmRole Local !!! 1 wcm: 
   successfull
*Sep  1 06:00:21.259: 0021.5C8C.C761 0.0.0.0, auth_state 7 mmRole Local, updating 
   wcdb not needed 1 wcm:  7 state LEARN_IP(2) vlan 20 client_id 0x84fd0000000050 
   mob=Local(1) ackflag 1 dropd 1
*Sep  1 06:00:21.259: 0021.5C8C.C761 Tclas Plumb needed: 1 wcm:  0
*Sep  1 06:00:21.260: EPM: 1 wcm:  Session create resp - client handle 
   84fd0000000050 session f2000027 
*Sep  1 06:00:21.260: EPM: 1 wcm:  Netflow session create resp - client handle 
   84fd0000000050 sess f2000027
*Sep  1 06:00:21.260: PEM recv processing msg Epm spi response(12)  1 wcm: le 
   84fd0000000050 sess f2000027
*Sep  1 06:00:21.261: 0021.5C8C.C761 Received session_create_response for client 
   handle 37432873367634000 1 wcm:  LEARN_IP(2) vlan 20 client_id 0x84fd0000000050 
   mob=Local(1) ackflag 1 dropd 1
*Sep  1 06:00:21.261: 0021.5C8C.C761 Received session_create_response with EPM 
   session handle 4060086311 1 wcm: 
*Sep  1 06:00:21.261: 0021.5C8C.C761 Send request to EPM 1 wcm: ate_response with 
   EPM session handle 4060086311
*Sep  1 06:00:21.261: 0021.5C8C.C761 aaa attribute list length is 485 1 wcm: with 
   EPM session handle 4060086311
*Sep  1 06:00:21.261: 0021.5C8C.C761 Sending Activate request for session handle 
   4060086311 successful 1 wcm: 1
*Sep  1 06:00:21.261: 0021.5C8C.C761 Post-auth policy request sent! Now wait for 
   post-auth policy ACK from EPM 1 wcm: N_IP(2) vlan 20 client_id 0x84fd0000000050 
   mob=Local(1) ackflag 1 dropd 1
*Sep  1 06:00:21.261: EPM: 1 wcm:  Init feature, client handle 84fd0000000050 
   session f2000027 authz 8f000011 
*Sep  1 06:00:21.261: EPM: 1 wcm:  Activate feature client handle 84fd0000000050 
   sess f2000027 authz 8f000011
*Sep  1 06:00:21.261: PEM recv processing msg Epm spi response(12)  1 wcm: 0050 
   sess f2000027 authz 8f000011
*Sep  1 06:00:21.261: 0021.5C8C.C761 Received activate_features_resp for client 
   handle 37432873367634000 1 wcm: m EPM
*Sep  1 06:00:21.261: 0021.5C8C.C761 Received activate_features_resp for EPM 
   session handle 4060086311 1 wcm: 0
*Sep  1 06:00:21.261: EPM: 1 wcm:  Policy enforcement -  client handle 
   84fd0000000050 session a8000011 authz 8f000011 
*Sep  1 06:00:21.261: EPM: 1 wcm:  Netflow policy enforcement - client handle 
   84fd0000000050 sess a8000011 authz 8f000011 msg_type 0 policy_status 0 attr len 0
*Sep  1 06:00:21.262: PEM recv processing msg Epm spi response(12)  1 wcm: e 
   84fd0000000050 sess a8000011 authz 8f000011 msg_type 0 policy_status 0 attr len 0
*Sep  1 06:00:21.262: 0021.5C8C.C761 Received policy_enforcement_response for 
   client handle 37432873367634000 1 wcm: 011 msg_type 0 policy_status 0 attr len 0
*Sep  1 06:00:21.262: 0021.5C8C.C761 Received policy_enforcement_response for EPM 
   session handle 2818572305 1 wcm: 0
*Sep  1 06:00:21.262: 0021.5C8C.C761 Received response for 
   _EPM_SPI_ACTIVATE_FEATURES request sent for client 1 wcm: 011 msg_type 0 
   policy_status 0 attr len 0
*Sep  1 06:00:21.262: 0021.5C8C.C761 Received _EPM_SPI_STATUS_SUCCESS for request 
   sent for client 1 wcm:  for client
*Sep  1 06:00:21.262: 0021.5C8C.C761 Post-auth policy ACK recvd from EPM, unset 
   flag on MSCB 1 wcm: ient
*Sep  1 06:00:21.262: 0021.5C8C.C761 WCDB SPI response msg handler client code 0 
   mob state 0 1 wcm: ient
*Sep  1 06:00:21.262: 0021.5C8C.C761 WcdbClientUpdate: 1 wcm:  L2 Auth ACK from 
   WCDB
*Sep  1 06:00:21.262: 0021.5C8C.C761 WCDB_L2ACK: 1 wcm:  wcdbAckRecvdFlag updated 
*Sep  1 06:00:21.262: 0021.5C8C.C761 WCDB_CHANGE: 1 wcm:  Client 1 m_vlan 20 Radio 
   iif id 0xbfcdc00000003a bssid iif id 0x81fac000000041, bssid C8F9.F983.4260
*Sep  1 06:00:21.262: 0021.5C8C.C761 WCDB_AUTH: 1 wcm:  Adding opt82 len 0
*Sep  1 06:00:21.262: 0021.5C8C.C761 WCDB_LLM: 1 wcm:  NoRun Prev Mob 0, Curr 
   Mob 1 llmReq 1, return False
*Sep  1 06:00:21.263: 0021.5C8C.C761 auth state 2 mob state 1 setWme 0 wme 1 
   roam_sent 0 1 wcm: rn False
*Sep  1 06:00:21.263: 0021.5C8C.C761 WCDB_CHANGE: 1 wcm:  auth=LEARN_IP(2) vlan 20 
   radio 1 client_id 0x84fd0000000050 mobility=Local(1) src_int 0xb6818000000038 
   dst_int 0x0 ackflag 2 reassoc_client 0 llm_notif 0 ip  0.0.0.0 ip_learn_type 
   UNKNOWN
*Sep  1 06:00:24.425: 0021.5C8C.C761 WCDB_IP_BIND: 1 wcm:  w/ IPv4 20.20.20.3 
   ip_learn_type DHCP add_delete 1,options_length 0
*Sep  1 06:00:24.425: 0021.5C8C.C761 WcdbClientUpdate: 1 wcm:  IP Binding from 
   WCDB ip_learn_type 1, add_or_delete 1
*Sep  1 06:00:24.425: 0021.5C8C.C761 IPv4 Addr: 1 wcm:  20:20:20:3 
*Sep  1 06:00:24.425: 0021.5C8C.C761 MS got the IP, resetting the Reassociation 
   Count 0 for client 1 wcm: _delete 1
*Sep  1 06:00:24.425:  0021.5C8C.C761  20.20.20.3 DHCP_REQD (7) Session Update not 
   required for Initial authenticated dot1x client 1 wcm: nt 0xb6818000000^G$8\227v^K
*Sep  1 06:00:24.426:  0021.5C8C.C761  20.20.20.3 DHCP_REQD (7) Change state to 
   RUN (20) last state RUN (20) 1 wcm: ticated dot1x client  
*Sep  1 06:00:24.426: 0021.5C8C.C761 WCDB_CHANGE: 1 wcm:  Client 1 m_vlan 20 Radio 
   iif id 0xbfcdc00000003a bssid iif id 0x81fac000000041, bssid C8F9.F983.4260
*Sep  1 06:00:24.426: 0021.5C8C.C761 WCDB_AUTH: 1 wcm:  Adding opt82 len 0
*Sep  1 06:00:24.426: 0021.5C8C.C761 WCDB_LLM: 1 wcm:  prev Mob state 1 curr Mob 
   State 1 llReq flag 0
*Sep  1 06:00:24.426: 0021.5C8C.C761 auth state 4 mob state 1 setWme 0 wme 1 
   roam_sent 0 1 wcm: g 0
*Sep  1 06:00:24.426: 0021.5C8C.C761 WCDB_CHANGE: 1 wcm:  auth=RUN(4) vlan 20 
   radio 1 client_id 0x84fd0000000050 mobility=Local(1) src_int 0xb6818000000038 
   dst_int 0x0 ackflag 2 reassoc_client 0 llm_notif 0 ip  20.20.20.3 ip_learn_type 
   DHCP
*Sep  1 06:00:24.426:  0021.5C8C.C761  20.20.20.3 RUN (20) Reached PLUMBFASTPATH: 
   1 wcm:  from line 4430
*Sep  1 06:00:24.426:  0021.5C8C.C761  20.20.20.3 RUN (20) Replacing Fast Path 
   rule  on AP  C8F9.F983.4260 , slot 1 802.1P = 0 1 wcm: 0xb6818000000038 dst_int 
   0x0 
   ackflag 2 reassoc_client 0 llm_notif 0 ip  20.$=6v0.3 
   ip_lt^_Dv^\7HnP6v^D6Hl5Ht^_Dv$6H8^ r^D6H>&5v8^ r^D6H>&5v^D6Ht^M^Lw^\7H8^ r
*Sep  1 06:00:24.426:  0021.5C8C.C761  20.20.20.3 RUN (20) Successfully plumbed 
   mobile rule  1 wcm:  C8F9.F983.4260 , slot 1 802.1P = 0^M 
*Sep  1 06:00:24.426: 0021.5C8C.C761  Sending IPv4 update to Controller 
   10.105.135.176  1 wcm: e 
*Sep  1 06:00:24.426: 0021.5C8C.C761 Assigning Address 20.20.20.3 to mobile  1 
   wcm: 05.135.176  
*Sep  1 06:00:24.426: PEM recv processing msg Add SCB(3)  1 wcm: 20.20.3 to mobile 
*Sep  1 06:00:24.426: 0021.5C8C.C761 20.20.20.3, auth_state 20 mmRole Local !!! 1 
   wcm: 135.176  
*Sep  1 06:00:24.426: 0021.5C8C.C761 20.20.20.3, auth_state 20 mmRole Local, 
   updating wcdb not needed 1 wcm: 3.4260 , slot 1 802.1P = 0^M 
*Sep  1 06:00:24.426: 0021.5C8C.C761 Tclas Plumb needed: 1 wcm:  0
*Sep  1 06:00:34.666: PEM recv processing msg Del SCB(4)  1 wcm: 
*Sep  1 06:00:34.864: PEM recv processing msg Add SCB(3)  1 wcm: 
*Sep  1 06:00:34.865: EPM: 1 wcm:  Init feature, client handle a028c00000004c 
   session a600001f authz 5e00000d 
*Sep  1 06:00:34.865: EPM: 1 wcm:  Activate feature client handle a028c00000004c 
   sess a600001f authz 5e00000d
*Sep  1 06:00:34.865: PEM recv processing msg Epm spi response(12)  1 wcm: 004c 
   sess a600001f authz 5e00000d
*Sep  1 06:00:34.865: EPM: 1 wcm:  Policy enforcement -  client handle 
   a028c00000004c session ca00000d authz 5e00000d 
*Sep  1 06:00:34.865: EPM: 1 wcm:  Netflow policy enforcement - client handle 
   a028c00000004c sess ca00000d authz 5e00000d msg_type 0 policy_status 0 attr len 0
*Sep  1 06:00:34.865: PEM recv processing msg Epm spi response(12)  1 wcm: e 
   a028c00000004c sess ca00000d authz 5e00000d msg_type 0 policy_status 0 attr len 0
*Sep  1 06:00:52.802: PEM recv processing msg Del SCB(4)  1 wcm: onse(12) 
*Sep  1 06:00:53.015: PEM recv processing msg Add SCB(3)  1 wcm: 
*Sep  1 06:00:53.015: EPM: 1 wcm:  Init feature, client handle a028c00000004c 
   session a600001f authz 5e00000d 
*Sep  1 06:00:53.015: EPM: 1 wcm:  Activate feature client handle a028c00000004c 
   sess a600001f authz 5e00000d
*Sep  1 06:00:53.015: PEM recv processing msg Epm spi response(12)  1 wcm: 004c 
   sess a600001f authz 5e00000d
*Sep  1 06:00:53.016: EPM: 1 wcm:  Policy enforcement -  client handle 
   a028c00000004c session ca00000d authz 5e00000d 
*Sep  1 06:00:53.016: EPM: 1 wcm:  Netflow policy enforcement - client handle 
   a028c00000004c sess ca00000d authz 5e00000d msg_type 0 policy_status 0 attr len 0
*Sep  1 06:00:53.016: PEM recv processing msg Epm spi response(12)  1 wcm: e 
   a028c00000004c sess ca00000d authz 5e00000d msg_type 0 policy_status 0 attr len 0
*Sep  1 06:01:18.829: PEM recv processing msg Del SCB(4)  1 wcm: nse(12) 
*Sep  1 06:01:19.037: PEM recv processing msg Add SCB(3)  1 wcm: 
*Sep  1 06:01:19.037: EPM: 1 wcm:  Init feature, client handle a028c00000004c 
   session a600001f authz 5e00000d 
*Sep  1 06:01:19.037: EPM: 1 wcm:  Activate feature client handle a028c00000004c 
   sess a600001f authz 5e00000d
*Sep  1 06:01:19.037: PEM recv processing msg Epm spi response(12)  1 wcm: 004c 
   sess a600001f authz 5e00000d
*Sep  1 06:01:19.037: EPM: 1 wcm:  Policy enforcement -  client handle 
   a028c00000004c session ca00000d authz 5e00000d 
*Sep  1 06:01:19.037: EPM: 1 wcm:  Netflow policy enforcement - client handle 
   a028c00000004c sess ca00000d authz 5e00000d msg_type 0 policy_status 0 attr len 0
*Sep  1 06:01:19.037: PEM recv processing msg Epm spi response(12)  1 wcm: e 
   a028c00000004c sess ca00000d authz 5e00000d msg_type 0 policy_status 0 attr len 0
*Sep  1 06:01:20.108: 0021.5C8C.C761 
Client stats update: 1 wcm:  Time now in sec 1378015280, Last Acct Msg Sent at 
   1378015224 sec


[09/01/13 11:59:18.282 IST 1572 5933] 0021.5C8C.C761 Scheduling deletion of Mobile 
   Station:  (callerId: 50) in 1 seconds
 --More--         [09/01/13 11:59:18.282 IST 1573 5933] 0021.5C8C.C761 
   Disconnecting client due to switch of WLANs from 1(wpa2psk) to 4(EAPFAST)
[09/01/13 11:59:19.174 IST 1574 5933] 0021.5C8C.C761 apfMsExpireCallback 
   (apf_ms.c:664) Expiring Mobile!
[09/01/13 11:59:19.174 IST 1575 5933] 0021.5C8C.C761 apfMsExpireMobileStation 
   (apf_ms.c:6953) Changing state for mobile  0021.5C8C.C761  on AP  C8F9.F983.4260  
   from Associated to Disassociated
[09/01/13 11:59:19.174 IST 1576 5933] 0021.5C8C.C761 1XA: Cleaning up dot1x
[09/01/13 11:59:19.174 IST 1577 5933] 0021.5C8C.C761 1XA: Session Manager Call to 
   cleanup session for Client capwap iif_id b6818000000038
[09/01/13 11:59:19.174 IST 1578 5933] 0021.5C8C.C761 Sent Deauthenticate to mobile 
   on BSSID  C8F9.F983.4260  slot 1(caller apf_ms.c:7036)
[09/01/13 11:59:19.174 IST 1579 5933] 0021.5C8C.C761 AAAS: acct method list NOT 
   configured for WLAN 1, accounting skipped
[09/01/13 11:59:19.174 IST 157a 5933] 0021.5C8C.C761 AAAS: freeing AAA accounting 
   session
[09/01/13 11:59:19.174 IST 157b 5933] 0021.5C8C.C761 apfMsAssoStateDec
[09/01/13 11:59:19.174 IST 157c 5933] 0021.5C8C.C761 apfMsExpireMobileStation 
   (apf_ms.c:7092) Changing state for mobile  0021.5C8C.C761  on AP  C8F9.F983.4260  
   from Disassociated to Idle
[09/01/13 11:59:19.174 IST 157d 33] ACCESS-CORE-SM-CLIENT-SPI-NOTF: 
   [0021.5c8c.c761, Ca1] Session stop request received  for Client[1] MAC 
   [0021.5c8c.c761] SID [] Disc 
   cause [(default)/0]
 --More--         [09/01/13 11:59:19.174 IST 157e 173] ACCESS-CORE-SM-NOTF: 
   [0021.5c8c.c761, Ca1] Received session event 'SESSION_STOP' from client
[09/01/13 11:59:19.174 IST 157f 5933] 0021.5C8C.C761 Incrementing the 
   Reassociation Count 1 for client (of interface VLAN0020)
[09/01/13 11:59:19.174 IST 1580 5933] 0021.5C8C.C761 Clearing Address 20.20.20.3 
   on mobile 
[09/01/13 11:59:19.174 IST 1581 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Session stop for 0021.5c8c.c761 - Audit ID (none), reason (default)/0
[09/01/13 11:59:19.174 IST 1582 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Unlocking 0xF3000023 for deletion
[09/01/13 11:59:19.174 IST 1583 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Processing SM CB request for 0xF3000023: Event: Pre-Disconnect notification t 
[09/01/13 11:59:19.174 IST 1584 5933] 0021.5C8C.C761 apfMsRunStateDec
[09/01/13 11:59:19.174 IST 1585 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Predisconnect notification - teardown complete for 0xF3000023(0021.5c8c.c761)
[09/01/13 11:59:19.174 IST 1586 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Session teardown completing, deleting context
[09/01/13 11:59:19.174 IST 1587 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Signalling "pre" delete for client 0021.5c8c.c761 / 0xF3000023
[09/01/13 11:59:19.174 IST 1588 5933] 0021.5C8C.C761 WCDB_AUTH: Adding opt82 len 0
[09/01/13 11:59:19.174 IST 1589 5933] 0021.5C8C.C761 WCDB_CHANGE: Suppressing SPI 
   (client pending deletion) pemstate 7 state LEARN_IP(2) vlan 20 client_id 
   0x8006400000004e mob=Local(1) ackflag 2 dropd 0, delete 1
 --More--         [09/01/13 11:59:19.174 IST 158a 173] ACCESS-CORE-SM-NOTF: 
   [0021.5c8c.c761, Ca1] Deleted record - hdl 0xF3000023. 2 session(s) remain on IDB.
[09/01/13 11:59:19.174 IST 158b 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Processing SM CB request for 0xF3000023: Event: Client disconnect notificatio 
[09/01/13 11:59:19.174 IST 158c 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   AAA-ID 0x0000001C for 0021.5c8c.c761 not freed, as externally generated
[09/01/13 11:59:19.174 IST 158d 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Removed policy (tgt 0x00000000) from session (hdl 0xF3000023)
[09/01/13 11:59:19.174 IST 158e 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Unblock events for 0021.5c8c.c761. 
[09/01/13 11:59:19.174 IST 158f 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   AAA-ID 0x0000001C for 0021.5c8c.c761 not freed, as externally generated
[09/01/13 11:59:19.174 IST 1590 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Freed Auth Manager context 0xF3000023
[09/01/13 11:59:19.174 IST 1591 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Signalling "post" delete for client in domain DATA
[09/01/13 11:59:19.174 IST 1592 5933] 0021.5C8C.C761 Sending SPI 
   spi_epm_epm_terminate_session successfull
[09/01/13 11:59:19.175 IST 1593 5933] 0021.5C8C.C761 Sending SPI 
   spi_epm_epm_terminate_session successfull
[09/01/13 11:59:19.175 IST 1594 5933] 0021.5C8C.C761 Deleting wireless client; 
   Reason code 0, Preset 1, AAA cause 1
[09/01/13 11:59:19.175 IST 1595 5933] 0021.5C8C.C761 WCDB_DEL: Successfully sent
[09/01/13 11:59:19.175 IST 1596 5933] 0021.5C8C.C761  Expiring mobile state delete
 --More--         [09/01/13 11:59:19.175 IST 1597 190] [WCDB] ==Delete event for 
   Wireless client (0021.5c8c.c761) client id (0x8006400000004e) vlan 20 auth_state 
   RUN mob_state LOCAL flags 2
[09/01/13 11:59:19.175 IST 1598 190] [WCDB] wcdb_client_mcast_update_notify: add = 
   0, port_update = 0, delete = 1
[09/01/13 11:59:19.175 IST 1599 190] ACCESS-CORE-SM-FEATURE-WIRED_TUNNEL-NOT: 
[0021.5c8c.c761] Client 0021.5c8c.c761 is not tunnel client..Return
[09/01/13 11:59:19.176 IST 159a 190] [WCDB] wcdb_ffcp_wcdb_client_delete_notify: 
   client (0021.5c8c.c761) id 0x8006400000004e ffcp delete
[09/01/13 11:59:19.178 IST 159b 33] [WCDB] wcdb_ffcp_cb: client (0021.5c8c.c761) 
   client (0x8006400000004e): FFCP operation (DELETE) return code (0)
[09/01/13 11:59:19.178 IST 159c 33] [WCDB] wcdb_send_delete_notify_callback_event: 
   Delete ACK sent to WCM after confirming clientLe is deleted for mac 0021.5c8c.c761 
[09/01/13 11:59:19.178 IST 159d 33] [WCDB] wcdb_client_delete_actual: WCDB DB 
   client 0021.5c8c.c761 is being deleted
[09/01/13 11:59:19.178 IST 159e 33] [WCDB] wcdb_client_delete_actual Client delete 
   notification is sent to DHCP snooping: host mac: 0021.5c8c.c761, IP: 20.20.20.3
[09/01/13 11:59:19.178 IST 159f 33] [WCDB] wcdb_client_delete_actual: Exit: WCDB 
   DB client 0021.5c8c.c761 is being deleted
[09/01/13 11:59:19.178 IST 15a0 186] ACCESS-CORE-SM-CLIENT-IPDT-ERR: 
   [0021.5c8c.c761, Ca1] No session for MAC 0021.5c8c.c761
[09/01/13 11:59:19.178 IST 15a1 5933] 0021.5C8C.C761 WCDB SPI response msg handler 
   client code 1 mob state 1
 --More--         [09/01/13 11:59:19.178 IST 15a2 5933] 0021.5C8C.C761 
   apfProcessWcdbClientDelete: Delete ACK from WCDB.
[09/01/13 11:59:19.178 IST 15a3 5933] 0021.5C8C.C761 WCDB_DELACK: wcdbAckRecvdFlag 
   updated
[09/01/13 11:59:19.178 IST 15a4 5933] 0021.5C8C.C761 Invoked platform delete and 
   cleared handle
[09/01/13 11:59:19.178 IST 15a5 5933] 0021.5C8C.C761 apfMs1xStateDec
[09/01/13 11:59:19.178 IST 15a6 5933] 0021.5C8C.C761 Deleting mobile on AP  
   C8F9.F983.4260 (1) 
[09/01/13 11:59:19.178 IST 15a7 5933] 0021.5C8C.C761 1XA: Cleaning up dot1x
[09/01/13 11:59:19.178 IST 15a8 5933] 0021.5C8C.C761 Unlinked and freed mscb
[09/01/13 11:59:19.361 IST 15a9 5933] 0021.5C8C.C761 Adding mobile on LWAPP AP  
   C8F9.F983.4260 (1) 
[09/01/13 11:59:19.361 IST 15aa 5933] 0021.5C8C.C761 Association received from 
   mobile on AP  C8F9.F983.4260 
[09/01/13 11:59:19.361 IST 15ab 5933] 0021.5C8C.C761 qos upstream policy is 
   unknown and downstream policy is unknown
[09/01/13 11:59:19.361 IST 15ac 5933] 0021.5C8C.C761 apChanged 0 wlanChanged 0 
   mscb ipAddr 0.0.0.0, apf RadiusOverride 0x0, numIPv6Addr=0
[09/01/13 11:59:19.361 IST 15ad 5933] 0021.5C8C.C761 Applying WLAN policy on MSCB.
[09/01/13 11:59:19.361 IST 15ae 5933] 0021.5C8C.C761 Applying WLAN ACL policies to 
   client
[09/01/13 11:59:19.361 IST 15af 5933] 0021.5C8C.C761 No Interface ACL used for 
   Wireless client in WCM(NGWC)
 --More--         [09/01/13 11:59:19.361 IST 15b0 5933] 0021.5C8C.C761 Applying 
   site-specific IPv6 override for station  0021.5C8C.C761  - vapId 4, site 
   'default-group', interface 'VLAN0020'
[09/01/13 11:59:19.361 IST 15b1 5933] 0021.5C8C.C761 Applying local bridging 
   Interface Policy for station  0021.5C8C.C761  - vlan 20, interface 'VLAN0020'
[09/01/13 11:59:19.361 IST 15b2 5933] 0021.5C8C.C761 STA - rates (8): 
   140 18 152 36 176 72 96 108 0 0 0 0 0 0 0 0
[09/01/13 11:59:19.361 IST 15b3 5933] 0021.5C8C.C761 Processing RSN IE type 48, 
   length 22 for mobile  0021.5C8C.C761 
[09/01/13 11:59:19.361 IST 15b4 5933] 0021.5C8C.C761 Received RSN IE with 0 PMKIDs 
   from mobile  0021.5C8C.C761 
[09/01/13 11:59:19.361 IST 15b5 5933] 0021.5C8C.C761 1XK: Looking for BSSID  
   C8F9.F983.426C  in PMKID cache
[09/01/13 11:59:19.361 IST 15b6 5933] 0021.5C8C.C761 1XK: Set Link Secure: 0
[09/01/13 11:59:19.361 IST 15b7 5933] 0021.5C8C.C761 new 
   capwap_wtp_iif_id b6818000000038, sm capwap_wtp_iif_id 0
[09/01/13 11:59:19.361 IST 15b8 5933] 0021.5C8C.C761 WCDB_ADD: Adding opt82 len 0
[09/01/13 11:59:19.361 IST 15b9 5933] 0021.5C8C.C761 WCDB_ADD: ssid EAPFAST bssid 
   C8F9.F983.4260 vlan 20 auth=ASSOCIATION(0) wlan(ap-group/global) 4/4 client 0 
   assoc 3 mob=Unassoc(0) radio 1 m_vlan 20 ip 0.0.0.0 src 0xb6818000000038 dst 0x0 
   cid 0x84fd0000000050 glob rsc id 16dhcpsrv  0.0.0.0 
[09/01/13 11:59:19.361 IST 15ba 5933] 0021.5C8C.C761 Not Using WMM Compliance code 
   qosCap 00
 --More--         [09/01/13 11:59:19.361 IST 15bb 5933] 0021.5C8C.C761 
   apfMsAssoStateInc
[09/01/13 11:59:19.361 IST 15bc 5933] 0021.5C8C.C761 apfPemAddUser2 
   (apf_policy.c:161) Changing state for mobile  0021.5C8C.C761  on AP  
   C8F9.F983.4260  from Idle to Associated
[09/01/13 11:59:19.361 IST 15bd 5933] 0021.5C8C.C761 Stopping deletion of Mobile 
   Station: (callerId: 48)
[09/01/13 11:59:19.361 IST 15be 5933] 0021.5C8C.C761 Ms Timeout = 0, Session 
   Timeout = 1800
[09/01/13 11:59:19.361 IST 15bf 5933] 0021.5C8C.C761 Sending Assoc Response to 
   station on BSSID  C8F9.F983.4260  (status 0) ApVapId 4 Slot 1
[09/01/13 11:59:19.362 IST 15c0 5933] 0021.5C8C.C761 apfProcessAssocReq 
   (apf_80211.c:5260) Changing state for mobile  0021.5C8C.C761  on AP  
   C8F9.F983.4260  from Associated to Associated
[09/01/13 11:59:19.363 IST 15c1 190] [WCDB] ==Add event: type Regular Wireless 
   client (0021.5c8c.c761) client id (0x84fd0000000050) client index (16) vlan (20) 
   auth_state (ASSOCIATION) mob_state (INIT) 
[09/01/13 11:59:19.363 IST 15c2 190] [WCDB] ===intf src/dst (0xb6818000000038)/
   (0x0) radio_id (1) p2p_state (P2P_BLOCKING_DISABLE) switch/asic (1/0) 
[09/01/13 11:59:19.367 IST 15c3 5933] 0021.5C8C.C761 1XA: Initiating 
   authentication
[09/01/13 11:59:19.368 IST 15c4 5933] 0021.5C8C.C761 1XA: Setting reauth timeout 
   to 1800 seconds
 --More-- 
*Sep  1 06:01:59.543: PEM recv processing msg Del SCB(4)  1 wcm:  Time now in sec 
   1378015280, Last Ac.D^Iwsg Sent at 137801522t! w\2105HnJ^Iw_status 0 attr len 
   ^G$8\227v^K
*Sep  1 06:01:59.547: WCDB_IIF: 1 wcm:  Ack Message ID: 0x973c000000004f code 1003
*Sep  1 06:02:50.119: 0021.5C8C.C761 
   Client stats update: 1 wcm:  Time now in sec 1378015370, Last Acct Msg Sent at 
   1378015224 sec
*Sep  1 06:02:50.119: 0021.5C8C.C761 Requested to send acct interim update request 
   msg to APF task for client 0: 1 wcm: 21:5c:8c:c7:61         [09/01/13 11:59:19.368 
   IST 15c5 5933] 0021.5C8C.C761 1XK: Set Link Secure: 0
 --More--         [09/01/13 11:59:19.368 IST 15c6 5933] 0021.5C8C.C761 1XA: 
   Allocated uid 30
[09/01/13 11:59:19.368 IST 15c7 5933] 0021.5C8C.C761 1XA: Calling Auth Mgr to 
   authenticate client 84fd0000000050 uid 30
 --More--         [09/01/13 11:59:19.368 IST 15c8 5933] 0021.5C8C.C761 1XA: 
   Session Start from wireless client 
 --More--     
  
[09/01/13 11:59:19.368 IST 15c9 5933] 0021.5C8C.C761 Session Manager Call Client 
   84fd0000000050, uid 30, capwap id b6818000000038,Flag 0, Audit-Session ID 
   0a6987b05222d7f30000001e, method list ACS 
[09/01/13 11:59:19.368 IST 15ca 33] ACCESS-CORE-SM-CLIENT-SPI-NOTF: 
   [0021.5c8c.c761, Ca1] Session start request from Client[1] for 0021.5c8c.c761 
   (method: Dot1X, method 
   list: ACS, aaa id: 0x0000001E)
[09/01/13 11:59:19.368 IST 15cb 33] ACCESS-CORE-SM-CLIENT-SPI-NOTF: 
   [0021.5c8c.c761, Ca1]  - client iif_id: 84FD0000000050, session ID: 
   0a6987b05222d7f30000001e for 
   0021.5c8c.c761
[09/01/13 11:59:19.368 IST 15cc 33] ACCESS-CORE-SM-CLIENT-SPI-NOTF: 
   [0021.5c8c.c761, Ca1]  - eap profile: none
[09/01/13 11:59:19.368 IST 15cd 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Received session event 'SESSION_START' from client
[09/01/13 11:59:19.368 IST 15ce 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Session start for 0021.5c8c.c761
[09/01/13 11:59:19.368 IST 15cf 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Found 2 sessions on this port, checking host limit
[09/01/13 11:59:19.368 IST 15d0 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Using stored AAA ID 0x0000001E
[09/01/13 11:59:19.368 IST 15d1 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Retrieved Client IIF ID 84FD0000000050
[09/01/13 11:59:19.368 IST 15d2 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Allocated new Auth Manager context (handle 0x32000026)
 --More--         [09/01/13 11:59:19.368 IST 15d3 173] ACCESS-CORE-SM-DEB: 
   [0021.5c8c.c761, Ca1] Client 0021.5c8c.c761, Initialising Method  state to 
   'Not run'
[09/01/13 11:59:19.368 IST 15d4 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] 
   Adding method Session Mgr IPDT Shim to runnable list for session 0x32000026
[09/01/13 11:59:19.368 IST 15d5 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] 
   Client 0021.5c8c.c761, Initialising Method SVM state to 'Not run'
[09/01/13 11:59:19.368 IST 15d6 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] 
   Adding method SVM to runnable list for session 0x32000026
[09/01/13 11:59:19.368 IST 15d7 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] 
   Client 0021.5c8c.c761, Initialising Method  state to 'Not run'
[09/01/13 11:59:19.368 IST 15d8 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] 
   Adding method Switch PI to runnable list for session 0x32000026
[09/01/13 11:59:19.368 IST 15d9 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] 
   Client 0021.5c8c.c761, Initialising Method  state to 'Not run'
[09/01/13 11:59:19.368 IST 15da 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] 
   Adding method Session Mgr SISF Shim to runnable list for session 0x32000026
[09/01/13 11:59:19.368 IST 15db 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] 
   Client 0021.5c8c.c761, Initialising Method iaf state to 'Not run'
[09/01/13 11:59:19.368 IST 15dc 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] 
   Adding method iaf to runnable list for session 0x32000026
[09/01/13 11:59:19.368 IST 15dd 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] 
   Client 0021.5c8c.c761, Initialising Method Tag state to 'Not run'
[09/01/13 11:59:19.368 IST 15de 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] 
   Adding method Tag to runnable list for session 0x32000026
 --More--         [09/01/13 11:59:19.368 IST 15df 173] ACCESS-CORE-SM-DEB: 
   [0021.5c8c.c761, Ca1] Client 0021.5c8c.c761, Initialising Method dct state to 
   'Not run'
[09/01/13 11:59:19.368 IST 15e0 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] 
   Adding method dct to runnable list for session 0x32000026
[09/01/13 11:59:19.368 IST 15e1 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] 
   Client 0021.5c8c.c761, Initialising Method SM Reauth Plugin state to 'Not run'
[09/01/13 11:59:19.368 IST 15e2 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] 
   Adding method SM Reauth Plugin to runnable list for session 0x32000026
[09/01/13 11:59:19.368 IST 15e3 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] 
   Client 0021.5c8c.c761, Initialising Method SM Accounting Feature state to 'Not run'
[09/01/13 11:59:19.368 IST 15e4 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] 
   Adding method SM Accounting Feature to runnable list for session 0x32000026
[09/01/13 11:59:19.368 IST 15e5 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] 
   Client 0021.5c8c.c761, Initialising Method  state to 'Not run'
[09/01/13 11:59:19.368 IST 15e6 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] 
   Adding method Session Mgr FFCP Shim to runnable list for session 0x32000026
[09/01/13 11:59:19.368 IST 15e7 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] 
   Client 0021.5c8c.c761, Initialising Method  state to 'Not run'
[09/01/13 11:59:19.368 IST 15e8 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] 
   Adding method AIM to runnable list for session 0x32000026
[09/01/13 11:59:19.368 IST 15e9 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] 
   Client 0021.5c8c.c761, Initialising Method dot1x state to 'Not run'
[09/01/13 11:59:19.368 IST 15ea 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] 
   Adding method dot1x to runnable list for session 0x32000026
 --More--         [09/01/13 11:59:19.368 IST 15eb 173] ACCESS-CORE-SM-DEB: 
   [0021.5c8c.c761, Ca1] Client 0021.5c8c.c761, Initialising Method mab state to 
   'Not run'
[09/01/13 11:59:19.368 IST 15ec 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] 
   Adding method mab to runnable list for session 0x32000026
[09/01/13 11:59:19.368 IST 15ed 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] 
   Client 0021.5c8c.c761, Initialising Method webauth state to 'Not run'
[09/01/13 11:59:19.368 IST 15ee 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] 
   Adding method webauth to runnable list for session 0x32000026
[09/01/13 11:59:19.368 IST 15ef 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Processing SM CB request for 0x32000026: Event: New client notification (201) 
[09/01/13 11:59:19.368 IST 15f0 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] 
   Create attr list, session 0x32000026:
[09/01/13 11:59:19.368 IST 15f1 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] - 
   adding MAC 0021.5c8c.c761
[09/01/13 11:59:19.368 IST 15f2 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] - 
   adding Swidb 0x99E27F00
[09/01/13 11:59:19.368 IST 15f3 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] - 
   adding AAA_ID=1E
[09/01/13 11:59:19.368 IST 15f4 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] - 
   adding Audit_sid=0a6987b05222d7f30000001e
[09/01/13 11:59:19.368 IST 15f5 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] - 
   adding IIF ID=0x84FD0000000050
[09/01/13 11:59:19.368 IST 15f6 173] ACCESS-CORE-SM-CLIENT-IPDT-NOTF: 
   [0021.5c8c.c761, Ca1] NewClient: No entry for 0021.5c8c.c761. session 0x32000026
 --More--         [09/01/13 11:59:19.368 IST 15f7 173] ACCESS-CORE-SM-NOTF: 
   [0021.5c8c.c761, Ca1] New client 0021.5c8c.c761 - client handle 0x00000001 for SVM
[09/01/13 11:59:19.368 IST 15f8 173] ACCESS-CORE-SM-CLIENT-SISF-NOTF: 
   [0021.5c8c.c761, Ca1] No IPv6 binding found for 0021.5c8c.c761(0x32000026)
[09/01/13 11:59:19.368 IST 15f9 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Added record to DB - hdl 0x32000026 / 0021.5c8c.c761. 3 session(s) on IDB
[09/01/13 11:59:19.368 IST 15fa 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] 
   Add record - adding MAC 0021.5c8c.c761
[09/01/13 11:59:19.368 IST 15fb 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] 
   Add record - adding SWIDB Capwap1
[09/01/13 11:59:19.368 IST 15fc 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] 
   Add record - adding AAA-ID 1E
[09/01/13 11:59:19.368 IST 15fd 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] 
   Add record - adding AUDIT-ID 0a6987b05222d7f30000001e
[09/01/13 11:59:19.368 IST 15fe 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] Add 
   record - adding IIF-ID 0x84FD0000000050
[09/01/13 11:59:19.368 IST 15ff 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] Add 
   record - adding TARGET_SCOPE (Client)
[09/01/13 11:59:19.368 IST 1600 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] No 
   policy handle to bind session
[09/01/13 11:59:19.368 IST 1601 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] 
   Create attr list, session 0x32000026:
[09/01/13 11:59:19.368 IST 1602 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] - 
   adding MAC 0021.5c8c.c761
 --More--         [09/01/13 11:59:19.368 IST 1603 173] ACCESS-CORE-SM-DEB: 
   [0021.5c8c.c761, Ca1] - adding Swidb 0x99E27F00
[09/01/13 11:59:19.368 IST 1604 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] - 
   adding AAA_ID=1E
[09/01/13 11:59:19.368 IST 1605 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] - 
   adding Audit_sid=0a6987b05222d7f30000001e
[09/01/13 11:59:19.368 IST 1606 173] ACCESS-CORE-SM-DEB: [0021.5c8c.c761, Ca1] - 
   adding IIF ID=0x84FD0000000050
[09/01/13 11:59:19.368 IST 1607 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Processing SM CB request for 0x32000026: Event: Start a method (200) 
[09/01/13 11:59:19.368 IST 1608 173] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, 
   Ca1] 0xA100000F: initialising
[09/01/13 11:59:19.368 IST 1609 173] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, 
   Ca1] 0xA100000F: disconnected
[09/01/13 11:59:19.368 IST 160a 173] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, 
   Ca1] 0xA100000F: entering restart
[09/01/13 11:59:19.368 IST 160b 173] ACCESS-METHOD-DOT1X-NOTF: [0021.5c8c.c761, 
   Ca1] Override cfg - MAC 0021.5c8c.c761 - profile (none)
[09/01/13 11:59:19.368 IST 160c 173] ACCESS-METHOD-DOT1X-NOTF: [0021.5c8c.c761, 
   Ca1] Override cfg - SuppTimeout 30s, ReAuthMax 2, MaxReq 2, TxPeriod 30s
[09/01/13 11:59:19.368 IST 160d 173] ACCESS-METHOD-DOT1X-NOTF: [0021.5c8c.c761, 
   Ca1] Sending create new context event to EAP for 0xA100000F (0021.5c8c.c761)
[09/01/13 11:59:19.368 IST 160e 173] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, 
   Ca1] 0xA100000F: entering init state
 --More--         [09/01/13 11:59:19.368 IST 160f 173] ACCESS-METHOD-DOT1X-DEB: 
   [0021.5c8c.c761, Ca1] 0xA100000F:entering idle state
[09/01/13 11:59:19.368 IST 1610 173] ACCESS-METHOD-DOT1X-NOTF: [0021.5c8c.c761, 
   Ca1] Created a client entry (0xA100000F)
[09/01/13 11:59:19.368 IST 1611 173] ACCESS-METHOD-DOT1X-NOTF: [0021.5c8c.c761, 
   Ca1] Dot1x authentication started for 0xA100000F (0021.5c8c.c761)
[09/01/13 11:59:19.368 IST 1612 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Client 0021.5c8c.c761, Context changing state from 'Idle' to 'Running'
[09/01/13 11:59:19.368 IST 1613 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Client 0021.5c8c.c761, Method dot1x changing state from 'Not run' to 'Running'
[09/01/13 11:59:19.368 IST 1614 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   SM will not apply policy for SESSION_STARTED on 0x32000026 / 0021.5c8c.c761
[09/01/13 11:59:19.368 IST 1615 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Processing default action(s) for event SESSION_STARTED for session 0x32000026.
[09/01/13 11:59:19.368 IST 1616 179] ACCESS-CORE-SM-CLIENT-DOT11-NOTF: 
   [0021.5c8c.c761, Ca1] DB alloc for 0021.5c8c.c761
[09/01/13 11:59:19.368 IST 1617 179] ACCESS-CORE-SM-CLIENT-DOT11-NOTF: 
   [0021.5c8c.c761, Ca1] Dot11 params, bssid: c8f9.f983.4260, radio id: 1, wlan id: 4, 
   assoc id: 3, ssid: EAPFAST
[09/01/13 11:59:19.368 IST 1618 179] ACCESS-CORE-SM-CLIENT-DOT11-NOTF: 
   [0021.5c8c.c761, Ca1] Dot11 params, wlan bssid set to: c8f9.f983.426c
[09/01/13 11:59:19.368 IST 1619 262] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   Posting !EAP_RESTART on Client 0xA100000F
[09/01/13 11:59:19.368 IST 161a 262] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:enter connecting state
 --More--         [09/01/13 11:59:19.368 IST 161b 262] ACCESS-METHOD-DOT1X-DEB: 
   [0021.5c8c.c761, Ca1] 0xA100000F: restart connecting
[09/01/13 11:59:19.368 IST 161c 262] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   Posting RX_REQ on Client 0xA100000F
[09/01/13 11:59:19.368 IST 161d 262] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F: authenticating state entered
[09/01/13 11:59:19.368 IST 161e 262] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:connecting authenticating action
[09/01/13 11:59:19.368 IST 161f 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   Posting AUTH_START for 0xA100000F
[09/01/13 11:59:19.368 IST 1620 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:entering request state
[09/01/13 11:59:19.368 IST 1621 270] ACCESS-METHOD-DOT1X-NOTF: [0021.5c8c.c761, Ca1] 
   Sending EAPOL packet
[09/01/13 11:59:19.368 IST 1622 270] ACCESS-METHOD-DOT1X-INFO: [0021.5c8c.c761, Ca1] 
   Platform changed src mac  of EAPOL packet
[09/01/13 11:59:19.368 IST 1623 270] ACCESS-METHOD-DOT1X-INFO: [0021.5c8c.c761, Ca1] 
   EAPOL packet sent to client 0xA100000F
[09/01/13 11:59:19.368 IST 1624 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:idle request action
[09/01/13 11:59:19.500 IST 1625 176] ACCESS-METHOD-DOT1X-INFO: [0021.5c8c.c761, Ca1] 
   Queuing an EAPOL pkt on Authenticator Q
[09/01/13 11:59:19.500 IST 1626 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] SM 
   will not apply policy for RX_METHOD_AGENT_FOUND on 0x32000026 / 0021.5c8c.c761
 --More--         [09/01/13 11:59:19.500 IST 1627 173] ACCESS-CORE-SM-NOTF: 
   [0021.5c8c.c761, Ca1] Processing default action(s) for event RX_METHOD_AGENT_FOUND 
   for session 0x32000026.
[09/01/13 11:59:19.500 IST 1628 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, 
   Ca1] 
   Posting EAPOL_EAP for 0xA100000F
[09/01/13 11:59:19.500 IST 1629 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:entering response state
[09/01/13 11:59:19.500 IST 162a 270] ACCESS-METHOD-DOT1X-NOTF: [0021.5c8c.c761, Ca1] 
   Response sent to the server from 0xA100000F
[09/01/13 11:59:19.500 IST 162b 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:request response action
[09/01/13 11:59:19.503 IST 162c 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   Posting EAP_REQ for 0xA100000F
[09/01/13 11:59:19.503 IST 162d 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:exiting response state
[09/01/13 11:59:19.503 IST 162e 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:entering request state
[09/01/13 11:59:19.503 IST 162f 270] ACCESS-METHOD-DOT1X-NOTF: [0021.5c8c.c761, Ca1] 
   Sending EAPOL packet
[09/01/13 11:59:19.503 IST 1630 270] ACCESS-METHOD-DOT1X-INFO: [0021.5c8c.c761, Ca1] 
   Platform changed src mac  of EAPOL packet
[09/01/13 11:59:19.503 IST 1631 270] ACCESS-METHOD-DOT1X-INFO: [0021.5c8c.c761, Ca1] 
   EAPOL packet sent to client 0xA100000F
[09/01/13 11:59:19.503 IST 1632 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:response request action
 --More--         [09/01/13 11:59:19.525 IST 1633 176] ACCESS-METHOD-DOT1X-INFO: 
   [0021.5c8c.c761, Ca1] Queuing an EAPOL pkt on Authenticator Q
[09/01/13 11:59:19.525 IST 1634 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   Posting EAPOL_EAP for 0xA100000F
[09/01/13 11:59:19.525 IST 1635 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:entering response state
[09/01/13 11:59:19.525 IST 1636 270] ACCESS-METHOD-DOT1X-NOTF: [0021.5c8c.c761, Ca1] 
   Response sent to the server from 0xA100000F
[09/01/13 11:59:19.525 IST 1637 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:request response action
[09/01/13 11:59:19.529 IST 1638 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   Posting EAP_REQ for 0xA100000F
[09/01/13 11:59:19.529 IST 1639 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:exiting response state
[09/01/13 11:59:19.529 IST 163a 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:entering request state
[09/01/13 11:59:19.529 IST 163b 270] ACCESS-METHOD-DOT1X-NOTF: [0021.5c8c.c761, Ca1] 
   Sending EAPOL packet
[09/01/13 11:59:19.529 IST 163c 270] ACCESS-METHOD-DOT1X-INFO: [0021.5c8c.c761, Ca1] 
   Platform changed src mac  of EAPOL packet
[09/01/13 11:59:19.529 IST 163d 270] ACCESS-METHOD-DOT1X-INFO: [0021.5c8c.c761, Ca1] 
   EAPOL packet sent to client 0xA100000F
[09/01/13 11:59:19.529 IST 163e 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:response request action
 --More--         [09/01/13 11:59:21.191 IST 163f 176] ACCESS-METHOD-DOT1X-INFO: 
   [0021.5c8c.c761, Ca1] Queuing an EAPOL pkt on Authenticator Q
[09/01/13 11:59:21.191 IST 1640 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   Posting EAPOL_EAP for 0xA100000F
[09/01/13 11:59:21.191 IST 1641 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:entering response state
[09/01/13 11:59:21.191 IST 1642 270] ACCESS-METHOD-DOT1X-NOTF: [0021.5c8c.c761, Ca1] 
   Response sent to the server from 0xA100000F
[09/01/13 11:59:21.191 IST 1643 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:request response action
[09/01/13 11:59:21.194 IST 1644 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   Posting EAP_REQ for 0xA100000F
[09/01/13 11:59:21.194 IST 1645 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:exiting response state
[09/01/13 11:59:21.194 IST 1646 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:entering request state
[09/01/13 11:59:21.194 IST 1647 270] ACCESS-METHOD-DOT1X-NOTF: [0021.5c8c.c761, Ca1] 
   Sending EAPOL packet
[09/01/13 11:59:21.194 IST 1648 270] ACCESS-METHOD-DOT1X-INFO: [0021.5c8c.c761, Ca1] 
   Platform changed src mac  of EAPOL packet
[09/01/13 11:59:21.194 IST 1649 270] ACCESS-METHOD-DOT1X-INFO: [0021.5c8c.c761, Ca1] 
   EAPOL packet sent to client 0xA100000F
[09/01/13 11:59:21.194 IST 164a 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:response request action
 --More--         [09/01/13 11:59:21.201 IST 164b 176] ACCESS-METHOD-DOT1X-INFO: 
   [0021.5c8c.c761, Ca1] Queuing an EAPOL pkt on Authenticator Q
[09/01/13 11:59:21.201 IST 164c 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   Posting EAPOL_EAP for 0xA100000F
[09/01/13 11:59:21.201 IST 164d 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:entering response state
[09/01/13 11:59:21.201 IST 164e 270] ACCESS-METHOD-DOT1X-NOTF: [0021.5c8c.c761, Ca1] 
   Response sent to the server from 0xA100000F
[09/01/13 11:59:21.201 IST 164f 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:request response action
[09/01/13 11:59:21.203 IST 1650 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   Posting EAP_REQ for 0xA100000F
[09/01/13 11:59:21.203 IST 1651 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:exiting response state
[09/01/13 11:59:21.203 IST 1652 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
  0xA100000F:entering request state
[09/01/13 11:59:21.203 IST 1653 270] ACCESS-METHOD-DOT1X-NOTF: [0021.5c8c.c761, Ca1] 
   Sending EAPOL packet
[09/01/13 11:59:21.203 IST 1654 270] ACCESS-METHOD-DOT1X-INFO: [0021.5c8c.c761, Ca1] 
   Platform changed src mac  of EAPOL packet
[09/01/13 11:59:21.203 IST 1655 270] ACCESS-METHOD-DOT1X-INFO: [0021.5c8c.c761, Ca1] 
   EAPOL packet sent to client 0xA100000F
[09/01/13 11:59:21.203 IST 1656 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:response request action
 --More--         [09/01/13 11:59:21.213 IST 1657 176] ACCESS-METHOD-DOT1X-INFO: 
   [0021.5c8c.c761, Ca1] Queuing an EAPOL pkt on Authenticator Q
[09/01/13 11:59:21.213 IST 1658 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   Posting EAPOL_EAP for 0xA100000F
[09/01/13 11:59:21.213 IST 1659 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:entering response state
[09/01/13 11:59:21.213 IST 165a 270] ACCESS-METHOD-DOT1X-NOTF: [0021.5c8c.c761, Ca1] 
   Response sent to the server from 0xA100000F
[09/01/13 11:59:21.213 IST 165b 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:request response action
[09/01/13 11:59:21.220 IST 165c 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   Posting EAP_REQ for 0xA100000F
[09/01/13 11:59:21.220 IST 165d 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:exiting response state
[09/01/13 11:59:21.220 IST 165e 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:entering request state
[09/01/13 11:59:21.220 IST 165f 270] ACCESS-METHOD-DOT1X-NOTF: [0021.5c8c.c761, Ca1] 
   Sending EAPOL packet
[09/01/13 11:59:21.220 IST 1660 270] ACCESS-METHOD-DOT1X-INFO: [0021.5c8c.c761, Ca1] 
   Platform changed src mac  of EAPOL packet
[09/01/13 11:59:21.220 IST 1661 270] ACCESS-METHOD-DOT1X-INFO: [0021.5c8c.c761, Ca1] 
   EAPOL packet sent to client 0xA100000F
[09/01/13 11:59:21.220 IST 1662 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:response request action
 --More--         [09/01/13 11:59:21.224 IST 1663 176] ACCESS-METHOD-DOT1X-INFO: 
   [0021.5c8c.c761, Ca1] Queuing an EAPOL pkt on Authenticator Q
[09/01/13 11:59:21.224 IST 1664 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   Posting EAPOL_EAP for 0xA100000F
[09/01/13 11:59:21.224 IST 1665 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:entering response state
[09/01/13 11:59:21.224 IST 1666 270] ACCESS-METHOD-DOT1X-NOTF: [0021.5c8c.c761, Ca1] 
   Response sent to the server from 0xA100000F
[09/01/13 11:59:21.224 IST 1667 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:request response action
[09/01/13 11:59:21.227 IST 1668 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   Posting EAP_REQ for 0xA100000F
[09/01/13 11:59:21.227 IST 1669 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:exiting response state
[09/01/13 11:59:21.227 IST 166a 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:entering request state
[09/01/13 11:59:21.227 IST 166b 270] ACCESS-METHOD-DOT1X-NOTF: [0021.5c8c.c761, Ca1] 
   Sending EAPOL packet
[09/01/13 11:59:21.227 IST 166c 270] ACCESS-METHOD-DOT1X-INFO: [0021.5c8c.c761, Ca1] 
   Platform changed src mac  of EAPOL packet
[09/01/13 11:59:21.227 IST 166d 270] ACCESS-METHOD-DOT1X-INFO: [0021.5c8c.c761, Ca1] 
   EAPOL packet sent to client 0xA100000F
[09/01/13 11:59:21.227 IST 166e 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:response request action
 --More--         [09/01/13 11:59:21.235 IST 166f 176] ACCESS-METHOD-DOT1X-INFO: 
   [0021.5c8c.c761, Ca1] Queuing an EAPOL pkt on Authenticator Q
[09/01/13 11:59:21.235 IST 1670 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   Posting EAPOL_EAP for 0xA100000F
[09/01/13 11:59:21.235 IST 1671 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:entering response state
[09/01/13 11:59:21.235 IST 1672 270] ACCESS-METHOD-DOT1X-NOTF: [0021.5c8c.c761, Ca1] 
   Response sent to the server from 0xA100000F
[09/01/13 11:59:21.235 IST 1673 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:request response action
[09/01/13 11:59:21.238 IST 1674 179] ACCESS-METHOD-DOT1X-INFO: [0021.5c8c.c761, Ca1] 
   Received an EAP Success
[09/01/13 11:59:21.238 IST 1675 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   Posting EAP_SUCCESS for 0xA100000F
[09/01/13 11:59:21.238 IST 1676 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:exiting response state
[09/01/13 11:59:21.238 IST 1677 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:entering success state
[09/01/13 11:59:21.238 IST 1678 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:response success action
[09/01/13 11:59:21.238 IST 1679 270] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   00xA100000F:entering idle state
[09/01/13 11:59:21.238 IST 167a 262] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   Posting AUTH_SUCCESS on Client 0xA100000F
 --More--         [09/01/13 11:59:21.238 IST 167b 262] ACCESS-METHOD-DOT1X-DEB: 
   [0021.5c8c.c761, Ca1] 0xA100000F:exiting authenticating state
[09/01/13 11:59:21.238 IST 167c 262] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:entering authc result state
[09/01/13 11:59:21.238 IST 167d 262] ACCESS-METHOD-DOT1X-NOTF: [0021.5c8c.c761, Ca1] 
   Sending EAPOL success immediately
[09/01/13 11:59:21.238 IST 167e 262] ACCESS-METHOD-DOT1X-NOTF: [0021.5c8c.c761, Ca1] 
   Sending EAPOL packet
[09/01/13 11:59:21.238 IST 167f 262] ACCESS-METHOD-DOT1X-INFO: [0021.5c8c.c761, Ca1] 
   Platform changed src mac  of EAPOL packet
[09/01/13 11:59:21.239 IST 1680 262] ACCESS-METHOD-DOT1X-INFO: [0021.5c8c.c761, Ca1] 
   EAPOL packet sent to client 0xA100000F
[09/01/13 11:59:21.239 IST 1681 262] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Authc success from Dot1X (1), status OK (0) / event success (0)
[09/01/13 11:59:21.239 IST 1682 262] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Highest prio method: INVALID, Authz method: INVALID, Conn hdl: dot1x
[09/01/13 11:59:21.239 IST 1683 262] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Queued AUTHC SUCCESS from Dot1X for session 0x32000026 (0021.5c8c.c761)
[09/01/13 11:59:21.239 IST 1684 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Received internal event APPLY_USER_PROFILE (handle 0x32000026)
[09/01/13 11:59:21.239 IST 1685 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Clearing AAA data for: 0021.5c8c.c761
[09/01/13 11:59:21.239 IST 1686 173] ACCESS-CORE-SM-SYNC-NOTF: [0021.5c8c.c761, Ca1] 
   Delay add/update sync of username for 0021.5c8c.c761 / 0x32000026
 --More--         [09/01/13 11:59:21.239 IST 1687 173] ACCESS-CORE-SM-NOTF: 
   [0021.5c8c.c761, Ca1] Received User-Name user for client 0021.5c8c.c761
[09/01/13 11:59:21.239 IST 1688 173] ACCESS-CORE-SM-SYNC-NOTF: [0021.5c8c.c761, Ca1] 
   Delay add/update sync of auth-domain for 0021.5c8c.c761 / 0x32000026
[09/01/13 11:59:21.239 IST 1689 173] ACCESS-CORE-SM-SYNC-NOTF: [0021.5c8c.c761, Ca1] 
   Delay add/update sync of target-scope for 0021.5c8c.c761 / 0x32000026
[09/01/13 11:59:21.239 IST 168a 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Existing AAA ID: 0x0000001E
[09/01/13 11:59:21.239 IST 168b 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Client 0021.5c8c.c761, Method dot1x changing state from 'Running' to 'Authc Success'
[09/01/13 11:59:21.239 IST 168c 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Client 0021.5c8c.c761, Context changing state from 'Running' to 'Authc Success'
[09/01/13 11:59:21.239 IST 168d 173] ACCESS-CORE-SM-CLIENT-DOT11-NOTF: 
   [0021.5c8c.c761, Ca1] Applying authz attrs - 0x1D0003FF
[09/01/13 11:59:21.239 IST 168e 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Non-SM policy applied for 0x32000026. Authz_attrs not freed
[09/01/13 11:59:21.239 IST 168f 173] ACCESS-CORE-SM-SYNC-NOTF: [0021.5c8c.c761, Ca1] 
   Delay add/update sync of method for 0021.5c8c.c761 / 0x32000026
[09/01/13 11:59:21.239 IST 1690 173] ACCESS-CORE-SM-CLIENT-DOT11-NOTF: 
   [0021.5c8c.c761, Ca1] Dot11: authz success signalled for 0021.5c8c.c761
[09/01/13 11:59:21.239 IST 1691 173] ACCESS-CORE-SM-CLIENT-SPI-NOTF: 
   [0021.5c8c.c761, Ca1] Session authz status notification sent to Client[1] for 
   0021.5c8c.c761 with handle CE38188, list 1D0003FF
 --More--         [09/01/13 11:59:21.239 IST 1692 173] ACCESS-CORE-SM-NOTF: 
   [0021.5c8c.c761, Ca1] SM will not apply policy for RX_METHOD_AUTHC_SUCCESS on 
   0x32000026 / 0021.5c8c.c761
[09/01/13 11:59:21.239 IST 1693 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Processing default action(s) for event RX_METHOD_AUTHC_SUCCESS for session 
   0x32000026.
[09/01/13 11:59:21.239 IST 1694 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Executing default action handler for AUTHC SUCCESS (0x32000026)
[09/01/13 11:59:21.239 IST 1695 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   AUTHC_SUCCESS - authorize by default
[09/01/13 11:59:21.239 IST 1696 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Signalling Authz success for client 0021.5c8c.c761
[09/01/13 11:59:21.239 IST 1697 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Client 0021.5c8c.c761, Context changing state from 'Authc Success' to 'Authz 
   Success'
[09/01/13 11:59:21.239 IST 1698 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Processing SM CB request for 0x32000026: Event: Authorize request (216) 
[09/01/13 11:59:21.239 IST 1699 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Authz complete (SUCCESS) for client 0021.5c8c.c761/0x32000026 reported
[09/01/13 11:59:21.239 IST 169a 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Received internal event AUTHZ_SUCCESS (handle 0x32000026)
[09/01/13 11:59:21.239 IST 169b 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Processing AUTHZ_CB RESULT (success) for 0x32000026
[09/01/13 11:59:21.239 IST 169c 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Processing SM CB request for 0x32000026: Event: Authz result processed (215) 
 --More--         [09/01/13 11:59:21.239 IST 169d 173] ACCESS-CORE-SM-NOTF: 
   [0021.5c8c.c761, Ca1] Authz result processed, result: 0
[09/01/13 11:59:21.239 IST 169e 173] ACCESS-METHOD-DOT1X-NOTF: [0021.5c8c.c761, Ca1] 
   Received Authz Success for the client 0xA100000F (0021.5c8c.c761)
[09/01/13 11:59:21.239 IST 169f 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] SM 
   Reauth Plugin: Client authz change, result=Success
[09/01/13 11:59:21.239 IST 16a0 173] ACCESS-CORE-SM-NOTF: [0021.5c8c.c761, Ca1] 
   Signalling Authz complete (success) for client 0x32000026
[09/01/13 11:59:21.239 IST 16a1 262] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   Posting AUTHZ_SUCCESS on Client 0xA100000F
[09/01/13 11:59:21.239 IST 16a2 262] ACCESS-METHOD-DOT1X-DEB: [0021.5c8c.c761, Ca1] 
   0xA100000F:entering authenticated state
[09/01/13 11:59:21.239 IST 16a3 262] ACCESS-METHOD-DOT1X-NOTF: [0021.5c8c.c761, Ca1] 
   EAPOL success packet was sent earlier.
[09/01/13 11:59:21.239 IST 16a4 5933] 0021.5C8C.C761 1XA: received authentication 
   response, status=0 AAA ID=0 protocol=0
[09/01/13 11:59:21.239 IST 16a5 5933] 0021.5C8C.C761 1XA: Handling status 
   notification request from dot1x, uid=30/0
[09/01/13 11:59:21.239 IST 16a6 5933] 0021.5C8C.C761 
   client incoming attribute size are 485
[09/01/13 11:59:21.239 IST 16a7 5933] 0021.5C8C.C761 1XA: received RADIUS attr 
   type 450
[09/01/13 11:59:21.239 IST 16a8 5933] 0021.5C8C.C761 1XA: received RADIUS attr 
   type 450
 --More--         [09/01/13 11:59:21.239 IST 16a9 5933] 0021.5C8C.C761 1XA: 
   received RADIUS attr type 383
[09/01/13 11:59:21.239 IST 16aa 5933] 0021.5C8C.C761 1XA: received RADIUS attr 
   type 383
[09/01/13 11:59:21.239 IST 16ab 5933] 0021.5C8C.C761 1XA: received RADIUS attr 
   type 87
[09/01/13 11:59:21.239 IST 16ac 5933] 0021.5C8C.C761 1XA: received RADIUS attr 
   type 87
[09/01/13 11:59:21.239 IST 16ad 5933] 0021.5C8C.C761 1XA: received RADIUS attr 
   type 274
[09/01/13 11:59:21.239 IST 16ae 5933] 0021.5C8C.C761 1XA: received RADIUS attr 
   type 274
[09/01/13 11:59:21.239 IST 16af 5933] 0021.5C8C.C761 1XA: received RADIUS attr 
   type 88
[09/01/13 11:59:21.239 IST 16b0 5933] 0021.5C8C.C761 1XA: received RADIUS attr 
   type 88
[09/01/13 11:59:21.239 IST 16b1 5933] 0021.5C8C.C761 1XA: received RADIUS attr 
   type 661
[09/01/13 11:59:21.239 IST 16b2 5933] 0021.5C8C.C761 1XA: received RADIUS attr 
   type 661
[09/01/13 11:59:21.239 IST 16b3 5933] 0021.5C8C.C761 1XA: received RADIUS attr 
   type 662
[09/01/13 11:59:21.239 IST 16b4 5933] 0021.5C8C.C761 1XA: received RADIUS attr 
   type 662
 --More--         [09/01/13 11:59:21.239 IST 16b5 5933] 0021.5C8C.C761 1XA: 
   received RADIUS attr type 82
[09/01/13 11:59:21.239 IST 16b6 5933] 0021.5C8C.C761 1XA: received RADIUS attr 
   type 82
[09/01/13 11:59:21.239 IST 16b7 5933] 0021.5C8C.C761 1XA: received RADIUS attr 
   type 37
[09/01/13 11:59:21.239 IST 16b8 5933] 0021.5C8C.C761 1XA: received RADIUS attr 
   type 37
[09/01/13 11:59:21.239 IST 16b9 5933] 0021.5C8C.C761 1XA: received RADIUS attr 
   type 819
[09/01/13 11:59:21.239 IST 16ba 5933] 0021.5C8C.C761 1XA: received RADIUS attr 
   type 819
[09/01/13 11:59:21.239 IST 16bb 5933] 0021.5C8C.C761 Applying new AAA override for 
   station  0021.5C8C.C761 
[09/01/13 11:59:21.239 IST 16bc 5933] 0021.5C8C.C761 Override values (cont..) 
   dataAvgC: -1, rTAvgC: -1, dataBurstC: -1, rTimeBurstC: -1    vlanIfName: '', 
   aclName: ''
[09/01/13 11:59:21.239 IST 16bd 5933] 0021.5C8C.C761 Not applying override policy - 
   allow override is FALSE
[09/01/13 11:59:21.239 IST 16be 5933] 0021.5C8C.C761 1XA: Setting reauth timeout to 
   1800 seconds from WLAN config
[09/01/13 11:59:21.239 IST 16bf 5933] 0021.5C8C.C761 1XA: Setting reauth timeout to 
   1800 seconds
 --More--         [09/01/13 11:59:21.239 IST 16c0 5933] 0021.5C8C.C761 1XK: Creating 
   a PKC PMKID Cache entry (RSN 1)
[09/01/13 11:59:21.239 IST 16c1 5933] 0021.5C8C.C761 1XK: Set Link Secure: 0
[09/01/13 11:59:21.239 IST 16c2 5933] 0021.5C8C.C761 1XK: Set Link Secure: 0
[09/01/13 11:59:21.239 IST 16c3 5933] 0021.5C8C.C761 1XK: Looking for BSSID  
   C8F9.F983.426C  in PMKID cache
[09/01/13 11:59:21.239 IST 16c4 5933] 0021.5C8C.C761 1XK: Adding BSSID  
   C8F9.F983.426C  to PMKID cache
[09/01/13 11:59:21.239 IST 16c5 5933] 0021.5C8C.C761 1XA: Disabling reauth - using 
   PMK lifetime instead
[09/01/13 11:59:21.239 IST 16c6 5933] 0021.5C8C.C761 Radius overrides disabled, 
   ignoring source 4
[09/01/13 11:59:21.239 IST 16c7 5933] 0021.5C8C.C761 Radius overrides disabled, 
   ignoring source 4
[09/01/13 11:59:21.239 IST 16c8 5933] 0021.5C8C.C761 Radius overrides disabled, 
   ignoring source 4
[09/01/13 11:59:21.239 IST 16c9 5933] 0021.5C8C.C761 PMK sent to mobility group
[09/01/13 11:59:21.239 IST 16ca 5933] 0021.5C8C.C761 1XA: authentication succeeded
[09/01/13 11:59:21.239 IST 16cb 5933] 0021.5C8C.C761 1XK: Looking for BSSID  
   C8F9.F983.426C  in PMKID cache
[09/01/13 11:59:21.239 IST 16cc 5933] 0021.5C8C.C761 1XK: Looking for BSSID  
   C8F9.F983.426C  in PMKID cache
 --More--         [09/01/13 11:59:21.239 IST 16cd 5933] 0021.5C8C.C761 Starting key 
   exchange with mobile - data forwarding is disabled
[09/01/13 11:59:21.239 IST 16ce 5933] 0021.5C8C.C761 1XA: Sending EAPOL message to 
   mobile, WLAN=4 AP WLAN=4
[09/01/13 11:59:21.246 IST 16cf 5933] 0021.5C8C.C761 1XA: Received 802.11 EAPOL 
   message (len 123) from mobile
[09/01/13 11:59:21.246 IST 16d0 5933] 0021.5C8C.C761 1XA: Received EAPOL-Key from 
   mobile
[09/01/13 11:59:21.246 IST 16d1 5933] 0021.5C8C.C761 1XK: Received EAPOL-key in 
   PTK_START state (msg 2) from mobile
[09/01/13 11:59:21.246 IST 16d2 5933] 0021.5C8C.C761 1XK: Stopping retransmission 
   timer
[09/01/13 11:59:21.246 IST 16d3 5933] 0021.5C8C.C761 1XA: Sending EAPOL message to 
   mobile, WLAN=4 AP WLAN=4
[09/01/13 11:59:21.258 IST 16d4 5933] 0021.5C8C.C761 1XA: Received 802.11 EAPOL 
   message (len 99) from mobile
[09/01/13 11:59:21.258 IST 16d5 5933] 0021.5C8C.C761 1XA: Received EAPOL-Key from 
   mobile
[09/01/13 11:59:21.258 IST 16d6 5933] 0021.5C8C.C761 1XK: Received EAPOL-key in 
   PTKINITNEGOTIATING state (msg 4) from mobile
[09/01/13 11:59:21.258 IST 16d7 5933] 0021.5C8C.C761 1XK: Set Link Secure: 1
[09/01/13 11:59:21.258 IST 16d8 5933] 0021.5C8C.C761 1XK: Key exchange complete - 
   updating PEM
 --More--         [09/01/13 11:59:21.258 IST 16d9 5933] 0021.5C8C.C761 
   apfMs1xStateInc
[09/01/13 11:59:21.258 IST 16da 5933] 0021.5C8C.C761 WCDB_AUTH: Adding opt82 len 0
[09/01/13 11:59:21.258 IST 16db 5933] 0021.5C8C.C761 WCDB_LLM: NoRun Prev Mob 0, 
   Curr Mob 0 llmReq 1, return False
[09/01/13 11:59:21.258 IST 16dc 5933] 0021.5C8C.C761 WCDB_CHANGE: auth=L2_AUTH(1) 
   vlan 20 radio 1 client_id 0x84fd0000000050 mobility=Unassoc(0) src_int 
   0xb6818000000038 dst_int 0x0 ackflag 0 reassoc_client 0 llm_notif 0 ip  0.0.0.0 
   ip_learn_type UNKNOWN
[09/01/13 11:59:21.258 IST 16dd 5933] 0021.5C8C.C761 WCDB_CHANGE: In L2 auth but 
   l2ack waiting lfag not set,so set
[09/01/13 11:59:21.258 IST 16de 5933] 0021.5C8C.C761 Not Using WMM Compliance code 
   qosCap 00
[09/01/13 11:59:21.258 IST 16df 5933] 0021.5C8C.C761 WCDB_AUTH: Adding opt82 len 0
[09/01/13 11:59:21.258 IST 16e0 5933] 0021.5C8C.C761 WCDB_CHANGE: Suppressing SPI 
   (Mobility state not known) pemstate 7 state LEARN_IP(2) vlan 20 client_id 
   0x84fd0000000050 mob=Unassoc(0) ackflag 1 dropd 0
[09/01/13 11:59:21.258 IST 16e1 5933] 0021.5C8C.C761 Incrementing the Reassociation 
   Count 1 for client (of interface VLAN0020)
[09/01/13 11:59:21.258 IST 16e2 5933] 0021.5C8C.C761 1XK: Stopping retransmission 
   timer
[09/01/13 11:59:21.258 IST 16e3 5933] 0021.5C8C.C761 0.0.0.0, auth_state 7 mmRole 
   Unassoc !!!
 --More--         [09/01/13 11:59:21.258 IST 16e4 5933] 0021.5C8C.C761 0.0.0.0, 
   auth_state 7 mmRole Unassoc, updating wcdb not needed
[09/01/13 11:59:21.258 IST 16e5 5933] 0021.5C8C.C761 Tclas Plumb needed: 0
[09/01/13 11:59:21.258 IST 16e6 5933] 0021.5C8C.C761 WCDB_AUTH: Adding opt82 len 0
[09/01/13 11:59:21.258 IST 16e7 5933] 0021.5C8C.C761 WCDB_LLM: NoRun Prev Mob 0, 
   Curr Mob 1 llmReq 1, return False
[09/01/13 11:59:21.258 IST 16e8 5933] 0021.5C8C.C761 WCDB_CHANGE: Suppressing SPI 
   (ACK message not recvd) pemstate 7 state LEARN_IP(2) vlan 20 
   client_id 0x84fd0000000050 mob=Local(1) ackflag 1 dropd 1
[09/01/13 11:59:21.258 IST 16e9 5933] 0021.5C8C.C761 Error updating wcdb on mobility 
   complete 
[09/01/13 11:59:21.258 IST 16ea 5933] 0021.5C8C.C761 aaa attribute list length is 79
[09/01/13 11:59:21.258 IST 16eb 5933] 0021.5C8C.C761 Sending SPI 
   spi_epm_epm_session_create successfull
[09/01/13 11:59:21.259 IST 16ec 5933] 0021.5C8C.C761 0.0.0.0, auth_state 7 mmRole 
   Local !!!
[09/01/13 11:59:21.259 IST 16ed 5933] 0021.5C8C.C761 0.0.0.0, auth_state 7 mmRole 
   Local, updating wcdb not needed
[09/01/13 11:59:21.259 IST 16ee 5933] 0021.5C8C.C761 Tclas Plumb needed: 0
[09/01/13 11:59:21.260 IST 16ef 190] [WCDB] ==Update event: client (0021.5c8c.c761) 
   client id:(0x84fd0000000050) vlan (20->20) global_wlan (4->4) auth_state 
   (ASSOCIATION->L2_AUTH_DONE) mob_state (INIT->INIT)
 --More--         [09/01/13 11:59:21.260 IST 16f0 190] [WCDB] ===intf src/dst 
   (0xb6818000000038->0xb6818000000038)/(0x0->0x0) radio/bssid 
   (1->1)/(c8f9.f983.4260->c8f9.f983.4260) llm_notify (false) addr v4/v6 (0)/(0)
[09/01/13 11:59:21.260 IST 16f1 190] [WCDB] wcdb_client_mcast_update_notify: No 
   mcast action reqd
[09/01/13 11:59:21.260 IST 16f2 190] [WCDB] Allocating Client LE and waiting for 
   ACK
[09/01/13 11:59:21.260 IST 16f3 190] [WCDB] wcdb_ffcp_wcdb_client_add_notify: 
   client (0021.5c8c.c761) id 0x84fd0000000050 ffcp create flags=0x0 iifid 
   bssid/radio = 0x81fac000000041/0xbfcdc00000003a, src_intf = 0xb6818000000038
[09/01/13 11:59:21.261 IST 16f4 5933] 0021.5C8C.C761 Received 
   session_create_response for client handle 37432873367634000
[09/01/13 11:59:21.261 IST 16f5 5933] 0021.5C8C.C761 Received 
   session_create_response with EPM session handle 4060086311
[09/01/13 11:59:21.261 IST 16f6 5933] 0021.5C8C.C761 Send request to EPM
[09/01/13 11:59:21.261 IST 16f7 5933] 0021.5C8C.C761 aaa attribute list length is 
   485
[09/01/13 11:59:21.261 IST 16f8 5933] 0021.5C8C.C761 Sending Activate request for 
   session handle 4060086311 successful
[09/01/13 11:59:21.261 IST 16f9 5933] 0021.5C8C.C761 Post-auth policy request sent! 
   Now wait for post-auth policy ACK from EPM
[09/01/13 11:59:21.261 IST 16fa 5933] 0021.5C8C.C761 Received 
   activate_features_resp for client handle 37432873367634000
[09/01/13 11:59:21.261 IST 16fb 5933] 0021.5C8C.C761 Received 
   activate_features_resp for EPM session handle 4060086311
 --More--         [09/01/13 11:59:21.262 IST 16fc 5933] 0021.5C8C.C761 Received 
   policy_enforcement_response for client handle 37432873367634000
[09/01/13 11:59:21.262 IST 16fd 5933] 0021.5C8C.C761 Received 
   policy_enforcement_response for EPM session handle 2818572305
[09/01/13 11:59:21.262 IST 16fe 5933] 0021.5C8C.C761 Received response 
   for _EPM_SPI_ACTIVATE_FEATURES request sent for client
[09/01/13 11:59:21.262 IST 16ff 5933] 0021.5C8C.C761 
   Received _EPM_SPI_STATUS_SUCCESS for request sent for client
[09/01/13 11:59:21.262 IST 1700 5933] 0021.5C8C.C761 Post-auth policy ACK recvd 
   from EPM, unset flag on MSCB
[09/01/13 11:59:21.262 IST 1701 33] [WCDB] wcdb_ffcp_add_cb: client (0021.5c8c.c761) 
   client (0x84fd0000000050): FFCP operation (CREATE) return code (0)
[09/01/13 11:59:21.262 IST 1702 33] [WCDB] wcdb_send_add_notify_callback_event: 
   Notifying other features about client add
[09/01/13 11:59:21.262 IST 1703 33] ACCESS-CORE-SM-FEATURE-WIRED_TUNNEL-NOT: 
   [0021.5c8c.c761] Client 0021.5c8c.c761 is not tunnel client..Return
[09/01/13 11:59:21.262 IST 1704 33] [WCDB] wcdb_sisf_client_add_notify: Notifying 
   SISF of DEASSOC to DOWN any old entry for 0021.5c8c.c761
[09/01/13 11:59:21.262 IST 1705 33] [WCDB] wcdb_sisf_client_add_notify: Notifying 
   SISF of new Association for 0021.5c8c.c761
[09/01/13 11:59:21.262 IST 1706 5933] 0021.5C8C.C761 WCDB SPI response msg handler 
   client code 0 mob state 0
[09/01/13 11:59:21.262 IST 1707 5933] 0021.5C8C.C761 WcdbClientUpdate: L2 Auth ACK 
   from WCDB
 --More--         [09/01/13 11:59:21.262 IST 1708 5933] 0021.5C8C.C761 WCDB_L2ACK: 
   wcdbAckRecvdFlag updated 
[09/01/13 11:59:21.262 IST 1709 5933] 0021.5C8C.C761 WCDB_AUTH: Adding opt82 len 0
[09/01/13 11:59:21.262 IST 170a 5933] 0021.5C8C.C761 WCDB_LLM: NoRun Prev Mob 0, 
   Curr Mob 1 llmReq 1, return False
[09/01/13 11:59:21.263 IST 170b 5933] 0021.5C8C.C761 WCDB_CHANGE: auth=LEARN_IP(2) 
   vlan 20 radio 1 client_id 0x84fd0000000050 mobility=Local(1) src_int 
   0xb6818000000038 dst_int 0x0 ackflag 2 reassoc_client 0 llm_notif 0 ip  0.0.0.0 
   ip_learn_type UNKNOWN
[09/01/13 11:59:21.263 IST 170c 190] [WCDB] ==Update event: client (0021.5c8c.c761) 
   client id:(0x84fd0000000050) vlan (20->20) global_wlan (4->4) auth_state 
   (L2_AUTH_DONE->LEARN_IP) mob_state (INIT->LOCAL)
[09/01/13 11:59:21.263 IST 170d 190] [WCDB] ===intf src/dst 
   (0xb6818000000038->0xb6818000000038)/(0x0->0x0) 
   radio/bssid (1->1)/(c8f9.f983.4260->c8f9.f983.4260) llm_notify (false) addr v4/v6 
   (0)/(0)
[09/01/13 11:59:21.263 IST 170e 190] [WCDB] wcdb_client_mcast_update_notify: No 
   mcast action reqd
[09/01/13 11:59:21.263 IST 170f 190] [WCDB] wcdb_ffcp_wcdb_client_update_notify 
   client (0021.5c8c.c761) id 0x84fd0000000050 ffcp update with flags=0x18
[09/01/13 11:59:21.263 IST 1710 190] [WCDB] wcdb_client_state_change_notify: 
   update flags = 0x3
[09/01/13 11:59:21.263 IST 1711 190] ACCESS-CORE-SM-CLIENT-DOT11-NOTF: 
   [0021.5c8c.c761] WCDB notification (LEARN_IP) for 0021.5c8c.c761
 --More--         [09/01/13 11:59:21.263 IST 1712 190] [WCDB] 
   wcdb_sisf_client_update_notify: Notifying SISF
[09/01/13 11:59:21.263 IST 1713 329] [WCDB] wcdb_ffcp_cb: client (0021.5c8c.c761) 
   client (0x84fd0000000050): FFCP operation (UPDATE) return code (0)
[09/01/13 11:59:24.417 IST 1714 264] dhcp pkt processing routine is called for pak 
   with SMAC = 0021.5c8c.c761 and SRC_ADDR = 0.0.0.0
[09/01/13 11:59:24.417 IST 1715 210] sending dhcp packet outafter processing with 
   SMAC = 0021.5c8c.c761 and SRC_ADDR = 0.0.0.0
[09/01/13 11:59:24.417 IST 1716 144] DHCPD: Sending notification of DISCOVER:
[09/01/13 11:59:24.417 IST 1717 144] DHCPD: Sending notification of DISCOVER:
[09/01/13 11:59:24.417 IST 1718 144] DHCPD: DHCPOFFER notify setup address 
   20.20.20.3 mask 255.255.255.0
[09/01/13 11:59:24.425 IST 1719 264] dhcp pkt processing routine is called for pak 
   with SMAC = 0021.5c8c.c761 and SRC_ADDR = 0.0.0.0
[09/01/13 11:59:24.425 IST 171a 210] sending dhcp packet outafter processing with 
   SMAC = 0021.5c8c.c761 and SRC_ADDR = 0.0.0.0
[09/01/13 11:59:24.425 IST 171b 144] DHCPD: address 20.20.20.3 mask 255.255.255.0
[09/01/13 11:59:24.425 IST 171c 186] ACCESS-CORE-SM-CLIENT-IPDT-NOTF: 
   [0021.5c8c.c761, Ca1] IP update for MAC 0021.5c8c.c761. New IP 20.20.20.3
[09/01/13 11:59:24.425 IST 171d 186] ACCESS-CORE-SM-CLIENT-IPDT-NOTF: 
   [0021.5c8c.c761, Ca1] IPv4 ID update notify success for label 0x32000026, MAC 
   0021.5c8c.c761
[09/01/13 11:59:24.425 IST 171e 186] [WCDB] wcdb_ffcp_wcdb_client_update_notify 
   client (0021.5c8c.c761) id 0x84fd0000000050 ffcp update with flags=0x18
 --More--         [09/01/13 11:59:24.425 IST 171f 173] ACCESS-CORE-SM-NOTF: 
   [0021.5c8c.c761, Ca1] Received internal event SINGLE_ID_UPDATE (handle 0x32000026)
[09/01/13 11:59:24.425 IST 1720 173] ACCESS-CORE-SM-SYNC-NOTF: [0021.5c8c.c761, Ca1] 
   Delay add/update sync of addr for 0021.5c8c.c761 / 0x32000026
[09/01/13 11:59:24.425 IST 1721 5933] 0021.5C8C.C761 WCDB_IP_BIND: w/ IPv4 
   20.20.20.3 ip_learn_type DHCP add_delete 1,options_length 0
[09/01/13 11:59:24.425 IST 1722 5933] 0021.5C8C.C761 WcdbClientUpdate: IP Binding 
   from WCDB ip_learn_type 1, add_or_delete 1
[09/01/13 11:59:24.425 IST 1723 5933] 0021.5C8C.C761 IPv4 Addr: 20:20:20:3
[09/01/13 11:59:24.425 IST 1724 5933] 0021.5C8C.C761 MS got the IP, resetting the 
   Reassociation Count 0 for client
[09/01/13 11:59:24.425 IST 1725 5933] 0021.5C8C.C761 apfMsRunStateInc
[09/01/13 11:59:24.426 IST 1726 5933] 0021.5C8C.C761 WCDB_AUTH: Adding opt82 len 0
[09/01/13 11:59:24.426 IST 1727 5933] 0021.5C8C.C761 WCDB_LLM: prev Mob state 1 
   curr Mob State 1 llReq flag 0
[09/01/13 11:59:24.426 IST 1728 5933] 0021.5C8C.C761 WCDB_CHANGE: auth=RUN(4) vlan 
   20 radio 1 client_id 0x84fd0000000050 mobility=Local(1) src_int 0xb6818000000038 
   dst_int 0x0 ackflag 2 reassoc_client 0 llm_notif 0 ip  20.20.20.3 ip_learn_type DHCP
[09/01/13 11:59:24.426 IST 1729 329] [WCDB] wcdb_ffcp_cb: client (0021.5c8c.c761) 
   client (0x84fd0000000050): FFCP operation (UPDATE) return code (0)
[09/01/13 11:59:24.426 IST 172a 5933] 0021.5C8C.C761 AAAS: acct method list NOT 
   configured for WLAN 4, accounting skipped
 --More--         [09/01/13 11:59:24.426 IST 172b 5933] 0021.5C8C.C761  
   Sending IPv4 update to Controller 10.105.135.176 
[09/01/13 11:59:24.426 IST 172c 5933] 0021.5C8C.C761 Assigning Address 20.20.20.3 
   to mobile 
[09/01/13 11:59:24.426 IST 172d 5933] 0021.5C8C.C761 20.20.20.3, auth_state 20 
   mmRole Local !!!
[09/01/13 11:59:24.426 IST 172e 5933] 0021.5C8C.C761 20.20.20.3, auth_state 20 
   mmRole Local, updating wcdb not needed
[09/01/13 11:59:24.426 IST 172f 5933] 0021.5C8C.C761 Tclas Plumb needed: 0
[09/01/13 11:59:24.427 IST 1730 190] [WCDB] ==Update event: client (0021.5c8c.c761) 
   client id:(0x84fd0000000050) vlan (20->20) global_wlan (4->4) auth_state 
   (LEARN_IP->RUN) mob_state (LOCAL->LOCAL)
[09/01/13 11:59:24.427 IST 1731 190] [WCDB] ===intf src/dst 
   (0xb6818000000038->0xb6818000000038)/(0x0->0x0) radio/bssid 
   (1->1)/(c8f9.f983.4260->c8f9.f983.4260) llm_notify (false) addr v4/v6 (0)/(0)
[09/01/13 11:59:24.427 IST 1732 190] [WCDB] wcdb_client_mcast_update_notify: No 
   mcast action reqd
[09/01/13 11:59:24.427 IST 1733 190] [WCDB] wcdb_ffcp_wcdb_client_update_notify 
   client (0021.5c8c.c761) id 0x84fd0000000050 ffcp update with flags=0x18
[09/01/13 11:59:24.427 IST 1734 190] [WCDB] wcdb_client_state_change_notify: 
   update flags = 0x2
[09/01/13 11:59:24.427 IST 1735 190] ACCESS-CORE-SM-CLIENT-DOT11-NOTF: 
   [0021.5c8c.c761] Ignore WCDB run notification for 0021.5c8c.c761 as authz complete.
 --More--         [09/01/13 11:59:24.427 IST 1736 190] [WCDB] 
   wcdb_sisf_client_update_notify: Notifying SISF
[09/01/13 11:59:24.427 IST 1737 329] [WCDB] wcdb_ffcp_cb: client (0021.5c8c.c761) 
   client (0x84fd0000000050): FFCP operation (UPDATE) return code (0)
[09/01/13 11:59:34.667 IST 1738 190] [WCDB] ==Update event: client (60fa.cd4c.597b) 
   client id:(0xa028c00000004c) vlan (20->20) global_wlan (2->2) auth_state 
   (RUN->ASSOCIATION) mob_state (LOCAL->LOCAL)
[09/01/13 11:59:34.667 IST 1739 190] [WCDB] ===intf src/dst 
   (0xb6818000000038->0xb6818000000038)/(0x0->0x0) radio/bssid (0->0)/
   (c8f9.f983.4260->c8f9.f983.4260) llm_notify (true) addr v4/v6 (0)/(0)
[09/01/13 11:59:34.667 IST 173a 190] [WCDB] wcdb_client_mcast_update_notify: 
   No mcast action reqd
[09/01/13 11:59:34.667 IST 173b 190] [WCDB] Ignoring auth state transition 
   (4 -> 0)
[09/01/13 11:59:34.667 IST 173c 190] [WCDB] wcdb_ffcp_wcdb_client_update_notify 
   client (60fa.cd4c.597b) id 0xa028c00000004c ffcp update with flags=0x18
[09/01/13 11:59:34.667 IST 173d 190] [WCDB] wcdb_client_state_change_notify: 
   update flags = 0x2
[09/01/13 11:59:34.667 IST 173e 190] [WCDB] wcdb_sisf_client_update_notify: 
   Notifying SISF
[09/01/13 11:59:34.667 IST 173f 329] [WCDB] wcdb_ffcp_cb: client (60fa.cd4c.597b) 
   client (0xa028c00000004c): FFCP operation (UPDATE) return code (0)
[09/01/13 11:59:34.865 IST 1740 190] [WCDB] ==Update event: client (60fa.cd4c.597b) 
   client id:(0xa028c00000004c) vlan (20->20) global_wlan (2->2) auth_state (RUN->RUN) 
   mob_state (LOCAL->LOCAL)
 --More--         [09/01/13 11:59:34.865 IST 1741 190] [WCDB] ===intf src/dst 
   (0xb6818000000038->0xb6818000000038)/(0x0->0x0) 
   radio/bssid (0->0)/(c8f9.f983.4260->c8f9.f983.4260) llm_notify (false) addr v4/v6 
   (0)/(0)
[09/01/13 11:59:34.865 IST 1742 190] [WCDB] wcdb_client_mcast_update_notify: No 
   mcast action reqd
[09/01/13 11:59:34.865 IST 1743 190] [WCDB] wcdb_ffcp_wcdb_client_update_notify 
   client (60fa.cd4c.597b) id 0xa028c00000004c ffcp update with flags=0x18
[09/01/13 11:59:34.865 IST 1744 190] [WCDB] wcdb_client_state_change_notify: 
   update flags = 0x2
[09/01/13 11:59:34.865 IST 1745 190] [WCDB] wcdb_sisf_client_update_notify: 
   Notifying SISF
[09/01/13 11:59:34.865 IST 1746 329] [WCDB] wcdb_ffcp_cb: client (60fa.cd4c.597b) 
   client (0xa028c00000004c): FFCP operation (UPDATE) return code (0)
[09/01/13 11:59:36.010 IST 1747 264] dhcp pkt processing routine is called for pak 
   with SMAC = 60fa.cd4c.597b and SRC_ADDR = 0.0.0.0
[09/01/13 11:59:36.010 IST 1748 210] sending dhcp packet outafter processing with 
   SMAC = 60fa.cd4c.597b and SRC_ADDR = 0.0.0.0
[09/01/13 11:59:36.010 IST 1749 144] DHCPD: address 20.20.20.2 mask 255.255.255.0
[09/01/13 11:59:52.802 IST 174a 190] [WCDB] ==Update event: client (60fa.cd4c.597b) 
   client id:(0xa028c00000004c) vlan (20->20) global_wlan (2->2) auth_state 
   (RUN->ASSOCIATION) mob_state (LOCAL->LOCAL)
[09/01/13 11:59:52.802 IST 174b 190] [WCDB] ===intf src/dst 
   (0xb6818000000038->0xb6818000000038)/(0x0->0x0) 
   radio/bssid (0->0)/(c8f9.f983.4260->c8f9.f983.4260) llm_notify (true) addr v4/v6 
   (0)/(0)
 --More--         [09/01/13 11:59:52.802 IST 174c 190] [WCDB] 
   wcdb_client_mcast_update_notify: No mcast action reqd
[09/01/13 11:59:52.802 IST 174d 190] [WCDB] Ignoring auth state transition (4 -> 0)
[09/01/13 11:59:52.802 IST 174e 190] [WCDB] wcdb_ffcp_wcdb_client_update_notify 
   client (60fa.cd4c.597b) id 0xa028c00000004c ffcp update with flags=0x18
[09/01/13 11:59:52.802 IST 174f 190] [WCDB] wcdb_client_state_change_notify: 
   update flags = 0x2
[09/01/13 11:59:52.802 IST 1750 190] [WCDB] wcdb_sisf_client_update_notify: 
   Notifying SISF
[09/01/13 11:59:52.803 IST 1751 329] [WCDB] wcdb_ffcp_cb: client (60fa.cd4c.597b) 
   client (0xa028c00000004c): FFCP operation (UPDATE) return code (0)
[09/01/13 11:59:53.015 IST 1752 190] [WCDB] ==Update event: client (60fa.cd4c.597b) 
   client id:(0xa028c00000004c) vlan (20->20) global_wlan (2->2) auth_state (RUN->RUN) 
   mob_state (LOCAL->LOCAL)
[09/01/13 11:59:53.015 IST 1753 190] [WCDB] ===intf src/dst 
   (0xb6818000000038->0xb6818000000038)/(0x0->0x0) 
   radio/bssid (0->0)/(c8f9.f983.4260->c8f9.f983.4260) llm_notify (false) addr v4/v6 
   (0)/(0)
[09/01/13 11:59:53.015 IST 1754 190] [WCDB] wcdb_client_mcast_update_notify: No 
   mcast action reqd
[09/01/13 11:59:53.015 IST 1755 190] [WCDB] wcdb_ffcp_wcdb_client_update_notify 
   client (60fa.cd4c.597b) id 0xa028c00000004c ffcp update with flags=0x18
[09/01/13 11:59:53.015 IST 1756 190] [WCDB] wcdb_client_state_change_notify: update 
   flags = 0x2
 --More--         [09/01/13 11:59:53.015 IST 1757 190] [WCDB] 
   wcdb_sisf_client_update_notify: Notifying SISF
[09/01/13 11:59:53.016 IST 1758 329] [WCDB] wcdb_ffcp_cb: client (60fa.cd4c.597b) 
   client (0xa028c00000004c): FFCP operation (UPDATE) return code (0)
[09/01/13 11:59:54.045 IST 1759 264] dhcp pkt processing routine is called for pak 
   with SMAC = 60fa.cd4c.597b and SRC_ADDR = 0.0.0.0
[09/01/13 11:59:54.045 IST 175a 210] sending dhcp packet outafter processing with 
   SMAC = 60fa.cd4c.597b and SRC_ADDR = 0.0.0.0
[09/01/13 11:59:54.045 IST 175b 144] DHCPD: address 20.20.20.2 mask 255.255.255.0
[09/01/13 12:00:18.830 IST 175c 190] [WCDB] ==Update event: client (60fa.cd4c.597b) 
   client id:(0xa028c00000004c) vlan (20->20) global_wlan (2->2) auth_state 
   (RUN->ASSOCIATION) mob_state (LOCAL->LOCAL)
[09/01/13 12:00:18.830 IST 175d 190] [WCDB] ===intf src/dst 
   (0xb6818000000038->0xb6818000000038)/(0x0->0x0) 
   radio/bssid (0->0)/(c8f9.f983.4260->c8f9.f983.4260) llm_notify (true) addr v4/v6 
   (0)/(0)
[09/01/13 12:00:18.830 IST 175e 190] [WCDB] wcdb_client_mcast_update_notify: No 
   mcast action reqd
[09/01/13 12:00:18.830 IST 175f 190] [WCDB] Ignoring auth state transition 
   (4 -> 0)
[09/01/13 12:00:18.830 IST 1760 190] [WCDB] wcdb_ffcp_wcdb_client_update_notify 
   client (60fa.cd4c.597b) id 0xa028c00000004c ffcp update with flags=0x18
[09/01/13 12:00:18.830 IST 1761 190] [WCDB] wcdb_client_state_change_notify: 
   update flags = 0x2
 --More--         [09/01/13 12:00:18.830 IST 1762 190] [WCDB] 
   wcdb_sisf_client_update_notify: Notifying SISF
[09/01/13 12:00:18.830 IST 1763 329] [WCDB] wcdb_ffcp_cb: client (60fa.cd4c.597b) 
   client (0xa028c00000004c): FFCP operation (UPDATE) return code (0)
[09/01/13 12:00:19.038 IST 1764 190] [WCDB] ==Update event: client (60fa.cd4c.597b) 
   client id:(0xa028c00000004c) vlan (20->20) global_wlan (2->2) auth_state (RUN->RUN) 
   mob_state (LOCAL->LOCAL)
[09/01/13 12:00:19.038 IST 1765 190] [WCDB] ===intf src/dst 
   (0xb6818000000038->0xb6818000000038)/(0x0->0x0) 
   radio/bssid (0->0)/(c8f9.f983.4260->c8f9.f983.4260) llm_notify (false) addr v4/v6 
   (0)/(0)
[09/01/13 12:00:19.038 IST 1766 190] [WCDB] wcdb_client_mcast_update_notify: 
   No mcast action reqd
[09/01/13 12:00:19.038 IST 1767 190] [WCDB] wcdb_ffcp_wcdb_client_update_notify 
   client (60fa.cd4c.597b) id 0xa028c00000004c ffcp update with flags=0x18
[09/01/13 12:00:19.038 IST 1768 190] [WCDB] wcdb_client_state_change_notify: 
   update flags = 0x2
[09/01/13 12:00:19.038 IST 1769 190] [WCDB] wcdb_sisf_client_update_notify: 
   Notifying SISF
[09/01/13 12:00:19.038 IST 176a 329] [WCDB] wcdb_ffcp_cb: client (60fa.cd4c.597b) 
   client (0xa028c00000004c): FFCP operation (UPDATE) return code (0)
[09/01/13 12:00:20.108 IST 176b 5933] 0021.5C8C.C761 
   Client stats update: Time now in sec 1378015280, Last Acct Msg Sent at 1378015224 
   sec
[09/01/13 12:00:20.590 IST 176c 264] dhcp pkt processing routine is called for pak 
   with SMAC = 60fa.cd4c.597b and SRC_ADDR = 0.0.0.0
 --More--         [09/01/13 12:00:20.590 IST 176d 210] sending dhcp packet outafter 
   processing with SMAC = 60fa.cd4c.597b and SRC_ADDR = 0.0.0.0
[09/01/13 12:00:20.590 IST 176e 144] DHCPD: address 20.20.20.2 mask 255.255.255.0

Controller#
*Sep  1 06:04:20.121: 0021.5C8C.C761 
   Client stats update: 1 wcm:  Time now in sec 1378015460, Last Acct Msg Sent at 
   1378015370 sec
*Sep  1 06:04:20.121: 0021.5C8C.C761 Requested to send acct interim update request 
   msg to APF task for client 0: 1 wcm: 21:5c:8c:c7:61 
*Sep  1 06:04:21.326: Load Balancer: 1 wcm:  Success, Resource allocated are: 
   Active Switch number: 1, Active Asic number : 2, Reserve Switch number 0 Reserve 
   Asic number 0. AP Asic num 0
*Sep  1 06:04:21.326: WCDB_IIF: 1 wcm:  Ack Message ID: 0x85780000000052 code 1001
*Sep  1 06:04:21.326: PEM recv processing msg Epm spi response(12)  1 wcm: e 1001
*Sep  1 06:04:21.326: PEM recv processing msg Add SCB(3)  1 wcm: onse(12)
*Sep  1 06:04:21.327: EPM: 1 wcm:  Session create resp - client handle 
   85780000000052 session 32000028 
*Sep  1 06:04:21.327: EPM: 1 wcm:  Netflow session create resp - client handle 
   85780000000052 sess 32000028
*Sep  1 06:04:21.328: PEM recv processing msg Epm spi response(12)  1 wcm: le 
   85780000000052 sess 32000028
*Sep  1 06:04:21.328: EPM: 1 wcm:  Init feature, client handle 85780000000052 
   session 32000028 authz 5000012 
*Sep  1 06:04:21.328: EPM: 1 wcm:  Activate feature client handle 85780000000052 
   sess 32000028 authz 5000012
*Sep  1 06:04:21.328: PEM recv processing msg Epm spi response(12)  1 wcm: 0052 
   sess 32000028 authz 5000012
*Sep  1 06:04:21.328: EPM: 1 wcm:  Policy enforcement -  client handle 
   85780000000052 session c8000012 authz 5000012 
*Sep  1 06:04:21.328: EPM: 1 wcm:  Netflow policy enforcement - client handle 
   85780000000052 sess c8000012 authz 5000012 msg_type 0 policy_status 0 attr len 0
*Sep  1 06:04:21.328: PEM recv processing msg Epm spi response(12)  1 wcm: e 
   85780000000052 sess c8000012 authz 5000012 msg_type 0 policy_status 0 attr len 0
*Sep  1 06:04:28.456: PEM recv processing msg Add SCB(3)  1 wcm: onse(12)

Revision History

Revision	Publish Date	Comments
1.0	01-Oct-2013	Initial Release

Contributed by Cisco Engineers

Surendra BG
Cisco TAC Engineer.

Was this Document Helpful?

Feedback

Contact Cisco

Open a Support Case
(Requires a Cisco Service Contract)

External RADIUS Server EAP Authentication with 5760/3850 WLC Configuration Example

Available Languages

Download Options

Bias-Free Language

Contents

Introduction

Prerequisites

Requirements

Components Used

Configure

Network Diagram

Overview

Configure WLC 5760/3850 with CLI

Configure WLC 5760/3850 with GUI

Configure ACS 5.2 (RADIUS Server)

Verify

Troubleshoot

Revision History

Contributed by Cisco Engineers

Was this Document Helpful?

Contact Cisco

This Document Applies to These Products