Panometric commented 2 years ago

Development Kit

esp32-box

Module or chip used

ESP32-S3

Debug Adapter

Built-in JTAG

OpenOCD version

v0.11.0-esp32-20220411 (2022-04-11-08:48)

Operating System

Windows

Using an IDE ?

no, bit in VScode IDE, this error generates an annoying popup every time openocd starts.

OpenOCD command line

openocd -d3 -f board/esp32-wrover-kit-3.3v.cfg 2>&1 | tee openocd.log

JTAG Clock Speed

default 40000

ESP-IDF version

4.4.2

Problem Description

Erroneous error on startup: "Error: libusb_open() failed with LIBUSB_ERROR_NOT_SUPPORTED"

PS C:\DCI\spi_lcd\lcd> openocd -f board/esp32s3-builtin.cfg Open On-Chip Debugger v0.11.0-esp32-20220411 (2022-04-11-08:48) Licensed under GNU GPL v2 For bug reports, read http://openocd.org/doc/doxygen/bugs.html Info : only one transport option; autoselect 'jtag' Info : esp_usb_jtag: VID set to 0x303a and PID to 0x1001 Info : esp_usb_jtag: capabilities descriptor set to 0x2000 Warn : Transport "jtag" was already selected Info : Listening on port 6666 for tcl connections Info : Listening on port 4444 for telnet connections Error: libusb_open() failed with LIBUSB_ERROR_NOT_SUPPORTED Info : esp_usb_jtag: serial (F4:12:FA:C1:A1:64) Info : esp_usb_jtag: Device found. Base speed 40000KHz, div range 1 to 255 Info : clock speed 40000 kHz Info : JTAG tap: esp32s3.cpu0 tap/device found: 0x120034e5 (mfg: 0x272 (Tensilica), part: 0x2003, ver: 0x1) Info : JTAG tap: esp32s3.cpu1 tap/device found: 0x120034e5 (mfg: 0x272 (Tensilica), part: 0x2003, ver: 0x1) Info : starting gdb server for esp32s3.cpu0 on 3333 Info : Listening on port 3333 for gdb connections

Debug Logs

openocd : Open On-Chip Debugger  v0.11.0-esp32-20220411 (2022-04-11-08:48)
At line:1 char:1
+ openocd -d3 -f board/esp32s3-builtin.cfg 2>&1 | tee openocd.log
+ ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
    + CategoryInfo          : NotSpecified: (Open On-Chip De...22-04-11-08:48):String) [], RemoteException
    + FullyQualifiedErrorId : NativeCommandError

Licensed under GNU GPL v2
For bug reports, read
    http://openocd.org/doc/doxygen/bugs.html
