riscv-collab / riscv-openocd

Fork of OpenOCD that has RISC-V support
Other
454 stars 327 forks source link

Fails connecting to SiFive HiFive1 A01 - `Failed to read vsatp register` #996

Closed TommyMurphyTM1234 closed 10 months ago

TommyMurphyTM1234 commented 10 months ago

Anybody got any ideas about this?

I was successfully using an OpenOCD build a while ago to run the tests against the SiFive HiFive1 Rev A01:

But having built OpenOCD afresh from the repo I now get this:

openocd -f board/sifive-hifive1.cfg
Open On-Chip Debugger 0.12.0+dev-03592-g4fc0d86ff (2024-01-17-09:52)
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
Warn : Got exception 0xffffffff when reading vsatp
Error: [riscv.cpu] Failed to read vsatp register; priv=0x7
Error: [riscv.cpu] Address translation failed.
Error: fespi_write_reg() error writing 0x1 to 0x10014050
Error: auto_probe failed

I tried using riscv set_enable_virtual off but that made no difference.

Here is the verbose openocd -d3 log: openocd.log

en-sc commented 10 months ago

I tried using riscv set_enable_virtual off but that made no difference.

If I'm correct riscv set_enable_virt2phys off should help.

en-sc commented 10 months ago

Caused by this change: https://github.com/riscv/riscv-openocd/commit/57c3f0d91c88b72c6f7bcaa5550d180e944fc371#diff-b4aa16f9e42cb8f0934baa7c8e0ec9c70a369bef98b99b26ae2e896c8aa95d6aL2484-R2495

TommyMurphyTM1234 commented 10 months ago

I tried using riscv set_enable_virtual off but that made no difference.

If I'm correct riscv set_enable_virt2phys off should help.

Ok - it only seems to work if inserted into the board/sifive-hifive1.cfg script:

# SPDX-License-Identifier: GPL-2.0-or-later

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 -data 0x0020

#Reset Stretcher logic on FE310 is ~1 second long
#This doesn't apply if you use
# ftdi set_signal, but still good to document
#adapter srst delay 1500

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 10000 -work-area-backup 1

riscv set_enable_virt2phys off

flash bank onboard_spi_flash fespi 0x20000000 0 0 0 $_TARGETNAME
init
#reset -- This type of reset is not implemented yet
if {[ info exists pulse_srst]} {
  ftdi set_signal nSRST 0
  ftdi set_signal nSRST z
  #Wait for the reset stretcher
  #It will work without this, but
  #will incur lots of delays for later commands.
  sleep 1500
}
halt
flash protect 0 64 last off

It doesn't work if passed from the command line.

./openocd -c "riscv set_enable_virt2phys off" -f board/sifive-hifive1.cfg
Open On-Chip Debugger 0.12.0+dev-03592-g4fc0d86ff (2024-01-17-10:52)
Licensed under GNU GPL v2
For bug reports, read
    http://openocd.org/doc/doxygen/bugs.html
invalid command name "riscv"
./openocd -f board/sifive-hifive1.cfg -c "riscv set_enable_virt2phys off"
Open On-Chip Debugger 0.12.0+dev-03592-g4fc0d86ff (2024-01-17-10:52)
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
Warn : Got exception 0xffffffff when reading vsatp
Error: [riscv.cpu] Failed to read vsatp register; priv=0x7
Error: [riscv.cpu] Address translation failed.
Error: fespi_write_reg() error writing 0x1 to 0x10014050
Error: auto_probe failed

Is this expected? Should the boards/sifive-hifive1*.cfg scripts (and others?) be changed to add this command?

TommyMurphyTM1234 commented 10 months ago

Caused by this change: 57c3f0d#diff-b4aa16f9e42cb8f0934baa7c8e0ec9c70a369bef98b99b26ae2e896c8aa95d6aL2484-R2495

Thanks @en-sc - I was looking at that but hadn't figured out if it was the root cause. So is there an issue with that PR that needs to be addressed or should it simply have also updated any relevant board scripts? Should the GitHub CI/CT actions have caught this?

en-sc commented 10 months ago

./openocd -c "riscv set_enable_virt2phys off" -f board/sifive-hifive1.cfg

