riscv-collab / riscv-openocd

Fork of OpenOCD that has RISC-V support
Other
445 stars 324 forks source link

During scan openjocd assumes progbuf is available. This is OPTIONAL. Scan fails on this. #1017

Open InspireSemi opened 8 months ago

InspireSemi commented 8 months ago

Error: 19418 1342611 program.c:203 riscv_program_insert(): [riscv.cpu] Unable to insert program into progbuf, capacity would be exceeded (progbufsize=0). Error: 19419 1342611 target.c:681 target_examine_one(): [riscv.cpu] Examination failed Debug: 19420 1342611 target.c:682 target_examine_one(): [riscv.cpu] examine() returned error code -4 Debug: 19421 1342611 target.c:1782 target_call_event_callbacks(): target event 20 (examine-fail) for core riscv.cpu Debug: 19422 1342611 target.c:3009 handle_target(): [riscv.cpu] Examination failed. Polling again in 5000ms Debug: 19423 1342611 target.c:3002 handle_target(): [riscv.cpu] target_poll() -> -4, next attempt in 5000ms

InspireSemi commented 8 months ago

My .cfg file:

debug verbosity 0-4 (2 normal error+warn; 3 debug; 4 extremely verbose)

debug_level 4

adapter speed 10000

adapter driver remote_bitbang remote_bitbang host localhost remote_bitbang port 43860

remote_bitbang_port $::env(JTAG_VPI_PORT)

set _CHIPNAME riscv jtag newtap $_CHIPNAME cpu -irlen 5

set _TARGETNAME $_CHIPNAME.cpu target create $_TARGETNAME riscv -chain-position $_TARGETNAME -rtos hwthread

ThreadX, FreeRTOS, eCos, linux, ChibiOS, Chromium-EC, embKernel, mqx, uCOS-III, nuttx, hwthread, or auto

riscv set_reset_timeout_sec 3600 riscv set_command_timeout_sec 3600 riscv set_mem_access sysbus

gdb_port 3333

riscv set_mem_access off

use system bus access vs program buffer for mem access

init echo "Ready for Remote Connections"

TommyMurphyTM1234 commented 8 months ago

I thought that this assumption by OpenOCD that the target implements a progbuf had been addressed previously? At least for debug spec 0.13 or later targets? E.g. see here:

en-sc commented 8 months ago

@InspireSemi, can you please provide more context? To triage the issue the log prior to the error is also needed -- currently it is unclear what is the program the debugger attempts to run here. debug_level 3 should be enough.

InspireSemi commented 8 months ago

This is during initial connection to the target. It has not gotten to opening up the gdb connection yet in openocd.

BTW: The "other" openocd (upstream) does not exhibit this behavior. I have been using it, but wanted to switch over to the riscv one, based on what looks like you are pulling from upstream back into this version.

TommyMurphyTM1234 commented 8 months ago

To echo what @en-sc said earlier, you'll probably need to capture and attach the verbose openocd -d3 log if you want others to look into this issue. The log fragments posted so far are insufficient for understanding fully what's happening.

InspireSemi commented 8 months ago

log.txt Here is a full log. Search for ERROR to find the issue. It is right afdter it reads the fp register.

Again this is before gdb can even be connected to openocd. It is in the initial connect stage.

InspireSemi commented 8 months ago

I am moving back to the openocd from openocd.org for now. I need something that works for our use as well as customers use.

I will be more than happy (as time permits) to help you debug what is wrong.

en-sc commented 7 months ago

@InspireSemi, I'm sorry for the delay.

I have analyzed the logs. The failure occurs while reading dcsr register.

Debug: 1968 308879 riscv-013.c:1776 set_dcsr_ebreak(): [riscv.cpu] Set dcsr.ebreak*
Debug: 1969 308879 riscv.c:5260 riscv_get_register(): [riscv.cpu] Reading dcsr from target

However, the abstract command fails with abstractcs.cmderr = 7 (other):

