wpa supplicant roaming issues

[Fabio Coatti]

Hi all,
I'm using wpa_supplicant in a corporate environment where the wifi is
provided byt several AP sharing the same SSID and with wpa2/enteprise
auth mode.

If the client uses only one AP, the connection is stable and free from
problems. If the client is moved from one ap to another or if the
client itself is in an area where two similar strenght ap are present,
basically the newtork connection becomes unusable because wpa tries to
roam and fails.

So far I have got some logs, maybe not much informative but maybe
somewhat useful:

wlan0: authenticate with **MAC**:b1 (try 1)
wlan0: authenticated
wlan0: associate with **MAC**:b1 (try 1)
wlan0: RX ReassocResp from **MAC**:b1 (capab=0x1 status=17 aid=0)
wlan0: **MAC**:b1 denied association (code=17)
wlan0: deauthenticating from **MAC**:b1 by local choice (reason=3)

The interesting part here is that on the wificontroller there's no
signs of overlcrowding (status 17 IIRC means that the AP refuses new
clients) and all windws/mac clients on the same desk are working just
fine.

digging in other logs, I'm seeing this:

Mar  6 16:13:43 calvin NetworkManager[5042]: <info> Activation (wlan0)
starting connection 'myssid'
Mar  6 16:13:43 calvin NetworkManager[5042]: <info> (wlan0): device
state change: disconnected -> prepare (reason 'none') [30 40 0]
Mar  6 16:13:43 calvin NetworkManager[5042]: <info> Activation (wlan0)
Stage 1 of 5 (Device Prepare) scheduled...
Mar  6 16:13:43 calvin NetworkManager[5042]: <info> Activation (wlan0)
Stage 1 of 5 (Device Prepare) started...
Mar  6 16:13:43 calvin NetworkManager[5042]: <info> Activation (wlan0)
Stage 2 of 5 (Device Configure) scheduled...
Mar  6 16:13:43 calvin NetworkManager[5042]: <info> Activation (wlan0)
Stage 1 of 5 (Device Prepare) complete.
Mar  6 16:13:43 calvin NetworkManager[5042]: <info> Activation (wlan0)
Stage 2 of 5 (Device Configure) starting...
Mar  6 16:13:43 calvin NetworkManager[5042]: <info> (wlan0): device
state change: prepare -> config (reason 'none') [40 50 0]
Mar  6 16:13:43 calvin NetworkManager[5042]: <info> Activation
(wlan0/wireless): access point 'myssid' has security, but secrets are
required.
Mar  6 16:13:43 calvin NetworkManager[5042]: <info> (wlan0): device
state change: config -> need-auth (reason 'none') [50 60 0]
Mar  6 16:13:43 calvin NetworkManager[5042]: <info> Activation (wlan0)
Stage 2 of 5 (Device Configure) complete.
Mar  6 16:13:44 calvin NetworkManager[5042]: <info> Activation (wlan0)
Stage 1 of 5 (Device Prepare) scheduled...
Mar  6 16:13:44 calvin NetworkManager[5042]: <info> Activation (wlan0)
Stage 1 of 5 (Device Prepare) started...
Mar  6 16:13:44 calvin NetworkManager[5042]: <info> (wlan0): device
state change: need-auth -> prepare (reason 'none') [60 40 0]
Mar  6 16:13:44 calvin NetworkManager[5042]: <info> Activation (wlan0)
Stage 2 of 5 (Device Configure) scheduled...
Mar  6 16:13:44 calvin NetworkManager[5042]: <info> Activation (wlan0)
Stage 1 of 5 (Device Prepare) complete.
Mar  6 16:13:44 calvin NetworkManager[5042]: <info> Activation (wlan0)
Stage 2 of 5 (Device Configure) starting...
Mar  6 16:13:44 calvin NetworkManager[5042]: <info> (wlan0): device
state change: prepare -> config (reason 'none') [40 50 0]
Mar  6 16:13:44 calvin NetworkManager[5042]: <info> Activation
(wlan0/wireless): connection 'myssid' has security, and secrets exist.
 No new secrets needed.
