use spdlog for logging in ws + unittest + remove un-needed mutex

This commit is contained in:
Benjamin Sergeant
2019-05-09 15:30:44 -07:00
parent 234ce4c173
commit c7f0bf3d64
114 changed files with 29168 additions and 6 deletions

48
third_party/spdlog/bench/CMakeLists.txt vendored Normal file
View File

@ -0,0 +1,48 @@
# *************************************************************************/
# * Copyright (c) 2015 Ruslan Baratov. */
# * */
# * Permission is hereby granted, free of charge, to any person obtaining */
# * a copy of this software and associated documentation files (the */
# * "Software"), to deal in the Software without restriction, including */
# * without limitation the rights to use, copy, modify, merge, publish, */
# * distribute, sublicense, and/or sell copies of the Software, and to */
# * permit persons to whom the Software is furnished to do so, subject to */
# * the following conditions: */
# * */
# * The above copyright notice and this permission notice shall be */
# * included in all copies or substantial portions of the Software. */
# * */
# * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, */
# * EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF */
# * MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT.*/
# * IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY */
# * CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION OF CONTRACT, */
# * TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION WITH THE */
# * SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE. */
# *************************************************************************/
cmake_minimum_required(VERSION 3.1)
project(SpdlogBench CXX)
if(NOT TARGET spdlog)
# Stand-alone build
find_package(spdlog CONFIG REQUIRED)
endif()
find_package(Threads REQUIRED)
find_package(benchmark CONFIG REQUIRED)
add_executable(bench bench.cpp)
target_link_libraries(bench PRIVATE spdlog::spdlog Threads::Threads)
add_executable(async_bench async_bench.cpp)
target_link_libraries(async_bench PRIVATE spdlog::spdlog Threads::Threads)
add_executable(latency latency.cpp)
target_link_libraries(latency PRIVATE benchmark::benchmark spdlog::spdlog Threads::Threads)
add_executable(formatter-bench formatter-bench.cpp)
target_link_libraries(formatter-bench PRIVATE benchmark::benchmark spdlog::spdlog Threads::Threads)
file(MAKE_DIRECTORY "${CMAKE_CURRENT_BINARY_DIR}/logs")

141
third_party/spdlog/bench/async_bench.cpp vendored Normal file
View File

@ -0,0 +1,141 @@
//
// Copyright(c) 2015 Gabi Melman.
// Distributed under the MIT License (http://opensource.org/licenses/MIT)
//
//
// bench.cpp : spdlog benchmarks
//
#include "spdlog/spdlog.h"
#include "spdlog/async.h"
#include "spdlog/sinks/basic_file_sink.h"
#include "spdlog/sinks/stdout_color_sinks.h"
#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);
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;
}
int main(int argc, char *argv[])
{
int howmany = 1000000;
int queue_size = howmany + 2;
int threads = 10;
int iters = 3;
try
{
if (argc == 1)
{
spdlog::set_pattern("%v");
spdlog::info("Usage: {} <message_count> <threads> <q_size> <iterations>", argv[0]);
return 0;
}
if (argc > 1)
howmany = atoi(argv[1]);
if (argc > 2)
threads = atoi(argv[2]);
if (argc > 3)
queue_size = atoi(argv[3]);
if (argc > 4)
iters = atoi(argv[4]);
spdlog::info("-------------------------------------------------");
spdlog::info("Messages: {:14n}", howmany);
spdlog::info("Threads : {:14n}", threads);
spdlog::info("Queue : {:14n}", queue_size);
spdlog::info("Iters : {:>14n}", iters);
spdlog::info("-------------------------------------------------");
const char *filename = "logs/basic_async.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::block);
bench_mt(howmany, std::move(logger), threads);
auto count = count_lines(filename);
if (count != howmany)
{
spdlog::error("Test failed. {} has {:n} lines instead of {:n}", filename, count, howmany);
exit(1);
}
else
{
spdlog::info("Line count OK ({:n})\n", count);
}
}
spdlog::shutdown();
}
catch (std::exception &ex)
{
std::cerr << "Error: " << ex.what() << std::endl;
perror("Last error");
return 1;
}
return 0;
}
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)
{
using std::chrono::high_resolution_clock;
vector<thread> threads;
auto start = high_resolution_clock::now();
int msgs_per_thread = howmany / thread_count;
int msgs_per_thread_mod = howmany % thread_count;
for (int t = 0; t < thread_count; ++t)
{
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));
}
for (auto &t : threads)
{
t.join();
};
auto delta = high_resolution_clock::now() - start;
auto delta_d = duration_cast<duration<double>>(delta).count();
spdlog::info("Elapsed: {} secs\t {:n}/sec", delta_d, int(howmany / delta_d));
}

