From 8a2514a9c94e5c717e3c07d72b27b7f04b67648c Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Thu, 5 Mar 2026 21:47:25 -1000 Subject: [PATCH] [log] Remove null check indirection from log functions Call global_logger->log_vprintf_() directly without null-checking global_logger on every log call. Logger::pre_setup() sets global_logger before any other component is created in the generated setup() function, so it is guaranteed to be valid by the time any log function is invoked. Also removes the __FlashStringHelper* esp_log_vprintf_ overload which was dead code (only called from esp_log_printf_, never directly). Add a Python codegen test to verify the ordering invariant, and a comment on App.pre_setup() documenting the constraint. --- esphome/core/application.h | 1 + esphome/core/log.cpp | 31 ++++--------- tests/component_tests/logger/__init__.py | 0 tests/component_tests/logger/test_logger.py | 43 +++++++++++++++++++ tests/component_tests/logger/test_logger.yaml | 9 ++++ 5 files changed, 61 insertions(+), 23 deletions(-) create mode 100644 tests/component_tests/logger/__init__.py create mode 100644 tests/component_tests/logger/test_logger.py create mode 100644 tests/component_tests/logger/test_logger.yaml diff --git a/esphome/core/application.h b/esphome/core/application.h index 40f8a00edd3..11e5f07c080 100644 --- a/esphome/core/application.h +++ b/esphome/core/application.h @@ -138,6 +138,7 @@ static constexpr uint32_t TEARDOWN_TIMEOUT_REBOOT_MS = 1000; // 1 second for qu class Application { public: + // Called before Logger::pre_setup() — must not log (global_logger is not yet set). void pre_setup(const std::string &name, const std::string &friendly_name, bool name_add_mac_suffix) { arch_init(); this->name_add_mac_suffix_ = name_add_mac_suffix; diff --git a/esphome/core/log.cpp b/esphome/core/log.cpp index 8bf188ddbbd..ad641f19814 100644 --- a/esphome/core/log.cpp +++ b/esphome/core/log.cpp @@ -8,52 +8,37 @@ namespace esphome { -// Call log_vprintf_ directly to avoid extra indirection through esp_log_vprintf_ +// No null check on global_logger — Logger::pre_setup() sets global_logger +// before any other component is created in the generated setup() function, +// so it is guaranteed to be valid by the time any log function is invoked. void HOT esp_log_printf_(int level, const char *tag, int line, const char *format, ...) { // NOLINT #ifdef USE_LOGGER - auto *log = logger::global_logger; - if (log == nullptr) - return; - va_list arg; va_start(arg, format); - log->log_vprintf_(static_cast(level), tag, line, format, arg); + logger::global_logger->log_vprintf_(static_cast(level), tag, line, format, arg); va_end(arg); #endif } + #ifdef USE_STORE_LOG_STR_IN_FLASH void HOT esp_log_printf_(int level, const char *tag, int line, const __FlashStringHelper *format, ...) { -#ifdef USE_LOGGER - auto *log = logger::global_logger; - if (log == nullptr) - return; - va_list arg; va_start(arg, format); - log->log_vprintf_(static_cast(level), tag, line, format, arg); + logger::global_logger->log_vprintf_(static_cast(level), tag, line, format, arg); va_end(arg); -#endif } #endif void HOT esp_log_vprintf_(int level, const char *tag, int line, const char *format, va_list args) { // NOLINT #ifdef USE_LOGGER - auto *log = logger::global_logger; - if (log == nullptr) - return; - - log->log_vprintf_(static_cast(level), tag, line, format, args); + logger::global_logger->log_vprintf_(static_cast(level), tag, line, format, args); #endif } #ifdef USE_ESP32 int HOT esp_idf_log_vprintf_(const char *format, va_list args) { // NOLINT #ifdef USE_LOGGER - auto *log = logger::global_logger; - if (log == nullptr) - return 0; - - log->log_vprintf_(ESPHOME_LOG_LEVEL, "esp-idf", 0, format, args); + logger::global_logger->log_vprintf_(ESPHOME_LOG_LEVEL, "esp-idf", 0, format, args); #endif return 0; } diff --git a/tests/component_tests/logger/__init__.py b/tests/component_tests/logger/__init__.py new file mode 100644 index 00000000000..e69de29bb2d diff --git a/tests/component_tests/logger/test_logger.py b/tests/component_tests/logger/test_logger.py new file mode 100644 index 00000000000..83f8caa2d82 --- /dev/null +++ b/tests/component_tests/logger/test_logger.py @@ -0,0 +1,43 @@ +"""Tests for the logger component.""" + +import re + + +def test_logger_pre_setup_before_other_components(generate_main): + """Logger::pre_setup() must be called before any other component is created. + + Log functions call global_logger->log_vprintf_() without a null check, + so global_logger must be set before anything can log. + """ + main_cpp = generate_main("tests/component_tests/logger/test_logger.yaml") + + # Find the position of logger pre_setup + pre_setup_match = re.search(r"->pre_setup\(\)", main_cpp) + assert pre_setup_match is not None, "Logger pre_setup() not found in generated code" + + # Find all "new " allocations (component creation) + new_allocations = list(re.finditer(r"\bnew [\w:]+", main_cpp)) + assert len(new_allocations) > 0, "No component allocations found" + + # Find the logger allocation + logger_new = None + for alloc in new_allocations: + if "logger" in alloc.group(): + logger_new = alloc + break + + assert logger_new is not None, ( + f"Logger allocation not found in: {[a.group() for a in new_allocations]}" + ) + + # All non-logger allocations must appear after pre_setup() + for alloc in new_allocations: + if alloc == logger_new: + continue + # Skip "new (&App)" placement new which is before logger + if "(&App)" in main_cpp[max(0, alloc.start() - 5) : alloc.start()]: + continue + assert alloc.start() > pre_setup_match.start(), ( + f"Component allocation '{alloc.group()}' at position {alloc.start()} " + f"appears before logger pre_setup() at position {pre_setup_match.start()}" + ) diff --git a/tests/component_tests/logger/test_logger.yaml b/tests/component_tests/logger/test_logger.yaml new file mode 100644 index 00000000000..5d983cb3f5d --- /dev/null +++ b/tests/component_tests/logger/test_logger.yaml @@ -0,0 +1,9 @@ +--- +esphome: + name: test + +esp8266: + board: d1_mini_lite + +logger: + level: DEBUG