Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions CMakeLists.txt
Original file line number Diff line number Diff line change
Expand Up @@ -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)
Expand Down
2 changes: 1 addition & 1 deletion benchmarks/CMakeLists.txt
Original file line number Diff line number Diff line change
Expand Up @@ -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})
49 changes: 32 additions & 17 deletions benchmarks/util/log/LoggerBenchmark.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -22,26 +22,36 @@
#include "util/prometheus/Prometheus.hpp"

#include <benchmark/benchmark.h>
#include <boost/log/core/core.hpp>
#include <boost/log/utility/setup/common_attributes.hpp>
#include <fmt/format.h>
#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 %^%3!l:%n%$ - %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));
}
};

Expand All @@ -53,7 +63,7 @@ uniqueLogDir()
auto const epochTime = std::chrono::high_resolution_clock::now().time_since_epoch();
auto const tmpDir = std::filesystem::temp_directory_path();
std::string const dirName =
"logs_" + std::to_string(std::chrono::duration_cast<std::chrono::microseconds>(epochTime).count());
fmt::format("logs_{}", std::chrono::duration_cast<std::chrono::microseconds>(epochTime).count());
return tmpDir / "clio_benchmark" / dirName;
}

Expand All @@ -62,7 +72,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));
Expand All @@ -74,12 +84,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;
Expand All @@ -92,10 +102,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 = fmt::format("Thread_{}", 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;
Expand All @@ -106,10 +122,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);
Expand All @@ -129,7 +144,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);
5 changes: 5 additions & 0 deletions cmake/deps/spdlog.cmake
Original file line number Diff line number Diff line change
@@ -0,0 +1,5 @@
find_package(spdlog REQUIRED)

if (NOT TARGET spdlog::spdlog)
message(FATAL_ERROR "spdlog::spdlog target not found")
endif ()
1 change: 1 addition & 0 deletions conan.lock
Original file line number Diff line number Diff line change
Expand Up @@ -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%1754401846.61",
"soci/4.0.3#a9f8d773cd33e356b5879a4b0564f287%1754412158.144",
"re2/20230301#dfd6e2bf050eb90ddd8729cfb4c844a4%1754412148.014",
"rapidjson/cci.20220822#1b9d8c2256876a154172dc5cfbe447c6%1754325007.656",
Expand Down
3 changes: 2 additions & 1 deletion conanfile.py
Original file line number Diff line number Diff line change
Expand Up @@ -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 = {
Expand Down
28 changes: 14 additions & 14 deletions docs/config-description.md
Original file line number Diff line number Diff line change
Expand Up @@ -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`.
- **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 %^%3!l:%n%$ - %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

Expand All @@ -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

Expand Down
9 changes: 5 additions & 4 deletions docs/examples/config/example-config.json
Original file line number Diff line number Diff line change
Expand Up @@ -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 %^%3!l:%n%$ - %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,
Expand Down
38 changes: 21 additions & 17 deletions docs/logging.md
Original file line number Diff line number Diff line change
Expand Up @@ -6,18 +6,29 @@ 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 %^%3!l:%n%$ - %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
- `%Y-%m-%d %H:%M:%S.%f`: The full date and time of the log entry with microsecond precision
- `%^`: Start color range
- `%3!l`: The severity (aka log level) the entry was sent at stripped to 3 characters
- `%n`: The logger name (channel) that this log entry was sent to
- `%$`: End color range
- `%v`: The actual log message

Some additional variables that might be useful:

- `%@`: A partial path to the C++ file and the line number in the said file (`src/file/path:linenumber`)
- `%t`: The ID of the thread the log entry is written from

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`

Expand Down Expand Up @@ -56,16 +67,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`
## `log_directory_max_files`

The max size of the log directory in **megabytes** before old log files will be deleted to free up space. Defaults to 50GB.

## `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`

Expand Down
2 changes: 2 additions & 0 deletions src/app/Stopper.hpp
Original file line number Diff line number Diff line change
Expand Up @@ -108,6 +108,8 @@ class Stopper {

ioc.stop();
LOG(util::LogService::info()) << "io_context stopped";

util::LogService::shutdown();
};
}
};
Expand Down
2 changes: 2 additions & 0 deletions src/main/Main.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,7 @@
#include "app/VerifyConfig.hpp"
#include "migration/MigrationApplication.hpp"
#include "rpc/common/impl/HandlerProvider.hpp"
#include "util/ScopeGuard.hpp"
#include "util/TerminationHandler.hpp"
#include "util/config/ConfigDefinition.hpp"
#include "util/log/Logger.hpp"
Expand All @@ -37,6 +38,7 @@ int
main(int argc, char const* argv[])
try {
util::setTerminationHandler();
util::ScopeGuard loggerShutdownGuard{[]() { util::LogService::shutdown(); }};

auto const action = app::CliArgs::parse(argc, argv);
return action.apply(
Expand Down
3 changes: 1 addition & 2 deletions src/util/CMakeLists.txt
Original file line number Diff line number Diff line change
Expand Up @@ -50,15 +50,14 @@ target_link_libraries(
clio_util
PUBLIC Boost::headers
Boost::iostreams
Boost::log
Boost::log_setup
fmt::fmt
openssl::openssl
xrpl::libxrpl
Threads::Threads
clio_options
clio_rpc_center
clio_build_version
PRIVATE spdlog::spdlog
)

# FIXME: needed on gcc-12, clang-16 and AppleClang for now (known boost 1.82 issue for some compilers)
Expand Down
57 changes: 57 additions & 0 deletions src/util/ScopeGuard.hpp
Original file line number Diff line number Diff line change
@@ -0,0 +1,57 @@
//------------------------------------------------------------------------------
/*
This file is part of clio: https://github.com/XRPLF/clio
Copyright (c) 2025, the clio developers.

Permission to use, copy, modify, and distribute this software for any
purpose with or without fee is hereby granted, provided that the above
copyright notice and this permission notice appear in all copies.

THE SOFTWARE IS PROVIDED "AS IS" AND THE AUTHOR DISCLAIMS ALL WARRANTIES
WITH REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF
MERCHANTABILITY AND FITNESS. IN NO EVENT SHALL THE AUTHOR BE LIABLE FOR
ANY SPECIAL, DIRECT, INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES
WHATSOEVER RESULTING FROM LOSS OF USE, DATA OR PROFITS, WHETHER IN AN
ACTION OF CONTRACT, NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT OF
OR IN CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE.
*/
//==============================================================================

#pragma once

#include <utility>

namespace util {

/**
* @brief Run a function when the scope is exited
*/
template <typename Func>
class ScopeGuard {
public:
ScopeGuard(ScopeGuard const&) = delete;
ScopeGuard(ScopeGuard&&) = delete;
ScopeGuard&
operator=(ScopeGuard const&) = delete;
ScopeGuard&
operator=(ScopeGuard&&) = delete;

/**
* @brief Create ScopeGuard object.
*
* @param func The function to run when the scope is exited.
*/
ScopeGuard(Func func) : func_(std::move(func))
{
}

~ScopeGuard()
{
func_();
}

private:
Func func_;
};

} // namespace util
3 changes: 3 additions & 0 deletions src/util/TerminationHandler.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -44,6 +44,9 @@ terminationHandler()
#else
LOG(LogService::fatal()) << "Exit on terminate. Stacktrace disabled.";
#endif // CLIO_WITHOUT_STACKTRACE

// We're calling std::abort later, so spdlog won't be shutdown automatically
util::LogService::shutdown();
std::abort();
}

Expand Down
Loading
Loading