search

riscv-software-src / opensbi

RISC-V Open Source Supervisor Binary Interface
Other
1.05k stars 517 forks source link

boot process hangs in payload with RISCV32 SPIKE + OPENSBI + Linux 5.7 #192

Closed gkamendje closed 3 years ago

gkamendje commented 3 years ago

Hello I have the following setup: 1) RISCV32 SPIKE commit 236de4dbfae9a23a1b58627faca7e01c95e6cee7 (dec 2020) 2) RISCV32 OPENSBI commit 4fffb53269156c8ea593ababbe4a664a1c06a1cd (dec 2020) 3) Busybox commit 15733cb48e570716cad6ece2d752507ecd767131 (dec 2020) 4) Linux 5.7

I use the following command to boot linux with Spike+Opensbi

riscv-isa-sim/build/spike -l --log logs/spike_rv32imafdc_boot_new.log --isa=rv32imafdc --initrd busybox/busybox opensbi/build/platform/generic/firmware/fw_payload.elf

The boot process starts pretty smoothly and I do get the Opensbi welcome screen. It proceeds with some CSR access related expected exceptions and some floating point exceptions. The process recovers from the last floating point exception but unfortunately, it hangs later-on in the payload_bin section while waiting for an interrupt. 

core   0: 1 0x80401038 (0x73c70713) x14 0x814bc770
core   0: 0xffffffff8040103c (0x00e6d763) bge     a3, a4, pc + 14
core   0: 1 0x8040103c (0x00e6d763)
core   0: 0xffffffff80401040 (0x0006b023) sd      zero, 0(a3)
core   0: exception trap_illegal_instruction, epc 0xffffffff80401040
core   0:           tval 0x000000000006b023
core   0: >>>>  _trap_handler
core   0: 0x0000000080000508 (0x34021273) csrrw   tp, mscratch, tp
core   0: 3 0x80000508 (0x34021273) x 4 0x80019000 c832_mscratch 0x80019000
core   0: 0xffffffff8000050c (0x02522023) sw      t0, 32(tp)
--
core   0: 1 0x804010b0 (0x95b6) x11 0x8140c1f0
core   0: 0xffffffff804010b2 (0x00009636) c.add   a2, a3
core   0: 1 0x804010b2 (0x9636) x12 0x8140c230
core   0: 0xffffffff804010b4 (0x0005b103) ld      sp, 0(a1)
core   0: exception trap_illegal_instruction, epc 0xffffffff804010b4
core   0:           tval 0x000000000005b103
core   0: >>>>  _trap_handler
core   0: 0x0000000080000508 (0x34021273) csrrw   tp, mscratch, tp
core   0: 3 0x80000508 (0x34021273) x 4 0x80019000 c832_mscratch 0x80019000
core   0: 0xffffffff8000050c (0x02522023) sw      t0, 32(tp)

Here the just before the inifite loop

core   0: 0xffffffff800005dc (0x000042d2) c.lwsp  t0, 20(sp)
core   0: 3 0x800005dc (0x42d2) x 5 0x00000008 mem 0x80018f88
core   0: 0xffffffff800005de (0x00004122) c.lwsp  sp, 8(sp)
core   0: 3 0x800005de (0x4122) x 2 0x80018f30 mem 0x80018f7c
core   0: 0xffffffff800005e0 (0x30200073) mret
core   0: 3 0x800005e0 (0x30200073) c768_mstatus 0x00000180
core   0: 0x00000000804000f4 (0x10500073) wfi
core   0: 0xffffffff804000f8 (0x0000bff5) c.j     pc - 4
core   0: 1 0x804000f8 (0xbff5)

And here we have the loop.

core   0: 0xffffffff804000f4 (0x10500073) wfi
core   0: 0xffffffff804000f8 (0x0000bff5) c.j     pc - 4
core   0: 0xffffffff804000f4 (0x10500073) wfi

