Wireless Access

Hi,

 

I am configuring AOS8.4 on a test system before we migrate from 6.5. I have an AP running and broadcasting a dot1x SSID. When a client connects to the SSID I can see on the RADIUS server that authentication is successful (ACCEPT), but the client never moves from the initial denyall role into the 802.1x Authentication Default Role.

 

It's more than likely that when I ported the config across from the 6.5 system I have managed to miss something, but tracking down what that is is proving difficult.

 

It would be helpful to know in detail how this should be working - eg at exactly what point should the role change? As soon as the client authenticates? After the client has authenticated *and* got an IP address? (At the moment the client does not get an IP, though the controller appears to be assigning it the right VLAN, and L2 connectivity for that VLAN appears to be fine).

 

# show aaa debug role user mac b4:9c:df:2c:f8:dd

Role Derivation History
=======================
0: l2 role->logon, mac user created
1: l2 role->denyall, Set AAA profile defaults

 

MAC Name Role Age(d:h:m) Auth AP name Essid Phy Remote Profile User Type
------------ ------ ---- ---------- ---- ------- ----- --- ------ ------- ---------
84:10:0d:f3:71:04 denyall 00:00:00 No c8:b5:ad:c6:d3:f0 testing g-HT No test_aaa WIRELESS

 

STA Table
---------
bssid auth assoc aid l-int essid vlan-id tunnel-id
----- ---- ----- --- ----- ----- ------- ---------
c8:b5:ad:ed:3f:00 y y 1 1 testing 1344 0x10010
State Hash Table
----------------
bssid state reason
----- ----- ------
c8:b5:ad:ed:3f:00 auth-assoc 0

 

 

 #show aaa state station 84:10:0d:f3:71:04

Association count = 1, User count = 0

essid: testing, bssid: c8:b5:ad:ed:3f:00 AP name/group: c8:b5:ad:c6:d3:f0/test_aps PHY: g, ingress=0x10010 (tunnel 16)
vlan default: 1344, current: 1344 vlan-how: 0
name: , role: denyall (default:denyall, cached:n/a, dot1x:n/a), role-how: 1, acl:101/0, age: 00:00:00
Authentication: No, status: not started, method: 4[802.1x], protocol: , server:
dot1xctx:1 sap:1
Flags: mba=0
AAA prof: eduroam_aaa, Auth dot1x prof: default, AAA mac prof: , def role: denyall
ncfg flags udr 0, mac 0, dot1x 1, RADIUS interim accounting 1
Born: 1558108472 (Fri May 17 16:54:32 2019
)

 

This line: "role: denyall (default:denyall, cached:n/a, dot1x:n/a)" suggests there's no default dot1x role, but there is defintely one configured... unless this is to do with hierarchy and it being configured in the wrong place...

 

If anyone could help explain this it would be very useful, and some good troubleshooting commands to debug it would be great too.

 

Thanks

 

Are you returning a user-role from the RADIUS server ? or are you trying to do a UDR ?

Sent from Mail for Windows 10

We're not doing anything fancy at all - no attributes returned from server, no derived VLAN, the VLAN is just configured in the VAP

In that case you need to assign the “authenticated” role as the Default 802.1X Role

Sent from Mail for Windows 10

Ok thanks - I'll check this tomorrow in the office

Hello Victor,

 

Thanks for your help so far. Looking at our existing 6.5 config (that I am porting over) we don't use the authenticated role, the aaa profile looks like this:

 

Initial role denyall
MAC Authentication Profile N/A
MAC Authentication Default Role guest
MAC Authentication Server Group default
802.1X Authentication Profile default
802.1X Authentication Default Role eduroam-open_role
802.1X Authentication Server Group lapwing_srvgrp
Download Role from CPPM Disabled
Set username from dhcp option 12 Disabled
L2 Authentication Fail Through Disabled
Multiple Server Accounting Disabled
User idle timeout N/A
Max IPv4 for wireless user 2
RADIUS Accounting Server Group lapwing_srvgrp
RADIUS Roaming Accounting Disabled
RADIUS Interim Accounting Enabled
RADIUS Acct-Session-Id In Access-Request Disabled
XML API server N/A
RFC 3576 server N/A
User derivation rules N/A
Wired to Wireless Roaming Enabled
Reauthenticate wired user on VLAN change Disabled
Device Type Classification Enabled
Enforce DHCP Enabled
PAN Firewall Integration Disabled
Open SSID radius accounting Disabled
Apply ageout mechanism on bridge mode wireless clients Disabled

 

So this is also what I have on the AOS8 set-up. eduroam-open_role exists on the cluster member when I look in the config.

 

It seems like client authentication is working (according to the RADIUS logs on our external server) but that the MD isn't aware of that (if I'm interpreting this correctly), from the 'show aaa state station...' output:

 

Authentication: No, status: not started, method: 4[802.1x], protocol: , server:
dot1xctx:1 sap:1

 

Would you agree? Or is this a red herring? The client doesn't appear on VLAN 1344 although the VLAN *is* shown in the STA table (would it show in this table before a client had authenticated?).

 

On our existing 6.5 system my client device looks like this (show aaa state station...):

 

...

