Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Random errors occuring with code that is not being executed (!!??) #623

Closed
agamez opened this issue May 26, 2023 · 9 comments · Fixed by #626
Closed

Random errors occuring with code that is not being executed (!!??) #623

agamez opened this issue May 26, 2023 · 9 comments · Fixed by #626
Assignees
Labels
bug Something isn't working as expected SW Software-related

Comments

@agamez
Copy link
Contributor

agamez commented May 26, 2023

Hi!

I'm experiencing some strange bugs that have me completely flabbergasted. I am writing a relatively simple program that makes use of an external interrupt to reprogram some SPI devices. The software also presents an ASCII based user interface through the serial port. I don't think any of this is out of the ordinary, but typing it just presents the characteristics of the configuration of the neorv32.

The architecture of the software, however, is maybe a little bit complex because I'm using OOP concepts (structs with pointers to functions, vtables, etc), so it's a bit difficult sometimes which function is being called. Now, I'm trying to printf-debug this UART interface because I don't have an available JTAG connection (this is implemented on an iCEBreaker and I don't have external hardware to connect JTAG to the output pins). I have my software running flawlessly, reacting perfectly fine to the interrupts and all is fine, but I want to debug this little function, which is only called when I type a specific command through the serial port. If there's no interaction from my part, the CPU will continue to react to the external stimulii and processing interrupts.

static char *find_reg(const struct bank_manager *bm, int reg_number)
{
        neorv32_uart0_printf("Reg number %d max %d\n", reg_number, bm->bank_desc->n_regs);
        if (reg_number >= bm->bank_desc->n_regs)
                return NULL;

        /* Calculate register position by adding reg_size */
        char *reg = bm->regs;
        int increment = 0;
        for (int i = 0; i < reg_number; i++) {
                if (increment > 0) {
                        reg += increment;
                } else {
                        if (bm->bank_desc->regs_size[i] == 0 && i > 0)
                                increment = bm->bank_desc->regs_size[i - 1];
                        else
                                increment = bm->bank_desc->regs_size[i];
                        reg += increment;
                }
        }

        return reg;
}

So I added that little printf at the beginning of the function. And, when I do that and load that new neorv32_exe.bin file, the CPU spits this out through the serial port without even having been requested find_reg function to be executed:

Booting from 0x00000000...

> ruction access faultMEOUT_ERR]C=0x7494D4B6VAL=0x44444444TAL EXCEPTION] Halting CPU. </RTE>

So, changes in pieces of code that are not being executed produce some kind of error on the CPU. Even the message it spits out is somewhat mangled.

I've been experiencing effects like this for the last couple of days and I've tried almost everything I can think of. This is running on a ice40up5k, which synthesizes with an estimate of 24.81MHz and I've tried running the CPU at just 16MHz and exactly the same thing is happening, so it doesn't seem like a timing issue.

Not being able to run gdb on this is definitely hindering my progress, but my guess is this would probably be a heisenbug which wouldn't show itself when being debugged, as I don't believe this to be a software issue but a hardware (RTL) one.

Any and all kinds of help would be greatly appreciated. Thanks!

@agamez
Copy link
Contributor Author

agamez commented May 26, 2023

Here's another example that shows the CPU behaving strangely. There's this function:

static size_t get_reg_size(const struct bank_manager *bm, int reg_number)
{
        if (reg_number >= bm->bank_desc->n_regs)
                return 0;


        for (int i = 0; i < reg_number; i++) {
                neorv32_uart0_printf("n = %d, %d, %d, %d\n", reg_number, i, bm->bank_desc->regs_size[i], bm->bank_desc->regs_size[i - 1]);
                if (bm->bank_desc->regs_size[i] == 0) {
                        if (i > 0)
                                return bm->bank_desc->regs_size[i - 1];
                        else
                                return 0;
                }
        }

        return bm->bank_desc->regs_size[reg_number];
}

I realized I had an off-by-one error and I just replaced the loop to be for (int i = 0; i <= reg_number; i++) instead of for (int i = 0; i < reg_number; i++). Again, this function is not being executed, as the CPU fails before it can even reach UI code:

Booting from 0x00000000...

> ruction access faultMEOUT_ERR]C=0x7494D4B6VAL=0x44444444TAL EXCEPTION] Halting CPU. </RTE>

By some miracle, I removed the printf call and I could test the loop conditions change and it solved the bug on my own code, but I lost the ability to printf-debug. And of course it still doesn't make any sense though...

@stnolting
Copy link
Owner

Hey @agamez!

I am not sure if this is really caused by a hardware bug... This damaged massage looks like some problem with the stack:

ruction access faultMEOUT_ERR]C=0x7494D4B6VAL=0x44444444TAL EXCEPTION] Halting CPU.

Maybe it is a problem on the software side. Maybe a crash of the stack and the bss segment or some rogue code that overrides parts of the program code.

Anyway, could you provide a minimal example program?

@stnolting stnolting added SW Software-related troubleshooting Something is not working as expected labels May 31, 2023
@stnolting stnolting self-assigned this May 31, 2023
@agamez
Copy link
Contributor Author

agamez commented Jun 1, 2023

Hi @stnolting !

I've tried to reduce the offending code as much as possible, and I've reached a state that is quite small. I'm observing right now a different error, which isn't triggering a TRAP, but I think you are right and it's got something to do with a stack overflow bug because it's corrupting serial output.

