problems with session duration for 1 client

lydia.walther · ‎02-28-2013

Hello,

we have some problems with one of our wifi clients.

The wireless lan controller is a model 4402 with software version 6.0.196.0.

The access points are connected via mesh mode! The status seems to be stable (Uptime of two access points

in the third floor is about 10 days).

Normally we only provide one wireless network with WPA+WPA2 and WEB-Auth. But since two weeks there is a guest

who says he's beeing disconnected very often. Because we thought it would be a problem with the WEB-Authentication and his apple computer,

we set up a new wifi network with mac address filter. But the guest is still complaining about the connection.

In the wireless control system reports I can see, that there are often connections of this guest which has a session duration

of exactly "5 min 0 sec". But in the meantime there are also session durations of several hours.

(Session timeout is not enabled! User Idle Timeout is set to 3000 seconds and ARP timeout is 300 seconds)

In the old version of WCS there was given a "reason code" for the disassociation of clients, but in this version I can't

see something like that. (I upgraded the version this week.)

In the trap log of the controller there are only messages like "Client Association" and "Client Authenticated" for the concerned client, but no entrys

for disassociation or deauthentication.

Other guests do not have this problem. It's only one guest using two different computers (1 Apple, 1 Windows).

Affected is the guest who's living in the highest floor of the house. Other guests in the first floor do not have

problems. Could this really be a problem of the mesh mode? We never had a guest before with so big problems.

Where can I found the reason for the clients new authentication? What is happening after exactly 5 minutes?

Does anybody has an idea?

During we tested the wifi with our computers there were no problems although we were sitting in the highest floor. We will do an endurance test for some hours tomorrow.

Greetings Lydia

Scott Fella · ‎02-28-2013

Can you post the show WLAN

Sent from Cisco Technical Support iPhone App

-Scott
*** Please rate helpful posts ***

lydia.walther · ‎02-28-2013

Hi,

thank you for your answer. Here is the output.

Cisco Controller) >show wlan 2

WLAN Identifier.................................. 2

Profile Name..................................... mpids_gh

Network Name (SSID).............................. mpids_gh

Status........................................... Enabled

MAC Filtering.................................... Enabled

Broadcast SSID................................... Enabled

AAA Policy Override.............................. Disabled

Network Admission Control

NAC-State...................................... Disabled

Quarantine VLAN................................ 0

Number of Active Clients......................... 1

Exclusionlist Timeout............................ 60 seconds

Session Timeout.................................. Infinity

CHD per WLAN..................................... Enabled

Webauth DHCP exclusion........................... Disabled

Interface........................................ mpids_gh_if

WLAN ACL......................................... unconfigured

DHCP Server...................................... 192.168.243.1

DHCP Address Assignment Required................. Enabled

--More-- or (q)uit

Quality of Service............................... Silver (best effort)

Scan Defer Priority.............................. 5,6

Scan Defer Time.................................. 100 milliseconds

WMM.............................................. Allowed

Media Stream Multicast-direct.................... Disabled

CCX - AironetIe Support.......................... Enabled

CCX - Gratuitous ProbeResponse (GPR)............. Disabled

CCX - Diagnostics Channel Capability............. Disabled

Dot11-Phone Mode (7920).......................... Disabled

Wired Protocol................................... None

IPv6 Support..................................... Disabled

Peer-to-Peer Blocking Action..................... Disabled

Radio Policy..................................... All

DTIM period for 802.11a radio.................... 1

DTIM period for 802.11b radio.................... 1

Radius Servers

Authentication................................ Global Servers

Accounting.................................... Global Servers

Dynamic Interface............................. Disabled

Local EAP Authentication......................... Disabled

Security

802.11 Authentication:........................ Open System

--More-- or (q)uit

Static WEP Keys............................... Disabled

802.1X........................................ Disabled

Wi-Fi Protected Access (WPA/WPA2)............. Enabled

WPA (SSN IE)............................... Enabled

TKIP Cipher............................. Enabled

AES Cipher.............................. Enabled

WPA2 (RSN IE).............................. Enabled

TKIP Cipher............................. Enabled

AES Cipher.............................. Enabled

Auth Key Management

802.1x.................................. Disabled

PSK..................................... Enabled

CCKM.................................... Disabled

FT(802.11r)............................. Disabled

FT-PSK(802.11r)......................... Disabled

FT Reassociation Timeout......................... 20

FT Over-The-Air mode............................. Enabled

FT Over-The-Ds mode.............................. Enabled

CKIP ......................................... Disabled

IP Security................................... Disabled

IP Security Passthru.......................... Disabled

Web Based Authentication...................... Disabled

Web-Passthrough............................... Disabled

--More-- or (q)uit

Conditional Web Redirect...................... Disabled

Splash-Page Web Redirect...................... Disabled

Auto Anchor................................... Disabled

H-REAP Local Switching........................ Disabled

H-REAP Learn IP Address....................... Enabled

Infrastructure MFP protection................. Disabled

Client MFP.................................... Optional

Tkip MIC Countermeasure Hold-down Timer....... 60

Call Snooping.................................... Disabled

Band Select...................................... Enabled

Load Balancing................................... Enabled

Mobility Anchor List

WLAN ID IP Address Status

------- --------------- ------

maldehne · ‎02-28-2013

it would be better to have debug client < mac address of client > while the issue is happenning to figure out the reason of disconnectivity.

it worths to have the output of show network summary

Regards

lydia.walther · ‎02-28-2013

Thank you.

Can you please tell me how to use the debug command?? I tried it in the morning, but it was not very succesfull.

(Cisco Controller) >show network summary

RF-Network Name............................. gaeste

Web Mode.................................... Disable

Secure Web Mode............................. Enable

Secure Web Mode Cipher-Option High.......... Disable

Secure Web Mode Cipher-Option SSLv2......... Enable

Secure Shell (ssh).......................... Enable

Telnet...................................... Disable

Ethernet Multicast Mode..................... Disable

Ethernet Broadcast Mode..................... Disable

AP Multicast Mode........................... Unicast

IGMP snooping............................... Disabled

IGMP timeout................................ 60 seconds

User Idle Timeout........................... 3000 seconds

ARP Idle Timeout............................ 300 seconds

Cisco AP Default Master..................... Disable

AP Join Priority............................ Disable

Mgmt Via Wireless Interface................. Disable

Mgmt Via Dynamic Interface.................. Disable

Bridge MAC filter Config.................... Enable

Bridge Security Mode........................ EAP

Mesh Full Sector DFS........................ Enable

Apple Talk ................................. Disable

AP Fallback ................................ Enable

Web Auth Redirect Ports .................... 80

Fast SSID Change ........................... Disabled

802.3 Bridging ............................. Disable

IP/MAC Addr Binding Check .................. Enabled

(Cisco Controller) >

-- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- --

(Cisco Controller) >debug client e8:39:df:84:8b:0c

(Cisco Controller) >debug client e8:39:df:84:8b:0c

(Cisco Controller) >show debug

MAC address ................................ e8:39:df:84:8b:0c

Debug Flags Enabled:

dhcp packet enabled.

dot11 mobile enabled.

dot11 state enabled

dot1x events enabled.

dot1x states enabled.

pem events enabled.

pem state enabled.

CCKM client debug enabled.

(Cisco Controller) >

Scott Fella · ‎02-28-2013

For one, you should only use either WPA with TKIP or WPA 2 with AES. You have all enabled and Apple devices don't like that. So with your test, make sure you use WPA2/AES and test the client again.

Sent from Cisco Technical Support iPhone App

-Scott
*** Please rate helpful posts ***

lydia.walther · ‎02-28-2013

As yet the client was always connected with WPA2/AES with both computers - the apple and the windows machine. And the problem of disassociating is occuring on both computers.

Greetings Lydia

Scott Fella · ‎02-28-2013

So if you setup the client with WPA2/AES, make sure WPA2/AES is only checked not all of them or a mixture of each. Also make the changes I suggested in the other post. I have a MacBook Pro and that is troublesome, but my iPhone and iPad is worse, that's how I know what works with these devices.

Sent from Cisco Technical Support iPhone App

-Scott
*** Please rate helpful posts ***

Scott Fella · ‎02-28-2013

Also disable band select and load balancing as that's another reason these devices fail. I would also remove dhcp required also for now. If your test seems to work, then you can enable that, but only that and then make sure the device works fine.

Sent from Cisco Technical Support iPhone App

-Scott
*** Please rate helpful posts ***

lydia.walther · ‎02-28-2013

ok, thank you. we will try these things.

Greetings Lydia

lydia.walther · ‎02-28-2013

I read it would be better to disable Aironet IE if there are apple Computers. What do you think about it? And is this effecting the mesh mode?

Greetings Lydia

Scott Fella · ‎02-28-2013

It doesn't hurt. It doesn't affect my devices but I tend to not have that enabled anyways. The other stuff will affect your devices.

Sent from Cisco Technical Support iPhone App

-Scott
*** Please rate helpful posts ***

lydia.walther · ‎03-03-2013

Hello @all,

I made all the changes you said on friday. I disabled band select and load balancing, removed dhcp required. I only activated WPA2 with AES and disabled AIRONET IE. And I installed a further access point in the second floor of our guest house.

The problem of short session durations is still there on the two computers of our guest as well as on our test-macbook. We placed it in the neighbour apartment of the guest who's having problems. It was "online" since friday morning (we run a ping all the time). We can see some interrupts and sometimes the session duration is exactly 5 min 0 sec. (picture in attachment)

Does anybody has an idea?

Greetings Lydia

maldehne · ‎03-04-2013

debug client while the issue is happenning

lydia.walther · ‎03-04-2013

Hello,

I captured something with debug client. At this moment client had to build a new association.

In advance sorry for the long text.

(Cisco Controller) >debug client e8:39:df:84:8b:0c

(Cisco Controller) >

(Cisco Controller) >*Mar 04 10:27:55.732: 00:1e:52:7d:e8:e7 Stopping retransmission timer for mobile 00:1e:52:7d:e8:e7

