Bug 204873

Summary: iwlwifi: 9260: FW error in SYNC CMD STATISTICS_CMD
Product: Drivers Reporter: lukas.redlinger
Component: network-wireless-intelAssignee: DO NOT USE - assign "network-wireless-intel" component instead (linuxwifi)
Status: ASSIGNED ---    
Severity: normal CC: alexander.haensch, andrey+kernel, angelsl, bugzilla, chris2553, crab2313, fierce.brake, grassia.mauro, intelfx, jeromegn, kernelbugs, linuxwifi, listac, ngocdunghoangdl, sunsi.lucas, thomas.natschlaeger
Priority: P1    
Hardware: All   
OS: Linux   
Kernel Version: 5.2.11 Subsystem:
Regression: No Bisected commit-id:
Attachments: dmesg
dmesg/journalctl logs
Reverts iwlwifi: mvm: add a loose synchronization of the NSSN across Rx queues
smallest fix
dmesg output showing 2 x ADVANCED_SYSASSERT FW errors + a call trace
dmesg for "FW error in SYNC CMD SCAN_CFG_CMD"
Another DMESG from 5.4.5 with some trace
ADVANCED_SYSASSERT Microcode SW error still happening on 5.5.0-rc4
Patch to avoid microcode errors on 5.5 kernels

Description lukas.redlinger 2019-09-16 06:36:03 UTC
Created attachment 284989 [details]
dmesg

On a Kontron A-150-KBL equipped with

Intel 9260
Arch Linux 5.2.11
Firmware 46.93e59cf4.0

all of a sudden:
---

Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: Microcode SW error detected. Restarting 0x0.
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: Start IWL Error Log Dump:
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: Status: 0x00000080, count: 6
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: Loaded firmware version: 46.93e59cf4.0
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x00002078 | ADVANCED_SYSASSERT          
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x0000A200 | trm_hw_status0
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x00000000 | trm_hw_status1
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x00488472 | branchlink2
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x00479392 | interruptlink1
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x00000000 | interruptlink2
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x01010001 | data1
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x00000000 | data2
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0xDEADBEEF | data3
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x9840C27D | beacon time
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0xBC01DD8F | tsf low
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x000000EB | tsf hi
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x00000000 | time gp1
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x3084C335 | time gp2
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x00000001 | uCode revision type
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x0000002E | uCode version major
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x93E59CF4 | uCode version minor
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x00000321 | hw version
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x00C89004 | board version
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x00DB014E | hcmd
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x24022080 | isr0
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x00000000 | isr1
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x08201802 | isr2
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x00417CC0 | isr3
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x00000000 | isr4
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x0A26001C | last cmd Id
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x0001AD36 | wait_event
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x000000D4 | l2p_control
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x00018034 | l2p_duration
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x00000007 | l2p_mhvalid
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x00000081 | l2p_addr_match
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x0000000D | lmpm_pmg_sel
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x19071250 | timestamp
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x0000F0E4 | flow_handler
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: Start IWL Error Log Dump:
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: Status: 0x00000080, count: 7
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x20000070 | NMI_INTERRUPT_LMAC_FATAL
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x00000000 | umac branchlink1
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0xC008888E | umac branchlink2
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0xC0084414 | umac interruptlink1
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0xC0084414 | umac interruptlink2
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x00000800 | umac data1
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0xC0084414 | umac data2
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0xDEADBEEF | umac data3
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x0000002E | umac major
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x93E59CF4 | umac minor
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x3084C347 | frame pointer
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0xC088627C | stack pointer
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x00DB014E | last host cmd
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x00000000 | isr status reg
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: Fseq Registers:
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0xDF102766 | FSEQ_ERROR_CODE
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x00000000 | FSEQ_TOP_INIT_VERSION
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x748DEF07 | FSEQ_CNVIO_INIT_VERSION
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x0000A371 | FSEQ_OTP_VERSION
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0xAF1C2EB2 | FSEQ_TOP_CONTENT_VERSION
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0xE2E2A6CE | FSEQ_ALIVE_TOKEN
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x4A3792F6 | FSEQ_CNVI_ID
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x35F3C190 | FSEQ_CNVR_ID
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x01000200 | CNVI_AUX_MISC_CHIP
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x01300202 | CNVR_AUX_MISC_CHIP
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x0000485B | CNVR_SCU_SD_REGS_SD_REG_DIG_DCDC_VTRIM
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: 0x0BADCAFE | CNVR_SCU_SD_REGS_SD_REG_ACTIVE_VDIG_MIRROR
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: Collecting data: trigger 2 fired.
Sep 15 03:31:47 kernel: ieee80211 phy0: Hardware restart was requested
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: FW error in SYNC CMD STATISTICS_CMD
Sep 15 03:31:47 kernel: CPU: 0 PID: 32511 Comm: kworker/0:0 Not tainted 5.2.11-arch1-1-ARCH #1
Sep 15 03:31:47 kernel: Hardware name: Kontron Europe GmbH A-150-KBL/ECX-KLU1, BIOS 1.11 11/27/2018
Sep 15 03:31:47 kernel: Workqueue: events iwl_mvm_tcm_work [iwlmvm]
Sep 15 03:31:47 kernel: Call Trace:
Sep 15 03:31:47 kernel:  dump_stack+0x5c/0x80
Sep 15 03:31:47 kernel:  iwl_trans_pcie_send_hcmd+0x547/0x560 [iwlwifi]
Sep 15 03:31:47 kernel:  ? wait_woken+0x70/0x70
Sep 15 03:31:47 kernel:  iwl_trans_send_cmd+0x59/0xb0 [iwlwifi]
Sep 15 03:31:47 kernel:  iwl_mvm_send_cmd+0x2e/0x80 [iwlmvm]
Sep 15 03:31:47 kernel:  iwl_mvm_request_statistics+0x72/0xd0 [iwlmvm]
Sep 15 03:31:47 kernel:  iwl_mvm_recalc_tcm+0xd6/0x600 [iwlmvm]
Sep 15 03:31:47 kernel:  ? iwl_mvm_rs_rate_init+0x76d/0xca0 [iwlmvm]
Sep 15 03:31:47 kernel:  ? preempt_count_add+0x79/0xb0
Sep 15 03:31:47 kernel:  ? _raw_spin_lock+0x13/0x30
Sep 15 03:31:47 kernel:  ? _raw_spin_unlock_irqrestore+0x20/0x40
Sep 15 03:31:47 kernel:  ? rcu_preempt_deferred_qs_irqrestore+0x1b3/0x2e0
Sep 15 03:31:47 kernel:  process_one_work+0x1d1/0x3e0
Sep 15 03:31:47 kernel:  worker_thread+0x4a/0x3d0
Sep 15 03:31:47 kernel:  kthread+0xfb/0x130
Sep 15 03:31:47 kernel:  ? process_one_work+0x3e0/0x3e0
Sep 15 03:31:47 kernel:  ? kthread_park+0x80/0x80
Sep 15 03:31:47 kernel:  ret_from_fork+0x35/0x40
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: Applying debug destination EXTERNAL_DRAM
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: Applying debug destination EXTERNAL_DRAM
Sep 15 03:31:47 kernel: iwlwifi 0000:04:00.0: FW already configured (0) - re-configuring
Comment 1 Mike Hardy 2019-10-08 03:33:58 UTC
I am seeing nearly the same thing, it's still occurring for me with linux kernel 5.3.5, but we are both using the most up to date AC9260 firware (46). It happened to me with 43 as well - I updated to 46 in the hopes it would fix but nope.


Firmware 43 used to be fine with the 5.2 series in the early patch releases there, I can't say exactly when this started happening unfortunately.


