espressif / esp-at

AT application for ESP32/ESP32-C2/ESP32-C3/ESP32-C6/ESP8266
Apache License 2.0
890 stars 802 forks source link

ESP32C3 USB-JTAG #615

Closed GiulioDallaVecchia closed 2 years ago

GiulioDallaVecchia commented 2 years ago

Hi team,

I flashed official AT firmware to esp32-C3-mini1 module through USB-JTAG build-in interface. After that I'm not able to connect to the module anymore. Does AT firmware configure or use PINs 18-19?

Thanks a lot!

ustccw commented 2 years ago

Actually not. The default uart pins esp-at used defined here: https://docs.espressif.com/projects/esp-at/en/latest/esp32c3/Get_Started/Hardware_connection.html#id3 i am not sure what is your real jtag pins, i found:

the first one used the same pins as esp-at uart1, i doubt possible pins conflict, please double check.

GiulioDallaVecchia commented 2 years ago

Hi @ustccw,

I'm using build-in JTAG-USB interface that is on pin IO18/IO19:

After flashing the official AT command firmware to the module I can't re-flash any other firmware using USB-JTAG build-in. When I try to connect with openocd I always receive an error.

I've already tried to do that with the "hello world" project and I don't get any error when I try to connect the board with openocd after flashing the code. It seems that the AT command firmware reconfigure the GPIO that are used for USB-JTAG connection. Is it possibile?

Thanks a lot in andvance.

ustccw commented 2 years ago

@GiulioDallaVecchia i dont think AT command firmware reconfigures the GPIO that are used for USB-JTAG connection. Would you mind drawing a sketch of your hardware connection, and the steps you did, and all logs. I'd be happy to ask my folks to help this issue.

xcguang commented 2 years ago

it may also be confirmed by enabling driver log

GiulioDallaVecchia commented 2 years ago

Hi @ustccw,

Below you can see the connections. I'm using USB cable connected to D+/D-. Below you can also see the log as I try to reconnect to the module to flash a new image after flashing the AT command firmware using the same cable and connection.

C:\Users\gdvecchia\Desktop\esp-idf>openocd -d3 -f board/esp32c3-builtin.cfg -c "init; halt; program_esp AT_Command.bin 0x00000 verify exit" Open On-Chip Debugger v0.10.0-esp32-20211111 (2021-11-10-21:40) Licensed under GNU GPL v2 For bug reports, read http://openocd.org/doc/doxygen/bugs.html User : 13 0 options.c:57 configuration_output_handler(): debug_level: 3 User : 14 0 options.c:57 configuration_output_handler(): Debug: 15 10 options.c:181 add_default_dirs(): bindir=/builds/idf/openocd-esp32/_build/../openocd-esp32/bin Debug: 16 10 options.c:182 add_default_dirs(): pkgdatadir=/builds/idf/openocd-esp32/_build/../openocd-esp32/share/openocd Debug: 17 20 options.c:183 add_default_dirs(): exepath=C:/Users/gdvecchia/.espressif/tools/openocd-esp32/v0.10.0-esp32-20211111/openocd-esp32/bin Debug: 18 20 options.c:184 add_default_dirs(): bin2data=../share/openocd Debug: 19 30 configuration.c:42 add_script_search_dir(): adding C:\Users\gdvecchia.espressif\tools\openocd-esp32\v0.10.0-esp32-20211111\openocd-esp32\share\openocd\scripts Debug: 20 30 configuration.c:42 add_script_search_dir(): adding C:\Users\gdvecchia\AppData\Roaming/OpenOCD Debug: 21 40 configuration.c:42 add_script_search_dir(): adding C:/Users/gdvecchia/.espressif/tools/openocd-esp32/v0.10.0-esp32-20211111/openocd-esp32/bin/../share/openocd/site Debug: 22 40 configuration.c:42 add_script_search_dir(): adding C:/Users/gdvecchia/.espressif/tools/openocd-esp32/v0.10.0-esp32-20211111/openocd-esp32/bin/../share/openocd/scripts Debug: 23 60 configuration.c:97 find_file(): found C:\Users\gdvecchia.espressif\tools\openocd-esp32\v0.10.0-esp32-20211111\openocd-esp32\share\openocd\scripts/board/esp32c3-builtin.cfg Debug: 24 70 configuration.c:97 find_file(): found C:\Users\gdvecchia.espressif\tools\openocd-esp32\v0.10.0-esp32-20211111\openocd-esp32\share\openocd\scripts/interface/esp_usb_jtag.cfg Debug: 25 80 command.c:143 script_debug(): command - interface interface esp_usb_jtag Debug: 27 80 command.c:355 register_command_handler(): registering 'espusbjtag'... Debug: 28 80 command.c:355 register_command_handler(): registering 'espusbjtag'... Debug: 29 90 command.c:355 register_command_handler(): registering 'espusbjtag'... Debug: 30 90 command.c:355 register_command_handler(): registering 'espusbjtag'... Info : 31 90 transport.c:117 allow_transports(): only one transport option; autoselect 'jtag' Debug: 32 100 command.c:355 register_command_handler(): registering 'jtag_flush_queue_sleep'... Debug: 33 100 command.c:355 register_command_handler(): registering 'jtag_rclk'... Debug: 34 110 command.c:355 register_command_handler(): registering 'jtag_ntrst_delay'... Debug: 35 110 command.c:355 register_command_handler(): registering 'jtag_ntrst_assert_width'... Debug: 36 110 command.c:355 register_command_handler(): registering 'scan_chain'... Debug: 37 120 command.c:355 register_command_handler(): registering 'jtag_reset'... Debug: 38 120 command.c:355 register_command_handler(): registering 'runtest'... Debug: 39 120 command.c:355 register_command_handler(): registering 'irscan'... Debug: 40 130 command.c:355 register_command_handler(): registering 'verify_ircapture'... Debug: 41 130 command.c:355 register_command_handler(): registering 'verify_jtag'... Debug: 42 130 command.c:355 register_command_handler(): registering 'tms_sequence'... Debug: 43 140 command.c:355 register_command_handler(): registering 'wait_srst_deassert'... Debug: 44 140 command.c:355 register_command_handler(): registering 'jtag'... Debug: 45 140 command.c:355 register_command_handler(): registering 'jtag'... Debug: 46 150 command.c:355 register_command_handler(): registering 'jtag'... Debug: 47 150 command.c:355 register_command_handler(): registering 'jtag'... Debug: 48 150 command.c:355 register_command_handler(): registering 'jtag'... Debug: 49 160 command.c:355 register_command_handler(): registering 'jtag'... Debug: 50 160 command.c:355 register_command_handler(): registering 'jtag'... Debug: 51 160 command.c:355 register_command_handler(): registering 'jtag'... Debug: 52 170 command.c:355 register_command_handler(): registering 'jtag'... Debug: 53 170 command.c:355 register_command_handler(): registering 'jtag'... Debug: 54 170 command.c:355 register_command_handler(): registering 'jtag'... Debug: 55 180 command.c:355 register_command_handler(): registering 'jtag'... Debug: 56 180 command.c:355 register_command_handler(): registering 'jtag'... Debug: 57 180 command.c:355 register_command_handler(): registering 'svf'... Debug: 58 190 command.c:355 register_command_handler(): registering 'xsvf'... Debug: 59 190 command.c:143 script_debug(): command - adapter_khz adapter_khz 40000 Debug: 61 190 core.c:1704 jtag_config_khz(): handle jtag khz Debug: 62 200 core.c:1667 adapter_khz_to_speed(): convert khz to interface specific speed value Debug: 63 200 core.c:1667 adapter_khz_to_speed(): convert khz to interface specific speed value Debug: 64 210 configuration.c:97 find_file(): found C:\Users\gdvecchia.espressif\tools\openocd-esp32\v0.10.0-esp32-20211111\openocd-esp32\share\openocd\scripts/target/esp32c3.cfg Debug: 65 210 command.c:143 script_debug(): command - transport transport select jtag Warn : 66 220 transport.c:297 jim_transport_select(): Transport "jtag" was already selected Debug: 67 220 configuration.c:97 find_file(): found C:\Users\gdvecchia.espressif\tools\openocd-esp32\v0.10.0-esp32-20211111\openocd-esp32\share\openocd\scripts/bitsbytes.tcl Debug: 68 230 configuration.c:97 find_file(): found C:\Users\gdvecchia.espressif\tools\openocd-esp32\v0.10.0-esp32-20211111\openocd-esp32\share\openocd\scripts/memory.tcl Debug: 69 240 configuration.c:97 find_file(): found C:\Users\gdvecchia.espressif\tools\openocd-esp32\v0.10.0-esp32-20211111\openocd-esp32\share\openocd\scripts/mmr_helpers.tcl Debug: 70 250 configuration.c:97 find_file(): found C:\Users\gdvecchia.espressif\tools\openocd-esp32\v0.10.0-esp32-20211111\openocd-esp32\share\openocd\scripts/target/esp_common.cfg Debug: 71 250 command.c:143 script_debug(): command - add_help_text 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: 73 260 command.c:1127 help_add_command(): added 'program_esp' help text Debug: 74 270 command.c:143 script_debug(): command - add_usage_text add_usage_text program_esp [address] [verify] [reset] [exit] [compress] [restore_clock] Debug: 76 270 command.c:1153 help_add_command(): added 'program_esp' usage text Debug: 77 280 command.c:143 script_debug(): command - add_help_text add_help_text program_esp_bins write all the images at address specified in flasher_args.json generated while building idf project Debug: 79 280 command.c:1127 help_add_command(): added 'program_esp_bins' help text Debug: 80 290 command.c:143 script_debug(): command - add_usage_text add_usage_text program_esp_bins flasher_args.json [verify] [reset] [exit] [compress] [restore_clock] Debug: 82 300 command.c:1153 help_add_command(): added 'program_esp_bins' usage text Debug: 83 300 command.c:143 script_debug(): command - add_help_text add_help_text esp_get_mac Print MAC address of the chip. Use a format argument to return formatted MAC value Debug: 85 310 command.c:1127 help_add_command(): added 'esp_get_mac' help text Debug: 86 310 command.c:143 script_debug(): command - add_usage_text add_usage_text esp_get_mac [format] Debug: 88 310 command.c:1153 help_add_command(): added 'esp_get_mac' usage text Debug: 89 320 command.c:143 script_debug(): command - jtag jtag newtap esp32c3 cpu -irlen 5 -expected-id 0x00005c25 Debug: 90 320 tcl.c:567 jim_newtap_cmd(): Creating New Tap, Chip: esp32c3, Tap: cpu, Dotted: esp32c3.cpu, 4 params Debug: 91 330 tcl.c:591 jim_newtap_cmd(): Processing option: -irlen Debug: 92 330 tcl.c:591 jim_newtap_cmd(): Processing option: -expected-id Debug: 93 330 core.c:1372 jtag_tap_init(): Created Tap: esp32c3.cpu @ abs position 0, irlen 5, capture: 0x1 mask: 0x3 Debug: 94 340 command.c:143 script_debug(): command - target target create esp32c3 esp32c3 -chain-position esp32c3.cpu -rtos FreeRTOS Debug: 95 340 target.c:2012 target_free_all_working_areas_restore(): freeing all working areas Debug: 96 350 target.c:2012 target_free_all_working_areas_restore(): freeing all working areas Debug: 97 350 FreeRTOS.c:1225 FreeRTOS_create(): FreeRTOS_create Debug: 98 350 command.c:355 register_command_handler(): registering 'riscv'... Debug: 99 360 command.c:355 register_command_handler(): registering 'riscv'... Debug: 100 360 command.c:355 register_command_handler(): registering 'riscv'... Debug: 101 360 command.c:355 register_command_handler(): registering 'riscv'... Debug: 102 370 command.c:355 register_command_handler(): registering 'riscv'... Debug: 103 370 command.c:355 register_command_handler(): registering 'riscv'... Debug: 104 370 command.c:355 register_command_handler(): registering 'riscv'... Debug: 105 380 command.c:355 register_command_handler(): registering 'riscv'... Debug: 106 380 command.c:355 register_command_handler(): registering 'riscv'... Debug: 107 380 command.c:355 register_command_handler(): registering 'riscv'... Debug: 108 390 command.c:355 register_command_handler(): registering 'riscv'... Debug: 109 390 command.c:355 register_command_handler(): registering 'riscv'... Debug: 110 390 command.c:355 register_command_handler(): registering 'riscv'... Debug: 111 400 command.c:355 register_command_handler(): registering 'riscv'... Debug: 112 400 command.c:355 register_command_handler(): registering 'riscv'... Debug: 113 400 command.c:355 register_command_handler(): registering 'riscv'... Debug: 114 410 command.c:355 register_command_handler(): registering 'riscv'... Debug: 115 410 command.c:355 register_command_handler(): registering 'riscv'... Debug: 116 410 command.c:355 register_command_handler(): registering 'arm'... Debug: 117 420 command.c:355 register_command_handler(): registering 'arm'... Debug: 118 420 command.c:355 register_command_handler(): registering 'arm'... Debug: 119 420 command.c:355 register_command_handler(): registering 'arm'... Debug: 120 430 command.c:355 register_command_handler(): registering 'esp'... Debug: 121 430 command.c:355 register_command_handler(): registering 'esp'... Debug: 122 430 command.c:355 register_command_handler(): registering 'esp'... Debug: 123 440 command.c:355 register_command_handler(): registering 'esp'... Debug: 124 440 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 125 440 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 126 450 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 127 450 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 128 450 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 129 460 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 130 460 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 131 460 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 132 470 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 133 470 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 134 470 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 135 480 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 136 480 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 137 480 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 138 490 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 139 490 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 140 490 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 141 500 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 142 500 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 143 500 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 144 510 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 145 510 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 146 520 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 147 520 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 148 520 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 149 530 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 150 530 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 151 530 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 152 540 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 153 540 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 154 540 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 155 550 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 156 550 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 157 550 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 158 560 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 159 560 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 160 560 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 161 570 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 162 570 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 163 570 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 164 580 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 165 580 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 166 580 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 167 590 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 168 590 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 169 590 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 170 600 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 171 600 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 172 600 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 173 610 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 174 610 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 175 610 command.c:355 register_command_handler(): registering 'esp32c3'... Debug: 176 620 command.c:143 script_debug(): command - esp32c3 esp32c3 configure -event reset-assert-post esp32c3_soc_reset Debug: 177 620 command.c:143 script_debug(): command - esp32c3 esp32c3 configure -event halted esp32c3_wdt_disable

Debug: 178 630 command.c:143 script_debug(): command - esp32c3 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

Debug: 179 640 command.c:143 script_debug(): command - esp32c3 esp32c3 configure -event gdb-attach

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

halt
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 maskisr steponly

Debug: 180 660 command.c:143 script_debug(): command - esp32c3 esp32c3 configure -work-area-phys 0x40380000 -work-area-virt 0x40380000 -work-area-size 0x4000 -work-area-backup 1 Debug: 181 670 target.c:2012 target_free_all_working_areas_restore(): freeing all working areas Debug: 182 680 target.c:2012 target_free_all_working_areas_restore(): freeing all working areas Debug: 183 680 target.c:2012 target_free_all_working_areas_restore(): freeing all working areas Debug: 184 680 target.c:2012 target_free_all_working_areas_restore(): freeing all working areas Debug: 185 690 command.c:143 script_debug(): command - esp32c3 esp32c3 configure -alt-work-area-phys 0x3FC84000 -alt-work-area-virt 0x3FC84000 -alt-work-area-size 0x20000 -alt-work-area-backup 1 Debug: 186 700 target.c:2012 target_free_all_working_areas_restore(): freeing all working areas Debug: 187 700 target.c:2012 target_free_all_working_areas_restore(): freeing all working areas Debug: 188 700 target.c:2012 target_free_all_working_areas_restore(): freeing all working areas Debug: 189 710 target.c:2012 target_free_all_working_areas_restore(): freeing all working areas Debug: 190 710 command.c:143 script_debug(): command - flash flash bank esp32c3.flash esp32c3 0x0 0 0 0 esp32c3 Debug: 193 720 command.c:377 register_command(): command 'esp' is already registered in '' context Debug: 194 720 command.c:355 register_command_handler(): registering 'esp'... Debug: 195 720 command.c:355 register_command_handler(): registering 'esp'... Debug: 196 730 command.c:355 register_command_handler(): registering 'esp'... Debug: 197 730 command.c:355 register_command_handler(): registering 'esp'... Debug: 198 730 tcl.c:1156 handle_flash_bank_command(): 'esp32c3' driver usage field missing Debug: 199 740 command.c:143 script_debug(): command - flash flash bank esp32c3.irom esp32c3 0x0 0 0 0 esp32c3 Debug: 201 740 command.c:377 register_command(): command 'esp' is already registered in '' context Debug: 202 750 command.c:377 register_command(): command 'appimage_offset' is already registered in 'esp' context Debug: 203 750 command.c:377 register_command(): command 'compression' is already registered in 'esp' context Debug: 204 750 command.c:377 register_command(): command 'verify_bank_hash' is already registered in 'esp' context Debug: 205 760 command.c:377 register_command(): command 'flash_stub_clock_boost' is already registered in 'esp' context Debug: 206 760 tcl.c:1156 handle_flash_bank_command(): 'esp32c3' driver usage field missing Debug: 207 770 command.c:143 script_debug(): command - flash flash bank esp32c3.drom esp32c3 0x0 0 0 0 esp32c3 Debug: 209 770 command.c:377 register_command(): command 'esp' is already registered in '' context Debug: 210 780 command.c:377 register_command(): command 'appimage_offset' is already registered in 'esp' context Debug: 211 780 command.c:377 register_command(): command 'compression' is already registered in 'esp' context Debug: 212 790 command.c:377 register_command(): command 'verify_bank_hash' is already registered in 'esp' context Debug: 213 790 command.c:377 register_command(): command 'flash_stub_clock_boost' is already registered in 'esp' context Debug: 214 790 tcl.c:1156 handle_flash_bank_command(): 'esp32c3' driver usage field missing Debug: 215 800 command.c:143 script_debug(): command - riscv riscv set_reset_timeout_sec 2 Debug: 217 800 command.c:143 script_debug(): command - riscv riscv set_command_timeout_sec 5 Debug: 219 810 command.c:143 script_debug(): command - riscv riscv set_prefer_sba on Debug: 221 810 command.c:143 script_debug(): command - init init Debug: 223 810 command.c:143 script_debug(): command - target target init Debug: 225 820 command.c:143 script_debug(): command - target target names Debug: 226 820 command.c:143 script_debug(): command - esp32c3 esp32c3 cget -event gdb-flash-erase-start Debug: 227 820 command.c:143 script_debug(): command - esp32c3 esp32c3 configure -event gdb-flash-erase-start reset init Debug: 228 830 command.c:143 script_debug(): command - esp32c3 esp32c3 cget -event gdb-flash-write-end Debug: 229 830 command.c:143 script_debug(): command - esp32c3 esp32c3 configure -event gdb-flash-write-end reset halt Debug: 230 840 command.c:143 script_debug(): command - esp32c3 esp32c3 cget -event gdb-attach Debug: 231 840 target.c:1450 handle_target_init_command(): Initializing targets... Debug: 232 840 esp32c3.c:106 esp32c3_init_target(): enter Debug: 233 850 semihosting_common.c:98 semihosting_common_init(): Debug: 234 850 command.c:355 register_command_handler(): registering 'target_request'... Debug: 235 850 command.c:355 register_command_handler(): registering 'trace'... Debug: 236 860 command.c:355 register_command_handler(): registering 'trace'... Debug: 237 860 command.c:355 register_command_handler(): registering 'fast_load_image'... Debug: 238 860 command.c:355 register_command_handler(): registering 'fast_load'... Debug: 239 870 command.c:355 register_command_handler(): registering 'profile'... Debug: 240 870 command.c:355 register_command_handler(): registering 'virt2phys'... Debug: 241 870 command.c:355 register_command_handler(): registering 'reg'... Debug: 242 880 command.c:355 register_command_handler(): registering 'poll'... Debug: 243 880 command.c:355 register_command_handler(): registering 'wait_halt'... Debug: 244 880 command.c:355 register_command_handler(): registering 'halt'... Debug: 245 890 command.c:355 register_command_handler(): registering 'resume'... Debug: 246 890 command.c:355 register_command_handler(): registering 'reset'... Debug: 247 890 command.c:355 register_command_handler(): registering 'soft_reset_halt'... Debug: 248 900 command.c:355 register_command_handler(): registering 'step'... Debug: 249 900 command.c:355 register_command_handler(): registering 'mdd'... Debug: 250 900 command.c:355 register_command_handler(): registering 'mdw'... Debug: 251 910 command.c:355 register_command_handler(): registering 'mdh'... Debug: 252 910 command.c:355 register_command_handler(): registering 'mdb'... Debug: 253 910 command.c:355 register_command_handler(): registering 'mwd'... Debug: 254 920 command.c:355 register_command_handler(): registering 'mww'... Debug: 255 920 command.c:355 register_command_handler(): registering 'mwh'... Debug: 256 920 command.c:355 register_command_handler(): registering 'mwb'... Debug: 257 930 command.c:355 register_command_handler(): registering 'bp'... Debug: 258 930 command.c:355 register_command_handler(): registering 'rbp'... Debug: 259 930 command.c:355 register_command_handler(): registering 'wp'... Debug: 260 940 command.c:355 register_command_handler(): registering 'rwp'... Debug: 261 940 command.c:355 register_command_handler(): registering 'load_image'... Debug: 262 940 command.c:355 register_command_handler(): registering 'dump_image'... Debug: 263 950 command.c:355 register_command_handler(): registering 'verify_image_checksum'... Debug: 264 950 command.c:355 register_command_handler(): registering 'verify_image'... Debug: 265 960 command.c:355 register_command_handler(): registering 'test_image'... Debug: 266 960 command.c:355 register_command_handler(): registering 'reset_nag'... Debug: 267 960 command.c:355 register_command_handler(): registering 'ps'... Debug: 268 970 command.c:355 register_command_handler(): registering 'test_mem_access'... Error: 269 990 libusb1_common.c:351 jtag_libusb_get_serial(): libusb_get_string_descriptor_ascii() failed with -9 Debug: 270 1005 command.c:630 run_command(): Command 'init' failed with error code -4 User : 271 1005 command.c:695 command_run_line(): Debug: 272 1005 riscv.c:487 riscv_deinit_target(): riscv_deinit_target() Debug: 273 1005 riscv-013.c:1460 deinit_target(): riscv_deinit_target() Debug: 274 1015 target.c:2012 target_free_all_working_areas_restore(): freeing all working areas

Immagine

ustccw commented 2 years ago

got it, will update issue if any progress.

igrr commented 2 years ago

@GiulioDallaVecchia as a debugging step, could you try the following?

  1. Put ESP32-C3 into download mode by bringing IO9 (boot) pin low, then toggling the EN pin.
  2. Verify that you see "USB JTAG/serial debug unit" in Device Manager.
  3. Run OpenOCD again

If OpenOCD connects successfully, then we will be sure that the issue is related to the application (in this case ESP-AT) loaded into the module. If it still fails to connect, it might be some hardware issue.

GiulioDallaVecchia commented 2 years ago

Hi @igrr,

I've already tried that. When I put the module into download mode OpenOCD connects successfully.

igrr commented 2 years ago

Thanks for checking this! I think the issue might be caused by the following.

USB and Wi-Fi peripherals in ESP32-C3 share some common hardware (PLL), and in the older versions of ESP-IDF there was a bug that enabling Wi-Fi disabled USB interface. Seems that AT firmware enables Wi-Fi by default. This issue was fixed in more recent release/v4.3 branch versions than the one the AT firmware is now using.

You can try to make a simple change in ESP-IDF code to check if that's indeed the issue.

  1. Find this file: https://github.com/espressif/esp-idf/blob/87f8a0d5f11fea174f8a77bf230bb9caf6caf38e/components/esp_wifi/src/phy_init.c#L615-L617
  2. Remove the ifdef around phy_bbpll_en_usb(true);, making sure that this function is called.
  3. Build the application and flash it to the board.
  4. Restart the board and check if the USB device is listed in the Device Manager
  5. Try running OpenOCD again
GiulioDallaVecchia commented 2 years ago

Hi @igrr,

There is a missing header file. When I try to compile after modified the file I get the error below.

i.dir/src/phy_init.c.obj -c ../esp-idf/components/esp_wifi/src/phy_init.c ../esp-idf/components/esp_wifi/src/phy_init.c: In function 'esp_phy_load_cal_and_init': ../esp-idf/components/esp_wifi/src/phy_init.c:616:5: error: implicit declaration of function 'phy_bbpll_en_usb' [-Werror=implicit-function-declaration] phy_bbpll_en_usb(true); ^~~~ cc1.exe: some warnings being treated as errors [166/1230] Building C object esp-idf/lwip/CMakeFiles/__idf_lwip.dir/lwip/src/api/if_api.c.obj ninja: build stopped: subcommand failed. ninja failed with exit code 1 idf.py build ret: 2 idf.py build failed

igrr commented 2 years ago

My bad, I didn't notice the declaration is also wrapped with an ifdef. Please remove the ifdef here and try again: https://github.com/espressif/esp-idf/blob/87f8a0d5f11fea174f8a77bf230bb9caf6caf38e/components/esp_wifi/include/phy.h#L97-L102 (this file is already included in phy_init.c)

GiulioDallaVecchia commented 2 years ago

Yes, now it's working properly!

Do you think it will be solved in the next AT command release?

Thanks a lot!

igrr commented 2 years ago

Thanks, that's good to know! The fix is already merged into release/v4.3 branch of ESP-IDF and will be part of the next 4.3.3 bugfix release. I'm not sure when the fix will be picked up by esp-at project, though. Regarding esp-at release plan, I'll leave it for @ustccw to confirm.

It might also be possible to make this work with the current commit of IDF which esp-at is using, without making the changes I have suggested above. To do this, enable CONFIG_ESP_CONSOLE_USB_SERIAL_JTAG in menuconfig. This has the effect of enabling CONFIG_ESP_PHY_ENABLE_USB option. That said, I am not sure if enabling CONFIG_ESP_CONSOLE_USB_SERIAL_JTAG will have any side effect in esp-at, so can't guarantee this option works.

ustccw commented 2 years ago

@GiulioDallaVecchia @igrr thanks for your information and for being so quick! esp-at will update esp-idf version to release/v4.3 latest in next week, and the next ESP32-C3 AT version (v2.4.0.0) is scheduled to be released in early April.

About CONFIG_ESP_CONSOLE_USB_SERIAL_JTAG and CONFIG_ESP_PHY_ENABLE_USB, i'm afraid esp-at will not configure it by default. Because working with USB, the RF performance may be affected. If users wanna debug by JTAG, please enable them in menuconfig.

QGB commented 2 years ago
C:\Espressif\tools\openocd-esp32\v0.11.0-esp32-20211220\openocd-esp32\share\openocd\scripts>openocd -f board/esp32c3-builtin.cfg
Open On-Chip Debugger  v0.11.0-esp32-20211220 (2021-12-20-15:43)
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: Device found. Base speed 40000KHz, div range 1 to 255
Info : clock speed 40000 kHz
Info : JTAG tap: esp32c3.cpu tap/device found: 0x00005c25 (mfg: 0x612 (Espressif Systems), part: 0x0005, ver: 0x0)
Info : Examined RISC-V core; found 1 harts
Info :  hart 0: XLEN=32, misa=0x40101104
Info : starting gdb server for esp32c3 on 3333
Info : Listening on port 3333 for gdb connections
Info : Hart 0 unexpectedly reset
Info : Hart 0 unexpectedly reset
Info : Hart 0 unexpectedly reset
Info : Hart 0 unexpectedly reset
Info : Hart 0 unexpectedly reset
Info : Hart 0 unexpectedly reset
Info : Hart 0 unexpectedly reset
Info : Hart 0 unexpectedly reset
Info : Hart 0 unexpectedly reset
Info : Hart 0 unexpectedly reset
Info : Hart 0 unexpectedly reset
Info : Hart 0 unexpectedly reset
Info : Hart 0 unexpectedly reset
Info : Hart 0 unexpectedly reset
Info : Hart 0 unexpectedly reset
Info : Hart 0 unexpectedly reset
Info : Hart 0 unexpectedly reset
Info : Hart 0 unexpectedly reset
Info : Hart 0 unexpectedly reset
Info : Hart 0 unexpectedly reset
Info : Hart 0 unexpectedly reset
Info : Hart 0 unexpectedly reset
Error: libusb_bulk_write error: LIBUSB_ERROR_IO
Error: missing data from bitq interface
Error: Unable to execute JTAG queue
Error: Failed to write ESP32C3_TIMG1WDT_PROTECT (-4)!
Error: Failed to disable WDTs (-4)!
Error: libusb_bulk_write error: LIBUSB_ERROR_IO
Error: missing data from bitq interface
Error: dmi_scan failed jtag scan
Error: failed write at 0x17, status=2
Error: libusb_bulk_write error: LIBUSB_ERROR_IO
Error: missing data from bitq interface
Error: dmi_scan failed jtag scan
Error: failed write at 0x17, status=2
Error: Failed to enable EBREAKS handling (-4)!
Error: libusb_bulk_write error: LIBUSB_ERROR_IO
Error: missing data from bitq interface
Error: dmi_scan failed jtag scan
Error: failed write at 0x10, status=2
Error: libusb_bulk_write error: LIBUSB_ERROR_IO
Error: missing data from bitq interface
Error: dmi_scan failed jtag scan
Error: failed read at 0x11, status=2
Error: Failed to read dmstatus!
Error: Failed to resume core (-4)!
Error: libusb_bulk_write error: LIBUSB_ERROR_IO
Error: missing data from bitq interface
Error: dmi_scan failed jtag scan
Error: failed read at 0x11, status=2
Error: libusb_bulk_write error: LIBUSB_ERROR_IO
Error: missing data from bitq interface
Error: dmi_scan failed jtag scan
Error: failed read at 0x11, status=2
Error: libusb_bulk_write error: LIBUSB_ERROR_IO
Error: missing data from bitq interface
Error: dmi_scan failed jtag scan
Error: failed read at 0x11, status=2
Error: libusb_bulk_write error: LIBUSB_ERROR_IO
Error: missing data from bitq interface
Error: dmi_scan failed jtag scan
Error: failed read at 0x11, status=2
QGB commented 2 years ago

jtag write_flash success !

C:\>cd C:\Espressif\frameworks\esp-idf-v4.4\examples\get-started\blink

C:\Espressif\frameworks\esp-idf-v4.4\examples\get-started\blink>openocd -f board/esp32c3-builtin.cfg -c "program_esp build/bootloader/bootloader.bin 0x0 verify exit"
Open On-Chip Debugger  v0.11.0-esp32-20211220 (2021-12-20-15:43)
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 : esp_usb_jtag: Device found. Base speed 40000KHz, div range 1 to 255
Info : clock speed 40000 kHz
Info : JTAG tap: esp32c3.cpu tap/device found: 0x00005c25 (mfg: 0x612 (Espressif Systems), part: 0x0005, ver: 0x0)
Info : Examined RISC-V core; found 1 harts
Info :  hart 0: XLEN=32, misa=0x40101104
Info : starting gdb server for esp32c3 on 3333
Info : Listening on port 3333 for gdb connections
Info : JTAG tap: esp32c3.cpu tap/device found: 0x00005c25 (mfg: 0x612 (Espressif Systems), part: 0x0005, ver: 0x0)
Info : [0] Found 8 triggers
Info : Flash mapping 0: 0x10020 -> 0x3c020020, 30 KB
Info : Flash mapping 1: 0x20020 -> 0x42000020, 73 KB
Info : Auto-detected flash bank 'esp32c3.flash' size 4096 KB
Info : Using flash bank 'esp32c3.flash' size 4096 KB
** Programming Started **
Info : PROF: Data transferred in 374.808 ms @ 53.3607 KB/s
** Programming Finished **
** Verify Started **
** Verified OK **
shutdown command invoked

C:\Espressif\frameworks\esp-idf-v4.4\examples\get-started\blink>
jeremyherbert commented 2 years ago

Hi @igrr @ustccw - I think this bug is still present somehow. I flashed the ESP32-C3-MINI-1 AT firmware version 2.4.0.0 via native USB on a blank WROOM module (using the binary with modified time: 20 May 2022, from the espressif website - I didn't build it myself).

Here is the command I used to flash the firmware originally via the USB interface:

esptool.py --chip esp32c3 write_flash --flash_mode dio --flash_freq 40m --flash_size 4MB 0x8000 partition_table/partition-table.bin 0xd000 ota_data_initial.bin 0xf000 phy_multiple_init_data.bin 0x0 bootloader/bootloader.bin 0x60000 esp-at.bin 0x1e000 at_customize.bin 0x25000 customized_partitions/server_cert.bin 0x3a000 customized_partitions/mqtt_key.bin 0x27000 customized_partitions/server_key.bin 0x29000 customized_partitions/server_ca.bin 0x2f000 customized_partitions/client_ca.bin 0x31000 customized_partitions/factory_param.bin 0x1F000 customized_partitions/ble_data.bin 0x3c000 customized_partitions/mqtt_ca.bin 0x38000 customized_partitions/mqtt_cert.bin 0x2b000 customized_partitions/client_cert.bin 0x2d000 customized_partitions/client_key.bin

After resetting/power cycling the ESP32-C3, when attempting to (for example) read the flash id over native USB, I get the following error:

$ esptool.py flash_id
esptool.py v4.1
Found 1 serial ports
Serial port /dev/ttyACM0
Connecting...
/dev/ttyACM0 failed to connect: [Errno 71] Protocol error

A fatal error occurred: Could not connect to an Espressif device on any of the 1 available serial ports.

Here is the lsusb output while the device is in the bad state (ie after flashing + reset):

$ lsusb -v -d 303a:1001
Bus 001 Device 008: ID 303a:1001 Espressif USB JTAG/serial debug unit
Device Descriptor:
  bLength                18
  bDescriptorType         1
  bcdUSB               2.00
  bDeviceClass          239 Miscellaneous Device
  bDeviceSubClass         2
  bDeviceProtocol         1 Interface Association
  bMaxPacketSize0        64
  idVendor           0x303a
  idProduct          0x1001
  bcdDevice            1.01
  iManufacturer           1 (error)
  iProduct                2 (error)
  iSerial                 3 (error)
  bNumConfigurations      1
  Configuration Descriptor:
    bLength                 9
    bDescriptorType         2
    wTotalLength       0x0062
    bNumInterfaces          3
    bConfigurationValue     1
    iConfiguration          0
    bmAttributes         0xc0
      Self Powered
    MaxPower              500mA
    Interface Association:
      bLength                 8
      bDescriptorType        11
      bFirstInterface         0
      bInterfaceCount         2
      bFunctionClass          2 Communications
      bFunctionSubClass       2 Abstract (modem)
      bFunctionProtocol       0
      iFunction               0
    Interface Descriptor:
      bLength                 9
      bDescriptorType         4
      bInterfaceNumber        0
      bAlternateSetting       0
      bNumEndpoints           1
      bInterfaceClass         2 Communications
      bInterfaceSubClass      2 Abstract (modem)
      bInterfaceProtocol      0
      iInterface              0
      CDC Header:
        bcdCDC               1.10
      CDC ACM:
        bmCapabilities       0x02
          line coding and serial state
      CDC Union:
        bMasterInterface        0
        bSlaveInterface         1
      CDC Call Management:
        bmCapabilities       0x03
          call management
          use DataInterface
        bDataInterface          1
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x82  EP 2 IN
        bmAttributes            3
          Transfer Type            Interrupt
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0040  1x 64 bytes
        bInterval               1
    Interface Descriptor:
      bLength                 9
      bDescriptorType         4
      bInterfaceNumber        1
      bAlternateSetting       0
      bNumEndpoints           2
      bInterfaceClass        10 CDC Data
      bInterfaceSubClass      2
      bInterfaceProtocol      0
      iInterface              0
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x01  EP 1 OUT
        bmAttributes            2
          Transfer Type            Bulk
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0040  1x 64 bytes
        bInterval               1
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x81  EP 1 IN
        bmAttributes            2
          Transfer Type            Bulk
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0040  1x 64 bytes
        bInterval               1
    Interface Descriptor:
      bLength                 9
      bDescriptorType         4
      bInterfaceNumber        2
      bAlternateSetting       0
      bNumEndpoints           2
      bInterfaceClass       255 Vendor Specific Class
      bInterfaceSubClass    255 Vendor Specific Subclass
      bInterfaceProtocol      1
      iInterface              0
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x02  EP 2 OUT
        bmAttributes            2
          Transfer Type            Bulk
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0040  1x 64 bytes
        bInterval               1
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x83  EP 3 IN
        bmAttributes            2
          Transfer Type            Bulk
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0040  1x 64 bytes
        bInterval               1
can't get device qualifier: Resource temporarily unavailable
can't get debug descriptor: Resource temporarily unavailable
cannot read device status, Resource temporarily unavailable (11)

No errors are present in dmesg when the device is in the bad state:

[2050125.932456] usb 1-1: new full-speed USB device number 8 using xhci_hcd
[2050126.081504] usb 1-1: New USB device found, idVendor=303a, idProduct=1001, bcdDevice= 1.01
[2050126.081507] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[2050126.081509] usb 1-1: Product: USB JTAG/serial debug unit
[2050126.081510] usb 1-1: Manufacturer: Espressif
[2050126.081512] usb 1-1: SerialNumber: 60:55:F9:83:EE:60
[2050126.083593] cdc_acm 1-1:1.0: ttyACM0: USB ACM device

I have a USB protocol analyser (Total Phase), and when I hook it up and run esptool.py I get the following trace (running esptool corresponds to packet index 189 in this trace):

esp32-c3-dump_-_Total_Phase_Data_Center_v6_73_007

(same screenshot but with expanded failed SETUP packets):

esp32-c3-dump_-_Total_Phase_Data_Center_v6_73_007

esp32-c3-dump.csv

I can provide the protocol dump in tdc format also if it would help. Also, my system details:

uname -a:

Linux goose 5.4.0-120-generic #136-Ubuntu SMP Fri Jun 10 13:40:48 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux

lsb_release -a:

Distributor ID: Ubuntu
Description:    Ubuntu 20.04.4 LTS
Release:    20.04
Codename:   focal
jeremyherbert commented 2 years ago

I can also replicate this problem on a brand new ESP32-C3-DevKitC-02 by doing the following:

  1. Flash AT firmware via CP2102 USB to serial converter
  2. Connect USB DP/DM (GPIO19/18) and GND to a different USB port
  3. Run esptool.py flash_id with the native USB CDC port => it fails
  4. Run esptool.py flash_id with the CP2102 serial port => it works
  5. Run esptool.py erase_flash with the CP2102 serial port
  6. Run esptool.py flash_id with the native USB CDC port => it works again
  7. Run esptool.py flash_id with the CP2102 serial port => it works

So the AT firmware is definitely breaking the USB interface.

Enumeration succeeds for the native USB port but esptool cannot communicate with it (nor can it force a reset). Any operation via the CP2102 works fine from my testing.

RamyaDidde commented 10 months ago

Uploading .pio\build\esp32-s3-devkitc-1\firmware.bin Open On-Chip Debugger v0.11.0-esp32-20220706 (2022-07-06-15:48) Licensed under GNU GPL v2 For bug reports, read http://openocd.org/doc/doxygen/bugs.html debug_level: 1

adapter speed: 40000 kHz

Warn : Transport "jtag" was already selected adapter speed: 5000 kHz

Error: libusb_get_string_descriptor_ascii() failed with -9 OpenOCD init failed shutdown command invoked

*** [upload] Error 1

Facing this issue can anyone help me with this please. I am Using ESP32 S3 devkit C1, i am trying to upload and debug the code using the USB port of the ESP32 S3 C1 devkit.