Hi David, Not using Aruba or IAS, but in these cases the radius environment is suspect no. 1. Have ther e been recent MS updates for the IAS software and / or server OS?
best regards, Kees. >>> David Ziemba <[email protected]> 10/19/2011 12:31 >>> So, We've been noticing some troubles, and I'm curious if anyone has seen anything like this lately. It'll happen to mobile devices, laptops, just about anything that connects to our enterprise wireless (wpa2-enterprise). We're running Aruba 3.4.4.3 across three controllers (sup2), Bradford 4.1.1.280.P13, and IAS on Windows 2003 server. Once clients associate to an access point (within 2 seconds), it takes anywhere from 15-40 seconds to successfully authenticate. We haven't found anything consistent per device if it takes longer or shorter to pass auth, and even the same device might associate/auth in 5 seconds, and then associate/auth in 40 seconds. On Bradford, the log turned over recently, and in the last 26 hours, there have been clients with 4200 radius requests, and the top 25 clients have between 1200-3500 radius requests. Looking at the debug on the controller, we see 14 eap requests and 14 radius requests for one client, and on the 14th radius request, there is a radius/eap accept/success. This one took about 15 seconds to pass auth: Oct 18 16:06:51 station-up * 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB - - wpa2 aes Oct 18 16:06:51 eap-id-req <- 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB 1 5 Oct 18 16:06:51 eap-id-resp -> 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB 1 12 jsmith Oct 18 16:06:51 rad-req -> 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB 19 165 Oct 18 16:06:53 rad-resp <- 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB/Bradford-PRI 19 77 Oct 18 16:06:53 eap-req <- 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB 2 6 Oct 18 16:06:53 eap-resp -> 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB 2 136 Oct 18 16:06:53 rad-req -> 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB/Bradford-PRI 94 314 Oct 18 16:06:54 rad-resp <- 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB/Bradford-PRI 94 1175 Oct 18 16:06:54 eap-req <- 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB 3 1096 Oct 18 16:06:54 eap-resp -> 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB 3 6 Oct 18 16:06:54 rad-req -> 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB/Bradford-PRI 127 184 Oct 18 16:06:56 rad-resp <- 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB/Bradford-PRI 127 1175 Oct 18 16:06:56 eap-req <- 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB 4 1096 Oct 18 16:06:56 eap-resp -> 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB 4 6 Oct 18 16:06:56 rad-req -> 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB/Bradford-PRI 81 184 Oct 18 16:06:57 rad-resp <- 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB/Bradford-PRI 81 1175 Oct 18 16:06:57 eap-req <- 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB 5 1096 Oct 18 16:06:57 eap-resp -> 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB 5 6 Oct 18 16:06:57 rad-req -> 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB/Bradford-PRI 223 184 Oct 18 16:06:58 rad-resp <- 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB/Bradford-PRI 223 1175 Oct 18 16:06:58 eap-req <- 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB 6 1096 Oct 18 16:06:58 eap-resp -> 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB 6 6 Oct 18 16:06:58 rad-req -> 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB/Bradford-PRI 215 184 Oct 18 16:06:59 rad-resp <- 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB/Bradford-PRI 215 1175 Oct 18 16:06:59 eap-req <- 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB 7 1096 Oct 18 16:06:59 eap-resp -> 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB 7 6 Oct 18 16:06:59 rad-req -> 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB/Bradford-PRI 233 184 Oct 18 16:07:00 rad-resp <- 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB/Bradford-PRI 233 1175 Oct 18 16:07:00 eap-req <- 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB 8 1096 Oct 18 16:07:00 eap-resp -> 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB 8 6 Oct 18 16:07:00 rad-req -> 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB/Bradford-PRI 191 184 Oct 18 16:07:00 rad-resp <- 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB/Bradford-PRI 191 1006 Oct 18 16:07:00 eap-req <- 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB 9 929 Oct 18 16:07:00 eap-resp -> 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB 9 332 Oct 18 16:07:00 rad-req -> 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB/Bradford-PRI 54 512 Oct 18 16:07:01 rad-resp <- 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB/Bradford-PRI 54 124 Oct 18 16:07:01 eap-req <- 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB 10 53 Oct 18 16:07:01 eap-resp -> 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB 10 6 Oct 18 16:07:01 rad-req -> 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB/Bradford-PRI 15 184 Oct 18 16:07:01 rad-resp <- 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB/Bradford-PRI 15 99 Oct 18 16:07:01 eap-req <- 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB 11 28 Oct 18 16:07:01 eap-resp -> 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB 11 35 Oct 18 16:07:01 rad-req -> 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB/Bradford-PRI 197 213 Oct 18 16:07:02 rad-resp <- 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB/Bradford-PRI 197 123 Oct 18 16:07:02 eap-req <- 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB 12 52 Oct 18 16:07:02 eap-resp -> 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB 12 89 Oct 18 16:07:02 rad-req -> 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB/Bradford-PRI 196 267 Oct 18 16:07:03 rad-resp <- 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB/Bradford-PRI 196 145 Oct 18 16:07:03 eap-req <- 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB 13 74 Oct 18 16:07:03 eap-resp -> 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB 13 29 Oct 18 16:07:03 rad-req -> 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB/Bradford-PRI 227 207 Oct 18 16:07:03 rad-resp <- 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB/Bradford-PRI 227 109 Oct 18 16:07:03 eap-req <- 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB 14 38 Oct 18 16:07:03 eap-resp -> 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB 14 38 Oct 18 16:07:03 rad-req -> 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB/Bradford-PRI 194 216 Oct 18 16:07:05 rad-accept <- 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB/Bradford-PRI 194 330 Oct 18 16:07:05 eap-success <- 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB 15 4 Oct 18 16:07:05 assg-vlan-req * 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB 208 200 Oct 18 16:07:05 assg-vlan-resp * 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB - 200 Oct 18 16:07:05 station-data-ready * 04:1e:64:AA:AA:AA 00:00:00:00:00:00 208 200 Oct 18 16:07:05 wpa2-key1 <- 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB - 117 Oct 18 16:07:05 wpa2-key2 -> 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB - 117 Oct 18 16:07:05 wpa2-key3 <- 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB - 175 Oct 18 16:07:05 wpa2-key4 -> 04:1e:64:AA:AA:AA 00:0b:86:BB:BB:BB - 95 On the Bradford server, I see four radius proxy requests during that period I am trying to associate, and then on the IAS server there is terrible logging to boot. On one previous attempt, I did get a message from the IAS server: Access request for user jsmith was discarded. Fully-Qualified-User-Name = NAS-IP-Address = 172.30.65.10 NAS-Identifier = 172.30.65.10 Called-Station-Identifier = 000B86BBBBBB Calling-Station-Identifier = 041E64AAAAAA Client-Friendly-Name = Bradford Client-IP-Address = 172.25.5.23 NAS-Port-Type = Wireless - IEEE 802.11 NAS-Port = 1 Proxy-Policy-Name = Use Windows authentication for all users Authentication-Provider = Windows Authentication-Server = Reason-Code = 3 Reason = The Remote Authentication Dial-In User Service (RADIUS) request was not properly formatted. Has anybody run into this, or have an idea(s) where to dig further? Regards, David ********** Participation and subscription information for this EDUCAUSE Constituent Group discussion list can be found at http://www.educause.edu/groups/. --------------------------------------------------------------------------- Op deze e-mail zijn de volgende voorwaarden van toepassing: The following conditions apply to this e-mail: http://emaildisclaimer.avans.nl --------------------------------------------------------------------------- ********** Participation and subscription information for this EDUCAUSE Constituent Group discussion list can be found at http://www.educause.edu/groups/.
