Re: Qemu sdhci-pci device can't be recognized by Linux kernel

[Alistair Francis]

On Wed, Feb 28, 2024 at 12:19 AM Li, Yong <yong.li@intel.com> wrote:
>
> Hello,
>
> QEMU virt platform of RISCV-64 can emulate the mmc device by using below 
> parameters:
> -device sdhci-pci,sd-spec-version=3 \
> -drive if=none,file=disk.img,format=raw,id=MMC1 \
> -device sd-card,drive=MMC1
>
> And as to u-boot, it do can recognize the mmc device and load the linux 
> kernel from the sdcard partition.
> But the mmc device can't be recognized by the linux kernel so that the root 
> filesystem in the sdcard can't be loaded.
>
> The logs are as below, any thoughts ? Thanks
>
>
> Starting kernel ...
>
> [    0.000000] Linux version 6.7.0-rc3-g2bb52284d571-dirty 
> (intel@intel-OptiPlex-7090) (riscv64-linux-gnu-gcc (Ubuntu 
> 9.4.0-1ubuntu1~20.04) 9.4.0, GNU ld (GNU Binutils for Ubuntu) 2.34) #11 SMP 
> Tue Feb 27 16:04:26 CST 2024
> [    0.000000] random: crng init done
> [    0.000000] Machine model: riscv-virtio,qemu
> [    0.000000] SBI specification v1.0 detected
> [    0.000000] SBI implementation ID=0x1 Version=0x10003
> [    0.000000] SBI TIME extension detected
> [    0.000000] SBI IPI extension detected
> [    0.000000] SBI RFENCE extension detected
> [    0.000000] earlycon: ns16550a0 at MMIO 0x0000000010000000 (options '')
> [    0.000000] printk: legacy bootconsole [ns16550a0] enabled
> [    0.000000] efi: UEFI not found.
> [    0.000000] OF: reserved mem: 0x0000000080000000..0x000000008003ffff (256 
> KiB) nomap non-reusable mmode_resv1@80000000
> [    0.000000] OF: reserved mem: 0x0000000080040000..0x000000008005ffff (128 
> KiB) nomap non-reusable mmode_resv0@80040000
> [    0.000000] Zone ranges:
> [    0.000000]   DMA32    [mem 0x0000000080000000-0x00000000ffffffff]
> [    0.000000]   Normal   [mem 0x0000000100000000-0x000000017fffffff]
> [    0.000000] Movable zone start for each node
> [    0.000000] Early memory node ranges
> [    0.000000]   node   0: [mem 0x0000000080000000-0x000000008005ffff]
> [    0.000000]   node   0: [mem 0x0000000080060000-0x000000017fffffff]
> [    0.000000] Initmem setup node 0 [mem 
> 0x0000000080000000-0x000000017fffffff]
> [    0.000000] SBI HSM extension detected
> [    0.000000] CPU with hartid=1 is not available
> [    0.000000] Falling back to deprecated "riscv,isa"
> [    0.000000] riscv: base ISA extensions acdfhim
> [    0.000000] riscv: ELF capabilities acdfim
> [    0.000000] percpu: Embedded 20 pages/cpu s41976 r8192 d31752 u81920
> [    0.000000] Kernel command line: root=/dev/vda1 ro earlycon 
> console=ttyS0,115200n8
> [    0.000000] Dentry cache hash table entries: 524288 (order: 10, 4194304 
> bytes, linear)
> [    0.000000] Inode-cache hash table entries: 262144 (order: 9, 2097152 
> bytes, linear)
> [    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 1032192
> [    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
> [    0.000000] software IO TLB: area num 1.
> [    0.000000] software IO TLB: mapped [mem 
> 0x00000000faec6000-0x00000000feec6000] (64MB)
> [    0.000000] Virtual kernel memory layout:
> [    0.000000]       fixmap : 0xff1bfffffea00000 - 0xff1bffffff000000   (6144 
> kB)
> [    0.000000]       pci io : 0xff1bffffff000000 - 0xff1c000000000000   (  16 
> MB)
> [    0.000000]      vmemmap : 0xff1c000000000000 - 0xff20000000000000   (1024 
> TB)
> [    0.000000]      vmalloc : 0xff20000000000000 - 0xff60000000000000   
> (16384 TB)
> [    0.000000]      modules : 0xffffffff01589000 - 0xffffffff80000000   (2026 
> MB)
> [    0.000000]       lowmem : 0xff60000000000000 - 0xff60000100000000   (4096 
> MB)
> [    0.000000]       kernel : 0xffffffff80000000 - 0xffffffffffffffff   (2047 
> MB)
> [    0.000000] Memory: 4016708K/4194304K available (9472K kernel code, 4986K 
> rwdata, 4096K rodata, 2222K init, 502K bss, 177596K reserved, 0K cma-reserved)
> [    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
> [    0.000000] rcu: Hierarchical RCU implementation.
> [    0.000000] rcu:     RCU restricting CPUs from NR_CPUS=64 to nr_cpu_ids=1.
> [    0.000000] rcu:     RCU debug extended QS entry/exit.
> [    0.000000]  Tracing variant of Tasks RCU enabled.
> [    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 
> jiffies.
> [    0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
> [    0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0
> [    0.000000] riscv-intc: 64 local interrupts mapped using AIA
> [    0.000000] riscv-imsic: imsics@28000000: invalid cpuid for parent irq1
> [    0.000000] riscv-imsic: imsics@28000000: providing IPIs using interrupt 1
> [    0.000000] rcu: srcu_init: Setting srcu_struct sizes based on contention.
> [    0.000000] clocksource: riscv_clocksource: mask: 0xffffffffffffffff 
> max_cycles: 0x24e6a1710, max_idle_ns: 440795202120 ns
> [    0.000084] sched_clock: 64 bits at 10MHz, resolution 100ns, wraps every 
> 4398046511100ns
> [    0.000338] riscv-timer: Timer interrupt in S-mode is available via sstc 
> extension
> [    0.005139] Console: colour dummy device 80x25
> [    0.008888] Calibrating delay loop (skipped), value calculated using timer 
> frequency.. 20.00 BogoMIPS (lpj=40000)
> [    0.009171] pid_max: default: 32768 minimum: 301
> [    0.010237] LSM: initializing lsm=capability,integrity
> [    0.014518] Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, 
> linear)
> [    0.014778] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 
> bytes, linear)
> [    0.033936] CPU node for /cpus/cpu@1 exist but the possible cpu range is :0
> [    0.044500] RCU Tasks Trace: Setting shift to 0 and lim to 1 
> rcu_task_cb_adjust=1.
> [    0.045051] riscv: ELF compat mode supported
> [    0.045275] ASID allocator using 16 bits (65536 entries)
> [    0.046454] rcu: Hierarchical SRCU implementation.
> [    0.046577] rcu:     Max phase no-delay instances is 1000.
> [    0.048704] EFI services will not be available.
> [    0.050031] smp: Bringing up secondary CPUs ...
> [    0.051095] smp: Brought up 1 node, 1 CPU
> [    0.063329] devtmpfs: initialized
> [    0.074382] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, 
> max_idle_ns: 7645041785100000 ns
> [    0.074689] futex hash table entries: 256 (order: 2, 16384 bytes, linear)
> [    0.076688] pinctrl core: initialized pinctrl subsystem
> [    0.080864] sse: Missing SBI SSE extension
> [    0.082410] NET: Registered PF_NETLINK/PF_ROUTE protocol family
> [    0.090488] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic 
> allocations
> [    0.091007] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic 
> allocations
> [    0.091370] audit: initializing netlink subsys (disabled)
> [    0.094571] thermal_sys: Registered thermal governor 'step_wise'
> [    0.095183] audit: type=2000 audit(0.084:1): state=initialized 
> audit_enabled=0 res=1
> [    0.095906] cpuidle: using governor menu
> [    0.120192] cpu0: Ratio of byte access time to unaligned word access is 
> 7.30, unaligned accesses are fast
> [    0.121054] riscv-rpxy: SBI RPXY extension detected
> [    0.143014] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages
> [    0.143168] HugeTLB: 28 KiB vmemmap can be freed for a 2.00 MiB page
> [    0.147680] ACPI: Interpreter disabled.
> [    0.148204] iommu: Default domain type: Translated
> [    0.148299] iommu: DMA domain TLB invalidation policy: strict mode
> [    0.150202] SCSI subsystem initialized
> [    0.152031] usbcore: registered new interface driver usbfs
> [    0.152332] usbcore: registered new interface driver hub
> [    0.152545] usbcore: registered new device driver usb
> [    0.154011] Advanced Linux Sound Architecture Driver Initialized.
> [    0.164653] vgaarb: loaded
> [    0.168952] clocksource: Switched to clocksource riscv_clocksource
> [    0.170805] pnp: PnP ACPI: disabled
> [    0.187515] NET: Registered PF_INET protocol family
> [    0.188635] IP idents hash table entries: 65536 (order: 7, 524288 bytes, 
> linear)
> [    0.196372] tcp_listen_portaddr_hash hash table entries: 2048 (order: 4, 
> 65536 bytes, linear)
> [    0.196668] Table-perturb hash table entries: 65536 (order: 6, 262144 
> bytes, linear)
> [    0.196857] TCP established hash table entries: 32768 (order: 6, 262144 
> bytes, linear)
> [    0.197276] TCP bind hash table entries: 32768 (order: 9, 2097152 bytes, 
> linear)
> [    0.201318] TCP: Hash tables configured (established 32768 bind 32768)
> [    0.202392] UDP hash table entries: 2048 (order: 5, 196608 bytes, linear)
> [    0.202904] UDP-Lite hash table entries: 2048 (order: 5, 196608 bytes, 
> linear)
> [    0.204091] NET: Registered PF_UNIX/PF_LOCAL protocol family
> [    0.206864] RPC: Registered named UNIX socket transport module.
> [    0.207015] RPC: Registered udp transport module.
> [    0.207090] RPC: Registered tcp transport module.
> [    0.207181] RPC: Registered tcp-with-tls transport module.
> [    0.207256] RPC: Registered tcp NFSv4.1 backchannel transport module.
> [    0.207489] PCI: CLS 0 bytes, default 64
> [    0.213042] workingset: timestamp_bits=46 max_order=20 bucket_order=0
> [    0.214484] squashfs: version 4.0 (2009/01/31) Phillip Lougher
> [    0.216473] NFS: Registering the id_resolver key type
> [    0.217281] Key type id_resolver registered
> [    0.217377] Key type id_legacy registered
> [    0.217680] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
> [    0.217865] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver 
> Registering...
> [    0.218602] 9p: Installing v9fs 9p2000 file system support
> [    0.221381] NET: Registered PF_ALG protocol family
> [    0.221731] Block layer SCSI generic (bsg) driver version 0.4 loaded 
> (major 244)
> [    0.221978] io scheduler mq-deadline registered
> [    0.222128] io scheduler kyber registered
> [    0.222306] io scheduler bfq registered
> [    0.224296] riscv-imsic: imsics@28000000: hart-index-bits: 0,  
> guest-index-bits: 0
> [    0.224426] riscv-imsic: imsics@28000000: group-index-bits: 1, 
> group-index-shift: 24
> [    0.224566] riscv-imsic: imsics@28000000: per-CPU IDs 255 at base PPN 
> 0x0000000028000000
> [    0.224711] riscv-imsic: imsics@28000000: total 254 interrupts available
> [    0.227558] pci-host-generic 30000000.pci: host bridge /soc/pci@30000000 
> ranges:
> [    0.228230] pci-host-generic 30000000.pci:       IO 
> 0x0003000000..0x000300ffff -> 0x0000000000
> [    0.228676] pci-host-generic 30000000.pci:      MEM 
> 0x0040000000..0x007fffffff -> 0x0040000000
> [    0.228857] pci-host-generic 30000000.pci:      MEM 
> 0x0400000000..0x07ffffffff -> 0x0400000000
> [    0.229362] pci-host-generic 30000000.pci: Memory resource size exceeds 
> max for 32 bits
> [    0.229814] pci-host-generic 30000000.pci: ECAM at [mem 
> 0x30000000-0x3fffffff] for [bus 00-ff]
> [    0.232176] pci-host-generic 30000000.pci: PCI host bridge to bus 0000:00
> [    0.232487] pci_bus 0000:00: root bus resource [bus 00-ff]
> [    0.232634] pci_bus 0000:00: root bus resource [io  0x0000-0xffff]
> [    0.232765] pci_bus 0000:00: root bus resource [mem 0x40000000-0x7fffffff]
> [    0.232899] pci_bus 0000:00: root bus resource [mem 
> 0x400000000-0x7ffffffff]
> [    0.234091] pci 0000:00:00.0: [1b36:0008] type 00 class 0x060000
> [    0.236786] pci 0000:00:01.0: [1b36:0007] type 00 class 0x080501
> [    0.237291] pci 0000:00:01.0: reg 0x10: [mem 0x40000000-0x400000ff]
> [    0.239022] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000
> [    0.239705] pci 0000:00:02.0: reg 0x10: [io  0x1000-0x101f]
> [    0.240324] pci 0000:00:02.0: reg 0x14: [mem 0x40001000-0x40001fff]
> [    0.242455] pci 0000:00:02.0: reg 0x20: [mem 0x40004000-0x40007fff 64bit 
> pref]
> [    0.243046] pci 0000:00:02.0: reg 0x30: [mem 0x40040000-0x4007ffff pref]
> [    0.245209] pci 0000:00:02.0: BAR 6: assigned [mem 0x40000000-0x4003ffff 
> pref]
> [    0.245492] pci 0000:00:02.0: BAR 4: assigned [mem 0x400000000-0x400003fff 
> 64bit pref]
> [    0.245989] pci 0000:00:02.0: BAR 1: assigned [mem 0x40040000-0x40040fff]
> [    0.246294] pci 0000:00:01.0: BAR 0: assigned [mem 0x40041000-0x400410ff]
> [    0.246655] pci 0000:00:02.0: BAR 0: assigned [io  0x0020-0x003f]
> [    0.252094] clk-sbi-rpxy soc:sbi-rpxy-clk: RPMI Clock Service Group Probe 
> Failed
> [    0.255411] irq: no irq domain found for aplic@d008000 !
> [    0.338181] Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
> [    0.347886] SuperH (H)SCI(F) driver initialized
> [    0.363037] loop: module loaded
> [    0.373271] genirq: irq_chip IMSIC-PCI did not update eff. affinity mask 
> of irq 11
> [    0.378037] e1000e: Intel(R) PRO/1000 Network Driver
> [    0.378140] e1000e: Copyright(c) 1999 - 2015 Intel Corporation.
> [    0.380675] usbcore: registered new interface driver uas
> [    0.380903] usbcore: registered new interface driver usb-storage
> [    0.381666] mousedev: PS/2 mouse device common for all mice
> [    0.384073] sdhci: Secure Digital Host Controller Interface driver
> [    0.384182] sdhci: Copyright(c) Pierre Ossman
> [    0.384361] sdhci-pltfm: SDHCI platform and OF driver helper
> [    0.385528] usbcore: registered new interface driver usbhid
> [    0.385646] usbhid: USB HID core driver
> [    0.386192] riscv-pmu-sbi: SBI PMU extension is available
> [    0.386646] riscv-pmu-sbi: 16 firmware and 18 hardware counters
> [    0.386789] riscv-pmu-sbi: Perf sampling/filtering is not supported as 
> sscof extension is not available
> [    0.387628] irq: no irq domain found for aplic@d008000 !
> [    0.387809] sdhci-pci 0000:00:01.0: SDHCI controller found [1b36:0007] 
> (rev 0)
> [    0.417829] mmc0: Failed to request IRQ 0: -22
> [    0.421338] sdhci-pci: probe of 0000:00:01.0 failed with error -22

It seems like interrupts aren't getting set up correctly.

You could try a different interrupt controller. It looks like you are
using the aplic, you could try the aplic-imsic maybe [1]?

Otherwise having a look at the kernel driver and trying to figure out
what is failing is probably the best bet.

1: https://www.qemu.org/docs/master/system/riscv/virt.html

Alistair

>
>
> Thanks,
> Yong Li
>
>