From 0ce3ac438b94e3e7e2a0acfae3f6c26e8f5e6097 Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Wed, 7 Jan 2026 13:40:15 -1000 Subject: [PATCH] [logger] Add thread-safe logging support for LibreTiny platform (#13062) --- esphome/components/logger/__init__.py | 13 +- esphome/components/logger/logger.cpp | 27 ++- esphome/components/logger/logger.h | 41 +++- .../logger/task_log_buffer_libretiny.cpp | 206 ++++++++++++++++++ .../logger/task_log_buffer_libretiny.h | 103 +++++++++ tests/components/logger/test.bk72xx-ard.yaml | 5 + tests/components/logger/test.ln882x-ard.yaml | 5 + tests/components/logger/test.rtl87xx-ard.yaml | 5 + 8 files changed, 396 insertions(+), 9 deletions(-) create mode 100644 esphome/components/logger/task_log_buffer_libretiny.cpp create mode 100644 esphome/components/logger/task_log_buffer_libretiny.h create mode 100644 tests/components/logger/test.bk72xx-ard.yaml create mode 100644 tests/components/logger/test.ln882x-ard.yaml create mode 100644 tests/components/logger/test.rtl87xx-ard.yaml diff --git a/esphome/components/logger/__init__.py b/esphome/components/logger/__init__.py index 79a9a4208c..7691458df5 100644 --- a/esphome/components/logger/__init__.py +++ b/esphome/components/logger/__init__.py @@ -226,8 +226,13 @@ CONFIG_SCHEMA = cv.All( cv.SplitDefault( CONF_TASK_LOG_BUFFER_SIZE, esp32=768, # Default: 768 bytes (~5-6 messages with 70-byte text plus thread names) + bk72xx=768, + ln882x=768, + rtl87xx=768, ): cv.All( - cv.only_on_esp32, + cv.only_on( + [PLATFORM_ESP32, PLATFORM_BK72XX, PLATFORM_LN882X, PLATFORM_RTL87XX] + ), cv.validate_bytes, cv.Any( cv.int_(0), # Disabled @@ -306,6 +311,7 @@ async def to_code(config): ) if CORE.is_esp32: cg.add(log.create_pthread_key()) + if CORE.is_esp32 or CORE.is_libretiny: task_log_buffer_size = config[CONF_TASK_LOG_BUFFER_SIZE] if task_log_buffer_size > 0: cg.add_define("USE_ESPHOME_TASK_LOG_BUFFER") @@ -529,6 +535,11 @@ FILTER_SOURCE_FILES = filter_source_files_from_platform( PlatformFramework.ESP32_IDF, }, "task_log_buffer_host.cpp": {PlatformFramework.HOST_NATIVE}, + "task_log_buffer_libretiny.cpp": { + PlatformFramework.BK72XX_ARDUINO, + PlatformFramework.RTL87XX_ARDUINO, + PlatformFramework.LN882X_ARDUINO, + }, } ) diff --git a/esphome/components/logger/logger.cpp b/esphome/components/logger/logger.cpp index e633f9fd7d..bb00a230ee 100644 --- a/esphome/components/logger/logger.cpp +++ b/esphome/components/logger/logger.cpp @@ -12,8 +12,8 @@ namespace esphome::logger { static const char *const TAG = "logger"; -#if defined(USE_ESP32) || defined(USE_HOST) -// Implementation for multi-threaded platforms (ESP32 with FreeRTOS, Host with pthreads) +#if defined(USE_ESP32) || defined(USE_HOST) || defined(USE_LIBRETINY) +// Implementation for multi-threaded platforms (ESP32 with FreeRTOS, Host with pthreads, LibreTiny with FreeRTOS) // Main thread/task always uses direct buffer access for console output and callbacks // // For non-main threads/tasks: @@ -27,7 +27,7 @@ void HOT Logger::log_vprintf_(uint8_t level, const char *tag, int line, const ch if (level > this->level_for(tag)) return; -#ifdef USE_ESP32 +#if defined(USE_ESP32) || defined(USE_LIBRETINY) TaskHandle_t current_task = xTaskGetCurrentTaskHandle(); bool is_main_task = (current_task == main_task_); #else // USE_HOST @@ -50,7 +50,7 @@ void HOT Logger::log_vprintf_(uint8_t level, const char *tag, int line, const ch bool message_sent = false; #ifdef USE_ESPHOME_TASK_LOG_BUFFER // For non-main threads/tasks, queue the message for callbacks -#ifdef USE_ESP32 +#if defined(USE_ESP32) || defined(USE_LIBRETINY) message_sent = this->log_buffer_->send_message_thread_safe(level, tag, static_cast(line), current_task, format, args); #else // USE_HOST @@ -101,7 +101,7 @@ void HOT Logger::log_vprintf_(uint8_t level, const char *tag, int line, const ch global_recursion_guard_ = false; } -#endif // USE_ESP32 / USE_HOST +#endif // USE_ESP32 / USE_HOST / USE_LIBRETINY #ifdef USE_STORE_LOG_STR_IN_FLASH // Implementation for ESP8266 with flash string support. @@ -191,8 +191,10 @@ void Logger::init_log_buffer(size_t total_buffer_size) { #ifdef USE_HOST // Host uses slot count instead of byte size this->log_buffer_ = esphome::make_unique(total_buffer_size); -#else +#elif defined(USE_ESP32) this->log_buffer_ = esphome::make_unique(total_buffer_size); +#elif defined(USE_LIBRETINY) + this->log_buffer_ = esphome::make_unique(total_buffer_size); #endif #ifdef USE_ESP32 @@ -220,7 +222,7 @@ void Logger::process_messages_() { this->log_buffer_->release_message_main_loop(); this->write_tx_buffer_to_console_(); } -#else // USE_ESP32 +#elif defined(USE_ESP32) logger::TaskLogBuffer::LogMessage *message; const char *text; void *received_token; @@ -232,6 +234,17 @@ void Logger::process_messages_() { this->log_buffer_->release_message_main_loop(received_token); this->write_tx_buffer_to_console_(); } +#elif defined(USE_LIBRETINY) + logger::TaskLogBufferLibreTiny::LogMessage *message; + const char *text; + while (this->log_buffer_->borrow_message_main_loop(&message, &text)) { + const char *thread_name = message->thread_name[0] != '\0' ? message->thread_name : nullptr; + this->format_buffered_message_and_notify_(message->level, message->tag, message->line, thread_name, text, + message->text_length); + // Release the message to allow other tasks to use it as soon as possible + this->log_buffer_->release_message_main_loop(); + this->write_tx_buffer_to_console_(); + } #endif } #ifdef USE_ESP32 diff --git a/esphome/components/logger/logger.h b/esphome/components/logger/logger.h index 86d2943135..79299c2b1c 100644 --- a/esphome/components/logger/logger.h +++ b/esphome/components/logger/logger.h @@ -16,6 +16,8 @@ #include "task_log_buffer_host.h" #elif defined(USE_ESP32) #include "task_log_buffer_esp32.h" +#elif defined(USE_LIBRETINY) +#include "task_log_buffer_libretiny.h" #endif #endif @@ -376,6 +378,8 @@ class Logger : public Component { std::unique_ptr log_buffer_; // Will be initialized with init_log_buffer #elif defined(USE_ESP32) std::unique_ptr log_buffer_; // Will be initialized with init_log_buffer +#elif defined(USE_LIBRETINY) + std::unique_ptr log_buffer_; // Will be initialized with init_log_buffer #endif #endif @@ -389,8 +393,11 @@ class Logger : public Component { #ifdef USE_LIBRETINY UARTSelection uart_{UART_SELECTION_DEFAULT}; #endif -#if defined(USE_ESP32) || defined(USE_HOST) +#if defined(USE_ESP32) || defined(USE_HOST) || defined(USE_LIBRETINY) bool main_task_recursion_guard_{false}; +#ifdef USE_LIBRETINY + bool non_main_task_recursion_guard_{false}; // Shared guard for all non-main tasks on LibreTiny +#endif #else bool global_recursion_guard_{false}; // Simple global recursion guard for single-task platforms #endif @@ -450,6 +457,38 @@ class Logger : public Component { pthread_setspecific(log_recursion_key_, (void *) 0); } +#elif defined(USE_LIBRETINY) + // LibreTiny doesn't have FreeRTOS TLS, so use a simple approach: + // - Main task uses dedicated boolean (same as ESP32) + // - Non-main tasks share a single recursion guard + // This is safe because: + // - Recursion from logging within logging is the main concern + // - Cross-task "recursion" is prevented by the buffer mutex anyway + // - 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) { + if (is_main_task) { + 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 + // This may block legitimate concurrent logs from different tasks, + // 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 #ifdef USE_HOST diff --git a/esphome/components/logger/task_log_buffer_libretiny.cpp b/esphome/components/logger/task_log_buffer_libretiny.cpp new file mode 100644 index 0000000000..580066e621 --- /dev/null +++ b/esphome/components/logger/task_log_buffer_libretiny.cpp @@ -0,0 +1,206 @@ +#ifdef USE_LIBRETINY + +#include "task_log_buffer_libretiny.h" +#include "esphome/core/helpers.h" +#include "esphome/core/log.h" + +#ifdef USE_ESPHOME_TASK_LOG_BUFFER + +namespace esphome::logger { + +TaskLogBufferLibreTiny::TaskLogBufferLibreTiny(size_t total_buffer_size) { + this->size_ = total_buffer_size; + // Allocate memory for the circular buffer using ESPHome's RAM allocator + RAMAllocator allocator; + this->storage_ = allocator.allocate(this->size_); + // Create mutex for thread-safe access + this->mutex_ = xSemaphoreCreateMutex(); +} + +TaskLogBufferLibreTiny::~TaskLogBufferLibreTiny() { + if (this->mutex_ != nullptr) { + vSemaphoreDelete(this->mutex_); + this->mutex_ = nullptr; + } + if (this->storage_ != nullptr) { + RAMAllocator allocator; + allocator.deallocate(this->storage_, this->size_); + this->storage_ = nullptr; + } +} + +size_t TaskLogBufferLibreTiny::available_contiguous_space() const { + if (this->head_ >= this->tail_) { + // head is ahead of or equal to tail + // Available space is from head to end, plus from start to tail + // But for contiguous, just from head to end (minus 1 to avoid head==tail ambiguity) + size_t space_to_end = this->size_ - this->head_; + if (this->tail_ == 0) { + // Can't use the last byte or head would equal tail + return space_to_end > 0 ? space_to_end - 1 : 0; + } + return space_to_end; + } else { + // tail is ahead of head + // Available contiguous space is from head to tail - 1 + return this->tail_ - this->head_ - 1; + } +} + +bool TaskLogBufferLibreTiny::borrow_message_main_loop(LogMessage **message, const char **text) { + if (message == nullptr || text == nullptr) { + return false; + } + + // Check if buffer was initialized successfully + if (this->mutex_ == nullptr || this->storage_ == nullptr) { + return false; + } + + // Try to take mutex without blocking - if busy, we'll get messages next loop iteration + if (xSemaphoreTake(this->mutex_, 0) != pdTRUE) { + return false; + } + + if (this->head_ == this->tail_) { + xSemaphoreGive(this->mutex_); + return false; + } + + // Read message header from tail + LogMessage *msg = reinterpret_cast(this->storage_ + this->tail_); + + // Check for padding marker (indicates wrap-around) + // We check the level field since valid levels are 0-7, and 0xFF indicates padding + if (msg->level == PADDING_MARKER_LEVEL) { + // Skip to start of buffer and re-read + this->tail_ = 0; + msg = reinterpret_cast(this->storage_); + } + *message = msg; + *text = msg->text_data(); + this->current_message_size_ = message_total_size(msg->text_length); + + // Keep mutex held until release_message_main_loop() + return true; +} + +void TaskLogBufferLibreTiny::release_message_main_loop() { + // Advance tail past the current message + this->tail_ += this->current_message_size_; + + // Handle wrap-around if we've reached the end + if (this->tail_ >= this->size_) { + this->tail_ = 0; + } + + this->message_count_--; + this->current_message_size_ = 0; + + xSemaphoreGive(this->mutex_); +} + +bool TaskLogBufferLibreTiny::send_message_thread_safe(uint8_t level, const char *tag, uint16_t line, + TaskHandle_t task_handle, const char *format, va_list args) { + // First, calculate the exact length needed using a null buffer (no actual writing) + va_list args_copy; + va_copy(args_copy, args); + int ret = vsnprintf(nullptr, 0, format, args_copy); + va_end(args_copy); + + if (ret <= 0) { + return false; // Formatting error or empty message + } + + // Calculate actual text length (capped to maximum size) + static constexpr size_t MAX_TEXT_SIZE = 255; + size_t text_length = (static_cast(ret) > MAX_TEXT_SIZE) ? MAX_TEXT_SIZE : ret; + + // Calculate total size needed (header + text length + null terminator) + size_t total_size = message_total_size(text_length); + + // Check if buffer was initialized successfully + if (this->mutex_ == nullptr || this->storage_ == nullptr) { + return false; // Buffer not initialized, fall back to direct output + } + + // Try to acquire mutex without blocking - don't block logging tasks + if (xSemaphoreTake(this->mutex_, 0) != pdTRUE) { + return false; // Mutex busy, fall back to direct output + } + + // Check if we have enough contiguous space + size_t contiguous = this->available_contiguous_space(); + + if (contiguous < total_size) { + // Not enough contiguous space at end + // Check if we can wrap around + size_t space_at_start = (this->head_ >= this->tail_) ? this->tail_ : 0; + if (space_at_start > 0) { + space_at_start--; // Leave 1 byte gap to distinguish full from empty + } + + // Need at least enough space to safely write padding marker (level field is at end of struct) + constexpr size_t PADDING_MARKER_MIN_SPACE = offsetof(LogMessage, level) + 1; + + if (space_at_start >= total_size && this->head_ > 0 && contiguous >= PADDING_MARKER_MIN_SPACE) { + // Add padding marker (set level field to indicate this is padding, not a real message) + LogMessage *padding = reinterpret_cast(this->storage_ + this->head_); + padding->level = PADDING_MARKER_LEVEL; + this->head_ = 0; + } else { + // Not enough space anywhere, or can't safely write padding marker + xSemaphoreGive(this->mutex_); + return false; + } + } + + // Write message header + LogMessage *msg = reinterpret_cast(this->storage_ + this->head_); + msg->level = level; + msg->tag = tag; + msg->line = line; + + // Store the thread name now to avoid crashes if task is deleted before processing + const char *thread_name = pcTaskGetTaskName(task_handle); + if (thread_name != nullptr) { + strncpy(msg->thread_name, thread_name, sizeof(msg->thread_name) - 1); + msg->thread_name[sizeof(msg->thread_name) - 1] = '\0'; + } else { + msg->thread_name[0] = '\0'; + } + + // Format the message text directly into the buffer + char *text_area = msg->text_data(); + ret = vsnprintf(text_area, text_length + 1, format, args); + + if (ret <= 0) { + xSemaphoreGive(this->mutex_); + return false; + } + + // Remove trailing newlines + while (text_length > 0 && text_area[text_length - 1] == '\n') { + text_length--; + } + + msg->text_length = text_length; + + // Advance head + this->head_ += total_size; + + // Handle wrap-around (shouldn't happen due to contiguous space check, but be safe) + if (this->head_ >= this->size_) { + this->head_ = 0; + } + + this->message_count_++; + + xSemaphoreGive(this->mutex_); + return true; +} + +} // namespace esphome::logger + +#endif // USE_ESPHOME_TASK_LOG_BUFFER +#endif // USE_LIBRETINY diff --git a/esphome/components/logger/task_log_buffer_libretiny.h b/esphome/components/logger/task_log_buffer_libretiny.h new file mode 100644 index 0000000000..bf6b2d2fa4 --- /dev/null +++ b/esphome/components/logger/task_log_buffer_libretiny.h @@ -0,0 +1,103 @@ +#pragma once + +#ifdef USE_LIBRETINY + +#include "esphome/core/defines.h" +#include "esphome/core/helpers.h" + +#ifdef USE_ESPHOME_TASK_LOG_BUFFER +#include +#include +#include +#include +#include +#include + +namespace esphome::logger { + +/** + * @brief Task log buffer for LibreTiny platform using mutex-protected circular buffer. + * + * Why This Is Critical: + * Without thread-safe logging, when a non-main task logs a message, it would directly + * call the logger which builds a protobuf message in a shared buffer. If this happens + * while the main loop is also using that buffer (e.g., sending API responses), the + * buffer gets corrupted, sending garbage to all connected API clients and breaking + * their connections. This buffer ensures log messages from other tasks are queued + * safely and processed only from the main loop. + * + * Threading Model: Multi-Producer Single-Consumer (MPSC) + * - Multiple FreeRTOS tasks can safely call send_message_thread_safe() concurrently + * - Only the main loop task calls borrow_message_main_loop() and release_message_main_loop() + * + * This uses a simple circular buffer protected by a FreeRTOS mutex. Unlike ESP32, + * LibreTiny lacks hardware atomic support (ARM968E-S has no LDREX/STREX), so we use + * a volatile counter for fast has_messages() checks instead of atomics. + * + * Design: + * - Variable-size messages with header + text stored contiguously (NOSPLIT style) + * - FreeRTOS mutex protects all buffer operations + * - Volatile counter enables fast has_messages() without lock overhead + * - If message doesn't fit at end, padding is added and message wraps to start + */ +class TaskLogBufferLibreTiny { + public: + // Structure for a log message header (text data follows immediately after) + struct LogMessage { + const char *tag; // We store the pointer, assuming tags are static + char thread_name[16]; // Store thread name directly (only used for non-main threads) + uint16_t text_length; // Length of the message text (up to ~64KB) + uint16_t line; // Source code line number + uint8_t level; // Log level (0-7) + + // Methods for accessing message contents + inline char *text_data() { return reinterpret_cast(this) + sizeof(LogMessage); } + inline const char *text_data() const { return reinterpret_cast(this) + sizeof(LogMessage); } + }; + + // Padding marker level to indicate wrap-around point (stored in LogMessage.level field) + // Valid log levels are 0-7, so 0xFF cannot be a real message + static constexpr uint8_t PADDING_MARKER_LEVEL = 0xFF; + + // Constructor that takes a total buffer size + explicit TaskLogBufferLibreTiny(size_t total_buffer_size); + ~TaskLogBufferLibreTiny(); + + // NOT thread-safe - borrow a message from the buffer, only call from main loop + bool borrow_message_main_loop(LogMessage **message, const char **text); + + // NOT thread-safe - release a message buffer, only call from main loop + void release_message_main_loop(); + + // Thread-safe - send a message to the buffer from any thread + bool send_message_thread_safe(uint8_t level, const char *tag, uint16_t line, TaskHandle_t task_handle, + const char *format, va_list args); + + // Fast check using volatile counter - no lock needed + // Worst case: miss a message for one loop iteration (~8ms at 7000 loops/min) + inline bool HOT has_messages() const { return this->message_count_ != 0; } + + // Get the total buffer size in bytes + inline size_t size() const { return this->size_; } + + private: + // Calculate total size needed for a message (header + text + null terminator) + static inline size_t message_total_size(size_t text_length) { return sizeof(LogMessage) + text_length + 1; } + + // Calculate available contiguous space at write position + size_t available_contiguous_space() const; + + uint8_t *storage_{nullptr}; // Pointer to allocated memory + size_t size_{0}; // Size of allocated memory + size_t head_{0}; // Write position + size_t tail_{0}; // Read position + + SemaphoreHandle_t mutex_{nullptr}; // FreeRTOS mutex for thread safety + volatile uint16_t message_count_{0}; // Fast check counter (dirty read OK) + size_t current_message_size_{0}; // Size of currently borrowed message +}; + +} // namespace esphome::logger + +#endif // USE_ESPHOME_TASK_LOG_BUFFER +#endif // USE_LIBRETINY diff --git a/tests/components/logger/test.bk72xx-ard.yaml b/tests/components/logger/test.bk72xx-ard.yaml new file mode 100644 index 0000000000..c5bc9de6e8 --- /dev/null +++ b/tests/components/logger/test.bk72xx-ard.yaml @@ -0,0 +1,5 @@ +<<: !include common-default_uart.yaml + +logger: + id: logger_id + task_log_buffer_size: 1024B diff --git a/tests/components/logger/test.ln882x-ard.yaml b/tests/components/logger/test.ln882x-ard.yaml new file mode 100644 index 0000000000..c5bc9de6e8 --- /dev/null +++ b/tests/components/logger/test.ln882x-ard.yaml @@ -0,0 +1,5 @@ +<<: !include common-default_uart.yaml + +logger: + id: logger_id + task_log_buffer_size: 1024B diff --git a/tests/components/logger/test.rtl87xx-ard.yaml b/tests/components/logger/test.rtl87xx-ard.yaml new file mode 100644 index 0000000000..c5bc9de6e8 --- /dev/null +++ b/tests/components/logger/test.rtl87xx-ard.yaml @@ -0,0 +1,5 @@ +<<: !include common-default_uart.yaml + +logger: + id: logger_id + task_log_buffer_size: 1024B