From 6209e31fef0b38c7aeef15868519a5d963728e9b Mon Sep 17 00:00:00 2001 From: James Knight Date: Sat, 8 Mar 2025 13:43:56 -0500 Subject: [PATCH] support using a priority inheritance protocol Provides initial support for utilizing a priority inheritance protocol for mutexes if supported by the threading library. Developers can opt to build with `SPDLOG_PRIORITY_INHERITANCE` enabled to help avoid priority inversion scenarios. Signed-off-by: James Knight --- CMakeLists.txt | 2 + include/spdlog/details/backtracer-inl.h | 16 +-- include/spdlog/details/backtracer.h | 3 +- include/spdlog/details/console_globals.h | 5 +- include/spdlog/details/mpmc_blocking_q.h | 29 ++-- include/spdlog/details/mutex.h | 144 +++++++++++++++++++ include/spdlog/details/periodic_worker-inl.h | 2 +- include/spdlog/details/periodic_worker.h | 6 +- include/spdlog/details/registry-inl.h | 46 +++--- include/spdlog/details/registry.h | 9 +- 10 files changed, 207 insertions(+), 55 deletions(-) create mode 100644 include/spdlog/details/mutex.h diff --git a/CMakeLists.txt b/CMakeLists.txt index e1a4a41e..7b14fa5a 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -91,6 +91,7 @@ option(SPDLOG_USE_STD_FORMAT "Use std::format instead of fmt library." OFF) option(SPDLOG_FMT_EXTERNAL "Use external fmt library instead of bundled" OFF) option(SPDLOG_FMT_EXTERNAL_HO "Use external fmt header-only library instead of bundled" OFF) option(SPDLOG_NO_EXCEPTIONS "Compile with -fno-exceptions. Call abort() on any spdlog exceptions" OFF) +option(SPDLOG_PRIORITY_INHERITANCE "Compile with priority inheritance protocols" OFF) if (SPDLOG_FMT_EXTERNAL AND SPDLOG_FMT_EXTERNAL_HO) message(FATAL_ERROR "SPDLOG_FMT_EXTERNAL and SPDLOG_FMT_EXTERNAL_HO are mutually exclusive") @@ -280,6 +281,7 @@ foreach ( SPDLOG_NO_TLS SPDLOG_NO_ATOMIC_LEVELS SPDLOG_DISABLE_DEFAULT_LOGGER + SPDLOG_PRIORITY_INHERITANCE SPDLOG_USE_STD_FORMAT) if (${SPDLOG_OPTION}) target_compile_definitions(spdlog PUBLIC ${SPDLOG_OPTION}) diff --git a/include/spdlog/details/backtracer-inl.h b/include/spdlog/details/backtracer-inl.h index 43d10024..1aee70da 100644 --- a/include/spdlog/details/backtracer-inl.h +++ b/include/spdlog/details/backtracer-inl.h @@ -9,50 +9,50 @@ namespace spdlog { namespace details { SPDLOG_INLINE backtracer::backtracer(const backtracer &other) { - std::lock_guard lock(other.mutex_); + std::lock_guard lock(other.mutex_); enabled_ = other.enabled(); messages_ = other.messages_; } SPDLOG_INLINE backtracer::backtracer(backtracer &&other) SPDLOG_NOEXCEPT { - std::lock_guard lock(other.mutex_); + std::lock_guard lock(other.mutex_); enabled_ = other.enabled(); messages_ = std::move(other.messages_); } SPDLOG_INLINE backtracer &backtracer::operator=(backtracer other) { - std::lock_guard lock(mutex_); + std::lock_guard lock(mutex_); enabled_ = other.enabled(); messages_ = std::move(other.messages_); return *this; } SPDLOG_INLINE void backtracer::enable(size_t size) { - std::lock_guard lock{mutex_}; + std::lock_guard lock{mutex_}; enabled_.store(true, std::memory_order_relaxed); messages_ = circular_q{size}; } SPDLOG_INLINE void backtracer::disable() { - std::lock_guard lock{mutex_}; + std::lock_guard lock{mutex_}; enabled_.store(false, std::memory_order_relaxed); } SPDLOG_INLINE bool backtracer::enabled() const { return enabled_.load(std::memory_order_relaxed); } SPDLOG_INLINE void backtracer::push_back(const log_msg &msg) { - std::lock_guard lock{mutex_}; + std::lock_guard lock{mutex_}; messages_.push_back(log_msg_buffer{msg}); } SPDLOG_INLINE bool backtracer::empty() const { - std::lock_guard lock{mutex_}; + std::lock_guard lock{mutex_}; return messages_.empty(); } // pop all items in the q and apply the given fun on each of them. SPDLOG_INLINE void backtracer::foreach_pop(std::function fun) { - std::lock_guard lock{mutex_}; + std::lock_guard lock{mutex_}; while (!messages_.empty()) { auto &front_msg = messages_.front(); fun(front_msg); diff --git a/include/spdlog/details/backtracer.h b/include/spdlog/details/backtracer.h index 541339cd..38948a04 100644 --- a/include/spdlog/details/backtracer.h +++ b/include/spdlog/details/backtracer.h @@ -5,6 +5,7 @@ #include #include +#include #include #include @@ -16,7 +17,7 @@ namespace spdlog { namespace details { class SPDLOG_API backtracer { - mutable std::mutex mutex_; + mutable spdlog_mutex mutex_; std::atomic enabled_{false}; circular_q messages_; diff --git a/include/spdlog/details/console_globals.h b/include/spdlog/details/console_globals.h index 9c552106..289424b6 100644 --- a/include/spdlog/details/console_globals.h +++ b/include/spdlog/details/console_globals.h @@ -4,6 +4,7 @@ #pragma once #include +#include #include namespace spdlog { @@ -12,8 +13,8 @@ namespace details { struct console_mutex { using mutex_t = std::mutex; static mutex_t &mutex() { - static mutex_t s_mutex; - return s_mutex; + static spdlog_mutex s_mutex; + return s_mutex.mtx(); } }; diff --git a/include/spdlog/details/mpmc_blocking_q.h b/include/spdlog/details/mpmc_blocking_q.h index 5848cca8..83174192 100644 --- a/include/spdlog/details/mpmc_blocking_q.h +++ b/include/spdlog/details/mpmc_blocking_q.h @@ -11,6 +11,7 @@ // passed. #include +#include #include #include @@ -30,7 +31,7 @@ public: // try to enqueue and block if no room left void enqueue(T &&item) { { - std::unique_lock lock(queue_mutex_); + std::unique_lock lock(queue_mutex_.mtx()); pop_cv_.wait(lock, [this] { return !this->q_.full(); }); q_.push_back(std::move(item)); } @@ -40,7 +41,7 @@ public: // enqueue immediately. overrun oldest message in the queue if no room left. void enqueue_nowait(T &&item) { { - std::unique_lock lock(queue_mutex_); + std::unique_lock lock(queue_mutex_.mtx()); q_.push_back(std::move(item)); } push_cv_.notify_one(); @@ -49,7 +50,7 @@ public: void enqueue_if_have_room(T &&item) { bool pushed = false; { - std::unique_lock lock(queue_mutex_); + std::unique_lock lock(queue_mutex_.mtx()); if (!q_.full()) { q_.push_back(std::move(item)); pushed = true; @@ -67,7 +68,7 @@ public: // Return true, if succeeded dequeue item, false otherwise bool dequeue_for(T &popped_item, std::chrono::milliseconds wait_duration) { { - std::unique_lock lock(queue_mutex_); + std::unique_lock lock(queue_mutex_.mtx()); if (!push_cv_.wait_for(lock, wait_duration, [this] { return !this->q_.empty(); })) { return false; } @@ -81,7 +82,7 @@ public: // blocking dequeue without a timeout. void dequeue(T &popped_item) { { - std::unique_lock lock(queue_mutex_); + std::unique_lock lock(queue_mutex_.mtx()); push_cv_.wait(lock, [this] { return !this->q_.empty(); }); popped_item = std::move(q_.front()); q_.pop_front(); @@ -95,7 +96,7 @@ public: // try to enqueue and block if no room left void enqueue(T &&item) { - std::unique_lock lock(queue_mutex_); + std::unique_lock lock(queue_mutex_.mtx()); pop_cv_.wait(lock, [this] { return !this->q_.full(); }); q_.push_back(std::move(item)); push_cv_.notify_one(); @@ -103,14 +104,14 @@ public: // enqueue immediately. overrun oldest message in the queue if no room left. void enqueue_nowait(T &&item) { - std::unique_lock lock(queue_mutex_); + std::unique_lock lock(queue_mutex_.mtx()); q_.push_back(std::move(item)); push_cv_.notify_one(); } void enqueue_if_have_room(T &&item) { bool pushed = false; - std::unique_lock lock(queue_mutex_); + std::unique_lock lock(queue_mutex_.mtx()); if (!q_.full()) { q_.push_back(std::move(item)); pushed = true; @@ -126,7 +127,7 @@ public: // dequeue with a timeout. // Return true, if succeeded dequeue item, false otherwise bool dequeue_for(T &popped_item, std::chrono::milliseconds wait_duration) { - std::unique_lock lock(queue_mutex_); + std::unique_lock lock(queue_mutex_.mtx()); if (!push_cv_.wait_for(lock, wait_duration, [this] { return !this->q_.empty(); })) { return false; } @@ -138,7 +139,7 @@ public: // blocking dequeue without a timeout. void dequeue(T &popped_item) { - std::unique_lock lock(queue_mutex_); + std::unique_lock lock(queue_mutex_.mtx()); push_cv_.wait(lock, [this] { return !this->q_.empty(); }); popped_item = std::move(q_.front()); q_.pop_front(); @@ -148,26 +149,26 @@ public: #endif size_t overrun_counter() { - std::lock_guard lock(queue_mutex_); + std::lock_guard lock(queue_mutex_.mtx()); return q_.overrun_counter(); } size_t discard_counter() { return discard_counter_.load(std::memory_order_relaxed); } size_t size() { - std::lock_guard lock(queue_mutex_); + std::lock_guard lock(queue_mutex_.mtx()); return q_.size(); } void reset_overrun_counter() { - std::lock_guard lock(queue_mutex_); + std::lock_guard lock(queue_mutex_.mtx()); q_.reset_overrun_counter(); } void reset_discard_counter() { discard_counter_.store(0, std::memory_order_relaxed); } private: - std::mutex queue_mutex_; + spdlog_mutex queue_mutex_; std::condition_variable push_cv_; std::condition_variable pop_cv_; spdlog::details::circular_q q_; diff --git a/include/spdlog/details/mutex.h b/include/spdlog/details/mutex.h new file mode 100644 index 00000000..4fd6c0c8 --- /dev/null +++ b/include/spdlog/details/mutex.h @@ -0,0 +1,144 @@ +// SPDX-License-Identifier: MIT +// Copyright(c) spdlog contributors + +// Mutexes used to help support priority inheritance support +// +// Standard library implementations will typically create mutexes that do +// not take into consideration the priority and scheduling of the thread +// they claim ownership on. In (near) real-time implementations, this is +// not ideal since this may lead to priority inversion scenarios. +// +// The following provides mutex implementations that can help avoid priority +// inversion scenarios by ensuring the underlying mutexes used take advantage +// of priority inheritance protocols. spdlog uses `std::mutex` and +// `std::recursive_mutex`, which are typically not priority inversion "safe". +// Therefore, we introduces custom mutexes for them below. Calls such as +// `std::condition_variable` are fine if the managed mutex used by the +// `std::unique_lock` are safe. However, the use of +// `std::condition_variable_any` is not due their implementations relying on +// both a provided mutex and an internal `std::mutex`. This is why the +// implementation opts for using `std::condition_variable` with the help of +// `mtx()` methods over using `std::condition_variable_any`. + +#pragma once + +#include +#include + +namespace spdlog { +namespace details { + + +class spdlog_mutex { +public: + spdlog_mutex() { +#ifdef SPDLOG_PRIORITY_INHERITANCE +#if defined(_GLIBCXX_HAS_GTHREADS) || defined(_LIBCPP_HAS_THREAD_API_PTHREAD) + pthread_mutexattr_t attr; + int ret = pthread_mutexattr_init(&attr); + if (ret != 0) { + return; + } + + ret = pthread_mutexattr_setprotocol(&attr, PTHREAD_PRIO_INHERIT); + if (ret != 0) { + return; + } + + auto handle = mtx_.native_handle(); + ret = pthread_mutex_destroy(handle); + if (ret < 0) { + throw_spdlog_ex("failed to tear down mutex", ret); + } + + ret = pthread_mutex_init(handle, &attr); + if (ret < 0) { + throw_spdlog_ex("failed to build mutex", ret); + } +#else + #error Priority inheritance is not supported. +#endif +#endif + } + + void lock() { + mtx_.lock(); + } + + bool try_lock() { + return mtx_.try_lock(); + } + + void unlock() { + mtx_.unlock(); + } + + std::mutex& mtx() { + return mtx_; + } + +private: + std::mutex mtx_; +}; + + +class spdlog_recursive_mutex { +public: + spdlog_recursive_mutex() { +#ifdef SPDLOG_PRIORITY_INHERITANCE +#if defined(_GLIBCXX_HAS_GTHREADS) || defined(_LIBCPP_HAS_THREAD_API_PTHREAD) + pthread_mutexattr_t attr; + int ret = pthread_mutexattr_init(&attr); + if (ret != 0) { + return; + } + + ret = pthread_mutexattr_setprotocol(&attr, PTHREAD_PRIO_INHERIT); + if (ret != 0) { + return; + } + + ret = pthread_mutexattr_settype(&attr, PTHREAD_MUTEX_RECURSIVE); + if (ret != 0) { + return; + } + + auto handle = mtx_.native_handle(); + ret = pthread_mutex_destroy(handle); + if (ret < 0) { + throw_spdlog_ex("failed to tear down mutex", ret); + } + + ret = pthread_mutex_init(handle, &attr); + if (ret < 0) { + throw_spdlog_ex("failed to build mutex", ret); + } +#else + #error Priority inheritance is not supported. +#endif +#endif + } + + void lock() { + mtx_.lock(); + } + + bool try_lock() { + return mtx_.try_lock(); + } + + void unlock() { + mtx_.unlock(); + } + + std::recursive_mutex& mtx() { + return mtx_; + } + +private: + std::recursive_mutex mtx_; +}; + + +} // namespace details +} // namespace spdlog diff --git a/include/spdlog/details/periodic_worker-inl.h b/include/spdlog/details/periodic_worker-inl.h index 18f11fbe..d0309c47 100644 --- a/include/spdlog/details/periodic_worker-inl.h +++ b/include/spdlog/details/periodic_worker-inl.h @@ -14,7 +14,7 @@ namespace details { SPDLOG_INLINE periodic_worker::~periodic_worker() { if (worker_thread_.joinable()) { { - std::lock_guard lock(mutex_); + std::lock_guard lock(mutex_); active_ = false; } cv_.notify_one(); diff --git a/include/spdlog/details/periodic_worker.h b/include/spdlog/details/periodic_worker.h index d647b66e..0ffcfe11 100644 --- a/include/spdlog/details/periodic_worker.h +++ b/include/spdlog/details/periodic_worker.h @@ -10,6 +10,8 @@ // stops and joins the thread on destruction (if the thread is executing a callback, wait for it // to finish first). +#include + #include #include #include @@ -30,7 +32,7 @@ public: worker_thread_ = std::thread([this, callback_fun, interval]() { for (;;) { - std::unique_lock lock(this->mutex_); + std::unique_lock lock(this->mutex_.mtx()); if (this->cv_.wait_for(lock, interval, [this] { return !this->active_; })) { return; // active_ == false, so exit this thread } @@ -47,7 +49,7 @@ public: private: bool active_; std::thread worker_thread_; - std::mutex mutex_; + spdlog_mutex mutex_; std::condition_variable cv_; }; } // namespace details diff --git a/include/spdlog/details/registry-inl.h b/include/spdlog/details/registry-inl.h index f447848e..dfeb57ec 100644 --- a/include/spdlog/details/registry-inl.h +++ b/include/spdlog/details/registry-inl.h @@ -50,12 +50,12 @@ SPDLOG_INLINE registry::registry() SPDLOG_INLINE registry::~registry() = default; SPDLOG_INLINE void registry::register_logger(std::shared_ptr new_logger) { - std::lock_guard lock(logger_map_mutex_); + std::lock_guard lock(logger_map_mutex_); register_logger_(std::move(new_logger)); } SPDLOG_INLINE void registry::initialize_logger(std::shared_ptr new_logger) { - std::lock_guard lock(logger_map_mutex_); + std::lock_guard lock(logger_map_mutex_); new_logger->set_formatter(formatter_->clone()); if (err_handler_) { @@ -79,13 +79,13 @@ SPDLOG_INLINE void registry::initialize_logger(std::shared_ptr new_logge } SPDLOG_INLINE std::shared_ptr registry::get(const std::string &logger_name) { - std::lock_guard lock(logger_map_mutex_); + std::lock_guard lock(logger_map_mutex_); auto found = loggers_.find(logger_name); return found == loggers_.end() ? nullptr : found->second; } SPDLOG_INLINE std::shared_ptr registry::default_logger() { - std::lock_guard lock(logger_map_mutex_); + std::lock_guard lock(logger_map_mutex_); return default_logger_; } @@ -98,7 +98,7 @@ SPDLOG_INLINE logger *registry::get_default_raw() { return default_logger_.get() // set default logger. // default logger is stored in default_logger_ (for faster retrieval) and in the loggers_ map. SPDLOG_INLINE void registry::set_default_logger(std::shared_ptr new_default_logger) { - std::lock_guard lock(logger_map_mutex_); + std::lock_guard lock(logger_map_mutex_); if (new_default_logger != nullptr) { loggers_[new_default_logger->name()] = new_default_logger; } @@ -106,18 +106,18 @@ SPDLOG_INLINE void registry::set_default_logger(std::shared_ptr new_defa } SPDLOG_INLINE void registry::set_tp(std::shared_ptr tp) { - std::lock_guard lock(tp_mutex_); + std::lock_guard lock(tp_mutex_); tp_ = std::move(tp); } SPDLOG_INLINE std::shared_ptr registry::get_tp() { - std::lock_guard lock(tp_mutex_); + std::lock_guard lock(tp_mutex_); return tp_; } // Set global formatter. Each sink in each logger will get a clone of this object SPDLOG_INLINE void registry::set_formatter(std::unique_ptr formatter) { - std::lock_guard lock(logger_map_mutex_); + std::lock_guard lock(logger_map_mutex_); formatter_ = std::move(formatter); for (auto &l : loggers_) { l.second->set_formatter(formatter_->clone()); @@ -125,7 +125,7 @@ SPDLOG_INLINE void registry::set_formatter(std::unique_ptr formatter) } SPDLOG_INLINE void registry::enable_backtrace(size_t n_messages) { - std::lock_guard lock(logger_map_mutex_); + std::lock_guard lock(logger_map_mutex_); backtrace_n_messages_ = n_messages; for (auto &l : loggers_) { @@ -134,7 +134,7 @@ SPDLOG_INLINE void registry::enable_backtrace(size_t n_messages) { } SPDLOG_INLINE void registry::disable_backtrace() { - std::lock_guard lock(logger_map_mutex_); + std::lock_guard lock(logger_map_mutex_); backtrace_n_messages_ = 0; for (auto &l : loggers_) { l.second->disable_backtrace(); @@ -142,7 +142,7 @@ SPDLOG_INLINE void registry::disable_backtrace() { } SPDLOG_INLINE void registry::set_level(level::level_enum log_level) { - std::lock_guard lock(logger_map_mutex_); + std::lock_guard lock(logger_map_mutex_); for (auto &l : loggers_) { l.second->set_level(log_level); } @@ -150,7 +150,7 @@ SPDLOG_INLINE void registry::set_level(level::level_enum log_level) { } SPDLOG_INLINE void registry::flush_on(level::level_enum log_level) { - std::lock_guard lock(logger_map_mutex_); + std::lock_guard lock(logger_map_mutex_); for (auto &l : loggers_) { l.second->flush_on(log_level); } @@ -158,7 +158,7 @@ SPDLOG_INLINE void registry::flush_on(level::level_enum log_level) { } SPDLOG_INLINE void registry::set_error_handler(err_handler handler) { - std::lock_guard lock(logger_map_mutex_); + std::lock_guard lock(logger_map_mutex_); for (auto &l : loggers_) { l.second->set_error_handler(handler); } @@ -167,21 +167,21 @@ SPDLOG_INLINE void registry::set_error_handler(err_handler handler) { SPDLOG_INLINE void registry::apply_all( const std::function)> &fun) { - std::lock_guard lock(logger_map_mutex_); + std::lock_guard lock(logger_map_mutex_); for (auto &l : loggers_) { fun(l.second); } } SPDLOG_INLINE void registry::flush_all() { - std::lock_guard lock(logger_map_mutex_); + std::lock_guard lock(logger_map_mutex_); for (auto &l : loggers_) { l.second->flush(); } } SPDLOG_INLINE void registry::drop(const std::string &logger_name) { - std::lock_guard lock(logger_map_mutex_); + std::lock_guard lock(logger_map_mutex_); auto is_default_logger = default_logger_ && default_logger_->name() == logger_name; loggers_.erase(logger_name); if (is_default_logger) { @@ -190,7 +190,7 @@ SPDLOG_INLINE void registry::drop(const std::string &logger_name) { } SPDLOG_INLINE void registry::drop_all() { - std::lock_guard lock(logger_map_mutex_); + std::lock_guard lock(logger_map_mutex_); loggers_.clear(); default_logger_.reset(); } @@ -198,27 +198,27 @@ SPDLOG_INLINE void registry::drop_all() { // clean all resources and threads started by the registry SPDLOG_INLINE void registry::shutdown() { { - std::lock_guard lock(flusher_mutex_); + std::lock_guard lock(flusher_mutex_); periodic_flusher_.reset(); } drop_all(); { - std::lock_guard lock(tp_mutex_); + std::lock_guard lock(tp_mutex_); tp_.reset(); } } -SPDLOG_INLINE std::recursive_mutex ®istry::tp_mutex() { return tp_mutex_; } +SPDLOG_INLINE std::recursive_mutex ®istry::tp_mutex() { return tp_mutex_.mtx(); } SPDLOG_INLINE void registry::set_automatic_registration(bool automatic_registration) { - std::lock_guard lock(logger_map_mutex_); + std::lock_guard lock(logger_map_mutex_); automatic_registration_ = automatic_registration; } SPDLOG_INLINE void registry::set_levels(log_levels levels, level::level_enum *global_level) { - std::lock_guard lock(logger_map_mutex_); + std::lock_guard lock(logger_map_mutex_); log_levels_ = std::move(levels); auto global_level_requested = global_level != nullptr; global_log_level_ = global_level_requested ? *global_level : global_log_level_; @@ -239,7 +239,7 @@ SPDLOG_INLINE registry ®istry::instance() { } SPDLOG_INLINE void registry::apply_logger_env_levels(std::shared_ptr new_logger) { - std::lock_guard lock(logger_map_mutex_); + std::lock_guard lock(logger_map_mutex_); auto it = log_levels_.find(new_logger->name()); auto new_level = it != log_levels_.end() ? it->second : global_log_level_; new_logger->set_level(new_level); diff --git a/include/spdlog/details/registry.h b/include/spdlog/details/registry.h index 8afcbd6f..5e1172ad 100644 --- a/include/spdlog/details/registry.h +++ b/include/spdlog/details/registry.h @@ -10,6 +10,7 @@ #include #include +#include #include #include @@ -65,13 +66,13 @@ public: template void flush_every(std::chrono::duration interval) { - std::lock_guard lock(flusher_mutex_); + std::lock_guard lock(flusher_mutex_); auto clbk = [this]() { this->flush_all(); }; periodic_flusher_ = details::make_unique(clbk, interval); } std::unique_ptr &get_flusher() { - std::lock_guard lock(flusher_mutex_); + std::lock_guard lock(flusher_mutex_); return periodic_flusher_; } @@ -106,8 +107,8 @@ private: void throw_if_exists_(const std::string &logger_name); void register_logger_(std::shared_ptr new_logger); bool set_level_from_cfg_(logger *logger); - std::mutex logger_map_mutex_, flusher_mutex_; - std::recursive_mutex tp_mutex_; + spdlog_mutex logger_map_mutex_, flusher_mutex_; + spdlog_recursive_mutex tp_mutex_; std::unordered_map> loggers_; log_levels log_levels_; std::unique_ptr formatter_;