pyocd / pyOCD

Open source Python library for programming and debugging Arm Cortex-M microcontrollers
https://pyocd.io
Apache License 2.0
1.11k stars 477 forks source link

debug sequences: NXP S32K3xx DFP attach failure #1545

Open flit opened 1 year ago

flit commented 1 year ago

Created from discussion in #1488.

From @dev-apcs:

The snag I have is when using gdb to attach without flashing: the cpu hard-faults.

I tracked this down to vector table corruption - or rather annihilation:

The sample being used moves the vector table to RAM There's a RAMInitialize sequence in the DFP that, well, clears RAM (under control of the debug variable DoRAMInitialize) This is all well and good if the core is returned to reset state before running the sequence With the present implementation, this reset appears not to happen so VTOR is not re-initialised hence the hard fault Setting DoRAMInitialize to 0 (initially directly in the .pdsc, before I discovered -Opack.debug_sequences.debugvars="DoRAMInitialize=0;") works around the issue. When I finally RTFM, I notice that some standard reset sequences are not yet supported.

I haven't yet done the analysis to identify the missing sequence but this would appear to be the cause.

I figure that a user script might be the easiest fix for now. Do you have a roadmap for the remaining DFP sequences?

P.S.

I may have spoke too soon. The reset is possibly the responsibility of the client. The CLion run configuration has an option to send a reset command. However, setting this to monitor reset (always) doesn't appear to make a difference.

flit commented 1 year ago

The way ResetHardwareDeassert is used in the S32K3xx pack… that's an annoying repurposing of those sequences. ☹️ I'll take a look at how difficult the ResetHardware* sequences to support.