Authentication: Yes, status: started, method: 4[802.1x]...

...

You should get the output of "show auth-tracebuf mac <client mac address" to see the client/ radius server interaction.

Thanks - useful command. On the 6.5 system the output is:

 

May 20 10:51:46 station-up * 84:10:0d:f3:71:04 c8:b5:ad:5e:02:c1 - - wpa2 aes
May 20 10:51:46 wpa2-key1 <- 84:10:0d:f3:71:04 c8:b5:ad:5e:02:c1 - 117
May 20 10:51:47 wpa2-key2 -> 84:10:0d:f3:71:04 c8:b5:ad:5e:02:c1 - 135
May 20 10:51:47 wpa2-key3 <- 84:10:0d:f3:71:04 c8:b5:ad:5e:02:c1 - 159
May 20 10:51:47 wpa2-key4 -> 84:10:0d:f3:71:04 c8:b5:ad:5e:02:c1 - 95

 

On AOS 8 I get a whole bunch of output, some eap-req/resp:

 

May 20 09:58:45 eap-resp -> 84:10:0d:f3:71:04 c8:b5:ad:ed:3f:00 2 110
May 20 09:58:45 rad-req -> 84:10:0d:f3:71:04 c8:b5:ad:ed:3f:00/radius0-lapwing_radius 20 319 131.x.x.x
May 20 09:58:45 rad-resp <- 84:10:0d:f3:71:04 c8:b5:ad:ed:3f:00/radius0-lapwing_radius 20 1068
May 20 09:58:45 eap-req <- 84:10:0d:f3:71:04 c8:b5:ad:ed:3f:00 3 1004
May 20 09:58:45 eap-resp -> 84:10:0d:f3:71:04 c8:b5:ad:ed:3f:00 3 6
May 20 09:58:45 rad-req -> 84:10:0d:f3:71:04 c8:b5:ad:ed:3f:00/radius0-lapwing_radius 21 215 131.x.x.x
May 20 09:58:45 rad-resp <- 84:10:0d:f3:71:04 c8:b5:ad:ed:3f:00/radius0-lapwing_radius 21 1064
May 20 09:58:45 eap-req <- 84:10:0d:f3:71:04 c8:b5:ad:ed:3f:00 4 1000
May 20 09:58:45 eap-resp -> 84:10:0d:f3:71:04 c8:b5:ad:ed:3f:00 4 6

 

then some dot1x-timeouts:

 

May 20 09:58:50 dot1x-timeout * 84:10:0d:f3:71:04 c8:b5:ad:ed:3f:00 12 3 server timeout
May 20 09:58:50 dot1x-timeout * 84:10:0d:f3:71:04 c8:b5:ad:ed:3f:00 13 2 station timeout
May 20 09:58:50 eap-id-req <- 84:10:0d:f3:71:04 c8:b5:ad:ed:3f:00 13 5
May 20 09:58:55 eap-id-req <- 84:10:0d:f3:71:04 c8:b5:ad:ed:3f:00 13 5
May 20 09:59:00 dot1x-timeout * 84:10:0d:f3:71:04 c8:b5:ad:ed:3f:00 13 1 station timeout
May 20 09:59:00 eap-id-req <- 84:10:0d:f3:71:04 c8:b5:ad:ed:3f:00 14 5
May 20 09:59:05 eap-id-req <- 84:10:0d:f3:71:04 c8:b5:ad:ed:3f:00 14 5
May 20 09:59:10 eap-id-req <- 84:10:0d:f3:71:04 c8:b5:ad:ed:3f:00 14 5
May 20 09:59:15 dot1x-timeout * 84:10:0d:f3:71:04 c8:b5:ad:ed:3f:00 14 1 station timeout
May 20 09:59:15 eap-id-req <- 84:10:0d:f3:71:04 c8:b5:ad:ed:3f:00 15 5
May 20 09:59:20 eap-id-req <- 84:10:0d:f3:71:04 c8:b5:ad:ed:3f:00 15 5
May 20 09:59:25 eap-id-req <- 84:10:0d:f3:71:04 c8:b5:ad:ed:3f:00 15 5
May 20 09:59:30 dot1x-timeout * 84:10:0d:f3:71:04 c8:b5:ad:ed:3f:00 15 1 station timeout
May 20 09:59:30 eap-id-req <- 84:10:0d:f3:71:04 c8:b5:ad:ed:3f:00 16 5
May 20 09:59:32 eap-start -> 84:10:0d:f3:71:04 c8:b5:ad:ed:3f:00 - -
May 20 09:59:32 eap-id-req <- 84:10:0d:f3:71:04 c8:b5:ad:ed:3f:00 16 5
May 20 09:59:32 eap-id-resp -> 84:10:0d:f3:71:04 c8:b5:ad:ed:3f:00 16 15 @x.x.uk
May 20 09:59:32 rad-req -> 84:10:0d:f3:71:04 c8:b5:ad:ed:3f:00 31 206 131.x.x.x
May 20 09:59:32 eap-id-resp -> 84:10:0d:f3:71:04 c8:b5:ad:ed:3f:00 16 15 @x.x.uk
May 20 09:59:32 rad-resp <- 84:10:0d:f3:71:04 c8:b5:ad:ed:3f:00/radius0-lapwing_radius 31 64
May 20 09:59:32 eap-req <- 84:10:0d:f3:71:04 c8:b5:ad:ed:3f:00 17 6
May 20 09:59:32 eap-resp -> 84:10:0d:f3:71:04 c8:b5:ad:ed:3f:00 17 142

 

