From 3cbbd925a26199635303edbd0f00bd299b47dcdd Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Wed, 9 Oct 2024 14:09:36 +0200 Subject: [PATCH 01/34] Updated Quill to v7.3.0 for core files --- CMakeLists.txt | 4 +++- include/cactus_rt/app.h | 21 ++++--------------- include/cactus_rt/config.h | 6 +++--- include/cactus_rt/thread.h | 38 ++++++++++++++++++++++++++++------ src/cactus_rt/app.cc | 16 +++++--------- src/cactus_rt/cyclic_thread.cc | 1 + src/cactus_rt/thread.cc | 26 ++++++++++++++++++++++- 7 files changed, 73 insertions(+), 39 deletions(-) diff --git a/CMakeLists.txt b/CMakeLists.txt index dddf8c4..7ccc845 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -27,8 +27,10 @@ if(CACTUS_RT_ENABLE_FETCH_DEPENDENCIES) FetchContent_Declare( quill GIT_REPOSITORY https://github.com/odygrd/quill.git - GIT_TAG 9a270d5d6f57a3ac19451292e3a9f370fcd744b1 + # GIT_TAG 9a270d5d6f57a3ac19451292e3a9f370fcd744b1 # GIT_TAG v3.3.2 + # GIT_TAG a058985253dffd6a77b4eeca3ba4aa5ad85a2d02 + GIT_TAG v7.3.0 ) FetchContent_MakeAvailable(quill) diff --git a/include/cactus_rt/app.h b/include/cactus_rt/app.h index c2907ad..752f893 100644 --- a/include/cactus_rt/app.h +++ b/include/cactus_rt/app.h @@ -1,5 +1,5 @@ -#ifndef CACTUS_RT_APP_H_ -#define CACTUS_RT_APP_H_ +#ifndef CACTUS_RT_APP +#define CACTUS_RT_APP #include @@ -8,7 +8,6 @@ #include #include "config.h" -#include "quill/Quill.h" #include "thread.h" #include "tracing/thread_tracer.h" #include "tracing/trace_aggregator.h" @@ -29,7 +28,7 @@ class App { size_t heap_size_; // Configuration for quill logging - quill::Config logger_config_; + quill::BackendOptions logger_backend_options_; TracerConfig tracer_config_; @@ -37,18 +36,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()); @@ -150,4 +137,4 @@ class App { }; } // namespace cactus_rt -#endif +#endif // CACTUS_RT_APP diff --git a/include/cactus_rt/config.h b/include/cactus_rt/config.h index 73d9e9a..c1aae19 100644 --- a/include/cactus_rt/config.h +++ b/include/cactus_rt/config.h @@ -1,7 +1,7 @@ #ifndef CACTUS_RT_CONFIG_H_ #define CACTUS_RT_CONFIG_H_ -#include +#include #include @@ -29,9 +29,9 @@ struct AppConfig { size_t heap_size = 0; /** - * @brief The configuration for quill logging + * @brief The Quill Backend configuration for logging */ - quill::Config logger_config; + quill::BackendOptions logger_backend_options; /** * @brief The config for the tracer if enabled (ENABLE_TRACING option in cmake) diff --git a/include/cactus_rt/thread.h b/include/cactus_rt/thread.h index 336a3f3..4b748ef 100644 --- a/include/cactus_rt/thread.h +++ b/include/cactus_rt/thread.h @@ -1,5 +1,5 @@ -#ifndef CACTUS_RT_THREAD_H_ -#define CACTUS_RT_THREAD_H_ +#ifndef CACTUS_RT_THREAD +#define CACTUS_RT_THREAD #include #include // For PTHREAD_STACK_MIN @@ -9,7 +9,7 @@ #include #include "config.h" -#include "quill/Quill.h" +#include "quill/Logger.h" #include "tracing/thread_tracer.h" #include "tracing/trace_aggregator.h" @@ -60,12 +60,38 @@ class Thread { name_(name), cpu_affinity_(config_.cpu_affinity), stack_size_(static_cast(PTHREAD_STACK_MIN) + config_.stack_size), - logger_(quill::create_logger(name_)) { + logger_(Thread::CreateDefaultThreadLogger(name_)) { if (!config.scheduler) { throw std::runtime_error("ThreadConfig::scheduler cannot be nullptr"); } } + /** + * Creates a new thread. + * + * @param name The thread name + * @param config The configuration for the thread + */ + Thread(std::string name, ThreadConfig config, quill::Logger* thread_logger) + : config_(config), + name_(name), + cpu_affinity_(config_.cpu_affinity), + stack_size_(static_cast(PTHREAD_STACK_MIN) + config_.stack_size), + logger_(thread_logger) { + if (!config.scheduler) { + throw std::runtime_error("ThreadConfig::scheduler cannot be nullptr"); + } + } + + /** + * Create a quill Logger object with default settings suitable for thread + * logging. + * + * @param logger_name Logger name to use. This can be e.g. the thread name. + * @return Pointer to the created logger. + */ + static quill::Logger* CreateDefaultThreadLogger(std::string logger_name); + public: /** * Returns the name of the thread @@ -94,7 +120,7 @@ class Thread { // The constructors and destructors are needed because we need to delete // objects of type Thread polymorphically, through the map in the App class. - virtual ~Thread() = default; + virtual ~Thread(); // Copy constructors are not allowed Thread(const Thread&) = delete; @@ -163,4 +189,4 @@ class Thread { }; } // namespace cactus_rt -#endif +#endif // CACTUS_RT_THREAD diff --git a/src/cactus_rt/app.cc b/src/cactus_rt/app.cc index ede9ee7..5f06272 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; @@ -19,20 +19,15 @@ namespace cactus_rt { App::App(std::string name, AppConfig config) : name_(name), heap_size_(config.heap_size), - logger_config_(config.logger_config), + logger_backend_options_(config.logger_backend_options), 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 } App::~App() { StopTraceSession(); - quill::flush(); + // Quill flush is handled per logger + quill::Backend::stop(); // Stop the quill backend thread } void App::Start(int64_t start_monotonic_time_ns) { @@ -156,8 +151,7 @@ void App::ReserveHeap() const { } void App::StartQuill() { - quill::configure(logger_config_); - quill::start(); + quill::Backend::start(logger_backend_options_); } void App::StopTraceAggregator() noexcept { diff --git a/src/cactus_rt/cyclic_thread.cc b/src/cactus_rt/cyclic_thread.cc index 2421394..03e085c 100644 --- a/src/cactus_rt/cyclic_thread.cc +++ b/src/cactus_rt/cyclic_thread.cc @@ -1,6 +1,7 @@ #include "cactus_rt/cyclic_thread.h" #include "cactus_rt/utils.h" +#include "quill/LogMacros.h" namespace cactus_rt { diff --git a/src/cactus_rt/thread.cc b/src/cactus_rt/thread.cc index 89f21c7..ff5da2c 100644 --- a/src/cactus_rt/thread.cc +++ b/src/cactus_rt/thread.cc @@ -10,9 +10,33 @@ #include "cactus_rt/config.h" #include "cactus_rt/tracing/thread_tracer.h" +#include "quill/Frontend.h" +#include "quill/LogMacros.h" +#include "quill/Logger.h" +#include "quill/sinks/ConsoleSink.h" namespace cactus_rt { +Thread::~Thread() { + // Blocks until all messages up to the current timestamp are flushed on the + // logger, to ensure every message is logged. + this->Logger()->flush_log(); +} + +quill::Logger* Thread::CreateDefaultThreadLogger(std::string logger_name) { + return quill::Frontend::create_or_get_logger( + logger_name, + quill::Frontend::create_or_get_sink( + logger_name + "_ConsoleSink", // Sink name is based on thread name + true // Enable console colours + ), + quill::PatternFormatterOptions( + "[%(time)][%(log_level_short_code)][%(logger)][%(file_name):%(line_number)] %(message)", + "%Y-%m-%d %H:%M:%S.%Qns" + ) + ); +} + void* Thread::RunThread(void* data) { auto* thread = static_cast(data); @@ -37,7 +61,7 @@ void* Thread::RunThread(void* data) { ); } - quill::preallocate(); // Pre-allocates thread-local data to avoid the need to allocate on the first log message + quill::Frontend::preallocate(); // Pre-allocates thread-local data to avoid the need to allocate on the first log message thread->BeforeRun(); thread->Run(); From acedfde67772288e2d9eb71a9f13bde7544b12d9 Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Wed, 9 Oct 2024 14:59:45 +0200 Subject: [PATCH 02/34] Updated quill in tracing --- include/cactus_rt/tracing/trace_aggregator.h | 11 ++++++----- src/cactus_rt/thread.cc | 1 + src/cactus_rt/tracing/trace_aggregator.cc | 20 +++++++++++++++++++- tests/tracing/multi_threaded_test.cc | 4 ++-- tests/tracing/single_threaded_test.cc | 4 ++-- 5 files changed, 30 insertions(+), 10 deletions(-) diff --git a/include/cactus_rt/tracing/trace_aggregator.h b/include/cactus_rt/tracing/trace_aggregator.h index 3b9965b..0418487 100644 --- a/include/cactus_rt/tracing/trace_aggregator.h +++ b/include/cactus_rt/tracing/trace_aggregator.h @@ -1,11 +1,9 @@ -#ifndef CACTUS_RT_TRACING_TRACE_AGGREGATOR_H_ -#define CACTUS_RT_TRACING_TRACE_AGGREGATOR_H_ +#ifndef TRACING_TRACE_AGGREGATOR +#define TRACING_TRACE_AGGREGATOR #ifndef CACTUS_RT_TRACING_ENABLED #include "trace_aggregator.disabled.h" #else -#include - #include #include #include @@ -14,6 +12,7 @@ #include #include +#include "quill/Logger.h" #include "sink.h" #include "thread_tracer.h" @@ -61,6 +60,8 @@ class TraceAggregator { public: explicit TraceAggregator(std::string name); + // TODO: Do we want to include a destructor which flushes the logger_? + // No copy no move TraceAggregator(const TraceAggregator&) = delete; TraceAggregator& operator=(const TraceAggregator&) = delete; @@ -128,4 +129,4 @@ class TraceAggregator { } // namespace cactus_rt::tracing #endif -#endif +#endif // TRACING_TRACE_AGGREGATOR diff --git a/src/cactus_rt/thread.cc b/src/cactus_rt/thread.cc index ff5da2c..40c4298 100644 --- a/src/cactus_rt/thread.cc +++ b/src/cactus_rt/thread.cc @@ -24,6 +24,7 @@ Thread::~Thread() { } quill::Logger* Thread::CreateDefaultThreadLogger(std::string logger_name) { + // TODO: move to another header file (cactus_rt/logging.h?) return quill::Frontend::create_or_get_logger( logger_name, quill::Frontend::create_or_get_sink( diff --git a/src/cactus_rt/tracing/trace_aggregator.cc b/src/cactus_rt/tracing/trace_aggregator.cc index b27b80d..cae3502 100644 --- a/src/cactus_rt/tracing/trace_aggregator.cc +++ b/src/cactus_rt/tracing/trace_aggregator.cc @@ -17,6 +17,10 @@ #include #include +#include "quill/Frontend.h" +#include "quill/LogMacros.h" +#include "quill/sinks/ConsoleSink.h" + using cactus_tracing::vendor::perfetto::protos::InternedData; using cactus_tracing::vendor::perfetto::protos::ProcessDescriptor; using cactus_tracing::vendor::perfetto::protos::ThreadDescriptor; @@ -57,7 +61,21 @@ namespace cactus_rt::tracing { TraceAggregator::TraceAggregator(std::string process_name) : process_name_(process_name), process_track_uuid_(static_cast(getpid())), - logger_(quill::create_logger("__trace_aggregator__")) { + logger_( + // TODO: VERY UGLY, move to another header file (cactus_rt/logging.h?) + quill::Frontend::create_or_get_logger( + "__trace_aggregator__", + quill::Frontend::create_or_get_sink( + "__trace_aggregator__" + "_ConsoleSink", // Sink name is based on thread name + true // Enable console colours + ), + quill::PatternFormatterOptions( + "[%(time)][%(log_level_short_code)][%(logger)][%(file_name):%(line_number)] %(message)", + "%Y-%m-%d %H:%M:%S.%Qns" + ) + ) + ) { } void TraceAggregator::RegisterThreadTracer(std::shared_ptr tracer) { diff --git a/tests/tracing/multi_threaded_test.cc b/tests/tracing/multi_threaded_test.cc index 8e39374..b95ac5e 100644 --- a/tests/tracing/multi_threaded_test.cc +++ b/tests/tracing/multi_threaded_test.cc @@ -1,6 +1,6 @@ #include #include -#include +#include #include @@ -42,7 +42,7 @@ class MultiThreadTracingTest : public ::testing::Test { app_.Join(); // Need to stop it for every test as every app.Start() will start a background thread. - quill::detail::LogManagerSingleton::instance().log_manager().stop_backend_worker(); + quill::Backend::stop(); } }; diff --git a/tests/tracing/single_threaded_test.cc b/tests/tracing/single_threaded_test.cc index 5f15ade..c65f6e4 100644 --- a/tests/tracing/single_threaded_test.cc +++ b/tests/tracing/single_threaded_test.cc @@ -1,6 +1,6 @@ #include #include -#include +#include #include #include @@ -48,7 +48,7 @@ class SingleThreadTracingTest : public ::testing::Test { app_.Join(); // Need to stop it for every test as every app.Start() will start a background thread. - quill::detail::LogManagerSingleton::instance().log_manager().stop_backend_worker(); + quill::Backend::stop(); } }; From 15ea07ea43cb1b81e9ebeaef85fb9dd9cafb51f6 Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Wed, 9 Oct 2024 15:32:16 +0200 Subject: [PATCH 03/34] Marked TODOs for this Quill update to find them back easily --- include/cactus_rt/tracing/trace_aggregator.h | 2 +- src/cactus_rt/thread.cc | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/include/cactus_rt/tracing/trace_aggregator.h b/include/cactus_rt/tracing/trace_aggregator.h index 0418487..ff846a0 100644 --- a/include/cactus_rt/tracing/trace_aggregator.h +++ b/include/cactus_rt/tracing/trace_aggregator.h @@ -60,7 +60,7 @@ class TraceAggregator { public: explicit TraceAggregator(std::string name); - // TODO: Do we want to include a destructor which flushes the logger_? + // TODO: (QUILL v7.3.0) Do we want to include a destructor which flushes the logger_? // No copy no move TraceAggregator(const TraceAggregator&) = delete; diff --git a/src/cactus_rt/thread.cc b/src/cactus_rt/thread.cc index 40c4298..8d4bc25 100644 --- a/src/cactus_rt/thread.cc +++ b/src/cactus_rt/thread.cc @@ -24,7 +24,7 @@ Thread::~Thread() { } quill::Logger* Thread::CreateDefaultThreadLogger(std::string logger_name) { - // TODO: move to another header file (cactus_rt/logging.h?) + // TODO: (QUILL v7.3.0) move to another header file (cactus_rt/logging.h?) return quill::Frontend::create_or_get_logger( logger_name, quill::Frontend::create_or_get_sink( From dbfd560a0b4885363330e50d6b0e9f61e2021bd9 Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Wed, 9 Oct 2024 15:36:02 +0200 Subject: [PATCH 04/34] Updated examples to use quill v7.3.0 --- examples/lockless_examples/realtime_read.cc | 2 ++ examples/logging_example/main.cc | 13 ++++++++----- .../message_passing_example/data_logger_thread.cc | 3 +++ examples/mutex_example/main.cc | 1 + examples/simple_example/main.cc | 3 +++ examples/tracing_example_no_rt/main.cc | 5 ++++- 6 files changed, 21 insertions(+), 6 deletions(-) diff --git a/examples/lockless_examples/realtime_read.cc b/examples/lockless_examples/realtime_read.cc index e22e8b7..829d13e 100644 --- a/examples/lockless_examples/realtime_read.cc +++ b/examples/lockless_examples/realtime_read.cc @@ -1,6 +1,8 @@ #include #include +#include "quill/LogMacros.h" // Required for the logging macro + using cactus_rt::App; using cactus_rt::CyclicThread; using cactus_rt::Thread; diff --git a/examples/logging_example/main.cc b/examples/logging_example/main.cc index 89c8b6d..e2b510a 100644 --- a/examples/logging_example/main.cc +++ b/examples/logging_example/main.cc @@ -3,6 +3,8 @@ #include #include +#include "quill/LogMacros.h" // Required for the logging macro + using cactus_rt::App; using cactus_rt::CyclicThread; @@ -40,16 +42,17 @@ 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; + // Create a Quill backend logging config to configure the Quill backend thread + quill::BackendOptions logger_backend_options; // Disable strict timestamp order - this will be faster, but logs may appear out of order - logging_config.backend_thread_strict_log_timestamp_order = false; + // See quill::BackendOptions documentation for more info + logger_backend_options.log_timestamp_ordering_grace_period = std::chrono::microseconds(0); // Set the background logging thread CPU affinity - logging_config.backend_thread_cpu_affinity = 1; // Different CPU than the CyclicThread CPU! + logger_backend_options.cpu_affinity = 1; // Different CPU than the CyclicThread CPU! - app_config.logger_config = logging_config; + app_config.logger_backend_options = logger_backend_options; App app("LoggingExampleApp", app_config); auto thread = app.CreateThread("ExampleRTThread", thread_config); diff --git a/examples/message_passing_example/data_logger_thread.cc b/examples/message_passing_example/data_logger_thread.cc index c83f4b6..dfad6b4 100644 --- a/examples/message_passing_example/data_logger_thread.cc +++ b/examples/message_passing_example/data_logger_thread.cc @@ -1,6 +1,9 @@ #include "data_logger_thread.h" #include +#include + +#include "quill/LogMacros.h" // Required for the logging macro DataLogger::DataLogger( const std::string& data_file_path, diff --git a/examples/mutex_example/main.cc b/examples/mutex_example/main.cc index 31945f2..fafb8b2 100644 --- a/examples/mutex_example/main.cc +++ b/examples/mutex_example/main.cc @@ -5,6 +5,7 @@ #include #include "double_buffer.h" +#include "quill/LogMacros.h" // Required for the logging macro using cactus_rt::App; using cactus_rt::CyclicThread; diff --git a/examples/simple_example/main.cc b/examples/simple_example/main.cc index bd89d20..9a9f5e6 100644 --- a/examples/simple_example/main.cc +++ b/examples/simple_example/main.cc @@ -3,6 +3,9 @@ #include #include +#include "quill/LogMacros.h" // Required for the logging macro +#include "quill/std/Chrono.h" // Required to parse std::chrono inside logging macros + using cactus_rt::App; using cactus_rt::CyclicThread; diff --git a/examples/tracing_example_no_rt/main.cc b/examples/tracing_example_no_rt/main.cc index 86bc64f..fffad8e 100644 --- a/examples/tracing_example_no_rt/main.cc +++ b/examples/tracing_example_no_rt/main.cc @@ -3,6 +3,9 @@ #include #include +#include "quill/Backend.h" // Required to start/stop the quill backend thread +#include "quill/LogMacros.h" // Required for the logging macro + using namespace std::chrono_literals; using FileSink = cactus_rt::tracing::FileSink; using TraceAggregator = cactus_rt::tracing::TraceAggregator; @@ -25,7 +28,7 @@ void StartTracing(const char* app_name, const char* filename) { // 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); } From 4f9438078725d6ce01f5defc87fafef46c594e19 Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Wed, 9 Oct 2024 16:25:19 +0200 Subject: [PATCH 05/34] Moved shared default logger implementation to dedicated header file and updated Thread and TraceAggregator thread --- include/cactus_rt/logging.h | 95 ++++++++++++++++++++ include/cactus_rt/thread.h | 12 +-- include/cactus_rt/tracing/trace_aggregator.h | 3 +- src/cactus_rt/thread.cc | 16 ---- src/cactus_rt/tracing/trace_aggregator.cc | 25 ++---- 5 files changed, 107 insertions(+), 44 deletions(-) create mode 100644 include/cactus_rt/logging.h diff --git a/include/cactus_rt/logging.h b/include/cactus_rt/logging.h new file mode 100644 index 0000000..2e34617 --- /dev/null +++ b/include/cactus_rt/logging.h @@ -0,0 +1,95 @@ +#ifndef CACTUS_RT_LOGGING +#define CACTUS_RT_LOGGING + +#include +#include + +#include "quill/Frontend.h" +#include "quill/Logger.h" +#include "quill/sinks/ConsoleSink.h" +#include "quill/sinks/Sink.h" + +namespace cactus_rt { + +/** + * Defines a Bounded Dropping queue, to drop logging messages if the buffers + * fill up. FrontendOptions are compile-time options and must be passed as a + * template argument. + * + * Based on: + * - https://github.com/odygrd/quill/blob/v7.3.0/examples/custom_frontend_options.cpp + * - https://quillcpp.readthedocs.io/en/latest/frontend_options.html + */ +struct BoundedDroppingFrontendOptions { + static constexpr quill::QueueType queue_type = quill::QueueType::BoundedDropping; + static constexpr uint32_t initial_queue_capacity = 128 * 1024; // 128 KiB + static constexpr uint32_t blocking_queue_retry_interval_ns = 800; // Ignored for Dropping queue + static constexpr bool huge_pages_enabled = false; +}; + +/** + * Define a quill::Frontend class using the custom options. FrontendOptions are + * compile-time options and must be passed as a template argument. + */ +using BoundedDroppingFrontend = quill::FrontendImpl; + +/** + * Define a custom quill::Logger to also use the custom options. FrontendOptions + * are compile-time options and must be passed as a template argument. + */ +using BoundedDroppingLogger = quill::LoggerImpl; + +/** + * Type alias for `cactus_rt::BoundedDroppingLogger`. + */ +using Logger = BoundedDroppingLogger; + +/** + * Create a ConsoleSink object with console colours. + * + * @param sink_name The Sink ID. + * @return A pointer to the created sink. If a sink with that ID already + * existed, a pointer to the existing sink is returned instead. + */ +static std::shared_ptr DefaultConsoleSink(std::string sink_name) { + // TODO: (QUILL v7.3.0): move implementation to .cpp file + return quill::Frontend::create_or_get_sink( + sink_name, + true // Enable console colours + ); +} + +/** + * Get a default pattern format. + */ +static quill::PatternFormatterOptions DefaultPatternFormatterOptions() { + // TODO: (QUILL v7.3.0): move implementation to .cpp file + return quill::PatternFormatterOptions( + "[%(time)][%(log_level_short_code)][%(logger)][%(file_name):%(line_number)] %(message)", + "%Y-%;m-%d %H:%M:%S.%Qns" + ); +} + +/** + * Create a Logger object with default settings which will write logs to the + * console with a default format. + * + * TODO: (QUILL v7.3.0): Make this use the `cactus_rt::Logger` + * (`cactus_rt::BoundedDroppingLogger`) instead + * + * @param logger_name + * @return A pointer to the created logger. If a logger with that ID already + * existed, a pointer to the existing logger is returned instead. + */ +static quill::Logger* DefaultLogger(std::string logger_name) { + // TODO: (QUILL v7.3.0): move implementation to .cpp file + return quill::Frontend::create_or_get_logger( + logger_name, + DefaultConsoleSink(logger_name + "_ConsoleSink"), + DefaultPatternFormatterOptions() + ); +} + +} // namespace cactus_rt + +#endif // CACTUS_RT_LOGGING diff --git a/include/cactus_rt/thread.h b/include/cactus_rt/thread.h index 4b748ef..0715ae1 100644 --- a/include/cactus_rt/thread.h +++ b/include/cactus_rt/thread.h @@ -9,6 +9,7 @@ #include #include "config.h" +#include "logging.h" #include "quill/Logger.h" #include "tracing/thread_tracer.h" #include "tracing/trace_aggregator.h" @@ -60,7 +61,7 @@ class Thread { name_(name), cpu_affinity_(config_.cpu_affinity), stack_size_(static_cast(PTHREAD_STACK_MIN) + config_.stack_size), - logger_(Thread::CreateDefaultThreadLogger(name_)) { + logger_(cactus_rt::DefaultLogger(name_)) { if (!config.scheduler) { throw std::runtime_error("ThreadConfig::scheduler cannot be nullptr"); } @@ -83,15 +84,6 @@ class Thread { } } - /** - * Create a quill Logger object with default settings suitable for thread - * logging. - * - * @param logger_name Logger name to use. This can be e.g. the thread name. - * @return Pointer to the created logger. - */ - static quill::Logger* CreateDefaultThreadLogger(std::string logger_name); - public: /** * Returns the name of the thread diff --git a/include/cactus_rt/tracing/trace_aggregator.h b/include/cactus_rt/tracing/trace_aggregator.h index ff846a0..819d121 100644 --- a/include/cactus_rt/tracing/trace_aggregator.h +++ b/include/cactus_rt/tracing/trace_aggregator.h @@ -60,7 +60,8 @@ class TraceAggregator { public: explicit TraceAggregator(std::string name); - // TODO: (QUILL v7.3.0) Do we want to include a destructor which flushes the logger_? + // Destructor is needed to flush the logger when this thread is destroyed + ~TraceAggregator(); // No copy no move TraceAggregator(const TraceAggregator&) = delete; diff --git a/src/cactus_rt/thread.cc b/src/cactus_rt/thread.cc index 8d4bc25..1f85861 100644 --- a/src/cactus_rt/thread.cc +++ b/src/cactus_rt/thread.cc @@ -13,7 +13,6 @@ #include "quill/Frontend.h" #include "quill/LogMacros.h" #include "quill/Logger.h" -#include "quill/sinks/ConsoleSink.h" namespace cactus_rt { @@ -23,21 +22,6 @@ Thread::~Thread() { this->Logger()->flush_log(); } -quill::Logger* Thread::CreateDefaultThreadLogger(std::string logger_name) { - // TODO: (QUILL v7.3.0) move to another header file (cactus_rt/logging.h?) - return quill::Frontend::create_or_get_logger( - logger_name, - quill::Frontend::create_or_get_sink( - logger_name + "_ConsoleSink", // Sink name is based on thread name - true // Enable console colours - ), - quill::PatternFormatterOptions( - "[%(time)][%(log_level_short_code)][%(logger)][%(file_name):%(line_number)] %(message)", - "%Y-%m-%d %H:%M:%S.%Qns" - ) - ); -} - void* Thread::RunThread(void* data) { auto* thread = static_cast(data); diff --git a/src/cactus_rt/tracing/trace_aggregator.cc b/src/cactus_rt/tracing/trace_aggregator.cc index cae3502..5d4a9a1 100644 --- a/src/cactus_rt/tracing/trace_aggregator.cc +++ b/src/cactus_rt/tracing/trace_aggregator.cc @@ -17,9 +17,8 @@ #include #include -#include "quill/Frontend.h" +#include "cactus_rt/logging.h" #include "quill/LogMacros.h" -#include "quill/sinks/ConsoleSink.h" using cactus_tracing::vendor::perfetto::protos::InternedData; using cactus_tracing::vendor::perfetto::protos::ProcessDescriptor; @@ -61,21 +60,13 @@ namespace cactus_rt::tracing { TraceAggregator::TraceAggregator(std::string process_name) : process_name_(process_name), process_track_uuid_(static_cast(getpid())), - logger_( - // TODO: VERY UGLY, move to another header file (cactus_rt/logging.h?) - quill::Frontend::create_or_get_logger( - "__trace_aggregator__", - quill::Frontend::create_or_get_sink( - "__trace_aggregator__" - "_ConsoleSink", // Sink name is based on thread name - true // Enable console colours - ), - quill::PatternFormatterOptions( - "[%(time)][%(log_level_short_code)][%(logger)][%(file_name):%(line_number)] %(message)", - "%Y-%m-%d %H:%M:%S.%Qns" - ) - ) - ) { + logger_(cactus_rt::DefaultLogger("__trace_aggregator__")) { +} + +TraceAggregator::~TraceAggregator() { + // Blocks until all messages up to the current timestamp are flushed on the + // logger, to ensure every message is logged. + this->Logger()->flush_log(); } void TraceAggregator::RegisterThreadTracer(std::shared_ptr tracer) { From d7d9ec083a2fd59e2a661c39a5277455b2b2f0b9 Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Thu, 10 Oct 2024 10:45:41 +0200 Subject: [PATCH 06/34] Moved logging config from the thread constructor into the thread config struct --- include/cactus_rt/config.h | 11 +++++++++++ include/cactus_rt/thread.h | 20 ++++---------------- 2 files changed, 15 insertions(+), 16 deletions(-) diff --git a/include/cactus_rt/config.h b/include/cactus_rt/config.h index c1aae19..87a2ef7 100644 --- a/include/cactus_rt/config.h +++ b/include/cactus_rt/config.h @@ -99,6 +99,15 @@ struct ThreadTracerConfig { bool trace_wakeup_latency = false; }; +/** + * @brief The configuration needed for Quill logging in a thread + */ +struct ThreadLoggerConfig { + // Pointer to the thread logger that is to be used. If nullptr is given, a default thread logger is created instead. + // TODO: (QUILL v7.3.0): Use a string as the logger name instead? + quill::Logger* thread_logger = nullptr; +}; + /** * @brief The configuration required for a thread */ @@ -111,6 +120,8 @@ struct ThreadConfig { ThreadTracerConfig tracer_config; + ThreadLoggerConfig logger_config; + // The scheduler type, default scheduler is SCHED_OTHER std::shared_ptr scheduler = std::make_shared(); diff --git a/include/cactus_rt/thread.h b/include/cactus_rt/thread.h index 0715ae1..5b282a3 100644 --- a/include/cactus_rt/thread.h +++ b/include/cactus_rt/thread.h @@ -61,26 +61,14 @@ class Thread { name_(name), cpu_affinity_(config_.cpu_affinity), stack_size_(static_cast(PTHREAD_STACK_MIN) + config_.stack_size), - logger_(cactus_rt::DefaultLogger(name_)) { + logger_(config.logger_config.thread_logger) { if (!config.scheduler) { throw std::runtime_error("ThreadConfig::scheduler cannot be nullptr"); } - } - /** - * Creates a new thread. - * - * @param name The thread name - * @param config The configuration for the thread - */ - Thread(std::string name, ThreadConfig config, quill::Logger* thread_logger) - : config_(config), - name_(name), - cpu_affinity_(config_.cpu_affinity), - stack_size_(static_cast(PTHREAD_STACK_MIN) + config_.stack_size), - logger_(thread_logger) { - if (!config.scheduler) { - throw std::runtime_error("ThreadConfig::scheduler cannot be nullptr"); + // If no logger was passed in the thread configuration, create a default logger instead + if (logger_ == nullptr) { + logger_ = DefaultLogger(name_); } } From 863c8785d92e5adde3040b0f263bcc4716f0490d Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Thu, 10 Oct 2024 10:46:27 +0200 Subject: [PATCH 07/34] Added todo to investigate if it is better to pass in logger names instead of pointers to loggers --- include/cactus_rt/logging.h | 3 +++ 1 file changed, 3 insertions(+) diff --git a/include/cactus_rt/logging.h b/include/cactus_rt/logging.h index 2e34617..ba66e86 100644 --- a/include/cactus_rt/logging.h +++ b/include/cactus_rt/logging.h @@ -77,6 +77,9 @@ static quill::PatternFormatterOptions DefaultPatternFormatterOptions() { * TODO: (QUILL v7.3.0): Make this use the `cactus_rt::Logger` * (`cactus_rt::BoundedDroppingLogger`) instead * + * TODO: (QUILL v7.3.0): What happens if we pass in a logger name which already + * exists? Are the sink and format discarded? + * * @param logger_name * @return A pointer to the created logger. If a logger with that ID already * existed, a pointer to the existing logger is returned instead. From 02115880d9f3f11dc124c7fb67e73d929b580153 Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Thu, 10 Oct 2024 10:46:49 +0200 Subject: [PATCH 08/34] Fixed timestamp in formatter which did not display months --- include/cactus_rt/logging.h | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/include/cactus_rt/logging.h b/include/cactus_rt/logging.h index ba66e86..91f635f 100644 --- a/include/cactus_rt/logging.h +++ b/include/cactus_rt/logging.h @@ -66,7 +66,7 @@ static quill::PatternFormatterOptions DefaultPatternFormatterOptions() { // TODO: (QUILL v7.3.0): move implementation to .cpp file return quill::PatternFormatterOptions( "[%(time)][%(log_level_short_code)][%(logger)][%(file_name):%(line_number)] %(message)", - "%Y-%;m-%d %H:%M:%S.%Qns" + "%Y-%m-%d %H:%M:%S.%Qns" ); } From d0be365eb54c2673fd201bc477703b5f254f2963 Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Thu, 10 Oct 2024 10:47:18 +0200 Subject: [PATCH 09/34] Extended example for logging with examples for custom loggers, multiple sinks and custom format --- examples/logging_example/main.cc | 41 +++++++++++++++++++++++++++++--- 1 file changed, 38 insertions(+), 3 deletions(-) diff --git a/examples/logging_example/main.cc b/examples/logging_example/main.cc index e2b510a..c7143d7 100644 --- a/examples/logging_example/main.cc +++ b/examples/logging_example/main.cc @@ -4,6 +4,7 @@ #include #include "quill/LogMacros.h" // Required for the logging macro +#include "quill/sinks/FileSink.h" using cactus_rt::App; using cactus_rt::CyclicThread; @@ -45,9 +46,10 @@ int main() { // Create a Quill backend logging config to configure the Quill backend thread quill::BackendOptions logger_backend_options; - // Disable strict timestamp order - this will be faster, but logs may appear out of order + // Disable strict timestamp order by setting the grace period to 0 - this will be faster, but logs may appear out of order // See quill::BackendOptions documentation for more info - logger_backend_options.log_timestamp_ordering_grace_period = std::chrono::microseconds(0); + // TODO: Setting this to 0 causes assertion error in Debug builds. Perhaps a bug in Quill (https://github.com/odygrd/quill/issues/605)? + logger_backend_options.log_timestamp_ordering_grace_period = std::chrono::microseconds(1); // Set the background logging thread CPU affinity logger_backend_options.cpu_affinity = 1; // Different CPU than the CyclicThread CPU! @@ -55,7 +57,40 @@ int main() { app_config.logger_backend_options = logger_backend_options; App app("LoggingExampleApp", app_config); - auto thread = app.CreateThread("ExampleRTThread", thread_config); + auto thread = app.CreateThread("ExampleRTThread", thread_config); + + // Create another thread with a custom logger, which has multiple sinks + cactus_rt::CyclicThreadConfig other_thread_config = thread_config; // Copy thread config + + // Create another console sink + auto console_sink = quill::Frontend::create_or_get_sink("OtherConsoleSink", true); + + // Create a file sink too + quill::FileSinkConfig file_sink_config; + file_sink_config.set_open_mode('w'); + file_sink_config.set_filename_append_option(quill::FilenameAppendOption::StartDateTime); + auto file_sink = quill::Frontend::create_or_get_sink( + "file_logging_example.log", + file_sink_config, + quill::FileEventNotifier{} + ); + + // Add both sinks to a vector + std::vector> sinks = {console_sink, file_sink}; + + // Create a custom formatter pattern + auto pattern_format = quill::PatternFormatterOptions( + "[%(time)][%(log_level_short_code)][%(logger)][%(file_name):%(line_number)] - WOW custom message format - %(message)", + "%H:%M:%S.%Qns" + ); + + // Use the new sinks and pattern to create a custom logger for the other thread + other_thread_config.logger_config.thread_logger = quill::Frontend::create_or_get_logger("CustomThreadLogger", sinks, pattern_format); + + // Add a second instance of the example thread class, which uses the configuration with the new logger + auto other_thread = app.CreateThread("OtherExampleRTThread", other_thread_config); + + // Start the app constexpr unsigned int time = 5; std::cout << "Testing RT loop for " << time << " seconds.\n"; From 846364d68b3dbac3aeb4e1154ffb6b4fa9355f0e Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Thu, 10 Oct 2024 12:03:16 +0200 Subject: [PATCH 10/34] Use custom frontend and logger everywhere, preallocate the trace aggregator before starting, and added default backend options --- examples/logging_example/main.cc | 9 ++-- include/cactus_rt/config.h | 12 +++-- include/cactus_rt/logging.h | 53 +++++++++++++++----- include/cactus_rt/thread.h | 7 ++- include/cactus_rt/tracing/trace_aggregator.h | 7 +-- src/cactus_rt/thread.cc | 5 +- src/cactus_rt/tracing/trace_aggregator.cc | 7 ++- 7 files changed, 66 insertions(+), 34 deletions(-) diff --git a/examples/logging_example/main.cc b/examples/logging_example/main.cc index c7143d7..de3a659 100644 --- a/examples/logging_example/main.cc +++ b/examples/logging_example/main.cc @@ -44,7 +44,7 @@ int main() { cactus_rt::AppConfig app_config; // Create a Quill backend logging config to configure the Quill backend thread - quill::BackendOptions logger_backend_options; + quill::BackendOptions logger_backend_options = cactus_rt::logging::DefaultBackendOptions(); // Disable strict timestamp order by setting the grace period to 0 - this will be faster, but logs may appear out of order // See quill::BackendOptions documentation for more info @@ -63,13 +63,14 @@ int main() { cactus_rt::CyclicThreadConfig other_thread_config = thread_config; // Copy thread config // Create another console sink - auto console_sink = quill::Frontend::create_or_get_sink("OtherConsoleSink", true); + // Make sure to use cactus_rt's logging Frontend instead of Quill's default + auto console_sink = cactus_rt::logging::Frontend::create_or_get_sink("OtherConsoleSink", true); // Create a file sink too quill::FileSinkConfig file_sink_config; file_sink_config.set_open_mode('w'); file_sink_config.set_filename_append_option(quill::FilenameAppendOption::StartDateTime); - auto file_sink = quill::Frontend::create_or_get_sink( + auto file_sink = cactus_rt::logging::Frontend::create_or_get_sink( "file_logging_example.log", file_sink_config, quill::FileEventNotifier{} @@ -85,7 +86,7 @@ int main() { ); // Use the new sinks and pattern to create a custom logger for the other thread - other_thread_config.logger_config.thread_logger = quill::Frontend::create_or_get_logger("CustomThreadLogger", sinks, pattern_format); + other_thread_config.logger_config.thread_logger = cactus_rt::logging::Frontend::create_or_get_logger("CustomThreadLogger", sinks, pattern_format); // Add a second instance of the example thread class, which uses the configuration with the new logger auto other_thread = app.CreateThread("OtherExampleRTThread", other_thread_config); diff --git a/include/cactus_rt/config.h b/include/cactus_rt/config.h index 87a2ef7..ea93c2a 100644 --- a/include/cactus_rt/config.h +++ b/include/cactus_rt/config.h @@ -1,11 +1,11 @@ #ifndef CACTUS_RT_CONFIG_H_ #define CACTUS_RT_CONFIG_H_ -#include - #include +#include "cactus_rt/logging.h" #include "cactus_rt/scheduler.h" +#include "quill/backend/BackendOptions.h" namespace cactus_rt { @@ -29,9 +29,11 @@ struct AppConfig { size_t heap_size = 0; /** - * @brief The Quill Backend configuration for logging + * @brief The Quill Backend configuration for logging. + * + * It is set to sensible default values for real-time logging. */ - quill::BackendOptions logger_backend_options; + quill::BackendOptions logger_backend_options = cactus_rt::logging::DefaultBackendOptions(); /** * @brief The config for the tracer if enabled (ENABLE_TRACING option in cmake) @@ -105,7 +107,7 @@ struct ThreadTracerConfig { struct ThreadLoggerConfig { // Pointer to the thread logger that is to be used. If nullptr is given, a default thread logger is created instead. // TODO: (QUILL v7.3.0): Use a string as the logger name instead? - quill::Logger* thread_logger = nullptr; + cactus_rt::logging::Logger* thread_logger = nullptr; }; /** diff --git a/include/cactus_rt/logging.h b/include/cactus_rt/logging.h index 91f635f..c4e32f4 100644 --- a/include/cactus_rt/logging.h +++ b/include/cactus_rt/logging.h @@ -6,14 +6,16 @@ #include "quill/Frontend.h" #include "quill/Logger.h" +#include "quill/backend/BackendOptions.h" #include "quill/sinks/ConsoleSink.h" #include "quill/sinks/Sink.h" -namespace cactus_rt { - +namespace cactus_rt::logging { /** * Defines a Bounded Dropping queue, to drop logging messages if the buffers - * fill up. FrontendOptions are compile-time options and must be passed as a + * fill up. This prevents run-time reallocations. + + * FrontendOptions are compile-time options and must be passed as a * template argument. * * Based on: @@ -28,21 +30,47 @@ struct BoundedDroppingFrontendOptions { }; /** - * Define a quill::Frontend class using the custom options. FrontendOptions are - * compile-time options and must be passed as a template argument. + * Define a quill::Frontend class using the custom options. This Frontend must + * be used consistently throughout the application instead of the default + * `quill::Frontend`. + * + * FrontendOptions are compile-time options and must be passed as a template + * argument. */ using BoundedDroppingFrontend = quill::FrontendImpl; +/// Type alias for `BoundedDroppingFrontend` +using Frontend = BoundedDroppingFrontend; + /** - * Define a custom quill::Logger to also use the custom options. FrontendOptions - * are compile-time options and must be passed as a template argument. + * Define a custom quill::Logger to also use the custom options. This Logger + * must be used consistently throughout the application instead of the default + * `quill::Logger`. + * + * FrontendOptions are compile-time options and must be passed as a template + * argument. */ using BoundedDroppingLogger = quill::LoggerImpl; +/// Type alias for `BoundedDroppingLogger` +using Logger = BoundedDroppingLogger; + /** - * Type alias for `cactus_rt::BoundedDroppingLogger`. + * Sets `quill:BackendOptions` to suitable defaults for real-time logging. + * + * @return quill::BackendOptions */ -using Logger = BoundedDroppingLogger; +static quill::BackendOptions DefaultBackendOptions() { + // Many of the default options set by Quill are already OK for real-time logging + quill::BackendOptions default_backend_options; + + // Disable strict timestamp order by setting the grace period to 0 - this will be faster, but logs may appear out of order + // See quill::BackendOptions documentation for more info + // TODO: Setting this to 0 causes assertion error in Debug builds. Perhaps a bug in Quill (https://github.com/odygrd/quill/issues/605)? + default_backend_options.log_timestamp_ordering_grace_period = std::chrono::milliseconds(1); + + return default_backend_options; +} /** * Create a ConsoleSink object with console colours. @@ -84,15 +112,14 @@ static quill::PatternFormatterOptions DefaultPatternFormatterOptions() { * @return A pointer to the created logger. If a logger with that ID already * existed, a pointer to the existing logger is returned instead. */ -static quill::Logger* DefaultLogger(std::string logger_name) { +static cactus_rt::logging::Logger* DefaultLogger(std::string logger_name) { // TODO: (QUILL v7.3.0): move implementation to .cpp file - return quill::Frontend::create_or_get_logger( + return cactus_rt::logging::Frontend::create_or_get_logger( logger_name, DefaultConsoleSink(logger_name + "_ConsoleSink"), DefaultPatternFormatterOptions() ); } - -} // namespace cactus_rt +} // namespace cactus_rt::logging #endif // CACTUS_RT_LOGGING diff --git a/include/cactus_rt/thread.h b/include/cactus_rt/thread.h index 5b282a3..0f9b68f 100644 --- a/include/cactus_rt/thread.h +++ b/include/cactus_rt/thread.h @@ -10,7 +10,6 @@ #include "config.h" #include "logging.h" -#include "quill/Logger.h" #include "tracing/thread_tracer.h" #include "tracing/trace_aggregator.h" @@ -31,7 +30,7 @@ class Thread { std::vector cpu_affinity_; size_t stack_size_; - quill::Logger* logger_; + cactus_rt::logging::Logger* logger_; // Use the custom BoundedDroppingLogger std::shared_ptr tracer_ = nullptr; std::atomic_bool stop_requested_ = false; @@ -68,7 +67,7 @@ class Thread { // If no logger was passed in the thread configuration, create a default logger instead if (logger_ == nullptr) { - logger_ = DefaultLogger(name_); + logger_ = cactus_rt::logging::DefaultLogger(name_); } } @@ -124,7 +123,7 @@ class Thread { void Start(int64_t start_monotonic_time_ns); protected: - inline quill::Logger* Logger() const { return logger_; } + inline cactus_rt::logging::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 819d121..058ae2c 100644 --- a/include/cactus_rt/tracing/trace_aggregator.h +++ b/include/cactus_rt/tracing/trace_aggregator.h @@ -12,7 +12,7 @@ #include #include -#include "quill/Logger.h" +#include "cactus_rt/logging.h" #include "sink.h" #include "thread_tracer.h" @@ -42,7 +42,8 @@ class TraceAggregator { const std::string process_name_; const uint64_t process_track_uuid_; - quill::Logger* logger_; + + cactus_rt::logging::Logger* logger_; // Use the custom BoundedDroppingLogger // This mutex protects tracers_ and session_ std::mutex mutex_; @@ -96,7 +97,7 @@ class TraceAggregator { void Stop() noexcept; private: - quill::Logger* Logger() noexcept; + cactus_rt::logging::Logger* Logger() noexcept; void Run(); bool StopRequested() const noexcept; diff --git a/src/cactus_rt/thread.cc b/src/cactus_rt/thread.cc index 1f85861..c76c5f4 100644 --- a/src/cactus_rt/thread.cc +++ b/src/cactus_rt/thread.cc @@ -9,10 +9,9 @@ #include #include "cactus_rt/config.h" +#include "cactus_rt/logging.h" #include "cactus_rt/tracing/thread_tracer.h" -#include "quill/Frontend.h" #include "quill/LogMacros.h" -#include "quill/Logger.h" namespace cactus_rt { @@ -46,7 +45,7 @@ void* Thread::RunThread(void* data) { ); } - quill::Frontend::preallocate(); // Pre-allocates thread-local data to avoid the need to allocate on the first log message + cactus_rt::logging::Frontend::preallocate(); // Pre-allocates thread-local data to avoid the need to allocate on the first log message thread->BeforeRun(); thread->Run(); diff --git a/src/cactus_rt/tracing/trace_aggregator.cc b/src/cactus_rt/tracing/trace_aggregator.cc index 5d4a9a1..65d5999 100644 --- a/src/cactus_rt/tracing/trace_aggregator.cc +++ b/src/cactus_rt/tracing/trace_aggregator.cc @@ -60,7 +60,7 @@ namespace cactus_rt::tracing { TraceAggregator::TraceAggregator(std::string process_name) : process_name_(process_name), process_track_uuid_(static_cast(getpid())), - logger_(cactus_rt::DefaultLogger("__trace_aggregator__")) { + logger_(cactus_rt::logging::DefaultLogger("__trace_aggregator__")) { } TraceAggregator::~TraceAggregator() { @@ -138,13 +138,16 @@ void TraceAggregator::Stop() noexcept { mutex_.unlock(); } -quill::Logger* TraceAggregator::Logger() noexcept { +cactus_rt::logging::Logger* TraceAggregator::Logger() noexcept { return logger_; } void TraceAggregator::Run() { ::SetupCPUAffinityIfNecessary(session_->cpu_affinity); + // Pre-allocates thread-local data to avoid the need to allocate on the first log message + cactus_rt::logging::Frontend::preallocate(); + while (!session_->stop_requested.load(std::memory_order_relaxed)) { Trace trace; auto num_events = TryDequeueOnceFromAllTracers(trace); From 46620fde60ca564d31f359c1a9f4464fe51465f9 Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Thu, 10 Oct 2024 12:16:15 +0200 Subject: [PATCH 11/34] Reverted automatic header guard update --- include/cactus_rt/app.h | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/include/cactus_rt/app.h b/include/cactus_rt/app.h index 752f893..1d07c54 100644 --- a/include/cactus_rt/app.h +++ b/include/cactus_rt/app.h @@ -1,5 +1,5 @@ -#ifndef CACTUS_RT_APP -#define CACTUS_RT_APP +#ifndef CACTUS_RT_APP_H_ +#define CACTUS_RT_APP_H_ #include @@ -137,4 +137,4 @@ class App { }; } // namespace cactus_rt -#endif // CACTUS_RT_APP +#endif From baaa14445aecdc8df9af849f9123f0b46d409575 Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Thu, 10 Oct 2024 12:17:16 +0200 Subject: [PATCH 12/34] Reverted automatic header guard update --- include/cactus_rt/thread.h | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/include/cactus_rt/thread.h b/include/cactus_rt/thread.h index 0f9b68f..eff9c96 100644 --- a/include/cactus_rt/thread.h +++ b/include/cactus_rt/thread.h @@ -1,5 +1,5 @@ -#ifndef CACTUS_RT_THREAD -#define CACTUS_RT_THREAD +#ifndef CACTUS_RT_THREAD_H_ +#define CACTUS_RT_THREAD_H_ #include #include // For PTHREAD_STACK_MIN @@ -168,4 +168,4 @@ class Thread { }; } // namespace cactus_rt -#endif // CACTUS_RT_THREAD +#endif From f265b09c1a08c4b3ad596f5e2d292b9888bc7c96 Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Thu, 10 Oct 2024 12:18:17 +0200 Subject: [PATCH 13/34] Reverted automatic header guard update --- include/cactus_rt/tracing/trace_aggregator.h | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/include/cactus_rt/tracing/trace_aggregator.h b/include/cactus_rt/tracing/trace_aggregator.h index 058ae2c..4cd14f2 100644 --- a/include/cactus_rt/tracing/trace_aggregator.h +++ b/include/cactus_rt/tracing/trace_aggregator.h @@ -1,5 +1,5 @@ -#ifndef TRACING_TRACE_AGGREGATOR -#define TRACING_TRACE_AGGREGATOR +#ifndef TRACING_TRACE_AGGREGATOR_H_ +#define TRACING_TRACE_AGGREGATOR_H_ #ifndef CACTUS_RT_TRACING_ENABLED #include "trace_aggregator.disabled.h" @@ -131,4 +131,4 @@ class TraceAggregator { } // namespace cactus_rt::tracing #endif -#endif // TRACING_TRACE_AGGREGATOR +#endif From d00260721030736627f384407aaf0188279529fa Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Thu, 10 Oct 2024 12:18:50 +0200 Subject: [PATCH 14/34] Updated header guard to match other files --- include/cactus_rt/logging.h | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/include/cactus_rt/logging.h b/include/cactus_rt/logging.h index c4e32f4..7f1051f 100644 --- a/include/cactus_rt/logging.h +++ b/include/cactus_rt/logging.h @@ -1,5 +1,5 @@ -#ifndef CACTUS_RT_LOGGING -#define CACTUS_RT_LOGGING +#ifndef CACTUS_RT_LOGGING_H_ +#define CACTUS_RT_LOGGING_H_ #include #include @@ -122,4 +122,4 @@ static cactus_rt::logging::Logger* DefaultLogger(std::string logger_name) { } } // namespace cactus_rt::logging -#endif // CACTUS_RT_LOGGING +#endif From 3d7fe7af6cbec10210345deb9b7b5941bff89b43 Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Thu, 10 Oct 2024 17:39:34 +0200 Subject: [PATCH 15/34] Moved implementation to logging.cc file --- CMakeLists.txt | 1 + include/cactus_rt/logging.h | 42 +++++++------------------------- src/cactus_rt/logging.cc | 48 +++++++++++++++++++++++++++++++++++++ 3 files changed, 57 insertions(+), 34 deletions(-) create mode 100644 src/cactus_rt/logging.cc diff --git a/CMakeLists.txt b/CMakeLists.txt index 7ccc845..21c4c43 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -119,6 +119,7 @@ add_library(cactus_rt src/cactus_rt/thread.cc src/cactus_rt/cyclic_thread.cc src/cactus_rt/signal_handler.cc + src/cactus_rt/logging.cc src/cactus_rt/experimental/lockless/atomic_bitset.cc ) diff --git a/include/cactus_rt/logging.h b/include/cactus_rt/logging.h index 7f1051f..44b26a2 100644 --- a/include/cactus_rt/logging.h +++ b/include/cactus_rt/logging.h @@ -3,11 +3,13 @@ #include #include +#include #include "quill/Frontend.h" #include "quill/Logger.h" #include "quill/backend/BackendOptions.h" -#include "quill/sinks/ConsoleSink.h" +#include "quill/core/Common.h" +#include "quill/core/PatternFormatterOptions.h" #include "quill/sinks/Sink.h" namespace cactus_rt::logging { @@ -60,17 +62,7 @@ using Logger = BoundedDroppingLogger; * * @return quill::BackendOptions */ -static quill::BackendOptions DefaultBackendOptions() { - // Many of the default options set by Quill are already OK for real-time logging - quill::BackendOptions default_backend_options; - - // Disable strict timestamp order by setting the grace period to 0 - this will be faster, but logs may appear out of order - // See quill::BackendOptions documentation for more info - // TODO: Setting this to 0 causes assertion error in Debug builds. Perhaps a bug in Quill (https://github.com/odygrd/quill/issues/605)? - default_backend_options.log_timestamp_ordering_grace_period = std::chrono::milliseconds(1); - - return default_backend_options; -} +quill::BackendOptions DefaultBackendOptions(); /** * Create a ConsoleSink object with console colours. @@ -79,24 +71,12 @@ static quill::BackendOptions DefaultBackendOptions() { * @return A pointer to the created sink. If a sink with that ID already * existed, a pointer to the existing sink is returned instead. */ -static std::shared_ptr DefaultConsoleSink(std::string sink_name) { - // TODO: (QUILL v7.3.0): move implementation to .cpp file - return quill::Frontend::create_or_get_sink( - sink_name, - true // Enable console colours - ); -} +std::shared_ptr DefaultConsoleSink(std::string sink_name); /** * Get a default pattern format. */ -static quill::PatternFormatterOptions DefaultPatternFormatterOptions() { - // TODO: (QUILL v7.3.0): move implementation to .cpp file - return quill::PatternFormatterOptions( - "[%(time)][%(log_level_short_code)][%(logger)][%(file_name):%(line_number)] %(message)", - "%Y-%m-%d %H:%M:%S.%Qns" - ); -} +quill::PatternFormatterOptions DefaultPatternFormatterOptions(); /** * Create a Logger object with default settings which will write logs to the @@ -112,14 +92,8 @@ static quill::PatternFormatterOptions DefaultPatternFormatterOptions() { * @return A pointer to the created logger. If a logger with that ID already * existed, a pointer to the existing logger is returned instead. */ -static cactus_rt::logging::Logger* DefaultLogger(std::string logger_name) { - // TODO: (QUILL v7.3.0): move implementation to .cpp file - return cactus_rt::logging::Frontend::create_or_get_logger( - logger_name, - DefaultConsoleSink(logger_name + "_ConsoleSink"), - DefaultPatternFormatterOptions() - ); -} +cactus_rt::logging::Logger* DefaultLogger(std::string logger_name); + } // namespace cactus_rt::logging #endif diff --git a/src/cactus_rt/logging.cc b/src/cactus_rt/logging.cc new file mode 100644 index 0000000..964fd81 --- /dev/null +++ b/src/cactus_rt/logging.cc @@ -0,0 +1,48 @@ +#include "cactus_rt/logging.h" + +#include +#include +#include + +#include "quill/Logger.h" +#include "quill/backend/BackendOptions.h" +#include "quill/core/PatternFormatterOptions.h" +#include "quill/sinks/ConsoleSink.h" +#include "quill/sinks/Sink.h" + +quill::BackendOptions cactus_rt::logging::DefaultBackendOptions() { + // Many of the default options set by Quill are already OK for real-time logging + quill::BackendOptions default_backend_options; + + // Disable strict timestamp order by setting the grace period to 0 - this will be faster, but logs may appear out of order + // See quill::BackendOptions documentation for more info + // TODO: Setting this to 0 causes assertion error in Debug builds. Perhaps a bug in Quill (https://github.com/odygrd/quill/issues/605)? + default_backend_options.log_timestamp_ordering_grace_period = std::chrono::milliseconds(1); + + return default_backend_options; +} + +cactus_rt::logging::Logger* cactus_rt::logging::DefaultLogger(std::string logger_name) { + // TODO: (QUILL v7.3.0): move implementation to .cpp file + return cactus_rt::logging::Frontend::create_or_get_logger( + logger_name, + DefaultConsoleSink(logger_name + "_ConsoleSink"), + DefaultPatternFormatterOptions() + ); +} + +std::shared_ptr cactus_rt::logging::DefaultConsoleSink(std::string sink_name) { + // TODO: (QUILL v7.3.0): move implementation to .cpp file + return cactus_rt::logging::Frontend::create_or_get_sink( + sink_name, + true // Enable console colours + ); +} + +quill::PatternFormatterOptions cactus_rt::logging::DefaultPatternFormatterOptions() { + // TODO: (QUILL v7.3.0): move implementation to .cpp file + return quill::PatternFormatterOptions( + "[%(time)][%(log_level_short_code)][%(logger)][%(file_name):%(line_number)] %(message)", + "%Y-%m-%d %H:%M:%S.%Qns" + ); +} From e19902c2f9ce7ceb12a02df81f7f524b1883867d Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Thu, 10 Oct 2024 17:39:45 +0200 Subject: [PATCH 16/34] Added missing include --- examples/logging_example/main.cc | 1 + 1 file changed, 1 insertion(+) diff --git a/examples/logging_example/main.cc b/examples/logging_example/main.cc index de3a659..df4384d 100644 --- a/examples/logging_example/main.cc +++ b/examples/logging_example/main.cc @@ -4,6 +4,7 @@ #include #include "quill/LogMacros.h" // Required for the logging macro +#include "quill/sinks/ConsoleSink.h" #include "quill/sinks/FileSink.h" using cactus_rt::App; From 71156eb297aed0a8a8a3c57394ca127133df74c5 Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Thu, 10 Oct 2024 17:39:55 +0200 Subject: [PATCH 17/34] Added missing include and math functions --- examples/message_passing_example/rt_thread.cc | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/examples/message_passing_example/rt_thread.cc b/examples/message_passing_example/rt_thread.cc index 6028bd8..4b7563c 100644 --- a/examples/message_passing_example/rt_thread.cc +++ b/examples/message_passing_example/rt_thread.cc @@ -1,12 +1,15 @@ #include "rt_thread.h" +#define _USE_MATH_DEFINES +#include "cmath" + cactus_rt::CyclicThread::LoopControl RtThread::Loop(int64_t ellapsed_ns) noexcept { const double ellapsed_ms = static_cast(ellapsed_ns) / 1'000'000.0; const double period = 1000.0; const double amplitude = 1.0; - data_logger_->EmplaceData(ellapsed_ms, amplitude * cos(2 * M_PI / period * ellapsed_ms)); + data_logger_->EmplaceData(ellapsed_ms, amplitude * std::cos(2 * M_PI / period * ellapsed_ms)); ++iterations_; return iterations_ >= max_iterations_ ? LoopControl::Stop : LoopControl::Continue; From ab566ae15dd97d8ba4ae8d645132b07e84e9af0c Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Thu, 10 Oct 2024 17:41:34 +0200 Subject: [PATCH 18/34] Removed solved todos --- include/cactus_rt/logging.h | 3 --- src/cactus_rt/logging.cc | 3 --- 2 files changed, 6 deletions(-) diff --git a/include/cactus_rt/logging.h b/include/cactus_rt/logging.h index 44b26a2..548881a 100644 --- a/include/cactus_rt/logging.h +++ b/include/cactus_rt/logging.h @@ -82,9 +82,6 @@ quill::PatternFormatterOptions DefaultPatternFormatterOptions(); * Create a Logger object with default settings which will write logs to the * console with a default format. * - * TODO: (QUILL v7.3.0): Make this use the `cactus_rt::Logger` - * (`cactus_rt::BoundedDroppingLogger`) instead - * * TODO: (QUILL v7.3.0): What happens if we pass in a logger name which already * exists? Are the sink and format discarded? * diff --git a/src/cactus_rt/logging.cc b/src/cactus_rt/logging.cc index 964fd81..d1e83a6 100644 --- a/src/cactus_rt/logging.cc +++ b/src/cactus_rt/logging.cc @@ -23,7 +23,6 @@ quill::BackendOptions cactus_rt::logging::DefaultBackendOptions() { } cactus_rt::logging::Logger* cactus_rt::logging::DefaultLogger(std::string logger_name) { - // TODO: (QUILL v7.3.0): move implementation to .cpp file return cactus_rt::logging::Frontend::create_or_get_logger( logger_name, DefaultConsoleSink(logger_name + "_ConsoleSink"), @@ -32,7 +31,6 @@ cactus_rt::logging::Logger* cactus_rt::logging::DefaultLogger(std::string logger } std::shared_ptr cactus_rt::logging::DefaultConsoleSink(std::string sink_name) { - // TODO: (QUILL v7.3.0): move implementation to .cpp file return cactus_rt::logging::Frontend::create_or_get_sink( sink_name, true // Enable console colours @@ -40,7 +38,6 @@ std::shared_ptr cactus_rt::logging::DefaultConsoleSink(std::string } quill::PatternFormatterOptions cactus_rt::logging::DefaultPatternFormatterOptions() { - // TODO: (QUILL v7.3.0): move implementation to .cpp file return quill::PatternFormatterOptions( "[%(time)][%(log_level_short_code)][%(logger)][%(file_name):%(line_number)] %(message)", "%Y-%m-%d %H:%M:%S.%Qns" From c81ca7fdce09d147e5fffda84fa900215c2fab19 Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Thu, 10 Oct 2024 17:59:47 +0200 Subject: [PATCH 19/34] Updated thread config to use logger name instead of passing around logger pointers --- examples/logging_example/main.cc | 5 +++-- include/cactus_rt/config.h | 11 ++++++++--- include/cactus_rt/logging.h | 15 ++++++--------- include/cactus_rt/thread.h | 12 +++++++----- 4 files changed, 24 insertions(+), 19 deletions(-) diff --git a/examples/logging_example/main.cc b/examples/logging_example/main.cc index df4384d..6310f8e 100644 --- a/examples/logging_example/main.cc +++ b/examples/logging_example/main.cc @@ -82,12 +82,13 @@ int main() { // Create a custom formatter pattern auto pattern_format = quill::PatternFormatterOptions( - "[%(time)][%(log_level_short_code)][%(logger)][%(file_name):%(line_number)] - WOW custom message format - %(message)", + "[%(time)][%(log_level_short_code)][%(logger)][%(process_id)][%(file_name):%(line_number)] - WOW custom message format - %(message)", "%H:%M:%S.%Qns" ); // Use the new sinks and pattern to create a custom logger for the other thread - other_thread_config.logger_config.thread_logger = cactus_rt::logging::Frontend::create_or_get_logger("CustomThreadLogger", sinks, pattern_format); + auto* custom_thread_logger = cactus_rt::logging::Frontend::create_or_get_logger("CustomThreadLogger", sinks, pattern_format); + other_thread_config.logger_config.logger_name = custom_thread_logger->get_logger_name(); // Add a second instance of the example thread class, which uses the configuration with the new logger auto other_thread = app.CreateThread("OtherExampleRTThread", other_thread_config); diff --git a/include/cactus_rt/config.h b/include/cactus_rt/config.h index ea93c2a..7dcf851 100644 --- a/include/cactus_rt/config.h +++ b/include/cactus_rt/config.h @@ -105,9 +105,14 @@ struct ThreadTracerConfig { * @brief The configuration needed for Quill logging in a thread */ struct ThreadLoggerConfig { - // Pointer to the thread logger that is to be used. If nullptr is given, a default thread logger is created instead. - // TODO: (QUILL v7.3.0): Use a string as the logger name instead? - cactus_rt::logging::Logger* thread_logger = nullptr; + /** + * @brief Name of the logger that is to be used as thread logger. + * + * @note If not given, a default thread logger is created with the name set to the thread name. + * + * @note If the name given does not correspond to a created logger, a default thread logger is created with the `logger_name`. + */ + std::string logger_name; }; /** diff --git a/include/cactus_rt/logging.h b/include/cactus_rt/logging.h index 548881a..5b69786 100644 --- a/include/cactus_rt/logging.h +++ b/include/cactus_rt/logging.h @@ -67,8 +67,8 @@ quill::BackendOptions DefaultBackendOptions(); /** * Create a ConsoleSink object with console colours. * - * @param sink_name The Sink ID. - * @return A pointer to the created sink. If a sink with that ID already + * @param sink_name The sink name to use. + * @return A pointer to the created sink. If a sink with that name already * existed, a pointer to the existing sink is returned instead. */ std::shared_ptr DefaultConsoleSink(std::string sink_name); @@ -79,14 +79,11 @@ std::shared_ptr DefaultConsoleSink(std::string sink_name); quill::PatternFormatterOptions DefaultPatternFormatterOptions(); /** - * Create a Logger object with default settings which will write logs to the - * console with a default format. + * Create or get a Logger object with default settings which will write logs to + * the console with a default format. * - * TODO: (QUILL v7.3.0): What happens if we pass in a logger name which already - * exists? Are the sink and format discarded? - * - * @param logger_name - * @return A pointer to the created logger. If a logger with that ID already + * @param logger_name The logger name to use. + * @return A pointer to the created logger. If a logger with that name already * existed, a pointer to the existing logger is returned instead. */ cactus_rt::logging::Logger* DefaultLogger(std::string logger_name); diff --git a/include/cactus_rt/thread.h b/include/cactus_rt/thread.h index eff9c96..41cf2ba 100644 --- a/include/cactus_rt/thread.h +++ b/include/cactus_rt/thread.h @@ -59,15 +59,17 @@ class Thread { : config_(config), name_(name), cpu_affinity_(config_.cpu_affinity), - stack_size_(static_cast(PTHREAD_STACK_MIN) + config_.stack_size), - logger_(config.logger_config.thread_logger) { + stack_size_(static_cast(PTHREAD_STACK_MIN) + config_.stack_size) { if (!config.scheduler) { throw std::runtime_error("ThreadConfig::scheduler cannot be nullptr"); } - // If no logger was passed in the thread configuration, create a default logger instead - if (logger_ == nullptr) { - logger_ = cactus_rt::logging::DefaultLogger(name_); + if (!config.logger_config.logger_name.empty()) { + // If a logger name was passed in the thread configuration, get or create it + logger_ = cactus_rt::logging::DefaultLogger(config_.logger_config.logger_name); + } else { + // If no logger name was passed in the thread configuration, create a new one using the thread name + logger_ = cactus_rt::logging::DefaultLogger(this->Name()); } } From 3374899b865a2a84f92f94f89057d7ed4b0a85e5 Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Thu, 10 Oct 2024 18:09:28 +0200 Subject: [PATCH 20/34] Added logging header to default includes --- include/cactus_rt/rt.h | 1 + 1 file changed, 1 insertion(+) diff --git a/include/cactus_rt/rt.h b/include/cactus_rt/rt.h index b4765ae..285a814 100644 --- a/include/cactus_rt/rt.h +++ b/include/cactus_rt/rt.h @@ -1,5 +1,6 @@ #include "app.h" #include "cyclic_thread.h" +#include "logging.h" #include "mutex.h" #include "signal_handler.h" #include "thread.h" From 901c8ed2b3b5a35f2588f0688edc57431facafdb Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Thu, 10 Oct 2024 18:10:01 +0200 Subject: [PATCH 21/34] Added the logging macros as convenience include to logging, to prevent having to include in all examples. --- examples/lockless_examples/realtime_read.cc | 2 -- examples/logging_example/main.cc | 1 - examples/message_passing_example/data_logger_thread.cc | 2 -- examples/mutex_example/main.cc | 1 - examples/simple_example/main.cc | 4 ++-- examples/tracing_example_no_rt/main.cc | 3 +-- include/cactus_rt/logging.h | 4 ++++ 7 files changed, 7 insertions(+), 10 deletions(-) diff --git a/examples/lockless_examples/realtime_read.cc b/examples/lockless_examples/realtime_read.cc index 829d13e..e22e8b7 100644 --- a/examples/lockless_examples/realtime_read.cc +++ b/examples/lockless_examples/realtime_read.cc @@ -1,8 +1,6 @@ #include #include -#include "quill/LogMacros.h" // Required for the logging macro - using cactus_rt::App; using cactus_rt::CyclicThread; using cactus_rt::Thread; diff --git a/examples/logging_example/main.cc b/examples/logging_example/main.cc index 6310f8e..5802025 100644 --- a/examples/logging_example/main.cc +++ b/examples/logging_example/main.cc @@ -3,7 +3,6 @@ #include #include -#include "quill/LogMacros.h" // Required for the logging macro #include "quill/sinks/ConsoleSink.h" #include "quill/sinks/FileSink.h" diff --git a/examples/message_passing_example/data_logger_thread.cc b/examples/message_passing_example/data_logger_thread.cc index dfad6b4..1a1866a 100644 --- a/examples/message_passing_example/data_logger_thread.cc +++ b/examples/message_passing_example/data_logger_thread.cc @@ -3,8 +3,6 @@ #include #include -#include "quill/LogMacros.h" // Required for the logging macro - DataLogger::DataLogger( const std::string& data_file_path, int64_t period_ns, diff --git a/examples/mutex_example/main.cc b/examples/mutex_example/main.cc index fafb8b2..31945f2 100644 --- a/examples/mutex_example/main.cc +++ b/examples/mutex_example/main.cc @@ -5,7 +5,6 @@ #include #include "double_buffer.h" -#include "quill/LogMacros.h" // Required for the logging macro using cactus_rt::App; using cactus_rt::CyclicThread; diff --git a/examples/simple_example/main.cc b/examples/simple_example/main.cc index 9a9f5e6..850d473 100644 --- a/examples/simple_example/main.cc +++ b/examples/simple_example/main.cc @@ -3,8 +3,8 @@ #include #include -#include "quill/LogMacros.h" // Required for the logging macro -#include "quill/std/Chrono.h" // Required to parse std::chrono inside logging macros +// Required to parse std::chrono inside logging macros +#include "quill/std/Chrono.h" // IWYU pragma: keep using cactus_rt::App; using cactus_rt::CyclicThread; diff --git a/examples/tracing_example_no_rt/main.cc b/examples/tracing_example_no_rt/main.cc index fffad8e..b14ac10 100644 --- a/examples/tracing_example_no_rt/main.cc +++ b/examples/tracing_example_no_rt/main.cc @@ -3,8 +3,7 @@ #include #include -#include "quill/Backend.h" // Required to start/stop the quill backend thread -#include "quill/LogMacros.h" // Required for the logging macro +#include "quill/Backend.h" // Required to start/stop the quill backend thread using namespace std::chrono_literals; using FileSink = cactus_rt::tracing::FileSink; diff --git a/include/cactus_rt/logging.h b/include/cactus_rt/logging.h index 5b69786..20df59b 100644 --- a/include/cactus_rt/logging.h +++ b/include/cactus_rt/logging.h @@ -12,6 +12,10 @@ #include "quill/core/PatternFormatterOptions.h" #include "quill/sinks/Sink.h" +// The quill logging macros are explicitly included in this header file. +// This is convenience to prevent another #include when using cactus_rt logging. +#include "quill/LogMacros.h" // IWYU pragma: export + namespace cactus_rt::logging { /** * Defines a Bounded Dropping queue, to drop logging messages if the buffers From 1db852df36ec3154ef09b186aadbbd4d6ac2d6d5 Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Thu, 10 Oct 2024 18:14:35 +0200 Subject: [PATCH 22/34] Removed old git tag --- CMakeLists.txt | 2 -- 1 file changed, 2 deletions(-) diff --git a/CMakeLists.txt b/CMakeLists.txt index 21c4c43..cad1f8f 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -27,8 +27,6 @@ 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 a058985253dffd6a77b4eeca3ba4aa5ad85a2d02 GIT_TAG v7.3.0 ) From fe0c3bddece804e80acde1433da186e38499aafd Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Thu, 10 Oct 2024 21:02:24 +0200 Subject: [PATCH 23/34] Removed deprecated compile flag for Quill --- CMakeLists.txt | 3 --- 1 file changed, 3 deletions(-) diff --git a/CMakeLists.txt b/CMakeLists.txt index cad1f8f..3c2891d 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -134,9 +134,6 @@ target_link_libraries(cactus_rt Threads::Threads ) -# Use a bounded queue -target_compile_definitions(cactus_rt PUBLIC QUILL_USE_BOUNDED_QUEUE) - if(${CMAKE_PROJECT_NAME} STREQUAL ${PROJECT_NAME}) if (ENABLE_TRACING) target_sources(cactus_rt From 3d1f03b9d4ede838cf313663f0822594eef1b57c Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Thu, 10 Oct 2024 21:51:42 +0200 Subject: [PATCH 24/34] Reverted accidental include guard update --- include/cactus_rt/tracing/trace_aggregator.h | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/include/cactus_rt/tracing/trace_aggregator.h b/include/cactus_rt/tracing/trace_aggregator.h index 4cd14f2..1cda95c 100644 --- a/include/cactus_rt/tracing/trace_aggregator.h +++ b/include/cactus_rt/tracing/trace_aggregator.h @@ -1,5 +1,5 @@ -#ifndef TRACING_TRACE_AGGREGATOR_H_ -#define TRACING_TRACE_AGGREGATOR_H_ +#ifndef CACTUS_RT_TRACING_TRACE_AGGREGATOR_H_ +#define CACTUS_RT_TRACING_TRACE_AGGREGATOR_H_ #ifndef CACTUS_RT_TRACING_ENABLED #include "trace_aggregator.disabled.h" From 5734001200d47c100f157ccf94da609d9fb41a87 Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Thu, 10 Oct 2024 22:31:53 +0200 Subject: [PATCH 25/34] Set the default console handler sink name to be static. If multiple loggers reference the same sink, that is fine. --- include/cactus_rt/logging.h | 14 +++++++++----- src/cactus_rt/logging.cc | 8 +++++--- 2 files changed, 14 insertions(+), 8 deletions(-) diff --git a/include/cactus_rt/logging.h b/include/cactus_rt/logging.h index 20df59b..8657203 100644 --- a/include/cactus_rt/logging.h +++ b/include/cactus_rt/logging.h @@ -68,14 +68,18 @@ using Logger = BoundedDroppingLogger; */ quill::BackendOptions DefaultBackendOptions(); +std::string DefaultConsoleSinkName(); + /** - * Create a ConsoleSink object with console colours. + * Create a default ConsoleSink object with console colours. The name of this + * sink is defined by `cactus_rt::logging::DefaultConsoleSinkName()`. + * + * @note If this is not the first call to this function, a pointer to the + * existing default console sink is returned instead of creating a new one. * - * @param sink_name The sink name to use. - * @return A pointer to the created sink. If a sink with that name already - * existed, a pointer to the existing sink is returned instead. + * @return A pointer to the sink. */ -std::shared_ptr DefaultConsoleSink(std::string sink_name); +std::shared_ptr DefaultConsoleSink(); /** * Get a default pattern format. diff --git a/src/cactus_rt/logging.cc b/src/cactus_rt/logging.cc index d1e83a6..b9b47e2 100644 --- a/src/cactus_rt/logging.cc +++ b/src/cactus_rt/logging.cc @@ -25,14 +25,16 @@ quill::BackendOptions cactus_rt::logging::DefaultBackendOptions() { cactus_rt::logging::Logger* cactus_rt::logging::DefaultLogger(std::string logger_name) { return cactus_rt::logging::Frontend::create_or_get_logger( logger_name, - DefaultConsoleSink(logger_name + "_ConsoleSink"), + DefaultConsoleSink(), DefaultPatternFormatterOptions() ); } -std::shared_ptr cactus_rt::logging::DefaultConsoleSink(std::string sink_name) { +std::string cactus_rt::logging::DefaultConsoleSinkName() { return "DefaultConsoleSink"; } + +std::shared_ptr cactus_rt::logging::DefaultConsoleSink() { return cactus_rt::logging::Frontend::create_or_get_sink( - sink_name, + cactus_rt::logging::DefaultConsoleSinkName(), true // Enable console colours ); } From 62ce284e764c6b2c64e989a486c64f01b86f9c71 Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Thu, 10 Oct 2024 22:32:26 +0200 Subject: [PATCH 26/34] Fixed clang-tidy warnings which were treated as errors in the CI test docker --- examples/logging_example/main.cc | 2 +- examples/message_passing_example/rt_thread.cc | 5 ++--- 2 files changed, 3 insertions(+), 4 deletions(-) diff --git a/examples/logging_example/main.cc b/examples/logging_example/main.cc index 5802025..3e677a3 100644 --- a/examples/logging_example/main.cc +++ b/examples/logging_example/main.cc @@ -77,7 +77,7 @@ int main() { ); // Add both sinks to a vector - std::vector> sinks = {console_sink, file_sink}; + const std::vector> sinks = {console_sink, file_sink}; // Create a custom formatter pattern auto pattern_format = quill::PatternFormatterOptions( diff --git a/examples/message_passing_example/rt_thread.cc b/examples/message_passing_example/rt_thread.cc index 4b7563c..b5bb192 100644 --- a/examples/message_passing_example/rt_thread.cc +++ b/examples/message_passing_example/rt_thread.cc @@ -1,7 +1,6 @@ #include "rt_thread.h" -#define _USE_MATH_DEFINES -#include "cmath" +#include cactus_rt::CyclicThread::LoopControl RtThread::Loop(int64_t ellapsed_ns) noexcept { const double ellapsed_ms = static_cast(ellapsed_ns) / 1'000'000.0; @@ -9,7 +8,7 @@ cactus_rt::CyclicThread::LoopControl RtThread::Loop(int64_t ellapsed_ns) noexcep const double period = 1000.0; const double amplitude = 1.0; - data_logger_->EmplaceData(ellapsed_ms, amplitude * std::cos(2 * M_PI / period * ellapsed_ms)); + data_logger_->EmplaceData(ellapsed_ms, amplitude * cos(2 * M_PI / period * ellapsed_ms)); ++iterations_; return iterations_ >= max_iterations_ ? LoopControl::Stop : LoopControl::Continue; From 63089eb38766cec67879970276db14b42df29baf Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Fri, 11 Oct 2024 14:43:00 +0200 Subject: [PATCH 27/34] Added check that the quill Backend thread is running before flushing the logs, because the flush will block indefinitely if the backend thread is stopped --- src/cactus_rt/thread.cc | 11 ++++++++--- src/cactus_rt/tracing/trace_aggregator.cc | 11 ++++++++--- 2 files changed, 16 insertions(+), 6 deletions(-) diff --git a/src/cactus_rt/thread.cc b/src/cactus_rt/thread.cc index c76c5f4..28ce3ef 100644 --- a/src/cactus_rt/thread.cc +++ b/src/cactus_rt/thread.cc @@ -11,14 +11,19 @@ #include "cactus_rt/config.h" #include "cactus_rt/logging.h" #include "cactus_rt/tracing/thread_tracer.h" +#include "quill/Backend.h" #include "quill/LogMacros.h" namespace cactus_rt { Thread::~Thread() { - // Blocks until all messages up to the current timestamp are flushed on the - // logger, to ensure every message is logged. - this->Logger()->flush_log(); + // Flushing the logger only if the background thread is still running, + // otherwise `flush_log()` will block indefinitely. + if (quill::Backend::is_running()) { + // Blocks until all messages up to the current timestamp are flushed on the + // logger, to ensure every message is logged. + this->Logger()->flush_log(); + } } void* Thread::RunThread(void* data) { diff --git a/src/cactus_rt/tracing/trace_aggregator.cc b/src/cactus_rt/tracing/trace_aggregator.cc index 65d5999..125d3ac 100644 --- a/src/cactus_rt/tracing/trace_aggregator.cc +++ b/src/cactus_rt/tracing/trace_aggregator.cc @@ -18,6 +18,7 @@ #include #include "cactus_rt/logging.h" +#include "quill/Backend.h" #include "quill/LogMacros.h" using cactus_tracing::vendor::perfetto::protos::InternedData; @@ -64,9 +65,13 @@ TraceAggregator::TraceAggregator(std::string process_name) } TraceAggregator::~TraceAggregator() { - // Blocks until all messages up to the current timestamp are flushed on the - // logger, to ensure every message is logged. - this->Logger()->flush_log(); + // Flushing the logger only if the background thread is still running, + // otherwise `flush_log()` will block indefinitely. + if (quill::Backend::is_running()) { + // Blocks until all messages up to the current timestamp are flushed on the + // logger, to ensure every message is logged. + this->Logger()->flush_log(); + } } void TraceAggregator::RegisterThreadTracer(std::shared_ptr tracer) { From 0f14b5b628ad09d2b5ab8eb543a95af0c2291292 Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Fri, 11 Oct 2024 15:31:25 +0200 Subject: [PATCH 28/34] Updated logging in ROS 2 code --- include/cactus_rt/ros2/publisher.h | 17 ++++++++-------- include/cactus_rt/ros2/ros2_adapter.h | 4 ++-- include/cactus_rt/ros2/subscription.h | 28 +++++++++++++-------------- src/cactus_rt/ros2/ros2_adapter.cc | 4 +++- 4 files changed, 28 insertions(+), 25 deletions(-) diff --git a/include/cactus_rt/ros2/publisher.h b/include/cactus_rt/ros2/publisher.h index c8fd498..60ba2ff 100644 --- a/include/cactus_rt/ros2/publisher.h +++ b/include/cactus_rt/ros2/publisher.h @@ -7,7 +7,8 @@ #include #include -#include "quill/Quill.h" +#include "cactus_rt/logging.h" +#include "quill/LogMacros.h" namespace cactus_rt::ros2 { class Ros2Adapter; @@ -31,7 +32,7 @@ class Publisher : public IPublisher { using NoConversion = std::is_same; using AdaptedRosType = typename std::conditional_t>; - quill::Logger* logger_; + cactus_rt::logging::Logger* logger_; typename rclcpp::Publisher::SharedPtr publisher_; moodycamel::ReaderWriterQueue queue_; @@ -77,11 +78,11 @@ class Publisher : public IPublisher { } static std::shared_ptr> Create( - quill::Logger* logger, - rclcpp::Node& node, - const std::string& topic_name, - const rclcpp::QoS& qos, - const size_t rt_queue_size = 1000 + cactus_rt::logging::Logger* logger, + rclcpp::Node& node, + const std::string& topic_name, + const rclcpp::QoS& qos, + const size_t rt_queue_size = 1000 ) { return std::shared_ptr>( new Publisher( @@ -93,7 +94,7 @@ class Publisher : public IPublisher { } Publisher( - quill::Logger* logger, + cactus_rt::logging::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 da9c572..ce05a89 100644 --- a/include/cactus_rt/ros2/ros2_adapter.h +++ b/include/cactus_rt/ros2/ros2_adapter.h @@ -10,8 +10,8 @@ #include #include +#include "cactus_rt/logging.h" #include "publisher.h" -#include "quill/Quill.h" #include "subscription.h" namespace cactus_rt::ros2 { @@ -44,7 +44,7 @@ class Ros2Adapter { std::vector> publishers_; std::vector> subscriptions_; - quill::Logger* logger_; + cactus_rt::logging::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 67bd856..99474d3 100644 --- a/include/cactus_rt/ros2/subscription.h +++ b/include/cactus_rt/ros2/subscription.h @@ -9,7 +9,7 @@ #include #include "../experimental/lockless/spsc/realtime_readable_value.h" -#include "quill/Quill.h" +#include "cactus_rt/logging.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. @@ -43,7 +43,7 @@ class SubscriptionLatest : public ISubscription { using RealtimeReadableValue = cactus_rt::experimental::lockless::spsc::RealtimeReadableValue>; - quill::Logger* logger_; + cactus_rt::logging::Logger* logger_; typename rclcpp::Subscription::SharedPtr ros_subscription_; int64_t current_msg_id_ = 0; RealtimeReadableValue latest_value_; @@ -60,10 +60,10 @@ class SubscriptionLatest : public ISubscription { } static std::shared_ptr> Create( - quill::Logger* logger, - rclcpp::Node& node, - const std::string& topic_name, - const rclcpp::QoS& qos + cactus_rt::logging::Logger* logger, + rclcpp::Node& node, + const std::string& topic_name, + const rclcpp::QoS& qos ) { std::shared_ptr> subscription( new SubscriptionLatest(logger) @@ -81,7 +81,7 @@ class SubscriptionLatest : public ISubscription { return subscription; } - explicit SubscriptionLatest(quill::Logger* logger) : logger_(logger) {} + explicit SubscriptionLatest(cactus_rt::logging::Logger* logger) : logger_(logger) {} public: StampedValue ReadLatest() noexcept { @@ -100,7 +100,7 @@ class SubscriptionQueued : public ISubscription { using Queue = moodycamel::ReaderWriterQueue>; - quill::Logger* logger_; + cactus_rt::logging::Logger* logger_; typename rclcpp::Subscription::SharedPtr ros_subscription_; int64_t current_msg_id_ = 0; Queue queue_; @@ -114,11 +114,11 @@ class SubscriptionQueued : public ISubscription { } static std::shared_ptr> Create( - quill::Logger* logger, - rclcpp::Node& node, - const std::string& topic_name, - const rclcpp::QoS& qos, - const size_t rt_queue_size = 1000 + cactus_rt::logging::Logger* logger, + rclcpp::Node& node, + const std::string& topic_name, + const rclcpp::QoS& qos, + const size_t rt_queue_size = 1000 ) { std::shared_ptr> subscription( new SubscriptionQueued( @@ -140,7 +140,7 @@ class SubscriptionQueued : public ISubscription { } SubscriptionQueued( - quill::Logger* logger, + cactus_rt::logging::Logger* logger, moodycamel::ReaderWriterQueue>&& queue ) : logger_(logger), queue_(std::move(queue)) {} diff --git a/src/cactus_rt/ros2/ros2_adapter.cc b/src/cactus_rt/ros2/ros2_adapter.cc index a9efc6e..c87bf17 100644 --- a/src/cactus_rt/ros2/ros2_adapter.cc +++ b/src/cactus_rt/ros2/ros2_adapter.cc @@ -2,11 +2,13 @@ #include +#include "cactus_rt/logging.h" + namespace cactus_rt::ros2 { Ros2Adapter::Ros2Adapter(const std::string& name, const Ros2Adapter::Config& config) : ros_node_(std::make_shared(name + "_ros_adapter")), - logger_(quill::create_logger("Ros2Adapter")) { + logger_(cactus_rt::logging::DefaultLogger("Ros2Adapter")) { timer_ = this->ros_node_->create_wall_timer(config.timer_interval, [this] { TimerCallback(); }); } From 49e13aa1d3a4c7be44888e48e177ab02b1e177c3 Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Fri, 11 Oct 2024 16:55:36 +0200 Subject: [PATCH 29/34] Fix for warning which was treated as error by clang-tidy --- examples/ros2/publisher/complex_data.cc | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/examples/ros2/publisher/complex_data.cc b/examples/ros2/publisher/complex_data.cc index 31740c4..8ddb361 100644 --- a/examples/ros2/publisher/complex_data.cc +++ b/examples/ros2/publisher/complex_data.cc @@ -70,7 +70,7 @@ class RTROS2PublisherThread : public cactus_rt::CyclicThread, public cactus_rt:: const auto elapsed_ns_f = static_cast(elapsed_ns); - MyCoefficientData msg{ + const MyCoefficientData msg{ elapsed_ns_f, elapsed_ns_f / 10.0F, elapsed_ns_f / 100.0F, From b27e7123d0b2d523d31ee3d3755a54e3bb44d9d8 Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Fri, 11 Oct 2024 18:05:27 +0200 Subject: [PATCH 30/34] Updated documentation in logging example --- examples/logging_example/README.md | 83 +++++++++++++++++++++++++++++- examples/logging_example/main.cc | 8 ++- 2 files changed, 87 insertions(+), 4 deletions(-) diff --git a/examples/logging_example/README.md b/examples/logging_example/README.md index 0b60003..bad547e 100644 --- a/examples/logging_example/README.md +++ b/examples/logging_example/README.md @@ -1,6 +1,85 @@ `logging_example` ================ -A simple example showing how to configure logging. Cactus RT uses [Quill](https://github.com/odygrd/quill) as a logger. +A simple example showing how to configure logging. Cactus RT uses [Quill](https://github.com/odygrd/quill) as a logger. Read the [Quill documentation](https://quillcpp.readthedocs.io/en/latest/) for details and additional examples. -To configure logging, create your own `quill::Config` and pass it to the `App` constructor. Configuration options for Quill can be found in the [Quill documentation](https://quillcpp.readthedocs.io/en/latest/users-api.html#config-class). The log format can also be configured, as per the [formatting documetnation](https://quillcpp.readthedocs.io/en/latest/users-api.html#config-class). +## `cactus_rt/logging.h` + +To use Quill in a real-time friendly manner, `include/cactus_rt/logging.h` defines important types, default settings and utilities. + +**Important**: `cactus_rt::logging::Logger` and `cactus_rt::logging::Frontend` types which define a `quill::QueueType::BoundedDropping` queue to prevent delays in case the loggers overflow, which is essential in any real-time thread. These *must* be used throughout the application instead of the default `quill::Logger` and `quill::Frontend` types! + +## Logging non-primitive STL types + +Logging non-primitive types on the hot path (i.e. in a real-time thread) requires some additional work. Most often-used standard library types are already provided for you by Quill though, and only require a simple `#include`. + +For example, when logging `std::chrono` types, you need to insert the following: + +```cpp +#include "quill/LogMacros.h" +// Required to parse std::chrono inside logging macros +#include "quill/std/Chrono.h" // IWYU pragma: keep + +... + +LOG_INFO(logger, "Time: {}", std::chrono::seconds(3)); +``` + +The [Quill Cheat Sheet](https://quillcpp.readthedocs.io/en/latest/cheat_sheet.html#) contains very useful information for logging various non-primitive types. + +## Default logging + +If unspecified, each thread will create a default logger for itself. This logger will write to a default console sink and uses a default format. All of these defaults can be found in `include/cactus_rt/logging.h`. + +## Customize logger, sink(s) or pattern format + +Customization of the quill Backend worker thread can be done by passing in logging options to the `cactus_rt::AppConfig`. + +To use a custom sink or pattern format, define them before creating the logger. The sink(s) and pattern format are used to create the logger. Finally, the name of the created logger must be passed to the `cactus_rt::ThreadConfig`. + +The snippets below might help + +1. Create a sink (see the [Quill documentation on sink types](https://quillcpp.readthedocs.io/en/latest/sink_types.html) for the full code to create each sink). + + ```cpp + // Default console sink + auto console_sink = cactus_rt::logging::DefaultConsoleSink(); + + // Custom sink, e.g. a file sink + // !! Make sure to use `cactus_rt::logging::Frontend instead of quill::Frontend !! + auto file_sink = cactus_rt::logging::Frontend::create_or_get_sink(...); + ``` + +2. Create a pattern format + + ```cpp + // Default formatter pattern + auto pattern_format = cactus_rt::logging::DefaultPatternFormatterOptions(); + + // Custom formatter pattern + auto pattern_format = quill::PatternFormatterOptions(...); + ``` + +3. Create the logger + + ```cpp + // Create custom logger using a single sink + // !! Make sure to use `cactus_rt::logging::Frontend instead of quill::Frontend !! + auto* custom_logger = cactus_rt::logging::Frontend::create_or_get_logger("CustomLogger", console_sink, pattern_format); + + // Alternatively, you can add multiple sinks to a vector and pass that instead + const std::vector> sinks = {console_sink, file_sink}; + // !! Make sure to use `cactus_rt::logging::Frontend instead of quill::Frontend !! + auto* custom_logger = cactus_rt::logging::Frontend::create_or_get_logger("CustomLogger", sinks, pattern_format); + ``` + +4. Pass the logger to the thread + + ```cpp + // Add the custom logger name to the thread config + cactus_rt::ThreadConfig thread_config; + thread_config.logger_name = custom_logger->get_logger_name(); + + // Finally, create the thread with using the thread config + auto thread = app.CreateThread("ExampleRTThread", thread_config); + ``` diff --git a/examples/logging_example/main.cc b/examples/logging_example/main.cc index 3e677a3..f91155f 100644 --- a/examples/logging_example/main.cc +++ b/examples/logging_example/main.cc @@ -3,9 +3,13 @@ #include #include +#include "quill/backend/BackendOptions.h" #include "quill/sinks/ConsoleSink.h" #include "quill/sinks/FileSink.h" +// Required to parse std::chrono inside logging macros +#include "quill/std/Chrono.h" // IWYU pragma: keep + using cactus_rt::App; using cactus_rt::CyclicThread; @@ -24,10 +28,10 @@ class ExampleRTThread : public CyclicThread { } protected: - LoopControl Loop(int64_t /*now*/) noexcept final { + LoopControl Loop(int64_t elapsed_ns) noexcept final { loop_counter_++; if (loop_counter_ % 1000 == 0) { - LOG_INFO(Logger(), "Loop {}", loop_counter_); + LOG_INFO(Logger(), "Loop {} ({})", loop_counter_, std::chrono::nanoseconds(elapsed_ns)); } LOG_INFO_LIMIT(std::chrono::milliseconds{1500}, Logger(), "Log limit: Loop {}", loop_counter_); return LoopControl::Continue; From f7947d08e328bc57b1457e27de590284fa9a192e Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Sun, 13 Oct 2024 23:01:47 +0200 Subject: [PATCH 31/34] Added type alias for custom FrontendOptions --- include/cactus_rt/logging.h | 3 +++ 1 file changed, 3 insertions(+) diff --git a/include/cactus_rt/logging.h b/include/cactus_rt/logging.h index 8657203..afb3c42 100644 --- a/include/cactus_rt/logging.h +++ b/include/cactus_rt/logging.h @@ -35,6 +35,9 @@ struct BoundedDroppingFrontendOptions { static constexpr bool huge_pages_enabled = false; }; +/// Type alias for `BoundedDroppingFrontendOptions` +using FrontendOptions = BoundedDroppingFrontendOptions; + /** * Define a quill::Frontend class using the custom options. This Frontend must * be used consistently throughout the application instead of the default From 10649a4cfe4429dd0ce057a43a9711e24114e1dc Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Mon, 14 Oct 2024 09:45:34 +0200 Subject: [PATCH 32/34] Updated todo for fixing timestamp grace period in 7.4.0 --- examples/logging_example/main.cc | 2 +- src/cactus_rt/logging.cc | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/examples/logging_example/main.cc b/examples/logging_example/main.cc index f91155f..3c7e19a 100644 --- a/examples/logging_example/main.cc +++ b/examples/logging_example/main.cc @@ -52,7 +52,7 @@ int main() { // Disable strict timestamp order by setting the grace period to 0 - this will be faster, but logs may appear out of order // See quill::BackendOptions documentation for more info - // TODO: Setting this to 0 causes assertion error in Debug builds. Perhaps a bug in Quill (https://github.com/odygrd/quill/issues/605)? + // TODO: There is a bug in quill where setting the grace period to 0 causes assertion error in Debug builds. This is fixed in 7.4.0 (https://github.com/odygrd/quill/issues/605) logger_backend_options.log_timestamp_ordering_grace_period = std::chrono::microseconds(1); // Set the background logging thread CPU affinity diff --git a/src/cactus_rt/logging.cc b/src/cactus_rt/logging.cc index b9b47e2..c183e2b 100644 --- a/src/cactus_rt/logging.cc +++ b/src/cactus_rt/logging.cc @@ -16,7 +16,7 @@ quill::BackendOptions cactus_rt::logging::DefaultBackendOptions() { // Disable strict timestamp order by setting the grace period to 0 - this will be faster, but logs may appear out of order // See quill::BackendOptions documentation for more info - // TODO: Setting this to 0 causes assertion error in Debug builds. Perhaps a bug in Quill (https://github.com/odygrd/quill/issues/605)? + // TODO: There is a bug in quill where setting the grace period to 0 causes assertion error in Debug builds. This is fixed in 7.4.0 (https://github.com/odygrd/quill/issues/605) default_backend_options.log_timestamp_ordering_grace_period = std::chrono::milliseconds(1); return default_backend_options; From ed2ddf64b15ea7b7a72b409ee54385cb661eece5 Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Mon, 14 Oct 2024 10:27:50 +0200 Subject: [PATCH 33/34] Moved logger configuration to static class method to better align with the example update --- examples/logging_example/main.cc | 109 +++++++++++++++++++++---------- 1 file changed, 74 insertions(+), 35 deletions(-) diff --git a/examples/logging_example/main.cc b/examples/logging_example/main.cc index a9b0dfe..62807ea 100644 --- a/examples/logging_example/main.cc +++ b/examples/logging_example/main.cc @@ -20,7 +20,6 @@ using cactus_rt::CyclicThread; class ExampleRTThread : public CyclicThread { int64_t loop_counter_ = 0; - public: static cactus_rt::CyclicThreadConfig MakeConfig() { cactus_rt::CyclicThreadConfig thread_config; thread_config.period_ns = 1'000'000; @@ -29,6 +28,7 @@ class ExampleRTThread : public CyclicThread { return thread_config; } + public: ExampleRTThread() : CyclicThread("ExampleRTThread", MakeConfig()) {} int64_t GetLoopCounter() const { @@ -47,6 +47,78 @@ class ExampleRTThread : public CyclicThread { } }; +/** + * Here we create a second real-time thread that runs at another frequency, to + * show that we can have multiple threads emitting logging data simultaneously. + */ +class SecondRTThread : public CyclicThread { + int64_t loop_counter_ = 0; + + static cactus_rt::CyclicThreadConfig MakeConfig() { + cactus_rt::CyclicThreadConfig thread_config; + thread_config.period_ns = 1'200'000; + thread_config.cpu_affinity = std::vector{2}; + thread_config.SetFifoScheduler(80); + + thread_config.logger_config.logger_name = MakeLogger(); + + return thread_config; + } + + /** + * Create a logger with multiple sinks and return the logger name. + */ + static std::string MakeLogger() { + // Use the default console logger too + // Make sure to use cactus_rt's logging Frontend instead of Quill's default + auto console_sink = cactus_rt::logging::Frontend::create_or_get_sink("OtherConsoleSink", true); + + // Create a new file sink and configuration + quill::FileSinkConfig file_sink_config; + file_sink_config.set_open_mode('w'); + file_sink_config.set_filename_append_option(quill::FilenameAppendOption::StartDateTime); + // !! Make sure to use `cactus_rt::logging::Frontend instead of quill::Frontend !! + auto file_sink = cactus_rt::logging::Frontend::create_or_get_sink( + "file_logging_example.log", + file_sink_config, + quill::FileEventNotifier{} + ); + + // Add both sinks to a vector + const std::vector> sinks = {console_sink, file_sink}; + + // Create a custom formatter pattern + auto pattern_format = quill::PatternFormatterOptions( + "[%(time)][%(log_level_short_code)][%(logger)][%(process_id)][%(file_name):%(line_number)] - WOW custom message format - %(message)", + "%H:%M:%S.%Qns" + ); + + // Use the new sinks and pattern to create a custom logger for the other thread + auto* custom_thread_logger = cactus_rt::logging::Frontend::create_or_get_logger("CustomThreadLogger", sinks, pattern_format); + + // Return the custom logger's name to pass into the configuration + return custom_thread_logger->get_logger_name(); + } + + public: + SecondRTThread() : CyclicThread("SecondRTThread", MakeConfig()) {} + + int64_t GetLoopCounter() const { + return loop_counter_; + } + + protected: + LoopControl Loop(int64_t elapsed_ns) noexcept final { + loop_counter_++; + if (loop_counter_ % 1000 == 0) { + LOG_INFO(Logger(), "Loop {} ({})", loop_counter_, std::chrono::nanoseconds(elapsed_ns)); + } + + LOG_INFO_LIMIT(std::chrono::milliseconds{1500}, Logger(), "Log limit: Loop {}", loop_counter_); + return LoopControl::Continue; + } +}; + int main() { // Create a cactus_rt app configuration cactus_rt::AppConfig app_config; @@ -65,41 +137,8 @@ int main() { App app("LoggingExampleApp", app_config); auto thread = app.CreateThread(); + auto other_thread = app.CreateThread(); - // Create another thread with a custom logger, which has multiple sinks - cactus_rt::CyclicThreadConfig other_thread_config = ExampleRTThread::MakeConfig(); // Copy thread config - - // Create another console sink - // Make sure to use cactus_rt's logging Frontend instead of Quill's default - auto console_sink = cactus_rt::logging::Frontend::create_or_get_sink("OtherConsoleSink", true); - - // Create a file sink too - quill::FileSinkConfig file_sink_config; - file_sink_config.set_open_mode('w'); - file_sink_config.set_filename_append_option(quill::FilenameAppendOption::StartDateTime); - auto file_sink = cactus_rt::logging::Frontend::create_or_get_sink( - "file_logging_example.log", - file_sink_config, - quill::FileEventNotifier{} - ); - - // Add both sinks to a vector - const std::vector> sinks = {console_sink, file_sink}; - - // Create a custom formatter pattern - auto pattern_format = quill::PatternFormatterOptions( - "[%(time)][%(log_level_short_code)][%(logger)][%(process_id)][%(file_name):%(line_number)] - WOW custom message format - %(message)", - "%H:%M:%S.%Qns" - ); - - // Use the new sinks and pattern to create a custom logger for the other thread - auto* custom_thread_logger = cactus_rt::logging::Frontend::create_or_get_logger("CustomThreadLogger", sinks, pattern_format); - other_thread_config.logger_config.logger_name = custom_thread_logger->get_logger_name(); - - // Add a second instance of the example thread class, which uses the configuration with the new logger - auto other_thread = app.CreateThread("OtherExampleRTThread", other_thread_config); - - // Start the app constexpr unsigned int time = 5; std::cout << "Testing RT loop for " << time << " seconds.\n"; From 85d10424e4abf1b02dea7bfbccc706a246817db0 Mon Sep 17 00:00:00 2001 From: Jelle Hierck Date: Tue, 15 Oct 2024 15:59:11 +0200 Subject: [PATCH 34/34] Removed the quill backend thread stop in the destructor of App, since it was causing programs to hang if they flush their quill loggers in destructors --- src/cactus_rt/app.cc | 2 -- 1 file changed, 2 deletions(-) diff --git a/src/cactus_rt/app.cc b/src/cactus_rt/app.cc index 5f06272..b3956f9 100644 --- a/src/cactus_rt/app.cc +++ b/src/cactus_rt/app.cc @@ -26,8 +26,6 @@ App::App(std::string name, AppConfig config) App::~App() { StopTraceSession(); - // Quill flush is handled per logger - quill::Backend::stop(); // Stop the quill backend thread } void App::Start(int64_t start_monotonic_time_ns) {