User : 3 2 options.c:63 configuration_output_handler(): debug_level: 3
User : 4 3 options.c:63 configuration_output_handler(): 
Debug: 5 3 options.c:244 add_default_dirs(): bindir=/builds/idf/openocd-esp32/_build/../openocd-esp32/bin
Debug: 6 3 options.c:245 add_default_dirs(): pkgdatadir=/builds/idf/openocd-esp32/_build/../openocd-esp32/share/openocd
Debug: 7 3 options.c:246 add_default_dirs(): 
exepath=C:/Users/username/.espressif/tools/openocd-esp32/v0.11.0-esp32-20220411/openocd-esp32/bin
Debug: 8 3 options.c:247 add_default_dirs(): bin2data=../share/openocd
Debug: 9 3 configuration.c:44 add_script_search_dir(): adding 
C:\Users\username\.espressif\tools\openocd-esp32\v0.11.0-esp32-20220411\openocd-esp32\share\openocd\scripts
Debug: 10 4 configuration.c:44 add_script_search_dir(): adding C:/Users/username/AppData/Roaming/OpenOCD
Debug: 11 4 configuration.c:44 add_script_search_dir(): adding 
C:/Users/username/.espressif/tools/openocd-esp32/v0.11.0-esp32-20220411/openocd-esp32/bin/../share/openocd/site
Debug: 12 4 configuration.c:44 add_script_search_dir(): adding 
C:/Users/username/.espressif/tools/openocd-esp32/v0.11.0-esp32-20220411/openocd-esp32/bin/../share/openocd/scripts
Debug: 13 4 command.c:166 script_debug(): command - ocd_find board/esp32s3-builtin.cfg
Debug: 14 4 configuration.c:99 find_file(): found C:\Users\username\.espressif\tools\openocd-esp32\v0.11.0-esp32-20220411\o
penocd-esp32\share\openocd\scripts/board/esp32s3-builtin.cfg
Debug: 15 7 command.c:166 script_debug(): command - ocd_find interface/esp_usb_jtag.cfg
Debug: 16 7 configuration.c:99 find_file(): found C:\Users\username\.espressif\tools\openocd-esp32\v0.11.0-esp32-20220411\o
penocd-esp32\share\openocd\scripts/interface/esp_usb_jtag.cfg
Debug: 17 8 command.c:166 script_debug(): command - adapter driver esp_usb_jtag
Info : 18 8 transport.c:118 allow_transports(): only one transport option; autoselect 'jtag'
Debug: 19 8 command.c:166 script_debug(): command - espusbjtag vid_pid 0x303a 0x1001
Info : 20 8 esp_usb_jtag.c:894 esp_usb_jtag_vid_pid(): esp_usb_jtag: VID set to 0x303a and PID to 0x1001
Debug: 21 8 command.c:166 script_debug(): command - espusbjtag caps_descriptor 0x2000
Info : 22 8 esp_usb_jtag.c:907 esp_usb_jtag_caps_descriptor(): esp_usb_jtag: capabilities descriptor set to 0x2000
Debug: 23 8 command.c:166 script_debug(): command - adapter speed 40000
Debug: 24 8 adapter.c:180 adapter_config_khz(): handle adapter khz
Debug: 25 8 adapter.c:144 adapter_khz_to_speed(): convert khz to adapter specific speed value
Debug: 26 8 adapter.c:144 adapter_khz_to_speed(): convert khz to adapter specific speed value
Debug: 27 8 command.c:166 script_debug(): command - ocd_find target/esp32s3.cfg
Debug: 28 9 configuration.c:99 find_file(): found C:\Users\username\.espressif\tools\openocd-esp32\v0.11.0-esp32-20220411\o
penocd-esp32\share\openocd\scripts/target/esp32s3.cfg
Debug: 29 10 command.c:166 script_debug(): command - transport select jtag
Warn : 30 10 transport.c:287 jim_transport_select(): Transport "jtag" was already selected
Debug: 31 10 command.c:166 script_debug(): command - ocd_find bitsbytes.tcl
Debug: 32 11 configuration.c:99 find_file(): found 
C:\Users\username\.espressif\tools\openocd-esp32\v0.11.0-esp32-20220411\openocd-esp32\share\openocd\scripts/bitsbytes.tcl
Debug: 33 11 command.c:166 script_debug(): command - expr 1 << $x
Debug: 34 12 command.c:166 script_debug(): command - expr $x + 1
Debug: 35 12 command.c:166 script_debug(): command - expr 1 << $x
Debug: 36 12 command.c:166 script_debug(): command - expr $x + 1
Debug: 37 12 command.c:166 script_debug(): command - expr 1 << $x
Debug: 38 12 command.c:166 script_debug(): command - expr $x + 1
Debug: 39 12 command.c:166 script_debug(): command - expr 1 << $x
Debug: 40 12 command.c:166 script_debug(): command - expr $x + 1
Debug: 41 13 command.c:166 script_debug(): command - expr 1 << $x
Debug: 42 13 command.c:166 script_debug(): command - expr $x + 1
Debug: 43 13 command.c:166 script_debug(): command - expr 1 << $x
Debug: 44 13 command.c:166 script_debug(): command - expr $x + 1
Debug: 45 13 command.c:166 script_debug(): command - expr 1 << $x
Debug: 46 13 command.c:166 script_debug(): command - expr $x + 1
Debug: 47 13 command.c:166 script_debug(): command - expr 1 << $x
Debug: 48 13 command.c:166 script_debug(): command - expr $x + 1
Debug: 49 13 command.c:166 script_debug(): command - expr 1 << $x
Debug: 50 13 command.c:166 script_debug(): command - expr $x + 1
Debug: 51 13 command.c:166 script_debug(): command - expr 1 << $x
Debug: 52 14 command.c:166 script_debug(): command - expr $x + 1
Debug: 53 14 command.c:166 script_debug(): command - expr 1 << $x
Debug: 54 14 command.c:166 script_debug(): command - expr $x + 1
Debug: 55 14 command.c:166 script_debug(): command - expr 1 << $x
Debug: 56 14 command.c:166 script_debug(): command - expr $x + 1
Debug: 57 14 command.c:166 script_debug(): command - expr 1 << $x
Debug: 58 14 command.c:166 script_debug(): command - expr $x + 1
Debug: 59 14 command.c:166 script_debug(): command - expr 1 << $x
Debug: 60 14 command.c:166 script_debug(): command - expr $x + 1
Debug: 61 15 command.c:166 script_debug(): command - expr 1 << $x
Debug: 62 15 command.c:166 script_debug(): command - expr $x + 1
Debug: 63 15 command.c:166 script_debug(): command - expr 1 << $x
Debug: 64 15 command.c:166 script_debug(): command - expr $x + 1
Debug: 65 15 command.c:166 script_debug(): command - expr 1 << $x
Debug: 66 15 command.c:166 script_debug(): command - expr $x + 1
Debug: 67 15 command.c:166 script_debug(): command - expr 1 << $x
Debug: 68 16 command.c:166 script_debug(): command - expr $x + 1
Debug: 69 16 command.c:166 script_debug(): command - expr 1 << $x
Debug: 70 16 command.c:166 script_debug(): command - expr $x + 1
Debug: 71 16 command.c:166 script_debug(): command - expr 1 << $x
Debug: 72 16 command.c:166 script_debug(): command - expr $x + 1
Debug: 73 16 command.c:166 script_debug(): command - expr 1 << $x
Debug: 74 16 command.c:166 script_debug(): command - expr $x + 1
Debug: 75 16 command.c:166 script_debug(): command - expr 1 << $x
Debug: 76 17 command.c:166 script_debug(): command - expr $x + 1
Debug: 77 17 command.c:166 script_debug(): command - expr 1 << $x
Debug: 78 17 command.c:166 script_debug(): command - expr $x + 1
Debug: 79 17 command.c:166 script_debug(): command - expr 1 << $x
Debug: 80 17 command.c:166 script_debug(): command - expr $x + 1
Debug: 81 17 command.c:166 script_debug(): command - expr 1 << $x
Debug: 82 17 command.c:166 script_debug(): command - expr $x + 1
Debug: 83 18 command.c:166 script_debug(): command - expr 1 << $x
Debug: 84 18 command.c:166 script_debug(): command - expr $x + 1
Debug: 85 18 command.c:166 script_debug(): command - expr 1 << $x
Debug: 86 18 command.c:166 script_debug(): command - expr $x + 1
Debug: 87 18 command.c:166 script_debug(): command - expr 1 << $x
Debug: 88 18 command.c:166 script_debug(): command - expr $x + 1
Debug: 89 18 command.c:166 script_debug(): command - expr 1 << $x
Debug: 90 18 command.c:166 script_debug(): command - expr $x + 1
Debug: 91 18 command.c:166 script_debug(): command - expr 1 << $x
Debug: 92 18 command.c:166 script_debug(): command - expr $x + 1
Debug: 93 19 command.c:166 script_debug(): command - expr 1 << $x
Debug: 94 19 command.c:166 script_debug(): command - expr $x + 1
Debug: 95 19 command.c:166 script_debug(): command - expr 1 << $x
Debug: 96 19 command.c:166 script_debug(): command - expr $x + 1
Debug: 97 19 command.c:166 script_debug(): command - expr 1024 * $x
Debug: 98 19 command.c:166 script_debug(): command - expr $x * 2
Debug: 99 19 command.c:166 script_debug(): command - expr 1024 * $x
Debug: 100 19 command.c:166 script_debug(): command - expr $x * 2
Debug: 101 19 command.c:166 script_debug(): command - expr 1024 * $x
Debug: 102 19 command.c:166 script_debug(): command - expr $x * 2
Debug: 103 19 command.c:166 script_debug(): command - expr 1024 * $x
Debug: 104 19 command.c:166 script_debug(): command - expr $x * 2
Debug: 105 19 command.c:166 script_debug(): command - expr 1024 * $x
Debug: 106 20 command.c:166 script_debug(): command - expr $x * 2
Debug: 107 20 command.c:166 script_debug(): command - expr 1024 * $x
Debug: 108 20 command.c:166 script_debug(): command - expr $x * 2
Debug: 109 20 command.c:166 script_debug(): command - expr 1024 * $x
Debug: 110 20 command.c:166 script_debug(): command - expr $x * 2
Debug: 111 20 command.c:166 script_debug(): command - expr 1024 * $x
Debug: 112 20 command.c:166 script_debug(): command - expr $x * 2
Debug: 113 20 command.c:166 script_debug(): command - expr 1024 * $x
Debug: 114 20 command.c:166 script_debug(): command - expr $x * 2
Debug: 115 20 command.c:166 script_debug(): command - expr 1024 * $x
Debug: 116 20 command.c:166 script_debug(): command - expr $x * 2
Debug: 117 20 command.c:166 script_debug(): command - expr 1024 * $x
Debug: 118 20 command.c:166 script_debug(): command - expr $x * 2
Debug: 119 20 command.c:166 script_debug(): command - expr 1024 * 1024 * $x
Debug: 120 21 command.c:166 script_debug(): command - expr $x * 2
Debug: 121 21 command.c:166 script_debug(): command - expr 1024 * 1024 * $x
Debug: 122 21 command.c:166 script_debug(): command - expr $x * 2
Debug: 123 21 command.c:166 script_debug(): command - expr 1024 * 1024 * $x
Debug: 124 21 command.c:166 script_debug(): command - expr $x * 2
Debug: 125 21 command.c:166 script_debug(): command - expr 1024 * 1024 * $x
Debug: 126 21 command.c:166 script_debug(): command - expr $x * 2
Debug: 127 22 command.c:166 script_debug(): command - expr 1024 * 1024 * $x
Debug: 128 22 command.c:166 script_debug(): command - expr $x * 2
Debug: 129 22 command.c:166 script_debug(): command - expr 1024 * 1024 * $x
Debug: 130 22 command.c:166 script_debug(): command - expr $x * 2
Debug: 131 22 command.c:166 script_debug(): command - expr 1024 * 1024 * $x
Debug: 132 22 command.c:166 script_debug(): command - expr $x * 2
Debug: 133 22 command.c:166 script_debug(): command - expr 1024 * 1024 * $x
Debug: 134 23 command.c:166 script_debug(): command - expr $x * 2
Debug: 135 23 command.c:166 script_debug(): command - expr 1024 * 1024 * $x
Debug: 136 23 command.c:166 script_debug(): command - expr $x * 2
Debug: 137 23 command.c:166 script_debug(): command - expr 1024 * 1024 * $x
Debug: 138 23 command.c:166 script_debug(): command - expr $x * 2
Debug: 139 23 command.c:166 script_debug(): command - expr 1024 * 1024 * $x
Debug: 140 23 command.c:166 script_debug(): command - expr $x * 2
Debug: 141 23 command.c:166 script_debug(): command - ocd_find memory.tcl
Debug: 142 23 configuration.c:99 find_file(): found 
C:\Users\username\.espressif\tools\openocd-esp32\v0.11.0-esp32-20220411\openocd-esp32\share\openocd\scripts/memory.tcl
Debug: 143 24 command.c:166 script_debug(): command - expr $RWX_R_ONLY + $RWX_W_ONLY
Debug: 144 24 command.c:166 script_debug(): command - expr $RWX_R_ONLY + $RWX_X_ONLY
Debug: 145 24 command.c:166 script_debug(): command - expr $RWX_R_ONLY + $RWX_W_ONLY + $RWX_X_ONLY
Debug: 146 24 command.c:166 script_debug(): command - expr $ACCESS_WIDTH_8 + $ACCESS_WIDTH_16 + $ACCESS_WIDTH_32
Debug: 147 24 command.c:166 script_debug(): command - ocd_find mmr_helpers.tcl
Debug: 148 25 configuration.c:99 find_file(): found 
C:\Users\username\.espressif\tools\openocd-esp32\v0.11.0-esp32-20220411\openocd-esp32\share\openocd\scripts/mmr_helpers.tcl
Debug: 149 25 command.c:166 script_debug(): command - ocd_find target/esp_common.cfg
Debug: 150 25 configuration.c:99 find_file(): found C:\Users\username\.espressif\tools\openocd-esp32\v0.11.0-esp32-20220411
\openocd-esp32\share\openocd\scripts/target/esp_common.cfg
Debug: 151 26 command.c:166 script_debug(): command - add_help_text program_esp write an image to flash, address is 
only required for binary images. verify, reset, exit, compress, restore_clock are optional
Debug: 152 26 command.c:166 script_debug(): command - add_usage_text program_esp <filename> [address] [verify] [reset] 
[exit] [compress] [restore_clock]
Debug: 153 26 command.c:166 script_debug(): command - add_help_text program_esp_bins write all the images at address 
specified in flasher_args.json generated while building idf project
Debug: 154 26 command.c:166 script_debug(): command - add_usage_text program_esp_bins <build_dir> flasher_args.json 
[verify] [reset] [exit] [compress] [restore_clock]
Debug: 155 26 command.c:166 script_debug(): command - add_help_text esp_get_mac Print MAC address of the chip. Use a 
`format` argument to return formatted MAC value
Debug: 156 26 command.c:166 script_debug(): command - add_usage_text esp_get_mac [format]
Debug: 157 26 command.c:166 script_debug(): command - jtag newtap esp32s3 cpu0 -irlen 5 -expected-id 0x120034e5
Debug: 158 27 tcl.c:569 jim_newtap_cmd(): Creating New Tap, Chip: esp32s3, Tap: cpu0, Dotted: esp32s3.cpu0, 4 params
Debug: 159 27 tcl.c:593 jim_newtap_cmd(): Processing option: -irlen
Debug: 160 27 tcl.c:593 jim_newtap_cmd(): Processing option: -expected-id
Debug: 161 27 core.c:1472 jtag_tap_init(): Created Tap: esp32s3.cpu0 @ abs position 0, irlen 5, capture: 0x1 mask: 0x3
Debug: 162 27 command.c:166 script_debug(): command - jtag newtap esp32s3 cpu1 -irlen 5 -expected-id 0x120034e5
Debug: 163 27 tcl.c:569 jim_newtap_cmd(): Creating New Tap, Chip: esp32s3, Tap: cpu1, Dotted: esp32s3.cpu1, 4 params
Debug: 164 27 tcl.c:593 jim_newtap_cmd(): Processing option: -irlen
Debug: 165 27 tcl.c:593 jim_newtap_cmd(): Processing option: -expected-id
Debug: 166 27 core.c:1472 jtag_tap_init(): Created Tap: esp32s3.cpu1 @ abs position 1, irlen 5, capture: 0x1 mask: 0x3
Debug: 167 27 command.c:166 script_debug(): command - target create esp32s3.cpu0 esp32s3 -endian little 
-chain-position esp32s3.cpu0 -coreid 0 -rtos FreeRTOS
Debug: 168 27 target.c:2236 target_free_all_working_areas_restore(): freeing all working areas
Debug: 169 27 target.c:2236 target_free_all_working_areas_restore(): freeing all working areas
Debug: 170 27 FreeRTOS.c:1337 freertos_create(): freertos_create
Debug: 171 28 command.c:300 register_command(): command 'esp' is already registered
Debug: 172 28 command.c:300 register_command(): command 'esp32s3.cpu0 esp' is already registered
Debug: 173 28 command.c:166 script_debug(): command - esp32s3.cpu0 configure -work-area-phys 0x403B0000 
-work-area-virt 0x403B0000 -work-area-size 0x3400 -work-area-backup 1
Debug: 174 28 target.c:2236 target_free_all_working_areas_restore(): freeing all working areas
Debug: 175 28 target.c:2236 target_free_all_working_areas_restore(): freeing all working areas
Debug: 176 28 target.c:2236 target_free_all_working_areas_restore(): freeing all working areas
Debug: 177 28 target.c:2236 target_free_all_working_areas_restore(): freeing all working areas
Debug: 178 28 command.c:166 script_debug(): command - esp32s3.cpu0 configure -alt-work-area-phys 0x3FCE0000 
-alt-work-area-virt 0x3FCE0000 -alt-work-area-size 0x10000 -alt-work-area-backup 1
Debug: 179 29 target.c:2236 target_free_all_working_areas_restore(): freeing all working areas
Debug: 180 29 target.c:2236 target_free_all_working_areas_restore(): freeing all working areas
Debug: 181 29 target.c:2236 target_free_all_working_areas_restore(): freeing all working areas
Debug: 182 29 target.c:2236 target_free_all_working_areas_restore(): freeing all working areas
Debug: 183 29 command.c:166 script_debug(): command - flash bank esp32s3.cpu0.flash esp32s3 0x0 0 0 0 esp32s3.cpu0
Debug: 184 29 command.c:300 register_command(): command 'esp' is already registered
Debug: 185 29 tcl.c:1316 handle_flash_bank_command(): 'esp32s3' driver usage field missing
Debug: 186 29 command.c:166 script_debug(): command - flash bank esp32s3.cpu0.irom esp32s3 0x0 0 0 0 esp32s3.cpu0
Debug: 187 30 command.c:300 register_command(): command 'esp' is already registered
Debug: 188 30 command.c:300 register_command(): command 'esp appimage_offset' is already registered
Debug: 189 30 command.c:300 register_command(): command 'esp compression' is already registered
Debug: 190 30 command.c:300 register_command(): command 'esp verify_bank_hash' is already registered
Debug: 191 30 command.c:300 register_command(): command 'esp flash_stub_clock_boost' is already registered
Debug: 192 30 command.c:300 register_command(): command 'esp32s3' is already registered
Debug: 193 30 command.c:300 register_command(): command 'esp32s3 appimage_offset' is already registered
Debug: 194 30 command.c:300 register_command(): command 'esp32s3 compression' is already registered
Debug: 195 30 command.c:300 register_command(): command 'esp32s3 verify_bank_hash' is already registered
Debug: 196 30 command.c:300 register_command(): command 'esp32s3 flash_stub_clock_boost' is already registered
Debug: 197 30 tcl.c:1316 handle_flash_bank_command(): 'esp32s3' driver usage field missing
Debug: 198 30 command.c:166 script_debug(): command - flash bank esp32s3.cpu0.drom esp32s3 0x0 0 0 0 esp32s3.cpu0
Debug: 199 30 command.c:300 register_command(): command 'esp' is already registered
Debug: 200 30 command.c:300 register_command(): command 'esp appimage_offset' is already registered
Debug: 201 30 command.c:300 register_command(): command 'esp compression' is already registered
Debug: 202 30 command.c:300 register_command(): command 'esp verify_bank_hash' is already registered
Debug: 203 31 command.c:300 register_command(): command 'esp flash_stub_clock_boost' is already registered
Debug: 204 31 command.c:300 register_command(): command 'esp32s3' is already registered
Debug: 205 31 command.c:300 register_command(): command 'esp32s3 appimage_offset' is already registered
Debug: 206 31 command.c:300 register_command(): command 'esp32s3 compression' is already registered
Debug: 207 31 command.c:300 register_command(): command 'esp32s3 verify_bank_hash' is already registered
Debug: 208 31 command.c:300 register_command(): command 'esp32s3 flash_stub_clock_boost' is already registered
Debug: 209 31 tcl.c:1316 handle_flash_bank_command(): 'esp32s3' driver usage field missing
Debug: 210 31 command.c:166 script_debug(): command - target create esp32s3.cpu1 esp32s3 -endian little 
-chain-position esp32s3.cpu1 -coreid 1 -rtos FreeRTOS
Debug: 211 31 target.c:2236 target_free_all_working_areas_restore(): freeing all working areas
Debug: 212 31 target.c:2236 target_free_all_working_areas_restore(): freeing all working areas
Debug: 213 31 FreeRTOS.c:1337 freertos_create(): freertos_create
Debug: 214 31 command.c:300 register_command(): command 'xtensa' is already registered
Debug: 215 31 command.c:300 register_command(): command 'xtensa set_permissive' is already registered
Debug: 216 31 command.c:300 register_command(): command 'xtensa maskisr' is already registered
Debug: 217 31 command.c:300 register_command(): command 'xtensa smpbreak' is already registered
Debug: 218 31 command.c:300 register_command(): command 'xtensa perfmon_enable' is already registered
Debug: 219 56 command.c:300 register_command(): command 'xtensa perfmon_dump' is already registered
Debug: 220 56 command.c:300 register_command(): command 'xtensa tracestart' is already registered
Debug: 221 56 command.c:300 register_command(): command 'xtensa tracestop' is already registered
Debug: 222 56 command.c:300 register_command(): command 'xtensa tracedump' is already registered
Debug: 223 56 command.c:300 register_command(): command 'esp' is already registered
Debug: 224 56 command.c:300 register_command(): command 'esp semihost_basedir' is already registered
Debug: 225 56 command.c:300 register_command(): command 'esp' is already registered
Debug: 226 56 command.c:300 register_command(): command 'esp apptrace' is already registered
Debug: 227 56 command.c:300 register_command(): command 'esp sysview' is already registered
Debug: 228 56 command.c:300 register_command(): command 'esp sysview_mcore' is already registered
Debug: 229 57 command.c:300 register_command(): command 'esp gcov' is already registered
Debug: 230 57 command.c:300 register_command(): command 'esp32' is already registered
Debug: 231 57 command.c:300 register_command(): command 'esp32 smp' is already registered
Debug: 232 57 command.c:300 register_command(): command 'esp32 smp_gdb' is already registered
Debug: 233 57 command.c:300 register_command(): command 'arm' is already registered
Debug: 234 57 command.c:300 register_command(): command 'arm semihosting' is already registered
Debug: 235 57 command.c:300 register_command(): command 'arm semihosting_redirect' is already registered
Debug: 236 57 command.c:300 register_command(): command 'arm semihosting_cmdline' is already registered
Debug: 237 57 command.c:300 register_command(): command 'arm semihosting_fileio' is already registered
Debug: 238 57 command.c:300 register_command(): command 'arm semihosting_resexit' is already registered
Debug: 239 57 command.c:300 register_command(): command 'arm semihosting_read_user_param' is already registered
Debug: 240 57 command.c:300 register_command(): command 'arm semihosting_basedir' is already registered
Debug: 241 57 command.c:300 register_command(): command 'esp32s3.cpu1 esp' is already registered
Debug: 242 58 command.c:166 script_debug(): command - flash bank esp32s3.cpu1.flash esp32s3 0x0 0 0 0 esp32s3.cpu1
Debug: 243 58 command.c:300 register_command(): command 'esp' is already registered
Debug: 244 58 command.c:300 register_command(): command 'esp appimage_offset' is already registered
Debug: 245 58 command.c:300 register_command(): command 'esp compression' is already registered
Debug: 246 58 command.c:300 register_command(): command 'esp verify_bank_hash' is already registered
Debug: 247 58 command.c:300 register_command(): command 'esp flash_stub_clock_boost' is already registered
Debug: 248 58 command.c:300 register_command(): command 'esp32s3' is already registered
Debug: 249 58 command.c:300 register_command(): command 'esp32s3 appimage_offset' is already registered
Debug: 250 58 command.c:300 register_command(): command 'esp32s3 compression' is already registered
Debug: 251 58 command.c:300 register_command(): command 'esp32s3 verify_bank_hash' is already registered
Debug: 252 58 command.c:300 register_command(): command 'esp32s3 flash_stub_clock_boost' is already registered
Debug: 253 58 tcl.c:1316 handle_flash_bank_command(): 'esp32s3' driver usage field missing
Debug: 254 58 command.c:166 script_debug(): command - flash bank esp32s3.cpu1.irom esp32s3 0x0 0 0 0 esp32s3.cpu1
Debug: 255 58 command.c:300 register_command(): command 'esp' is already registered
Debug: 256 59 command.c:300 register_command(): command 'esp appimage_offset' is already registered
Debug: 257 59 command.c:300 register_command(): command 'esp compression' is already registered
Debug: 258 59 command.c:300 register_command(): command 'esp verify_bank_hash' is already registered
Debug: 259 59 command.c:300 register_command(): command 'esp flash_stub_clock_boost' is already registered
Debug: 260 59 command.c:300 register_command(): command 'esp32s3' is already registered
Debug: 261 81 command.c:300 register_command(): command 'esp32s3 appimage_offset' is already registered
Debug: 262 81 command.c:300 register_command(): command 'esp32s3 compression' is already registered
Debug: 263 81 command.c:300 register_command(): command 'esp32s3 verify_bank_hash' is already registered
Debug: 264 81 command.c:300 register_command(): command 'esp32s3 flash_stub_clock_boost' is already registered
Debug: 265 81 tcl.c:1316 handle_flash_bank_command(): 'esp32s3' driver usage field missing
Debug: 266 82 command.c:166 script_debug(): command - flash bank esp32s3.cpu1.drom esp32s3 0x0 0 0 0 esp32s3.cpu1
Debug: 267 82 command.c:300 register_command(): command 'esp' is already registered
Debug: 268 82 command.c:300 register_command(): command 'esp appimage_offset' is already registered
Debug: 269 82 command.c:300 register_command(): command 'esp compression' is already registered
Debug: 270 82 command.c:300 register_command(): command 'esp verify_bank_hash' is already registered
Debug: 271 82 command.c:300 register_command(): command 'esp flash_stub_clock_boost' is already registered
Debug: 272 82 command.c:300 register_command(): command 'esp32s3' is already registered
Debug: 273 82 command.c:300 register_command(): command 'esp32s3 appimage_offset' is already registered
Debug: 274 82 command.c:300 register_command(): command 'esp32s3 compression' is already registered
Debug: 275 82 command.c:300 register_command(): command 'esp32s3 verify_bank_hash' is already registered
Debug: 276 82 command.c:300 register_command(): command 'esp32s3 flash_stub_clock_boost' is already registered
Debug: 277 82 tcl.c:1316 handle_flash_bank_command(): 'esp32s3' driver usage field missing
Debug: 278 83 command.c:166 script_debug(): command - target smp esp32s3.cpu0 esp32s3.cpu1
Debug: 279 83 target.c:6548 jim_target_smp(): 3
Debug: 280 83 target.c:6565 jim_target_smp(): esp32s3.cpu0 
Debug: 281 83 target.c:6565 jim_target_smp(): esp32s3.cpu1 
Debug: 282 83 command.c:166 script_debug(): command - esp32s3.cpu0 xtensa maskisr on
Debug: 283 83 command.c:166 script_debug(): command - esp32s3.cpu0 xtensa smpbreak BreakIn BreakOut
Debug: 284 83 xtensa.c:744 xtensa_smpbreak_set(): esp32s3.cpu0: set smpbreak=30000, state=1
Debug: 285 83 xtensa.c:744 xtensa_smpbreak_set(): esp32s3.cpu1: set smpbreak=30000, state=1
Debug: 286 83 command.c:166 script_debug(): command - esp32s3.cpu0 configure -event examine-end 
    # Need to enable to set 'semihosting_basedir'
    arm semihosting enable
    arm semihosting_resexit enable
    if { [info exists _SEMIHOST_BASEDIR] } {
        if { $_SEMIHOST_BASEDIR != "" } {
            arm semihosting_basedir $_SEMIHOST_BASEDIR
        }
    }

