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

Debug test suite unexpected failures against SiFive HiFive1 board #1047

Closed
TommyMurphyTM1234 opened this issue Apr 20, 2024 · 47 comments
Closed

Comments

@TommyMurphyTM1234
Copy link
Collaborator

New issue created to split off from this PR discussion:

Running the debug test suite:

against the SiFive HiFive1 board results in all but one test failing.

::::::::::::::::::::::::::[ ran 73 tests in 3842s ]:::::::::::::::::::::::::::
17 tests returned not_applicable
1 tests returned pass
55 tests returned exception
   DebugBreakpoint > logs/20240420-105749-HiFive1-DebugBreakpoint.log
   DebugChangeString > logs/20240420-105845-HiFive1-DebugChangeString.log
   DebugCompareSections > logs/20240420-105955-HiFive1-DebugCompareSections.log
   DebugExit > logs/20240420-110105-HiFive1-DebugExit.log
   DebugFunctionCall > logs/20240420-110215-HiFive1-DebugFunctionCall.log
   DebugSymbols > logs/20240420-110325-HiFive1-DebugSymbols.log
   DebugTurbostep > logs/20240420-110435-HiFive1-DebugTurbostep.log
   DisconnectTest > logs/20240420-110546-HiFive1-DisconnectTest.log
   DownloadTest > logs/20240420-110656-HiFive1-DownloadTest.log
   EbreakTest > logs/20240420-110806-HiFive1-EbreakTest.log
   EtriggerTest > logs/20240420-110916-HiFive1-EtriggerTest.log
   Hwbp1 > logs/20240420-111026-HiFive1-Hwbp1.log
   Hwbp2 > logs/20240420-111136-HiFive1-Hwbp2.log
   HwbpManual > logs/20240420-111246-HiFive1-HwbpManual.log
   IcountTest > logs/20240420-111356-HiFive1-IcountTest.log
   InfoTest > logs/20240420-111506-HiFive1-InfoTest.log
   InstantChangePc > logs/20240420-111616-HiFive1-InstantChangePc.log
   InstantHaltTest > logs/20240420-111726-HiFive1-InstantHaltTest.log
   InterruptTest > logs/20240420-111836-HiFive1-InterruptTest.log
   ItriggerTest > logs/20240420-111947-HiFive1-ItriggerTest.log
   JumpHbreak > logs/20240420-112057-HiFive1-JumpHbreak.log
   MemTest16 > logs/20240420-112207-HiFive1-MemTest16.log
   MemTest32 > logs/20240420-112317-HiFive1-MemTest32.log
   MemTest64 > logs/20240420-112427-HiFive1-MemTest64.log
   MemTest8 > logs/20240420-112537-HiFive1-MemTest8.log
   MemTestBlock0 > logs/20240420-112647-HiFive1-MemTestBlock0.log
   MemTestBlock1 > logs/20240420-112757-HiFive1-MemTestBlock1.log
   MemTestBlock2 > logs/20240420-112907-HiFive1-MemTestBlock2.log
   MemTestReadInvalid > logs/20240420-113017-HiFive1-MemTestReadInvalid.log
   MemorySampleMixed > logs/20240420-113127-HiFive1-MemorySampleMixed.log
   MemorySampleSingle > logs/20240420-113237-HiFive1-MemorySampleSingle.log
   PrivChange > logs/20240420-113347-HiFive1-PrivChange.log
   PrivRw > logs/20240420-113458-HiFive1-PrivRw.log
   ProgramHwWatchpoint > logs/20240420-113608-HiFive1-ProgramHwWatchpoint.log
   ProgramSwWatchpoint > logs/20240420-113718-HiFive1-ProgramSwWatchpoint.log
   Registers > logs/20240420-113828-HiFive1-Registers.log
   RepeatReadTest > logs/20240420-113938-HiFive1-RepeatReadTest.log
   Semihosting > logs/20240420-114048-HiFive1-Semihosting.log
   SemihostingFileio > logs/20240420-114158-HiFive1-SemihostingFileio.log
   SimpleF18Test > logs/20240420-114308-HiFive1-SimpleF18Test.log
   SimpleNoExistTest > logs/20240420-114418-HiFive1-SimpleNoExistTest.log
   SimpleS0Test > logs/20240420-114528-HiFive1-SimpleS0Test.log
   SimpleS1Test > logs/20240420-114638-HiFive1-SimpleS1Test.log
   SimpleT0Test > logs/20240420-114748-HiFive1-SimpleT0Test.log
   SimpleT1Test > logs/20240420-114858-HiFive1-SimpleT1Test.log
   SimpleV13Test > logs/20240420-115008-HiFive1-SimpleV13Test.log
   StepTest > logs/20240420-115118-HiFive1-StepTest.log
   TooManyHwbp > logs/20240420-115229-HiFive1-TooManyHwbp.log
   TriggerDmode > logs/20240420-115339-HiFive1-TriggerDmode.log
   TriggerExecuteInstant > logs/20240420-115449-HiFive1-TriggerExecuteInstant.log
   TriggerLoadAddressInstant > logs/20240420-115559-HiFive1-TriggerLoadAddressInstant.log
   TriggerStoreAddressInstant > logs/20240420-115709-HiFive1-TriggerStoreAddressInstant.log
   UserInterrupt > logs/20240420-115819-HiFive1-UserInterrupt.log
   WriteCsrs > logs/20240420-115929-HiFive1-WriteCsrs.log
   WriteGprs > logs/20240420-120039-HiFive1-WriteGprs.log

This does not tally with what I believe are the expected results:

:::::::::::::::::::::::::::[ ran 71 tests in 419s ]:::::::::::::::::::::::::::
17 tests returned not_applicable
44 tests returned pass
5 tests returned fail
   EtriggerTest > logs/20230629-202119-HiFive1-EtriggerTest.log
   IcountTest > logs/20230629-202143-HiFive1-IcountTest.log
   InstantHaltTest > logs/20230629-202157-HiFive1-InstantHaltTest.log
   Semihosting > logs/20230629-202504-HiFive1-Semihosting.log
   SemihostingFileio > logs/20230629-202513-HiFive1-SemihostingFileio.log
5 tests returned exception
   ItriggerTest > logs/20230629-202218-HiFive1-ItriggerTest.log
   MemTestReadInvalid > logs/20230629-202337-HiFive1-MemTestReadInvalid.log
   MemorySampleMixed > logs/20230629-202347-HiFive1-MemorySampleMixed.log
   MemorySampleSingle > logs/20230629-202359-HiFive1-MemorySampleSingle.log
   RepeatReadTest > logs/20230629-202456-HiFive1-RepeatReadTest.log

(Ignore the minor discrepancy in the total number of tests in some of these transcripts as this is not of significance in this context).

Note also that the HiFive1 specific exclusion list can also be used to refine these results:

:::::::::::::::::::::::::::[ ran 72 tests in 234s ]:::::::::::::::::::::::::::
28 tests returned not_applicable
44 tests returned pass

I looked at the first unexpected failure on the DebugBreakpoint test. Reproducing it by manually running OpenOCD and GDB and feeding the relevant commands I see that if I do a GDB si single instruction step from _start then the program immediately goes off into the weeds at address 0x2040016c.

# GDB
...
pc             0x80000000	0x80000000 <_start>
(gdb) si
halted at 0x2040016c due to step
halted at 0x2040016c due to step
0x2040016c in ?? ()
(gdb) 

# OpenOCD
...
Info : accepting 'gdb' connection on tcp/0
Info : Retrying memory write starting from 0x80000000 with more delays
halted at 0x2040016c due to step
halted at 0x2040016c due to step
Info : Retrying memory read starting from 0x2040016c with more delays
Info : Retrying memory read starting from 0x2040016c with more delays
Info : Retrying memory read starting from 0x2040016c with more delays
Info : Retrying memory read starting from 0x2040016c with more delays
Info : Retrying memory read starting from 0x2040016c with more delays
Info : Retrying memory read starting from 0x2040016c with more delays
Info : Retrying memory read starting from 0x2040016c with more delays
Info : Retrying memory read starting from 0x2040016c with more delays
Info : Retrying memory read starting from 0x2040016c with more delays
Info : Retrying memory read starting from 0x2040016c with more delays
Info : Retrying memory read starting from 0x2040016c with more delays
Info : Retrying memory read starting from 0x2040016c with more delays
Info : Retrying memory read starting from 0x2040016c with more delays
Info : Retrying memory read starting from 0x2040016c with more delays
Info : Retrying memory read starting from 0x2040016c with more delays
Info : Retrying memory read starting from 0x2040016c with more delays
Info : Retrying memory read starting from 0x2040016c with more delays
Info : Retrying memory read starting from 0x2040016c with more delays
Warn : keep_alive() was not invoked in the 1000 ms timelimit. GDB alive packet not sent! (1031 ms). Workaround: increase "set remotetimeout" in GDB

However if I do monitor reset init early on in the debug session then this does not happen:

(gdb) monitor reset init
JTAG tap: riscv.cpu tap/device found: 0x10e31913 (mfg: 0x489 (SiFive Inc), part: 0x0e31, ver: 0x1)
riscv.cpu halted due to breakpoint.
halted at 0x80000000 due to software breakpoint
(gdb) file HiFive1_debug-40001105
A program is being debugged already.
Are you sure you want to change the file? (y or n) y
Load new symbol table from "HiFive1_debug-40001105"? (y or n) y
Reading symbols from HiFive1_debug-40001105...
(gdb) load
Loading section .text, size 0x8ca lma 0x80000000
Loading section .rodata, size 0x38 lma 0x800008d0
Loading section .data, size 0x16c lma 0x80000910
Loading section .sdata, size 0x4 lma 0x80000a7c
Start address 0x80000000, load size 2674
Transfer rate: 11 KB/sec, 668 bytes/write.
(gdb) compare-sections
Section .text, range 0x80000000 -- 0x800008ca: matched.
Section .rodata, range 0x800008d0 -- 0x80000908: matched.
Section .data, range 0x80000910 -- 0x80000a7c: matched.
Section .sdata, range 0x80000a7c -- 0x80000a80: matched.
(gdb) i r
ra             0x204002d4	0x204002d4
sp             0x80000158	0x80000158 <precease+4>
gp             0x8000096c	0x8000096c
tp             0x0	0x0
t0             0x80000370	-2147482768
t1             0x80000370	-2147482768
t2             0x204000b4	541065396
fp             0x4000f067	0x4000f067
s1             0x0	0
a0             0x200c000	33603584
a1             0x0	0
a2             0x4032	16434
a3             0x0	0
a4             0x4032	16434
a5             0x20400000	541065216
a6             0x200c000	33603584
a7             0x7fffef7b	2147479419
s2             0x0	0
s3             0x0	0
s4             0x0	0
s5             0x0	0
s6             0x0	0
s7             0x0	0
s8             0x0	0
s9             0x0	0
s10            0x0	0
s11            0x0	0
t3             0x0	0
t4             0x0	0
t5             0x0	0
t6             0x0	0
pc             0x80000000	0x80000000 <_start>
(gdb) si
halted at 0x80000006 due to step
halted at 0x80000006 due to step
handle_reset () at programs/entry.S:29
29	  la t0, 3f
(gdb) si
halted at 0x8000000a due to step
halted at 0x8000000a due to step
0x8000000a	29	  la t0, 3f
(gdb) b main
Breakpoint 1 at 0x800002e2: file programs/debug.c, line 52.
(gdb) c
Continuing.
Breakpoint 1, main () at programs/debug.c:52
52	    __malloc_freelist = 0;
(gdb) list
47	
48	extern void *__malloc_freelist;
49	
50	int main()
51	{
52	    __malloc_freelist = 0;
53	
54	    volatile int i = 0;
55	    int j = 0;
56	    char *fox = "The quick brown fox jumps of the lazy dog.";
(gdb) 

Admittedly this is only on of the many unexpected failure cases.
However it may suggest that some sort of reset at the start of this (and other?) test(s) may be required?
But why did the test suite run OK before but not now?
Have changes to OpenOCD in the meantime caused some problem that results in almost all tests failing?
Why is the reset command commented out here?

Uncommenting it doesn't really help though - other than making the test fail more quickly.

@aap-sc
Copy link
Collaborator

aap-sc commented Apr 21, 2024

@TommyMurphyTM1234 I don't have SiFive HiFive1 but maybe we can debug this... It may take few experiments.

But why did the test suite run OK before but not now?

I suggest we start investigating with answering this question. In #869 @JanMatCodasip established a baseline against:

riscv-openocd commit: e0dd44a
riscv-tests commit: 7b52ba3b7167acb4d8b38f4d4633112b4699cb26

Could you take riscv-openocd from e0dd44a (mentioned above) and run testsuite against current riscv-tests TOT . I want to make sure that there were no incompatible changes in riscv-tests repository first.

Also, could you please attach the logs you have when you get "all but one test failing" is failing. Maybe I can try and figure out the reason from the logs alone?

@aap-sc
Copy link
Collaborator

aap-sc commented Apr 21, 2024

Could you take riscv-openocd from e0dd44a (mentioned above) and run testsuite against current riscv-tests TOT

Just for the reference. I've just tested e0dd44a against riscv-tests TOT on spike and it works. We need to figure out what is the situation against "SiFive HiFive1" platform

@TommyMurphyTM1234
Copy link
Collaborator Author

TommyMurphyTM1234 commented Apr 21, 2024

@TommyMurphyTM1234 I don't have SiFive HiFive1 but maybe we can debug this... It may take few experiments.

But why did the test suite run OK before but not now?

I suggest we start investigating with answering this question. In #869 @JanMatCodasip established a baseline against:

riscv-openocd commit: e0dd44a riscv-tests commit: 7b52ba3b7167acb4d8b38f4d4633112b4699cb26

Could you take riscv-openocd from e0dd44a (mentioned above) and run testsuite against current riscv-tests TOT . I want to make sure that there were no incompatible changes in riscv-tests repository first.

Thanks for the suggestions @aap-sc.

I built OpenOCD from e0dd44a:

openocd -v
Open On-Chip Debugger 0.12.0+dev-02921-ge0dd44a53-dirty (2024-04-21-17:20)
Licensed under GNU GPL v2
For bug reports, read
	http://openocd.org/doc/doxygen/bugs.html

and used the top of the tree RISC-V test suite and that gave the expected results:

./gdbserver.py targets/SiFive/HiFive1.py

...

:::::::::::::::::::::::::::[ ran 73 tests in 436s ]:::::::::::::::::::::::::::
19 tests returned not_applicable
44 tests returned pass
5 tests returned fail
   EtriggerTest > logs/20240421-172705-HiFive1-EtriggerTest.log
   IcountTest > logs/20240421-172733-HiFive1-IcountTest.log
   InstantHaltTest > logs/20240421-172749-HiFive1-InstantHaltTest.log
   Semihosting > logs/20240421-173058-HiFive1-Semihosting.log
   SemihostingFileio > logs/20240421-173107-HiFive1-SemihostingFileio.log
5 tests returned exception
   ItriggerTest > logs/20240421-172811-HiFive1-ItriggerTest.log
   MemTestReadInvalid > logs/20240421-172932-HiFive1-MemTestReadInvalid.log
   MemorySampleMixed > logs/20240421-172942-HiFive1-MemorySampleMixed.log
   MemorySampleSingle > logs/20240421-172955-HiFive1-MemorySampleSingle.log
   RepeatReadTest > logs/20240421-173049-HiFive1-RepeatReadTest.log

./gdbserver.py targets/SiFive/HiFive1-flash.py

...

:::::::::::::::::::::::::::[ ran 73 tests in 806s ]:::::::::::::::::::::::::::
19 tests returned not_applicable
36 tests returned pass
14 tests returned exception
   DebugBreakpoint > logs/20240421-174635-HiFive1Flash-DebugBreakpoint.log
   DebugExit > logs/20240421-174735-HiFive1Flash-DebugExit.log
   DebugFunctionCall > logs/20240421-174823-HiFive1Flash-DebugFunctionCall.log
   EtriggerTest > logs/20240421-174952-HiFive1Flash-EtriggerTest.log
   Hwbp1 > logs/20240421-175001-HiFive1Flash-Hwbp1.log
   Hwbp2 > logs/20240421-175049-HiFive1Flash-Hwbp2.log
   ItriggerTest > logs/20240421-175224-HiFive1Flash-ItriggerTest.log
   MemTestReadInvalid > logs/20240421-175346-HiFive1Flash-MemTestReadInvalid.log
   MemorySampleMixed > logs/20240421-175355-HiFive1Flash-MemorySampleMixed.log
   MemorySampleSingle > logs/20240421-175409-HiFive1Flash-MemorySampleSingle.log
   Registers > logs/20240421-175458-HiFive1Flash-Registers.log
   RepeatReadTest > logs/20240421-175547-HiFive1Flash-RepeatReadTest.log
   TooManyHwbp > logs/20240421-175719-HiFive1Flash-TooManyHwbp.log
   UserInterrupt > logs/20240421-175845-HiFive1Flash-UserInterrupt.log
4 tests returned fail
   IcountTest > logs/20240421-175144-HiFive1Flash-IcountTest.log
   InstantHaltTest > logs/20240421-175201-HiFive1Flash-InstantHaltTest.log
   Semihosting > logs/20240421-175555-HiFive1Flash-Semihosting.log
   SemihostingFileio > logs/20240421-175604-HiFive1Flash-SemihostingFileio.log

In case they're needed I've attached the zipped logs for these tests: logs.zip

Note that I did not use hifive1_excludes.yaml to exclude the fail/exception cases so those are expected at the moment but I have an outstanding task to see if any of them can be "fixed" so that they pass:

@TommyMurphyTM1234
Copy link
Collaborator Author

Also, could you please attach the logs you have when you get "all but one test failing" is failing. Maybe I can try and figure out the reason from the logs alone?

Sorry - I should have posted the logs in the first place.

Just to clarify, this is using OpenOCD built from the top of the tree:

openocd -v
Open On-Chip Debugger 0.12.0+dev-03744-g3991492cc-dirty (2024-04-21-18:06)
Licensed under GNU GPL v2
For bug reports, read
	http://openocd.org/doc/doxygen/bugs.html

plus this fix for the 0.11 segfault:

And the RISC-V tests from the top of the tree.

Here are the results that I get:

./gdbserver.py targets/SiFive/HiFive1.py

...

:::::::::::::::::::::::::::[ ran 73 tests in 83s ]::::::::::::::::::::::::::::
17 tests returned not_applicable
1 tests returned pass
55 tests returned exception
   DebugBreakpoint > logs/20240421-181109-HiFive1-DebugBreakpoint.log
   DebugChangeString > logs/20240421-181157-HiFive1-DebugChangeString.log
   DebugCompareSections > logs/20240421-181157-HiFive1-DebugCompareSections.log
   DebugExit > logs/20240421-181158-HiFive1-DebugExit.log
   DebugFunctionCall > logs/20240421-181158-HiFive1-DebugFunctionCall.log
   DebugSymbols > logs/20240421-181159-HiFive1-DebugSymbols.log
   DebugTurbostep > logs/20240421-181159-HiFive1-DebugTurbostep.log
   DisconnectTest > logs/20240421-181200-HiFive1-DisconnectTest.log
   DownloadTest > logs/20240421-181201-HiFive1-DownloadTest.log
   EbreakTest > logs/20240421-181202-HiFive1-EbreakTest.log
   EtriggerTest > logs/20240421-181202-HiFive1-EtriggerTest.log
   Hwbp1 > logs/20240421-181203-HiFive1-Hwbp1.log
   Hwbp2 > logs/20240421-181203-HiFive1-Hwbp2.log
   HwbpManual > logs/20240421-181204-HiFive1-HwbpManual.log
   IcountTest > logs/20240421-181204-HiFive1-IcountTest.log
   InfoTest > logs/20240421-181205-HiFive1-InfoTest.log
   InstantChangePc > logs/20240421-181206-HiFive1-InstantChangePc.log
   InstantHaltTest > logs/20240421-181206-HiFive1-InstantHaltTest.log
   InterruptTest > logs/20240421-181207-HiFive1-InterruptTest.log
   ItriggerTest > logs/20240421-181207-HiFive1-ItriggerTest.log
   JumpHbreak > logs/20240421-181208-HiFive1-JumpHbreak.log
   MemTest16 > logs/20240421-181209-HiFive1-MemTest16.log
   MemTest32 > logs/20240421-181209-HiFive1-MemTest32.log
   MemTest64 > logs/20240421-181210-HiFive1-MemTest64.log
   MemTest8 > logs/20240421-181210-HiFive1-MemTest8.log
   MemTestBlock0 > logs/20240421-181211-HiFive1-MemTestBlock0.log
   MemTestBlock1 > logs/20240421-181212-HiFive1-MemTestBlock1.log
   MemTestBlock2 > logs/20240421-181212-HiFive1-MemTestBlock2.log
   MemTestReadInvalid > logs/20240421-181213-HiFive1-MemTestReadInvalid.log
   MemorySampleMixed > logs/20240421-181213-HiFive1-MemorySampleMixed.log
   MemorySampleSingle > logs/20240421-181214-HiFive1-MemorySampleSingle.log
   PrivChange > logs/20240421-181215-HiFive1-PrivChange.log
   PrivRw > logs/20240421-181215-HiFive1-PrivRw.log
   ProgramHwWatchpoint > logs/20240421-181216-HiFive1-ProgramHwWatchpoint.log
   ProgramSwWatchpoint > logs/20240421-181217-HiFive1-ProgramSwWatchpoint.log
   Registers > logs/20240421-181217-HiFive1-Registers.log
   RepeatReadTest > logs/20240421-181218-HiFive1-RepeatReadTest.log
   Semihosting > logs/20240421-181219-HiFive1-Semihosting.log
   SemihostingFileio > logs/20240421-181219-HiFive1-SemihostingFileio.log
   SimpleF18Test > logs/20240421-181220-HiFive1-SimpleF18Test.log
   SimpleNoExistTest > logs/20240421-181221-HiFive1-SimpleNoExistTest.log
   SimpleS0Test > logs/20240421-181221-HiFive1-SimpleS0Test.log
   SimpleS1Test > logs/20240421-181222-HiFive1-SimpleS1Test.log
   SimpleT0Test > logs/20240421-181222-HiFive1-SimpleT0Test.log
   SimpleT1Test > logs/20240421-181223-HiFive1-SimpleT1Test.log
   SimpleV13Test > logs/20240421-181224-HiFive1-SimpleV13Test.log
   StepTest > logs/20240421-181224-HiFive1-StepTest.log
   TooManyHwbp > logs/20240421-181225-HiFive1-TooManyHwbp.log
   TriggerDmode > logs/20240421-181226-HiFive1-TriggerDmode.log
   TriggerExecuteInstant > logs/20240421-181226-HiFive1-TriggerExecuteInstant.log
   TriggerLoadAddressInstant > logs/20240421-181227-HiFive1-TriggerLoadAddressInstant.log
   TriggerStoreAddressInstant > logs/20240421-181227-HiFive1-TriggerStoreAddressInstant.log
   UserInterrupt > logs/20240421-181228-HiFive1-UserInterrupt.log
   WriteCsrs > logs/20240421-181229-HiFive1-WriteCsrs.log
   WriteGprs > logs/20240421-181229-HiFive1-WriteGprs.log

./gdbserver.py targets/SiFive/HiFive1-flash.py

...

:::::::::::::::::::::::::::[ ran 73 tests in 36s ]::::::::::::::::::::::::::::
17 tests returned not_applicable
56 tests returned exception
   CheckMisa > logs/20240421-181632-HiFive1Flash-CheckMisa.log
   DebugBreakpoint > logs/20240421-181632-HiFive1Flash-DebugBreakpoint.log
   DebugChangeString > logs/20240421-181633-HiFive1Flash-DebugChangeString.log
   DebugCompareSections > logs/20240421-181634-HiFive1Flash-DebugCompareSections.log
   DebugExit > logs/20240421-181634-HiFive1Flash-DebugExit.log
   DebugFunctionCall > logs/20240421-181635-HiFive1Flash-DebugFunctionCall.log
   DebugSymbols > logs/20240421-181636-HiFive1Flash-DebugSymbols.log
   DebugTurbostep > logs/20240421-181636-HiFive1Flash-DebugTurbostep.log
   DisconnectTest > logs/20240421-181637-HiFive1Flash-DisconnectTest.log
   DownloadTest > logs/20240421-181637-HiFive1Flash-DownloadTest.log
   EbreakTest > logs/20240421-181638-HiFive1Flash-EbreakTest.log
   EtriggerTest > logs/20240421-181639-HiFive1Flash-EtriggerTest.log
   Hwbp1 > logs/20240421-181639-HiFive1Flash-Hwbp1.log
   Hwbp2 > logs/20240421-181640-HiFive1Flash-Hwbp2.log
   HwbpManual > logs/20240421-181640-HiFive1Flash-HwbpManual.log
   IcountTest > logs/20240421-181641-HiFive1Flash-IcountTest.log
   InfoTest > logs/20240421-181642-HiFive1Flash-InfoTest.log
   InstantChangePc > logs/20240421-181642-HiFive1Flash-InstantChangePc.log
   InstantHaltTest > logs/20240421-181643-HiFive1Flash-InstantHaltTest.log
   InterruptTest > logs/20240421-181643-HiFive1Flash-InterruptTest.log
   ItriggerTest > logs/20240421-181644-HiFive1Flash-ItriggerTest.log
   JumpHbreak > logs/20240421-181645-HiFive1Flash-JumpHbreak.log
   MemTest16 > logs/20240421-181646-HiFive1Flash-MemTest16.log
   MemTest32 > logs/20240421-181646-HiFive1Flash-MemTest32.log
   MemTest64 > logs/20240421-181647-HiFive1Flash-MemTest64.log
   MemTest8 > logs/20240421-181648-HiFive1Flash-MemTest8.log
   MemTestBlock0 > logs/20240421-181648-HiFive1Flash-MemTestBlock0.log
   MemTestBlock1 > logs/20240421-181649-HiFive1Flash-MemTestBlock1.log
   MemTestBlock2 > logs/20240421-181650-HiFive1Flash-MemTestBlock2.log
   MemTestReadInvalid > logs/20240421-181650-HiFive1Flash-MemTestReadInvalid.log
   MemorySampleMixed > logs/20240421-181651-HiFive1Flash-MemorySampleMixed.log
   MemorySampleSingle > logs/20240421-181651-HiFive1Flash-MemorySampleSingle.log
   PrivChange > logs/20240421-181652-HiFive1Flash-PrivChange.log
   PrivRw > logs/20240421-181653-HiFive1Flash-PrivRw.log
   ProgramHwWatchpoint > logs/20240421-181654-HiFive1Flash-ProgramHwWatchpoint.log
   ProgramSwWatchpoint > logs/20240421-181654-HiFive1Flash-ProgramSwWatchpoint.log
   Registers > logs/20240421-181655-HiFive1Flash-Registers.log
   RepeatReadTest > logs/20240421-181656-HiFive1Flash-RepeatReadTest.log
   Semihosting > logs/20240421-181656-HiFive1Flash-Semihosting.log
   SemihostingFileio > logs/20240421-181657-HiFive1Flash-SemihostingFileio.log
   SimpleF18Test > logs/20240421-181658-HiFive1Flash-SimpleF18Test.log
   SimpleNoExistTest > logs/20240421-181658-HiFive1Flash-SimpleNoExistTest.log
   SimpleS0Test > logs/20240421-181659-HiFive1Flash-SimpleS0Test.log
   SimpleS1Test > logs/20240421-181700-HiFive1Flash-SimpleS1Test.log
   SimpleT0Test > logs/20240421-181700-HiFive1Flash-SimpleT0Test.log
   SimpleT1Test > logs/20240421-181701-HiFive1Flash-SimpleT1Test.log
   SimpleV13Test > logs/20240421-181701-HiFive1Flash-SimpleV13Test.log
   StepTest > logs/20240421-181702-HiFive1Flash-StepTest.log
   TooManyHwbp > logs/20240421-181703-HiFive1Flash-TooManyHwbp.log
   TriggerDmode > logs/20240421-181703-HiFive1Flash-TriggerDmode.log
   TriggerExecuteInstant > logs/20240421-181704-HiFive1Flash-TriggerExecuteInstant.log
   TriggerLoadAddressInstant > logs/20240421-181705-HiFive1Flash-TriggerLoadAddressInstant.log
   TriggerStoreAddressInstant > logs/20240421-181705-HiFive1Flash-TriggerStoreAddressInstant.log
   UserInterrupt > logs/20240421-181706-HiFive1Flash-UserInterrupt.log
   WriteCsrs > logs/20240421-181707-HiFive1Flash-WriteCsrs.log
   WriteGprs > logs/20240421-181707-HiFive1Flash-WriteGprs.log

And here are the zipped logs for these tests: logs.zip

If you need any further information or tests run let me know.

@aap-sc
Copy link
Collaborator

aap-sc commented Apr 21, 2024

@TommyMurphyTM1234 I've glanced at the logs. Looks like there is a common issue with these tests:

Info : [riscv.cpu] Examination succeed
Info : starting gdb server for riscv.cpu on 0
Info : Listening on port 44799 for gdb connections
Error: timeout
Error: auto_probe failed

I don't see this error in your previous logs.

I'd like to request few adjustments to how you run tests:

  1. Could you please adjust command line as described in Random/sporadic failures running test suite interactively against Spike #1049. Namely, please add the following arguments:
--isolate
--remotelogfile-enable
--server_cmd "<openocd_path> -d3"

I don't remember what --isolate does :). But this is what I use. --server_cmd is needed to include -d3 option.

  1. Now, with the command line adjusted, let's try an older OpenOCD version (but newer than the one that works). Let's start with b7e7a03 (it's around Febrary 9, 2024). Could you please re-run tests on that version?

@aap-sc
Copy link
Collaborator

aap-sc commented Apr 21, 2024

let's try an older OpenOCD version (but newer than the one that works)

So basically I suggest to do a kind of bisection (with few "educated guesses" as a bisection steps, instead of a proper bisection). Just with -d3 logs enabled. Usually this level of logging is enough to figure out what is wrong.

@TommyMurphyTM1234
Copy link
Collaborator Author

@TommyMurphyTM1234 I've glanced at the logs. Looks like there is a common issue with these tests:

Info : [riscv.cpu] Examination succeed
Info : starting gdb server for riscv.cpu on 0
Info : Listening on port 44799 for gdb connections
Error: timeout
Error: auto_probe failed

I don't see this error in your previous logs.

I'd like to request few adjustments to how you run tests:

  1. Could you please adjust command line as described in Random/sporadic failures running test suite interactively against Spike #1049. Namely, please add the following arguments:
--isolate
--remotelogfile-enable
--server_cmd "<openocd_path> -d3"

I don't remember what --isolate does :). But this is what I use. --server_cmd is needed to include -d3 option.

  1. Now, with the command line adjusted, let's try an older OpenOCD version (but newer than the one that works). Let's start with b7e7a03 (it's around Febrary 9, 2024). Could you please re-run tests on that version?
    With that setup no tests at all pass...
openocd -v
Open On-Chip Debugger 0.12.0+dev-03670-gb7e7a030c-dirty (2024-04-21-19:08)
Licensed under GNU GPL v2
For bug reports, read
	http://openocd.org/doc/doxygen/bugs.html

./gdbserver.py targets/SiFive/HiFive1.py --isolate --remotelogfile-enable --server_cmd "openocd -d3"

...

::::::::::::::::::::::::::[ ran 73 tests in 3415s ]:::::::::::::::::::::::::::
17 tests returned not_applicable
56 tests returned exception
   CheckMisa > logs/20240421-193239-HiFive1-CheckMisa.log
   DebugBreakpoint > logs/20240421-193240-HiFive1-DebugBreakpoint.log
   DebugChangeString > logs/20240421-193327-HiFive1-DebugChangeString.log
   DebugCompareSections > logs/20240421-193427-HiFive1-DebugCompareSections.log
   DebugExit > logs/20240421-193537-HiFive1-DebugExit.log
   DebugFunctionCall > logs/20240421-193638-HiFive1-DebugFunctionCall.log
   DebugSymbols > logs/20240421-193738-HiFive1-DebugSymbols.log
   DebugTurbostep > logs/20240421-193848-HiFive1-DebugTurbostep.log
   DisconnectTest > logs/20240421-193948-HiFive1-DisconnectTest.log
   DownloadTest > logs/20240421-194058-HiFive1-DownloadTest.log
   EbreakTest > logs/20240421-194158-HiFive1-EbreakTest.log
   EtriggerTest > logs/20240421-194258-HiFive1-EtriggerTest.log
   Hwbp1 > logs/20240421-194359-HiFive1-Hwbp1.log
   Hwbp2 > logs/20240421-194459-HiFive1-Hwbp2.log
   HwbpManual > logs/20240421-194559-HiFive1-HwbpManual.log
   IcountTest > logs/20240421-194709-HiFive1-IcountTest.log
   InfoTest > logs/20240421-194809-HiFive1-InfoTest.log
   InstantChangePc > logs/20240421-194909-HiFive1-InstantChangePc.log
   InstantHaltTest > logs/20240421-195009-HiFive1-InstantHaltTest.log
   InterruptTest > logs/20240421-195119-HiFive1-InterruptTest.log
   ItriggerTest > logs/20240421-195219-HiFive1-ItriggerTest.log
   JumpHbreak > logs/20240421-195319-HiFive1-JumpHbreak.log
   MemTest16 > logs/20240421-195420-HiFive1-MemTest16.log
   MemTest32 > logs/20240421-195520-HiFive1-MemTest32.log
   MemTest64 > logs/20240421-195620-HiFive1-MemTest64.log
   MemTest8 > logs/20240421-195730-HiFive1-MemTest8.log
   MemTestBlock0 > logs/20240421-195830-HiFive1-MemTestBlock0.log
   MemTestBlock1 > logs/20240421-195930-HiFive1-MemTestBlock1.log
   MemTestBlock2 > logs/20240421-200030-HiFive1-MemTestBlock2.log
   MemTestReadInvalid > logs/20240421-200130-HiFive1-MemTestReadInvalid.log
   MemorySampleMixed > logs/20240421-200230-HiFive1-MemorySampleMixed.log
   MemorySampleSingle > logs/20240421-200331-HiFive1-MemorySampleSingle.log
   PrivChange > logs/20240421-200431-HiFive1-PrivChange.log
   PrivRw > logs/20240421-200531-HiFive1-PrivRw.log
   ProgramHwWatchpoint > logs/20240421-200631-HiFive1-ProgramHwWatchpoint.log
   ProgramSwWatchpoint > logs/20240421-200741-HiFive1-ProgramSwWatchpoint.log
   Registers > logs/20240421-200841-HiFive1-Registers.log
   RepeatReadTest > logs/20240421-200941-HiFive1-RepeatReadTest.log
   Semihosting > logs/20240421-201041-HiFive1-Semihosting.log
   SemihostingFileio > logs/20240421-201142-HiFive1-SemihostingFileio.log
   SimpleF18Test > logs/20240421-201242-HiFive1-SimpleF18Test.log
   SimpleNoExistTest > logs/20240421-201352-HiFive1-SimpleNoExistTest.log
   SimpleS0Test > logs/20240421-201452-HiFive1-SimpleS0Test.log
   SimpleS1Test > logs/20240421-201552-HiFive1-SimpleS1Test.log
   SimpleT0Test > logs/20240421-201652-HiFive1-SimpleT0Test.log
   SimpleT1Test > logs/20240421-201752-HiFive1-SimpleT1Test.log
   SimpleV13Test > logs/20240421-201852-HiFive1-SimpleV13Test.log
   StepTest > logs/20240421-201952-HiFive1-StepTest.log
   TooManyHwbp > logs/20240421-202053-HiFive1-TooManyHwbp.log
   TriggerDmode > logs/20240421-202153-HiFive1-TriggerDmode.log
   TriggerExecuteInstant > logs/20240421-202253-HiFive1-TriggerExecuteInstant.log
   TriggerLoadAddressInstant > logs/20240421-202403-HiFive1-TriggerLoadAddressInstant.log
   TriggerStoreAddressInstant > logs/20240421-202513-HiFive1-TriggerStoreAddressInstant.log
   UserInterrupt > logs/20240421-202623-HiFive1-UserInterrupt.log
   WriteCsrs > logs/20240421-202733-HiFive1-WriteCsrs.log
   WriteGprs > logs/20240421-202833-HiFive1-WriteGprs.log

Notes:

  1. I didn't bother with the HiFive1-flash.py tests this time.
  2. Not even one test passes here.
  3. Here are the zipped logs: logs.zip

@aap-sc
Copy link
Collaborator

aap-sc commented Apr 21, 2024

@TommyMurphyTM1234 good, this is something. And if you don't mind could you run the tests with the same command line option (with -d3) agains the baseline (openocd e0dd44a , riscv-tests TOT). I want to make sure that -d3 does not affect the run.

@TommyMurphyTM1234
Copy link
Collaborator Author

TommyMurphyTM1234 commented Apr 21, 2024

@TommyMurphyTM1234 good, this is something. And if you don't mind could you run the tests with the same command line option (with -d3) agains the baseline (openocd e0dd44a , riscv-tests TOT). I want to make sure that -d3 does not affect the run.

openocd -v
Open On-Chip Debugger 0.12.0+dev-02921-ge0dd44a53-dirty (2024-04-21-21:38)
Licensed under GNU GPL v2
For bug reports, read
	http://openocd.org/doc/doxygen/bugs.html

./gdbserver.py targets/SiFive/HiFive1.py --isolate --remotelogfile-enable --server_cmd "openocd -d3"

...

:::::::::::::::::::::::::::[ ran 73 tests in 477s ]:::::::::::::::::::::::::::
19 tests returned not_applicable
6 tests returned exception
   CheckMisa > logs/20240421-214206-HiFive1-CheckMisa.log
   ItriggerTest > logs/20240421-214423-HiFive1-ItriggerTest.log
   MemTestReadInvalid > logs/20240421-214551-HiFive1-MemTestReadInvalid.log
   MemorySampleMixed > logs/20240421-214601-HiFive1-MemorySampleMixed.log
   MemorySampleSingle > logs/20240421-214616-HiFive1-MemorySampleSingle.log
   RepeatReadTest > logs/20240421-214719-HiFive1-RepeatReadTest.log
43 tests returned pass
5 tests returned fail
   EtriggerTest > logs/20240421-214313-HiFive1-EtriggerTest.log
   IcountTest > logs/20240421-214343-HiFive1-IcountTest.log
   InstantHaltTest > logs/20240421-214401-HiFive1-InstantHaltTest.log
   Semihosting > logs/20240421-214727-HiFive1-Semihosting.log
   SemihostingFileio > logs/20240421-214738-HiFive1-SemihostingFileio.log

Zipped logs: logs.zip

@MarekVCodasip
Copy link
Collaborator

MarekVCodasip commented Apr 22, 2024

Me and @JanMatCodasip have access to HiFive1 A01 board as well. I ran the current riscv-openocd master (3991492) EDIT: wrong branch, disregard, and riscv-tests master (6b1d7372d951ed75811e0a09c0fe9e065c141c2d) and got this result:

:::::::::::::::::::::::::::[ ran 73 tests in 227s ]:::::::::::::::::::::::::::
19 tests returned not_applicable
42 tests returned pass
9 tests returned fail
   EtriggerTest > logs/20240422-100315-HiFive1-EtriggerTest.log
   InstantHaltTest > logs/20240422-100412-HiFive1-InstantHaltTest.log
   InterruptTest > logs/20240422-100414-HiFive1-InterruptTest.log
   ItriggerTest > logs/20240422-100441-HiFive1-ItriggerTest.log
   MemorySampleMixed > logs/20240422-100501-HiFive1-MemorySampleMixed.log
   MemorySampleSingle > logs/20240422-100509-HiFive1-MemorySampleSingle.log
   Semihosting > logs/20240422-100535-HiFive1-Semihosting.log
   SemihostingFileio > logs/20240422-100538-HiFive1-SemihostingFileio.log
   StepTest > logs/20240422-100556-HiFive1-StepTest.log
3 tests returned exception
   IcountTest > logs/20240422-100327-HiFive1-IcountTest.log
   MemTestReadInvalid > logs/20240422-100459-HiFive1-MemTestReadInvalid.log
   RepeatReadTest > logs/20240422-100533-HiFive1-RepeatReadTest.log

With accompanying logs:
logs.zip

For completeness, I am running GCC (and GDB) version 12.2.0-3 (xpack)

@TommyMurphyTM1234
Copy link
Collaborator Author

TommyMurphyTM1234 commented Apr 22, 2024

Thanks @MarekVCodasip.

Me and @JanMatCodasip have access to HiFive1 A01 board as well. I ran the current riscv-openocd master (3991492), and riscv-tests master (6b1d7372d951ed75811e0a09c0fe9e065c141c2d) and got this result:

I'm confused - how come you didn't hit this segfault:

necessitating the manual integration of the patch to fix it?

:::::::::::::::::::::::::::[ ran 73 tests in 227s ]:::::::::::::::::::::::::::
19 tests returned not_applicable
42 tests returned pass
9 tests returned fail
   EtriggerTest > logs/20240422-100315-HiFive1-EtriggerTest.log
   InstantHaltTest > logs/20240422-100412-HiFive1-InstantHaltTest.log
   InterruptTest > logs/20240422-100414-HiFive1-InterruptTest.log
   ItriggerTest > logs/20240422-100441-HiFive1-ItriggerTest.log
   MemorySampleMixed > logs/20240422-100501-HiFive1-MemorySampleMixed.log
   MemorySampleSingle > logs/20240422-100509-HiFive1-MemorySampleSingle.log
   Semihosting > logs/20240422-100535-HiFive1-Semihosting.log
   SemihostingFileio > logs/20240422-100538-HiFive1-SemihostingFileio.log
   StepTest > logs/20240422-100556-HiFive1-StepTest.log
3 tests returned exception
   IcountTest > logs/20240422-100327-HiFive1-IcountTest.log
   MemTestReadInvalid > logs/20240422-100459-HiFive1-MemTestReadInvalid.log
   RepeatReadTest > logs/20240422-100533-HiFive1-RepeatReadTest.log

At a glance these results look correct given that the fail/exception tests would presumably be masked if hifive1_excludes.yaml was used:

./gdbserver.py targets/SiFive/HiFive1.py --exclude-tests hifive1_excludes.yaml

What do you get for the Flash tests?

./gdbserver.py targets/SiFive/HiFive1-flash.py [--exclude-tests hifive1_excludes.yaml]

I wonder if some of my issues arise from the use of a virtual machine and maybe I should try on a physical machine instead?

@MarekVCodasip
Copy link
Collaborator

MarekVCodasip commented Apr 22, 2024

I'm confused - how come you didn't hit this segfault necessitating the manual integration of the patch to fix it?

No idea. Could be that the undefined behavior manifests differently.

What do you get for the Flash tests?

:::::::::::::::::::::::::::[ ran 73 tests in 358s ]:::::::::::::::::::::::::::
18 tests returned not_applicable
9 tests returned pass
44 tests returned exception
   DebugBreakpoint > logs/20240422-102102-HiFive1Flash-DebugBreakpoint.log
   DebugExit > logs/20240422-102111-HiFive1Flash-DebugExit.log
   DebugFunctionCall > logs/20240422-102153-HiFive1Flash-DebugFunctionCall.log
   DebugTurbostep > logs/20240422-102240-HiFive1Flash-DebugTurbostep.log
   EtriggerTest > logs/20240422-102252-HiFive1Flash-EtriggerTest.log
   Hwbp1 > logs/20240422-102255-HiFive1Flash-Hwbp1.log
   Hwbp2 > logs/20240422-102258-HiFive1Flash-Hwbp2.log
   InterruptTest > logs/20240422-102312-HiFive1Flash-InterruptTest.log
   ItriggerTest > logs/20240422-102324-HiFive1Flash-ItriggerTest.log
   JumpHbreak > logs/20240422-102330-HiFive1Flash-JumpHbreak.log
   MemTest16 > logs/20240422-102336-HiFive1Flash-MemTest16.log
   MemTest32 > logs/20240422-102342-HiFive1Flash-MemTest32.log
   MemTest64 > logs/20240422-102348-HiFive1Flash-MemTest64.log
   MemTest8 > logs/20240422-102354-HiFive1Flash-MemTest8.log
   MemTestBlock0 > logs/20240422-102400-HiFive1Flash-MemTestBlock0.log
   MemTestBlock1 > logs/20240422-102406-HiFive1Flash-MemTestBlock1.log
   MemTestBlock2 > logs/20240422-102412-HiFive1Flash-MemTestBlock2.log
   MemTestReadInvalid > logs/20240422-102418-HiFive1Flash-MemTestReadInvalid.log
   MemorySampleMixed > logs/20240422-102424-HiFive1Flash-MemorySampleMixed.log
   MemorySampleSingle > logs/20240422-102430-HiFive1Flash-MemorySampleSingle.log
   PrivChange > logs/20240422-102436-HiFive1Flash-PrivChange.log
   PrivRw > logs/20240422-102442-HiFive1Flash-PrivRw.log
   ProgramHwWatchpoint > logs/20240422-102448-HiFive1Flash-ProgramHwWatchpoint.log
   ProgramSwWatchpoint > logs/20240422-102454-HiFive1Flash-ProgramSwWatchpoint.log
   Registers > logs/20240422-102500-HiFive1Flash-Registers.log
   RepeatReadTest > logs/20240422-102506-HiFive1Flash-RepeatReadTest.log
   Semihosting > logs/20240422-102512-HiFive1Flash-Semihosting.log
   SemihostingFileio > logs/20240422-102518-HiFive1Flash-SemihostingFileio.log
   SimpleF18Test > logs/20240422-102524-HiFive1Flash-SimpleF18Test.log
   SimpleNoExistTest > logs/20240422-102530-HiFive1Flash-SimpleNoExistTest.log
   SimpleS0Test > logs/20240422-102536-HiFive1Flash-SimpleS0Test.log
   SimpleS1Test > logs/20240422-102542-HiFive1Flash-SimpleS1Test.log
   SimpleT0Test > logs/20240422-102548-HiFive1Flash-SimpleT0Test.log
   SimpleT1Test > logs/20240422-102554-HiFive1Flash-SimpleT1Test.log
   SimpleV13Test > logs/20240422-102600-HiFive1Flash-SimpleV13Test.log
   StepTest > logs/20240422-102606-HiFive1Flash-StepTest.log
   TooManyHwbp > logs/20240422-102612-HiFive1Flash-TooManyHwbp.log
   TriggerDmode > logs/20240422-102618-HiFive1Flash-TriggerDmode.log
   TriggerExecuteInstant > logs/20240422-102624-HiFive1Flash-TriggerExecuteInstant.log
   TriggerLoadAddressInstant > logs/20240422-102630-HiFive1Flash-TriggerLoadAddressInstant.log
   TriggerStoreAddressInstant > logs/20240422-102636-HiFive1Flash-TriggerStoreAddressInstant.log
   UserInterrupt > logs/20240422-102642-HiFive1Flash-UserInterrupt.log
   WriteCsrs > logs/20240422-102648-HiFive1Flash-WriteCsrs.log
   WriteGprs > logs/20240422-102654-HiFive1Flash-WriteGprs.log
2 tests returned fail
   IcountTest > logs/20240422-102304-HiFive1Flash-IcountTest.log
   InstantHaltTest > logs/20240422-102310-HiFive1Flash-InstantHaltTest.log

Logs:
logs.zip

Given the large number of exceptions, I suspected one of the tests puts the target into some weird state OpenOCD cannot recover it from. Running the test suite again returns just exceptions without a single pass.

Pressing the physical reset button on the board made some tests pass again.

@TommyMurphyTM1234
Copy link
Collaborator Author

I ran the current riscv-openocd master (3991492)

That's not what your logs say:

-------------------------[ /tmp/openocdyjts01q_.log ]-------------------------
+  USE_FREERTOS=0 /home/codasip.com/marek.vrbka/repos/openocd-riscv/src/openocd -d3 --command 'gdb_port 0' --command 'tcl_port 0' --command 'telnet_port disabled' -f targets/SiFive/HiFive1.cfg
Open On-Chip Debugger 0.12.0+dev-00559-g04154af5d (2024-04-22-09:56)
Licensed under GNU GPL v2
For bug reports, read
	http://openocd.org/doc/doxygen/bugs.html

I can't find that commit (04154af) in this repo:

@MarekVCodasip
Copy link
Collaborator

MarekVCodasip commented Apr 22, 2024

Sorry, I have made a mistake. This was the master branch in the riscv-openocd repository. I will rerun the tests shortly with the proper branch.

@TommyMurphyTM1234
Copy link
Collaborator Author

Sorry, I have made a mistake. This was the master branch in the riscv-openocd repository. I will rerun the tests shortly with the proper branch.

Something still doesn't add up because the most recent commit on the (7 year old) master branch is afe5048 and not 04154af.

@MarekVCodasip
Copy link
Collaborator

Yes, it all now fails with exceptions built off commit 3991492

::::::::::::::::::::::::::::[ ran 73 tests in 7s ]::::::::::::::::::::::::::::
17 tests returned not_applicable
56 tests returned exception
   CheckMisa > logs/20240422-111232-HiFive1-CheckMisa.log
   DebugBreakpoint > logs/20240422-111232-HiFive1-DebugBreakpoint.log
   DebugChangeString > logs/20240422-111232-HiFive1-DebugChangeString.log
   DebugCompareSections > logs/20240422-111232-HiFive1-DebugCompareSections.log
   DebugExit > logs/20240422-111232-HiFive1-DebugExit.log
   DebugFunctionCall > logs/20240422-111232-HiFive1-DebugFunctionCall.log
   DebugSymbols > logs/20240422-111232-HiFive1-DebugSymbols.log
   DebugTurbostep > logs/20240422-111232-HiFive1-DebugTurbostep.log
   DisconnectTest > logs/20240422-111233-HiFive1-DisconnectTest.log
   DownloadTest > logs/20240422-111233-HiFive1-DownloadTest.log
   EbreakTest > logs/20240422-111233-HiFive1-EbreakTest.log
   EtriggerTest > logs/20240422-111233-HiFive1-EtriggerTest.log
   Hwbp1 > logs/20240422-111233-HiFive1-Hwbp1.log
   Hwbp2 > logs/20240422-111233-HiFive1-Hwbp2.log
   HwbpManual > logs/20240422-111233-HiFive1-HwbpManual.log
   IcountTest > logs/20240422-111233-HiFive1-IcountTest.log
   InfoTest > logs/20240422-111234-HiFive1-InfoTest.log
   InstantChangePc > logs/20240422-111234-HiFive1-InstantChangePc.log
   InstantHaltTest > logs/20240422-111234-HiFive1-InstantHaltTest.log
   InterruptTest > logs/20240422-111234-HiFive1-InterruptTest.log
   ItriggerTest > logs/20240422-111234-HiFive1-ItriggerTest.log
   JumpHbreak > logs/20240422-111234-HiFive1-JumpHbreak.log
   MemTest16 > logs/20240422-111234-HiFive1-MemTest16.log
   MemTest32 > logs/20240422-111234-HiFive1-MemTest32.log
   MemTest64 > logs/20240422-111235-HiFive1-MemTest64.log
   MemTest8 > logs/20240422-111235-HiFive1-MemTest8.log
   MemTestBlock0 > logs/20240422-111235-HiFive1-MemTestBlock0.log
   MemTestBlock1 > logs/20240422-111235-HiFive1-MemTestBlock1.log
   MemTestBlock2 > logs/20240422-111235-HiFive1-MemTestBlock2.log
   MemTestReadInvalid > logs/20240422-111235-HiFive1-MemTestReadInvalid.log
   MemorySampleMixed > logs/20240422-111235-HiFive1-MemorySampleMixed.log
   MemorySampleSingle > logs/20240422-111235-HiFive1-MemorySampleSingle.log
   PrivChange > logs/20240422-111235-HiFive1-PrivChange.log
   PrivRw > logs/20240422-111236-HiFive1-PrivRw.log
   ProgramHwWatchpoint > logs/20240422-111236-HiFive1-ProgramHwWatchpoint.log
   ProgramSwWatchpoint > logs/20240422-111236-HiFive1-ProgramSwWatchpoint.log
   Registers > logs/20240422-111236-HiFive1-Registers.log
   RepeatReadTest > logs/20240422-111236-HiFive1-RepeatReadTest.log
   Semihosting > logs/20240422-111236-HiFive1-Semihosting.log
   SemihostingFileio > logs/20240422-111236-HiFive1-SemihostingFileio.log
   SimpleF18Test > logs/20240422-111237-HiFive1-SimpleF18Test.log
   SimpleNoExistTest > logs/20240422-111237-HiFive1-SimpleNoExistTest.log
   SimpleS0Test > logs/20240422-111237-HiFive1-SimpleS0Test.log
   SimpleS1Test > logs/20240422-111237-HiFive1-SimpleS1Test.log
   SimpleT0Test > logs/20240422-111237-HiFive1-SimpleT0Test.log
   SimpleT1Test > logs/20240422-111237-HiFive1-SimpleT1Test.log
   SimpleV13Test > logs/20240422-111237-HiFive1-SimpleV13Test.log
   StepTest > logs/20240422-111237-HiFive1-StepTest.log
   TooManyHwbp > logs/20240422-111238-HiFive1-TooManyHwbp.log
   TriggerDmode > logs/20240422-111238-HiFive1-TriggerDmode.log
   TriggerExecuteInstant > logs/20240422-111238-HiFive1-TriggerExecuteInstant.log
   TriggerLoadAddressInstant > logs/20240422-111238-HiFive1-TriggerLoadAddressInstant.log
   TriggerStoreAddressInstant > logs/20240422-111238-HiFive1-TriggerStoreAddressInstant.log
   UserInterrupt > logs/20240422-111238-HiFive1-UserInterrupt.log
   WriteCsrs > logs/20240422-111238-HiFive1-WriteCsrs.log
   WriteGprs > logs/20240422-111238-HiFive1-WriteGprs.log

logs.zip

I will invetigate the master branch issue later. I think we should revise it in the whole repository if it is needed at all.

@aap-sc
Copy link
Collaborator

aap-sc commented Apr 22, 2024

@MarekVCodasip could you please double-check @TommyMurphyTM1234's results when running testsuite against b7e7a03 ?

My guess that the massive failures on current TOT should be fixed by #1045 . However, looks like regression on v0.11 happened a while ago.

@TommyMurphyTM1234
Copy link
Collaborator Author

I will invetigate the master branch issue later. I think we should revise it in the whole repository if it is needed at all.

I've opened a new issue for this:

@TommyMurphyTM1234
Copy link
Collaborator Author

My guess that the massive failures on current TOT should be fixed by #1045 . However, looks like regression on v0.11 happened a while ago.

I think so too.
When I encountered the segfault I got this:

Debug: 1445 618 riscv-011.c:1212 reg_cache_set(): s1 <= 0x0
Debug: 1446 618 riscv-011.c:1212 reg_cache_set(): fp <= 0x80000168
Debug: 1447 618 riscv-011.c:1212 reg_cache_set(): csr1904 <= 0x2040016c
Segmentation fault

@MarekVCodasip's logs show this:

Debug: 1485 22 riscv-011.c:1212 reg_cache_set(): s1 <= 0x0
Debug: 1486 22 riscv-011.c:1212 reg_cache_set(): fp <= 0x80000088
Debug: 1487 22 riscv-011.c:1212 reg_cache_set(): csr1904 <= 0x204008a8

--------------------------------[ Traceback ]---------------------------------
Traceback (most recent call last):
  File "/home/codasip.com/marek.vrbka/repos/riscv-tests/debug/testlib.py", line 1359, in run
    self.classSetup()
  File "/home/codasip.com/marek.vrbka/repos/riscv-tests/debug/testlib.py", line 1415, in classSetup
    BaseTest.classSetup(self)
  File "/home/codasip.com/marek.vrbka/repos/riscv-tests/debug/testlib.py", line 1326, in classSetup
    self.server = self.target.server(self)
  File "/home/codasip.com/marek.vrbka/repos/riscv-tests/debug/targets.py", line 186, in server
    debug_openocd=self.debug_server)
  File "/home/codasip.com/marek.vrbka/repos/riscv-tests/debug/testlib.py", line 368, in __init__
    self.start(cmd, logfile, extra_env)
  File "/home/codasip.com/marek.vrbka/repos/riscv-tests/debug/testlib.py", line 390, in start
    message="Waiting for OpenOCD to start up...")
  File "/home/codasip.com/marek.vrbka/repos/riscv-tests/debug/testlib.py", line 473, in expect
    raise TestLibError("OpenOCD exited early.")
testlib.TestLibError: OpenOCD exited early.

I'm not sure why this doesn't have the "Segmentation fault" error message but it seems to exit/crash at the same point.

@MarekVCodasip
Copy link
Collaborator

@MarekVCodasip could you please double-check @TommyMurphyTM1234's results when running testsuite against b7e7a03 ?

For said commit (and riscv-tests master) it seems that I also get full set of exceptions:

:::::::::::::::::::::::::::[ ran 73 tests in 379s ]:::::::::::::::::::::::::::
17 tests returned not_applicable
56 tests returned exception
   CheckMisa > logs/20240422-130924-HiFive1-CheckMisa.log
   DebugBreakpoint > logs/20240422-130925-HiFive1-DebugBreakpoint.log
   DebugChangeString > logs/20240422-131019-HiFive1-DebugChangeString.log
   DebugCompareSections > logs/20240422-131025-HiFive1-DebugCompareSections.log
   DebugExit > logs/20240422-131031-HiFive1-DebugExit.log
   DebugFunctionCall > logs/20240422-131037-HiFive1-DebugFunctionCall.log
   DebugSymbols > logs/20240422-131043-HiFive1-DebugSymbols.log
   DebugTurbostep > logs/20240422-131049-HiFive1-DebugTurbostep.log
   DisconnectTest > logs/20240422-131055-HiFive1-DisconnectTest.log
   DownloadTest > logs/20240422-131101-HiFive1-DownloadTest.log
   EbreakTest > logs/20240422-131107-HiFive1-EbreakTest.log
   EtriggerTest > logs/20240422-131113-HiFive1-EtriggerTest.log
   Hwbp1 > logs/20240422-131119-HiFive1-Hwbp1.log
   Hwbp2 > logs/20240422-131125-HiFive1-Hwbp2.log
   HwbpManual > logs/20240422-131131-HiFive1-HwbpManual.log
   IcountTest > logs/20240422-131137-HiFive1-IcountTest.log
   InfoTest > logs/20240422-131143-HiFive1-InfoTest.log
   InstantChangePc > logs/20240422-131149-HiFive1-InstantChangePc.log
   InstantHaltTest > logs/20240422-131155-HiFive1-InstantHaltTest.log
   InterruptTest > logs/20240422-131201-HiFive1-InterruptTest.log
   ItriggerTest > logs/20240422-131207-HiFive1-ItriggerTest.log
   JumpHbreak > logs/20240422-131213-HiFive1-JumpHbreak.log
   MemTest16 > logs/20240422-131219-HiFive1-MemTest16.log
   MemTest32 > logs/20240422-131225-HiFive1-MemTest32.log
   MemTest64 > logs/20240422-131231-HiFive1-MemTest64.log
   MemTest8 > logs/20240422-131237-HiFive1-MemTest8.log
   MemTestBlock0 > logs/20240422-131243-HiFive1-MemTestBlock0.log
   MemTestBlock1 > logs/20240422-131249-HiFive1-MemTestBlock1.log
   MemTestBlock2 > logs/20240422-131255-HiFive1-MemTestBlock2.log
   MemTestReadInvalid > logs/20240422-131301-HiFive1-MemTestReadInvalid.log
   MemorySampleMixed > logs/20240422-131307-HiFive1-MemorySampleMixed.log
   MemorySampleSingle > logs/20240422-131313-HiFive1-MemorySampleSingle.log
   PrivChange > logs/20240422-131319-HiFive1-PrivChange.log
   PrivRw > logs/20240422-131325-HiFive1-PrivRw.log
   ProgramHwWatchpoint > logs/20240422-131331-HiFive1-ProgramHwWatchpoint.log
   ProgramSwWatchpoint > logs/20240422-131337-HiFive1-ProgramSwWatchpoint.log
   Registers > logs/20240422-131343-HiFive1-Registers.log
   RepeatReadTest > logs/20240422-131349-HiFive1-RepeatReadTest.log
   Semihosting > logs/20240422-131355-HiFive1-Semihosting.log
   SemihostingFileio > logs/20240422-131401-HiFive1-SemihostingFileio.log
   SimpleF18Test > logs/20240422-131407-HiFive1-SimpleF18Test.log
   SimpleNoExistTest > logs/20240422-131413-HiFive1-SimpleNoExistTest.log
   SimpleS0Test > logs/20240422-131419-HiFive1-SimpleS0Test.log
   SimpleS1Test > logs/20240422-131425-HiFive1-SimpleS1Test.log
   SimpleT0Test > logs/20240422-131431-HiFive1-SimpleT0Test.log
   SimpleT1Test > logs/20240422-131437-HiFive1-SimpleT1Test.log
   SimpleV13Test > logs/20240422-131443-HiFive1-SimpleV13Test.log
   StepTest > logs/20240422-131449-HiFive1-StepTest.log
   TooManyHwbp > logs/20240422-131455-HiFive1-TooManyHwbp.log
   TriggerDmode > logs/20240422-131501-HiFive1-TriggerDmode.log
   TriggerExecuteInstant > logs/20240422-131507-HiFive1-TriggerExecuteInstant.log
   TriggerLoadAddressInstant > logs/20240422-131513-HiFive1-TriggerLoadAddressInstant.log
   TriggerStoreAddressInstant > logs/20240422-131519-HiFive1-TriggerStoreAddressInstant.log
   UserInterrupt > logs/20240422-131525-HiFive1-UserInterrupt.log
   WriteCsrs > logs/20240422-131531-HiFive1-WriteCsrs.log
   WriteGprs > logs/20240422-131537-HiFive1-WriteGprs.log

I did manually reset the board, just in case, before running the test suite.

Logs: logs.zip

@TommyMurphyTM1234
Copy link
Collaborator Author

let's try an older OpenOCD version (but newer than the one that works)

So basically I suggest to do a kind of bisection (with few "educated guesses" as a bisection steps, instead of a proper bisection). Just with -d3 logs enabled. Usually this level of logging is enough to figure out what is wrong.

I still need to get back to this but I'm curious as to why you suggest a manual/educated guess bisection approach rather than just using git bisect? If you still think that the former is the better approach perhaps you can suggest the next commit to check against? ;-)

@aap-sc
Copy link
Collaborator

aap-sc commented Apr 22, 2024

I still need to get back to this but I'm curious as to why you suggest a manual/educated guess bisection approach rather than just using git bisect?

Well, I'm just worried that a proper bisect will take too much time and it will be easier to just guess the offending commit. If someone (like you :)) has the bandwidth to do a proper bisect, you are very much welcome.

If you still think that the former is the better approach perhaps you can suggest the next commit to check against? ;-)

