Re: [regression, bisected, pci/iommu] Bug 216865 - Black screen when amdgpu started during 6.2-rc1 boot with AMD IOMMU enabled

From: Felix Kuehling
Date: Thu Feb 16 2023 - 14:59:47 EST

Next message: Hawkins, Nick: "Re: [PATCH v4 1/5] i2c: hpe: Add GXP SoC I2C Controller"
Previous message: shrikanth hegde: "Re: [RFC PATCH] sched/fair: Interleave cfs bandwidth timers for improved single thread performance at low utilization"
In reply to: Matt Fagnani: "Re: [regression, bisected, pci/iommu] Bug 216865 - Black screen when amdgpu started during 6.2-rc1 boot with AMD IOMMU enabled"
Next in thread: Vasant Hegde: "Re: [regression, bisected, pci/iommu] Bug 216865 - Black screen when amdgpu started during 6.2-rc1 boot with AMD IOMMU enabled"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

Feb 16 13:22:32 kernel: kfd kfd: amdgpu: Failed to resume IOMMU for device 1002:9874
Feb 16 13:22:32 kernel: kfd kfd: amdgpu: device 1002:9874 NOT added due to errors

This look like IOMMU device initialization still fails (but more gracefully now). Vasant, is that expected?

This would lead to KFD not being available on Carrizo with this kernel, which is probably not a big limitation in practice. It would only affect compute applications using the ROCm user mode stack. I don't think anyone does that these days on these old APUs.

The SMU errors seem unrelated to this unless there is some subtle interaction I'm missing.

Regards,
Felix

Am 2023-02-16 um 13:59 schrieb Matt Fagnani:

Vasant,

I applied your four patches to 6.2-rc8 and built that. The black screen, null pointer dereference, and warnings didn't happen when booting 6.2-rc8 with your patches. There were errors that the IOMMU wasn't restarted when amdgpu and amdkfd was starting though at kernel: kfd kfd: amdgpu: Failed to resume IOMMU for device 1002:9874. I don't know if those IOMMU errors were expected or not, but I did see those types of messages when I used amd_iommu=off to work around the black screen before. I didn't use amd_iommu=off when testing 6.2-rc8 with your patches. There were also a different amdgpu warning at drivers/gpu/drm/amd/amdgpu/../pm/powerplay/smumgr/smu8_smumgr.c:98 smu8_send_msg_to_smc_with_parameter+0x103/0x140 and errors about amdgpu timeouts on 1/3 boots. Plasma took over a minute to start and shut down on that boot which was unusually long. I've seen those sorts of amdgpu warnings and errors infrequently before so they might be unrelated to the IOMMU problem. The part of the journal where those errors started was the following.

