ARCHIVE/clio
1
0
Fork 0
mirror of https://github.com/XRPLF/clio.git synced 2025-11-04 11:55:51 +00:00
Code Issues Packages Projects Releases Wiki Activity

feat: Use spdlog logger (#2372)

Browse Source
This commit is contained in:
Ayaz Salikhov
2025-08-11 18:04:04 +01:00
committed by GitHub
parent 707427c63a
commit 9420c506ca
29 changed files with 745 additions and 548 deletions
Download Patch File Download Diff File Expand all files Collapse all files

1
CMakeLists.txt
View File

@@ -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)

2
benchmarks/CMakeLists.txt
View File

@@ -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})

51
benchmarks/util/log/LoggerBenchmark.cpp
View File

@@ -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;
struct BenchmarkLoggingInitializer {
static constexpr auto kLOG_FORMAT = "%TimeStamp% (%SourceLocation%) [%ThreadID%] %Channel%:%Severity% %Message%";
static constexpr auto kLOG_FORMAT = "%Y-%m-%d %H:%M:%S.%f %^%3!l:%n%$ - %v";
static void
initFileLogging(LogService::FileLoggingParams const& params)
struct BenchmarkLoggingInitializer {
static std::shared_ptr<spdlog::sinks::sink>
createFileSink(LogService::FileLoggingParams const& params)
{
LogService::initFileLogging(params, kLOG_FORMAT);
return LogService::createFileSink(params);
}
static Logger
getLogger(std::shared_ptr<spdlog::logger> logger)
{
return Logger(std::move(logger));
}
};
@@ -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;
}
@@ -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));
@@ -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;
@@ -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;
@@ -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);
@@ -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
cmake/deps/spdlog.cmake Normal file
View File

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

1
conan.lock
View File

@@ -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",

3
conanfile.py
View File

