sim.py hangs after sched_clock init

[geertu]

LiteX simulation seems to be broken. It hangs after

[ 0.001749] sched_clock: 64 bits at 1000kHz, resolution 1000ns, wraps every 2199023255500ns

Same result with the latest prebuilds and my own kernel .config. Works fine on OrangeCrab, though.

Palmer and Atish could use the simulator to investigate the L1_CACHE_SHIFT issue, cfr.
https://lore.kernel.org/linux-riscv/CAMuHMdXoJ9-jM4sazFbHXEsaDFFMK1ybM53SDqy_2QqPMZEQ=g@mail.gmail.com/

[enjoy-digital]

This was caused by the sys_clk_freq value passed to the .dts that was apparently too low and was causing a hang or slowing down too much the simulation.

This should be fixed with:

• enjoy-digital/litex@acb6741
• 4dd2ab4

With this, here is the simulation log I get:

        __   _ __      _  __
       / /  (_) /____ | |/_/
      / /__/ / __/ -_)>  <
     /____/_/\__/\__/_/|_|
   Build your hardware, easily!

 (c) Copyright 2012-2020 Enjoy-Digital
 (c) Copyright 2007-2015 M-Labs

 BIOS CRC passed (ac300d3c)

 Migen git sha1: 40b1092
 LiteX git sha1: 41964f94

--=============== SoC ==================--
CPU:		VexRiscv SMP-LINUX @ 100MHz
BUS:		WISHBONE 32-bit @ 4GiB
CSR:		32-bit data
ROM:		32KiB
SRAM:		8KiB
L2:		0KiB
SDRAM:		65536KiB 32-bit @ 100MT/s (CL-2 CWL-2)

--========== Initialization ============--
Initializing SDRAM @0x40000000...
Switching SDRAM to software control.
Switching SDRAM to hardware control.

--============== Boot ==================--
Booting from serial...
Press Q or ESC to abort boot completely.
sL5DdSMmkekro
Timeout
Executing booted program at 0x40f00000

--============= Liftoff! ===============--

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

Platform Name       : LiteX / VexRiscv-SMP
Platform Features   : timer,mfdeleg
Platform HART Count : 8
Boot HART ID        : 0
Boot HART ISA       : rv32imas
BOOT HART Features  : time
BOOT HART PMP Count : 0
Firmware Base       : 0x40f00000
Firmware Size       : 124 KB
Runtime SBI Version : 0.2