When you say "attach without flash", does that mean attaching to running code without reset (in which case I don't understand the issue…), or running existing code from reset?

dev-apcs commented 1 year ago

Thanks for breaking this issue out - something I ought to have done.

My expectation was based on previous experience with CLion and OpenOCD:

The configuration for pyOCD is more generic:

Hmm, CLion has moved on (finally). There's now a New Embedded GDB Server Run Configuration wizard with a pyOCD option:

Adding -Opack.debug_sequences.debugvars="DoRAMInitialize=0; to the command line arguments gets me to the same point as my manual configuration.

I was surprised to see S32K3xx listed in the supported targets list. A nice touch, caching the DFPs.

Yes, "attach" was a poor choice of words, and the reason I back-tracked in my previous post. It suggests connecting to a running target - which is a valid option but again broken without disabling RAMInitialize.

dev-apcs commented 1 year ago

Okay, after squinting at the code a bit, I came up with the following workaround:

The alias is actually an additional sequence in the .pdsc file:

index 13746aa..6f4a6d4 100644
--- a/Keil.S32K3xx_DFP.pdsc
+++ b/Keil.S32K3xx_DFP.pdsc
@@ -144,6 +144,12 @@
             </control>
           </sequence>

+          <sequence name="ResetCatchClear">
+            <block>
+              Sequence("ResetHardwareDeassert");
+            </block>
+          </sequence>
+
           <sequence name="DebugDeviceUnlock">
             <control if="(__connection &amp; 0x00010000)"               info="connect under reset">
               <block>

With this in place, it is possible to:

Might not be elegant, or even correct, but it does get me to the next snag...such as missing FreeRTOS stack trace info.

I'm also looking at the Zephyr BSP package (from NXP) hello_world sample. This package adds support for the mr_canhubk3, which I don't have but MCU is the same (some dts work needed). Early signs are that it's even more problematic when Zephyr RTOS support is enabled (in CLion).

The log for reference:

0002658 I Target type is s32k344 [board]
0002661 D Running task load_svd [sequencer]
0003027 D Running task pre_connect [sequencer]
0003033 I Asserting reset prior to connect [coresight_target]
0003060 D Running task dp_init [sequencer]
0003065 D Invoking returned call sequence: <CallSequence@7f030a1c9300: 
lock_probe: <bound method DebugProbe.lock of <CMSISDAPProbe@7f031c0d9390 NXP Semiconductors MCU-LINK Pro (r0CF) CMSIS-DAP V3.108>>
get_probe_capabilities: <bound method DebugPort._get_probe_capabilities of <pyocd.coresight.dap.DebugPort object at 0x7f0319e89c60>>
connect: <bound method DebugPort._connect of <pyocd.coresight.dap.DebugPort object at 0x7f0319e89c60>>
clear_sticky_err: <bound method DebugPort.clear_sticky_err of <pyocd.coresight.dap.DebugPort object at 0x7f0319e89c60>>
power_up_debug: <bound method DebugPort.power_up_debug of <pyocd.coresight.dap.DebugPort object at 0x7f0319e89c60>>
check_version: <bound method DebugPort._check_version of <pyocd.coresight.dap.DebugPort object at 0x7f0319e89c60>>
unlock_probe: <bound method DebugProbe.unlock of <CMSISDAPProbe@7f031c0d9390 NXP Semiconductors MCU-LINK Pro (r0CF) CMSIS-DAP V3.108>>> [sequencer]
0003070 D Running task lock_probe [sequencer]
0003075 D Running task get_probe_capabilities [sequencer]
0003080 D Running task connect [sequencer]
0003132 D Default wire protocol selected; using SWD [dap]
0003147 D Sending deprecated SWJ sequence to select SWD [swj]
0003256 I DP IDR = 0x6ba02477 (v2 rev6) [dap]
0003261 D Running task clear_sticky_err [sequencer]
0003267 D Running task power_up_debug [sequencer]
0003288 D Running task check_version [sequencer]
0003293 D Running task unlock_probe [sequencer]
0003298 D Running task unlock_device [sequencer]
0003303 D Running debug sequence 'DebugDeviceUnlock' (Cortex-M7_0) [pack_target]
0003309 I debugvar 'DoRAMInitialize' = 0x0 (0) [pack_target]
0003314 D Running debug sub-sequence 'DebugFromFirstInstruction' (Cortex-M7_0) [functions]
0003320 D Running debug sub-sequence 'EnableM7Debug' (Cortex-M7_0) [functions]
0003336 D Sub-sequence 'EnableM7Debug' result = 0 [functions]
0003357 D Sub-sequence 'DebugFromFirstInstruction' result = 0 [functions]
0003357 D Running debug sub-sequence 'ResetHardwareDeassert_Default' (Cortex-M7_0) [functions]
0003358 D Sub-sequence 'ResetHardwareDeassert_Default' result = 0 [functions]
0003359 D Running task create_discoverer [sequencer]
0003359 D Running task discovery [sequencer]
0003359 D Invoking returned call sequence: <CallSequence@7f0309d0ca00: 
find_aps: <bound method ADIv5Discovery._find_aps of <pyocd.coresight.discovery.ADIv5Discovery object at 0x7f030a1c9300>>
create_aps: <bound method ADIv5Discovery._create_aps of <pyocd.coresight.discovery.ADIv5Discovery object at 0x7f030a1c9300>>
find_components: <bound method ADIv5Discovery._find_components of <pyocd.coresight.discovery.ADIv5Discovery object at 0x7f030a1c9300>>
create_cores: <bound method CoreSightDiscovery._create_cores of <pyocd.coresight.discovery.ADIv5Discovery object at 0x7f030a1c9300>>
configure_core_reset: <bound method _PackTargetMethods._pack_target_configure_core_reset of <pyocd.target.pack.pack_target.S32k344 object at 0x7f031c0d9840>>
create_components: <bound method CoreSightDiscovery._create_components of <pyocd.coresight.discovery.ADIv5Discovery object at 0x7f030a1c9300>>> [sequencer]
0003359 D Running task find_aps [sequencer]
0003359 E Error probing AP#0: Memory transfer fault [discovery]
Traceback (most recent call last):
  File "pyOCD/pyocd/probe/cmsis_dap_probe.py", line 595, in read_ap_result_callback
    value = result()
  File "pyOCD/pyocd/probe/pydapaccess/dap_access_cmsis_dap.py", line 1071, in read_reg_cb
    res = transfer.get_result()
  File "pyOCD/pyocd/probe/pydapaccess/dap_access_cmsis_dap.py", line 157, in get_result
    self.daplink.flush()
  File "pyOCD/pyocd/utility/concurrency.py", line 29, in _locking
    return func(self, *args, **kwargs)
  File "pyOCD/pyocd/probe/pydapaccess/dap_access_cmsis_dap.py", line 881, in flush
    self._read_packet()
  File "pyOCD/pyocd/utility/concurrency.py", line 29, in _locking
    return func(self, *args, **kwargs)
  File "pyOCD/pyocd/probe/pydapaccess/dap_access_cmsis_dap.py", line 1157, in _read_packet
    decoded_data = cmd.decode_data(raw_data)
  File "pyOCD/pyocd/probe/pydapaccess/dap_access_cmsis_dap.py", line 480, in decode_data
    data = self._decode_transfer_data(data)
  File "pyOCD/pyocd/probe/pydapaccess/dap_access_cmsis_dap.py", line 386, in _decode_transfer_data
    self._check_response(data[2])
  File "pyOCD/pyocd/probe/pydapaccess/dap_access_cmsis_dap.py", line 364, in _check_response
    raise DAPAccessIntf.TransferFaultError()
pyocd.probe.pydapaccess.dap_access_api.DAPAccessIntf.TransferFaultError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "pyOCD/pyocd/coresight/discovery.py", line 133, in _find_aps
    isValid = AccessPort.probe(self.dp, apsel)
  File "pyOCD/pyocd/coresight/ap.py", line 342, in probe
    idr = dp.read_ap((ap_num << APSEL_SHIFT) | AP_IDR)
  File "pyOCD/pyocd/coresight/dap.py", line 934, in read_ap
    return read_ap_cb()
  File "pyOCD/pyocd/coresight/dap.py", line 922, in read_ap_cb
    result = result_cb()
  File "pyOCD/pyocd/probe/cmsis_dap_probe.py", line 600, in read_ap_result_callback
    raise self._convert_exception(error) from error
pyocd.core.exceptions.TransferFaultError: Memory transfer fault
0003362 E Error probing AP#3: Memory transfer fault [discovery]
Traceback (most recent call last):
  File "pyOCD/pyocd/probe/cmsis_dap_probe.py", line 595, in read_ap_result_callback
    value = result()
  File "pyOCD/pyocd/probe/pydapaccess/dap_access_cmsis_dap.py", line 1071, in read_reg_cb
    res = transfer.get_result()
  File "pyOCD/pyocd/probe/pydapaccess/dap_access_cmsis_dap.py", line 157, in get_result
    self.daplink.flush()
  File "pyOCD/pyocd/utility/concurrency.py", line 29, in _locking
    return func(self, *args, **kwargs)
  File "pyOCD/pyocd/probe/pydapaccess/dap_access_cmsis_dap.py", line 881, in flush
    self._read_packet()
  File "pyOCD/pyocd/utility/concurrency.py", line 29, in _locking
    return func(self, *args, **kwargs)
  File "pyOCD/pyocd/probe/pydapaccess/dap_access_cmsis_dap.py", line 1157, in _read_packet
    decoded_data = cmd.decode_data(raw_data)
  File "pyOCD/pyocd/probe/pydapaccess/dap_access_cmsis_dap.py", line 480, in decode_data
    data = self._decode_transfer_data(data)
  File "pyOCD/pyocd/probe/pydapaccess/dap_access_cmsis_dap.py", line 386, in _decode_transfer_data
    self._check_response(data[2])
  File "pyOCD/pyocd/probe/pydapaccess/dap_access_cmsis_dap.py", line 364, in _check_response
    raise DAPAccessIntf.TransferFaultError()
pyocd.probe.pydapaccess.dap_access_api.DAPAccessIntf.TransferFaultError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "pyOCD/pyocd/coresight/discovery.py", line 133, in _find_aps
    isValid = AccessPort.probe(self.dp, apsel)
  File "pyOCD/pyocd/coresight/ap.py", line 342, in probe
    idr = dp.read_ap((ap_num << APSEL_SHIFT) | AP_IDR)
  File "pyOCD/pyocd/coresight/dap.py", line 934, in read_ap
    return read_ap_cb()
  File "pyOCD/pyocd/coresight/dap.py", line 922, in read_ap_cb
    result = result_cb()
  File "pyOCD/pyocd/probe/cmsis_dap_probe.py", line 600, in read_ap_result_callback
    raise self._convert_exception(error) from error
pyocd.core.exceptions.TransferFaultError: Memory transfer fault
0003365 D Running task create_aps [sequencer]
0003365 D Invoking returned call sequence: <CallSequence@7f0309806500: 
create_ap.1: <function ADIv5Discovery._create_aps.<locals>.<lambda> at 0x7f0310894670>
create_ap.2: <function ADIv5Discovery._create_aps.<locals>.<lambda> at 0x7f0310894550>
create_ap.4: <function ADIv5Discovery._create_aps.<locals>.<lambda> at 0x7f0310894700>
create_ap.6: <function ADIv5Discovery._create_aps.<locals>.<lambda> at 0x7f0310894790>
create_ap.7: <function ADIv5Discovery._create_aps.<locals>.<lambda> at 0x7f0310894820>> [sequencer]
0003365 D Running task create_ap.1 [sequencer]
0003366 D APB-AP#1 default HPROT=0 HNONSEC=0 [ap]
0003367 D APB-AP#1 implemented HPROT=0 HNONSEC=0 [ap]
0003367 I APB-AP#1 IDR = 0x54770002 (APB-AP var0 rev5) [discovery]
0003367 D Running task create_ap.2 [sequencer]
0003369 D AHB-AP#2 default HPROT=3 HNONSEC=1 [ap]
0003369 D AHB-AP#2 implemented HPROT=f HNONSEC=1 [ap]
0003370 I AHB-AP#2 IDR = 0x84770001 (AHB-AP var0 rev8) [discovery]
0003370 D Running task create_ap.4 [sequencer]
0003371 D AHB-AP#4 default HPROT=3 HNONSEC=1 [ap]
0003372 D AHB-AP#4 implemented HPROT=f HNONSEC=1 [ap]
0003372 I AHB-AP#4 IDR = 0x84770001 (AHB-AP var0 rev8) [discovery]
0003372 D Running task create_ap.6 [sequencer]
0003373 I AP#6 IDR = 0x001c0030 (AP var3 rev0) [discovery]
0003373 D Running task create_ap.7 [sequencer]
0003373 I AP#7 IDR = 0x001c0040 (AP var4 rev0) [discovery]
0003373 D Running task find_components [sequencer]
0003373 D Invoking returned call sequence: <CallSequence@7f0309843400: 
init_ap.1: <bound method MEM_AP.find_components of <MEM_AP@7f0309806470 APB-AP#1 idr=54770002 rom=80000000>>
init_ap.2: <bound method AHB_AP.find_components of <AHB_AP@7f03098063e0 AHB-AP#2 idr=84770001 rom=f0000000>>
init_ap.4: <bound method AHB_AP.find_components of <AHB_AP@7f0309806110 AHB-AP#4 idr=84770001 rom=e00fe000>>> [sequencer]
0003373 D Running task init_ap.1 [sequencer]
0003375 I APB-AP#1 Class 0x1 ROM table #0 @ 0x80000000 (designer=00e:NXP part=995) [rom_table]
0003378 I [0]<80001000:Trace Funnel CS-400 class=9 designer=43b:Arm part=908 devtype=12 archid=0000 devid=38:0:0> [rom_table]
0003379 I [1]<80002000:Trace Funnel CS-400 class=9 designer=43b:Arm part=908 devtype=12 archid=0000 devid=38:0:0> [rom_table]
0003381 I [2]<80003000:Trace Funnel CS-400 class=9 designer=43b:Arm part=908 devtype=12 archid=0000 devid=38:0:0> [rom_table]
0003383 I [3]<80004000:ETF class=9 designer=43b:Arm part=961 devtype=32 archid=0000 devid=380:0:0> [rom_table]
0003385 I [4]<80005000:ETF class=9 designer=43b:Arm part=961 devtype=32 archid=0000 devid=480:0:0> [rom_table]
0003386 I [5]<80006000:ETF class=9 designer=43b:Arm part=961 devtype=32 archid=0000 devid=380:0:0> [rom_table]
0003388 I [6]<80007000:ETF class=9 designer=43b:Arm part=961 devtype=32 archid=0000 devid=380:0:0> [rom_table]
0003390 I [7]<80008000:??? class=9 designer=43b:Arm part=917 devtype=43 archid=0000 devid=0:0:0> [rom_table]
0003392 I [8]<80009000:CTI CS-400 class=9 designer=43b:Arm part=906 devtype=14 archid=0000 devid=40800:0:0> [rom_table]
0003394 I [9]<8000a000:TPIU CS-400 class=9 designer=43b:Arm part=912 devtype=11 archid=0000 devid=a0:0:0> [rom_table]
0003396 I [10]<8000b000:SWO CS-400 class=9 designer=43b:Arm part=914 devtype=11 archid=0000 devid=ea0:0:0> [rom_table]
0003397 I [11]<8000c000:TSGEN class=15 designer=43b:Arm part=101> [rom_table]
0003397 D [12]<0000d002 not present> [rom_table]
0003397 D [13]<0000e002 not present> [rom_table]
0003397 D [14]<0000f002 not present> [rom_table]
0003397 D [15]<00010002 not present> [rom_table]
0003397 D [16]<00011002 not present> [rom_table]
0003397 D [17]<00012002 not present> [rom_table]
0003398 D [18]<00013002 not present> [rom_table]
0003398 D [19]<00014002 not present> [rom_table]
0003398 D [20]<00015002 not present> [rom_table]
0003398 D [21]<00016002 not present> [rom_table]
0003398 D [22]<00017002 not present> [rom_table]
0003398 D [23]<00018002 not present> [rom_table]
0003398 D [24]<00019002 not present> [rom_table]
0003398 D [25]<0001a002 not present> [rom_table]
0003398 D [26]<0001b002 not present> [rom_table]
0003399 D [27]<0001c002 not present> [rom_table]
0003399 D [28]<0001d002 not present> [rom_table]
0003399 D [29]<0001e002 not present> [rom_table]
0003400 D [30]<0001f002 not present> [rom_table]
0003400 D [31]<00020002 not present> [rom_table]
0003400 D Running task init_ap.2 [sequencer]
0003401 E Transfer error while reading AHB-AP#2 ROM table: Memory transfer fault @ 0xf0000fd0-0xf0000fff [ap]
Traceback (most recent call last):
  File "pyOCD/pyocd/probe/cmsis_dap_probe.py", line 651, in read_ap_repeat_callback
    values = result()
  File "pyOCD/pyocd/probe/pydapaccess/dap_access_cmsis_dap.py", line 1112, in reg_read_repeat_cb
    res = transfer.get_result()
  File "pyOCD/pyocd/probe/pydapaccess/dap_access_cmsis_dap.py", line 157, in get_result
    self.daplink.flush()
  File "pyOCD/pyocd/utility/concurrency.py", line 29, in _locking
    return func(self, *args, **kwargs)
  File "pyOCD/pyocd/probe/pydapaccess/dap_access_cmsis_dap.py", line 881, in flush
    self._read_packet()
  File "pyOCD/pyocd/utility/concurrency.py", line 29, in _locking
    return func(self, *args, **kwargs)
  File "pyOCD/pyocd/probe/pydapaccess/dap_access_cmsis_dap.py", line 1157, in _read_packet
    decoded_data = cmd.decode_data(raw_data)
  File "pyOCD/pyocd/probe/pydapaccess/dap_access_cmsis_dap.py", line 480, in decode_data
    data = self._decode_transfer_data(data)
  File "pyOCD/pyocd/probe/pydapaccess/dap_access_cmsis_dap.py", line 386, in _decode_transfer_data
    self._check_response(data[2])
  File "pyOCD/pyocd/probe/pydapaccess/dap_access_cmsis_dap.py", line 364, in _check_response
    raise DAPAccessIntf.TransferFaultError()
pyocd.probe.pydapaccess.dap_access_api.DAPAccessIntf.TransferFaultError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "pyOCD/pyocd/coresight/ap.py", line 834, in find_components
    cmpid.read_id_registers()
  File "pyOCD/pyocd/coresight/rom_table.py", line 124, in read_id_registers
    regs = self.ap.read_memory_block32(self.top_address + self.IDR_READ_START, self.IDR_READ_COUNT)
  File "pyOCD/pyocd/utility/concurrency.py", line 29, in _locking
    return func(self, *args, **kwargs)
  File "pyOCD/pyocd/coresight/ap.py", line 1210, in _read_memory_block32
    resp += self._read_block32_page(addr, n//4)
  File "pyOCD/pyocd/coresight/ap.py", line 1168, in _read_block32_page
    resp = self.dp.read_ap_multiple(self.address.address + self._reg_offset + MEM_AP_DRW, size)
  File "pyOCD/pyocd/coresight/dap.py", line 1004, in read_ap_multiple
    return read_ap_multiple_cb()
  File "pyOCD/pyocd/coresight/dap.py", line 994, in read_ap_multiple_cb
    return result_cb()
  File "pyOCD/pyocd/probe/cmsis_dap_probe.py", line 658, in read_ap_repeat_callback
    raise self._convert_exception(exc) from exc
pyocd.core.exceptions.TransferFaultError: Memory transfer fault @ 0xf0000fd0-0xf0000fff
0003402 D Running task init_ap.4 [sequencer]
0003404 I AHB-AP#4 Class 0x1 ROM table #0 @ 0xe00fe000 (designer=43b:Arm part=4c8) [rom_table]
0003406 I [0]<e00ff000:ROM class=1 designer=43b:Arm part=4c7> [rom_table]
0003406 I   AHB-AP#4 Class 0x1 ROM table #1 @ 0xe00ff000 (designer=43b:Arm part=4c7) [rom_table]
0003408 I   [0]<e000e000:SCS v7-M class=14 designer=43b:Arm part=00c> [rom_table]
0003410 I   [1]<e0001000:DWT v7-M class=14 designer=43b:Arm part=002> [rom_table]
0003411 I   [2]<e0002000:FPB v7-M class=14 designer=43b:Arm part=00e> [rom_table]
0003412 I   [3]<e0000000:ITM v7-M class=14 designer=43b:Arm part=001> [rom_table]
0003412 D   [4]<fff41002 not present> [rom_table]
0003412 D   [5]<fff42002 not present> [rom_table]
0003414 I [1]<e0041000:ETM M7 class=9 designer=43b:Arm part=975 devtype=13 archid=4a13 devid=0:0:0> [rom_table]
0003416 I [2]<e0042000:CTI CS-400 class=9 designer=43b:Arm part=906 devtype=14 archid=0000 devid=40800:0:0> [rom_table]
0003416 D [3]<1ff02002 not present> [rom_table]
0003416 D Running task create_cores [sequencer]
0003416 D Creating SCS component [discovery]
0003416 D selected core #0 [soc_target]
0003418 I CPU core #0 is Cortex-M7 r1p2 [cortex_m]
0003418 I FPU present: FPv5-SP-D16-M [cortex_m]
0003420 D Running task configure_core_reset [sequencer]
0003420 D updated DFP core #0 reset types: {<ResetType.SW: 2>, <ResetType.SW_CORE: 4>, <ResetType.SW_SYSTEM: 3>, <ResetType.HW: 1>, <ResetType.SW_EMULATED: 5>} [pack_target]
0003420 I Setting core #0 (Cortex-M7_0) default reset sequence to ResetSystem [pack_target]
0003420 D Running task create_components [sequencer]
0003420 D Creating TPIU component [discovery]
0003421 D Creating SWO component [discovery]
0003421 D Creating DWT component [discovery]
0003422 I 4 hardware watchpoints [dwt]
0003422 D Creating FPB component [discovery]
0003424 I 8 hardware breakpoints, 1 literal comparators [fpb]
0003424 D fpb has been disabled [fpb]
0003424 D Creating ITM component [discovery]
0003426 D Running task check_for_cores [sequencer]
0003426 D Running task halt_on_connect [sequencer]
0003426 D Setting reset catch [coresight_target]
0003426 D set reset catch, core 0 [cortex_m]
0003426 D halting core 0 [cortex_m]
0003428 D Running task post_connect [sequencer]
0003428 I Deasserting reset post connect [coresight_target]
0003429 D Clearing reset catch [coresight_target]
0003429 D clear reset catch, core 0 [cortex_m]
0003429 D Running debug sequence 'ResetCatchClear' (Cortex-M7_0) [pack_target]
0003429 D Running debug sub-sequence 'ResetHardwareDeassert' (Cortex-M7_0) [functions]
0003430 D Running debug sub-sequence 'DebugEnablement' (Cortex-M7_0) [functions]
0003430 D Running debug sub-sequence 'EnableM7Debug' (Cortex-M7_0) [functions]
0003431 D Sub-sequence 'EnableM7Debug' result = 0 [functions]
0003431 D Sub-sequence 'DebugEnablement' result = 0 [functions]
0003431 D Sub-sequence 'ResetHardwareDeassert' result = 0 [functions]
0003431 D Running task post_connect_hook [sequencer]
0003431 D Running task create_flash [sequencer]
0003433 D flash algo: [stack=0x2040a670; 0xa670 b] [b2=0x2040c670,+0xc670] [b1=0x2040a670,+0xa670] [code=0x2040e67c,+0xe67c,0x1984 b] (ram=0x20400000, 0x10000 b) [flash_algo]
0003434 D flash algo: [stack=0x2040adb0; 0xadb0 b] [b2=0x2040cdb0,+0xcdb0] [b1=0x2040adb0,+0xadb0] [code=0x2040edb8,+0xedb8,0x1248 b] (ram=0x20400000, 0x10000 b) [flash_algo]
0003434 D Running task notify [sequencer]
0003435 D Setting vector catch to 0x00000001 [cortex_m]
0003437 I Semihost server started on port 4444 (core 0) [server]
0003519 I GDB server started on port 22344 (core 0) [gdbserver]
0003679 D Starting GDB server packet I/O thread [packet_io]
0003679 D halting core 0 [cortex_m]
0003680 I Client connected to port 22344! [gdbserver]
0003680 D GDB received query: [b'Supported', b'multiprocess+;swbreak+;hwbreak+;qRelocInsn+;fork-events+;vfork-events+;exec-events+;vContSupported+;QThreadEvents+;no-resumed+;memory-tagging+;xmlRegisters=i386#77'] [gdbserver]
0003722 D GDB general set: b'StartNoAckMode' [gdbserver]
0003766 D GDB received query: [b'Xfer', b'features', b'read', b'target.xml', b'0,7fb#4a'] [gdbserver]
0003767 D GDB query b'features': annex: b'target.xml', offset: 0, size: 2043 [gdbserver]
0003767 D GDB received query: [b'Xfer', b'features', b'read', b'target.xml', b'7fb,7fb#19'] [gdbserver]
0003767 D GDB query b'features': annex: b'target.xml', offset: 2043, size: 2043 [gdbserver]
0003769 D GDB general set: b'NonStop:0' [gdbserver]
0003770 D GDB received query: [b'TStatus#49'] [gdbserver]
0003770 D Current thread 0 is no longer valid, switching context to target [gdbserver]
0003771 D no accesses [register]
0003771 D out of date run token; invalidating cache [register]
0003774 D Tresponse=b'T0507:00000000;0d:00f04220;0e:ffffffff;0f:20144000;thread:1;' [gdbserver]
0003774 D GDB received query: [b'Xfer', b'threads', b'read', b'', b'0,7fb#d0'] [gdbserver]
0003774 D GDB query b'threads': annex: b'', offset: 0, size: 2043 [gdbserver]
0003777 D GDB received query: [b'Attached#8f'] [gdbserver]
0003778 D GDB received query: [b'Offsets#4b'] [gdbserver]
0003779 D GDB received query: [b'Xfer', b'memory-map', b'read', b'', b'0,7fb#e9'] [gdbserver]
0003779 D GDB query b'memory-map': annex: b'', offset: 0, size: 2043 [gdbserver]
0003779 D no reads [memory]
0003780 D out of date run token; invalidating cache [memory]
0003798 D GDB received query: [b'Xfer', b'threads', b'read', b'', b'0,7fb#d0'] [gdbserver]
0003798 D GDB query b'threads': annex: b'', offset: 0, size: 2043 [gdbserver]
0003808 D GDB getting register context [context_facade]
0003842 D GDB get_reg_context: r0 = 0x00000000 -> b'00000000' [context_facade]
0003842 D GDB get_reg_context: r1 = 0x00000000 -> b'00000000' [context_facade]
0003842 D GDB get_reg_context: r2 = 0x00000000 -> b'00000000' [context_facade]
0003842 D GDB get_reg_context: r3 = 0x00000000 -> b'00000000' [context_facade]
0003842 D GDB get_reg_context: r4 = 0x00000000 -> b'00000000' [context_facade]
0003842 D GDB get_reg_context: r5 = 0x00000000 -> b'00000000' [context_facade]
0003842 D GDB get_reg_context: r6 = 0x00000000 -> b'00000000' [context_facade]
0003842 D GDB get_reg_context: r7 = 0x00000000 -> b'00000000' [context_facade]
0003842 D GDB get_reg_context: r8 = 0x00000000 -> b'00000000' [context_facade]
0003842 D GDB get_reg_context: r9 = 0x00000000 -> b'00000000' [context_facade]
0003842 D GDB get_reg_context: r10 = 0x00000000 -> b'00000000' [context_facade]
0003842 D GDB get_reg_context: r11 = 0x00000000 -> b'00000000' [context_facade]
0003842 D GDB get_reg_context: r12 = 0x00000000 -> b'00000000' [context_facade]
0003842 D GDB get_reg_context: sp = 0x2042F000 -> b'00f04220' [context_facade]
0003842 D GDB get_reg_context: lr = 0xFFFFFFFF -> b'ffffffff' [context_facade]
0003842 D GDB get_reg_context: pc = 0x00401420 -> b'20144000' [context_facade]
0003842 D GDB get_reg_context: msp = 0x2042F000 -> b'00f04220' [context_facade]
0003842 D GDB get_reg_context: psp = 0x00000000 -> b'00000000' [context_facade]
0003842 D GDB get_reg_context: primask = 0x00000000 -> b'00000000' [context_facade]
0003842 D GDB get_reg_context: xpsr = 0x01000000 -> b'00000001' [context_facade]
0003842 D GDB get_reg_context: control = 0x00000000 -> b'00000000' [context_facade]
0003842 D GDB get_reg_context: fpscr = 0x00000000 -> b'00000000' [context_facade]
0003842 D GDB get_reg_context: d0 = 0x00000000 -> b'0000000000000000' [context_facade]
0003842 D GDB get_reg_context: d1 = 0x00000000 -> b'0000000000000000' [context_facade]
0003843 D GDB get_reg_context: d2 = 0x00000000 -> b'0000000000000000' [context_facade]
0003843 D GDB get_reg_context: d3 = 0x00000000 -> b'0000000000000000' [context_facade]
0003843 D GDB get_reg_context: d4 = 0x00000000 -> b'0000000000000000' [context_facade]
0003843 D GDB get_reg_context: d5 = 0x00000000 -> b'0000000000000000' [context_facade]
0003843 D GDB get_reg_context: d6 = 0x00000000 -> b'0000000000000000' [context_facade]
0003843 D GDB get_reg_context: d7 = 0xFFFFFFFF00000000 -> b'00000000ffffffff' [context_facade]
0003843 D GDB get_reg_context: d8 = 0x00000000 -> b'0000000000000000' [context_facade]
0003843 D GDB get_reg_context: d9 = 0x00000000 -> b'0000000000000000' [context_facade]
0003843 D GDB get_reg_context: d10 = 0x00000000 -> b'0000000000000000' [context_facade]
0003843 D GDB get_reg_context: d11 = 0x00000000 -> b'0000000000000000' [context_facade]
0003843 D GDB get_reg_context: d12 = 0x00000000 -> b'0000000000000000' [context_facade]
0003843 D GDB get_reg_context: d13 = 0x00000000 -> b'0000000000000000' [context_facade]
0003843 D GDB get_reg_context: d14 = 0x00000000 -> b'0000000000000000' [context_facade]
0003843 D GDB get_reg_context: d15 = 0xFFFFFFFF00000000 -> b'00000000ffffffff' [context_facade]
0003843 D GDB get_reg_context: basepri = 0x00000000 -> b'00000000' [context_facade]
0003843 D GDB get_reg_context: faultmask = 0x00000000 -> b'00000000' [context_facade]
0003844 D GDB received query: [b'Symbol', b'', b'#5b'] [gdbserver]
0003844 I Attempting to load RTOS plugins [gdbserver]
0003844 D Attempting to load argon [gdbserver]
0003844 D Attempting to load freertos [gdbserver]
0003844 D Value for symbol uxCurrentNumberOfTasks = 0x20400698 [provider]
0003845 D Value for symbol pxCurrentTCB = 0x2040055c [provider]
0003845 D Value for symbol pxReadyTasksLists = 0x20400560 [provider]
0003845 D Value for symbol xDelayedTaskList1 = 0x20400628 [provider]
0003845 D Value for symbol xDelayedTaskList2 = 0x2040063c [provider]
0003845 D Value for symbol xPendingReadyList = 0x20400658 [provider]
0003845 D Value for symbol uxTopReadyPriority = 0x204006a0 [provider]
0003845 D Value for symbol xSchedulerRunning = 0x204006a4 [provider]
0003845 D Value for symbol xSuspendedTaskList = 0x20400684 [provider]
0003845 D Value for symbol xTasksWaitingTermination = 0x2040066c [provider]
0003845 D Value for symbol vPortEnableVFP = 0x409248 [provider]
0003845 D FreeRTOS: number of priorities is 10 [freertos]
0003846 I freertos loaded successfully [gdbserver]
Debugger connected to tcp::22344
0003878 D GDB breakpoint b'Z'1 @ 401422 [gdbserver]
0003878 D set bkpt type HW at 0x401422 [manager]
0003878 D using hw bp instead because addr is flash [manager]
0003878 D selected bkpt type HW for addr 0x401422 [manager]
0003879 D GDB breakpoint b'Z'1 @ 409b18 [gdbserver]
0003879 D set bkpt type HW at 0x409b18 [manager]
0003879 D using hw bp instead because addr is flash [manager]
0003879 D selected bkpt type HW for addr 0x409b18 [manager]
0003879 D using hw bp instead because addr is flash [manager]
0003879 D selected bkpt type HW for addr 0x401422 [manager]
0003880 D GDB breakpoint b'Z'1 @ 409bbe [gdbserver]
0003880 D set bkpt type HW at 0x409bbe [manager]
0003880 D using hw bp instead because addr is flash [manager]
0003880 D selected bkpt type HW for addr 0x409bbe [manager]
0003880 D using hw bp instead because addr is flash [manager]
0003880 D selected bkpt type HW for addr 0x401422 [manager]
0003880 D using hw bp instead because addr is flash [manager]
0003880 D selected bkpt type HW for addr 0x409b18 [manager]
0003881 D GDB breakpoint b'Z'1 @ 419f28 [gdbserver]
0003881 D set bkpt type HW at 0x419f28 [manager]
0003881 D using hw bp instead because addr is flash [manager]
0003881 D selected bkpt type HW for addr 0x419f28 [manager]
0003881 D using hw bp instead because addr is flash [manager]
0003881 D selected bkpt type HW for addr 0x401422 [manager]
0003881 D using hw bp instead because addr is flash [manager]
0003881 D selected bkpt type HW for addr 0x409b18 [manager]
0003881 D using hw bp instead because addr is flash [manager]
0003881 D selected bkpt type HW for addr 0x409bbe [manager]
0003882 D GDB breakpoint b'Z'1 @ 41a80c [gdbserver]
0003882 D set bkpt type HW at 0x41a80c [manager]
0003882 D using hw bp instead because addr is flash [manager]
0003882 D selected bkpt type HW for addr 0x41a80c [manager]
0003882 D using hw bp instead because addr is flash [manager]
0003882 D selected bkpt type HW for addr 0x401422 [manager]
0003882 D using hw bp instead because addr is flash [manager]
0003882 D selected bkpt type HW for addr 0x409b18 [manager]
0003882 D using hw bp instead because addr is flash [manager]
0003882 D selected bkpt type HW for addr 0x409bbe [manager]
0003882 D using hw bp instead because addr is flash [manager]
0003882 D selected bkpt type HW for addr 0x419f28 [manager]
0003886 D thread_actions={1: None}; default_action=b'c' [gdbserver]
0003886 D resuming core 0 [cortex_m]
0003886 D added=[<UnrealizedBreakpoint@0x7f03126e9030 type=HW addr=0x00401422>, <UnrealizedBreakpoint@0x7f03126e8070 type=HW addr=0x00409b18>, <UnrealizedBreakpoint@0x7f03126e80d0 type=HW addr=0x00409bbe>, <UnrealizedBreakpoint@0x7f03126e9180 type=HW addr=0x00419f28>, <UnrealizedBreakpoint@0x7f03126e91e0 type=HW addr=0x0041a80c>] removed=[] [manager]
0003887 D using hw bp instead because addr is flash [manager]
0003887 D selected bkpt type HW for addr 0x401422 [manager]
0003887 D fpb has been enabled [fpb]
0003887 D BP: wrote 0x00401423 to comp @ 0xe0002008 [fpb]
0003887 D using hw bp instead because addr is flash [manager]
0003887 D selected bkpt type HW for addr 0x409b18 [manager]
0003887 D BP: wrote 0x00409b19 to comp @ 0xe000200c [fpb]
0003887 D using hw bp instead because addr is flash [manager]
0003887 D selected bkpt type HW for addr 0x409bbe [manager]
0003887 D BP: wrote 0x00409bbf to comp @ 0xe0002010 [fpb]
0003887 D using hw bp instead because addr is flash [manager]
0003887 D selected bkpt type HW for addr 0x419f28 [manager]
0003887 D BP: wrote 0x00419f29 to comp @ 0xe0002014 [fpb]
0003887 D using hw bp instead because addr is flash [manager]
0003887 D selected bkpt type HW for addr 0x41a80c [manager]
0003888 D BP: wrote 0x0041a80d to comp @ 0xe0002018 [fpb]
0003888 D bps after flush={4199458: <HardwareBreakpoint@0x7f03098e5840 type=HW addr=0x00401422>, 4234008: <HardwareBreakpoint@0x7f03098e5cc0 type=HW addr=0x00409b18>, 4234174: <HardwareBreakpoint@0x7f03098e5c90 type=HW addr=0x00409bbe>, 4300584: <HardwareBreakpoint@0x7f03098e5360 type=HW addr=0x00419f28>, 4302860: <HardwareBreakpoint@0x7f03098e5240 type=HW addr=0x0041a80c>} [manager]
0003889 D target resumed [gdbserver]
0003900 D 49 reads [14% hits, 7 regs] [register]
0003900 D out of date run token; invalidating cache [register]
0003901 D state halted; pc=0x00401422 [gdbserver]
0003902 D 44 reads, 498 bytes [21% hits, 106 bytes]; 0 bytes written [memory]
0003902 D out of date run token; invalidating cache [memory]
0003910 D Thread 0x20401c98 (IDLE) [freertos]
0003916 D Thread 0x20403500 (gmacif_po) [freertos]
0003920 D Thread 0x20402ad8 (tcpip_thr) [freertos]
0003923 D Thread 0x20401420 (CAN_Com) [freertos]
0003927 D Thread 0x20400fa8 (led_blink) [freertos]
0003933 D Thread 0x204050a0 (tcpecho_t) [freertos]
0003937 D Thread 0x204045f0 (http_serv) [freertos]
0003941 D Thread 0x20403d78 (chargen) [freertos]
0003945 D Thread 0x20406190 (Coverage_) [freertos]
0003949 D Thread 0x20405918 (udpecho_t) [freertos]
0003952 D Thread 0x20400b30 (mainloop) [freertos]
0003960 D Thread 0x204020d8 (Tmr Svc) [freertos]
0003975 D Tresponse=b'T0507:00000000;0d:00f04220;0e:ffffffff;0f:22144000;thread:20400fa8;' [gdbserver]
0003976 D GDB received query: [b'Xfer', b'threads', b'read', b'', b'0,7fb#d0'] [gdbserver]
0003976 D GDB query b'threads': annex: b'', offset: 0, size: 2043 [gdbserver]
0003980 D GDB breakpoint b'z'1 @ 401422 [gdbserver]
0003980 D remove bkpt at 0x401422 [manager]
0003980 D GDB breakpoint b'z'1 @ 409b18 [gdbserver]
0003980 D remove bkpt at 0x409b18 [manager]
0003981 D GDB breakpoint b'z'1 @ 409bbe [gdbserver]
0003981 D remove bkpt at 0x409bbe [manager]
0003981 D GDB breakpoint b'z'1 @ 419f28 [gdbserver]
0003981 D remove bkpt at 0x419f28 [manager]
0003981 D GDB breakpoint b'z'1 @ 41a80c [gdbserver]
0003981 D remove bkpt at 0x41a80c [manager]
0003994 D GDB getting register context [context_facade]
0004029 D GDB get_reg_context: r0 = 0x00000000 -> b'00000000' [context_facade]
0004029 D GDB get_reg_context: r1 = 0x00000000 -> b'00000000' [context_facade]
0004029 D GDB get_reg_context: r2 = 0x00000000 -> b'00000000' [context_facade]
0004029 D GDB get_reg_context: r3 = 0x00000000 -> b'00000000' [context_facade]
0004029 D GDB get_reg_context: r4 = 0x00000000 -> b'00000000' [context_facade]
0004029 D GDB get_reg_context: r5 = 0x00000000 -> b'00000000' [context_facade]
0004029 D GDB get_reg_context: r6 = 0x00000000 -> b'00000000' [context_facade]
0004029 D GDB get_reg_context: r7 = 0x00000000 -> b'00000000' [context_facade]
0004029 D GDB get_reg_context: r8 = 0x00000000 -> b'00000000' [context_facade]
0004029 D GDB get_reg_context: r9 = 0x00000000 -> b'00000000' [context_facade]
0004029 D GDB get_reg_context: r10 = 0x00000000 -> b'00000000' [context_facade]
0004030 D GDB get_reg_context: r11 = 0x00000000 -> b'00000000' [context_facade]
0004030 D GDB get_reg_context: r12 = 0x00000000 -> b'00000000' [context_facade]
0004030 D GDB get_reg_context: sp = 0x2042F000 -> b'00f04220' [context_facade]
0004030 D GDB get_reg_context: lr = 0xFFFFFFFF -> b'ffffffff' [context_facade]
0004030 D GDB get_reg_context: pc = 0x00401422 -> b'22144000' [context_facade]
0004030 D GDB get_reg_context: msp = 0x2042F000 -> b'00f04220' [context_facade]
0004030 D GDB get_reg_context: psp = 0x00000000 -> b'00000000' [context_facade]
0004030 D GDB get_reg_context: primask = 0x00000001 -> b'01000000' [context_facade]
0004030 D GDB get_reg_context: xpsr = 0x01000000 -> b'00000001' [context_facade]
0004030 D GDB get_reg_context: control = 0x00000000 -> b'00000000' [context_facade]
0004030 D GDB get_reg_context: fpscr = 0x00000000 -> b'00000000' [context_facade]
0004030 D GDB get_reg_context: d0 = 0x00000000 -> b'0000000000000000' [context_facade]
0004030 D GDB get_reg_context: d1 = 0x00000000 -> b'0000000000000000' [context_facade]
0004030 D GDB get_reg_context: d2 = 0x00000000 -> b'0000000000000000' [context_facade]
0004030 D GDB get_reg_context: d3 = 0x00000000 -> b'0000000000000000' [context_facade]
0004030 D GDB get_reg_context: d4 = 0x00000000 -> b'0000000000000000' [context_facade]
0004030 D GDB get_reg_context: d5 = 0x00000000 -> b'0000000000000000' [context_facade]
0004030 D GDB get_reg_context: d6 = 0x00000000 -> b'0000000000000000' [context_facade]
0004030 D GDB get_reg_context: d7 = 0xFFFFFFFF00000000 -> b'00000000ffffffff' [context_facade]
0004030 D GDB get_reg_context: d8 = 0x00000000 -> b'0000000000000000' [context_facade]
0004030 D GDB get_reg_context: d9 = 0x00000000 -> b'0000000000000000' [context_facade]
0004030 D GDB get_reg_context: d10 = 0x00000000 -> b'0000000000000000' [context_facade]
0004030 D GDB get_reg_context: d11 = 0x00000000 -> b'0000000000000000' [context_facade]
0004030 D GDB get_reg_context: d12 = 0x00000000 -> b'0000000000000000' [context_facade]
0004030 D GDB get_reg_context: d13 = 0x00000000 -> b'0000000000000000' [context_facade]
0004031 D GDB get_reg_context: d14 = 0x00000000 -> b'0000000000000000' [context_facade]
0004031 D GDB get_reg_context: d15 = 0xFFFFFFFF00000000 -> b'00000000ffffffff' [context_facade]
0004031 D GDB get_reg_context: basepri = 0x00000000 -> b'00000000' [context_facade]
0004031 D GDB get_reg_context: faultmask = 0x00000000 -> b'00000000' [context_facade]
flit commented 1 year ago

Cool! Nice to see CLion has pyOCD support now. 😄

Glad you have a workaround for now. With that, I'll probably go ahead and release a new version with the debug sequence support, then start working on improvements such as ResetHardware* support.

For the RTOS issues:

The missing stack trace is probably caused by LR being 0xffffffff. This could possibly be caused by incompatibility with the FreeRTOS version.

I just rebased the feature/freertos_10 branch onto the latest develop with debug sequence support. It's worth a shot.

dev-apcs commented 1 year ago

Yeah, sounds good.

The lwip_s32k344 sample uses FreeRTOS V10.4.6.

I appear to be having environmental issues (or there're issues with CLion). Launching pyocd as an Embedded GDB Server and attaching GDB all in one run configuration, I get the issues described. Launching pyocd independently (from pycharm) and then launching GDB (CLion Remote Debug run configuration), normal service is restored: all threads listed with the ability to switch between threads and up/down the call stack - all through CLion. Unfortunately, the more advanced RTOS debugging features (FreeRTOS Objects and FreeRTOS Heap) don't feature in Remote Debug. These advanced features do look to be working in the "broken" case (Embedded GDB Server. I have some more analysis to do, clearly.

Moving to feature/freertos_10 and running server and client separately breaks FreeRTOS integration: the current thread is intact with the call stack navigable but moving between threads, the call stack is gibberish - which looks like perhaps version compatibility. I'll concentrate on my environment woes before diving deeper into this. I need to better understand what both code bases are doing to provide FreeRTOS integration.

The Zephyr issues are more fundamental. I can set breakpoints early in the init cycle (around z_arm_reset) but it never reaches main. I need to consider all the usual suspects + I didn't fully follow the instructions (well, you never learn anything unless it goes wrong...). I'm using the Zephyr toolchain rather than NXP's and I'm seeing unsupported pragma warnings during build (around applying section attributes it seems). I think they've modified GCC to support a different syntax - reminiscent of AUTOSAR which is likely to be the SoC's primary market. If I have any sense, I'll create another build environment with the NXP's toolchain for comparison purposes...:blush:

flit commented 1 year ago

Hmm, well, let me know if it appears to be a pyocd issue!

I'd like to revive the feature/freertos_10 branch soon, and add automated functional tests for different FreeRTOS versions. Sorry it doesn't seem to work, but thanks for trying.

From having lots of experience debugging Zephyr linking issues (on odd toolchain variants for research), if you're getting warnings related to sections then it's probably not going to be functional. Zephyr is highly dependent on sections be assigned properly to get a functional executable. Sometimes it will link fine, and the errors only happen at runtime. If it's not reaching main, then one likely source is the kernel + device init list sections being incorrect.

dev-apcs commented 1 year ago

Thanks for the support!

I'm off on another job atm but expect to get back to this shortly.

I haven't gotten any further with the freertos problem. I need to sanity-check my setup before drawing any conclusions. Presumably you're only interested in testing the the touch-points for the functional tests? That ought to reduce the effort required.

Zephyr: from memory (a week's a long time):

Anyhow, back on topic:

The Keil pack .pdsc appears to have been written against an earlier silicon version. Some of the fields have moved, particularly around debug from first instruction (some fields appear to have moved from MDM-AP to SDA-AP for instance). I'd like to straighten this out but it probably makes more sense to report the issue to the author - which I'll do once I've completed the analysis. Perhaps the issue could include a nudge towards not re-purposing?

flit commented 1 year ago

I'll create an internal Arm bug ticket against the Keil pack to hopefully get it updated to the latest silicon revision. And I'll definitely mention the need to not repurpose standard sequences. 😄

FreeRTOS: Pretty much. Ideally the functional test would get 100% code coverage on the FreeRTOS support, with several FreeRTOS versions and CPU architecture variants. But anything would be better than the current state.

Zephyr: got it, thanks for the explanation

jonlamb-gh commented 1 month ago

@flit Hi there. I'm looking into getting S32K3xx support added to probe-rs, and came across this thread while searching around for references related to the debug sequences.

I'll create an internal Arm bug ticket against the Keil pack to hopefully get it updated to the latest silicon revision. And I'll definitely mention the need to not repurpose standard sequences.

Looks like the Keil pack has since been deprecated, did you get anywhere with this?