*Mar 04 10:43:45.412: e8:39:df:84:8b:0c Association received from mobile on AP 00:1d:70:01:b5:a0

*Mar 04 10:43:45.412: e8:39:df:84:8b:0c Applying site-specific IPv6 override for station e8:39:df:84:8b:0c - vapId 2, site 'default-group', interface 'mpids_gh_if'

*Mar 04 10:43:45.412: e8:39:df:84:8b:0c Applying IPv6 Interface Policy for station e8:39:df:84:8b:0c - vlan 14, interface id 9, interface 'mpids_gh_if'

*Mar 04 10:43:45.412: e8:39:df:84:8b:0c STA - rates (8): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*Mar 04 10:43:45.412: e8:39:df:84:8b:0c STA - rates (12): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*Mar 04 10:43:45.412: e8:39:df:84:8b:0c Processing RSN IE type 48, length 20 for mobile e8:39:df:84:8b:0c

*Mar 04 10:43:45.412: e8:39:df:84:8b:0c 192.168.243.45 RUN (20) Deleted mobile LWAPP rule on AP [00:1d:70:01:b7:f0]

*Mar 04 10:43:45.412: e8:39:df:84:8b:0c Updated location for station old AP 00:1d:70:01:b7:f0-0, new AP 00:1d:70:01:b5:a0-0

*Mar 04 10:43:45.412: e8:39:df:84:8b:0c 192.168.243.45 RUN (20) Change state to START (0) last state RUN (20)

*Mar 04 10:43:45.412: e8:39:df:84:8b:0c 192.168.243.45 START (0) Initializing policy

*Mar 04 10:43:45.412: e8:39:df:84:8b:0c 192.168.243.45 START (0) Change state to AUTHCHECK (2) last state RUN (20)

*Mar 04 10:43:45.412: e8:39:df:84:8b:0c 192.168.243.45 AUTHCHECK (2) Change state to 8021X_REQD (3) last state RUN (20)

*Mar 04 10:43:45.412: e8:39:df:84:8b:0c 192.168.243.45 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 00:1d:70:01:b5:a0 vapId 2 apVapId 2

*Mar 04 10:43:45.412: e8:39:df:84:8b:0c apfPemAddUser2 (apf_policy.c:212) Changing state for mobile e8:39:df:84:8b:0c on AP 00:1d:70:01:b5:a0 from Associated to Associated

*Mar 04 10:43:45.412: e8:39:df:84:8b:0c Stopping deletion of Mobile Station: (callerId: 48)

*Mar 04 10:43:45.412: e8:39:df:84:8b:0c Sending Assoc Response to station on BSSID 00:1d:70:01:b5:a0 (status 0)

*Mar 04 10:43:45.413: e8:39:df:84:8b:0c apfProcessAssocReq (apf_80211.c:4361) Changing state for mobile e8:39:df:84:8b:0c on AP 00:1d:70:01:b5:a0 from Associated to Associated

*Mar 04 10:43:45.416: e8:39:df:84:8b:0c 192.168.243.45 Removed NPU entry.

*Mar 04 10:43:45.425: e8:39:df:84:8b:0c Creating a PKC PMKID Cache entry for station e8:39:df:84:8b:0c (RSN 2)

*Mar 04 10:43:45.425: e8:39:df:84:8b:0c Adding BSSID 00:1d:70:01:b5:a1 to PMKID cache for station e8:39:df:84:8b:0c

*Mar 04 10:43:45.425: New PMKID: (16)

*Mar 04 10:43:45.425: [0000] 1a 3a 8b 04 05 59 7f f2 71 cb 4c 32 9c c2 3e 4d

*Mar 04 10:43:45.425: e8:39:df:84:8b:0c Initiating RSN PSK to mobile e8:39:df:84:8b:0c

*Mar 04 10:43:45.425: e8:39:df:84:8b:0c dot1x - moving mobile e8:39:df:84:8b:0c into Force Auth state

*Mar 04 10:43:45.426: e8:39:df:84:8b:0c Skipping EAP-Success to mobile e8:39:df:84:8b:0c

*Mar 04 10:43:45.426: Including PMKID in M1 (16)

*Mar 04 10:43:45.426: [0000] 1a 3a 8b 04 05 59 7f f2 71 cb 4c 32 9c c2 3e 4d

*Mar 04 10:43:45.426: e8:39:df:84:8b:0c Starting key exchange to mobile e8:39:df:84:8b:0c, data packets will be dropped

*Mar 04 10:43:45.426: e8:39:df:84:8b:0c Sending EAPOL-Key Message to mobile e8:39:df:84:8b:0c

state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Mar 04 10:43:45.431: e8:39:df:84:8b:0c Received EAPOL-Key from mobile e8:39:df:84:8b:0c

*Mar 04 10:43:45.432: e8:39:df:84:8b:0c Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile e8:39:df:84:8b:0c

*Mar 04 10:43:45.432: e8:39:df:84:8b:0c Received EAPOL-key in PTK_START state (message 2) from mobile e8:39:df:84:8b:0c

*Mar 04 10:43:45.432: e8:39:df:84:8b:0c Stopping retransmission timer for mobile e8:39:df:84:8b:0c

*Mar 04 10:43:45.432: e8:39:df:84:8b:0c Sending EAPOL-Key Message to mobile e8:39:df:84:8b:0c

state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01

*Mar 04 10:43:45.441: e8:39:df:84:8b:0c Received EAPOL-Key from mobile e8:39:df:84:8b:0c

*Mar 04 10:43:45.441: e8:39:df:84:8b:0c Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile e8:39:df:84:8b:0c

*Mar 04 10:43:45.441: e8:39:df:84:8b:0c Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile e8:39:df:84:8b:0c

*Mar 04 10:43:45.441: e8:39:df:84:8b:0c 192.168.243.45 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Mar 04 10:43:45.442: e8:39:df:84:8b:0c 192.168.243.45 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 00:1d:70:01:b5:a0 vapId 2 apVapId 2

*Mar 04 10:43:45.442: e8:39:df:84:8b:0c 192.168.243.45 L2AUTHCOMPLETE (4) Change state to RUN (20) last state RUN (20)

*Mar 04 10:43:45.443: e8:39:df:84:8b:0c 192.168.243.45 RUN (20) Reached PLUMBFASTPATH: from line 4574

*Mar 04 10:43:45.443: e8:39:df:84:8b:0c 192.168.243.45 RUN (20) Adding Fast Path rule

type = Airespace AP Client

on AP 00:1d:70:01:b5:a0, slot 0, interface = 1, QOS = 0

ACL Id = 255, Jumbo Frames = NO,

*Mar 04 10:43:45.443: e8:39:df:84:8b:0c 192.168.243.45 RUN (20) Successfully plumbed mobile rule (ACL ID 255)

*Mar 04 10:43:45.443: e8:39:df:84:8b:0c Stopping retransmission timer for mobile e8:39:df:84:8b:0c

*Mar 04 10:43:45.446: e8:39:df:84:8b:0c 192.168.243.45 Added NPU entry of type 1, dtlFlags 0x0

*Mar 04 10:43:45.484: e8:39:df:84:8b:0c DHCP received op BOOTREQUEST (1) (len 324, port 1, encap 0xec03)

*Mar 04 10:43:45.484: e8:39:df:84:8b:0c DHCP selecting relay 1 - control block settings:

dhcpServer: 192.168.243.1, dhcpNetmask: 255.255.255.0,

dhcpGateway: 192.168.243.254, dhcpRelay: 192.168.243.1 VL

*Mar 04 10:43:45.485: e8:39:df:84:8b:0c DHCP selected relay 1 - 192.168.243.1 (local address 192.168.243.1, gateway 192.168.243.1, VLAN 14, port 1)

*Mar 04 10:43:45.485: e8:39:df:84:8b:0c DHCP transmitting DHCP REQUEST (3)

*Mar 04 10:43:45.485: e8:39:df:84:8b:0c DHCP op: BOOTREQUEST, htype: Ethernet, hlen: 6, hops: 1

*Mar 04 10:43:45.485: e8:39:df:84:8b:0c DHCP xid: 0x3dd65115 (1037455637), secs: 0, flags: 0

*Mar 04 10:43:45.485: e8:39:df:84:8b:0c DHCP chaddr: e8:39:df:84:8b:0c

*Mar 04 10:43:45.485: e8:39:df:84:8b:0c DHCP ciaddr: 0.0.0.0, yiaddr: 0.0.0.0

*Mar 04 10:43:45.485: e8:39:df:84:8b:0c DHCP siaddr: 0.0.0.0, giaddr: 192.168.243.1

*Mar 04 10:43:45.485: e8:39:df:84:8b:0c DHCP requested ip: 192.168.243.45

*Mar 04 10:43:45.485: e8:39:df:84:8b:0c DHCP selecting relay 2 - control block settings:

dhcpServer: 192.168.243.1, dhcpNetmask: 255.255.255.0,

dhcpGateway: 192.168.243.254, dhcpRelay: 192.168.243.1 VL

*Mar 04 10:43:45.485: e8:39:df:84:8b:0c DHCP selected relay 2 - NONE

*Mar 04 10:43:45.486: e8:39:df:84:8b:0c DHCP received op BOOTREPLY (2) (len 548, port 0, encap 0x0)

*Mar 04 10:43:45.487: e8:39:df:84:8b:0c DHCP sending REPLY to STA (len 418, port 1, vlan 252)

*Mar 04 10:43:45.487: e8:39:df:84:8b:0c DHCP transmitting DHCP ACK (5)

*Mar 04 10:43:45.487: e8:39:df:84:8b:0c DHCP op: BOOTREPLY, htype: Ethernet, hlen: 6, hops: 0

*Mar 04 10:43:45.487: e8:39:df:84:8b:0c DHCP xid: 0x3dd65115 (1037455637), secs: 0, flags: 0

*Mar 04 10:43:45.487: e8:39:df:84:8b:0c DHCP chaddr: e8:39:df:84:8b:0c

