内容

概要

前提条件

要件

使用するコンポーネント

設定

ネットワーク図

概要

CLI での WLC 5760/3850 の設定

GUI での WLC 5760/3850 の設定

ACS 5.2（RADIUS サーバ）の設定

確認

トラブルシュート

概要

このドキュメントでは、外部 RADIUS サーバで使用する拡張認証プロトコル（EAP）Flexible Authentication via Secure Tunneling（FAST）認証のためにワイヤレス LAN（WLAN）コントローラ（WLC）を設定する方法について説明します。この設定例では、ワイヤレス クライアントを認証するために、Cisco Secure Access Control Server（ACS）を外部 RADIUS サーバとして使用しています。

前提条件

要件

次の項目に関する知識があることが推奨されます。

- Lightweight アクセス ポイント（LAP）、Cisco 5760 ワイヤレス LAN コントローラ、および Cisco Catalyst 3850 シリーズ スイッチの設定に関する基礎知識

- Lightweight アクセス ポイント プロトコル（LWAPP）に関する基礎知識

- Cisco Secure ACS 5.2などの外部RADIUSサーバの設定方法に関する知識。この設定例はEAP-FAST用です。

- 一般的な EAP フレームワークに関する実践的な知識

- Microsoft Challenge Handshake Authentication Protocol Version 2（MS-CHAPv2）、EAP-Generic Token Card（EAP-GTC）などのセキュリティ プロトコルに関する基礎知識

- デジタル証明書に関する基礎知識

使用するコンポーネント

このドキュメントの情報は、次のソフトウェアとハードウェアのバージョンに基づいています。

- Cisco Wireless LAN Controller 5760 リリース 3.2.2（Next Generation Wiring Closet [NGWC]）

- Cisco 3602 シリーズ Lightweight アクセス ポイント

- Microsoft Windows XP と Intel PROset サプリカント

- Cisco Secure Access Control Server リリース 5.2

- Cisco Catalyst 3560 シリーズ スイッチ

このドキュメントの情報は、特定のラボ環境にあるデバイスに基づいて作成されました。このドキュメントで使用するすべてのデバイスは、初期（デフォルト）設定の状態から起動しています。対象のネットワークが実稼働中である場合には、どのようなコマンドについても、その潜在的な影響について確実に理解しておく必要があります。

設定

注：このセクションで使用されるコマンドの詳細については、Command Lookup Tool（登録ユーザ専用）を使用してください。

ネットワーク図

次の画像は、ネットワーク ダイアグラムの例を示しています。

概要

次の 2 つの手順で、この設定を実行します。

1. コマンドライン インターフェイス（CLI）または GUI を使用して WLC 5760/3850 を設定します。

2. ACS 5.2（RADIUS サーバ）の設定

CLI での WLC 5760/3850 の設定

この手順では、CLI を使用して、要求されたクライアント VLAN の WLAN を設定し、認証方式リストにマッピングする方法を説明します。

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

GUI での WLC 5760/3850 の設定

この手順では、GUI を使用して 5760 コントローラと 3850 スイッチを設定する方法を説明します。

1. RADIUS サーバを追加するには、[Configuration] > [Security] > [AAA] に移動します。

2. [Server Groups] > [Radius] に移動し、「ACS」という名前で Radius サーバ グループを作成します。

3. [RADIUS] > [Services] に移動し、ACS RADIUS サーバを設定します。

完全な設定の例を次に示します。

4. [Method Lists] > [General] に移動し、[Dot1x System Auth Control]（802.1X システム認証コントロール）を有効にします。 これを有効にしないと、認証が失敗することがあります。

5. [Method Lists] > [Authentication] に移動し、設定した ACS RADIUS サーバを方式リストにマップします。次に、認証、許可、アカウンティング（AAA）サーバの下で WLAN にマップします。

次のように、「ACS」が方式リストに表示されます。

6. WLAN を設定し、ACS をマップするには、WLC の GUI アクセスを開き、[Configuration] > [Wireless] > [WLAN] > [WLANs] に移動します。

7. [WLAN]ページで[NEW]をクリックし、[General] タブに移動します。802.1Xを使用したWLANを作成し、RADIUSサーバをマッピングします。

8. [Security] タブ > [Layer 2] タブに移動し、802.1X が有効にされた WPA/WPA2 が設定されていることを確認します。

9. [AAA Servers] タブに移動し、「ACS」WLAN の認証方式リストをマップします。

ACS 5.2（RADIUS サーバ）の設定

この手順では、RADIUS サーバを設定する方法について説明します。5760 WLC および 3850 スイッチが AAA クライアントの下の ACS にすでに追加されていることを前提としています。

1. [Users and Identity Stores] > [Internal Identity Stores] > [Users] に移動し、ACS でユーザとユーザ データベースを設定します。

2. [Access Policies] > [Access Services] > [Default Network Access] に移動し、必要な認証プロトコルを有効にします。必ず EAP-FAST を有効にしてください。

3. [Default Network Access] > [Identity] に移動し、EAP-FAST 用のアイデンティティ シーケンス ルールを設定します。

4. [Default Network Access] > [Authorization] に移動し、認証が成功した後に EAP クライアントへのアクセスを付与する認証ルールを確認します。

確認

ここでは、設定が正常に機能しているかどうかを確認します。WLAN EAP-FAST にクライアントを接続します。

トラブルシュート

ここでは、設定のトラブルシューティングに使用できる情報を示します。

注：debug コマンドを使用する前に、「デバッグ コマンドの重要な情報」を参照してください。

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)