Stuck in loading RAM

[olofk]

Stuck in loading RAM

[olofk]

This should be really quick. Just a couple of seconds. I found errors in the documentation though. The command should be fusesoc run --target=verilator_tb servant --uart_baudrate=57600 --firmware=$SERV/serv/sw/zephyr_hello.hex The documentation is missing a serv/ between ...$SERV/ and sw.... But my version of verilator just stopped and complained that it couldn't find the file so I wonder if it's the same issue that you see

[Martoni]

If I add serv/ between $SERV/ and sw I have a file not found error :

fusesoc run --target=verilator_tb servant --uart_baudrate=57600 --firmware=$SERV/serv/sw/zephyr_hello.hex
INFO: Preparing ::serv:0
INFO: Preparing ::servant:0

verilator -f servant_0.vc --trace
make  -f Vservant.mk
make[1]: Entering directory '/home/fabien/myfpga/serv_virgin/workspace/build/servant_0/verilator_tb-verilator'

[...]

      Archiving Vservant__ALL.a ...
ar r Vservant__ALL.a Vservant__ALLcls.o Vservant__ALLsup.o
ar: creating Vservant__ALL.a
ranlib Vservant__ALL.a
g++    servant_tb.o verilated.o verilated_dpi.o verilated_vcd_c.o Vservant__ALL.a    -o Vservant -lm -lstdc++  2>&1 | c++filt
make[1]: Leaving directory '/home/fabien/myfpga/serv_virgin/workspace/build/servant_0/verilator_tb-verilator'
Loading RAM from /home/fabien/myfpga/serv_virgin/serv/sw/zephyr_hello.hex
%Error: /home/fabien/myfpga/serv_virgin/serv/sw/zephyr_hello.hex:0: $readmem file not found
Aborting...
ERROR: Failed to run ::servant:0 : './Vservant' exited with an error code

But I realize that my $SERV variable should not include the 'serv' directory name in fact. Then this line is false in my previous pull request :

cd $SERV/workspace && fusesoc library add serv $SERV

should be

cd $SERV/workspace && fusesoc library add serv ../serv

As it was.

[olofk]

Ah, yes. The original line was correct. Missed that change.

But I guess this still doesn't help with getting output from the CPU. Could you add --vcd to the command-line and check the VCD in build/servant_0/verilator_tb-verilator/trace.vcd to see if it seems to be alive at all (e.g. by checking the *_ibus_* signals in the CPU to see if it fetches new instructions)

[Martoni]

Yes, vcd file :

./build/servant_0/verilator_tb-verilator/trace.vcd

Is growing when I add the option --vcd. And being really big !
It seems to do something until 30ms:

After these 30ms the traces seems to be periodic :

[olofk]

Ok, this is actually pretty good but weird. The program finishes after 30 ms and just jumps to the current address (this is the opcode 0x0000006f in the trace), so it seems to be working but not outputting anything.

Three things to try:

1. Remove the uart_baudrate option and see if it starts printing a lot of 23766832 output q is OFF 23819098 output q is ON. This turns off the UART decoder and treats the q output as a GPIO
2. Measure the shortest time between two edges of the q signals so we can check if the baud rate is wrong for some reason
3. Check the value of baud_t in bench/servant_tb.cpp (e.g. add a printf("%d\n", context->baud_t); in uart_init)

[Martoni]

1. It start printing lot of output number yes :

Loading RAM from /home/fabien/myfpga/myserv/serv/sw/zephyr_hello.hex
2909536 output q is ON
3657442 output q is OFF
3692286 output q is ON
3709708 output q is OFF
3727130 output q is ON
3744552 output q is OFF
3761974 output q is ON
3779396 output q is OFF
3814240 output q is ON
3972774 output q is OFF
4007618 output q is ON
4025040 output q is OFF
4042462 output q is ON
4059884 output q is OFF
4077306 output q is ON
4094728 output q is OFF
4129572 output q is ON
[...]

I get 521 output with variable value intervals :

