From 547964010cc2eccb61ccc966124532cf9d7202a8 Mon Sep 17 00:00:00 2001 From: Stephanie Date: Mon, 2 Sep 2024 22:23:06 -0400 Subject: [PATCH] Update quill to 6.1.2 --- CMakeLists.txt | 4 +- examples/logging_example/main.cc | 27 ++++++++++---- .../data_logger_thread.cc | 1 + examples/message_passing_example/rt_thread.cc | 2 + examples/tracing_example_no_rt/main.cc | 12 +++++- include/cactus_rt/app.h | 21 +++-------- include/cactus_rt/config.h | 37 +++++++++++++++++-- include/cactus_rt/logger.h | 35 ++++++++++++++++++ include/cactus_rt/ros2/publisher.h | 8 ++-- include/cactus_rt/ros2/ros2_adapter.h | 3 +- include/cactus_rt/ros2/subscription.h | 8 ++-- include/cactus_rt/thread.h | 8 ++-- include/cactus_rt/tracing/trace_aggregator.h | 11 +++--- src/cactus_rt/app.cc | 25 +++++++------ src/cactus_rt/ros2/app.cc | 2 +- src/cactus_rt/ros2/ros2_adapter.cc | 4 +- src/cactus_rt/thread.cc | 3 +- src/cactus_rt/tracing/trace_aggregator.cc | 6 +-- 18 files changed, 148 insertions(+), 69 deletions(-) create mode 100644 include/cactus_rt/logger.h diff --git a/CMakeLists.txt b/CMakeLists.txt index 80e7220..d37c3c4 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -27,8 +27,8 @@ if(CACTUS_RT_ENABLE_FETCH_DEPENDENCIES) FetchContent_Declare( quill GIT_REPOSITORY https://github.com/odygrd/quill.git - GIT_TAG 9a270d5d6f57a3ac19451292e3a9f370fcd744b1 - # GIT_TAG v3.3.2 + GIT_TAG 1401d2d90f85a6b83ab1b259590d8ba227446a92 + # GIT_TAG v6.1.2 ) FetchContent_MakeAvailable(quill) diff --git a/examples/logging_example/main.cc b/examples/logging_example/main.cc index 89c8b6d..7110b67 100644 --- a/examples/logging_example/main.cc +++ b/examples/logging_example/main.cc @@ -3,6 +3,8 @@ #include #include +#include "quill/sinks/FileSink.h" + using cactus_rt::App; using cactus_rt::CyclicThread; @@ -26,7 +28,7 @@ class ExampleRTThread : public CyclicThread { if (loop_counter_ % 1000 == 0) { LOG_INFO(Logger(), "Loop {}", loop_counter_); } - LOG_INFO_LIMIT(std::chrono::milliseconds{1500}, Logger(), "Log limit: Loop {}", loop_counter_); + LOG_DEBUG_LIMIT(std::chrono::milliseconds{1500}, Logger(), "Log limit: Loop {}", loop_counter_); return LoopControl::Continue; } }; @@ -40,14 +42,25 @@ int main() { // Create a cactus_rt app configuration cactus_rt::AppConfig app_config; - // Create a Quill logging config to configure logging - quill::Config logging_config; - - // Disable strict timestamp order - this will be faster, but logs may appear out of order - logging_config.backend_thread_strict_log_timestamp_order = false; + // Create a logging config to configure logging + cactus_rt::LoggerConfig logging_config; // Set the background logging thread CPU affinity - logging_config.backend_thread_cpu_affinity = 1; // Different CPU than the CyclicThread CPU! + logging_config.backend_options.backend_cpu_affinity = 1; // Different CPU than the CyclicThread CPU! + + // Configure the log level for debug messages + logging_config.log_level = quill::LogLevel::Debug; + + logging_config.sink = cactus_rt::Frontend::create_or_get_sink( + "log_file", + []() { + quill::FileSinkConfig cfg; + cfg.set_open_mode('w'); + cfg.set_filename_append_option(quill::FilenameAppendOption::StartDateTime); + return cfg; + }(), + quill::FileEventNotifier{} + ); app_config.logger_config = logging_config; App app("LoggingExampleApp", app_config); diff --git a/examples/message_passing_example/data_logger_thread.cc b/examples/message_passing_example/data_logger_thread.cc index c83f4b6..1a1866a 100644 --- a/examples/message_passing_example/data_logger_thread.cc +++ b/examples/message_passing_example/data_logger_thread.cc @@ -1,6 +1,7 @@ #include "data_logger_thread.h" #include +#include DataLogger::DataLogger( const std::string& data_file_path, diff --git a/examples/message_passing_example/rt_thread.cc b/examples/message_passing_example/rt_thread.cc index 6028bd8..b5bb192 100644 --- a/examples/message_passing_example/rt_thread.cc +++ b/examples/message_passing_example/rt_thread.cc @@ -1,5 +1,7 @@ #include "rt_thread.h" +#include + cactus_rt::CyclicThread::LoopControl RtThread::Loop(int64_t ellapsed_ns) noexcept { const double ellapsed_ms = static_cast(ellapsed_ns) / 1'000'000.0; diff --git a/examples/tracing_example_no_rt/main.cc b/examples/tracing_example_no_rt/main.cc index 86bc64f..69623da 100644 --- a/examples/tracing_example_no_rt/main.cc +++ b/examples/tracing_example_no_rt/main.cc @@ -1,4 +1,7 @@ +#include #include +#include +#include #include #include @@ -19,13 +22,18 @@ void StartTracing(const char* app_name, const char* filename) { // Enable the tracing. cactus_rt::tracing::EnableTracing(); + // Create a logger + cactus_rt::Logger* logger = cactus_rt::Frontend::create_or_get_logger( + "TraceAggregatorLogger", cactus_rt::Frontend::create_or_get_sink("console_sink") + ); + // Create the trace aggregator that will pop the queues and write the events to sinks. - trace_aggregator = std::make_unique(app_name); + trace_aggregator = std::make_unique(app_name, logger); // Create the file sink so the data aggregated by the TraceAggregator will be written to somewhere. auto file_sink = std::make_shared(filename); - quill::start(); + quill::Backend::start(); trace_aggregator->Start(file_sink); } diff --git a/include/cactus_rt/app.h b/include/cactus_rt/app.h index c2907ad..27aea25 100644 --- a/include/cactus_rt/app.h +++ b/include/cactus_rt/app.h @@ -8,7 +8,7 @@ #include #include "config.h" -#include "quill/Quill.h" +#include "logger.h" #include "thread.h" #include "tracing/thread_tracer.h" #include "tracing/trace_aggregator.h" @@ -29,7 +29,7 @@ class App { size_t heap_size_; // Configuration for quill logging - quill::Config logger_config_; + LoggerConfig logger_config_; TracerConfig tracer_config_; @@ -37,18 +37,6 @@ class App { std::vector> threads_; - void SetDefaultLogFormat(quill::Config& cfg) { - // Create a handler of stdout - const std::shared_ptr handler = quill::stdout_handler(); - - // Enable console colours on the handler - static_cast(handler.get())->enable_console_colours(); - - // Set the default pattern - handler->set_pattern("[%(ascii_time)][%(level_id)][%(logger_name)][%(filename):%(lineno)] %(message)", "%Y-%m-%d %H:%M:%S.%Qns"); - cfg.default_handlers.push_back(handler); - } - public: explicit App(std::string name = "RTApp", AppConfig config = AppConfig()); @@ -62,6 +50,8 @@ class App { App(App&&) noexcept = delete; App& operator=(App&&) noexcept = delete; + cactus_rt::Logger* CreateLogger(const std::string& name) const; + template std::shared_ptr CreateThread(Args&&... args) { static_assert(std::is_base_of_v, "Must derive from cactus_rt::Thread"); @@ -70,6 +60,7 @@ class App { Thread* base_thread = thread.get(); base_thread->trace_aggregator_ = trace_aggregator_; base_thread->created_by_app_ = true; + base_thread->logger_ = CreateLogger(base_thread->name_); threads_.push_back(thread); @@ -143,7 +134,7 @@ class App { /** * Starts the Quill background logging thread. */ - void StartQuill(); + void StartQuill() const; private: void StopTraceAggregator() noexcept; diff --git a/include/cactus_rt/config.h b/include/cactus_rt/config.h index 73d9e9a..adab7c2 100644 --- a/include/cactus_rt/config.h +++ b/include/cactus_rt/config.h @@ -1,11 +1,14 @@ #ifndef CACTUS_RT_CONFIG_H_ #define CACTUS_RT_CONFIG_H_ -#include - #include #include "cactus_rt/scheduler.h" +#include "logger.h" +#include "quill/backend/BackendOptions.h" +#include "quill/core/LogLevel.h" +#include "quill/sinks/ConsoleSink.h" +#include "quill/sinks/Sink.h" namespace cactus_rt { @@ -19,6 +22,34 @@ struct TracerConfig { std::vector trace_aggregator_cpu_affinity; }; +struct LoggerConfig { + /** + * @brief Backend options for Quill logging + */ + quill::BackendOptions backend_options; + + /** + * @brief Pattern for formatting logs + */ + std::string format_pattern = "[%(time)][%(log_level)][%(logger)][%(file_name):%(line_number)] %(message)"; + + /** + * @brief Pattern for formatting time + */ + std::string time_pattern = "%Y-%m-%d %H:%M:%S.%Qns"; + + /** + * @brief Log level for Quill logging + */ + quill::LogLevel log_level = quill::LogLevel::Info; + + /** + * @brief The sink to log to. Default is console. + */ + std::shared_ptr sink; + + LoggerConfig() : sink(Frontend::create_or_get_sink("console_sink")) {} +}; /** * @brief The configuration required for an App */ @@ -31,7 +62,7 @@ struct AppConfig { /** * @brief The configuration for quill logging */ - quill::Config logger_config; + LoggerConfig logger_config; /** * @brief The config for the tracer if enabled (ENABLE_TRACING option in cmake) diff --git a/include/cactus_rt/logger.h b/include/cactus_rt/logger.h new file mode 100644 index 0000000..3746f69 --- /dev/null +++ b/include/cactus_rt/logger.h @@ -0,0 +1,35 @@ +#ifndef CACTUS_RT_LOGGER_H_ +#define CACTUS_RT_LOGGER_H_ + +#include "quill/Frontend.h" +#include "quill/LogMacros.h" +#include "quill/core/Common.h" +#include "quill/std/Array.h" +#include "quill/std/Chrono.h" +#include "quill/std/Deque.h" +#include "quill/std/FilesystemPath.h" +#include "quill/std/ForwardList.h" +#include "quill/std/List.h" +#include "quill/std/Map.h" +#include "quill/std/Optional.h" +#include "quill/std/Pair.h" +#include "quill/std/Set.h" +#include "quill/std/Tuple.h" +#include "quill/std/UnorderedMap.h" +#include "quill/std/UnorderedSet.h" +#include "quill/std/Vector.h" +#include "quill/std/WideString.h" + +namespace cactus_rt { +struct FrontendOptions { + // Set the queue to BoundedDropping to prevent allocation + static constexpr quill::QueueType queue_type = quill::QueueType::BoundedDropping; + static constexpr uint32_t initial_queue_capacity = 131'072; + static constexpr int32_t blocking_queue_retry_interval_ns = 800; + static constexpr bool huge_pages_enabled = false; +}; + +using Frontend = quill::FrontendImpl; +using Logger = quill::LoggerImpl; +} // namespace cactus_rt +#endif diff --git a/include/cactus_rt/ros2/publisher.h b/include/cactus_rt/ros2/publisher.h index c8fd498..34dfde7 100644 --- a/include/cactus_rt/ros2/publisher.h +++ b/include/cactus_rt/ros2/publisher.h @@ -7,7 +7,7 @@ #include #include -#include "quill/Quill.h" +#include "../logger.h" namespace cactus_rt::ros2 { class Ros2Adapter; @@ -31,7 +31,7 @@ class Publisher : public IPublisher { using NoConversion = std::is_same; using AdaptedRosType = typename std::conditional_t>; - quill::Logger* logger_; + cactus_rt::Logger* logger_; typename rclcpp::Publisher::SharedPtr publisher_; moodycamel::ReaderWriterQueue queue_; @@ -77,7 +77,7 @@ class Publisher : public IPublisher { } static std::shared_ptr> Create( - quill::Logger* logger, + cactus_rt::Logger* logger, rclcpp::Node& node, const std::string& topic_name, const rclcpp::QoS& qos, @@ -93,7 +93,7 @@ class Publisher : public IPublisher { } Publisher( - quill::Logger* logger, + cactus_rt::Logger* logger, typename rclcpp::Publisher::SharedPtr publisher, moodycamel::ReaderWriterQueue&& queue ) : logger_(logger), publisher_(publisher), queue_(std::move(queue)) {} diff --git a/include/cactus_rt/ros2/ros2_adapter.h b/include/cactus_rt/ros2/ros2_adapter.h index 3c5f443..33cbc44 100644 --- a/include/cactus_rt/ros2/ros2_adapter.h +++ b/include/cactus_rt/ros2/ros2_adapter.h @@ -11,7 +11,6 @@ #include #include "publisher.h" -#include "quill/Quill.h" #include "subscription.h" namespace cactus_rt::ros2 { @@ -44,7 +43,7 @@ class Ros2Adapter { std::vector> publishers_; std::vector> subscriptions_; - quill::Logger* logger_; + cactus_rt::Logger* logger_; public: Ros2Adapter(const std::string& name_, const Config& config); diff --git a/include/cactus_rt/ros2/subscription.h b/include/cactus_rt/ros2/subscription.h index a501e51..38dcc43 100644 --- a/include/cactus_rt/ros2/subscription.h +++ b/include/cactus_rt/ros2/subscription.h @@ -6,7 +6,7 @@ #include #include "../experimental/lockless/spsc/realtime_readable_value.h" -#include "quill/Quill.h" +#include "quill/Frontend.h" // Note: ROS subscription dispatch is here: https://github.com/ros2/rclcpp/blob/e10728c/rclcpp/include/rclcpp/any_subscription_callback.hpp#L481 // We are using the TypeAdapter method. @@ -40,7 +40,7 @@ class SubscriptionLatest : public ISubscription { using RealtimeReadableValue = cactus_rt::experimental::lockless::spsc::RealtimeReadableValue>; - quill::Logger* logger_; + cactus_rt::Logger* logger_; typename rclcpp::Subscription::SharedPtr ros_subscription_; int64_t current_msg_id_ = 0; RealtimeReadableValue latest_value_; @@ -57,7 +57,7 @@ class SubscriptionLatest : public ISubscription { } static std::shared_ptr> Create( - quill::Logger* logger, + cactus_rt::Logger* logger, rclcpp::Node& node, const std::string& topic_name, const rclcpp::QoS& qos @@ -78,7 +78,7 @@ class SubscriptionLatest : public ISubscription { return subscription; } - explicit SubscriptionLatest(quill::Logger* logger) : logger_(logger) {} + explicit SubscriptionLatest(cactus_rt::Logger* logger) : logger_(logger) {} public: StampedValue ReadLatest() noexcept { diff --git a/include/cactus_rt/thread.h b/include/cactus_rt/thread.h index 336a3f3..51de365 100644 --- a/include/cactus_rt/thread.h +++ b/include/cactus_rt/thread.h @@ -9,7 +9,6 @@ #include #include "config.h" -#include "quill/Quill.h" #include "tracing/thread_tracer.h" #include "tracing/trace_aggregator.h" @@ -30,7 +29,7 @@ class Thread { std::vector cpu_affinity_; size_t stack_size_; - quill::Logger* logger_; + cactus_rt::Logger* logger_; std::shared_ptr tracer_ = nullptr; std::atomic_bool stop_requested_ = false; @@ -59,8 +58,7 @@ class Thread { : config_(config), name_(name), cpu_affinity_(config_.cpu_affinity), - stack_size_(static_cast(PTHREAD_STACK_MIN) + config_.stack_size), - logger_(quill::create_logger(name_)) { + stack_size_(static_cast(PTHREAD_STACK_MIN) + config_.stack_size) { if (!config.scheduler) { throw std::runtime_error("ThreadConfig::scheduler cannot be nullptr"); } @@ -118,7 +116,7 @@ class Thread { void Start(int64_t start_monotonic_time_ns); protected: - inline quill::Logger* Logger() const { return logger_; } + inline cactus_rt::Logger* Logger() const { return logger_; } /** * Gets the current tracer object. Should only ever be called from within the thread itself. diff --git a/include/cactus_rt/tracing/trace_aggregator.h b/include/cactus_rt/tracing/trace_aggregator.h index 3b9965b..4b83c0b 100644 --- a/include/cactus_rt/tracing/trace_aggregator.h +++ b/include/cactus_rt/tracing/trace_aggregator.h @@ -4,8 +4,6 @@ #ifndef CACTUS_RT_TRACING_ENABLED #include "trace_aggregator.disabled.h" #else -#include - #include #include #include @@ -14,6 +12,7 @@ #include #include +#include "../logger.h" #include "sink.h" #include "thread_tracer.h" @@ -42,8 +41,8 @@ class TraceAggregator { const std::string process_name_; - const uint64_t process_track_uuid_; - quill::Logger* logger_; + const uint64_t process_track_uuid_; + cactus_rt::Logger* logger_; // This mutex protects tracers_ and session_ std::mutex mutex_; @@ -59,7 +58,7 @@ class TraceAggregator { std::unique_ptr session_ = nullptr; public: - explicit TraceAggregator(std::string name); + TraceAggregator(std::string name, cactus_rt::Logger* logger); // No copy no move TraceAggregator(const TraceAggregator&) = delete; @@ -94,7 +93,7 @@ class TraceAggregator { void Stop() noexcept; private: - quill::Logger* Logger() noexcept; + cactus_rt::Logger* Logger() noexcept; void Run(); bool StopRequested() const noexcept; diff --git a/src/cactus_rt/app.cc b/src/cactus_rt/app.cc index ede9ee7..7e1ca2f 100644 --- a/src/cactus_rt/app.cc +++ b/src/cactus_rt/app.cc @@ -10,7 +10,7 @@ #include "cactus_rt/tracing/trace_aggregator.h" #include "cactus_rt/tracing/tracing_enabled.h" #include "cactus_rt/utils.h" -#include "quill/Quill.h" +#include "quill/Backend.h" using FileSink = cactus_rt::tracing::FileSink; @@ -21,18 +21,12 @@ App::App(std::string name, AppConfig config) heap_size_(config.heap_size), logger_config_(config.logger_config), tracer_config_(config.tracer_config), - trace_aggregator_(std::make_shared(name)) { - if (logger_config_.default_handlers.empty()) { - SetDefaultLogFormat(logger_config_); - } - - // TODO: backend_thread_notification_handler can throw - we need to handle this somehow - // logger_config_.backend_thread_notification_handler + trace_aggregator_(std::make_shared(name, CreateLogger("__trace_aggregator__"))) { } App::~App() { + logger_config_.sink->flush_sink(); StopTraceSession(); - quill::flush(); } void App::Start(int64_t start_monotonic_time_ns) { @@ -155,9 +149,16 @@ void App::ReserveHeap() const { free(buf); } -void App::StartQuill() { - quill::configure(logger_config_); - quill::start(); +cactus_rt::Logger* App::CreateLogger(const std::string& name) const { + cactus_rt::Logger* logger = Frontend::create_or_get_logger( + name, logger_config_.sink, logger_config_.format_pattern, logger_config_.time_pattern + ); + logger->set_log_level(logger_config_.log_level); + return logger; +} + +void App::StartQuill() const { + quill::Backend::start(logger_config_.backend_options); } void App::StopTraceAggregator() noexcept { diff --git a/src/cactus_rt/ros2/app.cc b/src/cactus_rt/ros2/app.cc index 5cddc98..97f8973 100644 --- a/src/cactus_rt/ros2/app.cc +++ b/src/cactus_rt/ros2/app.cc @@ -52,7 +52,7 @@ App::App( signal_handling_thread_.detach(); // Must initialize rclcpp before making the Ros2Adapter; - ros2_adapter_ = std::make_shared(name, ros2_adapter_config); + ros2_adapter_ = std::make_shared(name, ros2_adapter_config, CreateLogger("Ros2Adapter")); ros2_executor_thread_ = CreateROS2EnabledThread(); } diff --git a/src/cactus_rt/ros2/ros2_adapter.cc b/src/cactus_rt/ros2/ros2_adapter.cc index a9efc6e..7f9f820 100644 --- a/src/cactus_rt/ros2/ros2_adapter.cc +++ b/src/cactus_rt/ros2/ros2_adapter.cc @@ -4,9 +4,9 @@ namespace cactus_rt::ros2 { -Ros2Adapter::Ros2Adapter(const std::string& name, const Ros2Adapter::Config& config) +Ros2Adapter::Ros2Adapter(const std::string& name, const Ros2Adapter::Config& config, cactus_rt::Logger* logger) : ros_node_(std::make_shared(name + "_ros_adapter")), - logger_(quill::create_logger("Ros2Adapter")) { + logger_(logger) { timer_ = this->ros_node_->create_wall_timer(config.timer_interval, [this] { TimerCallback(); }); } diff --git a/src/cactus_rt/thread.cc b/src/cactus_rt/thread.cc index 89f21c7..6568a35 100644 --- a/src/cactus_rt/thread.cc +++ b/src/cactus_rt/thread.cc @@ -37,7 +37,7 @@ void* Thread::RunThread(void* data) { ); } - quill::preallocate(); // Pre-allocates thread-local data to avoid the need to allocate on the first log message + cactus_rt::Frontend::preallocate(); // Pre-allocates thread-local data to avoid the need to allocate on the first log message thread->BeforeRun(); thread->Run(); @@ -45,6 +45,7 @@ void* Thread::RunThread(void* data) { thread->tracer_->MarkDone(); thread->tracer_ = nullptr; + thread->Logger()->flush_log(); return nullptr; } diff --git a/src/cactus_rt/tracing/trace_aggregator.cc b/src/cactus_rt/tracing/trace_aggregator.cc index b27b80d..6e040bd 100644 --- a/src/cactus_rt/tracing/trace_aggregator.cc +++ b/src/cactus_rt/tracing/trace_aggregator.cc @@ -54,10 +54,10 @@ void SetupCPUAffinityIfNecessary(const std::vector& cpu_affinity) { } // namespace namespace cactus_rt::tracing { -TraceAggregator::TraceAggregator(std::string process_name) +TraceAggregator::TraceAggregator(std::string process_name, cactus_rt::Logger* logger) : process_name_(process_name), process_track_uuid_(static_cast(getpid())), - logger_(quill::create_logger("__trace_aggregator__")) { + logger_(logger) { } void TraceAggregator::RegisterThreadTracer(std::shared_ptr tracer) { @@ -129,7 +129,7 @@ void TraceAggregator::Stop() noexcept { mutex_.unlock(); } -quill::Logger* TraceAggregator::Logger() noexcept { +cactus_rt::Logger* TraceAggregator::Logger() noexcept { return logger_; }