Feb 16 13:22:31 kernel: [drm] amdgpu kernel modesetting enabled.
Feb 16 13:22:31 kernel: amdgpu: Topology: Add APU node [0x0:0x0]
Feb 16 13:22:31 kernel: [drm] initializing kernel modesetting (CARRIZO 0x1002:0x9874 0x103C:0x8332 0xCA).
Feb 16 13:22:31 kernel: [drm] register mmio base: 0xF0400000
Feb 16 13:22:31 kernel: [drm] register mmio size: 262144
Feb 16 13:22:31 kernel: [drm] add ip block number 0 <vi_common>
Feb 16 13:22:31 kernel: [drm] add ip block number 1 <gmc_v8_0>
Feb 16 13:22:31 kernel: [drm] add ip block number 2 <cz_ih>
Feb 16 13:22:31 kernel: [drm] add ip block number 3 <gfx_v8_0>
Feb 16 13:22:31 kernel: [drm] add ip block number 4 <sdma_v3_0>
Feb 16 13:22:31 kernel: [drm] add ip block number 5 <powerplay>
Feb 16 13:22:31 kernel: [drm] add ip block number 6 <dm>
Feb 16 13:22:31 kernel: [drm] add ip block number 7 <uvd_v6_0>
Feb 16 13:22:31 kernel: [drm] add ip block number 8 <vce_v3_0>
Feb 16 13:22:31 kernel: [drm] add ip block number 9 <acp_ip>
Feb 16 13:22:31 kernel: amdgpu 0000:00:01.0: amdgpu: Fetched VBIOS from VFCT
Feb 16 13:22:31 kernel: amdgpu: ATOM BIOS: 113-C75100-031
Feb 16 13:22:31 kernel: [drm] UVD is enabled in physical mode
Feb 16 13:22:31 kernel: [drm] VCE enabled in physical mode
Feb 16 13:22:31 kernel: Console: switching to colour dummy device 80x25
Feb 16 13:22:31 kernel: amdgpu 0000:00:01.0: vgaarb: deactivate vga console
Feb 16 13:22:31 kernel: amdgpu 0000:00:01.0: amdgpu: Trusted Memory Zone (TMZ) feature not supported
Feb 16 13:22:31 kernel: [drm] vm size is 64 GB, 2 levels, block size is 10-bit, fragment size is 9-bit
Feb 16 13:22:31 kernel: amdgpu 0000:00:01.0: amdgpu: VRAM: 512M 0x000000F400000000 - 0x000000F41FFFFFFF (512M used)
Feb 16 13:22:31 kernel: amdgpu 0000:00:01.0: amdgpu: GART: 1024M 0x000000FF00000000 - 0x000000FF3FFFFFFF
Feb 16 13:22:31 kernel: [drm] Detected VRAM RAM=512M, BAR=512M
Feb 16 13:22:31 kernel: [drm] RAM width 64bits UNKNOWN
Feb 16 13:22:31 kernel: [drm] amdgpu: 512M of VRAM memory ready
Feb 16 13:22:31 kernel: [drm] amdgpu: 3704M of GTT memory ready.
Feb 16 13:22:31 kernel: [drm] GART: num cpu pages 262144, num gpu pages 262144
Feb 16 13:22:31 kernel: [drm] PCIE GART of 1024M enabled (table at 0x000000F400600000).
Feb 16 13:22:31 kernel: amdgpu: hwmgr_sw_init smu backed is smu8_smu
Feb 16 13:22:31 kernel: [drm] Found UVD firmware Version: 1.91 Family ID: 11
Feb 16 13:22:31 kernel: [drm] UVD ENC is disabled
Feb 16 13:22:31 kernel: [drm] Found VCE firmware Version: 52.4 Binary ID: 3
Feb 16 13:22:31 kernel: amdgpu: smu version 27.18.00
Feb 16 13:22:31 kernel: [drm] DM_PPLIB: values for Engine clock
Feb 16 13:22:31 kernel: [drm] DM_PPLIB:         300000
Feb 16 13:22:31 kernel: [drm] DM_PPLIB:         480000
Feb 16 13:22:31 kernel: [drm] DM_PPLIB:         533340
Feb 16 13:22:31 kernel: [drm] DM_PPLIB:         576000
Feb 16 13:22:31 kernel: [drm] DM_PPLIB:         626090
Feb 16 13:22:31 kernel: [drm] DM_PPLIB:         685720
Feb 16 13:22:31 kernel: [drm] DM_PPLIB:         720000
Feb 16 13:22:31 kernel: [drm] DM_PPLIB:         757900
Feb 16 13:22:31 kernel: [drm] DM_PPLIB: Validation clocks:
Feb 16 13:22:31 kernel: [drm] DM_PPLIB:    engine_max_clock: 75790
Feb 16 13:22:31 kernel: [drm] DM_PPLIB:    memory_max_clock: 93300
Feb 16 13:22:31 kernel: [drm] DM_PPLIB:    level           : 8
Feb 16 13:22:31 kernel: [drm] DM_PPLIB: values for Display clock
Feb 16 13:22:31 kernel: [drm] DM_PPLIB:         300000
Feb 16 13:22:31 kernel: [drm] DM_PPLIB:         400000
Feb 16 13:22:31 kernel: [drm] DM_PPLIB:         496560
Feb 16 13:22:31 kernel: [drm] DM_PPLIB:         626090
Feb 16 13:22:31 kernel: [drm] DM_PPLIB:         685720
Feb 16 13:22:31 kernel: [drm] DM_PPLIB:         757900
Feb 16 13:22:31 kernel: [drm] DM_PPLIB:         800000
Feb 16 13:22:31 kernel: [drm] DM_PPLIB:         847060
Feb 16 13:22:31 kernel: [drm] DM_PPLIB: Validation clocks:
Feb 16 13:22:31 kernel: [drm] DM_PPLIB:    engine_max_clock: 75790
Feb 16 13:22:31 kernel: [drm] DM_PPLIB:    memory_max_clock: 93300
Feb 16 13:22:31 kernel: [drm] DM_PPLIB:    level           : 8
Feb 16 13:22:31 kernel: [drm] DM_PPLIB: values for Memory clock
Feb 16 13:22:31 kernel: [drm] DM_PPLIB:         667000
Feb 16 13:22:31 kernel: [drm] DM_PPLIB:         933000
Feb 16 13:22:31 kernel: [drm] DM_PPLIB: Validation clocks:
Feb 16 13:22:31 kernel: [drm] DM_PPLIB:    engine_max_clock: 75790
Feb 16 13:22:31 kernel: [drm] DM_PPLIB:    memory_max_clock: 93300
Feb 16 13:22:31 kernel: [drm] DM_PPLIB:    level           : 8
Feb 16 13:22:31 kernel: [drm] Display Core initialized with v3.2.215!
Feb 16 13:22:32 kernel: [drm] UVD initialized successfully.
Feb 16 13:22:32 kernel: [drm] VCE initialized successfully.
Feb 16 13:22:32 kernel: kfd kfd: amdgpu: Allocated 3969056 bytes on gart
Feb 16 13:22:32 kernel: amdgpu: sdma_bitmap: f
Feb 16 13:22:32 kernel: kfd kfd: amdgpu: Failed to resume IOMMU for device 1002:9874
Feb 16 13:22:32 kernel: kfd kfd: amdgpu: device 1002:9874 NOT added due to errors
Feb 16 13:22:32 kernel: amdgpu 0000:00:01.0: amdgpu: SE 1, SH per SE 1, CU per SH 8, active_cu_number 6
Feb 16 13:22:32 kernel: [drm] Initialized amdgpu 3.49.0 20150101 for 0000:00:01.0 on minor 0
Feb 16 13:22:32 kernel: fbcon: amdgpudrmfb (fb0) is primary device
Feb 16 13:22:33 kernel: Console: switching to colour frame buffer device 170x48
Feb 16 13:22:33 kernel: amdgpu 0000:00:01.0: [drm] fb0: amdgpudrmfb frame buffer device
Feb 16 13:22:33 kernel: audit: type=1334 audit(1676571753.397:17): prog-id=21 op=LOAD
Feb 16 13:22:33 kernel: audit: type=1130 audit(1676571753.419:18): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=dbus-broker comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Feb 16 13:22:33 kernel: audit: type=1130 audit(1676571753.456:19): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=dracut-initqueue comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Feb 16 13:22:33 kernel: audit: type=1130 audit(1676571753.492:20): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-fsck-root comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Feb 16 13:22:33 kernel: EXT4-fs (dm-0): mounted filesystem 00107de9-54ef-4784-a03f-61802ed0b350 with ordered data mode. Quota mode: none.
Feb 16 13:22:36 kernel: ------------[ cut here ]------------
Feb 16 13:22:36 kernel: smu8_send_msg_to_smc_with_parameter(0x0009, 0x0) timed out after 2814625 us
Feb 16 13:22:36 kernel: WARNING: CPU: 1 PID: 112 at drivers/gpu/drm/amd/amdgpu/../pm/powerplay/smumgr/smu8_smumgr.c:98 smu8_send_msg_to_smc_with_parameter+0x103/0x140 [amdgpu]
Feb 16 13:22:36 kernel: Modules linked in: amdgpu i2c_algo_bit drm_ttm_helper ttm iommu_v2 mfd_core drm_buddy gpu_sched drm_display_helper drm_kms_helper hid_logitech_hidpp drm crct10dif_pclmul crc32_pclmul crc32c_intel r8169 sd_mod ghash_clmulni_intel t10_pi sha512_ssse3 crc64_rocksoft_generic crc64_rocksoft wdat_wdt sp5100_tco hid_logitech_dj crc64 cec video wmi fuse dm_multipath
Feb 16 13:22:36 kernel: CPU: 1 PID: 112 Comm: kworker/1:3 Not tainted 6.2.0-rc8+ #94
Feb 16 13:22:36 kernel: Hardware name: HP HP Laptop 15-bw0xx/8332, BIOS F.52 12/03/2019
Feb 16 13:22:36 kernel: Workqueue: events amdgpu_vce_idle_work_handler [amdgpu]
Feb 16 13:22:36 kernel: RIP: 0010:smu8_send_msg_to_smc_with_parameter+0x103/0x140 [amdgpu]
Feb 16 13:22:36 kernel: Code: 20 48 c7 c7 28 1c c1 c0 48 89 c1 48 f7 ea 48 89 c8 44 89 e9 48 c1 f8 3f 48 c1 fa 07 48 29 c2 49 89 d0 44 89 e2 e8 c5 28 48 e0 <0f> 0b eb b0 bd ea ff ff ff eb a9 48 8b 7b 40 be c0 01 00 00 48 8b
Feb 16 13:22:36 kernel: RSP: 0018:ffffb997004c7db8 EFLAGS: 00010282
Feb 16 13:22:36 kernel: RAX: 000000000000004b RBX: ffff8b4e4f596800 RCX: 0000000000000000
Feb 16 13:22:36 kernel: RDX: 0000000000000001 RSI: ffffffffa14cf075 RDI: 00000000ffffffff
Feb 16 13:22:36 kernel: RBP: 00000000ffffffc2 R08: 0000000000000000 R09: ffffb997004c7c68
Feb 16 13:22:36 kernel: R10: 0000000000000003 R11: ffffffffa1d42e48 R12: 0000000000000009
Feb 16 13:22:36 kernel: R13: 0000000000000000 R14: 00000003ded365a4 R15: 0000000000000002
Feb 16 13:22:36 kernel: FS: 0000000000000000(0000) GS:ffff8b4f37480000(0000) knlGS:0000000000000000
Feb 16 13:22:36 kernel: CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Feb 16 13:22:36 kernel: CR2: 00007f950a698364 CR3: 0000000033c10000 CR4: 00000000001506e0
Feb 16 13:22:36 kernel: Call Trace:
Feb 16 13:22:36 kernel: <TASK>
Feb 16 13:22:36 kernel: smum_send_msg_to_smc+0xba/0xf0 [amdgpu]
Feb 16 13:22:36 kernel: smu8_dpm_powergate_vce+0x15a/0x180 [amdgpu]
Feb 16 13:22:36 kernel: pp_set_powergating_by_smu+0xed/0x1f0 [amdgpu]
Feb 16 13:22:36 kernel: amdgpu_dpm_set_powergating_by_smu+0x84/0xf0 [amdgpu]
Feb 16 13:22:36 kernel: amdgpu_dpm_enable_vce+0x29/0xa0 [amdgpu]
Feb 16 13:22:36 kernel: process_one_work+0x1c8/0x380
Feb 16 13:22:36 kernel: worker_thread+0x4d/0x380
Feb 16 13:22:36 kernel: ? _raw_spin_lock_irqsave+0x23/0x50
Feb 16 13:22:36 kernel: ? __pfx_worker_thread+0x10/0x10
Feb 16 13:22:36 kernel: kthread+0xe9/0x110
Feb 16 13:22:36 kernel: ? __pfx_kthread+0x10/0x10
Feb 16 13:22:36 kernel: ret_from_fork+0x2c/0x50
Feb 16 13:22:36 kernel: </TASK>
Feb 16 13:22:36 kernel: ---[ end trace 0000000000000000 ]---
Feb 16 13:22:39 kernel: amdgpu: smu8_send_msg_to_smc_with_parameter(0x0004) aborted; SMU still servicing msg (0x0009)
Feb 16 13:22:41 kernel: amdgpu: smu8_send_msg_to_smc_with_parameter(0x0007) aborted; SMU still servicing msg (0x0009)

