Issues with bwn wireless

Tue May 3 14:46:35 UTC 2011

Sorry about the delay - I only had free time now.

> Can you post debug output of wpa_supplicant/bwn?
> % sysctl dev.bwn.0.debug=-1

#sysctl dev.bwn.0
dev.bwn.0.%driver: bwn
dev.bwn.0.%parent: siba_bwn0
dev.bwn.0.linknoise: 0
dev.bwn.0.rts: 0
dev.bwn.0.rtsfail: 0

> % wpa_supplicant -Dbsd -iwlan0 -c/etc/wpa_supplicant.conf -ddt

#wpa_supplicant -Dbsd -iwlan0 -c/etc/wpa_supplicant.conf -ddt
1304432141.061742: Initializing interface 'wlan0' conf
'/etc/wpa_supplicant.conf' driver 'bsd' ctrl_interface 'N/A' bridge
'N/A'
1304432141.061824: Configuration file '/etc/wpa_supplicant.conf' ->
'/etc/wpa_supplicant.conf'
1304432141.061837: Reading configuration file '/etc/wpa_supplicant.conf'
1304432141.095508: ctrl_interface='/var/run/wpa_supplicant'
1304432141.095534: ctrl_interface_group='wheel'
1304432141.095541: Line: 16 - start of a new network block
1304432141.095585: ssid - hexdump_ascii(len=10):
     62 75 77 69 72 65 6c 65 73 73                     buwireless
