ESP_LOGE and log_e broken with USB-CDC on ESP32-S2 (and others?) if #include <Arduino.h> [[includes diagnosis!]]

[egnor]

Board

any board with ESP32-S2 and USB-CDC, possibly other cores

Device Description

any board which uses on-chip USB as its primary serial port (i.e. running with -DARDUINO_USB_CDC_ON_BOOT=1)

Hardware Configuration

n/a

Version

latest master (checkout manually)

IDE Name

any

Operating System

any

Flash frequency

any

PSRAM enabled

yes

Upload speed

any

Description

On the ESP32-S2 (and probably some other cores), if using USB-CDC as the primary serial console, Serial.printf text will show up but log_* and ESP_LOG* reports will not. This severely hampers debugging as much of the system uses those macros to report important diagnostics.

I believe this is why:

1. esp32_hal_log.h is included indirectly by Arduino.h
2. In that file, (by default) ESP_LOG* is replaced with log_*, and log_* calls log_printf(...)
3. Surprisingly(?), log_printf(...) is defined in esp32_hal_uart.c; it calls log_printfv which includes this code:

#if CONFIG_IDF_TARGET_ESP32C3 || ((CONFIG_IDF_TARGET_ESP32H2 || CONFIG_IDF_TARGET_ESP32C6) && ARDUINO_USB_CDC_ON_BOOT)
  vsnprintf(temp, len + 1, format, arg);
  ets_printf("%s", temp);
#else
  int wlen = vsnprintf(temp, len + 1, format, arg);
  for (int i = 0; i < wlen; i++) {
    ets_write_char_uart(temp[i]);
  }
#endif

4. As you can see, on any chip which isn't the -C3, -H2, or -C6, it will always pass the log message to ets_write_char_uart, which (per its name) writes directly to the UART, even if the console is otherwise configured to use USB-CDC.

Sketch

#define LOG_LOCAL_LEVEL ESP_LOG_VERBOSE  // Optional, doesn't help 

#include <Arduino.h>
#include <esp_log.h>

void setup() {
  Serial.begin(115200);
  Serial.setDebugOutput(true);  // Optional, doesn't help
  esp_log_level_set("*", ESP_LOG_VERBOSE);  // Optional, doesn't help
}

void loop() {
  Serial.println("This is a Serial.println");
  log_e("This is a log_e error");
  ESP_LOGE("mainloop", "This is an ESP_LOGE error");
  delay(250);
}

Debug Message

Lots of...

This is a Serial.println
This is a Serial.println
This is a Serial.println
This is a Serial.println
...

...but I never see This is a log_e error or This is an ESP_LOGE error, even though these should absolutely show up.

Other Steps to Reproduce

This happens for me on an ESP32-S2 board. I am using this FQBN: esp32:esp32:esp32s2:CDCOnBoot=cdc,UploadMode=cdc,PSRAM=enabled,DebugLevel=debug

I have checked existing issues, online documentation and the Troubleshooting Guide

• I confirm I have checked existing issues, online documentation and Troubleshooting guide.

[P-R-O-C-H-Y]

@SuGlider I can confirm this behaviour, can you please take a look at this or we can discuss it on next meeting.
As ESP32S2 does not have SOC_USB_SERIAL_JTAG_SUPPORTED, that's the difference from other SoCs with USB. So it may not be possible for S2.

[SuGlider]

This issue affecct ESP32-S2 and ESP32-S3 when using TinyUSB OTG port.

[SuGlider]

@egnor - Serial.setDebugOutput(true); is necessary, otherwise there is no LOG output.
I'll post a PR to fix this issue.