Boot stalls at address 0x80001CBC

[fritzbauer]

Thank you very much for this amazing project. Really interesting idea!

Issue

I tried to boot on the Arduino, however even after waiting for a night there is no further output except for

arv32-opt: mini-rv32ima on Arduino UNO
SD card initialized successfully!
Current AVR free memory: 170 bytes

Dumping the state returns this:

Effective emulated speed: 10158 Hz, dtime=3795ms, dcycle=38550
Current AVR free memory: 170 bytes
icache hit/miss: 210245342/103741477; dcache hit/miss: 930282/177620
==============================================================================
Dumping emulator state:
Registers x0 - x31:
0x00000000 0x80001CC8 0x4EAECE20 0x80332FC8
0x802F1340 0x8040C1DC 0x00000002 0x00000000
0x80000010 0x80357740 0x0061E4DF 0x80357740
0x00000008 0x802E6C80 0x00000000 0x00308650
0xFFFFFFFF 0xFFFFFFFF 0x802EFE9F 0x802E6C83
0x802EFE9C 0x802EFE94 0x00000008 0x802E6C83
0x802D76F0 0x00000007 0x0000000B 0x00000000
0x00000002 0x000FFFFF 0x00000000 0x802EFE9C
pc: 0x80001CBC
mstatus: 0x00001800
cyclel: 0x12B71040
cycleh: 0x00000000
timerl: 0x095B881D
timerh: 0x00000000
timermatchl: 0x000DA10F
timermatchh: 0x00000000
mscratch: 0x00000000
mtvec: 0x80001CBC
mie: 0x00000088
mip: 0x00000080
mepc: 0x800088A8
mtval: 0x4EAECE28
mcause: 0x00000007
extraflags: 0x0179F623
==============================================================================
Dump completed. Emulator will continue when B1 is set back to HIGH
B1 is set to HIGH, emulator resume

• PC points to 0x80001CBC which is the trap handler address stored in mtvec. Repeatedly dumping the state always shows the same PC address.
• The first couple of minutes while booting the dumps show the PC changing constantly, but once it points to 0x80001CBC, it does not change anymore.

Troubleshooting

• Did you experience the same already and might have a hint, what is causing this?
• Do you have any best practices for troubleshooting?
• How did you build the rv32.bin image? Do you probably have the Makefiles, buildroot and kernelconfig available? This might help to add some code for debugging...
  • Booting this image with mini-rv32ima succeeds

[raspiduino]

Hello and thank you for being intersted in this project!
Honestly not only you but also I find the new fCLK increase to 8MHz commit really unstable. So probably you can try reset to commit f831c56cb7dc86fe63289bde70ce3d3ea5242d68 in the main branch. That revert the 8MHz change, and hopefully solve the problem.

For your question:

Did you experience the same already and might have a hint, what is causing this?

Yes, I have experienced it a lot since I move to 8MHz. In some cases when I'm lucky I was able to boot to clocksource or sth, but then it stuck. I have no idea why.

Do you have any best practices for troubleshooting?

I don't know too. But usually, I would double check the SD connection. Also I will try check the assembly at the PC address, by loading the image into IDA, then check that address (remember to rebase the image in IDA).

How did you build the rv32.bin image?

I modified mini-rv32ima to dump the RAM image immediately after it loads all the stuff to RAM. Something like this, but newer (the link is the old ver).

Do you probably have the Makefiles, buildroot and kernelconfig available?

I use the same build files as cnlohr's. Nothing changed.

Booting this image with mini-rv32ima succeeds

Yes, that would be a surprise if it didn't. Just remember to set RAM amount to 16MB

[fritzbauer]

Thank you, these points already helped a lot!
Unfortunately, setting the SD card to slow mode did not help in my case. It is still very unstable, so I changed your code to reinitialize SPI & the SD card instead of halting. Furthermore, I added code to set breakpoints, step debug and read memory: main...fritzbauer:arv32-opt:Debugger

Afterwards, I was able to figure out that the indefinitely looping traps occur after a kernel panic.
It turned out that setup_bootmem() was failing to memcpy() because the destination parameter new_dtb_early_va was pointing to 0. This was because memblock_phys_alloc() failed...I did not understand the details of that function but assumed that something could be wrong with the calculation of the dtb_pa.

So I compared the value of the avr32-opt calculation (0x80FFF93C) with the one mini-rv32ima (0x80FFF940).
After I added +4 to the calculation it is booting successfully now!
I guess, I need to be waiting patiently for the prompt now ;)

[fritzbauer]

Ok, I am confused again. The wrong value was caused because I adjusted the struct MiniRV32IMAState and added an additional register... It turns out it does not make sense to calculate the dtb_pa, because the offset depends on the static rv32.bin. For the current file 0x80FFF940 seems to be the right value.
However, I do not have an explanation, why it started booting successfully now and failed on my previous attempts...
EDIT: So it seems to be the combination: Reverting fCLK increase to 8MHz is needed indeed, otherwise it will stall at some point. My SD retry logic does not fix this. However, I need the retry logic, because I receive the failed 10 times error quite frequently.