I'm attaching the kernel log for the boot of 6.2-rc8 + patches with the IOMMU errors and amdgpu warnings and timeouts.

Thanks,

Matt

On 2/16/23 00:25, Vasant Hegde wrote:

Felix, Jason, Matt,

On 2/16/2023 6:05 AM, Felix Kuehling wrote:

[+Shimmer, Aaron]

Am 2023-02-15 um 10:39 schrieb Bjorn Helgaas:

[+cc Christian, Xinhui, amd-gfx]

On Fri, Jan 06, 2023 at 01:48:11PM +0800, Baolu Lu wrote:

On 1/5/23 11:27 PM, Felix Kuehling wrote:

Am 2023-01-05 um 09:46 schrieb Deucher, Alexander:

-----Original Message-----
From: Hegde, Vasant <Vasant.Hegde@xxxxxxx>
On 1/5/2023 4:07 PM, Baolu Lu wrote:

On 2023/1/5 18:27, Vasant Hegde wrote:

On 1/5/2023 6:39 AM, Matt Fagnani wrote:

I built 6.2-rc2 with the patch applied. The same black
screen problem happened with 6.2-rc2 with the patch. I
tried to use early kdump with 6.2-rc2 with the patch
twice by panicking the kernel with sysrq+alt+c after the
black screen happened. The system rebooted after about
10-20 seconds both times, but no kdump and dmesg files
were saved in /var/crash. I'm attaching the lspci -vvv
output as requested. ...

