diff --git a/esphome/components/logger/__init__.py b/esphome/components/logger/__init__.py index 77a875dd8f..b978aee7a1 100644 --- a/esphome/components/logger/__init__.py +++ b/esphome/components/logger/__init__.py @@ -101,6 +101,7 @@ USB_SERIAL_JTAG = "USB_SERIAL_JTAG" USB_CDC = "USB_CDC" DEFAULT = "DEFAULT" +CONF_BOOT_LOG_BUFFER_SIZE = "boot_log_buffer_size" CONF_INITIAL_LEVEL = "initial_level" CONF_LOGGER_ID = "logger_id" CONF_RUNTIME_TAG_LEVELS = "runtime_tag_levels" @@ -240,6 +241,13 @@ CONFIG_SCHEMA = cv.All( cv.validate_bytes, cv.int_range(min=160, max=65535) ), cv.Optional(CONF_DEASSERT_RTS_DTR, default=False): cv.boolean, + cv.Optional(CONF_BOOT_LOG_BUFFER_SIZE, default=0): cv.All( + cv.validate_bytes, + cv.Any( + cv.int_(0), # Disabled + cv.int_range(min=512, max=16384), + ), + ), cv.SplitDefault( CONF_TASK_LOG_BUFFER_SIZE, esp32=768, # Default: 768 bytes (~5-6 messages with 70-byte text plus thread names) @@ -350,6 +358,11 @@ async def to_code(config: ConfigType) -> None: if task_log_buffer_size > 0: cg.add_define("USE_ESPHOME_TASK_LOG_BUFFER") cg.add_define("ESPHOME_TASK_LOG_BUFFER_SIZE", task_log_buffer_size) + # Boot log buffer captures early WARN/ERROR lines for later replay + # (logger.replay_boot_logs action). Buffer is a direct member of Logger. + if (boot_log_buffer_size := config[CONF_BOOT_LOG_BUFFER_SIZE]) > 0: + cg.add_define("USE_LOGGER_BOOT_LOG_BUFFER") + cg.add_define("ESPHOME_LOGGER_BOOT_LOG_BUFFER_SIZE", boot_log_buffer_size) log = cg.new_Pvariable( config[CONF_ID], baud_rate, @@ -593,6 +606,27 @@ async def logger_set_level_to_code(config, action_id, template_arg, args): ) +@automation.register_action( + "logger.replay_boot_logs", + LambdaAction, + automation.maybe_conf( + CONF_LOGGER_ID, + { + cv.GenerateID(CONF_LOGGER_ID): cv.use_id(Logger), + }, + ), + synchronous=True, +) +async def logger_replay_boot_logs_to_code(config, action_id, template_arg, args): + logger = await cg.get_variable(config[CONF_LOGGER_ID]) + text = str(cg.statement(logger.replay_boot_logs())) + + lambda_ = await cg.process_lambda(Lambda(text), args, return_type=cg.void) + return automation.new_lambda_pvariable( + action_id, lambda_, StatelessLambdaAction, template_arg + ) + + FILTER_SOURCE_FILES = filter_source_files_from_platform( { "logger_esp32.cpp": { diff --git a/esphome/components/logger/logger.cpp b/esphome/components/logger/logger.cpp index 6527b6aa8c..da8750e1ef 100644 --- a/esphome/components/logger/logger.cpp +++ b/esphome/components/logger/logger.cpp @@ -1,5 +1,6 @@ #include "logger.h" #include +#include #include "esphome/core/application.h" #include "esphome/core/hal.h" @@ -202,6 +203,61 @@ void Logger::process_messages_() { } void Logger::set_baud_rate(uint32_t baud_rate) { this->baud_rate_ = baud_rate; } + +#ifdef USE_LOGGER_BOOT_LOG_BUFFER +// Record layout in boot_log_buffer_: u16 text_len | u8 level | u32 millis | text +static constexpr uint16_t BOOT_LOG_RECORD_HEADER_SIZE = 7; + +void Logger::boot_log_capture_(uint8_t level, const LogBuffer &buf) { + if (this->boot_log_done_ || level > ESPHOME_LOG_LEVEL_WARN || level == ESPHOME_LOG_LEVEL_NONE) + return; + // Strip the leading ANSI color prefix and trailing reset; the replay re-emits + // the text through the normal formatter, which colors it again. + const char *text = buf.data; + uint16_t len = buf.pos; + if (len > 0 && text[0] == '\033') { + const char *m = static_cast(memchr(text, 'm', len)); + if (m != nullptr) { + const uint16_t skip = static_cast(m - text) + 1; + text += skip; + len -= skip; + } + } + if (len >= 4 && memcmp(text + len - 4, "\033[0m", 4) == 0) + len -= 4; + if (this->boot_log_pos_ + BOOT_LOG_RECORD_HEADER_SIZE + len > ESPHOME_LOGGER_BOOT_LOG_BUFFER_SIZE) { + this->boot_log_dropped_++; + return; + } + char *p = this->boot_log_buffer_ + this->boot_log_pos_; + const uint32_t now = millis(); + memcpy(p, &len, sizeof(len)); + p[2] = static_cast(level); + memcpy(p + 3, &now, sizeof(now)); + memcpy(p + BOOT_LOG_RECORD_HEADER_SIZE, text, len); + this->boot_log_pos_ += BOOT_LOG_RECORD_HEADER_SIZE + len; +} + +void Logger::replay_boot_logs() { + // Stop capturing first so the replay output is not buffered again. + this->boot_log_done_ = true; + ESP_LOGI(TAG, "Replaying boot logs (%u bytes used, %u lines dropped)", this->boot_log_pos_, this->boot_log_dropped_); + uint16_t pos = 0; + while (pos + BOOT_LOG_RECORD_HEADER_SIZE <= this->boot_log_pos_) { + const char *p = this->boot_log_buffer_ + pos; + uint16_t len; + memcpy(&len, p, sizeof(len)); + uint32_t stamp; + memcpy(&stamp, p + 3, sizeof(stamp)); + esp_log_printf_(static_cast(p[2]), TAG, __LINE__, ESPHOME_LOG_FORMAT("@%" PRIu32 "ms %.*s"), stamp, + static_cast(len), p + BOOT_LOG_RECORD_HEADER_SIZE); + pos += BOOT_LOG_RECORD_HEADER_SIZE + len; + } + ESP_LOGI(TAG, "Boot log replay done"); +} +#else +void Logger::replay_boot_logs() { ESP_LOGW(TAG, "Boot log buffer not configured (set 'boot_log_buffer_size')"); } +#endif // USE_LOGGER_BOOT_LOG_BUFFER #ifdef USE_LOGGER_RUNTIME_TAG_LEVELS void Logger::set_log_level(const char *tag, uint8_t log_level) { this->log_levels_[tag] = log_level; } #endif @@ -239,6 +295,9 @@ void Logger::dump_config() { ESP_LOGCONFIG(TAG, " Task Log Buffer Size: %u bytes", static_cast(this->log_buffer_.size())); #endif #endif +#ifdef USE_LOGGER_BOOT_LOG_BUFFER + ESP_LOGCONFIG(TAG, " Boot Log Buffer Size: %u bytes", ESPHOME_LOGGER_BOOT_LOG_BUFFER_SIZE); +#endif #ifdef USE_LOGGER_RUNTIME_TAG_LEVELS for (auto &it : this->log_levels_) { diff --git a/esphome/components/logger/logger.h b/esphome/components/logger/logger.h index 69d8e6d32a..fb5bdcc07b 100644 --- a/esphome/components/logger/logger.h +++ b/esphome/components/logger/logger.h @@ -174,6 +174,12 @@ class Logger final : public Component { #endif uint8_t get_log_level() { return this->current_level_; } + /// Re-emit WARN/ERROR messages captured during boot through the normal log + /// dispatch so connected listeners (API, MQTT, ...) can see them. Stops + /// further capture; safe to call multiple times. Warns when the logger was + /// built without 'boot_log_buffer_size'. + void replay_boot_logs(); + // ========== INTERNAL METHODS ========== // (In most use cases you won't need these) /// Set up this component. @@ -291,6 +297,9 @@ class Logger final : public Component { { this->format_log_to_buffer_with_terminator_(level, tag, line, format, args, buf, thread_name); } +#ifdef USE_LOGGER_BOOT_LOG_BUFFER + this->boot_log_capture_(level, buf); +#endif this->notify_listeners_(level, tag, buf); this->write_log_buffer_to_console_(buf); } @@ -303,6 +312,9 @@ class Logger final : public Component { LogBuffer &buf) { buf.write_header(level, tag, line, thread_name); buf.write_body(text, text_length); +#ifdef USE_LOGGER_BOOT_LOG_BUFFER + this->boot_log_capture_(level, buf); +#endif this->notify_listeners_(level, tag, buf); } #endif @@ -311,6 +323,11 @@ class Logger final : public Component { const LogString *get_uart_selection_(); #endif +#ifdef USE_LOGGER_BOOT_LOG_BUFFER + /// Copy a formatted WARN/ERROR line (ANSI codes stripped) into the boot log buffer. + void boot_log_capture_(uint8_t level, const LogBuffer &buf); +#endif + // Group 4-byte aligned members first uint32_t baud_rate_; #if defined(USE_ARDUINO) && !defined(USE_ESP32) @@ -350,6 +367,11 @@ class Logger final : public Component { std::vector level_listeners_; // Log level change listeners #endif // Group smaller types together at the end +#ifdef USE_LOGGER_BOOT_LOG_BUFFER + uint16_t boot_log_pos_{0}; // Bytes used in boot_log_buffer_ + uint16_t boot_log_dropped_{0}; // Lines that did not fit + bool boot_log_done_{false}; // Set on first replay; stops further capture +#endif uint8_t current_level_{ESPHOME_LOG_LEVEL_VERY_VERBOSE}; #if defined(USE_ESP32) || defined(USE_ESP8266) || defined(USE_RP2) || defined(USE_ZEPHYR) UARTSelection uart_{UART_SELECTION_UART0}; @@ -368,6 +390,10 @@ class Logger final : public Component { // Large buffers placed last to keep frequently-accessed member offsets small char tx_buffer_[ESPHOME_LOGGER_TX_BUFFER_SIZE + 1]; // +1 for null terminator +#ifdef USE_LOGGER_BOOT_LOG_BUFFER + // Sequential records of early WARN/ERROR lines: u16 text_len | u8 level | u32 millis | text + char boot_log_buffer_[ESPHOME_LOGGER_BOOT_LOG_BUFFER_SIZE]; +#endif #ifdef USE_ESPHOME_TASK_LOG_BUFFER logger::TaskLogBuffer log_buffer_; // Embedded in Logger (no separate heap allocation) #endif diff --git a/esphome/core/defines.h b/esphome/core/defines.h index 61de97ca74..05548464bb 100644 --- a/esphome/core/defines.h +++ b/esphome/core/defines.h @@ -38,6 +38,8 @@ #define ESPHOME_LOGGER_TX_BUFFER_SIZE 512 #define USE_LOG_LISTENERS #define ESPHOME_LOG_MAX_LISTENERS 8 +#define USE_LOGGER_BOOT_LOG_BUFFER +#define ESPHOME_LOGGER_BOOT_LOG_BUFFER_SIZE 4096 // Feature flags #define USE_ALARM_CONTROL_PANEL diff --git a/tests/components/logger/test-boot_log_buffer.esp32-idf.yaml b/tests/components/logger/test-boot_log_buffer.esp32-idf.yaml new file mode 100644 index 0000000000..f61c02f1e5 --- /dev/null +++ b/tests/components/logger/test-boot_log_buffer.esp32-idf.yaml @@ -0,0 +1,13 @@ +<<: !include common-default_uart.yaml + +esphome: + on_boot: + then: + - logger.log: + level: warn + format: "Early boot warning for replay" + - logger.replay_boot_logs: logger_id + +logger: + id: logger_id + boot_log_buffer_size: 2kB diff --git a/tests/components/logger/test-boot_log_buffer.esp8266-ard.yaml b/tests/components/logger/test-boot_log_buffer.esp8266-ard.yaml new file mode 100644 index 0000000000..5584d7b8c7 --- /dev/null +++ b/tests/components/logger/test-boot_log_buffer.esp8266-ard.yaml @@ -0,0 +1,13 @@ +<<: !include common-default_uart.yaml + +esphome: + on_boot: + then: + - logger.log: + level: warn + format: "Early boot warning for replay" + - logger.replay_boot_logs: + +logger: + id: logger_id + boot_log_buffer_size: 2kB