2011-11-18 22:47:19

by Arnd Hannemann

[permalink] [raw]
Subject: 3.2.0-rc2: WARNING: at iwlwifi/wl-trans-pcie.c:1105

Hi,

I just got the following WARNING on a 3.2.0-rc2 kernel:

[ 191.516877] iwlwifi 0000:03:00.0: Tx aggregation enabled on ra = 30:46:9a:XX:XX:XX tid = 0
[ 191.516890] ------------[ cut here ]------------
[ 191.516920] WARNING: at /home/arnd/Projekte/kernel/linux-2.6/drivers/net/wireless/iwlwifi/iwl-trans-pcie.c:1105 iwl_trans_pcie_tx+0x835/0x890 [iwlwifi]()
[ 191.516925] Hardware name: 4384GEG
[ 191.516927] Modules linked in: ip6table_filter ip6_tables ipt_MASQUERADE iptable_nat nf_nat nf_conntrack_ipv4 nf_defrag_ipv4 xt_state nf_conntrack ipt_REJECT xt_CHECKSUM iptable_mangle xt_tcpudp iptable_filter ip_tables x_tables bnep rfcomm bridge stp llc kvm_intel kvm binfmt_misc joydev dm_crypt snd_hda_codec_hdmi snd_hda_codec_conexant arc4 snd_hda_intel snd_hda_codec snd_hwdep snd_pcm thinkpad_acpi snd_seq_midi snd_rawmidi snd_seq_midi_event qcserial usb_wwan usbserial snd_seq btusb bluetooth snd_timer snd_seq_device iwlwifi psmouse mac80211 intel_ips serio_raw snd cfg80211 snd_page_alloc mei(C) soundcore nvram tpm_tis btrfs zlib_deflate libcrc32c mxm_wmi firewire_ohci ahci firewire_core libahci wmi e1000e sdhci_pci crc_itu_t i915 drm_kms_helper drm sdhci i2c_algo_bit video
[ 191.517007] Pid: 2401, comm: kworker/u:17 Tainted: G WC 3.2.0-rc2aha #3
[ 191.517010] Call Trace:
[ 191.517013] <IRQ> [<ffffffff81062b9f>] warn_slowpath_common+0x7f/0xc0
[ 191.517027] [<ffffffff81062bfa>] warn_slowpath_null+0x1a/0x20
[ 191.517042] [<ffffffffa031ce25>] iwl_trans_pcie_tx+0x835/0x890 [iwlwifi]
[ 191.517059] [<ffffffffa02810b8>] ? ccmp_encrypt_skb.isra.4+0x108/0x230 [mac80211]
[ 191.517067] [<ffffffff8105a500>] ? try_to_wake_up+0x220/0x2a0
[ 191.517073] [<ffffffff810861e6>] ? autoremove_wake_function+0x16/0x40
[ 191.517085] [<ffffffffa03078d7>] ? iwlagn_tx_skb+0xc7/0x7d0 [iwlwifi]
[ 191.517096] [<ffffffffa0307c60>] iwlagn_tx_skb+0x450/0x7d0 [iwlwifi]
[ 191.517110] [<ffffffffa0323a87>] ? iwl_tx_cmd_complete+0x1e7/0x350 [iwlwifi]
[ 191.517120] [<ffffffffa02fe65a>] iwlagn_mac_tx+0x1a/0x30 [iwlwifi]
[ 191.517137] [<ffffffffa0299436>] __ieee80211_tx+0x76/0x230 [mac80211]
[ 191.517152] [<ffffffffa0320e96>] ? iwl_irq_tasklet+0x846/0xe10 [iwlwifi]
[ 191.517170] [<ffffffffa029b44c>] ieee80211_tx+0x8c/0xc0 [mac80211]
[ 191.517187] [<ffffffffa029c32d>] ieee80211_tx_pending+0x7d/0x220 [mac80211]
[ 191.517193] [<ffffffff8106a20d>] ? __do_softirq+0xfd/0x210
[ 191.517199] [<ffffffff81069b78>] tasklet_action+0x78/0x140
[ 191.517204] [<ffffffff8106a1b8>] __do_softirq+0xa8/0x210
[ 191.517210] [<ffffffff8160f2ac>] call_softirq+0x1c/0x30
[ 191.517212] <EOI> [<ffffffff81015195>] do_softirq+0x65/0xa0
[ 191.517222] [<ffffffff8106a104>] local_bh_enable_ip+0x94/0xa0
[ 191.517227] [<ffffffff81605109>] _raw_spin_unlock_bh+0x19/0x20
[ 191.517241] [<ffffffffa0284899>] ieee80211_agg_tx_operational+0xb9/0xd0 [mac80211]
[ 191.517257] [<ffffffffa028d9c8>] ? ieee80211_iface_work+0xd8/0x350 [mac80211]
[ 191.517273] [<ffffffffa02850ee>] ieee80211_process_addba_resp+0x11e/0x120 [mac80211]
[ 191.517289] [<ffffffffa028dbef>] ieee80211_iface_work+0x2ff/0x350 [mac80211]
[ 191.517305] [<ffffffffa028d8f0>] ? ieee80211_teardown_sdata+0xe0/0xe0 [mac80211]
[ 191.517312] [<ffffffff8108023a>] process_one_work+0x11a/0x480
[ 191.517317] [<ffffffff81080fc4>] worker_thread+0x164/0x370
[ 191.517322] [<ffffffff81080e60>] ? manage_workers.isra.30+0x230/0x230
[ 191.517327] [<ffffffff8108573c>] kthread+0x8c/0xa0
[ 191.517332] [<ffffffff8160f1b4>] kernel_thread_helper+0x4/0x10
[ 191.517338] [<ffffffff810856b0>] ? flush_kthread_worker+0xa0/0xa0
[ 191.517343] [<ffffffff8160f1b0>] ? gs_change+0x13/0x13
[ 191.517346] ---[ end trace f5849db7402e7e61 ]---
[ 193.817069] iwlwifi 0000:03:00.0: Queue 11 stuck for 2000 ms.
[ 193.817075] iwlwifi 0000:03:00.0: Current read_ptr 166 write_ptr 172
[ 193.817078] iwlwifi 0000:03:00.0: On demand firmware reload
[ 193.817420] ieee80211 phy0: Hardware restart was requested
[ 193.817470] iwlwifi 0000:03:00.0: L1 Disabled; Enabling L0S
[ 193.817596] iwlwifi 0000:03:00.0: Radio type=0x0-0x3-0x1