Debug: 287 83 command.c:166 script_debug(): command - esp32s3.cpu1 configure -event examine-end 
        # Need to enable to set 'semihosting_basedir'
        arm semihosting enable
        arm semihosting_resexit enable
        if { [info exists _SEMIHOST_BASEDIR] } {
            if { $_SEMIHOST_BASEDIR != "" } {
                arm semihosting_basedir $_SEMIHOST_BASEDIR
            }
        }

Debug: 288 84 command.c:166 script_debug(): command - esp32s3.cpu0 configure -event gdb-attach 
    $_TARGETNAME_0 xtensa smpbreak BreakIn BreakOut
    # necessary to auto-probe flash bank when GDB is connected
    halt
    if { [esp32s3_memprot_is_enabled] } {
        # 'reset halt' to disable memory protection and allow flasher to work correctly
        echo "Memory protection is enabled. Reset target to disable it..."
        reset halt
    }

Debug: 289 84 command.c:166 script_debug(): command - esp32s3.cpu1 configure -event gdb-attach 
        $_TARGETNAME_1 xtensa smpbreak BreakIn BreakOut
        # necessary to auto-probe flash bank when GDB is connected
        halt
        if { [esp32s3_memprot_is_enabled] } {
            # 'reset halt' to disable memory protection and allow flasher to work correctly
            echo "Memory protection is enabled. Reset target to disable it..."
            reset halt
        }

