Interrupts not working on Vexriscv SMP implementation

[lcomino64]

Hi all,

I'm almost finished porting my LiteX VexriscV SMP to Zephyr. I can build samples for the board, such as

• hello world
• arch/smp/pi, pktqueue
  etc.

These samples seem to work correctly, and use both cores, however, the issue becomes apparent when I build anything with interrupts, such as the console samples. Instantly when the program starts, the stack size for ISR1 is overflowed, see here:

I believe this to be the cause of interrupts not working and the program appearing to freeze, here's the output I get from the subsys/console/echo sample:

lachlancomino@ubuntu-machine:~/zephyrproject/zephyr$ litex_term /dev/ttyUSB2 --speed 115200 --kernel build/zephyr/zephyr.bin
     / /  (_) /____ | |/_/
      / /__/ / __/ -_)>  <
     /____/_/\__/\__/_/|_|
   Build your hardware, easily!

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

 BIOS CRC passed (02a8afa1)

 LiteX git sha1: ef775e0b8

--=============== SoC ==================--
CPU:		VexRiscv SMP-STANDARD @ 100MHz
BUS:		wishbone 32-bit @ 4GiB
CSR:		32-bit data
ROM:		64.0KiB
SRAM:		16.0KiB
L2:		8.0KiB
SDRAM:		64.0MiB 16-bit @ 800MT/s (CL-7 CWL-5)
MAIN-RAM:	256.0MiB

--========== Initialization ============--
Initializing SDRAM @0x40000000...
Switching SDRAM to software control.
Read leveling:
  m0, b00: |00000000000000000000000000000000| delays: -
  m0, b01: |00000000000000000000000000000000| delays: -
  m0, b02: |11111111111000000000000000000000| delays: 05+-05
  m0, b03: |00000000000001111111111111100000| delays: 19+-06
  m0, b04: |00000000000000000000000000000011| delays: 30+-00
  m0, b05: |00000000000000000000000000000000| delays: -
  m0, b06: |00000000000000000000000000000000| delays: -
  m0, b07: |00000000000000000000000000000000| delays: -
  best: m0, b03 delays: 19+-06
  m1, b00: |00000000000000000000000000000000| delays: -
  m1, b01: |00000000000000000000000000000000| delays: -
  m1, b02: |11111111111000000000000000000000| delays: 05+-05
  m1, b03: |00000000000001111111111111100000| delays: 20+-06
  m1, b04: |00000000000000000000000000000011| delays: 30+-00
  m1, b05: |00000000000000000000000000000000| delays: -
  m1, b06: |00000000000000000000000000000000| delays: -
  m1, b07: |00000000000000000000000000000000| delays: -
  best: m1, b03 delays: 19+-06
Switching SDRAM to hardware control.
Memtest at 0x40000000 (2.0MiB)...
  Write: 0x40000000-0x40200000 2.0MiB     
   Read: 0x40000000-0x40200000 2.0MiB     
Memtest OK
Memspeed at 0x40000000 (Sequential, 2.0MiB)...
  Write speed: 161.0MiB/s
   Read speed: 77.9MiB/s

--============== Boot ==================--
Booting from serial...
Press Q or ESC to abort boot completely.
sL5DdSMmkekro
[LITEX-TERM] Received firmware download request from the device.
[LITEX-TERM] Uploading build/zephyr/zephyr.bin to 0x40000000 (33982 bytes)...
[LITEX-TERM] Upload calibration... (inter-frame: 10.00us, length: 64)
[LITEX-TERM] Upload complete (9.9KB/s).
[LITEX-TERM] Booting the device.
[LITEX-TERM] Done.
Executing booted program at 0x40000000

--============= Liftoff! ===============--
*** Booting Zephyr OS build v3.7.0-2189-gdc0f9c469938 ***
You should see another line with instructions below. If not,
the (interrupt-driven) console device doesn't work as expected:
Start typing characters to see

I've checked many times that my CSR addresses match my devicetree and that it's mapped out similarly to other boards with the sifive PLIC/CLINT. I also noticed that in ${ZEPHYR_BASE}/zephyr/arch/riscv/core/smp.c, there's a macro for MSIP_BASE. I've also made that the same address as my CLINT. Didn't fix anything.

