diff --git a/include/spdlog/details/async_log_helper.h b/include/spdlog/details/async_log_helper.h index 1e454550..c5a147ec 100644 --- a/include/spdlog/details/async_log_helper.h +++ b/include/spdlog/details/async_log_helper.h @@ -27,6 +27,7 @@ #include #include #include +#include namespace spdlog { @@ -185,6 +186,12 @@ private: // wait until the queue is empty void wait_empty_q(); + // counter for messages discarded due to queue overflow + std::atomic _discarded_msg_count; + + // handle discarded messages + void handle_discarded_msg(const std::string& logger_name); + }; } } @@ -211,7 +218,8 @@ inline spdlog::details::async_log_helper::async_log_helper( _worker_warmup_cb(worker_warmup_cb), _flush_interval_ms(flush_interval_ms), _worker_teardown_cb(worker_teardown_cb), - _worker_thread(&async_log_helper::worker_loop, this) + _worker_thread(&async_log_helper::worker_loop, this), + _discarded_msg_count(0) {} // Send to the worker thread termination message(level=off) @@ -237,16 +245,24 @@ inline void spdlog::details::async_log_helper::log(const details::log_msg& msg) inline void spdlog::details::async_log_helper::push_msg(details::async_log_helper::async_msg&& new_msg) { - if (!_q.enqueue(std::move(new_msg)) && _overflow_policy != async_overflow_policy::discard_log_msg) + if (!_q.enqueue(std::move(new_msg))) { - auto last_op_time = details::os::now(); - auto now = last_op_time; - do + if (_overflow_policy != async_overflow_policy::discard_log_msg) { - now = details::os::now(); - sleep_or_yield(now, last_op_time); + auto last_op_time = details::os::now(); + auto now = last_op_time; + do + { + now = details::os::now(); + sleep_or_yield(now, last_op_time); + } while (!_q.enqueue(std::move(new_msg))); + } + else + { +#if defined(SPDLOG_ASYNC_COUNT_DISCARDED_MSG) + _discarded_msg_count++; +#endif } - while (!_q.enqueue(std::move(new_msg))); } } @@ -305,6 +321,10 @@ inline bool spdlog::details::async_log_helper::process_next_msg(log_clock::time_ break; default: +#if defined(SPDLOG_ASYNC_COUNT_DISCARDED_MSG) + handle_discarded_msg(incoming_async_msg.logger_name); +#endif + log_msg incoming_log_msg; incoming_async_msg.fill_log_msg(incoming_log_msg); _formatter->format(incoming_log_msg); @@ -389,5 +409,18 @@ inline void spdlog::details::async_log_helper::set_error_handler(spdlog::log_err _err_handler = err_handler; } - +inline void spdlog::details::async_log_helper::handle_discarded_msg(const std::string& logger_name) +{ + unsigned int num_of_discarded_messages = _discarded_msg_count.exchange(0); + if (num_of_discarded_messages) + { + log_msg discarded_warning_msg(&logger_name, level::warn); + discarded_warning_msg.raw << "Discarded " << num_of_discarded_messages << " messages - logger queue overflow"; + _formatter->format(discarded_warning_msg); + for (auto &s : _sinks) + { + s->log(discarded_warning_msg); + } + } +} diff --git a/include/spdlog/tweakme.h b/include/spdlog/tweakme.h index c167c716..e568d301 100644 --- a/include/spdlog/tweakme.h +++ b/include/spdlog/tweakme.h @@ -120,3 +120,10 @@ // // #define SPDLOG_FINAL final /////////////////////////////////////////////////////////////////////////////// + +/////////////////////////////////////////////////////////////////////////////// +// Uncomment count in print warning message about number of dropped messages. +// Only relevant for async_logger with async_overflow_policy::discard_log_msg +// +// #define SPDLOG_ASYNC_COUNT_DISCARDED_MSG +/////////////////////////////////////////////////////////////////////////////// diff --git a/tests/CMakeLists.txt b/tests/CMakeLists.txt index ce275ccb..22329b4e 100644 --- a/tests/CMakeLists.txt +++ b/tests/CMakeLists.txt @@ -10,7 +10,7 @@ find_package(Threads) add_library(catch INTERFACE) target_include_directories(catch INTERFACE ${CMAKE_CURRENT_SOURCE_DIR}) -file(GLOB catch_tests LIST_DIRECTORIES false RELATIVE ${CMAKE_CURRENT_SOURCE_DIR} *.cpp) +file(GLOB catch_tests LIST_DIRECTORIES false RELATIVE ${CMAKE_CURRENT_SOURCE_DIR} *.cpp *.h *.hpp) add_executable(catch_tests ${catch_tests}) target_link_libraries(catch_tests spdlog ${CMAKE_THREAD_LIBS_INIT}) diff --git a/tests/async_logger.cpp b/tests/async_logger.cpp new file mode 100644 index 00000000..bcfb1ca6 --- /dev/null +++ b/tests/async_logger.cpp @@ -0,0 +1,38 @@ + +#include + +#include "includes.h" +#include "../include/spdlog/common.h" +#include "../include/spdlog/tweakme.h" + + +TEST_CASE("async_logging_overflow ", "[async_logging]") +{ + std::string filename = "logs/async_log_overflow.txt"; + auto sink = std::make_shared(filename, true); + auto logger = std::make_shared( + "overflow_logger", + sink, + 2, // queue size + spdlog::async_overflow_policy::discard_log_msg + ); + for (int i = 0; i < 8; i++) { + logger->info("Message #{}", i); + } + logger->flush(); + logger.reset(); + std::string the_log = file_contents(filename); +#if defined(SPDLOG_ASYNC_COUNT_DISCARDED_MSG) + std::cout << the_log << std::endl; + REQUIRE(the_log.find("Dropped 6 messages") != std::string::npos); +#endif +} + + + + + + + + +