I'm not sure what this is telling me, other than timeout doesn't sound good!

 

show aaa authentication server rad stat gives (sorry, probably impossible to read in this format):

 

RADIUS Server Statistics
------------------------
Server Acct Rq Raw Rq PAP Rq CHAP Rq MSCHAP Rq MSCHAPv2 Rq Mismatch Rsp Bad Auth Acc Rej Acct Rsp Chal Ukn Rsp Tmout AvgRspTm Tot Rq Tot Rsp Rd Err Outstanding Auths Outstanding Requests Acc-RTTS Rq Acc-RTTS Rsp ExpAuthTm Uptime SEQ
------ ------- ------ ------ ------- --------- ----------- ------------ -------- --- --- -------- ---- ------- ----- -------- ------ ------- ------ ----------------- -------------------- ----------- ------------ --------- ------ ---
NMG0-RADIUS 0 0 1134 0 0 0 0 0 0 1134 0 0 0 0 1001 1134 1134 0 0 0 0 0 1001 3:23:7 255/255
NMG1-RADIUS 0 0 1151 0 0 0 0 0 17 1134 0 0 0 0 986 1151 1151 0 0 0 0 0 813 3:23:7 255/255
radius0-lapwing_radius 0 2210 0 0 0 1 0 0 179 1 0 1829 0 811 9 2211 2009 0 1 0 0 0 1002 3:18:39 255/255
radius1-lapwing_radius 0 2524 0 0 0 1 0 0 202 1 0 2134 0 752 8 2525 2337 0 2 0 0 0 1001 3:18:37 255/255

 

The servers dealing with clients are radius0 and radius1.

 

 

The RADIUS Server Stats output is a little hard to decipher. I'd check why the RADIUS is timing out in the first place as this will affect all clients.

 

May 20 09:58:50 dot1x-timeout * 84:10:0d:f3:71:04 c8:b5:ad:ed:3f:00 12 3 server timeout

Do you see any log entries (show log all | include timeout) for the server in question. What do you see on the RADIUS side of the conversation? 

Hello, thanks for responding so quickly.

 

The RADIUS end looks fine - the authentication completes and it sends an ACCEPT.

 

There are quite a lot of entries in the log that include 'timeout', but it's just these three messages repeated:

 

May 20 12:20:19 authmgr[3711]: <522050> <5129> <INFO> |authmgr| MAC=84:10:0d:f3:71:04,IP=N/A User data downloaded to datapath, new Role=denyall/101, bw Contract=0/0, reason=layer 2 event driven download, idle-timeout=300
May 20 12:20:19 authmgr[3711]: <522246> <5129> <DBUG> |authmgr| Idle timeout should be driven by STM for MAC 84:10:0d:f3:71:04.
May 20 12:21:29 authmgr[3711]: <522234> <5129> <DBUG> |authmgr| Setting idle timer for user 84:10:0d:f3:71:04 to 300 seconds (idle timeout: 300 ageout: 0).

 

Again - sorry this output is grim to read, these are the logs (well, a section of) for my client MAC (I can send this as an attachment if easier):

 

