From 61eddfdcda506038927aace8d29f43f842ec76c6 Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Sat, 15 Nov 2025 16:47:35 -0600 Subject: [PATCH] [logger] Reduce ESP32 UART mutex overhead by 50% --- esphome/components/logger/__init__.py | 2 ++ esphome/components/logger/logger.cpp | 1 + esphome/components/logger/logger.h | 35 ++++++++++++++++++++-- esphome/components/logger/logger_esp32.cpp | 24 +++++---------- 4 files changed, 43 insertions(+), 19 deletions(-) diff --git a/esphome/components/logger/__init__.py b/esphome/components/logger/__init__.py index cf78e6ae63..39877030e9 100644 --- a/esphome/components/logger/__init__.py +++ b/esphome/components/logger/__init__.py @@ -365,8 +365,10 @@ async def to_code(config): if CORE.is_esp32: if config[CONF_HARDWARE_UART] == USB_CDC: add_idf_sdkconfig_option("CONFIG_ESP_CONSOLE_USB_CDC", True) + cg.add_define("USE_LOGGER_UART_SELECTION_USB_CDC") elif config[CONF_HARDWARE_UART] == USB_SERIAL_JTAG: add_idf_sdkconfig_option("CONFIG_ESP_CONSOLE_USB_SERIAL_JTAG", True) + cg.add_define("USE_LOGGER_UART_SELECTION_USB_SERIAL_JTAG") try: uart_selection(USB_SERIAL_JTAG) cg.add_define("USE_LOGGER_USB_SERIAL_JTAG") diff --git a/esphome/components/logger/logger.cpp b/esphome/components/logger/logger.cpp index 9a9bf89fe3..810b65db2b 100644 --- a/esphome/components/logger/logger.cpp +++ b/esphome/components/logger/logger.cpp @@ -210,6 +210,7 @@ void Logger::process_messages_() { // 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->add_newline_to_buffer_if_needed_(); this->write_msg_(this->tx_buffer_); } } diff --git a/esphome/components/logger/logger.h b/esphome/components/logger/logger.h index dc8e06e0c9..f4f101031f 100644 --- a/esphome/components/logger/logger.h +++ b/esphome/components/logger/logger.h @@ -71,6 +71,16 @@ 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; +// Platform-specific: does write_msg_ add its own newline? +// ESP32: add newline to buffer (write it in one call) +// Zephyr: let printk/uart_poll_out add newline (unchanged behavior) +// Other platforms: println()/puts() adds newline, so skip +#if defined(USE_ESP32) +static constexpr bool WRITE_MSG_ADDS_NEWLINE = false; +#else +static constexpr bool WRITE_MSG_ADDS_NEWLINE = true; +#endif + #if defined(USE_ESP32) || defined(USE_ESP8266) || defined(USE_RP2040) || defined(USE_LIBRETINY) || defined(USE_ZEPHYR) /** Enum for logging UART selection * @@ -200,6 +210,21 @@ class Logger : public Component { } } + // Helper to add newline to buffer for platforms that need it + inline void HOT add_newline_to_buffer_if_needed_() { + if constexpr (!WRITE_MSG_ADDS_NEWLINE) { + // Add newline - don't need to maintain null termination + // write_msg_ uses tx_buffer_at_ as length, not strlen() + if (this->tx_buffer_at_ < this->tx_buffer_size_) { + this->tx_buffer_[this->tx_buffer_at_++] = '\n'; + } else if (this->tx_buffer_size_ > 0) { + // Buffer was full - replace last char with newline + this->tx_buffer_[this->tx_buffer_size_ - 1] = '\n'; + this->tx_buffer_at_ = this->tx_buffer_size_; + } + } + } + // Helper to format and send a log message to both console and callbacks inline void HOT log_message_to_buffer_and_send_(uint8_t level, const char *tag, int line, const char *format, va_list args) { @@ -208,10 +233,14 @@ class Logger : public Component { this->format_log_to_buffer_with_terminator_(level, tag, line, format, args, this->tx_buffer_, &this->tx_buffer_at_, this->tx_buffer_size_); - if (this->baud_rate_ > 0) { - this->write_msg_(this->tx_buffer_); // If logging is enabled, write to console - } + // Callbacks get message WITHOUT newline (for API/MQTT/syslog) this->log_callback_.call(level, tag, this->tx_buffer_, this->tx_buffer_at_); + + // Console gets message WITH newline (if platform needs it) + if (this->baud_rate_ > 0) { + this->add_newline_to_buffer_if_needed_(); + this->write_msg_(this->tx_buffer_); + } } // Write the body of the log message to the buffer diff --git a/esphome/components/logger/logger_esp32.cpp b/esphome/components/logger/logger_esp32.cpp index 7fc79e6f54..7435daebce 100644 --- a/esphome/components/logger/logger_esp32.cpp +++ b/esphome/components/logger/logger_esp32.cpp @@ -122,24 +122,16 @@ void Logger::pre_setup() { } void HOT Logger::write_msg_(const char *msg) { - if ( -#if defined(USE_LOGGER_USB_CDC) && !defined(USE_LOGGER_USB_SERIAL_JTAG) - this->uart_ == UART_SELECTION_USB_CDC -#elif defined(USE_LOGGER_USB_SERIAL_JTAG) && !defined(USE_LOGGER_USB_CDC) - this->uart_ == UART_SELECTION_USB_SERIAL_JTAG -#elif defined(USE_LOGGER_USB_CDC) && defined(USE_LOGGER_USB_SERIAL_JTAG) - this->uart_ == UART_SELECTION_USB_CDC || this->uart_ == UART_SELECTION_USB_SERIAL_JTAG + // Use tx_buffer_at_ if msg points to tx_buffer_, otherwise fall back to strlen + size_t len = (msg == this->tx_buffer_) ? this->tx_buffer_at_ : strlen(msg); + +#if defined(USE_LOGGER_UART_SELECTION_USB_CDC) || defined(USE_LOGGER_UART_SELECTION_USB_SERIAL_JTAG) + // USB CDC/JTAG - single write including newline (already in buffer) + esp_usb_console_write_buf(msg, len); #else - /* DISABLES CODE */ (false) // NOLINT + // Regular UART - single write including newline (already in buffer) + uart_write_bytes(this->uart_num_, msg, len); #endif - ) { - puts(msg); - } else { - // Use tx_buffer_at_ if msg points to tx_buffer_, otherwise fall back to strlen - size_t len = (msg == this->tx_buffer_) ? this->tx_buffer_at_ : strlen(msg); - uart_write_bytes(this->uart_num_, msg, len); - uart_write_bytes(this->uart_num_, "\n", 1); - } } const LogString *Logger::get_uart_selection_() {