I don't really fully understand what is going on here and I am not sure that this is an Opensbi issue either. Just looking for some pointers on where to start debugging. I am not very familiar with boot/Kernel debug. Any hint will be much appreciated. (I have an OpenOCD+SPIKE+GDB setup. However, I can't step into the Kernel code. I guess I am missing some kernel symbols here.)

The RV64 version of this configuration works pretty well and I do get all the way to the Linux prompt. G

avpatel commented 3 years ago

I tried latest OpenSBI, Spike and Linux-5.11-rc3 and everything looks fine.

  1. Spike (commit 35d50bc40e59ea1d5566fbd3d9226023821b1bb6)
  2. OpenSBI v0.8+ (commit 1bbf36183ef5beeeb6358ff4450611c9c76a2ea2)
  3. Linux-5.11-rc3 (kernel.org)

Here's my boot log:

anup@anup-ubuntu64-vm:~/Work/riscv-test$ ./riscv-isa-sim/spike -m512 --isa rv32gc --kernel ./build-riscv32/arch/riscv/boot/Image --initrd ./rootfs_riscv32.img opensbi/build/platform/generic/firmware/fw_jump.elf

OpenSBI v0.8-89-g1bbf361
   ____                    _____ ____ _____
  / __ \                  / ____|  _ \_   _|
 | |  | |_ __   ___ _ __ | (___ | |_) || |
 | |  | | '_ \ / _ \ '_ \ \___ \|  _ < | |
 | |__| | |_) |  __/ | | |____) | |_) || |_
  \____/| .__/ \___|_| |_|_____/|____/_____|
        | |
        |_|

Platform Name             : ucbbar,spike-bare
Platform Features         : timer,mfdeleg
Platform HART Count       : 1
Firmware Base             : 0x80000000
Firmware Size             : 96 KB
Runtime SBI Version       : 0.2

Domain0 Name              : root
Domain0 Boot HART         : 0
Domain0 HARTs             : 0*
Domain0 Region00          : 0x80000000-0x8001ffff ()
Domain0 Region01          : 0x00000000-0xffffffff (R,W,X)
Domain0 Next Address      : 0x80400000
Domain0 Next Arg1         : 0x82200000
Domain0 Next Mode         : S-mode
Domain0 SysReset          : yes