I'll need some time to look at these logs and try to figure out what went wrong and then glance at the changes we had. This may take some time.

@TommyMurphyTM1234
Copy link
Collaborator Author

I did manually reset the board, just in case, before running the test suite.

As I mentioned elsewhere it seems to me a bad idea that the test suite doesn't seem to reset the target before each test.
E.g. when I run the test suite against the b7e7a03 commit I get this:

./gdbserver.py targets/SiFive/HiFive1.py
PRNG seed for HiFive1 is generated automatically
PRNG seed for HiFive1 is 1713795242
Using $misa from hart definition: 0x40001105
[CeaseStepiTest] Starting > logs/20240422-151402-HiFive1-CeaseStepiTest.log
[CeaseStepiTest] not_applicable in 0.00s
[CheckMisa] Starting > logs/20240422-151402-HiFive1-CheckMisa.log
[CheckMisa] pass in 2.05s

...

::::::::::::::::::::::::::[ ran 73 tests in 3494s ]:::::::::::::::::::::::::::
17 tests returned not_applicable
1 tests returned pass
55 tests returned exception
   DebugBreakpoint > logs/20240422-151404-HiFive1-DebugBreakpoint.log
   DebugChangeString > logs/20240422-151500-HiFive1-DebugChangeString.log
   DebugCompareSections > logs/20240422-151610-HiFive1-DebugCompareSections.log
   DebugExit > logs/20240422-151710-HiFive1-DebugExit.log
   DebugFunctionCall > logs/20240422-151820-HiFive1-DebugFunctionCall.log
   DebugSymbols > logs/20240422-151920-HiFive1-DebugSymbols.log
   DebugTurbostep > logs/20240422-152020-HiFive1-DebugTurbostep.log
   DisconnectTest > logs/20240422-152121-HiFive1-DisconnectTest.log
   DownloadTest > logs/20240422-152221-HiFive1-DownloadTest.log
   EbreakTest > logs/20240422-152321-HiFive1-EbreakTest.log
   EtriggerTest > logs/20240422-152421-HiFive1-EtriggerTest.log
   Hwbp1 > logs/20240422-152531-HiFive1-Hwbp1.log
   Hwbp2 > logs/20240422-152631-HiFive1-Hwbp2.log
   HwbpManual > logs/20240422-152731-HiFive1-HwbpManual.log
   IcountTest > logs/20240422-152842-HiFive1-IcountTest.log
   InfoTest > logs/20240422-152942-HiFive1-InfoTest.log
   InstantChangePc > logs/20240422-153042-HiFive1-InstantChangePc.log
   InstantHaltTest > logs/20240422-153142-HiFive1-InstantHaltTest.log
   InterruptTest > logs/20240422-153242-HiFive1-InterruptTest.log
   ItriggerTest > logs/20240422-153342-HiFive1-ItriggerTest.log
   JumpHbreak > logs/20240422-153442-HiFive1-JumpHbreak.log
   MemTest16 > logs/20240422-153543-HiFive1-MemTest16.log
   MemTest32 > logs/20240422-153653-HiFive1-MemTest32.log
   MemTest64 > logs/20240422-153753-HiFive1-MemTest64.log
   MemTest8 > logs/20240422-153853-HiFive1-MemTest8.log
   MemTestBlock0 > logs/20240422-153953-HiFive1-MemTestBlock0.log
   MemTestBlock1 > logs/20240422-154053-HiFive1-MemTestBlock1.log
   MemTestBlock2 > logs/20240422-154203-HiFive1-MemTestBlock2.log
   MemTestReadInvalid > logs/20240422-154313-HiFive1-MemTestReadInvalid.log
   MemorySampleMixed > logs/20240422-154413-HiFive1-MemorySampleMixed.log
   MemorySampleSingle > logs/20240422-154523-HiFive1-MemorySampleSingle.log
   PrivChange > logs/20240422-154623-HiFive1-PrivChange.log
   PrivRw > logs/20240422-154724-HiFive1-PrivRw.log
   ProgramHwWatchpoint > logs/20240422-154824-HiFive1-ProgramHwWatchpoint.log
   ProgramSwWatchpoint > logs/20240422-154934-HiFive1-ProgramSwWatchpoint.log
   Registers > logs/20240422-155044-HiFive1-Registers.log
   RepeatReadTest > logs/20240422-155144-HiFive1-RepeatReadTest.log
   Semihosting > logs/20240422-155244-HiFive1-Semihosting.log
   SemihostingFileio > logs/20240422-155345-HiFive1-SemihostingFileio.log
   SimpleF18Test > logs/20240422-155455-HiFive1-SimpleF18Test.log
   SimpleNoExistTest > logs/20240422-155555-HiFive1-SimpleNoExistTest.log
   SimpleS0Test > logs/20240422-155655-HiFive1-SimpleS0Test.log
   SimpleS1Test > logs/20240422-155755-HiFive1-SimpleS1Test.log
   SimpleT0Test > logs/20240422-155905-HiFive1-SimpleT0Test.log
   SimpleT1Test > logs/20240422-160015-HiFive1-SimpleT1Test.log
   SimpleV13Test > logs/20240422-160115-HiFive1-SimpleV13Test.log
   StepTest > logs/20240422-160225-HiFive1-StepTest.log
   TooManyHwbp > logs/20240422-160335-HiFive1-TooManyHwbp.log
   TriggerDmode > logs/20240422-160435-HiFive1-TriggerDmode.log
   TriggerExecuteInstant > logs/20240422-160546-HiFive1-TriggerExecuteInstant.log
   TriggerLoadAddressInstant > logs/20240422-160646-HiFive1-TriggerLoadAddressInstant.log
   TriggerStoreAddressInstant > logs/20240422-160756-HiFive1-TriggerStoreAddressInstant.log
   UserInterrupt > logs/20240422-160856-HiFive1-UserInterrupt.log
   WriteCsrs > logs/20240422-161006-HiFive1-WriteCsrs.log
   WriteGprs > logs/20240422-161106-HiFive1-WriteGprs.log

