Compare commits

...

11 Commits

Author SHA1 Message Date
J. Nick Koston
fd3aa3f2ef [esp32] IRAM_ATTR on dispatch, document cold path
Put IRAM_ATTR back on esp_log_format (tiny ~43 byte dispatch function)
to match esp_log_va's IRAM placement and avoid cache miss. Leave the
512-byte formatting function in flash — it's cold on 99.9% of builds
(only runs during early boot and at DEBUG framework log level).
2026-03-13 18:18:19 -10:00
J. Nick Koston
4fbd0f1595 [esp32] Rename esp_log_format_early_ to esp_log_format_direct_ 2026-03-13 18:10:30 -10:00
J. Nick Koston
dc2d241c49 [esp32] Remove IRAM_ATTR from esp_log_format override 2026-03-13 18:09:03 -10:00
J. Nick Koston
5adc673981 [esp32] Remove pointless ISR check, document flash limitation
The ISR with cache disabled case can't be handled without
esp_rom_vprintf — the caller's format string and tag are also in
flash, so even esp_rom_printf would crash. This is the same
limitation V1 had. Document it and keep the simpler code.
2026-03-13 18:07:49 -10:00
J. Nick Koston
623f7249b8 [esp32] Add ISR safety check for constrained env logging
constrained_env combines three conditions: scheduler not running,
in ISR, or cache disabled. Only the first is safe for flash access.

Check xPortInIsrContext() (IRAM-resident) explicitly:
- In ISR: output tag only via esp_rom_printf (ROM). Flash may be
  inaccessible. This matches V1 behavior where ISR logging was
  best-effort.
- Not in ISR (scheduler not running, PHY init): call flash-resident
  esp_log_format_early_ which formats the full message.

This ensures the override is safe for all constrained env cases
without pulling in esp_rom_vprintf (1.2KB IRAM).
2026-03-13 18:05:07 -10:00
J. Nick Koston
98f0e53053 [esp32] Update stale comments and remove unused includes 2026-03-13 18:01:16 -10:00
J. Nick Koston
159005e91a [esp32] Use 512-byte stack buffer for early/constrained log formatting 2026-03-13 17:59:35 -10:00
J. Nick Koston
fac141e3fd [esp32] Avoid esp_rom_vprintf and fix constrained env crash
- Route constrained env (PHY init, efuse reads) through the early
  boot path which uses vsnprintf + esp_rom_printf. This avoids both
  the fwrite lock crash on USB JTAG devices and pulling in
  esp_rom_vprintf (1.2KB IRAM).
- Call esp_log_vprint_func directly on the normal path instead of
  going through the esp_log_vprintf inline (which would reference
  esp_rom_vprintf for the constrained env dispatch).
- Remove IRAM_ATTR from esp_log_format_early_ since it's only called
  when flash is accessible (early boot and constrained env with cache
  enabled like PHY init and efuse reads).
2026-03-13 17:58:42 -10:00
J. Nick Koston
d3055ea6ea [esp32] Drop :000 line number and shorten fallback tag 2026-03-13 17:06:45 -10:00
J. Nick Koston
99e0dcf563 [esp32] Use DRAM_ATTR for format strings in IRAM log override
ESP-IDF places log_format_text.c in IRAM/DRAM via linker fragment
(noflash) when CONFIG_LOG_IN_IRAM=y. Our override is in a different
compilation unit so string literals would default to flash. In
constrained environments where flash cache is disabled, reading
flash-resident format strings would fault.

Move all format string constants to DRAM_ATTR to match ESP-IDF's
own behavior.
2026-03-13 17:03:14 -10:00
J. Nick Koston
3a491722b2 [esp32] Use ESP-IDF Log V2 to reduce flash usage
Switch from ESP-IDF Log V1 to V2, which centralizes log formatting
inside esp_log() instead of expanding esp_log_timestamp(), color codes,
and LOG_FORMAT() at every ESP_LOGx macro call site.

This saves ~9KB of flash by eliminating ~500 per-site macro expansions
in ESP-IDF library code (gpio, ethernet, mdns, uart, wifi, etc.).

Override esp_log_format() to skip ESP-IDF's own formatting after the
ESPHome logger hook is installed, since ESPHome does its own formatting.
For early boot and constrained environments (ISR, cache disabled),
format messages in ESPHome style with colors using a stack buffer.
2026-03-13 15:38:43 -10:00
2 changed files with 81 additions and 0 deletions

View File