May 20 13:41:05 authmgr[3711]: <522004> <5129> <DBUG> |authmgr| 13:41:05.136222 auth_send_supplicant_up_to_dot1x use mac 84:10:0d:f3:71:04 bssid c8:b5:ad:ed:3f:00 essid eduroam-testing msg mac 84:10:0d:f3:71:04 bssid c8:b5:ad:ed:3f:00 essid eduroam-testing
May 20 13:41:05 authmgr[3711]: <522004> <5129> <DBUG> |authmgr| ac_active_add_mac_to_bucket: station 84:10:0d:f3:71:04 in essid eduroam-testing (mac_user 0x2094aac) being added to bucket-map
May 20 13:41:05 authmgr[3711]: <522004> <5129> <DBUG> |authmgr| auth_cluster_add_active_mac: essid eduroam-testing b_num 134 mu_mac 84:10:0d:f3:71:04 macuser 0x2094aac
May 20 13:41:05 authmgr[3711]: <522004> <5129> <DBUG> |authmgr| auth_cluster_is_active_uac_or_disconnected: essid eduroam-testing b_num 134 mac 84:10:0d:f3:71:04
May 20 13:41:05 authmgr[3711]: <522004> <5129> <DBUG> |authmgr| auth_gsm_publish_channels: mac 84:10:0d:f3:71:04 publish_list 3 user VALID macuser VALID ipuser NULL
May 20 13:41:05 authmgr[3711]: <522004> <5129> <DBUG> |authmgr| handle_sta_up_dn: mac 84:10:0d:f3:71:04 macuser 00x2094aac essid eduroam-testing user->essid eduroam-testing repready 0 repkey -1
May 20 13:41:05 authmgr[3711]: <522035> <5129> <INFO> |authmgr| MAC=84:10:0d:f3:71:04 Station UP: BSSID=c8:b5:ad:ed:3f:00 ESSID=eduroam-testing VLAN=1344 AP-name=c8:b5:ad:c6:d3:f0 u-encr-alg=0x40 m-encr-alg=0x40 at 13:41:05.136222
May 20 13:41:05 authmgr[3711]: <522049> <5129> <INFO> |authmgr| MAC=84:10:0d:f3:71:04,IP=N/A User role updated, existing Role=logon/none, new Role=denyall/none, reason=Set AAA profile defaults
May 20 13:41:05 authmgr[3711]: <522050> <5129> <INFO> |authmgr| MAC=84:10:0d:f3:71:04,IP=N/A User data downloaded to datapath, new Role=denyall/101, bw Contract=0/0, reason=layer 2 event driven download, idle-timeout=300
May 20 13:41:05 authmgr[3711]: <522077> <5129> <DBUG> |authmgr| MAC=84:10:0d:f3:71:04 ingress 0x10010 (tunnel 16), u_encr 0x40, m_encr 0x40, slotport 0x2100 , type: local, FW mode: 0, AP IP: 172.30.225.7 mdie 0 ft_complete 0
May 20 13:41:05 authmgr[3711]: <522127> <5129> <DBUG> |authmgr| {L2} Update role from logon to denyall for IP=N/A, MAC=84:10:0d:f3:71:04.
May 20 13:41:05 authmgr[3711]: <522142> <5129> <DBUG> |authmgr| Setting default role to denyall for user 84:10:0d:f3:71:04".
May 20 13:41:05 authmgr[3711]: <522158> <5129> <DBUG> |authmgr| Role Derivation for user N/A-84:10:0d:f3:71:04- N/A Set AAA profile defaults.
May 20 13:41:05 authmgr[3711]: <522242> <5129> <DBUG> |authmgr| MAC=84:10:0d:f3:71:04 Station Created Update MMS: BSSID=c8:b5:ad:ed:3f:00 ESSID=eduroam-testing VLAN=1344 AP-name=c8:b5:ad:c6:d3:f0
May 20 13:41:05 authmgr[3711]: <522246> <5129> <DBUG> |authmgr| Idle timeout should be driven by STM for MAC 84:10:0d:f3:71:04.
May 20 13:41:05 authmgr[3711]: <522254> <5129> <DBUG> |authmgr| VDR - mac 84:10:0d:f3:71:04 rolename denyall fwdmode 0 derivation_type Initial Role Contained vp not present.
May 20 13:41:05 authmgr[3711]: <522255> <5129> <DBUG> |authmgr| "VDR - set vlan in user for 84:10:0d:f3:71:04 vlan 1344 fwdmode 0 derivation_type Current VLAN updated.
May 20 13:41:05 authmgr[3711]: <522255> <5129> <DBUG> |authmgr| "VDR - set vlan in user for 84:10:0d:f3:71:04 vlan 1344 fwdmode 0 derivation_type Default VLAN.
May 20 13:41:05 authmgr[3711]: <522258> <5129> <DBUG> |authmgr| "VDR - Add to history of user user 84:10:0d:f3:71:04 vlan 0 derivation_type Reset Role Based VLANs index 3.
May 20 13:41:05 authmgr[3711]: <522258> <5129> <DBUG> |authmgr| "VDR - Add to history of user user 84:10:0d:f3:71:04 vlan 0 derivation_type Reset VLANs for Station up index 0.
May 20 13:41:05 authmgr[3711]: <522258> <5129> <DBUG> |authmgr| "VDR - Add to history of user user 84:10:0d:f3:71:04 vlan 1344 derivation_type Current VLAN updated index 2.
May 20 13:41:05 authmgr[3711]: <522258> <5129> <DBUG> |authmgr| "VDR - Add to history of user user 84:10:0d:f3:71:04 vlan 1344 derivation_type Default VLAN index 1.
May 20 13:41:05 authmgr[3711]: <522264> <5129> <DBUG> |authmgr| "MAC:84:10:0d:f3:71:04: Allocating UUID: 001a1e0580900000001f0236
May 20 13:41:05 authmgr[3711]: <522287> <5129> <DBUG> |authmgr| Auth GSM : MAC_USER publish for mac 84:10:0d:f3:71:04 bssid c8:b5:ad:ed:3f:00 vlan 1344 type 1 data-ready 0 HA-IP n.a
May 20 13:41:05 authmgr[3711]: <522295> <5129> <DBUG> |authmgr| Auth GSM : USER_STA event 0 for user 84:10:0d:f3:71:04
May 20 13:41:05 authmgr[3711]: <522301> <5129> <DBUG> |authmgr| Auth GSM : USER publish for uuid 001a1e0580900000001f0236 mac 84:10:0d:f3:71:04 name role denyall devtype wired 0 authtype 0 subtype 0 encrypt-type 10 conn-port 8448 fwd-mode 0 roam 0 repkey -1
May 20 13:41:05 authmgr[3711]: <522308> <5129> <DBUG> |authmgr| Device Type index derivation for 84:10:0d:f3:71:04 : dhcp (0,0,0) oui (0,0) ua (0,0,0) derived (0):
May 20 13:41:05 authmgr[3711]: <522344> <5129> <DBUG> |authmgr| handle_sta_up_dn (3854): rtts user=84:10:0d:f3:71:04 enabled=0 initial tput=50880
May 20 13:41:05 authmgr[3711]: <524124> <5129> <DBUG> |authmgr| auth_dot1x_supplicant_up(): MAC:84:10:0d:f3:71:04, pmkid_present:False, pmkid:N/A
May 20 13:41:05 authmgr[3711]: <524141> <5129> <DBUG> |authmgr| clr_pmkcache_ft():832: MAC:84:10:0d:f3:71:04 BSS:c8:b5:ad:ed:3f:00
May 20 13:41:05 dot1x-proc:1[4380]: <522038> <4380> <NOTI> |dot1x-proc:1| username=@x.x.uk MAC=84:10:0d:f3:71:04 IP=0.0.0.0 Result=Successful method=802.1x server=radius1-lapwing_radius
May 20 13:41:05 dot1x-proc:1[4380]: <526124> <4380> <DBUG> |dot1x-proc:1| dot1x_supplicant_up(): MAC:84:10:0d:f3:71:04, pmkid_present:False, pmkid:N/A
May 20 13:41:05 stm[3152]: <501093> <NOTI> |AP c8:b5:ad:c6:d3:f0@x.x.x.x stm| Auth success: 84:10:0d:f3:71:04: AP x.x.x.x-c8:b5:ad:ed:3f:00-c8:b5:ad:c6:d3:f0
May 20 13:41:05 stm[3152]: <501095> <NOTI> |AP c8:b5:ad:c6:d3:f0@x.x.x.x stm| Assoc request @ 13:41:05.560666: 84:10:0d:f3:71:04 (SN 0): AP x.x.x.x-c8:b5:ad:ed:3f:00-c8:b5:ad:c6:d3:f0
May 20 13:41:05 stm[3152]: <501100> <NOTI> |AP c8:b5:ad:c6:d3:f0@x.x.x.x stm| Assoc success @ 13:41:05.567664: 84:10:0d:f3:71:04: AP x.x.x.x-c8:b5:ad:ed:3f:00-c8:b5:ad:c6:d3:f0
May 20 13:41:05 stm[3737]: <501065> <3737> <DBUG> |stm| a2c_sm_process_stalist: client (84:10:0d:f3:71:04) is 11k-enabled
May 20 13:41:05 stm[3737]: <501100> <3737> <NOTI> |stm| Assoc success @ 13:41:05.570406: 84:10:0d:f3:71:04: AP 172.30.225.7-c8:b5:ad:ed:3f:00-c8:b5:ad:c6:d3:f0
May 20 13:42:15 authmgr[3711]: <522004> <5129> <DBUG> |authmgr| 84:10:0d:f3:71:04: station datapath entry deleted
May 20 13:42:15 authmgr[3711]: <522004> <5129> <DBUG> |authmgr| ac_active_remove_mac_from_bucket: station 84:10:0d:f3:71:04 in essid eduroam-testing (mh_entry found True addr 0x2094aac) removed in bucket-map 134
May 20 13:42:15 authmgr[3711]: <522004> <5129> <DBUG> |authmgr| auth_cluster_del_active_mac essid eduroam-testing b_num 134 mu_mac 84:10:0d:f3:71:04 mac_user 0x2094aac cluster_enabled=1
May 20 13:42:15 authmgr[3711]: <522004> <5129> <DBUG> |authmgr| mac_station_free: Sta->essid eduroam-testing mu_mac 84:10:0d:f3:71:04 macuser 0x0x2094aac
May 20 13:42:15 authmgr[3711]: <522036> <5129> <INFO> |authmgr| MAC=84:10:0d:f3:71:04 Station DN: BSSID=c8:b5:ad:ed:3f:00 ESSID=eduroam-testing VLAN=1344 AP-name=c8:b5:ad:c6:d3:f0 reason=3 at 13:42:15.200059
May 20 13:42:15 authmgr[3711]: <522152> <5129> <DBUG> |authmgr| station free: bssid=c8:b5:ad:ed:3f:00, mac=84:10:0d:f3:71:04.
May 20 13:42:15 authmgr[3711]: <522234> <5129> <DBUG> |authmgr| Setting idle timer for user 84:10:0d:f3:71:04 to 300 seconds (idle timeout: 300 ageout: 0).
May 20 13:42:15 authmgr[3711]: <522244> <5129> <DBUG> |authmgr| MAC=84:10:0d:f3:71:04 Station Deleted Update MMS
May 20 13:42:15 authmgr[3711]: <522290> <5129> <DBUG> |authmgr| Auth GSM : MAC_USER delete for mac 84:10:0d:f3:71:04
May 20 13:42:15 authmgr[3711]: <522296> <5129> <DBUG> |authmgr| Auth GSM : USER_STA delete event for user 84:10:0d:f3:71:04 age 0 deauth_reason 3
May 20 13:42:15 authmgr[3711]: <522303> <5129> <DBUG> |authmgr| Auth GSM : USER delete for mac 84:10:0d:f3:71:04 uuid 001a1e0580900000001f0236
May 20 13:42:15 stm[3152]: <501000> <DBUG> |AP c8:b5:ad:c6:d3:f0@172.30.225.7 stm| Station 84:10:0d:f3:71:04: Clearing state
May 20 13:42:15 stm[3152]: <501105> <NOTI> |AP c8:b5:ad:c6:d3:f0@x.x.x.x stm| Deauth from sta: 84:10:0d:f3:71:04: AP x.x.x.x-c8:b5:ad:ed:3f:00-c8:b5:ad:c6:d3:f0 Reason STA has left and is deauthenticated
May 20 13:42:15 stm[3737]: <501000> <3737> <DBUG> |stm| Station 84:10:0d:f3:71:04: Clearing state

 

