This commit is contained in:
gabime 2018-06-10 23:22:31 +03:00
parent 66b5772b61
commit 032035e72f
6 changed files with 255 additions and 259 deletions

View File

@ -18,22 +18,26 @@
// 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(), bool delete_empty_files = true, const filename_t &file_header = ""); 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());
// filename_t &tmp_ext = ".tmp", unsigned max_file_size = std::numeric_limits<unsigned>::max(), bool delete_empty_files = true, const
// filename_t &file_header = ""); 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
// inline std::shared_ptr<spdlog::logger> spdlog::step_logger_mt(
// const std::string &logger_name, const filename_t &filename_fmt, unsigned seconds, const filename_t &tmp_ext, unsigned max_file_size, bool delete_empty_files, const filename_t &file_header)
// const std::string &logger_name, const filename_t &filename_fmt, unsigned seconds, const filename_t &tmp_ext, unsigned max_file_size,
// bool delete_empty_files, const filename_t &file_header)
// {
// return create<spdlog::sinks::step_file_sink_mt>(logger_name, filename_fmt, seconds, tmp_ext, max_file_size, delete_empty_files, file_header);
// return create<spdlog::sinks::step_file_sink_mt>(logger_name, filename_fmt, seconds, tmp_ext, max_file_size, delete_empty_files,
// file_header);
// }
// inline std::shared_ptr<spdlog::logger> spdlog::step_logger_st(
// const std::string &logger_name, const filename_t &filename_fmt, unsigned seconds, const filename_t &tmp_ext, unsigned max_file_size, bool delete_empty_files, const filename_t &file_header)
// const std::string &logger_name, const filename_t &filename_fmt, unsigned seconds, const filename_t &tmp_ext, unsigned max_file_size,
// bool delete_empty_files, const filename_t &file_header)
// {
// return create<spdlog::sinks::step_file_sink_st>(logger_name, filename_fmt, seconds, tmp_ext, max_file_size, delete_empty_files, file_header);
// return create<spdlog::sinks::step_file_sink_st>(logger_name, filename_fmt, seconds, tmp_ext, max_file_size, delete_empty_files,
// file_header);
// }
namespace spdlog {
@ -64,7 +68,8 @@ template<class Mutex, class FileNameCalc = default_step_file_name_calculator>
class step_file_sink SPDLOG_FINAL : public base_sink<Mutex>
{
public:
step_file_sink(filename_t base_filename, unsigned step_seconds, filename_t tmp_ext, unsigned max_size, bool delete_empty_files, filename_t file_header)
step_file_sink(filename_t base_filename, unsigned step_seconds, filename_t tmp_ext, unsigned max_size, bool delete_empty_files,
filename_t file_header)
: _base_filename(std::move(base_filename))
, _tmp_ext(std::move(tmp_ext))
, _step_seconds(step_seconds)
@ -102,7 +107,8 @@ public:
if (!_current_size)
{
_current_size += _file_header.formatted.size();
if (_current_size) _file_helper.write(_file_header);
if (_current_size)
_file_helper.write(_file_header);
}
}
@ -126,9 +132,9 @@ protected:
{
filename_t new_filename;
std::tie(new_filename, std::ignore) = FileNameCalc::calc_filename(_base_filename, _tmp_ext);
bool change_occured = !details::file_helper::file_exists(new_filename);
if (change_occured)
if (change_occured)
{
close_current_file();
@ -142,7 +148,8 @@ protected:
if (change_occured)
{
_current_size = _file_header.formatted.size();
if (_current_size) _file_helper.write(_file_header);
if (_current_size)
_file_helper.write(_file_header);
}
}
@ -182,7 +189,8 @@ private:
if (details::file_helper::file_exists(_current_filename) && details::os::rename(_current_filename, target) != 0)
{
throw spdlog_ex("step_file_sink: failed renaming " + filename_to_str(_current_filename) + " to " + filename_to_str(target), errno);
throw spdlog_ex(
"step_file_sink: failed renaming " + filename_to_str(_current_filename) + " to " + filename_to_str(target), errno);
}
}

View File

@ -29,317 +29,305 @@
#include <utility>
#include <vector>
namespace spdlog {
namespace details {
namespace details {
class async_log_helper
{
// Async msg to move to/from the queue
// Movable only. should never be copied
enum class async_msg_type
{
log,
flush,
terminate
};
class async_log_helper
{
// Async msg to move to/from the queue
// Movable only. should never be copied
enum class async_msg_type
{
log,
flush,
terminate
};
struct async_msg
{
level::level_enum level;
log_clock::time_point time;
size_t thread_id;
std::string txt;
async_msg_type msg_type;
size_t msg_id;
struct async_msg
{
level::level_enum level;
log_clock::time_point time;
size_t thread_id;
std::string txt;
async_msg_type msg_type;
size_t msg_id;
async_msg() = default;
~async_msg() = default;
async_msg() = default;
~async_msg() = default;
explicit async_msg(async_msg_type m_type)
: level(level::info)
, thread_id(0)
, msg_type(m_type)
, msg_id(0)
{
}
explicit async_msg(async_msg_type m_type)
: level(level::info)
, thread_id(0)
, msg_type(m_type)
, msg_id(0)
{
}
async_msg(async_msg &&other) = default;
async_msg &operator=(async_msg &&other) = default;
async_msg(async_msg &&other) = default;
async_msg &operator=(async_msg &&other) = default;
// never copy or assign. should only be moved..
async_msg(const async_msg &) = delete;
async_msg &operator=(const async_msg &other) = delete;
// never copy or assign. should only be moved..
async_msg(const async_msg &) = delete;
async_msg &operator=(const async_msg &other) = delete;
// construct from log_msg
explicit async_msg(const details::log_msg &m)
: level(m.level)
, time(m.time)
, thread_id(m.thread_id)
, txt(m.raw.data(), m.raw.size())
, msg_type(async_msg_type::log)
, msg_id(m.msg_id)
{
}
// construct from log_msg
explicit async_msg(const details::log_msg &m)
: level(m.level)
, time(m.time)
, thread_id(m.thread_id)
, txt(m.raw.data(), m.raw.size())
, msg_type(async_msg_type::log)
, msg_id(m.msg_id)
{
}
// copy into log_msg
void fill_log_msg(log_msg &msg, std::string* logger_name)
{
msg.logger_name = logger_name;
msg.level = level;
msg.time = time;
msg.thread_id = thread_id;
msg.raw.clear();
msg.raw << txt;
msg.msg_id = msg_id;
}
};
// copy into log_msg
void fill_log_msg(log_msg &msg, std::string *logger_name)
{
msg.logger_name = logger_name;
msg.level = level;
msg.time = time;
msg.thread_id = thread_id;
msg.raw.clear();
msg.raw << txt;
msg.msg_id = msg_id;
}
};
public:
using item_type = async_msg;
using q_type = details::mpmc_bounded_queue<item_type>;
public:
using item_type = async_msg;
using q_type = details::mpmc_bounded_queue<item_type>;
using clock = std::chrono::steady_clock;
using clock = std::chrono::steady_clock;
async_log_helper(std::string logger_name,
formatter_ptr formatter,
std::vector<sink_ptr> sinks,
size_t queue_size,
const log_err_handler err_handler,
const async_overflow_policy overflow_policy = async_overflow_policy::block_retry,
std::function<void()> worker_warmup_cb = nullptr,
const std::chrono::milliseconds &flush_interval_ms = std::chrono::milliseconds::zero(),
std::function<void()> worker_teardown_cb = nullptr);
async_log_helper(std::string logger_name, formatter_ptr formatter, std::vector<sink_ptr> sinks, size_t queue_size,
const log_err_handler err_handler, const async_overflow_policy overflow_policy = async_overflow_policy::block_retry,
std::function<void()> worker_warmup_cb = nullptr,
const std::chrono::milliseconds &flush_interval_ms = std::chrono::milliseconds::zero(),
std::function<void()> worker_teardown_cb = nullptr);
void log(const details::log_msg &msg);
void log(const details::log_msg &msg);
// stop logging and join the back thread
~async_log_helper();
// stop logging and join the back thread
~async_log_helper();
async_log_helper(const async_log_helper &) = delete;
async_log_helper &operator=(const async_log_helper &) = delete;
async_log_helper(const async_log_helper &) = delete;
async_log_helper &operator=(const async_log_helper &) = delete;
void set_formatter(formatter_ptr msg_formatter);
void set_formatter(formatter_ptr msg_formatter);
void flush();
void flush();
void set_error_handler(spdlog::log_err_handler err_handler);
void set_error_handler(spdlog::log_err_handler err_handler);
private:
std::string _logger_name;
formatter_ptr _formatter;
std::vector<std::shared_ptr<sinks::sink>> _sinks;
private:
std::string _logger_name;
formatter_ptr _formatter;
std::vector<std::shared_ptr<sinks::sink>> _sinks;
// queue of messages to log
q_type _q;
// queue of messages to log
q_type _q;
log_err_handler _err_handler;
log_err_handler _err_handler;
std::chrono::time_point<log_clock> _last_flush;
std::chrono::time_point<log_clock> _last_flush;
// overflow policy
const async_overflow_policy _overflow_policy;
// overflow policy
const async_overflow_policy _overflow_policy;
// worker thread warmup callback - one can set thread priority, affinity, etc
const std::function<void()> _worker_warmup_cb;
// worker thread warmup callback - one can set thread priority, affinity, etc
const std::function<void()> _worker_warmup_cb;
// auto periodic sink flush parameter
const std::chrono::milliseconds _flush_interval_ms;
// auto periodic sink flush parameter
const std::chrono::milliseconds _flush_interval_ms;
// worker thread teardown callback
const std::function<void()> _worker_teardown_cb;
// worker thread teardown callback
const std::function<void()> _worker_teardown_cb;
std::mutex null_mutex_;
// null_mutex null_mutex_;
std::condition_variable_any not_empty_cv_;
std::condition_variable_any not_full_cv_;
std::mutex null_mutex_;
// null_mutex null_mutex_;
std::condition_variable_any not_empty_cv_;
std::condition_variable_any not_full_cv_;
// worker thread
std::thread _worker_thread;
// worker thread
std::thread _worker_thread;
void enqueue_msg(async_msg &&new_msg, async_overflow_policy policy);
void enqueue_msg(async_msg &&new_msg, async_overflow_policy policy);
// worker thread main loop
void worker_loop();
// worker thread main loop
void worker_loop();
// dequeue next message from the queue and process it.
// return false if termination of the queue is required
bool process_next_msg();
// dequeue next message from the queue and process it.
// return false if termination of the queue is required
bool process_next_msg();
void handle_flush_interval();
void handle_flush_interval();
void flush_sinks();
};
} // namespace details
void flush_sinks();
};
} // namespace details
} // namespace spdlog
///////////////////////////////////////////////////////////////////////////////
// async_sink class implementation
///////////////////////////////////////////////////////////////////////////////
inline spdlog::details::async_log_helper::async_log_helper(std::string logger_name,
formatter_ptr formatter,
std::vector<sink_ptr> sinks,
size_t queue_size,
log_err_handler err_handler,
const async_overflow_policy overflow_policy,
std::function<void()> worker_warmup_cb,
const std::chrono::milliseconds &flush_interval_ms,
std::function<void()> worker_teardown_cb)
: _logger_name(std::move(logger_name))
, _formatter(std::move(formatter))
, _sinks(std::move(sinks))
, _q(queue_size)
, _err_handler(std::move(err_handler))
, _last_flush(os::now())
, _overflow_policy(overflow_policy)
, _worker_warmup_cb(std::move(worker_warmup_cb))
, _flush_interval_ms(flush_interval_ms)
, _worker_teardown_cb(std::move(worker_teardown_cb))
inline spdlog::details::async_log_helper::async_log_helper(std::string logger_name, formatter_ptr formatter, std::vector<sink_ptr> sinks,
size_t queue_size, log_err_handler err_handler, const async_overflow_policy overflow_policy, std::function<void()> worker_warmup_cb,
const std::chrono::milliseconds &flush_interval_ms, std::function<void()> worker_teardown_cb)
: _logger_name(std::move(logger_name))
, _formatter(std::move(formatter))
, _sinks(std::move(sinks))
, _q(queue_size)
, _err_handler(std::move(err_handler))
, _last_flush(os::now())
, _overflow_policy(overflow_policy)
, _worker_warmup_cb(std::move(worker_warmup_cb))
, _flush_interval_ms(flush_interval_ms)
, _worker_teardown_cb(std::move(worker_teardown_cb))
{
_worker_thread = std::thread(&async_log_helper::worker_loop, this);
_worker_thread = std::thread(&async_log_helper::worker_loop, this);
}
// send to the worker thread terminate message, and join it.
inline spdlog::details::async_log_helper::~async_log_helper()
{
try
{
enqueue_msg(async_msg(async_msg_type::terminate), async_overflow_policy::block_retry);
_worker_thread.join();
}
catch (...) // don't crash in destructor
{
}
try
{
enqueue_msg(async_msg(async_msg_type::terminate), async_overflow_policy::block_retry);
_worker_thread.join();
}
catch (...) // don't crash in destructor
{
}
}
// try to push and block until succeeded (if the policy is not to discard when the queue is full)
inline void spdlog::details::async_log_helper::log(const details::log_msg &msg)
{
enqueue_msg(async_msg(msg), _overflow_policy);
enqueue_msg(async_msg(msg), _overflow_policy);
}
inline void spdlog::details::async_log_helper::enqueue_msg(details::async_log_helper::async_msg &&new_msg, async_overflow_policy policy)
{
// block until succeeded pushing to the queue
if (policy == async_overflow_policy::block_retry)
{
_q.enqueue(std::move(new_msg));
}
else
{
_q.enqueue_nowait(std::move(new_msg));
}
// block until succeeded pushing to the queue
if (policy == async_overflow_policy::block_retry)
{
_q.enqueue(std::move(new_msg));
}
else
{
_q.enqueue_nowait(std::move(new_msg));
}
}
// optionally wait for the queue be empty and request flush from the sinks
inline void spdlog::details::async_log_helper::flush()
{
enqueue_msg(async_msg(async_msg_type::flush), _overflow_policy);
enqueue_msg(async_msg(async_msg_type::flush), _overflow_policy);
}
inline void spdlog::details::async_log_helper::worker_loop()
{
if (_worker_warmup_cb)
{
_worker_warmup_cb();
}
auto active = true;
while (active)
{
try
{
active = process_next_msg();
}
SPDLOG_CATCH_AND_HANDLE
}
if (_worker_teardown_cb)
{
_worker_teardown_cb();
}
if (_worker_warmup_cb)
{
_worker_warmup_cb();
}
auto active = true;
while (active)
{
try
{
active = process_next_msg();
}
SPDLOG_CATCH_AND_HANDLE
}
if (_worker_teardown_cb)
{
_worker_teardown_cb();
}
}
// process next message in the queue
// return true if this thread should still be active (while no terminate msg was received)
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::seconds(2));
if (!dequeued)
{
handle_flush_interval();
return true;
}
async_msg incoming_async_msg;
bool dequeued = _q.dequeue_for(incoming_async_msg, std::chrono::seconds(2));
if (!dequeued)
{
handle_flush_interval();
return true;
}
switch (incoming_async_msg.msg_type)
{
case async_msg_type::flush:
flush_sinks();
return true;
switch (incoming_async_msg.msg_type)
{
case async_msg_type::flush:
flush_sinks();
return true;
case async_msg_type::terminate:
flush_sinks();
return false;
case async_msg_type::terminate:
flush_sinks();
return false;
default:
log_msg incoming_log_msg;
incoming_async_msg.fill_log_msg(incoming_log_msg, &_logger_name);
_formatter->format(incoming_log_msg);
for (auto &s : _sinks)
{
if (s->should_log(incoming_log_msg.level))
{
try
{
s->log(incoming_log_msg);
}
SPDLOG_CATCH_AND_HANDLE
}
}
handle_flush_interval();
return true;
}
assert(false);
return true; // should not be reached
default:
log_msg incoming_log_msg;
incoming_async_msg.fill_log_msg(incoming_log_msg, &_logger_name);
_formatter->format(incoming_log_msg);
for (auto &s : _sinks)
{
if (s->should_log(incoming_log_msg.level))
{
try
{
s->log(incoming_log_msg);
}
SPDLOG_CATCH_AND_HANDLE
}
}
handle_flush_interval();
return true;
}
assert(false);
return true; // should not be reached
}
inline void spdlog::details::async_log_helper::set_formatter(formatter_ptr msg_formatter)
{
_formatter = std::move(msg_formatter);
_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);
_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();
}
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()
{
for (auto &s : _sinks)
{
try
{
s->flush();
}
SPDLOG_CATCH_AND_HANDLE
}
_last_flush = os::now();
for (auto &s : _sinks)
{
try
{
s->flush();
}
SPDLOG_CATCH_AND_HANDLE
}
_last_flush = os::now();
}

