Hi Liviu, the log: > 1: Info : adapter_poll > 1: Info : stlink_usb_v2_read_debug_reg 0xE000EDF0 0x01030003 reports that, while reading register DHCSR, OpenOCD found that the CPU is halted. Then it expects it is due to a breakpoint.
Are you sure there is not any pending HW breakpoint? The address 0x080003D6 is in Flash, the CPU can halt there only for HW breakpoint or explicit break instruction. There could even be a bug in the HLA code. Could you please try a different command-line and replace "interface/stlink.cfg" with "interface/stlink-dap.cfg" ? This will use the native Cortex-M target code, in place of the HLA target code. Regards Antonio On Mon, Jul 10, 2023 at 7:50 PM Liviu Ionescu <i...@livius.net> wrote: > > Hi! > > I encountered a weird case that breaks my semihosted unit tests, and I would > appreciate any help to diagnose the issue. > > I did quite a lot of tests, and added several LOG lines in order to > understand what's going on, but my knowledge on the OpenOCD implementation of > the Cortex debug specs is very limited, and I don't yet have a solution. > > The use case is the following: I have a set of 3 different unit tests for a > relatively complex projects (µOS++, a C++ framework which also includes a > scheduler), all compiled as full semihosted applications, getting argc/argv > from outside and returning an exit code. Each test is compiled and performed > both as debug (-O0) and release (-Os). > > The tests first passed when compiled for Cortex-M0, Cortex-M3 and Cortex-M7F > for running via QEMU. Later I added the configuration to run the same tests > via OpenOCD on the Raspberry Pico board, and it was also fine. > > When I added the configuration for a faster NUCLEO-F767Zi board, out of the 3 > tests, 2 passed, but one failed in the release configuration; the debug > configuration passed. OpenOCD was running on an Intel Mac Mini. > > Running exactly the same tests with an OpenCOD compiled from the same sources > on a Raspberry Pi4, the same test failed, but this time in the debug > configuration, with the release one passing. > > The test performs quite a lot of operations, and prints the progress on the > semihosting standard output. Each and every breakpoint issued by the > SEMIHOSTING_SYS_WRITE calls is properly identified and processed, with the > message printed in the OpenOCD console. > > However, at a certain point in time, reproducible for each run, OpenOCD polls > the MCU right at the moment when a SysTick interrupt is entered, and thinks > that it is a breakpoint, but later checks the code and does not identify the > BKPT instruction and hangs: > > > ``` > 1: Info : stlink_usb_write_debug_reg 0xE000EDF0 0xA05F0001 > 1: Info : adapter_poll > 1: Info : stlink_usb_v2_read_debug_reg 0xE000EDF0 0x01030003 > 1: Info : stlink_usb_read_mem32 0xE000EDF8 0x00000000 > 1: Info : adapter_examine_debug_reason target->debug_reason = 5 -> 1 > (NOTHALTED -> BREAKPOINT) > 1: Info : stlink_usb_write_debug_reg 0xE000EDFC 0x01000000 > 1: Info : arm_semihosting is_armv7m target->debug_reason=1 (BREAKPOINT) > 1: Info : stlink_usb_read_mem16 0x0800BF90 0xBEAB > 1: Info : stlink_usb_read_mem32 0x2007F03C 0x00000008 > 1: Info : stlink_usb_read_mem32 0x20079C80 0x74736554 > 1: Info : stlink_usb_read_mem16 0x20079C90 0x0A65 > 1: Test C API - done <--- the message written on standard output > 1: Info : stlink_usb_read_mem16 0x0800BF90 0xBEAB > 1: Info : stlink_usb_write_mem32 0xE000EDFC 0x01000000 > 1: Info : stlink_usb_write_mem32 0xE000EDF8 0x00000000 > > 1: Info : stlink_usb_write_debug_reg 0xE000EDF0 0xA05F0001 > 1: Info : adapter_poll > 1: Info : stlink_usb_v2_read_debug_reg 0xE000EDF0 0x01030003 > 1: Info : stlink_usb_read_mem32 0xE000EDF8 0x00000000 > 1: Info : adapter_examine_debug_reason target->debug_reason = 5 -> 1 > (NOTHALTED -> BREAKPOINT) > 1: Info : stlink_usb_write_debug_reg 0xE000EDFC 0x01000000 > 1: Info : arm_semihosting is_armv7m target->debug_reason=1 (BREAKPOINT) > 1: Info : stlink_usb_read_mem16 0x080003D6 0xB508 <--- 0x080003D6 is the > address of SysTick_Handler > 1: Info : arm_semihosting insn 0xB508 != 0xBEAB <--- not a semihosting BKPT > 1: [stm32f7x.cpu] halted due to breakpoint, current mode: Handler SysTick > 1: xPSR: 0x010f000f pc: 0x080003d6 msp: 0x20080000, semihosting > 1: Info : adapter_poll > 1: Info : stlink_usb_v2_read_debug_reg 0xE000EDF0 0x00030003 > 1: Info : adapter_poll > 1: Info : stlink_usb_v2_read_debug_reg 0xE000EDF0 0x00030003 > 1: Info : adapter_poll > 1: Info : stlink_usb_v2_read_debug_reg 0xE000EDF0 0x00030003 > ... forever... > ``` > > It looks like there are two problems: > > - openocd should not halt on breakpoints if started standalone, i.e. not in a > debug session; in this case it falsely identifies a pending SysTick interrupt > and treats it as if a breakpoint was set at the start of the interrupt > handler; given that the application is not started in a debug session, there > is no explicit breakpoint set at any location, so this should be a false > pasitive > - in case a non-semihosted breakpoint is inadvertently entered, is must be > simply skipped over and execution resumed > > > The OpenCOD I use was built a few days ago from the master branch, and the > test is started via CMake (actually CTest) as: > > 1: Test command: > /Users/ilg/Work/xpack-dev-tools-build/openocd-0.12.0-2/darwin-x64/application/bin/openocd > "-c" "tcl_port disabled" "-c" "telnet_port disabled" "-f" > "interface/stlink.cfg" "-f" "target/stm32f7x.cfg" "-c" "program > rtos-apis-test.elf verify" "-c" "arm semihosting enable" "-c" "arm > semihosting_cmdline rtos-apis-test" "-c" "reset" > > > My current understanding is that, by chance, OpenOCD polls the device at a > particular moment when the SysTick is about to be entered, and, due to a bug, > gets confused to think it entered a breakpoint, which later ignores, and does > not resume execution. I saw some comments in the logic trying to identify the > debug reason, and apparently things might not be very well understood. > > To be noted that SysTick is enabled with 1000 Hz from the very beginning, and > some of the tests check the timers powered by SysTick, so the SysTick > interrupt handler is ok, it definitely does not include any breakpoints. > > On the Raspberry Pi, which is slower than the Mac, the OpenOCD polling > mechanism occurs at different moments in time, and does not stumble in the > pending SysTick in the release binary, but does this in the debug binary. > > Also to be noted that if I edit the project in any way, like add a new > printf(), remove tests, etc, the timings are different and the issue no > longer occurs. > > Running exactly the same binary using the SEGGER J-Link software was ok on my > Mac, with both the debug and release configurations passed. I dare to say > that the SEGGER software behaves correctly, but it might also be a fortunate > timing. > > > Given that diagnosing this issue requires a NUCLEO-F767ZI board and an Intel > MacMini or a Raspberry Pi, I don't expect many of you to be able to reproduce > the issue, so I'll try to do it myself, but I would appreciate any > suggestions on how to proceed, since for now I ran out of ideas. :-( > > So far I added lots of LOG messages, but did not change anything in the logic. > > The output with the full log looks like this: > > ``` > ... > 1: Test C API - done > 1: Debug: 15347 16371 semihosting_common.c:1399 semihosting_common(): > write(8, 0x20079c80, 18)=18 > 1: Debug: 15348 16371 target.c:1807 target_call_event_callbacks(): target > event 3 (resume-start) for core stm32f7x.cpu > 1: Debug: 15349 16371 hla_target.c:459 adapter_resume(): adapter_resume 1 > 0x00000000 0 0 > 1: Debug: 15350 16371 target.c:2161 target_free_all_working_areas_restore(): > freeing all working areas > 1: Debug: 15351 16371 hla_target.c:612 adapter_read_memory(): > adapter_read_memory 0x0800bf90 2 1 > 1: Info : 15352 16371 stlink_usb.c:2585 stlink_usb_read_mem16(): > stlink_usb_read_mem16 0x0800BF90 0xBEAB > 1: Debug: 15353 16371 target.c:2616 target_read_u16(): address: 0x0800bf90, > value: 0xbeab > 1: Debug: 15354 16371 armv7m.c:1088 armv7m_maybe_skip_bkpt_inst(): Skipping > over BKPT instruction > 1: Debug: 15355 16371 target.c:2680 target_write_u32(): address: 0xe000edfc, > value: 0x01000000 > 1: Debug: 15356 16371 hla_target.c:627 adapter_write_memory(): > adapter_write_memory 0xe000edfc 4 1 > 1: Info : 15357 16371 stlink_usb.c:2725 stlink_usb_write_mem32(): > stlink_usb_write_mem32 0xE000EDFC 0x01000000 > 1: Debug: 15358 16372 armv7m.c:174 armv7m_restore_context(): > 1: Debug: 15359 16372 armv7m.c:441 armv7m_write_core_reg(): write pc value > 0x0800bf92 > 1: Debug: 15360 16373 armv7m.c:441 armv7m_write_core_reg(): write r0 value > 0x00000000 > 1: Debug: 15361 16373 target.c:2680 target_write_u32(): address: 0xe000edf8, > value: 0x00000000 > 1: Debug: 15362 16373 hla_target.c:627 adapter_write_memory(): > adapter_write_memory 0xe000edf8 4 1 > 1: Info : 15363 16373 stlink_usb.c:2725 stlink_usb_write_mem32(): > stlink_usb_write_mem32 0xE000EDF8 0x00000000 > 1: Info : 15364 16374 stlink_usb.c:2056 stlink_usb_write_debug_reg(): > stlink_usb_write_debug_reg 0xE000EDF0 0xA05F0001 > 1: Debug: 15365 16374 target.c:1807 target_call_event_callbacks(): target > event 2 (resumed) for core stm32f7x.cpu > 1: Debug: 15366 16374 target.c:1807 target_call_event_callbacks(): target > event 4 (resume-end) for core stm32f7x.cpu > > 1: Info : 15367 16442 hla_target.c:301 adapter_poll(): adapter_poll > 1: Info : 15368 16442 stlink_usb.c:2044 stlink_usb_v2_read_debug_reg(): > stlink_usb_v2_read_debug_reg 0xE000EDF0 0x01030003 > 1: Debug: 15369 16442 hla_target.c:612 adapter_read_memory(): > adapter_read_memory 0xe000edf8 4 1 > 1: Info : 15370 16443 stlink_usb.c:2680 stlink_usb_read_mem32(): > stlink_usb_read_mem32 0xE000EDF8 0x00000000 > 1: Debug: 15371 16443 target.c:2592 target_read_u32(): address: 0xe000edf8, > value: 0x00000000 > 1: Info : 15372 16443 hla_target.c:65 adapter_examine_debug_reason(): > adapter_examine_debug_reason target->debug_reason = 5 -> 1 (NOTHALTED -> > BREAKPOINT) > 1: Debug: 15373 16443 armv7m.c:371 armv7m_read_core_reg(): read r0 value > 0x00000005 > 1: Debug: 15374 16444 armv7m.c:371 armv7m_read_core_reg(): read r1 value > 0x2007f0fc > 1: Debug: 15375 16444 armv7m.c:371 armv7m_read_core_reg(): read r2 value > 0x00000009 > 1: Debug: 15376 16445 armv7m.c:371 armv7m_read_core_reg(): read r3 value > 0x00000008 > 1: Debug: 15377 16445 armv7m.c:371 armv7m_read_core_reg(): read r4 value > 0x20002f74 > 1: Debug: 15378 16446 armv7m.c:371 armv7m_read_core_reg(): read r5 value > 0x00000008 > 1: Debug: 15379 16446 armv7m.c:371 armv7m_read_core_reg(): read r6 value > 0x00000005 > 1: Debug: 15380 16447 armv7m.c:371 armv7m_read_core_reg(): read r7 value > 0x2007f0fc > 1: Debug: 15381 16447 armv7m.c:371 armv7m_read_core_reg(): read r8 value > 0x200001d8 > 1: Debug: 15382 16448 armv7m.c:371 armv7m_read_core_reg(): read r9 value > 0x00000000 > 1: Debug: 15383 16448 armv7m.c:371 armv7m_read_core_reg(): read r10 value > 0x2007f240 > 1: Debug: 15384 16449 armv7m.c:371 armv7m_read_core_reg(): read r11 value > 0x00000001 > 1: Debug: 15385 16449 armv7m.c:371 armv7m_read_core_reg(): read r12 value > 0x08019041 > 1: Debug: 15386 16450 armv7m.c:371 armv7m_read_core_reg(): read sp value > 0x20080000 > 1: Debug: 15387 16450 armv7m.c:371 armv7m_read_core_reg(): read lr value > 0xffffffed > 1: Debug: 15388 16451 armv7m.c:371 armv7m_read_core_reg(): read pc value > 0x080003d6 > 1: Debug: 15389 16451 armv7m.c:371 armv7m_read_core_reg(): read xpsr value > 0x010f000f > 1: Debug: 15390 16452 armv7m.c:371 armv7m_read_core_reg(): read msp value > 0x20080000 > 1: Debug: 15391 16452 armv7m.c:371 armv7m_read_core_reg(): read psp value > 0x2007f090 > 1: Debug: 15392 16452 armv7m.c:371 armv7m_read_core_reg(): read > pmsk_bpri_fltmsk_ctrl value 0x00000000 > 1: Debug: 15393 16453 armv7m.c:369 armv7m_read_core_reg(): read d0 value > 0x0000000000000000 > 1: Debug: 15394 16454 armv7m.c:369 armv7m_read_core_reg(): read d1 value > 0x0000000000000000 > 1: Debug: 15395 16455 armv7m.c:369 armv7m_read_core_reg(): read d2 value > 0x0000000000000000 > 1: Debug: 15396 16456 armv7m.c:369 armv7m_read_core_reg(): read d3 value > 0x0000000000000000 > 1: Debug: 15397 16457 armv7m.c:369 armv7m_read_core_reg(): read d4 value > 0x0000000000000000 > 1: Debug: 15398 16458 armv7m.c:369 armv7m_read_core_reg(): read d5 value > 0x0000000000000000 > 1: Debug: 15399 16459 armv7m.c:369 armv7m_read_core_reg(): read d6 value > 0x0000000000000000 > 1: Debug: 15400 16460 armv7m.c:369 armv7m_read_core_reg(): read d7 value > 0xffffffff00000000 > 1: Debug: 15401 16461 armv7m.c:369 armv7m_read_core_reg(): read d8 value > 0x0000000000000000 > 1: Debug: 15402 16462 armv7m.c:369 armv7m_read_core_reg(): read d9 value > 0x0000000000000000 > 1: Debug: 15403 16463 armv7m.c:369 armv7m_read_core_reg(): read d10 value > 0x0000000000000000 > 1: Debug: 15404 16464 armv7m.c:369 armv7m_read_core_reg(): read d11 value > 0x0000000000000000 > 1: Debug: 15405 16465 armv7m.c:369 armv7m_read_core_reg(): read d12 value > 0x0000000000000000 > 1: Debug: 15406 16466 armv7m.c:369 armv7m_read_core_reg(): read d13 value > 0x0000000000000000 > 1: Debug: 15407 16467 armv7m.c:369 armv7m_read_core_reg(): read d14 value > 0x0000000000000000 > 1: Debug: 15408 16467 armv7m.c:369 armv7m_read_core_reg(): read d15 value > 0xffffffff00000000 > 1: Debug: 15409 16468 armv7m.c:371 armv7m_read_core_reg(): read fpscr value > 0x00000000 > 1: Info : 15410 16468 stlink_usb.c:2056 stlink_usb_write_debug_reg(): > stlink_usb_write_debug_reg 0xE000EDFC 0x01000000 > 1: Debug: 15411 16468 hla_target.c:289 adapter_debug_entry(): entered debug > state in core mode: Handler at PC 0x080003d6, target->state: halted > 1: Info : 15412 16468 arm_semihosting.c:265 arm_semihosting(): > arm_semihosting is_armv7m target->debug_reason=1 (BREAKPOINT) > 1: Debug: 15413 16468 hla_target.c:612 adapter_read_memory(): > adapter_read_memory 0x080003d6 2 1 > 1: Info : 15414 16469 stlink_usb.c:2585 stlink_usb_read_mem16(): > stlink_usb_read_mem16 0x080003D6 0xB508 > 1: Debug: 15415 16469 target.c:2616 target_read_u16(): address: 0x080003d6, > value: 0xb508 > 1: Info : 15416 16469 arm_semihosting.c:280 arm_semihosting(): > arm_semihosting insn 0xB508 != 0xBEAB > 1: Debug: 15417 16469 target.c:1807 target_call_event_callbacks(): target > event 0 (gdb-halt) for core stm32f7x.cpu > 1: Debug: 15418 16469 target.c:1807 target_call_event_callbacks(): target > event 1 (halted) for core stm32f7x.cpu > 1: User : 15419 16469 armv7m.c:752 armv7m_arch_state(): [stm32f7x.cpu] halted > due to breakpoint, current mode: Handler SysTick > 1: xPSR: 0x010f000f pc: 0x080003d6 msp: 0x20080000, semihosting > 1: Debug: 15420 16469 hla_target.c:333 adapter_poll(): halted: PC: 0x080003d6 > 1: Info : 15421 16542 hla_target.c:301 adapter_poll(): adapter_poll > 1: Info : 15422 16543 stlink_usb.c:2044 stlink_usb_v2_read_debug_reg(): > stlink_usb_v2_read_debug_reg 0xE000EDF0 0x00030003 > 1: Info : 15423 16642 hla_target.c:301 adapter_poll(): adapter_poll > 1: Info : 15424 16642 stlink_usb.c:2044 stlink_usb_v2_read_debug_reg(): > stlink_usb_v2_read_debug_reg 0xE000EDF0 0x00030003 > 1: Info : 15425 16742 hla_target.c:301 adapter_poll(): adapter_poll > ... > ``` > > > Thank you, > > Liviu > > > >