MIDELEG : 0x00000222
MEDELEG : 0x0000b101
[    0.000000] Linux version 5.11.0-rc2 (florent@panda) (riscv32-buildroot-linux-gnu-gcc.br_real (Buildroot 2020.11-281-g69e5046e7b) 10.2.0, GNU ld (GNU Binutils) 2.33.1) #2 SMP Mon Jan 11 10:05:20 CET 2021
[    0.000000] earlycon: sbi0 at I/O port 0x0 (options '')
[    0.000000] printk: bootconsole [sbi0] enabled
[    0.000000] Initial ramdisk at: 0x(ptrval) (8388608 bytes)
[    0.000000] Zone ranges:
[    0.000000]   Normal   [mem 0x0000000040000000-0x0000000043ffffff]
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000040000000-0x0000000043ffffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000040000000-0x0000000043ffffff]
[    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 HSM extension detected
[    0.000000] riscv: ISA extensions aim
[    0.000000] riscv: ELF capabilities aim
[    0.000000] percpu: Embedded 10 pages/cpu s18316 r0 d22644 u40960
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 16256
[    0.000000] Kernel command line: mem=64M@0x40000000 rootwait console=liteuart earlycon=sbi root=/dev/ram0 init=/sbin/init swiotlb=32
[    0.000000] Dentry cache hash table entries: 8192 (order: 3, 32768 bytes, linear)
[    0.000000] Inode-cache hash table entries: 4096 (order: 2, 16384 bytes, linear)
[    0.000000] Sorting __ex_table...
[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[    0.000000] Memory: 48872K/65536K available (5508K kernel code, 569K rwdata, 830K rodata, 209K init, 220K bss, 16664K reserved, 0K cma-reserved)
[    0.000000] SLUB: HWalign=32, 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] 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] plic: cpu0: parent irq not available
[    0.000000] plic: interrupt-controller@f0c00000: mapped 32 interrupts with 1 handlers for 2 contexts.
[    0.000000] riscv-intc: 32 local interrupts mapped
[    0.000000] random: get_random_bytes called from start_kernel+0x360/0x4d0 with crng_init=0
[    0.000000] riscv_timer_init_dt: Registering clocksource cpuid [0] hartid [0]
[    0.000000] clocksource: riscv_clocksource: mask: 0xffffffffffffffff max_cycles: 0x171024e7e0, max_idle_ns: 440795205315 ns
[    0.000017] sched_clock: 64 bits at 100MHz, resolution 10ns, wraps every 4398046511100ns
[    0.003781] Console: colour dummy device 80x25
[    0.005592] Calibrating delay loop (skipped), value calculated using timer frequency.. 200.00 BogoMIPS (lpj=400000)
[    0.009315] pid_max: default: 32768 minimum: 301
[    0.013736] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
[    0.016207] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
[    0.040008] rcu: Hierarchical SRCU implementation.
[    0.046315] smp: Bringing up secondary CPUs ...
[    0.047761] smp: Brought up 1 node, 1 CPU
[    0.053865] devtmpfs: initialized
[    0.075483] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
[    0.078971] futex hash table entries: 256 (order: 1, 8192 bytes, linear)
[    0.085132] NET: Registered protocol family 16
[    0.223725] FPGA manager framework
[    0.236171] clocksource: Switched to clocksource riscv_clocksource
[    0.381608] NET: Registered protocol family 2
[    0.390671] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear)
[    0.393994] TCP established hash table entries: 1024 (order: 0, 4096 bytes, linear)
[    0.396958] TCP bind hash table entries: 1024 (order: 1, 8192 bytes, linear)
[    0.399300] TCP: Hash tables configured (established 1024 bind 1024)
[    0.402211] UDP hash table entries: 256 (order: 1, 8192 bytes, linear)
[    0.404837] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes, linear)
[    0.416973] Unpacking initramfs...
[    3.403397] Freeing initrd memory: 8192K
[    3.413321] workingset: timestamp_bits=30 max_order=14 bucket_order=0
[    3.631025] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 253)
[    3.633475] io scheduler mq-deadline registered
[    3.634961] io scheduler kyber registered
[    3.641846] LiteX SoC Controller driver initialized: subreg:4, align:4
[    4.526042] f0001000.serial: ttyLXU0 at MMIO 0x0 (irq = 0, base_baud = 0) is a liteuart
[    4.530880] printk: console [liteuart0] enabled
[    4.530880] printk: console [liteuart0] enabled
[    4.532751] printk: bootconsole [sbi0] disabled
[    4.532751] printk: bootconsole [sbi0] disabled
[    4.561755] libphy: Fixed MDIO Bus: probed
[    4.564898] i2c /dev entries driver
[    4.601498] NET: Registered protocol family 10
[    4.613033] Segment Routing with IPv6
[    4.614483] sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver
[    4.634361] Freeing unused kernel memory: 204K
[    4.635031] Kernel memory protection not selected by kernel config.
[    4.636334] Run /init as init process
[    4.988963] tmpfs: Unknown parameter 'mode'
mount: mounting tmpfs on /dev/shm failed: Invalid argument
[    4.995108] tmpfs: Unknown parameter 'mode'
mount: mounting tmpfs on /tmp failed: Invalid argument
[    5.001820] tmpfs: Unknown parameter 'mode'
mount: mounting tmpfs on /run failed: Invalid argument
Starting syslogd: OK
Starting klogd: OK
Running sysctl: OK
Saving random seed: [    6.311057] random: dd: uninitialized urandom read (512 bytes read)

Can you try to reproduce the results @geertu?

[geertu]

Confirmed, booting to userspace again.
Note that wall-clock time is running really slow inside, but that may be expected?
E.g. "sleep 0.1" sleeps for 26s (on i7-8700K).

[enjoy-digital]

Thanks for the test @geertu. So the simulation is 260X slower than 100MHz, so runs at 384KHz, which is realistic here yes.