199
third_party/spdlog/bench/bench.cpp vendored Normal file
View File

@ -0,0 +1,199 @@
//
// Copyright(c) 2015 Gabi Melman.
// Distributed under the MIT License (http://opensource.org/licenses/MIT)
//
//
// bench.cpp : spdlog benchmarks
//
#include "spdlog/spdlog.h"
#include "spdlog/async.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 "utils.h"
#include <atomic>
#include <cstdlib> // EXIT_FAILURE
#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(int howmany, std::shared_ptr<spdlog::logger> log);
void bench_mt(int howmany, std::shared_ptr<spdlog::logger> log, int thread_count);
void bench_default_api(int howmany, std::shared_ptr<spdlog::logger> log);
void bench_c_string(int howmany, std::shared_ptr<spdlog::logger> log);
int main(int argc, char *argv[])
{
spdlog::default_logger()->set_pattern("[%^%l%$] %v");
int howmany = 1000000;
int queue_size = howmany + 2;
int threads = 10;
size_t file_size = 30 * 1024 * 1024;
size_t rotating_files = 5;
try
{
if (argc > 1)
howmany = atoi(argv[1]);
if (argc > 2)
threads = atoi(argv[2]);
if (argc > 3)
queue_size = atoi(argv[3]);
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);
bench(howmany, std::move(basic_st));
basic_st.reset();
auto rotating_st = spdlog::rotating_logger_st("rotating_st", "logs/rotating_st.log", file_size, rotating_files);
bench(howmany, std::move(rotating_st));
auto daily_st = spdlog::daily_logger_st("daily_st", "logs/daily_st.log");
bench(howmany, std::move(daily_st));
bench(howmany, spdlog::create<null_sink_st>("null_st"));
spdlog::info("**************************************************************");
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"));
spdlog::info("**************************************************************");
spdlog::info("{:n} threads sharing same logger, {:n} iterations", threads, howmany);
spdlog::info("**************************************************************");
auto basic_mt = spdlog::basic_logger_mt("basic_mt", "logs/basic_mt.log", true);
bench_mt(howmany, std::move(basic_mt), threads);
auto rotating_mt = spdlog::rotating_logger_mt("rotating_mt", "logs/rotating_mt.log", file_size, rotating_files);
bench_mt(howmany, std::move(rotating_mt), threads);
auto daily_mt = spdlog::daily_logger_mt("daily_mt", "logs/daily_mt.log");
bench_mt(howmany, std::move(daily_mt), threads);
bench_mt(howmany, spdlog::create<null_sink_mt>("null_mt"), threads);
spdlog::info("**************************************************************");
spdlog::info("Asyncronous.. {:n} threads sharing same logger, {:n} iterations", threads, howmany);
spdlog::info("**************************************************************");
for (int i = 0; i < 3; ++i)
{
spdlog::init_thread_pool(static_cast<size_t>(queue_size), 1);
auto as = spdlog::basic_logger_mt<spdlog::async_factory>("async", "logs/basic_async.log", true);
bench_mt(howmany, std::move(as), threads);
}
}
catch (std::exception &ex)
{
spdlog::error(ex.what());
return EXIT_FAILURE;
}
return EXIT_SUCCESS;
}
void bench(int howmany, std::shared_ptr<spdlog::logger> log)
{
using std::chrono::high_resolution_clock;
auto start = high_resolution_clock::now();
for (auto i = 0; i < howmany; ++i)
{
log->info("Hello logger: msg number {}", i);
}
auto delta = high_resolution_clock::now() - start;
auto delta_d = duration_cast<duration<double>>(delta).count();
spdlog::info("{:<16} Elapsed: {:0.2f} secs {:>16n}/sec", log->name(), delta_d, int(howmany / delta_d));
spdlog::drop(log->name());
}
void bench_mt(int howmany, std::shared_ptr<spdlog::logger> log, int thread_count)
{
using std::chrono::high_resolution_clock;
vector<thread> threads;
auto start = high_resolution_clock::now();
for (int t = 0; t < thread_count; ++t)
{
threads.push_back(std::thread([&]() {
for (int j = 0; j < howmany / thread_count; j++)
{
log->info("Hello logger: msg number {}", j);
}
}));
}
for (auto &t : threads)
{
t.join();
};
auto delta = high_resolution_clock::now() - start;
auto delta_d = duration_cast<duration<double>>(delta).count();
spdlog::info("{:<16} Elapsed: {:0.2f} secs {:>16n}/sec", log->name(), delta_d, int(howmany / delta_d));
spdlog::drop(log->name());
}
void bench_default_api(int howmany, std::shared_ptr<spdlog::logger> log)
{
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::info("Hello logger: msg number {}", i);
}
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));
}
void bench_c_string(int howmany, std::shared_ptr<spdlog::logger> log)
{
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));
}