View File

@ -21,8 +21,8 @@ inline spdlog::async_logger::async_logger(const std::string &logger_name, const
const async_overflow_policy overflow_policy, const std::function<void()> &worker_warmup_cb,
const std::chrono::milliseconds &flush_interval_ms, const std::function<void()> &worker_teardown_cb)
: logger(logger_name, begin, end)
, _async_log_helper(new details::async_log_helper(
logger_name, _formatter, _sinks, queue_size, _err_handler, overflow_policy, worker_warmup_cb, flush_interval_ms, worker_teardown_cb))
, _async_log_helper(new details::async_log_helper(logger_name, _formatter, _sinks, queue_size, _err_handler, overflow_policy,
worker_warmup_cb, flush_interval_ms, worker_teardown_cb))
{
}

View File

@ -84,7 +84,7 @@ inline void spdlog::logger::log(level::level_enum lvl, const char *msg)
log_msg.raw << msg;
_sink_it(log_msg);
}
SPDLOG_CATCH_AND_HANDLE
SPDLOG_CATCH_AND_HANDLE
}
template<typename T>
@ -100,7 +100,7 @@ inline void spdlog::logger::log(level::level_enum lvl, const T &msg)
log_msg.raw << msg;
_sink_it(log_msg);
}
SPDLOG_CATCH_AND_HANDLE
SPDLOG_CATCH_AND_HANDLE
}
template<typename Arg1, typename... Args>
@ -307,14 +307,14 @@ inline void spdlog::logger::_set_formatter(formatter_ptr msg_formatter)
inline void spdlog::logger::flush()
{
try
{
for (auto &sink : _sinks)
{
sink->flush();
}
}
SPDLOG_CATCH_AND_HANDLE
try
{
for (auto &sink : _sinks)
{
sink->flush();
}
}
SPDLOG_CATCH_AND_HANDLE
}
inline void spdlog::logger::_default_err_handler(const std::string &msg)