*Mar 04 10:43:45.487: e8:39:df:84:8b:0c DHCP ciaddr: 0.0.0.0, yiaddr: 192.168.243.45

*Mar 04 10:43:45.487: e8:39:df:84:8b:0c DHCP siaddr: 0.0.0.0, giaddr: 0.0.0.0

*Mar 04 10:43:45.487: e8:39:df:84:8b:0c DHCP server id: 1.1.1.1 rcvd server id: 192.168.243.1

*Mar 04 10:45:31.697: e8:39:df:84:8b:0c Reassociation received from mobile on AP 00:1d:70:01:b7:f0

*Mar 04 10:45:31.697: e8:39:df:84:8b:0c Applying site-specific IPv6 override for station e8:39:df:84:8b:0c - vapId 2, site 'default-group', interface 'mpids_gh_if'

*Mar 04 10:45:31.697: e8:39:df:84:8b:0c Applying IPv6 Interface Policy for station e8:39:df:84:8b:0c - vlan 14, interface id 9, interface 'mpids_gh_if'

*Mar 04 10:45:31.697: e8:39:df:84:8b:0c STA - rates (8): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*Mar 04 10:45:31.697: e8:39:df:84:8b:0c STA - rates (12): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*Mar 04 10:45:31.697: e8:39:df:84:8b:0c Processing RSN IE type 48, length 20 for mobile e8:39:df:84:8b:0c

*Mar 04 10:45:31.698: e8:39:df:84:8b:0c 192.168.243.45 RUN (20) Deleted mobile LWAPP rule on AP [00:1d:70:01:b5:a0]

*Mar 04 10:45:31.698: e8:39:df:84:8b:0c Updated location for station old AP 00:1d:70:01:b5:a0-0, new AP 00:1d:70:01:b7:f0-0

*Mar 04 10:45:31.698: e8:39:df:84:8b:0c 192.168.243.45 RUN (20) Change state to START (0) last state RUN (20)

*Mar 04 10:45:31.698: e8:39:df:84:8b:0c 192.168.243.45 START (0) Initializing policy

*Mar 04 10:45:31.698: e8:39:df:84:8b:0c 192.168.243.45 START (0) Change state to AUTHCHECK (2) last state RUN (20)

*Mar 04 10:45:31.698: e8:39:df:84:8b:0c 192.168.243.45 AUTHCHECK (2) Change state to 8021X_REQD (3) last state RUN (20)

*Mar 04 10:45:31.698: e8:39:df:84:8b:0c 192.168.243.45 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 00:1d:70:01:b7:f0 vapId 2 apVapId 2

*Mar 04 10:45:31.698: e8:39:df:84:8b:0c apfPemAddUser2 (apf_policy.c:212) Changing state for mobile e8:39:df:84:8b:0c on AP 00:1d:70:01:b7:f0 from Associated to Associated

*Mar 04 10:45:31.698: e8:39:df:84:8b:0c Stopping deletion of Mobile Station: (callerId: 48)

*Mar 04 10:45:31.698: e8:39:df:84:8b:0c Sending Assoc Response to station on BSSID 00:1d:70:01:b7:f0 (status 0)

*Mar 04 10:45:31.698: e8:39:df:84:8b:0c apfProcessAssocReq (apf_80211.c:4361) Changing state for mobile e8:39:df:84:8b:0c on AP 00:1d:70:01:b7:f0 from Associated to Associated

*Mar 04 10:45:31.702: e8:39:df:84:8b:0c 192.168.243.45 Removed NPU entry.

*Mar 04 10:45:31.796: e8:39:df:84:8b:0c Creating a PKC PMKID Cache entry for station e8:39:df:84:8b:0c (RSN 2)

*Mar 04 10:45:31.796: e8:39:df:84:8b:0c Adding BSSID 00:1d:70:01:b7:f1 to PMKID cache for station e8:39:df:84:8b:0c

*Mar 04 10:45:31.796: New PMKID: (16)

*Mar 04 10:45:31.796: [0000] 97 99 58 1b e9 58 dc 41 9c 73 36 bb 61 8d ac eb

*Mar 04 10:45:31.797: e8:39:df:84:8b:0c Initiating RSN PSK to mobile e8:39:df:84:8b:0c

*Mar 04 10:45:31.797: e8:39:df:84:8b:0c dot1x - moving mobile e8:39:df:84:8b:0c into Force Auth state

*Mar 04 10:45:31.797: e8:39:df:84:8b:0c Skipping EAP-Success to mobile e8:39:df:84:8b:0c

*Mar 04 10:45:31.797: Including PMKID in M1 (16)

*Mar 04 10:45:31.797: [0000] 97 99 58 1b e9 58 dc 41 9c 73 36 bb 61 8d ac eb

*Mar 04 10:45:31.797: e8:39:df:84:8b:0c Starting key exchange to mobile e8:39:df:84:8b:0c, data packets will be dropped

*Mar 04 10:45:31.797: e8:39:df:84:8b:0c Sending EAPOL-Key Message to mobile e8:39:df:84:8b:0c

state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Mar 04 10:45:33.456: e8:39:df:84:8b:0c Association received from mobile on AP 00:1d:70:01:b7:f0

*Mar 04 10:45:33.456: e8:39:df:84:8b:0c Applying site-specific IPv6 override for station e8:39:df:84:8b:0c - vapId 2, site 'default-group', interface 'mpids_gh_if'

*Mar 04 10:45:33.456: e8:39:df:84:8b:0c Applying IPv6 Interface Policy for station e8:39:df:84:8b:0c - vlan 14, interface id 9, interface 'mpids_gh_if'

*Mar 04 10:45:33.456: e8:39:df:84:8b:0c STA - rates (8): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*Mar 04 10:45:33.456: e8:39:df:84:8b:0c STA - rates (12): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*Mar 04 10:45:33.456: e8:39:df:84:8b:0c Processing RSN IE type 48, length 20 for mobile e8:39:df:84:8b:0c

*Mar 04 10:45:33.456: e8:39:df:84:8b:0c apfProcessAssocReq (apf_80211.c:4240) Changing state for mobile e8:39:df:84:8b:0c on AP 00:1d:70:01:b7:f0 from Associated to AAA Pending

*Mar 04 10:45:33.456: e8:39:df:84:8b:0c Scheduling deletion of Mobile Station: (callerId: 20) in 10 seconds

*Mar 04 10:45:33.457: e8:39:df:84:8b:0c 192.168.243.45 8021X_REQD (3) Initializing policy

*Mar 04 10:45:33.457: e8:39:df:84:8b:0c 192.168.243.45 8021X_REQD (3) Change state to AUTHCHECK (2) last state RUN (20)

*Mar 04 10:45:33.457: e8:39:df:84:8b:0c 192.168.243.45 AUTHCHECK (2) Change state to 8021X_REQD (3) last state RUN (20)

*Mar 04 10:45:33.457: e8:39:df:84:8b:0c 192.168.243.45 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 00:1d:70:01:b7:f0 vapId 2 apVapId 2

*Mar 04 10:45:33.457: e8:39:df:84:8b:0c apfPemAddUser2 (apf_policy.c:212) Changing state for mobile e8:39:df:84:8b:0c on AP 00:1d:70:01:b7:f0 from AAA Pending to Associated

*Mar 04 10:45:33.457: e8:39:df:84:8b:0c Stopping deletion of Mobile Station: (callerId: 48)

*Mar 04 10:45:33.457: e8:39:df:84:8b:0c Sending Assoc Response to station on BSSID 00:1d:70:01:b7:f0 (status 0)

*Mar 04 10:45:33.457: e8:39:df:84:8b:0c apfProcessRadiusAssocResp (apf_80211.c:1956) Changing state for mobile e8:39:df:84:8b:0c on AP 00:1d:70:01:b7:f0 from Associated to Associated

*Mar 04 10:45:33.700: e8:39:df:84:8b:0c 802.1x 'timeoutEvt' Timer expired for station e8:39:df:84:8b:0c

*Mar 04 10:45:33.700: e8:39:df:84:8b:0c Retransmit 1 of EAPOL-Key M1 (length 121) for mobile e8:39:df:84:8b:0c

*Mar 04 10:45:33.969: e8:39:df:84:8b:0c Association received from mobile on AP 00:1d:70:01:b5:a0

*Mar 04 10:45:33.969: e8:39:df:84:8b:0c Applying site-specific IPv6 override for station e8:39:df:84:8b:0c - vapId 2, site 'default-group', interface 'mpids_gh_if'

*Mar 04 10:45:33.969: e8:39:df:84:8b:0c Applying IPv6 Interface Policy for station e8:39:df:84:8b:0c - vlan 14, interface id 9, interface 'mpids_gh_if'

*Mar 04 10:45:33.969: e8:39:df:84:8b:0c STA - rates (8): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*Mar 04 10:45:33.969: e8:39:df:84:8b:0c STA - rates (12): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*Mar 04 10:45:33.969: e8:39:df:84:8b:0c Processing RSN IE type 48, length 20 for mobile e8:39:df:84:8b:0c

*Mar 04 10:45:33.970: e8:39:df:84:8b:0c 192.168.243.45 8021X_REQD (3) Deleted mobile LWAPP rule on AP [00:1d:70:01:b7:f0]

*Mar 04 10:45:33.970: e8:39:df:84:8b:0c Updated location for station old AP 00:1d:70:01:b7:f0-0, new AP 00:1d:70:01:b5:a0-0

*Mar 04 10:45:33.970: e8:39:df:84:8b:0c apfProcessAssocReq (apf_80211.c:4240) Changing state for mobile e8:39:df:84:8b:0c on AP 00:1d:70:01:b5:a0 from Associated to AAA Pending

*Mar 04 10:45:33.970: e8:39:df:84:8b:0c Scheduling deletion of Mobile Station: (callerId: 20) in 10 seconds

*Mar 04 10:45:33.971: e8:39:df:84:8b:0c 192.168.243.45 8021X_REQD (3) Initializing policy