The current code should just print: ART-NG-MCE-1.0 / art_reg_if-v1.0 and keep reading from uart0. However, it prints NG-MCE-1.0rt_reg_if-v1.0 which really looks like data is being overwritten by someone (and it's definitely not me!).

I've tried to make the code even smaller, but right now it doesn't matter what I change, because removing a variable or struct members, or removing a loop, or reducing the number of arguments of the function or whatever always makes it so the proper string is seen on the UART. Even moving the function on the second file to the main one, makes the error disappear.

The only relatively unusual thing there is I believe is the union, but it's not that rare, isn't it? Removing it makes the message turn OK, but also does it any other change, so I'm not sure if that's the culprit.

Anyway, since there are a couple of files I created a repo to store them, although I'm including the files here too for completeness.

neorv32-debug.tar.gz

Thanks a lot!

@stnolting
Copy link
Owner

I just tested the code you have attached to your last comment. I just modified the NEORV32 home folder path in the makefile and executed a simple GHDL simulation using the default testbench (latest version of the core):

$ make USER_FLAGS+=-DUART0_SIM_MODE clean_all sim
art_reg_if.c: In function 'art_reg_if':
art_reg_if.c:12:21: warning: unused variable 'instruction' [-Wunused-variable]
   12 |                 int instruction = neorv32_uart0_getc();
      |                     ^~~~~~~~~~~
../../../sw/lib/source/neorv32_uart.c: In function 'neorv32_uart_setup':
../../../sw/lib/source/neorv32_uart.c:116:2: warning: #warning UART0_SIM_MODE (primary UART) enabled! Sending all UART0.TX data to text.io simulation output instead of real UART0 transmitter. Use this for simulations only! [-Wcpp]
  116 | #warning UART0_SIM_MODE (primary UART) enabled! Sending all UART0.TX data to text.io simulation output instead of real UART0 transmitter. Use this for simulations only!
      |  ^~~~~~~
Memory utilization:
   text    data     bss     dec     hex filename
   3296       0     120    3416     d58 main.elf
Compiling ../../../sw/image_gen/image_gen
Installing application image to ../../../rtl/core/neorv32_application_image.vhd
Simulating neorv32_application_image.vhd...
Tip: Compile application with USER_FLAGS+=-DUART[0/1]_SIM_MODE to auto-enable UART[0/1]'s simulation mode (redirect UART output to simulator console).
../../src/ieee/math_real-body.vhdl:830:14:warning: declaration of "real_vector" hides type "real_vector" [-Whide]
        type REAL_VECTOR is array (NATURAL range <>) of REAL;
             ^
Using simulation runtime args: --stop-time=10ms
../../rtl/core/neorv32_top.vhd:347:3:@0ms:(assertion note): NEORV32 PROCESSOR CONFIGURATION: IMEM DMEM I-CACHE D-CACHE WISHBONE OCD + GPIO MTIME UART0 UART1 SPI SDI TWI PWM WDT TRNG CFS NEOLED XIRQ GPTMR XIP ONEWIRE DMA
../../rtl/core/neorv32_top.vhd:380:3:@0ms:(assertion note): NEORV32 PROCESSOR CONFIG NOTE: Boot configuration = direct boot from memory (processor-internal IMEM).
../../rtl/core/neorv32_top.vhd:392:3:@0ms:(assertion note): NEORV32 PROCESSOR CONFIG NOTE: Implementing on-chip debugger (OCD).
../../rtl/core/neorv32_cpu.vhd:144:3:@0ms:(assertion note): The NEORV32 RISC-V Processor (Version 0x01080502) - github.com/stnolting/neorv32
../../rtl/core/neorv32_cpu.vhd:148:3:@0ms:(assertion note): NEORV32 CPU CONFIG NOTE: Core ISA ('MARCH') = RV32IMCBU_Zicsr_Zicntr_Zicond_Zifencei_Zfinx_Zihpm_Zxcfu_Sdext_Sdtrig
../../rtl/core/neorv32_cpu.vhd:169:3:@0ms:(assertion warning): NEORV32 CPU WARNING! Assuming this is a simulation.
../../rtl/core/neorv32_cpu.vhd:177:3:@0ms:(assertion note): NEORV32 CPU CONFIG NOTE: Boot from address 0x00000000.
../../rtl/core/neorv32_cpu.vhd:183:3:@0ms:(assertion warning): NEORV32 CPU CONFIG WARNING! Overriding <CPU_IPB_ENTRIES> configuration (setting =2) because C ISA extension is enabled.
../../rtl/core/neorv32_cpu_cp_bitmanip.vhd:173:3:@0ms:(assertion note): NEORV32 CPU: Implementing bit-manipulation (B) sub-extensions Zba Zbb Zbc Zbs
../../rtl/core/neorv32_cpu_cp_cond.vhd:65:3:@0ms:(assertion warning): NEORV32 PROCESSOR CONFIG WARNING: The RISC-V 'Zicond' ISA extension is not ratified yet.
../../rtl/core/neorv32_dcache.vhd:136:3:@0ms:(assertion note): NEORV32 PROCESSOR CONFIG NOTE: d-cache uncached memory space 0xf0000000..0xffffffff.
../../rtl/core/mem/neorv32_imem.legacy.vhd:91:3:@0ms:(assertion note): NEORV32 PROCESSOR CONFIG NOTE: Using legacy HDL style IMEM.
../../rtl/core/mem/neorv32_imem.legacy.vhd:94:3:@0ms:(assertion note): NEORV32 PROCESSOR CONFIG NOTE: Implementing processor-internal IMEM as ROM (16384 bytes), pre-initialized with application (3296 bytes).
../../rtl/core/mem/neorv32_dmem.legacy.vhd:74:3:@0ms:(assertion note): NEORV32 PROCESSOR CONFIG NOTE: Using legacy HDL style DMEM.
../../rtl/core/mem/neorv32_dmem.legacy.vhd:77:3:@0ms:(assertion note): NEORV32 PROCESSOR CONFIG NOTE: Implementing processor-internal DMEM (RAM, 8192 bytes).
../../rtl/core/neorv32_wishbone.vhd:138:3:@0ms:(assertion note): NEORV32 PROCESSOR CONFIG NOTE: Ext. Bus Interface - CLASSIC/STANDARD Wishbone protocol, auto-timeout (256 cycles), LITTLE-endian byte order, registered RX, registered TX
../../rtl/core/neorv32_trng.vhd:144:3:@0ms:(assertion warning): NEORV32 PROCESSOR CONFIG WARNING: TRNG uses SIMULATION mode!
../../rtl/core/neorv32_trng.vhd:408:3:@0ms:(assertion note): << neoTRNG V2 - A Tiny and Platform-Independent True Random Number Generator for any FPGA >>
../../rtl/core/neorv32_trng.vhd:409:3:@0ms:(assertion note): neoTRNG note: Post-processing enabled.
../../rtl/core/neorv32_trng.vhd:410:3:@0ms:(assertion warning): neoTRNG WARNING: Simulation mode (PRNG!) enabled!
../../rtl/core/neorv32_trng.vhd:734:5:@0ms:(assertion warning): neoTRNG WARNING: Implementing simulation-only PRNG (LFSR)!
../../rtl/core/neorv32_trng.vhd:734:5:@0ms:(assertion warning): neoTRNG WARNING: Implementing simulation-only PRNG (LFSR)!
../../rtl/core/neorv32_trng.vhd:734:5:@0ms:(assertion warning): neoTRNG WARNING: Implementing simulation-only PRNG (LFSR)!
ART-NG-MCE-1.0 / art_reg_if-v1.0

The very last console line is the actual UART output, which looks fine, right?

So maybe there is configuration issue (hardware or software) on your side?!

  • What version of the core are you using?
  • Did you change the default linker script?
  • What GCC toolchain / version are you using?
  • What core configuration do you use (peripherals, ISA extensions, memory sizes, boot configuration)?

@agamez
Copy link
Contributor Author

agamez commented Jun 2, 2023

Hi!

I just tested the code you have attached to your last comment. I just modified the NEORV32 home folder path in the makefile and executed a simple GHDL simulation using the default testbench (latest version of the core):

I don't know why I didn't think of simulation it before... My simulation results are not the same as yours, instead they match what I see on the terminal.

$ make sim
art_reg_if.c: In function 'art_reg_if':
art_reg_if.c:12:21: warning: unused variable 'instruction' [-Wunused-variable]
   12 |                 int instruction = neorv32_uart0_getc();
      |                     ^~~~~~~~~~~
Memory utilization:
   text	   data	    bss	    dec	    hex	filename
   3284	      0	    120	   3404	    d4c	main.elf
Installing application image to ../neorv32/rtl/core/neorv32_application_image.vhd
Simulating neorv32_application_image.vhd...
Tip: Compile application with USER_FLAGS+=-DUART[0/1]_SIM_MODE to auto-enable UART[0/1]'s simulation mode (redirect UART output to simulator console).
Using simulation runtime args: --stop-time=10ms
../../rtl/core/neorv32_top.vhd:347:3:@0ms:(assertion note): NEORV32 PROCESSOR CONFIGURATION: IMEM DMEM I-CACHE D-CACHE WISHBONE OCD + GPIO MTIME UART0 UART1 SPI SDI TWI PWM WDT TRNG CFS NEOLED XIRQ GPTMR XIP ONEWIRE DMA 
../../rtl/core/neorv32_top.vhd:380:3:@0ms:(assertion note): NEORV32 PROCESSOR CONFIG NOTE: Boot configuration = direct boot from memory (processor-internal IMEM).
../../rtl/core/neorv32_top.vhd:392:3:@0ms:(assertion note): NEORV32 PROCESSOR CONFIG NOTE: Implementing on-chip debugger (OCD).
../../rtl/core/neorv32_cpu.vhd:144:3:@0ms:(assertion note): The NEORV32 RISC-V Processor (Version 0x01080502) - github.com/stnolting/neorv32
../../rtl/core/neorv32_cpu.vhd:148:3:@0ms:(assertion note): NEORV32 CPU CONFIG NOTE: Core ISA ('MARCH') = RV32IMCBU_Zicsr_Zicntr_Zicond_Zifencei_Zfinx_Zihpm_Zxcfu_Sdext_Sdtrig
../../rtl/core/neorv32_cpu.vhd:169:3:@0ms:(assertion warning): NEORV32 CPU WARNING! Assuming this is a simulation.
../../rtl/core/neorv32_cpu.vhd:177:3:@0ms:(assertion note): NEORV32 CPU CONFIG NOTE: Boot from address 0x00000000.
../../rtl/core/neorv32_cpu.vhd:183:3:@0ms:(assertion warning): NEORV32 CPU CONFIG WARNING! Overriding <CPU_IPB_ENTRIES> configuration (setting =2) because C ISA extension is enabled.
../../rtl/core/neorv32_cpu_cp_bitmanip.vhd:173:3:@0ms:(assertion note): NEORV32 CPU: Implementing bit-manipulation (B) sub-extensions Zba Zbb Zbc Zbs 
../../rtl/core/neorv32_cpu_cp_cond.vhd:65:3:@0ms:(assertion warning): NEORV32 PROCESSOR CONFIG WARNING: The RISC-V 'Zicond' ISA extension is not ratified yet.
../../rtl/core/neorv32_dcache.vhd:136:3:@0ms:(assertion note): NEORV32 PROCESSOR CONFIG NOTE: d-cache uncached memory space 0xf0000000..0xffffffff.
../../rtl/core/mem/neorv32_imem.legacy.vhd:91:3:@0ms:(assertion note): NEORV32 PROCESSOR CONFIG NOTE: Using legacy HDL style IMEM.
../../rtl/core/mem/neorv32_imem.legacy.vhd:94:3:@0ms:(assertion note): NEORV32 PROCESSOR CONFIG NOTE: Implementing processor-internal IMEM as ROM (16384 bytes), pre-initialized with application (3284 bytes).
../../rtl/core/mem/neorv32_dmem.legacy.vhd:74:3:@0ms:(assertion note): NEORV32 PROCESSOR CONFIG NOTE: Using legacy HDL style DMEM.
../../rtl/core/mem/neorv32_dmem.legacy.vhd:77:3:@0ms:(assertion note): NEORV32 PROCESSOR CONFIG NOTE: Implementing processor-internal DMEM (RAM, 8192 bytes).
../../rtl/core/neorv32_wishbone.vhd:138:3:@0ms:(assertion note): NEORV32 PROCESSOR CONFIG NOTE: Ext. Bus Interface - CLASSIC/STANDARD Wishbone protocol, auto-timeout (256 cycles), LITTLE-endian byte order, registered RX, registered TX
../../rtl/core/neorv32_trng.vhd:144:3:@0ms:(assertion warning): NEORV32 PROCESSOR CONFIG WARNING: TRNG uses SIMULATION mode!
../../rtl/core/neorv32_trng.vhd:408:3:@0ms:(assertion note): << neoTRNG V2 - A Tiny and Platform-Independent True Random Number Generator for any FPGA >>
../../rtl/core/neorv32_trng.vhd:409:3:@0ms:(assertion note): neoTRNG note: Post-processing enabled.
../../rtl/core/neorv32_trng.vhd:410:3:@0ms:(assertion warning): neoTRNG WARNING: Simulation mode (PRNG!) enabled!
../../rtl/core/neorv32_trng.vhd:734:5:@0ms:(assertion warning): neoTRNG WARNING: Implementing simulation-only PRNG (LFSR)!
../../rtl/core/neorv32_trng.vhd:734:5:@0ms:(assertion warning): neoTRNG WARNING: Implementing simulation-only PRNG (LFSR)!
../../rtl/core/neorv32_trng.vhd:734:5:@0ms:(assertion warning): neoTRNG WARNING: Implementing simulation-only PRNG (LFSR)!
uart_rx.simple.vhd:59:15:@504885ns:(report note): uart0.tx: N
uart_rx.simple.vhd:59:15:@1077765ns:(report note): uart0.tx: G
uart_rx.simple.vhd:59:15:@1650645ns:(report note): uart0.tx: -
uart_rx.simple.vhd:59:15:@2223525ns:(report note): uart0.tx: M
uart_rx.simple.vhd:59:15:@2796405ns:(report note): uart0.tx: C
uart_rx.simple.vhd:59:15:@3369285ns:(report note): uart0.tx: E
uart_rx.simple.vhd:59:15:@3942165ns:(report note): uart0.tx: -
uart_rx.simple.vhd:59:15:@4515045ns:(report note): uart0.tx: 1
uart_rx.simple.vhd:59:15:@5087925ns:(report note): uart0.tx: .
uart_rx.simple.vhd:59:15:@5660805ns:(report note): uart0.tx: 0
uart_rx.simple.vhd:59:15:@6233685ns:(report note): uart0.tx: r
uart_rx.simple.vhd:59:15:@6806565ns:(report note): uart0.tx: t
uart_rx.simple.vhd:59:15:@7379445ns:(report note): uart0.tx: _
uart_rx.simple.vhd:59:15:@7952325ns:(report note): uart0.tx: r
uart_rx.simple.vhd:59:15:@8525205ns:(report note): uart0.tx: e
uart_rx.simple.vhd:59:15:@9098085ns:(report note): uart0.tx: g
uart_rx.simple.vhd:59:15:@9670965ns:(report note): uart0.tx: _
ghdl:info: simulation stopped by --stop-time @10ms
make: *** [../neorv32/sw/common/common.mk:290: sim] Error 1

It looks like it grew tired of simulating it all :) But it's still visible that it was writing NG-MCE-1.0rt_reg which matches my results on hardware. I guess if I send you the neorv32_application_image.vhd it generated, you would get the same results? I'm attaching it here. Also... did you modify your output? Because in your log it only shows serial output, mine is being shown character by character with the nanoseconds.

