[logger] Use RAII guards for recursion protection and optimize hot path (#13194)

Co-authored-by: Copilot <175728472+Copilot@users.noreply.github.com>
This commit is contained in:
J. Nick Koston
2026-01-13 15:43:02 -10:00
committed by GitHub
parent be12e3667a
commit 5dfdd05122
2 changed files with 91 additions and 65 deletions
+43 -23
View File
@@ -23,30 +23,57 @@ static const char *const TAG = "logger";
// - Messages are serialized through main loop for proper console output // - Messages are serialized through main loop for proper console output
// - Fallback to emergency console logging only if ring buffer is full // - Fallback to emergency console logging only if ring buffer is full
// - WITHOUT task log buffer: Only emergency console output, no callbacks // - WITHOUT task log buffer: Only emergency console output, no callbacks
//
// Optimized for the common case: 99.9% of logs come from the main thread
void HOT Logger::log_vprintf_(uint8_t level, const char *tag, int line, const char *format, va_list args) { // NOLINT void HOT Logger::log_vprintf_(uint8_t level, const char *tag, int line, const char *format, va_list args) { // NOLINT
if (level > this->level_for(tag)) if (level > this->level_for(tag))
return; return;
#if defined(USE_ESP32) || defined(USE_LIBRETINY) #if defined(USE_ESP32) || defined(USE_LIBRETINY)
// Get task handle once - used for both main task check and passing to non-main thread handler
TaskHandle_t current_task = xTaskGetCurrentTaskHandle(); TaskHandle_t current_task = xTaskGetCurrentTaskHandle();
bool is_main_task = (current_task == main_task_); const bool is_main_task = (current_task == this->main_task_);
#else // USE_HOST #else // USE_HOST
pthread_t current_thread = pthread_self(); const bool is_main_task = pthread_equal(pthread_self(), this->main_thread_);
bool is_main_task = pthread_equal(current_thread, main_thread_);
#endif #endif
// Check and set recursion guard - uses pthread TLS for per-thread/task state // Fast path: main thread, no recursion (99.9% of all logs)
if (this->check_and_set_task_log_recursion_(is_main_task)) { if (is_main_task && !this->main_task_recursion_guard_) [[likely]] {
return; // Recursion detected RecursionGuard guard(this->main_task_recursion_guard_);
} // Format and send to both console and callbacks
// Main thread/task uses the shared buffer for efficiency
if (is_main_task) {
this->log_message_to_buffer_and_send_(level, tag, line, format, args); this->log_message_to_buffer_and_send_(level, tag, line, format, args);
this->reset_task_log_recursion_(is_main_task);
return; return;
} }
// Main task with recursion - silently drop to prevent infinite loop
if (is_main_task) {
return;
}
// Non-main thread handling (~0.1% of logs)
#if defined(USE_ESP32) || defined(USE_LIBRETINY)
this->log_vprintf_non_main_thread_(level, tag, line, format, args, current_task);
#else // USE_HOST
this->log_vprintf_non_main_thread_(level, tag, line, format, args);
#endif
}
// Handles non-main thread logging only
// Kept separate from hot path to improve instruction cache performance
#if defined(USE_ESP32) || defined(USE_LIBRETINY)
void Logger::log_vprintf_non_main_thread_(uint8_t level, const char *tag, int line, const char *format, va_list args,
TaskHandle_t current_task) {
#else // USE_HOST
void Logger::log_vprintf_non_main_thread_(uint8_t level, const char *tag, int line, const char *format, va_list args) {
#endif
// Check if already in recursion for this non-main thread/task
if (this->is_non_main_task_recursive_()) {
return;
}
// RAII guard - automatically resets on any return path
auto guard = this->make_non_main_task_guard_();
bool message_sent = false; bool message_sent = false;
#ifdef USE_ESPHOME_TASK_LOG_BUFFER #ifdef USE_ESPHOME_TASK_LOG_BUFFER
// For non-main threads/tasks, queue the message for callbacks // For non-main threads/tasks, queue the message for callbacks
@@ -85,21 +112,17 @@ void HOT Logger::log_vprintf_(uint8_t level, const char *tag, int line, const ch
this->write_msg_(console_buffer, buffer_at); this->write_msg_(console_buffer, buffer_at);
} }
// Reset the recursion guard for this thread/task // RAII guard automatically resets on return
this->reset_task_log_recursion_(is_main_task);
} }
#else #else
// Implementation for all other platforms // Implementation for all other platforms (single-task, no threading)
void HOT Logger::log_vprintf_(uint8_t level, const char *tag, int line, const char *format, va_list args) { // NOLINT void HOT Logger::log_vprintf_(uint8_t level, const char *tag, int line, const char *format, va_list args) { // NOLINT
if (level > this->level_for(tag) || global_recursion_guard_) if (level > this->level_for(tag) || global_recursion_guard_)
return; return;
global_recursion_guard_ = true; RecursionGuard guard(global_recursion_guard_);
// Format and send to both console and callbacks // Format and send to both console and callbacks
this->log_message_to_buffer_and_send_(level, tag, line, format, args); this->log_message_to_buffer_and_send_(level, tag, line, format, args);
global_recursion_guard_ = false;
} }
#endif // USE_ESP32 / USE_HOST / USE_LIBRETINY #endif // USE_ESP32 / USE_HOST / USE_LIBRETINY
@@ -130,7 +153,7 @@ void Logger::log_vprintf_(uint8_t level, const char *tag, int line, const __Flas
if (level > this->level_for(tag) || global_recursion_guard_) if (level > this->level_for(tag) || global_recursion_guard_)
return; return;
global_recursion_guard_ = true; RecursionGuard guard(global_recursion_guard_);
this->tx_buffer_at_ = 0; this->tx_buffer_at_ = 0;
// Copy format string from progmem // Copy format string from progmem
@@ -140,9 +163,8 @@ void Logger::log_vprintf_(uint8_t level, const char *tag, int line, const __Flas
this->tx_buffer_[this->tx_buffer_at_++] = ch = (char) progmem_read_byte(format_pgm_p++); this->tx_buffer_[this->tx_buffer_at_++] = ch = (char) progmem_read_byte(format_pgm_p++);
} }
// Buffer full from copying format // Buffer full from copying format - RAII guard handles cleanup on return
if (this->tx_buffer_at_ >= this->tx_buffer_size_) { if (this->tx_buffer_at_ >= this->tx_buffer_size_) {
global_recursion_guard_ = false; // Make sure to reset the recursion guard before returning
return; return;
} }
@@ -161,8 +183,6 @@ void Logger::log_vprintf_(uint8_t level, const char *tag, int line, const __Flas
// Write to console starting at the msg_start // Write to console starting at the msg_start
this->write_tx_buffer_to_console_(msg_start, &msg_length); this->write_tx_buffer_to_console_(msg_start, &msg_length);
global_recursion_guard_ = false;
} }
#endif // USE_STORE_LOG_STR_IN_FLASH #endif // USE_STORE_LOG_STR_IN_FLASH
+48 -42
View File
@@ -229,6 +229,31 @@ class Logger : public Component {
#endif #endif
protected: protected:
// RAII guard for recursion flags - sets flag on construction, clears on destruction
class RecursionGuard {
public:
explicit RecursionGuard(bool &flag) : flag_(flag) { flag_ = true; }
~RecursionGuard() { flag_ = false; }
RecursionGuard(const RecursionGuard &) = delete;
RecursionGuard &operator=(const RecursionGuard &) = delete;
RecursionGuard(RecursionGuard &&) = delete;
RecursionGuard &operator=(RecursionGuard &&) = delete;
private:
bool &flag_;
};
#if defined(USE_ESP32) || defined(USE_HOST) || defined(USE_LIBRETINY)
// Handles non-main thread logging only (~0.1% of calls)
#if defined(USE_ESP32) || defined(USE_LIBRETINY)
// ESP32/LibreTiny: Pass task handle to avoid calling xTaskGetCurrentTaskHandle() twice
void log_vprintf_non_main_thread_(uint8_t level, const char *tag, int line, const char *format, va_list args,
TaskHandle_t current_task);
#else // USE_HOST
// Host: No task handle parameter needed (not used in send_message_thread_safe)
void log_vprintf_non_main_thread_(uint8_t level, const char *tag, int line, const char *format, va_list args);
#endif
#endif
void process_messages_(); void process_messages_();
void write_msg_(const char *msg, size_t len); void write_msg_(const char *msg, size_t len);
@@ -348,10 +373,10 @@ class Logger : public Component {
const device *uart_dev_{nullptr}; const device *uart_dev_{nullptr};
#endif #endif
#if defined(USE_ESP32) || defined(USE_LIBRETINY) || defined(USE_ZEPHYR) #if defined(USE_ESP32) || defined(USE_LIBRETINY) || defined(USE_ZEPHYR)
void *main_task_ = nullptr; // Only used for thread name identification void *main_task_{nullptr}; // Main thread/task for fast path comparison
#endif #endif
#ifdef USE_HOST #ifdef USE_HOST
pthread_t main_thread_{}; // Main thread for identification pthread_t main_thread_{}; // Main thread for pthread_equal() comparison
#endif #endif
#ifdef USE_ESP32 #ifdef USE_ESP32
// Task-specific recursion guards: // Task-specific recursion guards:
@@ -434,29 +459,28 @@ class Logger : public Component {
#endif #endif
#if defined(USE_ESP32) || defined(USE_HOST) #if defined(USE_ESP32) || defined(USE_HOST)
inline bool HOT check_and_set_task_log_recursion_(bool is_main_task) { // RAII guard for non-main task recursion using pthread TLS
if (is_main_task) { class NonMainTaskRecursionGuard {
const bool was_recursive = main_task_recursion_guard_; public:
main_task_recursion_guard_ = true; explicit NonMainTaskRecursionGuard(pthread_key_t key) : key_(key) {
return was_recursive; pthread_setspecific(key_, reinterpret_cast<void *>(1));
} }
~NonMainTaskRecursionGuard() { pthread_setspecific(key_, nullptr); }
NonMainTaskRecursionGuard(const NonMainTaskRecursionGuard &) = delete;
NonMainTaskRecursionGuard &operator=(const NonMainTaskRecursionGuard &) = delete;
NonMainTaskRecursionGuard(NonMainTaskRecursionGuard &&) = delete;
NonMainTaskRecursionGuard &operator=(NonMainTaskRecursionGuard &&) = delete;
intptr_t current = (intptr_t) pthread_getspecific(log_recursion_key_); private:
if (current != 0) pthread_key_t key_;
return true; };
pthread_setspecific(log_recursion_key_, (void *) 1); // Check if non-main task is already in recursion (via TLS)
return false; inline bool HOT is_non_main_task_recursive_() const { return pthread_getspecific(log_recursion_key_) != nullptr; }
}
inline void HOT reset_task_log_recursion_(bool is_main_task) { // Create RAII guard for non-main task recursion
if (is_main_task) { inline NonMainTaskRecursionGuard make_non_main_task_guard_() { return NonMainTaskRecursionGuard(log_recursion_key_); }
main_task_recursion_guard_ = false;
return;
}
pthread_setspecific(log_recursion_key_, (void *) 0);
}
#elif defined(USE_LIBRETINY) #elif defined(USE_LIBRETINY)
// LibreTiny doesn't have FreeRTOS TLS, so use a simple approach: // LibreTiny doesn't have FreeRTOS TLS, so use a simple approach:
// - Main task uses dedicated boolean (same as ESP32) // - Main task uses dedicated boolean (same as ESP32)
@@ -466,29 +490,11 @@ class Logger : public Component {
// - Cross-task "recursion" is prevented by the buffer mutex anyway // - Cross-task "recursion" is prevented by the buffer mutex anyway
// - Missing a recursive call from another task is acceptable (falls back to direct output) // - Missing a recursive call from another task is acceptable (falls back to direct output)
inline bool HOT check_and_set_task_log_recursion_(bool is_main_task) { // Check if non-main task is already in recursion
if (is_main_task) { inline bool HOT is_non_main_task_recursive_() const { return non_main_task_recursion_guard_; }
const bool was_recursive = main_task_recursion_guard_;
main_task_recursion_guard_ = true;
return was_recursive;
}
// For non-main tasks, use a simple shared guard // Create RAII guard for non-main task recursion (uses shared boolean for all non-main tasks)
// This may block legitimate concurrent logs from different tasks, inline RecursionGuard make_non_main_task_guard_() { return RecursionGuard(non_main_task_recursion_guard_); }
// but that's acceptable - they'll fall back to direct console output
const bool was_recursive = non_main_task_recursion_guard_;
non_main_task_recursion_guard_ = true;
return was_recursive;
}
inline void HOT reset_task_log_recursion_(bool is_main_task) {
if (is_main_task) {
main_task_recursion_guard_ = false;
return;
}
non_main_task_recursion_guard_ = false;
}
#endif #endif
#ifdef USE_HOST #ifdef USE_HOST