espressif / esp-idf

Espressif IoT Development Framework. Official development framework for Espressif SoCs.
Apache License 2.0
13.53k stars 7.26k forks source link

ESP32-C3 USB JTAG/Serial console corrupted during wifi connect (IDFGH-6387) #8046

Closed nedv-eu closed 2 years ago

nedv-eu commented 2 years ago

Environment

Problem Description

When initiating a wifi connection on ESP32-C3 the attached debug session over embedded USB JTAG gets corrupted. Also USB serial console stops responding. Trying to restart openOCD without restarting ESP32-C3 ends with error: libusb_get_string_descriptor_ascii() failed with -1. The ESP32-C3 program continues to run without any problem (based on log from external USART0 console). But I am no more able to debug it. If I add some waiting before the wifi connect attempt the debugger works until the start of wifi connection. Also other examples not involving wifi connection works without any issues. After ESP-C3 restart the USB embedded JTAG and console works again until another connection attempt. I added 100uF capacitors and monitored VDD during connection on osciloscope. There are not any voltage drops below 3.1V. esp_wifi_set_ps(WIFI_PS_NONE) and esp_wifi_set_max_tx_power(8)) had no effect on this issue

Expected Behavior

The embbeded JTAG works normally after wifi connection

Actual Behavior

The embbeded JTAG/serial console do not work

Steps to reproduce

  1. Run esp-idf/examples/wifi/getting_started/station example on ESP-C3-12F module.
  2. Wait until the ESP is connected to an AP
  3. Try to start OpenOCD over built-in jtag - you get an error

Code to reproduce this issue

esp-idf/examples/wifi/getting_started/station without any modification

Debug Logs

ESP-ROM:esp32c3-api1-20210207 Build:Feb 7 2021 rst:0x1 (POWERON),boot:0xc (SPI_FAST_FLASH_BOOT) SPIWP:0xee mode:DIO, clock div:1 load:0x3fcd6100,len:0x1740 load:0x403ce000,len:0x930 load:0x403d0000,len:0x2d4c entry 0x403ce000 I (30) boot: ESP-IDF v5.0-dev-621-g4143a3f572 2nd stage bootloader I (30) boot: compile time 13:44:40 I (30) boot: chip revision: 3 I (33) boot.esp32c3: SPI Speed : 80MHz I (38) boot.esp32c3: SPI Mode : DIO I (43) boot.esp32c3: SPI Flash Size : 2MB I (48) boot: Enabling RNG early entropy source... I (53) boot: Partition Table: I (57) boot: ## Label Usage Type ST Offset Length I (64) boot: 0 nvs WiFi data 01 02 00009000 00006000 I (71) boot: 1 phy_init RF data 01 01 0000f000 00001000 I (79) boot: 2 factory factory app 00 00 00010000 00100000 I (86) boot: End of partition table I (90) esp_image: segment 0: paddr=00010020 vaddr=3c080020 size=13570h ( 79216) map I (111) esp_image: segment 1: paddr=00023598 vaddr=3fc8e200 size=02ba4h ( 11172) load I (113) esp_image: segment 2: paddr=00026144 vaddr=40380000 size=09ed4h ( 40660) load I (124) esp_image: segment 3: paddr=00030020 vaddr=42000020 size=74de0h (478688) map I (197) esp_image: segment 4: paddr=000a4e08 vaddr=40389ed4 size=04218h ( 16920) load I (203) esp_image: segment 5: paddr=000a9028 vaddr=50000000 size=00010h ( 16) load I (207) boot: Loaded app from partition at offset 0x10000 I (209) boot: Disabling RNG early entropy source... I (225) cpu_start: Pro cpu up. I (234) cpu_start: Pro cpu start user code I (234) cpu_start: cpu freq: 160000000 Hz I (234) cpu_start: Application information: I (237) cpu_start: Project name: wifi_station I (242) cpu_start: App version: 56bdd21-dirty I (248) cpu_start: Compile time: Dec 9 2021 13:44:25 I (254) cpu_start: ELF file SHA256: 03a342e76e213be3... I (260) cpu_start: ESP-IDF: v5.0-dev-621-g4143a3f572 I (266) heap_init: Initializing. RAM available for dynamic allocation: I (273) heap_init: At 3FC94D20 len 0002B2E0 (172 KiB): DRAM I (279) heap_init: At 3FCC0000 len 0001F060 (124 KiB): STACK/DRAM I (286) heap_init: At 50000010 len 00001FF0 (7 KiB): RTCRAM I (293) spi_flash: detected chip: generic I (297) spi_flash: flash io: dio W (301) spi_flash: Detected size(4096k) larger than the size in the binary image header(2048k). Using the size in the binary image header. I (315) sleep: Configure to isolate all GPIO pins in sleep state I (321) sleep: Enable automatic switching of GPIO sleep configuration I (328) cpu_start: Starting scheduler. I (796) wifi station: ESP_WIFI_MODE_STA I (796) pp: pp rom version: 9387209 I (796) net80211: net80211 rom version: 9387209 I (816) wifi:wifi driver task: 3fc9d8a4, prio:23, stack:6656, core=0 I (816) system_api: Base MAC address is not set I (816) system_api: read default base MAC address from EFUSE I (816) wifi:wifi firmware version: c279458 I (826) wifi:wifi certification version: v7.0 I (826) wifi:config NVS flash: enabled I (826) wifi:config nano formating: disabled I (836) wifi:Init data frame dynamic rx buffer num: 32 I (836) wifi:Init management frame dynamic rx buffer num: 32 I (846) wifi:Init management short buffer num: 32 I (846) wifi:Init dynamic tx buffer num: 32 I (856) wifi:Init static tx FG buffer num: 2 I (856) wifi:Init static rx buffer size: 1600 I (856) wifi:Init static rx buffer num: 10 I (866) wifi:Init dynamic rx buffer num: 32 I (866) wifi_init: rx ba win: 6 I (876) wifi_init: tcpip mbox: 32 I (876) wifi_init: udp mbox: 6 I (876) wifi_init: tcp mbox: 6 I (886) wifi_init: tcp tx win: 5744 I (886) wifi_init: tcp rx win: 5744 I (896) wifi_init: tcp mss: 1440 I (896) wifi_init: WiFi IRAM OP enabled I (896) wifi_init: WiFi RX IRAM OP enabled I (916) phy_init: phy_version 906,ed5370c,Nov 8 2021,18:01:10 W (916) phy_init: failed to load RF calibration data (0x1102), falling back to full calibration I (966) wifi:mode : sta (84:f7:03:3b:11:0c) I (966) wifi:enable tsf I (966) wifi station: wifi_init_sta finished. I (2176) wifi:new:<11,0>, old:<1,0>, ap:<255,255>, sta:<11,0>, prof:1 I (2796) wifi:state: init -> auth (b0) I (3796) wifi:state: auth -> init (200) I (3796) wifi:new:<11,0>, old:<11,0>, ap:<255,255>, sta:<11,0>, prof:1 I (3796) wifi station: retry to connect to the AP I (3796) wifi station: connect to the AP fail I (5846) wifi station: retry to connect to the AP I (5846) wifi station: connect to the AP fail I (5846) wifi:new:<11,0>, old:<11,0>, ap:<255,255>, sta:<11,0>, prof:1 I (5846) wifi:state: init -> auth (b0) I (5856) wifi:state: auth -> assoc (0) I (5876) wifi:state: assoc -> run (10) I (5896) wifi:connected with ap, aid = 4, channel 11, BW20, bssid = 50:8f:4c:d1:ca:05 I (5896) wifi:security: WPA2-PSK, phy: bgn, rssi: -53 I (5906) wifi:pm start, type: 1

I (5906) wifi:set rx beacon pti, rx_bcn_pti: 0, bcn_timeout: 0, mt_pti: 25000, mt_time: 10000 I (5936) wifi:BcnInt:102400, DTIM:2 I (6796) esp_netif_handlers: sta ip: 192.168.43.40, mask: 255.255.255.0, gw: 192.168.43.1 I (6796) wifi station: got ip:192.168.43.40 I (6796) wifi station: connected to ap SSID:ap password:######


openocd -f board\esp32c3-builtin.cfg 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 Info : only one transport option; autoselect 'jtag' Warn : Transport "jtag" was already selected Info : Listening on port 6666 for tcl connections Info : Listening on port 4444 for telnet connections Error: libusb_get_string_descriptor_ascii() failed with -1

nedv-eu commented 2 years ago

The same problem with built-in jtag/serial consoel is also present after running esp-idf/examples/wifi/getting_started/softAP and esp-idf/examples/wifi/espnow examples.

igrr commented 2 years ago

@nedv-eu Could you tell, which development board have you reproduced the issue with?

nedv-eu commented 2 years ago

https://docs.ai-thinker.com/_media/esp32/docs/esp-c3-12f_specification.pdf

Only USB data pins and linear regulator connected to the module. Also tested with bench power supply (3.3V / 3A) to eliminate possible issues with power supply. In both power supply variants the problem is present.

nedv-eu commented 2 years ago

This openocd-esp32 bug may be related: https://github.com/espressif/openocd-esp32/issues/192

igrr commented 2 years ago

@nedv-eu I wasn't able to reproduce the issue with the examples you mentioned on ESP32-C3-Devkit-M-1 board.

If your module is not soldered onto a PCB on top of a ground plane, you may meet an EMI issue when USB and Wi-Fi work at the same time. I don't know if Ai-Thinker's ESP-C3-12F module uses a 4-layer or 2-layer PCB. If it is 2-layer, then the issue would be much more noticeable.

Please consider using Espressif's design review service when designing the PCB for your product, this can help avoid common issues with power supply and EMI.

nedv-eu commented 2 years ago

Thanks for checking out the problem on your side. I am waiting for different hardware. It may indeed be a problem of single specific piece of module. Anyway interesting thing is that the USB device is not initialized properly even after wifi start and wifi stop sequence - there should be no EMI issue in this case.

fgervais commented 2 years ago

I think I have the same issue on my side.

The serial console was working fine without wifi but now with wifi I cannot enumerate correctly:

Jan 01 23:21:53 fgervais-System-Product-Name kernel: usb 1-8.4: new full-speed USB device number 98 using xhci_hcd
Jan 01 23:21:53 fgervais-System-Product-Name kernel: usb 1-8.4: device descriptor read/64, error -32
Jan 01 23:21:53 fgervais-System-Product-Name kernel: usb 1-8.4: device descriptor read/64, error -32
Jan 01 23:21:53 fgervais-System-Product-Name kernel: usb 1-8.4: new full-speed USB device number 99 using xhci_hcd
Jan 01 23:21:53 fgervais-System-Product-Name kernel: usb 1-8.4: device descriptor read/64, error -32
Jan 01 23:21:53 fgervais-System-Product-Name kernel: usb 1-8.4: device descriptor read/64, error -32
Jan 01 23:21:53 fgervais-System-Product-Name kernel: usb 1-8-port4: attempt power cycle
Jan 01 23:21:54 fgervais-System-Product-Name kernel: usb 1-8.4: new full-speed USB device number 100 using xhci_hcd
Jan 01 23:21:54 fgervais-System-Product-Name kernel: usb 1-8.4: Device not responding to setup address.
Jan 01 23:21:54 fgervais-System-Product-Name kernel: usb 1-8.4: Device not responding to setup address.
Jan 01 23:21:54 fgervais-System-Product-Name kernel: usb 1-8.4: device not accepting address 100, error -71
...

I'm using a ESP32-C3-WROOM-02 on a custom board https://github.com/fgervais/project-esp32-c3-wroom-02-breakout/tree/master/hardware.

fgervais commented 2 years ago

I made a small test sketch that waits 5 seconds before connecting to wifi to allow proper enumeration:

#include "Arduino.h"
#include "secrets.h"

#include <WiFi.h>

void init_wifi() {
    WiFi.mode(WIFI_STA);
    WiFi.begin(WIFI_SSID, WIFI_PASSWORD);
    while (WiFi.status() != WL_CONNECTED) {
        delay(1000);
    }
}

void setup()
{

}

void loop()
{
    if (WiFi.status() != WL_CONNECTED) {
        delay(5000);
        init_wifi();
    }

    delay(1000);
}

The USB console initializes fine but then once the wifi starts, the kernel starts reporting all sorts of error:

Jan 03 12:05:32 fgervais-System-Product-Name kernel: xhci_hcd 0000:00:14.0: WARN Cannot submit Set TR Deq Ptr
Jan 03 12:05:32 fgervais-System-Product-Name kernel: xhci_hcd 0000:00:14.0: A Set TR Deq Ptr command is pending.
Jan 03 12:05:32 fgervais-System-Product-Name kernel: xhci_hcd 0000:00:14.0: WARN Cannot submit Set TR Deq Ptr
Jan 03 12:05:32 fgervais-System-Product-Name kernel: xhci_hcd 0000:00:14.0: A Set TR Deq Ptr command is pending.
Jan 03 12:05:32 fgervais-System-Product-Name kernel: xhci_hcd 0000:00:14.0: WARN Set TR Deq Ptr cmd failed due to incorrect slot or ep state.
Jan 03 12:05:32 fgervais-System-Product-Name kernel: xhci_hcd 0000:00:14.0: WARN Set TR Deq Ptr cmd failed due to incorrect slot or ep state.
Jan 03 12:05:33 fgervais-System-Product-Name kernel: xhci_hcd 0000:00:14.0: WARN Cannot submit Set TR Deq Ptr
Jan 03 12:05:33 fgervais-System-Product-Name kernel: xhci_hcd 0000:00:14.0: A Set TR Deq Ptr command is pending.
Jan 03 12:05:34 fgervais-System-Product-Name kernel: xhci_hcd 0000:00:14.0: WARN Cannot submit Set TR Deq Ptr
Jan 03 12:05:34 fgervais-System-Product-Name kernel: xhci_hcd 0000:00:14.0: A Set TR Deq Ptr command is pending.
Jan 03 12:05:34 fgervais-System-Product-Name kernel: xhci_hcd 0000:00:14.0: WARN Cannot submit Set TR Deq Ptr
Jan 03 12:05:34 fgervais-System-Product-Name kernel: xhci_hcd 0000:00:14.0: A Set TR Deq Ptr command is pending.
Jan 03 12:05:35 fgervais-System-Product-Name kernel: xhci_hcd 0000:00:14.0: WARN Cannot submit Set TR Deq Ptr
Jan 03 12:05:35 fgervais-System-Product-Name kernel: xhci_hcd 0000:00:14.0: A Set TR Deq Ptr command is pending.
Jan 03 12:05:37 fgervais-System-Product-Name kernel: xhci_hcd 0000:00:14.0: WARN Cannot submit Set TR Deq Ptr
Jan 03 12:05:37 fgervais-System-Product-Name kernel: xhci_hcd 0000:00:14.0: A Set TR Deq Ptr command is pending.
Jan 03 12:05:37 fgervais-System-Product-Name kernel: xhci_hcd 0000:00:14.0: WARN Set TR Deq Ptr cmd failed due to incorrect slot or ep state.
Jan 03 12:05:38 fgervais-System-Product-Name kernel: xhci_hcd 0000:00:14.0: WARN Set TR Deq Ptr cmd failed due to incorrect slot or ep state.
Jan 03 12:05:40 fgervais-System-Product-Name kernel: xhci_hcd 0000:00:14.0: WARN Cannot submit Set TR Deq Ptr
Jan 03 12:05:40 fgervais-System-Product-Name kernel: xhci_hcd 0000:00:14.0: A Set TR Deq Ptr command is pending.
Jan 03 12:05:42 fgervais-System-Product-Name kernel: xhci_hcd 0000:00:14.0: WARN Cannot submit Set TR Deq Ptr
Jan 03 12:05:42 fgervais-System-Product-Name kernel: xhci_hcd 0000:00:14.0: A Set TR Deq Ptr command is pending.
Jan 03 12:05:43 fgervais-System-Product-Name kernel: xhci_hcd 0000:00:14.0: WARN Set TR Deq Ptr cmd failed due to incorrect slot or ep state.
Jan 03 12:05:43 fgervais-System-Product-Name kernel: xhci_hcd 0000:00:14.0: WARN Set TR Deq Ptr cmd failed due to incorrect slot or ep state.
Jan 03 12:05:43 fgervais-System-Product-Name kernel: xhci_hcd 0000:00:14.0: WARN Cannot submit Set TR Deq Ptr
...

I probed my D+/D- like so: IMG_0732

Here is D+/D- with WIFI enabled: D+_with_wifi D-_with_wifi

Looks reasonable right?

Any idea?

nedv-eu commented 2 years ago

I retested with different module and IDF SDK from latest master branch. The USB debug and serial console still gets corrupted once wifi is enabled.

iboguslavsky commented 2 years ago

+1 on this problem - using either BLE or WiFi triggers the problem. No other samples exhibit it. Confirmed on AI Tinker's ESP-C3-13U module.

faryon93 commented 2 years ago

Same problem here with ESP32-C3-WROOM-02

yamabu commented 2 years ago

Same problem here with ESP32-C3-MINI-1

delat commented 2 years ago

The same problem here with the original ESP32-C3-WROOM-02 module. Power supply voltage of the module is stable and decoupled with a series of different capacitors, but in case of WiFi+USB or WiFi+BLE+TWAI I see drops in logical one output signals on IO pins. So internal logic power supply circuits drop under high load. I even shortened the power supply inductor in the module but without any success. So looks like some problem in the module layout or ESP32C3 IC.

faryon93 commented 2 years ago

There is a workaround in the esp32-arduino repository: See espressif/arduino-esp32#6264 and the pull request with the workaround espressif/arduino-esp32#6287

A first test looks promising.

iboguslavsky commented 2 years ago

It appears that it's been merged with esp-idf master; the problem with USB enumeration is gone after rebuild

andypiper commented 2 years ago

What's the best way to get the fixes for idf and the Arduino core, is there a way to update my toolchains to track the latest git builds, or do I need to build and install from source locally? (ESP newcomer here, but I do have this issue)

krzychb commented 2 years ago

What's the best way to get the fixes for idf and the Arduino core

I believe the issue resolution has been merged to ESP-IDF master one month ago in commits d204bf4651c64f52a25983dc4c70b502e51aef9c and e04d4ac2b56e89dc00f751424801e17298202a72.

There are also backports of the fixes done couple of days ago to:

As for the Arduino core, the fix has been merged on 16-Feb-2022 in commit https://github.com/espressif/arduino-esp32/commit/05d8cddee73b819527e01049aa34e08967ae2430.

From what I see there are no tagged releases that include the above fixes yet. You need to use git to pull the updates manually and then recompile your projects. To do so please follow Updating to a Release Branch for ESP-IDF or How to update to the latest code for Arduino.

krzychb commented 2 years ago

Related issues: #7998, #8096, #8113, #8131, #8241 and https://github.com/espressif/arduino-esp32/issues/6264

Alvin1Zhang commented 2 years ago

Thanks for reporting, feel free to reopen.