firmware repeat RPI_MBOX_NOTIFY_XHCI_RESET calls, result in XHCI failures.

It appears that the XHCI reset function has problems if it is called multiple times, particularly if the pcie translation is changed without the system being hard reset.

The UEFI/EDK2 firmware is blanket configuring the pcie root port without a DMA translation on all bcm2711 SoCs and enforcing a 3G DMA limit in ACPI mode (and mixed ACPI+DT). This works fine except when recent Linux kernels are booted with the official rpi foundation DT which is suggesting an inbound DMA translation on the more recent devices. In that case the kernel reprograms the pcie root port per the DT, and issues the mailbox call, but the XHCI cannot seem to recover.

Weirdly enough, if the uefi firmware is patched to dynamically modify the DT's to match its programmed translation the controller will work in DT mode reliably until the kernel issues the XHCI mailbox reset. Once that happens it behaves like there is a DMA translation problem with some subset of devices attached to the XHCI controller continuing to work and others failing. This is odd because if the DT has an error, I would expect there to be DMA issues in the case where the XHCI is never reset, and that doesn't happen.

Expected behaviour

I would hope that following the kernel reconfiguring the PCIe root port the low-level firmware notices this and adjusts the way it sets up the XHCI firmware window.

Actual behaviour XHCI failures in Linux following any NOTIFY_XHCI_RESET calls.

System

Which model of Raspberry Pi? e.g. Pi3B+, PiZeroW
4B-8G
Which OS and version (cat /etc/rpi-issue)?
Kernel 5.13/14 tested.
Which firmware version (vcgencmd version)?
I tried all the start4. firmware images from the past few months, and the behavior seems consistent.
Which kernel version (uname -a)?

5.14rc6

Logs