This line does not work since the target-type-specific commands are registered only after the target is created. Please, try: ./openocd -f board/sifive-hifive1.cfg -c "riscv set_enable_virt2phys off"

Is this expected? Should the boards/sifive-hifive1*.cfg scripts (and others?) be changed to add this command?

I don't think this is expected. As for the solution, I believe we should not change the scripts. It seems strange that the translation is attempted when riscv set_enable_virtual off (which is the default). To be honest I'm a bit confused about the difference between enable_virtual and enable_virt2phys.

TommyMurphyTM1234 commented 10 months ago

./openocd -c "riscv set_enable_virt2phys off" -f board/sifive-hifive1.cfg

This line does not work since the target-type-specific commands are registered only after the target is created. Please, try: ./openocd -f board/sifive-hifive1.cfg -c "riscv set_enable_virt2phys off"

I already stated that this doesn't work either.

I don't think this is expected. As for the solution, I believe we should not change the scripts. It seems strange that the translation is attempted when riscv set_enable_virtual off (which is the default). To be honest I'm a bit confused about the difference between enable_virtual and enable_virt2phys.

Me too!

TommyMurphyTM1234 commented 10 months ago

It seems strange that the translation is attempted when riscv set_enable_virtual off (which is the default).

Is it?

en-sc commented 10 months ago

I already stated that this doesn't work either.

Oh, sorry for my sloppy reading.

Should the GitHub CI/CT actions have caught this?

They should, in the ideal world. For now the range of Spike configuration used is very limited (e.g. none of set_enable_virtual or set_enable_virt2phys are specified to anything other then default on any of the Spike targets in riscv-tests/debug). Though, this is a general problem -- and I'm not sure what is the best way to solve it.

TommyMurphyTM1234 commented 10 months ago

They should, in the ideal world. For now the range of Spike configuration used is very limited (e.g. none of set_enable_virtual or set_enable_virt2phys are specified to anything other then default on any of the Spike targets in riscv-tests/debug). Though, this is a general problem -- and I'm not sure what is the best way to solve it.

OK - I just thought that the CI did a test of Spike simulated HiFive1 (or equivalent RV32 with no MMU) as standard.

en-sc commented 10 months ago

It seems strange that the translation is attempted when riscv set_enable_virtual off (which is the default).

Is it?

Yes, it is. set_enable_virtual changes the value of riscv_enable_virtual https://github.com/riscv/riscv-openocd/blob/4fc0d86ff0c5ac45058777c9f0e5c53d3d17d7f9/src/target/riscv/riscv.c#L3442 And it is zero-initialized: https://github.com/riscv/riscv-openocd/blob/4fc0d86ff0c5ac45058777c9f0e5c53d3d17d7f9/src/target/riscv/riscv.c#L147

TommyMurphyTM1234 commented 10 months ago

It seems strange that the translation is attempted when riscv set_enable_virtual off (which is the default).

Is it?

Yes, it is. set_enable_virtual changes the value of riscv_enable_virtual

https://github.com/riscv/riscv-openocd/blob/4fc0d86ff0c5ac45058777c9f0e5c53d3d17d7f9/src/target/riscv/riscv.c#L3442

And it is zero-initialized: https://github.com/riscv/riscv-openocd/blob/4fc0d86ff0c5ac45058777c9f0e5c53d3d17d7f9/src/target/riscv/riscv.c#L147

Sorry - I was confusing riscv_enable_virtual and riscv_enable_virt2phys.

en-sc commented 10 months ago

OK - I just thought that the CI did a test of Spike simulated HiFive1 (or equivalent RV32 with no MMU) as standard.

Not sure it's possible. If I'm correct, Spike always supports user and supervisor modes, at least running:

spike ... --isa=rv32I ...

Results in misa value:

> reg misa
misa (/32): 0x40140100

(I, S, U are set)

TommyMurphyTM1234 commented 10 months ago

As far as I can see riscv_enable_virtual is not used at all for 0.11 (e.g. SiFive HiFive1) targets. It only appears here in riscv.c and not at all in riscv-011.c so it doesn't actually control any logic in this case:

