iprowifi4965: has trouble connecting when not using -ht workaround

[pulkomandy]

device Network controller [2|80|0]
  vendor 8086: Intel Corporation
  device 008a: Centrino Wireless-N 1030 [Rainbow Peak]

1) I have an annoying log that prevents me from getting an useful syslog:

KERN: [net/iprowifi4965/0] [24:95:04:01:fb:5c] AMRR: current rate 7, txcnt=11, retrycnt=0

2) Whenever I boot my system, I need 2-5 tries of entering the password in wpa_supplicant before I get to connect successfully. When using ifconfig -ht it always works on first try (same AP).

[waddlesplash]

The annoying log should be gone with hrev52207.

For HT mode: In the ieee80211_sysctl_vattach function I modified in that commit, please add | IEEE80211_MSG_11N, rebuild the driver, and attach a syslog from using it.

[pulkomandy]

with hrev52211 it connected immediately without any problems. Will keep an eye on it.

[pulkomandy]

Relevant part of syslog, but there was no connection problem this time:

KERN: register_domain(4, link)
KERN: wlan_control: 9234, 105
KERN: [net/iprowifi4965/0] ieee80211_init
KERN: [net/iprowifi4965/0] start running, 1 vaps running
KERN: [net/iprowifi4965/0] ieee80211_new_state_locked: SCAN -> SCAN (nrunning 0 nscanning 0)
KERN: [net/iprowifi4965/0] ieee80211_newstate_cb: SCAN -> SCAN arg 0
KERN: [net/iprowifi4965/0] sta_newstate: SCAN -> SCAN (0)
KERN: ieee80211_notify_scan_done
KERN: wlan_control: 9235, 15
KERN: wlan_control: 9235, 76
KERN: Last message repeated 6 times.
KERN: wlan_control: 9235, 78
KERN: wlan_control: 9235, 76
KERN: register_domain(9, unix)
KERN: wlan_close(0x829f0800)
KERN: [net/iprowifi4965/0] stop running, 1 vaps running
KERN: [net/iprowifi4965/0] ieee80211_new_state_locked: SCAN -> INIT (nrunning 0 nscanning 0)
KERN: [net/iprowifi4965/0] down parent 
KERN: [net/iprowifi4965/0] ieee80211_newstate_cb: SCAN -> INIT arg -1
KERN: [net/iprowifi4965/0] sta_newstate: SCAN -> INIT (-1)
KERN: [net/iprowifi4965/0] node_reclaim: remove 0xd2582000<ac:72:89:c4:f4:d2> from station table, refcnt 1
KERN: [net/iprowifi4965/0] ieee80211_alloc_node 0xd20c0000<ac:72:89:c4:f4:d2> in station table
KERN: [net/iprowifi4965/0] [ac:72:89:c4:f4:d2] ieee80211_alloc_node: inact_reload 2
KERN: wlan_control: 9235, 16
KERN: wlan_control: 9235, 17
KERN: wlan_control: 9235, 26
KERN: wlan_control: 9235, 98
KERN: wlan_control: 9234, 20
KERN: Last message repeated 3 times.
KERN: wlan_control: 9234, 25
KERN: ifmedia_ioctl: switching wlan to   Type: IEEE 802.11 Wireless Ethernet
KERN:   Mode: autoselect
KERN:   SubType: autoselect
KERN: wlan_control: 9234, 16
KERN: wlan_control: 9234, 17
KERN: wlan_control: 9234, 26
KERN: wlan_open(0x829f0800)
KERN: [net/iprowifi4965/0] ieee80211_init
KERN: [net/iprowifi4965/0] start running, 0 vaps running
KERN: [net/iprowifi4965/0] ieee80211_start_locked: up parent 
KERN: [net/iprowifi4965/0] start running, 1 vaps running
KERN: wlan_control: 9234, 103
KERN: [net/iprowifi4965/0] ieee80211_new_state_locked: INIT -> SCAN (nrunning 0 nscanning 0)
KERN: [iprowifi4965] (iwn) iwn_read_firmware: ucode rev=0x12a80601
KERN: [net/iprowifi4965/0] start running, 1 vaps running
KERN: [net/iprowifi4965/0] ieee80211_newstate_cb: INIT -> SCAN arg 0
KERN: [net/iprowifi4965/0] sta_newstate: INIT -> SCAN (0)
KERN: [net/iprowifi4965/0] ieee80211_add_htcap_body: advertised rxmax=0, density=0, vap rxmax=0, density=0
KERN: Last message repeated 12 times.
KERN: ieee80211_notify_scan_done
KERN: wlan_control: 9235, 76
KERN: ifmedia_ioctl: switching wlan to   Type: IEEE 802.11 Wireless Ethernet
KERN:   Mode: autoselect
KERN:   SubType: autoselect
KERN: wlan_control: 9234, 18
KERN: wlan_control: 9234, 7
KERN: wlan_control: 9234, 95
KERN: wlan_control: 9234, 17
KERN: wlan_control: 9234, 26
KERN: wlan_control: 9234, 21
KERN: [net/iprowifi4965/0] [24:95:04:01:fb:5c] station assoc via MLME
KERN: [net/iprowifi4965/0] ieee80211_alloc_node 0xd2332000<24:95:04:01:fb:5c> in station table
KERN: [net/iprowifi4965/0] [24:95:04:01:fb:5c] ieee80211_alloc_node: inact_reload 2
KERN: [net/iprowifi4965/0] node_reclaim: remove 0xd20c0000<ac:72:89:c4:f4:d2> from station table, refcnt 0
KERN: [net/iprowifi4965/0] set WME_AC_BE (chan) [acm 0 aifsn 3 logcwmin 4 logcwmax 10 txop 0]
KERN: [net/iprowifi4965/0] set WME_AC_BE (bss ) [acm 0 aifsn 3 logcwmin 4 logcwmax 10 txop 0]
KERN: [net/iprowifi4965/0] set WME_AC_BK (chan) [acm 0 aifsn 7 logcwmin 4 logcwmax 10 txop 0]
KERN: [net/iprowifi4965/0] set WME_AC_BK (bss ) [acm 0 aifsn 7 logcwmin 4 logcwmax 10 txop 0]
KERN: [net/iprowifi4965/0] set WME_AC_VI (chan) [acm 0 aifsn 2 logcwmin 3 logcwmax 4 txop 94]
KERN: [net/iprowifi4965/0] set WME_AC_VI (bss ) [acm 0 aifsn 2 logcwmin 3 logcwmax 4 txop 94]
KERN: [net/iprowifi4965/0] set WME_AC_VO (chan) [acm 0 aifsn 2 logcwmin 2 logcwmax 3 txop 47]
KERN: [net/iprowifi4965/0] set WME_AC_VO (bss ) [acm 0 aifsn 2 logcwmin 2 logcwmax 3 txop 47]
KERN: [net/iprowifi4965/0] update WME_AC_BE (chan+bss) [acm 0 aifsn 2 logcwmin 4 logcwmax 10 txop 0]
KERN: [net/iprowifi4965/0] ieee80211_wme_updateparams_locked: WME params updated, cap_info 0x0
KERN: [net/iprowifi4965/0] ieee80211_new_state_locked: SCAN -> AUTH (nrunning 0 nscanning 0)
KERN: [net/iprowifi4965/0] ieee80211_newstate_cb: SCAN -> AUTH arg 192
KERN: [net/iprowifi4965/0] sta_newstate: SCAN -> AUTH (192)
KERN: [net/iprowifi4965/0] ieee80211_ref_node (ieee80211_send_mgmt:2245) 0xd2332000<24:95:04:01:fb:5c> refcnt 3
KERN: [net/iprowifi4965/0] [24:95:04:01:fb:5c] recv auth frame with algorithm 0 seq 2
KERN: [net/iprowifi4965/0] ieee80211_new_state_locked: AUTH -> ASSOC (nrunning 0 nscanning 0)
KERN: [net/iprowifi4965/0] ieee80211_newstate_cb: AUTH -> ASSOC arg 0
KERN: [net/iprowifi4965/0] sta_newstate: AUTH -> ASSOC (0)
KERN: [net/iprowifi4965/0] ieee80211_ref_node (ieee80211_send_mgmt:2245) 0xd2332000<24:95:04:01:fb:5c> refcnt 3
KERN: [net/iprowifi4965/0] ieee80211_wme_updateparams_locked: WME params updated, cap_info 0x0
KERN: [net/iprowifi4965/0] [24:95:04:01:fb:5c] assoc success at aid 2: long preamble, short slot time, QoS
KERN: [net/iprowifi4965/0] ieee80211_new_state_locked: ASSOC -> RUN (nrunning 0 nscanning 0)
KERN: [net/iprowifi4965/0] ieee80211_newstate_cb: ASSOC -> RUN arg 16
KERN: [net/iprowifi4965/0] sta_newstate: ASSOC -> RUN (16)
KERN: ieee80211_notify_node_join
KERN: /dev/net/iprowifi4965/0: media change, media 0x8300af quality 1000 speed 10000000
KERN: [net/iprowifi4965/0] [24:95:04:01:fb:5c] ieee80211_node_authorize: inact_reload 20
KERN: wlan_control: 9235, 15
DAEMON 'DHCP': /dev/net/iprowifi4965/0: Send DHCP_DISCOVER to 255.255.255.255:67

[waddlesplash]

wpa_supplicant's debug output is often more relevant, especially when the connection dialog appears multiple times. Try to get that next time (kill wpa_supplicant and restart it in a Terminal window, for now.)

[humdinger]

Find attached the Terminal output from wpa_supplicant (failing-wpa-output.txt). It threw up the password dialog twice, but never actually connected. NetworkStatus kept showing "Configuring".
I replaced my router's MAC with ::::: and the MAC of neighbouring routers with ++.++.++.++.++.++. Hope there's not too much sensitive info still left in the log... :)

[humdinger]

failing to connect, showing wpa dialog twice

[humdinger]

Also attached, the wpa_supplicant's Terminal output of a successful connect (success-wpa-output.txt).
The wpa_supplicant dialog popped up only once, with encryption "Open" and empty password field. I just cancelled and after a very short configuration period, the connection was established and status "Ready".

[humdinger]

successful connection

[waddlesplash]

Please retest after hrev52730.

[waddlesplash]

PulkoMandy reports that he considers this fixed.

[nielx]

Assign tickets with status=closed and resolution=fixed within the R1/beta2 development window to the R1/beta2 Milestone