@@ -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 = {

28
docs/config-description.md
View File

@@ -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
@@ -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
### log_directory_max_files
- **Required**: True
- **Type**: int
- **Default value**: `51200`
- **Default value**: `25`
- **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
- **Required**: True
- **Type**: int
- **Default value**: `12`
- **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

9
docs/examples/config/example-config.json
View File

@@ -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,

38
docs/logging.md
View File

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

2
src/app/Stopper.hpp
View File

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

2
src/main/Main.cpp
View File

@@ -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"
@@ -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(

3
src/util/CMakeLists.txt
View File

@@ -50,8 +50,6 @@ target_link_libraries(
clio_util
PUBLIC Boost::headers
Boost::iostreams
Boost::log
Boost::log_setup
fmt::fmt
openssl::openssl
xrpl::libxrpl
@@ -59,6 +57,7 @@ target_link_libraries(
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)

57
src/util/ScopeGuard.hpp Normal file
View File

@@ -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
src/util/TerminationHandler.cpp
View File

@@ -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();
}

13
src/util/config/ConfigDefinition.cpp
View File

@@ -358,10 +358,9 @@ getClioConfig()
{"log_level", ConfigValue{ConfigType::String}.defaultValue("info").withConstraint(gValidateLogLevelName)},
{"log_format",
ConfigValue{ConfigType::String}.defaultValue(
R"(%TimeStamp% (%SourceLocation%) [%ThreadID%] %Channel%:%Severity% %Message%)"
)},
{"spdlog_format", ConfigValue{ConfigType::String}.defaultValue(R"(%Y-%m-%d %H:%M:%S.%f %^%3!l:%n%$ - %v)")},
{"spdlog_async", ConfigValue{ConfigType::Boolean}.defaultValue(true)},
{"log_to_console", ConfigValue{ConfigType::Boolean}.defaultValue(false)},
@@ -369,11 +368,7 @@ getClioConfig()
{"log_rotation_size", ConfigValue{ConfigType::Integer}.defaultValue(2048).withConstraint(gValidateUint32)},
{"log_directory_max_size",
ConfigValue{ConfigType::Integer}.defaultValue(50 * 1024).withConstraint(gValidateUint32)},
{"log_rotation_hour_interval",
ConfigValue{ConfigType::Integer}.defaultValue(12).withConstraint(gValidateUint32)},
{"log_directory_max_files", ConfigValue{ConfigType::Integer}.defaultValue(25).withConstraint(gValidateUint32)},
{"log_tag_style", ConfigValue{ConfigType::String}.defaultValue("none").withConstraint(gValidateLogTag)},

12
src/util/config/ConfigDescription.hpp
View File

@@ -263,18 +263,16 @@ private:
KV{.key = "log_level",
.value = "The general logging level of Clio. This level is applied to all log channels that do not have an "
"explicitly defined logging level."},
KV{.key = "log_format",
.value = "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>."},
KV{.key = "spdlog_format",
.value = "The format string for log messages using spdlog format patterns. Documentation can be found at: "
"<https://github.com/gabime/spdlog/wiki/Custom-formatting>."},
KV{.key = "spdlog_async", .value = "Whether spdlog is asynchronous or not."},
KV{.key = "log_to_console", .value = "Enables or disables logging to the console."},
KV{.key = "log_directory", .value = "The directory path for the log files."},
KV{.key = "log_rotation_size",
.value = "The log rotation size in megabytes. When the log file reaches this particular size, a new log "
"file starts."},
KV{.key = "log_directory_max_size", .value = "The maximum size of the log directory in megabytes."},
KV{.key = "log_rotation_hour_interval",
.value = "Represents the interval (in hours) for log rotation. If the current log file reaches this value "
"in logging, a new log file starts."},
KV{.key = "log_directory_max_files", .value = "The maximum number of log files in the directory."},
KV{.key = "log_tag_style",
.value =
"Log tags are unique identifiers for log messages. `uint`/`int` starts logging from 0 and increments, "

309
src/util/log/Logger.cpp
View File

@@ -25,83 +25,62 @@
#include "util/config/ArrayView.hpp"
#include "util/config/ConfigDefinition.hpp"
#include "util/config/ObjectView.hpp"
#include "util/prometheus/Counter.hpp"
#include "util/prometheus/Label.hpp"
#include "util/prometheus/Prometheus.hpp"
#include <boost/algorithm/string/predicate.hpp>
#include <boost/date_time/posix_time/posix_time_duration.hpp>
#include <boost/log/attributes/attribute_value_set.hpp>
#include <boost/log/core/core.hpp>
#include <boost/log/expressions/filter.hpp>
#include <boost/log/keywords/auto_flush.hpp>
#include <boost/log/keywords/file_name.hpp>
#include <boost/log/keywords/filter.hpp>
#include <boost/log/keywords/format.hpp>
#include <boost/log/keywords/max_size.hpp>
#include <boost/log/keywords/open_mode.hpp>
#include <boost/log/keywords/rotation_size.hpp>
#include <boost/log/keywords/target.hpp>
#include <boost/log/keywords/target_file_name.hpp>
#include <boost/log/keywords/time_based_rotation.hpp>
#include <boost/log/sinks/text_file_backend.hpp>
#include <boost/log/utility/exception_handler.hpp>
#include <boost/log/utility/setup/common_attributes.hpp>
#include <boost/log/utility/setup/console.hpp>
#include <boost/log/utility/setup/file.hpp>
#include <boost/log/utility/setup/formatter_parser.hpp>
#include <fmt/format.h>
#include <spdlog/async.h>
#include <spdlog/async_logger.h>
#include <spdlog/common.h>
#include <spdlog/logger.h>
#include <spdlog/sinks/basic_file_sink.h>
#include <spdlog/sinks/rotating_file_sink.h>
#include <spdlog/sinks/stdout_color_sinks.h>
#include <spdlog/spdlog.h>
#include <algorithm>
#include <array>
#include <cstddef>
#include <cstdint>
#include <exception>
#include <filesystem>
#include <functional>
#include <ios>
#include <iostream>
#include <memory>
#include <optional>
#include <ostream>
#include <string>
#include <string_view>
#include <system_error>
#include <unordered_map>
#include <utility>
#include <vector>
namespace util {
LogService::Data LogService::data{};
namespace {
class LoggerExceptionHandler {
std::reference_wrapper<util::prometheus::CounterInt> exceptionCounter_ =
PrometheusService::counterInt("logger_exceptions_total_number", util::prometheus::Labels{});
public:
using result_type = void;
LoggerExceptionHandler()
{
ASSERT(PrometheusService::isInitialised(), "Prometheus should be initialised before Logger");
}
void
operator()(std::exception const& e) const
{
std::cerr << fmt::format("Exception in logger: {}\n", e.what());
++exceptionCounter_.get();
}
};
} // namespace
Logger LogService::generalLog = Logger{"General"};
boost::log::filter LogService::filter{};
std::ostream&
operator<<(std::ostream& stream, Severity sev)
spdlog::level::level_enum
toSpdlogLevel(Severity sev)
{
static constexpr std::array<char const*, 6> kLABELS = {
switch (sev) {
case Severity::TRC:
return spdlog::level::trace;
case Severity::DBG:
return spdlog::level::debug;
case Severity::NFO:
return spdlog::level::info;
case Severity::WRN:
return spdlog::level::warn;
case Severity::ERR:
return spdlog::level::err;
case Severity::FTL:
return spdlog::level::critical;
}
return spdlog::level::info;
}
std::string_view
toString(Severity sev)
{
static constexpr std::array<std::string_view, 6> kLABELS = {
"TRC",
"DBG",
"NFO",
@@ -110,9 +89,11 @@ operator<<(std::ostream& stream, Severity sev)
"FTL",
};
return stream << kLABELS.at(static_cast<int>(sev));
return kLABELS.at(static_cast<int>(sev));
}
} // namespace
/**
* @brief converts the loglevel to string to a corresponding Severity enum value.
*
@@ -144,60 +125,47 @@ getSeverityLevel(std::string_view logLevel)
* @brief Initializes console logging.
*
* @param logToConsole A boolean indicating whether to log to console.
* @param format The log format string.
* @return Vector of sinks for console logging.
*/
static void
initConsoleLogging(bool logToConsole, std::string const& format)
static std::vector<spdlog::sink_ptr>
createConsoleSinks(bool logToConsole)
{
namespace keywords = boost::log::keywords;
std::vector<spdlog::sink_ptr> sinks;
if (logToConsole) {
boost::log::add_console_log(
std::cout, keywords::format = format, keywords::filter = LogSeverity < Severity::FTL
);
auto consoleSink = std::make_shared<spdlog::sinks::stdout_color_sink_mt>();
consoleSink->set_level(spdlog::level::trace);
sinks.push_back(std::move(consoleSink));
}
// Always print fatal logs to cerr
boost::log::add_console_log(std::cerr, keywords::format = format, keywords::filter = LogSeverity >= Severity::FTL);
// Always add stderr sink for fatal logs
auto stderrSink = std::make_shared<spdlog::sinks::stderr_color_sink_mt>();
stderrSink->set_level(spdlog::level::critical);
sinks.push_back(std::move(stderrSink));
return sinks;
}
/**
* @brief Initializes file logging.
*
* @param config The configuration object containing log settings.
* @param format The log format string.
* @param dirPath The directory path where log files will be stored.
* @return File sink for logging.
*/
void
LogService::initFileLogging(FileLoggingParams const& params, std::string const& format)
spdlog::sink_ptr
LogService::createFileSink(FileLoggingParams const& params)
{
namespace keywords = boost::log::keywords;
namespace sinks = boost::log::sinks;
// the below are taken from user in MB, but boost::log::add_file_log needs it to be in bytes
std::filesystem::path const dirPath(params.logDir);
// the below are taken from user in MB, but spdlog needs it to be in bytes
auto const rotationSize = mbToBytes(params.rotationSizeMB);
auto const dirSize = mbToBytes(params.dirMaxSizeMB);
auto const dirPath = std::filesystem::path{params.logDir};
auto fileSink = std::make_shared<spdlog::sinks::rotating_file_sink_mt>(
(dirPath / "clio.log").string(), rotationSize, params.dirMaxFiles
);
fileSink->set_level(spdlog::level::trace);
auto fileSink = boost::log::add_file_log(
keywords::file_name = dirPath / "clio.log",
keywords::target_file_name = dirPath / "clio_%Y-%m-%d_%H-%M-%S.log",
keywords::auto_flush = true,
keywords::format = format,
keywords::open_mode = std::ios_base::app,
keywords::rotation_size = rotationSize,
keywords::time_based_rotation =
sinks::file::rotation_at_time_interval(boost::posix_time::hours(params.rotationHours))
);
fileSink->locked_backend()->set_file_collector(
sinks::file::make_collector(keywords::target = dirPath, keywords::max_size = dirSize)
);
fileSink->locked_backend()->scan_for_files();
boost::log::core::get()->set_exception_handler(
boost::log::make_exception_handler<std::exception>(LoggerExceptionHandler())
);
return fileSink;
}
/**
@@ -229,41 +197,45 @@ getMinSeverity(config::ClioConfigDefinition const& config, Severity defaultSever
return minSeverity;
}
/**
* @brief Creates a log filter based on the minimum severity levels for each channel.
*
* @param defaultSeverity The default severity level to use if not overridden.
* @param minSeverity A map of channel names to their minimum severity levels.
* @return A boost::log::filter that filters log records based on the severity level.
*/
static boost::log::filter
createLogFilter(Severity defaultSeverity, std::unordered_map<std::string, Severity> const& minSeverity)
std::shared_ptr<spdlog::logger>
LogService::registerLogger(std::string const& channel, Severity severity)
{
auto logFilter = [minSeverity = minSeverity,
defaultSeverity](boost::log::attribute_value_set const& attributes) -> bool {
auto const channel = attributes[LogChannel];
auto const severity = attributes[LogSeverity];
if (!channel || !severity)
return false;
if (auto const it = minSeverity.find(channel.get()); it != minSeverity.end())
return severity.get() >= it->second;
return severity.get() >= defaultSeverity;
};
std::shared_ptr<spdlog::logger> logger;
if (data.isAsync) {
logger = std::make_shared<spdlog::async_logger>(
channel,
data.allSinks.begin(),
data.allSinks.end(),
spdlog::thread_pool(),
spdlog::async_overflow_policy::block
);
} else {
logger = std::make_shared<spdlog::logger>(channel, data.allSinks.begin(), data.allSinks.end());
}
return boost::log::filter{std::move(logFilter)};
logger->set_level(toSpdlogLevel(severity));
logger->flush_on(spdlog::level::err);
spdlog::register_logger(logger);
return logger;
}
std::expected<void, std::string>
LogService::init(config::ClioConfigDefinition const& config)
{
boost::log::add_common_attributes();
boost::log::register_simple_formatter_factory<Severity, char>("Severity");
std::string const format = config.get<std::string>("log_format");
// Drop existing loggers
spdlog::drop_all();
initConsoleLogging(config.get<bool>("log_to_console"), format);
data.isAsync = config.get<bool>("spdlog_async");
auto const logDir = config.maybeValue<std::string>("log_directory");
if (logDir) {
if (data.isAsync) {
spdlog::init_thread_pool(8192, 1);
}
data.allSinks = createConsoleSinks(config.get<bool>("log_to_console"));
if (auto const logDir = config.maybeValue<std::string>("log_directory"); logDir.has_value()) {
std::filesystem::path const dirPath{logDir.value()};
if (not std::filesystem::exists(dirPath)) {
if (std::error_code error; not std::filesystem::create_directories(dirPath, error)) {
@@ -272,13 +244,13 @@ LogService::init(config::ClioConfigDefinition const& config)
};
}
}
FileLoggingParams const params{
.logDir = logDir.value(),
.rotationSizeMB = config.get<uint32_t>("log_rotation_size"),
.dirMaxSizeMB = config.get<uint32_t>("log_directory_max_size"),
.rotationHours = config.get<uint32_t>("log_rotation_hour_interval")
.dirMaxFiles = config.get<uint32_t>("log_directory_max_files"),
};
initFileLogging(params, format);
data.allSinks.push_back(createFileSink(params));
}
// get default severity, can be overridden per channel using the `log_channels` array
@@ -289,17 +261,92 @@ LogService::init(config::ClioConfigDefinition const& config)
}
auto const minSeverity = std::move(maybeMinSeverity).value();
auto logFilter = createLogFilter(defaultSeverity, minSeverity);
boost::log::core::get()->set_filter(logFilter);
// Create loggers for each channel
for (auto const& channel : Logger::kCHANNELS) {
auto const it = minSeverity.find(channel);
auto const severity = (it != minSeverity.end()) ? it->second : defaultSeverity;
registerLogger(channel, severity);
}
LOG(LogService::info()) << "Default log level = " << defaultSeverity;
spdlog::set_default_logger(spdlog::get("General"));
std::string const format = config.get<std::string>("spdlog_format");
spdlog::set_pattern(format);
LOG(LogService::info()) << "Default log level = " << toString(defaultSeverity);
return {};
}
void
LogService::shutdown()
{
LOG(LogService::info()) << "Shutting down logger";
spdlog::shutdown();
}
Logger::Pump
LogService::trace(SourceLocationType const& loc)
{
return Logger(spdlog::default_logger()).trace(loc);
}
Logger::Pump
LogService::debug(SourceLocationType const& loc)
{
return Logger(spdlog::default_logger()).debug(loc);
}
Logger::Pump
LogService::info(SourceLocationType const& loc)
{
return Logger(spdlog::default_logger()).info(loc);
}
Logger::Pump
LogService::warn(SourceLocationType const& loc)
{
return Logger(spdlog::default_logger()).warn(loc);
}
Logger::Pump
LogService::error(SourceLocationType const& loc)
{
return Logger(spdlog::default_logger()).error(loc);
}
Logger::Pump
LogService::fatal(SourceLocationType const& loc)
{
return Logger(spdlog::default_logger()).fatal(loc);
}
bool
LogService::enabled()
{
return boost::log::core::get()->get_logging_enabled();
return spdlog::get_level() != spdlog::level::off;
}
Logger::Logger(std::string channel) : logger_(spdlog::get(channel))
{
if (!logger_) {
logger_ = LogService::registerLogger(channel);
}
}
Logger::Pump::Pump(std::shared_ptr<spdlog::logger> logger, Severity sev, SourceLocationType const& loc)
: logger_(std::move(logger))
, severity_(sev)
, sourceLocation_(loc)
, enabled_(logger_ != nullptr && logger_->should_log(toSpdlogLevel(sev)))
{
}
Logger::Pump::~Pump()
{
if (enabled_) {
spdlog::source_loc sourceLocation{prettyPath(sourceLocation_).cbegin(), sourceLocation_.line(), nullptr};
logger_->log(sourceLocation, toSpdlogLevel(severity_), std::move(stream_).str());
}
}
Logger::Pump
@@ -333,17 +380,21 @@ Logger::fatal(SourceLocationType const& loc) const
return {logger_, Severity::FTL, loc};
}
std::string
Logger::Logger(std::shared_ptr<spdlog::logger> logger) : logger_(std::move(logger))
{
}
std::string_view
Logger::Pump::prettyPath(SourceLocationType const& loc, size_t maxDepth)
{
auto const filePath = std::string{loc.file_name()};
std::string_view filePath{loc.file_name()};
auto idx = filePath.size();
while (maxDepth-- > 0) {
idx = filePath.rfind('/', idx - 1);
if (idx == std::string::npos || idx == 0)
break;
}
return filePath.substr(idx == std::string::npos ? 0 : idx + 1) + ':' + std::to_string(loc.line());
return filePath.substr(idx == std::string::npos ? 0 : idx + 1);
}
} // namespace util

159
src/util/log/Logger.hpp
View File

@@ -21,35 +21,27 @@
#include "util/SourceLocation.hpp"
#include <boost/algorithm/string/predicate.hpp>
#include <boost/filesystem.hpp>
#include <boost/json.hpp>
#include <boost/json/conversion.hpp>
#include <boost/json/value.hpp>
#include <boost/log/core/core.hpp>
#include <boost/log/core/record.hpp>
#include <boost/log/expressions/filter.hpp>
#include <boost/log/expressions/keyword.hpp>
#include <boost/log/expressions/predicates/channel_severity_filter.hpp>
#include <boost/log/keywords/channel.hpp>
#include <boost/log/keywords/severity.hpp>
#include <boost/log/sinks/unlocked_frontend.hpp>
#include <boost/log/sources/record_ostream.hpp>
#include <boost/log/sources/severity_channel_logger.hpp>
#include <boost/log/sources/severity_feature.hpp>
#include <boost/log/sources/severity_logger.hpp>
#include <boost/log/utility/manipulators/add_value.hpp>
#include <boost/log/utility/setup/common_attributes.hpp>
#include <boost/log/utility/setup/console.hpp>
#include <boost/log/utility/setup/file.hpp>
#include <boost/log/utility/setup/formatter_parser.hpp>
#include <array>
#include <cstddef>
#include <cstdint>
#include <expected>
#include <optional>
#include <ostream>
#include <memory>
#include <sstream>
#include <string>
#include <string_view>
#include <vector>
// We forward declare spdlog::logger and spdlog::sinks::sink
// to avoid including the spdlog headers in this header file.
namespace spdlog {
class logger;
namespace sinks {
class sink;
} // namespace sinks
} // namespace spdlog
struct BenchmarkLoggingInitializer;
@@ -85,23 +77,6 @@ enum class Severity {
FTL,
};
/** @cond */
// NOLINTBEGIN(readability-identifier-naming)
BOOST_LOG_ATTRIBUTE_KEYWORD(LogSeverity, "Severity", Severity);
BOOST_LOG_ATTRIBUTE_KEYWORD(LogChannel, "Channel", std::string);
// NOLINTEND(readability-identifier-naming)
/** @endcond */
/**
* @brief Custom labels for @ref Severity in log output.
*
* @param stream std::ostream The output stream
* @param sev Severity The severity to output to the ostream
* @return The same ostream we were given
*/
std::ostream&
operator<<(std::ostream& stream, Severity sev);
/**
* @brief A simple thread-safe logger for the channel specified
* in the constructor.
@@ -111,31 +86,25 @@ operator<<(std::ostream& stream, Severity sev);
* severity levels for each channel.
*/
class Logger final {
using LoggerType = boost::log::sources::severity_channel_logger_mt<Severity, std::string>;
mutable LoggerType logger_;
std::shared_ptr<spdlog::logger> logger_;
friend class LogService; // to expose the Pump interface
friend struct ::BenchmarkLoggingInitializer;
/**
* @brief Helper that pumps data into a log record via `operator<<`.
*/
class Pump final {
using PumpOptType = std::optional<boost::log::aux::record_pump<LoggerType>>;
boost::log::record rec_;
PumpOptType pump_ = std::nullopt;
std::shared_ptr<spdlog::logger> logger_;
Severity const severity_;
SourceLocationType const sourceLocation_;
std::ostringstream stream_;
bool const enabled_;
public:
~Pump() = default;
~Pump();
Pump(LoggerType& logger, Severity sev, SourceLocationType const& loc)
: rec_{logger.open_record(boost::log::keywords::severity = sev)}
{
if (rec_) {
pump_.emplace(boost::log::aux::make_record_pump(logger, rec_));
pump_->stream() << boost::log::add_value("SourceLocation", prettyPath(loc));
}
}
Pump(std::shared_ptr<spdlog::logger> logger, Severity sev, SourceLocationType const& loc);
Pump(Pump&&) = delete;
Pump(Pump const&) = delete;
@@ -145,7 +114,7 @@ class Logger final {
operator=(Pump&&) = delete;
/**
* @brief Perfectly forwards any incoming data into the underlying boost::log pump if the pump is available.
* @brief Perfectly forwards any incoming data into the underlying stream if data should be logged.
*
* @tparam T Type of data to pump
* @param data The data to pump
@@ -155,8 +124,8 @@ class Logger final {
[[maybe_unused]] Pump&
operator<<(T&& data)
{
if (pump_)
pump_->stream() << std::forward<T>(data);
if (enabled_)
stream_ << std::forward<T>(data);
return *this;
}
@@ -165,11 +134,11 @@ class Logger final {
*/
operator bool() const
{
return pump_.has_value();
return enabled_;
}
private:
[[nodiscard]] static std::string
[[nodiscard]] static std::string_view
prettyPath(SourceLocationType const& loc, size_t maxDepth = 3);
};
@@ -194,9 +163,7 @@ public:
*
* @param channel The channel this logger will report into.
*/
Logger(std::string channel) : logger_{boost::log::keywords::channel = channel}
{
}
Logger(std::string channel);
Logger(Logger const&) = default;
~Logger() = default;
@@ -261,6 +228,9 @@ public:
*/
[[nodiscard]] Pump
fatal(SourceLocationType const& loc = CURRENT_SRC_LOCATION) const;
private:
Logger(std::shared_ptr<spdlog::logger> logger);
};
/**
@@ -270,8 +240,19 @@ public:
* entrypoint for logging into the `General` channel as well as raising alerts.
*/
class LogService {
static Logger generalLog; /*< Global logger for General channel */
static boost::log::filter filter;
struct Data {
bool isAsync;
Severity severity;
std::vector<std::shared_ptr<spdlog::sinks::sink>> allSinks;
};
friend class Logger;
private:
static Data data;
static std::shared_ptr<spdlog::logger>
registerLogger(std::string const& channel, Severity severity = data.severity);
public:
LogService() = delete;
@@ -285,6 +266,12 @@ public:
[[nodiscard]] static std::expected<void, std::string>
init(config::ClioConfigDefinition const& config);
/**
* @brief Shutdown spdlog to guarantee output is not lost
*/
static void
shutdown();
/**
* @brief Globally accessible General logger at Severity::TRC severity
*
@@ -292,10 +279,7 @@ public:
* @return The pump to use for logging
*/
[[nodiscard]] static Logger::Pump
trace(SourceLocationType const& loc = CURRENT_SRC_LOCATION)
{
return generalLog.trace(loc);
}
trace(SourceLocationType const& loc = CURRENT_SRC_LOCATION);
/**
* @brief Globally accessible General logger at Severity::DBG severity
@@ -304,10 +288,7 @@ public:
* @return The pump to use for logging
*/
[[nodiscard]] static Logger::Pump
debug(SourceLocationType const& loc = CURRENT_SRC_LOCATION)
{
return generalLog.debug(loc);
}
debug(SourceLocationType const& loc = CURRENT_SRC_LOCATION);
/**
* @brief Globally accessible General logger at Severity::NFO severity
@@ -316,10 +297,7 @@ public:
* @return The pump to use for logging
*/
[[nodiscard]] static Logger::Pump
info(SourceLocationType const& loc = CURRENT_SRC_LOCATION)
{
return generalLog.info(loc);
}
info(SourceLocationType const& loc = CURRENT_SRC_LOCATION);
/**
* @brief Globally accessible General logger at Severity::WRN severity
@@ -328,10 +306,7 @@ public:
* @return The pump to use for logging
*/
[[nodiscard]] static Logger::Pump
warn(SourceLocationType const& loc = CURRENT_SRC_LOCATION)
{
return generalLog.warn(loc);
}
warn(SourceLocationType const& loc = CURRENT_SRC_LOCATION);
/**
* @brief Globally accessible General logger at Severity::ERR severity
@@ -340,10 +315,7 @@ public:
* @return The pump to use for logging
*/
[[nodiscard]] static Logger::Pump
error(SourceLocationType const& loc = CURRENT_SRC_LOCATION)
{
return generalLog.error(loc);
}
error(SourceLocationType const& loc = CURRENT_SRC_LOCATION);
/**
* @brief Globally accessible General logger at Severity::FTL severity
@@ -352,10 +324,7 @@ public:
* @return The pump to use for logging
*/
[[nodiscard]] static Logger::Pump
fatal(SourceLocationType const& loc = CURRENT_SRC_LOCATION)
{
return generalLog.fatal(loc);
}
fatal(SourceLocationType const& loc = CURRENT_SRC_LOCATION);
/**
* @brief Whether the LogService is enabled or not
@@ -370,14 +339,14 @@ private:
std::string logDir;
uint32_t rotationSizeMB;
uint32_t dirMaxSizeMB;
uint32_t rotationHours;
uint32_t dirMaxFiles;
};
friend struct ::BenchmarkLoggingInitializer;
static void
initFileLogging(FileLoggingParams const& params, std::string const& format);
[[nodiscard]]
static std::shared_ptr<spdlog::sinks::sink>
createFileSink(FileLoggingParams const& params);
};
}; // namespace util

2
tests/common/CMakeLists.txt
View File

@@ -18,4 +18,4 @@ target_sources(
include(deps/gtest)
target_include_directories(clio_testing_common PUBLIC .)
target_link_libraries(clio_testing_common PUBLIC clio_app gtest::gtest)
target_link_libraries(clio_testing_common PUBLIC clio_app gtest::gtest PRIVATE spdlog::spdlog)

48
tests/common/util/LoggerFixtures.cpp
View File

@@ -21,44 +21,40 @@
#include "util/log/Logger.hpp"
#include <boost/log/core/core.hpp>
#include <boost/log/expressions/predicates/channel_severity_filter.hpp>
#include <boost/log/keywords/format.hpp>
#include <boost/log/utility/setup/common_attributes.hpp>
#include <boost/log/utility/setup/console.hpp>
#include <boost/log/utility/setup/formatter_parser.hpp>
#include <spdlog/common.h>
#include <spdlog/sinks/ostream_sink.h>
#include <spdlog/spdlog.h>
#include <algorithm>
#include <mutex>
#include <memory>
LoggerFixture::LoggerFixture()
{
static std::once_flag kONCE;
std::call_once(kONCE, [] {
boost::log::add_common_attributes();
boost::log::register_simple_formatter_factory<util::Severity, char>("Severity");
// Clear any existing loggers
spdlog::drop_all();
// Create ostream sink for testing
auto ostreamSink = std::make_shared<spdlog::sinks::ostream_sink_mt>(stream_);
// Create loggers for each channel
std::ranges::for_each(util::Logger::kCHANNELS, [&ostreamSink](char const* channel) {
auto logger = std::make_shared<spdlog::logger>(channel, ostreamSink);
logger->set_level(spdlog::level::trace);
spdlog::register_logger(logger);
});
namespace keywords = boost::log::keywords;
namespace expr = boost::log::expressions;
auto core = boost::log::core::get();
spdlog::get("General")->set_level(spdlog::level::debug);
core->remove_all_sinks();
boost::log::add_console_log(stream_, keywords::format = "%Channel%:%Severity% %Message%");
auto minSeverity = expr::channel_severity_filter(util::LogChannel, util::LogSeverity);
auto traceLogger = std::make_shared<spdlog::logger>("Trace", ostreamSink);
traceLogger->set_level(spdlog::level::trace);
spdlog::register_logger(traceLogger);
std::ranges::for_each(util::Logger::kCHANNELS, [&minSeverity](char const* channel) {
minSeverity[channel] = util::Severity::TRC;
});
spdlog::set_default_logger(spdlog::get("General"));
minSeverity["General"] = util::Severity::DBG;
minSeverity["Trace"] = util::Severity::TRC;
core->set_filter(minSeverity);
core->set_logging_enabled(true);
spdlog::set_pattern("%^%3!l:%n%$ - %v");
}
NoLoggerFixture::NoLoggerFixture()
{
boost::log::core::get()->set_logging_enabled(false);
spdlog::set_level(spdlog::level::off);
}

39
tests/common/util/LoggerFixtures.hpp
View File

@@ -19,56 +19,25 @@
#pragma once
#include "util/log/Logger.hpp"
#include "util/StringBuffer.hpp"
#include <gtest/gtest.h>
#include <algorithm>
#include <mutex>
#include <ostream>
#include <sstream>
#include <string>
/**
* @brief Fixture with util::Logger support.
* @brief A fixture for testing LogService and Logger.
*/
class LoggerFixture : virtual public ::testing::Test {
/**
* @brief A simple string buffer that can be used to mock std::cout for
* console logging.
*/
class FakeBuffer final : public std::stringbuf {
public:
std::string
getStrAndReset()
{
auto value = str();
str("");
return value;
}
};
FakeBuffer buffer_;
StringBuffer buffer_;
std::ostream stream_ = std::ostream{&buffer_};
public:
// Simulates the `util::Logger::init(config)` call
// Simulates the `util::LogService::init(config)` call
LoggerFixture();
protected:
void
checkEqual(std::string expected)
{
auto value = buffer_.getStrAndReset();
ASSERT_EQ(value, expected + '\n') << "Got: " << value;
}
void
checkEmpty()
{
ASSERT_TRUE(buffer_.getStrAndReset().empty());
}
std::string
getLoggerString()
{

37
tests/common/util/StringBuffer.hpp Normal file
View File

@@ -0,0 +1,37 @@
//------------------------------------------------------------------------------
/*
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 <sstream>
#include <string>
/**
* @brief A simple string buffer that can be used to mock std::cout for console logging.
*/
class StringBuffer final : public std::stringbuf {
public:
std::string
getStrAndReset()
{
auto value = str();
str("");
return value;
}
};

4
tests/unit/CMakeLists.txt
View File

@@ -69,6 +69,7 @@ target_sources(
feed/TrackableSignalTests.cpp
feed/TransactionFeedTests.cpp
JsonUtilTests.cpp
LogServiceInitTests.cpp
LoggerTests.cpp
Main.cpp
Playground.cpp
@@ -173,6 +174,7 @@ target_sources(
util/RepeatTests.cpp
util/ResponseExpirationCacheTests.cpp
util/RetryTests.cpp
util/ScopeGuardTests.cpp
util/SignalsHandlerTests.cpp
util/SpawnTests.cpp
util/StopHelperTests.cpp
@@ -216,7 +218,7 @@ gtest_discover_tests(clio_tests DISCOVERY_TIMEOUT 90)
target_compile_options(clio_options INTERFACE -gdwarf-4)
target_include_directories(clio_tests PRIVATE .)
target_link_libraries(clio_tests PUBLIC clio_testing_common)
target_link_libraries(clio_tests PUBLIC clio_testing_common PRIVATE spdlog::spdlog)
set_target_properties(clio_tests PROPERTIES RUNTIME_OUTPUT_DIRECTORY ${CMAKE_BINARY_DIR})
# Generate `coverage_report` target if coverage is enabled

232
tests/unit/LogServiceInitTests.cpp Normal file
View File

@@ -0,0 +1,232 @@
//------------------------------------------------------------------------------
/*
This file is part of clio: https://github.com/XRPLF/clio
Copyright (c) 2022, 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.
*/
//==============================================================================
#include "util/StringBuffer.hpp"
#include "util/config/Array.hpp"
#include "util/config/ConfigConstraints.hpp"
#include "util/config/ConfigDefinition.hpp"
#include "util/config/ConfigFileJson.hpp"
#include "util/config/ConfigValue.hpp"
#include "util/config/Types.hpp"
#include "util/log/Logger.hpp"
#include <boost/json/array.hpp>
#include <boost/json/object.hpp>
#include <boost/json/parse.hpp>
#include <fmt/format.h>
#include <gmock/gmock.h>
#include <gtest/gtest.h>
#include <spdlog/sinks/ostream_sink.h>
#include <spdlog/spdlog.h>
#include <cstddef>
#include <cstdint>
#include <limits>
#include <memory>
#include <ostream>
#include <string>
#include <string_view>
#include <vector>
using namespace util;
using util::config::Array;
using util::config::ConfigFileJson;
using util::config::ConfigType;
using util::config::ConfigValue;
struct LogServiceInitTests : virtual public ::testing::Test {
protected:
util::config::ClioConfigDefinition config_{
{"log_channels.[].channel", Array{ConfigValue{ConfigType::String}}},
{"log_channels.[].log_level", Array{ConfigValue{ConfigType::String}}},
{"log_level", ConfigValue{ConfigType::String}.defaultValue("info")},
{"spdlog_format", ConfigValue{ConfigType::String}.defaultValue(R"(%Y-%m-%d %H:%M:%S.%f %^%3!l:%n%$ - %v)")},
{"spdlog_async", ConfigValue{ConfigType::Boolean}.defaultValue(false)},
{"log_to_console", ConfigValue{ConfigType::Boolean}.defaultValue(false)},
{"log_directory", ConfigValue{ConfigType::String}.optional()},
{"log_rotation_size",
ConfigValue{ConfigType::Integer}.defaultValue(2048).withConstraint(config::gValidateUint32)},
{"log_directory_max_files",
ConfigValue{ConfigType::Integer}.defaultValue(25).withConstraint(config::gValidateUint32)},
{"log_tag_style", ConfigValue{ConfigType::String}.defaultValue("none")},
};
std::string
getLoggerString()
{
return buffer_.getStrAndReset();
}
void
replaceSinks()
{
auto ostreamSink = std::make_shared<spdlog::sinks::ostream_sink_mt>(stream_);
for (auto const& channel : Logger::kCHANNELS) {
auto logger = spdlog::get(channel);
ASSERT_TRUE(logger != nullptr);
// It is expected that only stderrSink is present
ASSERT_EQ(logger->sinks().size(), 1);
logger->sinks().clear();
logger->sinks().push_back(ostreamSink);
}
spdlog::set_pattern("%^%3!l:%n%$ - %v");
}
private:
StringBuffer buffer_;
std::ostream stream_ = std::ostream{&buffer_};
};
TEST_F(LogServiceInitTests, DefaultLogLevel)
{
auto const parsingErrors = config_.parse(ConfigFileJson{boost::json::object{{"log_level", "warn"}}});
ASSERT_FALSE(parsingErrors.has_value());
std::string const logString = "some log";
EXPECT_TRUE(LogService::init(config_));
replaceSinks();
for (auto const& channel : Logger::kCHANNELS) {
Logger const log{channel};
log.trace() << logString;
ASSERT_TRUE(getLoggerString().empty());
log.debug() << logString;
ASSERT_TRUE(getLoggerString().empty());
log.info() << logString;
ASSERT_TRUE(getLoggerString().empty());
log.warn() << logString;
ASSERT_EQ(fmt::format("war:{} - {}\n", channel, logString), getLoggerString());
log.error() << logString;
ASSERT_EQ(fmt::format("err:{} - {}\n", channel, logString), getLoggerString());
}
}
TEST_F(LogServiceInitTests, ChannelLogLevel)
{
std::string const configStr = R"JSON(
{
"log_level": "error",
"log_channels": [
{
"channel": "Backend",
"log_level": "warning"
}
]
}
)JSON";
auto const parsingErrors = config_.parse(ConfigFileJson{boost::json::parse(configStr).as_object()});
ASSERT_FALSE(parsingErrors.has_value());
std::string const logString = "some log";
EXPECT_TRUE(LogService::init(config_));
replaceSinks();
for (auto const& channel : Logger::kCHANNELS) {
Logger const log{channel};
log.trace() << logString;
ASSERT_TRUE(getLoggerString().empty());
log.debug() << logString;
ASSERT_TRUE(getLoggerString().empty());
log.info() << logString;
ASSERT_TRUE(getLoggerString().empty());
log.warn() << logString;
if (std::string_view{channel} == "Backend") {
ASSERT_EQ(fmt::format("war:{} - {}\n", channel, logString), getLoggerString());
} else {
ASSERT_TRUE(getLoggerString().empty());
}
log.error() << logString;
ASSERT_EQ(fmt::format("err:{} - {}\n", channel, logString), getLoggerString());
}
}
TEST_F(LogServiceInitTests, InitReturnsErrorIfCouldNotCreateLogDirectory)
{
// "/proc" directory is read only on any unix OS
auto const parsingErrors = config_.parse(ConfigFileJson{boost::json::object{{"log_directory", "/proc/logs"}}});
ASSERT_FALSE(parsingErrors.has_value());
auto const result = LogService::init(config_);
EXPECT_FALSE(result);
EXPECT_THAT(result.error(), testing::HasSubstr("Couldn't create logs directory"));
}
TEST_F(LogServiceInitTests, InitReturnsErrorIfProvidedInvalidChannel)
{
auto const jsonStr = R"JSON(
{
"log_channels": [
{
"channel": "SomeChannel",
"log_level": "warn"
}
]
})JSON";
auto const json = boost::json::parse(jsonStr).as_object();
auto const parsingErrors = config_.parse(ConfigFileJson{json});
ASSERT_FALSE(parsingErrors.has_value());
auto const result = LogService::init(config_);
EXPECT_FALSE(result);
EXPECT_EQ(result.error(), "Can't override settings for log channel SomeChannel: invalid channel");
}
TEST_F(LogServiceInitTests, LogSizeAndHourRotationCannotBeZero)
{
std::vector<std::string_view> const keys{"log_directory_max_files", "log_rotation_size"};
auto const jsonStr = fmt::format(
R"JSON(
{{
"{}": 0,
"{}": 0
}}
)JSON",
keys[0],
keys[1]
);
auto const parsingErrors = config_.parse(ConfigFileJson{boost::json::parse(jsonStr).as_object()});
ASSERT_EQ(parsingErrors->size(), 2);
for (std::size_t i = 0; i < parsingErrors->size(); ++i) {
EXPECT_EQ(
(*parsingErrors)[i].error,
fmt::format("{} Number must be between 1 and {}", keys[i], std::numeric_limits<uint32_t>::max())
);
}
}

191
tests/unit/LoggerTests.cpp
View File

@@ -18,27 +18,14 @@
//==============================================================================
#include "util/LoggerFixtures.hpp"
#include "util/config/Array.hpp"
#include "util/config/ConfigConstraints.hpp"
#include "util/config/ConfigDefinition.hpp"
#include "util/config/ConfigFileJson.hpp"
#include "util/config/ConfigValue.hpp"
#include "util/config/Types.hpp"
#include "util/log/Logger.hpp"
#include <boost/json/array.hpp>
#include <boost/json/object.hpp>
#include <boost/json/parse.hpp>
#include <fmt/format.h>
#include <gmock/gmock.h>
#include <gtest/gtest.h>
#include <cstddef>
#include <cstdint>
#include <limits>
#include <string>
#include <string_view>
#include <vector>
using namespace util;
// Used as a fixture for tests with enabled logging
@@ -51,189 +38,27 @@ TEST_F(LoggerTest, Basic)
{
Logger const log{"General"};
log.info() << "Info line logged";
checkEqual("General:NFO Info line logged");
ASSERT_EQ(getLoggerString(), "inf:General - Info line logged\n");
LogService::debug() << "Debug line with numbers " << 12345;
checkEqual("General:DBG Debug line with numbers 12345");
ASSERT_EQ(getLoggerString(), "deb:General - Debug line with numbers 12345\n");
LogService::warn() << "Warning is logged";
checkEqual("General:WRN Warning is logged");
ASSERT_EQ(getLoggerString(), "war:General - Warning is logged\n");
}
TEST_F(LoggerTest, Filtering)
{
Logger const log{"General"};
log.trace() << "Should not be logged";
checkEmpty();
ASSERT_TRUE(getLoggerString().empty());
log.warn() << "Warning is logged";
checkEqual("General:WRN Warning is logged");
ASSERT_EQ(getLoggerString(), "war:General - Warning is logged\n");
Logger const tlog{"Trace"};
tlog.trace() << "Trace line logged for 'Trace' component";
checkEqual("Trace:TRC Trace line logged for 'Trace' component");
}
using util::config::Array;
using util::config::ConfigFileJson;
using util::config::ConfigType;
using util::config::ConfigValue;
struct LoggerInitTest : LoggerTest {
protected:
util::config::ClioConfigDefinition config_{
{"log_channels.[].channel", Array{ConfigValue{ConfigType::String}}},
{"log_channels.[].log_level", Array{ConfigValue{ConfigType::String}}},
{"log_level", ConfigValue{ConfigType::String}.defaultValue("info")},
{"log_format",
ConfigValue{ConfigType::String}.defaultValue(
R"(%TimeStamp% (%SourceLocation%) [%ThreadID%] %Channel%:%Severity% %Message%)"
)},
{"log_to_console", ConfigValue{ConfigType::Boolean}.defaultValue(false)},
{"log_directory", ConfigValue{ConfigType::String}.optional()},
{"log_rotation_size",
ConfigValue{ConfigType::Integer}.defaultValue(2048).withConstraint(config::gValidateUint32)},
{"log_directory_max_size",
ConfigValue{ConfigType::Integer}.defaultValue(50 * 1024).withConstraint(config::gValidateUint32)},
{"log_rotation_hour_interval",
ConfigValue{ConfigType::Integer}.defaultValue(12).withConstraint(config::gValidateUint32)},
{"log_tag_style", ConfigValue{ConfigType::String}.defaultValue("none")},
};
};
TEST_F(LoggerInitTest, DefaultLogLevel)
{
auto const parsingErrors = config_.parse(ConfigFileJson{boost::json::object{{"log_level", "warn"}}});
ASSERT_FALSE(parsingErrors.has_value());
std::string const logString = "some log";
EXPECT_TRUE(LogService::init(config_));
for (auto const& channel : Logger::kCHANNELS) {
Logger const log{channel};
log.trace() << logString;
checkEmpty();
log.debug() << logString;
checkEmpty();
log.info() << logString;
checkEmpty();
log.warn() << logString;
checkEqual(fmt::format("{}:WRN {}", channel, logString));
log.error() << logString;
checkEqual(fmt::format("{}:ERR {}", channel, logString));
}
}
TEST_F(LoggerInitTest, ChannelLogLevel)
{
std::string const configStr = R"JSON(
{
"log_level": "error",
"log_channels": [
{
"channel": "Backend",
"log_level": "warning"
}
]
}
)JSON";
auto const parsingErrors = config_.parse(ConfigFileJson{boost::json::parse(configStr).as_object()});
ASSERT_FALSE(parsingErrors.has_value());
std::string const logString = "some log";
EXPECT_TRUE(LogService::init(config_));
for (auto const& channel : Logger::kCHANNELS) {
Logger const log{channel};
log.trace() << logString;
checkEmpty();
log.debug() << logString;
checkEmpty();
log.info() << logString;
checkEmpty();
log.warn() << logString;
if (std::string_view{channel} == "Backend") {
checkEqual(fmt::format("{}:WRN {}", channel, logString));
} else {
checkEmpty();
}
log.error() << "some log";
checkEqual(fmt::format("{}:ERR {}", channel, logString));
}
}
TEST_F(LoggerInitTest, InitReturnsErrorIfCouldNotCreateLogDirectory)
{
// "/proc" directory is read only on any unix OS
auto const parsingErrors = config_.parse(ConfigFileJson{boost::json::object{{"log_directory", "/proc/logs"}}});
ASSERT_FALSE(parsingErrors.has_value());
auto const result = LogService::init(config_);
EXPECT_FALSE(result);
EXPECT_THAT(result.error(), testing::HasSubstr("Couldn't create logs directory"));
}
TEST_F(LoggerInitTest, InitReturnsErrorIfProvidedInvalidChannel)
{
auto const jsonStr = R"JSON(
{
"log_channels": [
{
"channel": "SomeChannel",
"log_level": "warn"
}
]
})JSON";
auto const json = boost::json::parse(jsonStr).as_object();
auto const parsingErrors = config_.parse(ConfigFileJson{json});
ASSERT_FALSE(parsingErrors.has_value());
auto const result = LogService::init(config_);
EXPECT_FALSE(result);
EXPECT_EQ(result.error(), "Can't override settings for log channel SomeChannel: invalid channel");
}
TEST_F(LoggerInitTest, LogSizeAndHourRotationCannotBeZero)
{
std::vector<std::string_view> const keys{
"log_rotation_hour_interval", "log_directory_max_size", "log_rotation_size"
};
auto const jsonStr = fmt::format(
R"JSON({{
"{}": 0,
"{}": 0,
"{}": 0
}})JSON",
keys[0],
keys[1],
keys[2]
);
auto const parsingErrors = config_.parse(ConfigFileJson{boost::json::parse(jsonStr).as_object()});
ASSERT_EQ(parsingErrors->size(), 3);
for (std::size_t i = 0; i < parsingErrors->size(); ++i) {
EXPECT_EQ(
(*parsingErrors)[i].error,
fmt::format("{} Number must be between 1 and {}", keys[i], std::numeric_limits<uint32_t>::max())
);
}
ASSERT_EQ(getLoggerString(), "tra:Trace - Trace line logged for 'Trace' component\n");
}
#ifndef COVERAGE_ENABLED
@@ -259,8 +84,8 @@ TEST_F(NoLoggerTest, Basic)
{
Logger const log{"Trace"};
log.trace() << "Nothing";
checkEmpty();
ASSERT_TRUE(getLoggerString().empty());
LogService::fatal() << "Still nothing";
checkEmpty();
ASSERT_TRUE(getLoggerString().empty());
}

2
tests/unit/etl/AmendmentBlockHandlerTests.cpp
View File

@@ -54,5 +54,5 @@ TEST_F(DefaultAmendmentBlockActionTest, Call)
{
AmendmentBlockHandler::kDEFAULT_AMENDMENT_BLOCK_ACTION();
auto const loggerString = getLoggerString();
EXPECT_TRUE(loggerString.starts_with("ETL:FTL Can't process new ledgers")) << "LoggerString " << loggerString;
EXPECT_TRUE(loggerString.starts_with("cri:ETL - Can't process new ledgers")) << "LoggerString " << loggerString;
}

2
tests/unit/etlng/AmendmentBlockHandlerTests.cpp
View File

@@ -65,5 +65,5 @@ TEST_F(DefaultAmendmentBlockActionNgTest, Call)
{
AmendmentBlockHandler::kDEFAULT_AMENDMENT_BLOCK_ACTION();
auto const loggerString = getLoggerString();
EXPECT_TRUE(loggerString.starts_with("ETL:FTL Can't process new ledgers")) << "LoggerString " << loggerString;
EXPECT_TRUE(loggerString.starts_with("cri:ETL - Can't process new ledgers")) << "LoggerString " << loggerString;
}

6
tests/unit/rpc/RPCHelpersTests.cpp
View File

@@ -1333,14 +1333,14 @@ INSTANTIATE_TEST_SUITE_P(
RPCHelpersLogDurationTests,
RPCHelpersLogDurationTest,
testing::Values(
RPCHelpersLogDurationTestBundle{"ShortDurationLogsAsInfo", std::chrono::milliseconds(500), "RPC:NFO", true},
RPCHelpersLogDurationTestBundle{"ShortDurationLogsAsInfo", std::chrono::milliseconds(500), "inf:RPC ", true},
RPCHelpersLogDurationTestBundle{
"MediumDurationLogsAsWarning",
std::chrono::milliseconds(5000),
"RPC:WRN",
"war:RPC ",
true
},
RPCHelpersLogDurationTestBundle{"LongDurationLogsAsError", std::chrono::milliseconds(15000), "RPC:ERR", true}
RPCHelpersLogDurationTestBundle{"LongDurationLogsAsError", std::chrono::milliseconds(15000), "err:RPC ", true}
),
tests::util::kNAME_GENERATOR
);

32
tests/unit/util/ScopeGuardTests.cpp Normal file
View File

@@ -0,0 +1,32 @@
//------------------------------------------------------------------------------
/*
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.
*/
//==============================================================================
#include "util/ScopeGuard.hpp"
#include <gmock/gmock.h>
#include <gtest/gtest.h>
TEST(ScopeGuardTest, IsCalled)
{
testing::StrictMock<testing::MockFunction<void()>> mockFunction;
EXPECT_CALL(mockFunction, Call());
{
util::ScopeGuard guard([&mockFunction] { mockFunction.Call(); });
}
}