bench

example/bench.cpp

-// example.cpp : Simple logger example
 //
+// bench.cpp : spdlog benchmarks
+//
+#include <iostream>
+#include <memory>
+#include <string>
+#include <thread>
+#include <atomic>
 #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<spdlog::logger> log)
 {
-    try {
+		cout << log->name() << ", " << format(howmany) << " iterations.." << endl;
+      
+        auto start = system_clock::now();
+        for (auto i = 0; i < howmany; ++i)
+        {
+            log->info("Hello logger: msg number ") << i;
+        }
 
-        using namespace spdlog::sinks;
-        spdlog::create<daily_file_sink_st>("mylog", "dailylog", "txt");
-        const unsigned int howmany = argc <= 1 ? 1500000 : atoi(argv[1]);
+        auto delta = system_clock::now() - start;
+        auto delta_d = duration_cast<duration<double>> (delta).count();		
+        cout << "Delta:" << format(delta_d) << " seconds" << endl;
+        cout << "Rate:" << format(howmany / delta_d) << "/sec" << endl << endl;
+}
 
-        spdlog::set_pattern("%Y-%m-%d %H:%M:%S.%e %l : %t");
 
+void bench_mt(int howmany, std::shared_ptr<spdlog::logger> log, int thread_count)
+{
 
-        auto console = spdlog::create<sinks::stdout_sink_st>("reporter");
-        console->info("Starting bench with", howmany, "iterations..");
-        console->log() <<  "Streams are also supprted: " << std::hex << 255;
-        spdlog::stop();
+        cout << log->name() << ", " << format(howmany) << " iterations.." << endl;
+        std::atomic<int > msg_counter{0};   
+      	vector<thread> 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();
+	    };
 
-        //return 0;
-        auto bench = spdlog::create<sinks::rotating_file_sink_st>("bench", "myrotating", "txt", 1024 * 1024 * 1, 10, 0);
+        auto delta = system_clock::now() - start;
+        auto delta_d = duration_cast<duration<double>> (delta).count();		
+        cout << "Delta:" << format(delta_d) << " seconds" << endl;
+        cout << "Rate:" << format(howmany / delta_d) << "/sec" << endl << endl;
+ }
 
-        //auto bench = spdlog::create<sinks::simple_file_sink_st>("bench", "simplelog.txt", 1);
-        //auto bench = spdlog::create<sinks::null_sink_st>("bench");
-        auto start = system_clock::now();
-        for (unsigned int i = 0; i < howmany; ++i)
-        {
-            bench->info("Hello logger: msg number") << i;
-        }
 
-        auto delta = system_clock::now() - start;
-        auto delta_d = duration_cast<duration<double>> (delta).count();
+int main(int argc, char* argv[])
+{
+	
 
-        cout << "Total:" << format(howmany) << endl;
-        cout << "Delta:" << format(delta_d) << endl;
-        cout << "Rate:" << format(howmany / delta_d) << "/sec\n";
+    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_sink_st>("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_sink_mt>("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;

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;
     }
-
 }
 

example/logs/.gitignore

+# Ignore everything in this directory
+*
+# Except this file
+!.gitignore

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

example/makefile.bench

-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
-
-

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

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<void() >& 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<void() >& fn)
-{
-
-    using namespace std::chrono;
-    auto start = steady_clock::now();
-    fn();
-    auto delta = steady_clock::now() - start;
-
-    std::cout << fn_name << ": " << duration_cast<milliseconds>(delta).count() << " ms" << std::endl;
-}
 }

include/spdlog/details/file_helper.h

@@ -12,7 +12,8 @@
 #include <string>
 #include <thread>
 #include <chrono>
-#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()

include/spdlog/logger.h

@@ -9,9 +9,6 @@
 
 #include<vector>
 #include<memory>
-#include<atomic>
-#include <sstream>
-#include <exception>
 #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"