*Mar 04 10:45:33.971: e8:39:df:84:8b:0c 192.168.243.45 8021X_REQD (3) Change state to AUTHCHECK (2) last state RUN (20)

*Mar 04 10:45:33.971: e8:39:df:84:8b:0c 192.168.243.45 AUTHCHECK (2) Change state to 8021X_REQD (3) last state RUN (20)

*Mar 04 10:45:33.971: e8:39:df:84:8b:0c 192.168.243.45 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 00:1d:70:01:b5:a0 vapId 2 apVapId 2

*Mar 04 10:45:33.971: e8:39:df:84:8b:0c apfPemAddUser2 (apf_policy.c:212) Changing state for mobile e8:39:df:84:8b:0c on AP 00:1d:70:01:b5:a0 from AAA Pending to Associated

*Mar 04 10:45:33.971: e8:39:df:84:8b:0c Stopping deletion of Mobile Station: (callerId: 48)

*Mar 04 10:45:33.971: e8:39:df:84:8b:0c Sending Assoc Response to station on BSSID 00:1d:70:01:b5:a0 (status 0)

*Mar 04 10:45:33.971: e8:39:df:84:8b:0c apfProcessRadiusAssocResp (apf_80211.c:1956) Changing state for mobile e8:39:df:84:8b:0c on AP 00:1d:70:01:b5:a0 from Associated to Associated

*Mar 04 10:45:33.977: e8:39:df:84:8b:0c Creating a PKC PMKID Cache entry for station e8:39:df:84:8b:0c (RSN 2)

*Mar 04 10:45:33.977: e8:39:df:84:8b:0c Adding BSSID 00:1d:70:01:b5:a1 to PMKID cache for station e8:39:df:84:8b:0c

*Mar 04 10:45:33.977: New PMKID: (16)

*Mar 04 10:45:33.977: [0000] 1a 3a 8b 04 05 59 7f f2 71 cb 4c 32 9c c2 3e 4d

*Mar 04 10:45:33.977: e8:39:df:84:8b:0c Initiating RSN PSK to mobile e8:39:df:84:8b:0c

*Mar 04 10:45:33.978: e8:39:df:84:8b:0c dot1x - moving mobile e8:39:df:84:8b:0c into Force Auth state

*Mar 04 10:45:33.978: e8:39:df:84:8b:0c Skipping EAP-Success to mobile e8:39:df:84:8b:0c

*Mar 04 10:45:33.978: Including PMKID in M1 (16)

*Mar 04 10:45:33.978: [0000] 1a 3a 8b 04 05 59 7f f2 71 cb 4c 32 9c c2 3e 4d

*Mar 04 10:45:33.978: e8:39:df:84:8b:0c Starting key exchange to mobile e8:39:df:84:8b:0c, data packets will be dropped

*Mar 04 10:45:33.978: e8:39:df:84:8b:0c Sending EAPOL-Key Message to mobile e8:39:df:84:8b:0c

state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Mar 04 10:45:33.983: e8:39:df:84:8b:0c Received EAPOL-Key from mobile e8:39:df:84:8b:0c

*Mar 04 10:45:33.984: e8:39:df:84:8b:0c Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile e8:39:df:84:8b:0c

*Mar 04 10:45:33.984: e8:39:df:84:8b:0c Received EAPOL-key in PTK_START state (message 2) from mobile e8:39:df:84:8b:0c

*Mar 04 10:45:33.984: e8:39:df:84:8b:0c Stopping retransmission timer for mobile e8:39:df:84:8b:0c

*Mar 04 10:45:33.984: e8:39:df:84:8b:0c Sending EAPOL-Key Message to mobile e8:39:df:84:8b:0c

state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01

*Mar 04 10:45:33.990: e8:39:df:84:8b:0c Received EAPOL-Key from mobile e8:39:df:84:8b:0c

*Mar 04 10:45:33.990: e8:39:df:84:8b:0c Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile e8:39:df:84:8b:0c

*Mar 04 10:45:33.990: e8:39:df:84:8b:0c Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile e8:39:df:84:8b:0c

*Mar 04 10:45:33.990: e8:39:df:84:8b:0c 192.168.243.45 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Mar 04 10:45:33.991: e8:39:df:84:8b:0c 192.168.243.45 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 00:1d:70:01:b5:a0 vapId 2 apVapId 2

*Mar 04 10:45:33.991: e8:39:df:84:8b:0c 192.168.243.45 L2AUTHCOMPLETE (4) Change state to RUN (20) last state RUN (20)

*Mar 04 10:45:33.992: e8:39:df:84:8b:0c 192.168.243.45 RUN (20) Reached PLUMBFASTPATH: from line 4574

*Mar 04 10:45:33.992: e8:39:df:84:8b:0c 192.168.243.45 RUN (20) Adding Fast Path rule

type = Airespace AP Client

on AP 00:1d:70:01:b5:a0, slot 0, interface = 1, QOS = 0

ACL Id = 255, Jumbo Frames = NO,

*Mar 04 10:45:33.992: e8:39:df:84:8b:0c 192.168.243.45 RUN (20) Successfully plumbed mobile rule (ACL ID 255)

*Mar 04 10:45:33.992: e8:39:df:84:8b:0c Stopping retransmission timer for mobile e8:39:df:84:8b:0c

*Mar 04 10:45:33.996: e8:39:df:84:8b:0c 192.168.243.45 Added NPU entry of type 1, dtlFlags 0x0

*Mar 04 10:45:34.028: e8:39:df:84:8b:0c DHCP received op BOOTREQUEST (1) (len 324, port 1, encap 0xec03)

*Mar 04 10:45:34.029: e8:39:df:84:8b:0c DHCP selecting relay 1 - control block settings:

dhcpServer: 192.168.243.1, dhcpNetmask: 255.255.255.0,

dhcpGateway: 192.168.243.254, dhcpRelay: 192.168.243.1 VL

*Mar 04 10:45:34.029: e8:39:df:84:8b:0c DHCP selected relay 1 - 192.168.243.1 (local address 192.168.243.1, gateway 192.168.243.1, VLAN 14, port 1)

*Mar 04 10:45:34.030: e8:39:df:84:8b:0c DHCP transmitting DHCP REQUEST (3)

*Mar 04 10:45:34.030: e8:39:df:84:8b:0c DHCP op: BOOTREQUEST, htype: Ethernet, hlen: 6, hops: 1

*Mar 04 10:45:34.030: e8:39:df:84:8b:0c DHCP xid: 0xfaa3e1da (4205044186), secs: 0, flags: 0

*Mar 04 10:45:34.030: e8:39:df:84:8b:0c DHCP chaddr: e8:39:df:84:8b:0c

*Mar 04 10:45:34.031: e8:39:df:84:8b:0c DHCP ciaddr: 0.0.0.0, yiaddr: 0.0.0.0

*Mar 04 10:45:34.031: e8:39:df:84:8b:0c DHCP siaddr: 0.0.0.0, giaddr: 192.168.243.1

*Mar 04 10:45:34.031: e8:39:df:84:8b:0c DHCP requested ip: 192.168.243.45

*Mar 04 10:45:34.032: e8:39:df:84:8b:0c DHCP selecting relay 2 - control block settings:

dhcpServer: 192.168.243.1, dhcpNetmask: 255.255.255.0,

dhcpGateway: 192.168.243.254, dhcpRelay: 192.168.243.1 VL

*Mar 04 10:45:34.032: e8:39:df:84:8b:0c DHCP selected relay 2 - NONE

*Mar 04 10:45:34.032: e8:39:df:84:8b:0c DHCP received op BOOTREPLY (2) (len 548, port 0, encap 0x0)

*Mar 04 10:45:34.033: e8:39:df:84:8b:0c DHCP sending REPLY to STA (len 418, port 1, vlan 252)

*Mar 04 10:45:34.033: e8:39:df:84:8b:0c DHCP transmitting DHCP ACK (5)

*Mar 04 10:45:34.034: e8:39:df:84:8b:0c DHCP op: BOOTREPLY, htype: Ethernet, hlen: 6, hops: 0

*Mar 04 10:45:34.034: e8:39:df:84:8b:0c DHCP xid: 0xfaa3e1da (4205044186), secs: 0, flags: 0

*Mar 04 10:45:34.034: e8:39:df:84:8b:0c DHCP chaddr: e8:39:df:84:8b:0c

*Mar 04 10:45:34.034: e8:39:df:84:8b:0c DHCP ciaddr: 0.0.0.0, yiaddr: 192.168.243.45

*Mar 04 10:45:34.035: e8:39:df:84:8b:0c DHCP siaddr: 0.0.0.0, giaddr: 0.0.0.0

*Mar 04 10:45:34.035: e8:39:df:84:8b:0c DHCP server id: 1.1.1.1 rcvd server id: 192.168.243.1

*Mar 04 10:45:36.305: e8:39:df:84:8b:0c Creating a PKC PMKID Cache entry for station e8:39:df:84:8b:0c (RSN 2)

*Mar 04 10:45:36.305: e8:39:df:84:8b:0c Adding BSSID 00:1d:70:01:b5:a1 to PMKID cache for station e8:39:df:84:8b:0c

*Mar 04 10:45:36.305: New PMKID: (16)

*Mar 04 10:45:36.305: [0000] 1a 3a 8b 04 05 59 7f f2 71 cb 4c 32 9c c2 3e 4d

*Mar 04 10:45:36.305: e8:39:df:84:8b:0c Initiating RSN PSK to mobile e8:39:df:84:8b:0c

*Mar 04 10:45:36.305: e8:39:df:84:8b:0c dot1x - moving mobile e8:39:df:84:8b:0c into Force Auth state

*Mar 04 10:45:36.306: e8:39:df:84:8b:0c Skipping EAP-Success to mobile e8:39:df:84:8b:0c

*Mar 04 10:45:36.306: Including PMKID in M1 (16)

*Mar 04 10:45:36.306: [0000] 1a 3a 8b 04 05 59 7f f2 71 cb 4c 32 9c c2 3e 4d