Boot HART ID              : 0
Boot HART Domain          : root
Boot HART ISA             : rv32imafdcsu
Boot HART Features        : scounteren,mcounteren
Boot HART PMP Count       : 16
Boot HART PMP Granularity : 4
Boot HART PMP Address Bits: 32
Boot HART MHPM Count      : 0
Boot HART MHPM Count      : 0
Boot HART MIDELEG         : 0x00000222
Boot HART MEDELEG         : 0x0000b109
[    0.000000] Linux version 5.11.0-rc3-00022-gad56588f06e1 (anup@anup-ubuntu64-vm) (riscv64-unknown-linux-gnu-gcc (GCC) 9.2.0, GNU ld (GNU Binutils) 2.34) #7 SMP Fri Jan 15 14:42:51 IST 2021
[    0.000000] OF: fdt: Ignoring memory range 0x80000000 - 0x80400000
[    0.000000] earlycon: sbi0 at I/O port 0x0 (options '')
[    0.000000] printk: bootconsole [sbi0] enabled
[    0.000000] efi: UEFI not found.
[    0.000000] Initial ramdisk at: 0x(ptrval) (2793472 bytes)
[    0.000000] Zone ranges:
[    0.000000]   Normal   [mem 0x0000000080400000-0x000000009fffffff]
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000080400000-0x000000009fffffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000080400000-0x000000009fffffff]
[    0.000000] ------------[ cut here ]------------
[    0.000000] WARNING: CPU: 0 PID: 0 at kernel/resource.c:799 __insert_resource+0x6a/0xba
[    0.000000] Modules linked in:
[    0.000000] CPU: 0 PID: 0 Comm: swapper Not tainted 5.11.0-rc3-00022-gad56588f06e1 #7
[    0.000000] epc: c001a968 ra : c001a93a sp : c1801f40
[    0.000000]  gp : c18a8b88 tp : c1806700 t0 : df55af60
[    0.000000]  t1 : df55b024 t2 : 00000000 s0 : c1801f50
[    0.000000]  s1 : c1807448 a0 : c1807448 a1 : c1807448
[    0.000000]  a2 : 80abfe6d a3 : c1807448 a4 : 80abfe6d
[    0.000000]  a5 : 80402000 a6 : dfbfff5c a7 : 00000024
[    0.000000]  s2 : dfbfff40 s3 : c18aa000 s4 : c0c065e0
[    0.000000]  s5 : c1807000 s6 : c18aa000 s7 : c111fef0
[    0.000000]  s8 : 00000fff s9 : 80000200 s10: c111fee4
[    0.000000]  s11: 00000000 t3 : 9f95af80 t4 : ffffffff
[    0.000000]  t5 : 00000000 t6 : df55b600
[    0.000000] status: 00000100 badaddr: c001a968 cause: 00000003
[    0.000000] random: get_random_bytes called from print_oops_end_marker+0x2a/0x60 with crng_init=0
[    0.000000] ---[ end trace 0000000000000000 ]---
[    0.000000] Failed to add a Kernel code resource at 80402000
[    0.000000] SBI specification v0.2 detected
[    0.000000] SBI implementation ID=0x1 Version=0x8
[    0.000000] SBI v0.2 TIME extension detected
[    0.000000] SBI v0.2 IPI extension detected
[    0.000000] SBI v0.2 RFENCE extension detected
[    0.000000] SBI v0.2 SRST extension detected
[    0.000000] SBI v0.2 HSM extension detected
[    0.000000] riscv: ISA extensions acdfim
[    0.000000] riscv: ELF capabilities acdfim
[    0.000000] percpu: Embedded 13 pages/cpu s22412 r8192 d22644 u53248
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 129032
[    0.000000] Kernel command line: root=/dev/ram console=hvc0 earlycon=sbi
[    0.000000] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes, linear)
[    0.000000] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes, linear)
[    0.000000] Sorting __ex_table...
[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[    0.000000] Memory: 487432K/520192K available (6903K kernel code, 8808K rwdata, 4096K rodata, 4157K init, 250K bss, 32760K 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=8 to nr_cpu_ids=1.
[    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: 32 local interrupts mapped
[    0.000000] riscv_timer_init_dt: Registering clocksource cpuid [0] hartid [0]
[    0.000000] clocksource: riscv_clocksource: mask: 0xffffffffffffffff max_cycles: 0x24e6a1710, max_idle_ns: 440795202120 ns
[    0.000015] sched_clock: 64 bits at 10MHz, resolution 100ns, wraps every 4398046511100ns
[    0.001230] Console: colour dummy device 80x25
[    0.001880] printk: console [hvc0] enabled
[    0.001880] printk: console [hvc0] enabled
[    0.002950] printk: bootconsole [sbi0] disabled
[    0.002950] printk: bootconsole [sbi0] disabled
[    0.004160] Calibrating delay loop (skipped), value calculated using timer frequency.. 20.00 BogoMIPS (lpj=40000)
[    0.005695] pid_max: default: 32768 minimum: 301
[    0.006410] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
[    0.007515] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
[    0.010610] rcu: Hierarchical SRCU implementation.
[    0.011715] EFI services will not be available.
[    0.012840] smp: Bringing up secondary CPUs ...
[    0.013500] smp: Brought up 1 node, 1 CPU
[    0.014370] devtmpfs: initialized
[    0.015550] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
[    0.017040] futex hash table entries: 256 (order: 2, 16384 bytes, linear)
[    0.018175] NET: Registered protocol family 16
[    0.025745] HugeTLB registered 4.00 MiB page size, pre-allocated 0 pages
[    0.028210] vgaarb: loaded
[    0.028730] SCSI subsystem initialized
[    0.029590] usbcore: registered new interface driver usbfs
[    0.030425] usbcore: registered new interface driver hub
[    0.031260] usbcore: registered new device driver usb
[    0.032480] clocksource: Switched to clocksource riscv_clocksource
[    0.039750] NET: Registered protocol family 2
[    0.040920] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear)
[    0.042200] TCP established hash table entries: 4096 (order: 2, 16384 bytes, linear)
[    0.043330] TCP bind hash table entries: 4096 (order: 3, 32768 bytes, linear)
[    0.044485] TCP: Hash tables configured (established 4096 bind 4096)
[    0.045395] UDP hash table entries: 256 (order: 1, 8192 bytes, linear)
[    0.046385] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes, linear)
[    0.047485] NET: Registered protocol family 1
[    0.049155] RPC: Registered named UNIX socket transport module.
[    0.050035] RPC: Registered udp transport module.
[    0.050685] RPC: Registered tcp transport module.
[    0.051335] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    0.052235] PCI: CLS 0 bytes, default 64
[    0.053020] Unpacking initramfs...
[    0.065180] Freeing initrd memory: 2724K
[    0.065775] kvm [1]: hypervisor extension not available
[    0.066985] workingset: timestamp_bits=30 max_order=17 bucket_order=0
[    0.072530] NFS: Registering the id_resolver key type
[    0.073240] Key type id_resolver registered
[    0.073845] Key type id_legacy registered
[    0.074445] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[    0.075495] 9p: Installing v9fs 9p2000 file system support
[    0.076570] NET: Registered protocol family 38
[    0.077230] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 252)
[    0.078270] io scheduler mq-deadline registered
[    0.078930] io scheduler kyber registered
[    0.117945] Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
[    0.119470] [drm] radeon kernel modesetting enabled.
[    0.123815] loop: module loaded
[    0.124735] libphy: Fixed MDIO Bus: probed
[    0.125755] e1000e: Intel(R) PRO/1000 Network Driver
[    0.126445] e1000e: Copyright(c) 1999 - 2015 Intel Corporation.
[    0.127365] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    0.128345] ehci-pci: EHCI PCI platform driver
[    0.129115] ehci-platform: EHCI generic platform driver
[    0.129900] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[    0.130825] ohci-pci: OHCI PCI platform driver
[    0.131490] ohci-platform: OHCI generic platform driver
[    0.132630] usbcore: registered new interface driver uas
[    0.133390] usbcore: registered new interface driver usb-storage
[    0.134310] mousedev: PS/2 mouse device common for all mice
[    0.135360] usbcore: registered new interface driver usbhid
[    0.136185] usbhid: USB HID core driver
[    0.137260] NET: Registered protocol family 10
[    0.138410] Segment Routing with IPv6
[    0.138940] sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver
[    0.140070] NET: Registered protocol family 17
[    0.140935] 9pnet: Installing 9P2000 support
[    0.141540] Key type dns_resolver registered
[    0.144090] Freeing unused kernel memory: 4156K
[    0.148515] Run /init as init process
           _  _
          | ||_|
          | | _ ____  _   _  _  _ 
          | || |  _ \| | | |\ \/ /
          | || | | | | |_| |/    \
          |_||_|_| |_|\____|\_/\_/

               Busybox Rootfs

