arduino-esp32 icon indicating copy to clipboard operation
arduino-esp32 copied to clipboard

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

Open egnor opened this issue 1 year ago • 6 comments

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

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

egnor avatar Aug 10 '24 19:08 egnor

Does it work if you use ets_printf instead?

lbernstone avatar Aug 10 '24 21:08 lbernstone

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 avatar Aug 10 '24 21:08 SuGlider

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.

SuGlider avatar Aug 10 '24 22:08 SuGlider

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

ets_printf DOES seem to work, though...

egnor avatar Aug 11 '24 00:08 egnor

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);
}

SuGlider avatar Aug 11 '24 02:08 SuGlider

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.

egnor avatar Aug 11 '24 03:08 egnor

@egnor Does the issue still exists with actual Arduino core 3.1.3 / 3.2.0-rc2?

Jason2866 avatar Mar 13 '25 16:03 Jason2866

@Jason2866 I ended up moving to just "never call anything, including log outputs, from event handlers". (I had a whole discussion about this.)

I can go back and re-run the repro cases above to see what the behavior is like now, or you can do that, or we can just close it out until someone bumps into the same gremlin in the night...

egnor avatar Mar 13 '25 17:03 egnor

@egnor I will close. If it is an issue it will pop up.

Jason2866 avatar Mar 13 '25 17:03 Jason2866