From 316fe2f06cfa7333b072e9ef09c2b8d5d18f3bd5 Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Sun, 18 May 2025 15:43:41 -0400 Subject: [PATCH] Fix ESP32 console logging corruption and message loss in multi-task (#8806) --- esphome/components/logger/logger.cpp | 44 +++++++++++++++++++--------- 1 file changed, 30 insertions(+), 14 deletions(-) diff --git a/esphome/components/logger/logger.cpp b/esphome/components/logger/logger.cpp index 0ad909cb07..014f7e3dec 100644 --- a/esphome/components/logger/logger.cpp +++ b/esphome/components/logger/logger.cpp @@ -16,9 +16,14 @@ static const char *const TAG = "logger"; #ifdef USE_ESP32 // Implementation for ESP32 (multi-task platform with task-specific tracking) // Main task always uses direct buffer access for console output and callbacks -// Other tasks: -// - With task log buffer: stack buffer for console output, async buffer for callbacks -// - Without task log buffer: only console output, no callbacks +// +// For non-main tasks: +// - WITH task log buffer: Prefer sending to ring buffer for async processing +// - Avoids allocating stack memory for console output in normal operation +// - Prevents console corruption from concurrent writes by multiple tasks +// - Messages are serialized through main loop for proper console output +// - Fallback to emergency console logging only if ring buffer is full +// - WITHOUT task log buffer: Only emergency console output, no callbacks void HOT Logger::log_vprintf_(int level, const char *tag, int line, const char *format, va_list args) { // NOLINT if (level > this->level_for(tag)) return; @@ -38,8 +43,18 @@ void HOT Logger::log_vprintf_(int level, const char *tag, int line, const char * return; } - // For non-main tasks: use stack-allocated buffer only for console output - if (this->baud_rate_ > 0) { // If logging is enabled, write to console + bool message_sent = false; +#ifdef USE_ESPHOME_TASK_LOG_BUFFER + // For non-main tasks, queue the message for callbacks - but only if we have any callbacks registered + message_sent = this->log_buffer_->send_message_thread_safe(static_cast(level), tag, + static_cast(line), current_task, format, args); +#endif // USE_ESPHOME_TASK_LOG_BUFFER + + // Emergency console logging for non-main tasks when ring buffer is full or disabled + // This is a fallback mechanism to ensure critical log messages are visible + // Note: This may cause interleaved/corrupted console output if multiple tasks + // log simultaneously, but it's better than losing important messages entirely + if (!message_sent && this->baud_rate_ > 0) { // If logging is enabled, write to console // Maximum size for console log messages (includes null terminator) static const size_t MAX_CONSOLE_LOG_MSG_SIZE = 144; char console_buffer[MAX_CONSOLE_LOG_MSG_SIZE]; // MUST be stack allocated for thread safety @@ -49,15 +64,6 @@ void HOT Logger::log_vprintf_(int level, const char *tag, int line, const char * this->write_msg_(console_buffer); } -#ifdef USE_ESPHOME_TASK_LOG_BUFFER - // For non-main tasks, queue the message for callbacks - but only if we have any callbacks registered - if (this->log_callback_.size() > 0) { - // This will be processed in the main loop - this->log_buffer_->send_message_thread_safe(static_cast(level), tag, static_cast(line), - current_task, format, args); - } -#endif // USE_ESPHOME_TASK_LOG_BUFFER - // Reset the recursion guard for this task this->reset_task_log_recursion_(is_main_task); } @@ -184,7 +190,17 @@ void Logger::loop() { this->write_footer_to_buffer_(this->tx_buffer_, &this->tx_buffer_at_, this->tx_buffer_size_); this->tx_buffer_[this->tx_buffer_at_] = '\0'; this->call_log_callbacks_(message->level, message->tag, this->tx_buffer_); + // At this point all the data we need from message has been transferred to the tx_buffer + // so we can release the message to allow other tasks to use it as soon as possible. this->log_buffer_->release_message_main_loop(received_token); + + // Write to console from the main loop to prevent corruption from concurrent writes + // This ensures all log messages appear on the console in a clean, serialized manner + // Note: Messages may appear slightly out of order due to async processing, but + // this is preferred over corrupted/interleaved console output + if (this->baud_rate_ > 0) { + this->write_msg_(this->tx_buffer_); + } } } #endif