From f00b34795bcdf303200fb6a24f0ed535b120a0d5 Mon Sep 17 00:00:00 2001 From: William Emfinger Date: Fri, 31 Jul 2026 22:04:28 -0500 Subject: [PATCH 1/2] feat(logger): Minor cleanup / improvement to impl for rate limiting --- components/logger/include/logger.hpp | 24 +++++++++++++++--------- 1 file changed, 15 insertions(+), 9 deletions(-) diff --git a/components/logger/include/logger.hpp b/components/logger/include/logger.hpp index 1132721a4..6b9808d5a 100644 --- a/components/logger/include/logger.hpp +++ b/components/logger/include/logger.hpp @@ -90,6 +90,8 @@ class Logger { NONE, /**< No verbosity - logger will not print anything. */ }; + using clock_t = std::chrono::steady_clock; /**< The clock type used for rate limiting. */ + /** * @brief Configuration struct for the logger. */ @@ -330,8 +332,9 @@ rate limit. @note Only calls that have _rate_limited suffixed will be rate limit if (level_ > espp::Logger::Verbosity::DEBUG) return; if (rate_limit_ > std::chrono::duration::zero()) { - auto now = std::chrono::high_resolution_clock::now(); - if (now - last_print_ < rate_limit_) + auto now = Logger::clock_t::now(); + auto duration = std::chrono::duration_cast>(now - last_print_); + if (duration < rate_limit_) return; last_print_ = now; } @@ -352,8 +355,9 @@ rate limit. @note Only calls that have _rate_limited suffixed will be rate limit if (level_ > espp::Logger::Verbosity::INFO) return; if (rate_limit_ > std::chrono::duration::zero()) { - auto now = std::chrono::high_resolution_clock::now(); - if (now - last_print_ < rate_limit_) + auto now = Logger::clock_t::now(); + auto duration = std::chrono::duration_cast>(now - last_print_); + if (duration < rate_limit_) return; last_print_ = now; } @@ -374,8 +378,9 @@ rate limit. @note Only calls that have _rate_limited suffixed will be rate limit if (level_ > espp::Logger::Verbosity::WARN) return; if (rate_limit_ > std::chrono::duration::zero()) { - auto now = std::chrono::high_resolution_clock::now(); - if (now - last_print_ < rate_limit_) + auto now = Logger::clock_t::now(); + auto duration = std::chrono::duration_cast>(now - last_print_); + if (duration < rate_limit_) return; last_print_ = now; } @@ -396,8 +401,9 @@ rate limit. @note Only calls that have _rate_limited suffixed will be rate limit if (level_ > espp::Logger::Verbosity::ERROR) return; if (rate_limit_ > std::chrono::duration::zero()) { - auto now = std::chrono::high_resolution_clock::now(); - if (now - last_print_ < rate_limit_) + auto now = Logger::clock_t::now(); + auto duration = std::chrono::duration_cast>(now - last_print_); + if (duration < rate_limit_) return; last_print_ = now; } @@ -482,7 +488,7 @@ rate limit. @note Only calls that have _rate_limited suffixed will be rate limit std::string tag_; ///< Name of the logger to be prepended to all logs. std::chrono::duration rate_limit_{ 0.0f}; ///< Rate limit for the logger. If set to 0, no rate limiting will be performed. - std::chrono::high_resolution_clock::time_point + Logger::clock_t::time_point last_print_{}; ///< Last time a log was printed. Used for rate limiting. std::atomic include_time_{true}; ///< Whether to include the time in the log. std::atomic level_ = From a9cf20a6a84a21f414415d9f18a83b2a78f1b515 Mon Sep 17 00:00:00 2001 From: William Emfinger Date: Sat, 1 Aug 2026 00:08:04 -0500 Subject: [PATCH 2/2] fix(logger): Make rate-limit state thread-safe and use native durations Address review feedback on the rate-limiting impl: - Store last_print_ as a std::atomic timestamp so the check-and-update in the *_rate_limited() methods is free of the data race / UB that occurred when logging from multiple threads. - Store rate_limit_ in the clock's native clock_t::duration (converted once in the constructor / set_rate_limit) and compare in that type, removing the per-call duration casts and their precision loss. - Drop the redundant Logger:: qualifier on clock_t inside the class. Co-Authored-By: Claude Opus 4.8 (1M context) --- components/logger/include/logger.hpp | 70 ++++++++++++++++------------ 1 file changed, 39 insertions(+), 31 deletions(-) diff --git a/components/logger/include/logger.hpp b/components/logger/include/logger.hpp index 6b9808d5a..813e249dc 100644 --- a/components/logger/include/logger.hpp +++ b/components/logger/include/logger.hpp @@ -112,7 +112,7 @@ rate limit. @note Only calls that have _rate_limited suffixed will be rate limit */ explicit Logger(const Config &config) : tag_(config.tag) - , rate_limit_(config.rate_limit) + , rate_limit_(std::chrono::duration_cast(config.rate_limit)) , include_time_(config.include_time) , level_(config.level) {} @@ -137,8 +137,8 @@ rate limit. @note Only calls that have _rate_limited suffixed will be rate limit std::scoped_lock lock(other.tag_mutex_); return std::move(other.tag_); }()) - , rate_limit_(std::move(other.rate_limit_)) - , last_print_(std::move(other.last_print_)) + , rate_limit_(other.rate_limit_) + , last_print_(other.last_print_.load()) , include_time_(other.include_time_.load()) , level_(other.level_.load()) {} @@ -169,8 +169,8 @@ rate limit. @note Only calls that have _rate_limited suffixed will be rate limit if (this != &other) { std::scoped_lock lock(tag_mutex_, other.tag_mutex_); tag_ = std::move(other.tag_); - rate_limit_ = std::move(other.rate_limit_); - last_print_ = std::move(other.last_print_); + rate_limit_ = other.rate_limit_; + last_print_.store(other.last_print_.load()); include_time_ = other.include_time_.load(); level_ = other.level_.load(); } @@ -219,13 +219,17 @@ rate limit. @note Only calls that have _rate_limited suffixed will be rate limit * @param rate_limit The new rate limit. * @note Only calls that have _rate_limited suffixed will be rate limited. */ - void set_rate_limit(const std::chrono::duration rate_limit) { rate_limit_ = rate_limit; } + void set_rate_limit(const std::chrono::duration rate_limit) { + rate_limit_ = std::chrono::duration_cast(rate_limit); + } /** * @brief Get the current rate limit for the logger. * @return The current rate limit. */ - std::chrono::duration get_rate_limit() const { return rate_limit_; } + std::chrono::duration get_rate_limit() const { + return std::chrono::duration_cast>(rate_limit_); + } /** * @brief Format args into string according to format string. From: @@ -331,12 +335,13 @@ rate limit. @note Only calls that have _rate_limited suffixed will be rate limit #if ESPP_LOGGER_DEBUG_ENABLED if (level_ > espp::Logger::Verbosity::DEBUG) return; - if (rate_limit_ > std::chrono::duration::zero()) { - auto now = Logger::clock_t::now(); - auto duration = std::chrono::duration_cast>(now - last_print_); - if (duration < rate_limit_) + if (rate_limit_ > clock_t::duration::zero()) { + const auto now = clock_t::now().time_since_epoch().count(); + // last_print_ is an atomic timestamp (clock_t rep) so the check/update is + // free of data races when logging from multiple threads. + if (clock_t::duration(now - last_print_.load()) < rate_limit_) return; - last_print_ = now; + last_print_.store(now); } // forward the arguments to the debug function debug(rt_fmt_str, std::forward(args)...); @@ -354,12 +359,13 @@ rate limit. @note Only calls that have _rate_limited suffixed will be rate limit #if ESPP_LOGGER_INFO_ENABLED if (level_ > espp::Logger::Verbosity::INFO) return; - if (rate_limit_ > std::chrono::duration::zero()) { - auto now = Logger::clock_t::now(); - auto duration = std::chrono::duration_cast>(now - last_print_); - if (duration < rate_limit_) + if (rate_limit_ > clock_t::duration::zero()) { + const auto now = clock_t::now().time_since_epoch().count(); + // last_print_ is an atomic timestamp (clock_t rep) so the check/update is + // free of data races when logging from multiple threads. + if (clock_t::duration(now - last_print_.load()) < rate_limit_) return; - last_print_ = now; + last_print_.store(now); } // forward the arguments to the info function info(rt_fmt_str, std::forward(args)...); @@ -377,12 +383,13 @@ rate limit. @note Only calls that have _rate_limited suffixed will be rate limit #if ESPP_LOGGER_WARN_ENABLED if (level_ > espp::Logger::Verbosity::WARN) return; - if (rate_limit_ > std::chrono::duration::zero()) { - auto now = Logger::clock_t::now(); - auto duration = std::chrono::duration_cast>(now - last_print_); - if (duration < rate_limit_) + if (rate_limit_ > clock_t::duration::zero()) { + const auto now = clock_t::now().time_since_epoch().count(); + // last_print_ is an atomic timestamp (clock_t rep) so the check/update is + // free of data races when logging from multiple threads. + if (clock_t::duration(now - last_print_.load()) < rate_limit_) return; - last_print_ = now; + last_print_.store(now); } // forward the arguments to the warn function warn(rt_fmt_str, std::forward(args)...); @@ -400,12 +407,13 @@ rate limit. @note Only calls that have _rate_limited suffixed will be rate limit #if ESPP_LOGGER_ERROR_ENABLED if (level_ > espp::Logger::Verbosity::ERROR) return; - if (rate_limit_ > std::chrono::duration::zero()) { - auto now = Logger::clock_t::now(); - auto duration = std::chrono::duration_cast>(now - last_print_); - if (duration < rate_limit_) + if (rate_limit_ > clock_t::duration::zero()) { + const auto now = clock_t::now().time_since_epoch().count(); + // last_print_ is an atomic timestamp (clock_t rep) so the check/update is + // free of data races when logging from multiple threads. + if (clock_t::duration(now - last_print_.load()) < rate_limit_) return; - last_print_ = now; + last_print_.store(now); } // forward the arguments to the error function error(rt_fmt_str, std::forward(args)...); @@ -486,10 +494,10 @@ rate limit. @note Only calls that have _rate_limited suffixed will be rate limit mutable std::mutex tag_mutex_; ///< Mutex for the tag. std::string tag_; ///< Name of the logger to be prepended to all logs. - std::chrono::duration rate_limit_{ - 0.0f}; ///< Rate limit for the logger. If set to 0, no rate limiting will be performed. - Logger::clock_t::time_point - last_print_{}; ///< Last time a log was printed. Used for rate limiting. + clock_t::duration rate_limit_{ + clock_t::duration::zero()}; ///< Rate limit for the logger. If zero, no rate limiting is done. + std::atomic last_print_{ + 0}; ///< Epoch count (clock_t rep) of the last printed log. Used for rate limiting. std::atomic include_time_{true}; ///< Whether to include the time in the log. std::atomic level_ = espp::Logger::Verbosity::WARN; ///< Current verbosity level of the logger.