neorv32_application_image.vhd.txt

The very last console line is the actual UART output, which looks fine, right?

Indeed, that is the expected output

So maybe there is configuration issue (hardware or software) on your side?!

* What version of the core are you using?

I'm using v1.8.4. I've just upgraded to the latest version and the same thing is happening. Although this time the implementation didn't reach timing closure, so I can't be entirely sure of these results.

* Did you change the default linker script?

Nope, neither the size of memory, they are the default

* What GCC toolchain / version are you using?

The one I built from https://github.com/riscv-collab/riscv-gnu-toolchain using your instructions in the user manual. It is version:

$ riscv32-unknown-elf-gcc -v
Using built-in specs.
COLLECT_GCC=riscv32-unknown-elf-gcc
COLLECT_LTO_WRAPPER=/home/sslayer/Proyectos/RISCV/riscv-bin/libexec/gcc/riscv32-unknown-elf/12.2.0/lto-wrapper
Target: riscv32-unknown-elf
Configured with: /home/sslayer/Proyectos/RISCV/riscv-gnu-toolchain/gcc/configure --target=riscv32-unknown-elf --prefix=/home/sslayer/Proyectos/RISCV/riscv-bin --disable-shared --disable-threads --enable-languages=c,c++ --with-pkgversion=g2ee5e430018 --with-system-zlib --enable-tls --with-newlib --with-sysroot=/home/sslayer/Proyectos/RISCV/riscv-bin/riscv32-unknown-elf --with-native-system-header-dir=/include --disable-libmudflap --disable-libssp --disable-libquadmath --disable-libgomp --disable-nls --disable-tm-clone-registry --src=.././gcc --disable-multilib --with-abi=ilp32 --with-arch=rv32i --with-tune=rocket --with-isa-spec=20191213 'CFLAGS_FOR_TARGET=-Os    -mcmodel=medlow' 'CXXFLAGS_FOR_TARGET=-Os    -mcmodel=medlow'
Thread model: single
Supported LTO compression algorithms: zlib
gcc version 12.2.0 (g2ee5e430018) 