*Mar 04 10:45:36.306: e8:39:df:84:8b:0c Starting key exchange to mobile e8:39:df:84:8b:0c, data packets will be dropped

*Mar 04 10:45:36.306: e8:39:df:84:8b:0c Sending EAPOL-Key Message to mobile e8:39:df:84:8b:0c

state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Mar 04 10:45:38.300: e8:39:df:84:8b:0c 802.1x 'timeoutEvt' Timer expired for station e8:39:df:84:8b:0c

*Mar 04 10:45:38.300: e8:39:df:84:8b:0c Retransmit 1 of EAPOL-Key M1 (length 121) for mobile e8:39:df:84:8b:0c

*Mar 04 10:45:40.300: e8:39:df:84:8b:0c 802.1x 'timeoutEvt' Timer expired for station e8:39:df:84:8b:0c

*Mar 04 10:45:40.300: e8:39:df:84:8b:0c Retransmit 2 of EAPOL-Key M1 (length 121) for mobile e8:39:df:84:8b:0c

*Mar 04 10:45:41.568: e8:39:df:84:8b:0c Reassociation received from mobile on AP 00:1d:70:01:b7:f0

*Mar 04 10:45:41.568: e8:39:df:84:8b:0c Applying site-specific IPv6 override for station e8:39:df:84:8b:0c - vapId 2, site 'default-group', interface 'mpids_gh_if'

*Mar 04 10:45:41.568: e8:39:df:84:8b:0c Applying IPv6 Interface Policy for station e8:39:df:84:8b:0c - vlan 14, interface id 9, interface 'mpids_gh_if'

*Mar 04 10:45:41.568: e8:39:df:84:8b:0c STA - rates (8): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*Mar 04 10:45:41.568: e8:39:df:84:8b:0c STA - rates (12): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*Mar 04 10:45:41.569: e8:39:df:84:8b:0c Processing RSN IE type 48, length 20 for mobile e8:39:df:84:8b:0c

*Mar 04 10:45:41.569: e8:39:df:84:8b:0c 192.168.243.45 RUN (20) Deleted mobile LWAPP rule on AP [00:1d:70:01:b5:a0]

*Mar 04 10:45:41.569: e8:39:df:84:8b:0c Updated location for station old AP 00:1d:70:01:b5:a0-0, new AP 00:1d:70:01:b7:f0-0

*Mar 04 10:45:41.569: e8:39:df:84:8b:0c 192.168.243.45 RUN (20) Change state to START (0) last state RUN (20)

*Mar 04 10:45:41.569: e8:39:df:84:8b:0c 192.168.243.45 START (0) Initializing policy

*Mar 04 10:45:41.569: e8:39:df:84:8b:0c 192.168.243.45 START (0) Change state to AUTHCHECK (2) last state RUN (20)

*Mar 04 10:45:41.569: e8:39:df:84:8b:0c 192.168.243.45 AUTHCHECK (2) Change state to 8021X_REQD (3) last state RUN (20)

*Mar 04 10:45:41.569: e8:39:df:84:8b:0c 192.168.243.45 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 00:1d:70:01:b7:f0 vapId 2 apVapId 2

*Mar 04 10:45:41.569: e8:39:df:84:8b:0c apfPemAddUser2 (apf_policy.c:212) Changing state for mobile e8:39:df:84:8b:0c on AP 00:1d:70:01:b7:f0 from Associated to Associated

*Mar 04 10:45:41.569: e8:39:df:84:8b:0c Stopping deletion of Mobile Station: (callerId: 48)

*Mar 04 10:45:41.569: e8:39:df:84:8b:0c Sending Assoc Response to station on BSSID 00:1d:70:01:b7:f0 (status 0)

*Mar 04 10:45:41.569: e8:39:df:84:8b:0c apfProcessAssocReq (apf_80211.c:4361) Changing state for mobile e8:39:df:84:8b:0c on AP 00:1d:70:01:b7:f0 from Associated to Associated

*Mar 04 10:45:41.573: e8:39:df:84:8b:0c 192.168.243.45 Removed NPU entry.

*Mar 04 10:45:42.300: e8:39:df:84:8b:0c 802.1x 'timeoutEvt' Timer expired for station e8:39:df:84:8b:0c

*Mar 04 10:45:42.300: e8:39:df:84:8b:0c Retransmit 3 of EAPOL-Key M1 (length 121) for mobile e8:39:df:84:8b:0c

*Mar 04 10:45:42.394: e8:39:df:84:8b:0c Received EAPOL-Key from mobile e8:39:df:84:8b:0c

*Mar 04 10:45:42.394: e8:39:df:84:8b:0c Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile e8:39:df:84:8b:0c

*Mar 04 10:45:42.394: e8:39:df:84:8b:0c Received EAPOL-key in PTK_START state (message 2) from mobile e8:39:df:84:8b:0c

*Mar 04 10:45:42.395: e8:39:df:84:8b:0c Stopping retransmission timer for mobile e8:39:df:84:8b:0c

*Mar 04 10:45:42.395: e8:39:df:84:8b:0c Sending EAPOL-Key Message to mobile e8:39:df:84:8b:0c

state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.04

*Mar 04 10:45:42.407: e8:39:df:84:8b:0c Received EAPOL-Key from mobile e8:39:df:84:8b:0c

*Mar 04 10:45:42.407: e8:39:df:84:8b:0c Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile e8:39:df:84:8b:0c

*Mar 04 10:45:42.407: e8:39:df:84:8b:0c Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile e8:39:df:84:8b:0c

*Mar 04 10:45:42.407: e8:39:df:84:8b:0c 192.168.243.45 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Mar 04 10:45:42.407: e8:39:df:84:8b:0c 192.168.243.45 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 00:1d:70:01:b7:f0 vapId 2 apVapId 2

*Mar 04 10:45:42.407: e8:39:df:84:8b:0c 192.168.243.45 L2AUTHCOMPLETE (4) Change state to RUN (20) last state RUN (20)

*Mar 04 10:45:42.408: e8:39:df:84:8b:0c 192.168.243.45 RUN (20) Reached PLUMBFASTPATH: from line 4574

*Mar 04 10:45:42.408: e8:39:df:84:8b:0c 192.168.243.45 RUN (20) Adding Fast Path rule

type = Airespace AP Client

on AP 00:1d:70:01:b7:f0, slot 0, interface = 1, QOS = 0

ACL Id = 255, Jumbo Frames = NO,

*Mar 04 10:45:42.409: e8:39:df:84:8b:0c 192.168.243.45 RUN (20) Successfully plumbed mobile rule (ACL ID 255)

*Mar 04 10:45:42.409: e8:39:df:84:8b:0c Stopping retransmission timer for mobile e8:39:df:84:8b:0c

*Mar 04 10:45:42.412: e8:39:df:84:8b:0c 192.168.243.45 Added NPU entry of type 1, dtlFlags 0x0

*Mar 04 10:45:44.510: e8:39:df:84:8b:0c Creating a PKC PMKID Cache entry for station e8:39:df:84:8b:0c (RSN 2)

*Mar 04 10:45:44.510: e8:39:df:84:8b:0c Adding BSSID 00:1d:70:01:b7:f1 to PMKID cache for station e8:39:df:84:8b:0c

*Mar 04 10:45:44.510: New PMKID: (16)

*Mar 04 10:45:44.510: [0000] 97 99 58 1b e9 58 dc 41 9c 73 36 bb 61 8d ac eb

*Mar 04 10:45:44.510: e8:39:df:84:8b:0c Initiating RSN PSK to mobile e8:39:df:84:8b:0c

*Mar 04 10:45:44.510: e8:39:df:84:8b:0c dot1x - moving mobile e8:39:df:84:8b:0c into Force Auth state

*Mar 04 10:45:44.510: e8:39:df:84:8b:0c Skipping EAP-Success to mobile e8:39:df:84:8b:0c

*Mar 04 10:45:44.511: Including PMKID in M1 (16)

*Mar 04 10:45:44.511: [0000] 97 99 58 1b e9 58 dc 41 9c 73 36 bb 61 8d ac eb

*Mar 04 10:45:44.511: e8:39:df:84:8b:0c Starting key exchange to mobile e8:39:df:84:8b:0c, data packets will be dropped

*Mar 04 10:45:44.511: e8:39:df:84:8b:0c Sending EAPOL-Key Message to mobile e8:39:df:84:8b:0c

state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Mar 04 10:45:46.307: e8:39:df:84:8b:0c DHCP received op BOOTREQUEST (1) (len 324, port 1, encap 0xec03)

*Mar 04 10:45:46.307: e8:39:df:84:8b:0c DHCP selecting relay 1 - control block settings:

dhcpServer: 192.168.243.1, dhcpNetmask: 255.255.255.0,

dhcpGateway: 192.168.243.254, dhcpRelay: 192.168.243.1 VL

*Mar 04 10:45:46.307: e8:39:df:84:8b:0c DHCP selected relay 1 - 192.168.243.1 (local address 192.168.243.1, gateway 192.168.243.1, VLAN 14, port 1)

*Mar 04 10:45:46.307: e8:39:df:84:8b:0c DHCP transmitting DHCP REQUEST (3)

*Mar 04 10:45:46.307: e8:39:df:84:8b:0c DHCP op: BOOTREQUEST, htype: Ethernet, hlen: 6, hops: 1

*Mar 04 10:45:46.307: e8:39:df:84:8b:0c DHCP xid: 0x27fda435 (670934069), secs: 1024, flags: 0

*Mar 04 10:45:46.307: e8:39:df:84:8b:0c DHCP chaddr: e8:39:df:84:8b:0c

*Mar 04 10:45:46.308: e8:39:df:84:8b:0c DHCP ciaddr: 0.0.0.0, yiaddr: 0.0.0.0

*Mar 04 10:45:46.308: e8:39:df:84:8b:0c DHCP siaddr: 0.0.0.0, giaddr: 192.168.243.1

*Mar 04 10:45:46.308: e8:39:df:84:8b:0c DHCP requested ip: 192.168.243.45

