libusb_get_string_descriptor_ascii() failed with -9 error for JTAG Debugging ESP32S3 (OCD-731)

[miczag80]

Development Kit

ESP32-S3-DevKitC-1

Module or chip used

ESP32-S3-WROOM1

Debug Adapter

USB Serial/JTAG

OpenOCD version

v0.11.0-esp32-20221026

Operating System

Windows

Using an IDE ?

Visual Studios Code

OpenOCD command line

openocd -f board/esp32s3-builtin.cfg

JTAG Clock Speed

default

ESP-IDF version

5.0.1

Problem Description

1. I started by opening up visual studio code, and installing the Espressif IDF v1.6.0 extension, with my ESP32S3 Device plugged in to my machine

2. I opened windows PowerShell and pasted the following line to install required drivers (downloaded successfully):

Invoke-WebRequest 'https://dl.espressif.com/dl/idf-env/idf-env.exe' -OutFile .\idf-env.exe; .\idf-env.exe driver install --espressif

3. I opened the command palette (View > Command Palette) and typed in the command 'ESP-IDF: Show Examples Projects,' then selected the current framework, which opened the example projects

4. I clicked 'blink' under the get-started examples and then created a new project using example blink

5. From here, without editing any of the code, in the lower left of the screen in the bar along the bottom I select the correct COM port, the device, and the debug type, which for me in this case was COM9, esp32s3, and JTAG.

6. I built the code, and after a successful build, I clicked the 'ESP-IDF Flash Device' button.

7. A prompt that indicates OpenOCD is not running pops up, I click 'open'

8. In the output, I get the error show in the debug logs below.

Debug Logs

[OpenOCD]
Open On-Chip Debugger v0.11.0-esp32-20221026 (2022-10-26-14:48)
Licensed under GNU GPL v2
For bug reports, read
	http://openocd.org/doc/doxygen/bugs.html
[OpenOCD]
debug_level: 2

[OpenOCD]
Info : only one t[OpenOCD]
ransport option; autoselect 'jtag'
Info : esp_usb_jtag: VID set to 0x303a and PID to 0x1001
Info : esp_usb_jtag: capabilities descriptor set to 0x2000
[OpenOCD]
Warn : Transport "jtag" w[OpenOCD]
as already selected
[OpenOCD]
Info : Listening on port 6666 for tcl conne[OpenOCD]
ctions
Info : Listening on port 4444 for telnet connections
[OpenOCD]
❌ Error: libusb_get_string_de[OpenOCD]
scriptor_ascii() failed with -9

[OpenOCD]
[Stopped] : OpenOCD Server

Expected behavior

Successful Debugging

Screenshots

[erhankur]

@miczag80 Can you update your OpenOCD with the latest release? We have upgraded libusb version which might be helpful to fix that error.

[erhankur]

@miczag80 Did you fix the issue? Can we close this?

[rapeauxa]

Can we reopen this? I have a similar issue with the same error message when attempting to use OpenOCD through esp32s3 USB-JTAG interface. The interface registers correctly for Windows (correct pid-vid). I have updated OpenOCD manually using the latest version and this did not fix the issue.

[erhankur]

@rapeauxa Can you please share the OpenOCD logs with -d3 option. First of all I would like to be sure about version and the other settings. As an additional , which windows version do you have?

[rapeauxa]

