search

pyocd / pyOCD

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

0.36.0 gdbserver generates "USB Error: [Errno 10060] Operation timed out" #1653

Open krebsbstn opened 6 months ago

krebsbstn commented 6 months ago

Hello,

I am using pyocd to host a GDB server and encountering an issue where the GDB server fails to open a debug session after flashing a firmware.

Here's the sequence of steps:

  1. I start the GDB server with the command: pyocd gdbserver -r --allow-remote --persist -S --verbose The server initialization seems to work fine.

  2. Connecting with a GDB client at this point works as expected.

  3. However, if I flash a Zephyr firmware before debugging using the command: west flash -r pyocd --dev-id remote:<ip-addr>:5555 The output indicates successful flashing:

    0006995 I Semihost server started on port 4444 (core 0) [server]
0007585 I GDB server started on port 3333 (core 0) [gdbserver]
0022919 I Client kubernetes.docker.internal (port 54076) connected to probe 001F002D3137510939383538 [tcp_probe_server]
0022922 D actual SWD frequency is 1000 kHz [stlink]
0022961 D creating memif for AP#0 (handle 0) [tcp_probe_server]
0022968 D creating memif for AP#1 (handle 1) [tcp_probe_server]
0022975 D creating memif for AP#2 (handle 2) [tcp_probe_server]
0024283 D empty request, closing connection [tcp_probe_server]
0024283 I Client kubernetes.docker.internal (port 54076) disconnected from probe 001F002D3137510939383538 [tcp_probe_server]

  4. When attempting to connect a debug session after flashing, I receive the following error message, indicating a timeout issue:

    
0165915 D Starting GDB server packet I/O thread [packet_io]
0165915 D halting core 0 [cortex_m]
0166921 E Unexpected exception: USB Error: [Errno 10060] Operation timed out [gdbserver]
Traceback (most recent call last):
File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\pyocd\probe\stlink\usb.py", line 249, in transfer
count = self._ep_out.write(writeData, timeout)
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\usb\core.py", line 408, in write
return self.device.write(self, data, timeout)
       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\usb\core.py", line 989, in write