View File

@ -12,10 +12,10 @@ class failing_sink : public spdlog::sinks::sink
throw std::runtime_error("some error happened during log");
}
void flush() override
{
throw std::runtime_error("some error happened during flush");
}
void flush() override
{
throw std::runtime_error("some error happened during flush");
}
};
using namespace std;
TEST_CASE("default_error_handler", "[errors]]")
@ -67,10 +67,10 @@ TEST_CASE("default_error_handler2", "[errors]]")
TEST_CASE("flush_error_handler", "[errors]]")
{
spdlog::drop_all();
auto logger = spdlog::create<failing_sink>("failed_logger");
logger->set_error_handler([=](const std::string &) { throw custom_ex(); });
REQUIRE_THROWS_AS(logger->flush(), custom_ex);
spdlog::drop_all();
auto logger = spdlog::create<failing_sink>("failed_logger");
logger->set_error_handler([=](const std::string &) { throw custom_ex(); });
REQUIRE_THROWS_AS(logger->flush(), custom_ex);
}
TEST_CASE("async_error_handler", "[errors]]")
@ -115,10 +115,10 @@ TEST_CASE("async_error_handler2", "[errors]]")
throw std::runtime_error("Failed open logs/custom_err2.txt");
ofs << err_msg;
});
logger->info("Hello failure");
logger->info("Hello failure");
spdlog::drop("failed_logger"); // force logger to drain the queue and shutdown
spdlog::set_sync_mode();
logger.reset();
logger.reset();
}
REQUIRE(file_contents("logs/custom_err2.txt") == err_msg);

View File

@ -70,7 +70,7 @@ TEST_CASE("rotating_file_logger1", "[rotating_logger]]")
TEST_CASE("rotating_file_logger2", "[rotating_logger]]")
{
prepare_logdir();
size_t max_size = 10 * 1024;
size_t max_size = 10 * 1024;
std::string basename = "logs/rotating_log.txt";
auto logger = spdlog::rotating_logger_mt("logger", basename, max_size, 1);
for (int i = 0; i < 10; ++i)
@ -90,7 +90,7 @@ TEST_CASE("rotating_file_logger2", "[rotating_logger]]")
logger->flush();
REQUIRE(get_filesize(filename) <= max_size);
auto filename1 = "logs/rotating_log.1.txt";
auto filename1 = "logs/rotating_log.1.txt";
REQUIRE(get_filesize(filename1) <= max_size);
}