Does the following section suggest it does know the dot1x auth has been successful?:

 

Result=Successful method=802.1x server=radius1-lapwing_radius
May 20 13:41:05 dot1x-proc:1[4380]: <526124> <4380> <DBUG> |dot1x-proc:1| dot1x_supplicant_up(): MAC:84:10:0d:f3:71:04, pmkid_present:False, pmkid:N/A
May 20 13:41:05 stm[3152]: <501093> <NOTI> |AP c8:b5:ad:c6:d3:f0@x.x.x.x stm| Auth success: 84:10:0d:f3:71:04: AP x.x.x.x-c8:b5:ad:ed:3f:00-c8:b5:ad:c6:d3:f0

Are you getting prompted to accept the RADIUS certificate ?

Sent from Mail for Windows 10

Double check your AAA Profile within 8.4. It is picking up the AAA Profile Defaults which is assigning denyall.

 

May 20 13:41:05 authmgr[3711]: <522049> <5129> <INFO> |authmgr| MAC=84:10:0d:f3:71:04,IP=N/A User role updated, existing Role=logon/none, new Role=denyall/none, reason=Set AAA profile defaults
--- TRUNCATED ---
May 20 13:41:05 authmgr[3711]: <522142> <5129> <DBUG> |authmgr| Setting default role to denyall for user 84:10:0d:f3:71:04".
May 20 13:41:05 authmgr[3711]: <522158> <5129> <DBUG> |authmgr| Role Derivation for user N/A-84:10:0d:f3:71:04- N/A Set AAA profile defaults.