Info : 290 86 server.c:303 add_service(): Listening on port 6666 for tcl connections
Info : 291 106 server.c:303 add_service(): Listening on port 4444 for telnet connections
Debug: 292 106 command.c:166 script_debug(): command - init
Debug: 293 107 command.c:166 script_debug(): command - target init
Debug: 294 107 command.c:166 script_debug(): command - target names
Debug: 295 107 command.c:166 script_debug(): command - esp32s3.cpu0 cget -event gdb-flash-erase-start
Debug: 296 107 command.c:166 script_debug(): command - esp32s3.cpu0 configure -event gdb-flash-erase-start reset init
Debug: 297 107 command.c:166 script_debug(): command - esp32s3.cpu0 cget -event gdb-flash-write-end
Debug: 298 107 command.c:166 script_debug(): command - esp32s3.cpu0 configure -event gdb-flash-write-end reset halt
Debug: 299 107 command.c:166 script_debug(): command - esp32s3.cpu0 cget -event gdb-attach
Debug: 300 107 command.c:166 script_debug(): command - esp32s3.cpu1 cget -event gdb-flash-erase-start
Debug: 301 107 command.c:166 script_debug(): command - esp32s3.cpu1 configure -event gdb-flash-erase-start reset init
Debug: 302 107 command.c:166 script_debug(): command - esp32s3.cpu1 cget -event gdb-flash-write-end
Debug: 303 107 command.c:166 script_debug(): command - esp32s3.cpu1 configure -event gdb-flash-write-end reset halt
Debug: 304 107 command.c:166 script_debug(): command - esp32s3.cpu1 cget -event gdb-attach
Debug: 305 108 target.c:1669 handle_target_init_command(): Initializing targets...
Debug: 306 108 xtensa.c:2382 xtensa_build_reg_cache(): Special reg 'litbase' (152) does not exist
Debug: 307 108 xtensa.c:2382 xtensa_build_reg_cache(): Special reg 'ptevaddr' (153) does not exist
Debug: 308 108 xtensa.c:2382 xtensa_build_reg_cache(): Special reg 'rasid' (154) does not exist
Debug: 309 108 xtensa.c:2382 xtensa_build_reg_cache(): Special reg 'itlbcfg' (155) does not exist
Debug: 310 108 xtensa.c:2382 xtensa_build_reg_cache(): Special reg 'dtlbcfg' (156) does not exist
Debug: 311 108 xtensa.c:2382 xtensa_build_reg_cache(): Special reg 'mepc' (157) does not exist
Debug: 312 108 xtensa.c:2382 xtensa_build_reg_cache(): Special reg 'meps' (158) does not exist
Debug: 313 108 xtensa.c:2382 xtensa_build_reg_cache(): Special reg 'mesave' (159) does not exist
Debug: 314 108 xtensa.c:2382 xtensa_build_reg_cache(): Special reg 'mesr' (160) does not exist
Debug: 315 108 xtensa.c:2382 xtensa_build_reg_cache(): Special reg 'mecr' (161) does not exist
Debug: 316 108 xtensa.c:2382 xtensa_build_reg_cache(): Special reg 'mevaddr' (162) does not exist
Debug: 317 108 semihosting_common.c:120 semihosting_common_init():  
Debug: 318 108 xtensa.c:2382 xtensa_build_reg_cache(): Special reg 'litbase' (152) does not exist
Debug: 319 109 xtensa.c:2382 xtensa_build_reg_cache(): Special reg 'ptevaddr' (153) does not exist
Debug: 320 109 xtensa.c:2382 xtensa_build_reg_cache(): Special reg 'rasid' (154) does not exist
Debug: 321 109 xtensa.c:2382 xtensa_build_reg_cache(): Special reg 'itlbcfg' (155) does not exist
Debug: 322 109 xtensa.c:2382 xtensa_build_reg_cache(): Special reg 'dtlbcfg' (156) does not exist
Debug: 323 109 xtensa.c:2382 xtensa_build_reg_cache(): Special reg 'mepc' (157) does not exist
Debug: 324 109 xtensa.c:2382 xtensa_build_reg_cache(): Special reg 'meps' (158) does not exist
Debug: 325 109 xtensa.c:2382 xtensa_build_reg_cache(): Special reg 'mesave' (159) does not exist
Debug: 326 109 xtensa.c:2382 xtensa_build_reg_cache(): Special reg 'mesr' (160) does not exist
Debug: 327 109 xtensa.c:2382 xtensa_build_reg_cache(): Special reg 'mecr' (161) does not exist
Debug: 328 109 xtensa.c:2382 xtensa_build_reg_cache(): Special reg 'mevaddr' (162) does not exist
Debug: 329 109 semihosting_common.c:120 semihosting_common_init():  
Error: 330 126 libusb_helper.c:190 jtag_libusb_open(): libusb_open() failed with LIBUSB_ERROR_NOT_SUPPORTED
Info : 331 131 esp_usb_jtag.c:677 esp_usb_jtag_init(): esp_usb_jtag: serial (F4:12:FA:C1:A1:64)
Debug: 332 131 libusb_helper.c:337 jtag_libusb_choose_interface(): usb ep out 02
Debug: 333 131 libusb_helper.c:337 jtag_libusb_choose_interface(): usb ep in 83
Debug: 334 150 libusb_helper.c:345 jtag_libusb_choose_interface(): Claiming interface 2
Info : 335 153 esp_usb_jtag.c:737 esp_usb_jtag_init(): esp_usb_jtag: Device found. Base speed 40000KHz, div range 1 to 
255
Debug: 336 155 adapter.c:144 adapter_khz_to_speed(): convert khz to adapter specific speed value
Debug: 337 155 adapter.c:148 adapter_khz_to_speed(): have adapter set up
Debug: 338 155 esp_usb_jtag.c:796 esp_usb_jtag_khz(): Divisor for 40000 KHz with base clock of 40000 khz is 1
Debug: 339 155 esp_usb_jtag.c:812 esp_usb_jtag_speed(): esp_usb_jtag: setting divisor 1
Debug: 340 157 adapter.c:144 adapter_khz_to_speed(): convert khz to adapter specific speed value
Debug: 341 157 adapter.c:148 adapter_khz_to_speed(): have adapter set up
Debug: 342 157 esp_usb_jtag.c:796 esp_usb_jtag_khz(): Divisor for 40000 KHz with base clock of 40000 khz is 1
Info : 343 157 adapter.c:108 adapter_init(): clock speed 40000 kHz
Debug: 344 157 openocd.c:143 handle_init_command(): Debug Adapter init complete
Debug: 345 157 command.c:166 script_debug(): command - transport init
Debug: 346 157 transport.c:230 handle_transport_init(): handle_transport_init
Debug: 347 157 core.c:712 legacy_jtag_add_reset(): SRST line released
Debug: 348 157 core.c:736 legacy_jtag_add_reset(): TRST line released
Debug: 349 157 core.c:322 jtag_call_event_callbacks(): jtag event: TAP reset
Debug: 350 158 command.c:166 script_debug(): command - jtag arp_init
Debug: 351 158 core.c:1503 jtag_init_inner(): Init JTAG chain
Debug: 352 158 core.c:322 jtag_call_event_callbacks(): jtag event: TAP reset
Debug: 353 158 core.c:1228 jtag_examine_chain(): DR scan interrogation for IDCODE/BYPASS
Debug: 354 158 core.c:322 jtag_call_event_callbacks(): jtag event: TAP reset
Info : 355 159 core.c:1127 jtag_examine_chain_display(): JTAG tap: esp32s3.cpu0 tap/device found: 0x120034e5 (mfg: 
0x272 (Tensilica), part: 0x2003, ver: 0x1)
Info : 356 159 core.c:1127 jtag_examine_chain_display(): JTAG tap: esp32s3.cpu1 tap/device found: 0x120034e5 (mfg: 
0x272 (Tensilica), part: 0x2003, ver: 0x1)
Debug: 357 159 core.c:1358 jtag_validate_ircapture(): IR capture validation scan
Debug: 358 159 core.c:1416 jtag_validate_ircapture(): esp32s3.cpu0: IR capture 0x01
Debug: 359 159 core.c:1416 jtag_validate_ircapture(): esp32s3.cpu1: IR capture 0x01
Debug: 360 159 command.c:166 script_debug(): command - dap init
Debug: 361 159 arm_dap.c:107 dap_init_all(): Initializing all DAPs ...
Debug: 362 159 openocd.c:160 handle_init_command(): Examining targets...
Debug: 363 160 target.c:1857 target_call_event_callbacks(): target event 19 (examine-start) for core esp32s3.cpu0
Debug: 364 160 esp32s3.c:593 esp32s3_handle_target_event(): 19
Debug: 365 160 esp_xtensa_smp.c:609 esp_xtensa_smp_handle_target_event(): 19
Debug: 366 160 esp_xtensa.c:79 esp_xtensa_handle_target_event(): 19
Debug: 367 160 xtensa.c:2450 xtensa_handle_target_event(): 19
Debug: 368 160 xtensa.c:685 xtensa_examine(): xtensa_examine coreid=0
Debug: 369 160 xtensa.c:698 xtensa_examine(): OCD_ID = 0b339fd2
Debug: 370 160 target.c:1857 target_call_event_callbacks(): target event 21 (examine-end) for core esp32s3.cpu0
Debug: 371 160 target.c:5148 target_handle_event(): target(0): esp32s3.cpu0 (esp32s3) event: 21 (examine-end) action: 
    # Need to enable to set 'semihosting_basedir'
    arm semihosting enable
    arm semihosting_resexit enable
    if { [info exists _SEMIHOST_BASEDIR] } {
        if { $_SEMIHOST_BASEDIR != "" } {
            arm semihosting_basedir $_SEMIHOST_BASEDIR
        }
    }