Best regards,
Arnd


2011-11-29 09:50:39

by Emmanuel Grumbach

[permalink] [raw]
Subject: Re: 3.2.0-rc2: WARNING: at iwlwifi/wl-trans-pcie.c:1105

On Thu, Nov 24, 2011 at 23:55, Arnd Hannemann <[email protected]> wrote:
> Hi,
>
> Am 24.11.2011 07:23, schrieb Emmanuel Grumbach:
>>>
>>> I applied the QUEUE_DEBUG.patch you posted in the other thread, not sure if I'm experiencing the same problem:
>>
>> Yes, it looks similar. Please enable the MAC80211_HT_DEBUG compilation flag too.
>> In any case now that I more the less see what is happening, I am
>> working now on another debug patch.
>
> Here you are, 3.2.0-rc3 with enabled MAC80211_HT_DEBUG and your QUEUE_DEBUG.patch:
>
> [ ?396.963871] switched off addBA timer for tid 0
> [ ?396.963877] Aggregation is on for tid 0
> [ ?396.964022] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate BA Queue 11 on FIFO 1
> [ ?396.964037] iwlwifi 0000:03:00.0: Tx aggregation enabled on ra = 30:46:9a:XX:XX:XX tid = 0
> [ ?396.964052] ------------[ cut here ]------------
> [ ?396.964079] WARNING: at /home/arnd/Projekte/kernel/linux-2.6/drivers/net/wireless/iwlwifi/iwl-trans-pcie.c:1106 iwl_trans_pcie_tx+0xb71/0xb90 [iwlwifi]()
> [ ?396.964086] Hardware name: 4384GEG
> [ ?396.964090] Modules linked in: iwlwifi ufs qnx4 hfsplus hfs minix ntfs vfat msdos fat jfs xfs reiserfs ip6table_filter ip6_tables bnep rfcomm ipt_MASQUERADE iptable_nat nf_nat nf_conntrack_ipv4 nf_defrag_ipv4 xt_state nf_conntrack ipt_REJECT xt_CHECKSUM iptable_mangle xt_tcpudp iptable_filter ip_tables x_tables bridge stp llc kvm_intel kvm joydev dm_crypt arc4 qcserial usb_wwan usbserial btusb bluetooth snd_hda_codec_hdmi snd_hda_codec_conexant binfmt_misc thinkpad_acpi snd_hda_intel snd_hda_codec snd_hwdep snd_seq_midi snd_pcm snd_rawmidi psmouse serio_raw snd_seq_midi_event snd_seq snd_timer snd_seq_device intel_ips mac80211 snd cfg80211 snd_page_alloc soundcore tpm_tis nvram mei(C) btrfs zlib_deflate libcrc32c mxm_wmi firewire_ohci wmi firewire_core crc_itu_t sdhci_pci sdhci ahci libahci i915 drm_kms_helper drm e1000e i2c_algo_bit video [last unloaded: iwlwifi]
> [ ?396.964231] Pid: 308, comm: kworker/u:4 Tainted: G ? ? ? ? C ? 3.2.0-rc3-aha+ #8
> [ ?396.964237] Call Trace:
> [ ?396.964241] ?<IRQ> ?[<ffffffff81062b7f>] warn_slowpath_common+0x7f/0xc0
> [ ?396.964259] ?[<ffffffff81062bda>] warn_slowpath_null+0x1a/0x20
> [ ?396.964279] ?[<ffffffffa0762fd1>] iwl_trans_pcie_tx+0xb71/0xb90 [iwlwifi]
> [ ?396.964304] ?[<ffffffffa026b0c8>] ? ccmp_encrypt_skb.isra.4+0x108/0x230 [mac80211]
> [ ?396.964321] ?[<ffffffffa07443e1>] ? iwlagn_tx_skb+0x161/0xb90 [iwlwifi]
> [ ?396.964336] ?[<ffffffffa074477f>] iwlagn_tx_skb+0x4ff/0xb90 [iwlwifi]
> [ ?396.964348] ?[<ffffffffa073b491>] iwlagn_mac_tx+0x121/0x1c0 [iwlwifi]
> [ ?396.964356] ?[<ffffffff8103aa39>] ? default_spin_lock_flags+0x9/0x10
> [ ?396.964376] ?[<ffffffffa0283806>] __ieee80211_tx+0x76/0x230 [mac80211]
> [ ?396.964394] ?[<ffffffffa028581c>] ieee80211_tx+0x8c/0xc0 [mac80211]
> [ ?396.964412] ?[<ffffffffa02866fd>] ieee80211_tx_pending+0x7d/0x220 [mac80211]
> [ ?396.964420] ?[<ffffffff8104a13c>] ? resched_task+0x2c/0x80
> [ ?396.964426] ?[<ffffffff81069b58>] tasklet_action+0x78/0x140
> [ ?396.964432] ?[<ffffffff8106a198>] __do_softirq+0xa8/0x210
> [ ?396.964439] ?[<ffffffff8160e5ec>] call_softirq+0x1c/0x30
> [ ?396.964441] ?<EOI> ?[<ffffffff81015195>] do_softirq+0x65/0xa0
> [ ?396.964451] ?[<ffffffff8106a0e4>] local_bh_enable_ip+0x94/0xa0
> [ ?396.964456] ?[<ffffffff81604439>] _raw_spin_unlock_bh+0x19/0x20
> [ ?396.964471] ?[<ffffffffa026e9a9>] ieee80211_agg_tx_operational+0xc9/0xe0 [mac80211]
> [ ?396.964486] ?[<ffffffffa026f2a4>] ieee80211_process_addba_resp+0x114/0x150 [mac80211]
> [ ?396.964503] ?[<ffffffffa0277f6f>] ieee80211_iface_work+0x2ff/0x350 [mac80211]
> [ ?396.964520] ?[<ffffffffa0277c70>] ? ieee80211_teardown_sdata+0xe0/0xe0 [mac80211]
> [ ?396.964527] ?[<ffffffff8108021a>] process_one_work+0x11a/0x480
> [ ?396.964533] ?[<ffffffff814f2ab7>] ? __kfree_skb+0x47/0xa0
> [ ?396.964538] ?[<ffffffff81080fa4>] worker_thread+0x164/0x370
> [ ?396.964543] ?[<ffffffff81080e40>] ? manage_workers.isra.30+0x230/0x230
> [ ?396.964548] ?[<ffffffff8108571c>] kthread+0x8c/0xa0
> [ ?396.964553] ?[<ffffffff8160e4f4>] kernel_thread_helper+0x4/0x10
> [ ?396.964558] ?[<ffffffff81085690>] ? flush_kthread_worker+0xa0/0xa0
> [ ?396.964563] ?[<ffffffff8160e4f0>] ? gs_change+0x13/0x13
> [ ?396.964566] ---[ end trace d76891b9559c3dcc ]---
> [ ?396.964741] Stopping Tx BA session for 30:46:9a:XX:XX:XX tid 0
> [ ?397.804618] Open BA session requested for 30:46:9a:XX:XX:XX tid 0
> [ ?397.844951] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 44 packets in HW queue
> [ ?397.844964] activated addBA response timer on tid 0
> [ ?397.847025] switched off addBA timer for tid 0
> [ ?399.230074] iwlwifi 0000:03:00.0: Queue 11 stuck for 2000 ms.
> [ ?399.230081] iwlwifi 0000:03:00.0: Current read_ptr 12 write_ptr 57
> [ ?399.230086] iwlwifi 0000:03:00.0: On demand firmware reload
> [ ?399.230449] ieee80211 phy1: Hardware restart was requested
> [ ?399.230536] iwlwifi 0000:03:00.0: L1 Disabled; Enabling L0S
> [ ?399.237213] iwlwifi 0000:03:00.0: Radio type=0x0-0x3-0x1
>
> Best regards
> Arnd
>
>