So all tests bar CheckMisa return exceptions.

Then if I run CheckMisa again manually I get this:

./gdbserver.py targets/SiFive/HiFive1.py CheckMisa
PRNG seed for HiFive1 is generated automatically
PRNG seed for HiFive1 is 1713801573
Using $misa from hart definition: 0x40001105
[CheckMisa] Starting > logs/20240422-165933-HiFive1-CheckMisa.log
[CheckMisa] exception in 70.04s
::::::::::::::::::::::::::::[ ran 1 tests in 70s ]::::::::::::::::::::::::::::
1 tests returned exception

But if I reset the board manually using the red button I get this:

./gdbserver.py targets/SiFive/HiFive1.py CheckMisa
PRNG seed for HiFive1 is generated automatically
PRNG seed for HiFive1 is 1713801689
Using $misa from hart definition: 0x40001105
[CheckMisa] Starting > logs/20240422-170129-HiFive1-CheckMisa.log
[CheckMisa] pass in 1.83s
::::::::::::::::::::::::::::[ ran 1 tests in 2s ]:::::::::::::::::::::::::::::
1 tests returned pass

So it looks like one test failing due to some anomaly/exception may cause subsequent tests to fail.
This may be a separate issue to the one in hand or it may be related - I'm not yet sure.
But not resetting the target to get it into a known good state before running a test seems like a bad idea generally.
(The only exception might be where the test is something like "connect to and interact with a running target without resetting first" but I'm not sure that such tests are run?).

@TommyMurphyTM1234
Copy link
Collaborator Author

TommyMurphyTM1234 commented Apr 22, 2024

I restricted the testing to just two tests - CheckMisa and DebugBreakpoint. The former normally always passes and the latter gets an exception with a "broken" OpenOCD.

With the known good e0dd44a commit I get:

# Manually reset the board for a clean start
./gdbserver.py targets/SiFive/HiFive1.py CheckMisa DebugBreakpoint --server_cmd "openocd -d3"
PRNG seed for HiFive1 is generated automatically
PRNG seed for HiFive1 is 1713803546
Using $misa from hart definition: 0x40001105
[CheckMisa] Starting > logs/20240422-173226-HiFive1-CheckMisa.log
[CheckMisa] pass in 2.13s
[DebugBreakpoint] Starting > logs/20240422-173228-HiFive1-DebugBreakpoint.log
[DebugBreakpoint] pass in 5.57s
::::::::::::::::::::::::::::[ ran 2 tests in 8s ]:::::::::::::::::::::::::::::
2 tests returned pass

With the known bad commit b7e7a03 I get this:

# Manually reset the board for a clean start
./gdbserver.py targets/SiFive/HiFive1.py CheckMisa DebugBreakpoint --server_cmd "openocd -d3"
PRNG seed for HiFive1 is generated automatically
PRNG seed for HiFive1 is 1713804060
Using $misa from hart definition: 0x40001105
[CheckMisa] Starting > logs/20240422-174100-HiFive1-CheckMisa.log
[CheckMisa] pass in 1.91s
[DebugBreakpoint] Starting > logs/20240422-174102-HiFive1-DebugBreakpoint.log
[DebugBreakpoint] exception in 55.97s
::::::::::::::::::::::::::::[ ran 2 tests in 58s ]::::::::::::::::::::::::::::
1 tests returned pass
1 tests returned exception
   DebugBreakpoint > logs/20240422-174102-HiFive1-DebugBreakpoint.log

I then used git bisect to pinpoint this commit:

3f1339f8e8dc87b99ac12618a9c9c3a1abd45d07 is the first bad commit
commit 3f1339f8e8dc87b99ac12618a9c9c3a1abd45d07
Author: liangzhen <[email protected]>
Date:   Wed Sep 20 15:27:35 2023 +0800

    target/riscv: use cacheable read/write function to handle DCSR
    
    Signed-off-by: liangzhen <[email protected]>

 src/target/riscv/riscv-013.c | 39 +++++----------------------------------
 src/target/riscv/riscv.c     | 23 +++++++++++++++++++++++
 2 files changed, 28 insertions(+), 34 deletions(-)

The failure log with a build from commit 3f1339f is here: 20240422-183238-HiFive1-DebugBreakpoint.log

I'll continue to look into this in more detail later.

@en-sc
Copy link
Collaborator

en-sc commented Apr 23, 2024

I then used git bisect to pinpoint this commit:

3f1339f8e8dc87b99ac12618a9c9c3a1abd45d07 is the first bad commit
commit 3f1339f8e8dc87b99ac12618a9c9c3a1abd45d07
Author: liangzhen <[email protected]>
Date:   Wed Sep 20 15:27:35 2023 +0800

    target/riscv: use cacheable read/write function to handle DCSR
    
    Signed-off-by: liangzhen <[email protected]>

 src/target/riscv/riscv-013.c | 39 +++++----------------------------------
 src/target/riscv/riscv.c     | 23 +++++++++++++++++++++++
 2 files changed, 28 insertions(+), 34 deletions(-)

@TommyMurphyTM1234, AFAIR the issue with 3f1339f is #996 and it was addressed by #997. Please, try ec28cf0.

@TommyMurphyTM1234
Copy link
Collaborator Author

@TommyMurphyTM1234, AFAIR the issue with 3f1339f is #996 and it was addressed by #997. Please, try ec28cf0.

Thanks @en-sc - yes - I was just going through the details/issues/PRs and noticed #997 alright.
With a build of OpenOCD at ec28cf0 I get this:

# Manually reset the board for a clean start
./gdbserver.py targets/SiFive/HiFive1.py CheckMisa DebugBreakpoint --server_cmd "openocd -d3"
PRNG seed for HiFive1 is generated automatically
PRNG seed for HiFive1 is 1713860376
Using $misa from hart definition: 0x40001105
[CheckMisa] Starting > logs/20240423-091936-HiFive1-CheckMisa.log
[CheckMisa] pass in 2.31s
[DebugBreakpoint] Starting > logs/20240423-091938-HiFive1-DebugBreakpoint.log
[DebugBreakpoint] exception in 55.71s
::::::::::::::::::::::::::::[ ran 2 tests in 58s ]::::::::::::::::::::::::::::
1 tests returned pass
1 tests returned exception
   DebugBreakpoint > logs/20240423-091938-HiFive1-DebugBreakpoint.log

At a glance of the log I can't really tell what goes wrong to cause the exception...

logs/20240423-091938-HiFive1-DebugBreakpoint.log: 20240423-091938-HiFive1-DebugBreakpoint.log

@TommyMurphyTM1234
Copy link
Collaborator Author

As I found before...

If I run the DebugBreakpoint manually by launching OpenOCD and GDB separately and following the GDB commands in the log I get this (I omitted some non-significant commands/details and use the default OpenOCD socket ports for convenience):

# OpenOCD terminal
USE_FREERTOS=0 openocd  -f targets/SiFive/HiFive1.cfg
Open On-Chip Debugger 0.12.0+dev-03604-gec28cf03a (2024-04-23-09:14)
Licensed under GNU GPL v2
For bug reports, read
	http://openocd.org/doc/doxygen/bugs.html
Info : auto-selecting first available session transport "jtag". To override use 'transport select <transport>'.
Info : ftdi: if you experience problems at higher adapter clocks, try the command "ftdi tdo_sample_edge falling"
Info : clock speed 10000 kHz
Info : JTAG tap: riscv.cpu tap/device found: 0x10e31913 (mfg: 0x489 (SiFive Inc), part: 0x0e31, ver: 0x1)
Warn : Got exception 0xffffffff when reading tinfo
Warn : Got exception 0xffffffff when reading tinfo
Info : [riscv.cpu] Found 2 triggers
halted at 0x400 due to software breakpoint
Info : Examined RISCV core; XLEN=32, misa=0x40001105
[riscv.cpu] Target successfully examined.
Info : [riscv.cpu] Examination succeed
Info : starting gdb server for riscv.cpu on 3333
Info : Listening on port 3333 for gdb connections
Info : Found flash device 'issi is25lp128d' (ID 0x0018609d)
Ready for Remote Connections
Info : Listening on port 6666 for tcl connections
Info : Listening on port 4444 for telnet connections
# GDB terminal
riscv64-unknown-elf-gdb
GNU gdb (GDB) 14.1
Copyright (C) 2023 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
Type "show copying" and "show warranty" for details.
This GDB was configured as "--host=x86_64-pc-linux-gnu --target=riscv64-unknown-elf".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<https://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
    <http://www.gnu.org/software/gdb/documentation/>.

For help, type "help".
Type "apropos word" to search for commands related to "word".
(gdb) target extended-remote :3333
Remote debugging using :3333
warning: No executable has been specified and target does not support
determining executable automatically.  Try using the "file" command.
0x00000400 in ?? ()
(gdb) file HiFive1_debug-40001105
A program is being debugged already.
Are you sure you want to change the file? (y or n) y
Reading symbols from HiFive1_debug-40001105...
(gdb) load
Loading section .text, size 0x8ca lma 0x80000000
Loading section .rodata, size 0x38 lma 0x800008d0
Loading section .data, size 0x16c lma 0x80000910
Loading section .sdata, size 0x4 lma 0x80000a7c
Start address 0x80000000, load size 2674
Transfer rate: 16 KB/sec, 668 bytes/write.
(gdb) compare-sections
Section .text, range 0x80000000 -- 0x800008ca: matched.
Section .rodata, range 0x800008d0 -- 0x80000908: matched.
Section .data, range 0x80000910 -- 0x80000a7c: matched.
Section .sdata, range 0x80000a7c -- 0x80000a80: matched.
(gdb) b _exit
Breakpoint 1 at 0x800008a8: file programs/init.c, line 36.
(gdb) b rot13
Breakpoint 2 at 0x800001d6: file programs/debug.c, line 28.
(gdb) si
halted at 0x404 due to step
halted at 0x404 due to step
0x00000404 in ?? ()
(gdb) 
# OpenOCD terminal
Info : Retrying memory write starting from 0x80000000 with more delays
halted at 0x404 due to step
halted at 0x404 due to step
Core got an exception (0xffffffff) while reading from 0x4000f07c
(It may have failed between 0x4000f040 and 0x4000f07b as well, but we didn't check then.)
Core got an exception (0xffffffff) while reading from 0x4000f063

But if I do a monitor reset init in GDB after loading the program then things seem to work better:

# GDB terminal
(gdb) target extended-remote :3333
Remote debugging using :3333
warning: No executable has been specified and target does not support
determining executable automatically.  Try using the "file" command.
0x00000400 in ?? ()
(gdb) file HiFive1_debug-40001105
A program is being debugged already.
Are you sure you want to change the file? (y or n) y
Reading symbols from HiFive1_debug-40001105...
(gdb) load
Loading section .text, size 0x8ca lma 0x80000000
Loading section .rodata, size 0x38 lma 0x800008d0
Loading section .data, size 0x16c lma 0x80000910
Loading section .sdata, size 0x4 lma 0x80000a7c
Start address 0x80000000, load size 2674
Transfer rate: 19 KB/sec, 668 bytes/write.
(gdb) monitor reset init
JTAG tap: riscv.cpu tap/device found: 0x10e31913 (mfg: 0x489 (SiFive Inc), part: 0x0e31, ver: 0x1)
riscv.cpu halted due to breakpoint.
halted at 0x80000000 due to software breakpoint
(gdb) b _exit
Breakpoint 1 at 0x800008a8: file programs/init.c, line 36.
(gdb) b rot13
Breakpoint 2 at 0x800001d6: file programs/debug.c, line 28.
(gdb) c
Continuing.

Breakpoint 2, rot13 (buf=0x800008d0 "The quick brown fox jumps of the lazy dog.") at programs/debug.c:28
28	    while (*buf) {
(gdb) 

I probably need to capture the verbose log for the failing case...

@TommyMurphyTM1234
Copy link
Collaborator Author

TommyMurphyTM1234 commented Apr 23, 2024

I probably need to capture the verbose log for the failing case...

USE_FREERTOS=0 openocd  -f targets/SiFive/HiFive1.cfg 2>&1 | tee openocd.log
...

openocd.log: openocd.log

For some reason I don't see this in the verbose log:

Core got an exception (0xffffffff) while reading from 0x4000f07c
(It may have failed between 0x4000f040 and 0x4000f07b as well, but we didn't check then.)
Core got an exception (0xffffffff) while reading from 0x4000f063

and the halt address is different in the non verbose test:

halted at 0x404 due to step
halted at 0x404 due to step

versus the verbose test:

User : 4908 26890 riscv-011.c:1887 handle_halt(): halted at 0x2040016a due to step
User : 5016 26897 riscv-011.c:1887 handle_halt(): halted at 0x2040016a due to step

So I don't know if -d3 verbose logging is having some side effect here?

@TommyMurphyTM1234
Copy link
Collaborator Author

TommyMurphyTM1234 commented Apr 23, 2024

Similar tests but using telnet instead of GDB in case this helps at all...

Without reset init:

# OpenOCD terminal
USE_FREERTOS=0 openocd  -f targets/SiFive/HiFive1.cfg
Open On-Chip Debugger 0.12.0+dev-03604-gec28cf03a (2024-04-23-09:14)
Licensed under GNU GPL v2
For bug reports, read
	http://openocd.org/doc/doxygen/bugs.html
Info : auto-selecting first available session transport "jtag". To override use 'transport select <transport>'.
Info : ftdi: if you experience problems at higher adapter clocks, try the command "ftdi tdo_sample_edge falling"
Info : clock speed 10000 kHz
Info : JTAG tap: riscv.cpu tap/device found: 0x10e31913 (mfg: 0x489 (SiFive Inc), part: 0x0e31, ver: 0x1)
Info : Examined RISCV core; XLEN=32, misa=0x40001105
[riscv.cpu] Target successfully examined.
Info : [riscv.cpu] Examination succeed
Info : starting gdb server for riscv.cpu on 3333
Info : Listening on port 3333 for gdb connections
Warn : Got exception 0xffffffff when reading tinfo
Warn : Got exception 0xffffffff when reading tinfo
Info : [riscv.cpu] Found 2 triggers
riscv.cpu halted due to debug-request.
halted at 0x2040016a due to debug interrupt
Info : Found flash device 'issi is25lp128d' (ID 0x0018609d)
Ready for Remote Connections
Info : Listening on port 6666 for tcl connections
Info : Listening on port 4444 for telnet connections
Info : accepting 'telnet' connection on tcp/4444
Info : Retrying memory write starting from 0x80000000 with more delays
riscv.cpu halted due to single-step.
halted at 0x2040016c due to step
riscv.cpu halted due to single-step.
halted at 0x2040016c due to step
# Telnet terminal
telnet localhost 4444
Trying 127.0.0.1...
Connected to localhost.
Escape character is '^]'.
Open On-Chip Debugger
> load_image HiFive1_debug-40001105
Retrying memory write starting from 0x80000000 with more delays
2688 bytes written at address 0x80000000
downloaded 2688 bytes in 0.115159s (22.795 KiB/s)
> reg pc                           
pc (/32): 0x00000400
> reg pc 0x80000000
pc (/32): 0x00000000
> reg pc force
pc (/32): 0x80000000
> step
riscv.cpu halted due to single-step.
halted at 0x2040016c due to step
riscv.cpu halted due to single-step.
halted at 0x2040016c due to step
> 

With reset init:

# OpenOCD terminal
USE_FREERTOS=0 openocd  -f targets/SiFive/HiFive1.cfg
Open On-Chip Debugger 0.12.0+dev-03604-gec28cf03a (2024-04-23-09:14)
Licensed under GNU GPL v2
For bug reports, read
	http://openocd.org/doc/doxygen/bugs.html
Info : auto-selecting first available session transport "jtag". To override use 'transport select <transport>'.
Info : ftdi: if you experience problems at higher adapter clocks, try the command "ftdi tdo_sample_edge falling"
Info : clock speed 10000 kHz
Info : JTAG tap: riscv.cpu tap/device found: 0x10e31913 (mfg: 0x489 (SiFive Inc), part: 0x0e31, ver: 0x1)
Info : Examined RISCV core; XLEN=32, misa=0x40001105
[riscv.cpu] Target successfully examined.
Info : [riscv.cpu] Examination succeed
Info : starting gdb server for riscv.cpu on 3333
Info : Listening on port 3333 for gdb connections
Warn : Got exception 0xffffffff when reading tinfo
Warn : Got exception 0xffffffff when reading tinfo
Info : [riscv.cpu] Found 2 triggers
riscv.cpu halted due to debug-request.
halted at 0x2040016a due to debug interrupt
Info : Found flash device 'issi is25lp128d' (ID 0x0018609d)
Ready for Remote Connections
Info : Listening on port 6666 for tcl connections
Info : Listening on port 4444 for telnet connections
Info : accepting 'telnet' connection on tcp/4444
Info : Retrying memory write starting from 0x80000000 with more delays
Info : JTAG tap: riscv.cpu tap/device found: 0x10e31913 (mfg: 0x489 (SiFive Inc), part: 0x0e31, ver: 0x1)
riscv.cpu halted due to breakpoint.
halted at 0x80000000 due to software breakpoint
riscv.cpu halted due to single-step.
halted at 0x80000006 due to step
riscv.cpu halted due to single-step.
halted at 0x80000006 due to step
# Telnet terminal
telnet localhost 4444
Trying 127.0.0.1...
Connected to localhost.
Escape character is '^]'.
Open On-Chip Debugger
> load_image HiFive1_debug-40001105
Retrying memory write starting from 0x80000000 with more delays
2688 bytes written at address 0x80000000
downloaded 2688 bytes in 0.111811s (23.477 KiB/s)
> reg pc                           
pc (/32): 0x00000400
> reg pc 0x80000000                
pc (/32): 0x00000000
> reg pc force                     
pc (/32): 0x80000000
> reset init
JTAG tap: riscv.cpu tap/device found: 0x10e31913 (mfg: 0x489 (SiFive Inc), part: 0x0e31, ver: 0x1)
riscv.cpu halted due to breakpoint.
halted at 0x80000000 due to software breakpoint
> step
riscv.cpu halted due to single-step.
halted at 0x80000006 due to step
riscv.cpu halted due to single-step.
halted at 0x80000006 due to step

@en-sc
Copy link
Collaborator

en-sc commented Apr 23, 2024

@TommyMurphyTM1234, @MarekVCodasip, I would suggest to proceed by running ./gdbserver.py targets/SiFive/HiFive1.py CheckMisa DebugBreakpoint --server_cmd "openocd -d3" on the following configurations:

  1. 28f630d (the parent of 3f1339f, which is known-bad, at least due to Fails connecting to SiFive HiFive1 A01 - Failed to read vsatp register #996). This will hopefully result in a most recent known-good log we can compare against.
  2. 3f1339f with ca3abca on top of it. This will allow to check if ca3abca really fixes Fails connecting to SiFive HiFive1 A01 - Failed to read vsatp register #996.
  3. If both (1) and (2) pass the test, it will be known that another issue was introduced between 3f1339f and ca3abca

@en-sc
Copy link
Collaborator

en-sc commented Apr 23, 2024

@TommyMurphyTM1234, I would also suggest to uncomment the line you have mentioned to reset the target (https://github.com/riscv-software-src/riscv-tests/blob/6b1d7372d951ed75811e0a09c0fe9e065c141c2d/debug/targets/SiFive/HiFive1.cfg#L29).

@TommyMurphyTM1234
Copy link
Collaborator Author

TommyMurphyTM1234 commented Apr 23, 2024

Thanks @en-sc - I will follow up on that ASAP.

In the meantime I modified gdbserver.py to add a reset after every program load - e.g.:

    def setup(self):
        self.gdb.load()
        # Tommy
        self.gdb.command("monitor reset init")

and the results look better but still not as expected:

openocd -v
Open On-Chip Debugger 0.12.0+dev-03604-gec28cf03a (2024-04-23-09:14)
Licensed under GNU GPL v2
For bug reports, read
	http://openocd.org/doc/doxygen/bugs.html

./gdbserver.py targets/SiFive/HiFive1.py
PRNG seed for HiFive1 is generated automatically
PRNG seed for HiFive1 is 1713868789
Using $misa from hart definition: 0x40001105
[CeaseStepiTest] Starting > logs/20240423-113949-HiFive1-CeaseStepiTest.log
[CeaseStepiTest] not_applicable in 0.00s
[CheckMisa] Starting > logs/20240423-113949-HiFive1-CheckMisa.log
[CheckMisa] pass in 2.06s
[CustomRegisterTest] Starting > logs/20240423-113951-HiFive1-CustomRegisterTest.log
[CustomRegisterTest] not_applicable in 0.00s
[DebugBreakpoint] Starting > logs/20240423-113951-HiFive1-DebugBreakpoint.log
[DebugBreakpoint] pass in 6.56s
[DebugChangeString] Starting > logs/20240423-113957-HiFive1-DebugChangeString.log
[DebugChangeString] exception in 8.44s
[DebugCompareSections] Starting > logs/20240423-114006-HiFive1-DebugCompareSections.log
[DebugCompareSections] pass in 4.07s
[DebugExit] Starting > logs/20240423-114010-HiFive1-DebugExit.log
[DebugExit] pass in 4.47s
[DebugFunctionCall] Starting > logs/20240423-114014-HiFive1-DebugFunctionCall.log
[DebugFunctionCall] exception in 9.16s
[DebugSymbols] Starting > logs/20240423-114024-HiFive1-DebugSymbols.log
[DebugSymbols] fail in 7.73s
[DebugTurbostep] Starting > logs/20240423-114031-HiFive1-DebugTurbostep.log
[DebugTurbostep] pass in 8.92s
[DisconnectTest] Starting > logs/20240423-114040-HiFive1-DisconnectTest.log
[DisconnectTest] pass in 9.77s
[DownloadTest] Starting > logs/20240423-114050-HiFive1-DownloadTest.log
[DownloadTest] pass in 5.16s
[EbreakTest] Starting > logs/20240423-114055-HiFive1-EbreakTest.log
[EbreakTest] fail in 9.45s
[EtriggerTest] Starting > logs/20240423-114105-HiFive1-EtriggerTest.log
[EtriggerTest] fail in 9.54s
[FreeRtosTest] Starting > logs/20240423-114114-HiFive1-FreeRtosTest.log
[FreeRtosTest] not_applicable in 0.00s
[Hwbp1] Starting > logs/20240423-114114-HiFive1-Hwbp1.log
[Hwbp1] pass in 6.07s
[Hwbp2] Starting > logs/20240423-114120-HiFive1-Hwbp2.log
[Hwbp2] pass in 7.41s
[HwbpManual] Starting > logs/20240423-114128-HiFive1-HwbpManual.log
[HwbpManual] not_applicable in 5.53s
[IcountTest] Starting > logs/20240423-114133-HiFive1-IcountTest.log
[IcountTest] fail in 7.42s
[InfoTest] Starting > logs/20240423-114141-HiFive1-InfoTest.log
[InfoTest] pass in 2.30s
[InstantChangePc] Starting > logs/20240423-114143-HiFive1-InstantChangePc.log
[InstantChangePc] fail in 9.95s
[InstantHaltTest] Starting > logs/20240423-114153-HiFive1-InstantHaltTest.log
[InstantHaltTest] fail in 6.71s
[InterruptTest] Starting > logs/20240423-114200-HiFive1-InterruptTest.log
[InterruptTest] pass in 15.94s
[ItriggerTest] Starting > logs/20240423-114216-HiFive1-ItriggerTest.log
[ItriggerTest] exception in 6.38s
[JumpHbreak] Starting > logs/20240423-114222-HiFive1-JumpHbreak.log
[JumpHbreak] pass in 4.47s
[MemTest16] Starting > logs/20240423-114226-HiFive1-MemTest16.log
[MemTest16] pass in 3.59s
[MemTest32] Starting > logs/20240423-114230-HiFive1-MemTest32.log
[MemTest32] pass in 3.72s
[MemTest64] Starting > logs/20240423-114234-HiFive1-MemTest64.log
[MemTest64] pass in 3.73s
[MemTest8] Starting > logs/20240423-114237-HiFive1-MemTest8.log
[MemTest8] pass in 3.80s
[MemTestBlock0] Starting > logs/20240423-114241-HiFive1-MemTestBlock0.log
[MemTestBlock0] pass in 5.38s
[MemTestBlock1] Starting > logs/20240423-114247-HiFive1-MemTestBlock1.log
[MemTestBlock1] pass in 4.85s
[MemTestBlock2] Starting > logs/20240423-114252-HiFive1-MemTestBlock2.log
[MemTestBlock2] pass in 5.38s
[MemTestBlockReadInvalid] Starting > logs/20240423-114257-HiFive1-MemTestBlockReadInvalid.log
[MemTestBlockReadInvalid] not_applicable in 0.00s
[MemTestReadInvalid] Starting > logs/20240423-114257-HiFive1-MemTestReadInvalid.log
[MemTestReadInvalid] exception in 9.66s
[MemorySampleMixed] Starting > logs/20240423-114307-HiFive1-MemorySampleMixed.log
[MemorySampleMixed] exception in 15.31s
[MemorySampleSingle] Starting > logs/20240423-114322-HiFive1-MemorySampleSingle.log
[MemorySampleSingle] exception in 14.26s
[MulticoreRegTest] Starting > logs/20240423-114336-HiFive1-MulticoreRegTest.log
[MulticoreRegTest] not_applicable in 0.00s
[MulticoreRtosSwitchActiveHartTest] Starting > logs/20240423-114336-HiFive1-MulticoreRtosSwitchActiveHartTest.log
[MulticoreRtosSwitchActiveHartTest] not_applicable in 0.00s
[MulticoreRunAllHaltOne] Starting > logs/20240423-114336-HiFive1-MulticoreRunAllHaltOne.log
[MulticoreRunAllHaltOne] not_applicable in 0.00s
[PrivChange] Starting > logs/20240423-114336-HiFive1-PrivChange.log
[PrivChange] not_applicable in 3.22s
[PrivRw] Starting > logs/20240423-114339-HiFive1-PrivRw.log
[PrivRw] pass in 9.28s
[ProgramHwWatchpoint] Starting > logs/20240423-114349-HiFive1-ProgramHwWatchpoint.log
[ProgramHwWatchpoint] pass in 8.87s
[ProgramSwWatchpoint] Starting > logs/20240423-114358-HiFive1-ProgramSwWatchpoint.log
[ProgramSwWatchpoint] pass in 13.49s
[Registers] Starting > logs/20240423-114411-HiFive1-Registers.log
[Registers] pass in 10.82s
[RepeatReadTest] Starting > logs/20240423-114422-HiFive1-RepeatReadTest.log
[RepeatReadTest] exception in 8.31s
[Semihosting] Starting > logs/20240423-114430-HiFive1-Semihosting.log
[Semihosting] exception in 8.63s
[SemihostingFileio] Starting > logs/20240423-114439-HiFive1-SemihostingFileio.log
[SemihostingFileio] exception in 8.98s
[SimpleF18Test] Starting > logs/20240423-114448-HiFive1-SimpleF18Test.log
[SimpleF18Test] pass in 6.11s
[SimpleNoExistTest] Starting > logs/20240423-114454-HiFive1-SimpleNoExistTest.log
[SimpleNoExistTest] pass in 1.74s
[SimpleS0Test] Starting > logs/20240423-114456-HiFive1-SimpleS0Test.log
[SimpleS0Test] fail in 12.87s
[SimpleS1Test] Starting > logs/20240423-114508-HiFive1-SimpleS1Test.log
[SimpleS1Test] pass in 10.79s
[SimpleT0Test] Starting > logs/20240423-114519-HiFive1-SimpleT0Test.log
[SimpleT0Test] pass in 9.82s
[SimpleT1Test] Starting > logs/20240423-114529-HiFive1-SimpleT1Test.log
[SimpleT1Test] pass in 9.95s
[SimpleV13Test] Starting > logs/20240423-114539-HiFive1-SimpleV13Test.log
[SimpleV13Test] pass in 6.36s
[SmpSimultaneousRunHalt] Starting > logs/20240423-114545-HiFive1-SmpSimultaneousRunHalt.log
[SmpSimultaneousRunHalt] not_applicable in 0.00s
[StepTest] Starting > logs/20240423-114545-HiFive1-StepTest.log
[StepTest] pass in 8.84s
[StepThread2Test] Starting > logs/20240423-114554-HiFive1-StepThread2Test.log
[StepThread2Test] not_applicable in 0.00s
[Sv32Test] Starting > logs/20240423-114554-HiFive1-Sv32Test.log
[Sv32Test] not_applicable in 0.00s
[Sv39Test] Starting > logs/20240423-114554-HiFive1-Sv39Test.log
[Sv39Test] not_applicable in 0.00s
[Sv48Test] Starting > logs/20240423-114554-HiFive1-Sv48Test.log
[Sv48Test] not_applicable in 0.00s
[TooManyHwbp] Starting > logs/20240423-114554-HiFive1-TooManyHwbp.log
[TooManyHwbp] pass in 11.33s
[TriggerDmode] Starting > logs/20240423-114606-HiFive1-TriggerDmode.log
[TriggerDmode] exception in 47.88s
[TriggerExecuteInstant] Starting > logs/20240423-114653-HiFive1-TriggerExecuteInstant.log
[TriggerExecuteInstant] pass in 4.87s
[TriggerLoadAddressInstant] Starting > logs/20240423-114658-HiFive1-TriggerLoadAddressInstant.log
[TriggerLoadAddressInstant] pass in 6.63s
[TriggerStoreAddressInstant] Starting > logs/20240423-114705-HiFive1-TriggerStoreAddressInstant.log
[TriggerStoreAddressInstant] pass in 5.57s
[UnavailableCycleTest] Starting > logs/20240423-114711-HiFive1-UnavailableCycleTest.log
[UnavailableCycleTest] not_applicable in 0.00s
[UnavailableHaltedTest] Starting > logs/20240423-114711-HiFive1-UnavailableHaltedTest.log
[UnavailableHaltedTest] not_applicable in 0.00s
[UnavailableMultiTest] Starting > logs/20240423-114711-HiFive1-UnavailableMultiTest.log
[UnavailableMultiTest] not_applicable in 0.00s
[UnavailableRunTest] Starting > logs/20240423-114711-HiFive1-UnavailableRunTest.log
[UnavailableRunTest] not_applicable in 0.00s
[UserInterrupt] Starting > logs/20240423-114711-HiFive1-UserInterrupt.log
[UserInterrupt] pass in 8.23s
[VectorTest] Starting > logs/20240423-114719-HiFive1-VectorTest.log
[VectorTest] not_applicable in 0.00s
[WriteCsrs] Starting > logs/20240423-114719-HiFive1-WriteCsrs.log
[WriteCsrs] exception in 11.18s
[WriteGprs] Starting > logs/20240423-114730-HiFive1-WriteGprs.log
[WriteGprs] exception in 53.20s
:::::::::::::::::::::::::::[ ran 73 tests in 514s ]:::::::::::::::::::::::::::
19 tests returned not_applicable
35 tests returned pass
12 tests returned exception
   DebugChangeString > logs/20240423-113957-HiFive1-DebugChangeString.log
   DebugFunctionCall > logs/20240423-114014-HiFive1-DebugFunctionCall.log
   ItriggerTest > logs/20240423-114216-HiFive1-ItriggerTest.log
   MemTestReadInvalid > logs/20240423-114257-HiFive1-MemTestReadInvalid.log
   MemorySampleMixed > logs/20240423-114307-HiFive1-MemorySampleMixed.log
   MemorySampleSingle > logs/20240423-114322-HiFive1-MemorySampleSingle.log
   RepeatReadTest > logs/20240423-114422-HiFive1-RepeatReadTest.log
   Semihosting > logs/20240423-114430-HiFive1-Semihosting.log
   SemihostingFileio > logs/20240423-114439-HiFive1-SemihostingFileio.log
   TriggerDmode > logs/20240423-114606-HiFive1-TriggerDmode.log
   WriteCsrs > logs/20240423-114719-HiFive1-WriteCsrs.log
   WriteGprs > logs/20240423-114730-HiFive1-WriteGprs.log
7 tests returned fail
   DebugSymbols > logs/20240423-114024-HiFive1-DebugSymbols.log
   EbreakTest > logs/20240423-114055-HiFive1-EbreakTest.log
   EtriggerTest > logs/20240423-114105-HiFive1-EtriggerTest.log
   IcountTest > logs/20240423-114133-HiFive1-IcountTest.log
   InstantChangePc > logs/20240423-114143-HiFive1-InstantChangePc.log
   InstantHaltTest > logs/20240423-114153-HiFive1-InstantHaltTest.log
   SimpleS0Test > logs/20240423-114456-HiFive1-SimpleS0Test.log

This is not a proposed fix but simply an experimentation.

Could there have been some change along the way that nullified some sort of implicit or explicit reset and thus caused problems with the tests?

As I've said before though, at a high level it would seem logical to me that a test suite would ensure up front for each test that the target is in a known good state - and, for example, not in an anomalous state from a previous test or previous use - to ensure that the test is running from a clean slate. I don't know why none of the tests seem to do this.

@TommyMurphyTM1234
Copy link
Collaborator Author

TommyMurphyTM1234 commented Apr 23, 2024

@TommyMurphyTM1234, I would also suggest to uncomment the line you have mentioned to reset the target (https://github.com/riscv-software-src/riscv-tests/blob/6b1d7372d951ed75811e0a09c0fe9e065c141c2d/debug/targets/SiFive/HiFive1.cfg#L29).

I will try that but my recollection is that I did before and it didn't improve matters.

Edit: yes - if I uncomment the reset command here:

then even the CheckMisa test fails:

./gdbserver.py targets/SiFive/HiFive1.py CheckMisa DebugBreakpoint
PRNG seed for HiFive1 is generated automatically
PRNG seed for HiFive1 is 1713869497
Using $misa from hart definition: 0x40001105
[CheckMisa] Starting > logs/20240423-115137-HiFive1-CheckMisa.log
[CheckMisa] exception in 1.74s
[DebugBreakpoint] Starting > logs/20240423-115139-HiFive1-DebugBreakpoint.log
[DebugBreakpoint] exception in 3.34s
::::::::::::::::::::::::::::[ ran 2 tests in 5s ]:::::::::::::::::::::::::::::
2 tests returned exception
   CheckMisa > logs/20240423-115137-HiFive1-CheckMisa.log
   DebugBreakpoint > logs/20240423-115139-HiFive1-DebugBreakpoint.log

Only if I do reset init after the program load does it seem to help - I checked this in both GDB and via the OpenOCD Telnet command interface.

@TommyMurphyTM1234
Copy link
Collaborator Author

@TommyMurphyTM1234, @MarekVCodasip, I would suggest to proceed by running ./gdbserver.py targets/SiFive/HiFive1.py CheckMisa DebugBreakpoint --server_cmd "openocd -d3" on the following configurations:

  1. 28f630d (the parent of 3f1339f, which is known-bad, at least due to Fails connecting to SiFive HiFive1 A01 - Failed to read vsatp register #996). This will hopefully result in a most recent known-good log we can compare against.
openocd -v
Open On-Chip Debugger 0.12.0+dev-03115-g28f630d24 (2024-04-23-12:23)
Licensed under GNU GPL v2
For bug reports, read
	http://openocd.org/doc/doxygen/bugs.html

./gdbserver.py targets/SiFive/HiFive1.py CheckMisa DebugBreakpoint --server_cmd "openocd -d3"
PRNG seed for HiFive1 is generated automatically
PRNG seed for HiFive1 is 1713871840
Using $misa from hart definition: 0x40001105
[CheckMisa] Starting > logs/20240423-123040-HiFive1-CheckMisa.log
[CheckMisa] pass in 1.78s
[DebugBreakpoint] Starting > logs/20240423-123042-HiFive1-DebugBreakpoint.log
[DebugBreakpoint] pass in 5.93s
::::::::::::::::::::::::::::[ ran 2 tests in 8s ]:::::::::::::::::::::::::::::
2 tests returned pass
  1. 3f1339f with ca3abca on top of it. This will allow to check if ca3abca really fixes Fails connecting to SiFive HiFive1 A01 - Failed to read vsatp register #996.
openocd -v
Open On-Chip Debugger 0.12.0+dev-03116-g3f1339f8e-dirty (2024-04-23-12:06)
Licensed under GNU GPL v2
For bug reports, read
	http://openocd.org/doc/doxygen/bugs.html

./gdbserver.py targets/SiFive/HiFive1.py CheckMisa DebugBreakpoint --server_cmd "openocd -d3"
PRNG seed for HiFive1 is generated automatically
PRNG seed for HiFive1 is 1713870850
Using $misa from hart definition: 0x40001105
[CheckMisa] Starting > logs/20240423-121410-HiFive1-CheckMisa.log
[CheckMisa] pass in 2.36s
[DebugBreakpoint] Starting > logs/20240423-121413-HiFive1-DebugBreakpoint.log
[DebugBreakpoint] exception in 45.45s
::::::::::::::::::::::::::::[ ran 2 tests in 48s ]::::::::::::::::::::::::::::
1 tests returned pass
1 tests returned exception
   DebugBreakpoint > logs/20240423-121413-HiFive1-DebugBreakpoint.log

@en-sc
Copy link
Collaborator

en-sc commented Apr 23, 2024

Could there have been some change along the way that nullified some sort of implicit or explicit reset and thus caused problems with the tests?

Thanks! I will look into this, though I don't remember such changes from the top of my head.

As I've said before though, at a high level it would seem logical to me that a test suite would ensure up front for each test that the target is in a known good state - and, for example, not in an anomalous state from a previous test or previous use - to ensure that the test is running from a clean slate. I don't know why none of the tests seem to do this.

This is true. However, the current behavior allows to check that the target is left in a consistent state after a disconnect, so I'm not sure this should be done without considerable extension to testsuite intended to cover such cases.

@aap-sc
Copy link
Collaborator

aap-sc commented Apr 23, 2024

@TommyMurphyTM1234 thanks for the logs. I think these should help.

A little off topic, If you will, while we are on it - a few notes regarding the reset init that you use. It's usage is questionable. Here is how the initialization script looks like for HiFive1:

adapter speed     10000

adapter driver ftdi
ftdi device_desc "Dual RS232-HS"
ftdi vid_pid 0x0403 0x6010

ftdi layout_init 0x0008 0x001b
ftdi layout_signal nSRST -oe 0x0020

# ...

set _CHIPNAME riscv
jtag newtap $_CHIPNAME cpu -irlen 5 -expected-id 0x10e31913

set _TARGETNAME $_CHIPNAME.cpu
target create $_TARGETNAME riscv -chain-position $_TARGETNAME
$_TARGETNAME configure -work-area-phys 0x80000000 -work-area-size 8096 -work-area-backup 1
#-rtos riscv

gdb_report_data_abort enable
gdb_report_register_access_error enable

# Expose an unimplemented CSR so we can test non-existent register access
# behavior.
riscv expose_csrs 2288

flash bank my_first_flash fespi 0x20000000 0 0 0 $_TARGETNAME
init
#reset
halt
flash protect 0 64 last off

echo "Ready for Remote Connections"

So the initialization script initializes flash memory, performs examine (via init), halts the target and then performs some flash magic (via flash protect).

  1. According to the documentation reset init should halt the target and then execute reset-init script. Since you don't have reset-init handler defined, I believe that your reset init command is equivalent to reset halt.
    This is unless fespi does not do some implicit magic that is (I'm not familiar with how OpenOCD interacts with flash)

  2. When you do the following sequence in GDB:

load
monitor reset init
continue

Strictly speaking this sequence is incorrect since after the reset command the execution starts from the reset vector which is not necessary the same as an entry point to the application.

  1. I'm not sure if we need to reprogram flash memory after the target is reset. It depends on the board documentation.

Just FYI.

@TommyMurphyTM1234
Copy link
Collaborator Author

TommyMurphyTM1234 commented Apr 23, 2024

I believe that your reset init command is equivalent to reset halt.

When I used reset halt I got different results than here - practically all tests failing as before:

This is unless fespi does not do some implicit magic that is (I'm not familiar with how OpenOCD interacts with flash)

I don't really understand this.

  1. When you do the following sequence in GDB:
load
monitor reset init
continue

Strictly speaking this sequence is incorrect since after the reset command the execution starts from the reset vector which is not necessary the same as an entry point to the application.

Maybe so but, in practice, the above sequence resulted in most or all of the test programs executing correctly from _start aka 0x80000000 in contrast to when reset init was not used. Without reset init the program immediately went off into the weeds in weird areas of memory even after a single instruction step.

Seems to me that the reset init does not change the pc from the value that was previously loaded via a GDB program load or an explicit write when using the OpenOCD Telnet interface. So execution starts from there (in this case _start/0x80000000).

As I mentioned above that was just an experiment and not a suggestion of any sort of fix but I thought that it might be relevant that things worked "better" with reset init compared to without when using OpenOCD builds more recent than e0dd44a - the last commit that can run the test suite successfully out of the box.

  1. I'm not sure if we need to reprogram flash memory after the target is reset. It depends on the board documentation.

Why would the RAM based tests (which were the ones that I was focusing on here) be doing anything at all with flash?
Other than perhaps target examination doing some sort of initialisation?

@aap-sc
Copy link
Collaborator

aap-sc commented Apr 23, 2024

When I used reset halt I got different results than here - practically all tests failing as before:

This is very strange.

I don't really understand this.

I mean flash bank my_first_flash fespi 0x20000000 0 0 0 $_TARGETNAME could in theory install some default reset-init handler, though I highly doubt that this is the case. I just don't know how these flash commands really work.

Seems to me that the reset init does not change the pc from the value that was previously loaded via a GDB program load or an explicit write when using the OpenOCD Telnet interface.

Well it should. It's either the reset vector on you board matches the entry point, or if you read the PC via GDB, you just read a cached copy.

Why would the RAM based tests (which were the ones that I was focusing on here) be doing anything at all with flash?

When we call reset OpenOCD performs ndm-based reset. Meaning the whole "platform" is reset (this is from the RISC-V Debug Spec). What constitutes the platform is implementation details.

@TommyMurphyTM1234
Copy link
Collaborator Author

OK - but I think that we can forget about the reset issues (which I've always found confusing in the OpenOCD context to be honest) for the moment here other than to note that with a build of OpenOCD at commit e0dd44a the test suite runs as expected but with a build of any subsequent commit it does not (althrough reset init seems to help).

From the various logs/data that I have collected so far I unfortunately have no clearer idea where the problem lies that casues the test suite to fail.

@en-sc
Copy link
Collaborator

en-sc commented Apr 23, 2024

@TommyMurphyTM1234, I think I have found the issue! Will post an explanation and a patch ASAP.

@en-sc
Copy link
Collaborator

en-sc commented Apr 23, 2024

So the other issue with 3f1339f is redirection from pc to dpc and how it interacts with riscv-011.c code.
The thing is, in riscv-011.c pc is cached in info->dpc, not in cahce, but accesses to DPC are not cached in info->dpc. When the redirection was introduced, it uncovered that issue.

@en-sc
Copy link
Collaborator

en-sc commented Apr 23, 2024

Should be addressed by #1054.
In particular:

  1. For versions before ea7e174 target/riscv/riscv-011: pc and dpc should be cached at the same location #1054 should be sufficient.
  2. For versions after ea7e174 target/riscv/riscv-011: pc and dpc should be cached at the same location #1054 should be applied with target/riscv/riscv-011.c: fix access to non-existent register #1046.

@TommyMurphyTM1234, could you please check the second configuration (TOT RISC-V OpenOCD + #1046 + #1054)?

@TommyMurphyTM1234
Copy link
Collaborator Author

Thanks a lot @en-sc.
I wasn't able to see the wood for the trees with all the logs and tests so if this is it it'll be great.
I'll be able to test later as I am offline from the pc at the moment.
🤞

@TommyMurphyTM1234
Copy link
Collaborator Author

  1. For versions after ea7e174 target/riscv/riscv-011: pc and dpc should be cached at the same location #1054 should be applied with target/riscv/riscv-011.c: fix access to non-existent register #1046.

@TommyMurphyTM1234, could you please check the second configuration (TOT RISC-V OpenOCD + #1046 + #1054)?

Thanks a lot @en-sc.
Here are the results of the latest run.

openocd -v
Open On-Chip Debugger 0.12.0+dev-03744-g3991492cc-dirty (2024-04-23-15:11)
Licensed under GNU GPL v2
For bug reports, read
	http://openocd.org/doc/doxygen/bugs.html
user@heron:~/Downloads/openocd-test/riscv-tests/debug$ 

./gdbserver.py targets/SiFive/HiFive1.py
PRNG seed for HiFive1 is generated automatically
PRNG seed for HiFive1 is 1713881825
Using $misa from hart definition: 0x40001105
[CeaseStepiTest] Starting > logs/20240423-151705-HiFive1-CeaseStepiTest.log
[CeaseStepiTest] not_applicable in 0.00s
[CheckMisa] Starting > logs/20240423-151705-HiFive1-CheckMisa.log
[CheckMisa] pass in 2.05s
[CustomRegisterTest] Starting > logs/20240423-151707-HiFive1-CustomRegisterTest.log
[CustomRegisterTest] not_applicable in 0.00s
[DebugBreakpoint] Starting > logs/20240423-151707-HiFive1-DebugBreakpoint.log
[DebugBreakpoint] pass in 5.87s
[DebugChangeString] Starting > logs/20240423-151713-HiFive1-DebugChangeString.log
[DebugChangeString] pass in 5.57s
[DebugCompareSections] Starting > logs/20240423-151718-HiFive1-DebugCompareSections.log
[DebugCompareSections] pass in 4.21s
[DebugExit] Starting > logs/20240423-151723-HiFive1-DebugExit.log
[DebugExit] pass in 3.89s
[DebugFunctionCall] Starting > logs/20240423-151726-HiFive1-DebugFunctionCall.log
[DebugFunctionCall] pass in 6.24s
[DebugSymbols] Starting > logs/20240423-151733-HiFive1-DebugSymbols.log
[DebugSymbols] pass in 5.16s
[DebugTurbostep] Starting > logs/20240423-151738-HiFive1-DebugTurbostep.log
[DebugTurbostep] pass in 9.58s
[DisconnectTest] Starting > logs/20240423-151747-HiFive1-DisconnectTest.log
[DisconnectTest] fail in 12.83s
[DownloadTest] Starting > logs/20240423-151800-HiFive1-DownloadTest.log
[DownloadTest] pass in 4.92s
[EbreakTest] Starting > logs/20240423-151805-HiFive1-EbreakTest.log
[EbreakTest] pass in 6.54s
[EtriggerTest] Starting > logs/20240423-151812-HiFive1-EtriggerTest.log
[EtriggerTest] fail in 11.11s
[FreeRtosTest] Starting > logs/20240423-151823-HiFive1-FreeRtosTest.log
[FreeRtosTest] not_applicable in 0.00s
[Hwbp1] Starting > logs/20240423-151823-HiFive1-Hwbp1.log
[Hwbp1] pass in 5.78s
[Hwbp2] Starting > logs/20240423-151829-HiFive1-Hwbp2.log
[Hwbp2] pass in 7.30s
[HwbpManual] Starting > logs/20240423-151836-HiFive1-HwbpManual.log
[HwbpManual] not_applicable in 5.48s
[IcountTest] Starting > logs/20240423-151841-HiFive1-IcountTest.log
[IcountTest] fail in 7.98s
[InfoTest] Starting > logs/20240423-151849-HiFive1-InfoTest.log
[InfoTest] pass in 1.99s
[InstantChangePc] Starting > logs/20240423-151851-HiFive1-InstantChangePc.log
[InstantChangePc] pass in 7.16s
[InstantHaltTest] Starting > logs/20240423-151858-HiFive1-InstantHaltTest.log
[InstantHaltTest] fail in 6.11s
[InterruptTest] Starting > logs/20240423-151905-HiFive1-InterruptTest.log
[InterruptTest] pass in 15.27s
[ItriggerTest] Starting > logs/20240423-151920-HiFive1-ItriggerTest.log
[ItriggerTest] exception in 47.52s
[JumpHbreak] Starting > logs/20240423-152007-HiFive1-JumpHbreak.log
[JumpHbreak] pass in 4.87s
[MemTest16] Starting > logs/20240423-152012-HiFive1-MemTest16.log
[MemTest16] pass in 3.67s
[MemTest32] Starting > logs/20240423-152016-HiFive1-MemTest32.log
[MemTest32] pass in 3.87s
[MemTest64] Starting > logs/20240423-152020-HiFive1-MemTest64.log
[MemTest64] pass in 3.57s
[MemTest8] Starting > logs/20240423-152023-HiFive1-MemTest8.log
[MemTest8] pass in 3.81s
[MemTestBlock0] Starting > logs/20240423-152027-HiFive1-MemTestBlock0.log
[MemTestBlock0] pass in 4.76s
[MemTestBlock1] Starting > logs/20240423-152032-HiFive1-MemTestBlock1.log
[MemTestBlock1] pass in 4.51s
[MemTestBlock2] Starting > logs/20240423-152036-HiFive1-MemTestBlock2.log
[MemTestBlock2] pass in 4.76s
[MemTestBlockReadInvalid] Starting > logs/20240423-152041-HiFive1-MemTestBlockReadInvalid.log
[MemTestBlockReadInvalid] not_applicable in 0.00s
[MemTestReadInvalid] Starting > logs/20240423-152041-HiFive1-MemTestReadInvalid.log
[MemTestReadInvalid] exception in 9.19s
[MemorySampleMixed] Starting > logs/20240423-152050-HiFive1-MemorySampleMixed.log
[MemorySampleMixed] exception in 14.20s
[MemorySampleSingle] Starting > logs/20240423-152105-HiFive1-MemorySampleSingle.log
[MemorySampleSingle] exception in 13.49s
[MulticoreRegTest] Starting > logs/20240423-152118-HiFive1-MulticoreRegTest.log
[MulticoreRegTest] not_applicable in 0.00s
[MulticoreRtosSwitchActiveHartTest] Starting > logs/20240423-152118-HiFive1-MulticoreRtosSwitchActiveHartTest.log
[MulticoreRtosSwitchActiveHartTest] not_applicable in 0.00s
[MulticoreRunAllHaltOne] Starting > logs/20240423-152118-HiFive1-MulticoreRunAllHaltOne.log
[MulticoreRunAllHaltOne] not_applicable in 0.00s
[PrivChange] Starting > logs/20240423-152118-HiFive1-PrivChange.log
[PrivChange] not_applicable in 3.21s
[PrivRw] Starting > logs/20240423-152121-HiFive1-PrivRw.log
[PrivRw] pass in 6.84s
[ProgramHwWatchpoint] Starting > logs/20240423-152128-HiFive1-ProgramHwWatchpoint.log
[ProgramHwWatchpoint] pass in 9.06s
[ProgramSwWatchpoint] Starting > logs/20240423-152137-HiFive1-ProgramSwWatchpoint.log
[ProgramSwWatchpoint] pass in 12.61s
[Registers] Starting > logs/20240423-152150-HiFive1-Registers.log
[Registers] pass in 12.49s
[RepeatReadTest] Starting > logs/20240423-152202-HiFive1-RepeatReadTest.log
[RepeatReadTest] exception in 8.84s
[Semihosting] Starting > logs/20240423-152211-HiFive1-Semihosting.log
[Semihosting] fail in 8.95s
[SemihostingFileio] Starting > logs/20240423-152220-HiFive1-SemihostingFileio.log
[SemihostingFileio] fail in 8.19s
[SimpleF18Test] Starting > logs/20240423-152228-HiFive1-SimpleF18Test.log
[SimpleF18Test] pass in 4.93s
[SimpleNoExistTest] Starting > logs/20240423-152233-HiFive1-SimpleNoExistTest.log
[SimpleNoExistTest] pass in 1.85s
[SimpleS0Test] Starting > logs/20240423-152235-HiFive1-SimpleS0Test.log
[SimpleS0Test] pass in 9.83s
[SimpleS1Test] Starting > logs/20240423-152245-HiFive1-SimpleS1Test.log
[SimpleS1Test] pass in 9.92s
[SimpleT0Test] Starting > logs/20240423-152255-HiFive1-SimpleT0Test.log
[SimpleT0Test] pass in 10.81s
[SimpleT1Test] Starting > logs/20240423-152306-HiFive1-SimpleT1Test.log
[SimpleT1Test] pass in 9.54s
[SimpleV13Test] Starting > logs/20240423-152315-HiFive1-SimpleV13Test.log
[SimpleV13Test] pass in 6.03s
[SmpSimultaneousRunHalt] Starting > logs/20240423-152321-HiFive1-SmpSimultaneousRunHalt.log
[SmpSimultaneousRunHalt] not_applicable in 0.00s
[StepTest] Starting > logs/20240423-152321-HiFive1-StepTest.log
[StepTest] pass in 7.89s
[StepThread2Test] Starting > logs/20240423-152329-HiFive1-StepThread2Test.log
[StepThread2Test] not_applicable in 0.00s
[Sv32Test] Starting > logs/20240423-152329-HiFive1-Sv32Test.log
[Sv32Test] not_applicable in 0.00s
[Sv39Test] Starting > logs/20240423-152329-HiFive1-Sv39Test.log
[Sv39Test] not_applicable in 0.00s
[Sv48Test] Starting > logs/20240423-152329-HiFive1-Sv48Test.log
[Sv48Test] not_applicable in 0.00s
[TooManyHwbp] Starting > logs/20240423-152329-HiFive1-TooManyHwbp.log
[TooManyHwbp] pass in 10.59s
[TriggerDmode] Starting > logs/20240423-152340-HiFive1-TriggerDmode.log
[TriggerDmode] pass in 7.74s
[TriggerExecuteInstant] Starting > logs/20240423-152347-HiFive1-TriggerExecuteInstant.log
[TriggerExecuteInstant] pass in 5.58s
[TriggerLoadAddressInstant] Starting > logs/20240423-152353-HiFive1-TriggerLoadAddressInstant.log
[TriggerLoadAddressInstant] pass in 6.99s
[TriggerStoreAddressInstant] Starting > logs/20240423-152400-HiFive1-TriggerStoreAddressInstant.log
[TriggerStoreAddressInstant] pass in 5.55s
[UnavailableCycleTest] Starting > logs/20240423-152406-HiFive1-UnavailableCycleTest.log
[UnavailableCycleTest] not_applicable in 0.00s
[UnavailableHaltedTest] Starting > logs/20240423-152406-HiFive1-UnavailableHaltedTest.log
[UnavailableHaltedTest] not_applicable in 0.00s
[UnavailableMultiTest] Starting > logs/20240423-152406-HiFive1-UnavailableMultiTest.log
[UnavailableMultiTest] not_applicable in 0.00s
[UnavailableRunTest] Starting > logs/20240423-152406-HiFive1-UnavailableRunTest.log
[UnavailableRunTest] not_applicable in 0.00s
[UserInterrupt] Starting > logs/20240423-152406-HiFive1-UserInterrupt.log
[UserInterrupt] pass in 8.52s
[VectorTest] Starting > logs/20240423-152414-HiFive1-VectorTest.log
[VectorTest] not_applicable in 0.00s
[WriteCsrs] Starting > logs/20240423-152414-HiFive1-WriteCsrs.log
[WriteCsrs] pass in 6.11s
[WriteGprs] Starting > logs/20240423-152420-HiFive1-WriteGprs.log
[WriteGprs] pass in 14.04s
:::::::::::::::::::::::::::[ ran 73 tests in 449s ]:::::::::::::::::::::::::::
19 tests returned not_applicable
43 tests returned pass
6 tests returned fail
   DisconnectTest > logs/20240423-151747-HiFive1-DisconnectTest.log
   EtriggerTest > logs/20240423-151812-HiFive1-EtriggerTest.log
   IcountTest > logs/20240423-151841-HiFive1-IcountTest.log
   InstantHaltTest > logs/20240423-151858-HiFive1-InstantHaltTest.log
   Semihosting > logs/20240423-152211-HiFive1-Semihosting.log
   SemihostingFileio > logs/20240423-152220-HiFive1-SemihostingFileio.log
5 tests returned exception
   ItriggerTest > logs/20240423-151920-HiFive1-ItriggerTest.log
   MemTestReadInvalid > logs/20240423-152041-HiFive1-MemTestReadInvalid.log
   MemorySampleMixed > logs/20240423-152050-HiFive1-MemorySampleMixed.log
   MemorySampleSingle > logs/20240423-152105-HiFive1-MemorySampleSingle.log
   RepeatReadTest > logs/20240423-152202-HiFive1-RepeatReadTest.log

./gdbserver.py targets/SiFive/HiFive1-flash.py
PRNG seed for HiFive1Flash is generated automatically
PRNG seed for HiFive1Flash is 1713882305
Using $misa from hart definition: 0x40001105
[CeaseStepiTest] Starting > logs/20240423-152505-HiFive1Flash-CeaseStepiTest.log
[CeaseStepiTest] not_applicable in 0.00s
[CheckMisa] Starting > logs/20240423-152505-HiFive1Flash-CheckMisa.log
[CheckMisa] pass in 2.10s
[CustomRegisterTest] Starting > logs/20240423-152507-HiFive1Flash-CustomRegisterTest.log
[CustomRegisterTest] not_applicable in 0.00s
[DebugBreakpoint] Starting > logs/20240423-152507-HiFive1Flash-DebugBreakpoint.log
[DebugBreakpoint] exception in 49.80s
[DebugChangeString] Starting > logs/20240423-152557-HiFive1Flash-DebugChangeString.log
[DebugChangeString] pass in 7.28s
[DebugCompareSections] Starting > logs/20240423-152604-HiFive1Flash-DebugCompareSections.log
[DebugCompareSections] pass in 5.80s
[DebugExit] Starting > logs/20240423-152610-HiFive1Flash-DebugExit.log
[DebugExit] exception in 48.24s
[DebugFunctionCall] Starting > logs/20240423-152658-HiFive1Flash-DebugFunctionCall.log
Exception ignored in: <function _TemporaryFileCloser.__del__ at 0x7dc531f4d630>
Traceback (most recent call last):
  File "/usr/lib/python3.10/tempfile.py", line 589, in __del__
    self.close()
  File "/usr/lib/python3.10/tempfile.py", line 585, in close
    unlink(self.name)
FileNotFoundError: [Errno 2] No such file or directory: '/tmp/[email protected]'
[DebugFunctionCall] exception in 51.17s
[DebugSymbols] Starting > logs/20240423-152749-HiFive1Flash-DebugSymbols.log
[DebugSymbols] pass in 6.23s
[DebugTurbostep] Starting > logs/20240423-152756-HiFive1Flash-DebugTurbostep.log
[DebugTurbostep] pass in 12.96s
[DisconnectTest] Starting > logs/20240423-152809-HiFive1Flash-DisconnectTest.log
[DisconnectTest] fail in 12.63s
[DownloadTest] Starting > logs/20240423-152821-HiFive1Flash-DownloadTest.log
[DownloadTest] pass in 6.45s
[EbreakTest] Starting > logs/20240423-152828-HiFive1Flash-EbreakTest.log
[EbreakTest] pass in 7.46s
[EtriggerTest] Starting > logs/20240423-152835-HiFive1Flash-EtriggerTest.log
[EtriggerTest] exception in 10.25s
[FreeRtosTest] Starting > logs/20240423-152845-HiFive1Flash-FreeRtosTest.log
[FreeRtosTest] not_applicable in 0.00s
[Hwbp1] Starting > logs/20240423-152845-HiFive1Flash-Hwbp1.log
[Hwbp1] exception in 49.15s
[Hwbp2] Starting > logs/20240423-152934-HiFive1Flash-Hwbp2.log
[Hwbp2] exception in 50.14s
[HwbpManual] Starting > logs/20240423-153025-HiFive1Flash-HwbpManual.log
[HwbpManual] not_applicable in 5.66s
[IcountTest] Starting > logs/20240423-153030-HiFive1Flash-IcountTest.log
[IcountTest] fail in 8.81s
[InfoTest] Starting > logs/20240423-153039-HiFive1Flash-InfoTest.log
[InfoTest] pass in 1.89s
[InstantChangePc] Starting > logs/20240423-153041-HiFive1Flash-InstantChangePc.log
[InstantChangePc] pass in 6.63s
[InstantHaltTest] Starting > logs/20240423-153048-HiFive1Flash-InstantHaltTest.log
[InstantHaltTest] fail in 6.70s
[InterruptTest] Starting > logs/20240423-153054-HiFive1Flash-InterruptTest.log
[InterruptTest] pass in 16.09s
[ItriggerTest] Starting > logs/20240423-153110-HiFive1Flash-ItriggerTest.log
[ItriggerTest] exception in 48.81s
[JumpHbreak] Starting > logs/20240423-153159-HiFive1Flash-JumpHbreak.log
[JumpHbreak] pass in 7.02s
[MemTest16] Starting > logs/20240423-153206-HiFive1Flash-MemTest16.log
[MemTest16] pass in 3.99s
[MemTest32] Starting > logs/20240423-153210-HiFive1Flash-MemTest32.log
[MemTest32] pass in 3.75s
[MemTest64] Starting > logs/20240423-153214-HiFive1Flash-MemTest64.log
[MemTest64] pass in 3.82s
[MemTest8] Starting > logs/20240423-153218-HiFive1Flash-MemTest8.log
[MemTest8] pass in 4.21s
[MemTestBlock0] Starting > logs/20240423-153222-HiFive1Flash-MemTestBlock0.log
[MemTestBlock0] pass in 5.42s
[MemTestBlock1] Starting > logs/20240423-153227-HiFive1Flash-MemTestBlock1.log
[MemTestBlock1] pass in 5.32s
[MemTestBlock2] Starting > logs/20240423-153233-HiFive1Flash-MemTestBlock2.log
[MemTestBlock2] pass in 5.15s
[MemTestBlockReadInvalid] Starting > logs/20240423-153238-HiFive1Flash-MemTestBlockReadInvalid.log
[MemTestBlockReadInvalid] not_applicable in 0.00s
[MemTestReadInvalid] Starting > logs/20240423-153238-HiFive1Flash-MemTestReadInvalid.log
[MemTestReadInvalid] exception in 9.76s
[MemorySampleMixed] Starting > logs/20240423-153248-HiFive1Flash-MemorySampleMixed.log
[MemorySampleMixed] exception in 15.02s
[MemorySampleSingle] Starting > logs/20240423-153303-HiFive1Flash-MemorySampleSingle.log
[MemorySampleSingle] exception in 15.54s
[MulticoreRegTest] Starting > logs/20240423-153318-HiFive1Flash-MulticoreRegTest.log
[MulticoreRegTest] not_applicable in 0.00s
[MulticoreRtosSwitchActiveHartTest] Starting > logs/20240423-153318-HiFive1Flash-MulticoreRtosSwitchActiveHartTest.log
[MulticoreRtosSwitchActiveHartTest] not_applicable in 0.00s
[MulticoreRunAllHaltOne] Starting > logs/20240423-153318-HiFive1Flash-MulticoreRunAllHaltOne.log
[MulticoreRunAllHaltOne] not_applicable in 0.00s
[PrivChange] Starting > logs/20240423-153318-HiFive1Flash-PrivChange.log
[PrivChange] not_applicable in 3.60s
[PrivRw] Starting > logs/20240423-153322-HiFive1Flash-PrivRw.log
[PrivRw] pass in 7.22s
[ProgramHwWatchpoint] Starting > logs/20240423-153329-HiFive1Flash-ProgramHwWatchpoint.log
[ProgramHwWatchpoint] pass in 9.78s
[ProgramSwWatchpoint] Starting > logs/20240423-153339-HiFive1Flash-ProgramSwWatchpoint.log
[ProgramSwWatchpoint] pass in 14.63s
[Registers] Starting > logs/20240423-153354-HiFive1Flash-Registers.log
[Registers] exception in 49.64s
[RepeatReadTest] Starting > logs/20240423-153443-HiFive1Flash-RepeatReadTest.log
[RepeatReadTest] exception in 9.61s
[Semihosting] Starting > logs/20240423-153453-HiFive1Flash-Semihosting.log
[Semihosting] fail in 11.47s
[SemihostingFileio] Starting > logs/20240423-153504-HiFive1Flash-SemihostingFileio.log
[SemihostingFileio] fail in 10.40s
[SimpleF18Test] Starting > logs/20240423-153515-HiFive1Flash-SimpleF18Test.log
[SimpleF18Test] pass in 5.82s
[SimpleNoExistTest] Starting > logs/20240423-153521-HiFive1Flash-SimpleNoExistTest.log
[SimpleNoExistTest] pass in 2.18s
[SimpleS0Test] Starting > logs/20240423-153523-HiFive1Flash-SimpleS0Test.log
[SimpleS0Test] pass in 10.63s
[SimpleS1Test] Starting > logs/20240423-153533-HiFive1Flash-SimpleS1Test.log
[SimpleS1Test] pass in 10.90s
[SimpleT0Test] Starting > logs/20240423-153544-HiFive1Flash-SimpleT0Test.log
[SimpleT0Test] pass in 9.95s
[SimpleT1Test] Starting > logs/20240423-153554-HiFive1Flash-SimpleT1Test.log
[SimpleT1Test] pass in 10.12s
[SimpleV13Test] Starting > logs/20240423-153604-HiFive1Flash-SimpleV13Test.log
[SimpleV13Test] pass in 6.13s
[SmpSimultaneousRunHalt] Starting > logs/20240423-153610-HiFive1Flash-SmpSimultaneousRunHalt.log
[SmpSimultaneousRunHalt] not_applicable in 0.00s
[StepTest] Starting > logs/20240423-153610-HiFive1Flash-StepTest.log
[StepTest] pass in 11.10s
[StepThread2Test] Starting > logs/20240423-153622-HiFive1Flash-StepThread2Test.log
[StepThread2Test] not_applicable in 0.00s
[Sv32Test] Starting > logs/20240423-153622-HiFive1Flash-Sv32Test.log
[Sv32Test] not_applicable in 0.00s
[Sv39Test] Starting > logs/20240423-153622-HiFive1Flash-Sv39Test.log
[Sv39Test] not_applicable in 0.00s
[Sv48Test] Starting > logs/20240423-153622-HiFive1Flash-Sv48Test.log
[Sv48Test] not_applicable in 0.00s
[TooManyHwbp] Starting > logs/20240423-153622-HiFive1Flash-TooManyHwbp.log
[TooManyHwbp] exception in 57.14s
[TriggerDmode] Starting > logs/20240423-153719-HiFive1Flash-TriggerDmode.log
[TriggerDmode] pass in 10.11s
[TriggerExecuteInstant] Starting > logs/20240423-153729-HiFive1Flash-TriggerExecuteInstant.log
[TriggerExecuteInstant] pass in 6.21s
[TriggerLoadAddressInstant] Starting > logs/20240423-153735-HiFive1Flash-TriggerLoadAddressInstant.log
[TriggerLoadAddressInstant] pass in 7.10s
[TriggerStoreAddressInstant] Starting > logs/20240423-153742-HiFive1Flash-TriggerStoreAddressInstant.log
[TriggerStoreAddressInstant] pass in 6.57s
[UnavailableCycleTest] Starting > logs/20240423-153749-HiFive1Flash-UnavailableCycleTest.log
[UnavailableCycleTest] not_applicable in 0.00s
[UnavailableHaltedTest] Starting > logs/20240423-153749-HiFive1Flash-UnavailableHaltedTest.log
[UnavailableHaltedTest] not_applicable in 0.00s
[UnavailableMultiTest] Starting > logs/20240423-153749-HiFive1Flash-UnavailableMultiTest.log
[UnavailableMultiTest] not_applicable in 0.00s
[UnavailableRunTest] Starting > logs/20240423-153749-HiFive1Flash-UnavailableRunTest.log
[UnavailableRunTest] not_applicable in 0.00s
[UserInterrupt] Starting > logs/20240423-153749-HiFive1Flash-UserInterrupt.log
[UserInterrupt] exception in 52.70s
[VectorTest] Starting > logs/20240423-153841-HiFive1Flash-VectorTest.log
[VectorTest] not_applicable in 0.00s
[WriteCsrs] Starting > logs/20240423-153841-HiFive1Flash-WriteCsrs.log
[WriteCsrs] pass in 9.17s
[WriteGprs] Starting > logs/20240423-153851-HiFive1Flash-WriteGprs.log
[WriteGprs] pass in 16.36s
:::::::::::::::::::::::::::[ ran 73 tests in 842s ]:::::::::::::::::::::::::::
19 tests returned not_applicable
35 tests returned pass
14 tests returned exception
   DebugBreakpoint > logs/20240423-152507-HiFive1Flash-DebugBreakpoint.log
   DebugExit > logs/20240423-152610-HiFive1Flash-DebugExit.log
   DebugFunctionCall > logs/20240423-152658-HiFive1Flash-DebugFunctionCall.log
   EtriggerTest > logs/20240423-152835-HiFive1Flash-EtriggerTest.log
   Hwbp1 > logs/20240423-152845-HiFive1Flash-Hwbp1.log
   Hwbp2 > logs/20240423-152934-HiFive1Flash-Hwbp2.log
   ItriggerTest > logs/20240423-153110-HiFive1Flash-ItriggerTest.log
   MemTestReadInvalid > logs/20240423-153238-HiFive1Flash-MemTestReadInvalid.log
   MemorySampleMixed > logs/20240423-153248-HiFive1Flash-MemorySampleMixed.log
   MemorySampleSingle > logs/20240423-153303-HiFive1Flash-MemorySampleSingle.log
   Registers > logs/20240423-153354-HiFive1Flash-Registers.log
   RepeatReadTest > logs/20240423-153443-HiFive1Flash-RepeatReadTest.log
   TooManyHwbp > logs/20240423-153622-HiFive1Flash-TooManyHwbp.log
   UserInterrupt > logs/20240423-153749-HiFive1Flash-UserInterrupt.log
5 tests returned fail
   DisconnectTest > logs/20240423-152809-HiFive1Flash-DisconnectTest.log
   IcountTest > logs/20240423-153030-HiFive1Flash-IcountTest.log
   InstantHaltTest > logs/20240423-153048-HiFive1Flash-InstantHaltTest.log
   Semihosting > logs/20240423-153453-HiFive1Flash-Semihosting.log
   SemihostingFileio > logs/20240423-153504-HiFive1Flash-SemihostingFileio.log

This looks a lot better although the results don't completely tally with expected fail/exception cases as currently detailed in the HiFive1 exclusion file (which itself I need to review):

# Below are known failing tests on riscv-openocd on HiFive1 board, rev. A01.
# This board uses the legacy debug spec v 0.11.

# Tested on Jun-26-2023.
# riscv-openocd commit: a45589d60aa6864475fddcded885c8ff47d50be1
# riscv-tests commit: 7b52ba3b7167acb4d8b38f4d4633112b4699cb26

all:
  - EtriggerTest
  - IcountTest
  - InstantHaltTest
  - ItriggerTest
  - MemorySampleMixed
  - MemorySampleSingle
  - MemTestReadInvalid
  - RepeatReadTest
  - Semihosting
  - SemihostingFileio

HiFive1Flash:
  - DebugBreakpoint
  - DebugExit
  - DebugFunctionCall
  - Hwbp1
  - Hwbp2
  - Registers
  - TooManyHwbp
  - UserInterrupt

And I don't know why that Python error cropped up.
However I will look at this and the results in more detail but I think that the main problem with OpenOCD causing test suite failures against the HiFive1 board (and mayvbe any 0.11 spec target) have been resolved by your patches.

Thanks a lot - I would have struggled to identify the root cause myself. 👍

@TommyMurphyTM1234
Copy link
Collaborator Author

TommyMurphyTM1234 commented Apr 23, 2024

Just for completeness ... the following tests are unexpected failures/exceptions with respect to the current exclusions file:

  • RAM
    • DisconnectTest
    • DownloadTest (Edit: actually this looks like a sporadic/intermittent failure for some reason)
  • Flash
    • DisconnectTest

I will look into these and maybe compare the logs against the previous known good OpenOCD at commit e0dd44a to try to diagnose them in case there is still some other OpenOCD issue at play here.

But I think that this issue can be marked fixed by these PRs once merged:

@TommyMurphyTM1234
Copy link
Collaborator Author

TommyMurphyTM1234 commented Apr 24, 2024

Quick update ... it looks to me like the DisconnectTest is failing due to some register caching problem that initially results in menvcfg failing to be read (correctly, I think, since it's presumably not implemented on the M only mode FE310-G000 RISC-V?) but on a subsequent read getting the value of another CSR and then the test's check that the old and new register values are the same failing.

Perhaps this merits its own issue but I'll post further diagnostic info here for now in a bit.

Edit: ok - I split this out into a separate issue:

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants