perf: Add benchmark for Logger (#2407)

This commit is contained in:
Ayaz Salikhov
2025-08-07 19:46:12 +01:00
committed by GitHub
parent 87565b685a
commit 4aa2ca94de
6 changed files with 164 additions and 13 deletions

View File

@@ -16,6 +16,7 @@ coverage:
# #
# More info: https://github.com/XRPLF/clio/pull/2066 # More info: https://github.com/XRPLF/clio/pull/2066
ignore: ignore:
- "benchmarks"
- "tests" - "tests"
- "src/data/cassandra/" - "src/data/cassandra/"
- "src/data/CassandraBackend.hpp" - "src/data/CassandraBackend.hpp"

View File

@@ -15,6 +15,7 @@ runs:
shell: bash shell: bash
run: | run: |
gcovr \ gcovr \
-e benchmarks \
-e tests \ -e tests \
-e src/data/cassandra \ -e src/data/cassandra \
-e src/data/CassandraBackend.hpp \ -e src/data/CassandraBackend.hpp \

View File

@@ -7,10 +7,12 @@ target_sources(
Playground.cpp Playground.cpp
# ExecutionContext # ExecutionContext
util/async/ExecutionContextBenchmarks.cpp util/async/ExecutionContextBenchmarks.cpp
# Logger
util/log/LoggerBenchmark.cpp
) )
include(deps/gbench) include(deps/gbench)
target_include_directories(clio_benchmark PRIVATE .) target_include_directories(clio_benchmark PRIVATE .)
target_link_libraries(clio_benchmark PUBLIC clio_etl benchmark::benchmark_main) target_link_libraries(clio_benchmark PUBLIC clio_util benchmark::benchmark_main)
set_target_properties(clio_benchmark PROPERTIES RUNTIME_OUTPUT_DIRECTORY ${CMAKE_BINARY_DIR}) set_target_properties(clio_benchmark PROPERTIES RUNTIME_OUTPUT_DIRECTORY ${CMAKE_BINARY_DIR})

View File