Sorry, somehow I saw the mail only now. This one should make it

http://www.spinics.net/lists/linux-wireless/msg81131.html

2011-11-24 06:24:01

by Emmanuel Grumbach

[permalink] [raw]
Subject: Re: 3.2.0-rc2: WARNING: at iwlwifi/wl-trans-pcie.c:1105

>
> I applied the QUEUE_DEBUG.patch you posted in the other thread, not sure if I'm experiencing the same problem:

Yes, it looks similar. Please enable the MAC80211_HT_DEBUG compilation flag too.
In any case now that I more the less see what is happening, I am
working now on another debug patch.

>
>
> [38275.502526] iwlwifi 0000:03:00.0: Tx aggregation enabled on ra = 30:46:9a:XX:XX:XX tid = 0
> [38283.406370] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_disable HW queue is empty
> [38283.406460] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
> [38290.363252] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is empty
> [38291.358619] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_disable HW queue is empty
> [38291.358713] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
> [38296.788459] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate BA Queue 11 on FIFO 1
> [38296.788475] iwlwifi 0000:03:00.0: Tx aggregation enabled on ra = 30:46:9a:XX:XX:XX tid = 0
> [38296.788489] ------------[ cut here ]------------
> [38296.788518] WARNING: at /home/arnd/Projekte/kernel/linux-2.6/drivers/net/wireless/iwlwifi/iwl-trans-pcie.c:1106 iwl_trans_pcie_tx+0xb71/0xb90 [iwlwifi]()
> [38296.788526] Hardware name: 4384GEG
> [38296.788529] Modules linked in: iwlwifi ip6table_filter ip6_tables bnep rfcomm ipt_MASQUERADE iptable_nat nf_nat nf_conntrack_ipv4 nf_defrag_ipv4 xt_state nf_conntrack ipt_REJECT xt_CHECKSUM iptable_mangle xt_tcpudp iptable_filter ip_tables x_tables bridge stp llc kvm_intel kvm joydev dm_crypt snd_hda_codec_hdmi snd_hda_codec_conexant snd_hda_intel snd_hda_codec snd_hwdep snd_pcm arc4 snd_seq_midi snd_rawmidi binfmt_misc snd_seq_midi_event psmouse qcserial usb_wwan serio_raw snd_seq usbserial intel_ips btusb snd_timer snd_seq_device bluetooth mac80211 tpm_tis thinkpad_acpi cfg80211 nvram snd mei(C) soundcore snd_page_alloc btrfs zlib_deflate libcrc32c mxm_wmi e1000e ahci libahci sdhci_pci sdhci firewire_ohci i915 firewire_core drm_kms_helper crc_itu_t drm i2c_algo_bit wmi video [last unloaded: iwlwifi]
> [38296.788663] Pid: 6243, comm: kworker/u:23 Tainted: G ? ? ? ?WC ? 3.2.0-rc2-aha+ #7
> [38296.788668] Call Trace:
> [38296.788672] ?<IRQ> ?[<ffffffff81062b9f>] warn_slowpath_common+0x7f/0xc0
> [38296.788690] ?[<ffffffff81062bfa>] warn_slowpath_null+0x1a/0x20
> [38296.788712] ?[<ffffffffa0580fd1>] iwl_trans_pcie_tx+0xb71/0xb90 [iwlwifi]
> [38296.788724] ?[<ffffffff814f2b1d>] ? consume_skb+0x3d/0xb0
> [38296.788749] ?[<ffffffffa028a0c8>] ? ccmp_encrypt_skb.isra.4+0x108/0x230 [mac80211]
> [38296.788759] ?[<ffffffff8105a592>] ? default_wake_function+0x12/0x20
> [38296.788767] ?[<ffffffff81086100>] ? remove_wait_queue+0x60/0x70
> [38296.788784] ?[<ffffffffa05623e1>] ? iwlagn_tx_skb+0x161/0xb90 [iwlwifi]
> [38296.788802] ?[<ffffffffa056277f>] iwlagn_tx_skb+0x4ff/0xb90 [iwlwifi]
> [38296.788815] ?[<ffffffffa0559491>] iwlagn_mac_tx+0x121/0x1c0 [iwlwifi]
> [38296.788824] ?[<ffffffff8103aa39>] ? default_spin_lock_flags+0x9/0x10
> [38296.788849] ?[<ffffffffa02a2506>] __ieee80211_tx+0x76/0x230 [mac80211]
> [38296.788873] ?[<ffffffffa02a451c>] ieee80211_tx+0x8c/0xc0 [mac80211]
> [38296.788896] ?[<ffffffffa02a53fd>] ieee80211_tx_pending+0x7d/0x220 [mac80211]
> [38296.788905] ?[<ffffffff8106a20d>] ? __do_softirq+0xfd/0x210
> [38296.788913] ?[<ffffffff81069b78>] tasklet_action+0x78/0x140
> [38296.788920] ?[<ffffffff8106a1b8>] __do_softirq+0xa8/0x210
> [38296.788930] ?[<ffffffff8160e5ac>] call_softirq+0x1c/0x30
> [38296.788934] ?<EOI> ?[<ffffffff81015195>] do_softirq+0x65/0xa0
> [38296.788950] ?[<ffffffff8106a104>] local_bh_enable_ip+0x94/0xa0
> [38296.788958] ?[<ffffffff816043f9>] _raw_spin_unlock_bh+0x19/0x20
> [38296.788980] ?[<ffffffffa028d8a9>] ieee80211_agg_tx_operational+0xb9/0xd0 [mac80211]
> [38296.789002] ?[<ffffffffa0296a78>] ? ieee80211_iface_work+0xd8/0x350 [mac80211]
> [38296.789023] ?[<ffffffffa028e0fe>] ieee80211_process_addba_resp+0x11e/0x120 [mac80211]
> [38296.789045] ?[<ffffffffa0296c9f>] ieee80211_iface_work+0x2ff/0x350 [mac80211]
> [38296.789068] ?[<ffffffffa02969a0>] ? ieee80211_teardown_sdata+0xe0/0xe0 [mac80211]
> [38296.789078] ?[<ffffffff8108023a>] process_one_work+0x11a/0x480
> [38296.789085] ?[<ffffffff81080fc4>] worker_thread+0x164/0x370
> [38296.789093] ?[<ffffffff81080e60>] ? manage_workers.isra.30+0x230/0x230
> [38296.789099] ?[<ffffffff8108573c>] kthread+0x8c/0xa0
> [38296.789105] ?[<ffffffff8160e4b4>] kernel_thread_helper+0x4/0x10
> [38296.789111] ?[<ffffffff810856b0>] ? flush_kthread_worker+0xa0/0xa0
> [38296.789119] ?[<ffffffff8160e4b0>] ? gs_change+0x13/0x13
> [38296.789123] ---[ end trace 201230ed6208edbf ]---
> [38298.939515] iwlwifi 0000:03:00.0: Queue 11 stuck for 2000 ms.
> [38298.939523] iwlwifi 0000:03:00.0: Current read_ptr 197 write_ptr 2
> [38298.939528] iwlwifi 0000:03:00.0: On demand firmware reload
> [38298.939926] ieee80211 phy3: Hardware restart was requested
> [38298.940032] iwlwifi 0000:03:00.0: L1 Disabled; Enabling L0S
> [38298.940167] iwlwifi 0000:03:00.0: Radio type=0x0-0x3-0x1
> [38299.006160] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Activate AC/CMD Queue 0 on FIFO 3
> [38299.006180] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Activate AC/CMD Queue 1 on FIFO 2
> [38299.006197] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Activate AC/CMD Queue 2 on FIFO 1
> [38299.006214] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Activate AC/CMD Queue 3 on FIFO 0
> [38299.006230] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Activate AC/CMD Queue 4 on FIFO 7
> [38301.596322] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 60 packets in HW queue
> [38306.705156] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
> [38306.820030] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 60 packets in HW queue
> [38311.921881] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
> [38312.027099] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 70 packets in HW queue
> [38317.138756] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
> [38317.235476] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 140 packets in HW queue
> [38322.424187] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
> [38322.767875] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 60 packets in HW queue
> [38327.939631] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
> [38328.086516] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 60 packets in HW queue
> [38333.251181] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
> [38333.540666] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 60 packets in HW queue
> [38338.766575] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
> [38338.969220] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 60 packets in HW queue
> [38344.282421] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
> [38344.409610] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 60 packets in HW queue
> [38349.593755] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
> [38349.680482] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 60 packets in HW queue
> [38354.905092] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
> [38355.233118] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 60 packets in HW queue
> [38360.420658] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
> [38361.314785] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 60 packets in HW queue
> [38376.705700] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
> [38377.554487] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 59 packets in HW queue
> [38382.687399] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
> [38383.068691] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 59 packets in HW queue
> [38388.203087] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
> [38388.297090] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 59 packets in HW queue
> [38393.514383] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
> [38393.609374] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 69 packets in HW queue
> [38398.825772] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
> [38399.038167] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 59 packets in HW queue
> [38404.138245] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
> [38404.794215] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 59 packets in HW queue
> [38410.061196] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
> [38411.198133] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 59 packets in HW queue
> [38416.393938] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
> [38416.527477] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 110 packets in HW queue
> [38421.705324] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
> [38421.797204] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 87 packets in HW queue
> [38427.016619] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
> [38429.109294] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 59 packets in HW queue
> [38434.211841] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
> [38435.229973] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 59 packets in HW queue
> [38473.797319] wlan0: deauthenticated from 30:46:9a:XX:XX:XX (Reason: 7)
> [38473.797417] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
> [38473.819945] iwlwifi 0000:03:00.0: Stopping AGG while state not ON or starting for 0 on 0 (0)
>
> Best regards,
> Arnd
>

