Bug 16691 - IPW5100: iwlagn broken with 2.6.34.x to 2.6.35.2 update
Summary: IPW5100: iwlagn broken with 2.6.34.x to 2.6.35.2 update
Status: CLOSED CODE_FIX
Alias: None
Product: Drivers
Classification: Unclassified
Component: network-wireless (show other bugs)
Hardware: All Linux
: P1 high
Assignee: drivers_network-wireless@kernel-bugs.osdl.org
URL:
Keywords:
: 16551 (view as bug list)
Depends on:
Blocks: 16055
  Show dependency tree
 
Reported: 2010-08-21 08:28 UTC by Can Celasun
Modified: 2011-06-20 09:59 UTC (History)
39 users (show)

See Also:
Kernel Version: 2.6.35.2
Subsystem:
Regression: Yes
Bisected commit-id:


Attachments
iwlagn errors from kernel.log (344.22 KB, text/plain)
2010-08-21 08:28 UTC, Can Celasun
Details
slow internet trace (12.72 KB, text/plain)
2010-11-27 13:55 UTC, alphazo
Details
Another slow internet trace (6.69 KB, text/plain)
2010-11-27 13:56 UTC, alphazo
Details
remove low ack count check for 5x00 (900 bytes, patch)
2010-11-29 16:35 UTC, wey-yi.w.guy
Details | Diff
After low-ack-count patch (3.18 KB, text/plain)
2010-11-29 21:10 UTC, alphazo
Details
extend the stuck queue timeout for tx queue (1.64 KB, patch)
2010-11-30 16:27 UTC, wey-yi.w.guy
Details | Diff
dmesg output (124.11 KB, text/plain)
2010-12-16 06:08 UTC, h.habighorst
Details
work around for slow tpt (2.65 KB, patch)
2011-01-03 14:57 UTC, wey-yi.w.guy
Details | Diff
work around for 6000 low tpt (2.08 KB, patch)
2011-01-03 16:22 UTC, wey-yi.w.guy
Details | Diff
kernel configuration to support compat-wireless modules for Intel wireless cards (618 bytes, application/octet-stream)
2011-01-04 01:18 UTC, Pradeep Kulkarni
Details
Kernel log for intel 5300 packetloss problem (108.51 KB, application/x-gzip)
2011-01-24 23:31 UTC, Nikolay Martynov
Details
Ping log for intel 5300 packetloss problem (1.10 KB, application/x-gzip)
2011-01-24 23:33 UTC, Nikolay Martynov
Details
Log when no packets are passing (3.29 KB, application/x-gzip)
2011-01-28 03:11 UTC, Nikolay Martynov
Details
remove low ack count for 5000 (900 bytes, patch)
2011-02-09 20:33 UTC, wey-yi.w.guy
Details | Diff
extract from kern.log for 4965 (1.48 KB, application/octet-stream)
2011-03-23 10:01 UTC, Arnaud Launay
Details
0001-iwl4965-fix-Received-BA-when-not-expected.patch (2.19 KB, text/plain)
2011-04-21 13:48 UTC, Stanislaw Gruszka
Details
0002-iwlagn-fix-Received-BA-when-not-expected.patch (2.16 KB, text/plain)
2011-04-21 13:51 UTC, Stanislaw Gruszka
Details
revert_sta_id_chages.patch (29.41 KB, text/plain)
2011-04-22 11:55 UTC, Stanislaw Gruszka
Details

Description Can Celasun 2010-08-21 08:28:17 UTC
Created attachment 27571 [details]
iwlagn errors from kernel.log

When using 2.6.35.2 my wireless connects to the AP on channel 1 (2.412 GHz) but drops the connection in roughly every 5 minutes, then auto-reconnects.

dmesg is flooded with:

iwlagn 0000:04:00.0: BA scd_flow 0 does not match txq_id 10

Relevant kernel log is attached. Using Archlinux and NetworkManager.
Comment 1 Andrew Morton 2010-08-24 23:25:54 UTC
It's a regression.  Which kernel version was OK?  2.6.34?

Thanks.
Comment 2 Can Celasun 2010-08-25 06:16:32 UTC
Yes, 2.6.34 was OK.
Comment 3 redskolnikow 2010-08-25 11:29:37 UTC
The same for me.
Arch Linux 2.6.35.2.

Now using 2.6.34 everything is OK.
Comment 4 Daniel Svensson 2010-08-25 12:16:42 UTC
This also affects:
Intel Corporation Ultimate N WiFi Link 5300
Comment 5 wey-yi.w.guy 2010-08-25 14:07:56 UTC
Yes, it is an known issue and we are woking on it.

