Created attachment 305774 [details]
dmesg-start.log

While running our weekly stress testing I've found that the Lenovo Thinkpad X1 stops being able to suspend to S2idle after about 1200 runs and it appears to be because of the iwlwifi device refusing to suspend. Here is the dmesg output at the first fail:

[23613.839111] iwlwifi 0000:00:14.3: Microcode SW error detected. Restarting 0x0.
[23613.839144] iwlwifi 0000:00:14.3: FW error in SYNC CMD D3_CONFIG_CMD
[23613.839152] CPU: 5 PID: 4587 Comm: kworker/u16:46 Not tainted 6.7.0-dirty #1
[23613.839156] Hardware name: LENOVO 20QA000FUS/20QA000FUS, BIOS N2MET49W (1.14 ) 05/20/2021
[23613.839159] Workqueue: events_unbound async_run_entry_fn
[23613.839169] Call Trace:
[23613.839171]  <TASK>
[23613.839175]  dump_stack_lvl+0x48/0x70
[23613.839189]  dump_stack+0x10/0x20
[23613.839195]  iwl_trans_txq_send_hcmd+0x32c/0x430 [iwlwifi]
[23613.839251]  ? __pfx_autoremove_wake_function+0x10/0x10
[23613.839258]  iwl_trans_send_cmd+0x99/0x100 [iwlwifi]
[23613.839301]  iwl_mvm_send_cmd+0x1f/0x60 [iwlmvm]
[23613.839352]  __iwl_mvm_suspend+0x291/0x460 [iwlmvm]
[23613.839400]  iwl_mvm_suspend+0x3f/0x50 [iwlmvm]
[23613.839439]  __ieee80211_suspend+0x253/0x3a0 [mac80211]
[23613.839600]  ieee80211_suspend+0x1a/0x30 [mac80211]
[23613.839693]  wiphy_suspend+0x9f/0x2d0 [cfg80211]
[23613.839773]  ? __pfx_wiphy_suspend+0x10/0x10 [cfg80211]
[23613.839836]  dpm_run_callback+0x56/0x1a0
[23613.839843]  __device_suspend+0x14c/0x500
[23613.839848]  async_suspend+0x1f/0xb0
[23613.839853]  async_run_entry_fn+0x30/0x120
[23613.839857]  process_scheduled_works+0x9a/0x390
[23613.839862]  worker_thread+0x15b/0x2d0
[23613.839865]  ? __pfx_worker_thread+0x10/0x10
[23613.839868]  kthread+0x106/0x140
[23613.839874]  ? __pfx_kthread+0x10/0x10
[23613.839879]  ret_from_fork+0x39/0x60
[23613.839884]  ? __pfx_kthread+0x10/0x10
[23613.839889]  ret_from_fork_asm+0x1b/0x30
[23613.839898]  </TASK>
[23613.839915] ieee80211 phy0: PM: dpm_run_callback(): wiphy_suspend+0x0/0x2d0 [cfg80211] returns -5
[23613.839984] ieee80211 phy0: PM: failed to suspend async: error -5
[23613.840312] iwlwifi 0000:00:14.3: Start IWL Error Log Dump:
[23613.840315] iwlwifi 0000:00:14.3: Transport status: 0x0000004A, valid: 6
[23613.840318] iwlwifi 0000:00:14.3: Loaded firmware version: 55.d9698065.0 QuZ-a0-hr-b0-55.ucode
[23613.840321] iwlwifi 0000:00:14.3: 0x00000071 | NMI_INTERRUPT_UMAC_FATAL    
[23613.840325] iwlwifi 0000:00:14.3: 0x000020F3 | trm_hw_status0
[23613.840327] iwlwifi 0000:00:14.3: 0x00000000 | trm_hw_status1
[23613.840329] iwlwifi 0000:00:14.3: 0x004CA3DE | branchlink2
[23613.840331] iwlwifi 0000:00:14.3: 0x00007908 | interruptlink1
[23613.840333] iwlwifi 0000:00:14.3: 0x00007908 | interruptlink2
[23613.840334] iwlwifi 0000:00:14.3: 0x0000C876 | data1
[23613.840336] iwlwifi 0000:00:14.3: 0x00001000 | data2
[23613.840338] iwlwifi 0000:00:14.3: 0x00000000 | data3
[23613.840339] iwlwifi 0000:00:14.3: 0xE0C01C92 | beacon time
[23613.840341] iwlwifi 0000:00:14.3: 0x694AB373 | tsf low
[23613.840343] iwlwifi 0000:00:14.3: 0x000002D3 | tsf hi
[23613.840345] iwlwifi 0000:00:14.3: 0x00000000 | time gp1
[23613.840347] iwlwifi 0000:00:14.3: 0xC1979AD5 | time gp2
[23613.840349] iwlwifi 0000:00:14.3: 0x00000001 | uCode revision type
[23613.840351] iwlwifi 0000:00:14.3: 0x00000037 | uCode version major
[23613.840353] iwlwifi 0000:00:14.3: 0xD9698065 | uCode version minor
[23613.840354] iwlwifi 0000:00:14.3: 0x00000000 | hw version
[23613.840356] iwlwifi 0000:00:14.3: 0x00000000 | board version
[23613.840358] iwlwifi 0000:00:14.3: 0x89A7001C | hcmd
[23613.840360] iwlwifi 0000:00:14.3: 0x66F20000 | isr0
[23613.840361] iwlwifi 0000:00:14.3: 0x60000000 | isr1
[23613.840363] iwlwifi 0000:00:14.3: 0x18F00002 | isr2
[23613.840365] iwlwifi 0000:00:14.3: 0x00C37FCE | isr3
[23613.840366] iwlwifi 0000:00:14.3: 0x00000000 | isr4
[23613.840368] iwlwifi 0000:00:14.3: 0x005D01E2 | last cmd Id
[23613.840370] iwlwifi 0000:00:14.3: 0x0000C876 | wait_event
[23613.840372] iwlwifi 0000:00:14.3: 0x000011C8 | l2p_control
[23613.840373] iwlwifi 0000:00:14.3: 0x00001C20 | l2p_duration
[23613.840375] iwlwifi 0000:00:14.3: 0x00000007 | l2p_mhvalid
[23613.840377] iwlwifi 0000:00:14.3: 0x00000010 | l2p_addr_match
[23613.840379] iwlwifi 0000:00:14.3: 0x00000009 | lmpm_pmg_sel
[23613.840381] iwlwifi 0000:00:14.3: 0x00000000 | timestamp
[23613.840382] iwlwifi 0000:00:14.3: 0x00004038 | flow_handler
[23613.840857] iwlwifi 0000:00:14.3: Start IWL Error Log Dump:
[23613.840859] iwlwifi 0000:00:14.3: Transport status: 0x0000004A, valid: 7
[23613.840861] iwlwifi 0000:00:14.3: 0x20100231 | ADVANCED_SYSASSERT
[23613.840863] iwlwifi 0000:00:14.3: 0x00000000 | umac branchlink1
[23613.840865] iwlwifi 0000:00:14.3: 0x80465D2E | umac branchlink2
[23613.840867] iwlwifi 0000:00:14.3: 0x8046A12C | umac interruptlink1
[23613.840869] iwlwifi 0000:00:14.3: 0x00000000 | umac interruptlink2
[23613.840871] iwlwifi 0000:00:14.3: 0x00000001 | umac data1
[23613.840872] iwlwifi 0000:00:14.3: 0x01058644 | umac data2
[23613.840874] iwlwifi 0000:00:14.3: 0x00000000 | umac data3
[23613.840876] iwlwifi 0000:00:14.3: 0x00000037 | umac major
[23613.840878] iwlwifi 0000:00:14.3: 0xD9698065 | umac minor
[23613.840880] iwlwifi 0000:00:14.3: 0xC1979AC9 | frame pointer
[23613.840881] iwlwifi 0000:00:14.3: 0xC0887F0C | stack pointer
[23613.840883] iwlwifi 0000:00:14.3: 0x006401D3 | last host cmd
[23613.840885] iwlwifi 0000:00:14.3: 0x00000000 | isr status reg
[23613.841006] iwlwifi 0000:00:14.3: IML/ROM dump:
[23613.841007] iwlwifi 0000:00:14.3: 0x00000003 | IML/ROM error/state
[23613.841105] iwlwifi 0000:00:14.3: 0x00005B99 | IML/ROM data1
[23613.841204] iwlwifi 0000:00:14.3: 0x00000080 | IML/ROM WFPM_AUTH_KEY_0
[23613.841254] iwlwifi 0000:00:14.3: Fseq Registers:
[23613.841280] iwlwifi 0000:00:14.3: 0x60000000 | FSEQ_ERROR_CODE
[23613.841308] iwlwifi 0000:00:14.3: 0x80290033 | FSEQ_TOP_INIT_VERSION
[23613.841336] iwlwifi 0000:00:14.3: 0x00090006 | FSEQ_CNVIO_INIT_VERSION
[23613.841364] iwlwifi 0000:00:14.3: 0x0000A482 | FSEQ_OTP_VERSION
[23613.841392] iwlwifi 0000:00:14.3: 0x00000003 | FSEQ_TOP_CONTENT_VERSION
[23613.841418] iwlwifi 0000:00:14.3: 0x4552414E | FSEQ_ALIVE_TOKEN
[23613.841446] iwlwifi 0000:00:14.3: 0x20000302 | FSEQ_CNVI_ID
[23613.841473] iwlwifi 0000:00:14.3: 0x01300504 | FSEQ_CNVR_ID
[23613.841517] iwlwifi 0000:00:14.3: 0x20000302 | CNVI_AUX_MISC_CHIP
[23613.841567] iwlwifi 0000:00:14.3: 0x01300504 | CNVR_AUX_MISC_CHIP
[23613.841597] iwlwifi 0000:00:14.3: 0x05B0905B | CNVR_SCU_SD_REGS_SD_REG_DIG_DCDC_VTRIM
[23613.841627] iwlwifi 0000:00:14.3: 0x0000025B | CNVR_SCU_SD_REGS_SD_REG_ACTIVE_VDIG_MIRROR
[23613.841655] iwlwifi 0000:00:14.3: 0x00090006 | FSEQ_PREV_CNVIO_INIT_VERSION
[23613.841674] iwlwifi 0000:00:14.3: 0x00290033 | FSEQ_WIFI_FSEQ_VERSION
[23613.841706] iwlwifi 0000:00:14.3: 0x00290033 | FSEQ_BT_FSEQ_VERSION
[23613.841725] iwlwifi 0000:00:14.3: 0x000000DC | FSEQ_CLASS_TP_VERSION
[23613.842512] async_waiting @ 4480 [python3]
[23613.842831] iwlwifi 0000:00:14.3: WRT: Collecting data: ini trigger 4 fired (delay=0ms).
[23613.986736] async_continuing @ 4480 [python3] after 140679 usec
[23613.986761] PM: suspend of devices aborted after 162.841 msecs
[23613.986763] PM: start suspend of devices aborted after 180.268 msecs
[23613.986785] PM: Some devices failed to suspend, or early wake event detected

I've attached the dmesg boot log for info on the device itself and firmware. The interesting thing is that the wifi network stays up just fine, it's just that the device refuses to respond to the request to suspend.