Are you certain the configuration copied across successfully? Your 6.5 configuration does have denyall for the Initial Role and correct role for dot1x.

 

You do successfully authenticate :

 

May 20 13:41:05 dot1x-proc:1[4380]: <522038> <4380> <NOTI> |dot1x-proc:1| username=@x.x.uk MAC=84:10:0d:f3:71:04 IP=0.0.0.0 Result=Successful method=802.1x server=radius1-lapwing_radius
May 20 13:41:05 dot1x-proc:1[4380]: <526124> <4380> <DBUG> |dot1x-proc:1| dot1x_supplicant_up(): MAC:84:10:0d:f3:71:04, pmkid_present:False, pmkid:N/A

Thanks - useful to confirm that authentication is successful. There's no profile called defaults in the config at all (that I can find). Though actually if I look on the 6.5 system I see this:

 

May 20 16:04:31 authmgr[4122]: <522049> <5247> <INFO> |authmgr| MAC=84:10:0d:f3:71:04,IP=N/A User role updated, existing Role=logon/none, new Role=denyall/none, reason=Set AAA profile defaults
May 20 16:04:31 authmgr[4122]: <522246> <5247> <DBUG> |authmgr| Idle timeout should be driven by STM for MAC 84:10:0d:f3:71:04.
May 20 16:04:31 authmgr[4122]: <524141> <5247> <DBUG> |authmgr| clr_pmkcache_ft():1016: MAC:84:10:0d:f3:71:04 BSS:c8:b5:ad:5e:02:c1
May 20 16:04:31 authmgr[4122]: <522287> <5247> <DBUG> |authmgr| Auth GSM : MAC_USER publish for mac 84:10:0d:f3:71:04 bssid c8:b5:ad:5e:02:c1 vlan 1344 type 1 data-ready 0
May 20 16:04:31 authmgr[4122]: <522254> <5247> <DBUG> |authmgr| VDR - mac 84:10:0d:f3:71:04 rolename denyall fwdmode 0 derivation_type Initial Role Contained vp not present.
May 20 16:04:31 authmgr[4122]: <522258> <5247> <DBUG> |authmgr| "VDR - Add to history of user user 84:10:0d:f3:71:04 vlan 0 derivation_type Reset Role Based VLANs index 3.
May 20 16:04:31 authmgr[4122]: <522320> <5247> <DBUG> |authmgr| handle_sta_up_dn (3007): rtts user=84:10:0d:f3:71:04 enabled=0 initial tput=48960
May 20 16:04:31 authmgr[4122]: <524124> <5247> <DBUG> |authmgr| dot1x_supplicant_up(): MAC:84:10:0d:f3:71:04, pmkid_present:True, pmkid:bc 2d 99 86 44 6b 58 2b 80 af b2 f0 88 b9 c4 12
May 20 16:04:31 authmgr[4122]: <522142> <5247> <DBUG> |authmgr| Setting cached role to eduroam-open_role for user 84:10:0d:f3:71:04".
May 20 16:04:31 authmgr[4122]: <522254> <5247> <DBUG> |authmgr| VDR - mac 84:10:0d:f3:71:04 rolename NULL fwdmode 0 derivation_type VLAN from pmk-cache vp not present.
May 20 16:04:31 authmgr[4122]: <522044> <5247> <INFO> |authmgr| MAC=84:10:0d:f3:71:04 Station authenticate(start): method=802.1x, role=denyall/eduroam-open_role//denyall, VLAN=1344/1344, Derivation=1/0, Value Pair=0, flags=0x8
May 20 16:04:31 authmgr[4122]: <522158> <5247> <DBUG> |authmgr| Role Derivation for user N/A-84:10:0d:f3:71:04-xxxxx@x.x.uk N/A station Authenticated with auth type: Unknown auth type.
May 20 16:04:31 authmgr[4122]: <522127> <5247> <DBUG> |authmgr| {L2} Update role from denyall to eduroam-open_role for IP=N/A, MAC=84:10:0d:f3:71:04.
May 20 16:04:31 authmgr[4122]: <522049> <5247> <INFO> |authmgr| MAC=84:10:0d:f3:71:04,IP=N/A User role updated, existing Role=denyall/none, new Role=eduroam-open_role/none, reason=station Authenticated with auth type: 802.1x
May 20 16:04:31 authmgr[4122]: <522050> <5247> <INFO> |authmgr| MAC=84:10:0d:f3:71:04,IP=N/A User data downloaded to datapath, new Role=eduroam-open_role/98, bw Contract=0/0, reason=Download driven by user role setting, idle-timeout=300
May 20 16:04:31 authmgr[4122]: <522301> <5247> <DBUG> |authmgr| Auth GSM : USER publish for uuid 0x38b07f03e9a81ab3 mac 84:10:0d:f3:71:04 name xxxxx@x.x.uk role eduroam-open_role devtype wired 0 authtype 4 subtype 0 encrypt-type 10 conn-port 8448 fwd-mode 0
May 20 16:04:31 authmgr[4122]: <522259> <5247> <DBUG> |authmgr| "VDR - Do Role Based VLAN Derivation user 84:10:0d:f3:71:04 role eduroam-open_role rolehow ROLE_DERIVATION_DOT1X.
May 20 16:04:31 authmgr[4122]: <522254> <5247> <DBUG> |authmgr| VDR - mac 84:10:0d:f3:71:04 rolename eduroam-open_role fwdmode 0 derivation_type User Dot1x Role Contained vp not present.
May 20 16:04:31 authmgr[4122]: <522258> <5247> <DBUG> |authmgr| "VDR - Add to history of user user 84:10:0d:f3:71:04 vlan 0 derivation_type Reset Role Based VLANs index 4.
May 20 16:04:31 authmgr[4122]: <522255> <5247> <DBUG> |authmgr| "VDR - set vlan in user for 84:10:0d:f3:71:04 vlan 1344 fwdmode 0 derivation_type Current VLAN updated.
May 20 16:04:31 authmgr[4122]: <522258> <5247> <DBUG> |authmgr| "VDR - Add to history of user user 84:10:0d:f3:71:04 vlan 1344 derivation_type Current VLAN updated index 5.
May 20 16:04:31 authmgr[4122]: <522260> <5247> <DBUG> |authmgr| "VDR - Cur VLAN updated 84:10:0d:f3:71:04 mob 0 inform 1 remote 0 wired 0 defvlan 1344 exportedvlan 0 curvlan 1344.
May 20 16:04:31 authmgr[4122]: <522029> <5247> <INFO> |authmgr| MAC=84:10:0d:f3:71:04 Station authenticate: method=802.1x, role=eduroam-open_role/eduroam-open_role//denyall, VLAN=1344/1344, Derivation=7/1, Value Pair=0
May 20 16:04:31 authmgr[4122]: <522301> <5247> <DBUG> |authmgr| Auth GSM : USER publish for uuid 0x38b07f03e9a81ab3 mac 84:10:0d:f3:71:04 name xxxxx@x.x.uk role eduroam-open_role devtype wired 0 authtype 4 subtype 0 encrypt-type 10 conn-port 8448 fwd-mode 0
May 20 16:04:31 authmgr[4122]: <522308> <5247> <DBUG> |authmgr| Device Type index derivation for 84:10:0d:f3:71:04 : dhcp (0,0,0) oui (0,0) ua (46,1,1) derived Android(1)
May 20 16:04:31 authmgr[4122]: <522299> <5247> <DBUG> |authmgr| Auth GSM : DEV_ID_CACHE publish for mac 84:10:0d:f3:71:04 dev-id Android index 1
May 20 16:04:31 authmgr[4122]: <522242> <5247> <DBUG> |authmgr| MAC=84:10:0d:f3:71:04 Station Created Update MMS: BSSID=c8:b5:ad:5e:02:c1 ESSID=eduroam VLAN=1344 AP-name=c8:b5:ad:cd:e0:2c

 