Thanks
Wey
Comment 6 John W. Linville 2010-08-25 14:12:36 UTC
*** Bug 16551 has been marked as a duplicate of this bug. ***
Comment 7 Denis 2010-08-26 17:34:16 UTC
Also having speed drops with 5100AGN card with error mentioned here.
Please post here what to echo into /sys/class/net/wlan0/device/debug_level
for further testing.
Comment 8 Can Celasun 2010-09-03 14:06:58 UTC
Should we expect a fix in a 2.6.35 point release or would 2.6.36 be more realistic?
Comment 9 wey-yi.w.guy 2010-09-03 15:21:23 UTC
(In reply to comment #8)
> Should we expect a fix in a 2.6.35 point release or would 2.6.36 be more
> realistic?

Based on what we found, the real fix is in uCode.

Wey
Comment 10 Can Celasun 2010-09-03 19:06:54 UTC
(In reply to comment #9)
> (In reply to comment #8)
> > Should we expect a fix in a 2.6.35 point release or would 2.6.36 be more
> > realistic?
> 
> Based on what we found, the real fix is in uCode.
> 
> Wey

So, does that mean an older firmware should work with 2.6.35?
Comment 11 wey-yi.w.guy 2010-09-03 19:48:08 UTC
it mean we need to release new firmware to fix this problem; the older firmware having this issue.

Wey
Comment 12 Florian Mickler 2010-09-06 07:30:23 UTC
Is there a in-kernel workaround for old firmware possible?
Comment 13 Can Celasun 2010-09-10 08:55:28 UTC
(In reply to comment #12)
> Is there a in-kernel workaround for old firmware possible?
I'd also appreciate an answer to this. A workaround would enable those who are affected to be able to use 2.6.35.x with the old firmware.
Comment 14 wey-yi.w.guy 2010-09-11 14:58:13 UTC
the best w/a I can think about is disable 11n (if it is ok for you)

$modprobe iwlagn 11n_disable=1

Thanks
Wey
Comment 15 Denis 2010-09-11 16:24:50 UTC
dmesg spits out:
iwlcore: Unknown parameter `11n_disable'
Comment 16 wey-yi.w.guy 2010-09-11 16:47:40 UTC
please check what module parameter are available for you

$mofinfo iwlagn

then use the one which allow you to disable 11n functionality

Thanks
Wey
Comment 17 Florian Mickler 2010-09-11 16:57:59 UTC
you mean(In reply to comment #16)
> please check what module parameter are available for you
> 
> $mofinfo iwlagn

$modinfo iwlagn

> 
> then use the one which allow you to disable 11n functionality
> 
> Thanks
> Wey

The correct module parameter is probably "disable_11n"  (not 11n_disable as suggested)

Cheers,
Flo
Comment 18 wey-yi.w.guy 2010-09-11 17:19:27 UTC
thanks, can not remember correctly on top of my head :-)

Wey
Comment 19 Can Celasun 2010-09-11 17:28:34 UTC
Using IPW5100, the parameter name is 11n_disable.
Comment 20 Florian Mickler 2010-09-22 17:17:16 UTC
Wey, 

should this be closed as wont fix then, or do you plan on providing some sort of quirk for affected hw/fw combinations?
Comment 21 h.habighorst 2010-09-22 20:15:52 UTC
I am not a developer. However, if disabling 11n is the only option and this bug is closed as won't fix, I am really disappointed.

Do you need more information?! Is there any possibility to help?

Closing this bug with won't fix and no solution basically means you'll leave all the users of affected hardware without having 11n support which is in my opinion... worst case. 

Would be nice to have an update in a short time -.- As I then need to buy another WLAN card for my laptop due to the driver being unusable.
Comment 22 wey-yi.w.guy 2010-09-22 20:20:02 UTC
I don't want to close this bug and we are very active working on this and we believe we already have a solution for it. We are in the process of figure out how to deliver the experimental version of uCode for user to test it out.

Thanks
Wey
Comment 23 Denis 2010-09-22 20:25:37 UTC
(In reply to comment #22)
> I don't want to close this bug and we are very active working on this and we
> believe we already have a solution for it. We are in the process of figure
> out
> how to deliver the experimental version of uCode for user to test it out.
> 
> Thanks
> Wey

Really? How about posting the patched ucode right here?
Heck. Push to an intel server of your choice and put a link to it here.
Just give the power users (checking this bug aren't they?) here a solution.
Comment 24 John W. Linville 2010-09-27 15:15:55 UTC
Wey, any estimate on when this new uCode will be available?
Comment 25 alphazo 2010-10-04 20:52:19 UTC
I see that there is a new linux-firmware 20100911 out there. Is it supposed to fix the problem?
Comment 26 wey-yi.w.guy 2010-10-06 19:30:07 UTC
John,

I am planning to release the experimental uCode soon (could be as early as next week), but it is experimental uCode, so it is not offical supported.

Wey
Comment 27 Florian Mickler 2010-10-09 14:31:33 UTC
References: http://www.spinics.net/lists/linux-wireless/msg57237.html

Following announcement just flew by on the intel wireless
mailinglist:

On Fri, 08 Oct 2010 16:39:22 -0700
"Guy, Wey-Yi" <wey-yi.w.guy@intel.com> wrote:

> Hi,
>  
> Experimental version 41.22.5.1 of uCode for Intel® 6050 Series Wi-Fi
> Adapters is now available for download from
> http://intellinuxwireless.org/?n=Downloads
> 
> 
> Experimental uCode is the WiFi uCode released by the Intel uCode team
> with the latest bug fixes to address issues being reported by external
> parties. The Experimental uCode has not gone through the full regression
> test procedures, and the goal is to address the issue(s) that can’t be
> easily reproduced within the internal testing environment.
>  
> Wey
>
Comment 28 Jelle Foks 2010-10-11 19:16:14 UTC
This intel 6050 series ucode does not apply to my intel wifi ipw5100 card with which I'm experiencing the problem. The driver on my system is requesting 'iwlwifi-5000-?.ucode', which is not in the tgz referred to above.

Intel Corporation WiFi Link 5100 05:00.0 0280: 8086:4232 Subsystem: 8086:1301
 
So, my test results are that this doesn't fix the problem...
Comment 29 Kevin DeKorte 2010-10-20 17:44:28 UTC
I have a iwlagn 5100 [Shiloh] wireless card with kernel 2.6.34.7 the card works great and is quite fast. With kernels 2.6.36.rc6 thru 2.6.36.rc8.git0 the wireless is much slower (11Mbps when connected to a 802.11n router) and drops on a regular basis. I am testing now with 2.6.36.rc8.git5, but I didn't see any patches in there that should affect it. I have tried the 11n_disable option to the iwlagn driver, but it didn't seem to make that much of a difference.
Comment 30 wey-yi.w.guy 2010-10-20 17:48:50 UTC
the experimental uCode being release is for 6050 series devices, it will not work for 5000 series devices. We are in the process of release the experimental uCode for 5000 series.

Kevin, did you see any error msg in your syslog file?

Thanks
Wey
Comment 31 Kevin DeKorte 2010-10-20 17:55:08 UTC
Wey,

No, I do not see any errors in dmesg or /var/log/messages
Comment 32 Kevin DeKorte 2010-10-20 19:04:56 UTC
after running the 2.6.36.rc8.git5 kernel it seems more stable, but I will keep testing. And then I will retest with 11n_disable.
Comment 33 wey-yi.w.guy 2010-10-20 19:08:20 UTC
Hi Kevin,

Thankyou very much, please do let me know, we need to get this unstable problem fixed asap.

Thanks
Wey
Comment 34 Kevin DeKorte 2010-10-20 21:01:44 UTC
Wey,

2.6.36.rc8.git5 seems ok, I haven't had any drops since I installed it. Perhaps it was related to power management or the hrtimer? But I would still like to see if updated uCode for the 5100 helps at all.
Comment 35 wey-yi.w.guy 2010-10-20 21:43:32 UTC
Great news (at least some what great :-)), 2.6.36.rc8 is much better. Please do let me know if you see the problrm again. Yes, Power Management is one of the possibility, are you in PSP mode when the problem occur before?

Thank you very much for the help.

Thanks
Wey
Comment 36 Christophe Dumez 2010-10-21 18:51:54 UTC
Hi, with kernel v2.6.36 final, the problem is still there:
[  141.903238] iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
[  146.879404] iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 68:7f:74:9b:3f:50 tid = 0
[  272.603070] iwlagn 0000:02:00.0: Received BA when not expected
[  272.724305] iwlagn 0000:02:00.0: Received BA when not expected
[  278.233800] iwlagn 0000:02:00.0: Received BA when not expected
[  294.167771] iwlagn 0000:02:00.0: Received BA when not expected
[  301.563828] iwlagn 0000:02:00.0: Received BA when not expected
[  453.251667] iwlagn 0000:02:00.0: Received BA when not expected
[  461.617478] iwlagn 0000:02:00.0: queue 10 stuck 3 time. Fw reload.
[  479.035088] hda-intel: IRQ timing workaround is activated for card #0. Suggest a bigger bdl_pos_adj.
[  588.292792] iwlagn 0000:02:00.0: Received BA when not expected

My card is an Intel Corporation Centrino Ultimate-N 6300 (rev 35). I cannot test the new uCode because it is not available for my card.
Comment 37 wey-yi.w.guy 2010-10-21 19:31:51 UTC
Hi Chris,

what uCode version you are using? is iwlwifi-6000-ucode.9.222.4.1, or something older

Thanks
Wey
Comment 38 Christophe Dumez 2010-10-21 20:35:36 UTC
Yes, I'm using the latest available from the Website:
iwlwifi-6000-ucode-9.221.4.1

I double-checked with the checksum to be sure.
Comment 39 wey-yi.w.guy 2010-10-21 22:07:44 UTC
Did you see any performance degrading besie the "
Received BA when not expected" message?

Thanks
Wey
Comment 40 alphazo 2010-11-17 22:12:34 UTC
Hi Wey,

I use 9.221.4.1 build 25532 on my 6000 card and few minutes after enabling it I experienced some firmware reloads due to some errrors.


iwlagn: Copyright(c) 2003-2010 Intel Corporation
iwlagn 0000:02:00.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
iwlagn 0000:02:00.0: setting latency timer to 64
iwlagn 0000:02:00.0: Detected Intel(R) Centrino(R) Ultimate-N 6300 AGN, REV=0x74
iwlagn 0000:02:00.0: device EEPROM VER=0x436, CALIB=0x6
iwlagn 0000:02:00.0: Tunable channels: 13 802.11bg, 24 802.11a channels
iwlagn 0000:02:00.0: irq 46 for MSI/MSI-X
iwlagn 0000:02:00.0: loaded firmware version 9.221.4.1 build 25532
phy4: ffff88012f2efce0
wlan0: authenticate with 00:30:bd:9d:fe:4a (try 1)
wlan0: authenticated
wlan0: associate with 00:30:bd:9d:fe:4a (try 1)
wlan0: associate with 00:30:bd:9d:fe:4a (try 2)
wlan0: RX AssocResp from 00:30:bd:9d:fe:4a (capab=0x431 status=0 aid=5)
wlan0: associated
wlan0: deauthenticating from 00:30:bd:9d:fe:4a by local choice (reason=3)
cfg80211: Calling CRDA to update world regulatory domain
wlan0: authenticate with 00:30:bd:9d:fe:4a (try 1)
wlan0: authenticated
wlan0: associate with 00:30:bd:9d:fe:4a (try 1)
wlan0: RX AssocResp from 00:30:bd:9d:fe:4a (capab=0x431 status=0 aid=5)
wlan0: associated
wlan0: deauthenticating from 00:30:bd:9d:fe:4a by local choice (reason=3)
cfg80211: Calling CRDA to update world regulatory domain
wlan0: authenticate with 00:46:9a:06:c5:9e (try 1)
wlan0: authenticated
wlan0: associate with 00:46:9a:06:c5:9e (try 1)
wlan0: RX AssocResp from 00:46:9a:06:c5:9e (capab=0x431 status=0 aid=1)
wlan0: associated
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 00:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 6
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 0
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 00:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 00:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 00:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: Microcode SW error detected.  Restarting 0x2000000.
iwlagn 0000:02:00.0: Loaded firmware version: 9.221.4.1 build 25532
iwlagn 0000:02:00.0: Start IWL Error Log Dump:
iwlagn 0000:02:00.0: Status: 0x000212E4, count: 5
iwlagn 0000:02:00.0: Desc                                  Time       data1      data2      line
iwlagn 0000:02:00.0: SYSASSERT                    (0x0005) 0056137292 0x00000000 0x00000F9B 3995
iwlagn 0000:02:00.0: pc      blink1  blink2  ilink1  ilink2  hcmd
iwlagn 0000:02:00.0: 0x0D8BC 0x0D7DC 0x0D7DC 0x01532 0x00000 0x0001C
iwlagn 0000:02:00.0: CSR values:
iwlagn 0000:02:00.0: (2nd byte of CSR_INT_COALESCING is CSR_INT_PERIODIC_REG)
iwlagn 0000:02:00.0:        CSR_HW_IF_CONFIG_REG: 0X00480303
iwlagn 0000:02:00.0:          CSR_INT_COALESCING: 0X0000ff40
iwlagn 0000:02:00.0:                     CSR_INT: 0X00000000
iwlagn 0000:02:00.0:                CSR_INT_MASK: 0X00000000
iwlagn 0000:02:00.0:           CSR_FH_INT_STATUS: 0X00000000
iwlagn 0000:02:00.0:                 CSR_GPIO_IN: 0X0000000f
iwlagn 0000:02:00.0:                   CSR_RESET: 0X00000000
iwlagn 0000:02:00.0:                CSR_GP_CNTRL: 0X080403c5
iwlagn 0000:02:00.0:                  CSR_HW_REV: 0X00000074
iwlagn 0000:02:00.0:              CSR_EEPROM_REG: 0Xa88d0ffd
iwlagn 0000:02:00.0:               CSR_EEPROM_GP: 0X90000001
iwlagn 0000:02:00.0:              CSR_OTP_GP_REG: 0X00030001
iwlagn 0000:02:00.0:                 CSR_GIO_REG: 0X00080046
iwlagn 0000:02:00.0:            CSR_GP_UCODE_REG: 0X0000000e
iwlagn 0000:02:00.0:           CSR_GP_DRIVER_REG: 0X00000000
iwlagn 0000:02:00.0:           CSR_UCODE_DRV_GP1: 0X00000000
iwlagn 0000:02:00.0:           CSR_UCODE_DRV_GP2: 0X00000000
iwlagn 0000:02:00.0:                 CSR_LED_REG: 0X00000078
iwlagn 0000:02:00.0:        CSR_DRAM_INT_TBL_REG: 0X8812f10c
iwlagn 0000:02:00.0:        CSR_GIO_CHICKEN_BITS: 0X27800200
iwlagn 0000:02:00.0:             CSR_ANA_PLL_CFG: 0X00000000
iwlagn 0000:02:00.0:           CSR_HW_REV_WA_REG: 0X0001001a
iwlagn 0000:02:00.0:        CSR_DBG_HPET_MEM_REG: 0Xffff0000
iwlagn 0000:02:00.0: FH register values:
iwlagn 0000:02:00.0:         FH_RSCSR_CHNL0_STTS_WPTR_REG: 0X10d2f700
iwlagn 0000:02:00.0:        FH_RSCSR_CHNL0_RBDCB_BASE_REG: 0X010d1f70
iwlagn 0000:02:00.0:                  FH_RSCSR_CHNL0_WPTR: 0X00000030
iwlagn 0000:02:00.0:         FH_MEM_RCSR_CHNL0_CONFIG_REG: 0X80819104
iwlagn 0000:02:00.0:          FH_MEM_RSSR_SHARED_CTRL_REG: 0X000000fc
iwlagn 0000:02:00.0:            FH_MEM_RSSR_RX_STATUS_REG: 0X07030000
iwlagn 0000:02:00.0:    FH_MEM_RSSR_RX_ENABLE_ERR_IRQ2DRV: 0X00000000
iwlagn 0000:02:00.0:                FH_TSSR_TX_STATUS_REG: 0X07ff0001
iwlagn 0000:02:00.0:                 FH_TSSR_TX_ERROR_REG: 0X00000000
iwlagn 0000:02:00.0: Start IWL Event Log Dump: display last 20 entries
iwlagn 0000:02:00.0: EVT_LOGT:0000073097:0x00000019:0484
iwlagn 0000:02:00.0: EVT_LOGT:0000073113:0x042700b0:0401
iwlagn 0000:02:00.0: EVT_LOGT:0000073224:0x0428004e:0401
iwlagn 0000:02:00.0: EVT_LOGT:0000073242:0x04290018:0401
iwlagn 0000:02:00.0: EVT_LOGT:0000073305:0x042a0018:0401
iwlagn 0000:02:00.0: EVT_LOGT:0000073386:0x042b0018:0401
iwlagn 0000:02:00.0: EVT_LOGT:0000073426:0x042c0018:0401
iwlagn 0000:02:00.0: EVT_LOGT:0000073495:0x00000001:1332
iwlagn 0000:02:00.0: EVT_LOGT:0000073496:0x0000001c:0206
iwlagn 0000:02:00.0: EVT_LOGT:0000073497:0x00000001:0204
iwlagn 0000:02:00.0: EVT_LOGT:0000073501:0x00000001:0219
iwlagn 0000:02:00.0: EVT_LOGT:0000073501:0x01000051:0211
iwlagn 0000:02:00.0: EVT_LOGT:0000073505:0x00000000:0212
iwlagn 0000:02:00.0: EVT_LOGT:0000073959:0x00000000:0215
iwlagn 0000:02:00.0: EVT_LOGT:0000073961:0x00000008:0220
iwlagn 0000:02:00.0: EVT_LOGT:0000074002:0x00000000:0302
iwlagn 0000:02:00.0: EVT_LOGT:0000074032:0x000000b4:0303
iwlagn 0000:02:00.0: EVT_LOGT:0000074036:0x0000000e:0322
iwlagn 0000:02:00.0: EVT_LOGT:0000074037:0x0000002c:0322
iwlagn 0000:02:00.0: EVT_LOGT:0000074046:0x00000000:0125
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 00:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 8
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 2
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 2
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 00:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 2
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 00:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 8
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 00:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 4
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 8
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 00:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 6
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 7
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 00:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 4
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 6
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 00:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 00:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 8
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 00:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 00:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 3
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 00:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 2
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 00:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 00:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 2
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 7
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 6
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 4
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 10
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 4
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 9
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 00:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 00:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 00:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 00:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 00:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 00:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 4
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 8
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 10
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 00:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 9
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 00:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 7
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 00:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 00:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 6
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 00:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 0
Comment 41 wey-yi.w.guy 2010-11-17 22:34:43 UTC
Hi Alphazo,

could you try to apply the following patch
commit#822395b591db32ad3cf8a5b57b0fe30fb8d12c37: "iwlwifi: quiet a noisy printk"

this patch already upstream in wireless-testing

Thanks
Wey
Comment 42 alphazo 2010-11-17 22:42:31 UTC
Is there a place where I can fetch the binary driver already patched?
Comment 43 alphazo 2010-11-19 20:26:56 UTC
I now have firmware 9.221.4.1 build 25532 and iwlagn.ko from compat-wireless-2010-11-18. However I can only connect at 54MB/s to my WNDR3700 running DD-WRT in NG mixed mode. dmesg doesn't show any error.

iwconfig reports:

wlan0     IEEE 802.11abg  ESSID:"TrvaLhy3vcw3j9KWvxQN"  
          Mode:Managed  Frequency:2.452 GHz  Access Point: 00:46:9A:06:C5:9E   
          Bit Rate=48 Mb/s   Tx-Power=15 dBm   
          Retry  long limit:7   RTS thr:off   Fragment thr:off
          Power Management:on
          Link Quality=58/70  Signal level=-52 dBm  
          Rx invalid nwid:0  Rx invalid crypt:0  Rx invalid frag:0
          Tx excessive retries:3  Invalid misc:125   Missed beacon:0


Any idea?
Comment 44 alphazo 2010-11-19 20:33:24 UTC
My mistake....
I forgot to remove the following 'old' fix in my /etc/rc.local:
rmmod iwlagn
modprobe iwlagn 11n_disable=1

So 'n' is back and the only dmesg errors are:

lan0: RX AssocResp from 00:46:9a:06:c5:9e (capab=0x431 status=0 aid=1)
wlan0: associated
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 2
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 2
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 6
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 3
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 3
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 00:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Error sending TX power (-5)
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 0
Comment 45 wey-yi.w.guy 2010-11-19 20:54:52 UTC
That looks right, the thing you saw on dmesg is for information only.

Thanks for testing and please DO let me know if any issue come up

Wey
Comment 46 alphazo 2010-11-20 13:38:19 UTC
Got disconnected for no reasons from a 54G AP.


iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Aggregation not enabled for tid 1 because load = 1
wlan0: deauthenticated from 30:46:9a:06:c5:9e (Reason: 2)
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
cfg80211: Calling CRDA to update world regulatory domain
wlan0: authenticate with 30:46:9a:06:c5:9e (try 1)
wlan0: authenticated
wlan0: associate with 30:46:9a:06:c5:9e (try 1)
wlan0: RX AssocResp from 30:46:9a:06:c5:9e (capab=0x411 status=0 aid=1)
wlan0: associated
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 2
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 3
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 5
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 3
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 6
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 2
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 2
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 2
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 10
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 0
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 9
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 3
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 2
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 0
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 3
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 6
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 3
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 0
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Error sending TX power (-5)
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 2
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Error sending TX power (-5)
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 4
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Error sending TX power (-5)
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 6
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 6
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 6
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Error sending TX power (-5)
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Error sending TX power (-5)
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Error sending TX power (-5)
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Error sending TX power (-5)
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Error sending TX power (-5)
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 7
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 9
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Error sending TX power (-5)
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Error sending TX power (-5)
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 8
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Error sending TX power (-5)
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Error sending TX power (-5)
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Error sending TX power (-5)
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 5
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Error sending TX power (-5)
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 9
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Error sending TX power (-5)
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 2
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 10
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 4
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 6
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Error sending TX power (-5)
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 9
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 9
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Error sending TX power (-5)
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 0
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 6
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 5
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Error sending TX power (-5)
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Error sending TX power (-5)
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: low ack count detected, restart firmware
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Error sending TX power (-5)
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 0
wlan0: deauthenticating from 30:46:9a:06:c5:9e by local choice (reason=3)
cfg80211: Calling CRDA to update world regulatory domain
wlan0: authenticate with 00:30:bd:9d:fe:4a (try 1)
wlan0: authenticated
wlan0: associate with 00:30:bd:9d:fe:4a (try 1)
wlan0: RX AssocResp from 00:30:bd:9d:fe:4a (capab=0x431 status=0 aid=5)
wlan0: associated
RPC: Registered udp transport module.
RPC: Registered tcp transport module.
RPC: Registered tcp NFSv4.1 backchannel transport module.
FS-Cache: Loaded
FS-Cache: Netfs 'nfs' registered for caching
wlan0: deauthenticated from 00:30:bd:9d:fe:4a (Reason: 16)
cfg80211: Calling CRDA to update world regulatory domain
wlan0: authenticate with 00:30:bd:9d:fe:4a (try 1)
wlan0: authenticated
wlan0: associate with 00:30:bd:9d:fe:4a (try 1)
wlan0: RX AssocResp from 00:30:bd:9d:fe:4a (capab=0x431 status=0 aid=5)
wlan0: associated
wlan0: deauthenticated from 00:30:bd:9d:fe:4a (Reason: 15)
cfg80211: Calling CRDA to update world regulatory domain
wlan0: authenticate with 00:30:bd:9d:fe:4a (try 1)
wlan0: authenticated
wlan0: associate with 00:30:bd:9d:fe:4a (try 1)
wlan0: RX AssocResp from 00:30:bd:9d:fe:4a (capab=0x431 status=0 aid=5)
wlan0: associated
wlan0: deauthenticated from 00:30:bd:9d:fe:4a (Reason: 15)
cfg80211: Calling CRDA to update world regulatory domain
wlan0: authenticate with 30:46:9a:06:c5:9e (try 1)
wlan0: authenticated
wlan0: associate with 30:46:9a:06:c5:9e (try 1)
wlan0: RX AssocResp from 30:46:9a:06:c5:9e (capab=0x411 status=0 aid=1)
wlan0: associated
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
Comment 47 alphazo 2010-11-20 13:45:32 UTC
Strange. I can no longer associate to the original 54G AP on which I got disconnected from.

wlan0: authenticate with 00:30:bd:9d:fe:4a (try 1)
wlan0: authenticated
wlan0: associate with 00:30:bd:9d:fe:4a (try 1)
wlan0: RX AssocResp from 00:30:bd:9d:fe:4a (capab=0x431 status=0 aid=5)
wlan0: associated
wlan0: deauthenticated from 00:30:bd:9d:fe:4a (Reason: 15)
cfg80211: Calling CRDA to update world regulatory domain
wlan0: authenticate with 00:30:bd:9d:fe:4a (try 1)
wlan0: authenticated
wlan0: associate with 00:30:bd:9d:fe:4a (try 1)
wlan0: RX AssocResp from 00:30:bd:9d:fe:4a (capab=0x431 status=0 aid=5)
wlan0: associated
wlan0: deauthenticated from 00:30:bd:9d:fe:4a (Reason: 15)
cfg80211: Calling CRDA to update world regulatory domain
wlan0: authenticate with 00:30:bd:9d:fe:4a (try 1)
wlan0: authenticated
wlan0: associate with 00:30:bd:9d:fe:4a (try 1)
wlan0: RX AssocResp from 00:30:bd:9d:fe:4a (capab=0x431 status=0 aid=5)
wlan0: associated
wlan0: deauthenticated from 00:30:bd:9d:fe:4a (Reason: 15)
cfg80211: Calling CRDA to update world regulatory domain
wlan0: authenticate with 00:30:bd:9d:fe:4a (try 1)
wlan0: authenticated
wlan0: associate with 00:30:bd:9d:fe:4a (try 1)
wlan0: RX AssocResp from 00:30:bd:9d:fe:4a (capab=0x431 status=0 aid=5)
wlan0: associated
wlan0: deauthenticated from 00:30:bd:9d:fe:4a (Reason: 15)
cfg80211: Calling CRDA to update world regulatory domain
wlan0: authenticate with 00:30:bd:9d:fe:4a (try 1)
wlan0: authenticated
wlan0: associate with 00:30:bd:9d:fe:4a (try 1)
wlan0: RX AssocResp from 00:30:bd:9d:fe:4a (capab=0x431 status=0 aid=5)
wlan0: associated
wlan0: deauthenticated from 00:30:bd:9d:fe:4a (Reason: 15)
cfg80211: Calling CRDA to update world regulatory domain
wlan0: authenticate with 00:30:bd:9d:fe:4a (try 1)
wlan0: authenticated
wlan0: associate with 00:30:bd:9d:fe:4a (try 1)
wlan0: RX AssocResp from 00:30:bd:9d:fe:4a (capab=0x431 status=0 aid=5)
wlan0: associated
wlan0: deauthenticated from 00:30:bd:9d:fe:4a (Reason: 15)
cfg80211: Calling CRDA to update world regulatory domain
wlan0: authenticate with 00:30:bd:9d:fe:4a (try 1)
wlan0: authenticated
wlan0: associate with 00:30:bd:9d:fe:4a (try 1)
wlan0: RX AssocResp from 00:30:bd:9d:fe:4a (capab=0x431 status=0 aid=5)
wlan0: associated
wlan0: deauthenticated from 00:30:bd:9d:fe:4a (Reason: 15)
cfg80211: Calling CRDA to update world regulatory domain
wlan0: authenticate with 00:30:bd:9d:fe:4a (try 1)
wlan0: authenticated
wlan0: associate with 00:30:bd:9d:fe:4a (try 1)
wlan0: RX AssocResp from 00:30:bd:9d:fe:4a (capab=0x431 status=0 aid=5)
wlan0: associated
wlan0: deauthenticated from 00:30:bd:9d:fe:4a (Reason: 15)
cfg80211: Calling CRDA to update world regulatory domain
wlan0: authenticate with 00:30:bd:9d:fe:4a (try 1)
wlan0: authenticated
wlan0: associate with 00:30:bd:9d:fe:4a (try 1)
wlan0: RX AssocResp from 00:30:bd:9d:fe:4a (capab=0x431 status=0 aid=5)
wlan0: associated
Comment 48 wey-yi.w.guy 2010-11-20 17:00:41 UTC
reason code show :
15[i]  4-Way Handshake timeout.
16[i]  Group key update timeout.

what kernel version you are using? maybe a log from wpa_supplicant will give some inside.

Wey
Comment 49 alphazo 2010-11-27 13:54:47 UTC
Above log was on 2.6.35.4. I since switched to 2.6.36.

I didn't get any disconnect for quite some time however my internet experience is terrible. Everything is slow, loading pages is slow and sometimes it won't load the page at all. I'm attaching 2 traces in case that can help to understand the problem. I'm running compat-wireless-2010-11-25.
Comment 50 alphazo 2010-11-27 13:55:58 UTC
Created attachment 38282 [details]
slow internet trace
Comment 51 alphazo 2010-11-27 13:56:32 UTC
Created attachment 38292 [details]
Another slow internet trace
Comment 52 wey-yi.w.guy 2010-11-29 16:35:56 UTC
Created attachment 38502 [details]
remove low ack count check for 5x00

Could you try this patch and see if it help?

Thanks
Wey
Comment 53 alphazo 2010-11-29 16:47:29 UTC
Sorry for the stupid question but how do I apply the patch. I tried:
# cd compat-wireless-2010-11-25
# cp /home/alpha/Downloads/0001-iwlagn-remove-low-ack-count-check.patch .
# patch -p0 < 0001-iwlagn-remove-low-ack-count-check.patch

>>
Perhaps you used the wrong -p or --strip option?
Comment 54 wey-yi.w.guy 2010-11-29 16:50:10 UTC
patch -p1 < 0001-iwlagn-remove-low-ack-count-check.patch
Comment 55 alphazo 2010-11-29 17:08:42 UTC
Thanks. Compile and installed. I'll report my results.
Comment 56 alphazo 2010-11-29 21:10:03 UTC
Created attachment 38572 [details]
After low-ack-count patch

Still very slow after patching with 0001-iwlagn-remove-low-ack-count-check.patch
Comment 57 wey-yi.w.guy 2010-11-29 21:15:42 UTC
looks like driver keep reloading firmware becuase driver think tx queue is stuck, I will send you another patch later to disable that.

FYI, those are experimental patches try to root cause the problem.

Thanks
Wey
Comment 58 wey-yi.w.guy 2010-11-30 16:27:57 UTC
Created attachment 38632 [details]
extend the stuck queue timeout for tx queue

Could you please try this patch, it is a hack and see if it help

Thanks
Wey
Comment 59 Kevin DeKorte 2010-11-30 18:12:56 UTC
Just some followup testing using the Fedora Kernels

Work fine:
kernel-2.6.34.7-61.fc13.x86_64 


Do not work fine.
kernel-2.6.36-4.f13.x86_64.rpm
kernel-2.6.36.1-10.f13.x86_64.rpm

The 2.6.36 kernels seem to run at a slower data rate, have less range and drop connections much more often than the 2.6.34 kernels. Even when the signal is strong. Today I was sitting at the same spot in my house. I could not keep a working connection with a .36 kernel for more than 3-4 mins before it died. Using the .34 kernel it has been working well for a couple of hours.

03:00.0 Network controller: Intel Corporation PRO/Wireless 5100 AGN [Shiloh] Network Connection
	Subsystem: Intel Corporation WiFi Link 5100 AGN
	Physical Slot: 1
	Flags: bus master, fast devsel, latency 0, IRQ 34
	Memory at f4300000 (64-bit, non-prefetchable) [size=8K]
	Capabilities: <access denied>
	Kernel driver in use: iwlagn
	Kernel modules: iwlagn

dmesg output on the .34 kernel

iwlagn: Intel(R) Wireless WiFi Link AGN driver for Linux, in-tree:d
iwlagn: Copyright(c) 2003-2010 Intel Corporation
iwlagn 0000:03:00.0: PCI INT A -> GSI 17 (level, low) -> IRQ 17
iwlagn 0000:03:00.0: setting latency timer to 64
iwlagn 0000:03:00.0: Detected Intel Wireless WiFi Link 5100AGN REV=0x54
iwlagn 0000:03:00.0: Tunable channels: 13 802.11bg, 24 802.11a channels
iwlagn 0000:03:00.0: irq 34 for MSI/MSI-X
iwlagn 0000:03:00.0: firmware: requesting iwlwifi-5000-2.ucode
iwlagn 0000:03:00.0: loaded firmware version 8.24.2.12
phy0: Selected rate control algorithm 'iwl-agn-rs'
Comment 60 h.habighorst 2010-12-16 06:08:45 UTC
Created attachment 40302 [details]
dmesg output

This is the full dmesg output of latest iwlwifi-2.6 kernel with debugging enabled.

I didn't apply any of the patches. Problem still exists.
Comment 61 wey-yi.w.guy 2010-12-16 16:21:11 UTC
Yes, it is uCode problem based and so far we don't have a good driver w/a solution to fix this. We still facing few regulatory issue on experimental uCode, as soon as those problem get fix, we will release experimental uCode to the community. Really sorry for the problem.

Thanks
Wey
Comment 62 alphazo 2011-01-02 18:05:02 UTC
My internet connection became very slow today over wlan. dmesg revealed:

iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 0
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 6
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Queue 3 stuck for 2000 ms.
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: Aggregation not enabled for tid 1 because load = 1
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 2
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 1
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Received BA when not expected
iwlagn 0000:02:00.0: Queue 3 stuck for 2000 ms.
iwlagn 0000:02:00.0: On demand firmware reload
iwlagn 0000:02:00.0: Stopping AGG while state not ON or starting
iwlagn 0000:02:00.0: queue number out of range: 0, must be 10 to 19
iwlagn 0000:02:00.0: Aggregation not enabled for tid 1 because load = 1
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
iwlagn 0000:02:00.0: Received BA when not expected

I'm using compat-wireless 2010_12_26 with 0001-iwlagn-disable-low-ack-count-for-6000-series.patch. Don't need 0001-iwlagn-disable-low-ack-count-for-6000-series.patch anymore as it has been included in mainstream.
Comment 63 wey-yi.w.guy 2011-01-03 14:57:46 UTC
Created attachment 42252 [details]
work around for slow tpt

please try this and see if help

thanks
Wey
Comment 64 alphazo 2011-01-03 15:02:22 UTC
Looks like the proposed patch is for a 5000 card. Do you have similar patch for 6000 cards?
Comment 65 wey-yi.w.guy 2011-01-03 15:38:34 UTC
ok, I was not sure what card you are using, I will creat the patch and send you later

thanks
Wey
Comment 66 wey-yi.w.guy 2011-01-03 16:22:12 UTC
Created attachment 42272 [details]
work around for 6000 low tpt

work around path for 6000 series devices

Wey
Comment 67 alphazo 2011-01-03 18:58:44 UTC
Applied both 0001-iwlagn-disable-low-ack-count-for-6000-series.patch and 0001-iwlagn-low_tpt-for-6000-series.patch but I got pretty bad connection right from the beginning (unable to fetch IMAP server).

cfg80211: Calling CRDA to update world regulatory domain
wlan0: authenticate with 30:46:9a:06:c5:9e (try 1)
wlan0: authenticated
wlan0: associate with 30:46:9a:06:c5:9e (try 1)
wlan0: RX AssocResp from 30:46:9a:06:c5:9e (capab=0x411 status=0 aid=2)
wlan0: associated
iwlagn 0000:02:00.0: Queue 2 stuck for 2000 ms.
iwlagn 0000:02:00.0: On demand firmware reload
chromium-sandbo (5653): /proc/5651/oom_adj is deprecated, please use /proc/5651/oom_score_adj instead.
cfg80211: Calling CRDA to update world regulatory domain
wlan0: authenticate with 30:46:9a:06:c5:9e (try 1)
wlan0: authenticated
wlan0: associate with 30:46:9a:06:c5:9e (try 1)
wlan0: RX AssocResp from 30:46:9a:06:c5:9e (capab=0x411 status=0 aid=2)
wlan0: associated
iwlagn 0000:02:00.0: Queue 2 stuck for 2000 ms.
iwlagn 0000:02:00.0: On demand firmware reload
Comment 68 wey-yi.w.guy 2011-01-03 19:02:04 UTC
did you try the latest patch "work around for 6000 low tpt" I attached?

Thanks
Wey
Comment 69 Denis 2011-01-03 19:11:14 UTC
Wey, I've got a few questions for you:

1. Why oh why do you need random "internet people" to test your patches? Don't you, as an Intel employee, have an access to a damn INTEL WIRELESS CARD???
2. This bug has been open for more than 4 months now. All this period my wireless card is pretty much driving me nuts. Isn't this enough for a paid developer to fix the issues?
3. I really, but really, don't give a crap about these "regulatory issues" (whatever they are) that you're facing. All I want is my driver getting fixed and the card I paid good money for working like it's supposed to.

Have a good day, and make some real progress for a change.
Comment 70 alphazo 2011-01-03 19:22:17 UTC
Yep this is using the patch found in comment #66 (low tpt).
Comment 71 wey-yi.w.guy 2011-01-03 19:40:32 UTC
(In reply to comment #70)
> Yep this is using the patch found in comment #66 (low tpt).

Pradeep, who is our engineer here will work with you on this 6000 low tpt issue.

Thanks
Wey
Comment 72 Pradeep Kulkarni 2011-01-04 01:04:23 UTC
Here is the message received from alphazo regarding throughput issue with 6000 wireless card.
Please reload the iwlagn module with debug option using the following command
modprobe -v iwlagn debug=0x100

I'm getting an error message when using the above command:

FATAL: Error inserting iwlagn (/lib/modules/2.6.36-ARCH/updates/drivers/net/wireless/iwlwifi/iwlagn.ko): Unknown symbol in module, or unknown parameter (see dmesg)

Note from Pradeep: Please recheck target kernel (2.6.36) configurations especially iwlwifi debug options and other iwlwifi wireless modules support. I have attached a kernel configuration file compat-wireless-iwlwifi-kernel-cfg for your reference.

Should I recompile compat-wirless with some debugging support ? Can you supply the right switch to pass?) ?


Please attach the dmesg output showing the wireless card type, EEPROM and wireless firmware (ucode) information. If you are using compat-wireless,
dmesg includes compat-wireless version information.

 

iwlagn: Intel(R) Wireless WiFi Link AGN driver for Linux, in-tree:

iwlagn: Copyright(c) 2003-2010 Intel Corporation

iwlagn 0000:02:00.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16

iwlagn 0000:02:00.0: setting latency timer to 64

iwlagn 0000:02:00.0: Detected Intel(R) Centrino(R) Ultimate-N 6300 AGN, REV=0x74

iwlagn 0000:02:00.0: device EEPROM VER=0x436, CALIB=0x6

iwlagn 0000:02:00.0: Device SKU: 0Xb

iwlagn 0000:02:00.0: Valid Tx ant: 0X7, Valid Rx ant: 0X7

iwlagn 0000:02:00.0: Tunable channels: 13 802.11bg, 24 802.11a channels

iwlagn 0000:02:00.0: irq 44 for MSI/MSI-X

iwlagn 0000:02:00.0: loaded firmware version 9.221.4.1 build 25532

 

Kernel version -
Which Linux distribution are you running e.g  Ubuntu/Fedora-core  etc -

- Linux kernel 2.6.36.2 (64-bit)

- ArchLinux 64-bit


Wireless Type

Intel(R) Centrino(R) Ultimate-N 6300 AGN, REV=0x74 

Firmware/ucode version

Are you using the iwlwifi driver modules based on compat-wireless? If so please let me know compat-version details.

Firmware/ucode version: 

Firmware 9.221.4.1 build 25532

I'm using compat-wireless based upon compat-wireless-2010-12-26.tar.bz2. Although dmesg reports:

Compat-wireless backport release: compat-wireless-2010-12-20-1-g53f8e22

Backport based on linux-next.git next-20101221

 
Furthermore I'm using two patches suggested by Wey (attached to this email):

- 0001-iwlagn-disable-low-ack-count-for-6000-series.patch

- 0001-iwlagn-low_tpt-for-6000-series.patch

Card has been working so-so with the first patch. When I added the second patch today it got even worse.

Notes from Pradeep: Working on to send compat-wireless source code based on Gold release.
Comment 73 Pradeep Kulkarni 2011-01-04 01:18:32 UTC
Created attachment 42302 [details]
kernel configuration to support compat-wireless modules for Intel wireless cards
Comment 74 wey-yi.w.guy 2011-01-06 01:11:46 UTC
Alphazo,

Could you help to update your latest status.

Thanks
Wey
Comment 75 alphazo 2011-01-06 11:25:09 UTC
I need to do some more testings but it appears that my AP was also part of the problem. I switched my WNDR3700 from OpenWRT to DD-WRT and I can get pretty steady performance with the Gold release compat-wirless driver (channel 9, WPA2/AES).
- 80Mb/s with 20MHz channel width
- 270Mb/s with 40MHz channel width

The only thing I see in dmesg is :
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 4
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 4
iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0

Again this was done yesterday night I need to go over more load testing but overall it looks great.

Thanks
Alphazo

PS: When do you plan to officially realase this Gold version?
Comment 76 wey-yi.w.guy 2011-01-06 16:05:58 UTC
(In reply to comment #75)
> I need to do some more testings but it appears that my AP was also part of
> the
> problem. I switched my WNDR3700 from OpenWRT to DD-WRT and I can get pretty
> steady performance with the Gold release compat-wirless driver (channel 9,
> WPA2/AES).
> - 80Mb/s with 20MHz channel width
> - 270Mb/s with 40MHz channel width
> The only thing I see in dmesg is :
> iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 4
> iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 1
> iwlagn 0000:02:00.0: Aggregation not enabled for tid 0 because load = 4
> iwlagn 0000:02:00.0: iwlagn_tx_agg_start on ra = 30:46:9a:06:c5:9e tid = 0
> Again this was done yesterday night I need to go over more load testing but
> overall it looks great.
> Thanks
> Alphazo
> PS: When do you plan to officially realase this Gold version?

I believe for the 6000 devices (the one you are using), the release is out there, something I miss?

Thanks
Wey
Comment 77 alphazo 2011-01-06 16:42:04 UTC
I'm talking about the password protected compat-wireless source code that Pradeep sent me. It looks like it is new. The file called compat_version says: compat-wireless-v2.6.36-rc8-1.
Comment 78 Jelle Foks 2011-01-15 01:52:52 UTC
Hi, 

I grabbed the fresh ucode from the experimental page: http://intellinuxwireless.org/?n=experimental

I compiled a new ubuntu kernel from git with the experimental ucode support enabled (as suggested in the readme), it's version 2.6.37-12.26. I uncommented the line in /etc/modprobe.d/intel-5300-iwlagn-disable11n.conf to re-enable 802.11n.

So far, it's looking very good. Haven't seen the problem with the new ucode, and no messages in the logs. Getting real-speed of up to 75Mbit/s at a link speed of 150Mbit/s (link quality up to 70/70 -38dB).

That's more than 3 times better real speed than I had before. My router is a WNDR3700, using 5.765 GHz, cannel 153. I was seeing the problem frequently before in this setup.

The only thing remaining, for me, is that I wonder why it's not connecting at 300Mbit/s, the router is set for it and it afaik it should work.

Great progress so far, thanks guys!

Jelle.

Jan 14 15:06:26 localhost kernel: [   30.009257] iwlagn: Intel(R) Wireless WiFi Link AGN driver for Linux, in-tree:d
Jan 14 15:06:26 localhost kernel: [   30.009260] iwlagn: Copyright(c) 2003-2010 Intel Corporation
Jan 14 15:06:26 localhost kernel: [   30.009381] iwlagn 0000:05:00.0: PCI INT A -> GSI 19 (level, low) -> IRQ 19
Jan 14 15:06:26 localhost kernel: [   30.009411] iwlagn 0000:05:00.0: setting latency timer to 64
Jan 14 15:06:26 localhost kernel: [   30.009464] iwlagn 0000:05:00.0: Detected Intel(R) WiFi Link 5100 AGN, REV=0x54
Jan 14 15:06:26 localhost kernel: [   30.031127] iwlagn 0000:05:00.0: device EEPROM VER=0x11f, CALIB=0x4
Jan 14 15:06:26 localhost kernel: [   30.031367] iwlagn 0000:05:00.0: Tunable channels: 13 802.11bg, 24 802.11a channels
Jan 14 15:06:26 localhost kernel: [   30.031495] iwlagn 0000:05:00.0: irq 43 for MSI/MSI-X
Jan 14 15:06:26 localhost kernel: [   30.067469] iwlagn 0000:05:00.0: loaded firmware version 8.83.5.1 build 33692 (EXP)
Comment 79 Jelle Foks 2011-01-15 02:15:40 UTC
Just checked with windows, and it reports a connection at 300Mbit, so my setup should be able to do it. Am I missing a magical iwpriv command, a module option, or something like that?
Comment 80 wey-yi.w.guy 2011-01-15 17:33:44 UTC
Hi Jelle,

What is your configuration?
not sure how Windows measure the rate, based on the MSC table
http://wireless.agilent.com/wireless/helpfiles/n7617b/n7617b.htm#coding_and_modulation_mimo.htm

300 Mbps is for MIMO2 40MHz MCS 15 SGI
When I ran the test here, I can see 144.4 Mbps 20 MHz MCS 15 SGI on my system.

Thanks
Wey
Comment 81 Jelle Foks 2011-01-16 01:53:19 UTC
The router is a netgear WNDR3700, set to channel 153, mode 'Up to 300Mbps'.

lspci and iwconfig below.

iwconfig
wlan0     IEEE 802.11abgn  ESSID:"zzzzzzzz"  
          Mode:Managed  Frequency:5.765 GHz  Access Point: zzzzzzz
          Bit Rate=150 Mb/s   Tx-Power=15 dBm   
          Retry  long limit:7   RTS thr:off   Fragment thr:off
          Power Management:off
          Link Quality=67/70  Signal level=-43 dBm  
          Rx invalid nwid:0  Rx invalid crypt:0  Rx invalid frag:0
          Tx excessive retries:2118  Invalid misc:721   Missed beacon:0

lspci
05:00.0 Network controller: Intel Corporation WiFi Link 5100
        Subsystem: Intel Corporation WiFi Link 5100 AGN
        Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
        Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
        Latency: 0, Cache Line Size: 64 bytes
        Interrupt: pin A routed to IRQ 43
        Region 0: Memory at d1900000 (64-bit, non-prefetchable) [size=8K]
        Capabilities: [c8] Power Management version 3
                Flags: PMEClk- DSI+ D1- D2- AuxCurrent=0mA PME(D0+,D1-,D2-,D3hot+,D3cold+)
                Status: D0 NoSoftRst- PME-Enable- DSel=0 DScale=0 PME-
        Capabilities: [d0] MSI: Enable+ Count=1/1 Maskable- 64bit+
                Address: 00000000fee0300c  Data: 4181
        Capabilities: [e0] Express (v1) Endpoint, MSI 00
                DevCap: MaxPayload 128 bytes, PhantFunc 0, Latency L0s <512ns, L1 unlimited
                        ExtTag- AttnBtn- AttnInd- PwrInd- RBE+ FLReset+
                DevCtl: Report errors: Correctable- Non-Fatal- Fatal- Unsupported-
                        RlxdOrd+ ExtTag- PhantFunc- AuxPwr- NoSnoop+ FLReset-
                        MaxPayload 128 bytes, MaxReadReq 128 bytes
                DevSta: CorrErr+ UncorrErr- FatalErr- UnsuppReq+ AuxPwr+ TransPend-
                LnkCap: Port #0, Speed 2.5GT/s, Width x1, ASPM L0s L1, Latency L0 <128ns, L1 <32us
                        ClockPM+ Surprise- LLActRep- BwNot-
                LnkCtl: ASPM L1 Enabled; RCB 64 bytes Disabled- Retrain- CommClk+
                        ExtSynch- ClockPM- AutWidDis- BWInt- AutBWInt-
                LnkSta: Speed 2.5GT/s, Width x1, TrErr- Train- SlotClk+ DLActive- BWMgmt- ABWMgmt-
        Capabilities: [100 v1] Advanced Error Reporting
                UESta:  DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt- RxOF- MalfTLP- ECRC- UnsupReq- ACSViol-
                UEMsk:  DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt- RxOF- MalfTLP- ECRC- UnsupReq- ACSViol-
                UESvrt: DLP+ SDES- TLP- FCP+ CmpltTO- CmpltAbrt- UnxCmplt- RxOF+ MalfTLP+ ECRC- UnsupReq- ACSViol-
                CESta:  RxErr- BadTLP- BadDLLP- Rollover- Timeout- NonFatalErr+
                CEMsk:  RxErr- BadTLP- BadDLLP- Rollover- Timeout- NonFatalErr+
                AERCap: First Error Pointer: 00, GenCap- CGenEn- ChkCap- ChkEn-
        Capabilities: [140 v1] Device Serial Number 00-16-ea-ff-ff-4e-09-dc
        Kernel driver in use: iwlagn
        Kernel modules: iwlagn
Comment 82 Craig G 2011-01-17 01:39:39 UTC
I've tested the experimental firmware (iwlwifi-5000-exp-8.83.5.1) with a 5300 card and kernel 2.6.36.2. Initially it seems to have solved the problem. iwconfig reported bit rate maxes out at 300 Mb/s (though it drops to 6 Mb/s during inactivity). File transfer rates are significantly greater than they were with N disabled. There are quite a few of the following messages in the syslog, but that may be expected given the kernel debugging options necessary in order to run the experimental firmware.

iwlagn 0000:03:00.0: Aggregation not enabled for tid 0 because load = 1
iwlagn 0000:03:00.0: iwlagn_tx_agg_start on ra = xx:xx:xx:xx:xx:xx tid = 0
iwlagn 0000:03:00.0: Aggregation not enabled for tid 0 because load = 2
iwlagn 0000:03:00.0: iwlagn_tx_agg_start on ra = xx:xx:xx:xx:xx:xx tid = 0
iwlagn 0000:03:00.0: iwlagn_tx_agg_start on ra = xx:xx:xx:xx:xx:xx tid = 0

However, after about 10 minutes of inactivity, the connection becomes inoperable. Reloading the module fixes the problem temporarily, but it hasn't held a connection for more than 15 minutes at a time. This is significantly longer than without the experimental firmware, but it doesn't seem to have completely fixed the problem.
Comment 83 Norbert Preining 2011-01-17 01:45:44 UTC
Report from my side, having problems with an n router and bad connections braking down permanently.

With the new experimental firmware, and 11n_disable deleted from the kernel cmd line, I see:
- with one (not 11n) router billions of iwlagn 0000:06:00.0: Received BA when not expected

- with the 11n router at University: several times:
[80552.360579] iwlagn 0000:06:00.0: Aggregation not enabled for tid 0 because load = 0
[80558.104375] iwlagn 0000:06:00.0: Aggregation not enabled for tid 0 because load = 4
[80562.216032] iwlagn 0000:06:00.0: iwlagn_tx_agg_start on ra = 00:24:c4:ab:bd:ed tid = 0
[81352.691387] iwlagn 0000:06:00.0: low ack count detected, restart firmware
[81352.691396] iwlagn 0000:06:00.0: On demand firmware reload
[81352.722557] iwlagn 0000:06:00.0: Stopping AGG while state not ON or starting
[81352.722567] iwlagn 0000:06:00.0: queue number out of range: 0, must be 10 to 19

This is with:
iwlagn 0000:06:00.0: Detected Intel(R) WiFi Link 5100 AGN, REV=0x54
iwlagn 0000:06:00.0: loaded firmware version 8.83.5.1 build 33692 (EXP)
and kernel 2.6.37

Maybe it is working a bit better, but still I get long hangs and broken connectivity (although the network-manager believes it is still connected)

All the best

Norbert
Comment 84 petteyg359 2011-01-17 02:47:02 UTC
Using kernel 2.6.37 with Gentoo patches (sys-kernel/gentoo-source-2.6.37), I have applied the remove-low-ack-count-check patch, modified the MAX_API in iwl-5000.c to 5, and using the experimental firmware 8.83.5.1 build 33692. After 24 hours of heavy usage, I have not had a single dissociation or firmware reload. /var/log/messages does have quite a lot of "Received BA when not expected" lines (378 in the past 20 hours), but all lines referencing aggregation are gone.

Using the experimental firmware without the remove-low-ack-count-check patch did not produce any benefit, nor did the applying the patch while using the stable 8.24.2.12 firmware.

My card is a 5100 (PCI ID 8086:4232). This is on an unsecured 5GHz 11n network.
Comment 85 wey-yi.w.guy 2011-01-17 16:44:50 UTC
"remove-low-ack-count-check" patch just a helper patch which might help some of the users in certain environment, but for sure not all the cases. For example, in our lab, it does not make any differences.

Wey
Comment 86 Tobias Wolf 2011-01-18 16:32:29 UTC
I tried to test the experimental iwlwifi 5000 firmware. I'm not sure if I did everything right because with my test case (iperf -u -b 40m) the link goes down almost immediately:

on v2.6.37-rc8

iwlagn: Intel(R) Wireless WiFi Link AGN driver for Linux, in-tree:d
iwlagn: Copyright(c) 2003-2010 Intel Corporation
iwlagn 0000:03:00.0: PCI INT A -> GSI 17 (level, low) -> IRQ 17
iwlagn 0000:03:00.0: setting latency timer to 64
iwlagn 0000:03:00.0: Detected Intel(R) Ultimate N WiFi Link 5300 AGN, REV=0x24
iwlagn 0000:03:00.0: device EEPROM VER=0x11e, CALIB=0x4
iwlagn 0000:03:00.0: Tunable channels: 13 802.11bg, 24 802.11a channels
iwlagn 0000:03:00.0: irq 44 for MSI/MSI-X
iwlagn 0000:03:00.0: loaded firmware version 8.83.5.1 build 33692 (EXP)


And during iperf I get the symptoms described above:

[10337.104519] iwlagn 0000:03:00.0: Aggregation not enabled for tid 0 because load = 1
[10338.216612] iwlagn 0000:03:00.0: iwlagn_tx_agg_start on ra = 00:0c:<cough>  tid = 0
[10338.440986] iwlagn 0000:03:00.0: Received BA when not expected

[ ...REPEAT 80 times... ]

[10343.443360] iwlagn 0000:03:00.0: Received BA when not expected
[10343.508159] ieee80211 phy0: wlan0: No probe response from AP 00:0c:<cough> after 500ms, disconnecting.
[10343.509129] iwlagn 0000:03:00.0: Stopping AGG while state not ON or starting
[10343.514288] cfg80211: All devices are disconnected, going to restore regulatory settings


Before starting iperf it was connected to 802.11na (ath9k OpenWrt hostapd in 11na mode):

Connected to 00:0c:<whoops> (on wlan0)
	SSID: <cough>
	freq: 5240
	RX: 1151900 bytes (2559 packets)
	TX: 1071209 bytes (1851 packets)
	signal: -51 dBm
	tx bitrate: 270.0 MBit/s MCS 15 40Mhz

As you can see it’s over within 5 seconds.
Comment 87 wey-yi.w.guy 2011-01-18 17:20:21 UTC
looks like you are using 40MHz on "A" band, are you seeing the similar behavior on 20MHz? how about "G" band?

is it Open connection or with security?

Wey
Comment 88 Tobias Wolf 2011-01-18 18:17:14 UTC
Yes, that was 11na with HT40- on channel 48. Everything is unencrypted, a plain connection.

I get the same for 11na with HT20 on the same channel, and again the same with 11ng on channel 6. There’s even something like a kernel oops referring to __ieee80211_wake_queue() in the dmesg. See long output below.

Now, on normal 54M 11g it works like it should. There’s no output in dmesg running iperf.


[11na 20Mhz]

$ iw wlan0 link
Connected to 00:0c:42<bleep> (on wlan0)
	SSID: <bleep>
	freq: 5240
	RX: 1263547 bytes (3817 packets)
	TX: 1094111 bytes (2032 packets)
	signal: -52 dBm
	tx bitrate: 78.0 MBit/s MCS 12
$ iperf -c 10.0.0.10 -u -b 40m
------------------------------------------------------------
Client connecting to 10.0.0.10, UDP port 5001
Sending 1470 byte datagrams
UDP buffer size:  112 KByte (default)
------------------------------------------------------------
[  3] local 10.0.0.9 port 48605 connected with 10.0.0.10 port 5001
[ ID] Interval       Transfer     Bandwidth
[  3]  0.0-10.0 sec  21.5 MBytes  18.0 Mbits/sec
[  3] Sent 15317 datagrams
[  3] WARNING: did not receive ack of last datagram after 10 tries.
$ dmesg
[15879.073023] iwlagn 0000:03:00.0: Aggregation not enabled for tid 0 because load = 0
[15879.991101] iwlagn 0000:03:00.0: iwlagn_tx_agg_start on ra = 00:0c:42<bleep> tid = 0
[15881.845349] iwlagn 0000:03:00.0: Received BA when not expected
[15881.971357] iwlagn 0000:03:00.0: Received BA when not expected
[15882.024417] iwlagn 0000:03:00.0: Received BA when not expected
[15882.173146] iwlagn 0000:03:00.0: Received BA when not expected
[15882.306437] iwlagn 0000:03:00.0: Received BA when not expected
[15882.554100] iwlagn 0000:03:00.0: Received BA when not expected
[15882.781407] iwlagn 0000:03:00.0: Received BA when not expected
[15882.794118] iwlagn 0000:03:00.0: Received BA when not expected
[15882.918819] iwlagn 0000:03:00.0: Received BA when not expected
[15883.112406] iwlagn 0000:03:00.0: Received BA when not expected
[15883.331439] iwlagn 0000:03:00.0: Received BA when not expected
[15883.403584] iwlagn 0000:03:00.0: Received BA when not expected
[15883.411567] iwlagn 0000:03:00.0: Received BA when not expected
[15883.453295] iwlagn 0000:03:00.0: Received BA when not expected
[15883.531676] iwlagn 0000:03:00.0: Received BA when not expected
[15883.547141] iwlagn 0000:03:00.0: Received BA when not expected
[15883.646557] iwlagn 0000:03:00.0: Received BA when not expected
[15883.655604] iwlagn 0000:03:00.0: Received BA when not expected
[15883.674290] iwlagn 0000:03:00.0: Received BA when not expected
[15883.696131] iwlagn 0000:03:00.0: Received BA when not expected
[15883.701215] iwlagn 0000:03:00.0: Received BA when not expected
[15883.708770] iwlagn 0000:03:00.0: Received BA when not expected
[15883.715014] iwlagn 0000:03:00.0: Received BA when not expected
[15883.724601] iwlagn 0000:03:00.0: Received BA when not expected
[15883.854559] iwlagn 0000:03:00.0: Received BA when not expected
[15883.854877] iwlagn 0000:03:00.0: Received BA when not expected
[15883.870096] iwlagn 0000:03:00.0: Received BA when not expected
[15883.882595] iwlagn 0000:03:00.0: Received BA when not expected
[15883.893112] iwlagn 0000:03:00.0: Received BA when not expected
[15883.899648] iwlagn 0000:03:00.0: Received BA when not expected
[15883.914041] iwlagn 0000:03:00.0: Received BA when not expected
[15883.932365] iwlagn 0000:03:00.0: Received BA when not expected
[15883.947263] iwlagn 0000:03:00.0: Received BA when not expected
[15884.044036] iwlagn 0000:03:00.0: Received BA when not expected
[15884.052262] iwlagn 0000:03:00.0: Received BA when not expected
[15884.072116] iwlagn 0000:03:00.0: Received BA when not expected
[15884.075145] iwlagn 0000:03:00.0: Received BA when not expected
[15884.080784] iwlagn 0000:03:00.0: Received BA when not expected
[15884.093898] iwlagn 0000:03:00.0: Received BA when not expected
[15884.103235] iwlagn 0000:03:00.0: Received BA when not expected
[15884.122295] iwlagn 0000:03:00.0: Received BA when not expected
[15884.295949] iwlagn 0000:03:00.0: Received BA when not expected
[15884.323679] iwlagn 0000:03:00.0: Received BA when not expected
[15884.342263] iwlagn 0000:03:00.0: Received BA when not expected
[15884.357780] iwlagn 0000:03:00.0: Received BA when not expected
[15884.368082] iwlagn 0000:03:00.0: Received BA when not expected
[15884.382672] iwlagn 0000:03:00.0: Received BA when not expected
[15884.472658] iwlagn 0000:03:00.0: Received BA when not expected
[15884.479364] iwlagn 0000:03:00.0: Received BA when not expected
[15884.488411] iwlagn 0000:03:00.0: Received BA when not expected
[15884.503859] iwlagn 0000:03:00.0: Received BA when not expected
[15884.513093] iwlagn 0000:03:00.0: Received BA when not expected
[15884.541127] iwlagn 0000:03:00.0: Received BA when not expected
[15884.551150] iwlagn 0000:03:00.0: Received BA when not expected
[15884.563195] iwlagn 0000:03:00.0: Received BA when not expected
[15884.573191] iwlagn 0000:03:00.0: Received BA when not expected
[15884.615590] iwlagn 0000:03:00.0: Received BA when not expected
[15884.723216] iwlagn 0000:03:00.0: Received BA when not expected
[15884.742902] iwlagn 0000:03:00.0: Received BA when not expected
[15884.752603] iwlagn 0000:03:00.0: Received BA when not expected
[15884.762772] iwlagn 0000:03:00.0: Received BA when not expected
[15884.932438] iwlagn 0000:03:00.0: Received BA when not expected
[15884.938828] iwlagn 0000:03:00.0: Received BA when not expected
[15884.947995] iwlagn 0000:03:00.0: Received BA when not expected
[15884.958488] iwlagn 0000:03:00.0: Received BA when not expected
[15884.969979] iwlagn 0000:03:00.0: Received BA when not expected
[15884.982246] iwlagn 0000:03:00.0: Received BA when not expected
[15884.991600] iwlagn 0000:03:00.0: Received BA when not expected
[15885.097536] iwlagn 0000:03:00.0: Received BA when not expected
[15885.113068] iwlagn 0000:03:00.0: Received BA when not expected
[15885.125358] iwlagn 0000:03:00.0: Received BA when not expected
[15885.133226] iwlagn 0000:03:00.0: Received BA when not expected
[15885.156518] iwlagn 0000:03:00.0: Received BA when not expected
[15885.156812] iwlagn 0000:03:00.0: Received BA when not expected
[15885.426373] iwlagn 0000:03:00.0: Received BA when not expected
[15885.508151] ieee80211 phy2: wlan0: No probe response from AP 00:0c:42<bleep> after 500ms, disconnecting.
[15885.508851] iwlagn 0000:03:00.0: Stopping AGG while state not ON or starting
[15885.511325] ------------[ cut here ]------------
[15885.511360] WARNING: at /home/towolf/src/kernel/linux-2.6.37-12.26iwlwifi/net/mac80211/util.c:275 __ieee80211_wake_queue+0xf1/0x100 [mac80211]()
[15885.511368] Hardware name: 2776LFG
[15885.511372] Modules linked in: iwlagn iwlcore mac80211 cfg80211 btrfs zlib_deflate libcrc32c ufs qnx4 hfsplus hfs minix ntfs vfat msdos fat jfs xfs exportfs reiserfs arc4 snd_hda_codec_conexant i915 snd_hda_intel snd_hda_codec snd_hwdep snd_pcm drm_kms_helper thinkpad_acpi snd_timer psmouse snd drm i2c_algo_bit video soundcore snd_page_alloc nvram output tp_smapi thinkpad_ec ahci libahci [last unloaded: iwlagn]
[15885.511466] Pid: 8977, comm: iperf Not tainted 2.6.37-12-generic #26
[15885.511471] Call Trace:
[15885.511484]  [<c05f92ce>] ? printk+0x30/0x32
[15885.511498]  [<c014fea2>] warn_slowpath_common+0x72/0xa0
[15885.511524]  [<f999d491>] ? __ieee80211_wake_queue+0xf1/0x100 [mac80211]
[15885.511549]  [<f999d491>] ? __ieee80211_wake_queue+0xf1/0x100 [mac80211]
[15885.511559]  [<c014fef2>] warn_slowpath_null+0x22/0x30
[15885.511584]  [<f999d491>] __ieee80211_wake_queue+0xf1/0x100 [mac80211]
[15885.511594]  [<c05fbaef>] ? _raw_spin_lock_irqsave+0x2f/0x50
[15885.511620]  [<f999da97>] ieee80211_wake_queue_by_reason+0x37/0x50 [mac80211]
[15885.511646]  [<f999dabf>] ieee80211_wake_queue+0xf/0x20 [mac80211]
[15885.511671]  [<fa5c72b4>] iwlagn_rx_reply_tx+0x294/0x3e0 [iwlagn]
[15885.511690]  [<fa5a9071>] iwl_rx_handle+0x121/0x500 [iwlagn]
[15885.511701]  [<c0517c2c>] ? consume_skb+0x2c/0x80
[15885.511721]  [<f99838b0>] ? ieee80211_tx_status+0x660/0x730 [mac80211]
[15885.511740]  [<fa5aa82e>] iwl_irq_tasklet+0x30e/0x1060 [iwlagn]
[15885.511749]  [<c0517850>] ? skb_dequeue+0x50/0x70
[15885.511769]  [<f998252b>] ? ieee80211_tasklet_handler+0x7b/0xc0 [mac80211]
[15885.511779]  [<c0156593>] tasklet_action+0x73/0x110
[15885.511788]  [<c0156c6b>] __do_softirq+0x8b/0x180
[15885.511797]  [<c0529aa0>] ? dev_addr_init+0x80/0x90
[15885.511805]  [<c0156be0>] ? __do_softirq+0x0/0x180
[15885.511810]  <IRQ>  [<c0156e3d>] ? irq_exit+0x6d/0x80
[15885.511827]  [<c0602992>] ? do_IRQ+0x52/0xc0
[15885.511835]  [<c0517bad>] ? __kfree_skb+0x3d/0x90
[15885.511845]  [<c0103770>] ? common_interrupt+0x30/0x38
[15885.511856]  [<c0376a74>] ? csum_partial_copy_generic+0x5c/0xf8
[15885.511865]  [<c051b273>] ? csum_partial_copy_fromiovecend+0x113/0x1f0
[15885.511875]  [<c0551862>] ? ip_generic_getfrag+0x42/0xb0
[15885.511883]  [<c0553877>] ? ip_append_data+0x6c7/0x9d0
[15885.511892]  [<c0551820>] ? ip_generic_getfrag+0x0/0xb0
[15885.511903]  [<c0574ea6>] ? udp_sendmsg+0x2c6/0x680
[15885.511915]  [<c0140d41>] ? entity_tick+0x21/0xf0
[15885.511925]  [<c057cd59>] ? inet_sendmsg+0x69/0xa0
[15885.511935]  [<c034a1c5>] ? apparmor_socket_sendmsg+0x15/0x20
[15885.511944]  [<c05111b8>] ? sock_aio_write+0x128/0x140
[15885.511957]  [<c0226054>] ? do_sync_write+0xa4/0xe0
[15885.511965]  [<c05f9794>] ? schedule+0x3a4/0x750
[15885.511974]  [<c022647a>] ? rw_verify_area+0x6a/0x110
[15885.511982]  [<c02268b2>] ? vfs_write+0x152/0x170
[15885.511990]  [<c0226ae2>] ? sys_write+0x42/0x70
[15885.511999]  [<c05fbd74>] ? syscall_call+0x7/0xb
[15885.512010]  [<c05f0000>] ? calibrate_delay_direct+0x48/0xf0
[15885.512017] ---[ end trace 3aca8422edac6e4d ]---
[15885.520360] cfg80211: All devices are disconnected, going to restore regulatory settings
[15885.520365] cfg80211: Restoring regulatory settings






[11ng 20Mhz]


$ iw wlan0 link
Connected to 00:0c:42<bleep> (on wlan0)
	SSID: <bleep>
	freq: 2437
	RX: 1160835 bytes (2642 packets)
	TX: 1076040 bytes (1865 packets)
	signal: -49 dBm
	tx bitrate: 117.0 MBit/s MCS 14
$ iperf -c 10.0.0.10 -u -b 40m
------------------------------------------------------------
Client connecting to 10.0.0.10, UDP port 5001
Sending 1470 byte datagrams
UDP buffer size:  112 KByte (default)
------------------------------------------------------------
[  3] local 10.0.0.9 port 40426 connected with 10.0.0.10 port 5001
[ ID] Interval       Transfer     Bandwidth
[  3]  0.0-10.0 sec  24.2 MBytes  20.3 Mbits/sec
[  3] Sent 17275 datagrams
[  3] WARNING: did not receive ack of last datagram after 10 tries.
$ dmesg
[16259.408116] wlan0: no IPv6 routers present
[16276.274895] iwlagn 0000:03:00.0: Received BA when not expected
[16276.292118] iwlagn 0000:03:00.0: Received BA when not expected
[16276.339698] iwlagn 0000:03:00.0: Received BA when not expected
[16276.502965] iwlagn 0000:03:00.0: Received BA when not expected
[16276.540802] iwlagn 0000:03:00.0: Received BA when not expected
[16276.633697] iwlagn 0000:03:00.0: Received BA when not expected
[16276.652073] iwlagn 0000:03:00.0: Received BA when not expected
[16276.662690] iwlagn 0000:03:00.0: Received BA when not expected
[16276.677445] iwlagn 0000:03:00.0: Received BA when not expected
[16276.688901] iwlagn 0000:03:00.0: Received BA when not expected
[16276.702001] iwlagn 0000:03:00.0: Received BA when not expected
[16276.715143] iwlagn 0000:03:00.0: Received BA when not expected
[16276.735881] iwlagn 0000:03:00.0: Received BA when not expected
[16276.745117] iwlagn 0000:03:00.0: Received BA when not expected
[16276.779169] iwlagn 0000:03:00.0: Received BA when not expected
[16276.953070] iwlagn 0000:03:00.0: Received BA when not expected
[16276.959240] iwlagn 0000:03:00.0: Received BA when not expected
[16276.968402] iwlagn 0000:03:00.0: Received BA when not expected
[16276.984255] iwlagn 0000:03:00.0: Received BA when not expected
[16276.993577] iwlagn 0000:03:00.0: Received BA when not expected
[16277.003169] iwlagn 0000:03:00.0: Received BA when not expected
[16277.011532] iwlagn 0000:03:00.0: Received BA when not expected
[16277.027605] iwlagn 0000:03:00.0: Received BA when not expected
[16277.049783] iwlagn 0000:03:00.0: Received BA when not expected
[16277.056097] iwlagn 0000:03:00.0: Received BA when not expected
[16277.071056] iwlagn 0000:03:00.0: Received BA when not expected
[16277.080043] iwlagn 0000:03:00.0: Received BA when not expected
[16277.091359] iwlagn 0000:03:00.0: Received BA when not expected
[16277.098844] iwlagn 0000:03:00.0: Received BA when not expected
[16277.117488] iwlagn 0000:03:00.0: Received BA when not expected
[16277.251588] iwlagn 0000:03:00.0: Received BA when not expected
[16277.278875] iwlagn 0000:03:00.0: Received BA when not expected
[16277.300721] iwlagn 0000:03:00.0: Received BA when not expected
[16277.403415] iwlagn 0000:03:00.0: Received BA when not expected
[16277.422482] iwlagn 0000:03:00.0: Received BA when not expected
[16277.489690] iwlagn 0000:03:00.0: Received BA when not expected
[16277.502648] iwlagn 0000:03:00.0: Received BA when not expected
[16277.643401] iwlagn 0000:03:00.0: Received BA when not expected
[16277.657222] iwlagn 0000:03:00.0: Received BA when not expected
[16277.670941] iwlagn 0000:03:00.0: Received BA when not expected
[16277.690014] iwlagn 0000:03:00.0: Received BA when not expected
[16277.766751] iwlagn 0000:03:00.0: Received BA when not expected
[16277.782722] iwlagn 0000:03:00.0: Received BA when not expected
[16277.810446] iwlagn 0000:03:00.0: Received BA when not expected
[16277.819778] iwlagn 0000:03:00.0: Received BA when not expected
[16277.831045] iwlagn 0000:03:00.0: Received BA when not expected
[16277.988745] iwlagn 0000:03:00.0: Received BA when not expected
[16278.040593] iwlagn 0000:03:00.0: Received BA when not expected
[16278.127359] iwlagn 0000:03:00.0: Received BA when not expected
[16278.189403] iwlagn 0000:03:00.0: Received BA when not expected
[16278.369840] iwlagn 0000:03:00.0: Received BA when not expected
[16278.382195] iwlagn 0000:03:00.0: Received BA when not expected
[16278.400898] iwlagn 0000:03:00.0: Received BA when not expected
[16278.410811] iwlagn 0000:03:00.0: Received BA when not expected
[16278.421781] iwlagn 0000:03:00.0: Received BA when not expected
[16278.568621] iwlagn 0000:03:00.0: Received BA when not expected
[16278.586829] iwlagn 0000:03:00.0: Received BA when not expected
[16278.619595] iwlagn 0000:03:00.0: Received BA when not expected
[16278.639644] iwlagn 0000:03:00.0: Received BA when not expected
[16278.649872] iwlagn 0000:03:00.0: Received BA when not expected
[16278.729872] iwlagn 0000:03:00.0: Received BA when not expected
[16278.745058] iwlagn 0000:03:00.0: Received BA when not expected
[16278.756154] iwlagn 0000:03:00.0: Received BA when not expected
[16278.894531] iwlagn 0000:03:00.0: Received BA when not expected
[16278.918977] iwlagn 0000:03:00.0: Received BA when not expected
[16278.934743] iwlagn 0000:03:00.0: Received BA when not expected
[16278.944028] iwlagn 0000:03:00.0: Received BA when not expected
[16278.959552] iwlagn 0000:03:00.0: Received BA when not expected
[16278.967284] iwlagn 0000:03:00.0: Received BA when not expected
[16278.978624] iwlagn 0000:03:00.0: Received BA when not expected
[16278.986406] iwlagn 0000:03:00.0: Received BA when not expected
[16278.995147] iwlagn 0000:03:00.0: Received BA when not expected
[16279.099335] iwlagn 0000:03:00.0: Received BA when not expected
[16279.207925] iwlagn 0000:03:00.0: Received BA when not expected
[16279.219323] iwlagn 0000:03:00.0: Received BA when not expected
[16279.233188] iwlagn 0000:03:00.0: Received BA when not expected
[16279.249790] iwlagn 0000:03:00.0: Received BA when not expected
[16279.374842] iwlagn 0000:03:00.0: Received BA when not expected
[16279.413643] iwlagn 0000:03:00.0: Received BA when not expected
[16279.502933] iwlagn 0000:03:00.0: Received BA when not expected
[16279.508108] ieee80211 phy4: wlan0: No probe response from AP 00:0c:42<bleep> after 500ms, disconnecting.
[16279.522466] iwlagn 0000:03:00.0: Stopping AGG while state not ON or starting
[16279.526775] ------------[ cut here ]------------
[16279.526812] WARNING: at /home/towolf/src/kernel/linux-2.6.37-12.26iwlwifi/net/mac80211/util.c:275 __ieee80211_wake_queue+0xf1/0x100 [mac80211]()
[16279.526820] Hardware name: 2776LFG
[16279.526824] Modules linked in: iwlagn iwlcore mac80211 cfg80211 btrfs zlib_deflate libcrc32c ufs qnx4 hfsplus hfs minix ntfs vfat msdos fat jfs xfs exportfs reiserfs arc4 snd_hda_codec_conexant i915 snd_hda_intel snd_hda_codec snd_hwdep snd_pcm drm_kms_helper thinkpad_acpi snd_timer psmouse snd drm i2c_algo_bit video soundcore snd_page_alloc nvram output tp_smapi thinkpad_ec ahci libahci [last unloaded: iwlagn]
[16279.526917] Pid: 9338, comm: iperf Tainted: G        W   2.6.37-12-generic #26
[16279.526922] Call Trace:
[16279.526936]  [<c05f92ce>] ? printk+0x30/0x32
[16279.526949]  [<c014fea2>] warn_slowpath_common+0x72/0xa0
[16279.526975]  [<f999d491>] ? __ieee80211_wake_queue+0xf1/0x100 [mac80211]
[16279.527001]  [<f999d491>] ? __ieee80211_wake_queue+0xf1/0x100 [mac80211]
[16279.527010]  [<c014fef2>] warn_slowpath_null+0x22/0x30
[16279.527035]  [<f999d491>] __ieee80211_wake_queue+0xf1/0x100 [mac80211]
[16279.527045]  [<c05fbaef>] ? _raw_spin_lock_irqsave+0x2f/0x50
[16279.527072]  [<f999da97>] ieee80211_wake_queue_by_reason+0x37/0x50 [mac80211]
[16279.527098]  [<f999dabf>] ieee80211_wake_queue+0xf/0x20 [mac80211]
[16279.527122]  [<fa5c72b4>] iwlagn_rx_reply_tx+0x294/0x3e0 [iwlagn]
[16279.527141]  [<fa5a9071>] iwl_rx_handle+0x121/0x500 [iwlagn]
[16279.527150]  [<c0169891>] ? __queue_work+0xe1/0x2a0
[16279.527168]  [<fa5aa82e>] iwl_irq_tasklet+0x30e/0x1060 [iwlagn]
[16279.527178]  [<c023745f>] ? __d_free+0x2f/0x50
[16279.527188]  [<c0156593>] tasklet_action+0x73/0x110
[16279.527197]  [<c0156c6b>] __do_softirq+0x8b/0x180
[16279.527206]  [<c0529aa0>] ? dev_addr_init+0x80/0x90
[16279.527215]  [<c0156be0>] ? __do_softirq+0x0/0x180
[16279.527220]  <IRQ>  [<c0156e3d>] ? irq_exit+0x6d/0x80
[16279.527236]  [<c0602992>] ? do_IRQ+0x52/0xc0
[16279.527246]  [<c017e01a>] ? tick_dev_program_event+0x3a/0x140
[16279.527256]  [<c0103770>] ? common_interrupt+0x30/0x38
[16279.527265]  [<c017007b>] ? posix_cpu_timer_schedule+0x9b/0x150
[16279.527275]  [<c05fb9f5>] ? _raw_spin_unlock_irqrestore+0x15/0x20
[16279.527284]  [<c0171e53>] ? __hrtimer_start_range_ns+0x193/0x470
[16279.527293]  [<c0172186>] ? hrtimer_start_range_ns+0x26/0x30
[16279.527302]  [<c05faa29>] ? do_nanosleep+0x89/0xd0
[16279.527310]  [<c0172926>] ? hrtimer_nanosleep+0xa6/0x150
[16279.527319]  [<c0171560>] ? hrtimer_wakeup+0x0/0x30
[16279.527327]  [<c0172186>] ? hrtimer_start_range_ns+0x26/0x30
[16279.527335]  [<c0172a21>] ? sys_nanosleep+0x51/0x60
[16279.527344]  [<c05fbd74>] ? syscall_call+0x7/0xb
[16279.527354]  [<c05f0000>] ? calibrate_delay_direct+0x48/0xf0
[16279.527360] ---[ end trace 3aca8422edac6e4e ]---
[16279.532125] cfg80211: All devices are disconnected, going to restore regulatory settings
[16279.532133] cfg80211: Restoring regulatory settings



[11g works]


$ iw wlan0 link
Connected to 00:0c:42<bleep> (on wlan0)
	SSID: <bleep>
	freq: 2437
	RX: 1114827 bytes (2279 packets)
	TX: 947542 bytes (1762 packets)
	signal: -44 dBm
	tx bitrate: 54.0 MBit/s
$ dmesg
$ iperf -c 10.0.0.10 
------------------------------------------------------------
Client connecting to 10.0.0.10, TCP port 5001
TCP window size: 16.0 KByte (default)
------------------------------------------------------------
[  3] local 10.0.0.9 port 48903 connected with 10.0.0.10 port 5001
[ ID] Interval       Transfer     Bandwidth
[  3]  0.0-10.1 sec  28.0 MBytes  23.3 Mbits/sec
$ iperf -c 10.0.0.10 -u -b 20m
------------------------------------------------------------
Client connecting to 10.0.0.10, UDP port 5001
Sending 1470 byte datagrams
UDP buffer size:  112 KByte (default)
------------------------------------------------------------
[  3] local 10.0.0.9 port 43616 connected with 10.0.0.10 port 5001
[ ID] Interval       Transfer     Bandwidth
[  3]  0.0-10.0 sec  21.8 MBytes  18.3 Mbits/sec
[  3] Sent 15560 datagrams
[  3] Server Report:
[  3]  0.0-10.2 sec  21.8 MBytes  18.0 Mbits/sec   2.017 ms    0/15559 (0%)
[  3]  0.0-10.2 sec  1 datagrams received out-of-order
$ dmesg
$
$
Comment 89 wey-yi.w.guy 2011-01-18 19:33:22 UTC
(In reply to comment #81)
> The router is a netgear WNDR3700, set to channel 153, mode 'Up to 300Mbps'.
> lspci and iwconfig below.
> iwconfig
> wlan0     IEEE 802.11abgn  ESSID:"zzzzzzzz"  
>           Mode:Managed  Frequency:5.765 GHz  Access Point: zzzzzzz
>           Bit Rate=150 Mb/s   Tx-Power=15 dBm   
>           Retry  long limit:7   RTS thr:off   Fragment thr:off
>           Power Management:off
>           Link Quality=67/70  Signal level=-43 dBm  
>           Rx invalid nwid:0  Rx invalid crypt:0  Rx invalid frag:0
>           Tx excessive retries:2118  Invalid misc:721   Missed beacon:0
> lspci
> 05:00.0 Network controller: Intel Corporation WiFi Link 5100
>         Subsystem: Intel Corporation WiFi Link 5100 AGN
>         Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr-
> Stepping- SERR- FastB2B- DisINTx-
>         Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort-
>         <TAbort-
> <MAbort- >SERR- <PERR- INTx-
>         Latency: 0, Cache Line Size: 64 bytes
>         Interrupt: pin A routed to IRQ 43
>         Region 0: Memory at d1900000 (64-bit, non-prefetchable) [size=8K]
>         Capabilities: [c8] Power Management version 3
>                 Flags: PMEClk- DSI+ D1- D2- AuxCurrent=0mA
> PME(D0+,D1-,D2-,D3hot+,D3cold+)
>                 Status: D0 NoSoftRst- PME-Enable- DSel=0 DScale=0 PME-
>         Capabilities: [d0] MSI: Enable+ Count=1/1 Maskable- 64bit+
>                 Address: 00000000fee0300c  Data: 4181
>         Capabilities: [e0] Express (v1) Endpoint, MSI 00
>                 DevCap: MaxPayload 128 bytes, PhantFunc 0, Latency L0s
>                 <512ns,
> L1 unlimited
>                         ExtTag- AttnBtn- AttnInd- PwrInd- RBE+ FLReset+
>                 DevCtl: Report errors: Correctable- Non-Fatal- Fatal-
> Unsupported-
>                         RlxdOrd+ ExtTag- PhantFunc- AuxPwr- NoSnoop+ FLReset-
>                         MaxPayload 128 bytes, MaxReadReq 128 bytes
>                 DevSta: CorrErr+ UncorrErr- FatalErr- UnsuppReq+ AuxPwr+
> TransPend-
>                 LnkCap: Port #0, Speed 2.5GT/s, Width x1, ASPM L0s L1,
>                 Latency
> L0 <128ns, L1 <32us
>                         ClockPM+ Surprise- LLActRep- BwNot-
>                 LnkCtl: ASPM L1 Enabled; RCB 64 bytes Disabled- Retrain-
> CommClk+
>                         ExtSynch- ClockPM- AutWidDis- BWInt- AutBWInt-
>                 LnkSta: Speed 2.5GT/s, Width x1, TrErr- Train- SlotClk+
> DLActive- BWMgmt- ABWMgmt-
>         Capabilities: [100 v1] Advanced Error Reporting
>                 UESta:  DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt-
> RxOF- MalfTLP- ECRC- UnsupReq- ACSViol-
>                 UEMsk:  DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt-
> RxOF- MalfTLP- ECRC- UnsupReq- ACSViol-
>                 UESvrt: DLP+ SDES- TLP- FCP+ CmpltTO- CmpltAbrt- UnxCmplt-
> RxOF+ MalfTLP+ ECRC- UnsupReq- ACSViol-
>                 CESta:  RxErr- BadTLP- BadDLLP- Rollover- Timeout-
>                 NonFatalErr+
>                 CEMsk:  RxErr- BadTLP- BadDLLP- Rollover- Timeout-
>                 NonFatalErr+
>                 AERCap: First Error Pointer: 00, GenCap- CGenEn- ChkCap-
>                 ChkEn-
>         Capabilities: [140 v1] Device Serial Number 00-16-ea-ff-ff-4e-09-dc
>         Kernel driver in use: iwlagn
>         Kernel modules: iwlagn

based on the information you provide, I can not tell you are using 20MHz or 40MHz, could you use the following command which can show the current tx bitrate

$iw dev wlanX station dump

Thanks
Wey
Comment 90 wey-yi.w.guy 2011-01-18 19:40:41 UTC
(In reply to comment #88)
> Yes, that was 11na with HT40- on channel 48. Everything is unencrypted, a
> plain
> connection.
> I get the same for 11na with HT20 on the same channel, and again the same
> with
> 11ng on channel 6. There’s even something like a kernel oops referring to
> __ieee80211_wake_queue() in the dmesg. See long output below.
> Now, on normal 54M 11g it works like it should. There’s no output in dmesg
> running iperf.
> [11na 20Mhz]
> $ iw wlan0 link
> Connected to 00:0c:42<bleep> (on wlan0)
>     SSID: <bleep>
>     freq: 5240
>     RX: 1263547 bytes (3817 packets)
>     TX: 1094111 bytes (2032 packets)
>     signal: -52 dBm
>     tx bitrate: 78.0 MBit/s MCS 12
> $ iperf -c 10.0.0.10 -u -b 40m
> ------------------------------------------------------------
> Client connecting to 10.0.0.10, UDP port 5001
> Sending 1470 byte datagrams
> UDP buffer size:  112 KByte (default)
> ------------------------------------------------------------
> [  3] local 10.0.0.9 port 48605 connected with 10.0.0.10 port 5001
> [ ID] Interval       Transfer     Bandwidth
> [  3]  0.0-10.0 sec  21.5 MBytes  18.0 Mbits/sec
> [  3] Sent 15317 datagrams
> [  3] WARNING: did not receive ack of last datagram after 10 tries.
> $ dmesg
> [15879.073023] iwlagn 0000:03:00.0: Aggregation not enabled for tid 0 because
> load = 0
> [15879.991101] iwlagn 0000:03:00.0: iwlagn_tx_agg_start on ra =
> 00:0c:42<bleep>
> tid = 0
> [15881.845349] iwlagn 0000:03:00.0: Received BA when not expected
> [15881.971357] iwlagn 0000:03:00.0: Received BA when not expected
> [15882.024417] iwlagn 0000:03:00.0: Received BA when not expected
> [15882.173146] iwlagn 0000:03:00.0: Received BA when not expected
> [15882.306437] iwlagn 0000:03:00.0: Received BA when not expected
> [15882.554100] iwlagn 0000:03:00.0: Received BA when not expected
> [15882.781407] iwlagn 0000:03:00.0: Received BA when not expected
> [15882.794118] iwlagn 0000:03:00.0: Received BA when not expected
> [15882.918819] iwlagn 0000:03:00.0: Received BA when not expected
> [15883.112406] iwlagn 0000:03:00.0: Received BA when not expected
> [15883.331439] iwlagn 0000:03:00.0: Received BA when not expected
> [15883.403584] iwlagn 0000:03:00.0: Received BA when not expected
> [15883.411567] iwlagn 0000:03:00.0: Received BA when not expected
> [15883.453295] iwlagn 0000:03:00.0: Received BA when not expected
> [15883.531676] iwlagn 0000:03:00.0: Received BA when not expected
> [15883.547141] iwlagn 0000:03:00.0: Received BA when not expected
> [15883.646557] iwlagn 0000:03:00.0: Received BA when not expected
> [15883.655604] iwlagn 0000:03:00.0: Received BA when not expected
> [15883.674290] iwlagn 0000:03:00.0: Received BA when not expected
> [15883.696131] iwlagn 0000:03:00.0: Received BA when not expected
> [15883.701215] iwlagn 0000:03:00.0: Received BA when not expected
> [15883.708770] iwlagn 0000:03:00.0: Received BA when not expected
> [15883.715014] iwlagn 0000:03:00.0: Received BA when not expected
> [15883.724601] iwlagn 0000:03:00.0: Received BA when not expected
> [15883.854559] iwlagn 0000:03:00.0: Received BA when not expected
> [15883.854877] iwlagn 0000:03:00.0: Received BA when not expected
> [15883.870096] iwlagn 0000:03:00.0: Received BA when not expected
> [15883.882595] iwlagn 0000:03:00.0: Received BA when not expected
> [15883.893112] iwlagn 0000:03:00.0: Received BA when not expected
> [15883.899648] iwlagn 0000:03:00.0: Received BA when not expected
> [15883.914041] iwlagn 0000:03:00.0: Received BA when not expected
> [15883.932365] iwlagn 0000:03:00.0: Received BA when not expected
> [15883.947263] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.044036] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.052262] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.072116] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.075145] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.080784] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.093898] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.103235] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.122295] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.295949] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.323679] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.342263] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.357780] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.368082] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.382672] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.472658] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.479364] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.488411] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.503859] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.513093] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.541127] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.551150] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.563195] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.573191] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.615590] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.723216] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.742902] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.752603] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.762772] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.932438] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.938828] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.947995] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.958488] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.969979] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.982246] iwlagn 0000:03:00.0: Received BA when not expected
> [15884.991600] iwlagn 0000:03:00.0: Received BA when not expected
> [15885.097536] iwlagn 0000:03:00.0: Received BA when not expected
> [15885.113068] iwlagn 0000:03:00.0: Received BA when not expected
> [15885.125358] iwlagn 0000:03:00.0: Received BA when not expected
> [15885.133226] iwlagn 0000:03:00.0: Received BA when not expected
> [15885.156518] iwlagn 0000:03:00.0: Received BA when not expected
> [15885.156812] iwlagn 0000:03:00.0: Received BA when not expected
> [15885.426373] iwlagn 0000:03:00.0: Received BA when not expected
> [15885.508151] ieee80211 phy2: wlan0: No probe response from AP
> 00:0c:42<bleep>
> after 500ms, disconnecting.
> [15885.508851] iwlagn 0000:03:00.0: Stopping AGG while state not ON or
> starting
> [15885.511325] ------------[ cut here ]------------
> [15885.511360] WARNING: at
> /home/towolf/src/kernel/linux-2.6.37-12.26iwlwifi/net/mac80211/util.c:275
> __ieee80211_wake_queue+0xf1/0x100 [mac80211]()
> [15885.511368] Hardware name: 2776LFG
> [15885.511372] Modules linked in: iwlagn iwlcore mac80211 cfg80211 btrfs
> zlib_deflate libcrc32c ufs qnx4 hfsplus hfs minix ntfs vfat msdos fat jfs xfs
> exportfs reiserfs arc4 snd_hda_codec_conexant i915 snd_hda_intel
> snd_hda_codec
> snd_hwdep snd_pcm drm_kms_helper thinkpad_acpi snd_timer psmouse snd drm
> i2c_algo_bit video soundcore snd_page_alloc nvram output tp_smapi thinkpad_ec
> ahci libahci [last unloaded: iwlagn]
> [15885.511466] Pid: 8977, comm: iperf Not tainted 2.6.37-12-generic #26
> [15885.511471] Call Trace:
> [15885.511484]  [<c05f92ce>] ? printk+0x30/0x32
> [15885.511498]  [<c014fea2>] warn_slowpath_common+0x72/0xa0
> [15885.511524]  [<f999d491>] ? __ieee80211_wake_queue+0xf1/0x100 [mac80211]
> [15885.511549]  [<f999d491>] ? __ieee80211_wake_queue+0xf1/0x100 [mac80211]
> [15885.511559]  [<c014fef2>] warn_slowpath_null+0x22/0x30
> [15885.511584]  [<f999d491>] __ieee80211_wake_queue+0xf1/0x100 [mac80211]
> [15885.511594]  [<c05fbaef>] ? _raw_spin_lock_irqsave+0x2f/0x50
> [15885.511620]  [<f999da97>] ieee80211_wake_queue_by_reason+0x37/0x50
> [mac80211]
> [15885.511646]  [<f999dabf>] ieee80211_wake_queue+0xf/0x20 [mac80211]
> [15885.511671]  [<fa5c72b4>] iwlagn_rx_reply_tx+0x294/0x3e0 [iwlagn]
> [15885.511690]  [<fa5a9071>] iwl_rx_handle+0x121/0x500 [iwlagn]
> [15885.511701]  [<c0517c2c>] ? consume_skb+0x2c/0x80
> [15885.511721]  [<f99838b0>] ? ieee80211_tx_status+0x660/0x730 [mac80211]
> [15885.511740]  [<fa5aa82e>] iwl_irq_tasklet+0x30e/0x1060 [iwlagn]
> [15885.511749]  [<c0517850>] ? skb_dequeue+0x50/0x70
> [15885.511769]  [<f998252b>] ? ieee80211_tasklet_handler+0x7b/0xc0 [mac80211]
> [15885.511779]  [<c0156593>] tasklet_action+0x73/0x110
> [15885.511788]  [<c0156c6b>] __do_softirq+0x8b/0x180
> [15885.511797]  [<c0529aa0>] ? dev_addr_init+0x80/0x90
> [15885.511805]  [<c0156be0>] ? __do_softirq+0x0/0x180
> [15885.511810]  <IRQ>  [<c0156e3d>] ? irq_exit+0x6d/0x80
> [15885.511827]  [<c0602992>] ? do_IRQ+0x52/0xc0
> [15885.511835]  [<c0517bad>] ? __kfree_skb+0x3d/0x90
> [15885.511845]  [<c0103770>] ? common_interrupt+0x30/0x38
> [15885.511856]  [<c0376a74>] ? csum_partial_copy_generic+0x5c/0xf8
> [15885.511865]  [<c051b273>] ? csum_partial_copy_fromiovecend+0x113/0x1f0
> [15885.511875]  [<c0551862>] ? ip_generic_getfrag+0x42/0xb0
> [15885.511883]  [<c0553877>] ? ip_append_data+0x6c7/0x9d0
> [15885.511892]  [<c0551820>] ? ip_generic_getfrag+0x0/0xb0
> [15885.511903]  [<c0574ea6>] ? udp_sendmsg+0x2c6/0x680
> [15885.511915]  [<c0140d41>] ? entity_tick+0x21/0xf0
> [15885.511925]  [<c057cd59>] ? inet_sendmsg+0x69/0xa0
> [15885.511935]  [<c034a1c5>] ? apparmor_socket_sendmsg+0x15/0x20
> [15885.511944]  [<c05111b8>] ? sock_aio_write+0x128/0x140
> [15885.511957]  [<c0226054>] ? do_sync_write+0xa4/0xe0
> [15885.511965]  [<c05f9794>] ? schedule+0x3a4/0x750
> [15885.511974]  [<c022647a>] ? rw_verify_area+0x6a/0x110
> [15885.511982]  [<c02268b2>] ? vfs_write+0x152/0x170
> [15885.511990]  [<c0226ae2>] ? sys_write+0x42/0x70
> [15885.511999]  [<c05fbd74>] ? syscall_call+0x7/0xb
> [15885.512010]  [<c05f0000>] ? calibrate_delay_direct+0x48/0xf0
> [15885.512017] ---[ end trace 3aca8422edac6e4d ]---
> [15885.520360] cfg80211: All devices are disconnected, going to restore
> regulatory settings
> [15885.520365] cfg80211: Restoring regulatory settings
> [11ng 20Mhz]
> $ iw wlan0 link
> Connected to 00:0c:42<bleep> (on wlan0)
>     SSID: <bleep>
>     freq: 2437
>     RX: 1160835 bytes (2642 packets)
>     TX: 1076040 bytes (1865 packets)
>     signal: -49 dBm
>     tx bitrate: 117.0 MBit/s MCS 14
> $ iperf -c 10.0.0.10 -u -b 40m
> ------------------------------------------------------------
> Client connecting to 10.0.0.10, UDP port 5001
> Sending 1470 byte datagrams
> UDP buffer size:  112 KByte (default)
> ------------------------------------------------------------
> [  3] local 10.0.0.9 port 40426 connected with 10.0.0.10 port 5001
> [ ID] Interval       Transfer     Bandwidth
> [  3]  0.0-10.0 sec  24.2 MBytes  20.3 Mbits/sec
> [  3] Sent 17275 datagrams
> [  3] WARNING: did not receive ack of last datagram after 10 tries.
> $ dmesg
> [16259.408116] wlan0: no IPv6 routers present
> [16276.274895] iwlagn 0000:03:00.0: Received BA when not expected
> [16276.292118] iwlagn 0000:03:00.0: Received BA when not expected
> [16276.339698] iwlagn 0000:03:00.0: Received BA when not expected
> [16276.502965] iwlagn 0000:03:00.0: Received BA when not expected
> [16276.540802] iwlagn 0000:03:00.0: Received BA when not expected
> [16276.633697] iwlagn 0000:03:00.0: Received BA when not expected
> [16276.652073] iwlagn 0000:03:00.0: Received BA when not expected
> [16276.662690] iwlagn 0000:03:00.0: Received BA when not expected
> [16276.677445] iwlagn 0000:03:00.0: Received BA when not expected
> [16276.688901] iwlagn 0000:03:00.0: Received BA when not expected
> [16276.702001] iwlagn 0000:03:00.0: Received BA when not expected
> [16276.715143] iwlagn 0000:03:00.0: Received BA when not expected
> [16276.735881] iwlagn 0000:03:00.0: Received BA when not expected
> [16276.745117] iwlagn 0000:03:00.0: Received BA when not expected
> [16276.779169] iwlagn 0000:03:00.0: Received BA when not expected
> [16276.953070] iwlagn 0000:03:00.0: Received BA when not expected
> [16276.959240] iwlagn 0000:03:00.0: Received BA when not expected
> [16276.968402] iwlagn 0000:03:00.0: Received BA when not expected
> [16276.984255] iwlagn 0000:03:00.0: Received BA when not expected
> [16276.993577] iwlagn 0000:03:00.0: Received BA when not expected
> [16277.003169] iwlagn 0000:03:00.0: Received BA when not expected
> [16277.011532] iwlagn 0000:03:00.0: Received BA when not expected
> [16277.027605] iwlagn 0000:03:00.0: Received BA when not expected
> [16277.049783] iwlagn 0000:03:00.0: Received BA when not expected
> [16277.056097] iwlagn 0000:03:00.0: Received BA when not expected
> [16277.071056] iwlagn 0000:03:00.0: Received BA when not expected
> [16277.080043] iwlagn 0000:03:00.0: Received BA when not expected
> [16277.091359] iwlagn 0000:03:00.0: Received BA when not expected
> [16277.098844] iwlagn 0000:03:00.0: Received BA when not expected
> [16277.117488] iwlagn 0000:03:00.0: Received BA when not expected
> [16277.251588] iwlagn 0000:03:00.0: Received BA when not expected
> [16277.278875] iwlagn 0000:03:00.0: Received BA when not expected
> [16277.300721] iwlagn 0000:03:00.0: Received BA when not expected
> [16277.403415] iwlagn 0000:03:00.0: Received BA when not expected
> [16277.422482] iwlagn 0000:03:00.0: Received BA when not expected
> [16277.489690] iwlagn 0000:03:00.0: Received BA when not expected
> [16277.502648] iwlagn 0000:03:00.0: Received BA when not expected
> [16277.643401] iwlagn 0000:03:00.0: Received BA when not expected
> [16277.657222] iwlagn 0000:03:00.0: Received BA when not expected
> [16277.670941] iwlagn 0000:03:00.0: Received BA when not expected
> [16277.690014] iwlagn 0000:03:00.0: Received BA when not expected
> [16277.766751] iwlagn 0000:03:00.0: Received BA when not expected
> [16277.782722] iwlagn 0000:03:00.0: Received BA when not expected
> [16277.810446] iwlagn 0000:03:00.0: Received BA when not expected
> [16277.819778] iwlagn 0000:03:00.0: Received BA when not expected
> [16277.831045] iwlagn 0000:03:00.0: Received BA when not expected
> [16277.988745] iwlagn 0000:03:00.0: Received BA when not expected
> [16278.040593] iwlagn 0000:03:00.0: Received BA when not expected
> [16278.127359] iwlagn 0000:03:00.0: Received BA when not expected
> [16278.189403] iwlagn 0000:03:00.0: Received BA when not expected
> [16278.369840] iwlagn 0000:03:00.0: Received BA when not expected
> [16278.382195] iwlagn 0000:03:00.0: Received BA when not expected
> [16278.400898] iwlagn 0000:03:00.0: Received BA when not expected
> [16278.410811] iwlagn 0000:03:00.0: Received BA when not expected
> [16278.421781] iwlagn 0000:03:00.0: Received BA when not expected
> [16278.568621] iwlagn 0000:03:00.0: Received BA when not expected
> [16278.586829] iwlagn 0000:03:00.0: Received BA when not expected
> [16278.619595] iwlagn 0000:03:00.0: Received BA when not expected
> [16278.639644] iwlagn 0000:03:00.0: Received BA when not expected
> [16278.649872] iwlagn 0000:03:00.0: Received BA when not expected
> [16278.729872] iwlagn 0000:03:00.0: Received BA when not expected
> [16278.745058] iwlagn 0000:03:00.0: Received BA when not expected
> [16278.756154] iwlagn 0000:03:00.0: Received BA when not expected
> [16278.894531] iwlagn 0000:03:00.0: Received BA when not expected
> [16278.918977] iwlagn 0000:03:00.0: Received BA when not expected
> [16278.934743] iwlagn 0000:03:00.0: Received BA when not expected
> [16278.944028] iwlagn 0000:03:00.0: Received BA when not expected
> [16278.959552] iwlagn 0000:03:00.0: Received BA when not expected
> [16278.967284] iwlagn 0000:03:00.0: Received BA when not expected
> [16278.978624] iwlagn 0000:03:00.0: Received BA when not expected
> [16278.986406] iwlagn 0000:03:00.0: Received BA when not expected
> [16278.995147] iwlagn 0000:03:00.0: Received BA when not expected
> [16279.099335] iwlagn 0000:03:00.0: Received BA when not expected
> [16279.207925] iwlagn 0000:03:00.0: Received BA when not expected
> [16279.219323] iwlagn 0000:03:00.0: Received BA when not expected
> [16279.233188] iwlagn 0000:03:00.0: Received BA when not expected
> [16279.249790] iwlagn 0000:03:00.0: Received BA when not expected
> [16279.374842] iwlagn 0000:03:00.0: Received BA when not expected
> [16279.413643] iwlagn 0000:03:00.0: Received BA when not expected
> [16279.502933] iwlagn 0000:03:00.0: Received BA when not expected
> [16279.508108] ieee80211 phy4: wlan0: No probe response from AP
> 00:0c:42<bleep>
> after 500ms, disconnecting.
> [16279.522466] iwlagn 0000:03:00.0: Stopping AGG while state not ON or
> starting
> [16279.526775] ------------[ cut here ]------------
> [16279.526812] WARNING: at
> /home/towolf/src/kernel/linux-2.6.37-12.26iwlwifi/net/mac80211/util.c:275
> __ieee80211_wake_queue+0xf1/0x100 [mac80211]()
> [16279.526820] Hardware name: 2776LFG
> [16279.526824] Modules linked in: iwlagn iwlcore mac80211 cfg80211 btrfs
> zlib_deflate libcrc32c ufs qnx4 hfsplus hfs minix ntfs vfat msdos fat jfs xfs
> exportfs reiserfs arc4 snd_hda_codec_conexant i915 snd_hda_intel
> snd_hda_codec
> snd_hwdep snd_pcm drm_kms_helper thinkpad_acpi snd_timer psmouse snd drm
> i2c_algo_bit video soundcore snd_page_alloc nvram output tp_smapi thinkpad_ec
> ahci libahci [last unloaded: iwlagn]
> [16279.526917] Pid: 9338, comm: iperf Tainted: G        W   2.6.37-12-generic
> #26
> [16279.526922] Call Trace:
> [16279.526936]  [<c05f92ce>] ? printk+0x30/0x32
> [16279.526949]  [<c014fea2>] warn_slowpath_common+0x72/0xa0
> [16279.526975]  [<f999d491>] ? __ieee80211_wake_queue+0xf1/0x100 [mac80211]
> [16279.527001]  [<f999d491>] ? __ieee80211_wake_queue+0xf1/0x100 [mac80211]
> [16279.527010]  [<c014fef2>] warn_slowpath_null+0x22/0x30
> [16279.527035]  [<f999d491>] __ieee80211_wake_queue+0xf1/0x100 [mac80211]
> [16279.527045]  [<c05fbaef>] ? _raw_spin_lock_irqsave+0x2f/0x50
> [16279.527072]  [<f999da97>] ieee80211_wake_queue_by_reason+0x37/0x50
> [mac80211]
> [16279.527098]  [<f999dabf>] ieee80211_wake_queue+0xf/0x20 [mac80211]
> [16279.527122]  [<fa5c72b4>] iwlagn_rx_reply_tx+0x294/0x3e0 [iwlagn]
> [16279.527141]  [<fa5a9071>] iwl_rx_handle+0x121/0x500 [iwlagn]
> [16279.527150]  [<c0169891>] ? __queue_work+0xe1/0x2a0
> [16279.527168]  [<fa5aa82e>] iwl_irq_tasklet+0x30e/0x1060 [iwlagn]
> [16279.527178]  [<c023745f>] ? __d_free+0x2f/0x50
> [16279.527188]  [<c0156593>] tasklet_action+0x73/0x110
> [16279.527197]  [<c0156c6b>] __do_softirq+0x8b/0x180
> [16279.527206]  [<c0529aa0>] ? dev_addr_init+0x80/0x90
> [16279.527215]  [<c0156be0>] ? __do_softirq+0x0/0x180
> [16279.527220]  <IRQ>  [<c0156e3d>] ? irq_exit+0x6d/0x80
> [16279.527236]  [<c0602992>] ? do_IRQ+0x52/0xc0
> [16279.527246]  [<c017e01a>] ? tick_dev_program_event+0x3a/0x140
> [16279.527256]  [<c0103770>] ? common_interrupt+0x30/0x38
> [16279.527265]  [<c017007b>] ? posix_cpu_timer_schedule+0x9b/0x150
> [16279.527275]  [<c05fb9f5>] ? _raw_spin_unlock_irqrestore+0x15/0x20
> [16279.527284]  [<c0171e53>] ? __hrtimer_start_range_ns+0x193/0x470
> [16279.527293]  [<c0172186>] ? hrtimer_start_range_ns+0x26/0x30
> [16279.527302]  [<c05faa29>] ? do_nanosleep+0x89/0xd0
> [16279.527310]  [<c0172926>] ? hrtimer_nanosleep+0xa6/0x150
> [16279.527319]  [<c0171560>] ? hrtimer_wakeup+0x0/0x30
> [16279.527327]  [<c0172186>] ? hrtimer_start_range_ns+0x26/0x30
> [16279.527335]  [<c0172a21>] ? sys_nanosleep+0x51/0x60
> [16279.527344]  [<c05fbd74>] ? syscall_call+0x7/0xb
> [16279.527354]  [<c05f0000>] ? calibrate_delay_direct+0x48/0xf0
> [16279.527360] ---[ end trace 3aca8422edac6e4e ]---
> [16279.532125] cfg80211: All devices are disconnected, going to restore
> regulatory settings
> [16279.532133] cfg80211: Restoring regulatory settings
> [11g works]
> $ iw wlan0 link
> Connected to 00:0c:42<bleep> (on wlan0)
>     SSID: <bleep>
>     freq: 2437
>     RX: 1114827 bytes (2279 packets)
>     TX: 947542 bytes (1762 packets)
>     signal: -44 dBm
>     tx bitrate: 54.0 MBit/s
> $ dmesg
> $ iperf -c 10.0.0.10 
> ------------------------------------------------------------
> Client connecting to 10.0.0.10, TCP port 5001
> TCP window size: 16.0 KByte (default)
> ------------------------------------------------------------
> [  3] local 10.0.0.9 port 48903 connected with 10.0.0.10 port 5001
> [ ID] Interval       Transfer     Bandwidth
> [  3]  0.0-10.1 sec  28.0 MBytes  23.3 Mbits/sec
> $ iperf -c 10.0.0.10 -u -b 20m
> ------------------------------------------------------------
> Client connecting to 10.0.0.10, UDP port 5001
> Sending 1470 byte datagrams
> UDP buffer size:  112 KByte (default)
> ------------------------------------------------------------
> [  3] local 10.0.0.9 port 43616 connected with 10.0.0.10 port 5001
> [ ID] Interval       Transfer     Bandwidth
> [  3]  0.0-10.0 sec  21.8 MBytes  18.3 Mbits/sec
> [  3] Sent 15560 datagrams
> [  3] Server Report:
> [  3]  0.0-10.2 sec  21.8 MBytes  18.0 Mbits/sec   2.017 ms    0/15559 (0%)
> [  3]  0.0-10.2 sec  1 datagrams received out-of-order
> $ dmesg
> $
> $

The "Received BA when not expected" message mean uCode sending BA when driver is not expecting it.

few more question.
1) is the Power Management On?
2) what AP you are using
3) what platform you are using?

Thanks
Wey
Comment 91 Tobias Wolf 2011-01-18 19:52:37 UTC
(In reply to comment #90)
> (In reply to comment #88)
> > Yes, that was 11na with HT40- on channel 48. Everything is unencrypted, a
> plain
> > connection.
> > I get the same for 11na with HT20 on the same channel, and again the same
> with
> > 11ng on channel 6. There’s even something like a kernel oops referring to
> > __ieee80211_wake_queue() in the dmesg. See long output below.
> > Now, on normal 54M 11g it works like it should. There’s no output in dmesg
> > running iperf.

 
> The "Received BA when not expected" message mean uCode sending BA when driver
> is not expecting it.
> 
> few more question.
> 1) is the Power Management On?

At least the standard PM is off according to iwconfig: "Power Management:off"

> 2) what AP you are using

It is current OpenWrt mipsel system using R52N 92xx card with ath9k. It is creating an AP using hostapd with these settings:


# cat /var/run/hostapd-phy0.conf
ctrl_interface=/var/run/hostapd-phy0
driver=nl80211
wmm_ac_bk_cwmin=4
wmm_ac_bk_cwmax=10
wmm_ac_bk_aifs=7
wmm_ac_bk_txop_limit=0
wmm_ac_bk_acm=0
wmm_ac_be_aifs=3
wmm_ac_be_cwmin=4
wmm_ac_be_cwmax=10
wmm_ac_be_txop_limit=0
wmm_ac_be_acm=0
wmm_ac_vi_aifs=2
wmm_ac_vi_cwmin=3
wmm_ac_vi_cwmax=4
wmm_ac_vi_txop_limit=94
wmm_ac_vi_acm=0
wmm_ac_vo_aifs=2
wmm_ac_vo_cwmin=2
wmm_ac_vo_cwmax=3
wmm_ac_vo_txop_limit=47
wmm_ac_vo_acm=0
tx_queue_data3_aifs=7
tx_queue_data3_cwmin=15
tx_queue_data3_cwmax=1023
tx_queue_data3_burst=0
tx_queue_data2_aifs=3
tx_queue_data2_cwmin=15
tx_queue_data2_cwmax=63
tx_queue_data2_burst=0
tx_queue_data1_aifs=1
tx_queue_data1_cwmin=7
tx_queue_data1_cwmax=15
tx_queue_data1_burst=3.0
tx_queue_data0_aifs=1
tx_queue_data0_cwmin=3
tx_queue_data0_cwmax=7
tx_queue_data0_burst=1.5
hw_mode=a
channel=48
country_code=DE

ieee80211n=1
ht_capab=[SHORT-GI-40][TX-STBC][RX-STBC1][DSSS_CCK-40][HT40-]

interface=wlan0
ctrl_interface=/var/run/hostapd-phy0
auth_algs=1
wpa=0
ssid=<bleep>
bridge=br-lan
wmm_enabled=1
bssid=00:0c:42:<bleep>
ignore_broadcast_ssid=0



> 3) what platform you are using?

Thinkpad X301, with current 32-bit Ubuntu.

Thanks for looking into this.
Comment 92 Jelle Foks 2011-01-19 02:45:40 UTC
On my WNDR3700, at 5Ghz (WPA encrypted)

$ sudo iw dev wlan0 station dump
Station zzzzzzzzzz (on wlan0)
	inactive time:	230 ms
	rx bytes:	1603871
	rx packets:	9804
	tx bytes:	88888
	tx packets:	589
	signal:  	-49 dBm
	tx bitrate:	150.0 MBit/s MCS 7 40Mhz short GI

And I actually saw some iwlagn kernel messages this time. But the link worked fine (no hickups), in fact, I measured a download speed of up to 136Mbit/s from my server (file in cache, and on channel 48 or lower). That speed is actually much higher than the max speed achieved in the review of this router at www.smallnetbuilder.com, so I guess I may be already getting the best speed this router can do. That is great guys!!! I'm very happy (but still a bit curious why I don't see the '300Mbits' reported anywhere). But for completeness, I'll finish this report:

Jan 18 20:22:10 localhost kernel: [221563.281674] wlan0: associated
Jan 18 20:22:20 localhost kernel: [221573.567748] iwlagn 0000:05:00.0: Aggregation not enabled for tid 0 because load = 4
Jan 18 20:22:25 localhost kernel: [221577.821131] iwlagn 0000:05:00.0: Aggregation not enabled for tid 0 because load = 9
Jan 18 20:22:35 localhost kernel: [221587.841190] iwlagn 0000:05:00.0: Aggregation not enabled for tid 0 because load = 1
Jan 18 20:22:44 localhost kernel: [221597.385300] iwlagn 0000:05:00.0: Aggregation not enabled for tid 0 because load = 2
Jan 18 20:23:00 localhost kernel: [221613.263798] iwlagn 0000:05:00.0: iwlagn_tx_agg_start on ra = zzzzzzz tid = 0


Then I connected to the 2.4Ghz radio of the router:

$ sudo iw dev wlan0 station dump
Station zzzzzzzzzzzzz (on wlan0)
	inactive time:	230 ms
	rx bytes:	479807
	rx packets:	2878
	tx bytes:	67755
	tx packets:	408
	signal:  	-28 dBm
	tx bitrate:	150.0 MBit/s MCS 7 40Mhz short GI

And one message after associating:

Jan 18 20:33:15 localhost kernel: [222228.281955] wlan0: associated
Jan 18 20:33:18 localhost kernel: [222231.390071] iwlagn 0000:05:00.0: iwlagn_tx_agg_start on ra = zzzzzzzz tid = 0

Didn't get quite such high download speeds at 2.4GHz (peaked at about 65Mbit/s, after unpluggin the wifi printer), but there is more interference from other networks, including one at the same channel at -82dBm.

And, for comparison (or confusion), today I happened to be able to connect to a 150Mbit/s rated router (a medialink MWN-APR150N), during which it reported this:

$ sudo iw dev wlan0 station dump
Station zzzzzzzzzzzzz (on wlan0)
	inactive time:	0 ms
	rx bytes:	33212141
	rx packets:	314137
	tx bytes:	805015522
	tx packets:	533257
	signal:  	-46 dBm
	tx bitrate:	72.2 MBit/s MCS 7 short GI

And iwconfig also never reported more than 72.2MBit/s speed.

Hope this helps,

Jelle.
Comment 93 wey-yi.w.guy 2011-01-19 15:56:51 UTC
(In reply to comment #92)
> On my WNDR3700, at 5Ghz (WPA encrypted)
> 
> $ sudo iw dev wlan0 station dump
> Station zzzzzzzzzz (on wlan0)
>     inactive time:    230 ms
>     rx bytes:    1603871
>     rx packets:    9804
>     tx bytes:    88888
>     tx packets:    589
>     signal:      -49 dBm
>     tx bitrate:    150.0 MBit/s MCS 7 40Mhz short GI
> 
> And I actually saw some iwlagn kernel messages this time. But the link worked
> fine (no hickups), in fact, I measured a download speed of up to 136Mbit/s
> from
> my server (file in cache, and on channel 48 or lower). That speed is actually
> much higher than the max speed achieved in the review of this router at
> www.smallnetbuilder.com, so I guess I may be already getting the best speed
> this router can do. That is great guys!!! I'm very happy (but still a bit
> curious why I don't see the '300Mbits' reported anywhere). But for
> completeness, I'll finish this report:
> 
> Jan 18 20:22:10 localhost kernel: [221563.281674] wlan0: associated
> Jan 18 20:22:20 localhost kernel: [221573.567748] iwlagn 0000:05:00.0:
> Aggregation not enabled for tid 0 because load = 4
> Jan 18 20:22:25 localhost kernel: [221577.821131] iwlagn 0000:05:00.0:
> Aggregation not enabled for tid 0 because load = 9
> Jan 18 20:22:35 localhost kernel: [221587.841190] iwlagn 0000:05:00.0:
> Aggregation not enabled for tid 0 because load = 1
> Jan 18 20:22:44 localhost kernel: [221597.385300] iwlagn 0000:05:00.0:
> Aggregation not enabled for tid 0 because load = 2
> Jan 18 20:23:00 localhost kernel: [221613.263798] iwlagn 0000:05:00.0:
> iwlagn_tx_agg_start on ra = zzzzzzz tid = 0
> 
> 
> Then I connected to the 2.4Ghz radio of the router:
> 
> $ sudo iw dev wlan0 station dump
> Station zzzzzzzzzzzzz (on wlan0)
>     inactive time:    230 ms
>     rx bytes:    479807
>     rx packets:    2878
>     tx bytes:    67755
>     tx packets:    408
>     signal:      -28 dBm
>     tx bitrate:    150.0 MBit/s MCS 7 40Mhz short GI
> 
> And one message after associating:
> 
> Jan 18 20:33:15 localhost kernel: [222228.281955] wlan0: associated
> Jan 18 20:33:18 localhost kernel: [222231.390071] iwlagn 0000:05:00.0:
> iwlagn_tx_agg_start on ra = zzzzzzzz tid = 0
> 
> Didn't get quite such high download speeds at 2.4GHz (peaked at about
> 65Mbit/s,
> after unpluggin the wifi printer), but there is more interference from other
> networks, including one at the same channel at -82dBm.
> 
> And, for comparison (or confusion), today I happened to be able to connect to
> a
> 150Mbit/s rated router (a medialink MWN-APR150N), during which it reported
> this:
> 
> $ sudo iw dev wlan0 station dump
> Station zzzzzzzzzzzzz (on wlan0)
>     inactive time:    0 ms
>     rx bytes:    33212141
>     rx packets:    314137
>     tx bytes:    805015522
>     tx packets:    533257
>     signal:      -46 dBm
>     tx bitrate:    72.2 MBit/s MCS 7 short GI
> 
> And iwconfig also never reported more than 72.2MBit/s speed.
> 
> Hope this helps,
> 
> Jelle.

Hi Jelle,

now I got it, sorry to miss the important information before.
you have 5100 which is 1x2 device (1 tx chain, 2 rx chain), by saying that, you can reach max. of 300 Mbps only on rx with MIMO, for tx, since it is only single chain, the max. tpt you can have is 150 Mbps with SISO.

Thanks
Wey
Comment 94 Jelle Foks 2011-01-19 16:09:07 UTC
That explains it. Great, and thanks for the effort! This is working great now for me.
Comment 95 Tobias Wolf 2011-01-19 16:53:44 UTC
Hello Wey,

I’ve got a series of messages now that I’m not sure what kind of network traffic 
 they arose from. They just appeared in my dmesg after normal usage.

$ iw wlan0 link
Connected to 00:0c:42:<...> (on wlan0)
	SSID: <...>
	freq: 5240
	RX: 186508052 bytes (258549 packets)
	TX: 196107448 bytes (195316 packets)
	signal: -52 dBm
	tx bitrate: 300.0 MBit/s MCS 15 40Mhz short GI


Do you need any other kind of information? Also, is my iwlwifi driver the right one to be testing experimental 500 series ucode with (in-tree 2.6.37 rc8)?


[45505.015961] iwlagn 0000:03:00.0: Received BA when not expected
[45505.216836] iwlagn 0000:03:00.0: BUG_ON idx doesn't match seq control idx=249, seq_idx=3834, seq=61344
[45505.216844] iwlagn 0000:03:00.0: Received BA when not expected
[45508.689936] iwlagn 0000:03:00.0: BUG_ON idx doesn't match seq control idx=251, seq_idx=3836, seq=61376
[45508.689951] iwlagn 0000:03:00.0: Received BA when not expected
[45508.698476] iwlagn 0000:03:00.0: BUG_ON idx doesn't match seq control idx=254, seq_idx=3839, seq=61424
[45508.698484] iwlagn 0000:03:00.0: Received BA when not expected
[45508.702740] iwlagn 0000:03:00.0: BUG_ON idx doesn't match seq control idx=3, seq_idx=3844, seq=61504
[45508.702749] iwlagn 0000:03:00.0: Received BA when not expected
[45508.706972] iwlagn 0000:03:00.0: BUG_ON idx doesn't match seq control idx=6, seq_idx=3847, seq=61552
[45508.706978] iwlagn 0000:03:00.0: Received BA when not expected
[45508.711754] iwlagn 0000:03:00.0: BUG_ON idx doesn't match seq control idx=9, seq_idx=3850, seq=61600
[45508.711761] iwlagn 0000:03:00.0: Received BA when not expected
[45508.720259] iwlagn 0000:03:00.0: BUG_ON idx doesn't match seq control idx=13, seq_idx=3854, seq=61664
[45508.720273] iwlagn 0000:03:00.0: Received BA when not expected
[45508.748623] iwlagn 0000:03:00.0: BUG_ON idx doesn't match seq control idx=19, seq_idx=3860, seq=61760
[45508.748637] iwlagn 0000:03:00.0: Received BA when not expected
[45508.757171] iwlagn 0000:03:00.0: BUG_ON idx doesn't match seq control idx=22, seq_idx=3863, seq=61808
[45508.757182] iwlagn 0000:03:00.0: Received BA when not expected
[45508.761443] iwlagn 0000:03:00.0: BUG_ON idx doesn't match seq control idx=24, seq_idx=3865, seq=61840
[45508.761452] iwlagn 0000:03:00.0: Received BA when not expected
[45508.765600] iwlagn 0000:03:00.0: BUG_ON idx doesn't match seq control idx=26, seq_idx=3867, seq=61872
[45508.765606] iwlagn 0000:03:00.0: Received BA when not expected
[45508.791231] iwlagn 0000:03:00.0: BUG_ON idx doesn't match seq control idx=32, seq_idx=3873, seq=61968
[45508.791239] iwlagn 0000:03:00.0: Received BA when not expected
[45508.804281] iwlagn 0000:03:00.0: BUG_ON idx doesn't match seq control idx=36, seq_idx=3877, seq=62032
[45508.804288] iwlagn 0000:03:00.0: Received BA when not expected
[45508.813007] iwlagn 0000:03:00.0: BUG_ON idx doesn't match seq control idx=40, seq_idx=3881, seq=62096
[45508.813015] iwlagn 0000:03:00.0: Received BA when not expected
[45508.848568] iwlagn 0000:03:00.0: BUG_ON idx doesn't match seq control idx=49, seq_idx=3890, seq=62240
[45508.848577] iwlagn 0000:03:00.0: Received BA when not expected
[45508.857113] iwlagn 0000:03:00.0: BUG_ON idx doesn't match seq control idx=52, seq_idx=3893, seq=62288
[45508.857121] iwlagn 0000:03:00.0: Received BA when not expected
[45508.865829] iwlagn 0000:03:00.0: BUG_ON idx doesn't match seq control idx=56, seq_idx=3897, seq=62352
[45508.865840] iwlagn 0000:03:00.0: Received BA when not expected
[45508.875410] iwlagn 0000:03:00.0: BUG_ON idx doesn't match seq control idx=59, seq_idx=3900, seq=62400
[45508.875423] iwlagn 0000:03:00.0: Received BA when not expected
Comment 96 Nikolay Martynov 2011-01-22 03:54:51 UTC
  Have 5300 card (with only two antennas attached), 802-11n ath9k router. With latest compat-wireless, experimental firmware and both patches from this ticket I get not messages in dmesg but awful packetloss. Macbook at same location with same AP gives about 4MB/s without any packetloss on ping.
  Is this the same issue or shall I report a new one?
Comment 97 wey-yi.w.guy 2011-01-24 14:57:22 UTC
Nikolay,

Not sure, could you help to provide more detail

Thanks
Wey
Comment 98 Nikolay Martynov 2011-01-24 16:06:40 UTC
I have ubuntu with 2.6.37-020637rc2 kernel.
As a router - it's ath9k with latest openwrt. There is no packet loss in 'g' mode and there are no problems with macbook on same AP in 'n' mode.
The only 'non-standard' thing in my configuration might be the fact that I use two antennas since I put this card into laptop (dell inspiron 6400) which has only two antennas. But according to /sys../chain_noise disconnected chain is not being used.
And as I said no error messages in logs.
I'd be happy to provide any information, just let me know what you need. Do you want me to records logs with debug turned on? What debug flags would be relevant?
Please, let me know.

Thanks!
Comment 99 Nikolay Martynov 2011-01-24 16:37:14 UTC
One more detail that might be interesting to you.
Some times in 'n' mode ping times between laptop (with intel 5300) and router can reach tens of seconds. Look like packets get queued on router for a very long time. This doesn't happen always, but if it does the attempt to open a single web page other this link skyrockets ping times.
Moreover, one this happens macbook on same AP experiences huge delays too.
That is, when macbook downloads in 'n' mode - no problem, when intel downloads in 'n' mode - problems for both wireless clients.
Hope this helps.
Comment 100 wey-yi.w.guy 2011-01-24 20:43:51 UTC
yes, if you can load the module with debug=0x43fff and provide the log, it will be very helpful

Thanks
Wey
Comment 101 Nikolay Martynov 2011-01-24 23:31:41 UTC
Created attachment 45062 [details]
Kernel log for intel 5300 packetloss problem

This is debug log. Intel 5300 client with ath9k AP. Ping and some other non heavy traffic was transmitted.
Ping log follows.
Comment 102 Nikolay Martynov 2011-01-24 23:33:41 UTC
Created attachment 45072 [details]
Ping log for intel 5300 packetloss problem

This is ping log. Intel 5300 client with ath9k AP. Ping and some other non heavy traffic was transmitted.
Comment 103 Nikolay Martynov 2011-01-27 01:58:11 UTC
Is there any chance to have information about this problem? Do you see something in logs? Is this a bug? Can you reproduce it? Can I do anything else to help you fixing it?

Thanks.
Comment 104 wey-yi.w.guy 2011-01-27 15:54:18 UTC
Thanks for the log, I did not see anything stand out from the log. Could you to make another round of testing with debug=0x40870002

With this flag, we should be able to understand is there any re-transmit or tx failure condition with error code.

Thanks
Wey
Comment 105 Nikolay Martynov 2011-01-28 03:11:12 UTC
Created attachment 45322 [details]
Log when no packets are passing

Pleas find log with debug settings you requested.
At the time of logging there is almost no successful pings. I tried to tcpdump on router and I see almost all ping requests and responses.
Here is log summary which I think might be useful:
cat /var/log/kern.log | grep " iwlagn_set_tx_status TXQ" | cut -d ' ' -f 14 | sort | uniq -c
      1 FIFO_UNDERRUN
     30 LONG_LIMIT
   1278 SHORT_LIMIT
      4 STA_INVALID
  20132 SUCCESS

Also, it looks like problem becomes much worse when there is another client (macbook) on same AP. The clients are very close to each other but at some distance to AP. I do not think that I've tested specifically client alone before. But it looks like this: intel 5300 is working fine in 'n' mode, then I turn on macbook and intel still has connection but receives no packets. And macbook works fine. Then when I turn macbook off I still see no packets.

So if you allow me to make a suggestion - it looks like there is some receive problem and it might be related to existence of other clients on same AP (or possibly other devices on same channel).

Please let me know whether this information was helpful and whether I can provide and other information.
Thanks.
Comment 106 wey-yi.w.guy 2011-01-28 19:55:26 UTC
great information, it is what I am looking for. Now I can forward the information you provide to our uCode team to hlep understand and roo cause the problem. I will let you know as soon as I got the feedback from our uCode team.

Thanks
Wey
Comment 107 Nikolay Martynov 2011-02-03 05:29:30 UTC
Experimental ucode does this:

[12027.714081] iwlagn 0000:0b:00.0: Microcode SW error detected.  Restarting 0x2000000.
[12027.714089] iwlagn 0000:0b:00.0: Loaded firmware version: 8.83.5.1 build 33692 (EXP)
[12027.714106] iwlagn 0000:0b:00.0: Start IWL Error Log Dump:
[12027.714109] iwlagn 0000:0b:00.0: Status: 0x000212E4, count: 5
[12027.714259] iwlagn 0000:0b:00.0: Desc                                  Time       data1      data2      line
[12027.714265] iwlagn 0000:0b:00.0: SYSASSERT                    (0x0005) 1532805784 0x000000FF 0x00000489 1161
[12027.714268] iwlagn 0000:0b:00.0: pc      blink1  blink2  ilink1  ilink2  hcmd
[12027.714272] iwlagn 0000:0b:00.0: 0x024EC 0x024C8 0x024C8 0x00916 0x00000 0x25D001C
[12027.714275] iwlagn 0000:0b:00.0: CSR values:
[12027.714278] iwlagn 0000:0b:00.0: (2nd byte of CSR_INT_COALESCING is CSR_INT_PERIODIC_REG)
[12027.714284] iwlagn 0000:0b:00.0:        CSR_HW_IF_CONFIG_REG: 0X00480302
[12027.714290] iwlagn 0000:0b:00.0:          CSR_INT_COALESCING: 0X00000040
[12027.714295] iwlagn 0000:0b:00.0:                     CSR_INT: 0X00000000
[12027.714301] iwlagn 0000:0b:00.0:                CSR_INT_MASK: 0X00000000
[12027.714307] iwlagn 0000:0b:00.0:           CSR_FH_INT_STATUS: 0X00000000
[12027.714312] iwlagn 0000:0b:00.0:                 CSR_GPIO_IN: 0X00000000
[12027.714318] iwlagn 0000:0b:00.0:                   CSR_RESET: 0X00000000
[12027.714324] iwlagn 0000:0b:00.0:                CSR_GP_CNTRL: 0X080403c5
[12027.714329] iwlagn 0000:0b:00.0:                  CSR_HW_REV: 0X00000024
[12027.714335] iwlagn 0000:0b:00.0:              CSR_EEPROM_REG: 0X00000000
[12027.714341] iwlagn 0000:0b:00.0:               CSR_EEPROM_GP: 0X90000004
[12027.714347] iwlagn 0000:0b:00.0:              CSR_OTP_GP_REG: 0X00060000
[12027.714352] iwlagn 0000:0b:00.0:                 CSR_GIO_REG: 0X00080044
[12027.714358] iwlagn 0000:0b:00.0:            CSR_GP_UCODE_REG: 0X000028c7
[12027.714364] iwlagn 0000:0b:00.0:           CSR_GP_DRIVER_REG: 0X00000000
[12027.714370] iwlagn 0000:0b:00.0:           CSR_UCODE_DRV_GP1: 0X00000000
[12027.714375] iwlagn 0000:0b:00.0:           CSR_UCODE_DRV_GP2: 0X00000000
[12027.714381] iwlagn 0000:0b:00.0:                 CSR_LED_REG: 0X00000058
[12027.714387] iwlagn 0000:0b:00.0:        CSR_DRAM_INT_TBL_REG: 0X8802c03c
[12027.714393] iwlagn 0000:0b:00.0:        CSR_GIO_CHICKEN_BITS: 0X27800200
[12027.714398] iwlagn 0000:0b:00.0:             CSR_ANA_PLL_CFG: 0X00880300
[12027.714404] iwlagn 0000:0b:00.0:           CSR_HW_REV_WA_REG: 0X0001001a
[12027.714410] iwlagn 0000:0b:00.0:        CSR_DBG_HPET_MEM_REG: 0Xffff0000
[12027.714413] iwlagn 0000:0b:00.0: FH register values:
[12027.714428] iwlagn 0000:0b:00.0:         FH_RSCSR_CHNL0_STTS_WPTR_REG: 0X02afe600
[12027.714443] iwlagn 0000:0b:00.0:        FH_RSCSR_CHNL0_RBDCB_BASE_REG: 0X002afe70
[12027.714458] iwlagn 0000:0b:00.0:                  FH_RSCSR_CHNL0_WPTR: 0X000000c0
[12027.714473] iwlagn 0000:0b:00.0:         FH_MEM_RCSR_CHNL0_CONFIG_REG: 0X80819104
[12027.714488] iwlagn 0000:0b:00.0:          FH_MEM_RSSR_SHARED_CTRL_REG: 0X000000fc
[12027.714503] iwlagn 0000:0b:00.0:            FH_MEM_RSSR_RX_STATUS_REG: 0X026b0000
[12027.714518] iwlagn 0000:0b:00.0:    FH_MEM_RSSR_RX_ENABLE_ERR_IRQ2DRV: 0X00000000
[12027.714533] iwlagn 0000:0b:00.0:                FH_TSSR_TX_STATUS_REG: 0X07ff0001
[12027.714548] iwlagn 0000:0b:00.0:                 FH_TSSR_TX_ERROR_REG: 0X00000000
[12027.714605] iwlagn 0000:0b:00.0: Start IWL Event Log Dump: display last 20 entries
[12027.714624] iwlagn 0000:0b:00.0: EVT_LOGT:0140615488:0x025d001c:0206
[12027.714637] iwlagn 0000:0b:00.0: EVT_LOGT:0140615489:0x01000001:0251
[12027.714649] iwlagn 0000:0b:00.0: EVT_LOGT:0140618254:0x00000113:0106
[12027.714661] iwlagn 0000:0b:00.0: EVT_LOGT:0140618256:0x00000000:0301
[12027.714674] iwlagn 0000:0b:00.0: EVT_LOGT:0140618442:0x00000000:0355
[12027.714686] iwlagn 0000:0b:00.0: EVT_LOGT:0140619897:0x00000113:0106
[12027.714698] iwlagn 0000:0b:00.0: EVT_LOGT:0140619898:0x00000000:0301
[12027.714710] iwlagn 0000:0b:00.0: EVT_LOGT:0140620088:0x00000000:0355
[12027.714722] iwlagn 0000:0b:00.0: EVT_LOGT:0140620486:0x00000113:0106
[12027.714735] iwlagn 0000:0b:00.0: EVT_LOGT:0140620488:0x00000000:0301
[12027.714747] iwlagn 0000:0b:00.0: EVT_LOGT:0140620675:0x00000000:0355
[12027.714759] iwlagn 0000:0b:00.0: EVT_LOGT:0140621434:0x00000113:0106
[12027.714771] iwlagn 0000:0b:00.0: EVT_LOGT:0140621436:0x00000000:0301
[12027.714784] iwlagn 0000:0b:00.0: EVT_LOGT:0140621623:0x00000000:0355
[12027.714796] iwlagn 0000:0b:00.0: EVT_LOGT:0140622057:0x00000113:0106
[12027.714808] iwlagn 0000:0b:00.0: EVT_LOGT:0140622058:0x00000000:0301
[12027.714820] iwlagn 0000:0b:00.0: EVT_LOGT:0140622247:0x00000000:0355
[12027.714832] iwlagn 0000:0b:00.0: EVT_LOGT:0140622419:0x000004b3:0511
[12027.714844] iwlagn 0000:0b:00.0: EVT_LOGT:0140622420:0x00000000:0512
[12027.714856] iwlagn 0000:0b:00.0: EVT_LOGT:0141622432:0x00000000:0125
Comment 108 Nikolay Martynov 2011-02-07 02:37:08 UTC
Hi.

Is there any chance to have a least some update on this?
Comment 109 Nikolay Martynov 2011-02-08 22:41:41 UTC
With last compat wireless ans experimental ucode on 5300 I get this in 'n' mode along with almost no usable connection:

[ 2745.392079] iwlagn 0000:0b:00.0: iwlagn_tx_agg_start on ra = 00:14:d1:53:50:2d tid = 0
[ 2750.111198] iwlagn 0000:0b:00.0: low ack count detected, restart firmware
[ 2750.111209] iwlagn 0000:0b:00.0: On demand firmware reload
[ 2750.149098] iwlagn 0000:0b:00.0: Stopping AGG while state not ON or starting
[ 2750.149109] iwlagn 0000:0b:00.0: queue number out of range: 0, must be 10 to 19
[ 2755.440244] iwlagn 0000:0b:00.0: Aggregation not enabled for tid 0 because load = 5
[ 2762.691663] iwlagn 0000:0b:00.0: Aggregation not enabled for tid 0 because load = 8
[ 2768.322478] iwlagn 0000:0b:00.0: Aggregation not enabled for tid 0 because load = 4
[ 2776.242230] iwlagn 0000:0b:00.0: Aggregation not enabled for tid 0 because load = 3
[ 2782.481029] iwlagn 0000:0b:00.0: Aggregation not enabled for tid 0 because load = 4
[ 2790.436647] iwlagn 0000:0b:00.0: Aggregation not enabled for tid 0 because load = 1
[ 2796.006168] iwlagn 0000:0b:00.0: Aggregation not enabled for tid 0 because load = 5
[ 2804.380575] iwlagn 0000:0b:00.0: Aggregation not enabled for tid 0 because load = 2
[ 2811.780753] iwlagn 0000:0b:00.0: Aggregation not enabled for tid 0 because load = 1
[ 2817.648347] iwlagn 0000:0b:00.0: Aggregation not enabled for tid 0 because load = 8
[ 2826.228289] iwlagn 0000:0b:00.0: Aggregation not enabled for tid 0 because load = 2
[ 2834.496927] iwlagn 0000:0b:00.0: Aggregation not enabled for tid 0 because load = 5
[ 2840.443307] iwlagn 0000:0b:00.0: Aggregation not enabled for tid 0 because load = 2
[ 2852.971803] iwlagn 0000:0b:00.0: Aggregation not enabled for tid 0 because load = 3
[ 2859.652160] iwlagn 0000:0b:00.0: Aggregation not enabled for tid 0 because load = 8
[ 2874.582415] iwlagn 0000:0b:00.0: Aggregation not enabled for tid 0 because load = 0
[ 2888.560058] iwlagn 0000:0b:00.0: iwlagn_tx_agg_start on ra = 00:14:d1:53:50:2d tid = 0
[ 3023.587013] iwlagn 0000:0b:00.0: low ack count detected, restart firmware
[ 3023.587023] iwlagn 0000:0b:00.0: On demand firmware reload
[ 3023.633711] iwlagn 0000:0b:00.0: Stopping AGG while state not ON or starting
[ 3023.633721] iwlagn 0000:0b:00.0: queue number out of range: 0, must be 10 to 19
[ 3031.641227] iwlagn 0000:0b:00.0: Aggregation not enabled for tid 0 because load = 2
[ 3050.298421] iwlagn 0000:0b:00.0: Aggregation not enabled for tid 0 because load = 0
[ 3068.132421] iwlagn 0000:0b:00.0: Aggregation not enabled for tid 0 because load = 0
[ 3075.902525] iwlagn 0000:0b:00.0: iwlagn_tx_agg_start on ra = 00:14:d1:53:50:2d tid = 0
[ 3081.072364] iwlagn 0000:0b:00.0: low ack count detected, restart firmware
[ 3081.072374] iwlagn 0000:0b:00.0: On demand firmware reload
[ 3081.120355] iwlagn 0000:0b:00.0: Stopping AGG while state not ON or starting
[ 3081.120366] iwlagn 0000:0b:00.0: queue number out of range: 0, must be 10 to 19
[ 3085.044094] iwlagn 0000:0b:00.0: iwlagn_tx_agg_start on ra = 00:14:d1:53:50:2d tid = 0
[ 3338.725340] wlan1: deauthenticated from 00:14:d1:53:50:2d (Reason: 2)
[ 3338.729861] iwlagn 0000:0b:00.0: Stopping AGG while state not ON or starting
Comment 110 wey-yi.w.guy 2011-02-08 22:54:01 UTC
we seeing issue on "low ack count" being trigger too often and cause problem, now we are in the process of address this. Stainslaw has few [RFC] patches to disable the "low ack count" by default. it should fix a lot of issues we seeing.

Thanks
Wey
Comment 111 Nikolay Martynov 2011-02-08 23:55:26 UTC
Can I try those patches locally to see whether they give and result?

Thanks.
Comment 112 Nikolay Martynov 2011-02-09 20:27:09 UTC
Having this in logs:
Feb  9 14:34:47 kolya-laptop kernel: [18802.192862] iwlagn 0000:0b:00.0: On demand firmware reload
Feb  9 14:34:47 kolya-laptop kernel: [18802.195167] iwlagn 0000:0b:00.0: Failing on timeout while stopping DMA channel 1 [0x07fd0001]
Feb  9 14:34:47 kolya-laptop kernel: [18802.232613] iwlagn 0000:0b:00.0: Stopping AGG while state not ON or starting
Feb  9 14:34:47 kolya-laptop kernel: [18802.232626] iwlagn 0000:0b:00.0: queue number out of range: 0, must be 10 to 19
Feb  9 14:34:48 kolya-laptop kernel: [18803.272099] iwlagn 0000:0b:00.0: iwlagn_tx_agg_start on ra = 00:14:d1:53:50:2d tid = 0
Feb  9 14:34:51 kolya-laptop kernel: [18806.192081] iwlagn 0000:0b:00.0: iwlagn_tx_agg_start on ra = 00:14:d1:53:50:2d tid = 0
Feb  9 14:34:57 kolya-laptop kernel: [18812.228136] iwlagn 0000:0b:00.0: low ack count detected, restart firmware
Feb  9 14:34:57 kolya-laptop kernel: [18812.228146] iwlagn 0000:0b:00.0: On demand firmware reload
Feb  9 14:34:57 kolya-laptop kernel: [18812.263921] iwlagn 0000:0b:00.0: Stopping AGG while state not ON or starting
Feb  9 14:34:57 kolya-laptop kernel: [18812.263932] iwlagn 0000:0b:00.0: queue number out of range: 0, must be 10 to 19
Feb  9 14:34:58 kolya-laptop kernel: [18813.060538] iwlagn 0000:0b:00.0: iwlagn_tx_agg_start on ra = 00:14:d1:53:50:2d tid = 0
Feb  9 14:35:00 kolya-laptop kernel: [18815.056091] iwlagn 0000:0b:00.0: iwlagn_tx_agg_start on ra = 00:14:d1:53:50:2d tid = 0
Feb  9 14:35:10 kolya-laptop kernel: [18824.966204] iwlagn 0000:0b:00.0: Received BA when not expected
Feb  9 14:35:10 kolya-laptop kernel: [18825.130652] iwlagn 0000:0b:00.0: low ack count detected, restart firmware
Feb  9 14:35:10 kolya-laptop kernel: [18825.130663] iwlagn 0000:0b:00.0: On demand firmware reload
Feb  9 14:35:10 kolya-laptop kernel: [18825.132980] iwlagn 0000:0b:00.0: Failing on timeout while stopping DMA channel 1 [0x07fd0001]
Feb  9 14:35:10 kolya-laptop kernel: [18825.174588] iwlagn 0000:0b:00.0: Stopping AGG while state not ON or starting
Feb  9 14:35:10 kolya-laptop kernel: [18825.174601] iwlagn 0000:0b:00.0: queue number out of range: 0, must be 10 to 19
Feb  9 14:35:10 kolya-laptop kernel: [18825.780147] iwlagn 0000:0b:00.0: iwlagn_tx_agg_start on ra = 00:14:d1:53:50:2d tid = 0
Feb  9 14:35:13 kolya-laptop kernel: [18828.730552] iwlagn 0000:0b:00.0: iwlagn_tx_agg_start on ra = 00:14:d1:53:50:2d tid = 0
Feb  9 14:35:19 kolya-laptop kernel: [18834.190104] iwlagn 0000:0b:00.0: Received BA when not expected
Feb  9 14:35:19 kolya-laptop kernel: [18834.235410] iwlagn 0000:0b:00.0: Received BA when not expected
Feb  9 14:35:19 kolya-laptop kernel: [18834.346738] iwlagn 0000:0b:00.0: low ack count detected, restart firmware
Feb  9 14:35:19 kolya-laptop kernel: [18834.346752] iwlagn 0000:0b:00.0: On demand firmware reload
Feb  9 14:35:19 kolya-laptop kernel: [18834.349110] iwlagn 0000:0b:00.0: Failing on timeout while stopping DMA channel 1 [0x07fd0001]
Feb  9 14:35:19 kolya-laptop kernel: [18834.384283] iwlagn 0000:0b:00.0: Stopping AGG while state not ON or starting


And at some point it seems that card stops receiving anything without any new messages in logs (i.e. no pings, no logs - nothing). But, after I try to 'tcpdump' interface - packets start to come again (on two occasions, might have been a coincidence though).

Do those patches address this kind of problem?
Comment 113 wey-yi.w.guy 2011-02-09 20:33:03 UTC
Created attachment 47012 [details]
remove low ack count for 5000

this patch remove "low ack count", please give a try

Wey
Comment 114 Nikolay Martynov 2011-02-09 22:11:15 UTC
Just tried.
I still see significant packetloss - >15% for ping. On the same hardware and location 'g' mode has no packetloss.
And I see this in logs:
Feb  9 17:08:38 kolya-laptop kernel: [  534.035451] iwlagn 0000:0b:00.0: Received BA when not expected
Feb  9 17:08:39 kolya-laptop kernel: [  535.105349] iwlagn 0000:0b:00.0: Received BA when not expected
Feb  9 17:08:40 kolya-laptop kernel: [  535.749596] iwlagn 0000:0b:00.0: Received BA when not expected
Feb  9 17:08:40 kolya-laptop kernel: [  536.057279] iwlagn 0000:0b:00.0: Received BA when not expected
Feb  9 17:08:48 kolya-laptop kernel: [  544.345882] iwlagn 0000:0b:00.0: Received BA when not expected
Feb  9 17:08:51 kolya-laptop kernel: [  546.940550] iwlagn 0000:0b:00.0: Received BA when not expected
Feb  9 17:08:51 kolya-laptop kernel: [  547.054304] iwlagn 0000:0b:00.0: Received BA when not expected
Feb  9 17:08:51 kolya-laptop kernel: [  547.111250] iwlagn 0000:0b:00.0: Received BA when not expected
Feb  9 17:08:52 kolya-laptop kernel: [  547.498983] iwlagn 0000:0b:00.0: Received BA when not expected
Feb  9 17:08:52 kolya-laptop kernel: [  547.570857] iwlagn 0000:0b:00.0: Received BA when not expected
Feb  9 17:08:53 kolya-laptop kernel: [  548.991506] iwlagn 0000:0b:00.0: Received BA when not expected
Feb  9 17:08:53 kolya-laptop kernel: [  549.062301] iwlagn 0000:0b:00.0: Received BA when not expected
Feb  9 17:09:08 kolya-laptop kernel: [  564.046203] iwlagn 0000:0b:00.0: Received BA when not expected
Comment 115 Nikolay Martynov 2011-02-18 00:01:40 UTC
So is there any news on this?

802.11n is still unusable on intel 5300, with both current and experimental ucode. Is there any chance to make it work?
Comment 116 wey-yi.w.guy 2011-02-18 00:47:22 UTC
Stanislaw has another patch in 
https://bugzilla.redhat.com/show_bug.cgi?id=648732

it diable plcp error checking, could you give a try?

Thanks
Wey
Comment 117 Nikolay Martynov 2011-02-18 01:58:03 UTC
I'm sure I could. But that bug only refers to fedora packages. I'm running ubuntu. Could you please provide me a link to actual patch so I could build compat-wireless myself?

Thanks
Comment 118 Nikolay Martynov 2011-02-18 04:08:24 UTC
I found patch which disables plcp error checking.
It was working fine with it for while, but at some point ping time skyrocketed to 3-5 seconds:
64 bytes from 192.168.1.1: icmp_req=1313 ttl=64 time=3155 ms
64 bytes from 192.168.1.1: icmp_req=1314 ttl=64 time=2225 ms
64 bytes from 192.168.1.1: icmp_req=1315 ttl=64 time=1989 ms
64 bytes from 192.168.1.1: icmp_req=1317 ttl=64 time=2942 ms
64 bytes from 192.168.1.1: icmp_req=1318 ttl=64 time=3701 ms
64 bytes from 192.168.1.1: icmp_req=1323 ttl=64 time=2221 ms
64 bytes from 192.168.1.1: icmp_req=1324 ttl=64 time=1758 ms
64 bytes from 192.168.1.1: icmp_req=1325 ttl=64 time=3048 ms
64 bytes from 192.168.1.1: icmp_req=1326 ttl=64 time=2804 ms
64 bytes from 192.168.1.1: icmp_req=1327 ttl=64 time=2995 ms
64 bytes from 192.168.1.1: icmp_req=1329 ttl=64 time=2338 ms
64 bytes from 192.168.1.1: icmp_req=1330 ttl=64 time=1350 ms

and I got this in logs:
[ 5397.182505] iwlagn 0000:0b:00.0: Stopping AGG while state not ON or starting
[ 5397.204845] cfg80211: All devices are disconnected, going to restore regulatory settings
[ 5397.204854] cfg80211: Restoring regulatory settings
[ 5397.204862] cfg80211: Calling CRDA to update world regulatory domain
[ 5397.381465] cfg80211: Ignoring regulatory request Set by core since the driver uses its own custom regulatory domain 
[ 5397.381476] cfg80211: World regulatory domain updated:
[ 5397.381479] cfg80211:     (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
[ 5397.381484] cfg80211:     (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[ 5397.381489] cfg80211:     (2457000 KHz - 2482000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
[ 5397.381493] cfg80211:     (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
[ 5397.381498] cfg80211:     (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[ 5397.381502] cfg80211:     (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[ 5400.548888] wlan1: authenticate with 00:14:d1:53:50:2d (try 1)
[ 5400.748068] wlan1: authenticate with 00:14:d1:53:50:2d (try 2)
[ 5400.750660] wlan1: authenticated
[ 5400.750818] wlan1: associate with 00:14:d1:53:50:2d (try 1)
[ 5400.754456] wlan1: RX AssocResp from 00:14:d1:53:50:2d (capab=0x411 status=0 aid=2)
[ 5400.754463] wlan1: associated
[ 5402.904757] iwlagn 0000:0b:00.0: iwlagn_tx_agg_start on ra = 00:14:d1:53:50:2d tid = 0
[ 5414.584074] iwlagn 0000:0b:00.0: Queue 11 stuck for 10000 ms.
[ 5414.584083] iwlagn 0000:0b:00.0: On demand firmware reload
[ 5414.622408] iwlagn 0000:0b:00.0: Stopping AGG while state not ON or starting
[ 5414.622419] iwlagn 0000:0b:00.0: queue number out of range: 0, must be 10 to 19


So all same problems still exist. No improvement.
Is there at least some understanding why all this is happening? What kind of additional information can I provide to help fixing this?

Thanks.
Comment 119 Stanislaw Gruszka 2011-02-18 09:01:54 UTC
(In reply to comment #118)
> So all same problems still exist. No improvement.
> Is there at least some understanding why all this is happening? What kind of
> additional information can I provide to help fixing this?

The problem here is that 5xxx firmware is unstable when working on 11n mode. Problem can be bugs in firmware itself or bugs in driver, which do things that firmware does not expect and put it into bad state.

How this bug or rather bugs could be fixed? It's totally up Intel, because firmware is closed as well as documentation for device. I could only look at driver, find some suspicious looking code, change it and have hope that will help somehow.

In a matter of fact, I'm afraid Intel does not even try to fix 5xxx bugs, concentrate rather of development of future devices and other platforms (i.e. Windows). These bugs could be fixed by reproducing problem locally at Intel and diagnose it. However I do not see any Intel effort to gather information how to reproduce problem, particularly I do not see any question like: what exact is your device (lspci -vnn), what is your AP model, what is it's firmware version and configuration, how many stations are in the network , etc. Hence conclusion Intel pretty much ignore linux 5xxx users (as well as other "old" devices 3945, 4965).
Comment 120 Alexander Gololobov 2011-02-18 10:09:36 UTC
This might be a stupid question but I wonder what has changed since some older kernels when my 5100 card was working fine in N mode? Isn't it possible to port that code to the latest kernel?
Comment 121 Stanislaw Gruszka 2011-02-18 10:25:04 UTC
Good point. What is the latest good working kernel for you (with the same firmware version)?
Comment 122 Stanislaw Gruszka 2011-02-18 10:29:09 UTC
Ok I see in topic this is .34 -> .35 regression, but please note that for many users, update to .35 fix their problems, in particular bugs when device stop working at random without any messages in dmesg.
Comment 123 Alexander Gololobov 2011-02-18 12:18:43 UTC
I don't remember exactly when this regression happened but most likely either when I upgraded from Ubuntu 9.10 to 10.04 or from 10.04.to 10.10
Comment 124 wey-yi.w.guy 2011-02-18 15:54:28 UTC
The support problem are fully aware and we are trying our best to address it, but it is also not easy since the firmware changes very fast. with the single driver support all the different devices (legacy and new). We are facing a lot of compatible issues. Now we are working on split the 3945/4965 driver into separated legacy, so we can at least avoid breaking the legacy driver functionality. This is the first step we are working to get thing right.

The "queue stuck" most likely is another firmware bug, but it might cause by something changed in the driver to introduce new functionalities for newer devices

Are you also using "experimental" uCode when you encounter this problem?

Wey
Comment 125 Nikolay Martynov 2011-02-18 16:46:00 UTC
Yes, in latest test I used experimental ucode, latest compat-wireless, ubuntu with 2.6.38-3-generic-pae kernel and patch you suggested.
AP - ath9k with latest openwrt and only one more station on this ap - macbook pro.
The problem persists for all the time I was trying to use 802.11n (two months - not long, yes), and all things you ask me to do do not really change behaviour - I still see pings which take 3-10 seconds after I run it for while.

The thing which I do not understand at all is why linux user have to deal with this ucode issue at all. There is stable and working ucode for windows, I suppose. But for some reason intel doesn't use it in linux drivers. Instead linux gets unstable substitute which is half a year in 'experimental' status and doesn't really fix any problems. I'm sure if there was 'known-to-work' ucode with at least some description community could create a driver for it. I.e. I do not think Windows does something in drivers linux cannot do.

Thanks.
Comment 126 Tobias Wolf 2011-03-11 17:25:39 UTC
Nikolay, you might want to check out OpenWrt trunk from today. There’s a new ath9k patch that might be relevant to our issue here:

https://dev.openwrt.org/browser/trunk/package/mac80211/patches/590-ath9k_tid_cleanup_send_bar.patch?rev=26036
Comment 127 Nikolay Martynov 2011-03-12 05:39:30 UTC
(In reply to comment #126)
> Nikolay, you might want to check out OpenWrt trunk from today. There’s a new
> ath9k patch that might be relevant to our issue here:
> 
>
> https://dev.openwrt.org/browser/trunk/package/mac80211/patches/590-ath9k_tid_cleanup_send_bar.patch?rev=26036

Thanks!
I did this and it seem that connection quality have greatly improved with both latest versions of openwrt and iwlagn driver. Although it still fails from time to time (I noted this on openwrt ticket).

I'm getting a lot of these messages in logs pretty often:
[ 3208.649868] iwlagn 0000:0b:00.0: Received BA when not expected
[ 3223.709624] iwlagn 0000:0b:00.0: Received BA when not expected
[ 3225.669194] iwlagn 0000:0b:00.0: Received BA when not expected
[ 3228.722359] iwlagn 0000:0b:00.0: Received BA when not expected


Thanks.
Comment 128 wey-yi.w.guy 2011-03-12 05:47:46 UTC
"Received BA when no expected" is an known issue in firmware across all iwlagn devices. our ucode team still working on it. We will release the new firmware once the problem being address.

Thanks
Wey
Comment 129 Nikolay Martynov 2011-03-12 05:55:31 UTC
(In reply to comment #128)
> "Received BA when no expected" is an known issue in firmware across all
> iwlagn
> devices. our ucode team still working on it. We will release the new firmware
> once the problem being address.

  Does this issue affect performance?

  BTW, currently I use '5000 fw v8.83.5.1 build 33692' firmware version which seems to be 'new' one.
Comment 130 wey-yi.w.guy 2011-03-12 06:15:08 UTC
I believe more or less it will impact performance on some degree.
yes, you have the latest firmware we just release few weeks ago, this firmware was to address more serious 11n aggregation issue in the ucode. we do aware the "Received BA when not expected" issue and we are continuous working it.

Thank you very much for testing and support.
Wey
Comment 131 Alexander Hall 2011-03-22 03:32:05 UTC
In reference to the splitting of the iwlagn driver with a legacy branch, will the 4965agn get a similar fix. These network cards have similar issues, including the "Received BA when not expected" errors.
Comment 132 wey-yi.w.guy 2011-03-22 14:56:50 UTC
(In reply to comment #131)
> In reference to the splitting of the iwlagn driver with a legacy branch, will
> the 4965agn get a similar fix. These network cards have similar issues,
> including the "Received BA when not expected" errors.

It will be very difficult to add the same firmware fix for legacy devices including 4965. I am really sorry about it.

Thanks
Wey
Comment 133 Arnaud Launay 2011-03-22 22:32:52 UTC
Ok, but if you cannot correct it for 4965, can you at least give us a workaround (apart from coming back to 2.6.34, which worked wonderfully...) ?
Comment 134 wey-yi.w.guy 2011-03-22 22:46:25 UTC
(In reply to comment #133)
> Ok, but if you cannot correct it for 4965, can you at least give us a
> workaround (apart from coming back to 2.6.34, which worked wonderfully...) ?

what is the problem you are seeing, is cause by "low ack count", or it complain about "tid mismatch", or it is "Received BA when not expected". I will need to know what is the bad behavior before I know how to provide w/a for you.

Thanks
Wey
Comment 135 Arnaud Launay 2011-03-23 10:01:27 UTC
Created attachment 51702 [details]
extract from kern.log for 4965

Sure, you'll find an extract of kern.log attached. Errors are "tid", followed by "received BA".
Kernel 2.6.36 from Gentoo, last stable firmware for 4965.
Comment 136 wey-yi.w.guy 2011-03-23 15:17:14 UTC
Hi Arnaud,

I look at the log you send me, thank you.
Did you experience any throughput or other issues, the "tid" and "received BA" messages you saw are new logging message we add for debugging purpose which should not cause any performance or connectivity issue. 

Thanks
Wey
Comment 137 Arnaud Launay 2011-03-24 16:00:10 UTC
Hi,
Yes, the throughput is less then expected (around 7MB/s at best in 802.11n), and I experience big latency from time to time. A "ping -f localserver" sometimes draw a dot line, before erasing it a second or two after, and it's even more noticeable when using ssh -- I type something, and it takes a second to be printed.

Unsure how to show this with logs or examples... It just seems that the connection freezes from time to time, for a small bit of time.
Comment 138 Stanislaw Gruszka 2011-04-21 13:48:10 UTC
Created attachment 54862 [details]
0001-iwl4965-fix-Received-BA-when-not-expected.patch

Proposed fix for iwlegacy for current upstream kernel. Please test.
Comment 139 Stanislaw Gruszka 2011-04-21 13:51:44 UTC
Created attachment 54872 [details]
0002-iwlagn-fix-Received-BA-when-not-expected.patch

Proposed fix for iwlagn for current upstream code. Patch fix messages on my setup, but does not fix performance with is kinda bad on 5xxx compared with 4965, anyway that should be change in good direction, please test.
Comment 140 Arnaud Launay 2011-04-21 14:17:57 UTC
I confirm that the patch 54872 (0002) works for my 4965 on a 2.6.37 kernel, I have no more BA messages, but perfs are around 1,6MB/s, despite an iwconfig bit rate at 104Mb/s . Better than before, at least ssh is usable again :)
Comment 141 Stanislaw Gruszka 2011-04-22 11:50:55 UTC
I have quite good performance on 4965 about 6 MB/s - 7 MB/s , and bad on 5300 1MB/s - 5MB/s (mostly about 2 MB/s). Also connection frequently hung on older kernels, but on current wireless-testing that seems to be fixed.
Comment 142 Stanislaw Gruszka 2011-04-22 11:55:32 UTC
Created attachment 55052 [details]
revert_sta_id_chages.patch

Arnaud, can you install 2.6.35-rc1 and apply this patch on top, and see if that help with performance on your setup?
Comment 143 Arnaud Launay 2011-04-22 11:58:52 UTC
> Arnaud, can you install 2.6.35-rc1 and apply this patch on top, and see if
> that
> help with performance on your setup?

2.6.*35* you're sure ?
Comment 144 Stanislaw Gruszka 2011-04-22 12:59:18 UTC
Yep, since this is 2.6.34 -> 2.6.35(-rc1) regression I'm investigating/bisecting/debugging 2.6.35 kernel, and prepared patch on top of 35-rc1. It probably would not apply on other versions, but you can try if you want.
Comment 145 Arnaud Launay 2011-04-23 12:19:59 UTC
It works, but perfs are still around 1,6MB.
Comment 146 Florian Mickler 2011-05-04 06:07:56 UTC
A patch referencing this bug report has been merged in v2.6.39-rc5-274-g609cfda:

commit bfd36103ec26599557c2bd3225a1f1c9267f8fcb
Author: Stanislaw Gruszka <sgruszka@redhat.com>
Date:   Fri Apr 29 17:51:06 2011 +0200

    iwlagn: fix "Received BA when not expected"
Comment 147 Stanislaw Gruszka 2011-05-12 11:14:35 UTC
FYI, I opened 34982 bug for 4965 problems reported by Arnaud, which are not yet solved.
Comment 148 I Kovalev 2011-06-05 14:22:48 UTC
I am experiencing this issue too. My system is Toshiba L40 series laptop based on Intel 945GM chipset currently equipped with 2GiB of RAM and  Intel Link 6250 ANX WiFi/WiMAX card, running Ubuntu 11.04 kernel 2.6.38-9 with the latest version of microcode from system repository - 41.28.5.1 build 33926.

What I would like to draw attention to is yet another issue which has already been reported above and might be related to "Received-BA-when-not-expected" error or might be not. It appears in the system log as an error in another process (see comment #88 for example) and results in sudden extreme latency in data exchange over PCI while accessing wireless network. Below is a typical extract of my log.

As of my observations of over a month long it occurs, for instance,  when another application accesses a data storage simultaneously with heavy traffic (>1MBit/s) passed over wireless network. To add more, it seems only affects those devices that use DMA. While SATA and IEEE1394 are clearly affected, USB 2.0 seems is not. Even though I haven't noticed any data corruption, the overall system performance is being degraded significantly.

Turning 802.11n off seems has not solved the issue completely for me. Even though "Received-BA-when-not-expected" has gone, I am still receiving errors occasionally. Currently I am trying to figure out if the issue is driver/microcode related or if it's just a kind of hardware incompatibility.

-------------------------
Jun  3 10:41:22 kovalev-home kernel: [155191.992117] Buffer I/O error on device sdb1, logical block 235695358
Jun  3 10:47:22 kovalev-home kernel: [155552.175968] __alloc_pages_slowpath: 54 callbacks suppressed
Jun  3 10:47:22 kovalev-home kernel: [155552.175972] bzip2: page allocation failure. order:1, mode:0x4020
Jun  3 10:47:22 kovalev-home kernel: [155552.175976] Pid: 15774, comm: bzip2 Tainted: G        W   2.6.38-9-generic #43-Ubuntu
Jun  3 10:47:22 kovalev-home kernel: [155552.175979] Call Trace:
Jun  3 10:47:22 kovalev-home kernel: [155552.175981]  <IRQ>  [<ffffffff81114744>] ? __alloc_pages_nodemask+0x604/0x840
Jun  3 10:47:22 kovalev-home kernel: [155552.175996]  [<ffffffff81149ed5>] ? alloc_pages_current+0xa5/0x110
Jun  3 10:47:22 kovalev-home kernel: [155552.176012]  [<ffffffffa02f9d2f>] ? iwlagn_rx_allocate+0x11f/0x280 [iwlagn]
Jun  3 10:47:22 kovalev-home kernel: [155552.176019]  [<ffffffffa02fa5cb>] ? iwlagn_rx_replenish_now+0x1b/0x30 [iwlagn]
Jun  3 10:47:22 kovalev-home kernel: [155552.176025]  [<ffffffffa02e1b1e>] ? iwl_rx_handle+0x34e/0x3e0 [iwlagn]
Jun  3 10:47:22 kovalev-home kernel: [155552.176031]  [<ffffffffa02e249c>] ? iwl_irq_tasklet+0x19c/0x840 [iwlagn]
Jun  3 10:47:22 kovalev-home kernel: [155552.176036]  [<ffffffff8106cbf3>] ? tasklet_action+0x73/0x120
Jun  3 10:47:22 kovalev-home kernel: [155552.176039]  [<ffffffff8106d4e8>] ? __do_softirq+0xa8/0x1c0
Jun  3 10:47:22 kovalev-home kernel: [155552.176043]  [<ffffffff8100cf1c>] ? call_softirq+0x1c/0x30
Jun  3 10:47:22 kovalev-home kernel: [155552.176047]  [<ffffffff8100ea45>] ? do_softirq+0x65/0xa0
Jun  3 10:47:22 kovalev-home kernel: [155552.176050]  [<ffffffff8106d705>] ? irq_exit+0x85/0x90
Jun  3 10:47:22 kovalev-home kernel: [155552.176055]  [<ffffffff815cb246>] ? do_IRQ+0x66/0xe0
Jun  3 10:47:22 kovalev-home kernel: [155552.176059]  [<ffffffff815c3593>] ? ret_from_intr+0x0/0x15
Jun  3 10:47:22 kovalev-home kernel: [155552.176060]  <EOI> Mem-Info:
Jun  3 10:47:22 kovalev-home kernel: [155552.176064] Node 0 DMA per-cpu:
Jun  3 10:47:22 kovalev-home kernel: [155552.176067] CPU    0: hi:    0, btch:   1 usd:   0
Jun  3 10:47:22 kovalev-home kernel: [155552.176070] CPU    1: hi:    0, btch:   1 usd:   0
Jun  3 10:47:22 kovalev-home kernel: [155552.176071] Node 0 DMA32 per-cpu:
Jun  3 10:47:22 kovalev-home kernel: [155552.176074] CPU    0: hi:  186, btch:  31 usd:   3
Jun  3 10:47:22 kovalev-home kernel: [155552.176077] CPU    1: hi:  186, btch:  31 usd:  72
Jun  3 10:47:22 kovalev-home kernel: [155552.176082] active_anon:170085 inactive_anon:59491 isolated_anon:0
Jun  3 10:47:22 kovalev-home kernel: [155552.176083]  active_file:68392 inactive_file:114749 isolated_file:96
Jun  3 10:47:22 kovalev-home kernel: [155552.176084]  unevictable:12 dirty:13619 writeback:4721 unstable:0
Jun  3 10:47:22 kovalev-home kernel: [155552.176085]  free:51660 slab_reclaimable:12117 slab_unreclaimable:8372
Jun  3 10:47:22 kovalev-home kernel: [155552.176087]  mapped:11297 shmem:28283 pagetables:7443 bounce:0
Jun  3 10:47:22 kovalev-home kernel: [155552.176089] Node 0 DMA free:8012kB min:40kB low:48kB high:60kB active_anon:144kB inactive_anon:644kB active_file:2812kB inactive_file:3940kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15684kB mlocked:0kB dirty:0kB writeback:0kB mapped:160kB shmem:0kB slab_reclaimable:116kB slab_unreclaimable:212kB kernel_stack:0kB pagetables:4kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Jun  3 10:47:22 kovalev-home kernel: [155552.176100] lowmem_reserve[]: 0 1996 1996 1996
Jun  3 10:47:22 kovalev-home kernel: [155552.176104] Node 0 DMA32 free:198628kB min:5696kB low:7120kB high:8544kB active_anon:680196kB inactive_anon:237320kB active_file:270756kB inactive_file:455056kB unevictable:48kB isolated(anon):0kB isolated(file):384kB present:2043984kB mlocked:16kB dirty:54476kB writeback:18884kB mapped:45028kB shmem:113132kB slab_reclaimable:48352kB slab_unreclaimable:33276kB kernel_stack:2880kB pagetables:29768kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Jun  3 10:47:22 kovalev-home kernel: [155552.176115] lowmem_reserve[]: 0 0 0 0
Jun  3 10:47:22 kovalev-home kernel: [155552.176119] Node 0 DMA: 13*4kB 9*8kB 7*16kB 15*32kB 26*64kB 0*128kB 2*256kB 2*512kB 2*1024kB 1*2048kB 0*4096kB = 8012kB
Jun  3 10:47:22 kovalev-home kernel: [155552.176130] Node 0 DMA32: 49427*4kB 7*8kB 6*16kB 6*32kB 2*64kB 0*128kB 0*256kB 1*512kB 0*1024kB 0*2048kB 0*4096kB = 198692kB
Jun  3 10:47:22 kovalev-home kernel: [155552.176141] 252560 total pagecache pages
Jun  3 10:47:22 kovalev-home kernel: [155552.176143] 41021 pages in swap cache
Jun  3 10:47:22 kovalev-home kernel: [155552.176146] Swap cache stats: add 430146, delete 389125, find 95507/123239
Jun  3 10:47:22 kovalev-home kernel: [155552.176148] Free swap  = 1290692kB
Jun  3 10:47:22 kovalev-home kernel: [155552.176150] Total swap = 1952712kB
Jun  3 10:47:22 kovalev-home kernel: [155552.186456] 522160 pages RAM
Jun  3 10:47:22 kovalev-home kernel: [155552.186460] 10049 pages reserved
Jun  3 10:47:22 kovalev-home kernel: [155552.186461] 231611 pages shared
Jun  3 10:47:22 kovalev-home kernel: [155552.186463] 288971 pages non-shared
Jun  3 10:47:22 kovalev-home kernel: [155552.186470] iwlagn 0000:02:00.0: Failed to alloc_pages with GFP_ATOMIC. Only 4 free buffers remaining.

Note You need to log in before you can comment on or make changes to this bug.