Debug: 372 161 command.c:166 script_debug(): command - arm semihosting enable
Info : 373 161 xtensa.c:1804 xtensa_poll(): esp32s3.cpu0: Debug controller was reset.
Debug: 374 161 xtensa.c:726 xtensa_smpbreak_write(): esp32s3.cpu0: write smpbreak set=0x30000 clear=0x600000
Info : 375 161 xtensa.c:1810 xtensa_poll(): esp32s3.cpu0: Core was reset.
Debug: 376 162 esp_xtensa.c:152 esp_xtensa_poll(): esp32s3.cpu0: Clear debug stubs info
Debug: 377 162 esp_xtensa_smp.c:175 esp_xtensa_smp_poll(): esp32s3.cpu0: Check for unexamined cores after reset
Debug: 378 174 target.c:1857 target_call_event_callbacks(): target event 19 (examine-start) for core esp32s3.cpu1
Debug: 379 174 esp32s3.c:593 esp32s3_handle_target_event(): 19
Debug: 380 174 esp_xtensa_smp.c:609 esp_xtensa_smp_handle_target_event(): 19
Debug: 381 174 esp_xtensa.c:79 esp_xtensa_handle_target_event(): 19
Debug: 382 174 xtensa.c:2450 xtensa_handle_target_event(): 19
Debug: 383 174 xtensa.c:685 xtensa_examine(): xtensa_examine coreid=1
Debug: 384 175 xtensa.c:698 xtensa_examine(): OCD_ID = 0b339fd2
Debug: 385 175 target.c:1857 target_call_event_callbacks(): target event 21 (examine-end) for core esp32s3.cpu1
Debug: 386 175 target.c:5148 target_handle_event(): target(1): esp32s3.cpu1 (esp32s3) event: 21 (examine-end) action: 
        # Need to enable to set 'semihosting_basedir'
        arm semihosting enable
        arm semihosting_resexit enable
        if { [info exists _SEMIHOST_BASEDIR] } {
            if { $_SEMIHOST_BASEDIR != "" } {
                arm semihosting_basedir $_SEMIHOST_BASEDIR
            }
        }