return fn(
       ^^^
File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\usb\backend\libusb1.py", line 837, in bulk_write
return self.__write(self.lib.libusb_bulk_transfer,
       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\usb\backend\libusb1.py", line 938, in __write
_check(retval)
File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\usb\backend\libusb1.py", line 602, in _check
raise USBTimeoutError(_strerror(ret), ret, _libusb_errno[ret])
usb.core.USBTimeoutError: [Errno 10060] Operation timed out

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

Traceback (most recent call last): File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\pyocd\gdbserver\gdbserver.py", line 336, in run self.target.halt() File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\pyocd\coresight\cortex_m.py", line 638, in halt self.write_memory(CortexM.DHCSR, CortexM.DBGKEY | CortexM.C_DEBUGEN | CortexM.C_HALT) File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\pyocd\coresight\cortex_m.py", line 579, in write_memory self.ap.write_memory(addr, data, transfer_size) File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\pyocd\utility\concurrency.py", line 29, in _locking return func(self, *args, **kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\pyocd\coresight\ap.py", line 1227, in _accelerated_write_memory self._accelerated_memory_interface.write_memory(addr, data, transfer_size, File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\pyocd\probe\stlink_probe.py", line 292, in write_memory self._link.write_mem32(addr, conversion.u32le_list_to_byte_list([data]), self._apsel, csw) File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\pyocd\probe\stlink\stlink.py", line 477, in write_mem32 self._write_mem(addr, data, Commands.JTAG_WRITEMEM_32BIT, self.MAXIMUM_TRANSFER_SIZE, apsel, csw) File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\pyocd\probe\stlink\stlink.py", line 446, in _write_mem self._device.transfer(cmd, writeData=thisTransferData) File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\pyocd\probe\stlink\usb.py", line 267, in transfer raise exceptions.ProbeError("USB Error: %s" % exc) from exc pyocd.core.exceptions.ProbeError: USB Error: [Errno 10060] Operation timed out Exception in thread gdb-packet-thread-port3333: Traceback (most recent call last): File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\threading.py", line 1052, in _bootstrap_inner self.run() File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\pyocd\gdbserver\packet_io.py", line 111, in run data = self._abstract_socket.read() ^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\pyocd\utility\sockets.py", line 55, in read return self.conn.recv(packet_size) ^^^^^^^^^^^^^^ AttributeError: 'NoneType' object has no attribute 'recv'



To reproduce the issue, you can perform a fresh install of the following software versions:
- `pyocd` version 0.36.0
- `libusb.dll` version 1.0.26 (copied to the Python folder)
- STLINKV3 with Firmware version V3J13M4 (recommended by en.stsw-link007-v3-13-4)
- Windows OS 64Bit

I appreciate your assistance in addressing this issue.

Best regards.
krebsbstn commented 6 months ago

For completeness here is a full log of the process:

PS H:\> pyocd gdbserver -r --allow-remote --persist -S --verbose
0002005 D Project directory: H:\ [session]
0005585 D Project directory: H:\ [session]
0006502 D STLink probe 001F002D3137510939383538 firmware version: V3J13M4 [stlink]
0006685 D STM32H7xx_DFP DFP (STM32H743ZITx): not loading non-default flash algorithm 'CMSIS/Flash/STM32H7B3I_EVAL_FMC-NOR.FLM' [cmsis_pack]
0006701 D STM32H7xx_DFP DFP (STM32H743ZITx): not loading non-default flash algorithm 'CMSIS/Flash/STM32H7xx_MT25TL01G_DUAL.FLM' [cmsis_pack]
0006701 D STM32H7xx_DFP DFP (STM32H743ZITx): not loading non-default flash algorithm 'CMSIS/Flash/MTFC4GACAJCN_STM32H750B-DISCO.FLM' [cmsis_pack]
0006701 D STM32H7xx_DFP DFP (STM32H743ZITx): not loading non-default flash algorithm 'CMSIS/Flash/MX25LM51245G_STM32H735-Disco.FLM' [cmsis_pack]
0006701 D STM32H7xx_DFP DFP (STM32H743ZITx): not loading non-default flash algorithm 'CMSIS/Flash/STM32H743I-eval_FMC.FLM' [cmsis_pack]
0006718 I Target type is stm32h743zitx [board]
0006735 D STLink probe 001F002D3137510939383538 firmware version: V3J13M4 [stlink]
0006735 D actual SWD frequency is 1000 kHz [stlink]
0006735 D Running task load_svd [sequencer]
0006780 D Running task pre_connect [sequencer]
0006785 D Running task dp_init [sequencer]
0006800 D Running task lock_probe [sequencer]
0006818 D Running task get_probe_capabilities [sequencer]
0006834 D Running task connect [sequencer]
0006902 D Default wire protocol selected; using SWD [dap]
0006902 I DP IDR = 0x6ba02477 (v2 rev6) [dap]
0006902 D Running task clear_sticky_err [sequencer]
0006902 D Running task power_up_debug [sequencer]
0006902 D Running task check_version [sequencer]
0006902 D Running task unlock_probe [sequencer]
0006902 D Running task unlock_device [sequencer]
0006902 D Running debug sequence 'DebugDeviceUnlock' (Cortex-M7) [pack_target]
0006902 I debugvar 'DbgMCU_APB1L_Fz1' = 0x0 (0) [pack_target]
0006902 I debugvar 'DbgMCU_APB2_Fz1' = 0x0 (0) [pack_target]
0006902 I debugvar 'DbgMCU_APB3_Fz1' = 0x0 (0) [pack_target]
0006902 I debugvar 'DbgMCU_APB4_Fz1' = 0x0 (0) [pack_target]
0006902 I debugvar 'DbgMCU_CR' = 0x7 (7) [pack_target]
0006902 I debugvar 'TraceClk_Pin' = 0x40002 (262146) [pack_target]
0006902 I debugvar 'TraceD0_Pin' = 0x40003 (262147) [pack_target]
0006902 I debugvar 'TraceD1_Pin' = 0x40004 (262148) [pack_target]
0006902 I debugvar 'TraceD2_Pin' = 0x40005 (262149) [pack_target]
0006902 I debugvar 'TraceD3_Pin' = 0x40006 (262150) [pack_target]
0006902 D Running debug sub-sequence 'CheckID' (Cortex-M7) [functions]
0006902 D Using accelerated memory access interface for APB-AP#2 [ap]
0006902 D APB-AP#2 default HPROT=0 HNONSEC=0 [ap]
0006902 D APB-AP#2 implemented HPROT=0 HNONSEC=0 [ap]
0006918 D Sub-sequence 'CheckID' result = 0 [functions]
0006918 D Running task create_discoverer [sequencer]
0006918 D Running task discovery [sequencer]
0006918 D Running task find_aps [sequencer]
0006918 D Running task create_aps [sequencer]
0006918 D Running task create_ap.0 [sequencer]
0006918 D Using accelerated memory access interface for AHB-AP#0 [ap]
0006918 D AHB-AP#0 default HPROT=b HNONSEC=0 [ap]
0006918 D AHB-AP#0 implemented HPROT=f HNONSEC=1 [ap]
0006918 I AHB-AP#0 IDR = 0x84770001 (AHB-AP var0 rev8) [discovery]
0006918 D Running task create_ap.1 [sequencer]
0006918 D Using accelerated memory access interface for AHB-AP#1 [ap]
0006918 D AHB-AP#1 default HPROT=3 HNONSEC=1 [ap]
0006918 D AHB-AP#1 implemented HPROT=f HNONSEC=1 [ap]
0006918 I AHB-AP#1 IDR = 0x84770001 (AHB-AP var0 rev8) [discovery]
0006918 D Running task create_ap.2 [sequencer]
0006918 D Using accelerated memory access interface for APB-AP#2 [ap]
0006918 D APB-AP#2 default HPROT=0 HNONSEC=0 [ap]
0006918 D APB-AP#2 implemented HPROT=0 HNONSEC=0 [ap]
0006918 I APB-AP#2 IDR = 0x54770002 (APB-AP var0 rev5) [discovery]
0006918 D Running task find_components [sequencer]
0006918 D Running task init_ap.0 [sequencer]
0006935 I AHB-AP#0 Class 0x1 ROM table #0 @ 0xe00fe000 (designer=020:ST part=450) [rom_table]
0006935 I [0]<e00ff000:ROM class=1 designer=43b:Arm part=4c7> [rom_table]
0006935 I   AHB-AP#0 Class 0x1 ROM table #1 @ 0xe00ff000 (designer=43b:Arm part=4c7) [rom_table]
0006935 I   [0]<e000e000:SCS v7-M class=14 designer=43b:Arm part=00c> [rom_table]
0006935 I   [1]<e0001000:DWT v7-M class=14 designer=43b:Arm part=002> [rom_table]
0006935 I   [2]<e0002000:FPB v7-M class=14 designer=43b:Arm part=00e> [rom_table]
0006935 I   [3]<e0000000:ITM v7-M class=14 designer=43b:Arm part=001> [rom_table]
0006935 D   [4]<fff41002 not present> [rom_table]
0006935 D   [5]<fff42002 not present> [rom_table]
0006935 I [1]<e0041000:ETM M7 class=9 designer=43b:Arm part=975 devtype=13 archid=4a13 devid=0:0:0> [rom_table]
0006935 I [2]<e0043000:CTI CS-400 class=9 designer=43b:Arm part=906 devtype=14 archid=0000 devid=40800:0:0> [rom_table]
0006935 D [3]<1ff02002 not present> [rom_table]
0006935 D Running task init_ap.2 [sequencer]
0006950 I APB-AP#2 Class 0x1 ROM table #0 @ 0xe00e0000 (designer=020:ST part=450) [rom_table]
0006952 D [0]<00001002 not present> [rom_table]
0006952 D [1]<00002002 not present> [rom_table]
0006952 I [2]<e00e3000:SWO CS-400 class=9 designer=43b:Arm part=914 devtype=11 archid=0000 devid=ea0:0:0> [rom_table]
0006952 I [3]<e00e4000:Trace Funnel CS-400 class=9 designer=43b:Arm part=908 devtype=12 archid=0000 devid=32:0:0> [rom_table]
0006952 I [4]<e00e5000:TSGEN class=15 designer=43b:Arm part=101> [rom_table]
0006952 I [5]<e00f0000:ROM class=1 designer=020:ST part=001> [rom_table]
0006952 I   APB-AP#2 Class 0x1 ROM table #1 @ 0xe00f0000 (designer=020:ST part=001) [rom_table]
0006952 I   [0]<e00f1000:CTI CS-400 class=9 designer=43b:Arm part=906 devtype=14 archid=0000 devid=40800:0:0> [rom_table]
0006952 D   [1]<00002002 not present> [rom_table]
0006952 I   [2]<e00f3000:Trace Funnel CS-400 class=9 designer=43b:Arm part=908 devtype=12 archid=0000 devid=34:0:0> [rom_table]
0006952 I   [3]<e00f4000:ETF class=9 designer=43b:Arm part=961 devtype=32 archid=0000 devid=380:0:0> [rom_table]
0006952 I   [4]<e00f5000:TPIU CS-400 class=9 designer=43b:Arm part=912 devtype=11 archid=0000 devid=a0:0:0> [rom_table]
0006952 D   [5]<00006002 not present> [rom_table]
0006952 D   [6]<00007002 not present> [rom_table]
0006952 D   [7]<00008002 not present> [rom_table]
0006952 D Running task create_cores [sequencer]
0006952 D Creating SCS component [discovery]
0006952 D selected core #0 [soc_target]
0006968 I CPU core #0: Cortex-M7 r1p1, v7.0-M architecture [cortex_m]
0006968 I   Extensions: [DSP, FPU, FPU_DP, FPU_V5, MPU] [cortex_m]
0006968 I   FPU present: FPv5-D16-M [cortex_m]
0006968 D Running task configure_core_reset [sequencer]
0006968 D updated DFP core #0 reset types: {<ResetType.SW: 2>, <ResetType.HW: 1>, <ResetType.SW_EMULATED: 5>, <ResetType.SW_CORE: 4>, <ResetType.SW_SYSTEM: 3>} [pack_target]
0006968 I Setting core #0 (Cortex-M7) default reset sequence to ResetSystem [pack_target]
0006968 D Running task create_components [sequencer]
0006968 D Creating DWT component [discovery]
0006968 I 4 hardware watchpoints [dwt]
0006968 D Creating FPB component [discovery]
0006968 I 8 hardware breakpoints, 1 literal comparators [fpb]
0006968 D fpb has been disabled [fpb]
0006981 D Creating ITM component [discovery]
0006981 D Creating SWO component [discovery]
0006981 D Creating Trace Funnel component [discovery]
0006985 D Creating Trace Funnel component [discovery]
0006988 D Creating TPIU component [discovery]
0006989 D Running task check_for_cores [sequencer]
0006989 D Running task halt_on_connect [sequencer]
0006989 D halting core 0 [cortex_m]
0006990 D Running task post_connect [sequencer]
0006990 D Running task post_connect_hook [sequencer]
0006990 D Running task create_flash [sequencer]
0006990 D flash algo: [stack=0x20007410; 0x7410 b] [b2=0x20007810,+0x7810] [b1=0x20007410,+0x7410] [code=0x20007c1c,+0x7c1c,0x3e4 b] (ram=0x20000000, 0x8000 b) [flash_algo]
0006990 D flash algo: [stack=0x20007410; 0x7410 b] [b2=0x20007810,+0x7810] [b1=0x20007410,+0x7410] [code=0x20007c1c,+0x7c1c,0x3e4 b] (ram=0x20000000, 0x8000 b) [flash_algo]
0006991 D Running task notify [sequencer]
0006991 I Serving debug probe STLINK-V3 (001F002D3137510939383538) on port 5555 [tcp_probe_server]
0006992 D Setting vector catch to 0x00000001 [cortex_m]
0006995 I Semihost server started on port 4444 (core 0) [server]
0007585 I GDB server started on port 3333 (core 0) [gdbserver]
0022919 I Client kubernetes.docker.internal (port 54076) connected to probe 001F002D3137510939383538 [tcp_probe_server]
0022922 D actual SWD frequency is 1000 kHz [stlink]
0022961 D creating memif for AP#0 (handle 0) [tcp_probe_server]
0022968 D creating memif for AP#1 (handle 1) [tcp_probe_server]
0022975 D creating memif for AP#2 (handle 2) [tcp_probe_server]
0024283 D empty request, closing connection [tcp_probe_server]
0024283 I Client kubernetes.docker.internal (port 54076) disconnected from probe 001F002D3137510939383538 [tcp_probe_server]
0165915 D Starting GDB server packet I/O thread [packet_io]
0165915 D halting core 0 [cortex_m]
0166921 E Unexpected exception: USB Error: [Errno 10060] Operation timed out [gdbserver]
Traceback (most recent call last):
  File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\pyocd\probe\stlink\usb.py", line 249, in transfer
    count = self._ep_out.write(writeData, timeout)
            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\usb\core.py", line 408, in write
    return self.device.write(self, data, timeout)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\usb\core.py", line 989, in write
    return fn(
           ^^^
  File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\usb\backend\libusb1.py", line 837, in bulk_write
    return self.__write(self.lib.libusb_bulk_transfer,
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\usb\backend\libusb1.py", line 938, in __write
    _check(retval)
  File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\usb\backend\libusb1.py", line 602, in _check
    raise USBTimeoutError(_strerror(ret), ret, _libusb_errno[ret])
usb.core.USBTimeoutError: [Errno 10060] Operation timed out

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

Traceback (most recent call last):
  File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\pyocd\gdbserver\gdbserver.py", line 336, in run
    self.target.halt()
  File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\pyocd\coresight\cortex_m.py", line 638, in halt
    self.write_memory(CortexM.DHCSR, CortexM.DBGKEY | CortexM.C_DEBUGEN | CortexM.C_HALT)
  File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\pyocd\coresight\cortex_m.py", line 579, in write_memory
    self.ap.write_memory(addr, data, transfer_size)
  File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\pyocd\utility\concurrency.py", line 29, in _locking
    return func(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\pyocd\coresight\ap.py", line 1227, in _accelerated_write_memory
    self._accelerated_memory_interface.write_memory(addr, data, transfer_size,
  File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\pyocd\probe\stlink_probe.py", line 292, in write_memory
    self._link.write_mem32(addr, conversion.u32le_list_to_byte_list([data]), self._apsel, csw)
  File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\pyocd\probe\stlink\stlink.py", line 477, in write_mem32
    self._write_mem(addr, data, Commands.JTAG_WRITEMEM_32BIT, self.MAXIMUM_TRANSFER_SIZE, apsel, csw)
  File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\pyocd\probe\stlink\stlink.py", line 446, in _write_mem
    self._device.transfer(cmd, writeData=thisTransferData)
  File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\pyocd\probe\stlink\usb.py", line 267, in transfer
    raise exceptions.ProbeError("USB Error: %s" % exc) from exc
pyocd.core.exceptions.ProbeError: USB Error: [Errno 10060] Operation timed out
Exception in thread gdb-packet-thread-port3333:
Traceback (most recent call last):
  File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\threading.py", line 1052, in _bootstrap_inner
    self.run()
  File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\pyocd\gdbserver\packet_io.py", line 111, in run
    data = self._abstract_socket.read()
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\XXX\AppData\Local\Programs\Python\Python312\Lib\site-packages\pyocd\utility\sockets.py", line 55, in read
    return self.conn.recv(packet_size)
           ^^^^^^^^^^^^^^
AttributeError: 'NoneType' object has no attribute 'recv'