2011-11-24 21:55:40

by Arnd Hannemann

[permalink] [raw]
Subject: Re: 3.2.0-rc2: WARNING: at iwlwifi/wl-trans-pcie.c:1105

Hi,

Am 24.11.2011 07:23, schrieb Emmanuel Grumbach:
>>
>> I applied the QUEUE_DEBUG.patch you posted in the other thread, not sure if I'm experiencing the same problem:
>
> Yes, it looks similar. Please enable the MAC80211_HT_DEBUG compilation flag too.
> In any case now that I more the less see what is happening, I am
> working now on another debug patch.

Here you are, 3.2.0-rc3 with enabled MAC80211_HT_DEBUG and your QUEUE_DEBUG.patch:

[ 396.963871] switched off addBA timer for tid 0
[ 396.963877] Aggregation is on for tid 0
[ 396.964022] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate BA Queue 11 on FIFO 1
[ 396.964037] iwlwifi 0000:03:00.0: Tx aggregation enabled on ra = 30:46:9a:XX:XX:XX tid = 0
[ 396.964052] ------------[ cut here ]------------
[ 396.964079] WARNING: at /home/arnd/Projekte/kernel/linux-2.6/drivers/net/wireless/iwlwifi/iwl-trans-pcie.c:1106 iwl_trans_pcie_tx+0xb71/0xb90 [iwlwifi]()
[ 396.964086] Hardware name: 4384GEG
[ 396.964090] Modules linked in: iwlwifi ufs qnx4 hfsplus hfs minix ntfs vfat msdos fat jfs xfs reiserfs ip6table_filter ip6_tables bnep rfcomm ipt_MASQUERADE iptable_nat nf_nat nf_conntrack_ipv4 nf_defrag_ipv4 xt_state nf_conntrack ipt_REJECT xt_CHECKSUM iptable_mangle xt_tcpudp iptable_filter ip_tables x_tables bridge stp llc kvm_intel kvm joydev dm_crypt arc4 qcserial usb_wwan usbserial btusb bluetooth snd_hda_codec_hdmi snd_hda_codec_conexant binfmt_misc thinkpad_acpi snd_hda_intel snd_hda_codec snd_hwdep snd_seq_midi snd_pcm snd_rawmidi psmouse serio_raw snd_seq_midi_event snd_seq snd_timer snd_seq_device intel_ips mac80211 snd cfg80211 snd_page_alloc soundcore tpm_tis nvram mei(C) btrfs zlib_deflate libcrc32c mxm_wmi firewire_ohci wmi firewire_core crc_itu_t sdhci_pci sdhci ahci libahci i915 drm_kms_helper drm e1000e i2c_algo_bit video [last unloaded: iwlwifi]
[ 396.964231] Pid: 308, comm: kworker/u:4 Tainted: G C 3.2.0-rc3-aha+ #8
[ 396.964237] Call Trace:
[ 396.964241] <IRQ> [<ffffffff81062b7f>] warn_slowpath_common+0x7f/0xc0
[ 396.964259] [<ffffffff81062bda>] warn_slowpath_null+0x1a/0x20
[ 396.964279] [<ffffffffa0762fd1>] iwl_trans_pcie_tx+0xb71/0xb90 [iwlwifi]
[ 396.964304] [<ffffffffa026b0c8>] ? ccmp_encrypt_skb.isra.4+0x108/0x230 [mac80211]
[ 396.964321] [<ffffffffa07443e1>] ? iwlagn_tx_skb+0x161/0xb90 [iwlwifi]
[ 396.964336] [<ffffffffa074477f>] iwlagn_tx_skb+0x4ff/0xb90 [iwlwifi]
[ 396.964348] [<ffffffffa073b491>] iwlagn_mac_tx+0x121/0x1c0 [iwlwifi]
[ 396.964356] [<ffffffff8103aa39>] ? default_spin_lock_flags+0x9/0x10
[ 396.964376] [<ffffffffa0283806>] __ieee80211_tx+0x76/0x230 [mac80211]
[ 396.964394] [<ffffffffa028581c>] ieee80211_tx+0x8c/0xc0 [mac80211]
[ 396.964412] [<ffffffffa02866fd>] ieee80211_tx_pending+0x7d/0x220 [mac80211]
[ 396.964420] [<ffffffff8104a13c>] ? resched_task+0x2c/0x80
[ 396.964426] [<ffffffff81069b58>] tasklet_action+0x78/0x140
[ 396.964432] [<ffffffff8106a198>] __do_softirq+0xa8/0x210
[ 396.964439] [<ffffffff8160e5ec>] call_softirq+0x1c/0x30
[ 396.964441] <EOI> [<ffffffff81015195>] do_softirq+0x65/0xa0
[ 396.964451] [<ffffffff8106a0e4>] local_bh_enable_ip+0x94/0xa0
[ 396.964456] [<ffffffff81604439>] _raw_spin_unlock_bh+0x19/0x20
[ 396.964471] [<ffffffffa026e9a9>] ieee80211_agg_tx_operational+0xc9/0xe0 [mac80211]
[ 396.964486] [<ffffffffa026f2a4>] ieee80211_process_addba_resp+0x114/0x150 [mac80211]
[ 396.964503] [<ffffffffa0277f6f>] ieee80211_iface_work+0x2ff/0x350 [mac80211]
[ 396.964520] [<ffffffffa0277c70>] ? ieee80211_teardown_sdata+0xe0/0xe0 [mac80211]
[ 396.964527] [<ffffffff8108021a>] process_one_work+0x11a/0x480
[ 396.964533] [<ffffffff814f2ab7>] ? __kfree_skb+0x47/0xa0
[ 396.964538] [<ffffffff81080fa4>] worker_thread+0x164/0x370
[ 396.964543] [<ffffffff81080e40>] ? manage_workers.isra.30+0x230/0x230
[ 396.964548] [<ffffffff8108571c>] kthread+0x8c/0xa0
[ 396.964553] [<ffffffff8160e4f4>] kernel_thread_helper+0x4/0x10
[ 396.964558] [<ffffffff81085690>] ? flush_kthread_worker+0xa0/0xa0
[ 396.964563] [<ffffffff8160e4f0>] ? gs_change+0x13/0x13
[ 396.964566] ---[ end trace d76891b9559c3dcc ]---
[ 396.964741] Stopping Tx BA session for 30:46:9a:XX:XX:XX tid 0
[ 397.804618] Open BA session requested for 30:46:9a:XX:XX:XX tid 0
[ 397.844951] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 44 packets in HW queue
[ 397.844964] activated addBA response timer on tid 0
[ 397.847025] switched off addBA timer for tid 0
[ 399.230074] iwlwifi 0000:03:00.0: Queue 11 stuck for 2000 ms.
[ 399.230081] iwlwifi 0000:03:00.0: Current read_ptr 12 write_ptr 57
[ 399.230086] iwlwifi 0000:03:00.0: On demand firmware reload
[ 399.230449] ieee80211 phy1: Hardware restart was requested
[ 399.230536] iwlwifi 0000:03:00.0: L1 Disabled; Enabling L0S
[ 399.237213] iwlwifi 0000:03:00.0: Radio type=0x0-0x3-0x1