Debug: 387 176 command.c:166 script_debug(): command - arm semihosting enable
Debug: 388 176 esp_xtensa_semihosting.c:46 esp_xtensa_semihosting_setup(): [esp32s3.cpu1] semihosting enable=1
Debug: 389 176 command.c:166 script_debug(): command - arm semihosting_resexit enable
Debug: 390 176 command.c:166 script_debug(): command - arm semihosting_basedir .
Debug: 391 176 esp32s3.c:593 esp32s3_handle_target_event(): 21
Debug: 392 176 esp_xtensa_smp.c:609 esp_xtensa_smp_handle_target_event(): 21
Debug: 393 176 esp_xtensa.c:79 esp_xtensa_handle_target_event(): 21
Debug: 394 176 xtensa.c:2450 xtensa_handle_target_event(): 21
Debug: 395 176 xtensa.c:726 xtensa_smpbreak_write(): esp32s3.cpu1: write smpbreak set=0x30000 clear=0x600000
Info : 396 177 xtensa.c:1804 xtensa_poll(): esp32s3.cpu1: Debug controller was reset.
Debug: 397 177 xtensa.c:726 xtensa_smpbreak_write(): esp32s3.cpu1: write smpbreak set=0x30000 clear=0x600000
Info : 398 177 xtensa.c:1810 xtensa_poll(): esp32s3.cpu1: Core was reset.
Debug: 399 178 esp_xtensa.c:152 esp_xtensa_poll(): esp32s3.cpu1: Clear debug stubs info
Debug: 400 178 esp_xtensa_smp.c:175 esp_xtensa_smp_poll(): esp32s3.cpu1: Check for unexamined cores after reset
Debug: 401 178 esp_xtensa_semihosting.c:46 esp_xtensa_semihosting_setup(): [esp32s3.cpu0] semihosting enable=1
Debug: 402 178 command.c:166 script_debug(): command - arm semihosting_resexit enable
Debug: 403 181 command.c:166 script_debug(): command - arm semihosting_basedir .
Debug: 404 183 esp32s3.c:593 esp32s3_handle_target_event(): 21
Debug: 405 183 esp_xtensa_smp.c:609 esp_xtensa_smp_handle_target_event(): 21
Debug: 406 183 esp_xtensa.c:79 esp_xtensa_handle_target_event(): 21
Debug: 407 183 xtensa.c:2450 xtensa_handle_target_event(): 21
Debug: 408 183 xtensa.c:726 xtensa_smpbreak_write(): esp32s3.cpu0: write smpbreak set=0x30000 clear=0x600000
Debug: 409 184 target.c:1857 target_call_event_callbacks(): target event 19 (examine-start) for core esp32s3.cpu1
Debug: 410 184 esp32s3.c:593 esp32s3_handle_target_event(): 19
Debug: 411 184 esp_xtensa_smp.c:609 esp_xtensa_smp_handle_target_event(): 19
Debug: 412 184 esp_xtensa.c:79 esp_xtensa_handle_target_event(): 19
Debug: 413 184 xtensa.c:2450 xtensa_handle_target_event(): 19
Debug: 414 184 xtensa.c:685 xtensa_examine(): xtensa_examine coreid=1
Debug: 415 185 xtensa.c:698 xtensa_examine(): OCD_ID = 0b339fd2
Debug: 416 185 target.c:1857 target_call_event_callbacks(): target event 21 (examine-end) for core esp32s3.cpu1
Debug: 417 185 target.c:5148 target_handle_event(): target(1): esp32s3.cpu1 (esp32s3) event: 21 (examine-end) action: 
        # Need to enable to set 'semihosting_basedir'
        arm semihosting enable
        arm semihosting_resexit enable
        if { [info exists _SEMIHOST_BASEDIR] } {
            if { $_SEMIHOST_BASEDIR != "" } {
                arm semihosting_basedir $_SEMIHOST_BASEDIR
            }
        }

Debug: 418 185 command.c:166 script_debug(): command - arm semihosting enable
Debug: 419 187 esp_xtensa_semihosting.c:46 esp_xtensa_semihosting_setup(): [esp32s3.cpu1] semihosting enable=1
Debug: 420 201 command.c:166 script_debug(): command - arm semihosting_resexit enable
Debug: 421 203 command.c:166 script_debug(): command - arm semihosting_basedir .
Debug: 422 205 esp32s3.c:593 esp32s3_handle_target_event(): 21
Debug: 423 205 esp_xtensa_smp.c:609 esp_xtensa_smp_handle_target_event(): 21
Debug: 424 206 esp_xtensa.c:79 esp_xtensa_handle_target_event(): 21
Debug: 425 206 xtensa.c:2450 xtensa_handle_target_event(): 21
Debug: 426 206 xtensa.c:726 xtensa_smpbreak_write(): esp32s3.cpu1: write smpbreak set=0x30000 clear=0x600000
Debug: 427 206 command.c:166 script_debug(): command - flash init
Debug: 428 208 tcl.c:1386 handle_flash_init_command(): Initializing flash devices...
Debug: 429 208 command.c:166 script_debug(): command - nand init
Debug: 430 210 tcl.c:498 handle_nand_init_command(): Initializing NAND devices...
Debug: 431 210 command.c:166 script_debug(): command - pld init
Debug: 432 213 pld.c:205 handle_pld_init_command(): Initializing PLDs...
Debug: 433 213 command.c:166 script_debug(): command - tpiu init
Info : 434 215 gdb_server.c:3742 gdb_target_start(): starting gdb server for esp32s3.cpu0 on 3333
Info : 435 215 server.c:303 add_service(): Listening on port 3333 for gdb connections

Expected behavior

Do not report an Error if connection is OK.

Screenshots

No response

Panometric commented 2 years ago

Can anyone help on this, it's so annoying.. I CAN debug, but the vscode extension pops up this error every session.

Others have reported since 2018... https://www.esp32.com/viewtopic.php?t=5580

erhankur commented 2 years ago

cc @kolipakakondal

kolipakakondal commented 2 years ago

Hi @Panometric

libusb_open() failed with LIBUSB_ERROR_NOT_SUPPORTED

This is ok for windows and the JTAG connection should work even with this. Looking at the above console log messages I don't see any other error.

However, run https://visualgdb.com/UsbDriverTool/ instead of Zadig for installation of libusb and see if that helps to avoid the above error as well.

Panometric commented 2 years ago

@kolipakakondal Thanks for that tip. I tried the WinUSB driver on VID 303A DevID 1001 Interface 2. Got the same error.

This is what I understood was the correct way, per "Please install the WinUSB driver only for the interface where there is no driver installed (probably it is Interface 2) and do not re-install the driver for the other interface."

But then I noticed UsbDriverTool also shows the composite device that Zadig does not. So I installed libusb to the Composite Device and rebooted the device, and JTAG was fixed. BUT, there is no Serial port anymore, only JTAG.

Note on interface 2, when debugging over JTAG and having the serial monitor on that I was also having unexpected DIR errors. I have set my clock speed down to 20000, as was suggested "In particular reduce frequency, if you get DSR/DIR errors " it has not gotten rid of the errors.

So perhaps there is more to this problem than just an unwanted message. It seems to be related to having a composite device.

Either way, there does not seem to be a solution that does not break something.

Log showing unchanged error with UsbDriverTool on Interface 2.

Open On-Chip Debugger  v0.11.0-esp32-20220411 (2022-04-11-08:48)
Licensed under GNU GPL v2
For bug reports, read
        http://openocd.org/doc/doxygen/bugs.html
Info : only one transport option; autoselect 'jtag'
Info : esp_usb_jtag: VID set to 0x303a and PID to 0x1001
Info : esp_usb_jtag: capabilities descriptor set to 0x2000
Warn : Transport "jtag" was already selected
Info : Listening on port 6666 for tcl connections
Info : Listening on port 4444 for telnet connections
Error: libusb_open() failed with LIBUSB_ERROR_NOT_SUPPORTED
Info : esp_usb_jtag: serial (F4:12:FA:C1:A1:64)
Info : esp_usb_jtag: Device found. Base speed 40000KHz, div range 1 to 255
Info : clock speed 20000 kHz
Info : JTAG tap: esp32s3.cpu0 tap/device found: 0x120034e5 (mfg: 0x272 (Tensilica), part: 0x2003, ver: 0x1)
Info : JTAG tap: esp32s3.cpu1 tap/device found: 0x120034e5 (mfg: 0x272 (Tensilica), part: 0x2003, ver: 0x1)
Info : starting gdb server for esp32s3.cpu0 on 3333
Info : Listening on port 3333 for gdb connections

erhankur commented 1 year ago

Hi @Panometric I have updated libusb version to 1.0.26. Looks like the error disappeared in my windows machine. (Win10)

Can you also test and verify with the attached package?

openocd-esp32-win32-0.11.0-esp32-20221026-87-gd269916f9.zip

erhankur commented 1 year ago

c:\esp_\openocd-esp32\bin>openocd.exe -s ..\share\openocd\scripts -f board/esp32s3-builtin.cfg
Open On-Chip Debugger v0.11.0-esp32-20221026-87-gd269916f (2023-01-16-14:04)
Licensed under GNU GPL v2
For bug reports, read
        http://openocd.org/doc/doxygen/bugs.html
