| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Message-ID: <CANUX_P1hFzSVPQzd6gq3tLY7hu+LX5suph6uHP+hq6+7rdAK1w@mail.gmail.com> Date: Fri, 25 Nov 2011 14:31:14 +0200 From: Emmanuel Grumbach <egrumbach@...il.com> To: Norbert Preining <preining@...ic.at> Cc: "Guy, Wey-Yi" <wey-yi.w.guy@...el.com>, David Rientjes <rientjes@...gle.com>, "linux-kernel@...r.kernel.org" <linux-kernel@...r.kernel.org>, "ipw3945-devel@...ts.sourceforge.net" <ipw3945-devel@...ts.sourceforge.net>, "ilw@...ux.intel.com" <ilw@...ux.intel.com>, "linux-wireless@...r.kernel.org" <linux-wireless@...r.kernel.org>, Pekka Enberg <penberg@...helsinki.fi>, Dave Jones <davej@...hat.com> Subject: Re: iwlagn is getting very shaky On Fri, Nov 25, 2011 at 14:21, Norbert Preining <preining@...ic.at> wrote: > Hi Emmanuel, > > On Do, 24 Nov 2011, Emmanuel Grumbach wrote: >> Please apply the patch attached on top of the one I previously sent. >> Let me know I you have trouble with patch. > > The patch you sent was not against kernel git, but I moved the > debug statement from iwl-mac80211.c to iwl-agn.c (where I guess is > the right place) and applied the rest of the patch. Thanks for doing the porting job :-) > >> Please also enable the MAC80211_HT_DEBUG compilation flag >> I also the (HT + TXQUEUES) debug flag of the driver: modprobe iwlwifi >> debug=0x84000000 > > Also activated. > cool > Here my very very small theory, but that is just guessing: Could it > be related to the time being adjusted by ntp or something? I have the > feeling it works for a bit, then hangs. In this little bit it might > be that ntp updates the time of the laptop. That would explain why > on a full normal reboot it most of the times work, but when the laptop > sleeps for long time, or is turned of for long time, then it is > getting problems. But this is surely just a stupid theory. > Well.. All this is really Layer 2 related, and even lower. It is a kind of bad handshake between the driver / HW / mac80211. So I wouldn't think that NTP may hurt here. Although one should never underestimate the damage a piece of software can do.... > Here we go with the debug output > > > [ 4592.437269] iwlwifi 0000:06:00.0: L1 Enabled; Disabling L0S > [ 4592.441080] iwlwifi 0000:06:00.0: Radio type=0x1-0x2-0x0 > [ 4592.482332] iwlwifi 0000:06:00.0: U iwl_txq_ctx_activate Activate txq 0 > [ 4592.482346] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Activate AC/CMD Queue 0 on FIFO 3 > [ 4592.482349] iwlwifi 0000:06:00.0: U iwl_txq_ctx_activate Activate txq 1 > [ 4592.482362] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Activate AC/CMD Queue 1 on FIFO 2 > [ 4592.482365] iwlwifi 0000:06:00.0: U iwl_txq_ctx_activate Activate txq 2 > [ 4592.482377] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Activate AC/CMD Queue 2 on FIFO 1 > [ 4592.482380] iwlwifi 0000:06:00.0: U iwl_txq_ctx_activate Activate txq 3 > [ 4592.482392] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Activate AC/CMD Queue 3 on FIFO 0 > [ 4592.482395] iwlwifi 0000:06:00.0: U iwl_txq_ctx_activate Activate txq 4 > [ 4592.482407] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Activate AC/CMD Queue 4 on FIFO 7 > [ 4592.482410] iwlwifi 0000:06:00.0: U iwl_txq_ctx_activate Activate txq 5 > [ 4592.482412] iwlwifi 0000:06:00.0: U iwl_txq_ctx_activate Activate txq 6 > [ 4592.482415] iwlwifi 0000:06:00.0: U iwl_txq_ctx_activate Activate txq 7 > [ 4592.482417] iwlwifi 0000:06:00.0: U iwl_txq_ctx_activate Activate txq 8 > [ 4592.482419] iwlwifi 0000:06:00.0: U iwl_txq_ctx_activate Activate txq 9 > [ 4592.482422] iwlwifi 0000:06:00.0: U iwl_txq_ctx_activate Activate txq 10 > [ 4600.139699] wlan0: authenticate with 00:0a:79:eb:56:10 (try 1) > [ 4600.142190] wlan0: authenticated > [ 4600.148081] wlan0: associate with 00:0a:79:eb:56:10 (try 1) > [ 4600.153962] wlan0: RX AssocResp from 00:0a:79:eb:56:10 (capab=0x411 status=0 aid=2) > [ 4600.153972] wlan0: associated > [ 4601.280512] iwlwifi 0000:06:00.0: U iwlagn_mac_ampdu_action A-MPDU action on addr 00:0a:79:eb:56:10 tid 0 > [ 4601.280525] iwlwifi 0000:06:00.0: U iwlagn_mac_ampdu_action start Rx > [ 4616.622380] iwlwifi 0000:06:00.0: I rs_tl_turn_on_agg_for_tid Starting Tx agg: STA: 00:0a:79:eb:56:10 tid: 0 > [ 4616.652083] iwlwifi 0000:06:00.0: U iwlagn_mac_ampdu_action A-MPDU action on addr 00:0a:79:eb:56:10 tid 0 > [ 4616.652087] iwlwifi 0000:06:00.0: U iwlagn_mac_ampdu_action start Tx > [ 4616.652090] iwlwifi 0000:06:00.0: U iwlagn_tx_agg_start TX AGG request on ra = 00:0a:79:eb:56:10 tid = 0 > [ 4616.652238] iwlwifi 0000:06:00.0: U iwlagn_txq_ctx_activate_free Activate txq 11 > [ 4616.652241] iwlwifi 0000:06:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is empty > [ 4616.652244] iwlwifi 0000:06:00.0: U iwl_start_tx_ba_trans_ready Telling mac start BA ready tid: 0 > [ 4617.652070] iwlwifi 0000:06:00.0: U iwlagn_mac_ampdu_action A-MPDU action on addr 00:0a:79:eb:56:10 tid 0 > [ 4617.652075] iwlwifi 0000:06:00.0: U iwlagn_mac_ampdu_action stop Tx > [ 4617.652077] iwlwifi 0000:06:00.0: U iwlagn_mac_ampdu_action Stop Tx agg for tid 0 > [ 4617.652081] iwlwifi 0000:06:00.0: U iwl_trans_pcie_tx_agg_disable HW queue is empty > [ 4617.652139] iwlwifi 0000:06:00.0: U iwl_trans_pcie_txq_agg_disable Disable AGG txq_id 11 > [ 4617.652192] iwlwifi 0000:06:00.0: U iwl_txq_ctx_deactivate Deactivate txq 11 > [ 4617.652210] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0 > [ 4617.652213] iwlwifi 0000:06:00.0: U iwl_stop_tx_ba_trans_ready Telling mac stop BA ready tid: 0 > [ 4621.013744] iwlwifi 0000:06:00.0: U iwlagn_mac_ampdu_action A-MPDU action on addr 00:0a:79:eb:56:10 tid 0 > [ 4621.013760] iwlwifi 0000:06:00.0: U iwl_trans_pcie_tx_agg_setup Setup AGG for tid 0 > [ 4621.013916] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Deactivate BA Queue 11 on FIFO 1 > [ 4621.013925] iwlwifi 0000:06:00.0: U iwlagn_mac_ampdu_action priv->agg_tids_count = 1 > [ 4621.013937] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 0 Thanks I am already on week-end here and will look at it more carefully later. First impression is that things are messy here. I guess we are getting in a bad failure path that wasn't checked... > [ 4621.013954] ------------[ cut here ]------------ > [ 4621.013991] WARNING: at drivers/net/wireless/iwlwifi/iwl-trans-pcie.c:1106 iwl_trans_pcie_tx+0x180/0x668 [iwlwifi]() > [ 4621.013999] Hardware name: VGN-Z11VN_B > [ 4621.014004] Modules linked in: usb_storage rfcomm bnep vboxpci(O) vboxnetadp(O) vboxnetflt(O) vboxdrv(O) snd_hrtimer binfmt_misc dm_crypt dm_mod isofs btrfs zlib_deflate crc32c libcrc32c vfat fat fuse loop uinput snd_hda_codec_realtek snd_hda_intel snd_hda_codec snd_hwdep snd_pcm_oss snd_mixer_oss arc4 snd_pcm iwlwifi mac80211 snd_seq_dummy snd_seq_oss snd_seq_midi snd_rawmidi snd_seq_midi_event btusb sony_laptop(O) bluetooth snd_seq snd_timer snd_seq_device snd soundcore cfg80211 firewire_ohci firewire_core mxm_wmi joydev rfkill tpm_infineon snd_page_alloc crc16 crc_itu_t > [ 4621.014134] Pid: 6169, comm: kworker/u:44 Tainted: G W O 3.2.0-rc3+ #2 > [ 4621.014140] Call Trace: > [ 4621.014145] <IRQ> [<ffffffff8103849d>] warn_slowpath_common+0x83/0x9b > [ 4621.014171] [<ffffffff810384cf>] warn_slowpath_null+0x1a/0x1c > [ 4621.014194] [<ffffffffa0204f4d>] iwl_trans_pcie_tx+0x180/0x668 [iwlwifi] > [ 4621.014208] [<ffffffff810d3861>] ? kmem_cache_alloc+0x44/0xb9 > [ 4621.014229] [<ffffffffa01eca7d>] iwlagn_tx_skb+0x87b/0x91b [iwlwifi] > [ 4621.014247] [<ffffffffa01e2fea>] iwlagn_mac_tx+0x131/0x1a2 [iwlwifi] > [ 4621.014268] [<ffffffffa01c1cc6>] ? ieee80211_tx_h_fragment+0x16/0x22c [mac80211] > [ 4621.014296] [<ffffffffa01b6000>] __ieee80211_tx+0x176/0x1cf [mac80211] > [ 4621.014314] [<ffffffffa01c1c38>] ? ieee80211_tx_h_calculate_duration+0x4c/0x65 [mac80211] > [ 4621.014344] [<ffffffffa01b6dc6>] ieee80211_tx+0x97/0xaf [mac80211] > [ 4621.014374] [<ffffffffa01b7cc2>] ieee80211_tx_pending+0xf0/0x1c3 [mac80211] > [ 4621.014386] [<ffffffff8103dc16>] tasklet_action+0x77/0xc2 > [ 4621.014395] [<ffffffff8103dd57>] __do_softirq+0xbc/0x1a5 > [ 4621.014408] [<ffffffff8140b24c>] call_softirq+0x1c/0x30 > [ 4621.014413] <EOI> [<ffffffff8100359e>] do_softirq+0x38/0x6e > [ 4621.014430] [<ffffffff8103da1d>] _local_bh_enable_ip.isra.12+0x7d/0xa0 > [ 4621.014439] [<ffffffff8103da4e>] local_bh_enable_ip+0xe/0x10 > [ 4621.014448] [<ffffffff81409462>] _raw_spin_unlock_bh+0x23/0x25 > [ 4621.014471] [<ffffffffa01a5c6c>] ieee80211_agg_tx_operational+0x99/0xa4 [mac80211] > [ 4621.014496] [<ffffffffa01a67bd>] ieee80211_process_addba_resp+0xb8/0xf3 [mac80211] > [ 4621.014508] [<ffffffff81064840>] ? do_raw_spin_trylock+0x18/0x2a > [ 4621.014534] [<ffffffffa01adada>] ieee80211_iface_work+0x130/0x2b5 [mac80211] > [ 4621.014560] [<ffffffffa01ad9aa>] ? ieee80211_teardown_sdata+0xcc/0xcc [mac80211] > [ 4621.014572] [<ffffffff8104de54>] process_one_work+0x17b/0x2bd > [ 4621.014583] [<ffffffff8104c499>] ? need_to_create_worker+0x12/0x26 > [ 4621.014593] [<ffffffff8104ef4f>] worker_thread+0xdb/0x15f > [ 4621.014602] [<ffffffff8104ee74>] ? manage_workers.isra.24+0x171/0x171 > [ 4621.014612] [<ffffffff81052639>] kthread+0x84/0x8c > [ 4621.014622] [<ffffffff8140b154>] kernel_thread_helper+0x4/0x10 > [ 4621.014633] [<ffffffff810525b5>] ? kthread_worker_fn+0x148/0x148 > [ 4621.014642] [<ffffffff8140b150>] ? gs_change+0xb/0xb > [ 4621.014649] ---[ end trace 81df68812429b16c ]--- > [ 4622.112804] iwlwifi 0000:06:00.0: I rs_tl_turn_on_agg_for_tid Starting Tx agg: STA: 00:0a:79:eb:56:10 tid: 0 > [ 4622.124104] iwlwifi 0000:06:00.0: U iwlagn_mac_ampdu_action A-MPDU action on addr 00:0a:79:eb:56:10 tid 0 > [ 4622.124116] iwlwifi 0000:06:00.0: U iwlagn_mac_ampdu_action start Tx > [ 4622.124126] iwlwifi 0000:06:00.0: U iwlagn_tx_agg_start TX AGG request on ra = 00:0a:79:eb:56:10 tid = 0 > [ 4622.124304] iwlwifi 0000:06:00.0: U iwlagn_txq_ctx_activate_free Activate txq 11 > [ 4622.124315] iwlwifi 0000:06:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 21 packets in HW queue > [ 4630.040070] iwlwifi 0000:06:00.0: Queue 11 stuck for 10000 ms. > [ 4630.040081] iwlwifi 0000:06:00.0: Current SW read_ptr 242 write_ptr 8 > [ 4630.040136] iwlwifi 0000:06:00.0: Current HW read_ptr 242 write_ptr 8 > [ 4630.040144] iwlwifi 0000:06:00.0: On demand firmware reload > [ 4630.040587] ieee80211 phy0: Hardware restart was requested > [ 4630.040698] iwlwifi 0000:06:00.0: L1 Enabled; Disabling L0S > [ 4630.043703] iwlwifi 0000:06:00.0: Radio type=0x1-0x2-0x0 > [ 4630.086602] iwlwifi 0000:06:00.0: U iwl_txq_ctx_activate Activate txq 0 > [ 4630.086624] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Activate AC/CMD Queue 0 on FIFO 3 > [ 4630.086634] iwlwifi 0000:06:00.0: U iwl_txq_ctx_activate Activate txq 1 > [ 4630.086653] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Activate AC/CMD Queue 1 on FIFO 2 > [ 4630.086662] iwlwifi 0000:06:00.0: U iwl_txq_ctx_activate Activate txq 2 > [ 4630.086681] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Activate AC/CMD Queue 2 on FIFO 1 > [ 4630.086690] iwlwifi 0000:06:00.0: U iwl_txq_ctx_activate Activate txq 3 > [ 4630.086709] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Activate AC/CMD Queue 3 on FIFO 0 > [ 4630.086717] iwlwifi 0000:06:00.0: U iwl_txq_ctx_activate Activate txq 4 > [ 4630.086736] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Activate AC/CMD Queue 4 on FIFO 7 > [ 4630.086745] iwlwifi 0000:06:00.0: U iwl_txq_ctx_activate Activate txq 5 > [ 4630.086752] iwlwifi 0000:06:00.0: U iwl_txq_ctx_activate Activate txq 6 > [ 4630.086759] iwlwifi 0000:06:00.0: U iwl_txq_ctx_activate Activate txq 7 > [ 4630.086767] iwlwifi 0000:06:00.0: U iwl_txq_ctx_activate Activate txq 8 > [ 4630.086774] iwlwifi 0000:06:00.0: U iwl_txq_ctx_activate Activate txq 9 > [ 4630.086781] iwlwifi 0000:06:00.0: U iwl_txq_ctx_activate Activate txq 10 > [ 4630.157921] iwlwifi 0000:06:00.0: U iwlagn_mac_ampdu_action A-MPDU action on addr 00:0a:79:eb:56:10 tid 0 > [ 4630.157933] iwlwifi 0000:06:00.0: U iwlagn_mac_ampdu_action stop Tx > [ 4630.157942] iwlwifi 0000:06:00.0: U iwlagn_mac_ampdu_action Stop Tx agg for tid 0 > [ 4630.157951] iwlwifi 0000:06:00.0: U iwl_trans_pcie_tx_agg_disable AGG stop before setup done > [ 4630.157992] iwlwifi 0000:06:00.0: U iwl_trans_pcie_txq_agg_disable Disable AGG txq_id 11 > [ 4630.158073] iwlwifi 0000:06:00.0: U iwl_txq_ctx_deactivate Deactivate txq 11 > [ 4630.158113] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Deactivate AC/CMD Queue 11 on FIFO 0 > [ 4630.158123] iwlwifi 0000:06:00.0: U iwl_stop_tx_ba_trans_ready Telling mac stop BA ready tid: 0 > [ 4630.158136] iwlwifi 0000:06:00.0: U iwlagn_mac_ampdu_action priv->agg_tids_count = 0 > [ 4630.158148] iwlwifi 0000:06:00.0: U iwlagn_mac_ampdu_action A-MPDU action on addr 00:0a:79:eb:56:10 tid 0 > [ 4630.158157] iwlwifi 0000:06:00.0: U iwlagn_mac_ampdu_action stop Rx > [ 4630.196845] iwlwifi 0000:06:00.0: U iwlagn_mac_ampdu_action A-MPDU action on addr 00:0a:79:eb:56:10 tid 0 > [ 4630.196857] iwlwifi 0000:06:00.0: U iwlagn_mac_ampdu_action start Rx > [ 4632.759183] iwlwifi 0000:06:00.0: I rs_tl_turn_on_agg_for_tid Starting Tx agg: STA: 00:0a:79:eb:56:10 tid: 0 > [ 4632.812124] iwlwifi 0000:06:00.0: U iwlagn_mac_ampdu_action A-MPDU action on addr 00:0a:79:eb:56:10 tid 0 > [ 4632.812136] iwlwifi 0000:06:00.0: U iwlagn_mac_ampdu_action start Tx > [ 4632.812145] iwlwifi 0000:06:00.0: U iwlagn_tx_agg_start TX AGG request on ra = 00:0a:79:eb:56:10 tid = 0 > [ 4632.812326] iwlwifi 0000:06:00.0: U iwlagn_txq_ctx_activate_free Activate txq 11 > [ 4632.812337] iwlwifi 0000:06:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is NOT empty: 21 packets in HW queue > [ 4634.916847] iwlwifi 0000:06:00.0: U iwlagn_mac_ampdu_action A-MPDU action on addr 00:0a:79:eb:56:10 tid 6 > [ 4634.916860] iwlwifi 0000:06:00.0: U iwlagn_mac_ampdu_action start Rx > [ 4644.716439] iwlwifi 0000:06:00.0: I rs_tl_turn_on_agg_for_tid Starting Tx agg: STA: 00:0a:79:eb:56:10 tid: 6 > [ 4644.764120] iwlwifi 0000:06:00.0: U iwlagn_mac_ampdu_action A-MPDU action on addr 00:0a:79:eb:56:10 tid 6 > [ 4644.764132] iwlwifi 0000:06:00.0: U iwlagn_mac_ampdu_action start Tx > [ 4644.764142] iwlwifi 0000:06:00.0: U iwlagn_tx_agg_start TX AGG request on ra = 00:0a:79:eb:56:10 tid = 6 > [ 4644.764306] iwlwifi 0000:06:00.0: U iwlagn_txq_ctx_activate_free Activate txq 12 > [ 4644.764315] iwlwifi 0000:06:00.0: U iwl_trans_pcie_tx_agg_alloc HW queue is empty > [ 4644.764325] iwlwifi 0000:06:00.0: U iwl_start_tx_ba_trans_ready Telling mac start BA ready tid: 6 > [ 4644.766328] iwlwifi 0000:06:00.0: U iwlagn_mac_ampdu_action A-MPDU action on addr 00:0a:79:eb:56:10 tid 6 > [ 4644.766339] iwlwifi 0000:06:00.0: U iwl_trans_pcie_tx_agg_setup Setup AGG for tid 6 > [ 4644.766494] iwlwifi 0000:06:00.0: U iwl_trans_tx_queue_set_status Activate BA Queue 12 on FIFO 3 > [ 4644.766503] iwlwifi 0000:06:00.0: U iwlagn_mac_ampdu_action priv->agg_tids_count = 1 > [ 4644.766549] iwlwifi 0000:06:00.0: Tx aggregation enabled on ra = 00:0a:79:eb:56:10 tid = 6 > [ 4703.713625] iwlwifi 0000:06:00.0: I iwlagn_rx_reply_compressed_ba agg frames sent:2, acked:2 > > > Best wishes > > Norbert > ------------------------------------------------------------------------ > Norbert Preining preining@...ist.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 > ------------------------------------------------------------------------ > BRISBANE > A perfectly reasonable explanation (Such as the one offered by a > person with a gurgling cough which has nothing to do with the fact > that they smoke fifty cigarettes a day.) > --- Douglas Adams, The Meaning of Liff > -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo@...r.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Powered by blists - more mailing lists