That gives me a hunch that it's kernel related though, even it's the kernel tickling a firmware issue, as the same firmware (43) was fine for me on older kernels for quite some time.


I believe https://bugzilla.kernel.org/show_bug.cgi?id=204151#c23 is related, where a commenter was asked to file a new issue but I couldn't find one?



I see linuxwifi@intel.com is already on the CC list. Please let me know if I can help debug it, similar to the comment I linked above I can trigger this very quickly with high data rate transfers, so it's pretty reproducible.
Comment 2 Hao Wei Tee 2019-10-10 05:35:36 UTC
I'm having this issue too.

Some tracing:

This started happening on 20 Sep for me, after I updated my kernel from 5.2.9 to 5.2.15. Before 4 Oct, I was using Arch Linux linux-firmware 20190815.07b925b-1 (linux-firmware.git 07b925b450bfb4cf3e141c612ec5b104658cd020); on 4 Oct I updated to Arch Linux linux-firmware 20190923.417a9c6-1 (417a9c6e197a8d3eec792494efc87a2b42f76324).

The issue seems to have gotten worse after the firmware update. I'm actually still on kernel 5.2.15. (Should update soon...)

Someone could test 5.2.9 and 5.2.15 and see if they can reproduce the bug on .15 but not .9, and then bisect it.
Comment 3 Mike Hardy 2019-10-11 22:00:07 UTC
Hao Wei Tee, thanks for the info. I took your idea and attempted to reproduce it.

My results differ a little bit, though I am still testing.

5.2.12 - start of bisect unable to reproduce
5.2.14 - unable to reproduce (this was unexpected!)
5.2.15 - unable to reproduce so far (very unexpected, different result)

So now I am confused.

I definitely reproduced with 5.3.5:

Transferred approximately 9GB across an NFS mount on an 802.11ac link with throughput around 17MB/s prior to this:

Oct 11 13:44:57 isabela kernel: [335526.734144] iwlwifi 0000:3b:00.0: Microcode SW error detected. Restarting 0x0.
Oct 11 13:44:57 isabela kernel: [335526.734715] iwlwifi 0000:3b:00.0: Start IWL Error Log Dump:
Oct 11 13:44:57 isabela kernel: [335526.734721] iwlwifi 0000:3b:00.0: Status: 0x00000080, count: 6
Oct 11 13:44:57 isabela kernel: [335526.734725] iwlwifi 0000:3b:00.0: Loaded firmware version: 46.6bf1df06.0
Oct 11 13:44:57 isabela kernel: [335526.734730] iwlwifi 0000:3b:00.0: 0x000022CE | ADVANCED_SYSASSERT
Oct 11 13:44:57 isabela kernel: [335526.734734] iwlwifi 0000:3b:00.0: 0x0590A2F2 | trm_hw_status0
Oct 11 13:44:57 isabela kernel: [335526.734737] iwlwifi 0000:3b:00.0: 0x00000000 | trm_hw_status1
Oct 11 13:44:57 isabela kernel: [335526.734746] iwlwifi 0000:3b:00.0: 0x0048853E | branchlink2
Oct 11 13:44:57 isabela kernel: [335526.734758] iwlwifi 0000:3b:00.0: 0x00479392 | interruptlink1
Oct 11 13:44:57 isabela kernel: [335526.734771] iwlwifi 0000:3b:00.0: 0x00000000 | interruptlink2
Oct 11 13:44:57 isabela kernel: [335526.734778] iwlwifi 0000:3b:00.0: 0x0000012C | data1
Oct 11 13:44:57 isabela kernel: [335526.734782] iwlwifi 0000:3b:00.0: 0x00000000 | data2
Oct 11 13:44:57 isabela kernel: [335526.734785] iwlwifi 0000:3b:00.0: 0x04000000 | data3
Oct 11 13:44:57 isabela kernel: [335526.734789] iwlwifi 0000:3b:00.0: 0x8100CE78 | beacon time
Oct 11 13:44:57 isabela kernel: [335526.734792] iwlwifi 0000:3b:00.0: 0x31839193 | tsf low
Oct 11 13:44:57 isabela kernel: [335526.734795] iwlwifi 0000:3b:00.0: 0x0000004E | tsf hi
Oct 11 13:44:57 isabela kernel: [335526.734799] iwlwifi 0000:3b:00.0: 0x00000000 | time gp1
Oct 11 13:44:57 isabela kernel: [335526.734803] iwlwifi 0000:3b:00.0: 0x47E6498C | time gp2
Oct 11 13:44:57 isabela kernel: [335526.734806] iwlwifi 0000:3b:00.0: 0x00000001 | uCode revision type
Oct 11 13:44:57 isabela kernel: [335526.734815] iwlwifi 0000:3b:00.0: 0x0000002E | uCode version major
Oct 11 13:44:57 isabela kernel: [335526.734819] iwlwifi 0000:3b:00.0: 0x6BF1DF06 | uCode version minor
Oct 11 13:44:57 isabela kernel: [335526.734822] iwlwifi 0000:3b:00.0: 0x00000321 | hw version
Oct 11 13:44:57 isabela kernel: [335526.734826] iwlwifi 0000:3b:00.0: 0x00489004 | board version
Oct 11 13:44:57 isabela kernel: [335526.734829] iwlwifi 0000:3b:00.0: 0x0A69001C | hcmd
Oct 11 13:44:57 isabela kernel: [335526.734833] iwlwifi 0000:3b:00.0: 0xA7F93802 | isr0
Oct 11 13:44:57 isabela kernel: [335526.734836] iwlwifi 0000:3b:00.0: 0x000C0000 | isr1
Oct 11 13:44:57 isabela kernel: [335526.734839] iwlwifi 0000:3b:00.0: 0x00001802 | isr2
Oct 11 13:44:57 isabela kernel: [335526.734843] iwlwifi 0000:3b:00.0: 0x40417DCD | isr3
Oct 11 13:44:57 isabela kernel: [335526.734846] iwlwifi 0000:3b:00.0: 0x00000000 | isr4
Oct 11 13:44:57 isabela kernel: [335526.734849] iwlwifi 0000:3b:00.0: 0x0A68001C | last cmd Id
Oct 11 13:44:57 isabela kernel: [335526.734853] iwlwifi 0000:3b:00.0: 0x0001ACA2 | wait_event
Oct 11 13:44:57 isabela kernel: [335526.734857] iwlwifi 0000:3b:00.0: 0x00004A88 | l2p_control
Oct 11 13:44:57 isabela kernel: [335526.734861] iwlwifi 0000:3b:00.0: 0x00001420 | l2p_duration
Oct 11 13:44:57 isabela kernel: [335526.734864] iwlwifi 0000:3b:00.0: 0x000003BF | l2p_mhvalid
Oct 11 13:44:57 isabela kernel: [335526.734868] iwlwifi 0000:3b:00.0: 0x000000E7 | l2p_addr_match
Oct 11 13:44:57 isabela kernel: [335526.734871] iwlwifi 0000:3b:00.0: 0x0000000D | lmpm_pmg_sel
Oct 11 13:44:57 isabela kernel: [335526.734875] iwlwifi 0000:3b:00.0: 0x08081424 | timestamp
Oct 11 13:44:57 isabela kernel: [335526.734878] iwlwifi 0000:3b:00.0: 0x15DC7878 | flow_handler
Oct 11 13:44:57 isabela kernel: [335526.735098] iwlwifi 0000:3b:00.0: Start IWL Error Log Dump:
Oct 11 13:44:57 isabela kernel: [335526.735102] iwlwifi 0000:3b:00.0: Status: 0x00000080, count: 7
Oct 11 13:44:57 isabela kernel: [335526.735106] iwlwifi 0000:3b:00.0: 0x20000070 | NMI_INTERRUPT_LMAC_FATAL
Oct 11 13:44:57 isabela kernel: [335526.735110] iwlwifi 0000:3b:00.0: 0x00000000 | umac branchlink1
Oct 11 13:44:57 isabela kernel: [335526.735114] iwlwifi 0000:3b:00.0: 0xC008888E | umac branchlink2
Oct 11 13:44:57 isabela kernel: [335526.735117] iwlwifi 0000:3b:00.0: 0xC0084414 | umac interruptlink1
Oct 11 13:44:57 isabela kernel: [335526.735120] iwlwifi 0000:3b:00.0: 0xC0084414 | umac interruptlink2
Oct 11 13:44:57 isabela kernel: [335526.735124] iwlwifi 0000:3b:00.0: 0x00000800 | umac data1
Oct 11 13:44:57 isabela kernel: [335526.735128] iwlwifi 0000:3b:00.0: 0xC0084414 | umac data2
Oct 11 13:44:57 isabela kernel: [335526.735132] iwlwifi 0000:3b:00.0: 0xDEADBEEF | umac data3
Oct 11 13:44:57 isabela kernel: [335526.735136] iwlwifi 0000:3b:00.0: 0x0000002E | umac major
Oct 11 13:44:57 isabela kernel: [335526.735140] iwlwifi 0000:3b:00.0: 0x6BF1DF06 | umac minor
Oct 11 13:44:57 isabela kernel: [335526.735143] iwlwifi 0000:3b:00.0: 0x47E64B47 | frame pointer
Oct 11 13:44:57 isabela kernel: [335526.735147] iwlwifi 0000:3b:00.0: 0xC088627C | stack pointer
Oct 11 13:44:57 isabela kernel: [335526.735151] iwlwifi 0000:3b:00.0: 0x00570502 | last host cmd
Oct 11 13:44:57 isabela kernel: [335526.735154] iwlwifi 0000:3b:00.0: 0x00000000 | isr status reg
Oct 11 13:44:57 isabela kernel: [335526.735192] iwlwifi 0000:3b:00.0: Fseq Registers:
Oct 11 13:44:57 isabela kernel: [335526.735208] iwlwifi 0000:3b:00.0: 0xF7C753BD | FSEQ_ERROR_CODE
Oct 11 13:44:57 isabela kernel: [335526.735224] iwlwifi 0000:3b:00.0: 0x00000000 | FSEQ_TOP_INIT_VERSION
Oct 11 13:44:57 isabela kernel: [335526.735240] iwlwifi 0000:3b:00.0: 0x100850C6 | FSEQ_CNVIO_INIT_VERSION
Oct 11 13:44:57 isabela kernel: [335526.735256] iwlwifi 0000:3b:00.0: 0x0000A371 | FSEQ_OTP_VERSION
Oct 11 13:44:57 isabela kernel: [335526.735272] iwlwifi 0000:3b:00.0: 0x018851D0 | FSEQ_TOP_CONTENT_VERSION
Oct 11 13:44:57 isabela kernel: [335526.735288] iwlwifi 0000:3b:00.0: 0x637BE7C3 | FSEQ_ALIVE_TOKEN
Oct 11 13:44:57 isabela kernel: [335526.735303] iwlwifi 0000:3b:00.0: 0x6440E109 | FSEQ_CNVI_ID
Oct 11 13:44:57 isabela kernel: [335526.735319] iwlwifi 0000:3b:00.0: 0x76F4851F | FSEQ_CNVR_ID
Oct 11 13:44:57 isabela kernel: [335526.735334] iwlwifi 0000:3b:00.0: 0x01000200 | CNVI_AUX_MISC_CHIP
Oct 11 13:44:57 isabela kernel: [335526.735353] iwlwifi 0000:3b:00.0: 0x01300202 | CNVR_AUX_MISC_CHIP
Oct 11 13:44:57 isabela kernel: [335526.735376] iwlwifi 0000:3b:00.0: 0x0000485B | CNVR_SCU_SD_REGS_SD_REG_DIG_DCDC_VTRIM
Oct 11 13:44:57 isabela kernel: [335526.735449] iwlwifi 0000:3b:00.0: 0x0BADCAFE | CNVR_SCU_SD_REGS_SD_REG_ACTIVE_VDIG_MIRROR
Oct 11 13:44:57 isabela kernel: [335526.735486] iwlwifi 0000:3b:00.0: Collecting data: trigger 2 fired.