Best regards
Arnd


2011-11-22 09:04:38

by Arnd Hannemann

[permalink] [raw]
Subject: Re: 3.2.0-rc2: WARNING: at iwlwifi/wl-trans-pcie.c:1105

Hi,

additional to the WARNING wireless with iwlwifi seems to be very flaky on 3.2.0-rc2.
Ping to the AP goes up to 4-5s in some periods (with network generally idle).
Here is some more info about the Hardware:

[ 11.133719] iwlwifi 0000:03:00.0: HW Revision ID = 0x35
[ 11.133825] iwlwifi 0000:03:00.0: irq 46 for MSI/MSI-X
[ 11.133865] iwlwifi 0000:03:00.0: Detected Intel(R) Centrino(R) Ultimate-N 6300 AGN, REV=0x74
[ 11.133931] iwlwifi 0000:03:00.0: L1 Disabled; Enabling L0S
[ 11.150077] iwlwifi 0000:03:00.0: device EEPROM VER=0x436, CALIB=0x6
[ 11.150081] iwlwifi 0000:03:00.0: Device SKU: 0X1f0
[ 11.150083] iwlwifi 0000:03:00.0: Valid Tx ant: 0X7, Valid Rx ant: 0X7
[ 11.150648] iwlwifi 0000:03:00.0: Tunable channels: 13 802.11bg, 24 802.11a channels
[ 11.417837] iwlwifi 0000:03:00.0: loaded firmware version 9.221.4.1 build 25532