*Mar 04 10:45:46.308: e8:39:df:84:8b:0c DHCP selecting relay 2 - control block settings:

dhcpServer: 192.168.243.1, dhcpNetmask: 255.255.255.0,

dhcpGateway: 192.168.243.254, dhcpRelay: 192.168.243.1 VL

*Mar 04 10:45:46.308: e8:39:df:84:8b:0c DHCP selected relay 2 - NONE

*Mar 04 10:45:46.309: e8:39:df:84:8b:0c DHCP received op BOOTREPLY (2) (len 548, port 0, encap 0x0)

*Mar 04 10:45:46.309: e8:39:df:84:8b:0c DHCP sending REPLY to STA (len 418, port 1, vlan 252)

*Mar 04 10:45:46.310: e8:39:df:84:8b:0c DHCP transmitting DHCP ACK (5)

*Mar 04 10:45:46.310: e8:39:df:84:8b:0c DHCP op: BOOTREPLY, htype: Ethernet, hlen: 6, hops: 0

*Mar 04 10:45:46.310: e8:39:df:84:8b:0c DHCP xid: 0x27fda435 (670934069), secs: 0, flags: 0

*Mar 04 10:45:46.310: e8:39:df:84:8b:0c DHCP chaddr: e8:39:df:84:8b:0c

*Mar 04 10:45:46.310: e8:39:df:84:8b:0c DHCP ciaddr: 0.0.0.0, yiaddr: 192.168.243.45

*Mar 04 10:45:46.310: e8:39:df:84:8b:0c DHCP siaddr: 0.0.0.0, giaddr: 0.0.0.0

*Mar 04 10:45:46.310: e8:39:df:84:8b:0c DHCP server id: 1.1.1.1 rcvd server id: 192.168.243.1

*Mar 04 10:45:46.500: e8:39:df:84:8b:0c 802.1x 'timeoutEvt' Timer expired for station e8:39:df:84:8b:0c

*Mar 04 10:45:46.500: e8:39:df:84:8b:0c Retransmit 1 of EAPOL-Key M1 (length 121) for mobile e8:39:df:84:8b:0c

*Mar 04 10:45:48.500: e8:39:df:84:8b:0c 802.1x 'timeoutEvt' Timer expired for station e8:39:df:84:8b:0c

*Mar 04 10:45:48.500: e8:39:df:84:8b:0c Retransmit 2 of EAPOL-Key M1 (length 121) for mobile e8:39:df:84:8b:0c

*Mar 04 10:45:50.500: e8:39:df:84:8b:0c 802.1x 'timeoutEvt' Timer expired for station e8:39:df:84:8b:0c

*Mar 04 10:45:50.500: e8:39:df:84:8b:0c Retransmit 3 of EAPOL-Key M1 (length 121) for mobile e8:39:df:84:8b:0c

*Mar 04 10:45:52.500: e8:39:df:84:8b:0c 802.1x 'timeoutEvt' Timer expired for station e8:39:df:84:8b:0c

*Mar 04 10:45:52.500: e8:39:df:84:8b:0c Retransmit 4 of EAPOL-Key M1 (length 121) for mobile e8:39:df:84:8b:0c

*Mar 04 10:45:54.500: e8:39:df:84:8b:0c 802.1x 'timeoutEvt' Timer expired for station e8:39:df:84:8b:0c

*Mar 04 10:45:54.501: e8:39:df:84:8b:0c Retransmit failure for EAPOL-Key M1 to mobile e8:39:df:84:8b:0c, retransmit count 5, mscb deauth count 0

*Mar 04 10:45:54.502: e8:39:df:84:8b:0c Sent Deauthenticate to mobile on BSSID 00:1d:70:01:b7:f0 slot 0(caller 1x_ptsm.c:467)

*Mar 04 10:45:54.502: e8:39:df:84:8b:0c Scheduling deletion of Mobile Station: (callerId: 57) in 10 seconds

*Mar 04 10:45:54.860: e8:39:df:84:8b:0c Association received from mobile on AP 00:1d:70:01:bc:20

*Mar 04 10:45:54.860: e8:39:df:84:8b:0c Applying site-specific IPv6 override for station e8:39:df:84:8b:0c - vapId 2, site 'default-group', interface 'mpids_gh_if'

*Mar 04 10:45:54.860: e8:39:df:84:8b:0c Applying IPv6 Interface Policy for station e8:39:df:84:8b:0c - vlan 14, interface id 9, interface 'mpids_gh_if'

*Mar 04 10:45:54.860: e8:39:df:84:8b:0c STA - rates (8): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*Mar 04 10:45:54.860: e8:39:df:84:8b:0c STA - rates (12): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*Mar 04 10:45:54.860: e8:39:df:84:8b:0c Processing RSN IE type 48, length 20 for mobile e8:39:df:84:8b:0c

*Mar 04 10:45:54.861: e8:39:df:84:8b:0c 192.168.243.45 RUN (20) Deleted mobile LWAPP rule on AP [00:1d:70:01:b7:f0]

*Mar 04 10:45:54.861: e8:39:df:84:8b:0c Updated location for station old AP 00:1d:70:01:b7:f0-0, new AP 00:1d:70:01:bc:20-0

*Mar 04 10:45:54.861: e8:39:df:84:8b:0c 192.168.243.45 RUN (20) Change state to START (0) last state RUN (20)

*Mar 04 10:45:54.861: e8:39:df:84:8b:0c 192.168.243.45 START (0) Initializing policy

*Mar 04 10:45:54.861: e8:39:df:84:8b:0c 192.168.243.45 START (0) Change state to AUTHCHECK (2) last state RUN (20)

*Mar 04 10:45:54.861: e8:39:df:84:8b:0c 192.168.243.45 AUTHCHECK (2) Change state to 8021X_REQD (3) last state RUN (20)

*Mar 04 10:45:54.861: e8:39:df:84:8b:0c 192.168.243.45 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 00:1d:70:01:bc:20 vapId 2 apVapId 2

*Mar 04 10:45:54.861: e8:39:df:84:8b:0c apfPemAddUser2 (apf_policy.c:212) Changing state for mobile e8:39:df:84:8b:0c on AP 00:1d:70:01:bc:20 from Associated to Associated

*Mar 04 10:45:54.861: e8:39:df:84:8b:0c Stopping deletion of Mobile Station: (callerId: 48)

*Mar 04 10:45:54.861: e8:39:df:84:8b:0c Sending Assoc Response to station on BSSID 00:1d:70:01:bc:20 (status 0)

*Mar 04 10:45:54.861: e8:39:df:84:8b:0c apfProcessAssocReq (apf_80211.c:4361) Changing state for mobile e8:39:df:84:8b:0c on AP 00:1d:70:01:bc:20 from Associated to Associated

*Mar 04 10:45:54.865: e8:39:df:84:8b:0c 192.168.243.45 Removed NPU entry.

*Mar 04 10:45:54.876: e8:39:df:84:8b:0c Creating a PKC PMKID Cache entry for station e8:39:df:84:8b:0c (RSN 2)

*Mar 04 10:45:54.876: e8:39:df:84:8b:0c Adding BSSID 00:1d:70:01:bc:21 to PMKID cache for station e8:39:df:84:8b:0c

*Mar 04 10:45:54.876: New PMKID: (16)

*Mar 04 10:45:54.876: [0000] c6 08 0c ca 6e 3a 2f 12 7f 1e dc b4 de 71 53 2c

*Mar 04 10:45:54.876: e8:39:df:84:8b:0c Initiating RSN PSK to mobile e8:39:df:84:8b:0c

*Mar 04 10:45:54.876: e8:39:df:84:8b:0c dot1x - moving mobile e8:39:df:84:8b:0c into Force Auth state

*Mar 04 10:45:54.877: e8:39:df:84:8b:0c Skipping EAP-Success to mobile e8:39:df:84:8b:0c

*Mar 04 10:45:54.877: Including PMKID in M1 (16)

*Mar 04 10:45:54.877: [0000] c6 08 0c ca 6e 3a 2f 12 7f 1e dc b4 de 71 53 2c

*Mar 04 10:45:54.877: e8:39:df:84:8b:0c Starting key exchange to mobile e8:39:df:84:8b:0c, data packets will be dropped

*Mar 04 10:45:54.877: e8:39:df:84:8b:0c Sending EAPOL-Key Message to mobile e8:39:df:84:8b:0c

state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Mar 04 10:45:54.895: e8:39:df:84:8b:0c Received EAPOL-Key from mobile e8:39:df:84:8b:0c

*Mar 04 10:45:54.895: e8:39:df:84:8b:0c Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile e8:39:df:84:8b:0c

*Mar 04 10:45:54.895: e8:39:df:84:8b:0c Received EAPOL-key in PTK_START state (message 2) from mobile e8:39:df:84:8b:0c

*Mar 04 10:45:54.896: e8:39:df:84:8b:0c Stopping retransmission timer for mobile e8:39:df:84:8b:0c

*Mar 04 10:45:54.896: e8:39:df:84:8b:0c Sending EAPOL-Key Message to mobile e8:39:df:84:8b:0c

state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01

*Mar 04 10:45:55.247: e8:39:df:84:8b:0c Reassociation received from mobile on AP 00:1d:70:01:b5:a0

*Mar 04 10:45:55.247: e8:39:df:84:8b:0c Applying site-specific IPv6 override for station e8:39:df:84:8b:0c - vapId 2, site 'default-group', interface 'mpids_gh_if'

*Mar 04 10:45:55.247: e8:39:df:84:8b:0c Applying IPv6 Interface Policy for station e8:39:df:84:8b:0c - vlan 14, interface id 9, interface 'mpids_gh_if'

*Mar 04 10:45:55.247: e8:39:df:84:8b:0c STA - rates (8): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*Mar 04 10:45:55.247: e8:39:df:84:8b:0c STA - rates (12): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*Mar 04 10:45:55.247: e8:39:df:84:8b:0c Processing RSN IE type 48, length 20 for mobile e8:39:df:84:8b:0c

