fixed flush interval in async helper

example/bench.cpp

@@ -7,7 +7,8 @@
 // bench.cpp : spdlog benchmarks
 //
 #include "spdlog/async_logger.h"
-#include "spdlog/sinks/test_sink.h"
+#include "spdlog/sinks/file_sinks.h"
+#include "spdlog/sinks/null_sink.h"
 #include "spdlog/spdlog.h"
 #include "utils.h"
 #include <atomic>
@@ -29,9 +30,11 @@ void bench_mt(int howmany, std::shared_ptr<spdlog::logger> log, int thread_count
 int main(int argc, char *argv[])
 {
 
-    int queue_size = 1024*1024;
+    int queue_size = 1048576;
     int howmany = 1000000;
     int threads = 10;
+    int file_size = 30 * 1024 * 1024;
+    int rotating_files = 5;
 
     try
     {
@@ -42,7 +45,7 @@ int main(int argc, char *argv[])
             threads = atoi(argv[2]);
         if (argc > 3)
             queue_size = atoi(argv[3]);
-		/*
+
         cout << "*******************************************************************************\n";
         cout << "Single thread, " << format(howmany) << " iterations" << endl;
         cout << "*******************************************************************************\n";
@@ -64,32 +67,17 @@ int main(int argc, char *argv[])
         bench_mt(howmany, daily_mt, threads);
         bench(howmany, spdlog::create<null_sink_st>("null_mt"));
 
-		*/
-
         cout << "\n*******************************************************************************\n";
         cout << "async logging.. " << threads << " threads sharing same logger, " << format(howmany) << " iterations " << endl;
         cout << "*******************************************************************************\n";
 
         spdlog::set_async_mode(queue_size);
 
-		
-        for (int i = 0; i < 300; ++i)
+        for (int i = 0; i < 3; ++i)
         {
-            //auto as = spdlog::daily_logger_mt("as", "logs/daily_async.log");
-			auto test_sink = std::make_shared<spdlog::sinks::test_sink_mt>();
-			//auto as = spdlog::basic_logger_mt("as", "logs/async.log", true);
-			auto as = std::make_shared<spdlog::async_logger>("as", test_sink, queue_size, async_overflow_policy::block_retry, nullptr, std::chrono::milliseconds(2000));
+            auto as = spdlog::daily_logger_st("as", "logs/daily_async.log");
             bench_mt(howmany, as, threads);
-			as.reset();
             spdlog::drop("as");
-
-			auto msg_counter = test_sink->msg_counter();
-			cout << "Count:" << msg_counter << endl;
-			if (msg_counter != howmany)
-			{
-				cout << "ERROR! Expected " << howmany;
-				exit(0);
-			}
         }
     }
     catch (std::exception &ex)
@@ -131,7 +119,6 @@ void bench_mt(int howmany, std::shared_ptr<spdlog::logger> log, int thread_count
                 if (counter > howmany)
                     break;
                 log->info("Hello logger: msg number {}", counter);
-				//std::this_thread::sleep_for(std::chrono::milliseconds(1000));
             }
         }));
     }

include/spdlog/contrib/sinks/step_file_sink.h

@@ -17,8 +17,10 @@
 //
 // Create a file logger which creates new files with a specified time step and fixed file size:
 //
-// std::shared_ptr<logger> step_logger_mt(const std::string &logger_name, const filename_t &filename, unsigned seconds = 60, const filename_t &tmp_ext = ".tmp", unsigned max_file_size = std::numeric_limits<unsigned>::max());
-// std::shared_ptr<logger> step_logger_st(const std::string &logger_name, const filename_t &filename, unsigned seconds = 60, const filename_t &tmp_ext = ".tmp", unsigned max_file_size = std::numeric_limits<unsigned>::max());
+// std::shared_ptr<logger> step_logger_mt(const std::string &logger_name, const filename_t &filename, unsigned seconds = 60, const
+// filename_t &tmp_ext = ".tmp", unsigned max_file_size = std::numeric_limits<unsigned>::max()); std::shared_ptr<logger>
+// step_logger_st(const std::string &logger_name, const filename_t &filename, unsigned seconds = 60, const filename_t &tmp_ext = ".tmp",
+// unsigned max_file_size = std::numeric_limits<unsigned>::max());
 
 // Example for spdlog_impl.h
 // Create a file logger that creates new files with a specified increment