Please press Enter to activate this console.
avpatel commented 3 years ago

The FW_PAYLOAD also works fine. I used following command: ./riscv-isa-sim/spike -m512 --isa rv32gc --initrd ./rootfs_riscv32.img opensbi/build/platform/generic/firmware/fw_payload.elf

gkamendje commented 3 years ago

Thanks Anup for your quick answer. I have grabbed Linux v5.11-rc3 and the latest version of Spike and OpenSbi and I am still not successfull. Similar to what I had before, it hangs on trap_instruction_access_fault, epc 0xffffffff800077de after printing

Boot HART MIDELEG         : 0x00000222
Boot HART MEDELEG         : 0x0000b109
core   0: 3 0x80005eea (0x30561673) x12 0x80000530 c773_mtvec 0x800086e0
core   0: 0xffffffff80005eee (0x3c0025f3) csrr    a1, unknown_3c0
core   0: exception trap_illegal_instruction, epc 0xffffffff80005eee
core   0:           tval 0x000000003c0025f3
core   0: >>>>  __sbi_expected_trap
core   0: 0x00000000800086e0 (0x34102773) csrr    a4, mepc
--
core   0: 3 0x800075d2 (0x305797f3) x15 0x80000530 c773_mtvec 0x800086e0
core   0: 0xffffffff800075d6 (0xc0102673) csrr    a2, time
core   0: exception trap_illegal_instruction, epc 0xffffffff800075d6
core   0:           tval 0x00000000c0102673
core   0: >>>>  __sbi_expected_trap
core   0: 0x00000000800086e0 (0x34102773) csrr    a4, mepc
--
core   0: 1 0x8040110c (0x00e6d763)
core   0: 0xffffffff80401110 (0x0006b023) sd      zero, 0(a3)
core   0: exception trap_illegal_instruction, epc 0xffffffff80401110
core   0:           tval 0x000000000006b023
core   0: >>>>  _trap_handler
core   0: 0x0000000080000530 (0x34021273) csrrw   tp, mscratch, tp
--
core   0: 1 0x80401190 (0x9636) x12 0x8160e1c8
core   0: 0xffffffff80401192 (0x0005b103) ld      sp, 0(a1)
core   0: exception trap_illegal_instruction, epc 0xffffffff80401192
core   0:           tval 0x000000000005b103
core   0: >>>>  _trap_handler
core   0: 0x0000000080000530 (0x34021273) csrrw   tp, mscratch, tp
--
core   0: 0x00000000804010c8 (0x00008082) ret
core   0: 1 0x804010c8 (0x8082)
core   0: exception trap_instruction_access_fault, epc 0xffffffff800077de
core   0:           tval 0xffffffff800077de
core   0: >>>>  _trap_handler
core   0: 0x0000000080000530 (0x34021273) csrrw   tp, mscratch, tp
--
core   0: 0x00000000804010c8 (0x00008082) ret
core   0: 1 0x804010c8 (0x8082)
core   0: exception trap_instruction_access_fault, epc 0xffffffff800077de
core   0:           tval 0xffffffff800077de
core   0: >>>>  _trap_handler
core   0: 0x0000000080000530 (0x34021273) csrrw   tp, mscratch, tp
--
core   0: 0x00000000804010c8 (0x00008082) ret
core   0: 1 0x804010c8 (0x8082)
core   0: exception trap_instruction_access_fault, epc 0xffffffff800077de
core   0:           tval 0xffffffff800077de
core   0: >>>>  _trap_handler
core   0: 0x0000000080000530 (0x34021273) csrrw   tp, mscratch, tp
--
core   0: 0x00000000804010c8 (0x00008082) ret
core   0: 1 0x804010c8 (0x8082)
core   0: exception trap_instruction_access_fault, epc 0xffffffff800077de
core   0:           tval 0xffffffff800077de
core   0: >>>>  _trap_handler
core   0: 0x0000000080000530 (0x34021273) csrrw   tp, mscratch, tp
--
core   0: 0x00000000804010c8 (0x00008082) ret
core   0: 1 0x804010c8 (0x8082)
core   0: exception trap_instruction_access_fault, epc 0xffffffff800077de
core   0:           tval 0xffffffff800077de
core   0: >>>>  _trap_handler
core   0: 0x0000000080000530 (0x34021273) csrrw   tp, mscratch, tp