[ 0.000000] Booting Linux on physical CPU 0x0000000000 [0x410fd083] [ 0.000000] Linux version 5.14.0-rc6PCIQUIRK+ ([email protected]) (aarch64-linux-gnu-gcc (GCC) 11.2.1 20210728 (Red Hat Cr1 [ 0.000000] Machine model: Raspberry Pi 4 Model B Rev 1.4 [ 0.000000] efi: EFI v2.70 by EDK2 [ 0.000000] efi: ACPI 2.0=0x33b20018 SMBIOS=0x37200000 SMBIOS 3.0=0x371e0000 MEMATTR=0x353b9018 RNG=0x373db798 MEMRESERVE=0x3377 [ 0.000000] efi: seeding entropy pool [ 0.000000] Reserved memory: created CMA memory pool at 0x0000000027c00000, size 64 MiB [ 0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool [ 0.000000] NUMA: No NUMA configuration found [ 0.000000] NUMA: Faking a node at [mem 0x0000000000000000-0x00000001ffffffff] [ 0.000000] NUMA: NODE_DATA [mem 0x1fefa9c80-0x1fefbffff] [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000000000-0x000000003fffffff] [ 0.000000] DMA32 [mem 0x0000000040000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x00000001ffffffff] [ 0.000000] Device empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000000000-0x00000000001fffff] [ 0.000000] node 0: [mem 0x0000000000200000-0x0000000033843fff] [ 0.000000] node 0: [mem 0x0000000033844000-0x0000000033b1ffff] [ 0.000000] node 0: [mem 0x0000000033b20000-0x0000000036ffffff] [ 0.000000] node 0: [mem 0x0000000037000000-0x00000000373dffff] [ 0.000000] node 0: [mem 0x00000000373e0000-0x000000003b3fffff] [ 0.000000] node 0: [mem 0x0000000040000000-0x00000000fbffffff] [ 0.000000] node 0: [mem 0x0000000100000000-0x00000001ffffffff] [ 0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x00000001ffffffff] [ 0.000000] On node 0, zone DMA32: 19456 pages in unavailable ranges [ 0.000000] On node 0, zone Normal: 16384 pages in unavailable ranges [ 0.000000] psci: probing for conduit method from DT. [ 0.000000] psci: PSCIv1.1 detected in firmware. [ 0.000000] psci: Using standard PSCI v0.2 function IDs [ 0.000000] psci: MIGRATE_INFO_TYPE not supported. [ 0.000000] psci: SMC Calling Convention v1.2 [ 0.000000] percpu: Embedded 23 pages/cpu s54680 r8192 d31336 u94208 [ 0.000000] Detected PIPT I-cache on CPU0 [ 0.000000] CPU features: detected: Spectre-v2 [ 0.000000] CPU features: detected: Spectre-v3a [ 0.000000] CPU features: kernel page table isolation forced ON by KASLR [ 0.000000] CPU features: detected: Kernel page table isolation (KPTI) [ 0.000000] CPU features: detected: ARM errata 1165522, 1319367, or 1530923 [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 2028848 [ 0.000000] Policy zone: Normal [ 0.000000] Kernel command line: BOOT_IMAGE=(hd0,msdos2)/vmlinuz-5.14.0-rc6PCIQUIRK+ root=UUID=4b3822da-3f43-4352-a122-05df373292 [ 0.000000] Unknown command line parameters: BOOT_IMAGE=(hd0,msdos2)/vmlinuz-5.14.0-rc6PCIQUIRK+ [ 0.000000] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, linear) [ 0.000000] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, linear) [ 0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off [ 0.000000] software IO TLB: mapped [mem 0x0000000037400000-0x000000003b400000] (64MB) [ 0.000000] Memory: 7820564K/8245248K available (14272K kernel code, 3266K rwdata, 10056K rodata, 4352K init, 8307K bss, 359148K) [ 0.000000] random: get_random_u64 called from kmem_cache_open+0x28/0x310 with crng_init=0 [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=4096 to nr_cpu_ids=4. [ 0.000000] Trampoline variant of Tasks RCU enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0 [ 0.000000] Root IRQ handler: gic_handle_irq [ 0.000000] GIC: Using split EOI/Deactivate mode [ 0.000000] rcu: Offload RCU callbacks from CPUs: (none). [ 0.000000] arch_timer: cp15 timer(s) running at 54.00MHz (phys). [ 0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns [ 0.000000] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns [ 0.000146] Console: colour dummy device 80x25 [ 0.000336] printk: console [tty0] enabled [ 0.000420] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=540000) [ 0.000432] pid_max: default: 32768 minimum: 301 [ 0.000496] LSM: Security Framework initializing [ 0.000517] Yama: becoming mindful. [ 0.000657] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, linear) [ 0.000744] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, linear) [ 0.001920] rcu: Hierarchical SRCU implementation. [ 0.003179] Remapping and enabling EFI services. [ 0.003672] smp: Bringing up secondary CPUs ... [ 0.004008] Detected PIPT I-cache on CPU1 [ 0.004047] CPU1: Booted secondary processor 0x0000000001 [0x410fd083] [ 0.004420] Detected PIPT I-cache on CPU2 [ 0.004441] CPU2: Booted secondary processor 0x0000000002 [0x410fd083] [ 0.004792] Detected PIPT I-cache on CPU3 [ 0.004812] CPU3: Booted secondary processor 0x0000000003 [0x410fd083] [ 0.004861] smp: Brought up 1 node, 4 CPUs [ 0.004890] SMP: Total of 4 processors activated. [ 0.004896] CPU features: detected: 32-bit EL0 Support [ 0.004900] CPU features: detected: 32-bit EL1 Support [ 0.004906] CPU features: detected: CRC32 instructions [ 0.004985] spectre-v2 mitigation disabled by command line option [ 0.005007] CPU features: emulated: Privileged Access Never (PAN) using TTBR0_EL1 switching [ 0.015694] CPU: All CPU(s) started at EL2 [ 0.015777] alternatives: patching kernel code [ 0.015791] spectre-v4 mitigation disabled by command-line option [ 0.017573] devtmpfs: initialized [ 0.022964] Registered cp15_barrier emulation handler [ 0.022994] Registered setend emulation handler [ 0.023001] KASLR enabled [ 0.023113] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns [ 0.023131] futex hash table entries: 1024 (order: 4, 65536 bytes, linear) [ 0.024585] pinctrl core: initialized pinctrl subsystem [ 0.025054] SMBIOS 3.3.0 present. [ 0.025070] DMI: Raspberry Pi Foundation Raspberry Pi 4 Model B/Raspberry Pi 4 Model B, BIOS EDK2-DEV 08/19/2021 [ 0.025411] NET: Registered PF_NETLINK/PF_ROUTE protocol family [ 0.026285] DMA: preallocated 1024 KiB GFP_KERNEL pool for atomic allocations [ 0.026395] DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.026566] DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations

... (trimming stuff, eventually, we start loading drivers from the initrd)

