Re: Fwd: iwlwifi causes dma-iommu.c:693 __iommu_dma_unmap since commit 19898ce9cf8a

[Xi Ruoyao <xry111@xry111.site>]

On Sun, 2023-07-02 at 19:13 +0700, Bagas Sanjaya wrote:
> Hi,
> 
> I notice a regression report on Bugzilla [1]: Quoting from it:
> 
> > Since commit 19898ce9cf8a the iwlwifi has generated three possibly
> > identical kernel stack traces for me. Because I only use the
> > Bluetooth but not the Wi-Fi functionality, this is not a big deal
> > for me but I thought such an issue is worth reporting nontheless.
> > 
> > All three traces point at **drivers/iommu/dma-iommu.c:693
> > __iommu_dma_unmap+0x150/0x160**.
> > 
> > I'm attaching to this bug report the three stack traces along with
> > other possibly relevant dmesg parts. Sorry in advance for not
> > cutting at the cut here markers which resulted in considerably
> > longer text but I suspected that the PCI, ACPI, memory and possibly
> > iwlwifi related messages may be of importance, too. If I should cut
> > the stack traces out and attach them as three distinct files (and
> > diff to see if there's any change between them) let me know. I can
> > provide a full (but redacted) dmesg output of a git master build, if
> > required as well.
> > 
> > I did try booting a much more recent git master build with
> > *iommu.passthrough=0 iommu.strict=0* on the kernel command line but
> > that did not seem to make any difference.
> > 
> > ```
> > 19898ce9cf8a33e0ac35cb4c7f68de297cc93cb2 is the first bad commit
> > commit 19898ce9cf8a33e0ac35cb4c7f68de297cc93cb2
> > Author: Johannes Berg <johannes.berg@intel.com>
> > Date:   Wed Jun 21 13:12:07 2023 +0300
> > 
> >     wifi: iwlwifi: split 22000.c into multiple files
> >     
> >     Split the configuration list in 22000.c into four new files,
> >     per new device family, so we don't have this huge unusable
> >     file. Yes, this duplicates a few small things, but that's
> >     still much better than what we have now.
> >     
> >     Signed-off-by: Johannes Berg <johannes.berg@intel.com>
> >     Signed-off-by: Gregory Greenman <gregory.greenman@intel.com>
> >     Link:
> > https://lore.kernel.org/r/20230621130443.7543603b2ee7.Ia8dd54216d341ef1ddc0531f2c9aa30d30536a5d@changeid
> >     Signed-off-by: Johannes Berg <johannes.berg@intel.com>
> > 
> >  drivers/net/wireless/intel/iwlwifi/Makefile     |   1 +
> >  drivers/net/wireless/intel/iwlwifi/cfg/22000.c  | 939 +------------
> > -----------
> >  drivers/net/wireless/intel/iwlwifi/cfg/ax210.c  | 452 ++++++++++++
> >  drivers/net/wireless/intel/iwlwifi/cfg/bz.c     | 523 +++++++++++++
> >  drivers/net/wireless/intel/iwlwifi/cfg/sc.c     | 214 ++++++
> >  drivers/net/wireless/intel/iwlwifi/iwl-config.h |   2 +
> >  drivers/net/wireless/intel/iwlwifi/pcie/drv.c   |   3 +
> >  7 files changed, 1206 insertions(+), 928 deletions(-)
> >  create mode 100644 drivers/net/wireless/intel/iwlwifi/cfg/ax210.c
> >  create mode 100644 drivers/net/wireless/intel/iwlwifi/cfg/bz.c
> >  create mode 100644 drivers/net/wireless/intel/iwlwifi/cfg/sc.c
> > ```
> > 
> 
> See Bugzilla for the full thread and attached dmesg.

I can reproduce the issue with an AX210 (the firmware is named iwlwifi-
ty-a0-gf-a0-81.ucode).  Reverting
19898ce9cf8a33e0ac35cb4c7f68de297cc93cb2 (and all following commits in
the same series) fixes the issue.

I guess some error messages might be useful:

[    4.058873] iwlwifi 0000:2b:00.0: Error sending NVM_ACCESS_COMPLETE: time out after 2000ms.
[    4.060263] iwlwifi 0000:2b:00.0: Current CMD queue read_ptr 1 write_ptr 2
[    4.062814] iwlwifi 0000:2b:00.0: Start IWL Error Log Dump:
[    4.064440] iwlwifi 0000:2b:00.0: Transport status: 0x0000004A, valid: 6
[    4.065481] iwlwifi 0000:2b:00.0: Loaded firmware version: 81.31fc9ae6.0 ty-a0-gf-a0-81.ucode
[    4.066655] iwlwifi 0000:2b:00.0: 0x00000084 | NMI_INTERRUPT_UNKNOWN       
[    4.067725] iwlwifi 0000:2b:00.0: 0x002002F0 | trm_hw_status0
[    4.068799] iwlwifi 0000:2b:00.0: 0x00000000 | trm_hw_status1
[    4.069777] iwlwifi 0000:2b:00.0: 0x004DBEE0 | branchlink2
[    4.070828] iwlwifi 0000:2b:00.0: 0x004D1DEA | interruptlink1
[    4.071823] iwlwifi 0000:2b:00.0: 0x004D1DEA | interruptlink2
[    4.072774] iwlwifi 0000:2b:00.0: 0x00016582 | data1
[    4.073714] iwlwifi 0000:2b:00.0: 0x01000000 | data2
[    4.074748] iwlwifi 0000:2b:00.0: 0x00000000 | data3
[    4.075681] iwlwifi 0000:2b:00.0: 0x00000000 | beacon time
[    4.076695] iwlwifi 0000:2b:00.0: 0x002097F1 | tsf low
[    4.077721] iwlwifi 0000:2b:00.0: 0x00000000 | tsf hi
[    4.078660] iwlwifi 0000:2b:00.0: 0x00000000 | time gp1
[    4.079680] iwlwifi 0000:2b:00.0: 0x0021B671 | time gp2
[    4.080678] iwlwifi 0000:2b:00.0: 0x00000001 | uCode revision type
[    4.081667] iwlwifi 0000:2b:00.0: 0x00000051 | uCode version major
[    4.082653] iwlwifi 0000:2b:00.0: 0x31FC9AE6 | uCode version minor
[    4.083655] iwlwifi 0000:2b:00.0: 0x00000420 | hw version
[    4.084636] iwlwifi 0000:2b:00.0: 0x18C80002 | board version
[    4.085613] iwlwifi 0000:2b:00.0: 0x8005FF00 | hcmd
[    4.086578] iwlwifi 0000:2b:00.0: 0x00020000 | isr0
[    4.087527] iwlwifi 0000:2b:00.0: 0x00000000 | isr1
[    4.088469] iwlwifi 0000:2b:00.0: 0x48F00002 | isr2
[    4.089390] iwlwifi 0000:2b:00.0: 0x00C0001C | isr3
[    4.090307] iwlwifi 0000:2b:00.0: 0x00000000 | isr4
[    4.091202] iwlwifi 0000:2b:00.0: 0x00000000 | last cmd Id
[    4.092083] iwlwifi 0000:2b:00.0: 0x00016582 | wait_event
[    4.092943] iwlwifi 0000:2b:00.0: 0x00000000 | l2p_control
[    4.093801] iwlwifi 0000:2b:00.0: 0x00000000 | l2p_duration
[    4.094639] iwlwifi 0000:2b:00.0: 0x00000000 | l2p_mhvalid
[    4.095525] iwlwifi 0000:2b:00.0: 0x00000000 | l2p_addr_match
[    4.097449] iwlwifi 0000:2b:00.0: 0x00000009 | lmpm_pmg_sel
[    4.098323] iwlwifi 0000:2b:00.0: 0x00000000 | timestamp
[    4.099165] iwlwifi 0000:2b:00.0: 0x00000024 | flow_handler
[    4.100024] iwlwifi 0000:2b:00.0: Start IWL Error Log Dump:
[    4.100832] iwlwifi 0000:2b:00.0: Transport status: 0x0000004A, valid: 7
[    4.101641] iwlwifi 0000:2b:00.0: 0x20000066 | NMI_INTERRUPT_HOST
[    4.102522] iwlwifi 0000:2b:00.0: 0x00000000 | umac branchlink1
[    4.103379] iwlwifi 0000:2b:00.0: 0x8046DA88 | umac branchlink2
[    4.104210] iwlwifi 0000:2b:00.0: 0x8048DB3A | umac interruptlink1
[    4.105014] iwlwifi 0000:2b:00.0: 0x8048DB3A | umac interruptlink2
[    4.105790] iwlwifi 0000:2b:00.0: 0x01000000 | umac data1
[    4.106544] iwlwifi 0000:2b:00.0: 0x8048DB3A | umac data2
[    4.107338] iwlwifi 0000:2b:00.0: 0x00000000 | umac data3
[    4.108109] iwlwifi 0000:2b:00.0: 0x00000051 | umac major
[    4.108855] iwlwifi 0000:2b:00.0: 0x31FC9AE6 | umac minor
[    4.109581] iwlwifi 0000:2b:00.0: 0x0021B66F | frame pointer
[    4.110349] iwlwifi 0000:2b:00.0: 0xC0886258 | stack pointer
[    4.111099] iwlwifi 0000:2b:00.0: 0x00000203 | last host cmd
[    4.111815] iwlwifi 0000:2b:00.0: 0x00000400 | isr status reg
[    4.112530] iwlwifi 0000:2b:00.0: IML/ROM dump:
[    4.113265] iwlwifi 0000:2b:00.0: 0x00000B03 | IML/ROM error/state
[    4.113982] iwlwifi 0000:2b:00.0: 0x000076E7 | IML/ROM data1
[    4.114689] iwlwifi 0000:2b:00.0: 0x00000090 | IML/ROM WFPM_AUTH_KEY_0
[    4.115447] iwlwifi 0000:2b:00.0: Fseq Registers:
[    4.116168] iwlwifi 0000:2b:00.0: 0x60000100 | FSEQ_ERROR_CODE
[    4.116867] iwlwifi 0000:2b:00.0: 0x80440007 | FSEQ_TOP_INIT_VERSION
[    4.117548] iwlwifi 0000:2b:00.0: 0x00080009 | FSEQ_CNVIO_INIT_VERSION
[    4.118265] iwlwifi 0000:2b:00.0: 0x0000A652 | FSEQ_OTP_VERSION
[    4.118946] iwlwifi 0000:2b:00.0: 0x00000002 | FSEQ_TOP_CONTENT_VERSION
[    4.119624] iwlwifi 0000:2b:00.0: 0x4552414E | FSEQ_ALIVE_TOKEN
[    4.121025] iwlwifi 0000:2b:00.0: 0x00400410 | FSEQ_CNVR_ID
[    4.121675] iwlwifi 0000:2b:00.0: 0x00400410 | CNVI_AUX_MISC_CHIP
[    4.122377] iwlwifi 0000:2b:00.0: 0x00400410 | CNVR_AUX_MISC_CHIP
[    4.123048] iwlwifi 0000:2b:00.0: 0x00009061 | CNVR_SCU_SD_REGS_SD_REG_DIG_DCDC_VTRIM
[    4.123693] iwlwifi 0000:2b:00.0: 0x00000061 | CNVR_SCU_SD_REGS_SD_REG_ACTIVE_VDIG_MIRROR
[    4.124383] iwlwifi 0000:2b:00.0: 0x00080009 | FSEQ_PREV_CNVIO_INIT_VERSION
[    4.125055] iwlwifi 0000:2b:00.0: 0x00440005 | FSEQ_WIFI_FSEQ_VERSION
[    4.125703] iwlwifi 0000:2b:00.0: 0x00440005 | FSEQ_BT_FSEQ_VERSION
[    4.126407] iwlwifi 0000:2b:00.0: 0x000000D2 | FSEQ_CLASS_TP_VERSION
[    4.127103] iwlwifi 0000:2b:00.0: UMAC CURRENT PC: 0x8048d640
[    4.127769] iwlwifi 0000:2b:00.0: LMAC1 CURRENT PC: 0xd0
[    4.128437] iwlwifi 0000:2b:00.0: Failed to run complete NVM access: -110
[    4.129134] iwlwifi 0000:2b:00.0: WRT: Collecting data: ini trigger 13 fired (delay=0ms).

And (part of) the stack trace:

[    5.071954]  iommu_dma_free+0x17/0x30
[    5.073232]  iwl_txq_gen2_free_memory+0x39/0x90 [iwlwifi]
[    5.074572]  iwl_txq_gen2_free+0x53/0xe0 [iwlwifi]
[    5.075954]  iwl_txq_gen2_tx_free+0x34/0x50 [iwlwifi]
[    5.077244]  _iwl_trans_pcie_gen2_stop_device+0x2f6/0x470 [iwlwifi]
[    5.078589]  iwl_trans_pcie_gen2_stop_device+0x50/0x70 [iwlwifi]
[    5.079993]  iwl_mvm_stop_device+0x35/0x50 [iwlmvm]
[    5.081307]  iwl_mvm_start_get_nvm+0x151/0x1d0 [iwlmvm]
[    5.082664]  iwl_op_mode_mvm_start+0x7b8/0x970 [iwlmvm]
[    5.084066]  _iwl_op_mode_start.isra.0+0x58/0x70 [iwlwifi]
[    5.085387]  iwl_opmode_register+0x68/0xd0 [iwlwifi]
[    5.086746]  ? 0xffffffffc0cf3000
[    5.088013]  iwl_mvm_init+0x21/0x1000 [iwlmvm]

I compared the iwlax210_2ax_cfg_ty_gf_a0 struct in the preprocessed
source before and after 19898ce9cf8a33e0ac35cb4c7f68de297cc93cb2 change.
The only suspicious change is the removal of ".trans.use_tfh = true,",
but adding this line into iwlax210_2ax_cfg_ty_gf_a0 does not fix the
issue.


-- 
Xi Ruoyao <xry111@xry111.site>
School of Aerospace Science and Technology, Xidian University