Info : only one transport option; autoselect 'jtag'
Info : esp_usb_jtag: VID set to 0x303a and PID to 0x1001
Info : esp_usb_jtag: capabilities descriptor set to 0x2000
Warn : Transport "jtag" was already selected
Info : Listening on port 6666 for tcl connections
Info : Listening on port 4444 for telnet connections
Info : esp_usb_jtag: serial (7C:DF:A1:E1:19:00)
Info : esp_usb_jtag: Device found. Base speed 40000KHz, div range 1 to 255
Info : clock speed 40000 kHz
Info : JTAG tap: esp32s3.cpu0 tap/device found: 0x120034e5 (mfg: 0x272 (Tensilica), part: 0x2003, ver: 0x1)
Info : JTAG tap: esp32s3.cpu1 tap/device found: 0x120034e5 (mfg: 0x272 (Tensilica), part: 0x2003, ver: 0x1)
Info : starting gdb server for esp32s3.cpu0 on 3333
Info : Listening on port 3333 for gdb connections
Info : [esp32s3.cpu0] Target halted, PC=0x4037A9E0, debug_reason=00000000
Info : [esp32s3.cpu0] Reset cause (3) - (Software core reset)
Info : [esp32s3.cpu1] Target halted, PC=0x4037A9E0, debug_reason=00000000
Info : [esp32s3.cpu1] Reset cause (3) - (Software core reset)

Panometric commented 1 year ago

@erhankur Just updating the driver didn't do it, but the package did. Where/ when will this be officially released? Thanks!

erhankur commented 1 year ago

Glad it worked for you, too. The official release date is not decided yet. Until release, you can just replace openocd-esp32 folder under .espressif\tools\openocd-esp32\<your version>\ We have backward compatibility between idf versions. So there should be no new issue.

sirapol commented 1 year ago

Hello I found same issues.

OS : Ubuntu VScode ESP-IDF : 5.2.0 Hardware : ESP32-2424S012 // ESP32-C3 with Round display

