feat: Use spdlog logger

Author: mathbunnyru

CMakeLists.txt

@@ -58,6 +58,7 @@ include(deps/Threads)
 include(deps/libfmt)
 include(deps/cassandra)
 include(deps/libbacktrace)
+include(deps/spdlog)
 
 add_subdirectory(src)
 add_subdirectory(tests)

benchmarks/CMakeLists.txt

@@ -14,5 +14,5 @@ target_sources(
 include(deps/gbench)
 
 target_include_directories(clio_benchmark PRIVATE .)
-target_link_libraries(clio_benchmark PUBLIC clio_util benchmark::benchmark_main)
+target_link_libraries(clio_benchmark PUBLIC clio_util benchmark::benchmark_main spdlog::spdlog)
 set_target_properties(clio_benchmark PROPERTIES RUNTIME_OUTPUT_DIRECTORY ${CMAKE_BINARY_DIR})

benchmarks/util/log/LoggerBenchmark.cpp

@@ -22,26 +22,35 @@
 #include "util/prometheus/Prometheus.hpp"
 
 #include <benchmark/benchmark.h>
-#include <boost/log/core/core.hpp>
-#include <boost/log/utility/setup/common_attributes.hpp>
+#include <spdlog/async.h>
+#include <spdlog/async_logger.h>
+#include <spdlog/spdlog.h>
 
 #include <barrier>
 #include <chrono>
 #include <cstddef>
 #include <filesystem>
+#include <memory>
 #include <string>
 #include <thread>
+#include <utility>
 #include <vector>
 
 using namespace util;
 
+static constexpr auto kLOG_FORMAT = "%Y-%m-%d %H:%M:%S.%f %^(%@) [%t] %n:%L%$ %v";
+
 struct BenchmarkLoggingInitializer {
-    static constexpr auto kLOG_FORMAT = "%TimeStamp% (%SourceLocation%) [%ThreadID%] %Channel%:%Severity% %Message%";
+    static std::shared_ptr<spdlog::sinks::sink>
+    createFileSink(LogService::FileLoggingParams const& params)
+    {
+        return LogService::createFileSink(params);
+    }
 
-    static void
-    initFileLogging(LogService::FileLoggingParams const& params)
+    static Logger
+    getLogger(std::shared_ptr<spdlog::logger> logger)
     {
-        LogService::initFileLogging(params, kLOG_FORMAT);
+        return Logger(std::move(logger));
     }
 };
 
@@ -62,7 +71,7 @@ uniqueLogDir()
 static void
 benchmarkConcurrentFileLogging(benchmark::State& state)
 {
-    boost::log::add_common_attributes();
+    spdlog::drop_all();
 
     auto const numThreads = static_cast<size_t>(state.range(0));
     auto const messagesPerThread = static_cast<size_t>(state.range(1));
@@ -74,12 +83,12 @@ benchmarkConcurrentFileLogging(benchmark::State& state)
         state.PauseTiming();
 
         std::filesystem::create_directories(logDir);
+        spdlog::init_thread_pool(8192, 1);
 
-        BenchmarkLoggingInitializer::initFileLogging({
+        auto fileSink = BenchmarkLoggingInitializer::createFileSink({
             .logDir = logDir,
             .rotationSizeMB = 5,
-            .dirMaxSizeMB = 125,
-            .rotationHours = 24,
+            .dirMaxFiles = 25,
         });
 
         std::vector<std::thread> threads;
@@ -92,10 +101,16 @@ benchmarkConcurrentFileLogging(benchmark::State& state)
         });
 
         for (size_t threadNum = 0; threadNum < numThreads; ++threadNum) {
-            threads.emplace_back([threadNum, messagesPerThread, &barrier]() {
-                barrier.arrive_and_wait();
+            threads.emplace_back([threadNum, messagesPerThread, fileSink, &barrier]() {
+                std::string const channel = "Thread_" + std::to_string(threadNum);
+                auto logger = std::make_shared<spdlog::async_logger>(
+                    channel, fileSink, spdlog::thread_pool(), spdlog::async_overflow_policy::block
+                );
+                logger->set_pattern(kLOG_FORMAT);
+                spdlog::register_logger(logger);
+                Logger const threadLogger = BenchmarkLoggingInitializer::getLogger(std::move(logger));
 
-                Logger const threadLogger("Thread_" + std::to_string(threadNum));
+                barrier.arrive_and_wait();
 
                 for (size_t messageNum = 0; messageNum < messagesPerThread; ++messageNum) {
                     LOG(threadLogger.info()) << "Test log message #" << messageNum;
@@ -106,10 +121,9 @@ benchmarkConcurrentFileLogging(benchmark::State& state)
         for (auto& thread : threads) {
             thread.join();
         }
-        boost::log::core::get()->flush();
+        spdlog::shutdown();
 
         auto const end = std::chrono::high_resolution_clock::now();
-
         state.SetIterationTime(std::chrono::duration_cast<std::chrono::duration<double>>(end - start).count());
 
         std::filesystem::remove_all(logDir);
@@ -129,7 +143,7 @@ BENCHMARK(benchmarkConcurrentFileLogging)
         // Number of threads
         {1, 2, 4, 8},
         // Messages per thread
-        {10'000, 100'000, 500'000},
+        {10'000, 100'000, 500'000, 1'000'000, 10'000'000},
     })
     ->UseManualTime()
     ->Unit(benchmark::kMillisecond);

cmake/deps/spdlog.cmake

@@ -0,0 +1,5 @@
+find_package(spdlog REQUIRED)
+
+if (NOT TARGET spdlog::spdlog)
+  message(FATAL_ERROR "spdlog::spdlog target not found")
+endif ()

conan.lock

@@ -5,6 +5,7 @@
         "xxhash/0.8.2#7856c968c985b2981b707ee8f2413b2b%1754325010.01",
         "xrpl/2.5.0@clio/boost-odr#f68e48da1490c0a583052e4f068ada55%1754325014.392",
         "sqlite3/3.47.0#7a0904fd061f5f8a2366c294f9387830%1754325009.708",
+        "spdlog/1.15.3#3ca0e9e6b83af4d0151e26541d140c86%1748617970.519",
         "soci/4.0.3#a9f8d773cd33e356b5879a4b0564f287%1754412158.144",
         "re2/20230301#dfd6e2bf050eb90ddd8729cfb4c844a4%1754412148.014",
         "rapidjson/cci.20220822#1b9d8c2256876a154172dc5cfbe447c6%1754325007.656",
@@ -54,4 +55,4 @@
         ]
     },
     "config_requires": []
-}
+}

conanfile.py

@@ -33,7 +33,8 @@ class ClioConan(ConanFile):
         'openssl/1.1.1v',
         'xrpl/2.5.0@clio/boost-odr',
         'zlib/1.3.1',
-        'libbacktrace/cci.20210118'
+        'libbacktrace/cci.20210118',
+        'spdlog/1.15.3',
     ]
 
     default_options = {

docs/config-description.md

@@ -439,13 +439,21 @@ This document provides a list of all available Clio configuration properties in
 - **Constraints**: The value must be one of the following: `trace`, `debug`, `info`, `warning`, `error`, `fatal`, `count`.
 - **Description**: The general logging level of Clio. This level is applied to all log channels that do not have an explicitly defined logging level.
 
-### log_format
+### spdlog_format
 
 - **Required**: True
 - **Type**: string
-- **Default value**: `%TimeStamp% (%SourceLocation%) [%ThreadID%] %Channel%:%Severity% %Message%`
+- **Default value**: `%Y-%m-%d %H:%M:%S.%f %^(%@) [%t] %n:%L%$ %v`
 - **Constraints**: None
-- **Description**: The format string for log messages. The format is described here: <https://www.boost.org/doc/libs/1_83_0/libs/log/doc/html/log/tutorial/formatters.html>.
+- **Description**: The format string for log messages using spdlog format patterns. Documentation can be found at: <https://github.com/gabime/spdlog/wiki/Custom-formatting>.
+
+### spdlog_async
+
+- **Required**: True
+- **Type**: boolean
+- **Default value**: `True`
+- **Constraints**: None
+- **Description**: Whether spdlog is asynchronous or not.
 
 ### log_to_console
 
@@ -471,21 +479,13 @@ This document provides a list of all available Clio configuration properties in
 - **Constraints**: The minimum value is `1`. The maximum value is `4294967295`.
 - **Description**: The log rotation size in megabytes. When the log file reaches this particular size, a new log file starts.
 
-### log_directory_max_size
-
-- **Required**: True
-- **Type**: int
-- **Default value**: `51200`
-- **Constraints**: The minimum value is `1`. The maximum value is `4294967295`.
-- **Description**: The maximum size of the log directory in megabytes.
-
-### log_rotation_hour_interval
+### log_directory_max_files
 
 - **Required**: True
 - **Type**: int
-- **Default value**: `12`
+- **Default value**: `25`
 - **Constraints**: The minimum value is `1`. The maximum value is `4294967295`.
-- **Description**: Represents the interval (in hours) for log rotation. If the current log file reaches this value in logging, a new log file starts.
+- **Description**: The maximum number of log files in the directory.
 
 ### log_tag_style
 

docs/examples/config/example-config.json

@@ -122,14 +122,15 @@
     "compress_reply": true
   },
   "log_level": "info",
-  // Log format (this is the default format)
-  "log_format": "%TimeStamp% (%SourceLocation%) [%ThreadID%] %Channel%:%Severity% %Message%",
+  // Log format using spdlog format patterns (this is the default format)
+  "spdlog_format": "%Y-%m-%d %H:%M:%S.%f %^(%@) [%t] %n:%L%$ %v",
+  // Whether spdlog is asynchronous or not.
+  "spdlog_async": true,
   "log_to_console": true,
   // Clio logs to file in the specified directory only if "log_directory" is set
   // "log_directory": "./clio_log",
   "log_rotation_size": 2048,
-  "log_directory_max_size": 51200,
-  "log_rotation_hour_interval": 12,
+  "log_directory_max_files": 25,
   "log_tag_style": "uint",
   "extractor_threads": 8,
   "read_only": false,

docs/logging.md

@@ -6,18 +6,26 @@ Clio provides several logging options, which all are configurable via the config
 
 The minimum level of severity at which the log message will be outputted by default. Severity options are `trace`, `debug`, `info`, `warning`, `error`, `fatal`. Defaults to `info`.
 
-## `log_format`
+## `spdlog_format`
 
-The format of log lines produced by Clio. Defaults to `"%TimeStamp% (%SourceLocation%) [%ThreadID%] %Channel%:%Severity% %Message%"`.
+The format of log lines produced by Clio using spdlog format patterns. Defaults to `"%Y-%m-%d %H:%M:%S.%f %^(%@) [%t] %n:%L%$ %v"`.
 
 Each of the variables expands like so:
 
-- `TimeStamp`: The full date and time of the log entry
-- `SourceLocation`: A partial path to the c++ file and the line number in said file (`source/file/path:linenumber`)
-- `ThreadID`: The ID of the thread the log entry is written from
-- `Channel`: The channel that this log entry was sent to
-- `Severity`: The severity (aka log level) the entry was sent at
-- `Message`: The actual log message
+- `%^`: Start color range
+- `%Y-%m-%d %H:%M:%S.%f`: The full date and time of the log entry with microsecond precision
+- `%@`: A partial path to the c++ file and the line number in said file (`source/file/path:linenumber`)
+- `%t`: The ID of the thread the log entry is written from
+- `%n`: The logger name (channel) that this log entry was sent to
+- `%l`: The severity (aka log level) the entry was sent at
+- `%$`: End color range
+- `%v`: The actual log message
+
+For more information about spdlog format patterns, see: <https://github.com/gabime/spdlog/wiki/Custom-formatting>
+
+## `spdlog_async`
+
+Whether spdlog is asynchronous or not.
 
 ## `log_channels`
 
@@ -56,16 +64,9 @@ If the option is not specified, the logs are not written to a file.
 
 The max size of the log file in **megabytes** before it will rotate into a smaller file. Defaults to 2GB.
 
-## `log_directory_max_size`
-
-The max size of the log directory in **megabytes** before old log files will be deleted to free up space. Defaults to 50GB.
+## `log_directory_max_files`
 
-## `log_rotation_hour_interval`
-
-The time interval in **hours** after the last log rotation to automatically rotate the current log file. Defaults to 12 hours.
-
-> [!NOTE]
-> Log rotation based on time occurs in conjunction with size-based log rotation. For example, if a size-based log rotation occurs, the timer for the time-based rotation will reset.
+The max number of log files in the directory before old log files will be deleted to free up space. Defaults to 25.
 
 ## `log_tag_style`
 

src/app/Stopper.hpp

@@ -108,6 +108,8 @@ class Stopper {
 
             ioc.stop();
             LOG(util::LogService::info()) << "io_context stopped";
+
+            util::LogService::shutdown();
         };
     }
 };