ESPHome  2024.2.0
logger.cpp
Go to the documentation of this file.
1 #include "logger.h"
2 #include <cinttypes>
3 
4 #ifdef USE_ESP_IDF
5 #include <driver/uart.h>
6 
7 #if defined(USE_ESP32_VARIANT_ESP32C3) || defined(USE_ESP32_VARIANT_ESP32C6) || defined(USE_ESP32_VARIANT_ESP32S3) || \
8  defined(USE_ESP32_VARIANT_ESP32H2)
9 #include <driver/usb_serial_jtag.h>
10 #include <esp_vfs_dev.h>
11 #include <esp_vfs_usb_serial_jtag.h>
12 #endif
13 
14 #include "freertos/FreeRTOS.h"
15 #include "esp_idf_version.h"
16 
17 #include <cstdint>
18 #include <cstdio>
19 #include <fcntl.h>
20 
21 #endif // USE_ESP_IDF
22 
23 #if defined(USE_ESP32_FRAMEWORK_ARDUINO) || defined(USE_ESP_IDF)
24 #include <esp_log.h>
25 #endif // USE_ESP32_FRAMEWORK_ARDUINO || USE_ESP_IDF
26 #include "esphome/core/hal.h"
27 #include "esphome/core/log.h"
28 
29 namespace esphome {
30 namespace logger {
31 
32 static const char *const TAG = "logger";
33 
34 static const char *const LOG_LEVEL_COLORS[] = {
35  "", // NONE
36  ESPHOME_LOG_BOLD(ESPHOME_LOG_COLOR_RED), // ERROR
37  ESPHOME_LOG_COLOR(ESPHOME_LOG_COLOR_YELLOW), // WARNING
38  ESPHOME_LOG_COLOR(ESPHOME_LOG_COLOR_GREEN), // INFO
39  ESPHOME_LOG_COLOR(ESPHOME_LOG_COLOR_MAGENTA), // CONFIG
40  ESPHOME_LOG_COLOR(ESPHOME_LOG_COLOR_CYAN), // DEBUG
41  ESPHOME_LOG_COLOR(ESPHOME_LOG_COLOR_GRAY), // VERBOSE
42  ESPHOME_LOG_COLOR(ESPHOME_LOG_COLOR_WHITE), // VERY_VERBOSE
43 };
44 static const char *const LOG_LEVEL_LETTERS[] = {
45  "", // NONE
46  "E", // ERROR
47  "W", // WARNING
48  "I", // INFO
49  "C", // CONFIG
50  "D", // DEBUG
51  "V", // VERBOSE
52  "VV", // VERY_VERBOSE
53 };
54 
55 void Logger::write_header_(int level, const char *tag, int line) {
56  if (level < 0)
57  level = 0;
58  if (level > 7)
59  level = 7;
60 
61  const char *color = LOG_LEVEL_COLORS[level];
62  const char *letter = LOG_LEVEL_LETTERS[level];
63  this->printf_to_buffer_("%s[%s][%s:%03u]: ", color, letter, tag, line);
64 }
65 
66 void HOT Logger::log_vprintf_(int level, const char *tag, int line, const char *format, va_list args) { // NOLINT
67  if (level > this->level_for(tag) || recursion_guard_)
68  return;
69 
70  recursion_guard_ = true;
71  this->reset_buffer_();
72  this->write_header_(level, tag, line);
73  this->vprintf_to_buffer_(format, args);
74  this->write_footer_();
75  this->log_message_(level, tag);
76  recursion_guard_ = false;
77 }
78 #ifdef USE_STORE_LOG_STR_IN_FLASH
79 void Logger::log_vprintf_(int level, const char *tag, int line, const __FlashStringHelper *format,
80  va_list args) { // NOLINT
81  if (level > this->level_for(tag) || recursion_guard_)
82  return;
83 
84  recursion_guard_ = true;
85  this->reset_buffer_();
86  // copy format string
87  auto *format_pgm_p = reinterpret_cast<const uint8_t *>(format);
88  size_t len = 0;
89  char ch = '.';
90  while (!this->is_buffer_full_() && ch != '\0') {
91  this->tx_buffer_[this->tx_buffer_at_++] = ch = (char) progmem_read_byte(format_pgm_p++);
92  }
93  // Buffer full form copying format
94  if (this->is_buffer_full_())
95  return;
96 
97  // length of format string, includes null terminator
98  uint32_t offset = this->tx_buffer_at_;
99 
100  // now apply vsnprintf
101  this->write_header_(level, tag, line);
102  this->vprintf_to_buffer_(this->tx_buffer_, args);
103  this->write_footer_();
104  this->log_message_(level, tag, offset);
105  recursion_guard_ = false;
106 }
107 #endif
108 
109 #ifdef USE_ESP_IDF
111  uart_config_t uart_config{};
112  uart_config.baud_rate = (int) baud_rate_;
113  uart_config.data_bits = UART_DATA_8_BITS;
114  uart_config.parity = UART_PARITY_DISABLE;
115  uart_config.stop_bits = UART_STOP_BITS_1;
116  uart_config.flow_ctrl = UART_HW_FLOWCTRL_DISABLE;
117 #if ESP_IDF_VERSION >= ESP_IDF_VERSION_VAL(5, 0, 0)
118  uart_config.source_clk = UART_SCLK_DEFAULT;
119 #endif
120  uart_param_config(this->uart_num_, &uart_config);
121  const int uart_buffer_size = tx_buffer_size_;
122  // Install UART driver using an event queue here
123  uart_driver_install(this->uart_num_, uart_buffer_size, uart_buffer_size, 10, nullptr, 0);
124 }
125 
126 #if defined(USE_ESP32_VARIANT_ESP32S2) || defined(USE_ESP32_VARIANT_ESP32S3)
128 #endif
129 
130 #if defined(USE_ESP32_VARIANT_ESP32C3) || defined(USE_ESP32_VARIANT_ESP32C6) || defined(USE_ESP32_VARIANT_ESP32S3) || \
131  defined(USE_ESP32_VARIANT_ESP32H2)
133  setvbuf(stdin, NULL, _IONBF, 0); // Disable buffering on stdin
134 
135  // Minicom, screen, idf_monitor send CR when ENTER key is pressed
136  esp_vfs_dev_usb_serial_jtag_set_rx_line_endings(ESP_LINE_ENDINGS_CR);
137  // Move the caret to the beginning of the next line on '\n'
138  esp_vfs_dev_usb_serial_jtag_set_tx_line_endings(ESP_LINE_ENDINGS_CRLF);
139 
140  // Enable non-blocking mode on stdin and stdout
141  fcntl(fileno(stdout), F_SETFL, 0);
142  fcntl(fileno(stdin), F_SETFL, 0);
143 
144  usb_serial_jtag_driver_config_t usb_serial_jtag_config{};
145  usb_serial_jtag_config.rx_buffer_size = 512;
146  usb_serial_jtag_config.tx_buffer_size = 512;
147 
148  esp_err_t ret = ESP_OK;
149  // Install USB-SERIAL-JTAG driver for interrupt-driven reads and writes
150  ret = usb_serial_jtag_driver_install(&usb_serial_jtag_config);
151  if (ret != ESP_OK) {
152  return;
153  }
154 
155  // Tell vfs to use usb-serial-jtag driver
156  esp_vfs_usb_serial_jtag_use_driver();
157 }
158 #endif
159 #endif
160 
161 int HOT Logger::level_for(const char *tag) {
162  // Uses std::vector<> for low memory footprint, though the vector
163  // could be sorted to minimize lookup times. This feature isn't used that
164  // much anyway so it doesn't matter too much.
165  for (auto &it : this->log_levels_) {
166  if (it.tag == tag) {
167  return it.level;
168  }
169  }
170  return ESPHOME_LOG_LEVEL;
171 }
172 void HOT Logger::log_message_(int level, const char *tag, int offset) {
173  // remove trailing newline
174  if (this->tx_buffer_[this->tx_buffer_at_ - 1] == '\n') {
175  this->tx_buffer_at_--;
176  }
177  // make sure null terminator is present
178  this->set_null_terminator_();
179 
180  const char *msg = this->tx_buffer_ + offset;
181  if (this->baud_rate_ > 0) {
182 #ifdef USE_ARDUINO
183  this->hw_serial_->println(msg);
184 #endif // USE_ARDUINO
185 #ifdef USE_ESP_IDF
186  if (
187 #if defined(USE_ESP32_VARIANT_ESP32S2)
189 #elif defined(USE_ESP32_VARIANT_ESP32C3) || defined(USE_ESP32_VARIANT_ESP32C6) || defined(USE_ESP32_VARIANT_ESP32H2)
191 #elif defined(USE_ESP32_VARIANT_ESP32S3)
193 #else
194  /* DISABLES CODE */ (false) // NOLINT
195 #endif
196  ) {
197  puts(msg);
198  } else {
199  uart_write_bytes(this->uart_num_, msg, strlen(msg));
200  uart_write_bytes(this->uart_num_, "\n", 1);
201  }
202 #endif
203  }
204 
205 #ifdef USE_ESP32
206  // Suppress network-logging if memory constrained, but still log to serial
207  // ports. In some configurations (eg BLE enabled) there may be some transient
208  // memory exhaustion, and trying to log when OOM can lead to a crash. Skipping
209  // here usually allows the stack to recover instead.
210  // See issue #1234 for analysis.
211  if (xPortGetFreeHeapSize() < 2048)
212  return;
213 #endif
214 #ifdef USE_HOST
215  time_t rawtime;
216  struct tm *timeinfo;
217  char buffer[80];
218 
219  time(&rawtime);
220  timeinfo = localtime(&rawtime);
221  strftime(buffer, sizeof buffer, "[%H:%M:%S]", timeinfo);
222  fputs(buffer, stdout);
223  puts(msg);
224 #endif
225 
226  this->log_callback_.call(level, tag, msg);
227 }
228 
229 Logger::Logger(uint32_t baud_rate, size_t tx_buffer_size) : baud_rate_(baud_rate), tx_buffer_size_(tx_buffer_size) {
230  // add 1 to buffer size for null terminator
231  this->tx_buffer_ = new char[this->tx_buffer_size_ + 1]; // NOLINT
232 }
233 
234 #ifndef USE_LIBRETINY
236  if (this->baud_rate_ > 0) {
237 #ifdef USE_ARDUINO
238  switch (this->uart_) {
240 #ifdef USE_ESP8266
242 #endif
243 #ifdef USE_RP2040
244  this->hw_serial_ = &Serial1;
245  Serial1.begin(this->baud_rate_);
246 #else
247 #if ARDUINO_USB_CDC_ON_BOOT
248  this->hw_serial_ = &Serial0;
249  Serial0.begin(this->baud_rate_);
250 #else
251  this->hw_serial_ = &Serial;
252  Serial.begin(this->baud_rate_);
253 #endif
254 #endif
255 #ifdef USE_ESP8266
256  if (this->uart_ == UART_SELECTION_UART0_SWAP) {
257  Serial.swap();
258  }
259  Serial.setDebugOutput(ESPHOME_LOG_LEVEL >= ESPHOME_LOG_LEVEL_VERBOSE);
260 #endif
261  break;
263 #ifdef USE_RP2040
264  this->hw_serial_ = &Serial2;
265  Serial2.begin(this->baud_rate_);
266 #else
267  this->hw_serial_ = &Serial1;
268  Serial1.begin(this->baud_rate_);
269 #endif
270 #ifdef USE_ESP8266
271  Serial1.setDebugOutput(ESPHOME_LOG_LEVEL >= ESPHOME_LOG_LEVEL_VERBOSE);
272 #endif
273  break;
274 #if defined(USE_ESP32) && !defined(USE_ESP32_VARIANT_ESP32C3) && !defined(USE_ESP32_VARIANT_ESP32C6) && \
275  !defined(USE_ESP32_VARIANT_ESP32S2) && !defined(USE_ESP32_VARIANT_ESP32S3)
277  this->hw_serial_ = &Serial2;
278  Serial2.begin(this->baud_rate_);
279  break;
280 #endif
281 #if defined(USE_ESP32) && \
282  (defined(USE_ESP32_VARIANT_ESP32S2) || defined(USE_ESP32_VARIANT_ESP32S3) || defined(USE_ESP32_VARIANT_ESP32C3))
283 #if defined(USE_ESP32_VARIANT_ESP32S2) || defined(USE_ESP32_VARIANT_ESP32S3) || defined(USE_ESP32_VARIANT_ESP32C3)
285 #endif // USE_ESP32_VARIANT_ESP32S2 || USE_ESP32_VARIANT_ESP32S3 || USE_ESP32_VARIANT_ESP32C3
286 #if defined(USE_ESP32_VARIANT_ESP32C3) || defined(USE_ESP32_VARIANT_ESP32S3)
288 #endif // USE_ESP32_VARIANT_ESP32C3 || USE_ESP32_VARIANT_ESP32S3
289 #if defined(USE_ESP32_VARIANT_ESP32S2) || defined(USE_ESP32_VARIANT_ESP32S3) || defined(USE_ESP32_VARIANT_ESP32C3)
290 #if ARDUINO_USB_CDC_ON_BOOT
291  this->hw_serial_ = &Serial;
292  Serial.setTxTimeoutMs(0); // workaround for 2.0.9 crash when there's no data connection
293  Serial.begin(this->baud_rate_);
294 #else
295  this->hw_serial_ = &Serial;
296  Serial.begin(this->baud_rate_);
297 #endif // ARDUINO_USB_CDC_ON_BOOT
298 #endif // USE_ESP32_VARIANT_ESP32S2 || USE_ESP32_VARIANT_ESP32S3 || USE_ESP32_VARIANT_ESP32C3
299  break;
300 #endif // USE_ESP32 && (USE_ESP32_VARIANT_ESP32S2 || USE_ESP32_VARIANT_ESP32S3 || USE_ESP32_VARIANT_ESP32C3)
301 #ifdef USE_RP2040
303  this->hw_serial_ = &Serial;
304  Serial.begin(this->baud_rate_);
305  break;
306 #endif // USE_RP2040
307  }
308 #endif // USE_ARDUINO
309 #ifdef USE_ESP_IDF
310  this->uart_num_ = UART_NUM_0;
311  switch (this->uart_) {
313  this->uart_num_ = UART_NUM_0;
314  break;
316  this->uart_num_ = UART_NUM_1;
317  break;
318 #if !defined(USE_ESP32_VARIANT_ESP32C3) && !defined(USE_ESP32_VARIANT_ESP32C6) && \
319  !defined(USE_ESP32_VARIANT_ESP32S2) && !defined(USE_ESP32_VARIANT_ESP32S3) && !defined(USE_ESP32_VARIANT_ESP32H2)
321  this->uart_num_ = UART_NUM_2;
322  break;
323 #endif // !USE_ESP32_VARIANT_ESP32C3 && !USE_ESP32_VARIANT_ESP32S2 && !USE_ESP32_VARIANT_ESP32S3 &&
324  // !USE_ESP32_VARIANT_ESP32H2
325 #if defined(USE_ESP32_VARIANT_ESP32S2) || defined(USE_ESP32_VARIANT_ESP32S3)
327  this->uart_num_ = -1;
328  this->init_usb_cdc_();
329  break;
330 #endif // USE_ESP32_VARIANT_ESP32S2 || USE_ESP32_VARIANT_ESP32S3
331 #if defined(USE_ESP32_VARIANT_ESP32C3) || defined(USE_ESP32_VARIANT_ESP32C6) || defined(USE_ESP32_VARIANT_ESP32S3) || \
332  defined(USE_ESP32_VARIANT_ESP32H2)
334  this->uart_num_ = -1;
335  this->init_usb_serial_jtag_();
336  break;
337 #endif // USE_ESP32_VARIANT_ESP32C3 || USE_ESP32_VARIANT_ESP32C6 || USE_ESP32_VARIANT_ESP32S3 ||
338  // USE_ESP32_VARIANT_ESP32H2
339  }
340  if (this->uart_num_ >= 0) {
341  this->init_uart_();
342  }
343 #endif // USE_ESP_IDF
344  }
345 #ifdef USE_ESP8266
346  else {
347  uart_set_debug(UART_NO);
348  }
349 #endif // USE_ESP8266
350 
351  global_logger = this;
352 #if defined(USE_ESP_IDF) || defined(USE_ESP32_FRAMEWORK_ARDUINO)
353  esp_log_set_vprintf(esp_idf_log_vprintf_);
354  if (ESPHOME_LOG_LEVEL >= ESPHOME_LOG_LEVEL_VERBOSE) {
355  esp_log_level_set("*", ESP_LOG_VERBOSE);
356  }
357 #endif // USE_ESP_IDF || USE_ESP32_FRAMEWORK_ARDUINO
358 
359  ESP_LOGI(TAG, "Log initialized");
360 }
361 #else // USE_LIBRETINY
362 void Logger::pre_setup() {
363  if (this->baud_rate_ > 0) {
364  switch (this->uart_) {
365 #if LT_HW_UART0
367  this->hw_serial_ = &Serial0;
368  Serial0.begin(this->baud_rate_);
369  break;
370 #endif
371 #if LT_HW_UART1
373  this->hw_serial_ = &Serial1;
374  Serial1.begin(this->baud_rate_);
375  break;
376 #endif
377 #if LT_HW_UART2
379  this->hw_serial_ = &Serial2;
380  Serial2.begin(this->baud_rate_);
381  break;
382 #endif
383  default:
384  this->hw_serial_ = &Serial;
385  Serial.begin(this->baud_rate_);
386  if (this->uart_ != UART_SELECTION_DEFAULT) {
387  ESP_LOGW(TAG, " The chosen logger UART port is not available on this board."
388  "The default port was used instead.");
389  }
390  break;
391  }
392 
393  // change lt_log() port to match default Serial
394  if (this->uart_ == UART_SELECTION_DEFAULT) {
395  this->uart_ = (UARTSelection) (LT_UART_DEFAULT_SERIAL + 1);
396  lt_log_set_port(LT_UART_DEFAULT_SERIAL);
397  } else {
398  lt_log_set_port(this->uart_ - 1);
399  }
400  }
401 
402  global_logger = this;
403  ESP_LOGI(TAG, "Log initialized");
404 }
405 #endif // USE_LIBRETINY
406 
407 void Logger::set_baud_rate(uint32_t baud_rate) { this->baud_rate_ = baud_rate; }
408 void Logger::set_log_level(const std::string &tag, int log_level) {
409  this->log_levels_.push_back(LogLevelOverride{tag, log_level});
410 }
411 
412 #if defined(USE_ESP32) || defined(USE_ESP8266) || defined(USE_RP2040) || defined(USE_LIBRETINY)
413 UARTSelection Logger::get_uart() const { return this->uart_; }
414 #endif
415 
416 void Logger::add_on_log_callback(std::function<void(int, const char *, const char *)> &&callback) {
417  this->log_callback_.add(std::move(callback));
418 }
419 float Logger::get_setup_priority() const { return setup_priority::BUS + 500.0f; }
420 const char *const LOG_LEVELS[] = {"NONE", "ERROR", "WARN", "INFO", "CONFIG", "DEBUG", "VERBOSE", "VERY_VERBOSE"};
421 #ifdef USE_ESP32
422 const char *const UART_SELECTIONS[] = {
423  "UART0", "UART1",
424 #if !defined(USE_ESP32_VARIANT_ESP32C3) && !defined(USE_ESP32_VARIANT_ESP32C6) && \
425  !defined(USE_ESP32_VARIANT_ESP32S2) && !defined(USE_ESP32_VARIANT_ESP32S3) && !defined(USE_ESP32_VARIANT_ESP32H2)
426  "UART2",
427 #endif // !USE_ESP32_VARIANT_ESP32C3 && !USE_ESP32_VARINT_ESP32C6 && !USE_ESP32_VARIANT_ESP32S2 &&
428  // !USE_ESP32_VARIANT_ESP32S3 && !USE_ESP32_VARIANT_ESP32H2
429 #if defined(USE_ESP32_VARIANT_ESP32S2) || defined(USE_ESP32_VARIANT_ESP32S3)
430  "USB_CDC",
431 #endif // USE_ESP32_VARIANT_ESP32S2 || USE_ESP32_VARIANT_ESP32S3
432 #if defined(USE_ESP32_VARIANT_ESP32C3) || defined(USE_ESP32_VARIANT_ESP32S3)
433  "USB_SERIAL_JTAG",
434 #endif // USE_ESP32_VARIANT_ESP32C3 || USE_ESP32_VARIANT_ESP32S3
435 };
436 #endif // USE_ESP32
437 #ifdef USE_ESP8266
438 const char *const UART_SELECTIONS[] = {"UART0", "UART1", "UART0_SWAP"};
439 #endif // USE_ESP8266
440 #ifdef USE_RP2040
441 const char *const UART_SELECTIONS[] = {"UART0", "UART1", "USB_CDC"};
442 #endif // USE_RP2040
443 #ifdef USE_LIBRETINY
444 const char *const UART_SELECTIONS[] = {"DEFAULT", "UART0", "UART1", "UART2"};
445 #endif // USE_LIBRETINY
447  ESP_LOGCONFIG(TAG, "Logger:");
448  ESP_LOGCONFIG(TAG, " Level: %s", LOG_LEVELS[ESPHOME_LOG_LEVEL]);
449  ESP_LOGCONFIG(TAG, " Log Baud Rate: %" PRIu32, this->baud_rate_);
450 #if defined(USE_ESP32) || defined(USE_ESP8266) || defined(USE_RP2040) || defined(USE_LIBRETINY)
451  ESP_LOGCONFIG(TAG, " Hardware UART: %s", UART_SELECTIONS[this->uart_]);
452 #endif
453 
454  for (auto &it : this->log_levels_) {
455  ESP_LOGCONFIG(TAG, " Level for '%s': %s", it.tag.c_str(), LOG_LEVELS[it.level]);
456  }
457 }
458 void Logger::write_footer_() { this->write_to_buffer_(ESPHOME_LOG_RESET_COLOR, strlen(ESPHOME_LOG_RESET_COLOR)); }
459 
460 Logger *global_logger = nullptr; // NOLINT(cppcoreguidelines-avoid-non-const-global-variables)
461 
462 } // namespace logger
463 } // namespace esphome
void set_baud_rate(uint32_t baud_rate)
Manually set the baud rate for serial, set to 0 to disable.
Definition: logger.cpp:407
void add_on_log_callback(std::function< void(int, const char *, const char *)> &&callback)
Register a callback that will be called for every log message sent.
Definition: logger.cpp:416
UARTSelection
Enum for logging UART selection.
Definition: logger.h:33
int level_for(const char *tag)
Definition: logger.cpp:161
void log_vprintf_(int level, const char *tag, int line, const char *format, va_list args)
Definition: logger.cpp:66
void vprintf_to_buffer_(const char *format, va_list args)
Definition: logger.h:139
void dump_config() override
Definition: logger.cpp:446
float get_setup_priority() const override
Definition: logger.cpp:419
Logger(uint32_t baud_rate, size_t tx_buffer_size)
Definition: logger.cpp:229
void write_header_(int level, const char *tag, int line)
Definition: logger.cpp:55
Logger * global_logger
Definition: logger.cpp:460
uart_port_t uart_num_
Definition: logger.h:175
const float BUS
For communication buses like i2c/spi.
Definition: component.cpp:15
UARTSelection get_uart() const
Get the UART used by the logger.
Definition: logger.cpp:413
void set_null_terminator_()
Definition: logger.h:126
void printf_to_buffer_(const char *format,...)
Definition: logger.h:154
void write_to_buffer_(char value)
Definition: logger.h:130
const char *const LOG_LEVELS[]
Definition: logger.cpp:420
UARTSelection uart_
Definition: logger.h:166
void pre_setup()
Set up this component.
Definition: logger.cpp:235
uint8_t progmem_read_byte(const uint8_t *addr)
Definition: core.cpp:55
std::string size_t len
Definition: helpers.h:292
const char *const UART_SELECTIONS[]
Definition: logger.cpp:422
void log_message_(int level, const char *tag, int offset=0)
Definition: logger.cpp:172
void init_usb_serial_jtag_()
Definition: logger.cpp:132
This is a workaround until we can figure out a way to get the tflite-micro idf component code availab...
Definition: a01nyub.cpp:7
std::vector< LogLevelOverride > log_levels_
Definition: logger.h:181
void set_log_level(const std::string &tag, int log_level)
Set the log level of the specified tag.
Definition: logger.cpp:408
bool recursion_guard_
Prevents recursive log calls, if true a log message is already being processed.
Definition: logger.h:184
CallbackManager< void(int, const char *, const char *)> log_callback_
Definition: logger.h:182
int HOT esp_idf_log_vprintf_(const char *format, va_list args)
Definition: log.cpp:50
bool is_buffer_full_() const
Definition: logger.h:123