I should also add that CONFIG_ATOMIC_OPERATIONS_C is disabled and CONFIG_ATOMIC_OPERATIONSBUILTIN is enabled (I think !CONFIG_ATOMIC_OPERATIONS_C has been asserted in Kconfig since this issue occured: #55049)

Here is my Zephyr fork:
https://github.com/lcomino64/zephyr-lcomino64

And here is a repo with the LiteX configuration:
https://github.com/lcomino64/Thesis-public

Can anyone suggest ways to debug this? Or tell me what could possibly be maxing out the ISR1 stack? I'm happy to give more context if needed, and here is a thread on Discord where @josuah and I have been trying to solve this issue:
https://discord.com/channels/720317445772017664/1276785758652338208

[lcomino64]

To describe the behaviour more, I've noticed that the ISR1 stack maxes out instantly upon Zephyr startup. Even if I make the stack size huge (256kb), it still maxes out and I don't get to see it fill up. Maybe my memory is misaligned somewhere? Not sure

[ycsin]

This is what I get with qemu_riscv64_smp on Zephyr v3.5.0:

west build -b qemu_riscv64_smp -p auto -t run zephyr/samples/hello_world -- -DCONFIG_SHELL=y -DCONFIG_SCHED_CPU_MASK=y

*** Booting Zephyr OS build zephyr-v3.5.0-80-gd47129f0f7d5 ***
Hello World! qemu_riscv64_smp


uart:~$ kernel stacks 
0x80010870 idle 01                          (real size 1024):   unused  612     usage  412 / 1024 (40 %)
0x80010c00 sysworkq                         (real size 1024):   unused  668     usage  356 / 1024 (34 %)
0x800100f0 shell_uart                       (real size 3072):   unused 1268     usage 1804 / 3072 (58 %)
0x80010710 idle 00                          (real size 1024):   unused  612     usage  412 / 1024 (40 %)
0x800119b0 IRQ 00                           (real size 2048):   unused 1236     usage  812 / 2048 (39 %)
0x800121b0 IRQ 01                           (real size 2048):   unused    0     usage 2048 / 2048 (100 %)

So seems like it has been like that for a while, I'm not sure if this is expected, but it definitely looks worrying.

For comparison, the following is from qemu_cortex_a53

west build -b qemu_cortex_a53_smp -p auto -t run zephyr/samples/hello_world -- -DCONFIG_SHELL=y -DCONFIG_SCHED_CPU_MASK=y

*** Booting Zephyr OS build zephyr-v3.5.0-80-gd47129f0f7d5 ***
Secondary CPU core 1 (MPID:0x1) is up
Hello World! qemu_cortex_a53


uart:~$ kernel stacks 
0x4001d700 idle 01                          (real size 4096):   unused 3600     usage  496 / 4096 (12 %)
0x4001de00 sysworkq                         (real size 4096):   unused 3712     usage  384 / 4096 ( 9 %)
0x4001d000 shell_uart                       (real size 3072):   unused  752     usage 2320 / 3072 (75 %)
0x4001d380 idle 00                          (real size 4096):   unused 3600     usage  496 / 4096 (12 %)
0x400675a0 IRQ 00                           (real size 4096):   unused 2432     usage 1664 / 4096 (40 %)
0x400685a0 IRQ 01                           (real size 4096):   unused 2976     usage 1120 / 4096 (27 %)

I'm trying to see what's wrong right now, cc @npitre @fkokosinski @carlocaione who might have insights on this

[ycsin]

Looks like just a display issue #78220

[lcomino64]

The issue was never caused by stack overflow then. Can confirm I see the proper ISR1 stack usage after your PR, @ycsin.

After skimming through the GDB output of my litex_sim (which also has the same issue), running the console sample, I can see several error handling functions throughout. For example, the first one is right after console_init():

I can't send the full output (it won't let me record), but I would like to see if anyone knows why these errors are not being shown in the console although my printk works and logging works (I can confirm samples/subsys/logging/logger runs properly).

If anyone would like to check my device tree for signs of a spurious interrupt, it's here:
https://github.com/lcomino64/zephyr-lcomino64/blob/main/dts/riscv/riscv32-litex-vexriscv-smp.dtsi

The rest of my zephyr configuration is also in that repo.

Thanks