linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* iwlagn is getting even worse with 3.3-rc1
@ 2012-01-24  1:36 Norbert Preining
  2012-01-24  4:47 ` Emmanuel Grumbach
                   ` (2 more replies)
  0 siblings, 3 replies; 25+ messages in thread
From: Norbert Preining @ 2012-01-24  1:36 UTC (permalink / raw)
  To: linux-kernel, ipw3945-devel, Guy, Wey-Yi, Johannes Berg,
	Emmanuel Grumbach
  Cc: linux-wireless, ilw

Dear all, 

(please cc)

long time ago we had a long discussion about iwlagn regressions in 3.1.0
Up to 3.2 I still have regular problems on the university network
with stuck iwl driver not even realizing that nothing goes out or in.

Today I switched to 3.3-rc1 to see it is getting even worse, now on my
home network I get stuck queue and no connection:

Here a bit of dmsg:
[   59.074751] wlan0: authenticate with 00:0a:79:eb:56:10 (try 1)
[   59.077291] wlan0: authenticated
[   59.082048] wlan0: associate with 00:0a:79:eb:56:10 (try 1)
[   59.088907] wlan0: RX AssocResp from 00:0a:79:eb:56:10 (capab=0x411 status=0 aid=2)
[   59.088911] wlan0: associated
[   59.088914] wlan0: moving STA 00:0a:79:eb:56:10 to state 1
[   59.088916] wlan0: moving STA 00:0a:79:eb:56:10 to state 2
[   59.094289] cfg80211: Calling CRDA for country: JP
....
[   59.100462] cfg80211:   (5490000 KHz - 5710000 KHz @ 40000 KHz), (N/A, 2300 mBm)
[   59.640945] wlan0: moving STA 00:0a:79:eb:56:10 to state 3
[   59.893618] Rx A-MPDU request on tid 0 result 0
[   67.500767] type=1305 audit(1327367378.735:34933): auid=4294967295 ses=4294967295 op="remove rule" key=(null) list=4 res=1
[   67.500772] type=1305 audit(1327367378.735:34934): audit_enabled=0 old=1 auid=4294967295 ses=4294967295 res=1
[   70.367923] Open BA session requested for 00:0a:79:eb:56:10 tid 0
[   70.380150] activated addBA response timer on tid 0
[   70.382052] switched off addBA timer for tid 0
[   70.382054] Aggregation is on for tid 0
[   70.382193] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 0
[   79.307470] Rx A-MPDU request on tid 6 result 0
[   88.975687] Open BA session requested for 00:0a:79:eb:56:10 tid 6
[   88.996195] activated addBA response timer on tid 6
[   88.998130] switched off addBA timer for tid 6
[   88.998132] Aggregation is on for tid 6
[   88.998294] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 6
[   94.128034] tx session timer expired on tid 6
[   94.128059] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 6
[   94.144199] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 6
[  204.928067] tx session timer expired on tid 0
[  204.928080] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 0
[  204.952166] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 0
[  213.387258] Open BA session requested for 00:0a:79:eb:56:10 tid 0
[  213.404237] activated addBA response timer on tid 0
[  213.406212] switched off addBA timer for tid 0
[  213.406214] Aggregation is on for tid 0
[  213.406375] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 0
[  226.208032] tx session timer expired on tid 0
[  226.208043] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 0
[  226.240201] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 0
[  228.599092] Open BA session requested for 00:0a:79:eb:56:10 tid 0
[  228.624228] activated addBA response timer on tid 0
[  228.626198] switched off addBA timer for tid 0
[  228.626200] Aggregation is on for tid 0
[  228.626317] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 0
[  258.908018] ieee80211 phy0: release an RX reorder frame due to timeout on earlier frames
[  258.908022] ieee80211 phy0: release an RX reorder frame due to timeout on earlier frames
[  258.908024] ieee80211 phy0: release an RX reorder frame due to timeout on earlier frames
[  258.908027] ieee80211 phy0: release an RX reorder frame due to timeout on earlier frames
[  258.908030] ieee80211 phy0: release an RX reorder frame due to timeout on earlier frames
[  259.316067] ieee80211 phy0: release an RX reorder frame due to timeout on earlier frames
[  259.316071] ieee80211 phy0: release an RX reorder frame due to timeout on earlier frames
[  259.316073] ieee80211 phy0: release an RX reorder frame due to timeout on earlier frames
[  259.316076] ieee80211 phy0: release an RX reorder frame due to timeout on earlier frames
[  259.316078] ieee80211 phy0: release an RX reorder frame due to timeout on earlier frames
[  259.827797] Rx BA session stop requested for 00:0a:79:eb:56:10 tid 0 inititator reason: 0
[  259.828087] Rx BA session stop requested for 00:0a:79:eb:56:10 tid 6 inititator reason: 0
[  259.828856] Rx A-MPDU request on tid 0 result 0
[  282.159584] Rx A-MPDU request on tid 6 result 0
[  317.440056] tx session timer expired on tid 0
[  317.440092] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 0
[  317.460203] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 0
[  319.344568] Open BA session requested for 00:0a:79:eb:56:10 tid 0
[  319.364211] activated addBA response timer on tid 0
[  319.366199] switched off addBA timer for tid 0
[  319.366201] Aggregation is on for tid 0
[  319.366376] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 0
[  331.616071] tx session timer expired on tid 0
[  331.616118] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 0
[  331.636237] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 0
[  335.560927] Open BA session requested for 00:0a:79:eb:56:10 tid 0
[  335.592265] activated addBA response timer on tid 0
[  335.594210] switched off addBA timer for tid 0
[  335.594217] Aggregation is on for tid 0
[  335.594374] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 0
[  352.912068] tx session timer expired on tid 0
[  352.912099] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 0
[  358.537559] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 0
[  358.542672] Open BA session requested for 00:0a:79:eb:56:10 tid 0
[  358.564308] activated addBA response timer on tid 0
[  358.566251] switched off addBA timer for tid 0
[  358.566259] Aggregation is on for tid 0
[  358.566414] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 0
[  376.928052] tx session timer expired on tid 0
[  376.928078] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 0
[  376.952178] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 0
[  389.583167] Open BA session requested for 00:0a:79:eb:56:10 tid 0
[  389.596155] activated addBA response timer on tid 0
[  389.598079] switched off addBA timer for tid 0
[  389.598081] Aggregation is on for tid 0
[  389.598211] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 0
[  472.736062] tx session timer expired on tid 0
[  472.736103] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 0
[  478.343144] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 0
[  483.817635] Open BA session requested for 00:0a:79:eb:56:10 tid 0
[  483.832171] activated addBA response timer on tid 0
[  483.834122] switched off addBA timer for tid 0
[  483.834124] Aggregation is on for tid 0
[  483.834251] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 0
[  559.520070] tx session timer expired on tid 0
[  559.520118] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 0
[  559.540222] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 0
[  564.472540] Open BA session requested for 00:0a:79:eb:56:10 tid 0
[  564.496123] activated addBA response timer on tid 0
[  564.498038] switched off addBA timer for tid 0
[  564.498041] Aggregation is on for tid 0
[  564.498179] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 0
[  580.800050] tx session timer expired on tid 0
[  580.800077] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 0
[  580.820245] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 0
[  589.529736] Open BA session requested for 00:0a:79:eb:56:10 tid 0
[  589.540229] activated addBA response timer on tid 0
[  589.542081] switched off addBA timer for tid 0
[  589.542089] Aggregation is on for tid 0
[  589.542247] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 0
[  602.128033] tx session timer expired on tid 0
[  602.128077] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 0

Here everything stopped working without any reaction or signal
from kernel, driver, whatsoever.

After some time I decided to reset (echo 1 > ...../force_reset):

[  685.975706] Open BA session requested for 00:0a:79:eb:56:10 tid 6
[  686.000235] activated addBA response timer on tid 6
[  686.002201] switched off addBA timer for tid 6
[  686.002203] Aggregation is on for tid 6
[  686.002393] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 6
[  688.643598] iwlwifi 0000:06:00.0: On demand firmware reload
[  688.644044] ieee80211 phy0: Hardware restart was requested
[  688.644147] iwlwifi 0000:06:00.0: L1 Enabled; Disabling L0S
[  688.647179] iwlwifi 0000:06:00.0: Radio type=0x1-0x2-0x0
[  688.700816] Rx BA session stop requested for 00:0a:79:eb:56:10 tid 0 recipient reason: 36
[  688.700983] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 6
[  688.701115] Rx BA session stop requested for 00:0a:79:eb:56:10 tid 6 recipient reason: 36
[  688.701124] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 6