* What core configuration do you use (peripherals, ISA extensions, memory sizes, boot configuration)?
	neorv32_top_inst: entity neorv32.neorv32_top
	generic map (
		-- General --
		CLOCK_FREQUENCY              => CLOCK_FREQUENCY,      -- clock frequency of clk_i in Hz
		HART_ID                      => x"00000000",
		VENDOR_ID                    => x"41525400",	-- "ART" v0
		CUSTOM_ID                    => x"4d434500",	-- "MCE" v0
		INT_BOOTLOADER_EN            => true,   -- boot configuration: true = boot explicit bootloader; false = boot from int/ext (I)MEM
		-- On-Chip Debugger (OCD) --
		ON_CHIP_DEBUGGER_EN          => false,  -- implement on-chip debugger
		-- RISC-V CPU Extensions --
		CPU_EXTENSION_RISCV_B        => false,  -- implement bit-manipulation extension?
		CPU_EXTENSION_RISCV_C        => false,  -- implement compressed extension?
		CPU_EXTENSION_RISCV_E        => false,  -- implement embedded RF extension?
		CPU_EXTENSION_RISCV_M        => false,  -- implement muld/div extension?
		CPU_EXTENSION_RISCV_U        => false,  -- implement user mode extension?
		CPU_EXTENSION_RISCV_Zfinx    => false,  -- implement 32-bit floating-point extension (using INT reg!)
		CPU_EXTENSION_RISCV_Zicntr   => true,   -- implement base counters?
		CPU_EXTENSION_RISCV_Zihpm    => false,  -- implement hardware performance monitors?
		CPU_EXTENSION_RISCV_Zifencei => true,  -- implement instruction stream sync.?
		CPU_EXTENSION_RISCV_Zmmul    => false,  -- implement multiply-only M sub-extension?
		CPU_EXTENSION_RISCV_Zxcfu    => false,  -- implement custom (instr.) functions unit?
		-- Extension Options --
		FAST_MUL_EN                  => false,  -- use DSPs for M extension's multiplier
		FAST_SHIFT_EN                => false,  -- use barrel shifter for shift operations
		CPU_IPB_ENTRIES              => 1,      -- entries in instruction prefetch buffer, has to be a power of 2, min 1
		-- Physical Memory Protection (PMP) --
		PMP_NUM_REGIONS              => 0,      -- number of regions (0..16)
		PMP_MIN_GRANULARITY          => 4,      -- minimal region granularity in bytes, has to be a power of 2, min 4 bytes
		-- Hardware Performance Monitors (HPM) --
		HPM_NUM_CNTS                 => 0,      -- number of implemented HPM counters (0..29)
		HPM_CNT_WIDTH                => 40,     -- total size of HPM counters (0..64)
		-- Internal Instruction memory --
		MEM_INT_IMEM_EN              => true,   -- implement processor-internal instruction memory
		MEM_INT_IMEM_SIZE            => 16*1024, -- size of processor-internal instruction memory in bytes
		-- Internal Data memory --
		MEM_INT_DMEM_EN              => true,   -- implement processor-internal data memory
		MEM_INT_DMEM_SIZE            => 8*1024, -- size of processor-internal data memory in bytes
		-- Internal Cache memory --
		ICACHE_EN                    => false,  -- implement instruction cache
		ICACHE_NUM_BLOCKS            => 4,      -- i-cache: number of blocks (min 1), has to be a power of 2
		ICACHE_BLOCK_SIZE            => 64,     -- i-cache: block size in bytes (min 4), has to be a power of 2
		ICACHE_ASSOCIATIVITY         => 1,      -- i-cache: associativity / number of sets (1=direct_mapped), has to be a power of 2
		-- External memory interface --
		MEM_EXT_EN                   => true,  -- implement external memory bus interface?
		MEM_EXT_TIMEOUT              => 255,    -- cycles after a pending bus access auto-terminates (0 = disabled)
		MEM_EXT_PIPE_MODE            => false,  -- protocol: false=classic/standard wishbone mode, true=pipelined wishbone mode
		MEM_EXT_BIG_ENDIAN           => false,  -- byte order: true=big-endian, false=little-endian
		MEM_EXT_ASYNC_RX             => false,  -- use register buffer for RX data when false
		MEM_EXT_ASYNC_TX             => false,  -- use register buffer for TX data when false
		-- External Interrupts Controller (XIRQ) --
		XIRQ_NUM_CH                  => 0,      -- number of external IRQ channels (0..32)
		XIRQ_TRIGGER_TYPE            => (others => '1'), -- trigger type: 0=level, 1=edge
		XIRQ_TRIGGER_POLARITY        => (others => '1'), -- trigger polarity: 0=low-level/falling-edge, 1=high-level/rising-edge
		-- Processor peripherals --
		IO_GPIO_NUM                  => 0,      -- implement general purpose input/output port unit (GPIO)?
		IO_MTIME_EN                  => true,   -- implement machine system timer (MTIME)?
		IO_UART0_EN                  => true,   -- implement primary universal asynchronous receiver/transmitter (UART0)?
		IO_UART0_RX_FIFO             => 16,     -- RX fifo depth, has to be a power of two, min 1
		IO_UART0_TX_FIFO             => 16,     -- TX fifo depth, has to be a power of two, min 1
		IO_UART1_EN                  => false,  -- implement secondary universal asynchronous receiver/transmitter (UART1)?
		IO_UART1_RX_FIFO             => 1,      -- RX fifo depth, has to be a power of two, min 1
		IO_UART1_TX_FIFO             => 1,      -- TX fifo depth, has to be a power of two, min 1
		IO_SPI_EN                    => true,   -- implement serial peripheral interface (SPI)?
		IO_SPI_FIFO                  => 32,     -- SPI RTX fifo depth, has to be zero or a power of two
		IO_TWI_EN                    => false,   -- implement two-wire interface (TWI)?
		IO_PWM_NUM_CH                => 0,      -- number of PWM channels to implement (0..60), 0 = disabled
		IO_WDT_EN                    => false,  -- implement watch dog timer (WDT)?
		IO_TRNG_EN                   => false,  -- implement true random number generator (TRNG)?
		IO_TRNG_FIFO                 => 1,      -- TRNG fifo depth, has to be a power of two, min 1
		IO_CFS_EN                    => false,  -- implement custom functions subsystem (CFS)?
		IO_CFS_CONFIG                => x"00000000", -- custom CFS configuration generic
		IO_CFS_IN_SIZE               => 32,    -- size of CFS input conduit in bits
		IO_CFS_OUT_SIZE              => 32,    -- size of CFS output conduit in bits
		IO_NEOLED_EN                 => false,   -- implement NeoPixel-compatible smart LED interface (NEOLED)?
		IO_GPTMR_EN                  => false,  -- implement general purpose timer (GPTMR)?
		IO_XIP_EN                    => false,  -- implement execute in place module (XIP)?
		IO_ONEWIRE_EN                => false   -- implement 1-wire interface (ONEWIRE)?
	)