View File

@ -0,0 +1,92 @@
//
// Copyright(c) 2018 Gabi Melman.
// Distributed under the MIT License (http://opensource.org/licenses/MIT)
//
#include "benchmark/benchmark.h"
#include "spdlog/spdlog.h"
#include "spdlog/details/pattern_formatter.h"
void bench_scoped_pad(benchmark::State &state, size_t wrapped_size, spdlog::details::padding_info padinfo)
{
fmt::memory_buffer dest;
for (auto _ : state)
{
{
spdlog::details::scoped_pad p(wrapped_size, padinfo, dest);
benchmark::DoNotOptimize(p);
dest.clear();
}
}
}
void bench_formatter(benchmark::State &state, std::string pattern)
{
auto formatter = spdlog::details::make_unique<spdlog::pattern_formatter>(pattern);
fmt::memory_buffer dest;
std::string logger_name = "logger-name";
const char *text = "Hello. This is some message with length of 80 ";
spdlog::details::log_msg msg(&logger_name, spdlog::level::info, text);
for (auto _ : state)
{
dest.clear();
formatter->format(msg, dest);
benchmark::DoNotOptimize(dest);
}
}
void bench_formatters()
{
// basic patterns(single flag)
std::string all_flags = "+vtPnlLaAbBcCYDmdHIMSefFprRTXzEi%";
std::vector<std::string> basic_patterns;
for (auto &flag : all_flags)
{
auto pattern = std::string("%") + flag;
benchmark::RegisterBenchmark(pattern.c_str(), bench_formatter, pattern);
// pattern = std::string("%16") + flag;
// benchmark::RegisterBenchmark(pattern.c_str(), bench_formatter, pattern);
//
// // bench center padding
// pattern = std::string("%=16") + flag;
// benchmark::RegisterBenchmark(pattern.c_str(), bench_formatter, pattern);
}
// complex patterns
std::vector<std::string> patterns = {
"[%D %X] [%l] [%n] %v",
"[%Y-%m-%d %H:%M:%S.%e] [%l] [%n] %v",
"[%Y-%m-%d %H:%M:%S.%e] [%l] [%n] [%t] %v",
};
for (auto &pattern : patterns)
{
benchmark::RegisterBenchmark(pattern.c_str(), bench_formatter, pattern)->Iterations(2500000);
}
}
int main(int argc, char *argv[])
{
spdlog::set_pattern("[%^%l%$] %v");
if (argc != 2)
{
spdlog::error("Usage: {} <pattern> (or \"all\" to bench all)", argv[0]);
exit(1);
}
std::string pattern = argv[1];
if (pattern == "all")
{
bench_formatters();
}
else
{
benchmark::RegisterBenchmark(pattern.c_str(), bench_formatter, pattern);
}
benchmark::Initialize(&argc, argv);
benchmark::RunSpecifiedBenchmarks();
}

143
third_party/spdlog/bench/latency.cpp vendored Normal file
View File