Looking into lspci output, it doesn't list ACS feature
for Graphics card. So with your fix it didn't enable PASID
and hence it failed to boot. ...

So do you mind telling why does the PASID need to be enabled
for the graphic device? Or in another word, what does the
graphic driver use the PASID for? ...

The GPU driver uses the pasid for shared virtual memory between
the CPU and GPU. I.e., so that the user apps can use the same
virtual address space on the GPU and the CPU. It also uses
pasid to take advantage of recoverable device page faults using
PRS. ...

Agreed. This applies to GPU computing on some older AMD APUs that
take advantage of memory coherence and IOMMUv2 address translation
to create a shared virtual address space between the CPU and GPU.
In this case it seems to be a Carrizo APU. It is also true for
Raven APUs. ...

Thanks for the explanation.

This is actually the problem that commit 201007ef707a was trying to
fix. The PCIe fabric routes Memory Requests based on the TLP
address, ignoring any PASID (PCIe r6.0, sec 2.2.10.4), so a TLP with
PASID that should go upstream to the IOMMU may instead be routed as
a P2P Request if its address falls in a bridge window.

In SVA case, the IOMMU shares the address space of a user
application. The user application side has no knowledge about the
PCI bridge window. It is entirely possible that the device is
programed with a P2P address and results in a disaster.

