From abac07d6764db0d3bf273917ace1252bf0f7785e Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Sat, 26 Jul 2025 16:28:48 -1000 Subject: [PATCH] Avoid strlen for logger on all platforms that support it --- esphome/components/logger/logger.cpp | 10 +++++----- esphome/components/logger/logger.h | 4 ++-- esphome/components/logger/logger_esp32.cpp | 18 ++++++++++++++---- esphome/components/logger/logger_esp8266.cpp | 8 +++++++- esphome/components/logger/logger_host.cpp | 2 +- esphome/components/logger/logger_libretiny.cpp | 8 +++++++- esphome/components/logger/logger_rp2040.cpp | 8 +++++++- esphome/components/logger/logger_zephyr.cpp | 7 +++---- 8 files changed, 46 insertions(+), 19 deletions(-) diff --git a/esphome/components/logger/logger.cpp b/esphome/components/logger/logger.cpp index 195e04948d..7bc8e0f8a2 100644 --- a/esphome/components/logger/logger.cpp +++ b/esphome/components/logger/logger.cpp @@ -65,7 +65,7 @@ void HOT Logger::log_vprintf_(uint8_t level, const char *tag, int line, const ch uint16_t buffer_at = 0; // Initialize buffer position this->format_log_to_buffer_with_terminator_(level, tag, line, format, args, console_buffer, &buffer_at, MAX_CONSOLE_LOG_MSG_SIZE); - this->write_msg_(console_buffer); + this->write_msg_(console_buffer, buffer_at); } // Reset the recursion guard for this task @@ -136,11 +136,11 @@ void Logger::log_vprintf_(uint8_t level, const char *tag, int line, const __Flas &this->tx_buffer_at_, this->tx_buffer_size_); // Write to console and send callback starting at the msg_start - if (this->baud_rate_ > 0) { - this->write_msg_(this->tx_buffer_ + msg_start); - } size_t msg_length = this->tx_buffer_at_ - msg_start; // Don't subtract 1 - tx_buffer_at_ is already at the null terminator position + if (this->baud_rate_ > 0) { + this->write_msg_(this->tx_buffer_ + msg_start, msg_length); + } this->log_callback_.call(level, tag, this->tx_buffer_ + msg_start, msg_length); global_recursion_guard_ = false; @@ -224,7 +224,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->write_msg_(this->tx_buffer_); + this->write_msg_(this->tx_buffer_, msg_len); } } } else { diff --git a/esphome/components/logger/logger.h b/esphome/components/logger/logger.h index aa76a188c9..d7cac229d8 100644 --- a/esphome/components/logger/logger.h +++ b/esphome/components/logger/logger.h @@ -161,7 +161,7 @@ class Logger : public Component { protected: void process_messages_(); - void write_msg_(const char *msg); + void write_msg_(const char *msg, size_t len); // Format a log message with printf-style arguments and write it to a buffer with header, footer, and null terminator // It's the caller's responsibility to initialize buffer_at (typically to 0) @@ -194,7 +194,7 @@ class Logger : public Component { this->tx_buffer_size_); if (this->baud_rate_ > 0) { - this->write_msg_(this->tx_buffer_); // If logging is enabled, write to console + this->write_msg_(this->tx_buffer_, this->tx_buffer_at_); // If logging is enabled, write to console } this->log_callback_.call(level, tag, this->tx_buffer_, this->tx_buffer_at_); } diff --git a/esphome/components/logger/logger_esp32.cpp b/esphome/components/logger/logger_esp32.cpp index 44243d4aa8..85ffc72f24 100644 --- a/esphome/components/logger/logger_esp32.cpp +++ b/esphome/components/logger/logger_esp32.cpp @@ -166,7 +166,7 @@ void Logger::pre_setup() { } #ifdef USE_ESP_IDF -void HOT Logger::write_msg_(const char *msg) { +void HOT Logger::write_msg_(const char *msg, size_t len) { if ( #if defined(USE_LOGGER_USB_CDC) && !defined(USE_LOGGER_USB_SERIAL_JTAG) this->uart_ == UART_SELECTION_USB_CDC @@ -178,16 +178,26 @@ void HOT Logger::write_msg_(const char *msg) { /* DISABLES CODE */ (false) // NOLINT #endif ) { + // For USB CDC/Serial JTAG, we use puts() which adds '\n' automatically. + // This is safe because the buffer is always null-terminated by format_log_to_buffer_with_terminator_. + // The VFS layer handles newline conversion (adding '\r' if configured) in its write function. + // While puts() likely calculates strlen internally, the VFS write function already processes + // character-by-character for newline conversion, so using puts() is efficient here. 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); + // ESP-IDF uses only '\n' for historical reasons, while Arduino platforms use '\r\n' uart_write_bytes(this->uart_num_, "\n", 1); } } #else -void HOT Logger::write_msg_(const char *msg) { this->hw_serial_->println(msg); } +void HOT Logger::write_msg_(const char *msg, size_t len) { + // Arduino's println() writes the message followed by "\r\n" (CRLF). + // Previously, println() would call write(msg) which uses strlen() internally. + // By using write(buffer, size) directly, we avoid the strlen() call. + this->hw_serial_->write(reinterpret_cast(msg), len); + this->hw_serial_->write(reinterpret_cast("\r\n"), 2); +} #endif const char *const UART_SELECTIONS[] = { diff --git a/esphome/components/logger/logger_esp8266.cpp b/esphome/components/logger/logger_esp8266.cpp index fb5f6cee5d..b199dbcd59 100644 --- a/esphome/components/logger/logger_esp8266.cpp +++ b/esphome/components/logger/logger_esp8266.cpp @@ -33,7 +33,13 @@ void Logger::pre_setup() { ESP_LOGI(TAG, "Log initialized"); } -void HOT Logger::write_msg_(const char *msg) { this->hw_serial_->println(msg); } +void HOT Logger::write_msg_(const char *msg, size_t len) { + // Arduino's println() writes the message followed by "\r\n" (CRLF). + // Previously, println() would call write(msg) which uses strlen() internally. + // By using write(buffer, size) directly, we avoid the strlen() call. + this->hw_serial_->write(reinterpret_cast(msg), len); + this->hw_serial_->write(reinterpret_cast("\r\n"), 2); +} const char *const UART_SELECTIONS[] = {"UART0", "UART1", "UART0_SWAP"}; diff --git a/esphome/components/logger/logger_host.cpp b/esphome/components/logger/logger_host.cpp index 4abe92286a..f7b665c69e 100644 --- a/esphome/components/logger/logger_host.cpp +++ b/esphome/components/logger/logger_host.cpp @@ -3,7 +3,7 @@ namespace esphome::logger { -void HOT Logger::write_msg_(const char *msg) { +void HOT Logger::write_msg_(const char *msg, size_t len) { time_t rawtime; struct tm *timeinfo; char buffer[80]; diff --git a/esphome/components/logger/logger_libretiny.cpp b/esphome/components/logger/logger_libretiny.cpp index 09d0622bc3..cd1edf807b 100644 --- a/esphome/components/logger/logger_libretiny.cpp +++ b/esphome/components/logger/logger_libretiny.cpp @@ -49,7 +49,13 @@ void Logger::pre_setup() { ESP_LOGI(TAG, "Log initialized"); } -void HOT Logger::write_msg_(const char *msg) { this->hw_serial_->println(msg); } +void HOT Logger::write_msg_(const char *msg, size_t len) { + // Arduino's println() writes the message followed by "\r\n" (CRLF). + // Previously, println() would call write(msg) which uses strlen() internally. + // By using write(buffer, size) directly, we avoid the strlen() call. + this->hw_serial_->write(reinterpret_cast(msg), len); + this->hw_serial_->write(reinterpret_cast("\r\n"), 2); +} const char *const UART_SELECTIONS[] = {"DEFAULT", "UART0", "UART1", "UART2"}; diff --git a/esphome/components/logger/logger_rp2040.cpp b/esphome/components/logger/logger_rp2040.cpp index f1cad9b283..a280013124 100644 --- a/esphome/components/logger/logger_rp2040.cpp +++ b/esphome/components/logger/logger_rp2040.cpp @@ -27,7 +27,13 @@ void Logger::pre_setup() { ESP_LOGI(TAG, "Log initialized"); } -void HOT Logger::write_msg_(const char *msg) { this->hw_serial_->println(msg); } +void HOT Logger::write_msg_(const char *msg, size_t len) { + // Arduino's println() writes the message followed by "\r\n" (CRLF). + // Previously, println() would call write(msg) which uses strlen() internally. + // By using write(buffer, size) directly, we avoid the strlen() call. + this->hw_serial_->write(reinterpret_cast(msg), len); + this->hw_serial_->write(reinterpret_cast("\r\n"), 2); +} const char *const UART_SELECTIONS[] = {"UART0", "UART1", "USB_CDC"}; diff --git a/esphome/components/logger/logger_zephyr.cpp b/esphome/components/logger/logger_zephyr.cpp index 58a09facd5..b5a551868a 100644 --- a/esphome/components/logger/logger_zephyr.cpp +++ b/esphome/components/logger/logger_zephyr.cpp @@ -63,16 +63,15 @@ void Logger::pre_setup() { ESP_LOGI(TAG, "Log initialized"); } -void HOT Logger::write_msg_(const char *msg) { +void HOT Logger::write_msg_(const char *msg, size_t len) { #ifdef CONFIG_PRINTK printk("%s\n", msg); #endif if (nullptr == this->uart_dev_) { return; } - while (*msg) { - uart_poll_out(this->uart_dev_, *msg); - ++msg; + for (size_t i = 0; i < len; i++) { + uart_poll_out(this->uart_dev_, msg[i]); } uart_poll_out(this->uart_dev_, '\n'); }