fixed flush interval in async helper

This commit is contained in:
gabime 2018-05-19 16:06:57 +03:00
parent 8321449c44
commit 911a2986ce
5 changed files with 325 additions and 344 deletions

View File

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

View File

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

View File

@ -19,16 +19,16 @@
#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 {
@ -185,7 +185,6 @@ namespace spdlog {
void handle_flush_interval();
void flush_sinks();
};
} // 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,13 +323,28 @@ 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()
{
@ -356,4 +354,3 @@ inline void spdlog::details::async_log_helper::flush_sinks()
}
_last_flush = os::now();
}

View File

@ -11,12 +11,10 @@
// 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 {
@ -24,17 +22,19 @@ namespace spdlog {
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,9 +72,6 @@ namespace spdlog {
return true;
}
private:
size_t max_items_;
std::mutex queue_mutex_;
@ -83,7 +79,6 @@ namespace spdlog {
std::condition_variable pop_cv_;
std::queue<T> q_;
};
}
}
} // namespace details
} // namespace spdlog

View File

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