Hi,
On Thu, 2023-09-21 at 13:24 -0400, Antoine Beaupré wrote:
> Hi,
>
> I've found what I feel might be a regression between Linux 6.1 and
> 6.5. For other reasons, I upgraded the kernel on my Debian 12
> ("bookworm", stale) laptop from the distribution 6.1.52 to the unstable
> ("sid") version, 6.5.3.
>
> After the upgrade, I started to notice stuttering in my audio player, I
> tracked it down and managed to correlate it with some kernel errors
> related to the iwlwifi driver.
>
> What's interesting is that this happens regardless of whether or not the
> NIC is connected to a network. In at least one of the traces, the
> computer was connected over a wire and wireless was not associated in
> Network Manager.
>
> Here's an example of the problem:
>
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: Microcode SW error detected. Restarting 0x0.
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: Start IWL Error Log Dump:
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: Transport status: 0x0000004B, valid: 6
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: Loaded firmware version: 73.35c0a2c6.0 ty-a0-gf-a0-73.ucode
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00000071 | NMI_INTERRUPT_UMAC_FATAL
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x000002F0 | trm_hw_status0
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00000000 | trm_hw_status1
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x004DB676 | branchlink2
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x004DAFCA | interruptlink1
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x004DAFCA | interruptlink2
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00016B8A | data1
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00000010 | data2
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00000000 | data3
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x003CF2BA | beacon time
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x01AF1EAD | tsf low
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00000000 | tsf hi
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00000000 | time gp1
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x01B06739 | time gp2
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00000001 | uCode revision type
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00000049 | uCode version major
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x35C0A2C6 | uCode version minor
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00000420 | hw version
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00C80002 | board version
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x80BBFF00 | hcmd
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00020000 | isr0
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00000000 | isr1
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x48F04002 | isr2
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00C3000C | isr3
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00000000 | isr4
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00220103 | last cmd Id
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00016B8A | wait_event
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00000000 | l2p_control
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00000000 | l2p_duration
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00000000 | l2p_mhvalid
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00000000 | l2p_addr_match
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00000018 | lmpm_pmg_sel
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00000000 | timestamp
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x0000284C | flow_handler
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: Start IWL Error Log Dump:
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: Transport status: 0x0000004B, valid: 7
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x20103600 | ADVANCED_SYSASSERT
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00000000 | umac branchlink1
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x8045F174 | umac branchlink2
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x8047A13C | umac interruptlink1
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00000000 | umac interruptlink2
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x000000FF | umac data1
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0xDEADBEEF | umac data2
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0xDEADBEEF | umac data3
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00000049 | umac major
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x35C0A2C6 | umac minor
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x01B06733 | frame pointer
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0xC0886C0C | stack pointer
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x002B010D | last host cmd
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00000000 | isr status reg
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: IML/ROM dump:
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00000B03 | IML/ROM error/state
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00008510 | IML/ROM data1
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00000080 | IML/ROM WFPM_AUTH_KEY_0
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: Fseq Registers:
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x60000100 | FSEQ_ERROR_CODE
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00440007 | FSEQ_TOP_INIT_VERSION
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00080009 | FSEQ_CNVIO_INIT_VERSION
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x0000A652 | FSEQ_OTP_VERSION
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00000002 | FSEQ_TOP_CONTENT_VERSION
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x4552414E | FSEQ_ALIVE_TOKEN
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00400410 | FSEQ_CNVI_ID
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00400410 | FSEQ_CNVR_ID
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00400410 | CNVI_AUX_MISC_CHIP
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00400410 | CNVR_AUX_MISC_CHIP
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00009061 | CNVR_SCU_SD_REGS_SD_REG_DIG_DCDC_VTRIM
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00000061 | CNVR_SCU_SD_REGS_SD_REG_ACTIVE_VDIG_MIRROR
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00080009 | FSEQ_PREV_CNVIO_INIT_VERSION
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00440005 | FSEQ_WIFI_FSEQ_VERSION
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x00440007 | FSEQ_BT_FSEQ_VERSION
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: 0x000000DC | FSEQ_CLASS_TP_VERSION
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: WRT: Collecting data: ini trigger 4 fired (delay=0ms).
> sep 21 09:33:14 angela kernel: ieee80211 phy0: Hardware restart was requested
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: FW error in SYNC CMD SCAN_REQ_UMAC
> sep 21 09:33:14 angela kernel: CPU: 7 PID: 1563 Comm: wpa_supplicant Tainted: G W 6.5.0-1-amd64 #1 Debian 6.5.3-1
> sep 21 09:33:14 angela kernel: Hardware name: Framework Laptop (12th Gen Intel Core)/FRANMACP04, BIOS 03.06 11/10/2022
> sep 21 09:33:14 angela kernel: Call Trace:
> sep 21 09:33:14 angela kernel: <TASK>
> sep 21 09:33:14 angela kernel: dump_stack_lvl+0x47/0x60
> sep 21 09:33:14 angela kernel: iwl_trans_txq_send_hcmd+0x33d/0x450 [iwlwifi]
> sep 21 09:33:14 angela kernel: ? __pfx_autoremove_wake_function+0x10/0x10
> sep 21 09:33:14 angela kernel: iwl_trans_send_cmd+0x66/0x100 [iwlwifi]
> sep 21 09:33:14 angela kernel: iwl_mvm_send_cmd+0x16/0x40 [iwlmvm]
> sep 21 09:33:14 angela kernel: iwl_mvm_reg_scan_start+0x3f0/0x610 [iwlmvm]
> sep 21 09:33:14 angela kernel: iwl_mvm_mac_hw_scan+0x4e/0x70 [iwlmvm]
> sep 21 09:33:14 angela kernel: drv_hw_scan+0x98/0x150 [mac80211]
> sep 21 09:33:14 angela kernel: __ieee80211_start_scan+0x255/0x6f0 [mac80211]
> sep 21 09:33:14 angela kernel: ieee80211_request_scan+0x2f/0x50 [mac80211]
> sep 21 09:33:14 angela kernel: rdev_scan+0x25/0xd0 [cfg80211]
> sep 21 09:33:14 angela kernel: nl80211_trigger_scan+0x409/0x7e0 [cfg80211]
> sep 21 09:33:14 angela kernel: genl_family_rcv_msg_doit.isra.0+0xe3/0x140
> sep 21 09:33:14 angela kernel: genl_rcv_msg+0x1b1/0x2c0
> sep 21 09:33:14 angela kernel: ? __pfx_nl80211_pre_doit+0x10/0x10 [cfg80211]
> sep 21 09:33:14 angela kernel: ? __pfx_nl80211_trigger_scan+0x10/0x10 [cfg80211]
> sep 21 09:33:14 angela kernel: ? __pfx_nl80211_post_doit+0x10/0x10 [cfg80211]
> sep 21 09:33:14 angela kernel: ? __pfx_genl_rcv_msg+0x10/0x10
> sep 21 09:33:14 angela kernel: netlink_rcv_skb+0x58/0x110
> sep 21 09:33:14 angela kernel: genl_rcv+0x28/0x40
> sep 21 09:33:14 angela kernel: netlink_unicast+0x19e/0x290
> sep 21 09:33:14 angela kernel: netlink_sendmsg+0x254/0x4d0
> sep 21 09:33:14 angela kernel: sock_sendmsg+0x93/0xa0
> sep 21 09:33:14 angela kernel: ____sys_sendmsg+0x278/0x300
> sep 21 09:33:14 angela kernel: ? copy_msghdr_from_user+0x7d/0xc0
> sep 21 09:33:14 angela kernel: ___sys_sendmsg+0x9a/0xe0
> sep 21 09:33:14 angela kernel: __sys_sendmsg+0x7a/0xd0
> sep 21 09:33:14 angela kernel: do_syscall_64+0x5d/0xc0
> sep 21 09:33:14 angela kernel: ? do_syscall_64+0x6c/0xc0
> sep 21 09:33:14 angela kernel: ? do_syscall_64+0x6c/0xc0
> sep 21 09:33:14 angela kernel: ? fpregs_assert_state_consistent+0x26/0x50
> sep 21 09:33:14 angela kernel: ? exit_to_user_mode_prepare+0x40/0x1d0
> sep 21 09:33:14 angela kernel: ? syscall_exit_to_user_mode+0x2b/0x40
> sep 21 09:33:14 angela kernel: ? do_syscall_64+0x6c/0xc0
> sep 21 09:33:14 angela kernel: ? do_syscall_64+0x6c/0xc0
> sep 21 09:33:14 angela kernel: ? do_syscall_64+0x6c/0xc0
> sep 21 09:33:14 angela kernel: ? do_syscall_64+0x6c/0xc0
> sep 21 09:33:14 angela kernel: entry_SYSCALL_64_after_hwframe+0x6e/0xd8
> sep 21 09:33:14 angela kernel: RIP: 0033:0x7fdbfbf29910
> sep 21 09:33:14 angela kernel: Code: 00 f7 d8 64 89 02 48 c7 c0 ff ff ff ff eb b7 66 2e 0f 1f 84 00 00 00 00 00 90 80 3d d1 fc 0c 00 00 74 17 b8 2e 00 00 00>
> sep 21 09:33:14 angela kernel: RSP: 002b:00007ffedc261e78 EFLAGS: 00000202 ORIG_RAX: 000000000000002e
> sep 21 09:33:14 angela kernel: RAX: ffffffffffffffda RBX: 00005568b18cf900 RCX: 00007fdbfbf29910
> sep 21 09:33:14 angela kernel: RDX: 0000000000000000 RSI: 00007ffedc261eb0 RDI: 0000000000000006
> sep 21 09:33:14 angela kernel: RBP: 00005568b1949360 R08: 0000000000000004 R09: 0000000000000000
> sep 21 09:33:14 angela kernel: R10: 00007ffedc261f94 R11: 0000000000000202 R12: 00005568b18cfbe0
> sep 21 09:33:14 angela kernel: R13: 00007ffedc261eb0 R14: 0000000000000000 R15: 00007ffedc261f94
> sep 21 09:33:14 angela kernel: </TASK>
> sep 21 09:33:14 angela kernel: iwlwifi 0000:a6:00.0: Scan failed! ret -5
> sep 21 09:33:14 angela kernel: ------------[ cut here ]------------
> sep 21 09:33:14 angela kernel: WARNING: CPU: 15 PID: 133361 at net/mac80211/scan.c:423 __ieee80211_scan_completed+0x308/0x320 [mac80211]
> sep 21 09:33:14 angela kernel: Modules linked in: cdc_mbim cdc_wdm xfrm_user xfrm_algo nvme_fabrics ctr ccm rfcomm cmac algif_hash algif_skcipher af_alg tls>
> sep 21 09:33:14 angela kernel: nf_reject_ipv4 intel_uncore_frequency_common snd_hda_codec_idt snd_soc_acpi nf_reject_ipv6 x86_pkg_temp_thermal snd_hda_code>
> sep 21 09:33:14 angela kernel: configfs ip_tables x_tables autofs4 ext4 crc16 mbcache jbd2 btrfs blake2b_generic dm_crypt dm_mod efivarfs raid10 raid456 as>
> sep 21 09:33:14 angela kernel: CPU: 15 PID: 133361 Comm: kworker/u32:22 Tainted: G W 6.5.0-1-amd64 #1 Debian 6.5.3-1
> sep 21 09:33:14 angela kernel: Hardware name: Framework Laptop (12th Gen Intel Core)/FRANMACP04, BIOS 03.06 11/10/2022
> sep 21 09:33:14 angela kernel: Workqueue: phy0 ieee80211_scan_work [mac80211]
> sep 21 09:33:14 angela kernel: RIP: 0010:__ieee80211_scan_completed+0x308/0x320 [mac80211]
> sep 21 09:33:14 angela kernel: Code: 0a 00 48 85 c0 74 0c 48 8b 78 08 48 89 ee e8 6f 49 04 00 65 ff 0d 10 49 2a 3e 0f 85 b1 fe ff ff 0f 1f 44 00 00 e9 a7 fe>
> sep 21 09:33:14 angela kernel: RSP: 0018:ffffb42640ab7dc8 EFLAGS: 00010246
> sep 21 09:33:14 angela kernel: RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
> sep 21 09:33:14 angela kernel: RDX: 0000000000000000 RSI: 0000000000000001 RDI: ffff9399481e8900
> sep 21 09:33:14 angela kernel: RBP: ffff9399481e8900 R08: 0000000000000000 R09: 0000000000000000
> sep 21 09:33:14 angela kernel: R10: 0000000000000001 R11: 0000000000000000 R12: ffff9399481e9b00
> sep 21 09:33:14 angela kernel: R13: 0000000000000000 R14: ffff9399634ff335 R15: 0000000000000001
> sep 21 09:33:14 angela kernel: FS: 0000000000000000(0000) GS:ffff93a0ef9c0000(0000) knlGS:0000000000000000
> sep 21 09:33:14 angela kernel: CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> sep 21 09:33:14 angela kernel: CR2: 00005614e1215588 CR3: 00000008a8020000 CR4: 0000000000f50ee0
> sep 21 09:33:14 angela kernel: PKRU: 55555554
> sep 21 09:33:14 angela kernel: Call Trace:
> sep 21 09:33:14 angela kernel: <TASK>
> sep 21 09:33:14 angela kernel: ? __ieee80211_scan_completed+0x308/0x320 [mac80211]
> sep 21 09:33:14 angela kernel: ? __warn+0x81/0x130
> sep 21 09:33:14 angela kernel: ? __ieee80211_scan_completed+0x308/0x320 [mac80211]
> sep 21 09:33:14 angela kernel: ? report_bug+0x191/0x1c0
> sep 21 09:33:14 angela kernel: ? handle_bug+0x3c/0x80
> sep 21 09:33:14 angela kernel: ? exc_invalid_op+0x17/0x70
> sep 21 09:33:14 angela kernel: ? asm_exc_invalid_op+0x1a/0x20
> sep 21 09:33:14 angela kernel: ? __ieee80211_scan_completed+0x308/0x320 [mac80211]
> sep 21 09:33:14 angela kernel: ieee80211_scan_work+0x127/0x5d0 [mac80211]
> sep 21 09:33:14 angela kernel: ? __schedule+0x3e7/0xb80
> sep 21 09:33:14 angela kernel: process_one_work+0x1de/0x3f0
> sep 21 09:33:14 angela kernel: worker_thread+0x51/0x390
> sep 21 09:33:14 angela kernel: ? __pfx_worker_thread+0x10/0x10
> sep 21 09:33:14 angela kernel: kthread+0xf4/0x130
> sep 21 09:33:14 angela kernel: ? __pfx_kthread+0x10/0x10
> sep 21 09:33:14 angela kernel: ret_from_fork+0x31/0x50
> sep 21 09:33:14 angela kernel: ? __pfx_kthread+0x10/0x10
> sep 21 09:33:14 angela kernel: ret_from_fork_asm+0x1b/0x30
> sep 21 09:33:14 angela kernel: </TASK>
> sep 21 09:33:14 angela kernel: ---[ end trace 0000000000000000 ]---
> sep 21 09:33:14 angela wpa_supplicant[1563]: wlan0: CTRL-EVENT-SCAN-FAILED ret=-5
> sep 21 09:33:15 angela kernel: iwlwifi 0000:a6:00.0: WFPM_UMAC_PD_NOTIFICATION: 0x1f
> sep 21 09:33:15 angela kernel: iwlwifi 0000:a6:00.0: WFPM_LMAC2_PD_NOTIFICATION: 0x1f
> sep 21 09:33:15 angela kernel: iwlwifi 0000:a6:00.0: WFPM_AUTH_KEY_0: 0x80
> sep 21 09:33:15 angela kernel: iwlwifi 0000:a6:00.0: CNVI_SCU_SEQ_DATA_DW9: 0x0
> sep 21 09:33:15 angela wpa_supplicant[1563]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=DRIVER type=WORLD
>
>
> Thanks for any ideas!
>
This firmware assert is related to the periodic scan wifi performs occasionally.
But, this firmware is rather old, it was relased in June 2022 and a lot of fixes and other changes were
introduced since then. The default driver from kernel 6.5 should load one of the latest firmwares,
availble at [1].
[1] http://git.kernel.org/pub/scm/linux/kernel/git/firmware/linux-firmware.git
