sascha/esphome
1
0
Fork 0
mirror of https://github.com/esphome/esphome.git synced 2026-02-08 00:31:58 +00:00
Code Issues Releases Wiki Activity

Merge branch 'logger_thread_name_cleanup' into integration

Browse Source
This commit is contained in:
J. Nick Koston
2026-02-07 09:02:06 +01:00
parent daebc2cc39 30f9bfaf83
commit 14071086bb
8 changed files with 93 additions and 89 deletions
Download Patch File Download Diff File Expand all files Collapse all files

43
esphome/components/logger/logger.cpp
View File

@@ -36,8 +36,9 @@ void HOT Logger::log_vprintf_(uint8_t level, const char *tag, int line, const ch
#endif
// Fast path: main thread, no recursion (99.9% of all logs)
// Pass nullptr for thread_name since we already know this is the main task
if (is_main_task && !this->main_task_recursion_guard_) [[likely]] {
this->log_message_to_buffer_and_send_(this->main_task_recursion_guard_, level, tag, line, format, args);
this->log_message_to_buffer_and_send_(this->main_task_recursion_guard_, level, tag, line, format, args, nullptr);
return;
}
@@ -47,21 +48,23 @@ void HOT Logger::log_vprintf_(uint8_t level, const char *tag, int line, const ch
}
// Non-main thread handling (~0.1% of logs)
// Resolve thread name once and pass it through the logging chain.
// ESP32/LibreTiny: use TaskHandle_t overload to avoid redundant xTaskGetCurrentTaskHandle()
// (we already have the handle from the main task check above).
// Host: pass a stack buffer for pthread_getname_np to write into.
#if defined(USE_ESP32) || defined(USE_LIBRETINY)
this->log_vprintf_non_main_thread_(level, tag, line, format, args, current_task);
const char *thread_name = get_thread_name_(current_task);
#else // USE_HOST
this->log_vprintf_non_main_thread_(level, tag, line, format, args);
char thread_name_buf[THREAD_NAME_BUF_SIZE];
const char *thread_name = this->get_thread_name_(thread_name_buf);
#endif
this->log_vprintf_non_main_thread_(level, tag, line, format, args, thread_name);
}
// Handles non-main thread logging only
// Kept separate from hot path to improve instruction cache performance
#if defined(USE_ESP32) || defined(USE_LIBRETINY)
void Logger::log_vprintf_non_main_thread_(uint8_t level, const char *tag, int line, const char *format, va_list args,
TaskHandle_t current_task) {
#else // USE_HOST
void Logger::log_vprintf_non_main_thread_(uint8_t level, const char *tag, int line, const char *format, va_list args) {
#endif
const char *thread_name) {
// Check if already in recursion for this non-main thread/task
if (this->is_non_main_task_recursive_()) {
return;
@@ -73,12 +76,8 @@ void Logger::log_vprintf_non_main_thread_(uint8_t level, const char *tag, int li
bool message_sent = false;
#ifdef USE_ESPHOME_TASK_LOG_BUFFER
// For non-main threads/tasks, queue the message for callbacks
#if defined(USE_ESP32) || defined(USE_LIBRETINY)
message_sent =
this->log_buffer_->send_message_thread_safe(level, tag, static_cast<uint16_t>(line), current_task, format, args);
#else // USE_HOST
message_sent = this->log_buffer_->send_message_thread_safe(level, tag, static_cast<uint16_t>(line), format, args);
#endif
this->log_buffer_->send_message_thread_safe(level, tag, static_cast<uint16_t>(line), thread_name, format, args);
if (message_sent) {
// Enable logger loop to process the buffered message
// This is safe to call from any context including ISRs
@@ -101,19 +100,27 @@ void Logger::log_vprintf_non_main_thread_(uint8_t level, const char *tag, int li
#endif
char console_buffer[MAX_CONSOLE_LOG_MSG_SIZE]; // MUST be stack allocated for thread safety
LogBuffer buf{console_buffer, MAX_CONSOLE_LOG_MSG_SIZE};
this->format_log_to_buffer_with_terminator_(level, tag, line, format, args, buf);
this->format_log_to_buffer_with_terminator_(level, tag, line, format, args, buf, thread_name);
this->write_to_console_(buf);
}
// RAII guard automatically resets on return
}
#else
// Implementation for all other platforms (single-task, no threading)
// Implementation for single-task platforms (ESP8266, RP2040, Zephyr)
// TODO: Zephyr may have multiple threads (work queues, etc.) but uses this single-task path.
// Logging calls are NOT thread-safe: global_recursion_guard_ is a plain bool and tx_buffer_ has no locking.
// Not a problem in practice yet since Zephyr has no API support (logs are console-only).
void HOT Logger::log_vprintf_(uint8_t level, const char *tag, int line, const char *format, va_list args) { // NOLINT
if (level > this->level_for(tag) || global_recursion_guard_)
return;
this->log_message_to_buffer_and_send_(global_recursion_guard_, level, tag, line, format, args);
#ifdef USE_ZEPHYR
char tmp[MAX_POINTER_REPRESENTATION];
this->log_message_to_buffer_and_send_(global_recursion_guard_, level, tag, line, format, args,
this->get_thread_name_(tmp));
#else // Other single-task platforms don't have thread names, so pass nullptr
this->log_message_to_buffer_and_send_(global_recursion_guard_, level, tag, line, format, args, nullptr);
#endif
}
#endif // USE_ESP32 / USE_HOST / USE_LIBRETINY
@@ -129,7 +136,7 @@ void Logger::log_vprintf_(uint8_t level, const char *tag, int line, const __Flas
if (level > this->level_for(tag) || global_recursion_guard_)
return;
this->log_message_to_buffer_and_send_(global_recursion_guard_, level, tag, line, format, args);
this->log_message_to_buffer_and_send_(global_recursion_guard_, level, tag, line, format, args, nullptr);
}
#endif // USE_STORE_LOG_STR_IN_FLASH

114
esphome/components/logger/logger.h
View File

@@ -2,6 +2,7 @@
#include <cstdarg>
#include <map>
#include <span>
#include <type_traits>
#if defined(USE_ESP32) || defined(USE_HOST)
#include <pthread.h>
@@ -124,6 +125,10 @@ static constexpr uint16_t MAX_HEADER_SIZE = 128;
// "0x" + 2 hex digits per byte + '\0'
static constexpr size_t MAX_POINTER_REPRESENTATION = 2 + sizeof(void *) * 2 + 1;
// Stack buffer size for retrieving thread/task names from the OS
// macOS allows up to 64 bytes, Linux up to 16
static constexpr size_t THREAD_NAME_BUF_SIZE = 64;
// Buffer wrapper for log formatting functions
struct LogBuffer {
char *data;
@@ -408,34 +413,24 @@ class Logger : public Component {
#if defined(USE_ESP32) || defined(USE_HOST) || defined(USE_LIBRETINY)
// Handles non-main thread logging only (~0.1% of calls)
#if defined(USE_ESP32) || defined(USE_LIBRETINY)
// ESP32/LibreTiny: Pass task handle to avoid calling xTaskGetCurrentTaskHandle() twice
// thread_name is resolved by the caller from the task handle, avoiding redundant lookups
void log_vprintf_non_main_thread_(uint8_t level, const char *tag, int line, const char *format, va_list args,
TaskHandle_t current_task);
#else // USE_HOST
// Host: No task handle parameter needed (not used in send_message_thread_safe)
void log_vprintf_non_main_thread_(uint8_t level, const char *tag, int line, const char *format, va_list args);
#endif
const char *thread_name);
#endif
void process_messages_();
void write_msg_(const char *msg, uint16_t len);
// Format a log message with printf-style arguments and write it to a buffer with header, footer, and null terminator
// thread_name: name of the calling thread/task, or nullptr for main task (callers already know which task they're on)
inline void HOT format_log_to_buffer_with_terminator_(uint8_t level, const char *tag, int line, const char *format,
va_list args, LogBuffer &buf) {
#if defined(USE_ESP32) || defined(USE_LIBRETINY) || defined(USE_HOST)
buf.write_header(level, tag, line, this->get_thread_name_());
#elif defined(USE_ZEPHYR)
char tmp[MAX_POINTER_REPRESENTATION];
buf.write_header(level, tag, line, this->get_thread_name_(tmp));
#else
buf.write_header(level, tag, line, nullptr);
#endif
va_list args, LogBuffer &buf, const char *thread_name) {
buf.write_header(level, tag, line, thread_name);
buf.format_body(format, args);
}
#ifdef USE_STORE_LOG_STR_IN_FLASH
// Format a log message with flash string format and write it to a buffer with header, footer, and null terminator
// ESP8266-only (single-task), thread_name is always nullptr
inline void HOT format_log_to_buffer_with_terminator_P_(uint8_t level, const char *tag, int line,
const __FlashStringHelper *format, va_list args,
LogBuffer &buf) {
@@ -466,9 +461,10 @@ class Logger : public Component {
// Helper to format and send a log message to both console and listeners
// Template handles both const char* (RAM) and __FlashStringHelper* (flash) format strings
// thread_name: name of the calling thread/task, or nullptr for main task
template<typename FormatType>
inline void HOT log_message_to_buffer_and_send_(bool &recursion_guard, uint8_t level, const char *tag, int line,
FormatType format, va_list args) {
FormatType format, va_list args, const char *thread_name) {
RecursionGuard guard(recursion_guard);
LogBuffer buf{this->tx_buffer_, this->tx_buffer_size_};
#ifdef USE_STORE_LOG_STR_IN_FLASH
@@ -477,7 +473,7 @@ class Logger : public Component {
} else
#endif
{
this->format_log_to_buffer_with_terminator_(level, tag, line, format, args, buf);
this->format_log_to_buffer_with_terminator_(level, tag, line, format, args, buf, thread_name);
}
this->notify_listeners_(level, tag, buf);
this->write_log_buffer_to_console_(buf);
@@ -565,37 +561,57 @@ class Logger : public Component {
bool global_recursion_guard_{false}; // Simple global recursion guard for single-task platforms
#endif
#if defined(USE_ESP32) || defined(USE_LIBRETINY) || defined(USE_ZEPHYR)
const char *HOT get_thread_name_(
#ifdef USE_ZEPHYR
char *buff
// --- get_thread_name_ overloads (per-platform) ---
#if defined(USE_ESP32) || defined(USE_LIBRETINY)
// Primary overload - takes a task handle directly to avoid redundant xTaskGetCurrentTaskHandle() calls
// when the caller already has the handle (e.g. from the main task check in log_vprintf_)
const char *get_thread_name_(TaskHandle_t task) {
if (task == this->main_task_) {
return nullptr; // Main task
}
#if defined(USE_ESP32)
return pcTaskGetName(task);
#elif defined(USE_LIBRETINY)
return pcTaskGetTaskName(task);
#endif
) {
#ifdef USE_ZEPHYR
}
// Convenience overload - gets the current task handle and delegates
const char *HOT get_thread_name_() { return this->get_thread_name_(xTaskGetCurrentTaskHandle()); }
#elif defined(USE_HOST)
// Takes a caller-provided buffer for the thread name (stack-allocated for thread safety)
const char *HOT get_thread_name_(std::span<char> buff) {
pthread_t current_thread = pthread_self();
if (pthread_equal(current_thread, main_thread_)) {
return nullptr; // Main thread
}
// For non-main threads, get the thread name into the caller-provided buffer
if (pthread_getname_np(current_thread, buff.data(), buff.size()) == 0) {
return buff.data();
}
return nullptr;
}
#elif defined(USE_ZEPHYR)
const char *HOT get_thread_name_(std::span<char> buff) {
k_tid_t current_task = k_current_get();
#else
TaskHandle_t current_task = xTaskGetCurrentTaskHandle();
#endif
if (current_task == main_task_) {
return nullptr; // Main task
} else {
#if defined(USE_ESP32)
return pcTaskGetName(current_task);
#elif defined(USE_LIBRETINY)
return pcTaskGetTaskName(current_task);
#elif defined(USE_ZEPHYR)
const char *name = k_thread_name_get(current_task);
if (name) {
// zephyr print task names only if debug component is present
return name;
}
std::snprintf(buff, MAX_POINTER_REPRESENTATION, "%p", current_task);
return buff;
#endif
}
const char *name = k_thread_name_get(current_task);
if (name) {
// zephyr print task names only if debug component is present
return name;
}
std::snprintf(buff.data(), buff.size(), "%p", current_task);
return buff.data();
}
#endif
// --- Non-main task recursion guards (per-platform) ---
#if defined(USE_ESP32) || defined(USE_HOST)
// RAII guard for non-main task recursion using pthread TLS
class NonMainTaskRecursionGuard {
@@ -635,22 +651,6 @@ class Logger : public Component {
inline RecursionGuard make_non_main_task_guard_() { return RecursionGuard(non_main_task_recursion_guard_); }
#endif
#ifdef USE_HOST
const char *HOT get_thread_name_() {
pthread_t current_thread = pthread_self();
if (pthread_equal(current_thread, main_thread_)) {
return nullptr; // Main thread
}
// For non-main threads, return the thread name
// We store it in thread-local storage to avoid allocation
static thread_local char thread_name_buf[32];
if (pthread_getname_np(current_thread, thread_name_buf, sizeof(thread_name_buf)) == 0) {
return thread_name_buf;
}
return nullptr;
}
#endif
#if defined(USE_ESP32) || defined(USE_LIBRETINY)
// Disable loop when task buffer is empty (with USB CDC check on ESP32)
inline void disable_loop_when_buffer_empty_() {

3
esphome/components/logger/task_log_buffer_esp32.cpp
View File

@@ -59,7 +59,7 @@ void TaskLogBuffer::release_message_main_loop(void *token) {
last_processed_counter_ = message_counter_.load(std::memory_order_relaxed);
}
bool TaskLogBuffer::send_message_thread_safe(uint8_t level, const char *tag, uint16_t line, TaskHandle_t task_handle,
bool TaskLogBuffer::send_message_thread_safe(uint8_t level, const char *tag, uint16_t line, const char *thread_name,
const char *format, va_list args) {
// First, calculate the exact length needed using a null buffer (no actual writing)
va_list args_copy;
@@ -95,7 +95,6 @@ bool TaskLogBuffer::send_message_thread_safe(uint8_t level, const char *tag, uin
// Store the thread name now instead of waiting until main loop processing
// This avoids crashes if the task completes or is deleted between when this message
// is enqueued and when it's processed by the main loop
const char *thread_name = pcTaskGetName(task_handle);
if (thread_name != nullptr) {
strncpy(msg->thread_name, thread_name, sizeof(msg->thread_name) - 1);
msg->thread_name[sizeof(msg->thread_name) - 1] = '\0'; // Ensure null termination

2
esphome/components/logger/task_log_buffer_esp32.h
View File

@@ -58,7 +58,7 @@ class TaskLogBuffer {
void release_message_main_loop(void *token);
// Thread-safe - send a message to the ring buffer from any thread
bool send_message_thread_safe(uint8_t level, const char *tag, uint16_t line, TaskHandle_t task_handle,
bool send_message_thread_safe(uint8_t level, const char *tag, uint16_t line, const char *thread_name,
const char *format, va_list args);
// Check if there are messages ready to be processed using an atomic counter for performance

12
esphome/components/logger/task_log_buffer_host.cpp
View File

@@ -70,8 +70,8 @@ void TaskLogBufferHost::commit_write_slot_(int slot_index) {
}
}
bool TaskLogBufferHost::send_message_thread_safe(uint8_t level, const char *tag, uint16_t line, const char *format,
va_list args) {
bool TaskLogBufferHost::send_message_thread_safe(uint8_t level, const char *tag, uint16_t line, const char *thread_name,
const char *format, va_list args) {
// Acquire a slot
int slot_index = this->acquire_write_slot_();
if (slot_index < 0) {
@@ -85,11 +85,9 @@ bool TaskLogBufferHost::send_message_thread_safe(uint8_t level, const char *tag,
msg.tag = tag;
msg.line = line;
// Get thread name using pthread
char thread_name_buf[LogMessage::MAX_THREAD_NAME_SIZE];
// pthread_getname_np works the same on Linux and macOS
if (pthread_getname_np(pthread_self(), thread_name_buf, sizeof(thread_name_buf)) == 0) {
strncpy(msg.thread_name, thread_name_buf, sizeof(msg.thread_name) - 1);
// Store the thread name now to avoid crashes if thread exits before processing
if (thread_name != nullptr) {
strncpy(msg.thread_name, thread_name, sizeof(msg.thread_name) - 1);
msg.thread_name[sizeof(msg.thread_name) - 1] = '\0';
} else {
msg.thread_name[0] = '\0';

3
esphome/components/logger/task_log_buffer_host.h
View File

@@ -86,7 +86,8 @@ class TaskLogBufferHost {
// Thread-safe - send a message to the buffer from any thread
// Returns true if message was queued, false if buffer is full
bool send_message_thread_safe(uint8_t level, const char *tag, uint16_t line, const char *format, va_list args);
bool send_message_thread_safe(uint8_t level, const char *tag, uint16_t line, const char *thread_name,
const char *format, va_list args);
// Check if there are messages ready to be processed
inline bool HOT has_messages() const {

3
esphome/components/logger/task_log_buffer_libretiny.cpp
View File

@@ -101,7 +101,7 @@ void TaskLogBufferLibreTiny::release_message_main_loop() {
}
bool TaskLogBufferLibreTiny::send_message_thread_safe(uint8_t level, const char *tag, uint16_t line,
TaskHandle_t task_handle, const char *format, va_list args) {
const char *thread_name, const char *format, va_list args) {
// First, calculate the exact length needed using a null buffer (no actual writing)
va_list args_copy;
va_copy(args_copy, args);
@@ -162,7 +162,6 @@ bool TaskLogBufferLibreTiny::send_message_thread_safe(uint8_t level, const char
msg->line = line;
// Store the thread name now to avoid crashes if task is deleted before processing
const char *thread_name = pcTaskGetTaskName(task_handle);
if (thread_name != nullptr) {
strncpy(msg->thread_name, thread_name, sizeof(msg->thread_name) - 1);
msg->thread_name[sizeof(msg->thread_name) - 1] = '\0';

2
esphome/components/logger/task_log_buffer_libretiny.h
View File

@@ -70,7 +70,7 @@ class TaskLogBufferLibreTiny {
void release_message_main_loop();
// Thread-safe - send a message to the buffer from any thread
bool send_message_thread_safe(uint8_t level, const char *tag, uint16_t line, TaskHandle_t task_handle,
bool send_message_thread_safe(uint8_t level, const char *tag, uint16_t line, const char *thread_name,
const char *format, va_list args);
// Fast check using volatile counter - no lock needed