5.3.6 is out, I'll test that to see if it resolves for me, and if not I will restart the bisect with endpoints 5.2.15 through 5.3.6
Comment 4 Hao Wei Tee 2019-10-12 10:57:27 UTC
There may be multiple issues at play here. No idea.

For me, I seem to run into this more in areas of high AP and client density (i.e. my university) where the card may roam across APs often and have to rekey often. It happens even when there isn't much data being transferred. Kind of random.
Comment 5 Thomas Natschläger 2019-10-12 11:03:32 UTC
This is what we realized too. There is a direct correlation between heavy roaming and frequency of crashing.
Comment 6 Hao Wei Tee 2019-10-12 11:05:04 UTC
> 5.3.6 is out, I'll test that to see if it resolves for me

I see no iwlwifi changes between 5.3.5 and 5.3.6, so if there is a difference, then this is going to be a very difficult bug to fix.
Comment 7 Mike Hardy 2019-10-12 13:33:14 UTC
Ok - good information - I'm just testing from my house but I was pretty reliably reproducing it. This tells me to be much more careful about my testing setup then and for now it's best to consider any negative results (can't reproduce) from me as potentially false negatives. I have several kernel versions where I know I can trigger it though so I'll see if I can get it to be more reliable.

My take on the 5.3.5->5.3.6 changelog matches yours (it should not be fixed there) but for mysterious bugs you never know...
Comment 8 Mike Hardy 2019-11-14 12:50:15 UTC
Still happening with 5.3.11


On 5.3.11-050311-generic

Nov 13 11:08:40 isabela kernel: [   20.481431] iwlwifi 0000:3b:00.0: loaded firmware version 46.6bf1df06.0 op_mode iwlmvm

Nov 13 15:20:54 isabela kernel: [11434.526425] iwlwifi 0000:3b:00.0: Microcode SW error detected. Restarting 0x0.
Nov 13 15:20:54 isabela kernel: [11434.526670] iwlwifi 0000:3b:00.0: Start IWL Error Log Dump:
Nov 13 15:20:54 isabela kernel: [11434.526672] iwlwifi 0000:3b:00.0: Status: 0x00000080, count: 6
Nov 13 15:20:54 isabela kernel: [11434.526673] iwlwifi 0000:3b:00.0: Loaded firmware version: 46.6bf1df06.0
Nov 13 15:20:54 isabela kernel: [11434.526674] iwlwifi 0000:3b:00.0: 0x000022CE | ADVANCED_SYSASSERT          
Nov 13 15:20:54 isabela kernel: [11434.526675] iwlwifi 0000:3b:00.0: 0x0590A2F2 | trm_hw_status0
Nov 13 15:20:54 isabela kernel: [11434.526676] iwlwifi 0000:3b:00.0: 0x00000000 | trm_hw_status1
Nov 13 15:20:54 isabela kernel: [11434.526677] iwlwifi 0000:3b:00.0: 0x0048853E | branchlink2
Nov 13 15:20:54 isabela kernel: [11434.526678] iwlwifi 0000:3b:00.0: 0x00479392 | interruptlink1
Nov 13 15:20:54 isabela kernel: [11434.526679] iwlwifi 0000:3b:00.0: 0x00000000 | interruptlink2
Nov 13 15:20:54 isabela kernel: [11434.526680] iwlwifi 0000:3b:00.0: 0x0000012C | data1
Nov 13 15:20:54 isabela kernel: [11434.526680] iwlwifi 0000:3b:00.0: 0x00000000 | data2
Nov 13 15:20:54 isabela kernel: [11434.526681] iwlwifi 0000:3b:00.0: 0x04000000 | data3
Nov 13 15:20:54 isabela kernel: [11434.526682] iwlwifi 0000:3b:00.0: 0xFE0184BA | beacon time
Nov 13 15:20:54 isabela kernel: [11434.526683] iwlwifi 0000:3b:00.0: 0x604A7B49 | tsf low
Nov 13 15:20:54 isabela kernel: [11434.526684] iwlwifi 0000:3b:00.0: 0x000002E7 | tsf hi
Nov 13 15:20:54 isabela kernel: [11434.526685] iwlwifi 0000:3b:00.0: 0x00000000 | time gp1
Nov 13 15:20:54 isabela kernel: [11434.526685] iwlwifi 0000:3b:00.0: 0x18F4F054 | time gp2
Nov 13 15:20:54 isabela kernel: [11434.526686] iwlwifi 0000:3b:00.0: 0x00000001 | uCode revision type
Nov 13 15:20:54 isabela kernel: [11434.526687] iwlwifi 0000:3b:00.0: 0x0000002E | uCode version major
Nov 13 15:20:54 isabela kernel: [11434.526688] iwlwifi 0000:3b:00.0: 0x6BF1DF06 | uCode version minor
Nov 13 15:20:54 isabela kernel: [11434.526689] iwlwifi 0000:3b:00.0: 0x00000321 | hw version
Nov 13 15:20:54 isabela kernel: [11434.526690] iwlwifi 0000:3b:00.0: 0x00489004 | board version
Nov 13 15:20:54 isabela kernel: [11434.526691] iwlwifi 0000:3b:00.0: 0x0ACC001C | hcmd
Nov 13 15:20:54 isabela kernel: [11434.526691] iwlwifi 0000:3b:00.0: 0xA3F93802 | isr0
Nov 13 15:20:54 isabela kernel: [11434.526692] iwlwifi 0000:3b:00.0: 0x000C0000 | isr1
Nov 13 15:20:54 isabela kernel: [11434.526693] iwlwifi 0000:3b:00.0: 0x00001802 | isr2
Nov 13 15:20:54 isabela kernel: [11434.526694] iwlwifi 0000:3b:00.0: 0x40417DCD | isr3
Nov 13 15:20:54 isabela kernel: [11434.526695] iwlwifi 0000:3b:00.0: 0x00000002 | isr4
Nov 13 15:20:54 isabela kernel: [11434.526696] iwlwifi 0000:3b:00.0: 0x0ACB001C | last cmd Id
Nov 13 15:20:54 isabela kernel: [11434.526696] iwlwifi 0000:3b:00.0: 0x0001ACA2 | wait_event
Nov 13 15:20:54 isabela kernel: [11434.526697] iwlwifi 0000:3b:00.0: 0x00004288 | l2p_control
Nov 13 15:20:54 isabela kernel: [11434.526698] iwlwifi 0000:3b:00.0: 0x00001420 | l2p_duration
Nov 13 15:20:54 isabela kernel: [11434.526699] iwlwifi 0000:3b:00.0: 0x00000000 | l2p_mhvalid
Nov 13 15:20:54 isabela kernel: [11434.526700] iwlwifi 0000:3b:00.0: 0x000000E7 | l2p_addr_match
Nov 13 15:20:54 isabela kernel: [11434.526701] iwlwifi 0000:3b:00.0: 0x0000000D | lmpm_pmg_sel
Nov 13 15:20:54 isabela kernel: [11434.526702] iwlwifi 0000:3b:00.0: 0x08081424 | timestamp
Nov 13 15:20:54 isabela kernel: [11434.526702] iwlwifi 0000:3b:00.0: 0x14B40808 | flow_handler
Nov 13 15:20:54 isabela kernel: [11434.526776] iwlwifi 0000:3b:00.0: 0x00000000 | ADVANCED_SYSASSERT
Nov 13 15:20:54 isabela kernel: [11434.526776] iwlwifi 0000:3b:00.0: 0x00000000 | umac branchlink1
Nov 13 15:20:54 isabela kernel: [11434.526777] iwlwifi 0000:3b:00.0: 0x00000000 | umac branchlink2
Nov 13 15:20:54 isabela kernel: [11434.526778] iwlwifi 0000:3b:00.0: 0x00000000 | umac interruptlink1
Nov 13 15:20:54 isabela kernel: [11434.526779] iwlwifi 0000:3b:00.0: 0x00000000 | umac interruptlink2
Nov 13 15:20:54 isabela kernel: [11434.526780] iwlwifi 0000:3b:00.0: 0x00000000 | umac data1
Nov 13 15:20:54 isabela kernel: [11434.526781] iwlwifi 0000:3b:00.0: 0x00000000 | umac data2
Nov 13 15:20:54 isabela kernel: [11434.526781] iwlwifi 0000:3b:00.0: 0x00000000 | umac data3
Nov 13 15:20:54 isabela kernel: [11434.526782] iwlwifi 0000:3b:00.0: 0x00000000 | umac major
Nov 13 15:20:54 isabela kernel: [11434.526783] iwlwifi 0000:3b:00.0: 0x00000000 | umac minor
Nov 13 15:20:54 isabela kernel: [11434.526784] iwlwifi 0000:3b:00.0: 0x00000000 | frame pointer
Nov 13 15:20:54 isabela kernel: [11434.526785] iwlwifi 0000:3b:00.0: 0x00000000 | stack pointer
Nov 13 15:20:54 isabela kernel: [11434.526786] iwlwifi 0000:3b:00.0: 0x00000000 | last host cmd
Nov 13 15:20:54 isabela kernel: [11434.526786] iwlwifi 0000:3b:00.0: 0x00000000 | isr status reg
Nov 13 15:20:54 isabela kernel: [11434.526815] iwlwifi 0000:3b:00.0: Fseq Registers:
Nov 13 15:20:54 isabela kernel: [11434.526828] iwlwifi 0000:3b:00.0: 0xF7C771FD | FSEQ_ERROR_CODE
Nov 13 15:20:54 isabela kernel: [11434.526840] iwlwifi 0000:3b:00.0: 0x00000000 | FSEQ_TOP_INIT_VERSION
Nov 13 15:20:54 isabela kernel: [11434.526851] iwlwifi 0000:3b:00.0: 0x10985046 | FSEQ_CNVIO_INIT_VERSION
Nov 13 15:20:54 isabela kernel: [11434.526864] iwlwifi 0000:3b:00.0: 0x0000A371 | FSEQ_OTP_VERSION
Nov 13 15:20:54 isabela kernel: [11434.526876] iwlwifi 0000:3b:00.0: 0x038053D4 | FSEQ_TOP_CONTENT_VERSION
Nov 13 15:20:54 isabela kernel: [11434.526888] iwlwifi 0000:3b:00.0: 0xF3F7E7E0 | FSEQ_ALIVE_TOKEN
Nov 13 15:20:54 isabela kernel: [11434.526899] iwlwifi 0000:3b:00.0: 0x4440E149 | FSEQ_CNVI_ID
Nov 13 15:20:54 isabela kernel: [11434.526911] iwlwifi 0000:3b:00.0: 0x76F4C55F | FSEQ_CNVR_ID
Nov 13 15:20:54 isabela kernel: [11434.526923] iwlwifi 0000:3b:00.0: 0x01000200 | CNVI_AUX_MISC_CHIP
Nov 13 15:20:54 isabela kernel: [11434.526938] iwlwifi 0000:3b:00.0: 0x01300202 | CNVR_AUX_MISC_CHIP
Nov 13 15:20:54 isabela kernel: [11434.526952] iwlwifi 0000:3b:00.0: 0x0000485B | CNVR_SCU_SD_REGS_SD_REG_DIG_DCDC_VTRIM
Nov 13 15:20:54 isabela kernel: [11434.527016] iwlwifi 0000:3b:00.0: 0x0BADCAFE | CNVR_SCU_SD_REGS_SD_REG_ACTIVE_VDIG_MIRROR
Nov 13 15:20:54 isabela kernel: [11434.527027] iwlwifi 0000:3b:00.0: Collecting data: trigger 2 fired.
Nov 13 15:20:54 isabela kernel: [11434.527031] ieee80211 phy0: Hardware restart was requested
Nov 13 15:20:54 isabela kernel: [11434.527073] iwlwifi 0000:3b:00.0: FW error in SYNC CMD SCAN_CFG_CMD
Nov 13 15:20:54 isabela kernel: [11434.527076] CPU: 2 PID: 23282 Comm: kworker/2:0 Tainted: G     U            5.3.11-050311-generic #201911121635
Nov 13 15:20:54 isabela kernel: [11434.527076] Hardware name: Dell Inc. XPS 15 9570/02MJVY, BIOS 1.13.0 08/22/2019
Nov 13 15:20:54 isabela kernel: [11434.527086] Workqueue: events iwl_mvm_tcm_work [iwlmvm]
Nov 13 15:20:54 isabela kernel: [11434.527087] Call Trace:
Nov 13 15:20:54 isabela kernel: [11434.527091]  dump_stack+0x6d/0x9a
Nov 13 15:20:54 isabela kernel: [11434.527098]  iwl_pcie_send_hcmd_sync+0x497/0x4b0 [iwlwifi]
Nov 13 15:20:54 isabela kernel: [11434.527101]  ? wait_woken+0x80/0x80
Nov 13 15:20:54 isabela kernel: [11434.527106]  iwl_trans_pcie_send_hcmd+0x34/0xe0 [iwlwifi]
Nov 13 15:20:54 isabela kernel: [11434.527112]  iwl_trans_send_cmd+0x5d/0xc0 [iwlwifi]
Nov 13 15:20:54 isabela kernel: [11434.527118]  iwl_mvm_send_cmd+0x34/0x90 [iwlmvm]
Nov 13 15:20:54 isabela kernel: [11434.527124]  iwl_mvm_config_scan+0x280/0x430 [iwlmvm]
Nov 13 15:20:54 isabela kernel: [11434.527142]  ? ieee80211_iterate_interfaces+0x46/0x60 [mac80211]
Nov 13 15:20:54 isabela kernel: [11434.527148]  iwl_mvm_recalc_tcm+0x1bc/0x1d0 [iwlmvm]
Nov 13 15:20:54 isabela kernel: [11434.527153]  iwl_mvm_tcm_work+0x15/0x20 [iwlmvm]
Nov 13 15:20:54 isabela kernel: [11434.527154]  process_one_work+0x1db/0x380
Nov 13 15:20:54 isabela kernel: [11434.527155]  worker_thread+0x4d/0x400
Nov 13 15:20:54 isabela kernel: [11434.527157]  kthread+0x104/0x140
Nov 13 15:20:54 isabela kernel: [11434.527158]  ? process_one_work+0x380/0x380
Nov 13 15:20:54 isabela kernel: [11434.527159]  ? kthread_park+0x80/0x80
Nov 13 15:20:54 isabela kernel: [11434.527161]  ret_from_fork+0x35/0x40
Nov 13 15:20:55 isabela kernel: [11435.768168] iwlwifi 0000:3b:00.0: Applying debug destination EXTERNAL_DRAM
Nov 13 15:20:55 isabela kernel: [11435.892418] iwlwifi 0000:3b:00.0: Applying debug destination EXTERNAL_DRAM
Nov 13 15:20:55 isabela kernel: [11435.971130] iwlwifi 0000:3b:00.0: FW already configured (0) - re-configuring


I could not reproduce 5.2.15. I'm running 5.2.21 now to see if it happens there.
Comment 9 Hao Wei Tee 2019-11-14 13:04:51 UTC
I feel like I've been seeing this less since switching to IWD.

But not really sure if that's the cause, or just a coincidence, since I've also been updating my kernel.
Comment 10 Mike Hardy 2019-11-14 13:17:22 UTC
That's interesting - I just read about AWD the first time based on your comment. But we may be seeing different problems. For me this is a single physically stationary machine in a wifi environment where everything is static and stable and the problem can be reproduced as a firmware error within minutes of boot with nothing else happening on 5.3.x, but 5.2.x seems fine - same firmware. I'm not sure how the config daemon affects that? Does it load different firmware or use a different kernel driver? If so I suppose I could add it to the things I'll test
Comment 11 David Valiente 2019-11-14 16:22:46 UTC
Created attachment 285921 [details]
dmesg/journalctl logs

Seems i am experiencing a similar issue. I have tried both the newest available firmrware as well as the intel one. Same  outcome on both cases

[PC][fierce](~)$ uname -r
5.3.11-arch1-1

[PC][fierce](~)$ lspci | grep Network
05:00.0 Network controller: Intel Corporation Wireless-AC 9260 (rev 29)
[PC][fierce](~)$
Comment 12 Mathias Tillman 2019-11-19 03:42:51 UTC
Having the same problem here running v5.3 or later (it started happening in rc4). I'm able to quite easily reproduce it by running a dozen or so torrents simultaneously and leaving it for a couple of minutes.
I've done some digging/bisecting, and it appears to be caused by commit 3c514bf831ac12356b695ff054bef641b9e99593 (https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/drivers/net/wireless/intel/iwlwifi?h=v5.3-rc4&id=3c514bf831ac12356b695ff054bef641b9e99593). As a test I checked out v5.3, reverted that commit, and compiled, and it now works perfectly without any firmware crashes or problems whatsoever.

If anyone else could test this it would be great to get some confirmation so we can get this fixed ASAP.
Comment 13 Mathias Tillman 2019-11-19 03:45:18 UTC
Created attachment 285969 [details]
Reverts iwlwifi: mvm: add a loose synchronization of the NSSN across Rx queues

This reverts the affected commit. Only tested on the v5.3 tag, so applying it on another tag may not work.
Comment 14 Mike Hardy 2019-11-19 11:41:01 UTC
I think there may be more than one thing happening since some reported a regression during the 5.2 series but my reproduction sounds like it fits yours exactly Mathias - I can't reproduce on any 5.2 but I reproduce on any official 5.3 easily. I don't have a kernel compile environment set up at all but I'll see if I can test your patch
Comment 15 Mathias Tillman 2019-11-19 11:52:58 UTC
I agree, there are most likely multiple issues here. However, I'm not able to reproduce it at all on any of the 5.2 series, but as soon as I upgrade to 5.3 it starts happening. Maybe we should open up a separate issue for 5.3 and leave this for issues with 5.2?
Comment 16 Mike Hardy 2019-11-19 14:16:36 UTC
I will follow the issue anywhere but won't do meta-work like moving it myself ;-).

Just wanted to say for other intrepid explorers that your patch applies cleanly following the ubuntu mainline kernel instructions vs tag v5.3.11 here https://kernel.ubuntu.com/~kernel-ppa/mainline/v5.3.11/ assuming you add a preamble to it with at minimum a From address and email in `<>`) and name it appropriately (so `git -am` may consume it). 

It did not apply cleanly to the linux tree at HEAD / tag v5.4-rc8 (HEAD and that tag are equivalent as I type this) but I did not have time to investigate if it was structural or just too much line skew for patch to succeed

My 5.3.11 kernel is building now but it is non-trivial for me to bounce this rig (my main machine) so I may not report status for a day or three. I'm hoping for success though!
Comment 17 Mike Hardy 2019-11-19 17:55:47 UTC
Okay, I had a chance to test it. v5.3.11 with the revert of that commit works for me. I no longer reproduce any problem where I can trigger it in minutes on v5.3.x with that commit.

What's the next step?
Comment 18 Mathias Tillman 2019-11-19 20:56:35 UTC
Great, good to see that it solved it for you as well.
We'll need someone from the iwlwifi team to get attention to this bug - preferrably the original maintainer of the commit. I sent an email to them with a link to this bug, so hopefully they'll respond momentarily, and either find a proper fix or at the very least revert it for the next week until the real issue has been found.

I tried the patch on v5.4-rc8 myself, and while it wasn't a perfect match, it did apply cleanly after some automatic fuzzing. More importantly, it also fixes the issue there as well.
Comment 19 lukas.redlinger 2019-11-20 07:24:15 UTC
Since updating to some 5.3 kernel it occurs more often on our systems too.

But:
My opening post was about "0x00002078 | ADVANCED_SYSASSERT", the one happening since 5.3 is "0x000022CE | ADVANCED_SYSASSERT".

Even though the message "FW error in SYNC CMD STATISTICS_CMD" is the same, those might be two different issues?!
Comment 20 Emmanuel Grumbach 2019-11-20 09:17:39 UTC
*** Bug 205001 has been marked as a duplicate of this bug. ***
Comment 21 Emmanuel Grumbach 2019-11-20 09:19:46 UTC
Created attachment 285983 [details]
smallest fix

Hi all,

please test this.
Comment 22 Emmanuel Grumbach 2019-11-20 09:29:11 UTC
*** Bug 205363 has been marked as a duplicate of this bug. ***
Comment 23 Mathias Tillman 2019-11-20 11:11:12 UTC
Hi, just tested the patch and it does seem to work. However, I'm assuming this would do nothing to fix the fw error Lukas saw initially in 5.2?
Comment 24 Emmanuel Grumbach 2019-11-20 11:14:13 UTC
(In reply to Mathias Tillman from comment #23)
> Hi, just tested the patch and it does seem to work.

Thanks. I'll publish it.

> However, I'm assuming this would do nothing to fix the fw error Lukas saw
> initially in 5.2?
Right.
Comment 25 Chris Clayton 2019-11-20 11:59:45 UTC
On 20/11/2019 09:19, bugzilla-daemon@bugzilla.kernel.org wrote:
> https://bugzilla.kernel.org/show_bug.cgi?id=204873
> 
> --- Comment #21 from Emmanuel Grumbach (emmanuel.grumbach@intel.com) ---
> Created attachment 285983 [details]
>   --> https://bugzilla.kernel.org/attachment.cgi?id=285983&action=edit
> smallest fix
> 
> Hi all,
> 
> please test this.

Your patch avoids the problem on 5.4.0-rc8+. Thanks.

>
Comment 26 Chris Clayton 2019-11-26 09:18:35 UTC
As I reported in comment 25 above, the "smallest fix" patch avoids the FW problem that I reported in bug 205001. That, however, seems to have opened the door for the ADVANCED_SYSASSERT problem to strike. During the concurrent download of two 2GB files I got two of these in the space of 5 minutes. The second one is followed by a call trace similar to that provided by Mike in comment 8. I'll add that as an attachment in a moment.
Comment 27 Chris Clayton 2019-11-26 09:22:59 UTC
Created attachment 286065 [details]
dmesg output showing 2 x ADVANCED_SYSASSERT FW errors + a call trace
Comment 28 Chris Clayton 2019-11-26 09:28:39 UTC
Should have said in commants 26 and 27 that the ADVANCED_SYSASSERT errors occured on the released 5.4.0 kernel with the "sallest fix" patch applied by hand ( because it doesn't apply cleanly otherwise)
Comment 29 Ivan Shapovalov 2019-11-27 09:22:24 UTC
Created attachment 286089 [details]
dmesg for "FW error in SYNC CMD SCAN_CFG_CMD"

Lenovo X1 Carbon 2018 with an Intel AC9260 (aftermarket upgrade) here. Since I upgraded to Linux 5.4.0, my AC9260 is crashing right after boot in a tight loop with a "FW error in SYNC CMD SCAN_CFG_CMD" (log attached). Before that, no issues whatsoever.

Should I assume this is a different problem from the one discussed here?
Comment 30 Mike Hardy 2019-12-08 13:50:59 UTC
Hi there - I maintain a bunch of FOSS so I understand release dates are flexible, have lag, and are hard to estimate. But I've been watching the v5.3 and 5.4 changelogs and I don't see the sync disable commit making it's way in there yet, also when I check on launchpad (which I was using as a sanity check, maybe incorrectly?) like so https://git.launchpad.net/~ubuntu-kernel-test/ubuntu/+source/linux/+git/mainline-crack/tree/drivers/net/wireless/intel/iwlwifi/mvm/rxmq.c#n524 I don't see it either

Any guess when the temporary queue sync disable will make it's way to mainline?

Happy to follow any pointers to docs on the process or discussions I could passively follow for resolution etc.

Thanks!
Comment 31 Ede Wolf 2019-12-19 17:45:58 UTC
Created attachment 286369 [details]
Another DMESG from 5.4.5 with some trace

Maybe some additional data will help. No problems with Kernel 5.3.13.
Comment 32 Chris Clayton 2019-12-30 11:00:53 UTC
Created attachment 286519 [details]
ADVANCED_SYSASSERT Microcode SW error still happening on 5.5.0-rc4

The  Microcode SW errors regression that I reported in comment 26 is still present in 5.5.0-rc4. The attached extract from dmesg shows two errors that have occurred this morning.

For others who are tired of interruptions in viewing online videos, I will shortly attach a patch which reverts 3c514bf831ac ("iwlwifi: mvm: add a loose synchronization of the NSSN across Rx queues"), which it seems is the change that induced these microcode errors. Applied to 5.5.0-rc3, the patch produces a kernel that I have been using over the last week and which has not suffered a microcode error. Later today I'll apply it to -rc4 too.
Comment 33 Chris Clayton 2019-12-30 11:03:43 UTC
Created attachment 286521 [details]
Patch to avoid microcode errors on 5.5 kernels

The patch that I mentioned in comment 32.
Comment 34 Mike Hardy 2020-01-27 18:49:03 UTC
The fix for the loose synchronization of the NSSN across Rx queues made it in to 5.5 release, for anyone following along, and I look forward to mainstream wireless without patch-ery on my rig. Thanks all https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/drivers/net/wireless/intel/iwlwifi/mvm/rxmq.c?id=d829229e35f302fd49c052b5c5906c90ecf9911d
Comment 35 Alexander Haensch 2020-05-12 07:00:50 UTC
I get this with recent 5.4.38. The hardware is new, so i have no experience with older kernels.

It happened while downloading large chuncks of data from steam and having multiple browsertabs open.

BTW: Looks like i get a kernel Oops here. Many processes hung after this event.

iwlwifi 0000:03:00.0: Error sending STATISTICS_CMD: time out after 2000ms.
iwlwifi 0000:03:00.0: Current CMD queue read_ptr 183 write_ptr 184
iwlwifi 0000:03:00.0: HW error, resetting before reading
iwlwifi 0000:03:00.0: Microcode SW error detected. Restarting 0x0.
BUG: kernel NULL pointer dereference, address: 0000000000000008
#PF: supervisor read access in kernel mode
#PF: error_code(0x0000) - not-present page
PGD 1d7ca4067 P4D 1d7ca4067 PUD 0 
Oops: 0000 [#1] PREEMPT SMP NOPTI
CPU: 0 PID: 2129 Comm: irq/80-iwlwifi: Tainted: P           O      5.4.38-gentoo #8
Hardware name: System manufacturer System Product Name/TUF GAMING X570-PLUS (WI-FI), BIOS 1407 04/01/2020
RIP: 0010:iwl_pcie_irq_msix_handler+0x131/0x570 [iwlwifi]
Code: 01 0f 85 4c 02 00 00 48 8b 45 10 44 89 e2 83 e2 02 83 78 10 13 0f 84 e2 01 00 00 85 d2 74 59 48 8b 83 38 72 00 00 48 8b 7d 38 <44> 8b 48 08 41 81 f9 d3 00 00 00 0f 84 bb 03 00 00 41 81 f9 d0 00
RSP: 0018:ffffc900015efe48 EFLAGS: 00010202
RAX: 0000000000000000 RBX: ffff8887d2410318 RCX: 0000000000000000
RDX: 0000000000000002 RSI: 0000000000000282 RDI: ffff8887fa03f0b0
RBP: ffff8887d2410018 R08: 0000000000000000 R09: ffffc900015efde0
R10: 0000000000000000 R11: 0000000000000000 R12: 0000000024000182
R13: 0000000000000000 R14: ffff8887d241900c R15: ffff8887d2417e24
FS:  0000000000000000(0000) GS:ffff8887fe800000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000000000000008 CR3: 00000002a9512000 CR4: 0000000000340ef0
Call Trace:
 ? irq_forced_thread_fn+0x90/0x90
 irq_thread_fn+0x22/0x60
 irq_thread+0xe0/0x170
 ? wake_threads_waitq+0x30/0x30
 kthread+0x10d/0x150
 ? irq_thread_dtor+0xb0/0xb0
 ? kthread_park+0x90/0x90
 ret_from_fork+0x22/0x40
Modules linked in: overlay ip6_tables xt_nat veth xt_MASQUERADE xt_recent ipt_REJECT nf_reject_ipv4 xt_addrtype iptable_nat xt_mark iptable_mangle xt_hashlimit xt_helper xt_tcpudp iptable_raw xt_multiport xt_conntrack nf_log_ipv4 nf_log_common xt_LOG nf_nat_tftp nf_nat_ftp nf_nat nf_conntrack_tf>
 drm_kms_helper cfbfillrect syscopyarea cfbimgblt sysfillrect sysimgblt fb_sys_fops cfbcopyarea fb fbdev ttm drm drm_panel_orientation_quirks xts ecb cbc sha512_generic sha1_generic libiscsi scsi_transport_iscsi ixgb ixgbe dca tulip cxgb3 cxgb mdio vxlan ip6_udp_tunnel udp_tunnel macvlan tg3 sky>
 aic7xxx aic79xx scsi_transport_spi sg pdc_adma sata_inic162x sata_mv ata_piix sata_qstor sata_vsc sata_uli sata_sis sata_sx4 sata_nv sata_via sata_svw sata_sil24 sata_sil sata_promise pata_sl82c105 pata_via pata_jmicron pata_marvell pata_sis pata_netcell pata_pdc202xx_old pata_triflex pata_atii>
CR2: 0000000000000008
---[ end trace 9c9f89a193076623 ]---
RIP: 0010:iwl_pcie_irq_msix_handler+0x131/0x570 [iwlwifi]
Code: 01 0f 85 4c 02 00 00 48 8b 45 10 44 89 e2 83 e2 02 83 78 10 13 0f 84 e2 01 00 00 85 d2 74 59 48 8b 83 38 72 00 00 48 8b 7d 38 <44> 8b 48 08 41 81 f9 d3 00 00 00 0f 84 bb 03 00 00 41 81 f9 d0 00
RSP: 0018:ffffc900015efe48 EFLAGS: 00010202
RAX: 0000000000000000 RBX: ffff8887d2410318 RCX: 0000000000000000
RDX: 0000000000000002 RSI: 0000000000000282 RDI: ffff8887fa03f0b0
RBP: ffff8887d2410018 R08: 0000000000000000 R09: ffffc900015efde0
R10: 0000000000000000 R11: 0000000000000000 R12: 0000000024000182
R13: 0000000000000000 R14: ffff8887d241900c R15: ffff8887d2417e24
FS:  0000000000000000(0000) GS:ffff8887fe800000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000000000000008 CR3: 00000002a9512000 CR4: 0000000000340ef0
BUG: kernel NULL pointer dereference, address: 0000000000000001
#PF: supervisor instruction fetch in kernel mode
#PF: error_code(0x0010) - not-present page
PGD 1d7ca4067 P4D 1d7ca4067 PUD 0 
Oops: 0010 [#2] PREEMPT SMP NOPTI
CPU: 0 PID: 2129 Comm: irq/80-iwlwifi: Tainted: P      D    O      5.4.38-gentoo #8
Hardware name: System manufacturer System Product Name/TUF GAMING X570-PLUS (WI-FI), BIOS 1407 04/01/2020
RIP: 0010:0x1
Code: Bad RIP value.
RSP: 0018:ffffc900015efea8 EFLAGS: 00010282
RAX: 0000000000000001 RBX: 0000000000000000 RCX: 0000000000000000
RDX: 0000000000000001 RSI: 0000000000000000 RDI: ffffc900015efec8
RBP: ffff8887c5dfa170 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: ffff8887c5df9b00
R13: ffffc900015efec8 R14: 0000000000000000 R15: ffff8887c5dfa1ac
FS:  0000000000000000(0000) GS:ffff8887fe800000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: ffffffffffffffd7 CR3: 00000002a9512000 CR4: 0000000000340ef0
Call Trace:
 ? task_work_run+0x84/0xa0
 ? do_exit+0x34c/0xab0
 ? kthread+0x10d/0x150
 ? rewind_stack_do_exit+0x17/0x20
Modules linked in: overlay ip6_tables xt_nat veth xt_MASQUERADE xt_recent ipt_REJECT nf_reject_ipv4 xt_addrtype iptable_nat xt_mark iptable_mangle xt_hashlimit xt_helper xt_tcpudp iptable_raw xt_multiport xt_conntrack nf_log_ipv4 nf_log_common xt_LOG nf_nat_tftp nf_nat_ftp nf_nat nf_conntrack_tf>
 drm_kms_helper cfbfillrect syscopyarea cfbimgblt sysfillrect sysimgblt fb_sys_fops cfbcopyarea fb fbdev ttm drm drm_panel_orientation_quirks xts ecb cbc sha512_generic sha1_generic libiscsi scsi_transport_iscsi ixgb ixgbe dca tulip cxgb3 cxgb mdio vxlan ip6_udp_tunnel udp_tunnel macvlan tg3 sky>
 aic7xxx aic79xx scsi_transport_spi sg pdc_adma sata_inic162x sata_mv ata_piix sata_qstor sata_vsc sata_uli sata_sis sata_sx4 sata_nv sata_via sata_svw sata_sil24 sata_sil sata_promise pata_sl82c105 pata_via pata_jmicron pata_marvell pata_sis pata_netcell pata_pdc202xx_old pata_triflex pata_atii>
CR2: 0000000000000001
---[ end trace 9c9f89a193076624 ]---
RIP: 0010:iwl_pcie_irq_msix_handler+0x131/0x570 [iwlwifi]
Code: 01 0f 85 4c 02 00 00 48 8b 45 10 44 89 e2 83 e2 02 83 78 10 13 0f 84 e2 01 00 00 85 d2 74 59 48 8b 83 38 72 00 00 48 8b 7d 38 <44> 8b 48 08 41 81 f9 d3 00 00 00 0f 84 bb 03 00 00 41 81 f9 d0 00
RSP: 0018:ffffc900015efe48 EFLAGS: 00010202
RAX: 0000000000000000 RBX: ffff8887d2410318 RCX: 0000000000000000
RDX: 0000000000000002 RSI: 0000000000000282 RDI: ffff8887fa03f0b0
RBP: ffff8887d2410018 R08: 0000000000000000 R09: ffffc900015efde0
R10: 0000000000000000 R11: 0000000000000000 R12: 0000000024000182
R13: 0000000000000000 R14: ffff8887d241900c R15: ffff8887d2417e24
FS:  0000000000000000(0000) GS:ffff8887fe800000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: ffffffffffffffd7 CR3: 00000002a9512000 CR4: 0000000000340ef0
Fixing recursive fault but reboot is needed!
iwlwifi 0000:03:00.0: Start IWL Error Log Dump:
iwlwifi 0000:03:00.0: Status: 0x00000040, count: 392696868
iwlwifi 0000:03:00.0: Loaded firmware version: 46.6bf1df06.0
iwlwifi 0000:03:00.0: 0x89FDECA9 | ADVANCED_SYSASSERT          
iwlwifi 0000:03:00.0: 0x526D0BA0 | trm_hw_status0
iwlwifi 0000:03:00.0: 0xC5D672D5 | trm_hw_status1
iwlwifi 0000:03:00.0: 0x51EA9964 | branchlink2
iwlwifi 0000:03:00.0: 0x0765A8D1 | interruptlink1
iwlwifi 0000:03:00.0: 0xFB69B1A0 | interruptlink2
iwlwifi 0000:03:00.0: 0x6BEEBCFB | data1
iwlwifi 0000:03:00.0: 0xCFE84271 | data2
iwlwifi 0000:03:00.0: 0xEEA558D9 | data3
iwlwifi 0000:03:00.0: 0xD6288BC5 | beacon time
iwlwifi 0000:03:00.0: 0xDCC888AA | tsf low
iwlwifi 0000:03:00.0: 0xE9B51804 | tsf hi
iwlwifi 0000:03:00.0: 0x0D1EBB7A | time gp1
iwlwifi 0000:03:00.0: 0xC0B7A7CE | time gp2
iwlwifi 0000:03:00.0: 0x80CF7727 | uCode revision type
iwlwifi 0000:03:00.0: 0x33F2E9C1 | uCode version major
iwlwifi 0000:03:00.0: 0xFDB8CCC7 | uCode version minor
iwlwifi 0000:03:00.0: 0xC37DEB94 | hw version
iwlwifi 0000:03:00.0: 0x0A63989E | board version
iwlwifi 0000:03:00.0: 0xC6D9DC4B | hcmd
iwlwifi 0000:03:00.0: 0xF74691CB | isr0
iwlwifi 0000:03:00.0: 0x628F175B | isr1
iwlwifi 0000:03:00.0: 0x50399C56 | isr2
iwlwifi 0000:03:00.0: 0x90F7C1B7 | isr3
iwlwifi 0000:03:00.0: 0xBF7261A9 | isr4
iwlwifi 0000:03:00.0: 0xAB95713D | last cmd Id
iwlwifi 0000:03:00.0: 0x46DD0B0D | wait_event
iwlwifi 0000:03:00.0: 0x7C075E28 | l2p_control
iwlwifi 0000:03:00.0: 0x6C8FAF10 | l2p_duration
iwlwifi 0000:03:00.0: 0x77D6E53A | l2p_mhvalid
iwlwifi 0000:03:00.0: 0xFE4FF0BD | l2p_addr_match
iwlwifi 0000:03:00.0: 0xDD31B467 | lmpm_pmg_sel
iwlwifi 0000:03:00.0: 0x6D39A349 | timestamp
iwlwifi 0000:03:00.0: 0xFD827DDC | flow_handler
iwlwifi 0000:03:00.0: Start IWL Error Log Dump:
iwlwifi 0000:03:00.0: Status: 0x00000040, count: 538633979
iwlwifi 0000:03:00.0: 0x671DFF0E | ADVANCED_SYSASSERT
iwlwifi 0000:03:00.0: 0xAC3B3B97 | umac branchlink1
iwlwifi 0000:03:00.0: 0x05CFDFAA | umac branchlink2
iwlwifi 0000:03:00.0: 0xE29C5581 | umac interruptlink1
iwlwifi 0000:03:00.0: 0xC5A5DE55 | umac interruptlink2
iwlwifi 0000:03:00.0: 0xB47AB60D | umac data1
iwlwifi 0000:03:00.0: 0xD602FEEC | umac data2
iwlwifi 0000:03:00.0: 0xD50CDF01 | umac data3
iwlwifi 0000:03:00.0: 0xD183C949 | umac major
iwlwifi 0000:03:00.0: 0xCB1C01D3 | umac minor
iwlwifi 0000:03:00.0: 0xEC57DAC9 | frame pointer
iwlwifi 0000:03:00.0: 0x4D9745F5 | stack pointer
iwlwifi 0000:03:00.0: 0x325CADB9 | last host cmd
iwlwifi 0000:03:00.0: 0xC9A9B6C1 | isr status reg
iwlwifi 0000:03:00.0: Fseq Registers:
iwlwifi 0000:03:00.0: 0xA5A5A5A2 | FSEQ_ERROR_CODE
iwlwifi 0000:03:00.0: 0xA5A5A5A2 | FSEQ_TOP_INIT_VERSION
iwlwifi 0000:03:00.0: 0xA5A5A5A2 | FSEQ_CNVIO_INIT_VERSION
iwlwifi 0000:03:00.0: 0xA5A5A5A2 | FSEQ_OTP_VERSION
iwlwifi 0000:03:00.0: 0xA5A5A5A2 | FSEQ_TOP_CONTENT_VERSION
iwlwifi 0000:03:00.0: 0xA5A5A5A2 | FSEQ_ALIVE_TOKEN
iwlwifi 0000:03:00.0: 0xA5A5A5A2 | FSEQ_CNVI_ID
iwlwifi 0000:03:00.0: 0xA5A5A5A2 | FSEQ_CNVR_ID
iwlwifi 0000:03:00.0: 0xA5A5A5A2 | CNVI_AUX_MISC_CHIP
iwlwifi 0000:03:00.0: 0xA5A5A5A2 | CNVR_AUX_MISC_CHIP
iwlwifi 0000:03:00.0: 0xA5A5A5A2 | CNVR_SCU_SD_REGS_SD_REG_DIG_DCDC_VTRIM
iwlwifi 0000:03:00.0: 0xA5A5A5A2 | CNVR_SCU_SD_REGS_SD_REG_ACTIVE_VDIG_MIRROR
iwlwifi 0000:03:00.0: Collecting data: trigger 2 fired.
ieee80211 phy0: Hardware restart was requested