spdlog/bench/bench.cpp

205 lines
7.9 KiB
C++
Raw Normal View History

2015-11-28 11:24:20 -05:00
//
// Copyright(c) 2015 Gabi Melman.
// Distributed under the MIT License (http://opensource.org/licenses/MIT)
//
2014-10-31 21:20:54 -04:00
2014-10-10 18:15:26 -04:00
//
2014-10-31 10:34:48 -04:00
// bench.cpp : spdlog benchmarks
//
2018-10-11 20:04:55 -04:00
#include "spdlog/spdlog.h"
2018-04-13 20:34:57 -04:00
#include "spdlog/async.h"
2018-07-07 06:22:43 -04:00
#include "spdlog/sinks/basic_file_sink.h"
2018-04-28 18:26:10 -04:00
#include "spdlog/sinks/daily_file_sink.h"
2018-03-09 08:26:33 -05:00
#include "spdlog/sinks/null_sink.h"
2018-04-28 18:36:45 -04:00
#include "spdlog/sinks/rotating_file_sink.h"
2018-10-11 20:04:55 -04:00
2018-03-09 08:26:33 -05:00
#include "utils.h"
#include <atomic>
#include <cstdlib> // EXIT_FAILURE
2014-10-31 10:34:48 -04:00
#include <memory>
#include <string>
#include <thread>
using namespace std;
2014-10-10 18:15:26 -04:00
using namespace std::chrono;
using namespace spdlog;
2014-10-31 10:34:48 -04:00
using namespace spdlog::sinks;
2014-10-10 18:15:26 -04:00
using namespace utils;
2014-10-31 20:12:12 -04:00
void bench(int howmany, std::shared_ptr<spdlog::logger> log);
void bench_mt(int howmany, std::shared_ptr<spdlog::logger> log, int thread_count);
2018-10-13 12:23:11 -04:00
void bench_default_api(int howmany, std::shared_ptr<spdlog::logger> log);
void bench_c_string(int howmany, std::shared_ptr<spdlog::logger> log);
2014-12-07 11:49:34 -05:00
2018-03-09 08:26:33 -05:00
int main(int argc, char *argv[])
2014-10-10 18:15:26 -04:00
{
2014-10-25 19:29:50 -04:00
2018-10-16 09:11:28 -04:00
spdlog::default_logger()->set_pattern("[%^%l%$] %v");
2018-09-24 18:22:28 -04:00
int howmany = 1000000;
int queue_size = 8192;
int threads = 10;
size_t file_size = 30 * 1024 * 1024;
size_t rotating_files = 5;
2014-12-20 19:47:04 -05:00
try
{
2018-03-09 08:26:33 -05:00
if (argc > 1)
2014-12-20 19:47:04 -05:00
howmany = atoi(argv[1]);
if (argc > 2)
2018-03-09 08:26:33 -05:00
threads = atoi(argv[2]);
if (argc > 3)
queue_size = atoi(argv[3]);
2018-04-28 18:36:45 -04:00
2018-10-16 09:11:28 -04:00
spdlog::info("**************************************************************");
spdlog::info("Single thread, {:n} iterations", howmany);
spdlog::info("**************************************************************");
auto basic_st = spdlog::basic_logger_st("basic_st", "logs/basic_st.log", true);
2018-10-13 12:23:11 -04:00
bench(howmany, std::move(basic_st));
2018-10-13 12:23:11 -04:00
basic_st.reset();
2018-09-24 18:22:28 -04:00
auto rotating_st = spdlog::rotating_logger_st("rotating_st", "logs/rotating_st.log", file_size, rotating_files);
2018-10-13 12:23:11 -04:00
bench(howmany, std::move(rotating_st));
2018-03-09 05:08:56 -05:00
auto daily_st = spdlog::daily_logger_st("daily_st", "logs/daily_st.log");
2018-10-13 12:23:11 -04:00
bench(howmany, std::move(daily_st));
2018-07-05 09:19:23 -04:00
2019-06-01 08:00:14 -04:00
bench(howmany, std::make_shared<spdlog::logger>("empty_logger"));
2014-12-20 19:47:04 -05:00
spdlog::info("**************************************************************");
2018-11-22 09:58:20 -05:00
spdlog::info("C-string (400 bytes). Single thread, {:n} iterations", howmany);
spdlog::info("**************************************************************");
basic_st = spdlog::basic_logger_st("basic_st", "logs/basic_cs.log", true);
bench_c_string(howmany, std::move(basic_st));
rotating_st = spdlog::rotating_logger_st("rotating_st", "logs/rotating_cs.log", file_size, rotating_files);
bench_c_string(howmany, std::move(rotating_st));
daily_st = spdlog::daily_logger_st("daily_st", "logs/daily_cs.log");
bench_c_string(howmany, std::move(daily_st));
bench_c_string(howmany, spdlog::create<null_sink_st>("null_st"));
2018-10-16 09:11:28 -04:00
spdlog::info("**************************************************************");
spdlog::info("{:n} threads sharing same logger, {:n} iterations", threads, howmany);
spdlog::info("**************************************************************");
2014-12-20 19:47:04 -05:00
2018-07-05 09:19:23 -04:00
auto basic_mt = spdlog::basic_logger_mt("basic_mt", "logs/basic_mt.log", true);
2018-10-13 12:23:11 -04:00
bench_mt(howmany, std::move(basic_mt), threads);
2018-07-05 09:19:23 -04:00
2018-03-09 05:08:56 -05:00
auto rotating_mt = spdlog::rotating_logger_mt("rotating_mt", "logs/rotating_mt.log", file_size, rotating_files);
2018-10-13 12:23:11 -04:00
bench_mt(howmany, std::move(rotating_mt), threads);
2014-12-20 19:47:04 -05:00
2018-03-09 05:08:56 -05:00
auto daily_mt = spdlog::daily_logger_mt("daily_mt", "logs/daily_mt.log");
2018-10-13 12:23:11 -04:00
bench_mt(howmany, std::move(daily_mt), threads);
2018-07-10 16:53:00 -04:00
bench_mt(howmany, spdlog::create<null_sink_mt>("null_mt"), threads);
int iters = 3;
2018-10-16 09:11:28 -04:00
spdlog::info("**************************************************************");
spdlog::info("Asyncronous bench {:n} threads sharing same logger", threads);
spdlog::info("Messages: {:n}", howmany);
spdlog::info("Queue size: {:n} slots", queue_size);
auto slot_size = sizeof(spdlog::details::async_msg);
2019-06-03 17:09:16 -04:00
spdlog::info("Total queue memory: {}x{} bytes per slot = {:n} Kb ", queue_size, slot_size, (queue_size * slot_size) / 1024);
2018-10-16 09:11:28 -04:00
spdlog::info("**************************************************************");
2018-06-01 10:52:05 -04:00
for (int i = 0; i < iters; ++i)
2014-12-20 19:47:04 -05:00
{
spdlog::init_thread_pool(static_cast<size_t>(queue_size), 1);
2018-07-08 09:46:12 -04:00
auto as = spdlog::basic_logger_mt<spdlog::async_factory>("async", "logs/basic_async.log", true);
2018-10-13 12:23:11 -04:00
bench_mt(howmany, std::move(as), threads);
2014-12-20 19:47:04 -05:00
}
}
catch (std::exception &ex)
{
2018-10-16 09:11:28 -04:00
spdlog::error(ex.what());
return EXIT_FAILURE;
2014-12-20 19:47:04 -05:00
}
return EXIT_SUCCESS;
2014-10-10 18:15:26 -04:00
}
2014-10-31 20:12:12 -04:00
void bench(int howmany, std::shared_ptr<spdlog::logger> log)
{
2018-07-05 09:19:23 -04:00
using std::chrono::high_resolution_clock;
auto start = high_resolution_clock::now();
2014-12-20 19:47:04 -05:00
for (auto i = 0; i < howmany; ++i)
{
2018-09-24 18:22:28 -04:00
log->info("Hello logger: msg number {}", i);
2014-12-20 19:47:04 -05:00
}
2014-10-31 20:12:12 -04:00
2018-07-05 09:19:23 -04:00
auto delta = high_resolution_clock::now() - start;
2018-03-09 08:26:33 -05:00
auto delta_d = duration_cast<duration<double>>(delta).count();
2018-10-16 09:11:28 -04:00
spdlog::info("{:<16} Elapsed: {:0.2f} secs {:>16n}/sec", log->name(), delta_d, int(howmany / delta_d));
spdlog::drop(log->name());
2014-10-31 20:12:12 -04:00
}
void bench_mt(int howmany, std::shared_ptr<spdlog::logger> log, int thread_count)
{
2018-07-05 09:19:23 -04:00
using std::chrono::high_resolution_clock;
2014-12-20 19:47:04 -05:00
vector<thread> threads;
2018-07-05 09:19:23 -04:00
auto start = high_resolution_clock::now();
2014-12-20 19:47:04 -05:00
for (int t = 0; t < thread_count; ++t)
{
2018-03-09 08:26:33 -05:00
threads.push_back(std::thread([&]() {
2018-07-07 06:22:43 -04:00
for (int j = 0; j < howmany / thread_count; j++)
2014-12-20 19:47:04 -05:00
{
2018-07-05 09:19:23 -04:00
log->info("Hello logger: msg number {}", j);
2014-12-20 19:47:04 -05:00
}
}));
}
2018-03-09 08:26:33 -05:00
for (auto &t : threads)
2014-12-20 19:47:04 -05:00
{
t.join();
};
2018-07-07 06:22:43 -04:00
auto delta = high_resolution_clock::now() - start;
2018-03-09 08:26:33 -05:00
auto delta_d = duration_cast<duration<double>>(delta).count();
2018-10-16 09:11:28 -04:00
spdlog::info("{:<16} Elapsed: {:0.2f} secs {:>16n}/sec", log->name(), delta_d, int(howmany / delta_d));
spdlog::drop(log->name());
2018-10-13 12:23:11 -04:00
}
void bench_default_api(int howmany, std::shared_ptr<spdlog::logger> log)
{
using std::chrono::high_resolution_clock;
2018-10-16 09:11:28 -04:00
auto orig_default = spdlog::default_logger();
2018-10-13 12:23:11 -04:00
spdlog::set_default_logger(log);
auto start = high_resolution_clock::now();
for (auto i = 0; i < howmany; ++i)
{
spdlog::info("Hello logger: msg number {}", i);
}
auto delta = high_resolution_clock::now() - start;
auto delta_d = duration_cast<duration<double>>(delta).count();
2018-10-16 09:11:28 -04:00
spdlog::drop(log->name());
spdlog::set_default_logger(std::move(orig_default));
spdlog::info("{:<16} Elapsed: {:0.2f} secs {:>16n}/sec", log->name(), delta_d, int(howmany / delta_d));
2014-10-31 20:12:12 -04:00
}
void bench_c_string(int howmany, std::shared_ptr<spdlog::logger> log)
{
2018-10-19 10:12:35 -04:00
const char *msg = "Lorem ipsum dolor sit amet, consectetur adipiscing elit. Vestibulum pharetra metus cursus "
"lacus placerat congue. Nulla egestas, mauris a tincidunt tempus, enim lectus volutpat mi, eu consequat sem "
"libero nec massa. In dapibus ipsum a diam rhoncus gravida. Etiam non dapibus eros. Donec fringilla dui sed "
"augue pretium, nec scelerisque est maximus. Nullam convallis, sem nec blandit maximus, nisi turpis ornare "
"nisl, sit amet volutpat neque massa eu odio. Maecenas malesuada quam ex, posuere congue nibh turpis duis.";
using std::chrono::high_resolution_clock;
auto orig_default = spdlog::default_logger();
spdlog::set_default_logger(log);
auto start = high_resolution_clock::now();
for (auto i = 0; i < howmany; ++i)
{
spdlog::log(level::info, msg);
}
auto delta = high_resolution_clock::now() - start;
auto delta_d = duration_cast<duration<double>>(delta).count();
spdlog::drop(log->name());
spdlog::set_default_logger(std::move(orig_default));
spdlog::info("{:<16} Elapsed: {:0.2f} secs {:>16n}/sec", log->name(), delta_d, int(howmany / delta_d));
}