Is this stalled? We explored the idea of changing the PCI core so
that for devices that use ATS/PRI, we could enable PASID without
checking for ACS [1], but IIUC we ultimately concluded that it was
based on a misunderstanding of how ATS Translation Requests are routed
and that an AMD driver change would be required [2].

So it seems like we still have this regression, and we're running out
of time before v6.2.

[1] https://lore.kernel.org/all/20230114073420.759989-1-baolu.lu@xxxxxxxxxxxxxxx/
[2] https://lore.kernel.org/all/Y91X9MeCOsa67CC6@xxxxxxxxxx/

If I understand this correctly, the HW or the BIOS is doing something wrong
about reporting ACS. I don't know what the GPU driver can do other than add some
quirk to stop using AMD IOMMUv2 on this HW/BIOS.

It looks like the problem is triggered when the driver calls
amd_iommu_init_device. That's when the first WARNs happen, soon followed by a
kernel oops in report_iommu_fault. The driver doesn't know anything is wrong
because amd_iommu_init_device seems to return "success". And the oops is not in
the GPU driver either.

WARN is fixed and its in Joerg's tree.
https://lore.kernel.org/all/20230111121503.5931-1-vasant.hegde@xxxxxxx/

report_iommu_fault() happened because in amd_iommu_init_device() path it failed
to attach devices to new domain and returned error. But it didn't put devices
back to old domain properly. It left in incosistent state and resulted in IO
page fault. I have proposed series to handle device to domain attachment failure
and better handling of subsequent report_iommu_fault().
https://lore.kernel.org/linux-iommu/20230215052642.6016-1-vasant.hegde@xxxxxxx/

@Matt,
   Can you please help to verify above patches on your system where you hit the
issue originally?
   (Grab above two series, apply it on top of latest kernel and test it)

-Vasant

Next message: Hawkins, Nick: "Re: [PATCH v4 1/5] i2c: hpe: Add GXP SoC I2C Controller"
Previous message: shrikanth hegde: "Re: [RFC PATCH] sched/fair: Interleave cfs bandwidth timers for improved single thread performance at low utilization"
In reply to: Matt Fagnani: "Re: [regression, bisected, pci/iommu] Bug 216865 - Black screen when amdgpu started during 6.2-rc1 boot with AMD IOMMU enabled"
Next in thread: Vasant Hegde: "Re: [regression, bisected, pci/iommu] Bug 216865 - Black screen when amdgpu started during 6.2-rc1 boot with AMD IOMMU enabled"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]