Is anyone using Radius to capture 802.1x session logs? We see several clients on our wpa2-802.1x ssid (random, not OS specific, but mostly IOS and MAC OS, yet still some Windows), that switch IPs within the lease time. I have a TAC case open, tried vlan mobility, preserve vlan, and IP Mobility but still see the same issue. Both controllers are connected to the same L2, and both have the same vlans and vlan pool configured. Even the same client connected to the same AP could connect for a minute, dissacociate, and when re-associating gets a diferent IP (see Radius start and stop session below). Also, still not clear why Aruba thinks this is one session, shouldn't this be 2 separate accounting sessions if it has different IPs, or is it based on the user idle time out?
We use external DHCP servers, and 30m lease times. User Idle Timeout is set to 12 minutes. We currently have one user on debug and we see the logs showing the same issue as the Radius accouting logs, TAC seems to be out of ideas. Client's Mac on debug is: 28:cf:da:de:ce:7c
Some clients will sometimes even change subnets, which makes less sense since with vlan pooling the client should always get the same subnet (unless adding or deleting a subnet from the pool wich changes the algorithm). We are running 6.1.2.5
I figured I post here maybe someone has seen a similar issue. Thanks!
from Aruba logs:
Oct 30 14:06:24 :522035: <INFO> |authmgr| MAC=28:cf:da:de:ce:7c Station UP: BSSID=d8:c7:c8:b5:75:50 ESSID=PioneerNet VLAN=220 AP-name=AP1-Mcomm
Oct 30 14:06:24 :500511: <DBUG> |mobileip| Station 28:cf:da:de:ce:7c, 0.0.0.0: Received association on ESSID: PioneerNet Mobility service Off, HA Discovery on Association Off, Fastroaming Disabled, AP: Name AP1-Mcomm Group DU-N BSSID d8:c7:c8:b5:75:50, phy a, VLAN 220
Oct 30 14:06:24 :500010: <NOTI> |mobileip| Station 28:cf:da:de:ce:7c, 0.0.0.0: Mobility trail, on switch 130.253.21.242, VLAN 220, AP AP1-Mcomm, PioneerNet/d8:c7:c8:b5:75:50/a
Oct 30 14:06:24 :522038: <INFO> |authmgr| username=872548589 MAC=28:cf:da:de:ce:7c IP=0.0.0.0 Authentication result=Authentication Successful method=802.1x server=Scabbers
Oct 30 14:06:24 :522044: <INFO> |authmgr| MAC=28:cf:da:de:ce:7c Station authenticate(start): method=802.1x, role=authenticated//, VLAN=220/220/0/0/0, Derivation=10/0, Value Pair=1
Oct 30 14:06:24 :522049: <INFO> |authmgr| MAC=28:cf:da:de:ce:7c,IP=0.0.0.0 User role updated, existing Role=authenticated/none, new Role=authenticated/none, reason=Station Authenticated with auth type: 4
Oct 30 14:06:24 :522050: <INFO> |authmgr| MAC=28:cf:da:de:ce:7c,IP=0.0.0.0 User data downloaded to datapath, new Role=authenticated/73, bw Contract=0/0,reason=Download driven by user role setting
Oct 30 14:06:24 :522029: <INFO> |authmgr| MAC=28:cf:da:de:ce:7c Station authenticate: method=802.1x, role=authenticated//, VLAN=220/220/0/0/0, Derivation=1/0, Value Pair=1
Oct 30 14:06:28 :522026: <INFO> |authmgr| MAC=28:cf:da:de:ce:7c IP=130.253.220.11 User miss: ingress=0x10b7, VLAN=220
Oct 30 14:06:28 :522049: <INFO> |authmgr| MAC=28:cf:da:de:ce:7c,IP=0.0.0.0 User role updated, existing Role=authenticated/none, new Role=authenticated/authenticated, reason=First IP user created
Oct 30 14:06:28 :522006: <INFO> |authmgr| MAC=28:cf:da:de:ce:7c IP=130.253.220.11 User entry added: reason=Sibtye
Oct 30 14:06:28 :522008: <NOTI> |authmgr| User Authentication Successful: username=872548589 MAC=28:cf:da:de:ce:7c IP=130.253.220.11 role=authenticated VLAN=220 AP=AP1-Mcomm SSID=PioneerNet AAA profile=default-dot1x auth method=802.1x auth server=Scabbers
Oct 30 14:06:28 :522050: <INFO> |authmgr| MAC=28:cf:da:de:ce:7c,IP=130.253.220.11 User data downloaded to datapath, new Role=authenticated/73, bw Contract=0/0,reason=New user IP processing
Oct 30 14:06:28 :522038: <INFO> |authmgr| username=872548589 MAC=28:cf:da:de:ce:7c IP=130.253.220.11 Authentication result=Authentication Successful method=radius-accounting server=Scabbers
Oct 30 14:06:28 :522026: <INFO> |authmgr| MAC=28:cf:da:de:ce:7c IP=130.253.220.239 User miss: ingress=0x10b7, VLAN=220
Oct 30 14:07:49 :501102: <NOTI> |stm| Disassoc from sta: 28:cf:da:de:ce:7c: AP 130.253.93.20-d8:c7:c8:b5:75:50-AP1-Mcomm Reason STA has left and is disassocisted
Oct 30 14:07:49 :501065: <DBUG> |stm| Sending STA 28:cf:da:de:ce:7c message to Auth and Mobility Unicast Encr WPA2 8021X AES Multicast Encr Dynamic WPA,WPA2 8021X TKIP VLAN 0xdc, wmm:1, rsn_cap:0
Oct 30 14:07:49 :522036: <INFO> |authmgr| MAC=28:cf:da:de:ce:7c Station DN: BSSID=d8:c7:c8:b5:75:50 ESSID=PioneerNet VLAN=220 AP-name=AP1-Mcomm
Oct 30 14:07:49 :500511: <DBUG> |mobileip| Station 28:cf:da:de:ce:7c, 0.0.0.0: Received disassociation on ESSID: PioneerNet Mobility service Off, HA Discovery on Association Off, Fastroaming Disabled, AP: Name AP1-Mcomm Group DU-N BSSID d8:c7:c8:b5:75:50, phy a, VLAN 220
Oct 30 14:07:49 :500010: <NOTI> |mobileip| Station 28:cf:da:de:ce:7c, 255.255.255.255: Mobility trail, on switch 130.253.21.242, VLAN 220, AP AP1-Mcomm, PioneerNet/d8:c7:c8:b5:75:50/a
Oct 30 14:07:49 :501000: <DBUG> |stm| Station 28:cf:da:de:ce:7c: Clearing state
-----------------------------------
From radius logs:
ATTRIBUTE = StartValue (StopValue)
Acct-Session-Id = 8725485828CFDADECE7C-E579D (8725485828CFDADECE7C-E579D)
User-Name = 872548589 (872548589) Calling-Station-Id = 28CFDADECE7C (28CFDADECE7C)
Aruba-Location-Id = AP16-Nelson (AP16-Nelson)
Timestamp = Tue Oct 30 12:00:26 2012 (Tue Oct 30 12:21:42 2012)
Framed-IP-Address = 130.253.220.239 (130.253.220.83)