output  | output - output(-1)
2909536 |  
3657442 | 747906
3692286 | 34844
3709708 | 17422
3727130 | 17422
3744552 | 17422
3761974 | 17422
3779396 | 17422
3814240 | 34844
3972774 | 158534
4007618 | 34844
4025040 | 17422
4042462 | 17422
4059884 | 17422
4077306 | 17422
4094728 | 17422
4129572 | 34844
4288106 | 158534
4322950 | 34844
4340372 | 17422
4357794 | 17422
4375216 | 17422
4392638 | 17422
4410060 | 17422
4444904 | 34844
4603438 | 158534
4638282 | 34844
4655704 | 17422
4673126 | 17422
4690548 | 17422
4707970 | 17422
4725392 | 17422
4760236 | 34844
4918770 | 158534
4953614 | 34844
4971036 | 17422
4988458 | 17422
5005880 | 17422
5023302 | 17422
5040724 | 17422
5075568 | 34844
5234102 | 158534
5338634 | 104532
[...]

[Martoni]

2. I measured a baud-rate of 57408.

[Martoni]

3. I got this baud rate :

---> 17361

Only if I set the option :

--uart_baudrate=57600

[olofk]

Super weird. I get the same numbers here.

I'm running out of ideas, but could you add some debug prints to check if the state changes in the do_uart function in bench/servant_tb.v. Especially to see if the putchar function is called at all

[Martoni]