Mar  6 16:13:44 calvin NetworkManager[5042]: <info> Activation (wlan0)
Stage 2 of 5 (Device Configure) complete.
Mar  6 16:13:44 calvin NetworkManager[5042]: <info> (wlan0):
supplicant interface state: disconnected -> scanning
Mar  6 16:13:47 calvin NetworkManager[5042]: <info> (wlan0):
supplicant interface state: scanning -> authenticating
Mar  6 16:13:47 calvin kernel: wlan0: direct probe to
00:11:22:33:44:ee:a1 (try 1/3)
Mar  6 16:13:47 calvin kernel: wlan0: direct probe to
00:11:22:33:44:ee:a1 (try 2/3)
Mar  6 16:13:47 calvin kernel: wlan0: direct probe to
00:11:22:33:44:ee:a1 (try 3/3)
Mar  6 16:13:47 calvin kernel: wlan0: direct probe to
00:11:22:33:44:ee:a1 timed out
Mar  6 16:13:55 calvin kernel: wlan0: direct probe to
00:11:22:33:55:15:01 (try 1/3)
Mar  6 16:13:55 calvin kernel: wlan0: direct probe to
00:11:22:33:55:15:01 (try 2/3)
Mar  6 16:13:55 calvin kernel: wlan0: direct probe to
00:11:22:33:55:15:01 (try 3/3)
Mar  6 16:13:56 calvin kernel: wlan0: direct probe to
00:11:22:33:55:15:01 timed out
Mar  6 16:14:03 calvin kernel: wlan0: direct probe to
00:11:22:33:44:ee:a1 (try 1/3)
Mar  6 16:14:04 calvin kernel: wlan0: direct probe to
00:11:22:33:44:ee:a1 (try 2/3)
Mar  6 16:14:04 calvin kernel: wlan0: direct probe to
00:11:22:33:44:ee:a1 (try 3/3)
Mar  6 16:14:04 calvin kernel: wlan0: direct probe to
00:11:22:33:44:ee:a1 timed out
Mar  6 16:14:09 calvin NetworkManager[5042]: <warn> Activation
(wlan0/wireless): association took too long.
Mar  6 16:14:09 calvin NetworkManager[5042]: <info> (wlan0): device
state change: config -> need-auth (reason 'none') [50 60 0]
Mar  6 16:14:09 calvin NetworkManager[5042]: <warn> Activation
(wlan0/wireless): asking for new secrets
Mar  6 16:14:09 calvin NetworkManager[5042]: <info> (wlan0):
supplicant interface state: authenticating -> disconnected
Mar  6 16:16:09 calvin NetworkManager[5042]: <info> (wlan0): device
state change: need-auth -> failed (reason 'no-secrets') [60 120 7]
Mar  6 16:16:09 calvin NetworkManager[5042]: <warn> Activation (wlan0)
failed for access point (myssid)
Mar  6 16:16:09 calvin NetworkManager[5042]: <warn> Activation (wlan0) failed.
Mar  6 16:16:09 calvin NetworkManager[5042]: <info> (wlan0): device
state change: failed -> disconnected (reason 'none') [120 30 0]
Mar  6 16:16:09 calvin NetworkManager[5042]: <info> (wlan0):
deactivating device (reason 'none') [0]

Something interesting is also going on with secrets: sometimes secrets
are required and sometimes aren't (no pass entered) but maybe this is
not correlated.

If someone can give me some hints, at least on how to get more
relevant debug data, it will make me happy :)


I've spotted several reports regarding problems with roaming but no
solutions so far.

data:

wpa_supplicant 0.7.3
Linux 3.2.9 x86_64
NetworkManager 0.9.2.0

distro: Gentoo (~)

Network controller: Intel Corporation Centrino Advanced-N 6200 (rev 35)

Intel(R) Wireless WiFi Link AGN driver for Linux, in-tree:d
Copyright(c) 2003-2011 Intel Corporation
iwlwifi 0000:44:00.0: PCI INT A -> GSI 19 (level, low) -> IRQ 19
iwlwifi 0000:44:00.0: setting latency timer to 64
iwlwifi 0000:44:00.0: pci_resource_len = 0x00002000
iwlwifi 0000:44:00.0: pci_resource_base = ffffc900100b8000
iwlwifi 0000:44:00.0: HW Revision ID = 0x35
iwlwifi 0000:44:00.0: irq 46 for MSI/MSI-X
iwlwifi 0000:44:00.0: Detected Intel(R) Centrino(R) Advanced-N 6200
AGN, REV=0x74
iwlwifi 0000:44:00.0: L1 Disabled; Enabling L0S
iwlwifi 0000:44:00.0: device EEPROM VER=0x436, CALIB=0x6
iwlwifi 0000:44:00.0: Device SKU: 0X1f0
iwlwifi 0000:44:00.0: Tunable channels: 13 802.11bg, 24 802.11a channels



Many thanks for any answer.

-- 
Fabio