LinuxQuestions.org

LinuxQuestions.org (/questions/)
-   Linux - Laptop and Netbook (http://www.linuxquestions.org/questions/linux-laptop-and-netbook-25/)
-   -   Linux Wireless Connectivity Slowness - Slackware 14 (3.7) BCM4313 BRCMSMAC (http://www.linuxquestions.org/questions/linux-laptop-and-netbook-25/linux-wireless-connectivity-slowness-slackware-14-3-7-bcm4313-brcmsmac-4175436715/)

alex.pujols 11-11-2012 09:43 PM

Linux Wireless Connectivity Slowness - Slackware 14 (3.7) BCM4313 BRCMSMAC
 
LQ Wireless Guru Friends,

I figured I'd reach out to the community regarding an issue I can't
seem to work through on my ASUS 1225B.

The issue at hand is that loading any webpage on any network loads at
a slothlike pace (ie... 25+ seconds for a page to load)

Here are a few things that I've done so far...
  • tried multiple SSID's, problem persists
  • tried 4 separately compiled kernel's (stock Slackware 14 as well as 3.4, 3.6.6, 3.7)
  • tried WEXT and nl driver within WPA supplicant
  • compiled wireless as kernel integrated and modules and problem persists
  • have enabled -dd through wpa_supplicant to pull full debug
  • checked all functional components of my wireless network (though no other end points are experiencing this problem)
  • verified wireless signal strength, problem persists within feet of any AP

(See some prelim debug output below, including wpa_supp -dd output from a live webserfing session with massive slowness)

Regards,
Alex

Slackware 14
Kernel 3.7
ASUS 1225b



*** lspci ***

04:00.0 Network controller: Broadcom Corporation BCM4313 802.11b/g/n
Wireless LAN Controller (rev 01)
*************


** var/log/messages **

Nov 12 09:29:13 LigHTsTar kernel: [ 6305.224575] IPv6:
ADDRCONF(NETDEV_UP): wlan0: link is not ready
Nov 12 09:32:29 LigHTsTar kernel: [ 6500.594340] wlan0: authenticate
with 00:17:df:a6:6b:02
Nov 12 09:32:29 LigHTsTar kernel: [ 6500.595325] wlan0: send auth to
00:17:df:a6:6b:02 (try 1/3)
Nov 12 09:32:29 LigHTsTar kernel: [ 6500.796110] wlan0: send auth to
00:17:df:a6:6b:02 (try 2/3)
Nov 12 09:32:29 LigHTsTar kernel: [ 6500.797662] wlan0: authenticated
Nov 12 09:32:29 LigHTsTar kernel: [ 6500.798314] wlan0: associate with
00:17:df:a6:6b:02 (try 1/3)
Nov 12 09:32:29 LigHTsTar kernel: [ 6500.802129] wlan0: RX AssocResp
from 00:17:df:a6:6b:02 (capab=0x431 status=0 aid=1)
Nov 12 09:32:29 LigHTsTar kernel: [ 6500.802666] wlan0: associated
Nov 12 09:32:29 LigHTsTar kernel: [ 6500.802821] cfg80211: Calling
CRDA for country: US
Nov 12 09:32:29 LigHTsTar kernel: [ 6500.803348] IPv6:
ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
Nov 12 09:32:29 LigHTsTar kernel: [ 6500.806591] cfg80211: Regulatory
domain changed to country: US
Nov 12 09:32:29 LigHTsTar kernel: [ 6500.806597] cfg80211:
(start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
Nov 12 09:32:29 LigHTsTar kernel: [ 6500.806602] cfg80211: (2402000
KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2700 mBm)
Nov 12 09:32:29 LigHTsTar kernel: [ 6500.806605] cfg80211: (5170000
KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 1700 mBm)
Nov 12 09:32:29 LigHTsTar kernel: [ 6500.806609] cfg80211: (5250000
KHz - 5330000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Nov 12 09:32:29 LigHTsTar kernel: [ 6500.806612] cfg80211: (5490000
KHz - 5600000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Nov 12 09:32:29 LigHTsTar kernel: [ 6500.806615] cfg80211: (5650000
KHz - 5710000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Nov 12 09:32:29 LigHTsTar kernel: [ 6500.806618] cfg80211: (5735000
KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 3000 mBm)
******************


** dmesg | tail **

[ 6500.806597] cfg80211: (start_freq - end_freq @ bandwidth),
(max_antenna_gain, max_eirp)
[ 6500.806602] cfg80211: (2402000 KHz - 2472000 KHz @ 40000 KHz),
(300 mBi, 2700 mBm)
[ 6500.806605] cfg80211: (5170000 KHz - 5250000 KHz @ 40000 KHz),
(300 mBi, 1700 mBm)
[ 6500.806609] cfg80211: (5250000 KHz - 5330000 KHz @ 40000 KHz),
(300 mBi, 2000 mBm)
[ 6500.806612] cfg80211: (5490000 KHz - 5600000 KHz @ 40000 KHz),
(300 mBi, 2000 mBm)
[ 6500.806615] cfg80211: (5650000 KHz - 5710000 KHz @ 40000 KHz),
(300 mBi, 2000 mBm)
[ 6500.806618] cfg80211: (5735000 KHz - 5835000 KHz @ 40000 KHz),
(300 mBi, 3000 mBm)
[ 6506.354455] ieee80211 phy0: brcms_ops_bss_info_changed: arp
filtering: enabled true, count 1 (implement)
[ 6535.655288] ieee80211 phy0: brcms_ops_bss_info_changed: arp
filtering: enabled true, count 0 (implement)
[ 6546.738473] ieee80211 phy0: brcms_ops_bss_info_changed: arp
filtering: enabled true, count 1 (implement)
******************


*** lsusb ***

ftdi_sio 27464 0
snd_seq_dummy 992 0
snd_seq_oss 23357 0
snd_seq_midi_event 4313 1 snd_seq_oss
snd_seq 39033 5 snd_seq_midi_event,snd_seq_oss,snd_seq_dummy
snd_seq_device 4021 3 snd_seq,snd_seq_oss,snd_seq_dummy
snd_pcm_oss 32646 0
snd_mixer_oss 12472 2 snd_pcm_oss
ipv6 229564 18
brcmsmac 476469 0
cordic 805 1 brcmsmac
brcmutil 2277 1 brcmsmac
mac80211 317836 1 brcmsmac
cfg80211 150039 2 brcmsmac,mac80211
bcma 21957 1 brcmsmac
usbserial 18574 1 ftdi_sio
fuse 58196 3
kvm_amd 43912 0
kvm 312335 1 kvm_amd
btusb 9849 0
k10temp 2075 0
bluetooth 162331 2 btusb
rfkill 12105 3 cfg80211,bluetooth
snd_hda_codec_hdmi 24145 1
snd_hda_intel 20597 3
snd_hda_codec 64662 2 snd_hda_codec_hdmi,snd_hda_intel
snd_pcm 61322 4
snd_pcm_oss,snd_hda_codec_hdmi,snd_hda_codec,snd_hda_intel
snd_page_alloc 5807 2 snd_pcm,snd_hda_intel
snd_timer 14255 2 snd_pcm,snd_seq
snd 41728 14
snd_pcm_oss,snd_timer,snd_hda_codec_hdmi,snd_pcm,snd_seq,snd_hda_codec,snd_hda_intel,snd_seq_oss,snd _seq_device,snd_mixer_oss
soundcore 4187 2 snd
************

** ping times to AP gateway **

PING 10.10.4.1 (10.10.4.1) 56(84) bytes of data.
64 bytes from 10.10.4.1: icmp_req=1 ttl=255 time=10.8 ms
64 bytes from 10.10.4.1: icmp_req=2 ttl=255 time=2.05 ms
64 bytes from 10.10.4.1: icmp_req=3 ttl=255 time=2.84 ms
64 bytes from 10.10.4.1: icmp_req=4 ttl=255 time=1.82 ms
64 bytes from 10.10.4.1: icmp_req=5 ttl=255 time=2.03 ms
64 bytes from 10.10.4.1: icmp_req=6 ttl=255 time=2.66 ms
64 bytes from 10.10.4.1: icmp_req=7 ttl=255 time=2.12 ms
64 bytes from 10.10.4.1: icmp_req=8 ttl=255 time=1.89 ms
64 bytes from 10.10.4.1: icmp_req=9 ttl=255 time=3.27 ms
64 bytes from 10.10.4.1: icmp_req=10 ttl=255 time=2.20 ms
64 bytes from 10.10.4.1: icmp_req=11 ttl=255 time=2.05 ms
64 bytes from 10.10.4.1: icmp_req=12 ttl=255 time=2.02 ms
64 bytes from 10.10.4.1: icmp_req=13 ttl=255 time=1.97 ms
64 bytes from 10.10.4.1: icmp_req=14 ttl=255 time=1.86 ms
64 bytes from 10.10.4.1: icmp_req=15 ttl=255 time=1.82 ms
64 bytes from 10.10.4.1: icmp_req=16 ttl=255 time=2.02 ms
64 bytes from 10.10.4.1: icmp_req=17 ttl=255 time=2.02 ms
64 bytes from 10.10.4.1: icmp_req=18 ttl=255 time=1.96 ms
64 bytes from 10.10.4.1: icmp_req=19 ttl=255 time=1.82 ms
64 bytes from 10.10.4.1: icmp_req=20 ttl=255 time=1.95 ms
64 bytes from 10.10.4.1: icmp_req=21 ttl=255 time=4.32 ms
64 bytes from 10.10.4.1: icmp_req=22 ttl=255 time=2.04 ms
64 bytes from 10.10.4.1: icmp_req=23 ttl=255 time=1.87 ms
64 bytes from 10.10.4.1: icmp_req=24 ttl=255 time=1.92 ms
64 bytes from 10.10.4.1: icmp_req=25 ttl=255 time=1.98 ms
64 bytes from 10.10.4.1: icmp_req=26 ttl=255 time=1.95 ms
64 bytes from 10.10.4.1: icmp_req=27 ttl=255 time=2.01 ms
64 bytes from 10.10.4.1: icmp_req=28 ttl=255 time=1.97 ms
64 bytes from 10.10.4.1: icmp_req=29 ttl=255 time=1.98 ms
64 bytes from 10.10.4.1: icmp_req=30 ttl=255 time=2.36 ms
64 bytes from 10.10.4.1: icmp_req=31 ttl=255 time=1.98 ms
64 bytes from 10.10.4.1: icmp_req=32 ttl=255 time=2.02 ms
64 bytes from 10.10.4.1: icmp_req=33 ttl=255 time=1.97 ms
64 bytes from 10.10.4.1: icmp_req=34 ttl=255 time=2.40 ms
64 bytes from 10.10.4.1: icmp_req=35 ttl=255 time=2.23 ms
64 bytes from 10.10.4.1: icmp_req=36 ttl=255 time=2.00 ms
64 bytes from 10.10.4.1: icmp_req=37 ttl=255 time=2.30 ms
64 bytes from 10.10.4.1: icmp_req=38 ttl=255 time=1.97 ms
64 bytes from 10.10.4.1: icmp_req=39 ttl=255 time=1.90 ms
64 bytes from 10.10.4.1: icmp_req=40 ttl=255 time=1.93 ms
64 bytes from 10.10.4.1: icmp_req=41 ttl=255 time=1.98 ms
64 bytes from 10.10.4.1: icmp_req=42 ttl=255 time=3.40 ms
64 bytes from 10.10.4.1: icmp_req=43 ttl=255 time=1.87 ms
64 bytes from 10.10.4.1: icmp_req=44 ttl=255 time=1.96 ms
64 bytes from 10.10.4.1: icmp_req=45 ttl=255 time=2.47 ms
64 bytes from 10.10.4.1: icmp_req=46 ttl=255 time=2.26 ms
64 bytes from 10.10.4.1: icmp_req=47 ttl=255 time=2.00 ms
64 bytes from 10.10.4.1: icmp_req=48 ttl=255 time=2.15 ms
64 bytes from 10.10.4.1: icmp_req=49 ttl=255 time=1.89 ms
64 bytes from 10.10.4.1: icmp_req=50 ttl=255 time=1.97 ms
64 bytes from 10.10.4.1: icmp_req=51 ttl=255 time=1.98 ms
64 bytes from 10.10.4.1: icmp_req=52 ttl=255 time=2.18 ms
64 bytes from 10.10.4.1: icmp_req=53 ttl=255 time=2.16 ms
^C
--- 10.10.4.1 ping statistics ---
53 packets transmitted, 53 received, 0% packet loss, time 52072ms
rtt min/avg/max/mdev = 1.825/2.317/10.895/1.267 ms



** wpa_supplicant Output **

wpa_supplicant v1.0
random: Trying to read entropy from /dev/random
Initializing interface 'wlan0' conf '/etc/wpa_supplicant.conf' driver
'wext' ctrl_interface 'N/A' bridge 'N/A'
Configuration file '/etc/wpa_supplicant.conf' -> '/etc/wpa_supplicant.conf'
Reading configuration file '/etc/wpa_supplicant.conf'
ctrl_interface='/var/run/wpa_supplicant'
ctrl_interface_group='0'
update_config=1
Line: 5 - start of a new network block
ssid - hexdump_ascii(len=6):
67 68 6f 73 74 79 ghosty
proto: 0x2
key_mgmt: 0x2
pairwise: 0x18
group: 0x18
PSK (ASCII passphrase) - hexdump_ascii(len=9): [REMOVED]
PSK (from passphrase) - hexdump(len=32): [REMOVED]
Line: 14 - start of a new network block
ssid - hexdump_ascii(len=8):
62 6c 69 7a 7a 61 72 64 blizzard
scan_ssid=1 (0x1)
key_mgmt: 0x1
pairwise: 0x10
group: 0x8
auth_alg: 0x1
eap methods - hexdump(len=16): 00 00 00 00 19 00 00 00 00 00 00 00 00 00 00 00
identity - hexdump_ascii(len=13):
43 49 53 43 4f 5c 61 70 75 6a 6f 6c 73 CISCO\apujols
anonymous_identity - hexdump_ascii(len=9):
61 6e 6f 6e 79 6d 6f 75 73 anonymous
password - hexdump_ascii(len=8): [REMOVED]
phase1 - hexdump_ascii(len=11):
70 65 61 70 6c 61 62 65 6c 3d 30 peaplabel=0
phase2 - hexdump_ascii(len=13):
61 75 74 68 3d 4d 53 43 48 41 50 56 32 auth=MSCHAPV2
pac_file - hexdump_ascii(len=32):
2f 65 74 63 2f 77 70 61 5f 73 75 70 70 6c 69 63 /etc/wpa_supplic
61 6e 74 2e 65 61 70 2d 66 61 73 74 2d 70 61 63 ant.eap-fast-pac
disabled=1 (0x1)
Priority group 0
id=0 ssid='ghosty'
id=1 ssid='blizzard'
WEXT: cfg80211-based driver detected
wext: interface wlan0 phy: phy0
rfkill: initial event: idx=0 type=2 op=0 soft=0 hard=0
rfkill: initial event: idx=1 type=1 op=0 soft=0 hard=0
SIOCGIWRANGE: WE(compiled)=22 WE(source)=21 enc_capa=0xf
capabilities: key_mgmt 0xf enc 0xf flags 0x0
netlink: Operstate: linkmode=1, operstate=5
wlan0: Own MAC address: dc:85:de:03:71:64
wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=1 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=2 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=3 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_countermeasures
wlan0: RSN: flushing PMKID list in the driver
wlan0: Setting scan request: 0 sec 100000 usec
WPS: Set UUID for interface wlan0
WPS: UUID based on MAC address - hexdump(len=16): 2f 09 98 30 bd 7c 59
64 b8 6b ce 35 ec 00 30 34
EAPOL: SUPP_PAE entering state DISCONNECTED
EAPOL: Supplicant port status: Unauthorized
EAPOL: KEY_RX entering state NO_KEY_RECEIVE
EAPOL: SUPP_BE entering state INITIALIZE
EAP: EAP entering state DISABLED
EAPOL: Supplicant port status: Unauthorized
EAPOL: Supplicant port status: Unauthorized
ctrl_interface_group=0
wlan0: Added interface wlan0
random: Got 20/20 bytes from /dev/random
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
WEXT: if_removed already cleared - ignore event
Wireless event: cmd=0x8b06 len=8
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
WEXT: if_removed already cleared - ignore event
Wireless event: cmd=0x8b1a len=8
wlan0: State: DISCONNECTED -> SCANNING
wlan0: Starting AP scan for wildcard SSID
Scan requested (ret=0) - scan timeout 10 seconds
EAPOL: disable timer tick
EAPOL: Supplicant port status: Unauthorized
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
WEXT: if_removed already cleared - ignore event
Wireless event: cmd=0x8b19 len=8
wlan0: Event SCAN_RESULTS (3) received
Received 1947 bytes of scan results (4 BSSes)
wlan0: BSS: Start scan result update 1
wlan0: BSS: Add new id 0 BSSID 00:17:df:a6:6b:02 SSID 'ghosty'
wlan0: BSS: Add new id 1 BSSID 00:21:d8:48:da:72 SSID 'ghosty'
wlan0: BSS: Add new id 2 BSSID c0:c1:c0:d7:43:d4 SSID 'Wolkenhauer'
wlan0: BSS: Add new id 3 BSSID c0:c1:c0:d7:43:d6 SSID 'Wolkenhauer-guest'
Add randomness: count=1 entropy=0
Add randomness: count=2 entropy=1
Add randomness: count=3 entropy=2
Add randomness: count=4 entropy=3
wlan0: New scan results available
wlan0: Selecting BSS from priority group 0
wlan0: 0: 00:17:df:a6:6b:02 ssid='ghosty' wpa_ie_len=0 rsn_ie_len=20
caps=0x11 level=-52
wlan0: selected based on RSN IE
wlan0: selected BSS 00:17:df:a6:6b:02 ssid='ghosty'
wlan0: Request association: reassociate: 0 selected:
00:17:df:a6:6b:02 bssid: 00:00:00:00:00:00 pending:
00:00:00:00:00:00 wpa_state: SCANNING
wlan0: Trying to associate with 00:17:df:a6:6b:02 (SSID='ghosty' freq=2412 MHz)
wlan0: Cancelling scan request
wlan0: WPA: clearing own WPA/RSN IE
wlan0: Automatic auth_alg selection: 0x1
wlan0: RSN: using IEEE 802.11i/D9.0
wlan0: WPA: Selected cipher suites: group 16 pairwise 16 key_mgmt 2 proto 2
wlan0: WPA: clearing AP WPA IE
WPA: set AP RSN IE - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00
0f ac 04 01 00 00 0f ac 02 28 00
wlan0: WPA: using GTK CCMP
wlan0: WPA: using PTK CCMP
wlan0: WPA: using KEY_MGMT WPA-PSK
WPA: Set own WPA IE default - hexdump(len=22): 30 14 01 00 00 0f ac 04
01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
wlan0: No keys have been configured - skip key clearing
wlan0: State: SCANNING -> ASSOCIATING
wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
netlink: Operstate: linkmode=-1, operstate=5
wpa_driver_wext_associate
wpa_driver_wext_set_drop_unencrypted
wpa_driver_wext_set_psk
wlan0: Association request to the driver failed
wlan0: Setting authentication timeout: 5 sec 0 usec
EAPOL: External notification - EAP success=0
EAPOL: Supplicant port status: Unauthorized
EAPOL: External notification - EAP fail=0
EAPOL: Supplicant port status: Unauthorized
EAPOL: External notification - portControl=Auto
EAPOL: Supplicant port status: Unauthorized
RSN: Ignored PMKID candidate without preauth flag
RSN: Ignored PMKID candidate without preauth flag
wlan0: Checking for other virtual interfaces sharing same radio (phy0)
in event_scan_results
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
WEXT: if_removed already cleared - ignore event
Wireless event: cmd=0x8b1a len=8
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
WEXT: if_removed already cleared - ignore event
Wireless event: cmd=0x8b06 len=8
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
WEXT: if_removed already cleared - ignore event
Wireless event: cmd=0x8b1a len=14
RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
WEXT: if_removed already cleared - ignore event
Wireless event: cmd=0x8c08 len=102
AssocResp IE wireless event - hexdump(len=94): 01 08 82 84 8b 96 0c 12
18 24 32 04 30 48 60 6c 2d 1a 2c 18 1b ff ff 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 3d 16 01 00 05 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 dd 18 00 50 f2 02 01 01 80
00 03 a4 00 00 27 a4 00 00 42 43 5e 00 62 32 2f 00
RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
WEXT: if_removed already cleared - ignore event
Wireless event: cmd=0x8b15 len=20
Wireless event: new AP: 00:17:df:a6:6b:02
wlan0: Event ASSOCINFO (4) received
wlan0: Association info event
resp_ies - hexdump(len=94): 01 08 82 84 8b 96 0c 12 18 24 32 04 30 48
60 6c 2d 1a 2c 18 1b ff ff 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 3d 16 01 00 05 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 dd 18 00 50 f2 02 01 01 80 00 03 a4 00 00 27
a4 00 00 42 43 5e 00 62 32 2f 00
wlan0: Event ASSOC (0) received
wlan0: State: ASSOCIATING -> ASSOCIATED
wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
netlink: Operstate: linkmode=-1, operstate=5
wlan0: Associated to a new BSS: BSSID=00:17:df:a6:6b:02
Add randomness: count=5 entropy=4
wlan0: No keys have been configured - skip key clearing
wlan0: Associated with 00:17:df:a6:6b:02
wlan0: WPA: Association event - clear replay counter
wlan0: WPA: Clear old PTK
EAPOL: External notification - portEnabled=0
EAPOL: Supplicant port status: Unauthorized
EAPOL: External notification - portValid=0
EAPOL: Supplicant port status: Unauthorized
EAPOL: External notification - EAP success=0
EAPOL: Supplicant port status: Unauthorized
EAPOL: External notification - portEnabled=1
EAPOL: SUPP_PAE entering state CONNECTING
EAPOL: enable timer tick
EAPOL: SUPP_BE entering state IDLE
wlan0: Setting authentication timeout: 10 sec 0 usec
wlan0: Cancelling scan request
RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
WEXT: if_removed already cleared - ignore event
wlan0: RX EAPOL from 00:17:df:a6:6b:02
RX EAPOL - hexdump(len=121): 02 03 00 75 02 00 8a 00 10 00 00 00 00 00
00 00 00 1b fd 33 d4 8c 39 4e 9d a2 44 ca 50 fc 6b 0a 61 25 99 c9 d9
77 f0 ae 84 69 d2 98 20 2b 39 0e 15 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 16 dd 14 00 0f ac 04 9a
a4 94 89 1f c4 24 8c b1 be 85 33 48 23 67 24
wlan0: Setting authentication timeout: 10 sec 0 usec
wlan0: IEEE 802.1X RX: version=2 type=3 length=117
wlan0: EAPOL-Key type=2
wlan0: key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)
wlan0: key_length=16 key_data_length=22
replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 00
key_nonce - hexdump(len=32): 1b fd 33 d4 8c 39 4e 9d a2 44 ca 50 fc
6b 0a 61 25 99 c9 d9 77 f0 ae 84 69 d2 98 20 2b 39 0e 15
key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
key_mic - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
WPA: RX EAPOL-Key - hexdump(len=121): 02 03 00 75 02 00 8a 00 10 00 00
00 00 00 00 00 00 1b fd 33 d4 8c 39 4e 9d a2 44 ca 50 fc 6b 0a 61 25
99 c9 d9 77 f0 ae 84 69 d2 98 20 2b 39 0e 15 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 16 dd 14 00 0f
ac 04 9a a4 94 89 1f c4 24 8c b1 be 85 33 48 23 67 24
wlan0: State: ASSOCIATED -> 4WAY_HANDSHAKE
wlan0: WPA: RX message 1 of 4-Way Handshake from 00:17:df:a6:6b:02 (ver=2)
RSN: msg 1/4 key data - hexdump(len=22): dd 14 00 0f ac 04 9a a4 94 89
1f c4 24 8c b1 be 85 33 48 23 67 24
WPA: PMKID in EAPOL-Key - hexdump(len=22): dd 14 00 0f ac 04 9a a4 94
89 1f c4 24 8c b1 be 85 33 48 23 67 24
RSN: PMKID from Authenticator - hexdump(len=16): 9a a4 94 89 1f c4 24
8c b1 be 85 33 48 23 67 24
wlan0: RSN: no matching PMKID found
Get randomness: len=32 entropy=5
WPA: Renewed SNonce - hexdump(len=32): 33 9c 1d 70 8b 5e d1 a1 dc 75
9f 72 8c 64 8b ad 34 6f aa 13 8a aa 57 0c 6b 9a 55 14 c9 5d 1a e6
WPA: PTK derivation - A1=dc:85:de:03:71:64 A2=00:17:df:a6:6b:02
WPA: Nonce1 - hexdump(len=32): 33 9c 1d 70 8b 5e d1 a1 dc 75 9f 72 8c
64 8b ad 34 6f aa 13 8a aa 57 0c 6b 9a 55 14 c9 5d 1a e6
WPA: Nonce2 - hexdump(len=32): 1b fd 33 d4 8c 39 4e 9d a2 44 ca 50 fc
6b 0a 61 25 99 c9 d9 77 f0 ae 84 69 d2 98 20 2b 39 0e 15
WPA: PMK - hexdump(len=32): [REMOVED]
WPA: PTK - hexdump(len=48): [REMOVED]
WPA: WPA IE for msg 2/4 - hexdump(len=22): 30 14 01 00 00 0f ac 04 01
00 00 0f ac 04 01 00 00 0f ac 02 00 00
WPA: Replay Counter - hexdump(len=8): 00 00 00 00 00 00 00 00
wlan0: WPA: Sending EAPOL-Key 2/4
WPA: KCK - hexdump(len=16): [REMOVED]
WPA: Derived Key MIC - hexdump(len=16): 7d 21 7c 80 99 e8 e7 dd 93 5f
18 e7 49 f8 57 3e
WPA: TX EAPOL-Key - hexdump(len=121): 01 03 00 75 02 01 0a 00 00 00 00
00 00 00 00 00 00 33 9c 1d 70 8b 5e d1 a1 dc 75 9f 72 8c 64 8b ad 34
6f aa 13 8a aa 57 0c 6b 9a 55 14 c9 5d 1a e6 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 7d 21 7c 80 99 e8 e7 dd 93 5f 18 e7 49 f8 57 3e 00 16 30 14 01 00
00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
wlan0: RX EAPOL from 00:17:df:a6:6b:02
RX EAPOL - hexdump(len=155): 02 03 00 97 02 13 ca 00 10 00 00 00 00 00
00 00 01 1b fd 33 d4 8c 39 4e 9d a2 44 ca 50 fc 6b 0a 61 25 99 c9 d9
77 f0 ae 84 69 d2 98 20 2b 39 0e 15 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 62 7b
e7 ac 87 20 8b 83 ca 3a 93 e4 6c 02 1e 32 00 38 dd 3f 58 ec 0c cf 7f
c2 13 b2 9f f3 38 37 2b c7 91 f6 7f 9e f1 6c 11 7d 31 8e 98 ff f8 e8
df 40 73 ed 6e b2 56 f8 e8 21 69 0e 10 3a 40 0f 8e 56 cb 42 af ba df
8f bb 31
wlan0: IEEE 802.1X RX: version=2 type=3 length=151
wlan0: EAPOL-Key type=2
wlan0: key_info 0x13ca (ver=2 keyidx=0 rsvd=0 Pairwise Install Ack
MIC Secure Encr)
wlan0: key_length=16 key_data_length=56
replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 01
key_nonce - hexdump(len=32): 1b fd 33 d4 8c 39 4e 9d a2 44 ca 50 fc
6b 0a 61 25 99 c9 d9 77 f0 ae 84 69 d2 98 20 2b 39 0e 15
key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
key_mic - hexdump(len=16): 62 7b e7 ac 87 20 8b 83 ca 3a 93 e4 6c 02 1e 32
WPA: RX EAPOL-Key - hexdump(len=155): 02 03 00 97 02 13 ca 00 10 00 00
00 00 00 00 00 01 1b fd 33 d4 8c 39 4e 9d a2 44 ca 50 fc 6b 0a 61 25
99 c9 d9 77 f0 ae 84 69 d2 98 20 2b 39 0e 15 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 62 7b e7 ac 87 20 8b 83 ca 3a 93 e4 6c 02 1e 32 00 38 dd 3f 58 ec
0c cf 7f c2 13 b2 9f f3 38 37 2b c7 91 f6 7f 9e f1 6c 11 7d 31 8e 98
ff f8 e8 df 40 73 ed 6e b2 56 f8 e8 21 69 0e 10 3a 40 0f 8e 56 cb 42
af ba df 8f bb 31
RSN: encrypted key data - hexdump(len=56): dd 3f 58 ec 0c cf 7f c2 13
b2 9f f3 38 37 2b c7 91 f6 7f 9e f1 6c 11 7d 31 8e 98 ff f8 e8 df 40
73 ed 6e b2 56 f8 e8 21 69 0e 10 3a 40 0f 8e 56 cb 42 af ba df 8f bb
31
WPA: decrypted EAPOL-Key key data - hexdump(len=48): [REMOVED]
wlan0: State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
wlan0: WPA: RX message 3 of 4-Way Handshake from 00:17:df:a6:6b:02 (ver=2)
WPA: IE KeyData - hexdump(len=48): 30 14 01 00 00 0f ac 04 01 00 00 0f
ac 04 01 00 00 0f ac 02 28 00 dd 16 00 0f ac 01 01 00 5d 1c 33 3c 9d
27 04 af 45 15 93 d3 94 4b 26 c7 dd 00
WPA: RSN IE in EAPOL-Key - hexdump(len=22): 30 14 01 00 00 0f ac 04 01
00 00 0f ac 04 01 00 00 0f ac 02 28 00
WPA: GTK in EAPOL-Key - hexdump(len=24): [REMOVED]
wlan0: WPA: Sending EAPOL-Key 4/4
WPA: KCK - hexdump(len=16): [REMOVED]
WPA: Derived Key MIC - hexdump(len=16): 21 6e f1 0b 8a 63 10 1c cc 0b
45 08 e7 ae 50 67
WPA: TX EAPOL-Key - hexdump(len=99): 01 03 00 5f 02 03 0a 00 00 00 00
00 00 00 00 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 21 6e f1 0b 8a 63 10 1c cc 0b 45 08 e7 ae 50 67 00 00
wlan0: WPA: Installing PTK to the driver
wpa_driver_wext_set_key: alg=3 key_idx=0 set_tx=1 seq_len=6 key_len=16
EAPOL: External notification - portValid=1
wlan0: State: 4WAY_HANDSHAKE -> GROUP_HANDSHAKE
RSN: received GTK in pairwise handshake - hexdump(len=18): [REMOVED]
WPA: Group Key - hexdump(len=16): [REMOVED]
wlan0: WPA: Installing GTK to the driver (keyidx=1 tx=0 len=16)
WPA: RSC - hexdump(len=6): 00 00 00 00 00 00
wpa_driver_wext_set_key: alg=3 key_idx=1 set_tx=0 seq_len=6 key_len=16
wlan0: WPA: Key negotiation completed with 00:17:df:a6:6b:02 [PTK=CCMP GTK=CCMP]
wlan0: Cancelling authentication timeout
wlan0: State: GROUP_HANDSHAKE -> COMPLETED
wlan0: CTRL-EVENT-CONNECTED - Connection to 00:17:df:a6:6b:02
completed (auth) [id=0 id_str=]
wpa_driver_wext_set_operstate: operstate 0->1 (UP)
netlink: Operstate: linkmode=-1, operstate=6
EAPOL: External notification - portValid=1
EAPOL: External notification - EAP success=1
EAPOL: SUPP_PAE entering state AUTHENTICATING
EAPOL: SUPP_BE entering state SUCCESS
EAP: EAP entering state DISABLED
EAPOL: SUPP_PAE entering state AUTHENTICATED
EAPOL: Supplicant port status: Authorized
EAPOL: SUPP_BE entering state IDLE
EAPOL authentication completed successfully
RTM_NEWLINK: operstate=1 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
WEXT: if_removed already cleared - ignore event
EAPOL: startWhen --> 0
EAPOL: disable timer tick
wlan0: BSS: Expire BSS 1 due to age
wlan0: BSS: Remove id 1 BSSID 00:21:d8:48:da:72 SSID 'ghosty'
wlan0: BSS: Expire BSS 2 due to age
wlan0: BSS: Remove id 2 BSSID c0:c1:c0:d7:43:d4 SSID 'Wolkenhauer'
wlan0: BSS: Expire BSS 3 due to age
wlan0: BSS: Remove id 3 BSSID c0:c1:c0:d7:43:d6 SSID 'Wolkenhauer-guest'
wlan0: CTRL-EVENT-TERMINATING - signal 2 received
wlan0: Removing interface wlan0
wpa_driver_wext_deauthenticate
wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=1 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=2 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=3 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
wlan0: State: COMPLETED -> DISCONNECTED
wpa_driver_wext_set_operstate: operstate 1->0 (DORMANT)
netlink: Operstate: linkmode=-1, operstate=5
EAPOL: External notification - portEnabled=0
EAPOL: SUPP_PAE entering state DISCONNECTED
EAPOL: Supplicant port status: Unauthorized
EAPOL: SUPP_BE entering state INITIALIZE
EAPOL: Supplicant port status: Unauthorized
EAPOL: External notification - portValid=0
EAPOL: Supplicant port status: Unauthorized
EAPOL: External notification - EAP success=0
EAPOL: Supplicant port status: Unauthorized
wpa_driver_wext_set_countermeasures
wlan0: No keys have been configured - skip key clearing
wlan0: BSS: Remove id 0 BSSID 00:17:df:a6:6b:02 SSID 'ghosty'
wlan0: Cancelling scan request
wlan0: Cancelling authentication timeout
netlink: Operstate: linkmode=0, operstate=6
***************************

alex.pujols 11-12-2012 10:09 AM

quick correction... the "lsusb" output is actually "lspci". Sorry for the mislabel

alex.pujols 11-12-2012 10:37 AM

further troubleshooting has revealed...

(1) When I drop wpa_supplicant and associate to an open network (no WPA, no WEP) the network speeds go from about 50/sec to around 256k/sec

** note that other netbooks on the same network are getting 24m UP & 2.5m down on this network


All times are GMT -5. The time now is 11:32 PM.