Still no success!!! So rfkill on and off:
[  725.234448] iwlwifi 0000:06:00.0: RF_KILL bit toggled to disable radio.
[  725.816063] iwlwifi 0000:06:00.0: Not sending command - RF KILL
[  725.816100] iwlwifi 0000:06:00.0: Not sending command - RF KILL
[  726.816121] iwlwifi 0000:06:00.0: Not sending command - RF KILL
[  726.816158] iwlwifi 0000:06:00.0: Not sending command - RF KILL
[  727.232124] iwlwifi 0000:06:00.0: Command REPLY_RXON aborted: RF KILL Switch
[  727.232151] iwlwifi 0000:06:00.0: Command REPLY_RXON aborted: RF KILL Switch
[  727.232161] iwlwifi 0000:06:00.0: Command REPLY_RXON aborted: RF KILL Switch
[  727.232177] wlan0: deauthenticating from 00:0a:79:eb:56:10 by local choice (reason=3)
[  727.264074] iwlwifi 0000:06:00.0: Command REPLY_ADD_STA aborted: RF KILL Switch
[  727.264088] ieee80211 phy0: failed to remove key (1, ff:ff:ff:ff:ff:ff) from hardware (-125)
[  727.288133] iwlwifi 0000:06:00.0: Command REPLY_ADD_STA aborted: RF KILL Switch
[  727.288146] ieee80211 phy0: failed to remove key (0, 00:0a:79:eb:56:10) from hardware (-125)
[  727.288221] wlan0: moving STA 00:0a:79:eb:56:10 to state 2
[  727.288227] wlan0: moving STA 00:0a:79:eb:56:10 to state 1
[  727.288234] wlan0: moving STA 00:0a:79:eb:56:10 to state 0
[  727.288243] iwlwifi 0000:06:00.0: Command REPLY_REMOVE_STA aborted: RF KILL Switch
[  727.320227] ieee80211 phy0: TX A-MPDU  purging 264 packets for tid=0
[  727.320461] iwlwifi 0000:06:00.0: Command REPLY_RXON aborted: RF KILL Switch
[  727.320497] iwlwifi 0000:06:00.0: Not sending command - RF KILL
[  727.320510] iwlwifi 0000:06:00.0: Command REPLY_RXON aborted: RF KILL Switch
[  727.320557] cfg80211: Calling CRDA to update world regulatory domain
[  727.340111] iwlwifi 0000:06:00.0: Command REPLY_RXON aborted: RF KILL Switch
[  727.345213] cfg80211: World regulatory domain updated:
[  727.345222] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
[  727.345232] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[  727.345241] cfg80211:   (2457000 KHz - 2482000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
[  727.345249] cfg80211:   (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
[  727.345257] cfg80211:   (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[  727.345266] cfg80211:   (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[  735.347967] iwlwifi 0000:06:00.0: RF_KILL bit toggled to enable radio.
[  735.350637] iwlwifi 0000:06:00.0: L1 Enabled; Disabling L0S
[  735.353938] iwlwifi 0000:06:00.0: Radio type=0x1-0x2-0x0
[  742.984202] wlan0: authenticate with 00:0a:79:eb:56:10 (try 1)
[  742.989491] wlan0: authenticated
[  742.991201] wlan0: associate with 00:0a:79:eb:56:10 (try 1)
[  742.997018] wlan0: RX AssocResp from 00:0a:79:eb:56:10 (capab=0x411 status=0 aid=2)
[  742.997037] wlan0: moving STA 00:0a:79:eb:56:10 to state 1
[  742.997044] wlan0: moving STA 00:0a:79:eb:56:10 to state 2
[  743.003883] cfg80211: Calling CRDA for country: JP
[  743.013936] cfg80211: Regulatory domain changed to country: JP
[  743.013946] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
[  743.013955] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz), (N/A, 2000 mBm)
[  743.013964] cfg80211:   (2457000 KHz - 2482000 KHz @ 20000 KHz), (N/A, 2000 mBm)
[  743.013971] cfg80211:   (2474000 KHz - 2494000 KHz @ 20000 KHz), (N/A, 2000 mBm)
[  743.013979] cfg80211:   (4910000 KHz - 4930000 KHz @ 10000 KHz), (N/A, 2300 mBm)
[  743.013987] cfg80211:   (4910000 KHz - 4990000 KHz @ 40000 KHz), (N/A, 2300 mBm)
[  743.013994] cfg80211:   (4930000 KHz - 4950000 KHz @ 10000 KHz), (N/A, 2300 mBm)
[  743.014002] cfg80211:   (5030000 KHz - 5045000 KHz @ 10000 KHz), (N/A, 2300 mBm)
[  743.014010] cfg80211:   (5030000 KHz - 5090000 KHz @ 40000 KHz), (N/A, 2300 mBm)
[  743.014017] cfg80211:   (5050000 KHz - 5060000 KHz @ 10000 KHz), (N/A, 2300 mBm)
[  743.014025] cfg80211:   (5170000 KHz - 5250000 KHz @ 40000 KHz), (N/A, 2000 mBm)
[  743.014033] cfg80211:   (5250000 KHz - 5330000 KHz @ 40000 KHz), (N/A, 2000 mBm)
[  743.014040] cfg80211:   (5490000 KHz - 5710000 KHz @ 40000 KHz), (N/A, 2300 mBm)
[  743.641206] wlan0: moving STA 00:0a:79:eb:56:10 to state 3
[  743.707121] Rx A-MPDU request on tid 0 result 0
[  754.151203] Rx A-MPDU request on tid 6 result 0
[  757.526560] Open BA session requested for 00:0a:79:eb:56:10 tid 0
[  757.544182] activated addBA response timer on tid 0
[  758.544087] addBA response timer expired on tid 0
[  758.544135] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 0
[  765.471766] switched off addBA timer for tid 0
[  765.471773] got addBA resp for tid 0 but we already gave up
[  765.471812] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 0
[  766.117423] Open BA session requested for 00:0a:79:eb:56:10 tid 0
[  766.137379] activated addBA response timer on tid 0
[  766.139746] switched off addBA timer for tid 0
[  766.139752] Aggregation is on for tid 0
[  766.139895] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 0
[  807.975974] Open BA session requested for 00:0a:79:eb:56:10 tid 6
[  807.996257] activated addBA response timer on tid 6
[  807.998205] switched off addBA timer for tid 6
[  807.998212] Aggregation is on for tid 6
[  807.998370] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 6
[  814.112068] tx session timer expired on tid 6
[  814.112118] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 6
[  814.132223] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 6
[  869.975764] Open BA session requested for 00:0a:79:eb:56:10 tid 6
[  869.992279] activated addBA response timer on tid 6

etc etc etc etc etc ... but at least now it is working.

Seems that iwlwifi is not really improving in any way.

Please let me know if you want me to test more patches or debugging.

Thanks

Norbert
------------------------------------------------------------------------
Norbert Preining            preining@{jaist.ac.jp, logic.at, debian.org}
JAIST, Japan                                 TeX Live & Debian Developer
DSA: 0x09C5B094   fp: 14DF 2E6C 0307 BE6D AD76  A9C0 D2BF 4AA3 09C5 B094
------------------------------------------------------------------------
ADRIGOLE (n.)
The centrepiece of a merry-go-round on which the man with the tickets
stands unnervingly still.
			--- Douglas Adams, The Meaning of Liff

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: iwlagn is getting even worse with 3.3-rc1
  2012-01-24  1:36 iwlagn is getting even worse with 3.3-rc1 Norbert Preining
@ 2012-01-24  4:47 ` Emmanuel Grumbach
  2012-01-25  0:22   ` Norbert Preining
  2012-02-22  8:37 ` Pekka Enberg
  2012-02-27 10:00 ` Matthew Turnbull
  2 siblings, 1 reply; 25+ messages in thread
From: Emmanuel Grumbach @ 2012-01-24  4:47 UTC (permalink / raw)
  To: Norbert Preining
  Cc: linux-kernel, ipw3945-devel, Guy, Wey-Yi, Johannes Berg,
	linux-wireless, ilw

On Mon, Jan 23, 2012 at 17:36, Norbert Preining <preining@logic.at> wrote:
> Dear all,
>
> (please cc)
>
> long time ago we had a long discussion about iwlagn regressions in 3.1.0
> Up to 3.2 I still have regular problems on the university network
> with stuck iwl driver not even realizing that nothing goes out or in.
>
> Today I switched to 3.3-rc1 to see it is getting even worse, now on my
> home network I get stuck queue and no connection:
>

Can you please run with debug flags 0x80000000 ?
We will probably need to enable TX_REPLY too: 0xC0000000 but this one
is noisy, so let's begin the 0x80000000

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: iwlagn is getting even worse with 3.3-rc1
  2012-01-24  4:47 ` Emmanuel Grumbach
@ 2012-01-25  0:22   ` Norbert Preining
  2012-01-25  5:32     ` Emmanuel Grumbach
  0 siblings, 1 reply; 25+ messages in thread
From: Norbert Preining @ 2012-01-25  0:22 UTC (permalink / raw)
  To: Emmanuel Grumbach
  Cc: linux-kernel, ipw3945-devel, Guy, Wey-Yi, Johannes Berg,
	linux-wireless, ilw

[-- Attachment #1: Type: text/plain, Size: 914 bytes --]

Hi Emmanuel,

On Mo, 23 Jan 2012, Emmanuel Grumbach wrote:
> Can you please run with debug flags 0x80000000 ?

Here we go. Booting into 3.3-rc1 tries to connect, the connection seems
to be established, but nothing actually goes out/in.
Main problem seems to be:
	iwlagn_tx_agg_stop Can't proceed: ssn 340, next_recl = 329

rfkill block wifi ; sleep 10; rfkill unblock wifi

helps.

I attach the dmesg of all wifi related things since boot.

Best wishes

Norbert
------------------------------------------------------------------------
Norbert Preining            preining@{jaist.ac.jp, logic.at, debian.org}
JAIST, Japan                                 TeX Live & Debian Developer
DSA: 0x09C5B094   fp: 14DF 2E6C 0307 BE6D AD76  A9C0 D2BF 4AA3 09C5 B094
------------------------------------------------------------------------
WHAPLODE DROVE (n.)
A homicidal golf stroke.
			--- Douglas Adams, The Meaning of Liff

[-- Attachment #2: dmesg.txt --]
[-- Type: text/plain, Size: 17718 bytes --]

[   35.768085] cfg80211: Calling CRDA to update world regulatory domain
[   35.980591] Intel(R) Wireless WiFi Link AGN driver for Linux, in-tree:d
[   35.982187] Copyright(c) 2003-2011 Intel Corporation
[   35.983888] iwlwifi 0000:06:00.0: pci_resource_len = 0x00002000
[   35.985471] iwlwifi 0000:06:00.0: pci_resource_base = ffffc900041bc000
[   35.986981] iwlwifi 0000:06:00.0: HW Revision ID = 0x0
[   35.988618] iwlwifi 0000:06:00.0: irq 47 for MSI/MSI-X
[   35.988681] iwlwifi 0000:06:00.0: CONFIG_IWLWIFI_DEBUG enabled
[   35.990170] iwlwifi 0000:06:00.0: CONFIG_IWLWIFI_DEBUGFS enabled
[   35.991651] iwlwifi 0000:06:00.0: CONFIG_IWLWIFI_DEVICE_TRACING disabled
[   35.993136] iwlwifi 0000:06:00.0: CONFIG_IWLWIFI_DEVICE_TESTMODE disabled
[   35.994616] iwlwifi 0000:06:00.0: CONFIG_IWLWIFI_P2P disabled
[   35.996112] iwlwifi 0000:06:00.0: Detected Intel(R) WiFi Link 5100 AGN, REV=0x54
[   35.997658] iwlwifi 0000:06:00.0: L1 Enabled; Disabling L0S
[   36.012102] firewire_core: created device fw0: GUID 0800460302b0163b, S400
[   36.020947] iwlwifi 0000:06:00.0: device EEPROM VER=0x11e, CALIB=0x4
[   36.022379] iwlwifi 0000:06:00.0: Device SKU: 0xF0
[   36.023793] iwlwifi 0000:06:00.0: Tunable channels: 13 802.11bg, 24 802.11a channels
[   36.623830] iwlwifi 0000:06:00.0: loaded firmware version 8.83.5.1 build 33692 (EXP)
[   36.625485] Registered led device: phy0-led
[   36.653785] ieee80211 phy0: Selected rate control algorithm 'iwl-agn-rs'

...

[   37.015237] cfg80211: World regulatory domain updated:
[   37.016730] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
[   37.018157] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[   37.019581] cfg80211:   (2457000 KHz - 2482000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
[   37.021011] cfg80211:   (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
[   37.022390] cfg80211:   (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[   37.023744] cfg80211:   (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)

...

[   45.598110] iwlwifi 0000:06:00.0: L1 Enabled; Disabling L0S
[   45.602018] iwlwifi 0000:06:00.0: Radio type=0x1-0x2-0x0
[   45.642289] iwlwifi 0000:06:00.0: U iwl_trans_set_wr_ptrs Q 4  WrPtr: 0
[   45.642359] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Activate AC/CMD Queue 0 on FIFO 3
[   45.642424] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Activate AC/CMD Queue 1 on FIFO 2
[   45.642486] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Activate AC/CMD Queue 2 on FIFO 1
[   45.642549] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Activate AC/CMD Queue 3 on FIFO 0
[   45.642610] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Activate AC/CMD Queue 4 on FIFO 7
[   45.717238] iwlwifi 0000:06:00.0: L1 Enabled; Disabling L0S
[   45.720267] iwlwifi 0000:06:00.0: Radio type=0x1-0x2-0x0
[   45.762302] iwlwifi 0000:06:00.0: U iwl_trans_set_wr_ptrs Q 4  WrPtr: 0
[   45.762335] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Activate AC/CMD Queue 0 on FIFO 3
[   45.762347] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Activate AC/CMD Queue 1 on FIFO 2
[   45.762360] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Activate AC/CMD Queue 2 on FIFO 1
[   45.762372] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Activate AC/CMD Queue 3 on FIFO 0
[   45.762385] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Activate AC/CMD Queue 4 on FIFO 7

...

[   53.589698] wlan0: authenticate with 00:0a:79:eb:56:10 (try 1)
[   53.598039] wlan0: authenticated
[   53.602978] wlan0: associate with 00:0a:79:eb:56:10 (try 1)
[   53.616050] wlan0: RX AssocResp from 00:0a:79:eb:56:10 (capab=0x411 status=0 aid=3)
[   53.616054] wlan0: associated
[   53.616058] wlan0: moving STA 00:0a:79:eb:56:10 to state 1
[   53.616060] wlan0: moving STA 00:0a:79:eb:56:10 to state 2
[   53.625011] cfg80211: Calling CRDA for country: JP
[   53.629833] cfg80211: Regulatory domain changed to country: JP
[   53.629836] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
[   53.629839] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz), (N/A, 2000 mBm)
[   53.629842] cfg80211:   (2457000 KHz - 2482000 KHz @ 20000 KHz), (N/A, 2000 mBm)
[   53.629844] cfg80211:   (2474000 KHz - 2494000 KHz @ 20000 KHz), (N/A, 2000 mBm)
[   53.629846] cfg80211:   (4910000 KHz - 4930000 KHz @ 10000 KHz), (N/A, 2300 mBm)
[   53.629849] cfg80211:   (4910000 KHz - 4990000 KHz @ 40000 KHz), (N/A, 2300 mBm)
[   53.629851] cfg80211:   (4930000 KHz - 4950000 KHz @ 10000 KHz), (N/A, 2300 mBm)
[   53.629854] cfg80211:   (5030000 KHz - 5045000 KHz @ 10000 KHz), (N/A, 2300 mBm)
[   53.629856] cfg80211:   (5030000 KHz - 5090000 KHz @ 40000 KHz), (N/A, 2300 mBm)
[   53.629859] cfg80211:   (5050000 KHz - 5060000 KHz @ 10000 KHz), (N/A, 2300 mBm)
[   53.629861] cfg80211:   (5170000 KHz - 5250000 KHz @ 40000 KHz), (N/A, 2000 mBm)
[   53.629864] cfg80211:   (5250000 KHz - 5330000 KHz @ 40000 KHz), (N/A, 2000 mBm)
[   53.629866] cfg80211:   (5490000 KHz - 5710000 KHz @ 40000 KHz), (N/A, 2300 mBm)
[   53.891052] wlan0: moving STA 00:0a:79:eb:56:10 to state 3
[   54.149647] Rx A-MPDU request on tid 0 result 0
[   65.575106] Open BA session requested for 00:0a:79:eb:56:10 tid 0
[   65.592289] iwlwifi 0000:06:00.0: U iwlagn_tx_agg_start Can proceed: ssn = next_recl = 66
[   65.592307] activated addBA response timer on tid 0
[   65.594292] switched off addBA timer for tid 0
[   65.594300] Aggregation is on for tid 0
[   65.594397] iwlwifi 0000:06:00.0: U iwl_trans_set_wr_ptrs Q 11  WrPtr: 66
[   65.594486] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Activate BA Queue 11 on FIFO 1
[   65.594496] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 0
[   73.331722] Rx A-MPDU request on tid 6 result 0
[   73.331806] unexpected AddBA Req from 00:0a:79:eb:56:10 on tid 6
[   73.331815] Rx BA session stop requested for 00:0a:79:eb:56:10 tid 6 recipient reason: 32
[   73.333589] Rx A-MPDU request on tid 6 result 0
[   74.417278] Open BA session requested for 00:0a:79:eb:56:10 tid 6
[   74.440231] iwlwifi 0000:06:00.0: U iwlagn_tx_agg_start Can proceed: ssn = next_recl = 13
[   74.440252] activated addBA response timer on tid 6
[   74.442198] switched off addBA timer for tid 6
[   74.442204] Aggregation is on for tid 6
[   74.442331] iwlwifi 0000:06:00.0: U iwl_trans_set_wr_ptrs Q 12  WrPtr: 13
[   74.442436] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Activate BA Queue 12 on FIFO 3
[   74.442446] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 6
[   74.629141] ieee80211 phy0: release an RX reorder frame due to timeout on earlier frames
[   74.629151] ieee80211 phy0: release an RX reorder frame due to timeout on earlier frames
[   89.536080] tx session timer expired on tid 6
[   89.536109] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 6
[   89.560113] iwlwifi 0000:06:00.0: U iwlagn_tx_agg_stop Can proceed: ssn = next_recl = 26
[   89.560172] iwlwifi 0000:06:00.0: U iwl_trans_set_wr_ptrs Q 12  WrPtr: 0
[   89.560251] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 12 on FIFO 0
[   89.560273] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 6
[  102.896068] tx session timer expired on tid 0
[  102.896116] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 0
[  102.916116] iwlwifi 0000:06:00.0: U iwlagn_tx_agg_stop Can proceed: ssn = next_recl = 163
[  102.916176] iwlwifi 0000:06:00.0: U iwl_trans_set_wr_ptrs Q 11  WrPtr: 0
[  102.916253] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
[  102.916273] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 0
[  108.838002] Open BA session requested for 00:0a:79:eb:56:10 tid 0
[  108.856257] iwlwifi 0000:06:00.0: U iwlagn_tx_agg_start Can proceed: ssn = next_recl = 167
[  108.856276] activated addBA response timer on tid 0
[  109.856064] addBA response timer expired on tid 0
[  109.856110] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 0
[  109.872130] iwlwifi 0000:06:00.0: U iwlagn_tx_agg_stop Can proceed: ssn = next_recl = 167
[  109.872177] iwlwifi 0000:06:00.0: U iwl_trans_set_wr_ptrs Q 11  WrPtr: 0
[  109.872232] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
[  112.755165] switched off addBA timer for tid 0
[  112.755168] got addBA resp for tid 0 but we already gave up
[  112.755178] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 0
[  114.418021] Open BA session requested for 00:0a:79:eb:56:10 tid 6
[  114.448976] iwlwifi 0000:06:00.0: U iwlagn_tx_agg_start Can proceed: ssn = next_recl = 27
[  114.448994] activated addBA response timer on tid 6
[  114.452114] switched off addBA timer for tid 6
[  114.452122] Aggregation is on for tid 6
[  114.452230] iwlwifi 0000:06:00.0: U iwl_trans_set_wr_ptrs Q 11  WrPtr: 27
[  114.452319] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Activate BA Queue 11 on FIFO 3
[  114.452329] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 6
[  119.381587] Open BA session requested for 00:0a:79:eb:56:10 tid 0
[  119.400274] iwlwifi 0000:06:00.0: U iwlagn_tx_agg_start Can proceed: ssn = next_recl = 184
[  119.400293] activated addBA response timer on tid 0
[  119.402287] switched off addBA timer for tid 0
[  119.402294] Aggregation is on for tid 0
[  119.402390] iwlwifi 0000:06:00.0: U iwl_trans_set_wr_ptrs Q 12  WrPtr: 184
[  119.402479] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Activate BA Queue 12 on FIFO 1
[  119.402489] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 0
[  119.584066] tx session timer expired on tid 6
[  119.584109] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 6
[  119.604111] iwlwifi 0000:06:00.0: U iwlagn_tx_agg_stop Can proceed: ssn = next_recl = 27
[  119.604168] iwlwifi 0000:06:00.0: U iwl_trans_set_wr_ptrs Q 11  WrPtr: 0
[  119.604246] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
[  119.604265] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 6
[  131.184092] tx session timer expired on tid 0
[  131.184141] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 0
[  131.204121] iwlwifi 0000:06:00.0: U iwlagn_tx_agg_stop Can proceed: ssn = next_recl = 255
[  131.204180] iwlwifi 0000:06:00.0: U iwl_trans_set_wr_ptrs Q 12  WrPtr: 0
[  131.204258] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 12 on FIFO 0
[  131.204280] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 0
[  139.198746] Open BA session requested for 00:0a:79:eb:56:10 tid 0
[  139.220255] iwlwifi 0000:06:00.0: U iwlagn_tx_agg_start Can proceed: ssn = next_recl = 262
[  139.220273] activated addBA response timer on tid 0
[  139.222218] switched off addBA timer for tid 0
[  139.222225] Aggregation is on for tid 0
[  139.222322] iwlwifi 0000:06:00.0: U iwl_trans_set_wr_ptrs Q 11  WrPtr: 6
[  139.222411] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Activate BA Queue 11 on FIFO 1
[  139.222421] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 0
[  144.352068] tx session timer expired on tid 0
[  144.352114] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 0
[  144.368114] iwlwifi 0000:06:00.0: U iwlagn_tx_agg_stop Can proceed: ssn = next_recl = 263
[  144.368172] iwlwifi 0000:06:00.0: U iwl_trans_set_wr_ptrs Q 11  WrPtr: 0
[  144.368249] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
[  144.368269] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 0
[  150.289509] Open BA session requested for 00:0a:79:eb:56:10 tid 0
[  150.308286] iwlwifi 0000:06:00.0: U iwlagn_tx_agg_start Can proceed: ssn = next_recl = 268
[  150.308307] activated addBA response timer on tid 0
[  150.310290] switched off addBA timer for tid 0
[  150.310296] Aggregation is on for tid 0
[  150.310393] iwlwifi 0000:06:00.0: U iwl_trans_set_wr_ptrs Q 11  WrPtr: 12
[  150.310483] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Activate BA Queue 11 on FIFO 1
[  150.310493] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 0
[  170.640067] tx session timer expired on tid 0
[  170.640114] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 0
[  170.660139] iwlwifi 0000:06:00.0: U iwlagn_tx_agg_stop Can proceed: ssn = next_recl = 280
[  170.660198] iwlwifi 0000:06:00.0: U iwl_trans_set_wr_ptrs Q 11  WrPtr: 0
[  170.660276] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
[  172.557483] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 0
[  177.553796] Open BA session requested for 00:0a:79:eb:56:10 tid 0
[  177.572273] iwlwifi 0000:06:00.0: U iwlagn_tx_agg_start Can proceed: ssn = next_recl = 286
[  177.572291] activated addBA response timer on tid 0
[  177.574282] switched off addBA timer for tid 0
[  177.574289] Aggregation is on for tid 0
[  177.574385] iwlwifi 0000:06:00.0: U iwl_trans_set_wr_ptrs Q 11  WrPtr: 30
[  177.574476] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Activate BA Queue 11 on FIFO 1
[  177.574486] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 0
[  184.688066] tx session timer expired on tid 0
[  184.688111] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 0
[  184.708131] iwlwifi 0000:06:00.0: U iwlagn_tx_agg_stop Can proceed: ssn = next_recl = 289
[  184.708188] iwlwifi 0000:06:00.0: U iwl_trans_set_wr_ptrs Q 11  WrPtr: 0
[  184.708266] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
[  184.708286] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 0
[  192.842284] Open BA session requested for 00:0a:79:eb:56:10 tid 0
[  192.868302] iwlwifi 0000:06:00.0: U iwlagn_tx_agg_start Can proceed: ssn = next_recl = 298
[  192.868320] activated addBA response timer on tid 0
[  192.870209] switched off addBA timer for tid 0
[  192.870216] Aggregation is on for tid 0
[  192.870312] iwlwifi 0000:06:00.0: U iwl_trans_set_wr_ptrs Q 11  WrPtr: 42
[  192.870402] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Activate BA Queue 11 on FIFO 1
[  192.870412] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 0
[  206.418315] Open BA session requested for 00:0a:79:eb:56:10 tid 6
[  206.436268] iwlwifi 0000:06:00.0: U iwlagn_tx_agg_start Can proceed: ssn = next_recl = 37
[  206.436287] activated addBA response timer on tid 6
[  206.438335] switched off addBA timer for tid 6
[  206.438342] Aggregation is on for tid 6
[  206.438437] iwlwifi 0000:06:00.0: U iwl_trans_set_wr_ptrs Q 12  WrPtr: 37
[  206.438527] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Activate BA Queue 12 on FIFO 3
[  206.438537] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 6
[  212.544076] tx session timer expired on tid 6
[  212.544125] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 6
[  212.560113] iwlwifi 0000:06:00.0: U iwlagn_tx_agg_stop Can proceed: ssn = next_recl = 38
[  212.560172] iwlwifi 0000:06:00.0: U iwl_trans_set_wr_ptrs Q 12  WrPtr: 0
[  212.560250] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 12 on FIFO 0
[  212.560270] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 6
[  218.304086] tx session timer expired on tid 0
[  218.304131] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 0
[  218.324119] iwlwifi 0000:06:00.0: U iwlagn_tx_agg_stop Can proceed: ssn = next_recl = 317
[  218.324176] iwlwifi 0000:06:00.0: U iwl_trans_set_wr_ptrs Q 11  WrPtr: 0
[  218.324254] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
[  218.324274] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 0
[  230.017770] Open BA session requested for 00:0a:79:eb:56:10 tid 0
[  230.036272] iwlwifi 0000:06:00.0: U iwlagn_tx_agg_start Can proceed: ssn = next_recl = 326
[  230.036290] activated addBA response timer on tid 0
[  230.038258] switched off addBA timer for tid 0
[  230.038265] Aggregation is on for tid 0
[  230.038361] iwlwifi 0000:06:00.0: U iwl_trans_set_wr_ptrs Q 11  WrPtr: 70
[  230.038450] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Activate BA Queue 11 on FIFO 1
[  230.038461] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 0
[  239.584087] tx session timer expired on tid 0
[  239.584134] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 0
[  239.604118] iwlwifi 0000:06:00.0: U iwlagn_tx_agg_stop Can proceed: ssn = next_recl = 331
[  239.604176] iwlwifi 0000:06:00.0: U iwl_trans_set_wr_ptrs Q 11  WrPtr: 0
[  239.604253] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
[  239.604273] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 0
[  241.484939] Open BA session requested for 00:0a:79:eb:56:10 tid 0
[  241.512277] iwlwifi 0000:06:00.0: U iwlagn_tx_agg_start Can proceed: ssn = next_recl = 333
[  241.512282] activated addBA response timer on tid 0
[  241.514167] switched off addBA timer for tid 0
[  241.514169] Aggregation is on for tid 0
[  241.514252] iwlwifi 0000:06:00.0: U iwl_trans_set_wr_ptrs Q 11  WrPtr: 77
[  241.514336] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Activate BA Queue 11 on FIFO 1
[  241.514339] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 0
[  253.808089] tx session timer expired on tid 0
[  253.808111] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 0
[  253.828117] iwlwifi 0000:06:00.0: U iwlagn_tx_agg_stop Can't proceed: ssn 340, next_recl = 329

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: iwlagn is getting even worse with 3.3-rc1
  2012-01-25  0:22   ` Norbert Preining
@ 2012-01-25  5:32     ` Emmanuel Grumbach
  2012-01-26  0:37       ` Norbert Preining
  0 siblings, 1 reply; 25+ messages in thread
From: Emmanuel Grumbach @ 2012-01-25  5:32 UTC (permalink / raw)
  To: Norbert Preining
  Cc: linux-kernel, ipw3945-devel, Guy, Wey-Yi, Johannes Berg,
	linux-wireless, ilw

On Tue, Jan 24, 2012 at 16:22, Norbert Preining <preining@logic.at> wrote:
> Hi Emmanuel,
>
> On Mo, 23 Jan 2012, Emmanuel Grumbach wrote:
>> Can you please run with debug flags 0x80000000 ?
>
> Here we go. Booting into 3.3-rc1 tries to connect, the connection seems
> to be established, but nothing actually goes out/in.
> Main problem seems to be:
>        iwlagn_tx_agg_stop Can't proceed: ssn 340, next_recl = 329
>
> rfkill block wifi ; sleep 10; rfkill unblock wifi
>
> helps.
>
> I attach the dmesg of all wifi related things since boot.
>

yeah... looks like the same issue as Dave. Can you please try with 0xc0000000 ?
it will be noisy so be prepared...

I will send a patch to clarify one thing about mgmt frames, but as I
said I am not in my office until end of next week.

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: iwlagn is getting even worse with 3.3-rc1
  2012-01-25  5:32     ` Emmanuel Grumbach
@ 2012-01-26  0:37       ` Norbert Preining
  2012-01-26  5:49         ` Emmanuel Grumbach
  0 siblings, 1 reply; 25+ messages in thread
From: Norbert Preining @ 2012-01-26  0:37 UTC (permalink / raw)
  To: Emmanuel Grumbach
  Cc: linux-kernel, ipw3945-devel, Guy, Wey-Yi, Johannes Berg,
	linux-wireless, ilw

Hi Emmanuel,

On Di, 24 Jan 2012, Emmanuel Grumbach wrote:
> yeah... looks like the same issue as Dave. Can you please try with 0xc0000000 ?
> it will be noisy so be prepared...

syslog output is at http://www.logic.at/people/preining/syslog.log
this is after a suspend and resume.

first connection after resume succeeded at around kernel time 378.859794
then it worked for say 20sec or so, hard to say when exactely it dropped,
but defeinitely at kernel time 451 it was finished.

After that nothing went out or in again.

Hope you can make something out of that.

Best wishes

Norbert
------------------------------------------------------------------------
Norbert Preining            preining@{jaist.ac.jp, logic.at, debian.org}
JAIST, Japan                                 TeX Live & Debian Developer
DSA: 0x09C5B094   fp: 14DF 2E6C 0307 BE6D AD76  A9C0 D2BF 4AA3 09C5 B094
------------------------------------------------------------------------
SKETTY (n.)
Apparently self-propelled little dance a beer glass performs in its
own puddle.
			--- Douglas Adams, The Meaning of Liff

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: iwlagn is getting even worse with 3.3-rc1
  2012-01-26  0:37       ` Norbert Preining
@ 2012-01-26  5:49         ` Emmanuel Grumbach
  2012-01-26 21:13           ` Emmanuel Grumbach
  0 siblings, 1 reply; 25+ messages in thread
From: Emmanuel Grumbach @ 2012-01-26  5:49 UTC (permalink / raw)
  To: Norbert Preining
  Cc: linux-kernel, ipw3945-devel, Guy, Wey-Yi, Johannes Berg,
	linux-wireless, ilw

[-- Attachment #1: Type: text/plain, Size: 849 bytes --]

Hi Norbert,

>
> syslog output is at http://www.logic.at/people/preining/syslog.log
> this is after a suspend and resume.
>
> first connection after resume succeeded at around kernel time 378.859794
> then it worked for say 20sec or so, hard to say when exactely it dropped,
> but defeinitely at kernel time 451 it was finished.
>
> After that nothing went out or in again.
>
> Hope you can make something out of that.
>

Unfortunately, not really. I can see you are hitting PASSIVE_NO_RX,
meaning that the uCode complains that you are trying to Tx on a
passive channel on which it hasn't heard any beacon yet. But then we
finally get a beacon there, and open the queue again.

Anyway, can you try the attached patch ?
Note that I have no real way to test it (I have to admit I haven't
even compiled... I am not in my office).
I hope it might help.

[-- Attachment #2: tid.patch --]
[-- Type: application/octet-stream, Size: 1998 bytes --]

diff --git a/drivers/net/wireless/iwlwifi/iwl-agn-tx.c b/drivers/net/wireless/iwlwifi/iwl-agn-tx.c
index d9d758e..1b70048 100644
--- a/drivers/net/wireless/iwlwifi/iwl-agn-tx.c
+++ b/drivers/net/wireless/iwlwifi/iwl-agn-tx.c
@@ -95,6 +95,7 @@ static void iwlagn_tx_cmd_build_basic(struct iwl_priv *priv,
 			tx_flags |= TX_CMD_FLG_SEQ_CTL_MSK;
 		else
 			tx_flags &= ~TX_CMD_FLG_SEQ_CTL_MSK;
+		tx_cmd->tid_tspec = IWL_MAX_TID_COUNT;
 	}
 
 	iwlagn_tx_cmd_protection(priv, info, fc, &tx_flags);
@@ -808,6 +809,8 @@ static void iwl_rx_reply_tx_agg(struct iwl_priv *priv,
 	u32 status = le16_to_cpu(tx_resp->status.status);
 	int i;
 
+        WARN_ON(tid == IWL_MAX_TID_COUNT);
+
 	if (agg->wait_for_ba)
 		IWL_DEBUG_TX_REPLY(priv,
 			"got tx response w/o block-ack\n");
@@ -1035,10 +1038,12 @@ int iwlagn_rx_reply_tx(struct iwl_priv *priv, struct iwl_rx_mem_buffer *rxb,
 		}
 
 		__skb_queue_head_init(&skbs);
-		priv->tid_data[sta_id][tid].next_reclaimed = next_reclaimed;
 
-		IWL_DEBUG_TX_REPLY(priv, "Next reclaimed packet:%d",
-					  next_reclaimed);
+		if (tid != IWL_MAX_TID_COUNT) {
+			priv->tid_data[sta_id][tid].next_reclaimed = next_reclaimed;
+			IWL_DEBUG_TX_REPLY(priv, "Next reclaimed packet:%d",
+						  next_reclaimed);
+		}
 
 		/*we can free until ssn % q.n_bd not inclusive */
 		WARN_ON(iwl_trans_reclaim(trans(priv), sta_id, tid, txq_id,
diff --git a/drivers/net/wireless/iwlwifi/iwl-trans-pcie.c b/drivers/net/wireless/iwlwifi/iwl-trans-pcie.c
index aa87994..fa1b369 100644
--- a/drivers/net/wireless/iwlwifi/iwl-trans-pcie.c
+++ b/drivers/net/wireless/iwlwifi/iwl-trans-pcie.c
@@ -1551,7 +1551,7 @@ static int iwl_trans_pcie_reclaim(struct iwl_trans *trans, int sta_id, int tid,
 
 	txq->time_stamp = jiffies;
 
-	if (unlikely(txq_id >= IWLAGN_FIRST_AMPDU_QUEUE &&
+	if (unlikely(tid != IWL_MAX_TID_COUNT && txq_id >= IWLAGN_FIRST_AMPDU_QUEUE &&
 		     txq_id != trans_pcie->agg_txq[sta_id][tid])) {
 		/*
 		 * FIXME: this is a uCode bug which need to be addressed,

^ permalink raw reply related	[flat|nested] 25+ messages in thread

* Re: iwlagn is getting even worse with 3.3-rc1
  2012-01-26  5:49         ` Emmanuel Grumbach
@ 2012-01-26 21:13           ` Emmanuel Grumbach
  2012-01-26 23:25             ` Norbert Preining
  0 siblings, 1 reply; 25+ messages in thread
From: Emmanuel Grumbach @ 2012-01-26 21:13 UTC (permalink / raw)
  To: Norbert Preining
  Cc: linux-kernel, ipw3945-devel, Guy, Wey-Yi, Johannes Berg,
	linux-wireless, ilw, Dave Jones

Hey Dave,

Can you please try to patch attached to this thread. You and Norbert
are suffering from the same issue. I am merging the mail threads here.

On Wed, Jan 25, 2012 at 21:49, Emmanuel Grumbach <egrumbach@gmail.com> wrote:
> Hi Norbert,
>
>>
>> syslog output is at http://www.logic.at/people/preining/syslog.log
>> this is after a suspend and resume.
>>
>> first connection after resume succeeded at around kernel time 378.859794
>> then it worked for say 20sec or so, hard to say when exactely it dropped,
>> but defeinitely at kernel time 451 it was finished.
>>
>> After that nothing went out or in again.
>>
>> Hope you can make something out of that.
>>
>
> Unfortunately, not really. I can see you are hitting PASSIVE_NO_RX,
> meaning that the uCode complains that you are trying to Tx on a
> passive channel on which it hasn't heard any beacon yet. But then we
> finally get a beacon there, and open the queue again.
>
> Anyway, can you try the attached patch ?
> Note that I have no real way to test it (I have to admit I haven't
> even compiled... I am not in my office).
> I hope it might help.

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: iwlagn is getting even worse with 3.3-rc1
  2012-01-26 21:13           ` Emmanuel Grumbach
@ 2012-01-26 23:25             ` Norbert Preining
  2012-01-27  0:06               ` Emmanuel Grumbach
  2012-01-27  1:50               ` Norbert Preining
  0 siblings, 2 replies; 25+ messages in thread
From: Norbert Preining @ 2012-01-26 23:25 UTC (permalink / raw)
  To: Emmanuel Grumbach
  Cc: linux-kernel, ipw3945-devel, Guy, Wey-Yi, Johannes Berg,
	linux-wireless, ilw, Dave Jones

Hi Emmanuel,

On Do, 26 Jan 2012, Emmanuel Grumbach wrote:
> are suffering from the same issue. I am merging the mail threads here.

First tests are promising, after reboot it was working immediately
without need to rfkill block/unblock. lso after suspend and resume.

Will test more the next days and report back.

dmesg output without debugging still the same, but connection 
continues without any problem:
[   62.437916] Open BA session requested for 00:0a:79:eb:56:10 tid 0
[   62.456184] activated addBA response timer on tid 0
[   63.456042] addBA response timer expired on tid 0
[   63.456063] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 0
[   67.008297] switched off addBA timer for tid 0
[   67.008305] got addBA resp for tid 0 but we already gave up
[   67.008340] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 0
[   67.015503] Open BA session requested for 00:0a:79:eb:56:10 tid 0
[   67.031648] activated addBA response timer on tid 0
[   67.129907] switched off addBA timer for tid 0
[   67.129914] Aggregation is on for tid 0
[   67.130076] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 0
[  100.288018] tx session timer expired on tid 0
[  100.288032] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 0
[  106.347302] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 0
[  106.374760] Open BA session requested for 00:0a:79:eb:56:10 tid 0
[  106.388178] activated addBA response timer on tid 0
[  106.390041] switched off addBA timer for tid 0
[  106.390044] Aggregation is on for tid 0
[  106.390193] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 0
[  135.786765] Open BA session requested for 00:0a:79:eb:56:10 tid 6
[  135.804164] activated addBA response timer on tid 6
[  135.806088] switched off addBA timer for tid 6
[  135.806092] Aggregation is on for tid 6
[  135.806241] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 6
[  146.912031] tx session timer expired on tid 6
[  146.912071] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 6
[  146.924187] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 6
[  256.560100] tx session timer expired on tid 0
[  256.560132] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 0
[  256.584379] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 0
[  258.477345] Open BA session requested for 00:0a:79:eb:56:10 tid 0
[  258.500189] activated addBA response timer on tid 0
[  258.502148] switched off addBA timer for tid 0
[  258.502151] Aggregation is on for tid 0
[  258.502340] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 0

Later on after resume I got a few hickups but the connection just
hang for a shor ttime, then came back:
[  589.895086] delba from 00:0a:79:eb:56:10 (initiator) tid 0 reason code 39
[  589.895095] Rx BA session stop requested for 00:0a:79:eb:56:10 tid 0 inititator reason: 0
[  589.900879] Rx A-MPDU request on tid 0 result 0
[  589.900950] unexpected AddBA Req from 00:0a:79:eb:56:10 on tid 0
[  589.900958] Rx BA session stop requested for 00:0a:79:eb:56:10 tid 0 recipient reason: 32
[  589.902649] Rx A-MPDU request on tid 0 result 0
[  589.902690] unexpected AddBA Req from 00:0a:79:eb:56:10 on tid 0
[  589.902698] Rx BA session stop requested for 00:0a:79:eb:56:10 tid 0 recipient reason: 32
[  589.903732] Rx A-MPDU request on tid 0 result 0
[  589.903810] unexpected AddBA Req from 00:0a:79:eb:56:10 on tid 0
[  589.903817] Rx BA session stop requested for 00:0a:79:eb:56:10 tid 0 recipient reason: 32
[  589.904965] Rx A-MPDU request on tid 0 result 0
[  589.905045] unexpected AddBA Req from 00:0a:79:eb:56:10 on tid 0
[  589.905053] Rx BA session stop requested for 00:0a:79:eb:56:10 tid 0 recipient reason: 32
[  589.906510] Rx A-MPDU request on tid 0 result 0
[  590.456062] ieee80211 phy0: release an RX reorder frame due to timeout on earlier frames
[  590.456075] ieee80211 phy0: release an RX reorder frame due to timeout on earlier frames
[  590.456083] ieee80211 phy0: release an RX reorder frame due to timeout on earlier frames
[  594.413810] delba from 00:0a:79:eb:56:10 (initiator) tid 0 reason code 39
[  594.413822] Rx BA session stop requested for 00:0a:79:eb:56:10 tid 0 inititator reason: 0
[  594.428073] Rx A-MPDU request on tid 0 result 0


Generally fine.

Thanks, more reports later.

Norbert
------------------------------------------------------------------------
Norbert Preining            preining@{jaist.ac.jp, logic.at, debian.org}
JAIST, Japan                                 TeX Live & Debian Developer
DSA: 0x09C5B094   fp: 14DF 2E6C 0307 BE6D AD76  A9C0 D2BF 4AA3 09C5 B094
------------------------------------------------------------------------
FAIRYMOUNT (vb.n.)
Polite word for buggery.
			--- Douglas Adams, The Meaning of Liff

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: iwlagn is getting even worse with 3.3-rc1
  2012-01-26 23:25             ` Norbert Preining
@ 2012-01-27  0:06               ` Emmanuel Grumbach
  2012-01-31  2:41                 ` Dave Jones
  2012-01-27  1:50               ` Norbert Preining
  1 sibling, 1 reply; 25+ messages in thread
From: Emmanuel Grumbach @ 2012-01-27  0:06 UTC (permalink / raw)
  To: Norbert Preining
  Cc: linux-kernel, ipw3945-devel, Guy, Wey-Yi, Johannes Berg,
	linux-wireless, ilw, Dave Jones

On Thu, Jan 26, 2012 at 15:25, Norbert Preining <preining@logic.at> wrote:
> Hi Emmanuel,
>
> On Do, 26 Jan 2012, Emmanuel Grumbach wrote:
>> are suffering from the same issue. I am merging the mail threads here.
>
> First tests are promising, after reboot it was working immediately
> without need to rfkill block/unblock. lso after suspend and resume.
>
> Will test more the next days and report back.
>
> dmesg output without debugging still the same, but connection
> continues without any problem:
> [   62.437916] Open BA session requested for 00:0a:79:eb:56:10 tid 0
> [   62.456184] activated addBA response timer on tid 0
> [   63.456042] addBA response timer expired on tid 0
> [   63.456063] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 0
> [   67.008297] switched off addBA timer for tid 0
> [   67.008305] got addBA resp for tid 0 but we already gave up
> [   67.008340] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 0
> [   67.015503] Open BA session requested for 00:0a:79:eb:56:10 tid 0
> [   67.031648] activated addBA response timer on tid 0
> [   67.129907] switched off addBA timer for tid 0
> [   67.129914] Aggregation is on for tid 0
> [   67.130076] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 0
> [  100.288018] tx session timer expired on tid 0
> [  100.288032] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 0
> [  106.347302] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 0
> [  106.374760] Open BA session requested for 00:0a:79:eb:56:10 tid 0
> [  106.388178] activated addBA response timer on tid 0
> [  106.390041] switched off addBA timer for tid 0
> [  106.390044] Aggregation is on for tid 0
> [  106.390193] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 0
> [  135.786765] Open BA session requested for 00:0a:79:eb:56:10 tid 6
> [  135.804164] activated addBA response timer on tid 6
> [  135.806088] switched off addBA timer for tid 6
> [  135.806092] Aggregation is on for tid 6
> [  135.806241] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 6
> [  146.912031] tx session timer expired on tid 6
> [  146.912071] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 6
> [  146.924187] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 6
> [  256.560100] tx session timer expired on tid 0
> [  256.560132] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 0
> [  256.584379] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 0
> [  258.477345] Open BA session requested for 00:0a:79:eb:56:10 tid 0
> [  258.500189] activated addBA response timer on tid 0
> [  258.502148] switched off addBA timer for tid 0
> [  258.502151] Aggregation is on for tid 0
> [  258.502340] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 0
>
> Later on after resume I got a few hickups but the connection just
> hang for a shor ttime, then came back:
> [  589.895086] delba from 00:0a:79:eb:56:10 (initiator) tid 0 reason code 39
> [  589.895095] Rx BA session stop requested for 00:0a:79:eb:56:10 tid 0 inititator reason: 0
> [  589.900879] Rx A-MPDU request on tid 0 result 0
> [  589.900950] unexpected AddBA Req from 00:0a:79:eb:56:10 on tid 0
> [  589.900958] Rx BA session stop requested for 00:0a:79:eb:56:10 tid 0 recipient reason: 32
> [  589.902649] Rx A-MPDU request on tid 0 result 0
> [  589.902690] unexpected AddBA Req from 00:0a:79:eb:56:10 on tid 0
> [  589.902698] Rx BA session stop requested for 00:0a:79:eb:56:10 tid 0 recipient reason: 32
> [  589.903732] Rx A-MPDU request on tid 0 result 0
> [  589.903810] unexpected AddBA Req from 00:0a:79:eb:56:10 on tid 0
> [  589.903817] Rx BA session stop requested for 00:0a:79:eb:56:10 tid 0 recipient reason: 32
> [  589.904965] Rx A-MPDU request on tid 0 result 0
> [  589.905045] unexpected AddBA Req from 00:0a:79:eb:56:10 on tid 0
> [  589.905053] Rx BA session stop requested for 00:0a:79:eb:56:10 tid 0 recipient reason: 32
> [  589.906510] Rx A-MPDU request on tid 0 result 0
> [  590.456062] ieee80211 phy0: release an RX reorder frame due to timeout on earlier frames
> [  590.456075] ieee80211 phy0: release an RX reorder frame due to timeout on earlier frames
> [  590.456083] ieee80211 phy0: release an RX reorder frame due to timeout on earlier frames
> [  594.413810] delba from 00:0a:79:eb:56:10 (initiator) tid 0 reason code 39
> [  594.413822] Rx BA session stop requested for 00:0a:79:eb:56:10 tid 0 inititator reason: 0
> [  594.428073] Rx A-MPDU request on tid 0 result 0
>
>
> Generally fine.
>
> Thanks, more reports later.
>

Dave ?

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: iwlagn is getting even worse with 3.3-rc1
  2012-01-26 23:25             ` Norbert Preining
  2012-01-27  0:06               ` Emmanuel Grumbach
@ 2012-01-27  1:50               ` Norbert Preining
  2012-01-27  3:11                 ` Emmanuel Grumbach
  1 sibling, 1 reply; 25+ messages in thread
From: Norbert Preining @ 2012-01-27  1:50 UTC (permalink / raw)
  To: Emmanuel Grumbach
  Cc: linux-kernel, ipw3945-devel, Guy, Wey-Yi, Johannes Berg,
	linux-wireless, ilw, Dave Jones

Hi Emmanuel,

On Fr, 27 Jan 2012, Norbert Preining wrote:
> First tests are promising, after reboot it was working immediately
> without need to rfkill block/unblock. lso after suspend and resume.
> 
> Will test more the next days and report back.

Unfortunately, at the university it is still a complete no-go.
Usually the connection works for a short time, then breaks down.
After that even unloading and loading the module did not reactivate
it, I cannot get a connection at all. But other units, or with
older kernel (it was 2.6.3X AFAIR) it was working without a glitch.

I uploaded a syslog output including kernel and network manager logs
to
	http://www.logic.at/people/preining/syslog.log
(new one). This shows a session from loading the module up to giving up.

Best wishes

Norbert
------------------------------------------------------------------------
Norbert Preining            preining@{jaist.ac.jp, logic.at, debian.org}
JAIST, Japan                                 TeX Live & Debian Developer
DSA: 0x09C5B094   fp: 14DF 2E6C 0307 BE6D AD76  A9C0 D2BF 4AA3 09C5 B094
------------------------------------------------------------------------
AITH (n.)
The single bristle that sticks out sideways on a cheap paintbrush.
			--- Douglas Adams, The Meaning of Liff

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: iwlagn is getting even worse with 3.3-rc1
  2012-01-27  1:50               ` Norbert Preining
@ 2012-01-27  3:11                 ` Emmanuel Grumbach
  2012-02-22  0:37                   ` Norbert Preining
  0 siblings, 1 reply; 25+ messages in thread
From: Emmanuel Grumbach @ 2012-01-27  3:11 UTC (permalink / raw)
  To: Norbert Preining
  Cc: linux-kernel, ipw3945-devel, Guy, Wey-Yi, Johannes Berg,
	linux-wireless, ilw, Dave Jones

> Hi Emmanuel,
>
> On Fr, 27 Jan 2012, Norbert Preining wrote:
>> First tests are promising, after reboot it was working immediately
>> without need to rfkill block/unblock. lso after suspend and resume.
>>
>> Will test more the next days and report back.
>
> Unfortunately, at the university it is still a complete no-go.
> Usually the connection works for a short time, then breaks down.
> After that even unloading and loading the module did not reactivate
> it, I cannot get a connection at all. But other units, or with
> older kernel (it was 2.6.3X AFAIR) it was working without a glitch.
>
> I uploaded a syslog output including kernel and network manager logs
> to
>        http://www.logic.at/people/preining/syslog.log
> (new one). This shows a session from loading the module up to giving up.
>

I glanced at the logs, and they look healthy from the wifi driver
side. You just don't get any reply to DHCP_DISCOVER apparently... can
you get a sniffer ?
I am pretty sure that the packet in sent in the air, but if you can
get a capture of that we could check that out.

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: iwlagn is getting even worse with 3.3-rc1
  2012-01-27  0:06               ` Emmanuel Grumbach
@ 2012-01-31  2:41                 ` Dave Jones
  2012-02-01 15:43                   ` Dave Jones
  0 siblings, 1 reply; 25+ messages in thread
From: Dave Jones @ 2012-01-31  2:41 UTC (permalink / raw)
  To: Emmanuel Grumbach
  Cc: Norbert Preining, linux-kernel, ipw3945-devel, Guy, Wey-Yi,
	Johannes Berg, linux-wireless, ilw

On Thu, Jan 26, 2012 at 04:06:36PM -0800, Emmanuel Grumbach wrote:
 > On Thu, Jan 26, 2012 at 15:25, Norbert Preining <preining@logic.at> wrote:
 > > Hi Emmanuel,
 > >
 > > On Do, 26 Jan 2012, Emmanuel Grumbach wrote:
 > >> are suffering from the same issue. I am merging the mail threads here.
 > >
 > > First tests are promising, after reboot it was working immediately
 > > without need to rfkill block/unblock. lso after suspend and resume.
 > >
 > > Will test more the next days and report back.
 > >
 > > dmesg output without debugging still the same, but connection
 > > continues without any problem:
 > > [   62.437916] Open BA session requested for 00:0a:79:eb:56:10 tid 0
 > > [   62.456184] activated addBA response timer on tid 0
 > > [   63.456042] addBA response timer expired on tid 0
 > > [   63.456063] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 0
 > > [   67.008297] switched off addBA timer for tid 0
 > > [   67.008305] got addBA resp for tid 0 but we already gave up
 > > [   67.008340] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 0
 > > [   67.015503] Open BA session requested for 00:0a:79:eb:56:10 tid 0
 > > [   67.031648] activated addBA response timer on tid 0
 > > [   67.129907] switched off addBA timer for tid 0
 > > [   67.129914] Aggregation is on for tid 0
 > > [   67.130076] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 0
 > > [  100.288018] tx session timer expired on tid 0
 > > [  100.288032] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 0
 > > [  106.347302] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 0
 > > [  106.374760] Open BA session requested for 00:0a:79:eb:56:10 tid 0
 > > [  106.388178] activated addBA response timer on tid 0
 > > [  106.390041] switched off addBA timer for tid 0
 > > [  106.390044] Aggregation is on for tid 0
 > > [  106.390193] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 0
 > > [  135.786765] Open BA session requested for 00:0a:79:eb:56:10 tid 6
 > > [  135.804164] activated addBA response timer on tid 6
 > > [  135.806088] switched off addBA timer for tid 6
 > > [  135.806092] Aggregation is on for tid 6
 > > [  135.806241] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 6
 > > [  146.912031] tx session timer expired on tid 6
 > > [  146.912071] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 6
 > > [  146.924187] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 6
 > > [  256.560100] tx session timer expired on tid 0
 > > [  256.560132] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 0
 > > [  256.584379] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 0
 > > [  258.477345] Open BA session requested for 00:0a:79:eb:56:10 tid 0
 > > [  258.500189] activated addBA response timer on tid 0
 > > [  258.502148] switched off addBA timer for tid 0
 > > [  258.502151] Aggregation is on for tid 0
 > > [  258.502340] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 0
 > >
 > > Later on after resume I got a few hickups but the connection just
 > > hang for a shor ttime, then came back:
 > > [  589.895086] delba from 00:0a:79:eb:56:10 (initiator) tid 0 reason code 39
 > > [  589.895095] Rx BA session stop requested for 00:0a:79:eb:56:10 tid 0 inititator reason: 0
 > > [  589.900879] Rx A-MPDU request on tid 0 result 0
 > > [  589.900950] unexpected AddBA Req from 00:0a:79:eb:56:10 on tid 0
 > > [  589.900958] Rx BA session stop requested for 00:0a:79:eb:56:10 tid 0 recipient reason: 32
 > > [  589.902649] Rx A-MPDU request on tid 0 result 0
 > > [  589.902690] unexpected AddBA Req from 00:0a:79:eb:56:10 on tid 0
 > > [  589.902698] Rx BA session stop requested for 00:0a:79:eb:56:10 tid 0 recipient reason: 32
 > > [  589.903732] Rx A-MPDU request on tid 0 result 0
 > > [  589.903810] unexpected AddBA Req from 00:0a:79:eb:56:10 on tid 0
 > > [  589.903817] Rx BA session stop requested for 00:0a:79:eb:56:10 tid 0 recipient reason: 32
 > > [  589.904965] Rx A-MPDU request on tid 0 result 0
 > > [  589.905045] unexpected AddBA Req from 00:0a:79:eb:56:10 on tid 0
 > > [  589.905053] Rx BA session stop requested for 00:0a:79:eb:56:10 tid 0 recipient reason: 32
 > > [  589.906510] Rx A-MPDU request on tid 0 result 0
 > > [  590.456062] ieee80211 phy0: release an RX reorder frame due to timeout on earlier frames
 > > [  590.456075] ieee80211 phy0: release an RX reorder frame due to timeout on earlier frames
 > > [  590.456083] ieee80211 phy0: release an RX reorder frame due to timeout on earlier frames
 > > [  594.413810] delba from 00:0a:79:eb:56:10 (initiator) tid 0 reason code 39
 > > [  594.413822] Rx BA session stop requested for 00:0a:79:eb:56:10 tid 0 inititator reason: 0
 > > [  594.428073] Rx A-MPDU request on tid 0 result 0
 > >
 > >
 > > Generally fine.
 > >
 > > Thanks, more reports later.
 > >
 > 
 > Dave ?

after running with it all evening, it seems to be working fine so far.

(Sorry for delay, been on vacation for a week)

	Dave


^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: iwlagn is getting even worse with 3.3-rc1
  2012-02-01 15:43                   ` Dave Jones
@ 2012-02-01 14:45                     ` Guy, Wey-Yi
  0 siblings, 0 replies; 25+ messages in thread
From: Guy, Wey-Yi @ 2012-02-01 14:45 UTC (permalink / raw)
  To: Dave Jones
  Cc: Emmanuel Grumbach, Norbert Preining, linux-kernel, ipw3945-devel,
	Johannes Berg, linux-wireless, ilw

On Wed, 2012-02-01 at 10:43 -0500, Dave Jones wrote:
> On Mon, Jan 30, 2012 at 09:41:43PM -0500, Dave Jones wrote:
>  
>  >  > > Generally fine.
>  >  > >
>  >  > > Thanks, more reports later.
>  >  > 
>  >  > Dave ?
>  > 
>  > after running with it all evening, it seems to be working fine so far.
> 
> Two days later, it hasn't locked up at all, so this is definitly fixing my problem.
> 
> One thing though, dmesg is flooded with these..
> 
> [ 4384.849732] iwlwifi 0000:04:00.0: Tx aggregation enabled on ra = b8:c7:5d:0c:39:87 tid = 0
> [ 4434.332275] iwlwifi 0000:04:00.0: Tx aggregation enabled on ra = b8:c7:5d:0c:39:87 tid = 0
> [ 4475.309883] iwlwifi 0000:04:00.0: Tx aggregation enabled on ra = b8:c7:5d:0c:39:87 tid = 0
> 
> Can it be supressed if the ra hasn't changed ?

John has a patch to fix this :-)

Wey
> 



^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: iwlagn is getting even worse with 3.3-rc1
  2012-01-31  2:41                 ` Dave Jones
@ 2012-02-01 15:43                   ` Dave Jones
  2012-02-01 14:45                     ` Guy, Wey-Yi
  0 siblings, 1 reply; 25+ messages in thread
From: Dave Jones @ 2012-02-01 15:43 UTC (permalink / raw)
  To: Emmanuel Grumbach, Norbert Preining, linux-kernel, ipw3945-devel,
	Guy, Wey-Yi, Johannes Berg, linux-wireless, ilw

On Mon, Jan 30, 2012 at 09:41:43PM -0500, Dave Jones wrote:
 
 >  > > Generally fine.
 >  > >
 >  > > Thanks, more reports later.
 >  > 
 >  > Dave ?
 > 
 > after running with it all evening, it seems to be working fine so far.

Two days later, it hasn't locked up at all, so this is definitly fixing my problem.

One thing though, dmesg is flooded with these..

[ 4384.849732] iwlwifi 0000:04:00.0: Tx aggregation enabled on ra = b8:c7:5d:0c:39:87 tid = 0
[ 4434.332275] iwlwifi 0000:04:00.0: Tx aggregation enabled on ra = b8:c7:5d:0c:39:87 tid = 0
[ 4475.309883] iwlwifi 0000:04:00.0: Tx aggregation enabled on ra = b8:c7:5d:0c:39:87 tid = 0

Can it be supressed if the ra hasn't changed ?

	Dave


^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: iwlagn is getting even worse with 3.3-rc1
  2012-01-27  3:11                 ` Emmanuel Grumbach
@ 2012-02-22  0:37                   ` Norbert Preining
  2012-02-22  6:58                     ` Emmanuel Grumbach
  2012-02-22  8:40                     ` Pekka Enberg
  0 siblings, 2 replies; 25+ messages in thread
From: Norbert Preining @ 2012-02-22  0:37 UTC (permalink / raw)
  To: Emmanuel Grumbach
  Cc: linux-kernel, ipw3945-devel, Guy, Wey-Yi, Johannes Berg,
	linux-wireless, ilw, Dave Jones

Hi Emmanuel,

sorry to come back soo late to that matter ... I was *really* busy
with real work.

On Do, 26 Jan 2012, Emmanuel Grumbach wrote:
> >
> > On Fr, 27 Jan 2012, Norbert Preining wrote:
> >> First tests are promising, after reboot it was working immediately
> >> without need to rfkill block/unblock. lso after suspend and resume.
> >>
> >> Will test more the next days and report back.
> >
> > Unfortunately, at the university it is still a complete no-go.
> > Usually the connection works for a short time, then breaks down.
> > After that even unloading and loading the module did not reactivate
> > it, I cannot get a connection at all. But other units, or with
> > older kernel (it was 2.6.3X AFAIR) it was working without a glitch.
> >
> > I uploaded a syslog output including kernel and network manager logs
> > to
> >        http://www.logic.at/people/preining/syslog.log
> > (new one). This shows a session from loading the module up to giving up.
> >
> 
> I glanced at the logs, and they look healthy from the wifi driver
> side. You just don't get any reply to DHCP_DISCOVER apparently... can
> you get a sniffer ?
> I am pretty sure that the packet in sent in the air, but if you can
> get a capture of that we could check that out.

I still see that, on 3.3-rc4, and it is the same as usual. The interface
believes it is up and connected, but nothing works.

I am *100%* sure that this is related to the driver, because in old
revisions (somewhen around 2.6.27 or so) it was working without
any problem, and when it started I reported it long time ago.

Anyway, today it was really hopeless again, and the exact time it always
hangs is when the kernel driver spits out:
	Rx A-MPDU request on tid 0 result 0
and with debugging on I get in addition:
	ieee80211 phy3: release an RX reorder frame due to timeout on earlier frames
that is where it all goes down the gully, without any reaction from the
outside world suddenly. Before ping was running, then off.

I uploaded a new syslog.log in the above location that shows 5 min
or so of trial and error.

I don't know what else to provide then that, but it is definitely 
a real problem, I cannot work without cable anymore at the university,
which is a serious rpbolem.

Best wishes

Norbert
------------------------------------------------------------------------
Norbert Preining            preining@{jaist.ac.jp, logic.at, debian.org}
JAIST, Japan                                 TeX Live & Debian Developer
DSA: 0x09C5B094   fp: 14DF 2E6C 0307 BE6D AD76  A9C0 D2BF 4AA3 09C5 B094
------------------------------------------------------------------------
HAUGHAM (n.)
One who loudly informs other diners in a restaurant what kind of man
he is by calling for the chef by his christian name from the lobby.
			--- Douglas Adams, The Meaning of Liff

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: iwlagn is getting even worse with 3.3-rc1
  2012-02-22  0:37                   ` Norbert Preining
@ 2012-02-22  6:58                     ` Emmanuel Grumbach
  2012-02-22  8:40                     ` Pekka Enberg
  1 sibling, 0 replies; 25+ messages in thread
From: Emmanuel Grumbach @ 2012-02-22  6:58 UTC (permalink / raw)
  To: Norbert Preining
  Cc: linux-kernel, ipw3945-devel, Guy, Wey-Yi, Johannes Berg,
	linux-wireless, ilw, Dave Jones

On Wed, Feb 22, 2012 at 02:37, Norbert Preining <preining@logic.at> wrote:
>
> Hi Emmanuel,
>
> sorry to come back soo late to that matter ... I was *really* busy
> with real work.
>
> On Do, 26 Jan 2012, Emmanuel Grumbach wrote:
> > >
> > > On Fr, 27 Jan 2012, Norbert Preining wrote:
> > >> First tests are promising, after reboot it was working immediately
> > >> without need to rfkill block/unblock. lso after suspend and resume.
> > >>
> > >> Will test more the next days and report back.
> > >
> > > Unfortunately, at the university it is still a complete no-go.
> > > Usually the connection works for a short time, then breaks down.
> > > After that even unloading and loading the module did not reactivate
> > > it, I cannot get a connection at all. But other units, or with
> > > older kernel (it was 2.6.3X AFAIR) it was working without a glitch.
> > >
> > > I uploaded a syslog output including kernel and network manager logs
> > > to
> > >        http://www.logic.at/people/preining/syslog.log
> > > (new one). This shows a session from loading the module up to giving
> > > up.
> > >
> >
> > I glanced at the logs, and they look healthy from the wifi driver
> > side. You just don't get any reply to DHCP_DISCOVER apparently... can
> > you get a sniffer ?
> > I am pretty sure that the packet in sent in the air, but if you can
> > get a capture of that we could check that out.
>
> I still see that, on 3.3-rc4, and it is the same as usual. The interface
> believes it is up and connected, but nothing works.
>
> I am *100%* sure that this is related to the driver, because in old
> revisions (somewhen around 2.6.27 or so) it was working without
> any problem, and when it started I reported it long time ago.
>
> Anyway, today it was really hopeless again, and the exact time it always
> hangs is when the kernel driver spits out:
>        Rx A-MPDU request on tid 0 result 0
> and with debugging on I get in addition:
>        ieee80211 phy3: release an RX reorder frame due to timeout on
> earlier frames
> that is where it all goes down the gully, without any reaction from the
> outside world suddenly. Before ping was running, then off.
>
> I uploaded a new syslog.log in the above location that shows 5 min
> or so of trial and error.

>From the log, I can see that we have a lot of "passive channel
failures". Can you try to disable 11n (module_parameter) ?
Please also try with debug=0xc0000000

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: iwlagn is getting even worse with 3.3-rc1
  2012-01-24  1:36 iwlagn is getting even worse with 3.3-rc1 Norbert Preining
  2012-01-24  4:47 ` Emmanuel Grumbach
@ 2012-02-22  8:37 ` Pekka Enberg
  2012-02-27 10:00 ` Matthew Turnbull
  2 siblings, 0 replies; 25+ messages in thread
From: Pekka Enberg @ 2012-02-22  8:37 UTC (permalink / raw)
  To: Norbert Preining
  Cc: linux-kernel, ipw3945-devel, Guy, Wey-Yi, Johannes Berg,
	Emmanuel Grumbach, linux-wireless, ilw

On Tue, Jan 24, 2012 at 3:36 AM, Norbert Preining <preining@logic.at> wrote:
> long time ago we had a long discussion about iwlagn regressions in 3.1.0
> Up to 3.2 I still have regular problems on the university network
> with stuck iwl driver not even realizing that nothing goes out or in.
>
> Today I switched to 3.3-rc1 to see it is getting even worse, now on my
> home network I get stuck queue and no connection:

I'm seeing the same thing with my home network as well with 3.3-rc3.
Is there a fix in the pipeline for 3.3 final or do you want me to
bisect which commits to revert?

                                Pekka

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: iwlagn is getting even worse with 3.3-rc1
  2012-02-22  0:37                   ` Norbert Preining
  2012-02-22  6:58                     ` Emmanuel Grumbach
@ 2012-02-22  8:40                     ` Pekka Enberg
  2012-02-22  8:54                       ` Emmanuel Grumbach
  1 sibling, 1 reply; 25+ messages in thread
From: Pekka Enberg @ 2012-02-22  8:40 UTC (permalink / raw)
  To: Norbert Preining
  Cc: Emmanuel Grumbach, linux-kernel, ipw3945-devel, Guy, Wey-Yi,
	Johannes Berg, linux-wireless, ilw, Dave Jones

On Wed, Feb 22, 2012 at 2:37 AM, Norbert Preining <preining@logic.at> wrote:
> I still see that, on 3.3-rc4, and it is the same as usual. The interface
> believes it is up and connected, but nothing works.
>
> I am *100%* sure that this is related to the driver, because in old
> revisions (somewhen around 2.6.27 or so) it was working without
> any problem, and when it started I reported it long time ago.

It's definitely a kernel regression, no question about it. Was 3.3-rc1
already broken for you? It shouldn't be that difficult to find the
offending commit with git bisect if it's that easy to reproduce for
you.

                        Pekka

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: iwlagn is getting even worse with 3.3-rc1
  2012-02-22  8:40                     ` Pekka Enberg
@ 2012-02-22  8:54                       ` Emmanuel Grumbach
  2012-02-23  7:06                         ` Pekka Enberg
  0 siblings, 1 reply; 25+ messages in thread
From: Emmanuel Grumbach @ 2012-02-22  8:54 UTC (permalink / raw)
  To: Pekka Enberg
  Cc: Norbert Preining, linux-kernel, ipw3945-devel, Guy, Wey-Yi,
	Johannes Berg, linux-wireless, ilw, Dave Jones

Please check this one:
http://git.kernel.org/?p=linux/kernel/git/torvalds/linux.git;a=commit;h=3d29dd9b5b160ba4542a9b8f869a220559e633a0

it is in 3.3-rc4


On Wed, Feb 22, 2012 at 10:40, Pekka Enberg <penberg@kernel.org> wrote:
> On Wed, Feb 22, 2012 at 2:37 AM, Norbert Preining <preining@logic.at> wrote:
>> I still see that, on 3.3-rc4, and it is the same as usual. The interface
>> believes it is up and connected, but nothing works.
>>
>> I am *100%* sure that this is related to the driver, because in old
>> revisions (somewhen around 2.6.27 or so) it was working without
>> any problem, and when it started I reported it long time ago.
>
> It's definitely a kernel regression, no question about it. Was 3.3-rc1
> already broken for you? It shouldn't be that difficult to find the
> offending commit with git bisect if it's that easy to reproduce for
> you.
>
>                        Pekka

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: iwlagn is getting even worse with 3.3-rc1
  2012-02-22  8:54                       ` Emmanuel Grumbach
@ 2012-02-23  7:06                         ` Pekka Enberg
  2012-02-27  8:36                           ` Norbert Preining
  0 siblings, 1 reply; 25+ messages in thread
From: Pekka Enberg @ 2012-02-23  7:06 UTC (permalink / raw)
  To: Emmanuel Grumbach
  Cc: Norbert Preining, linux-kernel, ipw3945-devel, Guy, Wey-Yi,
	Johannes Berg, linux-wireless, ilw, Dave Jones

Hi Emmanuel,

On Wed, Feb 22, 2012 at 10:54 AM, Emmanuel Grumbach <egrumbach@gmail.com> wrote:
> Please check this one:
> http://git.kernel.org/?p=linux/kernel/git/torvalds/linux.git;a=commit;h=3d29dd9b5b160ba4542a9b8f869a220559e633a0
>
> it is in 3.3-rc4

I used 3.3-rc4 yesterday and didn't notice the problem with my home
network. Is the patch supposed to fix Norbert's issue as well?

                        Pekka

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: iwlagn is getting even worse with 3.3-rc1
  2012-02-23  7:06                         ` Pekka Enberg
@ 2012-02-27  8:36                           ` Norbert Preining
  2012-02-27 18:01                             ` Emmanuel Grumbach
  0 siblings, 1 reply; 25+ messages in thread
From: Norbert Preining @ 2012-02-27  8:36 UTC (permalink / raw)
  To: Emmanuel Grumbach, Pekka Enberg
  Cc: linux-kernel, ipw3945-devel, Guy, Wey-Yi, Johannes Berg,
	linux-wireless, ilw, Dave Jones

[-- Attachment #1: Type: text/plain, Size: 1596 bytes --]

Hi Emmanuel,

sorry for the silence, I wasn't at the university for a few days so
I couldn't test.

Now I did:
kernel 3.3-rc5

On Mi, 22 Feb 2012, Emmanuel Grumbach wrote:
> From the log, I can see that we have a lot of "passive channel
> failures". Can you try to disable 11n (module_parameter) ?
> Please also try with debug=0xc0000000

Disabling 11n and adding this parameter created loads of output, but
still makes the connection break down and reconnection does not work
anymore. I attach a (small) part of the syslog file. I had 
loads *LOADS* (200000+) of messages
	Feb 27 12:58:04 mithrandir kernel: [ 1447.835281] iwlwifi 0000:06:00.0: I iwlagn_rx_reply_tx Next reclaimed packet:3333
	Feb 27 12:58:04 mithrandir kernel: [ 1447.835294] iwlwifi 0000:06:00.0: I iwl_trans_pcie_reclaim [Q 2 | AC 2] 213 -> 214 (470)
in the log. Then there is something about "TX on passive channel"
and from then on everything goes off.

> network. Is the patch supposed to fix Norbert's issue as well?

Apparently not.

Best wishes

Norbert
------------------------------------------------------------------------
Norbert Preining            preining@{jaist.ac.jp, logic.at, debian.org}
JAIST, Japan                                 TeX Live & Debian Developer
DSA: 0x09C5B094   fp: 14DF 2E6C 0307 BE6D AD76  A9C0 D2BF 4AA3 09C5 B094
------------------------------------------------------------------------
FRADDAM (n.)
The small awkward-shaped piece of cheese which remains after grating a
large regular-shaped piece of cheese and enables you to cut your
fingers.
			--- Douglas Adams, The Meaning of Liff

[-- Attachment #2: syslog --]
[-- Type: text/plain, Size: 22903 bytes --]

Feb 27 12:58:04 mithrandir kernel: [ 1447.835281] iwlwifi 0000:06:00.0: I iwlagn_rx_reply_tx Next reclaimed packet:3333
Feb 27 12:58:04 mithrandir kernel: [ 1447.835294] iwlwifi 0000:06:00.0: I iwl_trans_pcie_reclaim [Q 2 | AC 2] 213 -> 214 (470)
Feb 27 12:58:05 mithrandir kernel: [ 1449.314491] iwlwifi 0000:06:00.0: I iwlagn_rx_reply_tx Next reclaimed packet:3334
Feb 27 12:58:05 mithrandir kernel: [ 1449.314506] iwlwifi 0000:06:00.0: I iwl_trans_pcie_reclaim [Q 2 | AC 2] 214 -> 215 (471)
Feb 27 12:58:06 mithrandir wpa_supplicant[2113]: Trying to authenticate with 00:24:c4:ab:bd:e0 (SSID='JAISTALL' freq=2412 MHz)
Feb 27 12:58:06 mithrandir kernel: [ 1449.501156] iwlwifi 0000:06:00.0: I iwl_trans_pcie_reclaim [Q 0 | AC 0] 145 -> 146 (146)
Feb 27 12:58:06 mithrandir kernel: [ 1449.508991] iwlwifi 0000:06:00.0: I iwl_trans_pcie_reclaim [Q 0 | AC 0] 146 -> 147 (147)
Feb 27 12:58:06 mithrandir kernel: [ 1449.510261] wlan0: authenticate with 00:24:c4:ab:bd:e0 (try 1)
Feb 27 12:58:06 mithrandir NetworkManager[2062]: <info> (wlan0): supplicant interface state: completed -> authenticating
Feb 27 12:58:06 mithrandir kernel: [ 1449.513053] iwlwifi 0000:06:00.0: I iwl_trans_pcie_reclaim [Q 0 | AC 0] 147 -> 148 (148)
Feb 27 12:58:06 mithrandir kernel: [ 1449.513071] wlan0: authenticated
Feb 27 12:58:06 mithrandir wpa_supplicant[2113]: Trying to associate with 00:24:c4:ab:bd:e0 (SSID='JAISTALL' freq=2412 MHz)
Feb 27 12:58:06 mithrandir kernel: [ 1449.517823] iwlwifi 0000:06:00.0: I iwl_trans_pcie_reclaim [Q 0 | AC 0] 148 -> 149 (149)
Feb 27 12:58:06 mithrandir kernel: [ 1449.517828] iwlwifi 0000:06:00.0: I iwl_stop_queue Stop hwq 0 ac 0 stop count 1. Tx on passive channel
Feb 27 12:58:06 mithrandir kernel: [ 1449.517833] iwlwifi 0000:06:00.0: I iwlagn_rx_reply_tx TXQ 0 status PASSIVE_NO_RX (0x00000090) rate_n_flags 0x8003 retries 0
Feb 27 12:58:06 mithrandir kernel: [ 1449.517836] iwlwifi 0000:06:00.0: I iwlagn_rx_reply_tx FrameCnt = 1, idx=148
Feb 27 12:58:06 mithrandir kernel: [ 1449.522519] iwlwifi 0000:06:00.0: U iwl_trans_pcie_wake_any_queue Queue Status: Q[0] stopped
Feb 27 12:58:06 mithrandir kernel: [ 1449.522533] iwlwifi 0000:06:00.0: U iwl_wake_queue Wake hwq 0 ac 0. Disassoc: flush queue
Feb 27 12:58:06 mithrandir kernel: [ 1449.522536] iwlwifi 0000:06:00.0: U iwl_trans_pcie_wake_any_queue Queue Status: Q[1] awake
Feb 27 12:58:06 mithrandir kernel: [ 1449.522539] iwlwifi 0000:06:00.0: U iwl_trans_pcie_wake_any_queue Queue Status: Q[2] awake
Feb 27 12:58:06 mithrandir kernel: [ 1449.522542] iwlwifi 0000:06:00.0: U iwl_trans_pcie_wake_any_queue Queue Status: Q[3] awake
Feb 27 12:58:06 mithrandir kernel: [ 1449.522792] iwlwifi 0000:06:00.0: I iwl_trans_pcie_reclaim [Q 0 | AC 0] 149 -> 150 (150)
Feb 27 12:58:06 mithrandir kernel: [ 1449.522796] iwlwifi 0000:06:00.0: I iwl_stop_queue Stop hwq 0 ac 0 stop count 1. Tx on passive channel
Feb 27 12:58:06 mithrandir kernel: [ 1449.522799] iwlwifi 0000:06:00.0: I iwlagn_rx_reply_tx TXQ 0 status PASSIVE_NO_RX (0x00000090) rate_n_flags 0x8003 retries 0
Feb 27 12:58:06 mithrandir kernel: [ 1449.522803] iwlwifi 0000:06:00.0: I iwlagn_rx_reply_tx FrameCnt = 1, idx=149
Feb 27 12:58:06 mithrandir kernel: [ 1449.523260] wlan0: moving STA 00:24:c4:ab:bd:ef to state 2
Feb 27 12:58:06 mithrandir kernel: [ 1449.523262] wlan0: moving STA 00:24:c4:ab:bd:ef to state 1
Feb 27 12:58:06 mithrandir kernel: [ 1449.523264] wlan0: moving STA 00:24:c4:ab:bd:ef to state 0
Feb 27 12:58:06 mithrandir kernel: [ 1449.541708] wlan0: associate with 00:24:c4:ab:bd:e0 (try 1)
Feb 27 12:58:06 mithrandir NetworkManager[2062]: <info> (wlan0): supplicant interface state: authenticating -> associating
Feb 27 12:58:06 mithrandir kernel: [ 1449.740142] wlan0: associate with 00:24:c4:ab:bd:e0 (try 2)
Feb 27 12:58:06 mithrandir kernel: [ 1449.940086] wlan0: associate with 00:24:c4:ab:bd:e0 (try 3)
Feb 27 12:58:06 mithrandir kernel: [ 1450.140107] wlan0: association with 00:24:c4:ab:bd:e0 timed out
Feb 27 12:58:06 mithrandir NetworkManager[2062]: <info> (wlan0): supplicant interface state: associating -> disconnected
Feb 27 12:58:10 mithrandir NetworkManager[2062]: <info> (wlan0): roamed from BSSID 00:24:C4:AB:BD:EF (JAISTALL) to (none) ((none))
Feb 27 12:58:11 mithrandir NetworkManager[2062]: <info> (wlan0): supplicant interface state: disconnected -> scanning
Feb 27 12:58:14 mithrandir wpa_supplicant[2113]: Trying to authenticate with 00:24:c4:ab:bd:ef (SSID='JAISTALL' freq=5200 MHz)
Feb 27 12:58:14 mithrandir NetworkManager[2062]: <info> (wlan0): supplicant interface state: scanning -> authenticating
Feb 27 12:58:14 mithrandir kernel: [ 1457.529919] wlan0: authenticate with 00:24:c4:ab:bd:ef (try 1)
Feb 27 12:58:14 mithrandir kernel: [ 1457.728113] wlan0: authenticate with 00:24:c4:ab:bd:ef (try 2)
Feb 27 12:58:14 mithrandir kernel: [ 1457.928111] wlan0: authenticate with 00:24:c4:ab:bd:ef (try 3)
Feb 27 12:58:14 mithrandir kernel: [ 1458.128084] wlan0: authentication with 00:24:c4:ab:bd:ef timed out
Feb 27 12:58:21 mithrandir NetworkManager[2062]: <warn> (wlan0): link timed out.
Feb 27 12:58:21 mithrandir NetworkManager[2062]: <info> (wlan0): device state change: activated -> disconnected (reason 'supplicant-timeout') [100 30 11]
Feb 27 12:58:21 mithrandir NetworkManager[2062]: <info> (wlan0): deactivating device (reason 'supplicant-timeout') [11]
Feb 27 12:58:21 mithrandir NetworkManager[2062]: <info> (wlan0): canceled DHCP transaction, DHCP client pid 2580
Feb 27 12:58:21 mithrandir dbus[2053]: [system] Activating service name='org.freedesktop.nm_dispatcher' (using servicehelper)
Feb 27 12:58:21 mithrandir NetworkManager[2062]: <info> (wlan0): supplicant interface state: authenticating -> disconnected
Feb 27 12:58:21 mithrandir NetworkManager[2062]: <info> Auto-activating connection 'Auto JAISTALL'.
Feb 27 12:58:21 mithrandir NetworkManager[2062]: <info> Activation (wlan0) starting connection 'Auto JAISTALL'
Feb 27 12:58:21 mithrandir NetworkManager[2062]: <info> (wlan0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Feb 27 12:58:21 mithrandir NetworkManager[2062]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
Feb 27 12:58:21 mithrandir NetworkManager[2062]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
Feb 27 12:58:21 mithrandir NetworkManager[2062]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
Feb 27 12:58:21 mithrandir NetworkManager[2062]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
Feb 27 12:58:21 mithrandir NetworkManager[2062]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
Feb 27 12:58:21 mithrandir NetworkManager[2062]: <info> (wlan0): device state change: prepare -> config (reason 'none') [40 50 0]
Feb 27 12:58:21 mithrandir NetworkManager[2062]: <info> Activation (wlan0/wireless): connection 'Auto JAISTALL' requires no security.  No secrets needed.
Feb 27 12:58:21 mithrandir NetworkManager[2062]: <info> Config: added 'ssid' value 'JAISTALL'
Feb 27 12:58:21 mithrandir NetworkManager[2062]: <info> Config: added 'scan_ssid' value '1'
Feb 27 12:58:21 mithrandir NetworkManager[2062]: <info> Config: added 'key_mgmt' value 'NONE'
Feb 27 12:58:21 mithrandir NetworkManager[2062]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
Feb 27 12:58:21 mithrandir NetworkManager[2062]: <info> Config: set interface ap_scan to 1
Feb 27 12:58:21 mithrandir wpa_supplicant[2113]: Failed to initiate AP scan.
Feb 27 12:58:21 mithrandir dbus[2053]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Feb 27 12:58:21 mithrandir wpa_supplicant[2113]: Trying to authenticate with 00:24:c4:ab:bd:ef (SSID='JAISTALL' freq=5200 MHz)
Feb 27 12:58:21 mithrandir kernel: [ 1465.492154] wlan0: authenticate with 00:24:c4:ab:bd:ef (try 1)
Feb 27 12:58:21 mithrandir NetworkManager[2062]: <info> (wlan0): supplicant interface state: disconnected -> authenticating
Feb 27 12:58:22 mithrandir kernel: [ 1465.692131] wlan0: authenticate with 00:24:c4:ab:bd:ef (try 2)
Feb 27 12:58:22 mithrandir kernel: [ 1465.892106] wlan0: authenticate with 00:24:c4:ab:bd:ef (try 3)
Feb 27 12:58:22 mithrandir kernel: [ 1466.092096] wlan0: authentication with 00:24:c4:ab:bd:ef timed out
Feb 27 12:58:23 mithrandir ntpd[3410]: Deleting interface #2 wlan0, 150.65.206.149#123, interface stats: received=95, sent=97, dropped=0, active_time=1394 secs
Feb 27 12:58:23 mithrandir ntpd[3410]: 59.106.180.168 interface 150.65.206.149 -> (none)
Feb 27 12:58:23 mithrandir ntpd[3410]: 133.27.94.149 interface 150.65.206.149 -> (none)
Feb 27 12:58:23 mithrandir ntpd[3410]: 64.73.32.134 interface 150.65.206.149 -> (none)
Feb 27 12:58:23 mithrandir ntpd[3410]: 130.54.208.201 interface 150.65.206.149 -> (none)
Feb 27 12:58:23 mithrandir ntpd[3410]: peers refreshed
Feb 27 12:58:29 mithrandir wpa_supplicant[2113]: Trying to authenticate with 00:24:c4:ab:bd:e0 (SSID='JAISTALL' freq=2412 MHz)
Feb 27 12:58:29 mithrandir kernel: [ 1473.476094] wlan0: direct probe to 00:24:c4:ab:bd:e0 (try 1/3)
Feb 27 12:58:30 mithrandir kernel: [ 1473.676075] wlan0: direct probe to 00:24:c4:ab:bd:e0 (try 2/3)
Feb 27 12:58:30 mithrandir kernel: [ 1473.876092] wlan0: direct probe to 00:24:c4:ab:bd:e0 (try 3/3)
Feb 27 12:58:30 mithrandir kernel: [ 1474.076098] wlan0: direct probe to 00:24:c4:ab:bd:e0 timed out
Feb 27 12:58:37 mithrandir wpa_supplicant[2113]: Trying to authenticate with 00:24:c4:ab:bd:ef (SSID='JAISTALL' freq=5200 MHz)
Feb 27 12:58:37 mithrandir kernel: [ 1481.475855] wlan0: authenticate with 00:24:c4:ab:bd:ef (try 1)
Feb 27 12:58:38 mithrandir kernel: [ 1481.672049] wlan0: authenticate with 00:24:c4:ab:bd:ef (try 2)
Feb 27 12:58:38 mithrandir kernel: [ 1481.872065] wlan0: authenticate with 00:24:c4:ab:bd:ef (try 3)
Feb 27 12:58:38 mithrandir kernel: [ 1482.072103] wlan0: authentication with 00:24:c4:ab:bd:ef timed out
Feb 27 12:58:45 mithrandir wpa_supplicant[2113]: Trying to authenticate with 00:24:c4:ab:bd:e0 (SSID='JAISTALL' freq=2412 MHz)
Feb 27 12:58:45 mithrandir kernel: [ 1489.493280] wlan0: direct probe to 00:24:c4:ab:bd:e0 (try 1/3)
Feb 27 12:58:46 mithrandir kernel: [ 1489.692126] wlan0: direct probe to 00:24:c4:ab:bd:e0 (try 2/3)
Feb 27 12:58:46 mithrandir kernel: [ 1489.892101] wlan0: direct probe to 00:24:c4:ab:bd:e0 (try 3/3)
Feb 27 12:58:46 mithrandir NetworkManager[2062]: <warn> Activation (wlan0/wireless): association took too long, failing activation.
Feb 27 12:58:46 mithrandir NetworkManager[2062]: <info> (wlan0): device state change: config -> failed (reason 'supplicant-timeout') [50 120 11]
Feb 27 12:58:46 mithrandir NetworkManager[2062]: <warn> Activation (wlan0) failed for access point (JAISTALL)
Feb 27 12:58:46 mithrandir NetworkManager[2062]: <warn> Activation (wlan0) failed.
Feb 27 12:58:46 mithrandir NetworkManager[2062]: <info> (wlan0): device state change: failed -> disconnected (reason 'none') [120 30 0]
Feb 27 12:58:46 mithrandir NetworkManager[2062]: <info> (wlan0): deactivating device (reason 'none') [0]
Feb 27 12:58:46 mithrandir NetworkManager[2062]: <info> (wlan0): supplicant interface state: authenticating -> disconnected
Feb 27 12:58:46 mithrandir NetworkManager[2062]: <warn> Couldn't disconnect supplicant interface: This interface is not connected.
Feb 27 12:58:46 mithrandir kernel: [ 1490.092088] wlan0: direct probe to 00:24:c4:ab:bd:e0 timed out
Feb 27 12:58:49 mithrandir NetworkManager[2062]: <info> Auto-activating connection 'Auto JAISTALL'.
Feb 27 12:58:49 mithrandir NetworkManager[2062]: <info> Activation (wlan0) starting connection 'Auto JAISTALL'
Feb 27 12:58:49 mithrandir NetworkManager[2062]: <info> (wlan0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Feb 27 12:58:49 mithrandir NetworkManager[2062]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
Feb 27 12:58:49 mithrandir NetworkManager[2062]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
Feb 27 12:58:49 mithrandir NetworkManager[2062]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
Feb 27 12:58:49 mithrandir NetworkManager[2062]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
Feb 27 12:58:49 mithrandir NetworkManager[2062]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
Feb 27 12:58:49 mithrandir NetworkManager[2062]: <info> (wlan0): device state change: prepare -> config (reason 'none') [40 50 0]
Feb 27 12:58:49 mithrandir NetworkManager[2062]: <info> Activation (wlan0/wireless): connection 'Auto JAISTALL' requires no security.  No secrets needed.
Feb 27 12:58:49 mithrandir NetworkManager[2062]: <info> Config: added 'ssid' value 'JAISTALL'
Feb 27 12:58:49 mithrandir NetworkManager[2062]: <info> Config: added 'scan_ssid' value '1'
Feb 27 12:58:49 mithrandir NetworkManager[2062]: <info> Config: added 'key_mgmt' value 'NONE'
Feb 27 12:58:49 mithrandir NetworkManager[2062]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
Feb 27 12:58:49 mithrandir NetworkManager[2062]: <info> Config: set interface ap_scan to 1
Feb 27 12:58:51 mithrandir NetworkManager[2062]: <info> (wlan0): supplicant interface state: disconnected -> scanning
Feb 27 12:58:53 mithrandir wpa_supplicant[2113]: Trying to authenticate with 00:24:c4:ab:bd:e0 (SSID='JAISTALL' freq=2412 MHz)
Feb 27 12:58:53 mithrandir kernel: [ 1497.491880] wlan0: direct probe to 00:24:c4:ab:bd:e0 (try 1/3)
Feb 27 12:58:53 mithrandir NetworkManager[2062]: <info> (wlan0): supplicant interface state: scanning -> authenticating
Feb 27 12:58:54 mithrandir kernel: [ 1497.688100] wlan0: direct probe to 00:24:c4:ab:bd:e0 (try 2/3)
Feb 27 12:58:54 mithrandir kernel: [ 1497.888099] wlan0: direct probe to 00:24:c4:ab:bd:e0 (try 3/3)
Feb 27 12:58:54 mithrandir kernel: [ 1498.088102] wlan0: direct probe to 00:24:c4:ab:bd:e0 timed out
Feb 27 12:59:01 mithrandir wpa_supplicant[2113]: Trying to authenticate with 00:24:c4:ab:bd:ef (SSID='JAISTALL' freq=5200 MHz)
Feb 27 12:59:01 mithrandir kernel: [ 1505.480761] wlan0: authenticate with 00:24:c4:ab:bd:ef (try 1)
Feb 27 12:59:02 mithrandir kernel: [ 1505.680107] wlan0: authenticate with 00:24:c4:ab:bd:ef (try 2)
Feb 27 12:59:02 mithrandir kernel: [ 1505.880052] wlan0: authenticate with 00:24:c4:ab:bd:ef (try 3)
Feb 27 12:59:02 mithrandir kernel: [ 1506.080094] wlan0: authentication with 00:24:c4:ab:bd:ef timed out
Feb 27 12:59:09 mithrandir wpa_supplicant[2113]: Trying to authenticate with 00:24:c4:ab:bd:ef (SSID='JAISTALL' freq=5200 MHz)
Feb 27 12:59:09 mithrandir kernel: [ 1513.472263] wlan0: authenticate with 00:24:c4:ab:bd:ef (try 1)
Feb 27 12:59:10 mithrandir kernel: [ 1513.672108] wlan0: authenticate with 00:24:c4:ab:bd:ef (try 2)
Feb 27 12:59:10 mithrandir kernel: [ 1513.872102] wlan0: authenticate with 00:24:c4:ab:bd:ef (try 3)
Feb 27 12:59:10 mithrandir kernel: [ 1514.072058] wlan0: authentication with 00:24:c4:ab:bd:ef timed out
Feb 27 12:59:14 mithrandir NetworkManager[2062]: <warn> Activation (wlan0/wireless): association took too long, failing activation.
Feb 27 12:59:14 mithrandir NetworkManager[2062]: <info> (wlan0): device state change: config -> failed (reason 'supplicant-timeout') [50 120 11]
Feb 27 12:59:14 mithrandir NetworkManager[2062]: <warn> Activation (wlan0) failed for access point (JAISTALL)
Feb 27 12:59:14 mithrandir NetworkManager[2062]: <warn> Activation (wlan0) failed.
Feb 27 12:59:14 mithrandir NetworkManager[2062]: <info> (wlan0): device state change: failed -> disconnected (reason 'none') [120 30 0]
Feb 27 12:59:14 mithrandir NetworkManager[2062]: <info> (wlan0): deactivating device (reason 'none') [0]
Feb 27 12:59:14 mithrandir NetworkManager[2062]: <info> (wlan0): supplicant interface state: authenticating -> disconnected
Feb 27 12:59:14 mithrandir NetworkManager[2062]: <warn> Couldn't disconnect supplicant interface: This interface is not connected.
Feb 27 12:59:17 mithrandir NetworkManager[2062]: <info> Auto-activating connection 'Auto JAISTALL'.
Feb 27 12:59:17 mithrandir NetworkManager[2062]: <info> Activation (wlan0) starting connection 'Auto JAISTALL'
Feb 27 12:59:17 mithrandir NetworkManager[2062]: <info> (wlan0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Feb 27 12:59:17 mithrandir NetworkManager[2062]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
Feb 27 12:59:17 mithrandir NetworkManager[2062]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
Feb 27 12:59:17 mithrandir NetworkManager[2062]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
Feb 27 12:59:17 mithrandir NetworkManager[2062]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
Feb 27 12:59:17 mithrandir NetworkManager[2062]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
Feb 27 12:59:17 mithrandir NetworkManager[2062]: <info> (wlan0): device state change: prepare -> config (reason 'none') [40 50 0]
Feb 27 12:59:17 mithrandir NetworkManager[2062]: <info> Activation (wlan0/wireless): connection 'Auto JAISTALL' requires no security.  No secrets needed.
Feb 27 12:59:17 mithrandir NetworkManager[2062]: <info> Config: added 'ssid' value 'JAISTALL'
Feb 27 12:59:17 mithrandir NetworkManager[2062]: <info> Config: added 'scan_ssid' value '1'
Feb 27 12:59:17 mithrandir NetworkManager[2062]: <info> Config: added 'key_mgmt' value 'NONE'
Feb 27 12:59:17 mithrandir NetworkManager[2062]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
Feb 27 12:59:17 mithrandir NetworkManager[2062]: <info> Config: set interface ap_scan to 1
Feb 27 12:59:17 mithrandir NetworkManager[2062]: <info> (wlan0): supplicant interface state: disconnected -> scanning
Feb 27 12:59:19 mithrandir wpa_supplicant[2113]: Trying to authenticate with 00:24:c4:ab:bd:ef (SSID='JAISTALL' freq=5200 MHz)
Feb 27 12:59:19 mithrandir kernel: [ 1523.389933] wlan0: authenticate with 00:24:c4:ab:bd:ef (try 1)
Feb 27 12:59:19 mithrandir NetworkManager[2062]: <info> (wlan0): supplicant interface state: scanning -> authenticating
Feb 27 12:59:20 mithrandir kernel: [ 1523.588036] wlan0: authenticate with 00:24:c4:ab:bd:ef (try 2)
Feb 27 12:59:20 mithrandir kernel: [ 1523.788073] wlan0: authenticate with 00:24:c4:ab:bd:ef (try 3)
Feb 27 12:59:20 mithrandir kernel: [ 1523.988088] wlan0: authentication with 00:24:c4:ab:bd:ef timed out
Feb 27 12:59:27 mithrandir wpa_supplicant[2113]: Trying to authenticate with 00:24:c4:ab:bd:ef (SSID='JAISTALL' freq=5200 MHz)
Feb 27 12:59:27 mithrandir kernel: [ 1531.372573] wlan0: authenticate with 00:24:c4:ab:bd:ef (try 1)
Feb 27 12:59:28 mithrandir kernel: [ 1531.572044] wlan0: authenticate with 00:24:c4:ab:bd:ef (try 2)
Feb 27 12:59:28 mithrandir kernel: [ 1531.772076] wlan0: authenticate with 00:24:c4:ab:bd:ef (try 3)
Feb 27 12:59:28 mithrandir kernel: [ 1531.972108] wlan0: authentication with 00:24:c4:ab:bd:ef timed out
Feb 27 12:59:35 mithrandir wpa_supplicant[2113]: Trying to authenticate with 00:24:c4:ab:bd:ef (SSID='JAISTALL' freq=5200 MHz)
Feb 27 12:59:35 mithrandir kernel: [ 1539.320474] wlan0: authenticate with 00:24:c4:ab:bd:ef (try 1)
Feb 27 12:59:36 mithrandir kernel: [ 1539.520090] wlan0: authenticate with 00:24:c4:ab:bd:ef (try 2)
Feb 27 12:59:36 mithrandir kernel: [ 1539.720116] wlan0: authenticate with 00:24:c4:ab:bd:ef (try 3)
Feb 27 12:59:36 mithrandir kernel: [ 1539.920106] wlan0: authentication with 00:24:c4:ab:bd:ef timed out
Feb 27 12:59:42 mithrandir NetworkManager[2062]: <warn> Activation (wlan0/wireless): association took too long, failing activation.
Feb 27 12:59:42 mithrandir NetworkManager[2062]: <info> (wlan0): device state change: config -> failed (reason 'supplicant-timeout') [50 120 11]
Feb 27 12:59:42 mithrandir NetworkManager[2062]: <warn> Activation (wlan0) failed for access point (JAISTALL)
Feb 27 12:59:42 mithrandir NetworkManager[2062]: <warn> Activation (wlan0) failed.
Feb 27 12:59:42 mithrandir NetworkManager[2062]: <info> (wlan0): device state change: failed -> disconnected (reason 'none') [120 30 0]
Feb 27 12:59:42 mithrandir NetworkManager[2062]: <info> (wlan0): deactivating device (reason 'none') [0]
Feb 27 12:59:42 mithrandir NetworkManager[2062]: <info> (wlan0): supplicant interface state: authenticating -> disconnected
Feb 27 12:59:42 mithrandir NetworkManager[2062]: <warn> Couldn't disconnect supplicant interface: This interface is not connected.
Feb 27 12:59:45 mithrandir NetworkManager[2062]: <info> Auto-activating connection 'Auto JAISTALL'.
Feb 27 12:59:45 mithrandir NetworkManager[2062]: <info> Activation (wlan0) starting connection 'Auto JAISTALL'
Feb 27 12:59:45 mithrandir NetworkManager[2062]: <info> (wlan0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Feb 27 12:59:45 mithrandir NetworkManager[2062]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
Feb 27 12:59:45 mithrandir NetworkManager[2062]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
Feb 27 12:59:45 mithrandir NetworkManager[2062]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
Feb 27 12:59:45 mithrandir NetworkManager[2062]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
Feb 27 12:59:45 mithrandir NetworkManager[2062]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
Feb 27 12:59:45 mithrandir NetworkManager[2062]: <info> (wlan0): device state change: prepare -> config (reason 'none') [40 50 0]
Feb 27 12:59:45 mithrandir NetworkManager[2062]: <info> Activation (wlan0/wireless): connection 'Auto JAISTALL' requires no security.  No secrets needed.
Feb 27 12:59:45 mithrandir NetworkManager[2062]: <info> Config: added 'ssid' value 'JAISTALL'
Feb 27 12:59:45 mithrandir NetworkManager[2062]: <info> Config: added 'scan_ssid' value '1'
Feb 27 12:59:45 mithrandir NetworkManager[2062]: <info> Config: added 'key_mgmt' value 'NONE'
Feb 27 12:59:45 mithrandir NetworkManager[2062]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
Feb 27 12:59:45 mithrandir NetworkManager[2062]: <info> Config: set interface ap_scan to 1
Feb 27 12:59:45 mithrandir NetworkManager[2062]: <info> (wlan0): supplicant interface state: disconnected -> scanning
Feb 27 12:59:47 mithrandir wpa_supplicant[2113]: Trying to authenticate with 00:24:c4:ab:bd:ef (SSID='JAISTALL' freq=5200 MHz)
Feb 27 12:59:47 mithrandir kernel: [ 1551.383928] wlan0: authenticate with 00:24:c4:ab:bd:ef (try 1)
Feb 27 12:59:47 mithrandir NetworkManager[2062]: <info> (wlan0): supplicant interface state: scanning -> authenticating
Feb 27 12:59:48 mithrandir kernel: [ 1551.580048] wlan0: authenticate with 00:24:c4:ab:bd:ef (try 2)
Feb 27 12:59:48 mithrandir kernel: [ 1551.780080] wlan0: authenticate with 00:24:c4:ab:bd:ef (try 3)
Feb 27 12:59:48 mithrandir kernel: [ 1551.980072] wlan0: authentication with 00:24:c4:ab:bd:ef timed out

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: iwlagn is getting even worse with 3.3-rc1
  2012-01-24  1:36 iwlagn is getting even worse with 3.3-rc1 Norbert Preining
  2012-01-24  4:47 ` Emmanuel Grumbach
  2012-02-22  8:37 ` Pekka Enberg
@ 2012-02-27 10:00 ` Matthew Turnbull
  2 siblings, 0 replies; 25+ messages in thread
From: Matthew Turnbull @ 2012-02-27 10:00 UTC (permalink / raw)
  To: linux-kernel

Norbert Preining <preining <at> logic.at> writes:

> long time ago we had a long discussion about iwlagn regressions in 3.1.0
> Up to 3.2 I still have regular problems on the university network
> with stuck iwl driver not even realizing that nothing goes out or in.
> 
> Today I switched to 3.3-rc1 to see it is getting even worse, now on my
> home network I get stuck queue and no connection:

I've had a similar problem. Starting with 3.1.0, iwlagn would sporadically
'drop' connections, despite sill appearing to be connected (nothing obvious in
dmesg). Cycling rfkill would bring it back for a while.

I recently came across another topic, with the same issue, and this patch was
recommended:

http://git.kernel.org/?p=linux/kernel/git/iwlwifi/iwlwifi.git;
a=commitdiff;h=5dcbf480473f6c3f06ad2426b7517038a2a18911

I applied that on top of 3.2.6 and *knock on wood* I haven't seen the issue
reoccur.


^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: iwlagn is getting even worse with 3.3-rc1
  2012-02-27  8:36                           ` Norbert Preining
@ 2012-02-27 18:01                             ` Emmanuel Grumbach
  2012-02-27 22:42                               ` Norbert Preining
  2012-03-13 23:39                               ` Norbert Preining
  0 siblings, 2 replies; 25+ messages in thread
From: Emmanuel Grumbach @ 2012-02-27 18:01 UTC (permalink / raw)
  To: Norbert Preining
  Cc: Pekka Enberg, linux-kernel, ipw3945-devel, Guy, Wey-Yi,
	Johannes Berg, linux-wireless, ilw, Dave Jones

> sorry for the silence, I wasn't at the university for a few days so
> I couldn't test.
>
> Now I did:
> kernel 3.3-rc5
>
> On Mi, 22 Feb 2012, Emmanuel Grumbach wrote:
>> From the log, I can see that we have a lot of "passive channel
>> failures". Can you try to disable 11n (module_parameter) ?
>> Please also try with debug=0xc0000000

So this doesn't seem to be related to my rework of the AMPDU logic....
Will keep you updated if I think about something.

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: iwlagn is getting even worse with 3.3-rc1
  2012-02-27 18:01                             ` Emmanuel Grumbach
@ 2012-02-27 22:42                               ` Norbert Preining
  2012-03-13 23:39                               ` Norbert Preining
  1 sibling, 0 replies; 25+ messages in thread
From: Norbert Preining @ 2012-02-27 22:42 UTC (permalink / raw)
  To: Emmanuel Grumbach
  Cc: Pekka Enberg, linux-kernel, ipw3945-devel, Guy, Wey-Yi,
	Johannes Berg, linux-wireless, ilw, Dave Jones

On Mo, 27 Feb 2012, Emmanuel Grumbach wrote:
> So this doesn't seem to be related to my rework of the AMPDU logic....
> Will keep you updated if I think about something.

Thanks.

Best wishes

Norbert
------------------------------------------------------------------------
Norbert Preining            preining@{jaist.ac.jp, logic.at, debian.org}
JAIST, Japan                                 TeX Live & Debian Developer
DSA: 0x09C5B094   fp: 14DF 2E6C 0307 BE6D AD76  A9C0 D2BF 4AA3 09C5 B094
------------------------------------------------------------------------
MEATHOP (n.)
One who sets off for the scene of an aircraft crash with a picnic
hamper.
			--- Douglas Adams, The Meaning of Liff

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: iwlagn is getting even worse with 3.3-rc1
  2012-02-27 18:01                             ` Emmanuel Grumbach
  2012-02-27 22:42                               ` Norbert Preining
@ 2012-03-13 23:39                               ` Norbert Preining
  1 sibling, 0 replies; 25+ messages in thread
From: Norbert Preining @ 2012-03-13 23:39 UTC (permalink / raw)
  To: Emmanuel Grumbach
  Cc: Pekka Enberg, linux-kernel, ipw3945-devel, Guy, Wey-Yi,
	Johannes Berg, linux-wireless, ilw, Dave Jones

Hi Emmanuel,

(now at -rc6)

On Mo, 27 Feb 2012, Emmanuel Grumbach wrote:
> > Now I did:
> > kernel 3.3-rc5
> >
> > On Mi, 22 Feb 2012, Emmanuel Grumbach wrote:
> >> From the log, I can see that we have a lot of "passive channel
> >> failures". Can you try to disable 11n (module_parameter) ?
> >> Please also try with debug=0xc0000000
> 
> So this doesn't seem to be related to my rework of the AMPDU logic....
> Will keep you updated if I think about something.

Another thing ... I don't know what the hack is going on here, since
-rc6 I think I get *loads* of messages:
	delba from 00:0a:79:eb:56:10 (initiator) tid 0 reason code 39
After last reboot in about 10min (920.95) I got 414 of these lines.
Always in a triple:
[  914.882870] delba from 00:0a:79:eb:56:10 (initiator) tid 0 reason code 39
[  914.882881] Rx BA session stop requested for 00:0a:79:eb:56:10 tid 0 inititator reason: 0
[  915.012136] Rx A-MPDU request on tid 0 result 0
[  916.157983] delba from 00:0a:79:eb:56:10 (initiator) tid 0 reason code 39
...

No idea if that helps in any way, but it is new.

Interestingly, after doing rfkill block wifi; sleep 10; rfkill unblock wifi,
and that sometimes 2 or three times, at some point these messages disappear
and I have only:
[18876.624068] tx session timer expired on tid 0
[18876.624117] Tx BA session stop requested for 00:0a:79:eb:56:10 tid 0
[18876.644224] Stopping Tx BA session for 00:0a:79:eb:56:10 tid 0
[18877.609764] Open BA session requested for 00:0a:79:eb:56:10 tid 0
[18877.640279] activated addBA response timer on tid 0
[18877.642218] switched off addBA timer for tid 0
[18877.642224] Aggregation is on for tid 0
(again many of them)

Best wishes

Norbert
------------------------------------------------------------------------
Norbert Preining            preining@{jaist.ac.jp, logic.at, debian.org}
JAIST, Japan                                 TeX Live & Debian Developer
DSA: 0x09C5B094   fp: 14DF 2E6C 0307 BE6D AD76  A9C0 D2BF 4AA3 09C5 B094
------------------------------------------------------------------------
MELCOMBE REGIS (n.)
The name of the style of decoration used in cocktail lounges in mock
Tudor hotels in Surrey.
			--- Douglas Adams, The Meaning of Liff

^ permalink raw reply	[flat|nested] 25+ messages in thread

end of thread, other threads:[~2012-03-13 23:39 UTC | newest]

Thread overview: 25+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2012-01-24  1:36 iwlagn is getting even worse with 3.3-rc1 Norbert Preining
2012-01-24  4:47 ` Emmanuel Grumbach
2012-01-25  0:22   ` Norbert Preining
2012-01-25  5:32     ` Emmanuel Grumbach
2012-01-26  0:37       ` Norbert Preining
2012-01-26  5:49         ` Emmanuel Grumbach
2012-01-26 21:13           ` Emmanuel Grumbach
2012-01-26 23:25             ` Norbert Preining
2012-01-27  0:06               ` Emmanuel Grumbach
2012-01-31  2:41                 ` Dave Jones
2012-02-01 15:43                   ` Dave Jones
2012-02-01 14:45                     ` Guy, Wey-Yi
2012-01-27  1:50               ` Norbert Preining
2012-01-27  3:11                 ` Emmanuel Grumbach
2012-02-22  0:37                   ` Norbert Preining
2012-02-22  6:58                     ` Emmanuel Grumbach
2012-02-22  8:40                     ` Pekka Enberg
2012-02-22  8:54                       ` Emmanuel Grumbach
2012-02-23  7:06                         ` Pekka Enberg
2012-02-27  8:36                           ` Norbert Preining
2012-02-27 18:01                             ` Emmanuel Grumbach
2012-02-27 22:42                               ` Norbert Preining
2012-03-13 23:39                               ` Norbert Preining
2012-02-22  8:37 ` Pekka Enberg
2012-02-27 10:00 ` Matthew Turnbull

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).