flush interval part 2

This commit is contained in:
Denis Ivaykin 2015-05-11 00:17:49 +02:00
parent f363fff109
commit 432e1109dd
6 changed files with 47 additions and 43 deletions

View File

@ -59,21 +59,21 @@ public:
size_t queue_size, size_t queue_size,
const async_overflow_policy overflow_policy = async_overflow_policy::block_retry, const async_overflow_policy overflow_policy = async_overflow_policy::block_retry,
const std::function<void()>& worker_warmup_cb = nullptr, const std::function<void()>& worker_warmup_cb = nullptr,
const std::chrono::milliseconds auto_flush_millis = std::chrono::milliseconds::zero()); const std::chrono::milliseconds& flush_interval_ms = std::chrono::milliseconds::zero());
async_logger(const std::string& logger_name, async_logger(const std::string& logger_name,
sinks_init_list sinks, sinks_init_list sinks,
size_t queue_size, size_t queue_size,
const async_overflow_policy overflow_policy = async_overflow_policy::block_retry, const async_overflow_policy overflow_policy = async_overflow_policy::block_retry,
const std::function<void()>& worker_warmup_cb = nullptr, const std::function<void()>& worker_warmup_cb = nullptr,
const std::chrono::milliseconds auto_flush_millis = std::chrono::milliseconds::zero()); const std::chrono::milliseconds& flush_interval_ms = std::chrono::milliseconds::zero());
async_logger(const std::string& logger_name, async_logger(const std::string& logger_name,
sink_ptr single_sink, sink_ptr single_sink,
size_t queue_size, size_t queue_size,
const async_overflow_policy overflow_policy = async_overflow_policy::block_retry, const async_overflow_policy overflow_policy = async_overflow_policy::block_retry,
const std::function<void()>& worker_warmup_cb = nullptr, const std::function<void()>& worker_warmup_cb = nullptr,
const std::chrono::milliseconds auto_flush_millis = std::chrono::milliseconds::zero()); const std::chrono::milliseconds& flush_interval_ms = std::chrono::milliseconds::zero());
protected: protected:

View File