@@ -1614,6 +1614,11 @@ async def to_code(config):
# This saves ~250 bytes of RAM (tag cache) and associated code
add_idf_sdkconfig_option("CONFIG_LOG_TAG_LEVEL_IMPL_NONE", True)
# Use ESP-IDF Log V2 to eliminate per-site esp_log_timestamp() macro expansions
# V2 centralizes formatting inside esp_log(), reducing flash usage
add_idf_sdkconfig_option("CONFIG_LOG_VERSION_1", False)
add_idf_sdkconfig_option("CONFIG_LOG_VERSION_2", True)
# Reduce PHY TX power in the event of a brownout
add_idf_sdkconfig_option("CONFIG_ESP_PHY_REDUCE_TX_POWER", True)

View File

@@ -86,3 +86,79 @@ int HOT esp_idf_log_vprintf_(const char *format, va_list args) { // NOLINT
#endif
} // namespace esphome
#if defined(USE_ESP32) && !defined(BOOTLOADER_BUILD)
// Override esp_log_format to prevent V2's 3-call vprintf fragmentation.
// Without this, Log V2 calls the vprintf hook 3 times per message (header,
// body, newline) which creates 3 separate log entries in ESPHome's logger.
// This strong definition overrides the archive symbol from ESP-IDF's liblog,
// affecting all callers including precompiled blobs (e.g. wifi).
#include <esp_private/log_message.h>
#include <esp_log_write.h>
// Format an ESP-IDF log message directly to the console, bypassing the
// ESPHome logger hook. Used when the hook isn't installed (early boot) or
// can't be used safely (constrained env: PHY init, efuse reads — fwrite
// locks crash on USB JTAG devices).
// Formats in ESPHome style with ANSI colors into a 512-byte stack buffer,
// then outputs atomically via esp_rom_printf.
// This path is cold on 99.9% of builds — it only runs during early boot
// and at DEBUG framework log level (default is ERROR).
static void __attribute__((noinline)) esp_log_format_direct_(esp_log_msg_t *message) {
// ESP-IDF levels: NONE=0 ERROR=1 WARN=2 INFO=3 DEBUG=4 VERBOSE=5
// Color digits: E=1(red) W=3(yellow) I=2(green) D=6(cyan) V=7(gray)
static const char color_digit[] = {'\0', '1', '3', '2', '6', '7'};
static const char lvl[] = {'\0', 'E', 'W', 'I', 'D', 'V'};
// Format into stack buffer and output atomically via esp_rom_printf.
// Can't use fwrite (locks crash during early boot and PHY init).
char buf[512];
int pos = 0;
uint8_t level = message->config.opts.log_level;
if (level > 0 && level < sizeof(lvl)) {
pos = snprintf(buf, sizeof(buf), "\033[0;3%cm[%c][%s]: ", color_digit[level], lvl[level],
message->tag ? message->tag : "idf");
}
if (pos >= 0 && pos < (int) sizeof(buf) - 2) {
int body = vsnprintf(buf + pos, sizeof(buf) - pos, message->format, message->args);
if (body > 0)
pos += (body < (int) sizeof(buf) - pos) ? body : (int) sizeof(buf) - pos - 1;
}
if (level > 0 && level < sizeof(lvl) && pos < (int) sizeof(buf) - 6) {
pos += snprintf(buf + pos, sizeof(buf) - pos, "\033[0m");
}
if (pos < (int) sizeof(buf) - 1) {
buf[pos++] = '\n';
}
buf[pos] = '\0';
esp_rom_printf("%s", buf);
}
extern "C" {
// Override esp_log_format from liblog.a to prevent V2's 3-call vprintf
// fragmentation. IRAM_ATTR to match esp_log_va's IRAM placement and avoid
// an IRAM→flash cache miss on every ESP-IDF log call. This function is
// tiny (~43 bytes) so the IRAM cost is negligible.
void IRAM_ATTR esp_log_format(esp_log_msg_t *message) {
extern vprintf_like_t esp_log_vprint_func;
extern int vprintf(const char *, __gnuc_va_list); // NOLINT
if (esp_log_vprint_func == &vprintf || message->config.opts.constrained_env) [[unlikely]] {
// Early boot or constrained env (PHY init, efuse reads, scheduler not
// running). Can't use the ESPHome hook — fwrite locks crash during PHY
// init on USB JTAG devices and newlib isn't initialized during early boot.
// Format to stack buffer with vsnprintf + esp_rom_printf instead.
//
// Note: if called from an ISR with flash cache disabled, this will crash
// because the format string and tag are in flash. This is the same as V1
// where ESP_EARLY_LOGx from ISR also used flash-resident format strings
// via esp_rom_printf. No ESP-IDF code is known to log from ISR with
// cache disabled.
esp_log_format_direct_(message);
return;
}
// After hook installed, normal environment: skip formatting, forward body only.
// Call esp_log_vprint_func directly to avoid pulling in esp_rom_vprintf
// (1.2KB IRAM) through the esp_log_vprintf inline.
esp_log_vprint_func(message->format, message->args);
}
} // extern "C"
#endif