I added a printf in myserv/serv/bench/servant_tb.cpp :

 void do_uart(uart_context_t *context, bool rx) {
@@ -69,6 +70,7 @@ void do_uart(uart_context_t *context, bool rx) {
   else {
     if (main_time > context->last_update) {
       context->last_update += context->baud_t;
+      printf("Putchar context %c", context->ch);
       putchar(context->ch);
       context->state=0;
     }

But nothing is printed, with or without option --uart_baudrate=57600

[olofk]

Ok, so there's something fishy with the do_uart function. This will only be called when uart_baudrate is used btw. Can you try the following?

diff --git a/bench/servant_tb.cpp b/bench/servant_tb.cpp
index 13110aa..8f53bc7 100644
--- a/bench/servant_tb.cpp
+++ b/bench/servant_tb.cpp
@@ -50,6 +50,7 @@ void do_uart(uart_context_t *context, bool rx) {
     if (!rx) {
       context->last_update = main_time + context->baud_t/2;
       context->state++;
+      printf("%lu Moving to state %d. Next check at %lu\n", main_time, context->state, context->last_update);
     }
   }
   else if(context->state == 1) {
@@ -57,6 +58,7 @@ void do_uart(uart_context_t *context, bool rx) {
       context->last_update += context->baud_t;
       context->ch = 0;
       context->state++;
+      printf("%lu Moving to state %d. Next check at %lu\n", main_time, context->state, context->last_update);
     }
   }
   else if (context->state < 10) {
@@ -64,6 +66,7 @@ void do_uart(uart_context_t *context, bool rx) {
       context->last_update += context->baud_t;
       context->ch |= rx << (context->state-2);
       context->state++;
+      printf("%lu Moving to state %d. Next check at %lu\n", main_time, context->state, context->last_update);
     }
   }
   else {
@@ -71,6 +74,7 @@ void do_uart(uart_context_t *context, bool rx) {
       context->last_update += context->baud_t;
       putchar(context->ch);
       context->state=0;
+      printf("%lu Moving to state %d\n", main_time, context->state);
     }
   }
 }

[olofk]

Ha! I think I found the issue, thanks to another project using basically the same code. It seems to be caused by the state variable not being explicitly initialized to 0. On my system it seems to end up zero anyway, but just tried with a different environment and got no printout there due to the state starting up with the value 4.

So if you haven't given up, you could try the latest version where I have pushed a fix that will hopefully take care of this

[Martoni]

I haven't given up ! (but I was in family holidays ;)
I pulled new version with your last commit and it seems to work :

 fusesoc run --target=verilator_tb servant --uart_baudrate=57600 --firmware=$SERV/serv/sw/zephyr_hello.hex
INFO: Preparing ::serv:0
INFO: Preparing ::servant:0

verilator -f servant_0.vc --trace
make  -f Vservant.mk
make[1]: Entering directory '/home/fabien/myfpga/myserv/workspace/build/servant_0/verilator_tb-verilator'
g++  -I.  -MMD -I/usr/local/share/verilator/include -I/usr/local/share/verilator/include/vltstd -DVL_PRINTF=printf -DVM_COVERAGE=0 -DVM_SC=0 -DVM_TRACE=1 -Wno-char-subscripts -Wno-sign-compare -Wno-uninitialized -Wno-unused-but-set-variable -Wno-unused-parameter -Wno-unused-variable     -I../src/serv_0/rtl   -c -o servant_tb.o ../src/servant_0/bench/servant_tb.cpp
g++  -I.  -MMD -I/usr/local/share/verilator/include -I/usr/local/share/verilator/include/vltstd -DVL_PRINTF=printf -DVM_COVERAGE=0 -DVM_SC=0 -DVM_TRACE=1 -Wno-char-subscripts -Wno-sign-compare -Wno-uninitialized -Wno-unused-but-set-variable -Wno-unused-parameter -Wno-unused-variable     -I../src/serv_0/rtl   -c -o verilated.o /usr/local/share/verilator/include/verilated.cpp
g++  -I.  -MMD -I/usr/local/share/verilator/include -I/usr/local/share/verilator/include/vltstd -DVL_PRINTF=printf -DVM_COVERAGE=0 -DVM_SC=0 -DVM_TRACE=1 -Wno-char-subscripts -Wno-sign-compare -Wno-uninitialized -Wno-unused-but-set-variable -Wno-unused-parameter -Wno-unused-variable     -I../src/serv_0/rtl   -c -o verilated_dpi.o /usr/local/share/verilator/include/verilated_dpi.cpp
g++  -I.  -MMD -I/usr/local/share/verilator/include -I/usr/local/share/verilator/include/vltstd -DVL_PRINTF=printf -DVM_COVERAGE=0 -DVM_SC=0 -DVM_TRACE=1 -Wno-char-subscripts -Wno-sign-compare -Wno-uninitialized -Wno-unused-but-set-variable -Wno-unused-parameter -Wno-unused-variable     -I../src/serv_0/rtl   -c -o verilated_vcd_c.o /usr/local/share/verilator/include/verilated_vcd_c.cpp
/usr/bin/perl /usr/local/share/verilator/bin/verilator_includer -DVL_INCLUDE_OPT=include Vservant.cpp Vservant_servant.cpp Vservant_servant_ram__D2000.cpp > Vservant__ALLcls.cpp
/usr/bin/perl /usr/local/share/verilator/bin/verilator_includer -DVL_INCLUDE_OPT=include Vservant__Dpi.cpp Vservant__Trace.cpp Vservant__Syms.cpp Vservant__Trace__Slow.cpp > Vservant__ALLsup.cpp
g++  -I.  -MMD -I/usr/local/share/verilator/include -I/usr/local/share/verilator/include/vltstd -DVL_PRINTF=printf -DVM_COVERAGE=0 -DVM_SC=0 -DVM_TRACE=1 -Wno-char-subscripts -Wno-sign-compare -Wno-uninitialized -Wno-unused-but-set-variable -Wno-unused-parameter -Wno-unused-variable     -I../src/serv_0/rtl   -c -o Vservant__ALLcls.o Vservant__ALLcls.cpp
g++  -I.  -MMD -I/usr/local/share/verilator/include -I/usr/local/share/verilator/include/vltstd -DVL_PRINTF=printf -DVM_COVERAGE=0 -DVM_SC=0 -DVM_TRACE=1 -Wno-char-subscripts -Wno-sign-compare -Wno-uninitialized -Wno-unused-but-set-variable -Wno-unused-parameter -Wno-unused-variable     -I../src/serv_0/rtl   -c -o Vservant__ALLsup.o Vservant__ALLsup.cpp
      Archiving Vservant__ALL.a ...
ar r Vservant__ALL.a Vservant__ALLcls.o Vservant__ALLsup.o
ar: creating Vservant__ALL.a
ranlib Vservant__ALL.a
g++    servant_tb.o verilated.o verilated_dpi.o verilated_vcd_c.o Vservant__ALL.a    -o Vservant -lm -lstdc++  2>&1 | c++filt
make[1]: Leaving directory '/home/fabien/myfpga/myserv/workspace/build/servant_0/verilator_tb-verilator'
Loading RAM from /home/fabien/myfpga/myserv/serv/sw/zephyr_hello.hex
***** Booting Zephyr OS zephyr-v1.13.0-3-ge4f24e2f54 *****
Hello World! riscv32

But I'm stuck in that «Hello World» since about 5 minutes

[olofk]

Excellent!

Yes, you need to break the Zephyr examples manually with CTRL-C since there is nothing in the software that tells the simulator that the program has completed.

[Martoni]

Thanks, I will continue my test on your processor now.