I hope this all helps, thanks a lot!

@agamez
Copy link
Contributor Author

agamez commented Jun 2, 2023

Right, here's something strange.

If I simulate with your command line:
make USER_FLAGS+=-DUART0_SIM_MODE clean_all sim

Then my simulation output is exactly as yours: I see the whole string on the console and the message is the full ART-NG-MCE-1.0 / art_reg_if-v1.0

If I simulate without defining DUART0_SIM_MODE:

make clean_all sim

Then I see what I wrote on my post above, the characters one by one and the message that is being output is wrong:

uart_rx.simple.vhd:59:15:@504885ns:(report note): uart0.tx: N
uart_rx.simple.vhd:59:15:@1077765ns:(report note): uart0.tx: G
uart_rx.simple.vhd:59:15:@1650645ns:(report note): uart0.tx: -
uart_rx.simple.vhd:59:15:@2223525ns:(report note): uart0.tx: M
uart_rx.simple.vhd:59:15:@2796405ns:(report note): uart0.tx: C
uart_rx.simple.vhd:59:15:@3369285ns:(report note): uart0.tx: E
uart_rx.simple.vhd:59:15:@3942165ns:(report note): uart0.tx: -
uart_rx.simple.vhd:59:15:@4515045ns:(report note): uart0.tx: 1
uart_rx.simple.vhd:59:15:@5087925ns:(report note): uart0.tx: .
uart_rx.simple.vhd:59:15:@5660805ns:(report note): uart0.tx: 0
uart_rx.simple.vhd:59:15:@6233685ns:(report note): uart0.tx: r
uart_rx.simple.vhd:59:15:@6806565ns:(report note): uart0.tx: t
uart_rx.simple.vhd:59:15:@7379445ns:(report note): uart0.tx: _
uart_rx.simple.vhd:59:15:@7952325ns:(report note): uart0.tx: r
uart_rx.simple.vhd:59:15:@8525205ns:(report note): uart0.tx: e
uart_rx.simple.vhd:59:15:@9098085ns:(report note): uart0.tx: g
uart_rx.simple.vhd:59:15:@9670965ns:(report note): uart0.tx: _

