Compare commits

...
Author SHA1 Message Date
J. Nick Koston ea078bd9a4 Merge remote-tracking branch 'origin/dev' into logger-boot-log-buffer
# Conflicts:
#	esphome/components/logger/logger.cpp
2026-10-14 10:43:22 -10:00
J. Nick Koston 47f5c28925 Merge remote-tracking branch 'origin/dev' into logger-boot-log-buffer 2026-10-14 10:39:33 -10:00
J. Nick Koston 75aaeec28f Trailing underscore on the protected test helpers 2026-10-13 12:00:38 -10:00
J. Nick Koston 8b37d3a569 Inline the tag level schemas for the language schema builder and check boot_logs against logs 2026-10-13 11:02:53 -10:00
J. Nick Koston ead5824302 Reject boot_logs without a buffer and exercise per-tag boot levels on ESP8266 2026-10-13 10:48:07 -10:00
J. Nick Koston e411e19ab0 Share the LogBuffer colour code and tag lookup with the boot log replay 2026-10-13 10:45:53 -10:00
J. Nick Koston e57fca4f78 Guard the replay, warn on dropped lines, cap captured text, and register the action as an apply action 2026-10-13 10:33:49 -10:00
Omni Flux bbec20a66b [logger] Make boot log buffer log level configurable by tag
(cherry picked from commit fae4ecb708cf816902282c3b5cd6eff07dc02abf)
2026-10-13 10:24:15 -10:00
Omni Flux 9a353cc3e2 [logger] Make boot log buffer log level configurable
(cherry picked from commit 7f532b3021999bb75551368ca13966b729a89011)
2026-10-13 10:22:18 -10:00
J. Nick Koston 4b029993a4 Replay stored lines straight to the listeners with their tag, add host tests 2026-10-13 10:09:02 -10:00
J. Nick Koston 3a1bb239e9 Merge remote-tracking branch 'origin/dev' into logger-boot-log-buffer 2026-10-13 09:57:07 -10:00
J. Nick Koston e96553121c Merge remote-tracking branch 'upstream/dev' into HEAD 2026-09-17 08:49:38 -05:00
J. Nick Koston 9527929947 Merge remote-tracking branch 'origin/dev' into logger-boot-log-buffer
# Conflicts:
#	esphome/components/logger/logger.cpp
2026-09-14 11:01:54 -05:00
J. Nick Koston 38ab0805a0 [logger] Add optional boot log buffer replayed over the API 2026-07-17 23:02:43 -10:00
9 changed files with 405 additions and 13 deletions
+86 -4
View File
@@ -105,6 +105,9 @@ USB_SERIAL_JTAG = "USB_SERIAL_JTAG"
USB_CDC = "USB_CDC"
DEFAULT = "DEFAULT"
CONF_BOOT_LOG_BUFFER_SIZE = "boot_log_buffer_size"
CONF_BOOT_LOG_LEVEL = "boot_log_level"
CONF_BOOT_LOGS = "boot_logs"
CONF_INITIAL_LEVEL = "initial_level"
CONF_LOGGER_ID = "logger_id"
CONF_ESP8266_STORE_LOG_STRINGS_IN_FLASH = "esp8266_store_log_strings_in_flash"
@@ -193,17 +196,47 @@ def uart_selection(value: Any) -> str:
def validate_local_no_higher_than_global(config: ConfigType) -> ConfigType:
# A level more verbose than the global one is compiled out, so it could never log or be captured
global_level = config[CONF_LEVEL]
global_level_index = LOG_LEVEL_SEVERITY.index(global_level)
errs = []
for tag, level in config.get(CONF_LOGS, {}).items():
if LOG_LEVEL_SEVERITY.index(level) > global_level_index:
for key in (CONF_LOGS, CONF_BOOT_LOGS):
for tag, level in config.get(key, {}).items():
if LOG_LEVEL_SEVERITY.index(level) > global_level_index:
errs.append(
cv.Invalid(
f"The configured log level for {tag} ({level}) must not be less severe than the global log level ({global_level})",
[key, tag],
)
)
# Capture runs after the per-tag filter, so a boot level above the tag's own level keeps nothing
tag_levels = config.get(CONF_LOGS, {})
for tag, level in config.get(CONF_BOOT_LOGS, {}).items():
tag_level = tag_levels.get(tag)
if tag_level is not None and LOG_LEVEL_SEVERITY.index(
level
) > LOG_LEVEL_SEVERITY.index(tag_level):
errs.append(
cv.Invalid(
f"The configured log level for {tag} ({level}) must not be less severe than the global log level ({global_level})",
[CONF_LOGS, tag],
f"The boot log level for {tag} ({level}) must not be less severe than its log level ({tag_level})",
[CONF_BOOT_LOGS, tag],
)
)
boot_level = config[CONF_BOOT_LOG_LEVEL]
if LOG_LEVEL_SEVERITY.index(boot_level) > global_level_index:
errs.append(
cv.Invalid(
f"The boot log level ({boot_level}) must not be less severe than the global log level ({global_level})",
[CONF_BOOT_LOG_LEVEL],
)
)
if config[CONF_BOOT_LOGS] and config[CONF_BOOT_LOG_BUFFER_SIZE] == 0:
errs.append(
cv.Invalid(
"boot_logs has no effect without boot_log_buffer_size",
[CONF_BOOT_LOGS],
)
)
if errs:
raise cv.MultipleInvalid(errs)
return config
@@ -265,6 +298,19 @@ 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.Optional(CONF_BOOT_LOG_LEVEL, default="WARN"): is_log_level,
cv.Optional(CONF_BOOT_LOGS, default={}): cv.Schema(
{
cv.string: is_log_level,
}
),
cv.SplitDefault(
CONF_TASK_LOG_BUFFER_SIZE,
esp32=768, # Default: 768 bytes (~5-6 messages with 70-byte text plus thread names)
@@ -381,6 +427,29 @@ async def to_code(config: ConfigType) -> None:
config[CONF_ID],
baud_rate,
)
# Boot log buffer: early lines kept for the logger.replay_boot_logs action
if (boot_log_buffer_size := config[CONF_BOOT_LOG_BUFFER_SIZE]) > 0:
boot_level = config[CONF_BOOT_LOG_LEVEL]
boot_logs_config = config[CONF_BOOT_LOGS]
# The most verbose level any tag keeps, so lines above it skip the per-tag lookup
max_level = max(
[boot_level, *boot_logs_config.values()], key=LOG_LEVEL_SEVERITY.index
)
cg.add_define("USE_LOGGER_BOOT_LOG_BUFFER")
cg.add_define("ESPHOME_LOGGER_BOOT_LOG_BUFFER_SIZE", boot_log_buffer_size)
# Define values must be hashable, so the level expressions go in as raw text
cg.add_define(
"ESPHOME_LOGGER_BOOT_LOG_LEVEL",
cg.RawExpression(str(LOG_LEVELS[boot_level])),
)
cg.add_define(
"ESPHOME_LOGGER_BOOT_LOG_MAX_LEVEL",
cg.RawExpression(str(LOG_LEVELS[max_level])),
)
if boot_logs_config:
cg.add_define("USE_LOGGER_BOOT_LOG_PER_TAG_LEVELS")
for tag, log_level in boot_logs_config.items():
cg.add(log.set_boot_log_level(tag, LOG_LEVELS[log_level]))
if CORE.is_esp32 or CORE.is_host:
cg.add(log.create_pthread_key())
# set_uart_selection() must be called before pre_setup() because
@@ -635,6 +704,19 @@ async def logger_set_level_to_code(
)
automation.register_apply_action(
"logger.replay_boot_logs",
automation.maybe_conf(
CONF_LOGGER_ID,
{
cv.GenerateID(CONF_LOGGER_ID): cv.use_id(Logger),
},
),
automation.ApplyCall("replay_boot_logs()"),
id_key=CONF_LOGGER_ID,
)
FILTER_SOURCE_FILES = filter_source_files_from_platform(
{
"logger_esp32.cpp": {
+17 -1
View File
@@ -114,6 +114,23 @@ struct LogBuffer {
this->finalize_();
}
#endif
static constexpr uint16_t ANSI_COLOR_LEN = 7; // "\033[{bold};3{color}m" written by write_header for level != 0
static constexpr uint16_t ANSI_RESET_LEN = 4; // "\033[0m"
// Largest replay header: color plus "@4294967295ms "
static constexpr uint16_t REPLAY_HEADER_MAX_SIZE = ANSI_COLOR_LEN + 1 + 10 + 3;
// Color for level followed by the time since boot, in front of a line replayed from the boot log buffer
void write_replay_header(uint8_t level, uint32_t ms) {
if (this->pos + REPLAY_HEADER_MAX_SIZE > this->size)
return;
char *p = this->current_();
this->write_ansi_color_(p, level);
*p++ = '@';
p = uint32_to_str_unchecked(p, ms);
*p++ = 'm';
*p++ = 's';
*p++ = ' ';
this->pos = static_cast<uint16_t>(p - this->data);
}
void write_body(const char *text, uint16_t text_length) {
const uint16_t available = this->remaining_();
const uint16_t copy_len = (text_length < available) ? text_length : available;
@@ -134,7 +151,6 @@ struct LogBuffer {
this->data[this->full_() ? this->size - 1 : this->pos] = '\0';
}
// Write ANSI reset sequence inline ("\033[0m") - avoids write_() call overhead
static constexpr uint16_t ANSI_RESET_LEN = 4; // "\033[0m"
void write_ansi_reset_() {
if (this->remaining_() >= ANSI_RESET_LEN) {
char *p = this->current_();
+106 -7
View File
@@ -1,5 +1,6 @@
#include "logger.h"
#include <cinttypes>
#include <cstring>
#include "esphome/core/application.h"
#include "esphome/core/hal.h"
@@ -142,20 +143,37 @@ void Logger::log_vprintf_(uint8_t level, const char *tag, int line, const __Flas
}
#endif // USE_ESP8266
#if defined(USE_LOGGER_RUNTIME_TAG_LEVELS) || defined(USE_LOGGER_BOOT_LOG_PER_TAG_LEVELS)
// Level for tag from a per-tag map, or fallback when the tag has none; tags may live in flash
static inline uint8_t tag_level(const std::map<const char *, uint8_t, CStrCompare> &levels, const char *tag,
uint8_t fallback) {
if (levels.empty())
return fallback;
auto it = levels.find(FlashTag{tag});
return it != levels.end() ? it->second : fallback;
}
#endif
uint8_t Logger::get_log_level(const char *tag) { return this->level_for(tag); }
inline uint8_t Logger::level_for(const char *tag) {
#ifdef USE_LOGGER_RUNTIME_TAG_LEVELS
// Skip the lookup when no per-tag levels are set
if (this->log_levels_.empty())
return this->current_level_;
auto it = this->log_levels_.find(FlashTag{tag});
if (it != this->log_levels_.end())
return it->second;
#endif
return tag_level(this->log_levels_, tag, this->current_level_);
#else
return this->current_level_;
#endif
}
#ifdef USE_LOGGER_BOOT_LOG_BUFFER
inline uint8_t Logger::boot_level_for_(const char *tag) {
#ifdef USE_LOGGER_BOOT_LOG_PER_TAG_LEVELS
return tag_level(this->boot_log_levels_, tag, ESPHOME_LOGGER_BOOT_LOG_LEVEL);
#else
return ESPHOME_LOGGER_BOOT_LOG_LEVEL;
#endif
}
#endif
Logger::Logger(uint32_t baud_rate) : baud_rate_(baud_rate) {
#if defined(USE_ESP32) || defined(USE_LIBRETINY)
this->main_task_ = xTaskGetCurrentTaskHandle();
@@ -205,9 +223,82 @@ void Logger::process_messages_() {
#endif // USE_ESPHOME_TASK_LOG_BUFFER
}
#ifdef USE_LOGGER_BOOT_LOG_BUFFER
// Each boot_log_buffer_ record is this header followed by len bytes of text
struct __attribute__((packed)) BootLogRecord {
uint16_t len;
uint8_t level;
uint32_t ms;
const char *tag; // tags are string literals, so the pointer stays valid
};
// Stored text is capped so the replay header, the reset and the null terminator always fit in the transmit buffer
static constexpr uint16_t BOOT_LOG_MAX_TEXT =
ESPHOME_LOGGER_TX_BUFFER_SIZE - LogBuffer::REPLAY_HEADER_MAX_SIZE - LogBuffer::ANSI_RESET_LEN - 1;
void Logger::boot_log_capture_(uint8_t level, const char *tag, const LogBuffer &buf) {
// The most verbose level any tag keeps; cheaper than the per-tag lookup for the lines that cannot qualify
if (level > ESPHOME_LOGGER_BOOT_LOG_MAX_LEVEL || level == ESPHOME_LOG_LEVEL_NONE ||
level > this->boot_level_for_(tag))
return;
// Strip the color write_header put in front and the reset at the end; the replay adds its own around the stamp
const char *text = buf.data;
uint16_t len = buf.pos;
if (len >= LogBuffer::ANSI_COLOR_LEN && text[0] == '\033') {
text += LogBuffer::ANSI_COLOR_LEN;
len -= LogBuffer::ANSI_COLOR_LEN;
}
if (len >= LogBuffer::ANSI_RESET_LEN &&
memcmp(text + len - LogBuffer::ANSI_RESET_LEN, "\033[0m", LogBuffer::ANSI_RESET_LEN) == 0)
len -= LogBuffer::ANSI_RESET_LEN;
if (len > BOOT_LOG_MAX_TEXT)
len = BOOT_LOG_MAX_TEXT;
if (this->boot_log_pos_ + sizeof(BootLogRecord) + len > ESPHOME_LOGGER_BOOT_LOG_BUFFER_SIZE) {
this->boot_log_dropped_++;
return;
}
const BootLogRecord record{len, level, millis(), tag};
char *p = this->boot_log_buffer_ + this->boot_log_pos_;
memcpy(p, &record, sizeof(record));
memcpy(p + sizeof(record), text, len);
this->boot_log_pos_ += sizeof(record) + len;
}
void Logger::replay_boot_logs() {
// The replay shares tx_buffer_ with normal logging, so it is dropped like any other re-entrant log
bool &recursion_guard = this->main_loop_recursion_guard_();
if (recursion_guard)
return;
this->boot_log_done_ = true; // Stops capture first, so the replay output is not buffered again
// Dropped lines are reported at WARN so a device at level WARN still learns the buffer was too small
esp_log_printf_(this->boot_log_dropped_ > 0 ? ESPHOME_LOG_LEVEL_WARN : ESPHOME_LOG_LEVEL_INFO, TAG, __LINE__,
ESPHOME_LOG_FORMAT("Replaying boot logs (%u bytes used, %u lines dropped)"), this->boot_log_pos_,
this->boot_log_dropped_);
RecursionGuard guard(recursion_guard);
uint16_t pos = 0;
while (pos + sizeof(BootLogRecord) <= this->boot_log_pos_) {
BootLogRecord record;
memcpy(&record, this->boot_log_buffer_ + pos, sizeof(record));
const char *text = this->boot_log_buffer_ + pos + sizeof(record);
pos += sizeof(record) + record.len;
if (record.level > this->level_for(record.tag))
continue;
// The stored text already carries its [LEVEL][tag:line] header
LogBuffer buf{this->tx_buffer_, ESPHOME_LOGGER_TX_BUFFER_SIZE};
buf.write_replay_header(record.level, record.ms);
buf.write_body(text, record.len);
this->notify_listeners_(record.level, record.tag, buf);
this->write_log_buffer_to_console_(buf);
}
}
#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
#ifdef USE_LOGGER_BOOT_LOG_PER_TAG_LEVELS
void Logger::set_boot_log_level(const char *tag, uint8_t log_level) { this->boot_log_levels_[tag] = log_level; }
#endif
// Log level strings - packed into flash on ESP8266, indexed by log level (0-7)
PROGMEM_STRING_TABLE(LogLevelStrings, "NONE", "ERROR", "WARN", "INFO", "CONFIG", "DEBUG", "VERBOSE", "VERY_VERBOSE");
@@ -236,12 +327,20 @@ void Logger::dump_config() {
ESP_LOGCONFIG(TAG, " Task Log Buffer Size: %u bytes", static_cast<unsigned int>(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_) {
ESP_LOGCONFIG(TAG, " Level for '%s': %s", it.first, LOG_STR_ARG(get_log_level_str(it.second)));
}
#endif
#ifdef USE_LOGGER_BOOT_LOG_PER_TAG_LEVELS
for (auto &it : this->boot_log_levels_) {
ESP_LOGCONFIG(TAG, " Boot Level for '%s': %s", it.first, LOG_STR_ARG(get_log_level_str(it.second)));
}
#endif
#ifdef USE_ZEPHYR
dump_crash_();
if (!device_is_ready(this->uart_dev_)) {
+35 -1
View File
@@ -176,11 +176,18 @@ class Logger final : public Component {
#ifdef USE_LOGGER_RUNTIME_TAG_LEVELS
/// Set the log level of the specified tag.
void set_log_level(const char *tag, uint8_t log_level);
#endif
#ifdef USE_LOGGER_BOOT_LOG_PER_TAG_LEVELS
/// Set the boot log level of the specified tag.
void set_boot_log_level(const char *tag, uint8_t log_level);
#endif
uint8_t get_log_level() { return this->current_level_; }
/// The level in force for a tag: its own when one is set, else the default
uint8_t get_log_level(const char *tag);
/// Send the lines captured during boot to the listeners and stop capturing; safe to call repeatedly.
void replay_boot_logs();
// ========== INTERNAL METHODS ==========
// (In most use cases you won't need these)
/// Set up this component.
@@ -188,7 +195,6 @@ class Logger final : public Component {
void dump_config() override;
inline uint8_t level_for(const char *tag);
#ifdef USE_LOG_LISTENERS
/// Register a log callback to receive log messages
void add_log_callback(void *instance, void (*fn)(void *, uint8_t, const char *, const char *, size_t)) {
@@ -298,6 +304,10 @@ 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
if (!this->boot_log_done_)
this->boot_log_capture_(level, tag, buf);
#endif
this->notify_listeners_(level, tag, buf);
this->write_log_buffer_to_console_(buf);
}
@@ -310,6 +320,10 @@ 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
if (!this->boot_log_done_)
this->boot_log_capture_(level, tag, buf);
#endif
this->notify_listeners_(level, tag, buf);
}
#endif
@@ -318,6 +332,12 @@ class Logger final : public Component {
const LogString *get_uart_selection_();
#endif
#ifdef USE_LOGGER_BOOT_LOG_BUFFER
/// Copy a formatted line at or above the boot log level (outer ANSI codes stripped) into the boot log buffer.
void boot_log_capture_(uint8_t level, const char *tag, const LogBuffer &buf);
inline uint8_t boot_level_for_(const char *tag);
#endif
// Group 4-byte aligned members first
uint32_t baud_rate_;
#if defined(USE_ARDUINO) && !defined(USE_ESP32)
@@ -346,6 +366,9 @@ class Logger final : public Component {
#endif
// Large objects (internally aligned)
#ifdef USE_LOGGER_BOOT_LOG_PER_TAG_LEVELS
std::map<const char *, uint8_t, CStrCompare> boot_log_levels_{};
#endif
#ifdef USE_LOGGER_RUNTIME_TAG_LEVELS
std::map<const char *, uint8_t, CStrCompare> log_levels_{};
#endif
@@ -357,6 +380,11 @@ class Logger final : public Component {
std::vector<LoggerLevelListener *> 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}; // Must match cpp_default_uart in __init__.py
@@ -369,8 +397,11 @@ class Logger final : public Component {
#ifdef USE_LIBRETINY
bool non_main_task_recursion_guard_{false}; // Shared guard for all non-main tasks on LibreTiny
#endif
// The guard that protects tx_buffer_ on the main loop, for callers that run on any platform
bool &main_loop_recursion_guard_() { return this->main_task_recursion_guard_; }
#else
bool global_recursion_guard_{false}; // Simple global recursion guard for single-task platforms
bool &main_loop_recursion_guard_() { return this->global_recursion_guard_; }
#endif
// Large buffers placed last to keep frequently-accessed member offsets small
@@ -378,6 +409,9 @@ class Logger final : public Component {
#ifdef USE_ESPHOME_TASK_LOG_BUFFER
logger::TaskLogBuffer log_buffer_; // Embedded in Logger (no separate heap allocation)
#endif
#ifdef USE_LOGGER_BOOT_LOG_BUFFER
char boot_log_buffer_[ESPHOME_LOGGER_BOOT_LOG_BUFFER_SIZE]; // BootLogRecord headers each followed by their text
#endif
// --- get_thread_name_ overloads (per-platform) ---
+5
View File
@@ -39,6 +39,11 @@
#define ESPHOME_LOGGER_TX_BUFFER_SIZE 512
#define USE_LOG_LISTENERS
#define ESPHOME_LOG_MAX_LISTENERS 8
#define USE_LOGGER_BOOT_LOG_BUFFER
#define USE_LOGGER_BOOT_LOG_PER_TAG_LEVELS
#define ESPHOME_LOGGER_BOOT_LOG_BUFFER_SIZE 4096
#define ESPHOME_LOGGER_BOOT_LOG_LEVEL ESPHOME_LOG_LEVEL_WARN
#define ESPHOME_LOGGER_BOOT_LOG_MAX_LEVEL ESPHOME_LOG_LEVEL_WARN
// Feature flags
#define USE_ALARM_CONTROL_PANEL
+20
View File
@@ -1,7 +1,27 @@
from pathlib import Path
from esphome.components.logger import CONF_BOOT_LOG_BUFFER_SIZE, request_log_listener
from esphome.const import CONF_ESPHOME, CONF_INCLUDES
from esphome.core import CORE
from esphome.types import ConfigType
from tests.testing_helpers import ComponentManifestOverride
TESTS_DIR = Path(__file__).parent
def override_manifest(manifest: ComponentManifestOverride) -> None:
# logger must run its to_code during C++ test builds because it configures
# the logging subsystem used by ESP_LOG* macros throughout component code.
manifest.enable_codegen()
original_to_code = manifest.to_code
async def to_code(config: ConfigType) -> None:
# Only logger's own tests exercise the boot log buffer; they read the replay
# through a log listener, which nothing else registers in this build.
if any(Path(p) == TESTS_DIR for p in CORE.config[CONF_ESPHOME][CONF_INCLUDES]):
config = {**config, CONF_BOOT_LOG_BUFFER_SIZE: 512}
request_log_listener()
await original_to_code(config)
manifest.to_code = to_code
@@ -0,0 +1,109 @@
#include <gtest/gtest.h>
#include <algorithm>
#include <string>
#include <vector>
#include "esphome/components/logger/logger.h"
#include "esphome/core/log.h"
namespace esphome::logger::testing {
ESPHOME_LOG_TAG(BOOT_TAG, "boot.test");
struct Captured {
uint8_t level;
const char *tag;
std::string message;
};
// Collects what a listener such as the API connection would receive.
static void capture(void *instance, uint8_t level, const char *tag, const char *message, size_t len) {
static_cast<std::vector<Captured> *>(instance)->push_back({level, tag, std::string(message, len)});
}
class BootLogBufferTest : public ::testing::Test {
protected:
void SetUp() override {
this->previous_ = global_logger;
this->logger_.pre_setup();
this->logger_.set_log_level(ESPHOME_LOG_LEVEL_DEBUG);
}
void TearDown() override { global_logger = this->previous_; }
// Attach a listener after the early lines, replay, and return the replayed lines (they carry the boot tag)
std::vector<Captured> replay_() {
this->logger_.add_log_callback(&this->lines_, capture);
this->logger_.replay_boot_logs();
std::vector<Captured> out;
for (const auto &line : this->lines_) {
if (line.tag == BOOT_TAG)
out.push_back(line);
}
return out;
}
bool summary_warned_() const {
return std::any_of(this->lines_.begin(), this->lines_.end(),
[](const Captured &l) { return l.tag != BOOT_TAG && l.level == ESPHOME_LOG_LEVEL_WARN; });
}
Logger *previous_{nullptr};
Logger logger_{0};
std::vector<Captured> lines_;
};
TEST_F(BootLogBufferTest, ReplaysWarningsAndErrorsWithTheirTagAndLevel) {
ESP_LOGW(BOOT_TAG, "early warning %d", 1);
ESP_LOGE(BOOT_TAG, "early error");
ESP_LOGI(BOOT_TAG, "info is not kept");
const auto lines = this->replay_();
ASSERT_EQ(lines.size(), 2u);
EXPECT_EQ(lines[0].level, ESPHOME_LOG_LEVEL_WARN);
EXPECT_NE(lines[0].message.find("[W][boot.test:"), std::string::npos) << lines[0].message;
EXPECT_NE(lines[0].message.find("early warning 1"), std::string::npos) << lines[0].message;
EXPECT_EQ(lines[1].level, ESPHOME_LOG_LEVEL_ERROR);
EXPECT_NE(lines[1].message.find("early error"), std::string::npos) << lines[1].message;
// One header per line: the stored header is not formatted a second time
EXPECT_EQ(lines[1].message.find("[E]"), lines[1].message.rfind("[E]")) << lines[1].message;
EXPECT_FALSE(this->summary_warned_());
}
TEST_F(BootLogBufferTest, ReplayOutputIsNotCapturedAgain) {
ESP_LOGW(BOOT_TAG, "once");
this->replay_();
ESP_LOGW(BOOT_TAG, "after replay");
this->lines_.clear();
this->logger_.replay_boot_logs();
size_t replayed = 0;
for (const auto &line : this->lines_) {
if (line.tag == BOOT_TAG) {
replayed++;
EXPECT_NE(line.message.find("once"), std::string::npos) << line.message;
}
}
EXPECT_EQ(replayed, 1u);
}
TEST_F(BootLogBufferTest, LinesThatDoNotFitAreCountedAndWarned) {
for (int i = 0; i < 40; i++) {
ESP_LOGW(BOOT_TAG, "warning number %d padded to make the record longer", i);
}
const auto lines = this->replay_();
EXPECT_GT(lines.size(), 0u);
EXPECT_LT(lines.size(), 40u);
EXPECT_TRUE(this->summary_warned_());
}
TEST_F(BootLogBufferTest, LongestLineIsReplayedWithoutLosingItsTail) {
// A line that fills the transmit buffer must still fit once the replay adds its stamp
std::string text(ESPHOME_LOGGER_TX_BUFFER_SIZE, 'x');
ESP_LOGW(BOOT_TAG, "%s", text.c_str());
const auto lines = this->replay_();
ASSERT_EQ(lines.size(), 1u);
EXPECT_LE(lines[0].message.size(), static_cast<size_t>(ESPHOME_LOGGER_TX_BUFFER_SIZE));
// Text runs right up to the reset code, so nothing was cut by the replay header
EXPECT_EQ(lines[0].message.substr(lines[0].message.size() - 5), "x\033[0m") << lines[0].message.size();
}
} // namespace esphome::logger::testing
@@ -0,0 +1,14 @@
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
boot_log_level: INFO
boot_logs:
wifi: DEBUG
@@ -0,0 +1,13 @@
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
boot_logs:
wifi: DEBUG