There is a regression introduced with this patch.
On my ath9k AP + ath9k STA I get timeout for
management frames even when they are acked.
Attached syslog and iw event before and after
this patch.
I have seen it before in my testing and it gets
a lot worse with system load. Sometimes it can
retry auth/assoc frames for 10 seconds before
connecting.
Anyway it always looses the first authentication frame.
Wojtek
On 02/04/2013 04:43 PM, Johannes Berg wrote:
On Thu, 2013-01-31 at 14:28 +0100, Johannes Berg wrote:
From: Johannes Berg <johannes.berg@xxxxxxxxx>
When sending authentication/association frames they
might take a bit of time to go out because we may
have to synchronise with the AP, in particular in
the case where it's really a P2P GO. In this case
the 200ms fixed timeout could potentially be too
short if the beacon interval is relatively large.
For drivers that report TX status we can do better.
Instead of starting the timeout directly, start it
only when the frame status arrives. Since then the
frame was out on the air, we can wait shorter (the
typical response time is supposed to be 30ms, wait
100ms.) Also, if the frame failed to be transmitted
try again right away instead of waiting.
Applied.
johannes
--
To unsubscribe from this list: send the line "unsubscribe linux-wireless" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
[before commit mac80211: start auth/assoc timeout on frame status]
*syslog*
Feb 13 14:33:33 wlanTS kernel: [ 5486.324069] device wlan1 entered promiscuous mode
Feb 13 14:33:33 wlanTS kernel: [ 5486.335067] IPv6: ADDRCONF(NETDEV_UP): wlan1: link is not ready
Feb 13 14:33:33 wlanTS kernel: [ 5486.346850] IPv6: ADDRCONF(NETDEV_CHANGE): wlan1: link becomes ready
Feb 13 14:33:33 wlanTS kernel: [ 5486.346869] wlan_br: port 1(wlan1) entered forwarding state
Feb 13 14:33:33 wlanTS kernel: [ 5486.346871] wlan_br: port 1(wlan1) entered forwarding state
Feb 13 14:33:38 wlanTS kernel: [ 5491.355402] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
Feb 13 14:33:41 wlanTS kernel: [ 5494.074674] wlan0: authenticate with 04:f0:21:02:46:46
Feb 13 14:33:41 wlanTS kernel: [ 5494.077644] wlan0: send auth to 04:f0:21:02:46:46 (try 1/3)
Feb 13 14:33:41 wlanTS hostapd: wlan1: STA 04:f0:21:02:46:45 IEEE 802.11: authenticated
Feb 13 14:33:41 wlanTS kernel: [ 5494.099724] wlan0: authenticated
Feb 13 14:33:41 wlanTS kernel: [ 5494.100285] ath9k 0000:01:00.0 wlan0: disabling HT as WMM/QoS is not supported by the AP
Feb 13 14:33:41 wlanTS kernel: [ 5494.100290] ath9k 0000:01:00.0 wlan0: disabling VHT as WMM/QoS is not supported by the AP
Feb 13 14:33:41 wlanTS hostapd: wlan1: STA 04:f0:21:02:46:45 IEEE 802.11: associated (aid 1)
Feb 13 14:33:41 wlanTS kernel: [ 5494.104142] wlan0: associate with 04:f0:21:02:46:46 (try 1/3)
Feb 13 14:33:41 wlanTS kernel: [ 5494.107731] wlan0: RX AssocResp from 04:f0:21:02:46:46 (capab=0x11 status=0 aid=1)
Feb 13 14:33:41 wlanTS kernel: [ 5494.107800] wlan0: associated
Feb 13 14:33:41 wlanTS kernel: [ 5494.109144] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
Feb 13 14:33:41 wlanTS kernel: [ 5494.115996] wlan0: dropped frame to 04:f0:21:02:46:46 (unauthorized port)
Feb 13 14:33:41 wlanTS hostapd: wlan1: STA 04:f0:21:02:46:45 RADIUS: starting accounting session 511B962D-00000000
Feb 13 14:33:41 wlanTS hostapd: wlan1: STA 04:f0:21:02:46:45 WPA: pairwise key handshake completed (RSN)
Feb 13 14:33:48 wlanTS kernel: [ 5501.372049] wlan_br: port 1(wlan1) entered forwarding state
*iw event*
1360762419.008893: wlan0 (phy #0): scan started
1360762421.616111: wlan0 (phy #0): scan finished: 2412 2417 2422 2427 2432 2437 2442 2447 2452 2457 2462 5180 5200 5220 5240 5260 5280 5300 5320 5500 5520 5540 5560 5580 5660 5680 5700 5745 5765 5785 5805 5825, ""
1360762421.618919: wlan0: new station 04:f0:21:02:46:46
1360762421.640630: wlan1 (phy #1): mgmt TX status (cookie ffff8801fe4ca100): acked
1360762421.641175: wlan0 (phy #0): auth 04:f0:21:02:46:46 -> 04:f0:21:02:46:45 status: 0: Successful [frame: b0 00 2c 00 04 f0 21 02 46 45 04 f0 21 02 46 46 04 f0 21 02 46 46 f0 0b 00 00 02 00 00 00]
1360762421.646460: wlan1 (phy #1): mgmt TX status (cookie ffff8801c40fe900): acked
1360762421.648709: wlan1: new station 04:f0:21:02:46:45
1360762421.649241: wlan0 (phy #0): assoc 04:f0:21:02:46:46 -> 04:f0:21:02:46:45 status: 0: Successful [frame: 10 00 2c 00 04 f0 21 02 46 45 04 f0 21 02 46 46 04 f0 21 02 46 46 00 0c 11 00 00 00 01 c0 01 02 b0 c8]
1360762421.650437: wlan0 (phy #0): connected to 04:f0:21:02:46:46
[after commit mac80211: start auth/assoc timeout on frame status]
*syslog*
Feb 13 14:38:53 wlanTS kernel: [ 5805.902369] device wlan1 entered promiscuous mode
Feb 13 14:38:53 wlanTS kernel: [ 5805.906908] IPv6: ADDRCONF(NETDEV_UP): wlan1: link is not ready
Feb 13 14:38:53 wlanTS kernel: [ 5805.918510] IPv6: ADDRCONF(NETDEV_CHANGE): wlan1: link becomes ready
Feb 13 14:38:53 wlanTS kernel: [ 5805.918527] wlan_br: port 1(wlan1) entered forwarding state
Feb 13 14:38:53 wlanTS kernel: [ 5805.918529] wlan_br: port 1(wlan1) entered forwarding state
Feb 13 14:39:01 wlanTS kernel: [ 5813.686051] wlan0: authenticate with 04:f0:21:02:46:46
Feb 13 14:39:01 wlanTS hostapd: wlan1: STA 04:f0:21:02:46:45 IEEE 802.11: authenticated
Feb 13 14:39:01 wlanTS hostapd: wlan1: STA 04:f0:21:02:46:45 IEEE 802.11: authenticated
Feb 13 14:39:01 wlanTS kernel: [ 5813.690956] wlan0: send auth to 04:f0:21:02:46:46 (try 1/3)
Feb 13 14:39:01 wlanTS kernel: [ 5813.691059] wlan0: send auth to 04:f0:21:02:46:46 (try 2/3)
Feb 13 14:39:01 wlanTS kernel: [ 5813.692707] wlan0: authenticated
Feb 13 14:39:01 wlanTS kernel: [ 5813.694673] ath9k 0000:01:00.0 wlan0: disabling HT as WMM/QoS is not supported by the AP
Feb 13 14:39:01 wlanTS kernel: [ 5813.694674] ath9k 0000:01:00.0 wlan0: disabling VHT as WMM/QoS is not supported by the AP
Feb 13 14:39:01 wlanTS hostapd: wlan1: STA 04:f0:21:02:46:45 IEEE 802.11: associated (aid 1)
Feb 13 14:39:01 wlanTS kernel: [ 5813.698424] wlan0: associate with 04:f0:21:02:46:46 (try 1/3)
Feb 13 14:39:01 wlanTS kernel: [ 5813.701154] wlan0: RX AssocResp from 04:f0:21:02:46:46 (capab=0x11 status=0 aid=1)
Feb 13 14:39:01 wlanTS kernel: [ 5813.701187] wlan0: associated
Feb 13 14:39:01 wlanTS kernel: [ 5813.701288] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
Feb 13 14:39:01 wlanTS hostapd: wlan1: STA 04:f0:21:02:46:45 RADIUS: starting accounting session 511B976D-00000000
Feb 13 14:39:01 wlanTS hostapd: wlan1: STA 04:f0:21:02:46:45 WPA: pairwise key handshake completed (RSN)
*iw event*
1360762738.615338: wlan0 (phy #0): scan started
1360762741.224528: wlan0 (phy #0): scan finished: 2412 2417 2422 2427 2432 2437 2442 2447 2452 2457 2462 5180 5200 5220 5240 5260 5280 5300 5320 5500 5520 5540 5560 5580 5660 5680 5700 5745 5765 5785 5805 5825, ""
1360762741.229969: wlan0: new station 04:f0:21:02:46:46
1360762741.231382: wlan1 (phy #1): mgmt TX status (cookie ffff880202b3e500): acked
1360762741.231407: wlan1 (phy #1): mgmt TX status (cookie ffff880202b3e600): acked
1360762741.231898: wlan0 (phy #0): auth 04:f0:21:02:46:46 -> 04:f0:21:02:46:45 status: 0: Successful [frame: b0 00 2c 00 04 f0 21 02 46 45 04 f0 21 02 46 46 04 f0 21 02 46 46 f0 0b 00 00 02 00 00 00]
1360762741.238314: wlan1 (phy #1): mgmt TX status (cookie ffff880202b3e300): acked
1360762741.240121: wlan1: new station 04:f0:21:02:46:45
1360762741.240280: wlan0 (phy #0): assoc 04:f0:21:02:46:46 -> 04:f0:21:02:46:45 status: 0: Successful [frame: 10 00 2c 00 04 f0 21 02 46 45 04 f0 21 02 46 46 04 f0 21 02 46 46 20 0c 11 00 00 00 01 c0 01 02 b0 c8]
1360762741.240326: wlan0 (phy #0): connected to 04:f0:21:02:46:46
