On Monday 17 November 2008, Dave wrote:
> > Looking at wpa_supplicant log intersting part is
> >
> > Wireless event: cmd=0x8c07 len=32
> > AssocReq IE wireless event - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 02
> > RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
> > RTM_NEWLINK, IFLA_IFNAME: Interface 'eth1' added
> > Wireless event: cmd=0x8b15 len=20
> > Wireless event: new AP: 00:60:b3:ca:91:b0
> > Association info event
> > req_ies - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 02
> > WPA: set own WPA/RSN IE - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 02
> > State: ASSOCIATING -> ASSOCIATED
> > wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
> > WEXT: Operstate: linkmode=-1, operstate=5
> > Associated to a new BSS: BSSID=44:44:44:44:44:44
>
> > in other words, wpa_drv_get_bssid() returns 44:... BSSID. I could not find
> > any place in kernel or wpa_supplicant that would set it, so I can only assume
> > that firmware returns it for watever reason.
>
> It is a firmware value, but I don't know what the it means. I know
> hostap checks for it in hostap_main:prism2_sta_deauth.
>
In some place wpa_supplicant is using this to mark invalid BSSID; I
do not think it leaks it into the driver now though.
And it is value that is use by Hermes to indicate invalid BSSID. It is even
documents in iwconfig.c :)
/*
* Display an Wireless Access Point Socket Address in readable format.
* Note : 0x44 is an accident of history, that's what the Orinoco/PrismII
* chipset report, and the driver doesn't filter it.
*/
Anyway I now have Yet Another Theory that actually fits quite well into
what I have seen in wpa_supplicant logs and explains 44:... BSSID as well.
Mandriva is using approximately the following sequence to start wireless:
ifconfig eth1 up
iwconfig eth1 whatever-is-set-for-it
wpa_supplicant eth1
Now I had these parameters for eth1:
### WIRELESS_MODE=Managed
### WIRELESS_ESSID="Home, sweet home"
WIRELESS_WPA_DRIVER=wext
### WIRELESS_POWER=on
### WIRELESS_SENS=3
Notice WIRELESS_ESSID. So what happened was apparently this
iwcofnig eth1 ESSID
driver starts associating
wpa_supplicant starts
driver associated and send IWEVASSOCREQIE
wpa_supplicant calls SIOCSIWESSID |
+-------------------------+
|
| driver *again* starts associating
/
wpa_supplicant receives SIOCSIWESSID
wpa_supplicant calls SIOCGIWAP
at this point driver has not yet
completed *second* association
so it returns invalid BSSID
(44:44:44:44:44:44)
So it looks like user space issue after all. There is little driver can
do (except returning "officially blessed" indication for invalid BSSID).
As it is now, wpa_supplicant does not seem to check for invalid BSSID
from SIOCGIWAP in wpa_supplicant_event_assoc() at all. It enters quite a
long retry loop using invalid value until it finally decides to trigger
association again.
It also explains why nobody was able to reproduce it - it is really
quite unique timing issue. Any change in scheduling could have "fixed" it.
Attachment:
signature.asc
Description: This is a digitally signed message part.