I suspect that something is wrong with the way I am compiling the various components including the kernel. Could you please share your compilation steps? Here are the compilation steps that I use.

Compile Linux v5.11-rc3

cd linux_v5.11-rc3
git checkout v5.11-rc3
make ARCH=riscv CROSS_COMPILE=riscv32-linux- defconfig
make ARCH=riscv CROSS_COMPILE=riscv32-linux- -j $(nproc)

Grab and compile the latest version of OpenSbi

cd opensbi
git pull
 make clean
make PLATFORM=generic PLATFORM_RISCV_XLEN=32 FW_PAYLOAD_PATH=../linux_v5.11-rc3/arch/riscv/boot/Image

Grab and compile the latest version of Spike

cd riscv-isa-sim
git pull
rm -rf build 
mkdir build
 cd build/
 ../configure --prefix=$RISCV --enable-commitlog
make

I use the following toolchain riscv32-ilp32d--glibc--bleeding-edge-2020.08-1 from https://toolchains.bootlin.com/releases_riscv32-ilp32d.html

avpatel commented 3 years ago

Please compile RV32 Linux-5.11-rc3 using rv32_defconfig instead of defconfig.

Regards, Anup

gkamendje commented 3 years ago

Thanks once again. I got much further after compiling the kernel with rv32_defconfig. However, using riscv-isa-sim/build/spike -m512 --isa=rv32gc --initrd busybox/busybox opensbi/build/platform/generic/firmware/fw_payload.elf