1304432141.095600: key_mgmt: 0x4
1304432141.095646: Priority group 0
1304432141.095655:    id=0 ssid='buwireless'
1304432141.095661: Initializing interface (2) 'wlan0'
1304432141.130677: Own MAC address: 00:21:00:e7:75:20
1304432141.130697: wpa_driver_bsd_set_wpa: enabled=1
1304432141.130703: wpa_driver_bsd_set_wpa_internal: wpa=3 privacy=1
1304432141.130715: wpa_driver_bsd_del_key: keyidx=0
1304432141.130725: wpa_driver_bsd_del_key: keyidx=1
1304432141.130732: wpa_driver_bsd_del_key: keyidx=2
1304432141.130739: wpa_driver_bsd_del_key: keyidx=3
1304432141.130745: wpa_driver_bsd_set_countermeasures: enabled=0
1304432141.130752: wpa_driver_bsd_set_drop_unencrypted: enabled=1
1304432141.130758: RSN: flushing PMKID list in the driver
1304432141.130776: Setting scan request: 0 sec 100000 usec
1304432141.135198: EAPOL: SUPP_PAE entering state DISCONNECTED
1304432141.135215: EAPOL: KEY_RX entering state NO_KEY_RECEIVE
1304432141.135220: EAPOL: SUPP_BE entering state INITIALIZE
1304432141.135226: EAP: EAP entering state DISABLED
1304432141.135254: Using existing control interface directory.
1304432141.136063: ctrl_interface_group=0 (from group name 'wheel')
1304432141.136167: Added interface wlan0
1304432141.231289: State: DISCONNECTED -> SCANNING
1304432141.231310: Starting AP scan (broadcast SSID)
1304432141.231315: Trying to get current scan results first without
requesting a new scan to speed up initial association
1304432141.231380: Received 0 bytes of scan results (0 BSSes)
1304432141.231389: Scan results: 0
1304432141.231399: Cached scan results are empty - not posting
1304432141.231405: Selecting BSS from priority group 0
1304432141.231410: Try to find WPA-enabled AP
1304432141.231415: Try to find non-WPA AP
1304432141.231420: No suitable AP found.
1304432141.231426: Setting scan request: 0 sec 0 usec
1304432141.231444: Starting AP scan (broadcast SSID)
1304432142.197193: EAPOL: disable timer tick
1304432144.434911: Received 0 bytes of scan results (19 BSSes)
1304432144.434934: Scan results: 19
1304432144.434957: CTRL-EVENT-SCAN-RESULTS
1304432144.434964: Selecting BSS from priority group 0
1304432144.434969: Try to find WPA-enabled AP
1304432144.434974: 0: 00:23:eb:3a:67:a3 ssid='busecure' wpa_ie_len=28
rsn_ie_len=24 caps=0x11
1304432144.434982:    skip - SSID mismatch
1304432144.434987: 1: 00:23:eb:3a:67:a4 ssid='' wpa_ie_len=28
rsn_ie_len=24 caps=0x11
1304432144.434994:    skip - SSID mismatch
1304432144.434999: 2: 00:23:eb:0c:4f:33 ssid='busecure' wpa_ie_len=28
rsn_ie_len=24 caps=0x11
1304432144.435006:    skip - SSID mismatch
1304432144.435011: 3: 58:bc:27:5c:32:04 ssid='' wpa_ie_len=28
rsn_ie_len=24 caps=0x11
1304432144.435018:    skip - SSID mismatch
1304432144.435023: 4: 00:23:eb:0c:4f:34 ssid='' wpa_ie_len=28
rsn_ie_len=24 caps=0x11
1304432144.435030:    skip - SSID mismatch
1304432144.435034: 5: 00:23:eb:3a:f4:a4 ssid='' wpa_ie_len=28
rsn_ie_len=24 caps=0x11
1304432144.435041:    skip - SSID mismatch
1304432144.435046: 6: 58:bc:27:0f:e4:63 ssid='busecure' wpa_ie_len=28
rsn_ie_len=24 caps=0x11
1304432144.435053:    skip - SSID mismatch
1304432144.435058: 7: 00:23:eb:3a:67:a2 ssid='buwireless' wpa_ie_len=0
rsn_ie_len=0 caps=0x1
1304432144.435065:    skip - no WPA/RSN IE
1304432144.435070: 8: 00:23:eb:3a:67:a0 ssid='buguests' wpa_ie_len=0
rsn_ie_len=0 caps=0x1
1304432144.435077:    skip - no WPA/RSN IE
1304432144.435082: 9: 00:23:eb:0c:4f:30 ssid='buguests' wpa_ie_len=0
rsn_ie_len=0 caps=0x1
1304432144.435089:    skip - no WPA/RSN IE
1304432144.435094: 10: 00:23:eb:0c:4f:32 ssid='buwireless'
wpa_ie_len=0 rsn_ie_len=0 caps=0x1
1304432144.435101:    skip - no WPA/RSN IE
1304432144.435106: 11: 00:23:eb:3a:f4:a2 ssid='buwireless'
wpa_ie_len=0 rsn_ie_len=0 caps=0x1
1304432144.435113:    skip - no WPA/RSN IE
1304432144.435118: 12: 02:29:19:d6:67:d1 ssid='HP440F1C' wpa_ie_len=0
rsn_ie_len=0 caps=0x2
1304432144.435125:    skip - no WPA/RSN IE
1304432144.435129: 13: 58:bc:27:0f:e4:61 ssid='' wpa_ie_len=0
rsn_ie_len=0 caps=0x1
1304432144.435203:    skip - no WPA/RSN IE
1304432144.435209: 14: 58:bc:27:0f:e4:62 ssid='buwireless'
wpa_ie_len=0 rsn_ie_len=0 caps=0x1
1304432144.435217:    skip - no WPA/RSN IE
1304432144.435222: 15: 58:bc:27:0f:e4:60 ssid='buguests' wpa_ie_len=0
rsn_ie_len=0 caps=0x1
1304432144.435229:    skip - no WPA/RSN IE
1304432144.435233: 16: 2e:24:81:ba:a8:b6 ssid='hpsetup' wpa_ie_len=0
rsn_ie_len=0 caps=0x22
1304432144.435241:    skip - no WPA/RSN IE
1304432144.435246: 17: 02:98:8b:a3:0e:69 ssid='print server 0C2F98'
wpa_ie_len=0 rsn_ie_len=0 caps=0x2
1304432144.435254:    skip - no WPA/RSN IE
1304432144.435258: 18: da:29:05:26:52:6b ssid='Notorious' wpa_ie_len=0
rsn_ie_len=0 caps=0x2
1304432144.435266:    skip - no WPA/RSN IE
1304432144.435270: Try to find non-WPA AP
1304432144.435275: 0: 00:23:eb:3a:67:a3 ssid='busecure' wpa_ie_len=28
rsn_ie_len=24 caps=0x11
1304432144.435282:    skip - SSID mismatch
1304432144.435287: 1: 00:23:eb:3a:67:a4 ssid='' wpa_ie_len=28
rsn_ie_len=24 caps=0x11
1304432144.435294:    skip - SSID mismatch
1304432144.435299: 2: 00:23:eb:0c:4f:33 ssid='busecure' wpa_ie_len=28
rsn_ie_len=24 caps=0x11
1304432144.435306:    skip - SSID mismatch
1304432144.435310: 3: 58:bc:27:5c:32:04 ssid='' wpa_ie_len=28
rsn_ie_len=24 caps=0x11
1304432144.435317:    skip - SSID mismatch
1304432144.435322: 4: 00:23:eb:0c:4f:34 ssid='' wpa_ie_len=28
rsn_ie_len=24 caps=0x11
1304432144.435329:    skip - SSID mismatch
1304432144.435334: 5: 00:23:eb:3a:f4:a4 ssid='' wpa_ie_len=28
rsn_ie_len=24 caps=0x11
1304432144.435341:    skip - SSID mismatch
1304432144.435346: 6: 58:bc:27:0f:e4:63 ssid='busecure' wpa_ie_len=28
rsn_ie_len=24 caps=0x11
1304432144.435353:    skip - SSID mismatch
1304432144.435358: 7: 00:23:eb:3a:67:a2 ssid='buwireless' wpa_ie_len=0
rsn_ie_len=0 caps=0x1
1304432144.435366:    selected non-WPA AP 00:23:eb:3a:67:a2 ssid='buwireless'
1304432144.435376: Trying to associate with 00:23:eb:3a:67:a2
(SSID='buwireless' freq=2412 MHz)
1304432144.435414: Cancelling scan request
1304432144.435420: WPA: clearing own WPA/RSN IE
1304432144.435425: Automatic auth_alg selection: 0x1
1304432144.435430: wpa_driver_bsd_set_auth_alg alg 0x1 authmode 1
1304432144.435441: WPA: clearing AP WPA IE
1304432144.435447: WPA: clearing AP RSN IE
1304432144.435451: WPA: clearing own WPA/RSN IE
1304432144.435457: No keys have been configured - skip key clearing
1304432144.435462: wpa_driver_bsd_set_drop_unencrypted: enabled=0
1304432144.435470: State: SCANNING -> ASSOCIATING
1304432144.435476: wpa_driver_bsd_associate: ssid 'buwireless' wpa ie
len 0 pairwise 0 group 0 key mgmt 2
1304432144.435493: wpa_driver_bsd_associate: set PRIVACY 0
1304432144.444234: Setting authentication timeout: 10 sec 0 usec
1304432144.444249: EAPOL: External notification - EAP success=0
1304432144.444258: EAPOL: External notification - EAP fail=0
1304432144.444263: EAPOL: External notification - portControl=ForceAuthorized
1304432146.113912: State: ASSOCIATING -> ASSOCIATED
1304432146.113945: Associated to a new BSS: BSSID=00:23:eb:3a:67:a2
1304432146.113954: Associated with 00:23:eb:3a:67:a2
1304432146.113961: WPA: Association event - clear replay counter
1304432146.113966: WPA: Clear old PTK
1304432146.113971: EAPOL: External notification - portEnabled=0
1304432146.113979: EAPOL: External notification - portValid=0
1304432146.113985: EAPOL: External notification - portEnabled=1
1304432146.113989: EAPOL: SUPP_PAE entering state S_FORCE_AUTH
1304432146.113995: EAPOL: SUPP_BE entering state IDLE
1304432146.114001: Cancelling authentication timeout
1304432146.114007: State: ASSOCIATED -> COMPLETED
1304432146.114017: CTRL-EVENT-CONNECTED - Connection to
00:23:eb:3a:67:a2 completed (auth) [id=0 id_str=]
1304432146.114023: Cancelling scan request

>> 3) Sometimes I see the channel cycling somewhat randomly during the
>> "associated but not working" time.
>
> Sounds like a background scan issue, try with
> % ifconfig wlan0 -bgscan

I will try this soon and post here if it still works.

>
>> 4) ifconfig wlan0 scan never shows anything but ifconfig wlan0 list scan does.
>
> This should be fixed in HEAD.

Woot! thanks.

-- 
Eitan Adler