*Mar 04 10:45:55.247: e8:39:df:84:8b:0c 192.168.243.45 8021X_REQD (3) Deleted mobile LWAPP rule on AP [00:1d:70:01:bc:20]

*Mar 04 10:45:55.247: e8:39:df:84:8b:0c Updated location for station old AP 00:1d:70:01:bc:20-0, new AP 00:1d:70:01:b5:a0-0

*Mar 04 10:45:55.247: e8:39:df:84:8b:0c apfProcessAssocReq (apf_80211.c:4240) Changing state for mobile e8:39:df:84:8b:0c on AP 00:1d:70:01:b5:a0 from Associated to AAA Pending

*Mar 04 10:45:55.247: e8:39:df:84:8b:0c Scheduling deletion of Mobile Station: (callerId: 20) in 10 seconds

*Mar 04 10:45:55.248: e8:39:df:84:8b:0c 192.168.243.45 8021X_REQD (3) Initializing policy

*Mar 04 10:45:55.248: e8:39:df:84:8b:0c 192.168.243.45 8021X_REQD (3) Change state to AUTHCHECK (2) last state RUN (20)

*Mar 04 10:45:55.248: e8:39:df:84:8b:0c 192.168.243.45 AUTHCHECK (2) Change state to 8021X_REQD (3) last state RUN (20)

*Mar 04 10:45:55.248: e8:39:df:84:8b:0c 192.168.243.45 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 00:1d:70:01:b5:a0 vapId 2 apVapId 2

*Mar 04 10:45:55.248: e8:39:df:84:8b:0c apfPemAddUser2 (apf_policy.c:212) Changing state for mobile e8:39:df:84:8b:0c on AP 00:1d:70:01:b5:a0 from AAA Pending to Associated

*Mar 04 10:45:55.248: e8:39:df:84:8b:0c Stopping deletion of Mobile Station: (callerId: 48)

*Mar 04 10:45:55.248: e8:39:df:84:8b:0c Sending Assoc Response to station on BSSID 00:1d:70:01:b5:a0 (status 0)

*Mar 04 10:45:55.248: e8:39:df:84:8b:0c apfProcessRadiusAssocResp (apf_80211.c:1956) Changing state for mobile e8:39:df:84:8b:0c on AP 00:1d:70:01:b5:a0 from Associated to Associated

*Mar 04 10:45:55.255: e8:39:df:84:8b:0c Creating a PKC PMKID Cache entry for station e8:39:df:84:8b:0c (RSN 2)

*Mar 04 10:45:55.256: e8:39:df:84:8b:0c Adding BSSID 00:1d:70:01:b5:a1 to PMKID cache for station e8:39:df:84:8b:0c

*Mar 04 10:45:55.256: New PMKID: (16)

*Mar 04 10:45:55.256: [0000] 1a 3a 8b 04 05 59 7f f2 71 cb 4c 32 9c c2 3e 4d

*Mar 04 10:45:55.256: e8:39:df:84:8b:0c Initiating RSN PSK to mobile e8:39:df:84:8b:0c

*Mar 04 10:45:55.256: e8:39:df:84:8b:0c dot1x - moving mobile e8:39:df:84:8b:0c into Force Auth state

*Mar 04 10:45:55.256: e8:39:df:84:8b:0c Skipping EAP-Success to mobile e8:39:df:84:8b:0c

*Mar 04 10:45:55.256: Including PMKID in M1 (16)

*Mar 04 10:45:55.256: [0000] 1a 3a 8b 04 05 59 7f f2 71 cb 4c 32 9c c2 3e 4d

*Mar 04 10:45:55.256: e8:39:df:84:8b:0c Starting key exchange to mobile e8:39:df:84:8b:0c, data packets will be dropped

*Mar 04 10:45:55.257: e8:39:df:84:8b:0c Sending EAPOL-Key Message to mobile e8:39:df:84:8b:0c

state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Mar 04 10:45:55.262: e8:39:df:84:8b:0c Received EAPOL-Key from mobile e8:39:df:84:8b:0c

*Mar 04 10:45:55.262: e8:39:df:84:8b:0c Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile e8:39:df:84:8b:0c

*Mar 04 10:45:55.262: e8:39:df:84:8b:0c Received EAPOL-key in PTK_START state (message 2) from mobile e8:39:df:84:8b:0c

*Mar 04 10:45:55.262: e8:39:df:84:8b:0c Stopping retransmission timer for mobile e8:39:df:84:8b:0c

*Mar 04 10:45:55.263: e8:39:df:84:8b:0c Sending EAPOL-Key Message to mobile e8:39:df:84:8b:0c

state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01

*Mar 04 10:45:55.273: e8:39:df:84:8b:0c Received EAPOL-Key from mobile e8:39:df:84:8b:0c

*Mar 04 10:45:55.273: e8:39:df:84:8b:0c Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile e8:39:df:84:8b:0c

*Mar 04 10:45:55.273: e8:39:df:84:8b:0c Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile e8:39:df:84:8b:0c

*Mar 04 10:45:55.274: e8:39:df:84:8b:0c 192.168.243.45 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Mar 04 10:45:55.274: e8:39:df:84:8b:0c 192.168.243.45 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 00:1d:70:01:b5:a0 vapId 2 apVapId 2

*Mar 04 10:45:55.274: e8:39:df:84:8b:0c 192.168.243.45 L2AUTHCOMPLETE (4) Change state to RUN (20) last state RUN (20)

*Mar 04 10:45:55.275: e8:39:df:84:8b:0c 192.168.243.45 RUN (20) Reached PLUMBFASTPATH: from line 4574

*Mar 04 10:45:55.275: e8:39:df:84:8b:0c 192.168.243.45 RUN (20) Adding Fast Path rule

type = Airespace AP Client

on AP 00:1d:70:01:b5:a0, slot 0, interface = 1, QOS = 0

ACL Id = 255, Jumbo Frames = NO,

*Mar 04 10:45:55.275: e8:39:df:84:8b:0c 192.168.243.45 RUN (20) Successfully plumbed mobile rule (ACL ID 255)

*Mar 04 10:45:55.275: e8:39:df:84:8b:0c Stopping retransmission timer for mobile e8:39:df:84:8b:0c

*Mar 04 10:45:55.279: e8:39:df:84:8b:0c 192.168.243.45 Added NPU entry of type 1, dtlFlags 0x0

*Mar 04 10:45:55.307: e8:39:df:84:8b:0c DHCP received op BOOTREQUEST (1) (len 324, port 1, encap 0xec03)

*Mar 04 10:45:55.307: e8:39:df:84:8b:0c DHCP selecting relay 1 - control block settings:

dhcpServer: 192.168.243.1, dhcpNetmask: 255.255.255.0,

dhcpGateway: 192.168.243.254, dhcpRelay: 192.168.243.1 VL

*Mar 04 10:45:55.307: e8:39:df:84:8b:0c DHCP selected relay 1 - 192.168.243.1 (local address 192.168.243.1, gateway 192.168.243.1, VLAN 14, port 1)

*Mar 04 10:45:55.308: e8:39:df:84:8b:0c DHCP transmitting DHCP REQUEST (3)

*Mar 04 10:45:55.308: e8:39:df:84:8b:0c DHCP op: BOOTREQUEST, htype: Ethernet, hlen: 6, hops: 1

*Mar 04 10:45:55.308: e8:39:df:84:8b:0c DHCP xid: 0x8c84a505 (2357503237), secs: 0, flags: 0

*Mar 04 10:45:55.309: e8:39:df:84:8b:0c DHCP chaddr: e8:39:df:84:8b:0c

*Mar 04 10:45:55.309: e8:39:df:84:8b:0c DHCP ciaddr: 0.0.0.0, yiaddr: 0.0.0.0

*Mar 04 10:45:55.309: e8:39:df:84:8b:0c DHCP siaddr: 0.0.0.0, giaddr: 192.168.243.1

*Mar 04 10:45:55.309: e8:39:df:84:8b:0c DHCP requested ip: 192.168.243.45

*Mar 04 10:45:55.310: e8:39:df:84:8b:0c DHCP selecting relay 2 - control block settings:

dhcpServer: 192.168.243.1, dhcpNetmask: 255.255.255.0,

dhcpGateway: 192.168.243.254, dhcpRelay: 192.168.243.1 VL

*Mar 04 10:45:55.310: e8:39:df:84:8b:0c DHCP selected relay 2 - NONE

*Mar 04 10:45:55.310: e8:39:df:84:8b:0c DHCP received op BOOTREPLY (2) (len 548, port 0, encap 0x0)

*Mar 04 10:45:55.311: e8:39:df:84:8b:0c DHCP sending REPLY to STA (len 418, port 1, vlan 252)

*Mar 04 10:45:55.311: e8:39:df:84:8b:0c DHCP transmitting DHCP ACK (5)

*Mar 04 10:45:55.311: e8:39:df:84:8b:0c DHCP op: BOOTREPLY, htype: Ethernet, hlen: 6, hops: 0

*Mar 04 10:45:55.312: e8:39:df:84:8b:0c DHCP xid: 0x8c84a505 (2357503237), secs: 0, flags: 0

*Mar 04 10:45:55.312: e8:39:df:84:8b:0c DHCP chaddr: e8:39:df:84:8b:0c

*Mar 04 10:45:55.312: e8:39:df:84:8b:0c DHCP ciaddr: 0.0.0.0, yiaddr: 192.168.243.45

*Mar 04 10:45:55.312: e8:39:df:84:8b:0c DHCP siaddr: 0.0.0.0, giaddr: 0.0.0.0

*Mar 04 10:45:55.313: e8:39:df:84:8b:0c DHCP server id: 1.1.1.1 rcvd server id: 192.168.243.1

*Mar 04 10:45:59.366: e8:39:df:84:8b:0c Reassociation received from mobile on AP 00:1d:70:01:b7:f0

*Mar 04 10:45:59.366: e8:39:df:84:8b:0c Applying site-specific IPv6 override for station e8:39:df:84:8b:0c - vapId 2, site 'default-group', interface 'mpids_gh_if'