This successful auth also has "reason=Set AAA profile defaults", so perhaps it's not as relevant as initially thought?  :(

 

This is my first attempt at setting up AOS8 & porting the config and there are a couple of things I'm not happy with, so I have decided to blank everything and start again - a useful learning experience! I'll do that and see if afterwards this all magically works(!). Thanks for looking at it.

 

On a possibly unrelated note - should there be an ARM profile configured on the 11a/g radio profiles? I'm not sure whether this is a result of the ported config but we currently *do* have an ARM profile set, but I think in the new AOS8 world this  should all be done by ClientMatch? Is that right?

 

 

Not so much a profile called "default" but the default role for the AAA
Profile e.g denyall. Can you run "#show configuration effective" from the
Group level (e.g cd /md/YOUR_GROUP) then provide the full output of the AAA
Profile in question.

ARM is legacy now and should be used by AirMatch if using a MM.

Here is the AAA profile as seen from the MM:

 

aaa profile "eduroam_aaa"
initial-role "denyall"
authentication-dot1x "default"
dot1x-default-role "eduroam-open_role"
dot1x-server-group "lapwing_srvgrp"
radius-accounting "lapwing_srvgrp"
radius-interim-accounting

 

And logged into the MD, this is show aaa profile "eduroam_aaa":

 

