diff --git a/esphome/components/logger/__init__.py b/esphome/components/logger/__init__.py index 40ceaec7dc6..8de52db0cb9 100644 --- a/esphome/components/logger/__init__.py +++ b/esphome/components/logger/__init__.py @@ -231,9 +231,16 @@ CONFIG_SCHEMA = cv.All( bk72xx=768, ln882x=768, rtl87xx=768, + nrf52=768, ): cv.All( cv.only_on( - [PLATFORM_ESP32, PLATFORM_BK72XX, PLATFORM_LN882X, PLATFORM_RTL87XX] + [ + PLATFORM_ESP32, + PLATFORM_BK72XX, + PLATFORM_LN882X, + PLATFORM_RTL87XX, + PLATFORM_NRF52, + ] ), cv.validate_bytes, cv.Any( @@ -313,11 +320,14 @@ async def to_code(config): ) if CORE.is_esp32: cg.add(log.create_pthread_key()) - if CORE.is_esp32 or CORE.is_libretiny: + if CORE.is_esp32 or CORE.is_libretiny or CORE.is_nrf52: task_log_buffer_size = config[CONF_TASK_LOG_BUFFER_SIZE] if task_log_buffer_size > 0: cg.add_define("USE_ESPHOME_TASK_LOG_BUFFER") cg.add(log.init_log_buffer(task_log_buffer_size)) + if CORE.using_zephyr: + zephyr_add_prj_conf("THREAD_LOCAL_STORAGE", True) + zephyr_add_prj_conf("MPSC_PBUF", True) elif CORE.is_host: cg.add(log.create_pthread_key()) cg.add_define("USE_ESPHOME_TASK_LOG_BUFFER") diff --git a/esphome/components/logger/logger.cpp b/esphome/components/logger/logger.cpp index 4cbd4f1bf1b..63f04ff2c85 100644 --- a/esphome/components/logger/logger.cpp +++ b/esphome/components/logger/logger.cpp @@ -10,7 +10,7 @@ namespace esphome::logger { static const char *const TAG = "logger"; -#if defined(USE_ESP32) || defined(USE_HOST) || defined(USE_LIBRETINY) +#if defined(USE_ESP32) || defined(USE_HOST) || defined(USE_LIBRETINY) || defined(USE_ZEPHYR) // 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 // @@ -31,6 +31,9 @@ void HOT Logger::log_vprintf_(uint8_t level, const char *tag, int line, const ch // Get task handle once - used for both main task check and passing to non-main thread handler TaskHandle_t current_task = xTaskGetCurrentTaskHandle(); const bool is_main_task = (current_task == this->main_task_); +#elif (USE_ZEPHYR) + k_tid_t current_task = k_current_get(); + const bool is_main_task = (current_task == this->main_task_); #else // USE_HOST const bool is_main_task = pthread_equal(pthread_self(), this->main_thread_); #endif @@ -47,7 +50,7 @@ void HOT Logger::log_vprintf_(uint8_t level, const char *tag, int line, const ch } // Non-main thread handling (~0.1% of logs) -#if defined(USE_ESP32) || defined(USE_LIBRETINY) +#if defined(USE_ESP32) || defined(USE_LIBRETINY) || defined(USE_ZEPHYR) 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); @@ -56,12 +59,13 @@ void HOT Logger::log_vprintf_(uint8_t level, const char *tag, int line, const ch // Handles non-main thread logging only // Kept separate from hot path to improve instruction cache performance -#if defined(USE_ESP32) || defined(USE_LIBRETINY) +#if defined(USE_ESP32) || defined(USE_LIBRETINY) || defined(USE_ZEPHYR) 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) { + void *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) { +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; @@ -73,7 +77,7 @@ void Logger::log_vprintf_non_main_thread_(uint8_t level, const char *tag, int li bool message_sent = false; #ifdef USE_ESPHOME_TASK_LOG_BUFFER // For non-main threads/tasks, queue the message for callbacks -#if defined(USE_ESP32) || defined(USE_LIBRETINY) +#if defined(USE_ESP32) || defined(USE_LIBRETINY) || defined(USE_ZEPHYR) message_sent = this->log_buffer_->send_message_thread_safe(level, tag, static_cast(line), current_task, format, args); #else // USE_HOST @@ -91,11 +95,15 @@ void Logger::log_vprintf_non_main_thread_(uint8_t level, const char *tag, int li // Note: This may cause interleaved/corrupted console output if multiple threads // log simultaneously, but it's better than losing important messages entirely #ifdef USE_HOST - if (!message_sent) { + if (!message_sent) +#else + if (!message_sent && this->baud_rate_ > 0) // If logging is enabled, write to console +#endif + { +#ifdef USE_HOST // Host always has console output - no baud_rate check needed static const size_t MAX_CONSOLE_LOG_MSG_SIZE = 512; #else - 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; #endif @@ -166,9 +174,12 @@ void Logger::init_log_buffer(size_t total_buffer_size) { #elif defined(USE_LIBRETINY) // NOLINTNEXTLINE(cppcoreguidelines-owning-memory) - allocated once, never freed this->log_buffer_ = new logger::TaskLogBufferLibreTiny(total_buffer_size); +#elif defined(USE_ZEPHYR) + // NOLINTNEXTLINE(cppcoreguidelines-owning-memory) - allocated once, never freed + this->log_buffer_ = new logger::TaskLogBufferZephyr(total_buffer_size); #endif -#if defined(USE_ESP32) || defined(USE_LIBRETINY) +#if defined(USE_ESP32) || defined(USE_LIBRETINY) || (defined(USE_ZEPHYR) && !defined(USE_LOGGER_USB_CDC)) // Start with loop disabled when using task buffer (unless using USB CDC on ESP32) // The loop will be enabled automatically when messages arrive this->disable_loop_when_buffer_empty_(); @@ -176,8 +187,13 @@ void Logger::init_log_buffer(size_t total_buffer_size) { } #endif -#ifdef USE_ESPHOME_TASK_LOG_BUFFER -void Logger::loop() { this->process_messages_(); } +#if defined(USE_ESPHOME_TASK_LOG_BUFFER) || (defined(USE_ZEPHYR) && defined(USE_LOGGER_USB_CDC)) +void Logger::loop() { + this->process_messages_(); +#if defined(USE_ZEPHYR) && defined(USE_LOGGER_USB_CDC) + this->cdc_loop_(); +#endif +} #endif void Logger::process_messages_() { @@ -194,21 +210,14 @@ void Logger::process_messages_() { this->log_buffer_->release_message_main_loop(); this->write_log_buffer_to_console_(buf); } -#elif defined(USE_ESP32) +#elif defined(USE_ESP32) || defined(USE_LIBRETINY) || defined(USE_ZEPHYR) +#ifdef USE_ESP32 logger::TaskLogBuffer::LogMessage *message; - const char *text; - void *received_token; - while (this->log_buffer_->borrow_message_main_loop(&message, &text, &received_token)) { - const char *thread_name = message->thread_name[0] != '\0' ? message->thread_name : nullptr; - LogBuffer buf{this->tx_buffer_, this->tx_buffer_size_}; - this->format_buffered_message_and_notify_(message->level, message->tag, message->line, thread_name, text, - message->text_length, buf); - // Release the message to allow other tasks to use it as soon as possible - this->log_buffer_->release_message_main_loop(received_token); - this->write_log_buffer_to_console_(buf); - } #elif defined(USE_LIBRETINY) logger::TaskLogBufferLibreTiny::LogMessage *message; +#else + logger::TaskLogBufferZephyr::LogMessage *message; +#endif 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; @@ -221,7 +230,7 @@ void Logger::process_messages_() { } #endif } -#if defined(USE_ESP32) || defined(USE_LIBRETINY) +#if defined(USE_ESP32) || defined(USE_LIBRETINY) || (defined(USE_ZEPHYR) && !defined(USE_LOGGER_USB_CDC)) else { // No messages to process, disable loop if appropriate // This reduces overhead when there's no async logging activity diff --git a/esphome/components/logger/logger.h b/esphome/components/logger/logger.h index 1678fed5f5e..88a16583d2c 100644 --- a/esphome/components/logger/logger.h +++ b/esphome/components/logger/logger.h @@ -19,6 +19,8 @@ #include "task_log_buffer_esp32.h" #elif defined(USE_LIBRETINY) #include "task_log_buffer_libretiny.h" +#elif defined(USE_ZEPHYR) +#include "task_log_buffer_zephyr.h" #endif #endif @@ -121,9 +123,6 @@ static constexpr char LOG_LEVEL_LETTER_CHARS[] = { // Maximum header size: 35 bytes fixed + 32 bytes tag + 16 bytes thread name = 83 bytes (45 byte safety margin) static constexpr uint16_t MAX_HEADER_SIZE = 128; -// "0x" + 2 hex digits per byte + '\0' -static constexpr size_t MAX_POINTER_REPRESENTATION = 2 + sizeof(void *) * 2 + 1; - // Buffer wrapper for log formatting functions struct LogBuffer { char *data; @@ -406,17 +405,18 @@ class Logger : public Component { bool &flag_; }; -#if defined(USE_ESP32) || defined(USE_HOST) || defined(USE_LIBRETINY) +#if defined(USE_ESP32) || defined(USE_HOST) || defined(USE_LIBRETINY) || defined(USE_ZEPHYR) // Handles non-main thread logging only (~0.1% of calls) -#if defined(USE_ESP32) || defined(USE_LIBRETINY) +#if defined(USE_ESP32) || defined(USE_LIBRETINY) || defined(USE_ZEPHYR) // 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); + void *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 cdc_loop_(); void process_messages_(); void write_msg_(const char *msg, uint16_t len); @@ -544,6 +544,8 @@ class Logger : public Component { logger::TaskLogBuffer *log_buffer_{nullptr}; // Allocated once, never freed #elif defined(USE_LIBRETINY) logger::TaskLogBufferLibreTiny *log_buffer_{nullptr}; // Allocated once, never freed +#elif defined(USE_ZEPHYR) + logger::TaskLogBufferZephyr *log_buffer_{nullptr}; // Allocated once, never freed #endif #endif @@ -556,7 +558,7 @@ class Logger : public Component { #ifdef USE_LIBRETINY UARTSelection uart_{UART_SELECTION_DEFAULT}; #endif -#if defined(USE_ESP32) || defined(USE_HOST) || defined(USE_LIBRETINY) +#if defined(USE_ESP32) || defined(USE_HOST) || defined(USE_LIBRETINY) || USE_ZEPHYR 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 @@ -619,7 +621,7 @@ class Logger : public Component { // Create RAII guard for non-main task recursion inline NonMainTaskRecursionGuard make_non_main_task_guard_() { return NonMainTaskRecursionGuard(log_recursion_key_); } -#elif defined(USE_LIBRETINY) +#elif defined(USE_LIBRETINY) || defined(USE_ZEPHYR) // 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 @@ -627,6 +629,7 @@ class Logger : public Component { // - 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) + // Zephyr use __thread as TLS // Check if non-main task is already in recursion inline bool HOT is_non_main_task_recursive_() const { return non_main_task_recursion_guard_; } @@ -651,7 +654,7 @@ class Logger : public Component { } #endif -#if defined(USE_ESP32) || defined(USE_LIBRETINY) +#if defined(USE_ESP32) || defined(USE_LIBRETINY) || (defined(USE_ZEPHYR) && !defined(USE_LOGGER_USB_CDC)) // Disable loop when task buffer is empty (with USB CDC check on ESP32) inline void disable_loop_when_buffer_empty_() { // Thread safety note: This is safe even if another task calls enable_loop_soon_any_context() diff --git a/esphome/components/logger/logger_zephyr.cpp b/esphome/components/logger/logger_zephyr.cpp index ef1702c5c1c..ae649249b25 100644 --- a/esphome/components/logger/logger_zephyr.cpp +++ b/esphome/components/logger/logger_zephyr.cpp @@ -14,7 +14,7 @@ namespace esphome::logger { static const char *const TAG = "logger"; #ifdef USE_LOGGER_USB_CDC -void Logger::loop() { +void Logger::cdc_loop_() { if (this->uart_ != UART_SELECTION_USB_CDC || this->uart_dev_ == nullptr) { return; } diff --git a/esphome/components/logger/task_log_buffer_esp32.cpp b/esphome/components/logger/task_log_buffer_esp32.cpp index b9dfe45b7fa..90c0161ac8a 100644 --- a/esphome/components/logger/task_log_buffer_esp32.cpp +++ b/esphome/components/logger/task_log_buffer_esp32.cpp @@ -31,8 +31,8 @@ TaskLogBuffer::~TaskLogBuffer() { } } -bool TaskLogBuffer::borrow_message_main_loop(LogMessage **message, const char **text, void **received_token) { - if (message == nullptr || text == nullptr || received_token == nullptr) { +bool TaskLogBuffer::borrow_message_main_loop(LogMessage **message, const char **text) { + if (message == nullptr || text == nullptr || this->current_token_) { return false; } @@ -45,16 +45,17 @@ bool TaskLogBuffer::borrow_message_main_loop(LogMessage **message, const char ** LogMessage *msg = static_cast(received_item); *message = msg; *text = msg->text_data(); - *received_token = received_item; + this->current_token_ = received_item; return true; } -void TaskLogBuffer::release_message_main_loop(void *token) { - if (token == nullptr) { +void TaskLogBuffer::release_message_main_loop() { + if (this->current_token_ == nullptr) { return; } - vRingbufferReturnItem(ring_buffer_, token); + vRingbufferReturnItem(ring_buffer_, this->current_token_); + this->current_token_ = nullptr; // Update counter to mark all messages as processed last_processed_counter_ = message_counter_.load(std::memory_order_relaxed); } diff --git a/esphome/components/logger/task_log_buffer_esp32.h b/esphome/components/logger/task_log_buffer_esp32.h index fde9bd60d5e..e3103a8d345 100644 --- a/esphome/components/logger/task_log_buffer_esp32.h +++ b/esphome/components/logger/task_log_buffer_esp32.h @@ -52,10 +52,10 @@ class TaskLogBuffer { ~TaskLogBuffer(); // NOT thread-safe - borrow a message from the ring buffer, only call from main loop - bool borrow_message_main_loop(LogMessage **message, const char **text, void **received_token); + bool borrow_message_main_loop(LogMessage **message, const char **text); // NOT thread-safe - release a message buffer and update the counter, only call from main loop - void release_message_main_loop(void *token); + void release_message_main_loop(); // Thread-safe - send a message to the ring buffer from any thread bool send_message_thread_safe(uint8_t level, const char *tag, uint16_t line, TaskHandle_t task_handle, @@ -78,6 +78,7 @@ class TaskLogBuffer { // Atomic counter for message tracking (only differences matter) std::atomic message_counter_{0}; // Incremented when messages are committed mutable uint16_t last_processed_counter_{0}; // Tracks last processed message + void *current_token_{nullptr}; }; } // namespace esphome::logger diff --git a/esphome/components/logger/task_log_buffer_zephyr.cpp b/esphome/components/logger/task_log_buffer_zephyr.cpp new file mode 100644 index 00000000000..b788f777d83 --- /dev/null +++ b/esphome/components/logger/task_log_buffer_zephyr.cpp @@ -0,0 +1,108 @@ +#ifdef USE_ZEPHYR + +#include "task_log_buffer_zephyr.h" + +namespace esphome::logger { + +__thread bool non_main_task_recursion_guard_; + +TaskLogBufferZephyr::TaskLogBufferZephyr(size_t total_buffer_size) { + // alignment to 4 bytes + total_buffer_size = (total_buffer_size + 3) / sizeof(uint32_t); + this->mpsc_config_.buf = new uint32_t[total_buffer_size]; + this->mpsc_config_.size = total_buffer_size; + this->mpsc_config_.flags = MPSC_PBUF_MODE_OVERWRITE; + // .get_wlen = log_msg_generic_get_wlen, + + mpsc_pbuf_init(&this->log_buffer_, &this->mpsc_config_); +} + +TaskLogBufferZephyr::~TaskLogBufferZephyr() { delete[] this->mpsc_config_.buf; } + +bool TaskLogBufferZephyr::send_message_thread_safe(uint8_t level, const char *tag, uint16_t line, void *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 in 32-bit words needed (header + text length + null terminator + 3(4 bytes alignment) + size_t total_size = (sizeof(LogMessage) + text_length + 1 + 3) / sizeof(uint32_t); + auto msg = reinterpret_cast(mpsc_pbuf_alloc(&this->log_buffer_, total_size, K_NO_WAIT)); + if (nullptr == msg) { + return false; + } + msg->level = level; + msg->tag = tag; + msg->line = line; + const char *thread_name = k_thread_name_get(static_cast(task_handle)); + if (thread_name) { + strncpy(msg->thread_name, thread_name, sizeof(msg->thread_name) - 1); + } else { + std::snprintf(msg->thread_name, MAX_POINTER_REPRESENTATION, "%p", task_handle); + } + + // Format the message text directly into the acquired memory + // We add 1 to text_length to ensure space for null terminator during formatting + char *text_area = msg->text_data(); + ret = vsnprintf(text_area, text_length + 1, format, args); + + // Handle unexpected formatting error + if (ret <= 0) { + // this shall not happened vsnprintf was called already once + // fill with '\n' to not call mpsc_pbuf_free from producer + // it will be trimmed anyway + for (uint16_t i = 0; i < text_length; ++i) { + text_area[i] = '\n'; + } + text_area[text_length] = 0; + } + + msg->text_length = text_length; + + mpsc_pbuf_commit(&this->log_buffer_, reinterpret_cast(msg)); + return true; +} + +bool TaskLogBufferZephyr::borrow_message_main_loop(LogMessage **message, const char **text) { + if (this->current_token_) { + return false; + } + + this->current_token_ = mpsc_pbuf_claim(&this->log_buffer_); + + if (nullptr == this->current_token_) { + return false; + } + + // we claimed buffer alraedy const_cast is safe here + *message = const_cast(reinterpret_cast(this->current_token_)); + + *text = (*message)->text_data(); + + // Remove trailing newlines + while ((*message)->text_length > 0 && *text[(*message)->text_length - 1] == '\n') { + (*message)->text_length--; + } + + return true; +} + +void TaskLogBufferZephyr::release_message_main_loop() { + if (this->current_token_ == nullptr) { + return; + } + mpsc_pbuf_free(&this->log_buffer_, this->current_token_); + this->current_token_ = nullptr; +} +} // namespace esphome::logger + +#endif diff --git a/esphome/components/logger/task_log_buffer_zephyr.h b/esphome/components/logger/task_log_buffer_zephyr.h new file mode 100644 index 00000000000..12e5f4ca34d --- /dev/null +++ b/esphome/components/logger/task_log_buffer_zephyr.h @@ -0,0 +1,64 @@ +#pragma once + +#ifdef USE_ZEPHYR + +#include "esphome/core/defines.h" +#include "esphome/core/helpers.h" +#include + +namespace esphome::logger { + +// "0x" + 2 hex digits per byte + '\0' +static constexpr size_t MAX_POINTER_REPRESENTATION = 2 + sizeof(void *) * 2 + 1; + +extern __thread bool non_main_task_recursion_guard_; + +class TaskLogBufferZephyr { + public: + // Structure for a log message header (text data follows immediately after) + struct LogMessage { + MPSC_PBUF_HDR; // this is only 2 bits put not more that 30 bits directly after + uint16_t line; // Source code line number + uint8_t level; // Log level (0-7) +#if defined(CONFIG_THREAD_NAME) + char thread_name[CONFIG_THREAD_MAX_NAME_LEN]; // Store thread name directly (only used for non-main threads) +#else + char thread_name[MAX_POINTER_REPRESENTATION]; // Store thread name directly (only used for non-main threads) +#endif + const char *tag; // We store the pointer, assuming tags are static + uint16_t text_length; // Length of the message text (up to ~64KB) + + // 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); } + }; + // Constructor that takes a total buffer size + explicit TaskLogBufferZephyr(size_t total_buffer_size); + ~TaskLogBufferZephyr(); + + // Check if there are messages ready to be processed using an atomic counter for performance + inline bool HOT has_messages() { return mpsc_pbuf_is_pending(&this->log_buffer_); } + + // Get the total buffer size in bytes + inline size_t size() const { return this->mpsc_config_.size * sizeof(uint32_t); } + + // NOT thread-safe - borrow a message from the ring buffer, only call from main loop + bool borrow_message_main_loop(LogMessage **message, const char **text); + + // NOT thread-safe - release a message buffer and update the counter, only call from main loop + void release_message_main_loop(); + + // Thread-safe - send a message to the ring buffer from any thread + bool send_message_thread_safe(uint8_t level, const char *tag, uint16_t line, void *task_handle, const char *format, + va_list args); + + protected: + mpsc_pbuf_buffer_config mpsc_config_{}; + mpsc_pbuf_buffer log_buffer_{}; + const mpsc_pbuf_generic *current_token_{}; +}; + +} // namespace esphome::logger + +#endif