@ -0,0 +1,143 @@
//
// Copyright(c) 2018 Gabi Melman.
// Distributed under the MIT License (http://opensource.org/licenses/MIT)
//
//
// latency.cpp : spdlog latency benchmarks
//
#include "benchmark/benchmark.h"
#include "spdlog/spdlog.h"
#include "spdlog/async.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"
void prepare_logdir()
{
spdlog::info("Preparing latency_logs directory..");
#ifdef _WIN32
system("if not exist logs mkdir latency_logs");
system("del /F /Q logs\\*");
#else
auto rv = system("mkdir -p latency_logs");
if (rv != 0)
{
throw std::runtime_error("Failed to mkdir -p latency_logs");
}
rv = system("rm -f latency_logs/*");
if (rv != 0)
{
throw std::runtime_error("Failed to rm -f latency_logs/*");
}
#endif
}
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 "
"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.";
for (auto _ : state)
{
logger->info(msg);
}
}
void bench_logger(benchmark::State &state, std::shared_ptr<spdlog::logger> logger)
{
int i = 0;
for (auto _ : state)
{
logger->info("Hello logger: msg number {}...............", ++i);
}
}
void bench_disabled_macro(benchmark::State &state, std::shared_ptr<spdlog::logger> logger)
{
int i = 0;
benchmark::DoNotOptimize(i); // prevent unused warnings
benchmark::DoNotOptimize(logger); // prevent unused warnings
for (auto _ : state)
{
SPDLOG_LOGGER_DEBUG(logger, "Hello logger: msg number {}...............", i++);
SPDLOG_DEBUG("Hello logger: msg number {}...............", i++);
}
}
int main(int argc, char *argv[])
{
using spdlog::sinks::basic_file_sink_mt;
using spdlog::sinks::basic_file_sink_st;
using spdlog::sinks::null_sink_mt;
using spdlog::sinks::null_sink_st;
size_t file_size = 30 * 1024 * 1024;
size_t rotating_files = 5;
int n_threads = benchmark::CPUInfo::Get().num_cpus;
prepare_logdir();
// disabled loggers
auto disabled_logger = std::make_shared<spdlog::logger>("bench", std::make_shared<null_sink_mt>());
disabled_logger->set_level(spdlog::level::off);
benchmark::RegisterBenchmark("disabled-at-compile-time", bench_disabled_macro, disabled_logger);
benchmark::RegisterBenchmark("disabled-at-runtime", bench_logger, disabled_logger);
auto null_logger_st = std::make_shared<spdlog::logger>("bench", std::make_shared<null_sink_st>());
benchmark::RegisterBenchmark("null_sink_st (500_bytes c_str)", bench_c_string, std::move(null_logger_st));
benchmark::RegisterBenchmark("null_sink_st", bench_logger, null_logger_st);
// basic_st
auto basic_st = spdlog::basic_logger_st("basic_st", "latency_logs/basic_st.log", true);
benchmark::RegisterBenchmark("basic_st", bench_logger, std::move(basic_st))->UseRealTime();
spdlog::drop("basic_st");
// rotating st
auto rotating_st = spdlog::rotating_logger_st("rotating_st", "latency_logs/rotating_st.log", file_size, rotating_files);
benchmark::RegisterBenchmark("rotating_st", bench_logger, std::move(rotating_st))->UseRealTime();
spdlog::drop("rotating_st");
// daily st
auto daily_st = spdlog::daily_logger_mt("daily_st", "latency_logs/daily_st.log");
benchmark::RegisterBenchmark("daily_st", bench_logger, std::move(daily_st))->UseRealTime();
spdlog::drop("daily_st");
// //
// // Multi threaded bench, 10 loggers using same logger concurrently
// //
auto null_logger_mt = std::make_shared<spdlog::logger>("bench", std::make_shared<null_sink_mt>());
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);
benchmark::RegisterBenchmark("basic_mt", bench_logger, std::move(basic_mt))->Threads(n_threads)->UseRealTime();
spdlog::drop("basic_mt");
// rotating mt
auto rotating_mt = spdlog::rotating_logger_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();
spdlog::drop("rotating_mt");
// daily mt
auto daily_mt = spdlog::daily_logger_mt("daily_mt", "latency_logs/daily_mt.log");
benchmark::RegisterBenchmark("daily_mt", bench_logger, std::move(daily_mt))->Threads(n_threads)->UseRealTime();
spdlog::drop("daily_mt");
// 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);
benchmark::RegisterBenchmark("async_logger", bench_logger, async_logger)->Threads(n_threads)->UseRealTime();
benchmark::Initialize(&argc, argv);
benchmark::RunSpecifiedBenchmarks();
}

View File

@ -0,0 +1,4 @@
# Ignore everything in this directory
*
# Except this file
!.gitignore

19
third_party/spdlog/bench/mem vendored Executable file
View File

@ -0,0 +1,19 @@
#!/bin/sh
if [ $# -lt 1 ]; then
echo "usage: $0 <program>"
fi
PROG=$1
if [ ! -x "$PROG" ]; then
echo $PROG not found or not executable.
exit 1
fi
$* &
PID=$!
while `kill -0 $PID 2>/dev/null`; do
ps -eo size,pid,user,pcpu,command --sort -size | awk '{ line=1 ; hr=$1/1024 ; printf("%13.2f Mb ",hr); } { for ( x=4 ; x<=NF ; x++ ) { printf("%s ",$x) } print "" }' | grep -v grep | grep -v $0 | grep $PROG
done

34
third_party/spdlog/bench/utils.h vendored Normal file
View File

@ -0,0 +1,34 @@
//
// Copyright(c) 2015 Gabi Melman.
// Distributed under the MIT License (http://opensource.org/licenses/MIT)
//
#pragma once
#include <iomanip>
#include <locale>
#include <sstream>
namespace utils {
template<typename T>
inline std::string format(const T &value)
{
static std::locale loc("");
std::stringstream ss;
ss.imbue(loc);
ss << value;
return ss.str();
}
template<>
inline std::string format(const double &value)
{
static std::locale loc("");
std::stringstream ss;
ss.imbue(loc);
ss << std::fixed << std::setprecision(1) << value;
return ss.str();
}
} // namespace utils