[raspiduino]

You added a buffer for UART?

input_buf = (char*)malloc((INPUT_LEN+1)*sizeof(char));
memset(input_buf, 0, INPUT_LEN+1);

Well, since the UART itself also has problem when you type into the prompt (it only take first 2 characters, then finally an enter; probably because AVR's UART register only save only value at a time, and can't get more), I also wanted to implement a FIFO buffer for it (but I was too lazy). Now I will try adding it, and hopefully it will fix the UART problem.

Overall I think your changes look good for me. I will merge it if you create a PR. Thank you for contributing!

[fritzbauer]

Ahh, that's good to know. I'll see how mine behaves. Still booting, just printed Run /init as init process.
It's not really a buffer which is used for the emulated core. I added some debugging functionality. That buffer is used to read 8 characters for the address in order to print the value at that address afterwards.

[raspiduino]

Still booting, just printed Run /init as init process.

Wait for it!

It's not really a buffer which is used for the emulated core.

Yes I know, that's why I said Now I will try adding it, and hopefully it will fix the UART problem.

[fritzbauer]

Wait for it!
Huuurrraaayyy! It is up. Running coremark now...If it does 20.000 iterations like it does in mini-rv32ima it may take up to a week xD

fix the UART problem
I think the UART problem is caused by the Arduino serial console, since it always submits the whole string at once. I was able to
type the whole commands by writing one character at a time. Although it takes quite some time to input each character (~30s). You may have more success using PuTTY as serial console...

I think the issue can be considered as resolved after reverting the SD commit. After coremark completed I still might try to check what causes the kernel to panic in the fast SD card mode...(therefore, leaving to you whether you want to close it now)

[raspiduino]

Congratulation on successfully booting Linux on your Arduino UNO! Btw did you measured the time?

what causes the kernel to panic in the fast SD card mode

I also want to know it, I don't think I can wait 16 hours again for Linux to boot.

P/S: if you have time, please take a look at a branch named restore. It's still buggy for now (and even uncompleted, IIRC), but the basic concept is to save the boot state so you don't need to wait 16 hours.

[fritzbauer]

I think it was around 15h 30min for me.

Ohh, I like the restore idea! Was thinking whether I could obtain the register values even from my current boot, write them to the SD manually and restore them after the code is complete. However, I am afraid there is no point were all caches are flushed to the SD, right?! Than at least a way to flush the caches would be needed for the next boot. When do you want to store all the data to the SD card? Each time B1 is pulled low?

[raspiduino]

When do you want to store all the data to the SD card? Each time B1 is pulled low?

You might use another digital pin for restore button, or you can use the command menu you added to the state dump (the command menu for debugging), and add a command to save state and load state or sth

[fritzbauer]

I tried to avoid booting by restoring, but not too successfully.
In mini-rv32ima I added the export to CtrlC():

FILE * dump = fopen("dump.bin", "wb");
    for (uint32_t i = 0; i < ram_amt; i++) {
        uint8_t b = ram_image[i];
        fwrite(&b, 1, 1, dump);
    }

Then I booted the emulator to the command prompt and hit CtrlC. Removing all the code from the emulator which modifies the state and loading this dumped file works great. The system continues were it was before. However, using the same dump on the Arduino did not work.
Since ram_image already contains the core at the end, it is quite handy to just load this data which is already in the dump in the Arduino. Just replace the memset 0 for the core with this part:

UInt8 *core_data = (UInt8*)core;
UInt32 core_base = RAM_SIZE - sizeof( struct MiniRV32IMAState );
for (uint32_t i = 0; i < sizeof(struct MiniRV32IMAState); i++) {
        UInt8 b = load1(core_base + i);
        core_data[i] = b;
}

I confirmed that the core has all registers set properly afterwards. However, on the first attempt a kernel OOPS happened and on the next attempt there was no output at all and it ended up at 0x80001CBC again.

[raspiduino]

Then I booted the emulator to the command prompt and hit CtrlC.

I made the exact same mistake! The problem is that when you press CTRL+C, the excution loop, wherever it is, will break, and the current state is saved to your file.

As you know, there is a macro that define the number of instruction to execute (in the emulator's for loop) before breaking out, checking the state, set state flag and handle error, and also increasing the timer. If you break when you are in the middle of the loop, some flag and error might not be handled, the timer will not be increased and the unhandled state will be saved. That will lead to unexpected behaviour.

So what can you do? When you press CTRL+C, the CtrlC handler function will set a flag. In the loop, after calculating the timer value and right before calling to the emulator function, do a if check to see if the break flag is set. If yes, then save the state and exit.

This should work.

[raspiduino]

I will close this as it's no longer an issue. Feel free to reopen or create a new issue report if you want.