Files
firmware/src/SerialConsole.cpp
T
p0nsandBen Meadors 144b07986b Fix ESP32-S3 USB CDC: post-disconnect task-WDT reboot from blocking console log writes (#10956)
* Fix ESP32-S3 USB CDC: post-disconnect task-WDT reboot from blocking console log writes

When a serial API client disconnects (USB cable still attached), the host
stops draining the USB-Serial/JTAG CDC buffer. The next raw-text debug log
write can then block the main loop task indefinitely (measured: a single
write blocked 52.4 s). The loop task stops feeding the app task watchdog
(APP_WATCHDOG_SECS = 90 s, trigger_panic), so the device reboots with
esp_reset_reason = ESP_RST_TASK_WDT ~97 s after every serial disconnect.

On 2.7.x (arduino-esp32 2.x / IDF 4.4) the reboot also re-enumerated USB;
since the Arduino 3.x migration the reboot is silent (USB stays enumerated),
making it look like a random reboot ~90 s after using the CLI.

Fix: on USB CDC targets, keep console TX in non-blocking mode (txTimeout 0,
drop-oldest) whenever no API client is provably alive, and restore the
normal bounded timeout while a client is connected so protobuf API frames
are never truncated. Toggle points: boot, handleToRadio (host sent bytes),
and onConnectionChanged (set non-blocking before disconnect handling emits
more log lines to a dead port).

Repro/validation on HELTEC_WIRELESS_TRACKER_V2 (macOS + Linux hosts):
open+close any meshtastic-python session, wait 150 s: reboot_count +1 every
time on unpatched builds; flat with this fix. Max observed log write stall
drops from 52405 ms to 30 ms.

* Condense comments per review feedback

---------

Co-authored-by: Ben Meadors <benmmeadors@gmail.com>
2026-07-09 11:42:15 -05:00

179 lines
5.0 KiB
C++

#include "SerialConsole.h"
#include "Default.h"
#include "NodeDB.h"
#include "PowerFSM.h"
#include "Throttle.h"
#include "configuration.h"
#include "time.h"
#if defined(ARDUINO_USB_CDC_ON_BOOT) && ARDUINO_USB_CDC_ON_BOOT
#define IS_USB_SERIAL
#ifdef SERIAL_HAS_ON_RECEIVE
#undef SERIAL_HAS_ON_RECEIVE
#endif
#include "HWCDC.h"
#endif
#ifdef RP2040_SLOW_CLOCK
#define Port Serial2
#else
#ifdef USER_DEBUG_PORT // change by WayenWeng
#define Port USER_DEBUG_PORT
#else
#define Port Serial
#endif
#endif
// Defaulting to the formerly removed phone_timeout_secs value of 15 minutes
#define SERIAL_CONNECTION_TIMEOUT (15 * 60) * 1000UL
SerialConsole *console;
void consoleInit()
{
if (console) {
return;
}
auto sc = new SerialConsole(); // Must be dynamically allocated because we are now inheriting from thread
#if defined(SERIAL_HAS_ON_RECEIVE)
// onReceive does only exist for HardwareSerial not for USB CDC serial
Port.onReceive([sc]() { sc->rxInt(); });
#else
(void)sc;
#endif
DEBUG_PORT.rpInit(); // Simply sets up semaphore
}
void consolePrintf(const char *format, ...)
{
va_list arg;
va_start(arg, format);
console->vprintf(nullptr, format, arg);
va_end(arg);
console->flush();
}
SerialConsole::SerialConsole() : StreamAPI(&Port), RedirectablePrint(&Port), concurrency::OSThread("SerialConsole")
{
api_type = TYPE_SERIAL;
assert(!console);
console = this;
canWrite = false; // We don't send packets to our port until it has talked to us first
#ifdef RP2040_SLOW_CLOCK
Port.setTX(SERIAL2_TX);
Port.setRX(SERIAL2_RX);
#endif
Port.begin(SERIAL_BAUD);
// Boot with console TX in non-blocking mode: no host is provably listening yet.
setHostDraining(false);
time_t timeout = millis();
while (!Port) {
if (Throttle::isWithinTimespanMs(timeout, FIVE_SECONDS_MS)) {
delay(100);
} else {
break;
}
}
#if !ARCH_PORTDUINO
emitRebooted();
#endif
}
int32_t SerialConsole::runOnce()
{
#ifdef HELTEC_MESH_SOLAR
// After enabling the mesh solar serial port module configuration, command processing is handled by the serial port module.
if (moduleConfig.serial.enabled && moduleConfig.serial.override_console_serial_port &&
moduleConfig.serial.mode == meshtastic_ModuleConfig_SerialConfig_Serial_Mode_MS_CONFIG) {
return 250;
}
#endif
int32_t delay = runOncePart();
#if defined(SERIAL_HAS_ON_RECEIVE) || defined(CONFIG_IDF_TARGET_ESP32S2)
return Port.available() ? delay : INT32_MAX;
#elif defined(IS_USB_SERIAL)
return HWCDC::isPlugged() ? delay : (1000 * 20);
#else
return delay;
#endif
}
void SerialConsole::flush()
{
Port.flush();
}
// trigger tx of serial data
void SerialConsole::onNowHasData(uint32_t fromRadioNum)
{
setIntervalFromNow(0);
}
// trigger rx of serial data
void SerialConsole::rxInt()
{
setIntervalFromNow(0);
}
// For the serial port we can't really detect if any client is on the other side, so instead just look for recent messages
bool SerialConsole::checkIsConnected()
{
return Throttle::isWithinTimespanMs(lastContactMsec, SERIAL_CONNECTION_TIMEOUT);
}
void SerialConsole::setHostDraining(bool draining)
{
#ifdef IS_USB_SERIAL
// Timeout 0 makes HWCDC writes drop instead of block when the host stops draining;
// bounded blocking is restored while an API client is connected so frames aren't truncated.
Port.setTxTimeoutMs(draining ? 100 : 0);
#else
(void)draining;
#endif
}
void SerialConsole::onConnectionChanged(bool connected)
{
// Order matters on disconnect: make console TX non-blocking *before* the
// PowerFSM/close handling below emits more log lines to a dead port.
if (!connected)
setHostDraining(false);
StreamAPI::onConnectionChanged(connected);
if (connected)
setHostDraining(true);
}
/**
* we override this to notice when we've received a protobuf over the serial
* stream. Then we shut off debug serial output.
*/
bool SerialConsole::handleToRadio(const uint8_t *buf, size_t len)
{
// only talk to the API once the configuration has been loaded and we're sure the serial port is not disabled.
if (config.has_lora && config.security.serial_enabled) {
// The host just sent us bytes, so it is alive and draining the port:
// restore normal bounded-blocking TX before any API response is written.
setHostDraining(true);
// Switch to protobufs for log messages
usingProtobufs = true;
canWrite = true;
return StreamAPI::handleToRadio(buf, len);
} else {
return false;
}
}
void SerialConsole::log_to_serial(const char *logLevel, const char *format, va_list arg)
{
if (usingProtobufs && config.security.debug_log_api_enabled) {
meshtastic_LogRecord_Level ll = RedirectablePrint::getLogLevel(logLevel);
auto thread = concurrency::OSThread::currentThread;
emitLogRecord(ll, thread ? thread->ThreadName.c_str() : "", format, arg);
} else
RedirectablePrint::log_to_serial(logLevel, format, arg);
}