*Mar 04 10:45:59.366: e8:39:df:84:8b:0c Applying IPv6 Interface Policy for station e8:39:df:84:8b:0c - vlan 14, interface id 9, interface 'mpids_gh_if'

*Mar 04 10:45:59.366: e8:39:df:84:8b:0c STA - rates (8): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*Mar 04 10:45:59.366: e8:39:df:84:8b:0c STA - rates (12): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*Mar 04 10:45:59.366: e8:39:df:84:8b:0c Processing RSN IE type 48, length 20 for mobile e8:39:df:84:8b:0c

*Mar 04 10:45:59.366: e8:39:df:84:8b:0c 192.168.243.45 RUN (20) Deleted mobile LWAPP rule on AP [00:1d:70:01:b5:a0]

*Mar 04 10:45:59.366: e8:39:df:84:8b:0c Updated location for station old AP 00:1d:70:01:b5:a0-0, new AP 00:1d:70:01:b7:f0-0

*Mar 04 10:45:59.366: e8:39:df:84:8b:0c 192.168.243.45 RUN (20) Change state to START (0) last state RUN (20)

*Mar 04 10:45:59.366: e8:39:df:84:8b:0c 192.168.243.45 START (0) Initializing policy

*Mar 04 10:45:59.366: e8:39:df:84:8b:0c 192.168.243.45 START (0) Change state to AUTHCHECK (2) last state RUN (20)

*Mar 04 10:45:59.366: e8:39:df:84:8b:0c 192.168.243.45 AUTHCHECK (2) Change state to 8021X_REQD (3) last state RUN (20)

*Mar 04 10:45:59.366: e8:39:df:84:8b:0c 192.168.243.45 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 00:1d:70:01:b7:f0 vapId 2 apVapId 2

*Mar 04 10:45:59.366: e8:39:df:84:8b:0c apfPemAddUser2 (apf_policy.c:212) Changing state for mobile e8:39:df:84:8b:0c on AP 00:1d:70:01:b7:f0 from Associated to Associated

*Mar 04 10:45:59.366: e8:39:df:84:8b:0c Stopping deletion of Mobile Station: (callerId: 48)

*Mar 04 10:45:59.366: e8:39:df:84:8b:0c Sending Assoc Response to station on BSSID 00:1d:70:01:b7:f0 (status 0)

*Mar 04 10:45:59.367: e8:39:df:84:8b:0c apfProcessAssocReq (apf_80211.c:4361) Changing state for mobile e8:39:df:84:8b:0c on AP 00:1d:70:01:b7:f0 from Associated to Associated

*Mar 04 10:45:59.370: e8:39:df:84:8b:0c 192.168.243.45 Removed NPU entry.

*Mar 04 10:46:02.312: e8:39:df:84:8b:0c Creating a PKC PMKID Cache entry for station e8:39:df:84:8b:0c (RSN 2)

*Mar 04 10:46:02.313: e8:39:df:84:8b:0c Adding BSSID 00:1d:70:01:b7:f1 to PMKID cache for station e8:39:df:84:8b:0c

*Mar 04 10:46:02.313: New PMKID: (16)

*Mar 04 10:46:02.313: [0000] 97 99 58 1b e9 58 dc 41 9c 73 36 bb 61 8d ac eb

*Mar 04 10:46:02.313: e8:39:df:84:8b:0c Initiating RSN PSK to mobile e8:39:df:84:8b:0c

*Mar 04 10:46:02.313: e8:39:df:84:8b:0c dot1x - moving mobile e8:39:df:84:8b:0c into Force Auth state

*Mar 04 10:46:02.313: e8:39:df:84:8b:0c Skipping EAP-Success to mobile e8:39:df:84:8b:0c

*Mar 04 10:46:02.313: Including PMKID in M1 (16)

*Mar 04 10:46:02.313: [0000] 97 99 58 1b e9 58 dc 41 9c 73 36 bb 61 8d ac eb

*Mar 04 10:46:02.313: e8:39:df:84:8b:0c Starting key exchange to mobile e8:39:df:84:8b:0c, data packets will be dropped

*Mar 04 10:46:02.314: e8:39:df:84:8b:0c Sending EAPOL-Key Message to mobile e8:39:df:84:8b:0c

state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Mar 04 10:46:02.439: e8:39:df:84:8b:0c Received EAPOL-Key from mobile e8:39:df:84:8b:0c

*Mar 04 10:46:02.439: e8:39:df:84:8b:0c Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile e8:39:df:84:8b:0c

*Mar 04 10:46:02.440: e8:39:df:84:8b:0c Received EAPOL-key in PTK_START state (message 2) from mobile e8:39:df:84:8b:0c

*Mar 04 10:46:02.440: e8:39:df:84:8b:0c Stopping retransmission timer for mobile e8:39:df:84:8b:0c

*Mar 04 10:46:02.440: e8:39:df:84:8b:0c Sending EAPOL-Key Message to mobile e8:39:df:84:8b:0c

state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01

*Mar 04 10:46:02.496: e8:39:df:84:8b:0c Received EAPOL-Key from mobile e8:39:df:84:8b:0c

*Mar 04 10:46:02.497: e8:39:df:84:8b:0c Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile e8:39:df:84:8b:0c

*Mar 04 10:46:02.497: e8:39:df:84:8b:0c Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile e8:39:df:84:8b:0c

*Mar 04 10:46:02.497: e8:39:df:84:8b:0c 192.168.243.45 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Mar 04 10:46:02.497: e8:39:df:84:8b:0c 192.168.243.45 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 00:1d:70:01:b7:f0 vapId 2 apVapId 2

*Mar 04 10:46:02.497: e8:39:df:84:8b:0c 192.168.243.45 L2AUTHCOMPLETE (4) Change state to RUN (20) last state RUN (20)

*Mar 04 10:46:02.498: e8:39:df:84:8b:0c 192.168.243.45 RUN (20) Reached PLUMBFASTPATH: from line 4574

*Mar 04 10:46:02.498: e8:39:df:84:8b:0c 192.168.243.45 RUN (20) Adding Fast Path rule

type = Airespace AP Client

on AP 00:1d:70:01:b7:f0, slot 0, interface = 1, QOS = 0

ACL Id = 255, Jumbo Frames = NO,

*Mar 04 10:46:02.499: e8:39:df:84:8b:0c 192.168.243.45 RUN (20) Successfully plumbed mobile rule (ACL ID 255)

*Mar 04 10:46:02.499: e8:39:df:84:8b:0c Stopping retransmission timer for mobile e8:39:df:84:8b:0c

*Mar 04 10:46:02.502: e8:39:df:84:8b:0c 192.168.243.45 Added NPU entry of type 1, dtlFlags 0x0

*Mar 04 10:46:06.483: e8:39:df:84:8b:0c DHCP received op BOOTREQUEST (1) (len 324, port 1, encap 0xec03)

*Mar 04 10:46:06.483: e8:39:df:84:8b:0c DHCP selecting relay 1 - control block settings:

dhcpServer: 192.168.243.1, dhcpNetmask: 255.255.255.0,

dhcpGateway: 192.168.243.254, dhcpRelay: 192.168.243.1 VL

*Mar 04 10:46:06.483: e8:39:df:84:8b:0c DHCP selected relay 1 - 192.168.243.1 (local address 192.168.243.1, gateway 192.168.243.1, VLAN 14, port 1)

*Mar 04 10:46:06.483: e8:39:df:84:8b:0c DHCP transmitting DHCP REQUEST (3)

*Mar 04 10:46:06.483: e8:39:df:84:8b:0c DHCP op: BOOTREQUEST, htype: Ethernet, hlen: 6, hops: 1

*Mar 04 10:46:06.483: e8:39:df:84:8b:0c DHCP xid: 0x24de6853 (618555475), secs: 1024, flags: 0

*Mar 04 10:46:06.483: e8:39:df:84:8b:0c DHCP chaddr: e8:39:df:84:8b:0c

*Mar 04 10:46:06.484: e8:39:df:84:8b:0c DHCP ciaddr: 0.0.0.0, yiaddr: 0.0.0.0

*Mar 04 10:46:06.484: e8:39:df:84:8b:0c DHCP siaddr: 0.0.0.0, giaddr: 192.168.243.1

*Mar 04 10:46:06.484: e8:39:df:84:8b:0c DHCP requested ip: 192.168.243.45

*Mar 04 10:46:06.484: e8:39:df:84:8b:0c DHCP selecting relay 2 - control block settings:

dhcpServer: 192.168.243.1, dhcpNetmask: 255.255.255.0,

dhcpGateway: 192.168.243.254, dhcpRelay: 192.168.243.1 VL

*Mar 04 10:46:06.484: e8:39:df:84:8b:0c DHCP selected relay 2 - NONE

*Mar 04 10:46:06.485: e8:39:df:84:8b:0c DHCP received op BOOTREPLY (2) (len 548, port 0, encap 0x0)

*Mar 04 10:46:06.485: e8:39:df:84:8b:0c DHCP sending REPLY to STA (len 418, port 1, vlan 252)

*Mar 04 10:46:06.485: e8:39:df:84:8b:0c DHCP transmitting DHCP ACK (5)

*Mar 04 10:46:06.486: e8:39:df:84:8b:0c DHCP op: BOOTREPLY, htype: Ethernet, hlen: 6, hops: 0

*Mar 04 10:46:06.486: e8:39:df:84:8b:0c DHCP xid: 0x24de6853 (618555475), secs: 0, flags: 0

*Mar 04 10:46:06.486: e8:39:df:84:8b:0c DHCP chaddr: e8:39:df:84:8b:0c

*Mar 04 10:46:06.486: e8:39:df:84:8b:0c DHCP ciaddr: 0.0.0.0, yiaddr: 192.168.243.45

*Mar 04 10:46:06.486: e8:39:df:84:8b:0c DHCP siaddr: 0.0.0.0, giaddr: 0.0.0.0