Logger Recursion Guard per Task on ESP32 (#8765)

This commit is contained in:
J. Nick Koston 2025-05-15 04:36:28 -05:00 committed by GitHub
parent efa6745a5e
commit 0b77cb1d16
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
3 changed files with 82 additions and 26 deletions

View File

@ -254,6 +254,7 @@ async def to_code(config):
config[CONF_TX_BUFFER_SIZE],
)
if CORE.is_esp32:
cg.add(log.create_pthread_key())
task_log_buffer_size = config[CONF_TASK_LOG_BUFFER_SIZE]
if task_log_buffer_size > 0:
cg.add_define("USE_ESPHOME_TASK_LOG_BUFFER")

View File

@ -14,20 +14,27 @@ namespace logger {
static const char *const TAG = "logger";
#ifdef USE_ESP32
// Implementation for ESP32 (multi-core with atomic support)
// Main thread: synchronous logging with direct buffer access
// Other threads: console output with stack buffer, callbacks via async buffer
// 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
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) || recursion_guard_.load(std::memory_order_relaxed))
if (level > this->level_for(tag))
return;
recursion_guard_.store(true, std::memory_order_relaxed);
TaskHandle_t current_task = xTaskGetCurrentTaskHandle();
bool is_main_task = (current_task == main_task_);
// For main task: call log_message_to_buffer_and_send_ which does console and callback logging
if (current_task == main_task_) {
// Check and set recursion guard - uses pthread TLS for per-task state
if (this->check_and_set_task_log_recursion_(is_main_task)) {
return; // Recursion detected
}
// Main task uses the shared buffer for efficiency
if (is_main_task) {
this->log_message_to_buffer_and_send_(level, tag, line, format, args);
recursion_guard_.store(false, std::memory_order_release);
this->reset_task_log_recursion_(is_main_task);
return;
}
@ -51,23 +58,21 @@ void HOT Logger::log_vprintf_(int level, const char *tag, int line, const char *
}
#endif // USE_ESPHOME_TASK_LOG_BUFFER
recursion_guard_.store(false, std::memory_order_release);
// Reset the recursion guard for this task
this->reset_task_log_recursion_(is_main_task);
}
#endif // USE_ESP32
#ifndef USE_ESP32
// Implementation for platforms that do not support atomic operations
// or have to consider logging in other tasks
#else
// Implementation for all other platforms
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) || recursion_guard_)
if (level > this->level_for(tag) || global_recursion_guard_)
return;
recursion_guard_ = true;
global_recursion_guard_ = true;
// Format and send to both console and callbacks
this->log_message_to_buffer_and_send_(level, tag, line, format, args);
recursion_guard_ = false;
global_recursion_guard_ = false;
}
#endif // !USE_ESP32
@ -76,10 +81,10 @@ void HOT Logger::log_vprintf_(int level, const char *tag, int line, const char *
// Note: USE_STORE_LOG_STR_IN_FLASH is only defined for ESP8266.
void Logger::log_vprintf_(int level, const char *tag, int line, const __FlashStringHelper *format,
va_list args) { // NOLINT
if (level > this->level_for(tag) || recursion_guard_)
if (level > this->level_for(tag) || global_recursion_guard_)
return;
recursion_guard_ = true;
global_recursion_guard_ = true;
this->tx_buffer_at_ = 0;
// Copy format string from progmem
@ -91,7 +96,7 @@ void Logger::log_vprintf_(int level, const char *tag, int line, const __FlashStr
// Buffer full from copying format
if (this->tx_buffer_at_ >= this->tx_buffer_size_) {
recursion_guard_ = false; // Make sure to reset the recursion guard before returning
global_recursion_guard_ = false; // Make sure to reset the recursion guard before returning
return;
}
@ -107,7 +112,7 @@ void Logger::log_vprintf_(int level, const char *tag, int line, const __FlashStr
}
this->call_log_callbacks_(level, tag, this->tx_buffer_ + msg_start);
recursion_guard_ = false;
global_recursion_guard_ = false;
}
#endif // USE_STORE_LOG_STR_IN_FLASH

View File

@ -3,7 +3,7 @@
#include <cstdarg>
#include <map>
#ifdef USE_ESP32
#include <atomic>
#include <pthread.h>
#endif
#include "esphome/core/automation.h"
#include "esphome/core/component.h"
@ -84,6 +84,23 @@ enum UARTSelection {
};
#endif // USE_ESP32 || USE_ESP8266 || USE_RP2040 || USE_LIBRETINY
/**
* @brief Logger component for all ESPHome logging.
*
* This class implements a multi-platform logging system with protection against recursion.
*
* Recursion Protection Strategy:
* - On ESP32: Uses task-specific recursion guards
* * Main task: Uses a dedicated boolean member variable for efficiency
* * Other tasks: Uses pthread TLS with a dynamically allocated key for task-specific state
* - On other platforms: Uses a simple global recursion guard
*
* We use pthread TLS via pthread_key_create to create a unique key for storing
* task-specific recursion state, which:
* 1. Efficiently handles multiple tasks without locks or mutexes
* 2. Works with ESP-IDF's pthread implementation that uses a linked list for TLS variables
* 3. Avoids the limitations of the fixed FreeRTOS task local storage slots
*/
class Logger : public Component {
public:
explicit Logger(uint32_t baud_rate, size_t tx_buffer_size);
@ -102,6 +119,9 @@ class Logger : public Component {
#ifdef USE_ESP_IDF
uart_port_t get_uart_num() const { return uart_num_; }
#endif
#ifdef USE_ESP32
void create_pthread_key() { pthread_key_create(&log_recursion_key_, nullptr); }
#endif
#if defined(USE_ESP32) || defined(USE_ESP8266) || defined(USE_RP2040) || defined(USE_LIBRETINY)
void set_uart_selection(UARTSelection uart_selection) { uart_ = uart_selection; }
/// Get the UART used by the logger.
@ -222,18 +242,22 @@ class Logger : public Component {
std::map<std::string, int> log_levels_{};
CallbackManager<void(int, const char *, const char *)> log_callback_{};
int current_level_{ESPHOME_LOG_LEVEL_VERY_VERBOSE};
#ifdef USE_ESP32
std::atomic<bool> recursion_guard_{false};
#ifdef USE_ESPHOME_TASK_LOG_BUFFER
std::unique_ptr<logger::TaskLogBuffer> log_buffer_; // Will be initialized with init_log_buffer
#endif
#ifdef USE_ESP32
// Task-specific recursion guards:
// - Main task uses a dedicated member variable for efficiency
// - Other tasks use pthread TLS with a dynamically created key via pthread_key_create
bool main_task_recursion_guard_{false};
pthread_key_t log_recursion_key_;
#else
bool recursion_guard_{false};
bool global_recursion_guard_{false}; // Simple global recursion guard for single-task platforms
#endif
void *main_task_ = nullptr;
CallbackManager<void(int)> level_callback_{};
#if defined(USE_ESP32) || defined(USE_LIBRETINY)
void *main_task_ = nullptr; // Only used for thread name identification
const char *HOT get_thread_name_() {
TaskHandle_t current_task = xTaskGetCurrentTaskHandle();
if (current_task == main_task_) {
@ -248,6 +272,32 @@ class Logger : public Component {
}
#endif
#ifdef USE_ESP32
inline bool HOT check_and_set_task_log_recursion_(bool is_main_task) {
if (is_main_task) {
const bool was_recursive = main_task_recursion_guard_;
main_task_recursion_guard_ = true;
return was_recursive;
}
intptr_t current = (intptr_t) pthread_getspecific(log_recursion_key_);
if (current != 0)
return true;
pthread_setspecific(log_recursion_key_, (void *) 1);
return false;
}
inline void HOT reset_task_log_recursion_(bool is_main_task) {
if (is_main_task) {
main_task_recursion_guard_ = false;
return;
}
pthread_setspecific(log_recursion_key_, (void *) 0);
}
#endif
inline void HOT write_header_to_buffer_(int level, const char *tag, int line, const char *thread_name, char *buffer,
int *buffer_at, int buffer_size) {
// Format header