[log] Detect early log calls before logger init and optimize hot path (#14538)

esphome/components/logger/__init__.py

@@ -337,6 +337,10 @@ async def to_code(config):
     )
     if CORE.is_esp32:
         cg.add(log.create_pthread_key())
+    # pre_setup() must be called before init_log_buffer() because
+    # init_log_buffer() calls disable_loop() which may log at VV level,
+    # and global_logger must be set before any logging occurs.
+    cg.add(log.pre_setup())
     if CORE.is_esp32 or CORE.is_libretiny or CORE.is_nrf52:
         task_log_buffer_size = config[CONF_TASK_LOG_BUFFER_SIZE]
         if task_log_buffer_size > 0:
@@ -356,7 +360,6 @@ async def to_code(config):
                 HARDWARE_UART_TO_UART_SELECTION[config[CONF_HARDWARE_UART]]
             )
         )
-    cg.add(log.pre_setup())
 
     # Enable runtime tag levels if logs are configured or explicitly enabled
     logs_config = config[CONF_LOGS]

esphome/core/application.h

@@ -142,6 +142,7 @@ static constexpr uint32_t TEARDOWN_TIMEOUT_REBOOT_MS = 1000;  // 1 second for qu
 class Application {
  public:
 #ifdef ESPHOME_NAME_ADD_MAC_SUFFIX
+  // Called before Logger::pre_setup() — must not log (global_logger is not yet set).
   /// Pre-setup with MAC suffix: overwrites placeholder in mutable static buffers with actual MAC.
   void pre_setup(char *name, size_t name_len, char *friendly_name, size_t friendly_name_len) {
     arch_init();
@@ -163,6 +164,7 @@ class Application {
     this->friendly_name_ = StringRef(friendly_name, friendly_name_len);
   }
 #else
+  // Called before Logger::pre_setup() — must not log (global_logger is not yet set).
   /// Pre-setup without MAC suffix: StringRef points directly at const string literals in flash.
   void pre_setup(const char *name, size_t name_len, const char *friendly_name, size_t friendly_name_len) {
     arch_init();

esphome/core/log.cpp

@@ -1,6 +1,7 @@
 #include "log.h"
 #include "defines.h"
 #include "helpers.h"
+#include <cstdio>
 
 #ifdef USE_LOGGER
 #include "esphome/components/logger/logger.h"
@@ -8,40 +9,63 @@
 
 namespace esphome {
 
+#ifdef ESPHOME_DEBUG
+static void early_log_printf_(const char *tag, int line, const char *format, va_list args) {
+  fprintf(stderr, "LOG BEFORE LOGGER INIT [%s:%d]: ", tag, line);
+  vfprintf(stderr, format, args);
+  fputc('\n', stderr);
+  assert(false && "log called before Logger::pre_setup()");  // NOLINT
+}
+#endif
+
 void HOT esp_log_printf_(int level, const char *tag, int line, const char *format, ...) {  // NOLINT
+#ifdef USE_LOGGER
+#ifdef ESPHOME_DEBUG
+  if (logger::global_logger == nullptr) {
+    va_list arg;
+    va_start(arg, format);
+    early_log_printf_(tag, line, format, arg);
+    va_end(arg);
+    return;
+  }
+#endif
   va_list arg;
   va_start(arg, format);
-  esp_log_vprintf_(level, tag, line, format, arg);
+  logger::global_logger->log_vprintf_(static_cast<uint8_t>(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
+  ESPHOME_DEBUG_ASSERT(logger::global_logger != nullptr);
   va_list arg;
   va_start(arg, format);
-  esp_log_vprintf_(level, tag, line, format, arg);
+  logger::global_logger->log_vprintf_(static_cast<uint8_t>(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)
+#ifdef ESPHOME_DEBUG
+  if (logger::global_logger == nullptr) {
+    early_log_printf_(tag, line, format, args);
     return;
-
-  log->log_vprintf_(static_cast<uint8_t>(level), tag, line, format, args);
+  }
+#endif
+  logger::global_logger->log_vprintf_(static_cast<uint8_t>(level), tag, line, format, args);
 #endif
 }
 
 #ifdef USE_STORE_LOG_STR_IN_FLASH
-void HOT esp_log_vprintf_(int level, const char *tag, int line, const __FlashStringHelper *format,
-                          va_list args) {  // NOLINT
+// Remove before 2026.9.0
+void HOT esp_log_vprintf_(int level, const char *tag, int line, const __FlashStringHelper *format, va_list args) {
 #ifdef USE_LOGGER
-  auto *log = logger::global_logger;
-  if (log == nullptr)
-    return;
-
-  log->log_vprintf_(static_cast<uint8_t>(level), tag, line, format, args);
+  ESPHOME_DEBUG_ASSERT(logger::global_logger != nullptr);
+  logger::global_logger->log_vprintf_(static_cast<uint8_t>(level), tag, line, format, args);
 #endif
 }
 #endif
@@ -49,11 +73,13 @@ void HOT esp_log_vprintf_(int level, const char *tag, int line, const __FlashStr
 #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)
+#ifdef ESPHOME_DEBUG
+  if (logger::global_logger == nullptr) {
+    early_log_printf_("esp-idf", 0, format, args);
     return 0;
-
-  log->log_vprintf_(ESPHOME_LOG_LEVEL, "esp-idf", 0, format, args);
+  }
+#endif
+  logger::global_logger->log_vprintf_(ESPHOME_LOG_LEVEL, "esp-idf", 0, format, args);
 #endif
   return 0;
 }

esphome/core/log.h

@@ -4,6 +4,14 @@
 
 #include <cassert>
 #include <cstdarg>
+
+// Debug assert that only fires when ESPHOME_DEBUG is defined (e.g. in CI/test builds).
+// Zero cost in production firmware.
+#ifdef ESPHOME_DEBUG
+#define ESPHOME_DEBUG_ASSERT(expr) assert(expr)  // NOLINT
+#else
+#define ESPHOME_DEBUG_ASSERT(expr) ((void) 0)
+#endif
 // for PRIu32 and friends
 #include <cinttypes>
 #include <string>
@@ -61,7 +69,9 @@ void esp_log_printf_(int level, const char *tag, int line, const __FlashStringHe
 #endif
 void esp_log_vprintf_(int level, const char *tag, int line, const char *format, va_list args);  // NOLINT
 #ifdef USE_STORE_LOG_STR_IN_FLASH
-void esp_log_vprintf_(int level, const char *tag, int line, const __FlashStringHelper *format, va_list args);
+// Remove before 2026.9.0
+__attribute__((deprecated("Use esp_log_printf_() instead. Removed in 2026.9.0."))) void esp_log_vprintf_(
+    int level, const char *tag, int line, const __FlashStringHelper *format, va_list args);
 #endif
 #if defined(USE_ESP32)
 int esp_idf_log_vprintf_(const char *format, va_list args);  // NOLINT

script/cpp_unit_test.py

@@ -78,6 +78,7 @@ def create_test_config(config_name: str, includes: list[str]) -> dict:
                 "build_flags": [
                     "-Og",  # optimize for debug
                     "-DUSE_TIME_TIMEZONE",  # enable timezone code paths for testing
+                    "-DESPHOME_DEBUG",  # enable debug assertions
                 ],
                 "debug_build_flags": [  # only for debug builds
                     "-g3",  # max debug info

tests/component_tests/logger/test_logger.py

@@ -0,0 +1,50 @@
+"""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 logger's pre_setup() call specifically
+    logger_pre_setup = re.search(r"logger_logger->pre_setup\(\)", main_cpp)
+    if logger_pre_setup is None:
+        # Fall back to finding any logger-related pre_setup
+        logger_pre_setup = re.search(r"logger\w*->pre_setup\(\)", main_cpp)
+    assert logger_pre_setup 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"
+
+    # Separate logger and non-logger allocations
+    logger_allocs = [a for a in new_allocations if "logger" in a.group().lower()]
+    non_logger_allocs = [
+        a
+        for a in new_allocations
+        if "logger" not in a.group().lower()
+        # Skip placement new for App
+        and "(&App)" not in main_cpp[max(0, a.start() - 5) : a.start()]
+    ]
+
+    assert len(logger_allocs) > 0, (
+        f"Logger allocation not found in: {[a.group() for a in new_allocations]}"
+    )
+    assert len(non_logger_allocs) > 0, (
+        "No non-logger component allocations found — "
+        "add a component to test_logger.yaml so the ordering check is meaningful"
+    )
+
+    # All non-logger allocations must appear after logger pre_setup()
+    for alloc in non_logger_allocs:
+        assert alloc.start() > logger_pre_setup.start(), (
+            f"Component allocation '{alloc.group()}' at position {alloc.start()} "
+            f"appears before logger pre_setup() at position {logger_pre_setup.start()}"
+        )

tests/component_tests/logger/test_logger.yaml

@@ -0,0 +1,14 @@
+---
+esphome:
+  name: test
+
+esp8266:
+  board: d1_mini_lite
+
+logger:
+  level: DEBUG
+
+# Need at least one non-logger component so the ordering test
+# can verify that logger pre_setup() comes before other allocations.
+preferences:
+  flash_write_interval: 1min

tests/components/main.cpp

@@ -1,5 +1,7 @@
 #include <gtest/gtest.h>
 
+#include "esphome/components/logger/logger.h"
+
 /*
 This special main.cpp replaces the default one.
 It will run all the Google Tests found in all compiled cpp files and then exit with the result
@@ -18,6 +20,12 @@ void original_setup() {
 }
 
 void setup() {
+  // Log functions call global_logger->log_vprintf_() without a null check,
+  // so we must set up a Logger before any test that triggers logging.
+  static esphome::logger::Logger test_logger(0);
+  test_logger.set_log_level(ESPHOME_LOG_LEVEL);
+  test_logger.pre_setup();
+
   ::testing::InitGoogleTest();
   int exit_code = RUN_ALL_TESTS();
   exit(exit_code);

tests/integration/conftest.py

@@ -193,6 +193,7 @@ async def yaml_config(request: pytest.FixtureRequest, unused_tcp_port: int) -> s
             "  platformio_options:\n"
             "    build_flags:\n"
             '      - "-DDEBUG"  # Enable assert() statements\n'
+            '      - "-DESPHOME_DEBUG"  # Enable ESPHOME_DEBUG_ASSERT checks\n'
             '      - "-DESPHOME_DEBUG_API"  # Enable API protocol asserts\n'
             '      - "-g"       # Add debug symbols',
         )