Debug: 1972 308879 riscv-013.c:893 execute_abstract_command(): [riscv.cpu] access register=0x2207b0 {regno=0x7b0 write=arg0 transfer=enabled postexec=disabled aarpostincrement=disabled aarsize=32bit}
Debug: 1991 309944 riscv-013.c:397 dump_field(): 66b w 002207b0 @17 -> + 00000004 @00; 20i
Debug: 1992 309944 riscv-013.c:405 dump_field(): write: command=0x2207b0 {control=0x2207b0}
...
Debug: 2011 311091 riscv-013.c:397 dump_field(): 66b r 00000000 @16 -> + 00000004 @00; 10i
...
Debug: 2023 312064 riscv-013.c:397 dump_field(): 66b - 00000000 @16 -> + 00000704 @00; 10i
Debug: 2024 312064 riscv-013.c:411 dump_field(): read:
Debug: 2025 312064 riscv-013.c:917 execute_abstract_command(): [riscv.cpu] command 0x2207b0 failed; abstractcs=0x704

Therefore, it is attempted to read dcsr via program buffer, which fails with the reported error:

Error: 2181 321258 program.c:203 riscv_program_insert(): [riscv.cpu] Unable to insert program into progbuf, capacity would be exceeded (progbufsize=0).

TLDR:

This is not obvious by the error reported to the user, but the examination fails because the debugger is unable to read dcsr via abstract command access. This seems like a hardware issue to me, though I would like to investigate further to be sure.

Why openocd.org version works?

Setting dcsr.ebreak* during examine() was introduced in f0898155d1e83c0f8691396eb01103cd3beb470c. I'm curious to know, are you able to step/resume the hart on openocd.org version (the dcsr is read there also)? If you can, please, provide the log from doing step or resume on either 21433e83eeda7abe621027f12d588ebdea7760d3 or the version from openocd.org.

InspireSemi commented 7 months ago

I have not seen any issues with openocd.org. I am able to connect, set SW breakpoints, resume, halt (ctrl-C), dump memory, single step, etc..

I will post the logs from running openocd.org.

I noticed that you are setting the ebreak bits in dcsr during initial connection and openocd.org is not doing this. It waits until gdb has connected to set them.

InspireSemi commented 7 months ago

cr2464_mmap.txt gdb.output.txt Here is the output from openocd.org. It is through connecting to the target, openign gdb port, gdb connecting I then executed: si, display/4i $pc, si

FYI: I had opened gdb with the wrong elf file.

InspireSemi commented 7 months ago

Do you need any further information? Logs, etc..
Would like to move over to this version of openocd.

I can spare some cycles in helping to debug if needed..

en-sc commented 7 months ago

@InspireSemi, again, sorry for the delay. This issue slipped my mind.

Do you need any further information?

Yes, It would be nice if you could collect OpenOCD -d3 logs for the following scenarios (using openocd.org version). They can be collected without running GDB if it is more convenient. In particular:

  1. Reading dcsr:
    .../openocd ... -d3 -l <log_name> -c init -c 'reset halt' -c 'reg dcsr' -c shutdown
  2. Stepping:
    .../openocd ... -d3 -l <log_name> -c init -c 'reset halt' -c step -c shutdown
InspireSemi commented 6 months ago

I will get to this in a day or so..

InspireSemi commented 3 hours ago

finally getting back around to this.

Attached are logs from openocd.org and one from this repo. The error message riscv.openocd gives is: Debug: 10565 3214 riscv-013.c:1548 register_read_direct(): [riscv.cpu] fp = 0xffffffff81603de0 Debug: 10566 3214 riscv_reg.c:971 riscv_reg_get(): [riscv.cpu] Read fp: 0xffffffff81603de0 Error: 10567 3214 program.c:203 riscv_program_insert(): [riscv.cpu] Unable to insert program into progbuf, capacity would be exceeded (progbufsize=0). Error: 10568 3214 target.c:681 target_examine_one(): [riscv.cpu] Examination failed Debug: 10569 3214 target.c:682 target_examine_one(): [riscv.cpu] examine() returned error code -4 Debug: 10570 3214 target.c:1782 target_call_event_callbacks(): target event 20 (examine-fail) for core riscv.cpu Debug: 10571 3214 target.c:3009 handle_target(): [riscv.cpu] Examination failed. Polling again in 3231ms

It then loops on this getting to the same point with the progbuf fails, rinse repeat..

openocd.bad.txt openocd.good.txt openocd.good.txt