`/home/sirapol/.espressif/tools/openocd-esp32/v0.12.0-esp32-20230419/openocd-esp32/bin/openocd

Open On-Chip Debugger v0.12.0-esp32-20230419 (2023-04-18-22:02) Licensed under GNU GPL v2 For bug reports, read http://openocd.org/doc/doxygen/bugs.html

/home/sirapol/.espressif/tools/openocd-esp32/v0.12.0-esp32-20230419/openocd-esp32/bin/openocd

[OpenOCD] Open On-Chip Debugger v0.12.0-esp32-20230419 (2023-04-18-22:02) Licensed under GNU GPL v2 For bug reports, read http://openocd.org/doc/doxygen/bugs.html User : 3 1 options.c:52 configuration_output_handler(): debug_level: 3User : 4 1 options.c:52 configuration_output_handler(): Debug: 5 1 options.c:233 add_default_dirs(): bindir=/builds/idf/openocd-esp32/_build/../openocd-esp32/bin Debug: 6 1 options.c:234 add_default_dirs(): pkgdatadir=/builds/idf/openocd-esp32/_build/../openocd-esp32/share/openocd Debug: 7 1 options.c:235 add_default_dirs(): exepath=/home/sirapol/.espressif/tools/openocd-esp32/v0.12.0-esp32-20230419/openocd-esp32/bin Debug: 8 1 options.c:236 add_default_dirs(): bin2data=../share/openocd Debug: 9 1 configuration.c:33 add_script_search_dir(): adding /home/sirapol/.espressif/tools/openocd-esp32/v0.12.0-esp32-20230419/openocd-esp32/share/openocd/scripts Debug: 10 1 configuration.c:33 add_script_search_dir(): adding /home/sirapol/.config/openocd Debug: 11 1 configuration.c:33 add_script_search_dir(): adding /home/sirapol/.openocd Debug: 12 1 configuration.c:33 add_script_search_dir(): adding /home/sirapol/.espressif/tools/openocd-esp32/v0.12.0-esp32-20230419/openocd-esp32/bin/../share/openocd/site Debug: 13 1 configuration.c:33 add_script_search_dir(): adding /home/sirapol/.espressif/tools/openocd-esp32/v0.12.0-esp32-20230419/openocd-esp32/bin/../share/openocd/scripts Debug: 14 1 command.c:152 script_debug(): command - ocd_find board/esp32c3-builtin.cfg Debug: 15 1 configuration.c:88 find_file(): found /home/sirapol/.espressif/tools/openocd-esp32/v0.12.0-esp32-20230419/openocd-esp32/share/openocd/scripts/board/esp32c3-builtin.cfg Debug: 16 1 command.c:152 script_debug(): command - ocd_find interface/esp_usb_jtag.cfg Debug: 17 1 configuration.c:88 find_file(): found /home/sirapol/.espressif/tools/openocd-esp32/v0.12.0-esp32-20230419/openocd-esp32/share/openocd/scripts/interface/esp_usb_jtag.cfg Debug: 18 1 command.c:152 script_debug(): command - adapter driver esp_usb_jtag

[OpenOCD] Info : 19 1 transport.c:107 allow_transports(): only one transport option; autoselecting 'jtag' Debug: 20 1 command.c:152 script_debug(): command - espusbjtag vid_pid 0x303a 0x1001 Info : 21 1 esp_usb_jtag.c:894 esp_usb_jtag_vid_pid(): esp_usb_jtag: VID set to 0x303a and PID to 0x1001 Debug: 22 1 command.c:152 script_debug(): command - espusbjtag caps_descriptor 0x2000 Info : 23 1 esp_usb_jtag.c:905 esp_usb_jtag_caps_descriptor(): esp_usb_jtag: capabilities descriptor set to 0x2000 Debug: 24 1 command.c:152 script_debug(): command - adapter speed 40000 Debug: 25 1 adapter.c:253 adapter_config_khz(): handle adapter khz Debug: 26 1 adapter.c:217 adapter_khz_to_speed(): convert khz to adapter specific speed value Debug: 27 1 adapter.c:217 adapter_khz_to_speed(): convert khz to adapter specific speed value Debug: 28 1 command.c:152 script_debug(): command - ocd_find target/esp32c3.cfg Debug: 29 1 configuration.c:88 find_file(): found /home/sirapol/.espressif/tools/openocd-esp32/v0.12.0-esp32-20230419/openocd-esp32/share/openocd/scripts/target/esp32c3.cfg Debug: 30 1 command.c:152 script_debug(): command - transport select jtag Warn : 31 1 transport.c:280 handle_transport_select(): Transport "jtag" was already selected Debug: 32 1 command.c:152 script_debug(): command - ocd_find bitsbytes.tcl Debug: 33 1 configuration.c:88 find_file(): found /home/sirapol/.espressif/tools/openocd-esp32/v0.12.0-esp32-20230419/openocd-esp32/share/openocd/scripts/bitsbytes.tcl Debug: 34 2 command.c:152 script_debug(): command - ocd_find memory.tcl Debug: 35 2 configuration.c:88 find_file(): found /home/sirapol/.espressif/tools/openocd-esp32/v0.12.0-esp32-20230419/openocd-esp32/share/openocd/scripts/memory.tcl Debug: 36 2 command.c:152 script_debug(): command - ocd_find mmr_helpers.tcl Debug: 37 2 configuration.c:88 find_file(): found /home/sirapol/.espressif/tools/openocd-esp32/v0.12.0-esp32-20230419/openocd-esp32/share/openocd/scripts/mmr_helpers.tcl Debug: 38 2 command.c:152 script_debug(): command - ocd_find target/esp_common.cfg Debug: 39 2 configuration.c:88 find_file(): found /home/sirapol/.espressif/tools/openocd-esp32/v0.12.0-esp32-20230419/openocd-esp32/share/openocd/scripts/target/esp_common.cfg Debug: 40 2 command.c:152 script_debug(): command - ocd_find target/esp_version.cfg Debug: 41 2 configuration.c:88 find_file(): found /home/sirapol/.espressif/tools/openocd-esp32/v0.12.0-esp32-20230419/openocd-esp32/share/openocd/scripts/target/esp_version.cfg Debug: 42 2 command.c:152 script_debug(): command - version Debug: 43 2 command.c:152 script_debug(): command - add_help_text program_esp write an image to flash, address is only required for binary images. verify, reset, exit, compress, restore_clock and encrypt are optional Debug: 44 2 command.c:152 script_debug(): command - add_usage_text program_esp [address] [verify] [reset] [exit] [compress] [no_clock_boost] [restore_clock] [encrypt] Debug: 45 2 command.c:152 script_debug(): command - add_help_text program_esp_bins write all the images at address specified in flasher_args.json generated while building idf project Debug: 46 2 command.c:152 script_debug(): command - add_usage_text program_esp_bins flasher_args.json [verify] [reset] [exit] [compress] [no_clock_boost] [restore_clock] Debug: 47 2 command.c:152 script_debug(): command - add_help_text esp_get_mac Print MAC address of the chip. Use a format argument to return formatted MAC value Debug: 48 2 command.c:152 script_debug(): command - add_usage_text esp_get_mac [format] Debug: 49 2 command.c:152 script_debug(): command - jtag newtap esp32c3 cpu -irlen 5 -expected-id 0x00005c25 Debug: 50 2 tcl.c:562 jim_newtap_cmd(): Creating New Tap, Chip: esp32c3, Tap: cpu, Dotted: esp32c3.cpu, 4 params Debug: 51 2 tcl.c:579 jim_newtap_cmd(): Processing option: -irlen Debug: 52 2 tcl.c:579 jim_newtap_cmd(): Processing option: -expected-id Debug: 53 2 core.c:1478 jtag_tap_init(): Created Tap: esp32c3.cpu @ abs position 0, irlen 5, capture: 0x1 mask: 0x3 Debug: 54 2 command.c:152 script_debug(): command - target create esp32c3 esp32c3 -chain-position esp32c3.cpu -rtos FreeRTOS Debug: 55 2 target.c:2223 target_free_all_working_areas_restore(): freeing all working areas Debug: 56 2 target.c:2223 target_free_all_working_areas_restore(): freeing all working areas Debug: 57 2 FreeRTOS.c:1414 freertos_create(): freertos_create

[OpenOCD] Debug: 58 2 command.c:286 register_command(): command 'esp' is already registered Debug: 59 2 command.c:286 register_command(): command 'esp32c3 esp' is already registered Debug: 60 2 command.c:152 script_debug(): command - esp32c3 configure -event reset-assert-post esp32c3_soc_reset Debug: 61 2 command.c:152 script_debug(): command - esp32c3 configure -event halted esp32c3_wdt_disable esp halted_event_handler

Debug: 62 2 command.c:152 script_debug(): command - esp32c3 configure -event examine-end

Need this to handle 'apptrace init' syscall correctly because semihosting is not enabled by default

arm semihosting enable
arm semihosting_resexit enable
if { [info exists _SEMIHOST_BASEDIR] } {
    if { $_SEMIHOST_BASEDIR != "" } {
        arm semihosting_basedir $_SEMIHOST_BASEDIR
    }
}

Debug: 63 2 command.c:152 script_debug(): command - esp32c3 configure -event gdb-detach $_TARGETNAME esp gdb_detach_handler

Debug: 64 2 command.c:152 script_debug(): command - esp32c3 configure -event gdb-attach

'halt' is necessary to auto-probe flash bank when GDB is connected and generate proper memory map

halt 1000
if { [esp32c3_memprot_is_enabled] } {
    # 'reset halt' to disable memory protection and allow flasher to work correctly
    echo "Memory protection is enabled. Reset target to disable it..."
    reset halt
}
# by default mask interrupts while stepping
riscv set_maskisr steponly

Debug: 65 2 command.c:152 script_debug(): command - esp32c3 configure -work-area-phys 0x40380000 -work-area-virt 0x40380000 -work-area-size 0x4000 -work-area-backup 1 Debug: 66 2 target.c:2223 target_free_all_working_areas_restore(): freeing all working areas Debug: 67 2 target.c:2223 target_free_all_working_areas_restore(): freeing all working areas Debug: 68 2 target.c:2223 target_free_all_working_areas_restore(): freeing all working areas Debug: 69 2 target.c:2223 target_free_all_working_areas_restore(): freeing all working areas Debug: 70 2 command.c:152 script_debug(): command - esp32c3 configure -alt-work-area-phys 0x3FC84000 -alt-work-area-virt 0x3FC84000 -alt-work-area-size 0x20000 -alt-work-area-backup 1 Debug: 71 2 target.c:2223 target_free_all_working_areas_restore(): freeing all working areas Debug: 72 2 target.c:2223 target_free_all_working_areas_restore(): freeing all working areas Debug: 73 2 target.c:2223 target_free_all_working_areas_restore(): freeing all working areas Debug: 74 2 target.c:2223 target_free_all_working_areas_restore(): freeing all working areas Debug: 75 2 command.c:152 script_debug(): command - flash bank esp32c3.flash esp32c3 0x0 0 0 0 esp32c3 Debug: 76 2 command.c:286 register_command(): command 'esp' is already registered Debug: 77 2 tcl.c:1305 handle_flash_bank_command(): 'esp32c3' driver usage field missing Debug: 78 2 command.c:152 script_debug(): command - flash bank esp32c3.irom esp32c3 0x0 0 0 0 esp32c3 Debug: 79 2 command.c:286 register_command(): command 'esp' is already registered Debug: 80 2 command.c:286 register_command(): command 'esp appimage_offset' is already registered Debug: 81 2 command.c:286 register_command(): command 'esp compression' is already registered Debug: 82 2 command.c:286 register_command(): command 'esp verify_bank_hash' is already registered Debug: 83 2 command.c:286 register_command(): command 'esp flash_stub_clock_boost' is already registered Debug: 84 2 command.c:286 register_command(): command 'esp encrypt_binary' is already registered Debug: 85 2 command.c:286 register_command(): command 'esp stub_log' is already registered Debug: 86 2 tcl.c:1305 handle_flash_bank_command(): 'esp32c3' driver usage field missing Debug: 87 3 command.c:152 script_debug(): command - flash bank esp32c3.drom esp32c3 0x0 0 0 0 esp32c3 Debug: 88 3 command.c:286 register_command(): command 'esp' is already registered Debug: 89 3 command.c:286 register_command(): command 'esp appimage_offset' is already registered Debug: 90 3 command.c:286 register_command(): command 'esp compression' is already registered Debug: 91 3 command.c:286 register_command(): command 'esp verify_bank_hash' is already registered Debug: 92 3 command.c:286 register_command(): command 'esp flash_stub_clock_boost' is already registered Debug: 93 3 command.c:286 register_command(): command 'esp encrypt_binary' is already registered Debug: 94 3 command.c:286 register_command(): command 'esp stub_log' is already registered Debug: 95 3 tcl.c:1305 handle_flash_bank_command(): 'esp32c3' driver usage field missing Debug: 96 3 command.c:152 script_debug(): command - riscv set_reset_timeout_sec 2 Debug: 97 3 command.c:152 script_debug(): command - riscv set_command_timeout_sec 5 Debug: 98 3 command.c:152 script_debug(): command - riscv set_mem_access sysbus progbuf abstract Debug: 99 3 command.c:152 script_debug(): command - riscv set_ebreakm on Debug: 100 3 command.c:152 script_debug(): command - riscv set_ebreaks on Debug: 101 3 command.c:152 script_debug(): command - riscv set_ebreaku on Info : 102 3 server.c:298 add_service(): Listening on port 6666 for tcl connections Info : 103 3 server.c:298 add_service(): Listening on port 4444 for telnet connections Debug: 104 3 command.c:152 script_debug(): command - init Debug: 105 3 command.c:152 script_debug(): command - target init Debug: 106 3 command.c:152 script_debug(): command - target names Debug: 107 3 command.c:152 script_debug(): command - esp32c3 cget -event gdb-flash-erase-start Debug: 108 3 command.c:152 script_debug(): command - esp32c3 configure -event gdb-flash-erase-start reset init Debug: 109 3 command.c:152 script_debug(): command - esp32c3 cget -event gdb-flash-write-end Debug: 110 3 command.c:152 script_debug(): command - esp32c3 configure -event gdb-flash-write-end reset halt Debug: 111 3 command.c:152 script_debug(): command - esp32c3 cget -event gdb-attach Debug: 112 3 target.c:1657 handle_target_init_command(): Initializing targets... Debug: 113 3 riscv.c:444 riscv_init_target(): riscv_init_target() Debug: 114 3 semihosting_common.c:107 semihosting_common_init():

[OpenOCD] ❌ Error: 115 6 libusb_helper.c:179 jtag_libusb_open(): libusb_open() failed with LIBUSB_ERROR_ACCESS

[OpenOCD] ❌ Error: 116 6 esp_usb_jtag.c:646 esp_usb_jtag_init(): esp_usb_jtag: could not find or open device! Debug: 117 6 command.c:542 run_command(): Command 'init' failed with error code -4 User : 118 6 command.c:613 command_run_line(): /home/sirapol/.espressif/tools/openocd-esp32/v0.12.0-esp32-20230419/openocd-esp32/share/openocd/scripts/target/esp_common.cfg:4: Error: at file "/home/sirapol/.espressif/tools/openocd-esp32/v0.12.0-esp32-20230419/openocd-esp32/share/openocd/scripts/target/esp_common.cfg", line 4 Debug: 119 6 riscv.c:490 riscv_deinit_target(): riscv_deinit_target() Debug: 120 6 target.c:2223 target_free_all_working_areas_restore(): freeing all working areas

[OpenOCD] [Stopped] : OpenOCD Server [Flash] Can't perform JTag flash, because OpenOCD server is not running!`

erhankur commented 1 year ago

@sirapol Did you follow the instructions outlined here

Have you ensured that USB_SERIAL_JTAG is not disabled in the EFUSE?

Panometric commented 1 year ago

@sirapol > LIBUSB_ERROR_ACCESS is not the same error at all . Please delete to prevent complicating the issue.

sirapol commented 1 year ago

Thank you everyone

espressif / openocd-esp32

ESP32-S3 erroneous "Error: 330 126 libusb_helper.c:190 jtag_libusb_open(): libusb_open() failed with LIBUSB_ERROR_NOT_SUPPORTED" (OCD-649) #255

Development Kit

Module or chip used

Debug Adapter

OpenOCD version

Operating System

Using an IDE ?

OpenOCD command line

JTAG Clock Speed

ESP-IDF version

Problem Description

Debug Logs

Expected behavior

Screenshots

Need this to handle 'apptrace init' syscall correctly because semihosting is not enabled by default

'halt' is necessary to auto-probe flash bank when GDB is connected and generate proper memory map