Changing BAUD_RATE to 115200 makes it even worse and shows just nonsense:

uart_rx.simple.vhd:57:15:@503195ns:(report note): uart0.tx: (31)
uart_rx.simple.vhd:59:15:@980705ns:(report note): uart0.tx: ?
uart_rx.simple.vhd:57:15:@1458205ns:(report note): uart0.tx: (189)

Is this just a timing issue? But reducing UART speed to 1200 does not make it any better:

uart_rx.simple.vhd:57:15:@506755ns:(report note): uart0.tx: (138)
uart_rx.simple.vhd:57:15:@1001565ns:(report note): uart0.tx: (163)
uart_rx.simple.vhd:57:15:@1509435ns:(report note): uart0.tx: (138)
uart_rx.simple.vhd:57:15:@2004245ns:(report note): uart0.tx: (161)
uart_rx.simple.vhd:57:15:@2512115ns:(report note): uart0.tx: (135)
uart_rx.simple.vhd:57:15:@3045985ns:(report note): uart0.tx: (207)
uart_rx.simple.vhd:57:15:@3553845ns:(report note): uart0.tx: (255)
uart_rx.simple.vhd:57:15:@4048665ns:(report note): uart0.tx: (142)
uart_rx.simple.vhd:57:15:@4569545ns:(report note): uart0.tx: (153)
uart_rx.simple.vhd:57:15:@5090435ns:(report note): uart0.tx: (242)

