Upstream/esphome
1
0
Fork 0
mirror of https://github.com/esphome/esphome.git synced 2024-09-30 04:28:42 +02:00
Code Issues Projects Releases Wiki Activity

Make logger string memory usage more efficient (#641)

Browse Source 
* Make logger string storing more efficient

* Lint
This commit is contained in:
Otto Winter 2019-06-16 19:14:24 +02:00 committed by GitHub
parent c13f132399
commit 904a0b26ea
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
6 changed files with 155 additions and 100 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

2
esphome/components/esp32_ble_tracker/esp32_ble_tracker.cpp
View File

@ -140,7 +140,7 @@ bool ESP32BLETracker::ble_setup() {
void ESP32BLETracker::start_scan(bool first) {
if (!xSemaphoreTake(this->scan_end_lock_, 0L)) {
ESP_LOGW("Cannot start scan!");
ESP_LOGW(TAG, "Cannot start scan!");
return;
}

2
esphome/components/logger/__init__.py
View File

@ -29,7 +29,7 @@ LOG_LEVEL_TO_ESP_LOG = {
'VERY_VERBOSE': cg.global_ns.ESP_LOGVV,
}
LOG_LEVEL_SEVERITY = ['NONE', 'ERROR', 'WARN', 'INFO', 'DEBUG', 'VERBOSE', 'VERY_VERBOSE']
LOG_LEVEL_SEVERITY = ['NONE', 'ERROR', 'WARN', 'INFO', 'CONFIG', 'DEBUG', 'VERBOSE', 'VERY_VERBOSE']
UART_SELECTION_ESP32 = ['UART0', 'UART1', 'UART2']

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

@ -10,38 +10,74 @@ namespace logger {
static const char *TAG = "logger";
int HOT Logger::log_vprintf_(int level, const char *tag, const char *format, va_list args) { // NOLINT
if (level > this->level_for(tag))
return 0;
static const char *LOG_LEVEL_COLORS[] = {
"", // NONE
ESPHOME_LOG_BOLD(ESPHOME_LOG_COLOR_RED), // ERROR
ESPHOME_LOG_COLOR(ESPHOME_LOG_COLOR_YELLOW), // WARNING
ESPHOME_LOG_COLOR(ESPHOME_LOG_COLOR_GREEN), // INFO
ESPHOME_LOG_COLOR(ESPHOME_LOG_COLOR_MAGENTA), // CONFIG
ESPHOME_LOG_COLOR(ESPHOME_LOG_COLOR_CYAN), // DEBUG
ESPHOME_LOG_COLOR(ESPHOME_LOG_COLOR_GRAY), // VERBOSE
ESPHOME_LOG_COLOR(ESPHOME_LOG_COLOR_WHITE), // VERY_VERBOSE
};
static const char *LOG_LEVEL_LETTERS[] = {
"", // NONE
"E", // ERROR
"W", // WARNING
"I", // INFO
"C", // CONFIG
"D", // DEBUG
"V", // VERBOSE
"VV", // VERY_VERBOSE
};
int ret = vsnprintf(this->tx_buffer_.data(), this->tx_buffer_.capacity(), format, args);
this->log_message_(level, tag, this->tx_buffer_.data(), ret);
return ret;
void Logger::write_header_(int level, const char *tag, int line) {
if (level < 0)
level = 0;
if (level > 7)
level = 7;
const char *color = LOG_LEVEL_COLORS[level];
const char *letter = LOG_LEVEL_LETTERS[level];
this->printf_to_buffer_("%s[%s][%s:%03u]: ", color, letter, tag, line);
}
void HOT Logger::log_vprintf_(int level, const char *tag, int line, const char *format, va_list args) { // NOLINT
if (level > this->level_for(tag))
return;
this->reset_buffer_();
this->write_header_(level, tag, line);
this->vprintf_to_buffer_(format, args);
this->write_footer_();
this->log_message_(level, tag);
}
#ifdef USE_STORE_LOG_STR_IN_FLASH
int Logger::log_vprintf_(int level, const char *tag, const __FlashStringHelper *format, va_list args) { // NOLINT
void Logger::log_vprintf_(int level, const char *tag, int line, const __FlashStringHelper *format,
va_list args) { // NOLINT
if (level > this->level_for(tag))
return 0;
return;
this->reset_buffer_();
// copy format string
const char *format_pgm_p = (PGM_P) format;
size_t len = 0;
char *write = this->tx_buffer_.data();
char ch = '.';
while (len < this->tx_buffer_.capacity() && ch != '\0') {
*write++ = ch = pgm_read_byte(format_pgm_p++);
len++;
while (!this->is_buffer_full_() && ch != '\0') {
this->tx_buffer_[this->tx_buffer_at_++] = ch = pgm_read_byte(format_pgm_p++);
}
if (len == this->tx_buffer_.capacity())
return -1;
// Buffer full form copying format
if (this->is_buffer_full_())
return;
// length of format string, includes null terminator
uint32_t offset = this->tx_buffer_at_;
// now apply vsnprintf
size_t offset = len + 1;
size_t remaining = this->tx_buffer_.capacity() - offset;
char *msg = this->tx_buffer_.data() + offset;
int ret = vsnprintf(msg, remaining, this->tx_buffer_.data(), args);
this->log_message_(level, tag, msg, ret);
return ret;
this->write_header_(level, tag, line);
this->vprintf_to_buffer_(this->tx_buffer_, args);
this->write_footer_();
this->log_message_(level, tag, offset);
}
#endif
@ -54,22 +90,26 @@ int HOT Logger::level_for(const char *tag) {
return it.level;
}
}
return this->global_log_level_;
return ESPHOME_LOG_LEVEL;
}
void HOT Logger::log_message_(int level, const char *tag, char *msg, int ret) {
if (ret <= 0)
return;
void HOT Logger::log_message_(int level, const char *tag, int offset) {
// remove trailing newline
if (msg[ret - 1] == '\n') {
msg[ret - 1] = '\0';
if (this->tx_buffer_[this->tx_buffer_at_ - 1] == '\n') {
this->tx_buffer_at_--;
}
// make sure null terminator is present
this->set_null_terminator_();
const char *msg = this->tx_buffer_ + offset;
if (this->baud_rate_ > 0)
this->hw_serial_->println(msg);
this->log_callback_.call(level, tag, msg);
}
Logger::Logger(uint32_t baud_rate, size_t tx_buffer_size, UARTSelection uart) : baud_rate_(baud_rate), uart_(uart) {
this->set_tx_buffer_size(tx_buffer_size);
Logger::Logger(uint32_t baud_rate, size_t tx_buffer_size, UARTSelection uart)
: baud_rate_(baud_rate), tx_buffer_size_(tx_buffer_size), uart_(uart) {
// add 1 to buffer size for null terminator
this->tx_buffer_ = new char[this->tx_buffer_size_ + 1];
}
void Logger::pre_setup() {
@ -96,7 +136,7 @@ void Logger::pre_setup() {
if (this->uart_ == UART_SELECTION_UART0_SWAP) {
this->hw_serial_->swap();
}
this->hw_serial_->setDebugOutput(this->global_log_level_ >= ESPHOME_LOG_LEVEL_VERBOSE);
this->hw_serial_->setDebugOutput(ESPHOME_LOG_LEVEL >= ESPHOME_LOG_LEVEL_VERBOSE);
#endif
}
#ifdef ARDUINO_ARCH_ESP8266
@ -108,7 +148,7 @@ void Logger::pre_setup() {
global_logger = this;
#ifdef ARDUINO_ARCH_ESP32
esp_log_set_vprintf(esp_idf_log_vprintf_);
if (this->global_log_level_ >= ESPHOME_LOG_LEVEL_VERBOSE) {
if (ESPHOME_LOG_LEVEL >= ESPHOME_LOG_LEVEL_VERBOSE) {
esp_log_level_set("*", ESP_LOG_VERBOSE);
}
#endif
@ -116,17 +156,15 @@ void Logger::pre_setup() {
ESP_LOGI(TAG, "Log initialized");
}
void Logger::set_baud_rate(uint32_t baud_rate) { this->baud_rate_ = baud_rate; }
void Logger::set_global_log_level(int log_level) { this->global_log_level_ = log_level; }
void Logger::set_log_level(const std::string &tag, int log_level) {
this->log_levels_.push_back(LogLevelOverride{tag, log_level});
}
void Logger::set_tx_buffer_size(size_t tx_buffer_size) { this->tx_buffer_.reserve(tx_buffer_size); }
UARTSelection Logger::get_uart() const { return this->uart_; }
void Logger::add_on_log_callback(std::function<void(int, const char *, const char *)> &&callback) {
this->log_callback_.add(std::move(callback));
}
float Logger::get_setup_priority() const { return setup_priority::HARDWARE - 1.0f; }
const char *LOG_LEVELS[] = {"NONE", "ERROR", "WARN", "INFO", "DEBUG", "VERBOSE", "VERY_VERBOSE"};
const char *LOG_LEVELS[] = {"NONE", "ERROR", "WARN", "INFO", "CONFIG", "DEBUG", "VERBOSE", "VERY_VERBOSE"};
#ifdef ARDUINO_ARCH_ESP32
const char *UART_SELECTIONS[] = {"UART0", "UART1", "UART2"};
#endif
@ -135,13 +173,14 @@ const char *UART_SELECTIONS[] = {"UART0", "UART1", "UART0_SWAP"};
#endif
void Logger::dump_config() {
ESP_LOGCONFIG(TAG, "Logger:");
ESP_LOGCONFIG(TAG, " Level: %s", LOG_LEVELS[this->global_log_level_]);
ESP_LOGCONFIG(TAG, " Level: %s", LOG_LEVELS[ESPHOME_LOG_LEVEL]);
ESP_LOGCONFIG(TAG, " Log Baud Rate: %u", this->baud_rate_);
ESP_LOGCONFIG(TAG, " Hardware UART: %s", UART_SELECTIONS[this->uart_]);
for (auto &it : this->log_levels_) {
ESP_LOGCONFIG(TAG, " Level for '%s': %s", it.tag.c_str(), LOG_LEVELS[it.level]);
}
}
void Logger::write_footer_() { this->write_to_buffer_(ESPHOME_LOG_RESET_COLOR, strlen(ESPHOME_LOG_RESET_COLOR)); }
Logger *global_logger = nullptr;

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

@ -31,16 +31,9 @@ class Logger : public Component {
/// Manually set the baud rate for serial, set to 0 to disable.
void set_baud_rate(uint32_t baud_rate);
/// Set the buffer size that's used for constructing log messages. Log messages longer than this will be truncated.
void set_tx_buffer_size(size_t tx_buffer_size);
/// Get the UART used by the logger.
UARTSelection get_uart() const;
/// Set the global log level. Note: Use the ESPHOME_LOG_LEVEL define to also remove the logs from the build.
void set_global_log_level(int log_level);
int get_global_log_level() const { return this->global_log_level_; }
/// Set the log level of the specified tag.
void set_log_level(const std::string &tag, int log_level);
@ -57,17 +50,58 @@ class Logger : public Component {
float get_setup_priority() const override;
int log_vprintf_(int level, const char *tag, const char *format, va_list args); // NOLINT
void log_vprintf_(int level, const char *tag, int line, const char *format, va_list args); // NOLINT
#ifdef USE_STORE_LOG_STR_IN_FLASH
int log_vprintf_(int level, const char *tag, const __FlashStringHelper *format, va_list args); // NOLINT
void log_vprintf_(int level, const char *tag, int line, const __FlashStringHelper *format, va_list args); // NOLINT
#endif
protected:
void log_message_(int level, const char *tag, char *msg, int ret);
void write_header_(int level, const char *tag, int line);
void write_footer_();
void log_message_(int level, const char *tag, int offset = 0);
inline bool is_buffer_full_() const { return this->tx_buffer_at_ >= this->tx_buffer_size_; }
inline int buffer_remaining_capacity_() const { return this->tx_buffer_size_ - this->tx_buffer_at_; }
inline void reset_buffer_() { this->tx_buffer_at_ = 0; }
inline void set_null_terminator_() {
// does not increment buffer_at
this->tx_buffer_[this->tx_buffer_at_] = '\0';
}
inline void write_to_buffer_(char value) {
if (!this->is_buffer_full_())
this->tx_buffer_[this->tx_buffer_at_++] = value;
}
inline void write_to_buffer_(const char *value, int length) {
for (int i = 0; i < length && !this->is_buffer_full_(); i++) {
this->tx_buffer_[this->tx_buffer_at_++] = value[i];
}
}
inline void vprintf_to_buffer_(const char *format, va_list args) {
if (this->is_buffer_full_())
return;
int remaining = this->buffer_remaining_capacity_();
int ret = vsnprintf(this->tx_buffer_ + this->tx_buffer_at_, remaining, format, args);
if (ret < 0) {
// Encoding error, do not increment buffer_at
return;
}
if (ret >= remaining) {
// output was too long, truncated
ret = remaining;
}
this->tx_buffer_at_ += ret;
}
inline void printf_to_buffer_(const char *format, ...) {
va_list arg;
va_start(arg, format);
this->vprintf_to_buffer_(format, arg);
va_end(arg);
}
uint32_t baud_rate_;
std::vector<char> tx_buffer_;
int global_log_level_{ESPHOME_LOG_LEVEL};
char *tx_buffer_{nullptr};
int tx_buffer_at_{0};
int tx_buffer_size_{0};
UARTSelection uart_{UART_SELECTION_UART0};
HardwareSerial *hw_serial_{nullptr};
struct LogLevelOverride {

39
esphome/core/log.cpp
View File

@ -1,6 +1,6 @@
#include "esphome/core/log.h"
#include "esphome/core/defines.h"
#include "esphome/core/helpers.h"
#include "log.h"
#include "defines.h"
#include "helpers.h"
#ifdef USE_LOGGER
#include "esphome/components/logger/logger.h"
@ -8,46 +8,40 @@
namespace esphome {
int HOT esp_log_printf_(int level, const char *tag, const char *format, ...) { // NOLINT
void HOT esp_log_printf_(int level, const char *tag, int line, const char *format, ...) { // NOLINT
va_list arg;
va_start(arg, format);
int ret = esp_log_vprintf_(level, tag, format, arg);
esp_log_vprintf_(level, tag, line, format, arg);
va_end(arg);
return ret;
}
#ifdef USE_STORE_LOG_STR_IN_FLASH
int HOT esp_log_printf_(int level, const char *tag, const __FlashStringHelper *format, ...) {
void HOT esp_log_printf_(int level, const char *tag, int line, const __FlashStringHelper *format, ...) {
va_list arg;
va_start(arg, format);
int ret = esp_log_vprintf_(level, tag, format, arg);
esp_log_vprintf_(level, tag, line, format, arg);
va_end(arg);
return ret;
return 0;
}
#endif
int HOT esp_log_vprintf_(int level, const char *tag, const char *format, va_list args) { // NOLINT
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 0;
return;
return log->log_vprintf_(level, tag, format, args);
#else
return 0;
log->log_vprintf_(level, tag, line, format, args);
#endif
}
#ifdef USE_STORE_LOG_STR_IN_FLASH
int HOT esp_log_vprintf_(int level, const char *tag, const __FlashStringHelper *format, va_list args) { // NOLINT
void HOT esp_log_vprintf_(int level, const char *tag, int line, const __FlashStringHelper *format,
va_list args) { // NOLINT
#ifdef USE_LOGGER
auto *log = logger::global_logger;
if (log == nullptr)
return 0;
return;
return log->log_vprintf_(level, tag, format, args);
#else
return 0;
log->log_vprintf_(level, tag, line, format, args);
#endif
}
#endif
@ -58,10 +52,9 @@ int HOT esp_idf_log_vprintf_(const char *format, va_list args) { // NOLINT
if (log == nullptr)
return 0;
return log->log_vprintf_(log->get_global_log_level(), "", format, args);
#else
return 0;
log->log_vprintf_(ESPHOME_LOG_LEVEL, "", 0, format, args);
#endif
return 0;
}
} // namespace esphome

47
esphome/core/log.h
View File

@ -20,9 +20,10 @@ namespace esphome {
#define ESPHOME_LOG_LEVEL_ERROR 1
#define ESPHOME_LOG_LEVEL_WARN 2
#define ESPHOME_LOG_LEVEL_INFO 3
#define ESPHOME_LOG_LEVEL_DEBUG 4
#define ESPHOME_LOG_LEVEL_VERBOSE 5
#define ESPHOME_LOG_LEVEL_VERY_VERBOSE 6
#define ESPHOME_LOG_LEVEL_CONFIG 4
#define ESPHOME_LOG_LEVEL_DEBUG 5
#define ESPHOME_LOG_LEVEL_VERBOSE 6
#define ESPHOME_LOG_LEVEL_VERY_VERBOSE 7
#ifndef ESPHOME_LOG_LEVEL
#define ESPHOME_LOG_LEVEL ESPHOME_LOG_LEVEL_DEBUG
@ -43,38 +44,28 @@ namespace esphome {
#define ESPHOME_LOG_COLOR(COLOR) "\033[0;" COLOR "m"
#define ESPHOME_LOG_BOLD(COLOR) "\033[1;" COLOR "m"
#define ESPHOME_LOG_COLOR_E ESPHOME_LOG_BOLD(ESPHOME_LOG_COLOR_RED)
#define ESPHOME_LOG_COLOR_W ESPHOME_LOG_COLOR(ESPHOME_LOG_COLOR_YELLOW)
#define ESPHOME_LOG_COLOR_I ESPHOME_LOG_COLOR(ESPHOME_LOG_COLOR_GREEN)
#define ESPHOME_LOG_COLOR_C ESPHOME_LOG_COLOR(ESPHOME_LOG_COLOR_MAGENTA)
#define ESPHOME_LOG_COLOR_D ESPHOME_LOG_COLOR(ESPHOME_LOG_COLOR_CYAN)
#define ESPHOME_LOG_COLOR_V ESPHOME_LOG_COLOR(ESPHOME_LOG_COLOR_GRAY)
#define ESPHOME_LOG_COLOR_VV ESPHOME_LOG_COLOR(ESPHOME_LOG_COLOR_WHITE)
#define ESPHOME_LOG_RESET_COLOR "\033[0m"
int esp_log_printf_(int level, const char *tag, const char *format, ...) // NOLINT
__attribute__((format(printf, 3, 4)));
void esp_log_printf_(int level, const char *tag, int line, const char *format, ...) // NOLINT
__attribute__((format(printf, 4, 5)));
#ifdef USE_STORE_LOG_STR_IN_FLASH
int esp_log_printf_(int level, const char *tag, const __FlashStringHelper *format, ...);
void esp_log_printf_(int level, const char *tag, int line, const __FlashStringHelper *format, ...);
#endif
int esp_log_vprintf_(int level, const char *tag, const char *format, va_list args); // NOLINT
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
int esp_log_vprintf_(int level, const char *tag, const __FlashStringHelper *format, va_list args);
void esp_log_vprintf_(int level, const char *tag, int line, const __FlashStringHelper *format, va_list args);
#endif
int esp_idf_log_vprintf_(const char *format, va_list args); // NOLINT
#ifdef USE_STORE_LOG_STR_IN_FLASH
#define ESPHOME_LOG_FORMAT(tag, letter, format) \
F(ESPHOME_LOG_COLOR_##letter "[" #letter "][%s:%03u]: " format ESPHOME_LOG_RESET_COLOR), tag, __LINE__
#define ESPHOME_LOG_FORMAT(format) F(format)
#else
#define ESPHOME_LOG_FORMAT(tag, letter, format) \
ESPHOME_LOG_COLOR_##letter "[" #letter "][%s:%03u]: " format ESPHOME_LOG_RESET_COLOR, tag, __LINE__
#define ESPHOME_LOG_FORMAT(format) format
#endif
#if ESPHOME_LOG_LEVEL >= ESPHOME_LOG_LEVEL_VERY_VERBOSE
#define esph_log_vv(tag, format, ...) \
esp_log_printf_(ESPHOME_LOG_LEVEL_VERY_VERBOSE, tag, ESPHOME_LOG_FORMAT(tag, VV, format), ##__VA_ARGS__)
esp_log_printf_(ESPHOME_LOG_LEVEL_VERY_VERBOSE, tag, __LINE__, ESPHOME_LOG_FORMAT(format), ##__VA_ARGS__)
#define ESPHOME_LOG_HAS_VERY_VERBOSE
#else
@ -83,7 +74,7 @@ int esp_idf_log_vprintf_(const char *format, va_list args); // NOLINT
#if ESPHOME_LOG_LEVEL >= ESPHOME_LOG_LEVEL_VERBOSE
#define esph_log_v(tag, format, ...) \
esp_log_printf_(ESPHOME_LOG_LEVEL_VERBOSE, tag, ESPHOME_LOG_FORMAT(tag, V, format), ##__VA_ARGS__)
esp_log_printf_(ESPHOME_LOG_LEVEL_VERBOSE, tag, __LINE__, ESPHOME_LOG_FORMAT(format), ##__VA_ARGS__)
#define ESPHOME_LOG_HAS_VERBOSE
#else
@ -92,22 +83,20 @@ int esp_idf_log_vprintf_(const char *format, va_list args); // NOLINT
#if ESPHOME_LOG_LEVEL >= ESPHOME_LOG_LEVEL_DEBUG
#define esph_log_d(tag, format, ...) \
esp_log_printf_(ESPHOME_LOG_LEVEL_DEBUG, tag, ESPHOME_LOG_FORMAT(tag, D, format), ##__VA_ARGS__)
esp_log_printf_(ESPHOME_LOG_LEVEL_DEBUG, tag, __LINE__, ESPHOME_LOG_FORMAT(format), ##__VA_ARGS__)
#define esph_log_config(tag, format, ...) \
esp_log_printf_(ESPHOME_LOG_LEVEL_DEBUG, tag, ESPHOME_LOG_FORMAT(tag, C, format), ##__VA_ARGS__)
esp_log_printf_(ESPHOME_LOG_LEVEL_CONFIG, tag, __LINE__, ESPHOME_LOG_FORMAT(format), ##__VA_ARGS__)
#define ESPHOME_LOG_HAS_DEBUG
#define ESPHOME_LOG_HAS_CONFIG
#else
#define esph_log_d(tag, format, ...)
#define esph_log_config(tag, format, ...)
#endif
#if ESPHOME_LOG_LEVEL >= ESPHOME_LOG_LEVEL_INFO
#define esph_log_i(tag, format, ...) \
esp_log_printf_(ESPHOME_LOG_LEVEL_INFO, tag, ESPHOME_LOG_FORMAT(tag, I, format), ##__VA_ARGS__)
esp_log_printf_(ESPHOME_LOG_LEVEL_INFO, tag, __LINE__, ESPHOME_LOG_FORMAT(format), ##__VA_ARGS__)
#define ESPHOME_LOG_HAS_INFO
#else
@ -116,7 +105,7 @@ int esp_idf_log_vprintf_(const char *format, va_list args); // NOLINT
#if ESPHOME_LOG_LEVEL >= ESPHOME_LOG_LEVEL_WARN
#define esph_log_w(tag, format, ...) \
esp_log_printf_(ESPHOME_LOG_LEVEL_WARN, tag, ESPHOME_LOG_FORMAT(tag, W, format), ##__VA_ARGS__)
esp_log_printf_(ESPHOME_LOG_LEVEL_WARN, tag, __LINE__, ESPHOME_LOG_FORMAT(format), ##__VA_ARGS__)
#define ESPHOME_LOG_HAS_WARN
#else
@ -125,7 +114,7 @@ int esp_idf_log_vprintf_(const char *format, va_list args); // NOLINT
#if ESPHOME_LOG_LEVEL >= ESPHOME_LOG_LEVEL_ERROR
#define esph_log_e(tag, format, ...) \
esp_log_printf_(ESPHOME_LOG_LEVEL_ERROR, tag, ESPHOME_LOG_FORMAT(tag, E, format), ##__VA_ARGS__)
esp_log_printf_(ESPHOME_LOG_LEVEL_ERROR, tag, __LINE__, ESPHOME_LOG_FORMAT(format), ##__VA_ARGS__)
#define ESPHOME_LOG_HAS_ERROR
#else