@@ -0,0 +1,127 @@
//------------------------------------------------------------------------------
/*
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/config/ConfigDefinition.hpp"
#include "util/log/Logger.hpp"
#include "util/prometheus/Prometheus.hpp"
#include <benchmark/benchmark.h>
#include <boost/log/core/core.hpp>
#include <boost/log/utility/setup/common_attributes.hpp>
#include <barrier>
#include <chrono>
#include <cstddef>
#include <filesystem>
#include <string>
#include <thread>
#include <vector>
using namespace util;
struct BenchmarkLoggingInitializer {
static constexpr auto kLOG_FORMAT = "%TimeStamp% (%SourceLocation%) [%ThreadID%] %Channel%:%Severity% %Message%";
static void
initFileLogging(LogService::FileLoggingParams const& params)
{
boost::log::add_common_attributes();
std::filesystem::create_directories(params.logDir);
LogService::initFileLogging(params, kLOG_FORMAT);
}
};
namespace {
std::string
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());
return tmpDir / "clio_benchmark" / dirName;
}
} // anonymous namespace
static void
benchmarkConcurrentFileLogging(benchmark::State& state)
{
auto const numThreads = static_cast<size_t>(state.range(0));
auto const messagesPerThread = static_cast<size_t>(state.range(1));
PrometheusService::init(config::getClioConfig());
auto const logDir = uniqueLogDir();
for (auto _ : state) {
state.PauseTiming();
std::filesystem::remove_all(logDir);
BenchmarkLoggingInitializer::initFileLogging({
.logDir = logDir,
.rotationSizeMB = 1,
.dirMaxSizeMB = 10,
.rotationHours = 24,
});
state.ResumeTiming();
std::vector<std::thread> threads;
threads.reserve(numThreads);
std::chrono::high_resolution_clock::time_point start;
std::barrier barrier(numThreads, [&start]() { start = std::chrono::high_resolution_clock::now(); });
for (size_t threadNum = 0; threadNum < numThreads; ++threadNum) {
threads.emplace_back([threadNum, messagesPerThread, &barrier]() {
barrier.arrive_and_wait();
Logger threadLogger("Thread_" + std::to_string(threadNum));
for (size_t messageNum = 0; messageNum < messagesPerThread; ++messageNum) {
LOG(threadLogger.info()) << "Test log message #" << messageNum;
}
});
}
for (auto& thread : threads) {
thread.join();
}
boost::log::core::get()->flush();
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);
auto const totalMessages = numThreads * messagesPerThread;
state.counters["TotalMessagesRate"] = benchmark::Counter(totalMessages, benchmark::Counter::kIsRate);
state.counters["Threads"] = numThreads;
state.counters["MessagesPerThread"] = messagesPerThread;
}
BENCHMARK(benchmarkConcurrentFileLogging)
->ArgsProduct({
{1, 2, 4, 8}, // Number of threads
{500, 1000, 2000, 100000}, // Messages per thread
})
->UseManualTime()
->Unit(benchmark::kMillisecond);

View File

@@ -168,21 +168,18 @@ initConsoleLogging(bool logToConsole, std::string const& format)
* @param format The log format string. * @param format The log format string.
* @param dirPath The directory path where log files will be stored. * @param dirPath The directory path where log files will be stored.
*/ */
static void void
initFileLogging( LogService::initFileLogging(FileLoggingParams const& params, std::string const& format)
config::ClioConfigDefinition const& config,
std::string const& format,
std::filesystem::path const& dirPath
)
{ {
namespace keywords = boost::log::keywords; namespace keywords = boost::log::keywords;
namespace sinks = boost::log::sinks; namespace sinks = boost::log::sinks;
auto const rotationPeriod = config.get<uint32_t>("log_rotation_hour_interval");
// the below are taken from user in MB, but boost::log::add_file_log needs it to be in bytes // the below are taken from user in MB, but boost::log::add_file_log needs it to be in bytes
auto const rotationSize = mbToBytes(config.get<uint32_t>("log_rotation_size")); auto const rotationSize = mbToBytes(params.rotationSizeMB);
auto const dirSize = mbToBytes(config.get<uint32_t>("log_directory_max_size")); auto const dirSize = mbToBytes(params.dirMaxSizeMB);
auto const dirPath = std::filesystem::path{params.logDir};
auto fileSink = boost::log::add_file_log( auto fileSink = boost::log::add_file_log(
keywords::file_name = dirPath / "clio.log", keywords::file_name = dirPath / "clio.log",
keywords::target_file_name = dirPath / "clio_%Y-%m-%d_%H-%M-%S.log", keywords::target_file_name = dirPath / "clio_%Y-%m-%d_%H-%M-%S.log",
@@ -190,7 +187,8 @@ initFileLogging(
keywords::format = format, keywords::format = format,
keywords::open_mode = std::ios_base::app, keywords::open_mode = std::ios_base::app,
keywords::rotation_size = rotationSize, keywords::rotation_size = rotationSize,
keywords::time_based_rotation = sinks::file::rotation_at_time_interval(boost::posix_time::hours(rotationPeriod)) keywords::time_based_rotation =
sinks::file::rotation_at_time_interval(boost::posix_time::hours(params.rotationHours))
); );
fileSink->locked_backend()->set_file_collector( fileSink->locked_backend()->set_file_collector(
sinks::file::make_collector(keywords::target = dirPath, keywords::max_size = dirSize) sinks::file::make_collector(keywords::target = dirPath, keywords::max_size = dirSize)
@@ -274,7 +272,13 @@ LogService::init(config::ClioConfigDefinition const& config)
}; };
} }
} }
initFileLogging(config, format, dirPath); FileLoggingParams 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")
};
initFileLogging(params, format);
} }
// get default severity, can be overridden per channel using the `log_channels` array // get default severity, can be overridden per channel using the `log_channels` array

View File

@@ -51,6 +51,8 @@
#include <ostream> #include <ostream>
#include <string> #include <string>
struct BenchmarkLoggingInitializer;
namespace util { namespace util {
namespace config { namespace config {
@@ -362,6 +364,20 @@ public:
*/ */
[[nodiscard]] static bool [[nodiscard]] static bool
enabled(); enabled();
private:
struct FileLoggingParams {
std::string logDir;
uint32_t rotationSizeMB;
uint32_t dirMaxSizeMB;
uint32_t rotationHours;
};
friend struct ::BenchmarkLoggingInitializer;
static void
initFileLogging(FileLoggingParams const& params, std::string const& format);
}; };
}; // namespace util }; // namespace util