AAA Profile "eduroam_aaa"
-------------------------
Parameter Value
--------- -----
Initial role denyall
MAC Authentication Profile N/A
MAC Authentication Default Role guest
MAC Authentication Server Group default
802.1X Authentication Profile default
802.1X Authentication Default Role eduroam-open_role
802.1X Authentication Server Group lapwing_srvgrp
Download Role from CPPM Disabled
Set username from dhcp option 12 Disabled
L2 Authentication Fail Through Disabled
Multiple Server Accounting Disabled
User idle timeout N/A
Max IPv4 for wireless user 2
RADIUS Accounting Server Group lapwing_srvgrp
RADIUS Roaming Accounting Disabled
RADIUS Interim Accounting Enabled
RADIUS Acct-Session-Id In Access-Request Disabled
XML API server N/A
RFC 3576 server N/A
User derivation rules N/A
Wired to Wireless Roaming Enabled
Reauthenticate wired user on VLAN change Disabled
Device Type Classification Enabled
Enforce DHCP Disabled
PAN Firewall Integration Disabled
Open SSID radius accounting Disabled
Apply ageout mechanism on bridge mode wireless clients Disabled

 

We're still having issues with this. The RADIUS server shows the authentication completing, but the role never changes. On our 6.5 system we see this:

 

May 28 11:40:00 authmgr[4122]: <524158> <4122> <DBUG> |authmgr| rx_dot1x_radius (1709): rtts user=84:10:0d:f3:71:04 RADIUS ACCEPT result=-1 discard=0 reest=0 keepalive=0 bkoff=0 earlylift=0

 

But we never see that on the 8.4 system

 

We briefly tested this using our CPPM server (currently just a test server) configured as the RADIUS server and it worked fine. Is there anything that AOS8 might expect to be different by way of how our RADIUS server should respond to it? It seems like there is something that we need to do differently at the RADIUS end of things perhaps?

How have things been going with your issue? Any fresh logs from the commands you ran previously. I was trying to make sense of each piece but saw a switch from the "testing" ssid - so just getting a fresh perspective as of today.

Hi,

 

The logs I posted a few messages ago were from our 6.5 system which is all working fine (hence 'eduroam' not 'eduroam-testing'), I was just using them as a comparison.

 

We don't have this particular dot1x SSID working on the AOS 8 system yet. As we are at a bit of an impasse we have moved onto other things (getting used to clustering, testing AP failover, etc), so there is nothing new on this problem at the moment. We have an Aruba engineer coming to have a general look at how things are going (hopefully on Monday) so we will go through this with him.

I don't think I can help you directly with your problem, but I can provide you with some resources that may help you understand and troubleshoot it. A couple of years ago I created a role derivation flowchart for an ArubaOS 6 book that I wrote. From the book I have made 15 images, including the flowchart available for anyone to download because i thought they should be shared. If you go to www.westcott-consulting.com and click on download you can get them. You will be signing up for my mailing list (which I rarely use) but you can remove yourself from the list. After you fill out the form, you will receive an email (it may go to junk) that will download the files.

 

When I created this flowchart, I used the following command to track and validate what I was doing. The output shows as the role is assigned and reassigned during the login/connection process. The following is a sample output.

 

I hope this helps,

 

 

Thanks for this David - I will definitely do that.

Just to follow up on this - with the help of an Aruba techie we found that that when we transferred our config from our FreeRADIUS2 server onto our new FreeRADIUS3 server (some time ago), we accidentally also ported a fix for a bug which was fixed in FreeRADIUS3. This resulted in the username being added twice to the ACCEPT packet. I guess ArubaOS 6.x doesn't object to this, but 8.x clearly does. Once we removed the 'fix' all was happy.

 

The clue was in the logs where we could see the RADIUS packet being dropped. To see this we had turned on:

 

- logging security process dot1x-proc level debug

 

(I think we also had a couple of other 'logging security...' settings, I'm afraid I don't have a record of those)

 

Thanks to those on Airheads who helped