Asink sink (#3309)

Replace async logger with async sink
This commit is contained in:
Gabi Melman
2025-01-05 02:17:31 +02:00
committed by GitHub
parent 166843ff3a
commit 83c9ede9e6
82 changed files with 986 additions and 1789 deletions

View File

@@ -8,11 +8,14 @@
//
#include <atomic>
#include <iostream>
#include <fstream>
#include <memory>
#include <string>
#include <thread>
#include <locale>
#include <algorithm>
#include "spdlog/async.h"
#include "spdlog/sinks/async_sink.h"
#include "spdlog/sinks/basic_file_sink.h"
#include "spdlog/spdlog.h"
@@ -23,21 +26,9 @@ using namespace spdlog::sinks;
void bench_mt(int howmany, std::shared_ptr<spdlog::logger> log, int thread_count);
#ifdef _MSC_VER
#pragma warning(push)
#pragma warning(disable : 4996) // disable fopen warning under msvc
#endif // _MSC_VER
int count_lines(const char *filename) {
int counter = 0;
auto *infile = fopen(filename, "r");
int ch;
while (EOF != (ch = getc(infile))) {
if ('\n' == ch) counter++;
}
fclose(infile);
return counter;
std::ifstream ifs(filename);
return std::count(std::istreambuf_iterator(ifs), std::istreambuf_iterator<char>(), '\n');
}
void verify_file(const char *filename, int expected_count) {
@@ -54,7 +45,11 @@ void verify_file(const char *filename, int expected_count) {
#pragma warning(pop)
#endif
using namespace spdlog::sinks;
int main(int argc, char *argv[]) {
// setlocale to show thousands separators
std::locale::global(std::locale("en_US.UTF-8"));
int howmany = 1000000;
int queue_size = std::min(howmany + 2, 8192);
int threads = 10;
@@ -62,7 +57,7 @@ int main(int argc, char *argv[]) {
try {
spdlog::set_pattern("[%^%l%$] %v");
if (argc == 1) {
if (argc > 1 && (std::string(argv[1]) == "-h" || std::string(argv[1]) == "--help")) {
spdlog::info("Usage: {} <message_count> <threads> <q_size> <iterations>", argv[0]);
return 0;
}
@@ -78,8 +73,13 @@ int main(int argc, char *argv[]) {
}
if (argc > 4) iters = atoi(argv[4]);
// validate all argc values
if (howmany < 1 || threads < 1 || queue_size < 1 || iters < 1) {
spdlog::error("Invalid input values");
exit(1);
}
auto slot_size = sizeof(spdlog::details::async_msg);
auto slot_size = sizeof(details::async_log_msg);
spdlog::info("-------------------------------------------------");
spdlog::info("Messages : {:L}", howmany);
spdlog::info("Threads : {:L}", threads);
@@ -94,14 +94,17 @@ int main(int argc, char *argv[]) {
spdlog::info("Queue Overflow Policy: block");
spdlog::info("*********************************");
for (int i = 0; i < iters; i++) {
auto tp = std::make_shared<details::thread_pool>(queue_size, 1);
auto file_sink = std::make_shared<spdlog::sinks::basic_file_sink_mt>(filename, true);
auto logger =
std::make_shared<async_logger>("async_logger", std::move(file_sink), std::move(tp), async_overflow_policy::block);
bench_mt(howmany, std::move(logger), threads);
// verify_file(filename, howmany);
{
auto file_sink = std::make_shared<basic_file_sink_mt>(filename, true);
auto cfg = async_sink::config();
cfg.queue_size = queue_size;
cfg.sinks.push_back(std::move(file_sink));
auto async_sink = std::make_shared<sinks::async_sink>(cfg);
auto logger = std::make_shared<spdlog::logger>("async_logger", std::move(async_sink));
bench_mt(howmany, std::move(logger), threads);
}
//verify_file(filename, howmany); // in separate scope to ensure logger is destroyed and all logs were written
}
spdlog::info("");
spdlog::info("*********************************");
spdlog::info("Queue Overflow Policy: overrun");
@@ -109,10 +112,13 @@ int main(int argc, char *argv[]) {
// do same test but discard the oldest if queue is full instead of blocking
filename = "logs/basic_async-overrun.log";
for (int i = 0; i < iters; i++) {
auto tp = std::make_shared<details::thread_pool>(queue_size, 1);
auto file_sink = std::make_shared<spdlog::sinks::basic_file_sink_mt>(filename, true);
auto logger = std::make_shared<async_logger>("async_logger", std::move(file_sink), std::move(tp),
async_overflow_policy::overrun_oldest);
async_sink::config cfg;
cfg.policy = async_sink::overflow_policy::overrun_oldest;
cfg.queue_size = queue_size;
auto file_sink = std::make_shared<basic_file_sink_mt>(filename, true);
cfg.sinks.push_back(std::move(file_sink));
auto async_sink = std::make_shared<sinks::async_sink>(cfg);
auto logger = std::make_shared<spdlog::logger>("async_logger", std::move(async_sink));
bench_mt(howmany, std::move(logger), threads);
}
spdlog::shutdown();

View File

@@ -31,21 +31,22 @@ static const size_t file_size = 30 * 1024 * 1024;
static const size_t rotating_files = 5;
static const int max_threads = 1000;
using namespace spdlog::sinks;
void bench_threaded_logging(size_t threads, int iters) {
spdlog::info("**************************************************************");
spdlog::info(
spdlog::fmt_lib::format(std::locale("en_US.UTF-8"), "Multi threaded: {:L} threads, {:L} messages", threads, iters));
spdlog::info("**************************************************************");
auto basic_mt = spdlog::basic_logger_mt("basic_mt", "logs/basic_mt.log", true);
auto basic_mt = spdlog::create<basic_file_sink_mt>("basic_mt", "logs/basic_mt.log", true);
bench_mt(iters, std::move(basic_mt), threads);
spdlog::info("");
auto rotating_mt = spdlog::rotating_logger_mt("rotating_mt", "logs/rotating_mt.log", file_size, rotating_files);
auto rotating_mt = spdlog::create<rotating_file_sink_mt>("rotating_mt", "logs/rotating_mt.log", file_size, rotating_files);
bench_mt(iters, std::move(rotating_mt), threads);
spdlog::info("");
auto daily_mt = spdlog::daily_logger_mt("daily_mt", "logs/daily_mt.log");
auto daily_mt = spdlog::create<daily_file_sink_mt>("daily_mt", "logs/daily_mt.log", 0, 1);
bench_mt(iters, std::move(daily_mt), threads);
spdlog::info("");
@@ -59,15 +60,15 @@ void bench_single_threaded(int iters) {
spdlog::info(spdlog::fmt_lib::format(std::locale("en_US.UTF-8"), "Single threaded: {} messages", iters));
spdlog::info("**************************************************************");
auto basic_st = spdlog::basic_logger_st("basic_st", "logs/basic_st.log", true);
auto basic_st = spdlog::create<basic_file_sink_st>("basic_st", "logs/basic_st.log", true);
bench(iters, std::move(basic_st));
spdlog::info("");
auto rotating_st = spdlog::rotating_logger_st("rotating_st", "logs/rotating_st.log", file_size, rotating_files);
auto rotating_st = spdlog::create<rotating_file_sink_st>("rotating_st", "logs/rotating_st.log", file_size, rotating_files);
bench(iters, std::move(rotating_st));
spdlog::info("");
auto daily_st = spdlog::daily_logger_st("daily_st", "logs/daily_st.log");
auto daily_st = spdlog::create<daily_file_sink_st>("daily_st", "logs/daily_st.log", 0, 1);
bench(iters, std::move(daily_st));
spdlog::info("");

View File

@@ -8,13 +8,14 @@
//
#include "benchmark/benchmark.h"
#include "spdlog/async.h"
#include "spdlog/sinks/async_sink.h"
#include "spdlog/sinks/basic_file_sink.h"
#include "spdlog/sinks/daily_file_sink.h"
#include "spdlog/sinks/null_sink.h"
#include "spdlog/sinks/rotating_file_sink.h"
#include "spdlog/spdlog.h"
using namespace spdlog::sinks;
void bench_c_string(benchmark::State &state, std::shared_ptr<spdlog::logger> logger) {
const char *msg =
"Lorem ipsum dolor sit amet, consectetur adipiscing elit. Vestibulum pharetra metus cursus "
@@ -69,10 +70,10 @@ void bench_disabled_macro_global_logger(benchmark::State &state, std::shared_ptr
#ifdef __linux__
void bench_dev_null() {
auto dev_null_st = spdlog::basic_logger_st("/dev/null_st", "/dev/null");
auto dev_null_st = spdlog::create<basic_file_sink_st>("/dev/null_st", "/dev/null");
benchmark::RegisterBenchmark("/dev/null_st", bench_logger, std::move(dev_null_st))->UseRealTime();
auto dev_null_mt = spdlog::basic_logger_mt("/dev/null_mt", "/dev/null");
auto dev_null_mt = spdlog::create<basic_file_sink_mt>("/dev/null_mt", "/dev/null");
benchmark::RegisterBenchmark("/dev/null_mt", bench_logger, std::move(dev_null_mt))->UseRealTime();
}
@@ -85,7 +86,7 @@ static std::string prepare_null_loggers() {
const std::string some_logger_name = "Some logger name";
const int null_logger_count = 9;
for (int i = 0; i < null_logger_count; i++) {
spdlog::create<spdlog::sinks::null_sink_mt>(some_logger_name + std::to_string(i));
spdlog::create<null_sink_mt>(some_logger_name + std::to_string(i));
}
return some_logger_name + std::to_string(null_logger_count / 2);
}
@@ -119,15 +120,15 @@ int main(int argc, char *argv[]) {
if (full_bench) {
// basic_st
auto basic_st = spdlog::basic_logger_st("basic_st", "latency_logs/basic_st.log", true);
auto basic_st = spdlog::create<basic_file_sink_st>("basic_st", "latency_logs/basic_st.log", true);
benchmark::RegisterBenchmark("basic_st", bench_logger, std::move(basic_st))->UseRealTime();
// rotating st
auto rotating_st = spdlog::rotating_logger_st("rotating_st", "latency_logs/rotating_st.log", file_size, rotating_files);
auto rotating_st = spdlog::create<rotating_file_sink_st>("rotating_st", "latency_logs/rotating_st.log", file_size, rotating_files);
benchmark::RegisterBenchmark("rotating_st", bench_logger, std::move(rotating_st))->UseRealTime();
// daily st
auto daily_st = spdlog::daily_logger_mt("daily_st", "latency_logs/daily_st.log");
auto daily_st = spdlog::create<daily_file_sink_st>("daily_st", "latency_logs/daily_st.log", 0, 1);
benchmark::RegisterBenchmark("daily_st", bench_logger, std::move(daily_st))->UseRealTime();
//
@@ -137,23 +138,23 @@ int main(int argc, char *argv[]) {
benchmark::RegisterBenchmark("null_sink_mt", bench_logger, null_logger_mt)->Threads(n_threads)->UseRealTime();
// basic_mt
auto basic_mt = spdlog::basic_logger_mt("basic_mt", "latency_logs/basic_mt.log", true);
auto basic_mt = spdlog::create<basic_file_sink_mt>("basic_mt", "latency_logs/basic_mt.log", true);
benchmark::RegisterBenchmark("basic_mt", bench_logger, std::move(basic_mt))->Threads(n_threads)->UseRealTime();
// rotating mt
auto rotating_mt = spdlog::rotating_logger_mt("rotating_mt", "latency_logs/rotating_mt.log", file_size, rotating_files);
auto rotating_mt = spdlog::create<rotating_file_sink_mt>("rotating_mt", "latency_logs/rotating_mt.log", file_size, rotating_files);
benchmark::RegisterBenchmark("rotating_mt", bench_logger, std::move(rotating_mt))->Threads(n_threads)->UseRealTime();
// daily mt
auto daily_mt = spdlog::daily_logger_mt("daily_mt", "latency_logs/daily_mt.log");
auto daily_mt = spdlog::create<daily_file_sink_mt>("daily_mt", "latency_logs/daily_mt.log", 0, 1);
benchmark::RegisterBenchmark("daily_mt", bench_logger, std::move(daily_mt))->Threads(n_threads)->UseRealTime();
}
// async
auto queue_size = 1024 * 1024 * 3;
auto tp = std::make_shared<spdlog::details::thread_pool>(queue_size, 1);
auto async_logger = std::make_shared<spdlog::async_logger>("async_logger", std::make_shared<null_sink_mt>(), std::move(tp),
spdlog::async_overflow_policy::overrun_oldest);
using spdlog::sinks::async_sink;
async_sink::config config;
config.queue_size = 3 * 1024 * 1024;;
config.sinks.push_back(std::make_shared<null_sink_st>());
config.policy = async_sink::overflow_policy::overrun_oldest;
auto async_logger = std::make_shared<spdlog::logger>("async_logger", std::make_shared<async_sink>(config));
benchmark::RegisterBenchmark("async_logger", bench_logger, async_logger)->Threads(n_threads)->UseRealTime();
benchmark::Initialize(&argc, argv);