From 2d075bcfdaae37011f21c2bf3e31b622a83f6457 Mon Sep 17 00:00:00 2001 From: gabime Date: Fri, 31 Oct 2014 16:34:48 +0200 Subject: [PATCH] bench --- example/bench.cpp | 108 ++++++++++++++++++++------- example/example.cpp | 5 +- example/logs/.gitignore | 4 + example/makefile | 2 +- example/makefile.bench | 24 ------ example/makefile.clang | 2 +- example/utils.h | 34 --------- include/spdlog/details/file_helper.h | 19 ++--- include/spdlog/logger.h | 18 ----- 9 files changed, 98 insertions(+), 118 deletions(-) create mode 100644 example/logs/.gitignore delete mode 100644 example/makefile.bench diff --git a/example/bench.cpp b/example/bench.cpp index c098ab7a..d69b8b4e 100644 --- a/example/bench.cpp +++ b/example/bench.cpp @@ -1,5 +1,11 @@ -// example.cpp : Simple logger example // +// bench.cpp : spdlog benchmarks +// +#include +#include +#include +#include +#include #include "spdlog/spdlog.h" #include "spdlog/sinks/file_sinks.h" #include "spdlog/sinks/stdout_sinks.h" @@ -10,47 +16,93 @@ using namespace std; using namespace std::chrono; using namespace spdlog; +using namespace spdlog::sinks; using namespace utils; -int main_(int argc, char* argv[]) +void bench(int howmany, std::shared_ptr log) { - try { - - using namespace spdlog::sinks; - spdlog::create("mylog", "dailylog", "txt"); - const unsigned int howmany = argc <= 1 ? 1500000 : atoi(argv[1]); - - spdlog::set_pattern("%Y-%m-%d %H:%M:%S.%e %l : %t"); - - - auto console = spdlog::create("reporter"); - console->info("Starting bench with", howmany, "iterations.."); - console->log() << "Streams are also supprted: " << std::hex << 255; - spdlog::stop(); - - //return 0; - auto bench = spdlog::create("bench", "myrotating", "txt", 1024 * 1024 * 1, 10, 0); - - //auto bench = spdlog::create("bench", "simplelog.txt", 1); - //auto bench = spdlog::create("bench"); + cout << log->name() << ", " << format(howmany) << " iterations.." << endl; + auto start = system_clock::now(); - for (unsigned int i = 0; i < howmany; ++i) + for (auto i = 0; i < howmany; ++i) { - bench->info("Hello logger: msg number") << i; + log->info("Hello logger: msg number ") << i; } auto delta = system_clock::now() - start; - auto delta_d = duration_cast> (delta).count(); + auto delta_d = duration_cast> (delta).count(); + cout << "Delta:" << format(delta_d) << " seconds" << endl; + cout << "Rate:" << format(howmany / delta_d) << "/sec" << endl << endl; +} - cout << "Total:" << format(howmany) << endl; - cout << "Delta:" << format(delta_d) << endl; - cout << "Rate:" << format(howmany / delta_d) << "/sec\n"; +void bench_mt(int howmany, std::shared_ptr log, int thread_count) +{ + + cout << log->name() << ", " << format(howmany) << " iterations.." << endl; + std::atomic msg_counter{0}; + vector threads; + auto start = system_clock::now(); + for (int t = 0; t < thread_count; ++t) + { + threads.push_back(std::thread([&]() { + while(msg_counter++ < howmany) + log->info("Hello logger: msg number ") << msg_counter; + + })); + } + + for(auto &t:threads) + { + t.join(); + }; + + auto delta = system_clock::now() - start; + auto delta_d = duration_cast> (delta).count(); + cout << "Delta:" << format(delta_d) << " seconds" << endl; + cout << "Rate:" << format(howmany / delta_d) << "/sec" << endl << endl; + } + + +int main(int argc, char* argv[]) +{ + + + try { + + int howmany = argc <= 1 ? 100000 : atoi(argv[1]); + int threads = argc <= 2 ? 4 : atoi(argv[2]); + int flush_interval = 100; + + + cout << "*******************************************************************************\n"; + cout << "Single threaded benchmarks. flush_interval = " << flush_interval << endl; + cout << "*******************************************************************************\n"; + + auto rotating_st = spdlog::rotating_logger_st("rotating_st", "logs/rotating_st", 1024 * 1024 * 5, 5, flush_interval); + bench(howmany, rotating_st); + + auto daily_st = spdlog::daily_logger_st("daily_st", "logs/daily_st", flush_interval); + bench(howmany, daily_st); + + bench(howmany, spdlog::create("null_st")); + + cout << "*******************************************************************************\n"; + cout << "Multi threaded benchmarks (" << threads << " threads), flush_interval = " << flush_interval << endl; + cout << "*******************************************************************************\n"; + + auto rotating_mt = spdlog::rotating_logger_mt("rotating_mt", "logs/rotating_mt", 1024 * 1024 * 5, 5, flush_interval); + bench_mt(howmany, rotating_mt, threads); + + auto daily_mt = spdlog::daily_logger_mt("daily_mt", "logs/daily_mt", flush_interval); + bench_mt(howmany, daily_mt, threads); + + bench_mt(howmany, spdlog::create("null_mt"), threads); } catch (std::exception &ex) { - std::cerr << "Exception: " << ex.what() << std::endl; + std::cerr << "Error: " << ex.what() << std::endl; perror("Last error"); } return 0; diff --git a/example/example.cpp b/example/example.cpp index 20e0b8bc..9e94496e 100644 --- a/example/example.cpp +++ b/example/example.cpp @@ -10,11 +10,12 @@ int main(int, char* []) { namespace spd = spdlog; + try { std::string filename = "spdlog_example"; auto console = spd::stderr_logger_mt("console"); - console->info("Welcome to spdlog!"); + console->info("Welcome to spdlog!") ; console->info() << "Creating file " << filename << ".."; auto file_logger = spd::rotating_logger_mt("file_logger", filename, 1024 * 1024 * 5, 3); @@ -26,7 +27,6 @@ int main(int, char* []) file_logger->info() << i << '*' << i << '=' << square << " (" << "0x" << std::hex << square << ")"; } - // Change log level to all loggers to warning and above spd::set_level(spd::level::WARN); console->info("This should not be displayed"); @@ -40,6 +40,5 @@ int main(int, char* []) { std::cout << "Log failed: " << ex.what() << std::endl; } - } diff --git a/example/logs/.gitignore b/example/logs/.gitignore new file mode 100644 index 00000000..5e7d2734 --- /dev/null +++ b/example/logs/.gitignore @@ -0,0 +1,4 @@ +# Ignore everything in this directory +* +# Except this file +!.gitignore diff --git a/example/makefile b/example/makefile index 306b890d..e0e1eda8 100644 --- a/example/makefile +++ b/example/makefile @@ -23,7 +23,7 @@ bench-debug: bench.cpp clean: - rm -f *.o *.txt example example-debug bench bench-debug + rm -f *.o logs/*.txt example example-debug bench bench-debug rebuild: clean all diff --git a/example/makefile.bench b/example/makefile.bench deleted file mode 100644 index ab33e423..00000000 --- a/example/makefile.bench +++ /dev/null @@ -1,24 +0,0 @@ -CXX = g++ -CXXFLAGS = -march=native -Wall -Wextra -Wshadow -pedantic -std=c++11 -pthread -I../include -CXX_RELEASE_FLAGS = -O3 -flto -CXX_DEBUG_FLAGS= -g - -OUTBIN = bench - -all: bench.cpp - $(CXX) bench.cpp -o $(OUTBIN) $(CXXFLAGS) $(CXX_RELEASE_FLAGS) - - -debug: bench.cpp - $(CXX) bench.cpp -o $(OUTBIN)-debug $(CXXFLAGS) $(CXX_DEBUG_FLAGS) - - - -clean: - rm -f *.txt $(OUTBIN) $(OUTBIN)-debug - - -rebuild: clean all -rebuild-debug: clean debug - - diff --git a/example/makefile.clang b/example/makefile.clang index fb8de71d..9d68e796 100644 --- a/example/makefile.clang +++ b/example/makefile.clang @@ -23,7 +23,7 @@ bench-debug: bench.cpp clean: - rm -f *.o *.txt example-clang example-clang-debug bench-clang bench-clang-debug + rm -f *.o logs/*.txt example-clang example-clang-debug bench-clang bench-clang-debug rebuild: clean all diff --git a/example/utils.h b/example/utils.h index 9b7b43f4..7612dbb3 100644 --- a/example/utils.h +++ b/example/utils.h @@ -30,38 +30,4 @@ inline std::string format(const double & value) return ss.str(); } -inline void bench(const std::string& fn_name, const std::chrono::milliseconds &duration, const std::function& fn) -{ - using namespace std::chrono; - typedef steady_clock the_clock; - size_t counter = 0; - seconds print_interval(1); - auto start_time = the_clock::now(); - auto lastPrintTime = start_time; - while (true) - { - fn(); - ++counter; - auto now = the_clock::now(); - if (now - start_time >= duration) - break; - if (now - lastPrintTime >= print_interval) - { - std::cout << fn_name << ": " << format(counter) << " per sec" << std::endl; - counter = 0; - lastPrintTime = the_clock::now(); - } - } -} - -inline void bench(const std::string& fn_name, const std::function& fn) -{ - - using namespace std::chrono; - auto start = steady_clock::now(); - fn(); - auto delta = steady_clock::now() - start; - - std::cout << fn_name << ": " << duration_cast(delta).count() << " ms" << std::endl; -} } diff --git a/include/spdlog/details/file_helper.h b/include/spdlog/details/file_helper.h index eae6c60e..490e2e47 100644 --- a/include/spdlog/details/file_helper.h +++ b/include/spdlog/details/file_helper.h @@ -12,7 +12,8 @@ #include #include #include -#include "../common.h" +#include "os.h" + @@ -24,8 +25,8 @@ namespace details class file_helper { public: - static const int open_max_tries = 5; - static const int sleep_ms_bewteen_tries = 10; + const int open_tries = 5; + const int open_interval = 10; explicit file_helper(const std::size_t flush_inverval): _fd(nullptr), @@ -40,21 +41,21 @@ public: } - void open(const std::string& filename) + void open(const std::string& fname) { close(); - _filename = filename; - for (int tries = 0; tries < open_max_tries; ++tries) + _filename = fname; + for (int tries = 0; tries < open_tries; ++tries) { - if(!os::fopen_s(&_fd, filename, "wb")) + if(!os::fopen_s(&_fd, fname, "wb")) return; - std::this_thread::sleep_for(std::chrono::milliseconds(sleep_ms_bewteen_tries)); + std::this_thread::sleep_for(std::chrono::milliseconds(open_interval)); } - throw spdlog_ex("Failed opening file " + filename + " for writing"); + throw spdlog_ex("Failed opening file " + fname + " for writing"); } void close() diff --git a/include/spdlog/logger.h b/include/spdlog/logger.h index 0789318b..2d54457b 100644 --- a/include/spdlog/logger.h +++ b/include/spdlog/logger.h @@ -9,9 +9,6 @@ #include #include -#include -#include -#include #include "sinks/base_sink.h" #include "common.h" @@ -75,19 +72,4 @@ private: } -// -// Trace & debug macros -// -#ifdef FFLOG_ENABLE_TRACE -#define FFLOG_TRACE(logger, ...) logger->log(spdlog::level::TRACE, __FILE__, " #", __LINE__,": " __VA_ARGS__) -#else -#define FFLOG_TRACE(logger, ...) {} -#endif - -#ifdef FFLOG_ENABLE_DEBUG -#define FFLOG_DEBUG(logger, ...) logger->log(spdlog::level::DEBUG, __VA_ARGS__) -#else -#define FFLOG_DEBUG(logger, ...) {} -#endif - #include "./details/logger_impl.h"