If you need some more info, please don't hesitate to ask.

Best regards
Arnd

2011-11-22 14:11:42

by Stanislaw Gruszka

[permalink] [raw]
Subject: Re: 3.2.0-rc2: WARNING: at iwlwifi/wl-trans-pcie.c:1105

On Tue, Nov 22, 2011 at 01:47:53PM +0200, Emmanuel Grumbach wrote:
> > additional to the WARNING wireless with iwlwifi seems to be very flaky on 3.2.0-rc2.
> Yeah I know about that one. I haven't found the time to look at it yet.
> I do have a patch that can help to debug. This patch will be sent
> through the regular channel.
> I am considering to remove the warning though

Just after the warning there is "Queue stuck" message, without warning
there will be no hint what is causing firmware hung.

Stanislaw

2011-11-23 20:51:00

by Arnd Hannemann

[permalink] [raw]
Subject: Re: 3.2.0-rc2: WARNING: at iwlwifi/wl-trans-pcie.c:1105

Am 22.11.2011 12:47, schrieb Emmanuel Grumbach:
>>
>> additional to the WARNING wireless with iwlwifi seems to be very flaky on 3.2.0-rc2.
>> Ping to the AP goes up to 4-5s in some periods (with network generally idle).
>> Here is some more info about the Hardware:
>>
>> [ 11.133719] iwlwifi 0000:03:00.0: HW Revision ID = 0x35
>> [ 11.133825] iwlwifi 0000:03:00.0: irq 46 for MSI/MSI-X
>> [ 11.133865] iwlwifi 0000:03:00.0: Detected Intel(R) Centrino(R) Ultimate-N 6300 AGN, REV=0x74
>> [ 11.133931] iwlwifi 0000:03:00.0: L1 Disabled; Enabling L0S
>> [ 11.150077] iwlwifi 0000:03:00.0: device EEPROM VER=0x436, CALIB=0x6
>> [ 11.150081] iwlwifi 0000:03:00.0: Device SKU: 0X1f0
>> [ 11.150083] iwlwifi 0000:03:00.0: Valid Tx ant: 0X7, Valid Rx ant: 0X7
>> [ 11.150648] iwlwifi 0000:03:00.0: Tunable channels: 13 802.11bg, 24 802.11a channels
>> [ 11.417837] iwlwifi 0000:03:00.0: loaded firmware version 9.221.4.1 build 25532
>>
>> If you need some more info, please don't hesitate to ask.
>>
>
> Yeah I know about that one. I haven't found the time to look at it yet.
> I do have a patch that can help to debug. This patch will be sent
> through the regular channel.
> I am considering to remove the warning though

I applied the QUEUE_DEBUG.patch you posted in the other thread, not sure if I'm experiencing the same problem:


[38275.502526] iwlwifi 0000:03:00.0: Tx aggregation enabled on ra = 30:46:9a:XX:XX:XX tid = 0
[38283.406370] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_disable HW queue is empty
[38283.406460] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
[38290.363252] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is empty
[38291.358619] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_disable HW queue is empty
[38291.358713] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
[38296.788459] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate BA Queue 11 on FIFO 1
[38296.788475] iwlwifi 0000:03:00.0: Tx aggregation enabled on ra = 30:46:9a:XX:XX:XX tid = 0
[38296.788489] ------------[ cut here ]------------
[38296.788518] WARNING: at /home/arnd/Projekte/kernel/linux-2.6/drivers/net/wireless/iwlwifi/iwl-trans-pcie.c:1106 iwl_trans_pcie_tx+0xb71/0xb90 [iwlwifi]()
[38296.788526] Hardware name: 4384GEG
[38296.788529] Modules linked in: iwlwifi ip6table_filter ip6_tables bnep rfcomm ipt_MASQUERADE iptable_nat nf_nat nf_conntrack_ipv4 nf_defrag_ipv4 xt_state nf_conntrack ipt_REJECT xt_CHECKSUM iptable_mangle xt_tcpudp iptable_filter ip_tables x_tables bridge stp llc kvm_intel kvm joydev dm_crypt snd_hda_codec_hdmi snd_hda_codec_conexant snd_hda_intel snd_hda_codec snd_hwdep snd_pcm arc4 snd_seq_midi snd_rawmidi binfmt_misc snd_seq_midi_event psmouse qcserial usb_wwan serio_raw snd_seq usbserial intel_ips btusb snd_timer snd_seq_device bluetooth mac80211 tpm_tis thinkpad_acpi cfg80211 nvram snd mei(C) soundcore snd_page_alloc btrfs zlib_deflate libcrc32c mxm_wmi e1000e ahci libahci sdhci_pci sdhci firewire_ohci i915 firewire_core drm_kms_helper crc_itu_t drm i2c_algo_bit wmi video [last unloaded: iwlwifi]
[38296.788663] Pid: 6243, comm: kworker/u:23 Tainted: G WC 3.2.0-rc2-aha+ #7
[38296.788668] Call Trace:
[38296.788672] <IRQ> [<ffffffff81062b9f>] warn_slowpath_common+0x7f/0xc0
[38296.788690] [<ffffffff81062bfa>] warn_slowpath_null+0x1a/0x20
[38296.788712] [<ffffffffa0580fd1>] iwl_trans_pcie_tx+0xb71/0xb90 [iwlwifi]
[38296.788724] [<ffffffff814f2b1d>] ? consume_skb+0x3d/0xb0
[38296.788749] [<ffffffffa028a0c8>] ? ccmp_encrypt_skb.isra.4+0x108/0x230 [mac80211]
[38296.788759] [<ffffffff8105a592>] ? default_wake_function+0x12/0x20
[38296.788767] [<ffffffff81086100>] ? remove_wait_queue+0x60/0x70
[38296.788784] [<ffffffffa05623e1>] ? iwlagn_tx_skb+0x161/0xb90 [iwlwifi]
[38296.788802] [<ffffffffa056277f>] iwlagn_tx_skb+0x4ff/0xb90 [iwlwifi]
[38296.788815] [<ffffffffa0559491>] iwlagn_mac_tx+0x121/0x1c0 [iwlwifi]
[38296.788824] [<ffffffff8103aa39>] ? default_spin_lock_flags+0x9/0x10
[38296.788849] [<ffffffffa02a2506>] __ieee80211_tx+0x76/0x230 [mac80211]
[38296.788873] [<ffffffffa02a451c>] ieee80211_tx+0x8c/0xc0 [mac80211]
[38296.788896] [<ffffffffa02a53fd>] ieee80211_tx_pending+0x7d/0x220 [mac80211]
[38296.788905] [<ffffffff8106a20d>] ? __do_softirq+0xfd/0x210
[38296.788913] [<ffffffff81069b78>] tasklet_action+0x78/0x140
[38296.788920] [<ffffffff8106a1b8>] __do_softirq+0xa8/0x210
[38296.788930] [<ffffffff8160e5ac>] call_softirq+0x1c/0x30
[38296.788934] <EOI> [<ffffffff81015195>] do_softirq+0x65/0xa0
[38296.788950] [<ffffffff8106a104>] local_bh_enable_ip+0x94/0xa0
[38296.788958] [<ffffffff816043f9>] _raw_spin_unlock_bh+0x19/0x20
[38296.788980] [<ffffffffa028d8a9>] ieee80211_agg_tx_operational+0xb9/0xd0 [mac80211]
[38296.789002] [<ffffffffa0296a78>] ? ieee80211_iface_work+0xd8/0x350 [mac80211]
[38296.789023] [<ffffffffa028e0fe>] ieee80211_process_addba_resp+0x11e/0x120 [mac80211]
[38296.789045] [<ffffffffa0296c9f>] ieee80211_iface_work+0x2ff/0x350 [mac80211]
[38296.789068] [<ffffffffa02969a0>] ? ieee80211_teardown_sdata+0xe0/0xe0 [mac80211]
[38296.789078] [<ffffffff8108023a>] process_one_work+0x11a/0x480
[38296.789085] [<ffffffff81080fc4>] worker_thread+0x164/0x370
[38296.789093] [<ffffffff81080e60>] ? manage_workers.isra.30+0x230/0x230
[38296.789099] [<ffffffff8108573c>] kthread+0x8c/0xa0
[38296.789105] [<ffffffff8160e4b4>] kernel_thread_helper+0x4/0x10
[38296.789111] [<ffffffff810856b0>] ? flush_kthread_worker+0xa0/0xa0
[38296.789119] [<ffffffff8160e4b0>] ? gs_change+0x13/0x13
[38296.789123] ---[ end trace 201230ed6208edbf ]---
[38298.939515] iwlwifi 0000:03:00.0: Queue 11 stuck for 2000 ms.
[38298.939523] iwlwifi 0000:03:00.0: Current read_ptr 197 write_ptr 2
[38298.939528] iwlwifi 0000:03:00.0: On demand firmware reload
[38298.939926] ieee80211 phy3: Hardware restart was requested
[38298.940032] iwlwifi 0000:03:00.0: L1 Disabled; Enabling L0S
[38298.940167] iwlwifi 0000:03:00.0: Radio type=0x0-0x3-0x1
[38299.006160] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Activate AC/CMD Queue 0 on FIFO 3
[38299.006180] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Activate AC/CMD Queue 1 on FIFO 2
[38299.006197] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Activate AC/CMD Queue 2 on FIFO 1
[38299.006214] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Activate AC/CMD Queue 3 on FIFO 0
[38299.006230] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Activate AC/CMD Queue 4 on FIFO 7
[38301.596322] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 60 packets in HW queue
[38306.705156] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
[38306.820030] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 60 packets in HW queue
[38311.921881] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
[38312.027099] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 70 packets in HW queue
[38317.138756] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
[38317.235476] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 140 packets in HW queue
[38322.424187] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
[38322.767875] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 60 packets in HW queue
[38327.939631] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
[38328.086516] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 60 packets in HW queue
[38333.251181] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
[38333.540666] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 60 packets in HW queue
[38338.766575] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
[38338.969220] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 60 packets in HW queue
[38344.282421] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
[38344.409610] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 60 packets in HW queue
[38349.593755] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
[38349.680482] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 60 packets in HW queue
[38354.905092] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
[38355.233118] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 60 packets in HW queue
[38360.420658] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
[38361.314785] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 60 packets in HW queue
[38376.705700] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
[38377.554487] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 59 packets in HW queue
[38382.687399] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
[38383.068691] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 59 packets in HW queue
[38388.203087] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
[38388.297090] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 59 packets in HW queue
[38393.514383] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
[38393.609374] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 69 packets in HW queue
[38398.825772] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
[38399.038167] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 59 packets in HW queue
[38404.138245] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
[38404.794215] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 59 packets in HW queue
[38410.061196] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
[38411.198133] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 59 packets in HW queue
[38416.393938] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
[38416.527477] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 110 packets in HW queue
[38421.705324] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
[38421.797204] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 87 packets in HW queue
[38427.016619] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
[38429.109294] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 59 packets in HW queue
[38434.211841] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
[38435.229973] iwlwifi 0000:03:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 59 packets in HW queue
[38473.797319] wlan0: deauthenticated from 30:46:9a:XX:XX:XX (Reason: 7)
[38473.797417] iwlwifi 0000:03:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0
[38473.819945] iwlwifi 0000:03:00.0: Stopping AGG while state not ON or starting for 0 on 0 (0)