But setting it to 1200 and simulation with make USER_FLAGS+=-DUART0_SIM_MODE clean_all sim:

$ make USER_FLAGS+=-DUART0_SIM_MODE clean_all sim
art_reg_if.c: In function 'art_reg_if':
art_reg_if.c:12:21: warning: unused variable 'instruction' [-Wunused-variable]
   12 |                 int instruction = neorv32_uart0_getc();
      |                     ^~~~~~~~~~~
../neorv32/sw/lib/source/neorv32_uart.c: In function 'neorv32_uart_setup':
../neorv32/sw/lib/source/neorv32_uart.c:116:2: warning: #warning UART0_SIM_MODE (primary UART) enabled! Sending all UART0.TX data to text.io simulation output instead of real UART0 transmitter. Use this for simulations only! [-Wcpp]
  116 | #warning UART0_SIM_MODE (primary UART) enabled! Sending all UART0.TX data to text.io simulation output instead of real UART0 transmitter. Use this for simulations only!
      |  ^~~~~~~
Memory utilization:
   text	   data	    bss	    dec	    hex	filename
   3292	      0	    120	   3412	    d54	main.elf
Compiling ../neorv32/sw/image_gen/image_gen
Installing application image to ../neorv32/rtl/core/neorv32_application_image.vhd
Simulating neorv32_application_image.vhd...
Tip: Compile application with USER_FLAGS+=-DUART[0/1]_SIM_MODE to auto-enable UART[0/1]'s simulation mode (redirect UART output to simulator console).
Using simulation runtime args: --stop-time=10ms
../../rtl/core/neorv32_top.vhd:347:3:@0ms:(assertion note): NEORV32 PROCESSOR CONFIGURATION: IMEM DMEM I-CACHE D-CACHE WISHBONE OCD + GPIO MTIME UART0 UART1 SPI SDI TWI PWM WDT TRNG CFS NEOLED XIRQ GPTMR XIP ONEWIRE DMA 
../../rtl/core/neorv32_top.vhd:380:3:@0ms:(assertion note): NEORV32 PROCESSOR CONFIG NOTE: Boot configuration = direct boot from memory (processor-internal IMEM).
../../rtl/core/neorv32_top.vhd:392:3:@0ms:(assertion note): NEORV32 PROCESSOR CONFIG NOTE: Implementing on-chip debugger (OCD).
../../rtl/core/neorv32_cpu.vhd:144:3:@0ms:(assertion note): The NEORV32 RISC-V Processor (Version 0x01080502) - github.com/stnolting/neorv32
../../rtl/core/neorv32_cpu.vhd:148:3:@0ms:(assertion note): NEORV32 CPU CONFIG NOTE: Core ISA ('MARCH') = RV32IMCBU_Zicsr_Zicntr_Zicond_Zifencei_Zfinx_Zihpm_Zxcfu_Sdext_Sdtrig
../../rtl/core/neorv32_cpu.vhd:169:3:@0ms:(assertion warning): NEORV32 CPU WARNING! Assuming this is a simulation.
../../rtl/core/neorv32_cpu.vhd:177:3:@0ms:(assertion note): NEORV32 CPU CONFIG NOTE: Boot from address 0x00000000.
../../rtl/core/neorv32_cpu.vhd:183:3:@0ms:(assertion warning): NEORV32 CPU CONFIG WARNING! Overriding <CPU_IPB_ENTRIES> configuration (setting =2) because C ISA extension is enabled.
../../rtl/core/neorv32_cpu_cp_bitmanip.vhd:173:3:@0ms:(assertion note): NEORV32 CPU: Implementing bit-manipulation (B) sub-extensions Zba Zbb Zbc Zbs 
../../rtl/core/neorv32_cpu_cp_cond.vhd:65:3:@0ms:(assertion warning): NEORV32 PROCESSOR CONFIG WARNING: The RISC-V 'Zicond' ISA extension is not ratified yet.
../../rtl/core/neorv32_dcache.vhd:136:3:@0ms:(assertion note): NEORV32 PROCESSOR CONFIG NOTE: d-cache uncached memory space 0xf0000000..0xffffffff.
../../rtl/core/mem/neorv32_imem.legacy.vhd:91:3:@0ms:(assertion note): NEORV32 PROCESSOR CONFIG NOTE: Using legacy HDL style IMEM.
../../rtl/core/mem/neorv32_imem.legacy.vhd:94:3:@0ms:(assertion note): NEORV32 PROCESSOR CONFIG NOTE: Implementing processor-internal IMEM as ROM (16384 bytes), pre-initialized with application (3292 bytes).
../../rtl/core/mem/neorv32_dmem.legacy.vhd:74:3:@0ms:(assertion note): NEORV32 PROCESSOR CONFIG NOTE: Using legacy HDL style DMEM.
../../rtl/core/mem/neorv32_dmem.legacy.vhd:77:3:@0ms:(assertion note): NEORV32 PROCESSOR CONFIG NOTE: Implementing processor-internal DMEM (RAM, 8192 bytes).
../../rtl/core/neorv32_wishbone.vhd:138:3:@0ms:(assertion note): NEORV32 PROCESSOR CONFIG NOTE: Ext. Bus Interface - CLASSIC/STANDARD Wishbone protocol, auto-timeout (256 cycles), LITTLE-endian byte order, registered RX, registered TX
../../rtl/core/neorv32_trng.vhd:144:3:@0ms:(assertion warning): NEORV32 PROCESSOR CONFIG WARNING: TRNG uses SIMULATION mode!
../../rtl/core/neorv32_trng.vhd:408:3:@0ms:(assertion note): << neoTRNG V2 - A Tiny and Platform-Independent True Random Number Generator for any FPGA >>
../../rtl/core/neorv32_trng.vhd:409:3:@0ms:(assertion note): neoTRNG note: Post-processing enabled.
../../rtl/core/neorv32_trng.vhd:410:3:@0ms:(assertion warning): neoTRNG WARNING: Simulation mode (PRNG!) enabled!
../../rtl/core/neorv32_trng.vhd:734:5:@0ms:(assertion warning): neoTRNG WARNING: Implementing simulation-only PRNG (LFSR)!
../../rtl/core/neorv32_trng.vhd:734:5:@0ms:(assertion warning): neoTRNG WARNING: Implementing simulation-only PRNG (LFSR)!
../../rtl/core/neorv32_trng.vhd:734:5:@0ms:(assertion warning): neoTRNG WARNING: Implementing simulation-only PRNG (LFSR)!
NG-MCE-1.0rt_reg_if-v1.0