@ -120,7 +120,7 @@ public:
size_t queue_size, size_t queue_size,
const async_overflow_policy overflow_policy = async_overflow_policy::block_retry, const async_overflow_policy overflow_policy = async_overflow_policy::block_retry,
const std::function<void()>& worker_warmup_cb = nullptr, const std::function<void()>& worker_warmup_cb = nullptr,
const std::chrono::milliseconds auto_flush_millis = std::chrono::milliseconds::zero()); const std::chrono::milliseconds& flush_interval_ms = std::chrono::milliseconds::zero());
void log(const details::log_msg& msg); void log(const details::log_msg& msg);
@ -147,7 +147,7 @@ private:
const std::function<void()> _worker_warmup_cb; const std::function<void()> _worker_warmup_cb;
// auto periodic sink flush parameter // auto periodic sink flush parameter
const std::chrono::milliseconds _auto_flush_millis; const std::chrono::milliseconds _flush_interval_ms;
// worker thread // worker thread
std::thread _worker_thread; std::thread _worker_thread;
@ -160,10 +160,10 @@ private:
// pop next message from the queue and process it // pop next message from the queue and process it
// return true if a message was available (queue was not empty), will set the last_pop to the pop time // return true if a message was available (queue was not empty), will set the last_pop to the pop time
bool process_next_msg(clock::time_point& last_pop); bool process_next_msg(log_clock::time_point& last_pop, log_clock::time_point& last_flush);
// sleep,yield or return immediatly using the time passed since last message as a hint // sleep,yield or return immediatly using the time passed since last message as a hint
static std::chrono::nanoseconds sleep_or_yield(const clock::time_point& last_op_time); static void sleep_or_yield(const spdlog::log_clock::time_point& now, const log_clock::time_point& last_op_time);
}; };
} }
@ -172,13 +172,13 @@ private:
/////////////////////////////////////////////////////////////////////////////// ///////////////////////////////////////////////////////////////////////////////
// async_sink class implementation // async_sink class implementation
/////////////////////////////////////////////////////////////////////////////// ///////////////////////////////////////////////////////////////////////////////
inline spdlog::details::async_log_helper::async_log_helper(formatter_ptr formatter, const std::vector<sink_ptr>& sinks, size_t queue_size, const async_overflow_policy overflow_policy, const std::function<void()>& worker_warmup_cb, const std::chrono::milliseconds auto_flush_millis): inline spdlog::details::async_log_helper::async_log_helper(formatter_ptr formatter, const std::vector<sink_ptr>& sinks, size_t queue_size, const async_overflow_policy overflow_policy, const std::function<void()>& worker_warmup_cb, const std::chrono::milliseconds& flush_interval_ms):
_formatter(formatter), _formatter(formatter),
_sinks(sinks), _sinks(sinks),
_q(queue_size), _q(queue_size),
_overflow_policy(overflow_policy), _overflow_policy(overflow_policy),
_worker_warmup_cb(worker_warmup_cb), _worker_warmup_cb(worker_warmup_cb),
_auto_flush_millis(auto_flush_millis), _flush_interval_ms(flush_interval_ms),
_worker_thread(&async_log_helper::worker_loop, this) _worker_thread(&async_log_helper::worker_loop, this)
{} {}
@ -204,10 +204,12 @@ inline void spdlog::details::async_log_helper::log(const details::log_msg& msg)
async_msg new_msg(msg); async_msg new_msg(msg);
if (!_q.enqueue(std::move(new_msg)) && _overflow_policy != async_overflow_policy::discard_log_msg) if (!_q.enqueue(std::move(new_msg)) && _overflow_policy != async_overflow_policy::discard_log_msg)
{ {
auto last_op_time = clock::now(); auto last_op_time = log_clock::now();
auto now = last_op_time;
do do
{ {
sleep_or_yield(last_op_time); now = log_clock::now();
sleep_or_yield(now, last_op_time);
} }
while (!_q.enqueue(std::move(new_msg))); while (!_q.enqueue(std::move(new_msg)));
} }
@ -219,8 +221,9 @@ inline void spdlog::details::async_log_helper::worker_loop()
try try
{ {
if (_worker_warmup_cb) _worker_warmup_cb(); if (_worker_warmup_cb) _worker_warmup_cb();
clock::time_point last_pop = clock::now(); auto last_pop = log_clock::now();
while(process_next_msg(last_pop)); auto last_flush = last_pop;
while(process_next_msg(last_pop, last_flush));
} }
catch (const std::exception& ex) catch (const std::exception& ex)
{ {
@ -234,7 +237,7 @@ inline void spdlog::details::async_log_helper::worker_loop()
// process next message in the queue // process next message in the queue
// return true if this thread should still be active (no msg with level::off was received) // return true if this thread should still be active (no msg with level::off was received)
inline bool spdlog::details::async_log_helper::process_next_msg(clock::time_point& last_pop) inline bool spdlog::details::async_log_helper::process_next_msg(log_clock::time_point& last_pop, log_clock::time_point& last_flush)
{ {
async_msg incoming_async_msg; async_msg incoming_async_msg;
@ -242,7 +245,7 @@ inline bool spdlog::details::async_log_helper::process_next_msg(clock::time_poin
if (_q.dequeue(incoming_async_msg)) if (_q.dequeue(incoming_async_msg))
{ {
last_pop = clock::now(); last_pop = log_clock::now();
if(incoming_async_msg.level == level::off) if(incoming_async_msg.level == level::off)
return false; return false;
@ -254,12 +257,18 @@ inline bool spdlog::details::async_log_helper::process_next_msg(clock::time_poin
} }
else //empty queue else //empty queue
{ {
auto time_since_op = sleep_or_yield(last_pop); auto now = log_clock::now();
if (_auto_flush_millis > std::chrono::milliseconds::zero() && time_since_op > _auto_flush_millis) if (_flush_interval_ms > std::chrono::milliseconds::zero())
{ {
for (auto &s : _sinks) auto time_since_flush = now - last_flush;
s->flush(); if (time_since_flush >= _flush_interval_ms)
{
last_flush = now;
for (auto &s : _sinks)
s->flush();
}
} }
sleep_or_yield(now, last_pop);
} }
return true; return true;
} }
@ -271,34 +280,27 @@ inline void spdlog::details::async_log_helper::set_formatter(formatter_ptr msg_f
// sleep,yield or return immediatly using the time passed since last message as a hint // sleep,yield or return immediatly using the time passed since last message as a hint
inline std::chrono::nanoseconds spdlog::details::async_log_helper::sleep_or_yield(const clock::time_point& last_op_time) inline void spdlog::details::async_log_helper::sleep_or_yield(const spdlog::log_clock::time_point& now, const spdlog::log_clock::time_point& last_op_time)
{ {
using std::chrono::milliseconds; using std::chrono::milliseconds;
using namespace std::this_thread; using namespace std::this_thread;
auto time_since_op = clock::now() - last_op_time; auto time_since_op = now - last_op_time;
// spin upto 1 ms // spin upto 1 ms
if (time_since_op <= milliseconds(1)) if (time_since_op <= milliseconds(1))
return time_since_op; return;
// yield upto 10ms // yield upto 10ms
if (time_since_op <= milliseconds(10)) if (time_since_op <= milliseconds(10))
{ return yield();
yield();
return time_since_op;
}
// sleep for half of duration since last op // sleep for half of duration since last op
if (time_since_op <= milliseconds(100)) if (time_since_op <= milliseconds(100))
{ return sleep_for(time_since_op / 2);
sleep_for(time_since_op / 2);
return time_since_op;
}
sleep_for(milliseconds(100)); return sleep_for(milliseconds(100));
return time_since_op;
} }
// throw if the worker thread threw an exception or not active // throw if the worker thread threw an exception or not active

View File

@ -40,9 +40,9 @@ inline spdlog::async_logger::async_logger(const std::string& logger_name,
size_t queue_size, size_t queue_size,
const async_overflow_policy overflow_policy, const async_overflow_policy overflow_policy,
const std::function<void()>& worker_warmup_cb, const std::function<void()>& worker_warmup_cb,
const std::chrono::milliseconds auto_flush_millis) : const std::chrono::milliseconds& flush_interval_ms) :
logger(logger_name, begin, end), logger(logger_name, begin, end),
_async_log_helper(new details::async_log_helper(_formatter, _sinks, queue_size, overflow_policy, worker_warmup_cb, auto_flush_millis)) _async_log_helper(new details::async_log_helper(_formatter, _sinks, queue_size, overflow_policy, worker_warmup_cb, flush_interval_ms))
{ {
} }
@ -51,16 +51,16 @@ inline spdlog::async_logger::async_logger(const std::string& logger_name,
size_t queue_size, size_t queue_size,
const async_overflow_policy overflow_policy, const async_overflow_policy overflow_policy,
const std::function<void()>& worker_warmup_cb, const std::function<void()>& worker_warmup_cb,
const std::chrono::milliseconds auto_flush_millis) : const std::chrono::milliseconds& flush_interval_ms) :
async_logger(logger_name, sinks.begin(), sinks.end(), queue_size, overflow_policy, worker_warmup_cb, auto_flush_millis) {} async_logger(logger_name, sinks.begin(), sinks.end(), queue_size, overflow_policy, worker_warmup_cb, flush_interval_ms) {}
inline spdlog::async_logger::async_logger(const std::string& logger_name, inline spdlog::async_logger::async_logger(const std::string& logger_name,
sink_ptr single_sink, sink_ptr single_sink,
size_t queue_size, size_t queue_size,
const async_overflow_policy overflow_policy, const async_overflow_policy overflow_policy,
const std::function<void()>& worker_warmup_cb, const std::function<void()>& worker_warmup_cb,
const std::chrono::milliseconds auto_flush_millis) : const std::chrono::milliseconds& flush_interval_ms) :
async_logger(logger_name, { single_sink }, queue_size, overflow_policy, worker_warmup_cb, auto_flush_millis) {} async_logger(logger_name, { single_sink }, queue_size, overflow_policy, worker_warmup_cb, flush_interval_ms) {}
inline void spdlog::async_logger::_set_formatter(spdlog::formatter_ptr msg_formatter) inline void spdlog::async_logger::_set_formatter(spdlog::formatter_ptr msg_formatter)

View File

@ -69,7 +69,7 @@ public:
if (_async_mode) if (_async_mode)
new_logger = std::make_shared<async_logger>(logger_name, sinks_begin, sinks_end, _async_q_size, _overflow_policy, _worker_warmup_cb); new_logger = std::make_shared<async_logger>(logger_name, sinks_begin, sinks_end, _async_q_size, _overflow_policy, _worker_warmup_cb, _flush_interval_ms);
else else
new_logger = std::make_shared<logger>(logger_name, sinks_begin, sinks_end); new_logger = std::make_shared<logger>(logger_name, sinks_begin, sinks_end);
@ -127,13 +127,14 @@ public:
_level = log_level; _level = log_level;
} }
void set_async_mode(size_t q_size, const async_overflow_policy overflow_policy, const std::function<void()>& worker_warmup_cb) void set_async_mode(size_t q_size, const async_overflow_policy overflow_policy, const std::function<void()>& worker_warmup_cb, const std::chrono::milliseconds& flush_interval_ms)
{ {
std::lock_guard<std::mutex> lock(_mutex); std::lock_guard<std::mutex> lock(_mutex);
_async_mode = true; _async_mode = true;
_async_q_size = q_size; _async_q_size = q_size;
_overflow_policy = overflow_policy; _overflow_policy = overflow_policy;
_worker_warmup_cb = worker_warmup_cb; _worker_warmup_cb = worker_warmup_cb;
_flush_interval_ms = flush_interval_ms;
} }
void set_sync_mode() void set_sync_mode()
@ -167,6 +168,7 @@ private:
size_t _async_q_size = 0; size_t _async_q_size = 0;
async_overflow_policy _overflow_policy = async_overflow_policy::block_retry; async_overflow_policy _overflow_policy = async_overflow_policy::block_retry;
std::function<void()> _worker_warmup_cb = nullptr; std::function<void()> _worker_warmup_cb = nullptr;
std::chrono::milliseconds _flush_interval_ms;
}; };
} }
} }