And because riscv_enable_virt2phys defaults to true:

we get past this:

and eventually try to read vsatp which results in the connection failure.

I don't know if checks such as these are expected to prevent this happening with a 0.11 target and, if so, why they don't?

TommyMurphyTM1234 commented 10 months ago

Does the code need to be better understood to figure out why this issue arises with 0.11 targets and why riscv-mmu() doesn't bail out sooner?

Or is it sufficient to just change the relevant board scripts to have them explicitly call riscv set_enable_virt2phys off?

If the latter then which scripts? Presumably these two board scripts?

But what about the other RISC-V board scripts?

Or should the change (also?) be applied to some of the relevant RISC-V target scripts?

TommyMurphyTM1234 commented 10 months ago

Or is it sufficient to just change the relevant board scripts to have them explicitly call riscv set_enable_virt2phys off?

If the latter then which scripts? Presumably these two board scripts?

I just noticed that this one already has this:

And has had since it was created/added:

TommyMurphyTM1234 commented 10 months ago

I think I'll just do a PR for board/sifive-hifive1.cfg and leave the others as I am not 100% confident that I can change them without causing some other issues and I don't have the wherewithal to test such changes.

en-sc commented 10 months ago

I think I'll just do a PR for board/sifive-hifive1.cfg and leave the others as I am not 100% confident that I can change them without causing some other issues and I don't have the wherewithal to test such changes.

Please, wait a little. The actual cause can be seen in the log here:

Debug: 1725 796 riscv.c:2230 riscv_effective_privilege_mode(): [riscv.cpu] Effective mode=3; v=1

This is not a well-defined combination (if v=1 Effective mode should be either 0 or 1).

The issue is with this PR: https://github.com/riscv/riscv-openocd/pull/920

en-sc commented 10 months ago

I will prepare a patch today

TommyMurphyTM1234 commented 10 months ago

Please, wait a little.

Ok, will do.

The actual cause can be seen in the log here:

Debug: 1725 796 riscv.c:2230 riscv_effective_privilege_mode(): [riscv.cpu] Effective mode=3; v=1

This is not a well-defined combination (if v=1 Effective mode should be either 0 or 1).

If you need me to gather more info, including using additional custom logging in OpenOCD, let me know. I realise that probably not too many people have the SiFive HiFive1 board.

en-sc commented 10 months ago

If you need me to gather more info, including using additional custom logging in OpenOCD, let me know. I realise that probably not too many people have the SiFive HiFive1 board.

Thank you a lot! I will describe the issue in the PR I've mentioned.

en-sc commented 10 months ago

Should be fixed by https://github.com/riscv/riscv-openocd/pull/997. @TommyMurphyTM1234, can you please check?

TommyMurphyTM1234 commented 10 months ago

Should be fixed by #997. @TommyMurphyTM1234, can you please check?

That seems to do the trick alright. I did a clean build/install of OpenOCD including the changes in that PR and it connects fine now. Thanks a lot - much appreciated.

./openocd -f board/sifive-hifive1.cfg
Open On-Chip Debugger 0.12.0+dev-03592-g4fc0d86ff-dirty (2024-01-17-15:20)
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)
cleared protection for sectors 64 through 255 on flash bank 0
Info : Listening on port 6666 for tcl connections
Info : Listening on port 4444 for telnet connections
en-sc commented 10 months ago

@TommyMurphyTM1234, the fix has been merged. Can you please verify and close the issue?

TommyMurphyTM1234 commented 10 months ago

Hi @en-sc - yes - it works OK. I did a fresh clone, bootstrap, configure and build and get this when I run it against the SiFive HiFive1 Rev A01 board:

./installed-tools/bin/openocd -f board/sifive-hifive1.cfg
Open On-Chip Debugger 0.12.0+dev-03604-gec28cf03a (2024-01-28-12:12)
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 0x2040016c due to debug interrupt
Info : Found flash device 'issi is25lp128d' (ID 0x0018609d)
cleared protection for sectors 64 through 255 on flash bank 0
Info : Listening on port 6666 for tcl connections
Info : Listening on port 4444 for telnet connections
^Cshutdown command invoked

Thanks a lot for sorting this out.