espressif / arduino-esp32

Arduino core for the ESP32
GNU Lesser General Public License v2.1
13.3k stars 7.35k forks source link

Serial.print() in WiFi event handler can hang ESP32-S2 (repro case included) #10137

Open egnor opened 1 month ago

egnor commented 1 month ago

Board & Hardware Description

I'm using my own ESP32-S2 board, but probably any ESP32-S2-based board with USB would reproduce this. (I can pick up a generic dev board and try there if desired.) It's probably important to be using USB for bootloading and console output.

Version

v3.0.4

IDE Name

arduino-cli

Operating System

Ubuntu 24.04 (probably doesn't matter tho)

Flash frequency

default

PSRAM enabled

yes

Upload speed

default

Description

When an event handler on the ESP-IDF default event loop (such as registered by WiFi.onEvent) calls Serial.print() too often, the CPU locks up and stops responding to anything.

Sketch

(Edit the wifi access point constants obviously! -- it might be important that the wifi actually connects.)

#include <Arduino.h>
#include <WiFi.h>

constexpr char const* WIFI_SSID = "oneruling classic";
constexpr char const* WIFI_PASSWORD = "oneruling";

static void on_event(arduino_event_id_t id) {
  for (int i = 0; i < 80; ++i) Serial.print(".");
  Serial.println();
}

void setup() {
  Serial.begin(115200);
  Serial.setDebugOutput(true);
  for (int n = 5; n > 0; --n) {
    Serial.print("SETUP COUNTDOWN: ");
    Serial.println(n);
    delay(1000);
  }

  WiFi.onEvent(on_event);
  WiFi.begin(WIFI_SSID, WIFI_PASSWORD);  
  while (WiFi.status() != WL_CONNECTED) {
    delay(500);
    Serial.println("Waiting for wifi...");
  }
}

void loop() {
  Serial.println("LOOP");
  delay(500);
}

Debug Message

SETUP COUNTDOWN: 5
SETUP COUNTDOWN: 4
SETUP COUNTDOWN: 3
SETUP COUNTDOWN: 2
SETUP COUNTDOWN: 1
.............

(and then it hangs)

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

lbernstone commented 1 month ago

Does it work if you use ets_printf instead?

SuGlider commented 1 month ago

Thank you, @egnor! Issue confirmed. We will investigate it.

The issue seems to be some problem with concurrency related to USB OTG state in TinyUSB (S2 and S3 using OTG UB Mode).

Up on my testing, the issue doesn't affect the UART and also not the HW Serial JTAG USB CDC.

In the meanwhile, if necessary, you can use logging (like log_i("msg")) inside the WiFi events. It seems to work fine.

SuGlider commented 1 month ago

It seems that this is an exclusive issue with the S2 USB OTG with CDC. The S3 using USB OTG port isn't affected by this problem. This is interesting given that both use the same TinyUSB source code.

egnor commented 1 month ago

log_i("msg") doesn't work for me (see https://github.com/espressif/arduino-esp32/issues/10121).

ets_printf DOES seem to work, though...

SuGlider commented 1 month ago

Does it work if you use ets_printf instead?

Yes, it also works fine. Thank you @lbernstone. @egnor - In that case your code would be this - which works fine with ESP32-S2 + USB CDC.

#include <Arduino.h>
#include <WiFi.h>
#include "rom/ets_sys.h"

constexpr char const* WIFI_SSID = "oneruling classic";
constexpr char const* WIFI_PASSWORD = "oneruling";

static void on_event(arduino_event_id_t id) {
  // ets_printf() replaces Serial.print(".") only when Serial.setDebutOutput(true) is executed
  for (int i = 0; i < 80; ++i) ets_printf(".");
  ets_printf("\r\n");                           // replaces Serial.println();
}

void setup() {
  Serial.begin();
  Serial.setDebugOutput(true);
  for (int n = 5; n > 0; --n) {
    Serial.print("SETUP COUNTDOWN: ");
    Serial.println(n);
    delay(100);
  }

  WiFi.onEvent(on_event);
  WiFi.begin(WIFI_SSID, WIFI_PASSWORD);
  while (WiFi.status() != WL_CONNECTED) {
    delay(500);
    Serial.println("Waiting for wifi...");
  }
}

void loop() {
  Serial.println("LOOP");
  delay(500);
}
egnor commented 1 month ago

Yeah, I tried using ets_printf() for general logging, but it was weird and sluggish and chunky and hung in different places. I just won't log/print from event handlers (or non-mainloop tasks in general?) until this is fixed.