search

pyocd / pyOCD

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

target mimxrt685s (NXP i.MX RT685): SocTarget has no selected core #1554

Open IvoBCD opened 1 year ago

IvoBCD commented 1 year ago

Still trying to program the on-board flash of the NXP i.MX RT685EVK through pyOCD; I get an "SoCTarget has no selected core" error.

(NXP.MIMXRT685S_DFP.pdsc modified, removing Pname="cm33")

+ set -e
+ grep DebugPortStart mypack/NXP.MIMXRT685S_DFP.pdsc
          <sequence name="DebugPortStart">
+ cat pyocd_user.py
session.options['debug.log_flm_info'] = True
session.options['allow_no_cores'] = True

def will_connect():
    extFlash = FlashRegion(
               name="flexspi",
               start=0x18000000,
               length=0x800000,
               is_boot_memory=True,
               blocksize=0x1000,
               page_size=0x100,
               flm = "MIMXRT6XX_EVK_FLEXSPI_S.FLM",
            )
    target.memory_map.add_region(extFlash)
+ pyocd flash -v --pack mypack -e chip -t mimxrt685s blinky-mimxrt685_evk_cm33-3.3.0.elf
0010728 W CMSIS-Pack device MIMXRT685S has no identifiable boot memory [cmsis_pack]
0010978 I Target type is mimxrt685s [board]
0014782 I DP IDR = 0x6ba02477 (v2 rev6) [dap]
0014857 I debugvar 'BootTime' = 0x2710 (10000) [pack_target]
0014863 I debugvar 'Dbg_CR' = 0x0 (0) [pack_target]
0014869 I debugvar 'SWO_Pin' = 0x0 (0) [pack_target]
0016292 I AHB-AP#0 IDR = 0x84770001 (AHB-AP var0 rev8) [discovery]
0016388 I AP#2 IDR = 0x002a0000 (AP var0 rev0) [discovery]
0016808 W Skipping CoreSight discovery for AHB-AP#0 because it is disabled [ap]
0016814 E No cores were discovered! [coresight_target]
0016825 I Creating flash algo for region flexspi from: /home/root/nxp/MIMXRT6XX_EVK_FLEXSPI_S.FLM [flm_region_builder]
0017028 I Loading /home/root/nxp/blinky-mimxrt685_evk_cm33-3.3.0.elf [load_cmd]
[                                                  ]   0%0017455 C Error: 'SoCTarget has no selected core' [__main__]

with more logging detail:

0017231 D flash algo: [stack=0x1f850; 0x1f850 b] [b2=0x1f950,+0x1f950] [b1=0x1f850,+0x1f850] [code=0x1fa5c,+0x1fa5c,0x5a4 b] (ram=0x00000000, 0x20000 b) [flash_algo]
0017237 D Running task notify [sequencer]
0017255 I Loading /home/root/nxp/blinky-mimxrt685_evk_cm33-3.3.0.elf [load_cmd]
0017302 D Skipping segment LMA:0x18005598, VMA:0x18005598, size 8 [file_programmer]
0017308 D Writing segment LMA:0x18000000, VMA:0x18000000, size 4912 [file_programmer]
0017325 D Writing segment LMA:0x18001330, VMA:0x30180000, size 256 [file_programmer]
0017332 D Writing segment LMA:0x18001430, VMA:0x18001430, size 18364 [file_programmer]
0017349 D Writing segment LMA:0x18005bec, VMA:0x30180100, size 2386 [file_programmer]
0017365 D Writing segment LMA:0x1800653e, VMA:0x1800653e, size 4 [file_programmer]
0017372 D Skipping segment LMA:0x30180a58, VMA:0x30180a58, size 0 [file_programmer]
0017413 D Using double buffer chip erase program [builder]
0017418 D 0 of 102 pages have erased data [builder]
[                                                  ]   0%0017435 D uninit session <pyocd.core.session.Session object at 0x7fbba39810> [session]
0017441 D uninit board <pyocd.board.board.Board object at 0x7fb9c134d0> [board]
0017831 C Error: 'SoCTarget has no selected core' [__main__]
Traceback (most recent call last):
  File "/usr/lib/python3.11/site-packages/pyocd/__main__.py", line 161, in run
    status = cmd.invoke()
             ^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/pyocd/subcommands/load_cmd.py", line 130, in invoke
    programmer.program(filename,
  File "/usr/lib/python3.11/site-packages/pyocd/flash/file_programmer.py", line 175, in program
    self._loader.commit()
  File "/usr/lib/python3.11/site-packages/pyocd/flash/loader.py", line 295, in commit
    perf = builder.program(chip_erase=chipErase,
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
flit commented 1 year ago

This error is because pyocd hasn't been able to successfully find an accessible CPU core. It needs a CPU to run the flash algorithm, and when it tries to access the default core (abstracted by the SoCTarget class's notion of a currently selected core) it, naturally, fails.

For some reason, debug is not being properly unlocked, thus the "Skipping CoreSight discovery for AHB-AP#0 because it is disabled" warning. Which is strange, because the last you provided in #1547 shows that AHB-AP#0 has been successfully enabled and the CPU discovered.

Did the command for the final #1547 log also fail with the same "no selected core" error?

Would you mind attaching the log with -vv -Lpyocd.debug.sequences.sequences.trace=debug added to the command line? This will output debug logging plus the full debug sequence execution trace. Maybe we can figure out why debug isn't unlocked like it should be.

IvoBCD commented 1 year ago

I've had some USB host stack issues affecting my tests, with those sorted out and updating to latest PyOCD, the core does seem to be detected, and programming fails with target was not halted as expected after calling flash algorithm routine (IPSR=3).

# pyocd flash --pack ./NXP.MIMXRT685S_DFP.16.0.0 -t mimxrt685s blinky-mimxrt685_evk_cm33-3.3.0.elf
0007439 W CMSIS-Pack device MIMXRT685S has no identifiable boot memory [cmsis_pack]
0011302 I Loading /home/root/mimxrt685evk/blinky-mimxrt685_evk_cm33-3.3.0.elf [load_cmd]
0012667 C target was not halted as expected after calling flash algorithm routine (IPSR=3) [__main__]

Detailed log:

# pyocd --version
0.35.0.dev+gda303b04
+ pyocd list
  #   Probe/Board                                     Unique ID   Target  
--------------------------------------------------------------------------
  0   NXP Semiconductors LPC-LINK2 CMSIS-DAP V5.361   NRAQBQHR    n/a     
# grep DebugPortStart ./NXP.MIMXRT685S_DFP.16.0.0/NXP.MIMXRT685S_DFP.pdsc
      <sequence name="DebugPortStart"> <!-- [removed for PyOCD] Pname="cm33" -->
# cat pyocd_user.py
session.options['debug.log_flm_info'] = True
session.options['allow_no_cores'] = True
def will_connect():
    extFlash = FlashRegion(
               name="flexspi",
               start=0x18000000,
               length=0x800000,
               is_boot_memory=True,
               blocksize=0x1000,
               page_size=0x100,
               flm = "MIMXRT6XX_EVK_FLEXSPI_S.FLM",
            )
    target.memory_map.add_region(extFlash)
# pyocd flash -v -vv -Lpyocd.debug.sequences.sequences.trace=debug --pack ./NXP.MIMXRT685S_DFP.16.0.0 -t mimxrt685s blinky-mimxrt685_evk_cm33-3.3.0.elf
0004286 D setting log level debug for ['pyocd.debug.sequences.sequences.trace'] [__main__]
0004430 D Project directory: /home/root/mimxrt685evk [session]
0007379 D Project directory: /home/root/mimxrt685evk [session]
0007381 D Loading user script: /home/root/mimxrt685evk/pyocd_user.py [session]
0007423 D Detaching Kernel Driver of Interface 0 from USB device (VID=1fc9 PID=0090). [pyusb_backend]
0007438 D CMSIS-DAP v1 probe NRAQBQHR: protocol version 1.1.0 [dap_access_cmsis_dap]
0007446 D closing interface [pyusb_backend]
0007520 D MIMXRT685S_DFP DFP (MIMXRT685S): not loading non-default flash algorithm 'arm/MIMXRT6XX_FLEXSPI_B_SFDP_QSPI.FLM' [cmsis_pack]
0007521 D MIMXRT685S_DFP DFP (MIMXRT685S): not loading non-default flash algorithm 'arm/MIMXRT6XX_FLEXSPI_B_SFDP_QSPI_S.FLM' [cmsis_pack]
0007522 W CMSIS-Pack device MIMXRT685S has no identifiable boot memory [cmsis_pack]
0007775 I Target type is mimxrt685s [board]
0007814 D Detaching Kernel Driver of Interface 0 from USB device (VID=1fc9 PID=0090). [pyusb_backend]
0007828 D Running task load_svd [sequencer]
0009791 D Running task pre_connect [sequencer]
0009808 D Running task dp_init [sequencer]
0009814 D Running task lock_probe [sequencer]
0009820 D Running task get_probe_capabilities [sequencer]
0009826 D Running task connect [sequencer]
0009941 D Default wire protocol selected; using SWD [dap]
0009962 D Sending deprecated SWJ sequence to select SWD [swj]
0010046 I DP IDR = 0x6ba02477 (v2 rev6) [dap]
0010051 D Running task clear_sticky_err [sequencer]
0010057 D Running task power_up_debug [sequencer]
0010063 D Running debug sequence 'DebugPortStart' [pack_target]
0010073 D (line 3): decl SWO_Pin = 0x0 [sequences]
0010085 D (line 4): decl Dbg_CR = 0x0 [sequences]
0010090 D (line 5): decl BootTime = 0x2710 [sequences]
0010096 I debugvar 'BootTime' = 0x2710 (10000) [pack_target]
0010102 I debugvar 'Dbg_CR' = 0x0 (0) [pack_target]
0010107 I debugvar 'SWO_Pin' = 0x0 (0) [pack_target]
0010116 D (line 2): decl SW_DP_ABORT = 0x0 [sequences]
0010121 D (line 3): decl DP_CTRL_STAT = 0x4 [sequences]
0010127 D (line 4): decl DP_SELECT = 0x8 [sequences]
0010133 D (line 5): decl powered_down = 0x0 [sequences]
0010139 D (line 7): fn writedp (DP_SELECT{0x8}, 0x0) ... [sequences]
0010160 D (line 7): fn writedp () returned 0x0 [sequences]
0010166 D (line 7): expr stmt = 0x0 [sequences]
0010171 D (line 10): fn readdp (DP_CTRL_STAT{0x4}) ... [sequences]
0010193 D (line 10): fn readdp () returned 0xf40 [sequences]
0010199 D (line 0): 0xf40 & 0xa0000000 -> 0x0 [sequences]
0010204 D (line 0): 0x0 != 0xa0000000 -> 0x1 [sequences]
0010210 D (line 10): powered_down = 0x1 [sequences]
0010216 D (line 1): expr stmt = powered_down{0x1} [sequences]
0010222 D IF(powered_down): pred=1 [sequences]
0010229 D (line 3): fn writedp (DP_CTRL_STAT{0x4}, 0x50000000) ... [sequences]
0010264 D (line 3): fn writedp () returned 0x0 [sequences]
0010270 D (line 3): expr stmt = 0x0 [sequences]
0010277 D (line 1): fn readdp (DP_CTRL_STAT{0x4}) ... [sequences]
0010317 D (line 1): fn readdp () returned 0xf0000040 [sequences]
0010323 D (line 0): 0xf0000040 & 0xa0000000 -> 0xa0000000 [sequences]
0010329 D (line 0): 0xa0000000 != 0xa0000000 -> 0x0 [sequences]
0010334 D (line 1): expr stmt = 0x0 [sequences]
0010340 D WHILE((ReadDP(DP_CTRL_STAT) & 0xA0000000) != 0xA0000000): pred=0 [sequences]
0010347 D (line 0): __protocol{0x10002} & 0xffff -> 0x2 [sequences]
0010352 D (line 0): 0x2 == 0x2 -> 0x1 [sequences]
0010358 D (line 1): expr stmt = 0x1 [sequences]
0010364 D IF((__protocol & 0xFFFF) == 2): pred=1 [sequences]
0010371 D (line 3): fn writedp (DP_CTRL_STAT{0x4}, 0x50000f00) ... [sequences]
0010392 D (line 3): fn writedp () returned 0x0 [sequences]
0010398 D (line 3): expr stmt = 0x0 [sequences]
0010404 D (line 6): fn writedp (SW_DP_ABORT{0x0}, 0x1e) ... [sequences]
0010439 D (line 6): fn writedp () returned 0x0 [sequences]
0010444 D (line 6): expr stmt = 0x0 [sequences]
0010450 D (line 8): fn sequence ('EnableDebugMailbox') ... [sequences]
0010456 D Running debug sub-sequence 'EnableDebugMailbox' [functions]
0010464 D (line 1): fn readap (0x0) ... [sequences]
0010500 D (line 1): fn readap () returned 0x3800052 [sequences]
0010506 D (line 0): 0x3800052 & 0x40 -> 0x40 [sequences]
0010512 D (line 0): ! 0x40 -> 0x0 [sequences]
0010517 D (line 1): expr stmt = 0x0 [sequences]
0010523 D IF(!(ReadAP(0x0) & 0x40)): pred=0 [sequences]
0010529 D Sub-sequence 'EnableDebugMailbox' result = 0 [functions]
0010534 D (line 8): fn sequence () returned 0x0 [sequences]
0010540 D (line 8): expr stmt = 0x0 [sequences]
0010546 D Running task check_version [sequencer]
0010551 D Running task unlock_probe [sequencer]
0010557 D Running task unlock_device [sequencer]
0010563 D Running task create_discoverer [sequencer]
0010568 D Running task discovery [sequencer]
0010574 D Running task find_aps [sequencer]
0010699 D Running task create_aps [sequencer]
0010705 D Running task create_ap.0 [sequencer]
0010776 D AHB-AP#0 default HPROT=3 HNONSEC=0 [ap]
0010811 D AHB-AP#0 implemented HPROT=f HNONSEC=1 [ap]
0010833 I AHB-AP#0 IDR = 0x84770001 (AHB-AP var0 rev8) [discovery]
0010839 D Running task create_ap.2 [sequencer]
0010874 I AP#2 IDR = 0x002a0000 (AP var0 rev0) [discovery]
0010880 D Running task create_ap.3 [sequencer]
0010945 D APB-AP#3 default HPROT=0 HNONSEC=0 [ap]
0010981 D APB-AP#3 implemented HPROT=0 HNONSEC=0 [ap]
0011022 I APB-AP#3 IDR = 0x54770002 (APB-AP var0 rev5) [discovery]
0011028 D Running task find_components [sequencer]
0011033 D Running task init_ap.0 [sequencer]
0011116 I AHB-AP#0 Class 0x1 ROM table #0 @ 0xe00fe000 (designer=015 part=000) [rom_table]
0011173 I [0]<e00ff000:ROM class=1 designer=43b:Arm part=4c9> [rom_table]
0011179 I   AHB-AP#0 Class 0x1 ROM table #1 @ 0xe00ff000 (designer=43b:Arm part=4c9) [rom_table]
0011230 I   [0]<e000e000:SCS M33 class=9 designer=43b:Arm part=d21 devtype=00 archid=2a04 devid=0:0:0> [rom_table]
0011297 I   [1]<e0001000:DWT M33 class=9 designer=43b:Arm part=d21 devtype=00 archid=1a02 devid=0:0:0> [rom_table]
0011347 I   [2]<e0002000:BPU M33 class=9 designer=43b:Arm part=d21 devtype=00 archid=1a03 devid=0:0:0> [rom_table]
0011403 I   [3]<e0000000:ITM M33 class=9 designer=43b:Arm part=d21 devtype=43 archid=1a01 devid=0:0:0> [rom_table]
0011409 D   [4]<fff41002 not present> [rom_table]
0011445 I   [5]<e0041000:ETM M33 class=9 designer=43b:Arm part=d21 devtype=13 archid=4a13 devid=0:0:0> [rom_table]
0011521 I   [6]<e0042000:CTI M33 class=9 designer=43b:Arm part=d21 devtype=14 archid=1a14 devid=40800:0:0> [rom_table]
0011527 D   [7]<fff44002 not present> [rom_table]
0011579 I [1]<e0040000:TPIU M33 class=9 designer=43b:Arm part=d21 devtype=11 archid=0000 devid=ca1:0:0> [rom_table]
0011585 D [2]<1ff02002 not present> [rom_table]
0011591 D [3]<1ff02002 not present> [rom_table]
0011597 D Running task create_cores [sequencer]
0011602 D Creating SCS component [discovery]
0011632 D selected core #0 [soc_target]
0011684 I CPU core #0 is Cortex-M33 r0p3 (security ext present) [cortex_m_v8m]
0011720 I FPU present: FPv5-SP-D16-M [cortex_m]
0011762 D Running task configure_core_reset [sequencer]
0011768 D updated DFP core #0 reset types: {<ResetType.SW_EMULATED: 5>, <ResetType.HW: 1>, <ResetType.SW: 2>, <ResetType.SW_SYSTEM: 3>} [pack_target]
0011774 I Setting core #0 (cm33) default reset sequence to ResetSystem [pack_target]
0011780 D Running task create_components [sequencer]
0011786 D Creating DWT component [discovery]
0011842 I 4 hardware watchpoints [dwt]
0011850 D Creating BPU component [discovery]
0011871 I 8 hardware breakpoints, 1 literal comparators [fpb]
0011878 D fpb has been disabled [fpb]
0011886 D Creating ITM component [discovery]
0011927 D Creating TPIU component [discovery]
0011949 D Running task check_for_cores [sequencer]
0011954 D Running task halt_on_connect [sequencer]
0011960 D halting core 0 [cortex_m]
0011981 D Running task post_connect [sequencer]
0011987 D Running task post_connect_hook [sequencer]
0011992 D Running task create_flash [sequencer]
0012004 I Creating flash algo for region flexspi from: /home/root/mimxrt685evk/MIMXRT6XX_EVK_FLEXSPI_S.FLM [flm_region_builder]
0012161 D Flash algo info: Flash Device:
  name=b'MIMXRT6XX FLEXSPI'
  version=0x101
  type=5
  start=0x18000000
  size=0x4000000
  page_size=0x100
  value_empty=0xff
  prog_timeout_ms=300
  erase_timeout_ms=3000
  sectors:
    start=0x0, size=0x1000
 [flm_region_builder]
0012171 D flash algo: [stack=0x1f850; 0x1f850 b] [b2=0x1f950,+0x1f950] [b1=0x1f850,+0x1f850] [code=0x1fa5c,+0x1fa5c,0x5a4 b] (ram=0x00000000, 0x20000 b) [flash_algo]
0012177 D Running task notify [sequencer]
0012195 I Loading /home/root/mimxrt685evk/blinky-mimxrt685_evk_cm33-3.3.0.elf [load_cmd]
0012234 D Skipping segment LMA:0x18005598, VMA:0x18005598, size 8 [file_programmer]
0012241 D Writing segment LMA:0x18000000, VMA:0x18000000, size 4912 [file_programmer]
0012252 D Writing segment LMA:0x18001330, VMA:0x30180000, size 256 [file_programmer]
0012269 D Writing segment LMA:0x18001430, VMA:0x18001430, size 18364 [file_programmer]
0012280 D Writing segment LMA:0x18005bec, VMA:0x30180100, size 2386 [file_programmer]
0012292 D Writing segment LMA:0x1800653e, VMA:0x1800653e, size 4 [file_programmer]
0012298 D Skipping segment LMA:0x30180a58, VMA:0x30180a58, size 0 [file_programmer]
0012338 D halting core 0 [cortex_m]
0012359 D set reset catch, core 0 [cortex_m]
0012365 D halting core 0 [cortex_m]
0012417 D reset, core 0, type=SW_SYSTEM [cortex_m]
0012423 D Running debug sequence 'ResetSystem' (cm33) [pack_target]
0012440 D (line 2): __dp = 0x0 [sequences]
0012446 D (line 3): __ap = 0x0 [sequences]
0012452 D (line 5): decl SCS_Addr = 0xe000e000 [sequences]
0012457 D (line 0): SCS_Addr{0xe000e000} + 0xd0c -> 0xe000ed0c [sequences]
0012463 D (line 6): decl AIRCR_Addr = 0xe000ed0c [sequences]
0012469 D (line 0): SCS_Addr{0xe000e000} + 0xdf0 -> 0xe000edf0 [sequences]
0012474 D (line 7): decl DHCSR_Addr = 0xe000edf0 [sequences]
0012481 D (line 0): SCS_Addr{0xe000e000} + 0xdfc -> 0xe000edfc [sequences]
0012487 D (line 8): decl DEMCR_Addr = 0xe000edfc [sequences]
0012492 D (line 9): decl tmp = 0 [sequences]
0012498 D (line 11): fn write32 (DHCSR_Addr{0xe000edf0}, 0xa05f0003) ... [sequences]
0012519 D (line 11): fn write32 () returned 0x0 [sequences]
0012525 D (line 11): expr stmt = 0x0 [sequences]
0012531 D (line 13): fn read32 (DEMCR_Addr{0xe000edfc}) ... [sequences]
0012573 D (line 13): fn read32 () returned 0x1100001 [sequences]
0012579 D (line 13): tmp = 0x1100001 [sequences]
0012585 D (line 0): tmp{0x1100001} | 0x1000000 -> 0x1100001 [sequences]
0012590 D (line 14): fn write32 (DEMCR_Addr{0xe000edfc}, 0x1100001) ... [sequences]
0012632 D (line 14): fn write32 () returned 0x0 [sequences]
0012638 D (line 14): expr stmt = 0x0 [sequences]
0012643 D (line 15): fn sequence ('ResetFlash') ... [sequences]
0012649 D Running debug sub-sequence 'ResetFlash' (cm33) [functions]
0012656 D (line 0): __connection{0x1} & 0x1 -> 0x1 [sequences]
0012662 D (line 1): expr stmt = 0x1 [sequences]
0012667 D IF((__connection & 0x01)): pred=1 [sequences]
0012677 D (line 3): fn write32 (0x40004130, 0x130) ... [sequences]
0012698 D (line 3): fn write32 () returned 0x0 [sequences]
0012704 D (line 3): expr stmt = 0x0 [sequences]
0012710 D (line 4): fn write32 (0x40021044, 0x4) ... [sequences]
0012731 D (line 4): fn write32 () returned 0x0 [sequences]
0012737 D (line 4): expr stmt = 0x0 [sequences]
0012743 D (line 5): fn write32 (0x40020074, 0x4) ... [sequences]
0012763 D (line 5): fn write32 () returned 0x0 [sequences]
0012769 D (line 5): expr stmt = 0x0 [sequences]
0012775 D (line 6): fn write32 (0x40102008, 0x1000) ... [sequences]
0012796 D (line 6): fn write32 () returned 0x0 [sequences]
0012802 D (line 6): expr stmt = 0x0 [sequences]
0012808 D (line 7): fn write32 (0x40102288, 0x1000) ... [sequences]
0012829 D (line 7): fn write32 () returned 0x0 [sequences]
0012835 D (line 7): expr stmt = 0x0 [sequences]
0012841 D (line 8): fn dap_delay (0x64) ... [sequences]
0012852 D (line 8): fn dap_delay () returned 0x0 [sequences]
0012857 D (line 8): expr stmt = 0x0 [sequences]
0012863 D (line 9): fn write32 (0x40102208, 0x1000) ... [sequences]
0012884 D (line 9): fn write32 () returned 0x0 [sequences]
0012890 D (line 9): expr stmt = 0x0 [sequences]
0012896 D Sub-sequence 'ResetFlash' result = 0 [functions]
0012902 D (line 15): fn sequence () returned 0x0 [sequences]
0012907 D (line 15): expr stmt = 0x0 [sequences]
0012913 D (line 17): fn write32 (0xe0001020, 0x50002034) ... [sequences]
0012934 D (line 17): fn write32 () returned 0x0 [sequences]
0012940 D (line 17): expr stmt = 0x0 [sequences]
0012946 D (line 18): fn write32 (0xe0001028, 0x814) ... [sequences]
0012967 D (line 18): fn write32 () returned 0x0 [sequences]
0012972 D (line 18): expr stmt = 0x0 [sequences]
0012978 D (line 19): __errorcontrol = 0x1 [sequences]
0012984 D (line 21): fn write32 (AIRCR_Addr{0xe000ed0c}, 0x5fa0004) ... [sequences]
0013005 D Write32(0xe000ed0c) ignored TransferFaultError() because __errorcontrol is set [functions]
0013011 D (line 21): fn write32 () returned 0x0 [sequences]
0013017 D (line 21): expr stmt = 0x0 [sequences]
0013023 D (line 22): fn sequence ('WaitForStopAfterReset') ... [sequences]
0013028 D Running debug sub-sequence 'WaitForStopAfterReset' (cm33) [functions]
0013035 D (line 2): decl SCS_Addr = 0xe000e000 [sequences]
0013041 D (line 0): SCS_Addr{0xe000e000} + 0xdf0 -> 0xe000edf0 [sequences]
0013047 D (line 3): decl DHCSR_Addr = 0xe000edf0 [sequences]
0013053 D (line 0): SCS_Addr{0xe000e000} + 0xd30 -> 0xe000ed30 [sequences]
0013058 D (line 4): decl DFSR_Addr = 0xe000ed30 [sequences]
0013065 D (line 1): fn readap (0x0) ... [sequences]
0013087 D ReadAP(0x00000000) ignored TransferFaultError() because __errorcontrol is set [functions]
0013092 D (line 1): fn readap () returned 0x0 [sequences]
0013098 D (line 0): 0x0 & 0x40 -> 0x0 [sequences]
0013104 D (line 0): 0x0 == 0x0 -> 0x1 [sequences]
0013109 D (line 1): expr stmt = 0x1 [sequences]
0013115 D WHILE((ReadAP(0) & 0x40) == 0): pred=1 [sequences]
0013121 D (line 1): fn readap (0x0) ... [sequences]
0013157 D (line 1): fn readap () returned 0x3800052 [sequences]
0013163 D (line 0): 0x3800052 & 0x40 -> 0x40 [sequences]
0013168 D (line 0): 0x40 == 0x0 -> 0x0 [sequences]
0013174 D (line 1): expr stmt = 0x0 [sequences]
0013180 D WHILE((ReadAP(0) & 0x40) == 0): pred=0 [sequences]
0013188 D (line 2): fn sequence ('EnableDebugMailbox') ... [sequences]
0013193 D Running debug sub-sequence 'EnableDebugMailbox' (cm33) [functions]
0013201 D (line 1): fn readap (0x0) ... [sequences]
0013222 D (line 1): fn readap () returned 0x3800052 [sequences]
0013228 D (line 0): 0x3800052 & 0x40 -> 0x40 [sequences]
0013234 D (line 0): ! 0x40 -> 0x0 [sequences]
0013239 D (line 1): expr stmt = 0x0 [sequences]
0013245 D IF(!(ReadAP(0x0) & 0x40)): pred=0 [sequences]
0013251 D Sub-sequence 'EnableDebugMailbox' result = 0 [functions]
0013256 D (line 2): fn sequence () returned 0x0 [sequences]
0013262 D (line 2): expr stmt = 0x0 [sequences]
0013268 D (line 3): fn write32 (DHCSR_Addr{0xe000edf0}, 0xa05f0003) ... [sequences]
0013288 D (line 3): fn write32 () returned 0x0 [sequences]
0013293 D (line 3): expr stmt = 0x0 [sequences]
0013299 D (line 5): fn write32 (0xe0001020, 0x0) ... [sequences]
0013319 D (line 5): fn write32 () returned 0x0 [sequences]
0013325 D (line 5): expr stmt = 0x0 [sequences]
0013330 D (line 6): fn write32 (0xe0001028, 0x0) ... [sequences]
0013443 D (line 6): fn write32 () returned 0x0 [sequences]
0013444 D (line 6): expr stmt = 0x0 [sequences]
0013444 D Sub-sequence 'WaitForStopAfterReset' result = 0 [functions]
0013445 D (line 22): fn sequence () returned 0x0 [sequences]
0013445 D (line 22): expr stmt = 0x0 [sequences]
0013446 D (line 23): __errorcontrol = 0x0 [sequences]
0013481 D clear reset catch, core 0 [cortex_m]
0013525 D resuming core 0 [cortex_m]
0013525 D added=[] removed=[] [manager]
0013526 D bps after flush={} [manager]
0013534 D halting core 0 [cortex_m]
0013545 D halting core 0 [cortex_m]
0013569 D resuming core 0 [cortex_m]
0013569 D added=[] removed=[] [manager]
0013570 D bps after flush={} [manager]
0013577 D halting core 0 [cortex_m]
0013589 D uninit session <pyocd.core.session.Session object at 0x7fba662550> [session]
0013590 D uninit board <pyocd.board.board.Board object at 0x7fb9ff26d0> [board]
0013594 D resuming core 0 [cortex_m]
0013595 D added=[] removed=[] [manager]
0013595 D bps after flush={} [manager]
0013609 D closing interface [pyusb_backend]
0013633 C target was not halted as expected after calling flash algorithm routine (IPSR=3) [__main__]
Traceback (most recent call last):
  File "/usr/lib/python3.11/site-packages/pyocd/flash/builder.py", line 259, in _enable_read_access
    self.flash.init(self.flash.Operation.VERIFY)
  File "/usr/lib/python3.11/site-packages/pyocd/flash/flash.py", line 253, in init
    result = self._call_function_and_wait(self.flash_algo['pc_init'],
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/pyocd/flash/flash.py", line 676, in _call_function_and_wait
    return self.wait_for_completion(timeout=timeout)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/pyocd/flash/flash.py", line 663, in wait_for_completion
    raise exceptions.FlashFailure("target was not halted as expected after calling "
pyocd.core.exceptions.FlashFailure: target was not halted as expected after calling flash algorithm routine (IPSR=3)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.11/site-packages/pyocd/__main__.py", line 161, in run
    status = cmd.invoke()
             ^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/pyocd/subcommands/load_cmd.py", line 130, in invoke
    programmer.program(filename,
  File "/usr/lib/python3.11/site-packages/pyocd/flash/file_programmer.py", line 175, in program
    self._loader.commit()
  File "/usr/lib/python3.11/site-packages/pyocd/flash/loader.py", line 295, in commit
    perf = builder.program(chip_erase=chipErase,
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/pyocd/flash/builder.py", line 492, in program
    sector_erase_count, page_program_time = self._compute_sector_erase_pages_and_weight(fast_verify)
                                            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/pyocd/flash/builder.py", line 673, in _compute_sector_erase_pages_and_weight
    self._analyze_pages_with_partial_read()
  File "/usr/lib/python3.11/site-packages/pyocd/flash/builder.py", line 608, in _analyze_pages_with_partial_read
    self._enable_read_access()
  File "/usr/lib/python3.11/site-packages/pyocd/flash/builder.py", line 262, in _enable_read_access
    self.flash.init(self.flash.Operation.ERASE)
  File "/usr/lib/python3.11/site-packages/pyocd/flash/flash.py", line 253, in init
    result = self._call_function_and_wait(self.flash_algo['pc_init'],
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/pyocd/flash/flash.py", line 676, in _call_function_and_wait
    return self.wait_for_completion(timeout=timeout)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/pyocd/flash/flash.py", line 663, in wait_for_completion
    raise exceptions.FlashFailure("target was not halted as expected after calling "
pyocd.core.exceptions.FlashFailure: target was not halted as expected after calling flash algorithm routine (IPSR=3)
IvoBCD commented 1 year ago

Same outcome, but different debug logs, when using the unmodified pack file:

# pyocd flash -v -vv -Lpyocd.debug.sequences.sequences.trace=debug --pack ./NXP.MIMXRT685S_DFP.16.0.0.pack -t mimxrt685s blinky-mimxrt685_evk_cm33-3.3.0.elf
0004299 D setting log level debug for ['pyocd.debug.sequences.sequences.trace'] [__main__]
0004443 D Project directory: /home/root/mimxrt685evk [session]
0007363 D Project directory: /home/root/mimxrt685evk [session]
0007366 D Loading user script: /home/root/mimxrt685evk/pyocd_user.py [session]
0007407 D Detaching Kernel Driver of Interface 0 from USB device (VID=1fc9 PID=0090). [pyusb_backend]
0007424 D CMSIS-DAP v1 probe NRAQBQHR: protocol version 1.1.0 [dap_access_cmsis_dap]
0007431 D closing interface [pyusb_backend]
0007545 D MIMXRT685S_DFP DFP (MIMXRT685S): not loading non-default flash algorithm 'arm/MIMXRT6XX_FLEXSPI_B_SFDP_QSPI.FLM' [cmsis_pack]
0007546 D MIMXRT685S_DFP DFP (MIMXRT685S): not loading non-default flash algorithm 'arm/MIMXRT6XX_FLEXSPI_B_SFDP_QSPI_S.FLM' [cmsis_pack]
0007546 W CMSIS-Pack device MIMXRT685S has no identifiable boot memory [cmsis_pack]
0007851 I Target type is mimxrt685s [board]
0007891 D Detaching Kernel Driver of Interface 0 from USB device (VID=1fc9 PID=0090). [pyusb_backend]
0007904 D Running task load_svd [sequencer]
0009847 D Running task pre_connect [sequencer]
0009864 D Running task dp_init [sequencer]
0009870 D Running task lock_probe [sequencer]
0009877 D Running task get_probe_capabilities [sequencer]
0009883 D Running task connect [sequencer]
0009975 D Default wire protocol selected; using SWD [dap]
0010010 D Sending deprecated SWJ sequence to select SWD [swj]
0010129 I DP IDR = 0x6ba02477 (v2 rev6) [dap]
0010135 D Running task clear_sticky_err [sequencer]
0010141 D Running task power_up_debug [sequencer]
0010168 D Running task check_version [sequencer]
0010173 D Running task unlock_probe [sequencer]
0010179 D Running task unlock_device [sequencer]
0010185 D Running task create_discoverer [sequencer]
0010191 D Running task discovery [sequencer]
0010196 D Running task find_aps [sequencer]
0010380 D Running task create_aps [sequencer]
0010386 D Running task create_ap.0 [sequencer]
0010454 D AHB-AP#0 default HPROT=3 HNONSEC=0 [ap]
0010474 D AHB-AP#0 implemented HPROT=f HNONSEC=1 [ap]
0010496 I AHB-AP#0 IDR = 0x84770001 (AHB-AP var0 rev8) [discovery]
0010502 D Running task create_ap.2 [sequencer]
0010522 I AP#2 IDR = 0x002a0000 (AP var0 rev0) [discovery]
0010528 D Running task create_ap.3 [sequencer]
0010624 D APB-AP#3 default HPROT=0 HNONSEC=0 [ap]
0010645 D APB-AP#3 implemented HPROT=0 HNONSEC=0 [ap]
0010686 I APB-AP#3 IDR = 0x54770002 (APB-AP var0 rev5) [discovery]
0010692 D Running task find_components [sequencer]
0010698 D Running task init_ap.0 [sequencer]
0010790 I AHB-AP#0 Class 0x1 ROM table #0 @ 0xe00fe000 (designer=015 part=000) [rom_table]
0010841 I [0]<e00ff000:ROM class=1 designer=43b:Arm part=4c9> [rom_table]
0010847 I   AHB-AP#0 Class 0x1 ROM table #1 @ 0xe00ff000 (designer=43b:Arm part=4c9) [rom_table]
0010933 I   [0]<e000e000:SCS M33 class=9 designer=43b:Arm part=d21 devtype=00 archid=2a04 devid=0:0:0> [rom_table]
0010999 I   [1]<e0001000:DWT M33 class=9 designer=43b:Arm part=d21 devtype=00 archid=1a02 devid=0:0:0> [rom_table]
0011035 I   [2]<e0002000:BPU M33 class=9 designer=43b:Arm part=d21 devtype=00 archid=1a03 devid=0:0:0> [rom_table]
0011071 I   [3]<e0000000:ITM M33 class=9 designer=43b:Arm part=d21 devtype=43 archid=1a01 devid=0:0:0> [rom_table]
0011076 D   [4]<fff41002 not present> [rom_table]
0011112 I   [5]<e0041000:ETM M33 class=9 designer=43b:Arm part=d21 devtype=13 archid=4a13 devid=0:0:0> [rom_table]
0011148 I   [6]<e0042000:CTI M33 class=9 designer=43b:Arm part=d21 devtype=14 archid=1a14 devid=40800:0:0> [rom_table]
0011153 D   [7]<fff44002 not present> [rom_table]
0011204 I [1]<e0040000:TPIU M33 class=9 designer=43b:Arm part=d21 devtype=11 archid=0000 devid=ca1:0:0> [rom_table]
0011210 D [2]<1ff02002 not present> [rom_table]
0011215 D [3]<1ff02002 not present> [rom_table]
0011221 D Running task create_cores [sequencer]
0011227 D Creating SCS component [discovery]
0011257 D selected core #0 [soc_target]
0011309 I CPU core #0 is Cortex-M33 r0p3 (security ext present) [cortex_m_v8m]
0011359 I FPU present: FPv5-SP-D16-M [cortex_m]
0011422 D Running task configure_core_reset [sequencer]
0011428 D updated DFP core #0 reset types: {<ResetType.HW: 1>, <ResetType.SW_EMULATED: 5>, <ResetType.SW_SYSTEM: 3>, <ResetType.SW: 2>} [pack_target]
0011433 I Setting core #0 (cm33) default reset sequence to ResetSystem [pack_target]
0011449 D Running task create_components [sequencer]
0011455 D Creating DWT component [discovery]
0011507 I 4 hardware watchpoints [dwt]
0011515 D Creating BPU component [discovery]
0011557 I 8 hardware breakpoints, 1 literal comparators [fpb]
0011564 D fpb has been disabled [fpb]
0011572 D Creating ITM component [discovery]
0011622 D Creating TPIU component [discovery]
0011644 D Running task check_for_cores [sequencer]
0011649 D Running task halt_on_connect [sequencer]
0011655 D halting core 0 [cortex_m]
0011676 D Running task post_connect [sequencer]
0011681 D Running task post_connect_hook [sequencer]
0011687 D Running task create_flash [sequencer]
0011698 I Creating flash algo for region flexspi from: /home/root/mimxrt685evk/MIMXRT6XX_EVK_FLEXSPI_S.FLM [flm_region_builder]
0011855 D Flash algo info: Flash Device:
  name=b'MIMXRT6XX FLEXSPI'
  version=0x101
  type=5
  start=0x18000000
  size=0x4000000
  page_size=0x100
  value_empty=0xff
  prog_timeout_ms=300
  erase_timeout_ms=3000
  sectors:
    start=0x0, size=0x1000
 [flm_region_builder]
0011863 D flash algo: [stack=0x1f850; 0x1f850 b] [b2=0x1f950,+0x1f950] [b1=0x1f850,+0x1f850] [code=0x1fa5c,+0x1fa5c,0x5a4 b] (ram=0x00000000, 0x20000 b) [flash_algo]
0011870 D Running task notify [sequencer]
0011887 I Loading /home/root/mimxrt685evk/blinky-mimxrt685_evk_cm33-3.3.0.elf [load_cmd]
0011937 D Skipping segment LMA:0x18005598, VMA:0x18005598, size 8 [file_programmer]
0011948 D Writing segment LMA:0x18000000, VMA:0x18000000, size 4912 [file_programmer]
0011959 D Writing segment LMA:0x18001330, VMA:0x30180000, size 256 [file_programmer]
0011981 D Writing segment LMA:0x18001430, VMA:0x18001430, size 18364 [file_programmer]
0011998 D Writing segment LMA:0x18005bec, VMA:0x30180100, size 2386 [file_programmer]
0012009 D Writing segment LMA:0x1800653e, VMA:0x1800653e, size 4 [file_programmer]
0012016 D Skipping segment LMA:0x30180a58, VMA:0x30180a58, size 0 [file_programmer]
0012055 D halting core 0 [cortex_m]
0012077 D set reset catch, core 0 [cortex_m]
0012083 D halting core 0 [cortex_m]
0012130 D reset, core 0, type=SW_SYSTEM [cortex_m]
0012137 D Running debug sequence 'ResetSystem' (cm33) [pack_target]
0012147 D (line 3): decl SWO_Pin = 0x0 [sequences]
0012153 D (line 4): decl Dbg_CR = 0x0 [sequences]
0012159 D (line 5): decl BootTime = 0x2710 [sequences]
0012164 I debugvar 'BootTime' = 0x2710 (10000) [pack_target]
0012170 I debugvar 'Dbg_CR' = 0x0 (0) [pack_target]
0012176 I debugvar 'SWO_Pin' = 0x0 (0) [pack_target]
0012193 D (line 2): __dp = 0x0 [sequences]
0012199 D (line 3): __ap = 0x0 [sequences]
0012204 D (line 5): decl SCS_Addr = 0xe000e000 [sequences]
0012210 D (line 0): SCS_Addr{0xe000e000} + 0xd0c -> 0xe000ed0c [sequences]
0012216 D (line 6): decl AIRCR_Addr = 0xe000ed0c [sequences]
0012222 D (line 0): SCS_Addr{0xe000e000} + 0xdf0 -> 0xe000edf0 [sequences]
0012227 D (line 7): decl DHCSR_Addr = 0xe000edf0 [sequences]
0012233 D (line 0): SCS_Addr{0xe000e000} + 0xdfc -> 0xe000edfc [sequences]
0012239 D (line 8): decl DEMCR_Addr = 0xe000edfc [sequences]
0012244 D (line 9): decl tmp = 0 [sequences]
0012250 D (line 11): fn write32 (DHCSR_Addr{0xe000edf0}, 0xa05f0003) ... [sequences]
0012277 D (line 11): fn write32 () returned 0x0 [sequences]
0012282 D (line 11): expr stmt = 0x0 [sequences]
0012288 D (line 13): fn read32 (DEMCR_Addr{0xe000edfc}) ... [sequences]
0012315 D (line 13): fn read32 () returned 0x1100001 [sequences]
0012331 D (line 13): tmp = 0x1100001 [sequences]
0012332 D (line 0): tmp{0x1100001} | 0x1000000 -> 0x1100001 [sequences]
0012338 D (line 14): fn write32 (DEMCR_Addr{0xe000edfc}, 0x1100001) ... [sequences]
0012364 D (line 14): fn write32 () returned 0x0 [sequences]
0012370 D (line 14): expr stmt = 0x0 [sequences]
0012376 D (line 15): fn sequence ('ResetFlash') ... [sequences]
0012381 D Running debug sub-sequence 'ResetFlash' (cm33) [functions]
0012388 D (line 0): __connection{0x1} & 0x1 -> 0x1 [sequences]
0012394 D (line 1): expr stmt = 0x1 [sequences]
0012399 D IF((__connection & 0x01)): pred=1 [sequences]
0012409 D (line 3): fn write32 (0x40004130, 0x130) ... [sequences]
0012430 D (line 3): fn write32 () returned 0x0 [sequences]
0012436 D (line 3): expr stmt = 0x0 [sequences]
0012442 D (line 4): fn write32 (0x40021044, 0x4) ... [sequences]
0012468 D (line 4): fn write32 () returned 0x0 [sequences]
0012474 D (line 4): expr stmt = 0x0 [sequences]
0012479 D (line 5): fn write32 (0x40020074, 0x4) ... [sequences]
0012506 D (line 5): fn write32 () returned 0x0 [sequences]
0012512 D (line 5): expr stmt = 0x0 [sequences]
0012518 D (line 6): fn write32 (0x40102008, 0x1000) ... [sequences]
0012544 D (line 6): fn write32 () returned 0x0 [sequences]
0012550 D (line 6): expr stmt = 0x0 [sequences]
0012556 D (line 7): fn write32 (0x40102288, 0x1000) ... [sequences]
0012582 D (line 7): fn write32 () returned 0x0 [sequences]
0012588 D (line 7): expr stmt = 0x0 [sequences]
0012594 D (line 8): fn dap_delay (0x64) ... [sequences]
0012605 D (line 8): fn dap_delay () returned 0x0 [sequences]
0012611 D (line 8): expr stmt = 0x0 [sequences]
0012617 D (line 9): fn write32 (0x40102208, 0x1000) ... [sequences]
0012643 D (line 9): fn write32 () returned 0x0 [sequences]
0012649 D (line 9): expr stmt = 0x0 [sequences]
0012655 D Sub-sequence 'ResetFlash' result = 0 [functions]
0012661 D (line 15): fn sequence () returned 0x0 [sequences]
0012666 D (line 15): expr stmt = 0x0 [sequences]
0012672 D (line 17): fn write32 (0xe0001020, 0x50002034) ... [sequences]
0012698 D (line 17): fn write32 () returned 0x0 [sequences]
0012698 D (line 17): expr stmt = 0x0 [sequences]
0012699 D (line 18): fn write32 (0xe0001028, 0x814) ... [sequences]
0012718 D (line 18): fn write32 () returned 0x0 [sequences]
0012724 D (line 18): expr stmt = 0x0 [sequences]
0012730 D (line 19): __errorcontrol = 0x1 [sequences]
0012736 D (line 21): fn write32 (AIRCR_Addr{0xe000ed0c}, 0x5fa0004) ... [sequences]
0012761 D Write32(0xe000ed0c) ignored TransferFaultError() because __errorcontrol is set [functions]
0012767 D (line 21): fn write32 () returned 0x0 [sequences]
0012773 D (line 21): expr stmt = 0x0 [sequences]
0012779 D (line 22): fn sequence ('WaitForStopAfterReset') ... [sequences]
0012785 D Running debug sub-sequence 'WaitForStopAfterReset' (cm33) [functions]
0012791 D (line 2): decl SCS_Addr = 0xe000e000 [sequences]
0012797 D (line 0): SCS_Addr{0xe000e000} + 0xdf0 -> 0xe000edf0 [sequences]
0012803 D (line 3): decl DHCSR_Addr = 0xe000edf0 [sequences]
0012809 D (line 0): SCS_Addr{0xe000e000} + 0xd30 -> 0xe000ed30 [sequences]
0012814 D (line 4): decl DFSR_Addr = 0xe000ed30 [sequences]
0012821 D (line 1): fn readap (0x0) ... [sequences]
0012848 D ReadAP(0x00000000) ignored TransferFaultError() because __errorcontrol is set [functions]
0012854 D (line 1): fn readap () returned 0x0 [sequences]
0012860 D (line 0): 0x0 & 0x40 -> 0x0 [sequences]
0012865 D (line 0): 0x0 == 0x0 -> 0x1 [sequences]
0012871 D (line 1): expr stmt = 0x1 [sequences]
0012877 D WHILE((ReadAP(0) & 0x40) == 0): pred=1 [sequences]
0012882 D (line 1): fn readap (0x0) ... [sequences]
0012909 D (line 1): fn readap () returned 0x3800052 [sequences]
0012915 D (line 0): 0x3800052 & 0x40 -> 0x40 [sequences]
0012920 D (line 0): 0x40 == 0x0 -> 0x0 [sequences]
0012926 D (line 1): expr stmt = 0x0 [sequences]
0012932 D WHILE((ReadAP(0) & 0x40) == 0): pred=0 [sequences]
0012940 D (line 2): fn sequence ('EnableDebugMailbox') ... [sequences]
0012946 D Running debug sub-sequence 'EnableDebugMailbox' (cm33) [functions]
0012953 D (line 1): fn readap (0x0) ... [sequences]
0012979 D (line 1): fn readap () returned 0x3800052 [sequences]
0012985 D (line 0): 0x3800052 & 0x40 -> 0x40 [sequences]
0012991 D (line 0): ! 0x40 -> 0x0 [sequences]
0012996 D (line 1): expr stmt = 0x0 [sequences]
0013002 D IF(!(ReadAP(0x0) & 0x40)): pred=0 [sequences]
0013008 D Sub-sequence 'EnableDebugMailbox' result = 0 [functions]
0013013 D (line 2): fn sequence () returned 0x0 [sequences]
0013019 D (line 2): expr stmt = 0x0 [sequences]
0013025 D (line 3): fn write32 (DHCSR_Addr{0xe000edf0}, 0xa05f0003) ... [sequences]
0013046 D (line 3): fn write32 () returned 0x0 [sequences]
0013052 D (line 3): expr stmt = 0x0 [sequences]
0013057 D (line 5): fn write32 (0xe0001020, 0x0) ... [sequences]
0013084 D (line 5): fn write32 () returned 0x0 [sequences]
0013090 D (line 5): expr stmt = 0x0 [sequences]
0013096 D (line 6): fn write32 (0xe0001028, 0x0) ... [sequences]
0013122 D (line 6): fn write32 () returned 0x0 [sequences]
0013128 D (line 6): expr stmt = 0x0 [sequences]
0013133 D Sub-sequence 'WaitForStopAfterReset' result = 0 [functions]
0013139 D (line 22): fn sequence () returned 0x0 [sequences]
0013145 D (line 22): expr stmt = 0x0 [sequences]
0013150 D (line 23): __errorcontrol = 0x0 [sequences]
0013309 D clear reset catch, core 0 [cortex_m]
0013437 D resuming core 0 [cortex_m]
0013542 D added=[] removed=[] [manager]
0013543 D bps after flush={} [manager]
0013551 D halting core 0 [cortex_m]
0013563 D halting core 0 [cortex_m]
0013587 D resuming core 0 [cortex_m]
0013588 D added=[] removed=[] [manager]
0013588 D bps after flush={} [manager]
0013596 D halting core 0 [cortex_m]
0013607 D uninit session <pyocd.core.session.Session object at 0x7f899332d0> [session]
0013608 D uninit board <pyocd.board.board.Board object at 0x7f8d4dbb10> [board]
0013613 D resuming core 0 [cortex_m]
0013614 D added=[] removed=[] [manager]
0013614 D bps after flush={} [manager]
0013629 D closing interface [pyusb_backend]
0013653 C target was not halted as expected after calling flash algorithm routine (IPSR=3) [__main__]
Traceback (most recent call last):
  File "/usr/lib/python3.11/site-packages/pyocd/flash/builder.py", line 259, in _enable_read_access
    self.flash.init(self.flash.Operation.VERIFY)
  File "/usr/lib/python3.11/site-packages/pyocd/flash/flash.py", line 253, in init
    result = self._call_function_and_wait(self.flash_algo['pc_init'],
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/pyocd/flash/flash.py", line 676, in _call_function_and_wait
    return self.wait_for_completion(timeout=timeout)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/pyocd/flash/flash.py", line 663, in wait_for_completion
    raise exceptions.FlashFailure("target was not halted as expected after calling "
pyocd.core.exceptions.FlashFailure: target was not halted as expected after calling flash algorithm routine (IPSR=3)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.11/site-packages/pyocd/__main__.py", line 161, in run
    status = cmd.invoke()
             ^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/pyocd/subcommands/load_cmd.py", line 130, in invoke
    programmer.program(filename,
  File "/usr/lib/python3.11/site-packages/pyocd/flash/file_programmer.py", line 175, in program
    self._loader.commit()
  File "/usr/lib/python3.11/site-packages/pyocd/flash/loader.py", line 295, in commit
    perf = builder.program(chip_erase=chipErase,
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/pyocd/flash/builder.py", line 492, in program
    sector_erase_count, page_program_time = self._compute_sector_erase_pages_and_weight(fast_verify)
                                            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/pyocd/flash/builder.py", line 673, in _compute_sector_erase_pages_and_weight
    self._analyze_pages_with_partial_read()
  File "/usr/lib/python3.11/site-packages/pyocd/flash/builder.py", line 608, in _analyze_pages_with_partial_read
    self._enable_read_access()
  File "/usr/lib/python3.11/site-packages/pyocd/flash/builder.py", line 262, in _enable_read_access
    self.flash.init(self.flash.Operation.ERASE)
  File "/usr/lib/python3.11/site-packages/pyocd/flash/flash.py", line 253, in init
    result = self._call_function_and_wait(self.flash_algo['pc_init'],
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/pyocd/flash/flash.py", line 676, in _call_function_and_wait
    return self.wait_for_completion(timeout=timeout)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/pyocd/flash/flash.py", line 663, in wait_for_completion
    raise exceptions.FlashFailure("target was not halted as expected after calling "
pyocd.core.exceptions.FlashFailure: target was not halted as expected after calling flash algorithm routine (IPSR=3)
IvoBCD commented 1 year ago

What does work, is using PyOCD (without CMSIS pack) with NXP's SPSDK, to put the i.MX RT685 in serial download mode:

# nxpdebugmbox -i pyocd -v -vv ispmode -m 0
  #   Interface   Id         Description                                    
----------------------------------------------------------------------------
  0   PyOCD       NRAQBQHR   NXP Semiconductors LPC-LINK2 CMSIS-DAP V5.361  
DEBUG:spsdk.debuggers.debug_probe_pyocd:The SPSDK PyOCD Interface has been initialized (10701ms since start, debug_probe_pyocd.py:66)
DEBUG:pyocd.core.session:Project directory: /home/root
DEBUG:pyocd.core.session:Project directory: /home/root
DEBUG:pyocd.probe.pydapaccess.interface.pyusb_backend:Detaching Kernel Driver of Interface 0 from USB device (VID=1fc9 PID=0090).
DEBUG:pyocd.probe.pydapaccess.dap_access_cmsis_dap:CMSIS-DAP v1 probe NRAQBQHR: protocol version 1.1.0
DEBUG:pyocd.probe.pydapaccess.interface.pyusb_backend:closing interface
DEBUG:pyocd.coresight.coresight_target:Using default Cortex-M memory map (no memory map supplied)
DEBUG:pyocd.probe.pydapaccess.interface.pyusb_backend:Detaching Kernel Driver of Interface 0 from USB device (VID=1fc9 PID=0090).
DEBUG:pyocd.probe.swj:Sending deprecated SWJ sequence to select SWD
DEBUG:spsdk.debuggers.debug_probe_pyocd:DPIDR(idr=1805657207, partno=186, version=2, revision=6, mindp=False) (10924ms since start, debug_probe_pyocd.py:119)
DEBUG:spsdk.debuggers.debug_probe_pyocd:Coresight read DP, address: 00000004, data: F0000F40 (10928ms since start, debug_probe_pyocd.py:190)
DEBUG:spsdk.debuggers.debug_probe:Checked Sticky Errors: 0xf0000f40 (10928ms since start, debug_probe.py:283)
DEBUG:spsdk.debuggers.debug_probe:Power up the debug connection (10929ms since start, debug_probe.py:361)
DEBUG:spsdk.debuggers.debug_probe:Power Control the debug connection:
System power: True
Debug power: True (10929ms since start, debug_probe.py:334)
DEBUG:spsdk.debuggers.debug_probe_pyocd:Coresight write DP, address: 00000004, data: 50000F00 (10930ms since start, debug_probe_pyocd.py:220)
DEBUG:spsdk.debuggers.debug_probe_pyocd:Coresight read DP, address: 00000004, data: F0000F40 (10934ms since start, debug_probe_pyocd.py:190)
INFO:spsdk.debuggers.debug_probe_pyocd:PyOCD connected via LPC-LINK2 CMSIS-DAP V5.361 probe.
DEBUG:spsdk.dat.debug_mailbox:Reset mode: True (10935ms since start, debug_mailbox.py:66)
DEBUG:spsdk.debuggers.debug_probe_pyocd:Coresight write DP, address: 00000008, data: 000000F0 (10936ms since start, debug_probe_pyocd.py:220)
DEBUG:spsdk.debuggers.debug_probe:Selected AP: 0, Bank: 0xf (10936ms since start, debug_probe.py:382)
DEBUG:spsdk.debuggers.debug_probe_pyocd:Coresight read AP, address: 0000000C, data: 84770001 (10940ms since start, debug_probe_pyocd.py:190)
DEBUG:spsdk.debuggers.debug_probe_pyocd:Coresight write DP, address: 00000008, data: 020000F0 (10941ms since start, debug_probe_pyocd.py:220)
DEBUG:spsdk.debuggers.debug_probe:Selected AP: 2, Bank: 0xf (10941ms since start, debug_probe.py:382)
DEBUG:spsdk.debuggers.debug_probe_pyocd:Coresight read AP, address: 0000000C, data: 002A0000 (10945ms since start, debug_probe_pyocd.py:190)
DEBUG:spsdk.dat.debug_mailbox:Found debug mailbox access port at AP2, IDR: 0x002A0000 (10945ms since start, debug_mailbox.py:190)
DEBUG:spsdk.debuggers.debug_probe_pyocd:Coresight write DP, address: 00000008, data: 02000000 (10946ms since start, debug_probe_pyocd.py:220)
DEBUG:spsdk.debuggers.debug_probe:Selected AP: 2, Bank: 0x0 (10946ms since start, debug_probe.py:382)
DEBUG:spsdk.debuggers.debug_probe_pyocd:Coresight write AP, address: 00000000, data: 00000021 (10947ms since start, debug_probe_pyocd.py:220)
DEBUG:spsdk.debuggers.debug_probe:Trying to re-initialize debug connection (10951ms since start, debug_probe.py:319)
DEBUG:spsdk.debuggers.debug_probe:Power down the debug connection (10952ms since start, debug_probe.py:367)
DEBUG:spsdk.debuggers.debug_probe:Power Control the debug connection:
System power: False
Debug power: True (10952ms since start, debug_probe.py:334)
DEBUG:spsdk.debuggers.debug_probe_pyocd:Coresight write DP, address: 00000004, data: 10000F00 (10953ms since start, debug_probe_pyocd.py:220)
DEBUG:spsdk.debuggers.debug_probe_pyocd:Coresight read DP, address: 00000004, data: 30000F00 (10956ms since start, debug_probe_pyocd.py:190)
DEBUG:spsdk.debuggers.debug_probe:Power Control the debug connection:
System power: False
Debug power: False (10957ms since start, debug_probe.py:334)
DEBUG:spsdk.debuggers.debug_probe_pyocd:Coresight write DP, address: 00000004, data: 00000F00 (10957ms since start, debug_probe_pyocd.py:220)
DEBUG:spsdk.debuggers.debug_probe:Power up the debug connection (10958ms since start, debug_probe.py:361)
DEBUG:spsdk.debuggers.debug_probe:Power Control the debug connection:
System power: True
Debug power: True (10958ms since start, debug_probe.py:334)
DEBUG:spsdk.debuggers.debug_probe_pyocd:Coresight write DP, address: 00000004, data: 50000F00 (10959ms since start, debug_probe_pyocd.py:220)
DEBUG:spsdk.debuggers.debug_probe_pyocd:Coresight read DP, address: 00000004, data: F0000F00 (10963ms since start, debug_probe_pyocd.py:190)
DEBUG:spsdk.debuggers.debug_probe_pyocd:Coresight read DP, address: 00000004, data: F0000F00 (10966ms since start, debug_probe_pyocd.py:190)
DEBUG:spsdk.debuggers.debug_probe:Checked Sticky Errors: 0xf0000f00 (10966ms since start, debug_probe.py:283)
DEBUG:spsdk.debuggers.debug_probe:Debug interface: Read OK fail detected:

  - READOK: Read operation failed (10967ms since start, debug_probe.py:299)
DEBUG:spsdk.debuggers.debug_probe_pyocd:Coresight write DP, address: 00000000, data: 0000001F (10967ms since start, debug_probe_pyocd.py:220)
DEBUG:spsdk.debuggers.debug_probe_pyocd:Coresight write DP, address: 00000008, data: 02000000 (11018ms since start, debug_probe_pyocd.py:220)
DEBUG:spsdk.debuggers.debug_probe:Selected AP: 2, Bank: 0x0 (11019ms since start, debug_probe.py:382)
DEBUG:spsdk.debuggers.debug_probe_pyocd:Coresight read AP, address: 00000000, data: 00000000 (11022ms since start, debug_probe_pyocd.py:190)
DEBUG:spsdk.dat.debug_mailbox:<- spin_write: 0x0001_0005 (11073ms since start, dm_commands.py:52)
DEBUG:spsdk.debuggers.debug_probe_pyocd:Coresight write AP, address: 00000004, data: 00010005 (11074ms since start, debug_probe_pyocd.py:220)
DEBUG:spsdk.debuggers.debug_probe_pyocd:Coresight read AP, address: 00000000, data: 00000000 (11077ms since start, debug_probe_pyocd.py:190)
DEBUG:spsdk.debuggers.debug_probe_pyocd:Coresight read AP, address: 00000008, data: 0001A5A5 (11111ms since start, debug_probe_pyocd.py:190)
DEBUG:spsdk.dat.debug_mailbox:-> spin_read:  0x0001_a5a5 (11111ms since start, dm_commands.py:61)
DEBUG:spsdk.dat.debug_mailbox:<- spin_write: 0x0000_0000 (11112ms since start, dm_commands.py:68)
DEBUG:spsdk.debuggers.debug_probe_pyocd:Coresight write AP, address: 00000004, data: 00000000 (11112ms since start, debug_probe_pyocd.py:220)
DEBUG:spsdk.debuggers.debug_probe_pyocd:Coresight read AP, address: 00000000, data: 00000000 (11116ms since start, debug_probe_pyocd.py:190)
DEBUG:spsdk.debuggers.debug_probe_pyocd:Coresight read AP, address: 00000008, data: 00000000 (11119ms since start, debug_probe_pyocd.py:190)
DEBUG:spsdk.dat.debug_mailbox:-> spin_read:  0x0000_0000 (11120ms since start, dm_commands.py:72)
DEBUG:pyocd.probe.pydapaccess.interface.pyusb_backend:closing interface
Entering into ISP mode succeeded
flit commented 1 year ago

Some improvement, I guess. 🫤

In the "target was not halted as expected after calling flash algorithm routine (IPSR=3)" error, the IPSR=3 means that the core is in the HardFault handler. In other words, the flash algorithm crashed when it was called to init prior to erase. And unfortunately, NXP doesn't provide the source to the flash algorithms in their DFPs, so it's not possible to debug.

IvoBCD commented 1 year ago

@flit Thanks for looking into this; looks like I'll have to look into using MCUBoot or similar.

flit commented 1 year ago

@IvoBCD I've asked NXP for the source to the flash algorithm, seems it might be possible to get it.

There is also source to the .cfx algorithms included with the MCUXpresso IDE, located at <MCUXpresso IDE>/ide/Examples/Flashdrivers/NXP/iMXRT. While the .cfx doesn't appear to be compatible, it does have some of the same APIs as seen in the iMXRT6xxB_FlexSPI_SFDP/flashdriver/FlashPrg.c source file. I'm asking about how this is related to the CMSIS-Pack style .FLM algorithms used by pyocd.

Also… it turns out that I do actually have an MIMXRT685-EVK! (I have so many boards that it's sometimes hard to remember what I do and don't have.) Sorry I forgot about this and made you do all the testing yourself.

sreenivr commented 5 months ago

I am new to pyocd. I am trying to erase and program flash on NXP i.MX RT685 EVK using pyocd. Discussion on this thread helped me to overcome initial challenges and configure the pyocd_user.py script. Thanks !

I ran into the same issue described here. 0006956 C target was not halted as expected after calling flash algorithm routine (IPSR=3) [main]

Has anyone found a fix for this issue ?