It looks like the kernel is not able to mount the file system.

[    0.145620] VFS: Cannot open root device "ram" or unknown-block(1,0): error -6
[    0.146635] Please append a correct "root=" boot option; here are the available partitions:
[    0.147805] DEBUG_BLOCK_EXT_DEVT is enabled, you need to specify explicit textual name for "root=" boot option.
[    0.149350] Kernel panic - not syncing: VFS: Unable to mount root fs on unknown-block(1,0)
[    0.150605] CPU: 0 PID: 1 Comm: swapper/0 Tainted: G        W         5.11.0-rc3 #2
[    0.151680] Call Trace:
[    0.152010] [<c0004666>] walk_stackframe+0x0/0xa6
[    0.152625] [<c06c3c70>] show_stack+0x32/0x3e
[    0.153195] [<c06c6346>] dump_stack+0x70/0x8e
[    0.153760] [<c06c3e96>] panic+0xfa/0x2a0
[    0.154285] [<c080121a>] mount_block_root+0x21c/0x236
[    0.154940] [<c080132e>] mount_root+0xfa/0x124
[    0.155555] [<c0801498>] prepare_namespace+0x140/0x180
[    0.156270] [<c0800da4>] kernel_init_freeable+0x1c4/0x1e0
[    0.156970] [<c06cd7c0>] kernel_init+0x12/0xf4
[    0.157590] [<c000326e>] ret_from_exception+0x0/0xc
[    0.158265] ---[ end Kernel panic - not syncing: VFS: Unable to mount root fs on unknown-block(1,0) ]---

I could not find any rv32 related compilation option for Busybox. Any idea what is going on here?

BTW I do see these other kernel messages. Should I worry about them?

[    0.000000] Failed to add a Kernel code resource at 80402000
[    0.054020] Initramfs unpacking failed: invalid magic at start of compressed archive
avpatel commented 3 years ago

Based on your spike parameters, it seems you are providing busybox ELF as initrd. This is not correct.

You should provide CPIO initrd image containing busybox rootfs as initrd to Spike.

Regards, Anup

gkamendje commented 3 years ago

Thanks Anup, I was able to boot and mount a CPIO root FS generated with Buildroot. For some obscure reason generating the root FS with Busybox did not work for me. This is odd given that Buildroot uses Busybox under the hood. Thanks once again. Closing this topic. G