Best regards,
Arnd

2011-11-22 11:47:55

by Emmanuel Grumbach

[permalink] [raw]
Subject: Re: 3.2.0-rc2: WARNING: at iwlwifi/wl-trans-pcie.c:1105

>
> additional to the WARNING wireless with iwlwifi seems to be very flaky on 3.2.0-rc2.
> Ping to the AP goes up to 4-5s in some periods (with network generally idle).
> Here is some more info about the Hardware:
>
> [ ? 11.133719] iwlwifi 0000:03:00.0: HW Revision ID = 0x35
> [ ? 11.133825] iwlwifi 0000:03:00.0: irq 46 for MSI/MSI-X
> [ ? 11.133865] iwlwifi 0000:03:00.0: Detected Intel(R) Centrino(R) Ultimate-N 6300 AGN, REV=0x74
> [ ? 11.133931] iwlwifi 0000:03:00.0: L1 Disabled; Enabling L0S
> [ ? 11.150077] iwlwifi 0000:03:00.0: device EEPROM VER=0x436, CALIB=0x6
> [ ? 11.150081] iwlwifi 0000:03:00.0: Device SKU: 0X1f0
> [ ? 11.150083] iwlwifi 0000:03:00.0: Valid Tx ant: 0X7, Valid Rx ant: 0X7
> [ ? 11.150648] iwlwifi 0000:03:00.0: Tunable channels: 13 802.11bg, 24 802.11a channels
> [ ? 11.417837] iwlwifi 0000:03:00.0: loaded firmware version 9.221.4.1 build 25532
>
> If you need some more info, please don't hesitate to ask.
>

Yeah I know about that one. I haven't found the time to look at it yet.
I do have a patch that can help to debug. This patch will be sent
through the regular channel.
I am considering to remove the warning though

2011-12-01 19:17:37

by Arnd Hannemann

[permalink] [raw]
Subject: Re: 3.2.0-rc2: WARNING: at iwlwifi/wl-trans-pcie.c:1105

Am 29.11.2011 10:50, schrieb Emmanuel Grumbach:
> On Thu, Nov 24, 2011 at 23:55, Arnd Hannemann <[email protected]> wrote:
>> Hi,
>>
>> Am 24.11.2011 07:23, schrieb Emmanuel Grumbach:
>>>>
>>>> I applied the QUEUE_DEBUG.patch you posted in the other thread, not sure if I'm experiencing the same problem:
>>>
>>> Yes, it looks similar. Please enable the MAC80211_HT_DEBUG compilation flag too.
>>> In any case now that I more the less see what is happening, I am
>>> working now on another debug patch.
>>
...

> Sorry, somehow I saw the mail only now. This one should make it
>
> http://www.spinics.net/lists/linux-wireless/msg81131.html

JFYI: I'm currently running on Linus git from Monday (last commit 4244cb482e8eab18142162a27c8829a04585863a)
for a while now and didn't have seen this Warning yet, nor did I experience the described lag.
Maybe some other patch might already have fixed it or at least lessen the probability for the
previous bug to occur.

Best regards
Arnd