Bug 85691

Summary: iwlwifi iwlmvm WARN: Got an HT rate for a non data frame 0x8 (drivers/net/wireless/iwlwifi/mvm/tx.c:190 iwl_mvm_set_tx_params)
Product: Drivers Reporter: Dmitry Nezhevenko (dion)
Component: network-wirelessAssignee: drivers_network-wireless (drivers_network-wireless)
Status: CLOSED CODE_FIX    
Severity: normal CC: david, ilw, linville, stalkerg
Priority: P3    
Hardware: All   
OS: Linux   
Kernel Version: 3.17 Subsystem:
Regression: No Bisected commit-id:
Attachments: dmesg
trace.dat

Description Dmitry Nezhevenko 2014-10-06 17:12:40 UTC
After updating kernel 3.16 -> 3.17 I'm getting followed warning on Lenovo t440p machine:

430.914690] ------------[ cut here ]------------
[  430.914703] WARNING: CPU: 0 PID: 3946 at drivers/net/wireless/iwlwifi/mvm/tx.c:190 iwl_mvm_set_tx_params+0x60a/0x6f0 [iwlmvm]()
[  430.914704] Got an HT rate for a non data frame 0x8
[  430.914704] Modules linked in: hid_generic hid_microsoft usbhid hid snd_usb_audio snd_usbmidi_lib snd_rawmidi snd_seq_device xhci_hcd tun ctr ccm bnep acpi_call(O) nfsd auth_rpcgss oid_registry nfs_acl nfs lockd fscache sunrpc nls_utf8 nls_cp437 vfat fat snd_hda_codec_realtek snd_hda_codec_generic snd_hda_codec_hdmi arc4 uvcvideo videobuf2_vmalloc videobuf2_memops videobuf2_core btusb v4l2_common bluetooth videodev iwlmvm media mac80211 iwlwifi iTCO_wdt joydev iTCO_vendor_support x86_pkg_temp_thermal intel_powerclamp snd_hda_intel snd_hda_controller intel_rapl snd_hda_codec cfg80211 i915 snd_hwdep coretemp thinkpad_acpi snd_pcm nvram kvm_intel kvm rfkill snd_timer snd psmouse soundcore mei_me mei rtsx_pci_ms evdev rtc_efi drm_kms_helper serio_raw memstick pcspkr efivars ie31200_edac drm edac_core
[  430.914730]  i2c_algo_bit tpm_tis shpchp tpm i2c_i801 lpc_ich video battery ac processor wmi button i2c_dev i2c_core fuse parport_pc ppdev lp parport autofs4 algif_skcipher af_alg dm_crypt dm_mod uhci_hcd ohci_hcd usb_storage ext4 crc16 mbcache jbd2 sg sd_mod sr_mod crc_t10dif cdrom crct10dif_generic rtsx_pci_sdmmc mmc_core crct10dif_pclmul crct10dif_common crc32_pclmul crc32c_intel ghash_clmulni_intel ahci libahci ehci_pci libata aesni_intel ehci_hcd aes_x86_64 lrw gf128mul glue_helper ablk_helper e1000e cryptd rtsx_pci ptp scsi_mod mfd_core usbcore pps_core usb_common thermal thermal_sys [last unloaded: xhci_hcd]
[  430.914753] CPU: 0 PID: 3946 Comm: wpa_supplicant Tainted: G           O   3.17.0+ #6
[  430.914754] Hardware name: LENOVO 20ANCTO1WW/20ANCTO1WW, BIOS GLET71WW (2.25 ) 07/02/2014
[  430.914755]  0000000000000009 ffffffff814fa911 ffff8804288db8f8 ffffffff81064f52
[  430.914756]  0000000000001808 ffff8804288db948 ffff88040add8660 ffff8804291b5600
[  430.914758]  0000000000000000 ffffffff81064fb7 ffffffffa07b73d0 0000000000000020
[  430.914759] Call Trace:
[  430.914763]  [<ffffffff814fa911>] ? dump_stack+0x41/0x51
[  430.914775]  [<ffffffff81064f52>] ? warn_slowpath_common+0x72/0x90
[  430.914777]  [<ffffffff81064fb7>] ? warn_slowpath_fmt+0x47/0x50
[  430.914780]  [<ffffffffa07a39ea>] ? iwl_mvm_set_tx_params+0x60a/0x6f0 [iwlmvm]
[  430.914783]  [<ffffffffa07a3cf8>] ? iwl_mvm_tx_skb+0x48/0x3c0 [iwlmvm]
[  430.914785]  [<ffffffffa079cb9b>] ? iwl_mvm_mac_tx+0x7b/0x180 [iwlmvm]
[  430.914791]  [<ffffffffa0746ce9>] ? __ieee80211_tx+0x2b9/0x3c0 [mac80211]
[  430.914795]  [<ffffffffa07492f3>] ? ieee80211_tx+0xb3/0x100 [mac80211]
[  430.914799]  [<ffffffffa0749c49>] ? ieee80211_subif_start_xmit+0x459/0xca0 [mac80211]
[  430.914803]  [<ffffffff814116e7>] ? dev_hard_start_xmit+0x337/0x5f0
[  430.914805]  [<ffffffff81430d46>] ? sch_direct_xmit+0x96/0x1f0
[  430.914806]  [<ffffffff81411ba3>] ? __dev_queue_xmit+0x203/0x4f0
[  430.914809]  [<ffffffff8142f670>] ? ether_setup+0x70/0x70
[  430.914811]  [<ffffffff814e96a1>] ? packet_sendmsg+0xf81/0x1110
[  430.914814]  [<ffffffff8140625c>] ? skb_free_datagram+0xc/0x40
[  430.914816]  [<ffffffff813f7538>] ? sock_sendmsg+0x88/0xc0
[  430.914818]  [<ffffffff813f7274>] ? move_addr_to_kernel.part.20+0x14/0x60
[  430.914820]  [<ffffffff811c47c2>] ? __inode_wait_for_writeback+0x62/0xb0
[  430.914821]  [<ffffffff813f7a91>] ? SYSC_sendto+0xf1/0x180
[  430.914823]  [<ffffffff813f88f9>] ? __sys_recvmsg+0x39/0x70
[  430.914825]  [<ffffffff8150066d>] ? system_call_fastpath+0x1a/0x1f
[  430.914826] ---[ end trace cc19a150d311fc63 ]---