Many thanks for the prompt answer. Using Windows 10 Pro. Will provide logs tomorrow, first thing (I don't have development system with me today, apologies). openOCD version: v0.12.0-esp32-20230419 (2023-04-18-22:02)

[rapeauxa]

openocd_log_esp32s3_usbjtag.txt
Here is the debug level 3 log for running openocd

[MrPec]

Same problem here.

Custom board, ESP32-C3-MINI-1
GPIO9 is high measured as high
Nothing else connected to GPIO18 / GPIO19.

Version info:
Open On-Chip Debugger v0.12.0-esp32-20230419 (2023-04-18-22:02)
Device appears as

1. "Serielles USB-Gerät (COM5)", 10.0.19041.2130
2. "USB JTAG/serial debug unit",libwdi, 6.1.7600.16386

Things worth to mention:

1. I can't open the serial port COM5 with Putty or Arduino IDE
2. I can read out board info in Arduino IDE (with Serial number etc - where does it come from?)
3. If I pull GPIO9 low on startup, it works. After flashing any firmware it also works without pulling GPIO9 low (?)

Full log with d3:

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 2 options.c:52 configuration_output_handler(): debug_level: 3User : 4 5 options.c:52 configuration_output_handler():
Debug: 5 7 options.c:233 add_default_dirs(): bindir=/builds/idf/openocd-esp32/_build/../openocd-esp32/bin
Debug: 6 10 options.c:234 add_default_dirs(): pkgdatadir=/builds/idf/openocd-esp32/_build/../openocd-esp32/share/openocd
Debug: 7 14 options.c:235 add_default_dirs(): exepath=C:/Users/unknown-user/.espressif/tools/openocd-esp32/v0.12.0-esp32-20230419/openocd-esp32/bin
Debug: 8 19 options.c:236 add_default_dirs(): bin2data=../share/openocd
Debug: 9 20 configuration.c:33 add_script_search_dir(): adding C:/Users/unknown-user/AppData/Roaming/OpenOCD
Debug: 10 24 configuration.c:33 add_script_search_dir(): adding C:/Users/unknown-user/.espressif/tools/openocd-esp32/v0.12.0-esp32-20230419/openocd-esp32/bin/../share/openocd/site
Debug: 11 31 configuration.c:33 add_script_search_dir(): adding C:/Users/unknown-user/.espressif/tools/openocd-esp32/v0.12.0-esp32-20230419/openocd-esp32/bin/../share/openocd/scripts
Debug: 12 36 command.c:152 script_debug(): command - ocd_find board/esp32c3-builtin.cfg
Debug: 13 38 configuration.c:88 find_file(): found C:/Users/unknown-user/.espressif/tools/openocd-esp32/v0.12.0-esp32-20230419/openocd-esp32/bin/../share/openocd/scripts/board/esp32c3-builtin.cfg
Debug: 14 47 command.c:152 script_debug(): command - ocd_find interface/esp_usb_jtag.cfg
Debug: 15 50 configuration.c:88 find_file(): found C:/Users/unknown-user/.espressif/tools/openocd-esp32/v0.12.0-esp32-20230419/openocd-esp32/bin/../share/openocd/scripts/interface/esp_usb_jtag.cfg
Debug: 16 57 command.c:152 script_debug(): command - adapter driver esp_usb_jtag
Info : 17 60 transport.c:107 allow_transports(): only one transport option; autoselecting 'jtag'
Debug: 18 63 command.c:152 script_debug(): command - espusbjtag vid_pid 0x303a 0x1001
Info : 19 66 esp_usb_jtag.c:894 esp_usb_jtag_vid_pid(): esp_usb_jtag: VID set to 0x303a and PID to 0x1001
Debug: 20 69 command.c:152 script_debug(): command - espusbjtag caps_descriptor 0x2000
Info : 21 72 esp_usb_jtag.c:905 esp_usb_jtag_caps_descriptor(): esp_usb_jtag: capabilities descriptor set to 0x2000
Debug: 22 76 command.c:152 script_debug(): command - adapter speed 40000
Debug: 23 78 adapter.c:253 adapter_config_khz(): handle adapter khz
Debug: 24 81 adapter.c:217 adapter_khz_to_speed(): convert khz to adapter specific speed value
Debug: 25 84 adapter.c:217 adapter_khz_to_speed(): convert khz to adapter specific speed value
Debug: 26 87 command.c:152 script_debug(): command - ocd_find target/esp32c3.cfg
Debug: 27 89 configuration.c:88 find_file(): found C:/Users/unknown-user/.espressif/tools/openocd-esp32/v0.12.0-esp32-20230419/openocd-esp32/bin/../share/openocd/scripts/target/esp32c3.cfg
Debug: 28 97 command.c:152 script_debug(): command - transport select jtag
Warn : 29 99 transport.c:280 handle_transport_select(): Transport "jtag" was already selected
Debug: 30 102 command.c:152 script_debug(): command - ocd_find bitsbytes.tcl
Debug: 31 104 configuration.c:88 find_file(): found C:/Users/unknown-user/.espressif/tools/openocd-esp32/v0.12.0-esp32-20230419/openocd-esp32/bin/../share/openocd/scripts/bitsbytes.tcl
Debug: 32 112 command.c:152 script_debug(): command - ocd_find memory.tcl
Debug: 33 115 configuration.c:88 find_file(): found C:/Users/unknown-user/.espressif/tools/openocd-esp32/v0.12.0-esp32-20230419/openocd-esp32/bin/../share/openocd/scripts/memory.tcl
Debug: 34 122 command.c:152 script_debug(): command - ocd_find mmr_helpers.tcl
Debug: 35 125 configuration.c:88 find_file(): found C:/Users/unknown-user/.espressif/tools/openocd-esp32/v0.12.0-esp32-20230419/openocd-esp32/bin/../share/openocd/scripts/mmr_helpers.tcl
Debug: 36 132 command.c:152 script_debug(): command - ocd_find target/esp_common.cfg
Debug: 37 136 configuration.c:88 find_file(): found C:/Users/unknown-user/.espressif/tools/openocd-esp32/v0.12.0-esp32-20230419/openocd-esp32/bin/../share/openocd/scripts/target/esp_common.cfg
Debug: 38 143 command.c:152 script_debug(): command - ocd_find target/esp_version.cfg
Debug: 39 146 configuration.c:88 find_file(): found C:/Users/unknown-user/.espressif/tools/openocd-esp32/v0.12.0-esp32-20230419/openocd-esp32/bin/../share/openocd/scripts/target/esp_version.cfg
Debug: 40 154 command.c:152 script_debug(): command - version
Debug: 41 156 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: 42 164 command.c:152 script_debug(): command - add_usage_text program_esp <filename> [address] [verify] [reset] [exit] [compress] [no_clock_boost] [restore_clock] [encrypt]
Debug: 43 172 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: 44 178 command.c:152 script_debug(): command - add_usage_text program_esp_bins <build_dir> flasher_args.json [verify] [reset] [exit] [compress] [no_clock_boost] [restore_clock]
Debug: 45 185 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: 46 192 command.c:152 script_debug(): command - add_usage_text esp_get_mac [format]
Debug: 47 196 command.c:152 script_debug(): command - jtag newtap esp32c3 cpu -irlen 5 -expected-id 0x00005c25
Debug: 48 200 tcl.c:562 jim_newtap_cmd(): Creating New Tap, Chip: esp32c3, Tap: cpu, Dotted: esp32c3.cpu, 4 params
Debug: 49 204 tcl.c:579 jim_newtap_cmd(): Processing option: -irlen
Debug: 50 207 tcl.c:579 jim_newtap_cmd(): Processing option: -expected-id
Debug: 51 209 core.c:1478 jtag_tap_init(): Created Tap: esp32c3.cpu @ abs position 0, irlen 5, capture: 0x1 mask: 0x3
Debug: 52 214 command.c:152 script_debug(): command - target create esp32c3 esp32c3 -chain-position esp32c3.cpu -rtos FreeRTOS
Debug: 53 219 target.c:2223 target_free_all_working_areas_restore(): freeing all working areas
Debug: 54 223 target.c:2223 target_free_all_working_areas_restore(): freeing all working areas
Debug: 55 226 FreeRTOS.c:1414 freertos_create(): freertos_create
Debug: 56 229 command.c:286 register_command(): command 'esp' is already registered
Debug: 57 233 command.c:286 register_command(): command 'esp32c3 esp' is already registered
Debug: 58 237 command.c:152 script_debug(): command - esp32c3 configure -event reset-assert-post  esp32c3_soc_reset
Debug: 59 242 command.c:152 script_debug(): command - esp32c3 configure -event halted
    esp32c3_wdt_disable
    esp halted_event_handler

Debug: 60 249 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: 61 266 command.c:152 script_debug(): command - esp32c3 configure -event gdb-detach
        $_TARGETNAME esp gdb_detach_handler

Debug: 62 271 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: 63 294 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: 64 300 target.c:2223 target_free_all_working_areas_restore(): freeing all working areas
Debug: 65 302 target.c:2223 target_free_all_working_areas_restore(): freeing all working areas
Debug: 66 305 target.c:2223 target_free_all_working_areas_restore(): freeing all working areas
Debug: 67 308 target.c:2223 target_free_all_working_areas_restore(): freeing all working areas
Debug: 68 313 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: 69 319 target.c:2223 target_free_all_working_areas_restore(): freeing all working areas
Debug: 70 321 target.c:2223 target_free_all_working_areas_restore(): freeing all working areas
Debug: 71 324 target.c:2223 target_free_all_working_areas_restore(): freeing all working areas
Debug: 72 328 target.c:2223 target_free_all_working_areas_restore(): freeing all working areas
Debug: 73 331 command.c:152 script_debug(): command - flash bank esp32c3.flash esp32c3 0x0 0 0 0 esp32c3
Debug: 74 335 command.c:286 register_command(): command 'esp' is already registered
Debug: 75 337 tcl.c:1305 handle_flash_bank_command(): 'esp32c3' driver usage field missing
Debug: 76 340 command.c:152 script_debug(): command - flash bank esp32c3.irom esp32c3 0x0 0 0 0 esp32c3
Debug: 77 345 command.c:286 register_command(): command 'esp' is already registered
Debug: 78 347 command.c:286 register_command(): command 'esp appimage_offset' is already registered
Debug: 79 351 command.c:286 register_command(): command 'esp compression' is already registered
Debug: 80 355 command.c:286 register_command(): command 'esp verify_bank_hash' is already registered
Debug: 81 360 command.c:286 register_command(): command 'esp flash_stub_clock_boost' is already registered
Debug: 82 364 command.c:286 register_command(): command 'esp encrypt_binary' is already registered
Debug: 83 368 command.c:286 register_command(): command 'esp stub_log' is already registered
Debug: 84 371 tcl.c:1305 handle_flash_bank_command(): 'esp32c3' driver usage field missing
Debug: 85 375 command.c:152 script_debug(): command - flash bank esp32c3.drom esp32c3 0x0 0 0 0 esp32c3
Debug: 86 379 command.c:286 register_command(): command 'esp' is already registered
Debug: 87 381 command.c:286 register_command(): command 'esp appimage_offset' is already registered
Debug: 88 384 command.c:286 register_command(): command 'esp compression' is already registered
Debug: 89 387 command.c:286 register_command(): command 'esp verify_bank_hash' is already registered
Debug: 90 391 command.c:286 register_command(): command 'esp flash_stub_clock_boost' is already registered
Debug: 91 395 command.c:286 register_command(): command 'esp encrypt_binary' is already registered
Debug: 92 398 command.c:286 register_command(): command 'esp stub_log' is already registered
Debug: 93 402 tcl.c:1305 handle_flash_bank_command(): 'esp32c3' driver usage field missing
Debug: 94 405 command.c:152 script_debug(): command - riscv set_reset_timeout_sec 2
Debug: 95 409 command.c:152 script_debug(): command - riscv set_command_timeout_sec 5
Debug: 96 412 command.c:152 script_debug(): command - riscv set_mem_access sysbus progbuf abstract
Debug: 97 417 command.c:152 script_debug(): command - riscv set_ebreakm on
Debug: 98 419 command.c:152 script_debug(): command - riscv set_ebreaks on
Debug: 99 421 command.c:152 script_debug(): command - riscv set_ebreaku on
Info : 100 426 server.c:298 add_service(): Listening on port 6666 for tcl connections
Info : 101 429 server.c:298 add_service(): Listening on port 4444 for telnet connections
Debug: 102 433 command.c:152 script_debug(): command - init
Debug: 103 435 command.c:152 script_debug(): command - target init
Debug: 104 439 command.c:152 script_debug(): command - target names
Debug: 105 442 command.c:152 script_debug(): command - esp32c3 cget -event gdb-flash-erase-start
Debug: 106 447 command.c:152 script_debug(): command - esp32c3 configure -event gdb-flash-erase-start reset init
Debug: 107 450 command.c:152 script_debug(): command - esp32c3 cget -event gdb-flash-write-end
Debug: 108 454 command.c:152 script_debug(): command - esp32c3 configure -event gdb-flash-write-end reset halt
Debug: 109 458 command.c:152 script_debug(): command - esp32c3 cget -event gdb-attach
Debug: 110 461 target.c:1657 handle_target_init_command(): Initializing targets...
Debug: 111 465 riscv.c:444 riscv_init_target(): riscv_init_target()
Debug: 112 467 semihosting_common.c:107 semihosting_common_init():
Error: 113 485 libusb_helper.c:373 jtag_libusb_get_serial(): libusb_get_string_descriptor_ascii() failed with -9