Fix ESP32 console logging corruption and message loss in multi-task (#8806)

This commit is contained in:
J. Nick Koston 2025-05-18 15:43:41 -04:00 committed by Jesse Hills
parent f8681adec4
commit 316fe2f06c
No known key found for this signature in database
GPG Key ID: BEAAE804EFD8E83A

View File

@ -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<uint8_t>(level), tag,
static_cast<uint16_t>(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<uint8_t>(level), tag, static_cast<uint16_t>(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