@@ -96,7 +98,8 @@ public:
             close_current_file();
         }
         catch (...)
-        {}
+        {
+        }
     }
 
 protected:
@@ -130,7 +133,7 @@ private:
     {
         using details::os::filename_to_str;
 
-        filename_t src =_current_filename, target;
+        filename_t src = _current_filename, target;
         std::tie(target, std::ignore) = details::file_helper::split_by_extenstion(src);
         target += _ext;
 

include/spdlog/details/async_log_helper.h

@@ -19,22 +19,22 @@
 #include "../formatter.h"
 #include "../sinks/sink.h"
 
-#include<iostream>
 #include <chrono>
+#include <condition_variable>
 #include <exception>
 #include <functional>
+#include <iostream>
 #include <memory>
 #include <string>
 #include <thread>
 #include <utility>
 #include <vector>
-#include <condition_variable>
 
 namespace spdlog {
-	namespace details {
+namespace details {
 
-		class async_log_helper
-		{
+class async_log_helper
+{
     // Async msg to move to/from the queue
     // Movable only. should never be copied
     enum class async_msg_type
@@ -117,9 +117,9 @@ namespace spdlog {
         }
     };
 
-		public:
+public:
     using item_type = async_msg;
-			using q_type = details::mpmc_bounded_queue <item_type>;
+    using q_type = details::mpmc_bounded_queue<item_type>;
 
     using clock = std::chrono::steady_clock;
 
@@ -142,7 +142,7 @@ namespace spdlog {
 
     void set_error_handler(spdlog::log_err_handler err_handler);
 
-		private:
+private:
     formatter_ptr _formatter;
     std::vector<std::shared_ptr<sinks::sink>> _sinks;
 
@@ -166,7 +166,7 @@ namespace spdlog {
     const std::function<void()> _worker_teardown_cb;
 
     std::mutex null_mutex_;
-			//null_mutex null_mutex_;
+    // null_mutex null_mutex_;
     std::condition_variable_any not_empty_cv_;
     std::condition_variable_any not_full_cv_;
 
@@ -185,9 +185,8 @@ namespace spdlog {
     void handle_flush_interval();
 
     void flush_sinks();
-			
-		};
-	} // namespace details
+};
+} // namespace details
 } // namespace spdlog
 
 ///////////////////////////////////////////////////////////////////////////////
@@ -241,7 +240,6 @@ inline void spdlog::details::async_log_helper::enqueue_msg(details::async_log_he
     {
         _q.enqueue_nowait(std::move(new_msg));
     }
-	
 }
 
 // optionally wait for the queue be empty and request flush from the sinks
@@ -283,7 +281,7 @@ inline void spdlog::details::async_log_helper::worker_loop()
 inline bool spdlog::details::async_log_helper::process_next_msg()
 {
     async_msg incoming_async_msg;
-	bool dequeued = _q.dequeue_for(incoming_async_msg, std::chrono::milliseconds(1000));		
+    bool dequeued = _q.dequeue_for(incoming_async_msg, std::chrono::seconds(2));	
     if (!dequeued)
     {
         handle_flush_interval();
@@ -296,12 +294,10 @@ inline bool spdlog::details::async_log_helper::process_next_msg()
         flush_sinks();
         return true;
 
-
     case async_msg_type::terminate:
-		//flush_sinks();
+        flush_sinks();
         return false;
 
-
     default:
         log_msg incoming_log_msg;
         incoming_async_msg.fill_log_msg(incoming_log_msg);
@@ -313,26 +309,13 @@ inline bool spdlog::details::async_log_helper::process_next_msg()
                 s->log(incoming_log_msg);
             }
         }
+		handle_flush_interval();
         return true;
     }
     assert(false);
     return true; // should not be reached
-
 }
 
-// flush all sinks if _flush_interval_ms has expired. only called if queue is empty
-inline void spdlog::details::async_log_helper::handle_flush_interval()
-{		
-	if (_flush_interval_ms == std::chrono::milliseconds::zero())
-	{
-		return;
-	}
-	auto delta = details::os::now() - _last_flush;;		
-	if (delta >= _flush_interval_ms)
-	{					
-		flush_sinks();
-	}
-}
 
 
 inline void spdlog::details::async_log_helper::set_formatter(formatter_ptr msg_formatter)
@@ -340,21 +323,33 @@ inline void spdlog::details::async_log_helper::set_formatter(formatter_ptr msg_f
     _formatter = std::move(msg_formatter);
 }
 
-
 inline void spdlog::details::async_log_helper::set_error_handler(spdlog::log_err_handler err_handler)
 {
     _err_handler = std::move(err_handler);
 }
 
 
+// flush all sinks if _flush_interval_ms has expired. 
+inline void spdlog::details::async_log_helper::handle_flush_interval()
+{
+    if (_flush_interval_ms == std::chrono::milliseconds::zero())
+    {
+        return;
+    }
+    auto delta = details::os::now() - _last_flush;
+    ;
+    if (delta >= _flush_interval_ms)
+    {
+        flush_sinks();
+    }
+}
+
 // flush all sinks if _flush_interval_ms has expired. only called if queue is empty
 inline void spdlog::details::async_log_helper::flush_sinks()
 {    
-	printf("FLUSH!\n");
     for (auto &s : _sinks)
     {
         s->flush();
     }
     _last_flush = os::now();
 }
-

include/spdlog/details/mpmc_blocking_q.h

@@ -11,30 +11,30 @@
 // enqueue_nowait(..) - will return immediatly with false if no room left in the queue
 // dequeue_for(..) - will block until the queue is not empty or timeout passed
 
-
 #include <condition_variable>
 #include <mutex>
 #include <queue>
 
-
 namespace spdlog {
-	namespace details {
-
-		template<typename T>
-		class mpmc_bounded_queue
-		{
-		public:
+namespace details {
 
+template<typename T>
+class mpmc_bounded_queue
+{
+public:
     using item_type = T;
-			explicit mpmc_bounded_queue(size_t max_items) : max_items_(max_items) {}
+    explicit mpmc_bounded_queue(size_t max_items)
+        : max_items_(max_items)
+    {
+    }
 
     // try to enqueue and block if no room left
     void enqueue(T &&item)
     {
         {
             std::unique_lock<std::mutex> lock(queue_mutex_);
-					pop_cv_.wait(lock, [this] {return this->q_.size() <= this->max_items_; });
-					q_.push(std::forward<T>(item));
+            pop_cv_.wait(lock, [this] { return this->q_.size() < this->max_items_; });
+            q_.push(std::move(item));
         }
         push_cv_.notify_one();
     }
@@ -44,7 +44,7 @@ namespace spdlog {
     {
         {
             std::unique_lock<std::mutex> lock(queue_mutex_);
-					if (this->q_.size() >= this->max_items_)
+            if (q_.size() == this->max_items_)
             {
                 return false;
             }
@@ -60,12 +60,11 @@ namespace spdlog {
     {
         {
             std::unique_lock<std::mutex> lock(queue_mutex_);
-					//push_cv_.wait(lock, [this] {return this->q_.size() > 0; });
-					bool found_msg = push_cv_.wait_for(lock, wait_duration, [this] {return this->q_.size() > 0; });
-					if (!found_msg)
+            if (!push_cv_.wait_for(lock, wait_duration, [this] { return this->q_.size() > 0; }))
             {
                 return false;
             }
+
             popped_item = std::move(q_.front());
             q_.pop();
         }
@@ -73,17 +72,13 @@ namespace spdlog {
         return true;
     }
 
-
-
-
-		private:
+private:
     size_t max_items_;
     std::mutex queue_mutex_;
     std::condition_variable push_cv_;
     std::condition_variable pop_cv_;
 
     std::queue<T> q_;
-
-		};
-	}
-}
+};
+} // namespace details
+} // namespace spdlog

include/spdlog/sinks/test_sink.h

@@ -29,8 +29,7 @@ protected:
     }
 
     void _flush() override {}
-	size_t msg_counter_{ 0 };
-
+    size_t msg_counter_{0};
 };
 
 using test_sink_mt = test_sink<std::mutex>;