Tried with two different AP.

04:00.0 Network controller: Intel Corporation Wireless 7260 (rev 83)

When this happens, everything seems to be working fine.

dmesg attached.
Comment 1 Dmitry Nezhevenko 2014-10-06 17:12:58 UTC
Created attachment 152651 [details]
dmesg
Comment 2 Emmanuel Grumbach 2014-10-06 18:18:16 UTC
Can you reproduce easily?


if yes - please record tracing:

sudo trace-cmd record -e iwlwifi -e iwlwifi_msg

and send the trace.dat file.

Thanks.
Comment 3 Dmitry Nezhevenko 2014-10-06 19:45:09 UTC
Not very easily. But it seems that I'm getting it pretty often under high CPU load.

I'm recomiling kernel with CONFIG_IWLWIFI_DEVICE_TRACING. Will back tomorrow.
Comment 4 Dmitry Nezhevenko 2014-10-07 07:14:57 UTC
Created attachment 152741 [details]
trace.dat

Now it's 0x88, but everything else seems to be ok. Now I'm almost sure that it happens only under load.

PID 3770 is wpa_supplicant.

Attaching trace.dat.

[ 1334.019589] ------------[ cut here ]------------
[ 1334.019607] WARNING: CPU: 1 PID: 3770 at drivers/net/wireless/iwlwifi/mvm/tx.c:190 iwl_mvm_set_tx_params+0x60a/0x6f0 [iwlmvm]()
[ 1334.019610] Got an HT rate for a non data frame 0x88
[ 1334.019611] Modules linked in: tun ctr ccm bnep acpi_call(O) nfsd auth_rpcgss oid_registry nfs_acl nfs lockd fscache sunrpc nls_utf8 nls_cp437 vfat fat snd_hda_codec_realtek snd_hda_codec_hdmi snd_hda_codec_generic arc4 uvcvideo videobuf2_vmalloc iwlmvm videobuf2_memops videobuf2_core mac80211 v4l2_common videodev media ecb btusb x86_pkg_temp_thermal bluetooth intel_powerclamp iwlwifi intel_rapl joydev coretemp iTCO_wdt iTCO_vendor_support cfg80211 snd_hda_intel kvm_intel snd_hda_controller snd_hda_codec snd_hwdep kvm thinkpad_acpi snd_pcm nvram snd_timer rfkill snd i915 soundcore rtsx_pci_ms drm_kms_helper memstick drm efivars pcspkr psmouse evdev ie31200_edac mei_me serio_raw i2c_algo_bit rtc_efi edac_core shpchp video mei i2c_i801 tpm_tis tpm battery ac lpc_ich processor button wmi i2c_dev i2c_core
[ 1334.019677]  fuse parport_pc ppdev lp parport autofs4 algif_skcipher af_alg dm_crypt dm_mod uhci_hcd ohci_hcd usb_storage ext4 crc16 mbcache jbd2 sg sd_mod sr_mod crc_t10dif cdrom crct10dif_generic crct10dif_pclmul crct10dif_common crc32_pclmul crc32c_intel ghash_clmulni_intel rtsx_pci_sdmmc ehci_pci aesni_intel xhci_hcd ahci ehci_hcd libahci mmc_core aes_x86_64 lrw gf128mul libata glue_helper ablk_helper cryptd scsi_mod e1000e rtsx_pci ptp mfd_core usbcore pps_core usb_common thermal thermal_sys
[ 1334.019720] CPU: 1 PID: 3770 Comm: wpa_supplicant Tainted: G           O   3.17.0+ #6
[ 1334.019722] Hardware name: LENOVO 20ANCTO1WW/20ANCTO1WW, BIOS GLET71WW (2.25 ) 07/02/2014
[ 1334.019724]  0000000000000009 ffffffff814fa911 ffff8804283e38e8 ffffffff81064f52
[ 1334.019728]  0000000000000008 ffff8804283e3938 ffff8802facaa660 ffff880426754300
[ 1334.019732]  0000000000000000 ffffffff81064fb7 ffffffffa08bed68 ffffffff00000020
[ 1334.019735] Call Trace:
[ 1334.019744]  [<ffffffff814fa911>] ? dump_stack+0x41/0x51
[ 1334.019750]  [<ffffffff81064f52>] ? warn_slowpath_common+0x72/0x90
[ 1334.019754]  [<ffffffff81064fb7>] ? warn_slowpath_fmt+0x47/0x50
[ 1334.019762]  [<ffffffffa08a791a>] ? iwl_mvm_set_tx_params+0x60a/0x6f0 [iwlmvm]
[ 1334.019768]  [<ffffffffa08a7c6e>] ? iwl_mvm_tx_skb+0x4e/0x410 [iwlmvm]
[ 1334.019773]  [<ffffffffa08a00bb>] ? iwl_mvm_mac_tx+0x9b/0x1a0 [iwlmvm]
[ 1334.019786]  [<ffffffffa0849ce9>] ? __ieee80211_tx+0x2b9/0x3c0 [mac80211]
[ 1334.019797]  [<ffffffffa084c2f3>] ? ieee80211_tx+0xb3/0x100 [mac80211]
[ 1334.019807]  [<ffffffffa084cc49>] ? ieee80211_subif_start_xmit+0x459/0xca0 [mac80211]
[ 1334.019814]  [<ffffffff814116e7>] ? dev_hard_start_xmit+0x337/0x5f0
[ 1334.019819]  [<ffffffff81430d46>] ? sch_direct_xmit+0x96/0x1f0
[ 1334.019823]  [<ffffffff81411ba3>] ? __dev_queue_xmit+0x203/0x4f0
[ 1334.019827]  [<ffffffff8142f670>] ? ether_setup+0x70/0x70
[ 1334.019832]  [<ffffffff814e96a1>] ? packet_sendmsg+0xf81/0x1110
[ 1334.019837]  [<ffffffff8140625c>] ? skb_free_datagram+0xc/0x40
[ 1334.019841]  [<ffffffff813f7538>] ? sock_sendmsg+0x88/0xc0
[ 1334.019846]  [<ffffffff813f7274>] ? move_addr_to_kernel.part.20+0x14/0x60
[ 1334.019850]  [<ffffffff811c47c2>] ? __inode_wait_for_writeback+0x62/0xb0
[ 1334.019855]  [<ffffffff813f7a91>] ? SYSC_sendto+0xf1/0x180
[ 1334.019859]  [<ffffffff813f88f9>] ? __sys_recvmsg+0x39/0x70
[ 1334.019863]  [<ffffffff8150066d>] ? system_call_fastpath+0x1a/0x1f
[ 1334.019866] ---[ end trace 00e746c4dfb43615 ]---
Comment 5 Emmanuel Grumbach 2014-10-07 08:28:28 UTC
Thanks - I think I understand what happens here - but I need to ask someone who is currently not available.

I'll report back. For sure - this WARNING is noisy but harmless.
Comment 6 Emmanuel Grumbach 2014-10-07 08:32:27 UTC
Oh - and this frame seems to be send by the supplicant (if the trace is to trusted). Yes - this seems to confirm what I think.
Comment 7 Zhuravlev Uriy 2014-10-09 12:19:02 UTC
I confirm this bug. 

Hardware name: Dell Inc. XPS13 9333/0GFTRT, BIOS A04 03/19/2014
Comment 9 Emmanuel Grumbach 2014-10-20 05:43:03 UTC
Sorry - due to the merge windows closing, I am shuffling my tress all the time - so the commit ID can't be trusted.

Just take my -fixes tree if you want to test the fix.