Hi, On 8/23/22 10:04, Mathias Nyman wrote: > On 19.8.2022 15.04, Hans de Goede wrote: >> Hi All, >> >> While dogfooding 6.0-rc1 on my main workstation I noticed the following >> new WARN/oops: >> >> Aug 19 12:22:39 shalem kernel: ------------[ cut here ]------------ >> Aug 19 12:22:39 shalem kernel: DMA-API: xhci_hcd 0000:30:00.3: cacheline tracking EEXIST, overlapping mappings aren't supported >> Aug 19 12:22:39 shalem kernel: WARNING: CPU: 14 PID: 8321 at kernel/dma/debug.c:570 add_dma_entry+0x1ed/0x270 >> Aug 19 12:22:39 shalem kernel: Modules linked in: rfcomm snd_seq_dummy snd_hrtimer qrtr bnep vboxnetadp(OE) vboxnetflt(OE) vboxdrv(OE) binfmt_misc vfat fat intel_rapl_msr intel_rapl_common iwlmvm snd_hda_codec_realtek snd_hda_codec_generic edac_mce_amd mac80211 ledtrig_audio snd_hda_codec_hdmi kvm_amd snd_hda_intel snd_intel_dspcfg snd_intel_sdw_acpi libarc4 kvm snd_hda_codec irqbypass iwlwifi snd_hda_core snd_usb_audio btusb rapl btrtl snd_usbmidi_lib iwlmei btbcm snd_hwdep btintel snd_rawmidi snd_seq mc btmtk snd_seq_device cfg80211 wmi_bmof bluetooth snd_pcm joydev snd_timer rfkill mei r8169 snd soundcore i2c_piix4 k10temp gpio_amdpt gpio_generic zram dm_crypt amdgpu drm_ttm_helper ttm iommu_v2 crct10dif_pclmul gpu_sched crc32_pclmul crc32c_intel drm_buddy hid_lg_g15 drm_display_helper nvme ghash_clmulni_intel nvme_core ccp cec sp5100_tco wmi video hid_logitech_hidpp uas usb_storage hid_logitech_dj ip6_tables ip_tables fuse i2c_dev >> Aug 19 12:22:39 shalem kernel: Unloaded tainted modules: acpi_cpufreq():1 acpi_cpufreq():1 acpi_cpufreq():1 acpi_cpufreq():1 acpi_cpufreq():1 pcc_cpufreq():1 pcc_cpufreq():1 acpi_cpufreq():1 acpi_cpufreq():1 acpi_cpufreq():1 amd64_edac():1 acpi_cpufreq():1 amd64_edac():1 acpi_cpufreq():1 amd64_edac():1 acpi_cpufreq():1 amd64_edac():1 acpi_cpufreq():1 amd64_edac():1 amd64_edac():1 acpi_cpufreq():1 fjes():1 amd64_edac():1 acpi_cpufreq():1 fjes():1 amd64_edac():1 acpi_cpufreq():1 fjes():1 pcc_cpufreq():1 amd64_edac():1 acpi_cpufreq():1 fjes():1 amd64_edac():1 acpi_cpufreq():1 pcc_cpufreq():1 fjes():1 acpi_cpufreq():1 amd64_edac():1 pcc_cpufreq():1 acpi_cpufreq():1 fjes():1 amd64_edac():1 pcc_cpufreq():1 acpi_cpufreq():1 fjes():1 amd64_edac():1 pcc_cpufreq():1 fjes():1 amd64_edac():1 acpi_cpufreq():1 pcc_cpufreq():1 fjes():1 amd64_edac():1 acpi_cpufreq():1 pcc_cpufreq():1 amd64_edac():1 fjes():1 pcc_cpufreq():1 acpi_cpufreq():1 acpi_cpufreq():1 pcc_cpufreq():1 fjes():1 >> acpi_cpufreq():1 pcc_cpufreq():1 >> Aug 19 12:22:39 shalem kernel: fjes():1 acpi_cpufreq():1 pcc_cpufreq():1 acpi_cpufreq():1 fjes():1 pcc_cpufreq():1 acpi_cpufreq():1 acpi_cpufreq():1 fjes():1 pcc_cpufreq():1 acpi_cpufreq():1 fjes():1 acpi_cpufreq():1 pcc_cpufreq():1 fjes():1 acpi_cpufreq():1 >> Aug 19 12:22:39 shalem kernel: CPU: 14 PID: 8321 Comm: kworker/u64:57 Tainted: G OE ------- --- 6.0.0-0.rc1.20220817git3cc40a443a04.14.fc38.x86_64 #1 >> Aug 19 12:22:39 shalem kernel: Hardware name: Micro-Star International Co., Ltd. MS-7C95/B550M PRO-VDH WIFI (MS-7C95), BIOS 2.90 12/23/2021 >> Aug 19 12:22:39 shalem kernel: Workqueue: events_unbound async_run_entry_fn >> Aug 19 12:22:39 shalem kernel: RIP: 0010:add_dma_entry+0x1ed/0x270 >> Aug 19 12:22:39 shalem kernel: Code: ff 0f 84 97 00 00 00 48 8b 5f 50 48 85 db 75 03 48 8b 1f e8 15 96 85 00 48 89 c6 48 89 da 48 c7 c7 30 c9 86 85 e8 73 99 ce 00 <0f> 0b 48 85 ed 0f 85 a9 50 cf 00 8b 05 f2 09 23 02 85 c0 0f 85 ca >> Aug 19 12:22:39 shalem kernel: RSP: 0018:ffffa78dc2c0ba20 EFLAGS: 00010282 >> Aug 19 12:22:39 shalem kernel: RAX: 0000000000000060 RBX: ffff8ac186a636c0 RCX: 0000000000000000 >> Aug 19 12:22:39 shalem kernel: RDX: 0000000000000001 RSI: ffffffff858d07a4 RDI: 00000000ffffffff >> Aug 19 12:22:39 shalem kernel: RBP: ffff8ac184f17a80 R08: 0000000000000001 R09: 0000000000000001 >> Aug 19 12:22:39 shalem kernel: R10: 0000000000000001 R11: 0000000000000000 R12: 0000000000000000 >> Aug 19 12:22:39 shalem kernel: R13: 0000000000000001 R14: 0000000000000206 R15: 00000000042f65bd >> Aug 19 12:22:39 shalem kernel: FS: 0000000000000000(0000) GS:ffff8ac409a00000(0000) knlGS:0000000000000000 >> Aug 19 12:22:39 shalem kernel: CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 >> Aug 19 12:22:39 shalem kernel: CR2: 0000000000000000 CR3: 000000014c028000 CR4: 0000000000750ee0 >> Aug 19 12:22:39 shalem kernel: PKRU: 55555554 >> Aug 19 12:22:39 shalem kernel: Call Trace: >> Aug 19 12:22:39 shalem kernel: <TASK> >> Aug 19 12:22:39 shalem kernel: dma_map_page_attrs+0x82/0x2d0 >> Aug 19 12:22:39 shalem kernel: ? _raw_spin_unlock_irqrestore+0x30/0x60 >> Aug 19 12:22:39 shalem kernel: usb_hcd_map_urb_for_dma+0x423/0x500 >> Aug 19 12:22:39 shalem kernel: usb_hcd_submit_urb+0x9b/0xb80 >> Aug 19 12:22:39 shalem kernel: ? lockdep_init_map_type+0x62/0x260 >> Aug 19 12:22:39 shalem kernel: usb_start_wait_urb+0x55/0x140 >> Aug 19 12:22:39 shalem kernel: usb_control_msg+0xc9/0x120 >> Aug 19 12:22:39 shalem kernel: hub_ext_port_status+0x89/0x110 >> Aug 19 12:22:39 shalem kernel: hub_activate+0x11c/0x8b0 >> Aug 19 12:22:39 shalem kernel: ? usb_dev_thaw+0x10/0x10 >> Aug 19 12:22:39 shalem kernel: hub_resume+0x23/0xe0 >> Aug 19 12:22:39 shalem kernel: ? usb_dev_thaw+0x10/0x10 >> Aug 19 12:22:39 shalem kernel: usb_resume_interface.constprop.0.isra.0+0x89/0xd0 >> Aug 19 12:22:39 shalem kernel: usb_resume_both+0x109/0x180 >> Aug 19 12:22:39 shalem kernel: ? usb_dev_thaw+0x10/0x10 >> Aug 19 12:22:39 shalem kernel: usb_resume+0x15/0x60 >> Aug 19 12:22:39 shalem kernel: dpm_run_callback+0x53/0xc0 >> Aug 19 12:22:39 shalem kernel: device_resume+0xa8/0x200 >> Aug 19 12:22:39 shalem kernel: async_resume+0x19/0x30 >> Aug 19 12:22:39 shalem kernel: async_run_entry_fn+0x30/0x130 >> Aug 19 12:22:39 shalem kernel: process_one_work+0x2a0/0x600 >> Aug 19 12:22:39 shalem kernel: worker_thread+0x4f/0x3a0 >> Aug 19 12:22:39 shalem kernel: ? process_one_work+0x600/0x600 >> Aug 19 12:22:39 shalem kernel: kthread+0xf5/0x120 >> Aug 19 12:22:39 shalem kernel: ? kthread_complete_and_exit+0x20/0x20 >> Aug 19 12:22:39 shalem kernel: ret_from_fork+0x22/0x30 >> Aug 19 12:22:39 shalem kernel: </TASK> >> Aug 19 12:22:39 shalem kernel: irq event stamp: 2115 >> Aug 19 12:22:39 shalem kernel: hardirqs last enabled at (2123): [<ffffffff8418fb52>] vprintk_emit+0x342/0x350 >> Aug 19 12:22:39 shalem kernel: hardirqs last disabled at (2130): [<ffffffff8418fb01>] vprintk_emit+0x2f1/0x350 >> Aug 19 12:22:39 shalem kernel: softirqs last enabled at (0): [<ffffffff840f5079>] copy_process+0xa49/0x1e50 >> Aug 19 12:22:39 shalem kernel: softirqs last disabled at (0): [<0000000000000000>] 0x0 >> Aug 19 12:22:39 shalem kernel: ---[ end trace 0000000000000000 ]--- >> Aug 19 12:22:39 shalem kernel: DMA-API: Mapped at: >> Aug 19 12:22:39 shalem kernel: debug_dma_map_page+0x66/0x100 >> Aug 19 12:22:39 shalem kernel: dma_map_page_attrs+0x82/0x2d0 >> Aug 19 12:22:39 shalem kernel: usb_hcd_map_urb_for_dma+0x423/0x500 >> Aug 19 12:22:39 shalem kernel: usb_hcd_submit_urb+0x9b/0xb80 >> Aug 19 12:22:39 shalem kernel: usb_start_wait_urb+0x55/0x140 >> > > I'm guessing that the data buffer where hub driver stores port status data > was already dma mapped when hub driver submitted a new get port status URB. > usb core tries to map the buffer again at urb subit, triggering this. > > Hub driver allocates one data buffer once, and uses it to store both > hub status data and port status data. (union &hub->status->port and &hub->status->hub) > > So probably the previous URB (get port status, or get hub status) never successfully > completed, or for some reason didn't unmap dma at completion. > > Looks like this issue is hit in resume, so maybe somethin went wrong in completing the > hub URB in suspend? > > Was this easy to reproduce? any external hubs connected? > > One thing to check would be if usbmon shows an uncompleted hub URB when > a new URB is submitted, triggering this. Sorry for being (very) slow in following up on this. I have not seen this for quite a while now, so this seems to be resolved with 6.1 and later. Regards, Hans