View File

@ -137,9 +137,9 @@ inline void spdlog::set_level(level::level_enum log_level)
} }
inline void spdlog::set_async_mode(size_t queue_size, const async_overflow_policy overflow_policy, const std::function<void()>& worker_warmup_cb) inline void spdlog::set_async_mode(size_t queue_size, const async_overflow_policy overflow_policy, const std::function<void()>& worker_warmup_cb, const std::chrono::milliseconds& flush_interval_ms)
{ {
details::registry::instance().set_async_mode(queue_size, overflow_policy, worker_warmup_cb); details::registry::instance().set_async_mode(queue_size, overflow_policy, worker_warmup_cb, flush_interval_ms);
} }
inline void spdlog::set_sync_mode() inline void spdlog::set_sync_mode()

View File

@ -68,7 +68,7 @@ void set_level(level::level_enum log_level);
// worker_warmup_cb (optional): // worker_warmup_cb (optional):
// callback function that will be called in worker thread upon start (can be used to init stuff like thread affinity) // callback function that will be called in worker thread upon start (can be used to init stuff like thread affinity)
// //
void set_async_mode(size_t queue_size, const async_overflow_policy overflow_policy = async_overflow_policy::block_retry, const std::function<void()>& worker_warmup_cb = nullptr); void set_async_mode(size_t queue_size, const async_overflow_policy overflow_policy = async_overflow_policy::block_retry, const std::function<void()>& worker_warmup_cb = nullptr, const std::chrono::milliseconds& flush_interval_ms = std::chrono::milliseconds::zero());
// Turn off async mode // Turn off async mode
void set_sync_mode(); void set_sync_mode();