Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

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

Open
krebsbstn opened this issue Dec 15, 2023 · 1 comment
Open

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

krebsbstn opened this issue Dec 15, 2023 · 1 comment

Comments

@krebsbstn
Copy link

krebsbstn commented Dec 15, 2023 •
edited

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]
  1. 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
Copy link
Author

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'

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@krebsbstn