spdlog/bench/async_bench.cpp

186 lines
5.8 KiB
C++
Raw Normal View History

2018-08-05 05:14:01 +08:00
//
// Copyright(c) 2015 Gabi Melman.
// Distributed under the MIT License (http://opensource.org/licenses/MIT)
//
//
// bench.cpp : spdlog benchmarks
//
2018-10-12 08:04:55 +08:00
#include "spdlog/spdlog.h"
2018-08-05 05:14:01 +08:00
#include "spdlog/async.h"
#include "spdlog/sinks/basic_file_sink.h"
#ifdef SPDLOG_FMT_EXTERNAL
#include <fmt/locale.h>
#else
2020-08-26 05:02:09 +08:00
#include "spdlog/fmt/bundled/locale.h"
#endif
2018-10-12 08:04:55 +08:00
2018-08-05 05:14:01 +08:00
#include "utils.h"
#include <atomic>
#include <iostream>
#include <memory>
#include <string>
#include <thread>
using namespace std;
using namespace std::chrono;
using namespace spdlog;
using namespace spdlog::sinks;
using namespace utils;
void bench_mt(int howmany, std::shared_ptr<spdlog::logger> log, int thread_count);
2019-06-06 23:13:30 +08:00
#ifdef _MSC_VER
2019-06-14 05:23:51 +08:00
#pragma warning(push)
#pragma warning(disable : 4996) // disable fopen warning under msvc
2020-09-26 20:34:05 +08:00
#endif // _MSC_VER
2019-06-06 23:13:30 +08:00
2018-08-05 05:14:01 +08:00
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++;
}
2018-10-05 19:52:38 +08:00
fclose(infile);
2018-08-05 05:14:01 +08:00
return counter;
}
void verify_file(const char *filename, int expected_count)
{
2020-08-26 05:02:09 +08:00
spdlog::info("Verifying {} to contain {} line..", filename, expected_count);
auto count = count_lines(filename);
if (count != expected_count)
{
2020-08-26 05:02:09 +08:00
spdlog::error("Test failed. {} has {} lines instead of {}", filename, count, expected_count);
exit(1);
}
2020-08-26 05:02:09 +08:00
spdlog::info("Line count OK ({})\n", count);
}
2019-06-06 23:13:30 +08:00
#ifdef _MSC_VER
2019-06-14 05:23:51 +08:00
#pragma warning(pop)
2019-06-06 23:13:30 +08:00
#endif
2018-08-05 05:14:01 +08:00
int main(int argc, char *argv[])
{
int howmany = 1000000;
int queue_size = std::min(howmany + 2, 8192);
2018-08-05 05:14:01 +08:00
int threads = 10;
int iters = 3;
try
{
spdlog::set_pattern("[%^%l%$] %v");
2018-08-05 05:14:01 +08:00
if (argc == 1)
{
2018-10-17 00:31:25 +08:00
spdlog::info("Usage: {} <message_count> <threads> <q_size> <iterations>", argv[0]);
2018-08-05 05:14:01 +08:00
return 0;
}
if (argc > 1)
howmany = atoi(argv[1]);
if (argc > 2)
threads = atoi(argv[2]);
if (argc > 3)
{
2018-08-05 05:14:01 +08:00
queue_size = atoi(argv[3]);
2019-06-04 05:09:16 +08:00
if (queue_size > 500000)
{
spdlog::error("Max queue size allowed: 500,000");
exit(1);
}
}
2018-08-05 05:14:01 +08:00
if (argc > 4)
iters = atoi(argv[4]);
auto slot_size = sizeof(spdlog::details::async_msg);
2018-10-17 00:31:25 +08:00
spdlog::info("-------------------------------------------------");
2020-08-26 05:02:09 +08:00
spdlog::info(fmt::format(std::locale("en_US.UTF-8"), "Messages : {:L}", howmany));
spdlog::info(fmt::format(std::locale("en_US.UTF-8"), "Threads : {:L}", threads));
spdlog::info(fmt::format(std::locale("en_US.UTF-8"), "Queue : {:L} slots", queue_size));
spdlog::info(fmt::format(
std::locale("en_US.UTF-8"), "Queue memory : {:L} x {:L} = {:L} KB ", queue_size, slot_size, (queue_size * slot_size) / 1024));
spdlog::info(fmt::format(std::locale("en_US.UTF-8"), "Total iters : {:L}", iters));
2018-10-17 00:31:25 +08:00
spdlog::info("-------------------------------------------------");
2018-08-05 05:14:01 +08:00
const char *filename = "logs/basic_async.log";
spdlog::info("");
spdlog::info("*********************************");
spdlog::info("Queue Overflow Policy: block");
spdlog::info("*********************************");
2018-08-05 05:14:01 +08:00
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);
2019-08-28 01:22:07 +08:00
// verify_file(filename, howmany);
}
2018-08-05 05:14:01 +08:00
spdlog::info("");
spdlog::info("*********************************");
spdlog::info("Queue Overflow Policy: overrun");
spdlog::info("*********************************");
// do same test but discard oldest if queue is full instead of blocking
2019-08-26 05:53:52 +08:00
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);
2019-06-14 05:23:51 +08:00
auto logger =
std::make_shared<async_logger>("async_logger", std::move(file_sink), std::move(tp), async_overflow_policy::overrun_oldest);
bench_mt(howmany, std::move(logger), threads);
2018-08-05 05:14:01 +08:00
}
2018-10-30 07:08:32 +08:00
spdlog::shutdown();
2018-08-05 05:14:01 +08:00
}
catch (std::exception &ex)
{
std::cerr << "Error: " << ex.what() << std::endl;
perror("Last error");
return 1;
}
return 0;
}
2018-08-05 06:25:40 +08:00
void thread_fun(std::shared_ptr<spdlog::logger> logger, int howmany)
{
for (int i = 0; i < howmany; i++)
{
logger->info("Hello logger: msg number {}", i);
}
}
void bench_mt(int howmany, std::shared_ptr<spdlog::logger> logger, int thread_count)
2018-08-05 05:14:01 +08:00
{
using std::chrono::high_resolution_clock;
vector<thread> threads;
auto start = high_resolution_clock::now();
2018-08-05 06:25:40 +08:00
int msgs_per_thread = howmany / thread_count;
int msgs_per_thread_mod = howmany % thread_count;
2018-08-05 05:14:01 +08:00
for (int t = 0; t < thread_count; ++t)
{
2018-08-05 06:25:40 +08:00
if (t == 0 && msgs_per_thread_mod)
threads.push_back(std::thread(thread_fun, logger, msgs_per_thread + msgs_per_thread_mod));
else
threads.push_back(std::thread(thread_fun, logger, msgs_per_thread));
2018-08-05 05:14:01 +08:00
}
for (auto &t : threads)
{
t.join();
};
auto delta = high_resolution_clock::now() - start;
auto delta_d = duration_cast<duration<double>>(delta).count();
2020-08-26 05:02:09 +08:00
spdlog::info(fmt::format(std::locale("en_US.UTF-8"), "Elapsed: {} secs\t {:L}/sec", delta_d, int(howmany / delta_d)));
2018-08-05 05:14:01 +08:00
}