[ 6.315628] brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges: [ 6.322751] brcm-pcie fd500000.pcie: No bus range found for /scb/pcie@7d500000, using [bus 00-ff] [ 6.341071] brcm-pcie fd500000.pcie: MEM 0x0600000000..0x063fffffff -> 0x00c0000000 [ 6.359758] brcm-pcie fd500000.pcie: IB MEM 0x0000000000..0x00bfffffff -> 0x0400000000 [ 6.406692] brcm-pcie fd500000.pcie: link up, 5.0 GT/s PCIe x1 (SSC) [ 6.413272] brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00 [ 6.416876] random: fast init done [ 6.432328] bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000 [ 6.441323] mmc1: new high speed SDIO card at address 0001 [ 6.446718] pci_bus 0000:00: root bus resource [bus 00-ff] [ 6.453338] pci_bus 0000:00: root bus resource [mem 0x600000000-0x63fffffff] (bus address [0xc0000000-0xffffffff]) [ 6.476736] pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400 [ 6.482838] pci 0000:00:00.0: PME# supported from D0 D3hot [ 6.499916] pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330 [ 6.505999] pci 0000:01:00.0: reg 0x10: [mem 0x638000000-0x638000fff 64bit] [ 6.507026] libphy: bcmgenet MII bus: probed [ 6.540653] pci 0000:01:00.0: PME# supported from D0 D3cold [ 6.578456] pci 0000:00:00.0: BAR 14: assigned [mem 0x600000000-0x6000fffff] [ 6.578476] pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit] [ 6.578491] pci 0000:00:00.0: PCI bridge to [bus 01] [ 6.578496] pci 0000:00:00.0: bridge window [mem 0x600000000-0x6000fffff] [ 6.578886] pcieport 0000:00:00.0: PME: Signaling with IRQ 46 [ 6.583184] pcieport 0000:00:00.0: AER: enabled with IRQ 46 [ 6.612070] xhci_hcd 0000:01:00.0: xHCI Host Controller [ 6.612233] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1 [ 8.767368] random: crng init done [ 8.770808] random: 7 urandom warning(s) missed due to ratelimiting [ 16.612262] xhci_hcd 0000:01:00.0: can't setup: -110 [ 16.617291] xhci_hcd 0000:01:00.0: USB bus 1 deregistered [ 16.622895] xhci_hcd 0000:01:00.0: init 0000:01:00.0 fail, -110 [ 16.629057] xhci_hcd: probe of 0000:01:00.0 failed with error -110

Aug 24 '21 18:08 jlinton

NOTIFY_XHCI_RESET should only be called after the PCIe fundamental reset is asserted which will cause the VLI to be reset. There doesn't appear to be a VLI 'software reset' mechanism available and the firmware can't track the PCIe state to see whether it should make the mbox request a NOOP. Before starting the 'ARM stage' the firmware asserts PCIe reset. UEFI / UBOOT etc should do the same. It's ok to do other PCIe init but bus-mastering should not be enabled on the XHCI until the system is ready to call NOTIFY_XHCI_RESET

Aug 25 '21 09:08 timg236

I believe that the pcie-brcmstb DT code is doing a full reset sequence when it is probed. note: https://elixir.bootlin.com/linux/v5.14-rc7/source/drivers/pci/controller/pcie-brcmstb.c#L880 and then: https://elixir.bootlin.com/linux/v5.14-rc7/source/drivers/pci/controller/pcie-brcmstb.c#L962

Then the kernel calls the mailbox as part of the XHCI probe sequence. So the mailbox should be getting called as you suggest.

Aug 25 '21 13:08 jlinton

It's worth making sure that the .dtb files are up to date, otherwise, Linux won't find the reset controller.

https://github.com/raspberrypi/linux/blob/rpi-5.10.y/arch/arm/boot/dts/bcm2711-rpi-cm4.dts#L288

Sep 23 '21 15:09 timg236

Fairly certain I was running with a new enough DT that the mailbox was being triggered. I added some extra pr_xx's around the reset and mailbox send, which printed information as each step was executed. I've been wondering if there is a timing problem around how long it takes between the reset and the mailbox call, or whether the PERST sequence is being held long enough because if I modify the DT to support non translating DMA's everything will work if the mailbox controller to send the XHCI notification is disabled even if the bus is reset.

Sep 27 '21 15:09 jlinton