After seen all this... I'm also wondering if this is the underlying cause to my traps or if they are two different things. In any case, it'd be good to solve this.

@stnolting
Copy link
Owner

I checked your code a little bit further. You are right, using make USER_FLAGS+=-DUART0_SIM_MODE clean_all sim for the simulation outputs the right string while using make clean_all sim leads to an incorrect string.

Adding -DUART0_SIM_MODE to the simulation scripts automatically inserts code that enables the UART's simulation mode (see Datasheet: UART0 section "Simulation mode"). When this mode is enabled there are no "physical" UART transmissions. Instead, all the data written to the UART TX FIFO is send to VHDL textio and printed to the simulator console.

When the UART simulation mode is disabled, all UART data is sent to "simulation receiver" using an actual physical transmission based on the configured BAUD rate: https://github.com/stnolting/neorv32/blob/main/sim/simple/uart_rx.simple.vhd

Note that the baud rate of this simulation receiver is hardwired to 19200. If you change the baud rate on the software side then you will get garbage as output. The simulation mode is not affected by this as there is no "real/physical" transmission.

Anyway, I had a close look at the actual executable being executed. And it seems like we have a problem there. If the executable (or more specific, the .text section / the actual program code) has a (very) specific size, then it gets padded with some zero bytes to enforce some specific alignment. This causes a "hole" between the text segment and the following rodata segment (which contains the strings your are outputting).

.text and rodata are extracted from the final ELF and concatenated to form the actual executable. This process requires that there is no gap (in terms of continuous addresses) between those segments. However, in the current setup we do have a gap here:

 9c8:	f61ff0ef          	jal	ra,928 <__hidden___udivsi3>
 9cc:	40b00533          	neg	a0,a1
 9d0:	00028067          	jr	t0

Disassembly of section .rodata:

000009d8 <config_bank_manager-0x10>:
 9d8:	5241                	.2byte	0x5241
 9da:	2d54                	.2byte	0x2d54
 9dc:	474e                	.2byte	0x474e

Here, address 9d4 is missing. This causes an offset in .rodata. So all the addresses / data there are "off" by 4 bytes.

So this is a problem with the linker script. I think I found a way to fix this, but I need some more testing. I will file a PR when everything is ready.

Thank you very much for finding this (heisen-)bug! This is a very interesting corner case you have found! 😉

@stnolting stnolting added bug Something isn't working as expected and removed troubleshooting Something is not working as expected labels Jun 2, 2023
@agamez
Copy link
Contributor Author

agamez commented Jun 2, 2023

Here, address 9d4 is missing. This causes an offset in .rodata. So all the addresses / data there are "off" by 4 bytes.

That definitely explains why a working program wouldn't fail ever but a wrong one would fail even when changing a region of code that was never reached. With a little bit of luck, only the strings were misaligned, but code could still execute, otherwise instructions would all be mangled up and the existence of const pointers to functions probably made it easier to spot.

Thank you very much for finding this (heisen-)bug! This is a very interesting corner case you have found! 😉

Well, my. Thanks to you, definitely. I wouldn't have ever guessed any of that. I truly appreciate your assistance. The quality of your work is more than remarkable!

@stnolting
Copy link
Owner

I have started implementing a fix for this in #626.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working as expected SW Software-related
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants