From 74df115fc1fd943a1fc414c05c637a15a71c55e7 Mon Sep 17 00:00:00 2001 From: gabime Date: Thu, 22 Aug 2019 00:59:16 +0300 Subject: [PATCH 01/59] Removed uneeded include --- include/spdlog/details/log_msg.h | 1 - 1 file changed, 1 deletion(-) diff --git a/include/spdlog/details/log_msg.h b/include/spdlog/details/log_msg.h index f2976df8..30190f63 100644 --- a/include/spdlog/details/log_msg.h +++ b/include/spdlog/details/log_msg.h @@ -4,7 +4,6 @@ #pragma once #include "spdlog/common.h" -#include namespace spdlog { namespace details { From 6b527a50dd6ad878051514349e9ba60125e1fc5c Mon Sep 17 00:00:00 2001 From: gabime Date: Thu, 22 Aug 2019 19:36:47 +0300 Subject: [PATCH 02/59] backtrace sink and refactoring --- bench/async_bench.cpp | 2 + include/spdlog/details/log_msg.h | 6 +- include/spdlog/details/log_msg_buffer.h | 62 +++++++++++++++ include/spdlog/details/thread_pool-inl.h | 3 +- include/spdlog/details/thread_pool.h | 59 ++++---------- include/spdlog/sinks/backtrace-sink.h | 98 ++++++++++++++++++++++++ 6 files changed, 181 insertions(+), 49 deletions(-) create mode 100644 include/spdlog/details/log_msg_buffer.h create mode 100644 include/spdlog/sinks/backtrace-sink.h diff --git a/bench/async_bench.cpp b/bench/async_bench.cpp index e5732725..26836da0 100644 --- a/bench/async_bench.cpp +++ b/bench/async_bench.cpp @@ -115,6 +115,8 @@ int main(int argc, char *argv[]) auto file_sink = std::make_shared(filename, true); auto logger = std::make_shared("async_logger", std::move(file_sink), std::move(tp), async_overflow_policy::block); bench_mt(howmany, std::move(logger), threads); + + verify_file(filename, howmany); #ifdef SPDLOG_ASYNC_BENCH_VERIFY verify_file(filename, howmany); #endif // SPDLOG_ASYNC_BENCH_VERIFY diff --git a/include/spdlog/details/log_msg.h b/include/spdlog/details/log_msg.h index 30190f63..ccd41ecb 100644 --- a/include/spdlog/details/log_msg.h +++ b/include/spdlog/details/log_msg.h @@ -4,16 +4,18 @@ #pragma once #include "spdlog/common.h" +#include namespace spdlog { namespace details { struct log_msg { + log_msg() = default; log_msg(source_loc loc, string_view_t logger_name, level::level_enum lvl, string_view_t msg); log_msg(string_view_t logger_name, level::level_enum lvl, string_view_t msg); log_msg(const log_msg &other) = default; - const string_view_t logger_name; + string_view_t logger_name; level::level_enum level{level::off}; log_clock::time_point time; size_t thread_id{0}; @@ -23,7 +25,7 @@ struct log_msg mutable size_t color_range_end{0}; source_loc source; - const string_view_t payload; + string_view_t payload; }; } // namespace details } // namespace spdlog diff --git a/include/spdlog/details/log_msg_buffer.h b/include/spdlog/details/log_msg_buffer.h new file mode 100644 index 00000000..fa5675ce --- /dev/null +++ b/include/spdlog/details/log_msg_buffer.h @@ -0,0 +1,62 @@ +// Copyright(c) 2015-present, Gabi Melman & spdlog contributors. +// Distributed under the MIT License (http://opensource.org/licenses/MIT) + +#pragma once + +#include "spdlog/details/log_msg.h" +#include "spdlog/fmt/bundled/core.h" + +namespace spdlog { +namespace details { + +// regular log_msgs only holds string_views to stack data - so the cannot be stored for later use. +// this one can, since it contains and owns the payload buffer. +struct log_msg_buffer : log_msg +{ + fmt::basic_memory_buffer loggername_buf; + fmt::basic_memory_buffer payload_buf; + log_msg_buffer() = default; + + log_msg_buffer(const log_msg &orig_msg): log_msg(orig_msg) + { + update_buffers(); + } + + log_msg_buffer(const log_msg_buffer& other):log_msg(other) + { + update_buffers(); + } + + log_msg_buffer(const log_msg_buffer&& other):log_msg(std::move(other)) + { + update_buffers(); + } + + log_msg_buffer& operator=(log_msg_buffer &other) SPDLOG_NOEXCEPT + { + *static_cast(this) = other; + update_buffers(); + return *this; + } + + log_msg_buffer& operator=(log_msg_buffer &&other) SPDLOG_NOEXCEPT + { + *static_cast(this) = std::move(other); + update_buffers(); + return *this; + } + + void update_buffers() SPDLOG_NOEXCEPT + { + loggername_buf.clear(); + loggername_buf.append(logger_name.data(), logger_name.data() + logger_name.size()); + logger_name = string_view_t{loggername_buf.data(), loggername_buf.size()}; + + payload_buf.clear(); + payload_buf.append(payload.data(),payload.data() + payload.size()); + payload = string_view_t{payload_buf.data(), payload_buf.size()}; + } +}; + +} +} \ No newline at end of file diff --git a/include/spdlog/details/thread_pool-inl.h b/include/spdlog/details/thread_pool-inl.h index eecfa45c..1f3837d5 100644 --- a/include/spdlog/details/thread_pool-inl.h +++ b/include/spdlog/details/thread_pool-inl.h @@ -100,8 +100,7 @@ bool SPDLOG_INLINE thread_pool::process_next_msg_() { case async_msg_type::log: { - auto msg = incoming_async_msg.to_log_msg(); - incoming_async_msg.worker_ptr->backend_log_(msg); + incoming_async_msg.worker_ptr->backend_log_(incoming_async_msg); return true; } case async_msg_type::flush: diff --git a/include/spdlog/details/thread_pool.h b/include/spdlog/details/thread_pool.h index ff022082..e934c510 100644 --- a/include/spdlog/details/thread_pool.h +++ b/include/spdlog/details/thread_pool.h @@ -3,10 +3,11 @@ #pragma once -#include "spdlog/details/log_msg.h" +#include "spdlog/details/log_msg_buffer.h" #include "spdlog/details/mpmc_blocking_q.h" #include "spdlog/details/os.h" + #include #include #include @@ -27,17 +28,12 @@ enum class async_msg_type terminate }; +#include "spdlog/details/log_msg_buffer.h" // Async msg to move to/from the queue // Movable only. should never be copied -struct async_msg +struct async_msg:log_msg_buffer { async_msg_type msg_type {async_msg_type::log}; - level::level_enum level {level::info}; - log_clock::time_point time; - size_t thread_id {0}; - fmt::basic_memory_buffer raw; - - source_loc source; async_logger_ptr worker_ptr; async_msg() = default; @@ -49,51 +45,35 @@ struct async_msg // support for vs2013 move #if defined(_MSC_VER) && _MSC_VER <= 1800 async_msg(async_msg &&other) - : msg_type(other.msg_type) - , level(other.level) - , time(other.time) - , thread_id(other.thread_id) - , raw(move(other.raw)) - , msg_id(other.msg_id) - , source(other.source) + : log_msg_buffer(std::move(other)) + , msg_type(other.msg_type) , worker_ptr(std::move(other.worker_ptr)) {} async_msg &operator=(async_msg &&other) + { + *static_cast(this) = std::move(other); msg_type = other.msg_type; - level = other.level; - time = other.time; - thread_id = other.thread_id; - raw = std::move(other.raw); - msg_id = other.msg_id; - source = other.source; worker_ptr = std::move(other.worker_ptr); return *this; } #else // (_MSC_VER) && _MSC_VER <= 1800 - async_msg(async_msg &&) = default; - async_msg &operator=(async_msg &&) = default; + async_msg(async_msg &&) SPDLOG_NOEXCEPT = default; + async_msg &operator=(async_msg &&) SPDLOG_NOEXCEPT = default; #endif // construct from log_msg with given type async_msg(async_logger_ptr &&worker, async_msg_type the_type, details::log_msg &m) - : msg_type(the_type) - , level(m.level) - , time(m.time) - , thread_id(m.thread_id) - , source(m.source) + : log_msg_buffer(m) + , msg_type(the_type) , worker_ptr(std::move(worker)) { - raw.append(m.payload.data(), m.payload.data() + m.payload.size()); } async_msg(async_logger_ptr &&worker, async_msg_type the_type) - : msg_type(the_type) - , level(level::off) - , time() - , thread_id(0) - , source() + : log_msg_buffer() + , msg_type(the_type) , worker_ptr(std::move(worker)) {} @@ -101,17 +81,6 @@ struct async_msg : async_msg(nullptr, the_type) {} - // copy into log_msg - log_msg to_log_msg() - { - log_msg msg(string_view_t(worker_ptr->name()), level, string_view_t(raw.data(), raw.size())); - msg.time = time; - msg.thread_id = thread_id; - msg.source = source; - msg.color_range_start = 0; - msg.color_range_end = 0; - return msg; - } }; class thread_pool diff --git a/include/spdlog/sinks/backtrace-sink.h b/include/spdlog/sinks/backtrace-sink.h new file mode 100644 index 00000000..470763b8 --- /dev/null +++ b/include/spdlog/sinks/backtrace-sink.h @@ -0,0 +1,98 @@ +// Copyright(c) 2015-present, Gabi Melman & spdlog contributors. +// Distributed under the MIT License (http://opensource.org/licenses/MIT) + +#pragma once + +#include "dist_sink.h" +#include "spdlog/details/null_mutex.h" +#include "spdlog/details/log_msg.h" +#include "spdlog/details/log_msg_buffer.h" +#include "spdlog/details/circular_q.h" + +#include +#include +#include + +// Store log messages in circular buffer +// If it encounters a message with high enough level, it will send all pervious message to its child sinks +// Useful for storing debug data in case of error/warning happens + +// +// Example: +// +// #include "spdlog/spdlog.h" +// #include "spdlog/sinks/backtrace_sink.h +// +// int main() { +// auto backtrace_sink = std::make_shared(); +// backtrace_sink ->add_sink(std::make_shared()); +// spdlog::logger l("logger", backtrace_sink); +// logger.set_level(spdlog::level::trace); +// l.trace("Hello"); +// l.debug("Hello"); +// l.info("Hello"); +// l.warn("This will trigger the log of all prev messages in the queue"); +// } + + +namespace spdlog { +namespace sinks { +template +class backtrace_sink : public dist_sink +{ +public: + explicit backtrace_sink(level::level_enum trigger_level = spdlog::level::warn, size_t n_messages = 32) + : trigger_level_{trigger_level}, traceback_msgs_{n_messages} + {} + +protected: + level::level_enum trigger_level_; + + details::circular_q traceback_msgs_; + + // if current message is high enough, trigger a backtrace log, + // otherwise save the message in the queue for future trigger. + void sink_it_(const details::log_msg &msg) override + { + if(msg.level < trigger_level_) + { + traceback_msgs_.push_back(details::log_msg_buffer(msg)); + } + if(msg.level > level::debug) + { + dist_sink::sink_it_(msg); + } + if(msg.level >= trigger_level_) + { + log_backtrace_(msg.logger_name); + } + } + + void log_backtrace_(const string_view_t& logger_name) + { + if(traceback_msgs_.empty()) + { + return; + } + + dist_sink::sink_it_(details::log_msg{ + logger_name,level::info,"********************* [Backtrace Start] *********************"}); + + do + { + details::log_msg_buffer popped; + traceback_msgs_.pop_front(popped); + dist_sink::sink_it_(popped); + } + while (!traceback_msgs_.empty()); + + dist_sink::sink_it_(details::log_msg{ + logger_name,level::info,"********************* [Backtrace End] ***********************"}); + } +}; + +using backtrace_sink_mt = backtrace_sink; +using backtrace_sink_st = backtrace_sink; + +} // namespace sinks +} // namespace spdlog From f1718fb5b369425bf32d372aaf7af458ba8c42a6 Mon Sep 17 00:00:00 2001 From: gabime Date: Thu, 22 Aug 2019 19:38:00 +0300 Subject: [PATCH 03/59] clang-format --- include/spdlog/details/log_msg_buffer.h | 23 +++++++++++++---------- include/spdlog/details/thread_pool.h | 11 ++++------- include/spdlog/sinks/backtrace-sink.h | 25 ++++++++++++------------- include/spdlog/sinks/daily_file_sink.h | 1 - 4 files changed, 29 insertions(+), 31 deletions(-) diff --git a/include/spdlog/details/log_msg_buffer.h b/include/spdlog/details/log_msg_buffer.h index fa5675ce..dbe7be84 100644 --- a/include/spdlog/details/log_msg_buffer.h +++ b/include/spdlog/details/log_msg_buffer.h @@ -17,31 +17,34 @@ struct log_msg_buffer : log_msg fmt::basic_memory_buffer payload_buf; log_msg_buffer() = default; - log_msg_buffer(const log_msg &orig_msg): log_msg(orig_msg) + log_msg_buffer(const log_msg &orig_msg) + : log_msg(orig_msg) { update_buffers(); } - log_msg_buffer(const log_msg_buffer& other):log_msg(other) + log_msg_buffer(const log_msg_buffer &other) + : log_msg(other) { update_buffers(); } - log_msg_buffer(const log_msg_buffer&& other):log_msg(std::move(other)) + log_msg_buffer(const log_msg_buffer &&other) + : log_msg(std::move(other)) { update_buffers(); } - log_msg_buffer& operator=(log_msg_buffer &other) SPDLOG_NOEXCEPT + log_msg_buffer &operator=(log_msg_buffer &other) SPDLOG_NOEXCEPT { - *static_cast(this) = other; + *static_cast(this) = other; update_buffers(); return *this; } - log_msg_buffer& operator=(log_msg_buffer &&other) SPDLOG_NOEXCEPT + log_msg_buffer &operator=(log_msg_buffer &&other) SPDLOG_NOEXCEPT { - *static_cast(this) = std::move(other); + *static_cast(this) = std::move(other); update_buffers(); return *this; } @@ -53,10 +56,10 @@ struct log_msg_buffer : log_msg logger_name = string_view_t{loggername_buf.data(), loggername_buf.size()}; payload_buf.clear(); - payload_buf.append(payload.data(),payload.data() + payload.size()); + payload_buf.append(payload.data(), payload.data() + payload.size()); payload = string_view_t{payload_buf.data(), payload_buf.size()}; } }; -} -} \ No newline at end of file +} // namespace details +} // namespace spdlog \ No newline at end of file diff --git a/include/spdlog/details/thread_pool.h b/include/spdlog/details/thread_pool.h index e934c510..fe5e3850 100644 --- a/include/spdlog/details/thread_pool.h +++ b/include/spdlog/details/thread_pool.h @@ -7,7 +7,6 @@ #include "spdlog/details/mpmc_blocking_q.h" #include "spdlog/details/os.h" - #include #include #include @@ -31,9 +30,9 @@ enum class async_msg_type #include "spdlog/details/log_msg_buffer.h" // Async msg to move to/from the queue // Movable only. should never be copied -struct async_msg:log_msg_buffer +struct async_msg : log_msg_buffer { - async_msg_type msg_type {async_msg_type::log}; + async_msg_type msg_type{async_msg_type::log}; async_logger_ptr worker_ptr; async_msg() = default; @@ -53,7 +52,7 @@ struct async_msg:log_msg_buffer async_msg &operator=(async_msg &&other) { - *static_cast(this) = std::move(other); + *static_cast(this) = std::move(other); msg_type = other.msg_type; worker_ptr = std::move(other.worker_ptr); return *this; @@ -68,8 +67,7 @@ struct async_msg:log_msg_buffer : log_msg_buffer(m) , msg_type(the_type) , worker_ptr(std::move(worker)) - { - } + {} async_msg(async_logger_ptr &&worker, async_msg_type the_type) : log_msg_buffer() @@ -80,7 +78,6 @@ struct async_msg:log_msg_buffer explicit async_msg(async_msg_type the_type) : async_msg(nullptr, the_type) {} - }; class thread_pool diff --git a/include/spdlog/sinks/backtrace-sink.h b/include/spdlog/sinks/backtrace-sink.h index 470763b8..44f35365 100644 --- a/include/spdlog/sinks/backtrace-sink.h +++ b/include/spdlog/sinks/backtrace-sink.h @@ -34,7 +34,6 @@ // l.warn("This will trigger the log of all prev messages in the queue"); // } - namespace spdlog { namespace sinks { template @@ -42,7 +41,8 @@ class backtrace_sink : public dist_sink { public: explicit backtrace_sink(level::level_enum trigger_level = spdlog::level::warn, size_t n_messages = 32) - : trigger_level_{trigger_level}, traceback_msgs_{n_messages} + : trigger_level_{trigger_level} + , traceback_msgs_{n_messages} {} protected: @@ -54,40 +54,39 @@ protected: // otherwise save the message in the queue for future trigger. void sink_it_(const details::log_msg &msg) override { - if(msg.level < trigger_level_) + if (msg.level < trigger_level_) { traceback_msgs_.push_back(details::log_msg_buffer(msg)); } - if(msg.level > level::debug) + if (msg.level > level::debug) { dist_sink::sink_it_(msg); } - if(msg.level >= trigger_level_) + if (msg.level >= trigger_level_) { log_backtrace_(msg.logger_name); } } - void log_backtrace_(const string_view_t& logger_name) + void log_backtrace_(const string_view_t &logger_name) { - if(traceback_msgs_.empty()) + if (traceback_msgs_.empty()) { return; } - dist_sink::sink_it_(details::log_msg{ - logger_name,level::info,"********************* [Backtrace Start] *********************"}); + dist_sink::sink_it_( + details::log_msg{logger_name, level::info, "********************* [Backtrace Start] *********************"}); do { details::log_msg_buffer popped; traceback_msgs_.pop_front(popped); dist_sink::sink_it_(popped); - } - while (!traceback_msgs_.empty()); + } while (!traceback_msgs_.empty()); - dist_sink::sink_it_(details::log_msg{ - logger_name,level::info,"********************* [Backtrace End] ***********************"}); + dist_sink::sink_it_( + details::log_msg{logger_name, level::info, "********************* [Backtrace End] ***********************"}); } }; diff --git a/include/spdlog/sinks/daily_file_sink.h b/include/spdlog/sinks/daily_file_sink.h index 32cf6756..341b5c42 100644 --- a/include/spdlog/sinks/daily_file_sink.h +++ b/include/spdlog/sinks/daily_file_sink.h @@ -11,7 +11,6 @@ #include "spdlog/details/os.h" #include "spdlog/details/synchronous_factory.h" - #include #include #include From 5aefa1af3d29d8277cb847fa373e021b0b2a8a11 Mon Sep 17 00:00:00 2001 From: gabime Date: Thu, 22 Aug 2019 19:40:45 +0300 Subject: [PATCH 04/59] Fixed clang-tidy warnings --- include/spdlog/details/log_msg_buffer.h | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/include/spdlog/details/log_msg_buffer.h b/include/spdlog/details/log_msg_buffer.h index dbe7be84..98c1301f 100644 --- a/include/spdlog/details/log_msg_buffer.h +++ b/include/spdlog/details/log_msg_buffer.h @@ -17,7 +17,7 @@ struct log_msg_buffer : log_msg fmt::basic_memory_buffer payload_buf; log_msg_buffer() = default; - log_msg_buffer(const log_msg &orig_msg) + explicit log_msg_buffer(const log_msg &orig_msg) : log_msg(orig_msg) { update_buffers(); @@ -29,13 +29,13 @@ struct log_msg_buffer : log_msg update_buffers(); } - log_msg_buffer(const log_msg_buffer &&other) + log_msg_buffer(const log_msg_buffer &&other) SPDLOG_NOEXCEPT : log_msg(std::move(other)) { update_buffers(); } - log_msg_buffer &operator=(log_msg_buffer &other) SPDLOG_NOEXCEPT + log_msg_buffer &operator=(const log_msg_buffer &other) SPDLOG_NOEXCEPT { *static_cast(this) = other; update_buffers(); From a19d93e1a24a1e19357761e7c6b6f80f1363e4b0 Mon Sep 17 00:00:00 2001 From: gabime Date: Thu, 22 Aug 2019 19:45:32 +0300 Subject: [PATCH 05/59] brace initialize some ctors --- include/spdlog/details/thread_pool.h | 14 +++++++------- 1 file changed, 7 insertions(+), 7 deletions(-) diff --git a/include/spdlog/details/thread_pool.h b/include/spdlog/details/thread_pool.h index fe5e3850..aa8bd42f 100644 --- a/include/spdlog/details/thread_pool.h +++ b/include/spdlog/details/thread_pool.h @@ -64,19 +64,19 @@ struct async_msg : log_msg_buffer // construct from log_msg with given type async_msg(async_logger_ptr &&worker, async_msg_type the_type, details::log_msg &m) - : log_msg_buffer(m) - , msg_type(the_type) - , worker_ptr(std::move(worker)) + : log_msg_buffer{m} + , msg_type{the_type} + , worker_ptr{std::move(worker)} {} async_msg(async_logger_ptr &&worker, async_msg_type the_type) - : log_msg_buffer() - , msg_type(the_type) - , worker_ptr(std::move(worker)) + : log_msg_buffer{} + , msg_type{the_type} + , worker_ptr{std::move(worker)} {} explicit async_msg(async_msg_type the_type) - : async_msg(nullptr, the_type) + : async_msg{nullptr, the_type} {} }; From 7e728869cc18cfbb5d7ad50d82f6b7677c15b4d9 Mon Sep 17 00:00:00 2001 From: gabime Date: Thu, 22 Aug 2019 19:48:11 +0300 Subject: [PATCH 06/59] comment --- example/example.cpp | 237 ++---------------------- include/spdlog/details/log_msg_buffer.h | 2 +- 2 files changed, 20 insertions(+), 219 deletions(-) diff --git a/example/example.cpp b/example/example.cpp index ce57fc9d..3c3782ff 100644 --- a/example/example.cpp +++ b/example/example.cpp @@ -6,227 +6,28 @@ #include -void stdout_logger_example(); -void basic_example(); -void rotating_example(); -void daily_example(); -void async_example(); -void binary_example(); -void trace_example(); -void multi_sink_example(); -void user_defined_example(); -void err_handler_example(); -void syslog_example(); -void clone_example(); - +#define SPDLOG_ACTIVE_LEVEL SPDLOG_LEVEL_TRACE #include "spdlog/spdlog.h" - -int main(int, char *[]) -{ - spdlog::info("Welcome to spdlog version {}.{}.{} !", SPDLOG_VER_MAJOR, SPDLOG_VER_MINOR, SPDLOG_VER_PATCH); - spdlog::warn("Easy padding in numbers like {:08d}", 12); - spdlog::critical("Support for int: {0:d}; hex: {0:x}; oct: {0:o}; bin: {0:b}", 42); - spdlog::info("Support for floats {:03.2f}", 1.23456); - spdlog::info("Positional args are {1} {0}..", "too", "supported"); - spdlog::info("{:>8} aligned, {:<8} aligned", "right", "left"); - - // Runtime log levels - spdlog::set_level(spdlog::level::info); // Set global log level to info - spdlog::debug("This message should not be displayed!"); - spdlog::set_level(spdlog::level::trace); // Set specific logger's log level - spdlog::debug("This message should be displayed.."); - - // Customize msg format for all loggers - spdlog::set_pattern("[%H:%M:%S %z] [%^%L%$] [thread %t] %v"); - spdlog::info("This an info message with custom format"); - spdlog::set_pattern("%+"); // back to default format - - try - { - stdout_logger_example(); - basic_example(); - rotating_example(); - daily_example(); - clone_example(); - async_example(); - binary_example(); - multi_sink_example(); - user_defined_example(); - err_handler_example(); - trace_example(); - - // Flush all *registered* loggers using a worker thread every 3 seconds. - // note: registered loggers *must* be thread safe for this to work correctly! - spdlog::flush_every(std::chrono::seconds(3)); - - // Apply some function on all registered loggers - spdlog::apply_all([&](std::shared_ptr l) { l->info("End of example."); }); - - // Release all spdlog resources, and drop all loggers in the registry. - // This is optional (only mandatory if using windows + async log). - spdlog::shutdown(); - } - - // Exceptions will only be thrown upon failed logger or sink construction (not during logging). - catch (const spdlog::spdlog_ex &ex) - { - std::printf("Log initialization failed: %s\n", ex.what()); - return 1; - } -} - -#include "spdlog/sinks/stdout_color_sinks.h" -// or #include "spdlog/sinks/stdout_sinks.h" if no colors needed. -void stdout_logger_example() -{ - // Create color multi threaded logger. - auto console = spdlog::stdout_color_mt("console"); - // or for stderr: - // auto console = spdlog::stderr_color_mt("error-logger"); -} - -#include "spdlog/sinks/basic_file_sink.h" -void basic_example() -{ - // Create basic file logger (not rotated). - auto my_logger = spdlog::basic_logger_mt("file_logger", "logs/basic-log.txt"); -} - -#include "spdlog/sinks/rotating_file_sink.h" -void rotating_example() -{ - // Create a file rotating logger with 5mb size max and 3 rotated files. - auto rotating_logger = spdlog::rotating_logger_mt("some_logger_name", "logs/rotating.txt", 1048576 * 5, 3); -} - -#include "spdlog/sinks/daily_file_sink.h" -void daily_example() -{ - // Create a daily logger - a new file is created every day on 2:30am. - auto daily_logger = spdlog::daily_logger_mt("daily_logger", "logs/daily.txt", 2, 30); -} - -// Clone a logger and give it new name. -// Useful for creating component/subsystem loggers from some "root" logger. -void clone_example() -{ - auto network_logger = spdlog::default_logger()->clone("network"); - network_logger->info("Logging network stuff.."); -} - #include "spdlog/async.h" -void async_example() -{ - // Default thread pool settings can be modified *before* creating the async logger: - // spdlog::init_thread_pool(32768, 1); // queue with max 32k items 1 backing thread. - auto async_file = spdlog::basic_logger_mt("async_file_logger", "logs/async_log.txt"); - // alternatively: - // auto async_file = spdlog::create_async("async_file_logger", "logs/async_log.txt"); +#include "spdlog/sinks/stdout_color_sinks.h" +#include "spdlog/sinks/backtrace-sink.h" - for (int i = 1; i < 101; ++i) +#include + + +using namespace spdlog::details; +using namespace spdlog::sinks; + +int main(int, char *[]) { + auto backtrack_sink = std::make_shared(spdlog::level::debug, 10); + backtrack_sink ->add_sink(std::make_shared()); + spdlog::logger l("loggername", backtrack_sink); + l.set_level(spdlog::level::trace); + //spdlog::set_backtrace(spdlog::level::warn, 16) + for(int i = 0; i < 100; i++) { - async_file->info("Async message #{}", i); + //l.log(spdlog::source_loc{__FILE__, __LINE__, "main"}, spdlog::level::debug, "Debug message #{}", i); + SPDLOG_LOGGER_TRACE((&l), "Debug message #{}", i); } + l.warn("This will trigger the log of all prev messages in the queue"); } - -// Log binary data as hex. -// Many types of std::container types can be used. -// Iterator ranges are supported too. -// Format flags: -// {:X} - print in uppercase. -// {:s} - don't separate each byte with space. -// {:p} - don't print the position on each line start. -// {:n} - don't split the output to lines. - -#include "spdlog/fmt/bin_to_hex.h" -void binary_example() -{ - std::vector buf; - for (int i = 0; i < 80; i++) - { - buf.push_back(static_cast(i & 0xff)); - } - spdlog::info("Binary example: {}", spdlog::to_hex(buf)); - spdlog::info("Another binary example:{:n}", spdlog::to_hex(std::begin(buf), std::begin(buf) + 10)); - // more examples: - // logger->info("uppercase: {:X}", spdlog::to_hex(buf)); - // logger->info("uppercase, no delimiters: {:Xs}", spdlog::to_hex(buf)); - // logger->info("uppercase, no delimiters, no position info: {:Xsp}", spdlog::to_hex(buf)); -} - -// Compile time log levels. -// define SPDLOG_ACTIVE_LEVEL to required level (e.g. SPDLOG_LEVEL_TRACE) -void trace_example() -{ - // trace from default logger - SPDLOG_TRACE("Some trace message.. {} ,{}", 1, 3.23); - // debug from default logger - SPDLOG_DEBUG("Some debug message.. {} ,{}", 1, 3.23); - - // trace from logger object - auto logger = spdlog::get("file_logger"); - SPDLOG_LOGGER_TRACE(logger, "another trace message"); -} - -// A logger with multiple sinks (stdout and file) - each with a different format and log level. -void multi_sink_example() -{ - auto console_sink = std::make_shared(); - console_sink->set_level(spdlog::level::warn); - console_sink->set_pattern("[multi_sink_example] [%^%l%$] %v"); - - auto file_sink = std::make_shared("logs/multisink.txt", true); - file_sink->set_level(spdlog::level::trace); - - spdlog::logger logger("multi_sink", {console_sink, file_sink}); - logger.set_level(spdlog::level::debug); - logger.warn("this should appear in both console and file"); - logger.info("this message should not appear in the console, only in the file"); -} - -// User defined types logging by implementing operator<< -#include "spdlog/fmt/ostr.h" // must be included -struct my_type -{ - int i; - template - friend OStream &operator<<(OStream &os, const my_type &c) - { - return os << "[my_type i=" << c.i << "]"; - } -}; - -void user_defined_example() -{ - spdlog::info("user defined type: {}", my_type{14}); -} - -// Custom error handler. Will be triggered on log failure. -void err_handler_example() -{ - // can be set globally or per logger(logger->set_error_handler(..)) - spdlog::set_error_handler([](const std::string &msg) { printf("*** Custom log error handler: %s ***\n", msg.c_str()); }); -} - -// syslog example (linux/osx/freebsd) -#ifndef _WIN32 -#include "spdlog/sinks/syslog_sink.h" -void syslog_example() -{ - std::string ident = "spdlog-example"; - auto syslog_logger = spdlog::syslog_logger_mt("syslog", ident, LOG_PID); - syslog_logger->warn("This is warning that will end up in syslog."); -} -#endif - -// Android example. -#if defined(__ANDROID__) -#include "spdlog/sinks/android_sink.h" -void android_example() -{ - std::string tag = "spdlog-android"; - auto android_logger = spdlog::android_logger_mt("android", tag); - android_logger->critical("Use \"adb shell logcat\" to view this message."); -} - -#endif diff --git a/include/spdlog/details/log_msg_buffer.h b/include/spdlog/details/log_msg_buffer.h index 98c1301f..019433aa 100644 --- a/include/spdlog/details/log_msg_buffer.h +++ b/include/spdlog/details/log_msg_buffer.h @@ -9,7 +9,7 @@ namespace spdlog { namespace details { -// regular log_msgs only holds string_views to stack data - so the cannot be stored for later use. +// regular log_msgs hold string_views to stack data - so they cannot be stored for later use. // this one can, since it contains and owns the payload buffer. struct log_msg_buffer : log_msg { From 0284a23d0ab5421107002894755c407dc767a007 Mon Sep 17 00:00:00 2001 From: gabime Date: Thu, 22 Aug 2019 19:57:59 +0300 Subject: [PATCH 07/59] Changed sink_it_ to accept const log_message& --- include/spdlog/async_logger-inl.h | 2 +- include/spdlog/async_logger.h | 3 +-- include/spdlog/details/thread_pool-inl.h | 2 +- include/spdlog/details/thread_pool.h | 4 ++-- include/spdlog/logger-inl.h | 2 +- include/spdlog/logger.h | 2 +- 6 files changed, 7 insertions(+), 8 deletions(-) diff --git a/include/spdlog/async_logger-inl.h b/include/spdlog/async_logger-inl.h index 45c6d8a9..e3866083 100644 --- a/include/spdlog/async_logger-inl.h +++ b/include/spdlog/async_logger-inl.h @@ -25,7 +25,7 @@ SPDLOG_INLINE spdlog::async_logger::async_logger( {} // send the log message to the thread pool -SPDLOG_INLINE void spdlog::async_logger::sink_it_(details::log_msg &msg) +SPDLOG_INLINE void spdlog::async_logger::sink_it_(const details::log_msg &msg) { if (auto pool_ptr = thread_pool_.lock()) { diff --git a/include/spdlog/async_logger.h b/include/spdlog/async_logger.h index 9899837b..b3026f1d 100644 --- a/include/spdlog/async_logger.h +++ b/include/spdlog/async_logger.h @@ -52,9 +52,8 @@ public: std::shared_ptr clone(std::string new_name) override; protected: - void sink_it_(details::log_msg &msg) override; + void sink_it_(const details::log_msg &msg) override; void flush_() override; - void backend_log_(const details::log_msg &incoming_log_msg); void backend_flush_(); diff --git a/include/spdlog/details/thread_pool-inl.h b/include/spdlog/details/thread_pool-inl.h index 1f3837d5..38e3d135 100644 --- a/include/spdlog/details/thread_pool-inl.h +++ b/include/spdlog/details/thread_pool-inl.h @@ -51,7 +51,7 @@ SPDLOG_INLINE thread_pool::~thread_pool() SPDLOG_CATCH_ALL() {} } -void SPDLOG_INLINE thread_pool::post_log(async_logger_ptr &&worker_ptr, details::log_msg &msg, async_overflow_policy overflow_policy) +void SPDLOG_INLINE thread_pool::post_log(async_logger_ptr &&worker_ptr, const details::log_msg &msg, async_overflow_policy overflow_policy) { async_msg async_m(std::move(worker_ptr), async_msg_type::log, msg); post_async_msg_(std::move(async_m), overflow_policy); diff --git a/include/spdlog/details/thread_pool.h b/include/spdlog/details/thread_pool.h index aa8bd42f..00c375d3 100644 --- a/include/spdlog/details/thread_pool.h +++ b/include/spdlog/details/thread_pool.h @@ -63,7 +63,7 @@ struct async_msg : log_msg_buffer #endif // construct from log_msg with given type - async_msg(async_logger_ptr &&worker, async_msg_type the_type, details::log_msg &m) + async_msg(async_logger_ptr &&worker, async_msg_type the_type, const details::log_msg &m) : log_msg_buffer{m} , msg_type{the_type} , worker_ptr{std::move(worker)} @@ -95,7 +95,7 @@ public: thread_pool(const thread_pool &) = delete; thread_pool &operator=(thread_pool &&) = delete; - void post_log(async_logger_ptr &&worker_ptr, details::log_msg &msg, async_overflow_policy overflow_policy); + void post_log(async_logger_ptr &&worker_ptr, const details::log_msg &msg, async_overflow_policy overflow_policy); void post_flush(async_logger_ptr &&worker_ptr, async_overflow_policy overflow_policy); size_t overrun_counter(); diff --git a/include/spdlog/logger-inl.h b/include/spdlog/logger-inl.h index 52d3fd5f..29a43dfa 100644 --- a/include/spdlog/logger-inl.h +++ b/include/spdlog/logger-inl.h @@ -161,7 +161,7 @@ SPDLOG_INLINE std::shared_ptr logger::clone(std::string logger_name) } // protected methods -SPDLOG_INLINE void logger::sink_it_(details::log_msg &msg) +SPDLOG_INLINE void logger::sink_it_(const details::log_msg &msg) { for (auto &sink : sinks_) { diff --git a/include/spdlog/logger.h b/include/spdlog/logger.h index 2778fef4..bc497532 100644 --- a/include/spdlog/logger.h +++ b/include/spdlog/logger.h @@ -346,7 +346,7 @@ protected: spdlog::level_t flush_level_{level::off}; err_handler custom_err_handler_{nullptr}; - virtual void sink_it_(details::log_msg &msg); + virtual void sink_it_(const details::log_msg &msg); virtual void flush_(); bool should_flush_(const details::log_msg &msg); From 0db4978899327be783c2c3e3167ac0637d563b89 Mon Sep 17 00:00:00 2001 From: gabime Date: Thu, 22 Aug 2019 19:58:49 +0300 Subject: [PATCH 08/59] Fixed example --- example/example.cpp | 233 ++++++++++++++++++++++++++++++++++++++++---- 1 file changed, 216 insertions(+), 17 deletions(-) diff --git a/example/example.cpp b/example/example.cpp index 3c3782ff..ce57fc9d 100644 --- a/example/example.cpp +++ b/example/example.cpp @@ -6,28 +6,227 @@ #include -#define SPDLOG_ACTIVE_LEVEL SPDLOG_LEVEL_TRACE +void stdout_logger_example(); +void basic_example(); +void rotating_example(); +void daily_example(); +void async_example(); +void binary_example(); +void trace_example(); +void multi_sink_example(); +void user_defined_example(); +void err_handler_example(); +void syslog_example(); +void clone_example(); + #include "spdlog/spdlog.h" -#include "spdlog/async.h" -#include "spdlog/sinks/stdout_color_sinks.h" -#include "spdlog/sinks/backtrace-sink.h" -#include +int main(int, char *[]) +{ + spdlog::info("Welcome to spdlog version {}.{}.{} !", SPDLOG_VER_MAJOR, SPDLOG_VER_MINOR, SPDLOG_VER_PATCH); + spdlog::warn("Easy padding in numbers like {:08d}", 12); + spdlog::critical("Support for int: {0:d}; hex: {0:x}; oct: {0:o}; bin: {0:b}", 42); + spdlog::info("Support for floats {:03.2f}", 1.23456); + spdlog::info("Positional args are {1} {0}..", "too", "supported"); + spdlog::info("{:>8} aligned, {:<8} aligned", "right", "left"); + // Runtime log levels + spdlog::set_level(spdlog::level::info); // Set global log level to info + spdlog::debug("This message should not be displayed!"); + spdlog::set_level(spdlog::level::trace); // Set specific logger's log level + spdlog::debug("This message should be displayed.."); -using namespace spdlog::details; -using namespace spdlog::sinks; + // Customize msg format for all loggers + spdlog::set_pattern("[%H:%M:%S %z] [%^%L%$] [thread %t] %v"); + spdlog::info("This an info message with custom format"); + spdlog::set_pattern("%+"); // back to default format -int main(int, char *[]) { - auto backtrack_sink = std::make_shared(spdlog::level::debug, 10); - backtrack_sink ->add_sink(std::make_shared()); - spdlog::logger l("loggername", backtrack_sink); - l.set_level(spdlog::level::trace); - //spdlog::set_backtrace(spdlog::level::warn, 16) - for(int i = 0; i < 100; i++) + try { - //l.log(spdlog::source_loc{__FILE__, __LINE__, "main"}, spdlog::level::debug, "Debug message #{}", i); - SPDLOG_LOGGER_TRACE((&l), "Debug message #{}", i); + stdout_logger_example(); + basic_example(); + rotating_example(); + daily_example(); + clone_example(); + async_example(); + binary_example(); + multi_sink_example(); + user_defined_example(); + err_handler_example(); + trace_example(); + + // Flush all *registered* loggers using a worker thread every 3 seconds. + // note: registered loggers *must* be thread safe for this to work correctly! + spdlog::flush_every(std::chrono::seconds(3)); + + // Apply some function on all registered loggers + spdlog::apply_all([&](std::shared_ptr l) { l->info("End of example."); }); + + // Release all spdlog resources, and drop all loggers in the registry. + // This is optional (only mandatory if using windows + async log). + spdlog::shutdown(); + } + + // Exceptions will only be thrown upon failed logger or sink construction (not during logging). + catch (const spdlog::spdlog_ex &ex) + { + std::printf("Log initialization failed: %s\n", ex.what()); + return 1; } - l.warn("This will trigger the log of all prev messages in the queue"); } + +#include "spdlog/sinks/stdout_color_sinks.h" +// or #include "spdlog/sinks/stdout_sinks.h" if no colors needed. +void stdout_logger_example() +{ + // Create color multi threaded logger. + auto console = spdlog::stdout_color_mt("console"); + // or for stderr: + // auto console = spdlog::stderr_color_mt("error-logger"); +} + +#include "spdlog/sinks/basic_file_sink.h" +void basic_example() +{ + // Create basic file logger (not rotated). + auto my_logger = spdlog::basic_logger_mt("file_logger", "logs/basic-log.txt"); +} + +#include "spdlog/sinks/rotating_file_sink.h" +void rotating_example() +{ + // Create a file rotating logger with 5mb size max and 3 rotated files. + auto rotating_logger = spdlog::rotating_logger_mt("some_logger_name", "logs/rotating.txt", 1048576 * 5, 3); +} + +#include "spdlog/sinks/daily_file_sink.h" +void daily_example() +{ + // Create a daily logger - a new file is created every day on 2:30am. + auto daily_logger = spdlog::daily_logger_mt("daily_logger", "logs/daily.txt", 2, 30); +} + +// Clone a logger and give it new name. +// Useful for creating component/subsystem loggers from some "root" logger. +void clone_example() +{ + auto network_logger = spdlog::default_logger()->clone("network"); + network_logger->info("Logging network stuff.."); +} + +#include "spdlog/async.h" +void async_example() +{ + // Default thread pool settings can be modified *before* creating the async logger: + // spdlog::init_thread_pool(32768, 1); // queue with max 32k items 1 backing thread. + auto async_file = spdlog::basic_logger_mt("async_file_logger", "logs/async_log.txt"); + // alternatively: + // auto async_file = spdlog::create_async("async_file_logger", "logs/async_log.txt"); + + for (int i = 1; i < 101; ++i) + { + async_file->info("Async message #{}", i); + } +} + +// Log binary data as hex. +// Many types of std::container types can be used. +// Iterator ranges are supported too. +// Format flags: +// {:X} - print in uppercase. +// {:s} - don't separate each byte with space. +// {:p} - don't print the position on each line start. +// {:n} - don't split the output to lines. + +#include "spdlog/fmt/bin_to_hex.h" +void binary_example() +{ + std::vector buf; + for (int i = 0; i < 80; i++) + { + buf.push_back(static_cast(i & 0xff)); + } + spdlog::info("Binary example: {}", spdlog::to_hex(buf)); + spdlog::info("Another binary example:{:n}", spdlog::to_hex(std::begin(buf), std::begin(buf) + 10)); + // more examples: + // logger->info("uppercase: {:X}", spdlog::to_hex(buf)); + // logger->info("uppercase, no delimiters: {:Xs}", spdlog::to_hex(buf)); + // logger->info("uppercase, no delimiters, no position info: {:Xsp}", spdlog::to_hex(buf)); +} + +// Compile time log levels. +// define SPDLOG_ACTIVE_LEVEL to required level (e.g. SPDLOG_LEVEL_TRACE) +void trace_example() +{ + // trace from default logger + SPDLOG_TRACE("Some trace message.. {} ,{}", 1, 3.23); + // debug from default logger + SPDLOG_DEBUG("Some debug message.. {} ,{}", 1, 3.23); + + // trace from logger object + auto logger = spdlog::get("file_logger"); + SPDLOG_LOGGER_TRACE(logger, "another trace message"); +} + +// A logger with multiple sinks (stdout and file) - each with a different format and log level. +void multi_sink_example() +{ + auto console_sink = std::make_shared(); + console_sink->set_level(spdlog::level::warn); + console_sink->set_pattern("[multi_sink_example] [%^%l%$] %v"); + + auto file_sink = std::make_shared("logs/multisink.txt", true); + file_sink->set_level(spdlog::level::trace); + + spdlog::logger logger("multi_sink", {console_sink, file_sink}); + logger.set_level(spdlog::level::debug); + logger.warn("this should appear in both console and file"); + logger.info("this message should not appear in the console, only in the file"); +} + +// User defined types logging by implementing operator<< +#include "spdlog/fmt/ostr.h" // must be included +struct my_type +{ + int i; + template + friend OStream &operator<<(OStream &os, const my_type &c) + { + return os << "[my_type i=" << c.i << "]"; + } +}; + +void user_defined_example() +{ + spdlog::info("user defined type: {}", my_type{14}); +} + +// Custom error handler. Will be triggered on log failure. +void err_handler_example() +{ + // can be set globally or per logger(logger->set_error_handler(..)) + spdlog::set_error_handler([](const std::string &msg) { printf("*** Custom log error handler: %s ***\n", msg.c_str()); }); +} + +// syslog example (linux/osx/freebsd) +#ifndef _WIN32 +#include "spdlog/sinks/syslog_sink.h" +void syslog_example() +{ + std::string ident = "spdlog-example"; + auto syslog_logger = spdlog::syslog_logger_mt("syslog", ident, LOG_PID); + syslog_logger->warn("This is warning that will end up in syslog."); +} +#endif + +// Android example. +#if defined(__ANDROID__) +#include "spdlog/sinks/android_sink.h" +void android_example() +{ + std::string tag = "spdlog-android"; + auto android_logger = spdlog::android_logger_mt("android", tag); + android_logger->critical("Use \"adb shell logcat\" to view this message."); +} + +#endif From 2848e517553881d990bb2de9ce547ae99884848a Mon Sep 17 00:00:00 2001 From: gabime Date: Fri, 23 Aug 2019 00:16:13 +0300 Subject: [PATCH 09/59] Clean log_msg_buffer --- include/spdlog/details/log_msg_buffer.h | 52 ++++++------------------- 1 file changed, 11 insertions(+), 41 deletions(-) diff --git a/include/spdlog/details/log_msg_buffer.h b/include/spdlog/details/log_msg_buffer.h index 019433aa..2dbe5aa4 100644 --- a/include/spdlog/details/log_msg_buffer.h +++ b/include/spdlog/details/log_msg_buffer.h @@ -9,56 +9,26 @@ namespace spdlog { namespace details { -// regular log_msgs hold string_views to stack data - so they cannot be stored for later use. -// this one can, since it contains and owns the payload buffer. +// extend log_msg with internal buffer to store its payload. +// this is needed since log_msg holds string_views that points to stack data. + struct log_msg_buffer : log_msg { - fmt::basic_memory_buffer loggername_buf; - fmt::basic_memory_buffer payload_buf; + fmt::basic_memory_buffer buffer; log_msg_buffer() = default; explicit log_msg_buffer(const log_msg &orig_msg) : log_msg(orig_msg) { - update_buffers(); + buffer.append(logger_name.begin(), logger_name.end()); + logger_name = string_view_t{buffer.data(), buffer.size()}; + + buffer.append(payload.begin(), payload.end()); + payload = string_view_t{logger_name.end(), payload.size()}; } - log_msg_buffer(const log_msg_buffer &other) - : log_msg(other) - { - update_buffers(); - } - - log_msg_buffer(const log_msg_buffer &&other) SPDLOG_NOEXCEPT - : log_msg(std::move(other)) - { - update_buffers(); - } - - log_msg_buffer &operator=(const log_msg_buffer &other) SPDLOG_NOEXCEPT - { - *static_cast(this) = other; - update_buffers(); - return *this; - } - - log_msg_buffer &operator=(log_msg_buffer &&other) SPDLOG_NOEXCEPT - { - *static_cast(this) = std::move(other); - update_buffers(); - return *this; - } - - void update_buffers() SPDLOG_NOEXCEPT - { - loggername_buf.clear(); - loggername_buf.append(logger_name.data(), logger_name.data() + logger_name.size()); - logger_name = string_view_t{loggername_buf.data(), loggername_buf.size()}; - - payload_buf.clear(); - payload_buf.append(payload.data(), payload.data() + payload.size()); - payload = string_view_t{payload_buf.data(), payload_buf.size()}; - } + log_msg_buffer(log_msg_buffer &&other) = default; + log_msg_buffer &operator=(log_msg_buffer &&other) = default; }; } // namespace details From 543060683b3ea68c6f00afc56392fa4c4f2e3387 Mon Sep 17 00:00:00 2001 From: gabime Date: Fri, 23 Aug 2019 00:16:44 +0300 Subject: [PATCH 10/59] Clean log_msg_buffer --- include/spdlog/details/thread_pool.h | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/include/spdlog/details/thread_pool.h b/include/spdlog/details/thread_pool.h index 00c375d3..f02517b3 100644 --- a/include/spdlog/details/thread_pool.h +++ b/include/spdlog/details/thread_pool.h @@ -58,8 +58,8 @@ struct async_msg : log_msg_buffer return *this; } #else // (_MSC_VER) && _MSC_VER <= 1800 - async_msg(async_msg &&) SPDLOG_NOEXCEPT = default; - async_msg &operator=(async_msg &&) SPDLOG_NOEXCEPT = default; + async_msg(async_msg &&) = default; + async_msg &operator=(async_msg &&) = default; #endif // construct from log_msg with given type From 65407539bb7cbb7faf9cfedfbf6d871cde732298 Mon Sep 17 00:00:00 2001 From: gabime Date: Fri, 23 Aug 2019 01:10:48 +0300 Subject: [PATCH 11/59] Fixed log_msg_buffer --- include/spdlog/details/log_msg_buffer.h | 39 ++++++++++++++++++------- 1 file changed, 28 insertions(+), 11 deletions(-) diff --git a/include/spdlog/details/log_msg_buffer.h b/include/spdlog/details/log_msg_buffer.h index 2dbe5aa4..fd49ba7b 100644 --- a/include/spdlog/details/log_msg_buffer.h +++ b/include/spdlog/details/log_msg_buffer.h @@ -12,23 +12,40 @@ namespace details { // extend log_msg with internal buffer to store its payload. // this is needed since log_msg holds string_views that points to stack data. -struct log_msg_buffer : log_msg +class log_msg_buffer : public log_msg { fmt::basic_memory_buffer buffer; - log_msg_buffer() = default; - - explicit log_msg_buffer(const log_msg &orig_msg) - : log_msg(orig_msg) + void update_string_views() { - buffer.append(logger_name.begin(), logger_name.end()); - logger_name = string_view_t{buffer.data(), buffer.size()}; - - buffer.append(payload.begin(), payload.end()); + logger_name = string_view_t{buffer.data(), logger_name.size()}; payload = string_view_t{logger_name.end(), payload.size()}; } - log_msg_buffer(log_msg_buffer &&other) = default; - log_msg_buffer &operator=(log_msg_buffer &&other) = default; +public: + log_msg_buffer() = default; + + explicit log_msg_buffer(const log_msg &orig_msg) + : log_msg{orig_msg} + { + buffer.append(logger_name.begin(), logger_name.end()); + buffer.append(payload.begin(), payload.end()); + update_string_views(); + } + + log_msg_buffer(log_msg_buffer &&other) + : log_msg{std::move(other)} + , buffer{std::move(other.buffer)} + { + update_string_views(); + } + + log_msg_buffer &operator=(log_msg_buffer &&other) + { + log_msg::operator=(std::move(other)); + buffer = std::move(other.buffer); + update_string_views(); + return *this; + } }; } // namespace details From a6d8b52686e178d34f37e0f46f1224882da47d4c Mon Sep 17 00:00:00 2001 From: gabime Date: Fri, 23 Aug 2019 02:28:52 +0300 Subject: [PATCH 12/59] Added enable_backtrace to spdlog_api --- include/spdlog/details/registry-inl.h | 19 +++++++++++++++++++ include/spdlog/details/registry.h | 4 ++++ include/spdlog/logger-inl.h | 10 ++++++++++ include/spdlog/logger.h | 2 ++ include/spdlog/sinks/backtrace-sink.h | 6 +++--- include/spdlog/spdlog-inl.h | 5 +++++ include/spdlog/spdlog.h | 3 +++ 7 files changed, 46 insertions(+), 3 deletions(-) diff --git a/include/spdlog/details/registry-inl.h b/include/spdlog/details/registry-inl.h index d19e1f15..26191a12 100644 --- a/include/spdlog/details/registry-inl.h +++ b/include/spdlog/details/registry-inl.h @@ -67,10 +67,17 @@ SPDLOG_INLINE void registry::initialize_logger(std::shared_ptr new_logge new_logger->set_level(level_); new_logger->flush_on(flush_level_); + if(backtrace_level_ != level::off) + { + new_logger->enable_backtrace(backtrace_level_, backtrace_n_messages_); + } + if (automatic_registration_) { register_logger_(std::move(new_logger)); } + + } SPDLOG_INLINE std::shared_ptr registry::get(const std::string &logger_name) @@ -135,6 +142,18 @@ SPDLOG_INLINE void registry::set_formatter(std::unique_ptr formatter) } } +SPDLOG_INLINE void registry::enable_backtrace(level::level_enum trigger_level, size_t n_messages) +{ + std::lock_guard lock(logger_map_mutex_); + backtrace_level_ = trigger_level; + backtrace_n_messages_ = n_messages; + + for (auto &l : loggers_) + { + l.second->enable_backtrace(trigger_level, n_messages); + } +} + SPDLOG_INLINE void registry::set_level(level::level_enum log_level) { std::lock_guard lock(logger_map_mutex_); diff --git a/include/spdlog/details/registry.h b/include/spdlog/details/registry.h index f96a7698..b09db533 100644 --- a/include/spdlog/details/registry.h +++ b/include/spdlog/details/registry.h @@ -52,6 +52,8 @@ public: // Set global formatter. Each sink in each logger will get a clone of this object void set_formatter(std::unique_ptr formatter); + void enable_backtrace(level::level_enum trigger_level, size_t n_messages); + void set_level(level::level_enum log_level); void flush_on(level::level_enum log_level); @@ -94,6 +96,8 @@ private: std::unique_ptr periodic_flusher_; std::shared_ptr default_logger_; bool automatic_registration_ = true; + level::level_enum backtrace_level_ = level::off; + size_t backtrace_n_messages_ = 0; }; } // namespace details diff --git a/include/spdlog/logger-inl.h b/include/spdlog/logger-inl.h index 29a43dfa..5f2174b6 100644 --- a/include/spdlog/logger-inl.h +++ b/include/spdlog/logger-inl.h @@ -8,6 +8,7 @@ #endif #include "spdlog/sinks/sink.h" +#include "spdlog/sinks/backtrace-sink.h" #include "spdlog/details/pattern_formatter.h" #include @@ -119,6 +120,15 @@ SPDLOG_INLINE void logger::set_pattern(std::string pattern, pattern_time_type ti set_formatter(std::move(new_formatter)); } +SPDLOG_INLINE void logger::enable_backtrace(level::level_enum trigger_level, size_t n_messages) +{ + auto backtrace_sink = std::make_shared(trigger_level, n_messages); + backtrace_sink->set_sinks(std::move(sinks())); + sinks().push_back(std::move(backtrace_sink)); + this->set_level(spdlog::level::trace); +} + + // flush functions SPDLOG_INLINE void logger::flush() { diff --git a/include/spdlog/logger.h b/include/spdlog/logger.h index bc497532..b0f26edf 100644 --- a/include/spdlog/logger.h +++ b/include/spdlog/logger.h @@ -323,6 +323,8 @@ public: void set_pattern(std::string pattern, pattern_time_type time_type = pattern_time_type::local); + void enable_backtrace(level::level_enum trigger_level = level::err, size_t n_messages = 16); + // flush functions void flush(); void flush_on(level::level_enum log_level); diff --git a/include/spdlog/sinks/backtrace-sink.h b/include/spdlog/sinks/backtrace-sink.h index 44f35365..f37d7f98 100644 --- a/include/spdlog/sinks/backtrace-sink.h +++ b/include/spdlog/sinks/backtrace-sink.h @@ -40,7 +40,7 @@ template class backtrace_sink : public dist_sink { public: - explicit backtrace_sink(level::level_enum trigger_level = spdlog::level::warn, size_t n_messages = 32) + explicit backtrace_sink(level::level_enum trigger_level = spdlog::level::err, size_t n_messages = 16) : trigger_level_{trigger_level} , traceback_msgs_{n_messages} {} @@ -76,7 +76,7 @@ protected: } dist_sink::sink_it_( - details::log_msg{logger_name, level::info, "********************* [Backtrace Start] *********************"}); + details::log_msg{logger_name, level::info, "********************* Backtrace Start *********************"}); do { @@ -86,7 +86,7 @@ protected: } while (!traceback_msgs_.empty()); dist_sink::sink_it_( - details::log_msg{logger_name, level::info, "********************* [Backtrace End] ***********************"}); + details::log_msg{logger_name, level::info, "********************* Backtrace End ***********************"}); } }; diff --git a/include/spdlog/spdlog-inl.h b/include/spdlog/spdlog-inl.h index 5f6c8fb1..b46ee2b2 100644 --- a/include/spdlog/spdlog-inl.h +++ b/include/spdlog/spdlog-inl.h @@ -32,6 +32,11 @@ SPDLOG_INLINE void set_pattern(std::string pattern, pattern_time_type time_type) set_formatter(std::unique_ptr(new pattern_formatter(std::move(pattern), time_type))); } +SPDLOG_INLINE void enable_backtrace(level::level_enum trigger_level, size_t n_messages) +{ + details::registry::instance().enable_backtrace(trigger_level, n_messages); +} + SPDLOG_INLINE void set_level(level::level_enum log_level) { details::registry::instance().set_level(log_level); diff --git a/include/spdlog/spdlog.h b/include/spdlog/spdlog.h index b4996688..e96e9d82 100644 --- a/include/spdlog/spdlog.h +++ b/include/spdlog/spdlog.h @@ -60,6 +60,9 @@ void set_formatter(std::unique_ptr formatter); // example: spdlog::set_pattern("%Y-%m-%d %H:%M:%S.%e %l : %v"); void set_pattern(std::string pattern, pattern_time_type time_type = pattern_time_type::local); +// enable global backtrace support +void enable_backtrace(level::level_enum trigger_level = level::err, size_t n_messages = 16); + // Set global logging level void set_level(level::level_enum log_level); From b24ef39b9dc9bfd2efa37b2965dbad84269a906f Mon Sep 17 00:00:00 2001 From: gabime Date: Fri, 23 Aug 2019 02:45:35 +0300 Subject: [PATCH 13/59] Update example --- example/example.cpp | 8 ++++++++ 1 file changed, 8 insertions(+) diff --git a/example/example.cpp b/example/example.cpp index ce57fc9d..f14dd1ac 100644 --- a/example/example.cpp +++ b/example/example.cpp @@ -41,6 +41,14 @@ int main(int, char *[]) spdlog::info("This an info message with custom format"); spdlog::set_pattern("%+"); // back to default format + // Backtrace support. + // Auto trigger backtrace of latest debug/trace messages upon when error/critical messages happen.. + spdlog::enable_backtrace(); + spdlog::trace("Backtrace message 1"); + spdlog::debug("Backtrace message 2"); + spdlog::debug("Backtrace message 3"); + spdlog::error("This should trigger backtrace!") + try { stdout_logger_example(); From 33f881ac8b860a2cdb3c2d3e776795fdebbce889 Mon Sep 17 00:00:00 2001 From: gabime Date: Fri, 23 Aug 2019 02:45:41 +0300 Subject: [PATCH 14/59] clang-format --- include/spdlog/details/registry-inl.h | 4 +--- include/spdlog/logger-inl.h | 1 - include/spdlog/sinks/backtrace-sink.h | 20 +------------------- 3 files changed, 2 insertions(+), 23 deletions(-) diff --git a/include/spdlog/details/registry-inl.h b/include/spdlog/details/registry-inl.h index 26191a12..d6dbb451 100644 --- a/include/spdlog/details/registry-inl.h +++ b/include/spdlog/details/registry-inl.h @@ -67,7 +67,7 @@ SPDLOG_INLINE void registry::initialize_logger(std::shared_ptr new_logge new_logger->set_level(level_); new_logger->flush_on(flush_level_); - if(backtrace_level_ != level::off) + if (backtrace_level_ != level::off) { new_logger->enable_backtrace(backtrace_level_, backtrace_n_messages_); } @@ -76,8 +76,6 @@ SPDLOG_INLINE void registry::initialize_logger(std::shared_ptr new_logge { register_logger_(std::move(new_logger)); } - - } SPDLOG_INLINE std::shared_ptr registry::get(const std::string &logger_name) diff --git a/include/spdlog/logger-inl.h b/include/spdlog/logger-inl.h index 5f2174b6..d86cba77 100644 --- a/include/spdlog/logger-inl.h +++ b/include/spdlog/logger-inl.h @@ -128,7 +128,6 @@ SPDLOG_INLINE void logger::enable_backtrace(level::level_enum trigger_level, siz this->set_level(spdlog::level::trace); } - // flush functions SPDLOG_INLINE void logger::flush() { diff --git a/include/spdlog/sinks/backtrace-sink.h b/include/spdlog/sinks/backtrace-sink.h index f37d7f98..897a7c8b 100644 --- a/include/spdlog/sinks/backtrace-sink.h +++ b/include/spdlog/sinks/backtrace-sink.h @@ -5,7 +5,6 @@ #include "dist_sink.h" #include "spdlog/details/null_mutex.h" -#include "spdlog/details/log_msg.h" #include "spdlog/details/log_msg_buffer.h" #include "spdlog/details/circular_q.h" @@ -14,26 +13,9 @@ #include // Store log messages in circular buffer -// If it encounters a message with high enough level, it will send all pervious message to its child sinks +// If it encounters a message with high enough level, it will send all previous message to it child sinks // Useful for storing debug data in case of error/warning happens -// -// Example: -// -// #include "spdlog/spdlog.h" -// #include "spdlog/sinks/backtrace_sink.h -// -// int main() { -// auto backtrace_sink = std::make_shared(); -// backtrace_sink ->add_sink(std::make_shared()); -// spdlog::logger l("logger", backtrace_sink); -// logger.set_level(spdlog::level::trace); -// l.trace("Hello"); -// l.debug("Hello"); -// l.info("Hello"); -// l.warn("This will trigger the log of all prev messages in the queue"); -// } - namespace spdlog { namespace sinks { template From e085ba7fcca482590887245a839b4bc42811ca1e Mon Sep 17 00:00:00 2001 From: gabime Date: Fri, 23 Aug 2019 02:48:40 +0300 Subject: [PATCH 15/59] Fix example --- example/example.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/example/example.cpp b/example/example.cpp index f14dd1ac..b3b76f1b 100644 --- a/example/example.cpp +++ b/example/example.cpp @@ -47,7 +47,7 @@ int main(int, char *[]) spdlog::trace("Backtrace message 1"); spdlog::debug("Backtrace message 2"); spdlog::debug("Backtrace message 3"); - spdlog::error("This should trigger backtrace!") + spdlog::error("This should trigger backtrace!"); try { From 8d8aacf5e97f5bf710ace5cf615311f4bafbaba8 Mon Sep 17 00:00:00 2001 From: gabime Date: Fri, 23 Aug 2019 03:17:45 +0300 Subject: [PATCH 16/59] Protect from double call to enable_backtrace() --- include/spdlog/logger-inl.h | 15 +++++++++++---- include/spdlog/logger.h | 1 + 2 files changed, 12 insertions(+), 4 deletions(-) diff --git a/include/spdlog/logger-inl.h b/include/spdlog/logger-inl.h index d86cba77..3bf05df2 100644 --- a/include/spdlog/logger-inl.h +++ b/include/spdlog/logger-inl.h @@ -120,14 +120,21 @@ SPDLOG_INLINE void logger::set_pattern(std::string pattern, pattern_time_type ti set_formatter(std::move(new_formatter)); } + +// create new backtrace sink and hand it all sinks SPDLOG_INLINE void logger::enable_backtrace(level::level_enum trigger_level, size_t n_messages) { - auto backtrace_sink = std::make_shared(trigger_level, n_messages); - backtrace_sink->set_sinks(std::move(sinks())); - sinks().push_back(std::move(backtrace_sink)); - this->set_level(spdlog::level::trace); + if(!backtrace_enabled_) + { + backtrace_enabled_ = true; + auto backtrace_sink = std::make_shared(trigger_level, n_messages); + backtrace_sink->set_sinks(std::move(sinks())); + sinks().push_back(std::move(backtrace_sink)); + this->set_level(spdlog::level::trace); + } } + // flush functions SPDLOG_INLINE void logger::flush() { diff --git a/include/spdlog/logger.h b/include/spdlog/logger.h index b0f26edf..778f7976 100644 --- a/include/spdlog/logger.h +++ b/include/spdlog/logger.h @@ -347,6 +347,7 @@ protected: spdlog::level_t level_{level::info}; spdlog::level_t flush_level_{level::off}; err_handler custom_err_handler_{nullptr}; + bool backtrace_enabled_ {false}; virtual void sink_it_(const details::log_msg &msg); virtual void flush_(); From e0bf0c0301197e79a57d42cbcd4da26284001052 Mon Sep 17 00:00:00 2001 From: Gabi Melman Date: Fri, 23 Aug 2019 03:30:56 +0300 Subject: [PATCH 17/59] Update thread_pool.h --- include/spdlog/details/thread_pool.h | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/include/spdlog/details/thread_pool.h b/include/spdlog/details/thread_pool.h index f02517b3..81bd12de 100644 --- a/include/spdlog/details/thread_pool.h +++ b/include/spdlog/details/thread_pool.h @@ -50,7 +50,6 @@ struct async_msg : log_msg_buffer {} async_msg &operator=(async_msg &&other) - { *static_cast(this) = std::move(other); msg_type = other.msg_type; @@ -118,4 +117,4 @@ private: #ifdef SPDLOG_HEADER_ONLY #include "thread_pool-inl.h" -#endif \ No newline at end of file +#endif From dd33c16aae8e2dc35155e38003be4fcfe9ccf498 Mon Sep 17 00:00:00 2001 From: gabime Date: Fri, 23 Aug 2019 14:47:40 +0300 Subject: [PATCH 18/59] Replace backtrace trigger with dump_backtrace() --- include/spdlog/details/registry-inl.h | 9 ++++---- include/spdlog/details/registry.h | 3 +-- include/spdlog/logger-inl.h | 17 +++++++++++---- include/spdlog/logger.h | 6 ++++-- include/spdlog/sinks/backtrace-sink.h | 30 ++++++++++++--------------- include/spdlog/spdlog-inl.h | 4 ++-- include/spdlog/spdlog.h | 2 +- 7 files changed, 38 insertions(+), 33 deletions(-) diff --git a/include/spdlog/details/registry-inl.h b/include/spdlog/details/registry-inl.h index d6dbb451..d6d1aa07 100644 --- a/include/spdlog/details/registry-inl.h +++ b/include/spdlog/details/registry-inl.h @@ -67,9 +67,9 @@ SPDLOG_INLINE void registry::initialize_logger(std::shared_ptr new_logge new_logger->set_level(level_); new_logger->flush_on(flush_level_); - if (backtrace_level_ != level::off) + if (backtrace_n_messages_ > 0) { - new_logger->enable_backtrace(backtrace_level_, backtrace_n_messages_); + new_logger->enable_backtrace(backtrace_n_messages_); } if (automatic_registration_) @@ -140,15 +140,14 @@ SPDLOG_INLINE void registry::set_formatter(std::unique_ptr formatter) } } -SPDLOG_INLINE void registry::enable_backtrace(level::level_enum trigger_level, size_t n_messages) +SPDLOG_INLINE void registry::enable_backtrace(size_t n_messages) { std::lock_guard lock(logger_map_mutex_); - backtrace_level_ = trigger_level; backtrace_n_messages_ = n_messages; for (auto &l : loggers_) { - l.second->enable_backtrace(trigger_level, n_messages); + l.second->enable_backtrace(n_messages); } } diff --git a/include/spdlog/details/registry.h b/include/spdlog/details/registry.h index b09db533..73be7b28 100644 --- a/include/spdlog/details/registry.h +++ b/include/spdlog/details/registry.h @@ -52,7 +52,7 @@ public: // Set global formatter. Each sink in each logger will get a clone of this object void set_formatter(std::unique_ptr formatter); - void enable_backtrace(level::level_enum trigger_level, size_t n_messages); + void enable_backtrace(size_t n_messages); void set_level(level::level_enum log_level); @@ -96,7 +96,6 @@ private: std::unique_ptr periodic_flusher_; std::shared_ptr default_logger_; bool automatic_registration_ = true; - level::level_enum backtrace_level_ = level::off; size_t backtrace_n_messages_ = 0; }; diff --git a/include/spdlog/logger-inl.h b/include/spdlog/logger-inl.h index 3bf05df2..d0f5a0c7 100644 --- a/include/spdlog/logger-inl.h +++ b/include/spdlog/logger-inl.h @@ -120,20 +120,29 @@ SPDLOG_INLINE void logger::set_pattern(std::string pattern, pattern_time_type ti set_formatter(std::move(new_formatter)); } - // create new backtrace sink and hand it all sinks -SPDLOG_INLINE void logger::enable_backtrace(level::level_enum trigger_level, size_t n_messages) +SPDLOG_INLINE void logger::enable_backtrace(size_t n_messages) { - if(!backtrace_enabled_) + if (!backtrace_enabled_) { backtrace_enabled_ = true; - auto backtrace_sink = std::make_shared(trigger_level, n_messages); + auto backtrace_sink = std::make_shared(n_messages); backtrace_sink->set_sinks(std::move(sinks())); sinks().push_back(std::move(backtrace_sink)); this->set_level(spdlog::level::trace); } } +SPDLOG_INLINE void logger::dump_backtrace() +{ + if (backtrace_enabled_) + { + // auto backtrace_sink = static_cast>(sinks_[0]); + auto *first_sink = sinks_[0].get(); + auto tracer = static_cast(first_sink); + tracer->dump_backtrace(); + } +} // flush functions SPDLOG_INLINE void logger::flush() diff --git a/include/spdlog/logger.h b/include/spdlog/logger.h index 778f7976..62f8b729 100644 --- a/include/spdlog/logger.h +++ b/include/spdlog/logger.h @@ -323,7 +323,9 @@ public: void set_pattern(std::string pattern, pattern_time_type time_type = pattern_time_type::local); - void enable_backtrace(level::level_enum trigger_level = level::err, size_t n_messages = 16); + void enable_backtrace(size_t n_messages = 16); + + void dump_backtrace(); // flush functions void flush(); @@ -347,7 +349,7 @@ protected: spdlog::level_t level_{level::info}; spdlog::level_t flush_level_{level::off}; err_handler custom_err_handler_{nullptr}; - bool backtrace_enabled_ {false}; + bool backtrace_enabled_{false}; virtual void sink_it_(const details::log_msg &msg); virtual void flush_(); diff --git a/include/spdlog/sinks/backtrace-sink.h b/include/spdlog/sinks/backtrace-sink.h index 897a7c8b..cb42bde9 100644 --- a/include/spdlog/sinks/backtrace-sink.h +++ b/include/spdlog/sinks/backtrace-sink.h @@ -22,41 +22,37 @@ template class backtrace_sink : public dist_sink { public: - explicit backtrace_sink(level::level_enum trigger_level = spdlog::level::err, size_t n_messages = 16) - : trigger_level_{trigger_level} - , traceback_msgs_{n_messages} + explicit backtrace_sink(size_t n_messages = 16) + : traceback_msgs_{n_messages} {} -protected: - level::level_enum trigger_level_; + void dump_backtrace() + { + std::lock_guard lock(base_sink::mutex_); + dump_backtrace_(); + } +protected: details::circular_q traceback_msgs_; - // if current message is high enough, trigger a backtrace log, - // otherwise save the message in the queue for future trigger. + // save the messages in a circular queue void sink_it_(const details::log_msg &msg) override { - if (msg.level < trigger_level_) - { - traceback_msgs_.push_back(details::log_msg_buffer(msg)); - } + traceback_msgs_.push_back(details::log_msg_buffer(msg)); + if (msg.level > level::debug) { dist_sink::sink_it_(msg); } - if (msg.level >= trigger_level_) - { - log_backtrace_(msg.logger_name); - } } - void log_backtrace_(const string_view_t &logger_name) + void dump_backtrace_() { if (traceback_msgs_.empty()) { return; } - + const char *logger_name = "??????"; dist_sink::sink_it_( details::log_msg{logger_name, level::info, "********************* Backtrace Start *********************"}); diff --git a/include/spdlog/spdlog-inl.h b/include/spdlog/spdlog-inl.h index b46ee2b2..2e4ee652 100644 --- a/include/spdlog/spdlog-inl.h +++ b/include/spdlog/spdlog-inl.h @@ -32,9 +32,9 @@ SPDLOG_INLINE void set_pattern(std::string pattern, pattern_time_type time_type) set_formatter(std::unique_ptr(new pattern_formatter(std::move(pattern), time_type))); } -SPDLOG_INLINE void enable_backtrace(level::level_enum trigger_level, size_t n_messages) +SPDLOG_INLINE void enable_backtrace(size_t n_messages) { - details::registry::instance().enable_backtrace(trigger_level, n_messages); + details::registry::instance().enable_backtrace(n_messages); } SPDLOG_INLINE void set_level(level::level_enum log_level) diff --git a/include/spdlog/spdlog.h b/include/spdlog/spdlog.h index e96e9d82..4254f49d 100644 --- a/include/spdlog/spdlog.h +++ b/include/spdlog/spdlog.h @@ -61,7 +61,7 @@ void set_formatter(std::unique_ptr formatter); void set_pattern(std::string pattern, pattern_time_type time_type = pattern_time_type::local); // enable global backtrace support -void enable_backtrace(level::level_enum trigger_level = level::err, size_t n_messages = 16); +void enable_backtrace(size_t n_messages); // Set global logging level void set_level(level::level_enum log_level); From a7f7984c4ab4908a4453b644ccffbc4c5a7ab778 Mon Sep 17 00:00:00 2001 From: gabime Date: Sun, 25 Aug 2019 17:24:17 +0300 Subject: [PATCH 19/59] backtrace support api --- include/spdlog/details/registry-inl.h | 10 +++++ include/spdlog/details/registry.h | 2 + include/spdlog/logger-inl.h | 59 +++++++++++++++++++-------- include/spdlog/logger.h | 4 +- include/spdlog/sinks/backtrace-sink.h | 21 ++++++++-- include/spdlog/sinks/dist_sink.h | 6 +++ include/spdlog/spdlog-inl.h | 10 +++++ include/spdlog/spdlog.h | 6 +++ 8 files changed, 97 insertions(+), 21 deletions(-) diff --git a/include/spdlog/details/registry-inl.h b/include/spdlog/details/registry-inl.h index d6d1aa07..a2205ebd 100644 --- a/include/spdlog/details/registry-inl.h +++ b/include/spdlog/details/registry-inl.h @@ -151,6 +151,16 @@ SPDLOG_INLINE void registry::enable_backtrace(size_t n_messages) } } +SPDLOG_INLINE void registry::disable_backtrace() +{ + std::lock_guard lock(logger_map_mutex_); + + for (auto &l : loggers_) + { + l.second->disable_backtrace(); + } +} + SPDLOG_INLINE void registry::set_level(level::level_enum log_level) { std::lock_guard lock(logger_map_mutex_); diff --git a/include/spdlog/details/registry.h b/include/spdlog/details/registry.h index 73be7b28..35a117d9 100644 --- a/include/spdlog/details/registry.h +++ b/include/spdlog/details/registry.h @@ -54,6 +54,8 @@ public: void enable_backtrace(size_t n_messages); + void disable_backtrace(); + void set_level(level::level_enum log_level); void flush_on(level::level_enum log_level); diff --git a/include/spdlog/logger-inl.h b/include/spdlog/logger-inl.h index d0f5a0c7..34c9bc8a 100644 --- a/include/spdlog/logger-inl.h +++ b/include/spdlog/logger-inl.h @@ -22,13 +22,17 @@ SPDLOG_INLINE logger::logger(const logger &other) , level_(other.level_.load(std::memory_order_relaxed)) , flush_level_(other.flush_level_.load(std::memory_order_relaxed)) , custom_err_handler_(other.custom_err_handler_) + , backtrace_sink_(other.backtrace_sink_) {} -SPDLOG_INLINE logger::logger(logger &&other) SPDLOG_NOEXCEPT : name_(std::move(other.name_)), - sinks_(std::move(other.sinks_)), - level_(other.level_.load(std::memory_order_relaxed)), - flush_level_(other.flush_level_.load(std::memory_order_relaxed)), - custom_err_handler_(std::move(other.custom_err_handler_)) +SPDLOG_INLINE logger::logger(logger &&other) SPDLOG_NOEXCEPT : + name_(std::move(other.name_)), + sinks_(std::move(other.sinks_)), + level_(other.level_.load(std::memory_order_relaxed)), + flush_level_(other.flush_level_.load(std::memory_order_relaxed)), + custom_err_handler_(std::move(other.custom_err_handler_)), + backtrace_sink_(std::move(other.backtrace_sink_)) + {} SPDLOG_INLINE logger &logger::operator=(logger other) SPDLOG_NOEXCEPT @@ -53,6 +57,7 @@ SPDLOG_INLINE void logger::swap(spdlog::logger &other) SPDLOG_NOEXCEPT other.flush_level_.store(tmp); custom_err_handler_.swap(other.custom_err_handler_); + backtrace_sink_.swap(other.backtrace_sink_); } SPDLOG_INLINE void swap(logger &a, logger &b) @@ -83,7 +88,16 @@ SPDLOG_INLINE bool logger::should_log(level::level_enum msg_level) const SPDLOG_INLINE void logger::set_level(level::level_enum log_level) { - level_.store(log_level); + if(backtrace_sink_) + { + auto tracer = static_cast(backtrace_sink_.get()); + tracer->set_filter_level(log_level); + level_.store(level::trace); + } + else + { + level_.store(log_level); + } } SPDLOG_INLINE level::level_enum logger::level() const @@ -120,26 +134,37 @@ SPDLOG_INLINE void logger::set_pattern(std::string pattern, pattern_time_type ti set_formatter(std::move(new_formatter)); } -// create new backtrace sink and hand it all sinks +// create new backtrace sink and move to it all our child sinks SPDLOG_INLINE void logger::enable_backtrace(size_t n_messages) { - if (!backtrace_enabled_) + if (!backtrace_sink_) { - backtrace_enabled_ = true; - auto backtrace_sink = std::make_shared(n_messages); - backtrace_sink->set_sinks(std::move(sinks())); - sinks().push_back(std::move(backtrace_sink)); - this->set_level(spdlog::level::trace); + auto new_backtrace_sink = new spdlog::sinks::backtrace_sink_mt(level(), n_messages); + new_backtrace_sink->set_sinks(std::move(sinks_)); + backtrace_sink_.reset(new_backtrace_sink); + sinks().push_back(backtrace_sink_); + assert(sinks().size() == 1); + level_.store(level::trace); + } +} + +// restore orig sinks and level and delete the backtrace sink +SPDLOG_INLINE void logger::disable_backtrace() +{ + if (backtrace_sink_) + { + auto tracer = static_cast(backtrace_sink_.get()); + sinks_ = std::move(tracer->sinks()); + level_.store(tracer->get_filter_level()); + backtrace_sink_.reset(); } } SPDLOG_INLINE void logger::dump_backtrace() { - if (backtrace_enabled_) + if (backtrace_sink_) { - // auto backtrace_sink = static_cast>(sinks_[0]); - auto *first_sink = sinks_[0].get(); - auto tracer = static_cast(first_sink); + auto tracer = static_cast(backtrace_sink_.get()); tracer->dump_backtrace(); } } diff --git a/include/spdlog/logger.h b/include/spdlog/logger.h index 62f8b729..96aed560 100644 --- a/include/spdlog/logger.h +++ b/include/spdlog/logger.h @@ -324,6 +324,7 @@ public: void set_pattern(std::string pattern, pattern_time_type time_type = pattern_time_type::local); void enable_backtrace(size_t n_messages = 16); + void disable_backtrace(); void dump_backtrace(); @@ -349,7 +350,8 @@ protected: spdlog::level_t level_{level::info}; spdlog::level_t flush_level_{level::off}; err_handler custom_err_handler_{nullptr}; - bool backtrace_enabled_{false}; + sink_ptr backtrace_sink_; + //bool backtrace_enabled_{false}; virtual void sink_it_(const details::log_msg &msg); virtual void flush_(); diff --git a/include/spdlog/sinks/backtrace-sink.h b/include/spdlog/sinks/backtrace-sink.h index cb42bde9..d86652a9 100644 --- a/include/spdlog/sinks/backtrace-sink.h +++ b/include/spdlog/sinks/backtrace-sink.h @@ -4,6 +4,7 @@ #pragma once #include "dist_sink.h" +#include "spdlog/common.h" #include "spdlog/details/null_mutex.h" #include "spdlog/details/log_msg_buffer.h" #include "spdlog/details/circular_q.h" @@ -22,10 +23,23 @@ template class backtrace_sink : public dist_sink { public: - explicit backtrace_sink(size_t n_messages = 16) - : traceback_msgs_{n_messages} + explicit backtrace_sink(spdlog::level::level_enum filter_level, size_t n_messages) + : filter_level_{filter_level} + , traceback_msgs_{n_messages} {} + void set_filter_level(spdlog::level::level_enum filter_level) + { + std::lock_guard lock(base_sink::mutex_); + filter_level_ = filter_level; + } + + spdlog::level::level_enum get_filter_level() + { + std::lock_guard lock(base_sink::mutex_); + return filter_level_; + } + void dump_backtrace() { std::lock_guard lock(base_sink::mutex_); @@ -33,6 +47,7 @@ public: } protected: + spdlog::level::level_enum filter_level_; details::circular_q traceback_msgs_; // save the messages in a circular queue @@ -40,7 +55,7 @@ protected: { traceback_msgs_.push_back(details::log_msg_buffer(msg)); - if (msg.level > level::debug) + if (msg.level >= filter_level_) { dist_sink::sink_it_(msg); } diff --git a/include/spdlog/sinks/dist_sink.h b/include/spdlog/sinks/dist_sink.h index c7f207d7..00b908e1 100644 --- a/include/spdlog/sinks/dist_sink.h +++ b/include/spdlog/sinks/dist_sink.h @@ -45,6 +45,12 @@ public: sinks_ = std::move(sinks); } + std::vector>& sinks() + { + return sinks_; + } + + protected: void sink_it_(const details::log_msg &msg) override { diff --git a/include/spdlog/spdlog-inl.h b/include/spdlog/spdlog-inl.h index 2e4ee652..bbfb6e24 100644 --- a/include/spdlog/spdlog-inl.h +++ b/include/spdlog/spdlog-inl.h @@ -37,6 +37,16 @@ SPDLOG_INLINE void enable_backtrace(size_t n_messages) details::registry::instance().enable_backtrace(n_messages); } +SPDLOG_INLINE void disable_backtrace() +{ + details::registry::instance().disable_backtrace(); +} + +SPDLOG_INLINE void dump_backtrace() +{ + default_logger_raw()->dump_backtrace(); +} + SPDLOG_INLINE void set_level(level::level_enum log_level) { details::registry::instance().set_level(log_level); diff --git a/include/spdlog/spdlog.h b/include/spdlog/spdlog.h index 4254f49d..4563c900 100644 --- a/include/spdlog/spdlog.h +++ b/include/spdlog/spdlog.h @@ -63,6 +63,12 @@ void set_pattern(std::string pattern, pattern_time_type time_type = pattern_time // enable global backtrace support void enable_backtrace(size_t n_messages); +// disable global backtrace support +void disable_backtrace(); + +// call dump backtrace on default logger +void dump_backtrace(); + // Set global logging level void set_level(level::level_enum log_level); From b5d61b963a99018a629469c36c1abb641a86a810 Mon Sep 17 00:00:00 2001 From: gabime Date: Sun, 25 Aug 2019 17:25:06 +0300 Subject: [PATCH 20/59] Fixed example --- example/example.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/example/example.cpp b/example/example.cpp index b3b76f1b..51114b5f 100644 --- a/example/example.cpp +++ b/example/example.cpp @@ -43,7 +43,7 @@ int main(int, char *[]) // Backtrace support. // Auto trigger backtrace of latest debug/trace messages upon when error/critical messages happen.. - spdlog::enable_backtrace(); + spdlog::enable_backtrace(16); spdlog::trace("Backtrace message 1"); spdlog::debug("Backtrace message 2"); spdlog::debug("Backtrace message 3"); From 4f98b000ebccd9f2de296beac972fb364f2f65f4 Mon Sep 17 00:00:00 2001 From: gabime Date: Sun, 25 Aug 2019 17:27:21 +0300 Subject: [PATCH 21/59] Fixed example --- example/example.cpp | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/example/example.cpp b/example/example.cpp index 51114b5f..3040ef4f 100644 --- a/example/example.cpp +++ b/example/example.cpp @@ -35,6 +35,7 @@ int main(int, char *[]) spdlog::debug("This message should not be displayed!"); spdlog::set_level(spdlog::level::trace); // Set specific logger's log level spdlog::debug("This message should be displayed.."); + spdlog::set_level(spdlog::level::info); // Set specific logger's log level // Customize msg format for all loggers spdlog::set_pattern("[%H:%M:%S %z] [%^%L%$] [thread %t] %v"); @@ -46,8 +47,7 @@ int main(int, char *[]) spdlog::enable_backtrace(16); spdlog::trace("Backtrace message 1"); spdlog::debug("Backtrace message 2"); - spdlog::debug("Backtrace message 3"); - spdlog::error("This should trigger backtrace!"); + spdlog::dump_backtrace(); try { From 36f253893e6b318ca3a19986420dad1ddef827a7 Mon Sep 17 00:00:00 2001 From: gabime Date: Sun, 25 Aug 2019 17:44:08 +0300 Subject: [PATCH 22/59] Pass logger name to tracer --- include/spdlog/logger-inl.h | 2 +- include/spdlog/sinks/backtrace-sink.h | 7 +++---- 2 files changed, 4 insertions(+), 5 deletions(-) diff --git a/include/spdlog/logger-inl.h b/include/spdlog/logger-inl.h index 34c9bc8a..fd91a47d 100644 --- a/include/spdlog/logger-inl.h +++ b/include/spdlog/logger-inl.h @@ -165,7 +165,7 @@ SPDLOG_INLINE void logger::dump_backtrace() if (backtrace_sink_) { auto tracer = static_cast(backtrace_sink_.get()); - tracer->dump_backtrace(); + tracer->dump_backtrace(name()); } } diff --git a/include/spdlog/sinks/backtrace-sink.h b/include/spdlog/sinks/backtrace-sink.h index d86652a9..bb51e5a7 100644 --- a/include/spdlog/sinks/backtrace-sink.h +++ b/include/spdlog/sinks/backtrace-sink.h @@ -40,10 +40,10 @@ public: return filter_level_; } - void dump_backtrace() + void dump_backtrace(string_view_t logger_name) { std::lock_guard lock(base_sink::mutex_); - dump_backtrace_(); + dump_backtrace_(logger_name); } protected: @@ -61,13 +61,12 @@ protected: } } - void dump_backtrace_() + void dump_backtrace_(string_view_t logger_name) { if (traceback_msgs_.empty()) { return; } - const char *logger_name = "??????"; dist_sink::sink_it_( details::log_msg{logger_name, level::info, "********************* Backtrace Start *********************"}); From 099137fe9a052a18037ac6427f628220c8d5ce5c Mon Sep 17 00:00:00 2001 From: gabime Date: Sun, 25 Aug 2019 18:05:47 +0300 Subject: [PATCH 23/59] backtrace_sink code cleanup --- include/spdlog/logger-inl.h | 18 ++++++++---------- include/spdlog/logger.h | 2 +- include/spdlog/sinks/backtrace-sink.h | 14 +++++++------- include/spdlog/sinks/dist_sink.h | 3 +-- 4 files changed, 17 insertions(+), 20 deletions(-) diff --git a/include/spdlog/logger-inl.h b/include/spdlog/logger-inl.h index fd91a47d..ab8b5c59 100644 --- a/include/spdlog/logger-inl.h +++ b/include/spdlog/logger-inl.h @@ -25,13 +25,12 @@ SPDLOG_INLINE logger::logger(const logger &other) , backtrace_sink_(other.backtrace_sink_) {} -SPDLOG_INLINE logger::logger(logger &&other) SPDLOG_NOEXCEPT : - name_(std::move(other.name_)), - sinks_(std::move(other.sinks_)), - level_(other.level_.load(std::memory_order_relaxed)), - flush_level_(other.flush_level_.load(std::memory_order_relaxed)), - custom_err_handler_(std::move(other.custom_err_handler_)), - backtrace_sink_(std::move(other.backtrace_sink_)) +SPDLOG_INLINE logger::logger(logger &&other) SPDLOG_NOEXCEPT : name_(std::move(other.name_)), + sinks_(std::move(other.sinks_)), + level_(other.level_.load(std::memory_order_relaxed)), + flush_level_(other.flush_level_.load(std::memory_order_relaxed)), + custom_err_handler_(std::move(other.custom_err_handler_)), + backtrace_sink_(std::move(other.backtrace_sink_)) {} @@ -88,7 +87,7 @@ SPDLOG_INLINE bool logger::should_log(level::level_enum msg_level) const SPDLOG_INLINE void logger::set_level(level::level_enum log_level) { - if(backtrace_sink_) + if (backtrace_sink_) { auto tracer = static_cast(backtrace_sink_.get()); tracer->set_filter_level(log_level); @@ -139,8 +138,7 @@ SPDLOG_INLINE void logger::enable_backtrace(size_t n_messages) { if (!backtrace_sink_) { - auto new_backtrace_sink = new spdlog::sinks::backtrace_sink_mt(level(), n_messages); - new_backtrace_sink->set_sinks(std::move(sinks_)); + auto new_backtrace_sink = new spdlog::sinks::backtrace_sink_mt(std::move(sinks_), level(), n_messages); backtrace_sink_.reset(new_backtrace_sink); sinks().push_back(backtrace_sink_); assert(sinks().size() == 1); diff --git a/include/spdlog/logger.h b/include/spdlog/logger.h index 96aed560..a17f9bfc 100644 --- a/include/spdlog/logger.h +++ b/include/spdlog/logger.h @@ -351,7 +351,7 @@ protected: spdlog::level_t flush_level_{level::off}; err_handler custom_err_handler_{nullptr}; sink_ptr backtrace_sink_; - //bool backtrace_enabled_{false}; + // bool backtrace_enabled_{false}; virtual void sink_it_(const details::log_msg &msg); virtual void flush_(); diff --git a/include/spdlog/sinks/backtrace-sink.h b/include/spdlog/sinks/backtrace-sink.h index bb51e5a7..fe265ac5 100644 --- a/include/spdlog/sinks/backtrace-sink.h +++ b/include/spdlog/sinks/backtrace-sink.h @@ -5,7 +5,6 @@ #include "dist_sink.h" #include "spdlog/common.h" -#include "spdlog/details/null_mutex.h" #include "spdlog/details/log_msg_buffer.h" #include "spdlog/details/circular_q.h" @@ -13,9 +12,9 @@ #include #include -// Store log messages in circular buffer -// If it encounters a message with high enough level, it will send all previous message to it child sinks -// Useful for storing debug data in case of error/warning happens +// Store log messages in circular buffer. +// If it encounters a message with high enough level, it will send all previous message to it child sinks. +// Useful for storing debug data in case of error/warning happens. namespace spdlog { namespace sinks { @@ -23,10 +22,12 @@ template class backtrace_sink : public dist_sink { public: - explicit backtrace_sink(spdlog::level::level_enum filter_level, size_t n_messages) + backtrace_sink(std::vector> &&child_sinks, spdlog::level::level_enum filter_level, size_t n_messages) : filter_level_{filter_level} , traceback_msgs_{n_messages} - {} + { + dist_sink::set_sinks(std::move(child_sinks)); + } void set_filter_level(spdlog::level::level_enum filter_level) { @@ -83,7 +84,6 @@ protected: }; using backtrace_sink_mt = backtrace_sink; -using backtrace_sink_st = backtrace_sink; } // namespace sinks } // namespace spdlog diff --git a/include/spdlog/sinks/dist_sink.h b/include/spdlog/sinks/dist_sink.h index 00b908e1..8f931cf7 100644 --- a/include/spdlog/sinks/dist_sink.h +++ b/include/spdlog/sinks/dist_sink.h @@ -45,12 +45,11 @@ public: sinks_ = std::move(sinks); } - std::vector>& sinks() + std::vector> &sinks() { return sinks_; } - protected: void sink_it_(const details::log_msg &msg) override { From f63df65245720e6352e3e2e11e7a9b7b7508bc5f Mon Sep 17 00:00:00 2001 From: gabime Date: Sun, 25 Aug 2019 19:33:12 +0300 Subject: [PATCH 24/59] some cleanup in logger --- include/spdlog/logger-inl.h | 6 ++---- 1 file changed, 2 insertions(+), 4 deletions(-) diff --git a/include/spdlog/logger-inl.h b/include/spdlog/logger-inl.h index ab8b5c59..c75934d1 100644 --- a/include/spdlog/logger-inl.h +++ b/include/spdlog/logger-inl.h @@ -138,11 +138,9 @@ SPDLOG_INLINE void logger::enable_backtrace(size_t n_messages) { if (!backtrace_sink_) { - auto new_backtrace_sink = new spdlog::sinks::backtrace_sink_mt(std::move(sinks_), level(), n_messages); - backtrace_sink_.reset(new_backtrace_sink); + backtrace_sink_ = std::make_shared((std::move(sinks_), level(), n_messages)); sinks().push_back(backtrace_sink_); - assert(sinks().size() == 1); - level_.store(level::trace); + level_.store(level::trace); // pass all messages to the backtrace sink. } } From 0258c4777497f05504b6b746539ceec290ea74ba Mon Sep 17 00:00:00 2001 From: gabime Date: Sun, 25 Aug 2019 19:35:57 +0300 Subject: [PATCH 25/59] some cleanup in logger --- bench/latency.cpp | 3 +++ include/spdlog/logger-inl.h | 2 +- 2 files changed, 4 insertions(+), 1 deletion(-) diff --git a/bench/latency.cpp b/bench/latency.cpp index 2a7787d6..d62ca5d4 100644 --- a/bench/latency.cpp +++ b/bench/latency.cpp @@ -38,6 +38,7 @@ void prepare_logdir() void bench_c_string(benchmark::State &state, std::shared_ptr logger) { + logger->enable_backtrace(64); const char *msg = "Lorem ipsum dolor sit amet, consectetur adipiscing elit. Vestibulum pharetra metus cursus " "lacus placerat congue. Nulla egestas, mauris a tincidunt tempus, enim lectus volutpat mi, eu consequat sem " "libero nec massa. In dapibus ipsum a diam rhoncus gravida. Etiam non dapibus eros. Donec fringilla dui sed " @@ -52,6 +53,7 @@ void bench_c_string(benchmark::State &state, std::shared_ptr log void bench_logger(benchmark::State &state, std::shared_ptr logger) { + logger->enable_backtrace(64); int i = 0; for (auto _ : state) { @@ -61,6 +63,7 @@ void bench_logger(benchmark::State &state, std::shared_ptr logge void bench_disabled_macro(benchmark::State &state, std::shared_ptr logger) { + logger->enable_backtrace(64); int i = 0; benchmark::DoNotOptimize(i); // prevent unused warnings benchmark::DoNotOptimize(logger); // prevent unused warnings diff --git a/include/spdlog/logger-inl.h b/include/spdlog/logger-inl.h index c75934d1..eceefa0a 100644 --- a/include/spdlog/logger-inl.h +++ b/include/spdlog/logger-inl.h @@ -138,7 +138,7 @@ SPDLOG_INLINE void logger::enable_backtrace(size_t n_messages) { if (!backtrace_sink_) { - backtrace_sink_ = std::make_shared((std::move(sinks_), level(), n_messages)); + backtrace_sink_ = std::make_shared(std::move(sinks_), level(), n_messages); sinks().push_back(backtrace_sink_); level_.store(level::trace); // pass all messages to the backtrace sink. } From f3e379cf78cf741ad692709bbd391ee6eda89bb2 Mon Sep 17 00:00:00 2001 From: gabime Date: Sun, 25 Aug 2019 23:55:35 +0300 Subject: [PATCH 26/59] Fixed async dump_backtrace --- bench/latency.cpp | 30 ++++++++++++++++---- include/spdlog/async_logger-inl.h | 36 ++++++++++++++++++++++-- include/spdlog/async_logger.h | 3 ++ include/spdlog/details/thread_pool-inl.h | 11 ++++++++ include/spdlog/details/thread_pool.h | 4 ++- include/spdlog/logger-inl.h | 16 +++++++---- include/spdlog/logger.h | 2 +- src/spdlog.cpp | 1 - 8 files changed, 87 insertions(+), 16 deletions(-) diff --git a/bench/latency.cpp b/bench/latency.cpp index d62ca5d4..7cf0ed8b 100644 --- a/bench/latency.cpp +++ b/bench/latency.cpp @@ -38,7 +38,6 @@ void prepare_logdir() void bench_c_string(benchmark::State &state, std::shared_ptr logger) { - logger->enable_backtrace(64); const char *msg = "Lorem ipsum dolor sit amet, consectetur adipiscing elit. Vestibulum pharetra metus cursus " "lacus placerat congue. Nulla egestas, mauris a tincidunt tempus, enim lectus volutpat mi, eu consequat sem " "libero nec massa. In dapibus ipsum a diam rhoncus gravida. Etiam non dapibus eros. Donec fringilla dui sed " @@ -53,7 +52,6 @@ void bench_c_string(benchmark::State &state, std::shared_ptr log void bench_logger(benchmark::State &state, std::shared_ptr logger) { - logger->enable_backtrace(64); int i = 0; for (auto _ : state) { @@ -63,7 +61,6 @@ void bench_logger(benchmark::State &state, std::shared_ptr logge void bench_disabled_macro(benchmark::State &state, std::shared_ptr logger) { - logger->enable_backtrace(64); int i = 0; benchmark::DoNotOptimize(i); // prevent unused warnings benchmark::DoNotOptimize(logger); // prevent unused warnings @@ -93,29 +90,50 @@ int main(int argc, char *argv[]) disabled_logger->set_level(spdlog::level::off); benchmark::RegisterBenchmark("disabled-at-compile-time", bench_disabled_macro, disabled_logger); benchmark::RegisterBenchmark("disabled-at-runtime", bench_logger, disabled_logger); + // with backtrace of 64 + auto tracing_disabled_logger = std::make_shared("bench", std::make_shared()); + tracing_disabled_logger->enable_backtrace(64); + benchmark::RegisterBenchmark("disabled-at-runtime/backtrace", bench_logger, tracing_disabled_logger); auto null_logger_st = std::make_shared("bench", std::make_shared()); benchmark::RegisterBenchmark("null_sink_st (500_bytes c_str)", bench_c_string, std::move(null_logger_st)); benchmark::RegisterBenchmark("null_sink_st", bench_logger, null_logger_st); + // with backtrace of 64 + auto tracing_null_logger_st = std::make_shared("bench", std::make_shared()); + tracing_null_logger_st->enable_backtrace(64); + benchmark::RegisterBenchmark("null_sink_st/backtrace", bench_logger, tracing_null_logger_st); // basic_st auto basic_st = spdlog::basic_logger_st("basic_st", "latency_logs/basic_st.log", true); benchmark::RegisterBenchmark("basic_st", bench_logger, std::move(basic_st))->UseRealTime(); spdlog::drop("basic_st"); + // with backtrace of 64 + auto tracing_basic_st = spdlog::basic_logger_st("tracing_basic_st", "latency_logs/tracing_basic_st.log", true); + tracing_basic_st->enable_backtrace(64); + benchmark::RegisterBenchmark("basic_st/backtrace", bench_logger, std::move(tracing_basic_st))->UseRealTime(); + spdlog::drop("tracing_basic_st"); // rotating st auto rotating_st = spdlog::rotating_logger_st("rotating_st", "latency_logs/rotating_st.log", file_size, rotating_files); benchmark::RegisterBenchmark("rotating_st", bench_logger, std::move(rotating_st))->UseRealTime(); spdlog::drop("rotating_st"); + // with backtrace of 64 + auto tracing_rotating_st = + spdlog::rotating_logger_st("tracing_rotating_st", "latency_logs/tracing_rotating_st.log", file_size, rotating_files); + benchmark::RegisterBenchmark("rotating_st/tracing", bench_logger, std::move(tracing_rotating_st))->UseRealTime(); + spdlog::drop("tracing_rotating_st"); // daily st auto daily_st = spdlog::daily_logger_mt("daily_st", "latency_logs/daily_st.log"); benchmark::RegisterBenchmark("daily_st", bench_logger, std::move(daily_st))->UseRealTime(); spdlog::drop("daily_st"); + auto tracing_daily_st = spdlog::daily_logger_mt("tracing_daily_st", "latency_logs/daily_st.log"); + benchmark::RegisterBenchmark("daily_st/tracing", bench_logger, std::move(tracing_daily_st))->UseRealTime(); + spdlog::drop("tracing_daily_st"); - // // - // // Multi threaded bench, 10 loggers using same logger concurrently - // // + // + // Multi threaded bench, 10 loggers using same logger concurrently + // auto null_logger_mt = std::make_shared("bench", std::make_shared()); benchmark::RegisterBenchmark("null_sink_mt", bench_logger, null_logger_mt)->Threads(n_threads)->UseRealTime(); diff --git a/include/spdlog/async_logger-inl.h b/include/spdlog/async_logger-inl.h index e3866083..3b71e573 100644 --- a/include/spdlog/async_logger-inl.h +++ b/include/spdlog/async_logger-inl.h @@ -4,7 +4,9 @@ #pragma once #ifndef SPDLOG_HEADER_ONLY + #include "spdlog/async_logger.h" + #endif #include "spdlog/sinks/sink.h" @@ -73,12 +75,42 @@ SPDLOG_INLINE void spdlog::async_logger::backend_log_(const details::log_msg &in } } -SPDLOG_INLINE void spdlog::async_logger::backend_flush_(){SPDLOG_TRY{for (auto &sink : sinks_){sink->flush(); +SPDLOG_INLINE void spdlog::async_logger::backend_flush_() +{ + SPDLOG_TRY + { + for (auto &sink : sinks_){sink->flush();} + } + SPDLOG_LOGGER_CATCH() } + + +SPDLOG_INLINE void spdlog::async_logger::dump_backtrace_() +{ + if (auto pool_ptr = thread_pool_.lock()) + { + pool_ptr->post_dump_backtrace(shared_from_this(), overflow_policy_); + } + else + { + SPDLOG_THROW(spdlog_ex("async dumptrace: thread pool doesn't exist anymore")); + } } -SPDLOG_LOGGER_CATCH() + +SPDLOG_INLINE void spdlog::async_logger::backend_dump_backtrace_() +{ + SPDLOG_TRY + { + if (backtrace_sink_) { + auto tracer = static_cast(backtrace_sink_.get()); + tracer->dump_backtrace(name()); + } + } + SPDLOG_LOGGER_CATCH() } + + SPDLOG_INLINE std::shared_ptr spdlog::async_logger::clone(std::string new_name) { auto cloned = std::make_shared(std::move(new_name), sinks_.begin(), sinks_.end(), thread_pool_, overflow_policy_); diff --git a/include/spdlog/async_logger.h b/include/spdlog/async_logger.h index b3026f1d..bb0fc3ec 100644 --- a/include/spdlog/async_logger.h +++ b/include/spdlog/async_logger.h @@ -51,11 +51,14 @@ public: std::shared_ptr clone(std::string new_name) override; + protected: void sink_it_(const details::log_msg &msg) override; void flush_() override; + void dump_backtrace_() override ; void backend_log_(const details::log_msg &incoming_log_msg); void backend_flush_(); + void backend_dump_backtrace_(); private: std::weak_ptr thread_pool_; diff --git a/include/spdlog/details/thread_pool-inl.h b/include/spdlog/details/thread_pool-inl.h index 38e3d135..4019ea84 100644 --- a/include/spdlog/details/thread_pool-inl.h +++ b/include/spdlog/details/thread_pool-inl.h @@ -62,6 +62,11 @@ void SPDLOG_INLINE thread_pool::post_flush(async_logger_ptr &&worker_ptr, async_ post_async_msg_(async_msg(std::move(worker_ptr), async_msg_type::flush), overflow_policy); } +void SPDLOG_INLINE thread_pool::post_dump_backtrace(async_logger_ptr &&worker_ptr, async_overflow_policy overflow_policy) +{ + post_async_msg_(async_msg(std::move(worker_ptr), async_msg_type::dump_backtrace), overflow_policy); +} + size_t SPDLOG_INLINE thread_pool::overrun_counter() { return q_.overrun_counter(); @@ -109,6 +114,12 @@ bool SPDLOG_INLINE thread_pool::process_next_msg_() return true; } + case async_msg_type ::dump_backtrace: + { + incoming_async_msg.worker_ptr->backend_dump_backtrace_(); + return true; + } + case async_msg_type::terminate: { return false; diff --git a/include/spdlog/details/thread_pool.h b/include/spdlog/details/thread_pool.h index 81bd12de..577e1243 100644 --- a/include/spdlog/details/thread_pool.h +++ b/include/spdlog/details/thread_pool.h @@ -24,7 +24,8 @@ enum class async_msg_type { log, flush, - terminate + terminate, + dump_backtrace }; #include "spdlog/details/log_msg_buffer.h" @@ -96,6 +97,7 @@ public: void post_log(async_logger_ptr &&worker_ptr, const details::log_msg &msg, async_overflow_policy overflow_policy); void post_flush(async_logger_ptr &&worker_ptr, async_overflow_policy overflow_policy); + void post_dump_backtrace(async_logger_ptr &&worker_ptr, async_overflow_policy overflow_policy); size_t overrun_counter(); private: diff --git a/include/spdlog/logger-inl.h b/include/spdlog/logger-inl.h index eceefa0a..d42effc9 100644 --- a/include/spdlog/logger-inl.h +++ b/include/spdlog/logger-inl.h @@ -158,13 +158,10 @@ SPDLOG_INLINE void logger::disable_backtrace() SPDLOG_INLINE void logger::dump_backtrace() { - if (backtrace_sink_) - { - auto tracer = static_cast(backtrace_sink_.get()); - tracer->dump_backtrace(name()); - } + dump_backtrace_(); } + // flush functions SPDLOG_INLINE void logger::flush() { @@ -239,6 +236,15 @@ SPDLOG_INLINE void logger::flush_() } } +SPDLOG_INLINE void logger::dump_backtrace_() +{ + if (backtrace_sink_) + { + auto tracer = static_cast(backtrace_sink_.get()); + tracer->dump_backtrace(name()); + } +} + SPDLOG_INLINE bool logger::should_flush_(const details::log_msg &msg) { auto flush_level = flush_level_.load(std::memory_order_relaxed); diff --git a/include/spdlog/logger.h b/include/spdlog/logger.h index a17f9bfc..3fea1965 100644 --- a/include/spdlog/logger.h +++ b/include/spdlog/logger.h @@ -325,7 +325,6 @@ public: void enable_backtrace(size_t n_messages = 16); void disable_backtrace(); - void dump_backtrace(); // flush functions @@ -355,6 +354,7 @@ protected: virtual void sink_it_(const details::log_msg &msg); virtual void flush_(); + virtual void dump_backtrace_(); bool should_flush_(const details::log_msg &msg); // handle errors during logging. diff --git a/src/spdlog.cpp b/src/spdlog.cpp index be91412d..d30665aa 100644 --- a/src/spdlog.cpp +++ b/src/spdlog.cpp @@ -6,7 +6,6 @@ #endif #include -#include #include "spdlog/details/null_mutex.h" #include "spdlog/async.h" From eec6e28b1994dacadcdb452637f6184ce391b906 Mon Sep 17 00:00:00 2001 From: gabime Date: Mon, 26 Aug 2019 00:13:43 +0300 Subject: [PATCH 27/59] Async logger cleanup --- include/spdlog/async_logger-inl.h | 93 +++++++----------------- include/spdlog/async_logger.h | 2 +- include/spdlog/details/thread_pool-inl.h | 2 +- include/spdlog/logger-inl.h | 6 +- 4 files changed, 35 insertions(+), 68 deletions(-) diff --git a/include/spdlog/async_logger-inl.h b/include/spdlog/async_logger-inl.h index 3b71e573..70440ce1 100644 --- a/include/spdlog/async_logger-inl.h +++ b/include/spdlog/async_logger-inl.h @@ -17,103 +17,66 @@ #include SPDLOG_INLINE spdlog::async_logger::async_logger( - std::string logger_name, sinks_init_list sinks_list, std::weak_ptr tp, async_overflow_policy overflow_policy) - : async_logger(std::move(logger_name), sinks_list.begin(), sinks_list.end(), std::move(tp), overflow_policy) -{} + std::string logger_name, sinks_init_list sinks_list, std::weak_ptr tp, + async_overflow_policy overflow_policy) + : async_logger(std::move(logger_name), sinks_list.begin(), sinks_list.end(), std::move(tp), overflow_policy) {} SPDLOG_INLINE spdlog::async_logger::async_logger( - std::string logger_name, sink_ptr single_sink, std::weak_ptr tp, async_overflow_policy overflow_policy) - : async_logger(std::move(logger_name), {std::move(single_sink)}, std::move(tp), overflow_policy) -{} + std::string logger_name, sink_ptr single_sink, std::weak_ptr tp, + async_overflow_policy overflow_policy) + : async_logger(std::move(logger_name), {std::move(single_sink)}, std::move(tp), overflow_policy) {} // send the log message to the thread pool -SPDLOG_INLINE void spdlog::async_logger::sink_it_(const details::log_msg &msg) -{ - if (auto pool_ptr = thread_pool_.lock()) - { +SPDLOG_INLINE void spdlog::async_logger::sink_it_(const details::log_msg &msg) { + if (auto pool_ptr = thread_pool_.lock()) { pool_ptr->post_log(shared_from_this(), msg, overflow_policy_); - } - else - { + } else { SPDLOG_THROW(spdlog_ex("async log: thread pool doesn't exist anymore")); } } // send flush request to the thread pool -SPDLOG_INLINE void spdlog::async_logger::flush_() -{ - if (auto pool_ptr = thread_pool_.lock()) - { +SPDLOG_INLINE void spdlog::async_logger::flush_() { + if (auto pool_ptr = thread_pool_.lock()) { pool_ptr->post_flush(shared_from_this(), overflow_policy_); - } - else - { + } else { SPDLOG_THROW(spdlog_ex("async flush: thread pool doesn't exist anymore")); } } +SPDLOG_INLINE void spdlog::async_logger::dump_backtrace_() +{ + if (auto pool_ptr = thread_pool_.lock()) { + pool_ptr->post_dump_backtrace(shared_from_this(), overflow_policy_); + } else { + SPDLOG_THROW(spdlog_ex("async dumptrace: thread pool doesn't exist anymore")); + } +} + // // backend functions - called from the thread pool to do the actual job // -SPDLOG_INLINE void spdlog::async_logger::backend_log_(const details::log_msg &incoming_log_msg) +SPDLOG_INLINE void spdlog::async_logger::backend_sink_it_(const details::log_msg &incoming_log_msg) { - SPDLOG_TRY - { - for (auto &s : sinks_) - { - if (s->should_log(incoming_log_msg.level)) - { - s->log(incoming_log_msg); - } - } - } - SPDLOG_LOGGER_CATCH() - - if (should_flush_(incoming_log_msg)) - { - backend_flush_(); - } + spdlog::logger::sink_it_(incoming_log_msg); } SPDLOG_INLINE void spdlog::async_logger::backend_flush_() { - SPDLOG_TRY - { - for (auto &sink : sinks_){sink->flush();} - } - SPDLOG_LOGGER_CATCH() + spdlog::logger::flush_(); } -SPDLOG_INLINE void spdlog::async_logger::dump_backtrace_() -{ - if (auto pool_ptr = thread_pool_.lock()) - { - pool_ptr->post_dump_backtrace(shared_from_this(), overflow_policy_); - } - else - { - SPDLOG_THROW(spdlog_ex("async dumptrace: thread pool doesn't exist anymore")); - } -} SPDLOG_INLINE void spdlog::async_logger::backend_dump_backtrace_() { - SPDLOG_TRY - { - if (backtrace_sink_) { - auto tracer = static_cast(backtrace_sink_.get()); - tracer->dump_backtrace(name()); - } - } - SPDLOG_LOGGER_CATCH() + spdlog::logger::dump_backtrace_(); } - -SPDLOG_INLINE std::shared_ptr spdlog::async_logger::clone(std::string new_name) -{ - auto cloned = std::make_shared(std::move(new_name), sinks_.begin(), sinks_.end(), thread_pool_, overflow_policy_); +SPDLOG_INLINE std::shared_ptr spdlog::async_logger::clone(std::string new_name) { + auto cloned = std::make_shared(std::move(new_name), sinks_.begin(), sinks_.end(), + thread_pool_, overflow_policy_); cloned->set_level(this->level()); cloned->flush_on(this->flush_level()); diff --git a/include/spdlog/async_logger.h b/include/spdlog/async_logger.h index bb0fc3ec..bee24015 100644 --- a/include/spdlog/async_logger.h +++ b/include/spdlog/async_logger.h @@ -56,7 +56,7 @@ protected: void sink_it_(const details::log_msg &msg) override; void flush_() override; void dump_backtrace_() override ; - void backend_log_(const details::log_msg &incoming_log_msg); + void backend_sink_it_(const details::log_msg &incoming_log_msg); void backend_flush_(); void backend_dump_backtrace_(); diff --git a/include/spdlog/details/thread_pool-inl.h b/include/spdlog/details/thread_pool-inl.h index 4019ea84..c9b4852c 100644 --- a/include/spdlog/details/thread_pool-inl.h +++ b/include/spdlog/details/thread_pool-inl.h @@ -105,7 +105,7 @@ bool SPDLOG_INLINE thread_pool::process_next_msg_() { case async_msg_type::log: { - incoming_async_msg.worker_ptr->backend_log_(incoming_async_msg); + incoming_async_msg.worker_ptr->backend_sink_it_(incoming_async_msg); return true; } case async_msg_type::flush: diff --git a/include/spdlog/logger-inl.h b/include/spdlog/logger-inl.h index d42effc9..2c27551b 100644 --- a/include/spdlog/logger-inl.h +++ b/include/spdlog/logger-inl.h @@ -241,7 +241,11 @@ SPDLOG_INLINE void logger::dump_backtrace_() if (backtrace_sink_) { auto tracer = static_cast(backtrace_sink_.get()); - tracer->dump_backtrace(name()); + SPDLOG_TRY + { + tracer->dump_backtrace(name()); + } + SPDLOG_LOGGER_CATCH() } } From 6b7f3db28e564407ccb6c32df9cc0603a7fb8682 Mon Sep 17 00:00:00 2001 From: gabime Date: Mon, 26 Aug 2019 00:23:09 +0300 Subject: [PATCH 28/59] Fixed async sink_it --- include/spdlog/async_logger-inl.h | 23 ++++++++++++++++++----- 1 file changed, 18 insertions(+), 5 deletions(-) diff --git a/include/spdlog/async_logger-inl.h b/include/spdlog/async_logger-inl.h index 70440ce1..34ecbc5a 100644 --- a/include/spdlog/async_logger-inl.h +++ b/include/spdlog/async_logger-inl.h @@ -49,16 +49,31 @@ SPDLOG_INLINE void spdlog::async_logger::dump_backtrace_() if (auto pool_ptr = thread_pool_.lock()) { pool_ptr->post_dump_backtrace(shared_from_this(), overflow_policy_); } else { - SPDLOG_THROW(spdlog_ex("async dumptrace: thread pool doesn't exist anymore")); + SPDLOG_THROW(spdlog_ex("async dump_backtrace: thread pool doesn't exist anymore")); } } // // backend functions - called from the thread pool to do the actual job // -SPDLOG_INLINE void spdlog::async_logger::backend_sink_it_(const details::log_msg &incoming_log_msg) +SPDLOG_INLINE void spdlog::async_logger::backend_sink_it_(const details::log_msg &msg) { - spdlog::logger::sink_it_(incoming_log_msg); + for (auto &sink : sinks_) + { + if (sink->should_log(msg.level)) + { + SPDLOG_TRY + { + sink->log(msg); + } + SPDLOG_LOGGER_CATCH() + } + } + + if (should_flush_(msg)) + { + backend_flush_(); + } } SPDLOG_INLINE void spdlog::async_logger::backend_flush_() @@ -66,8 +81,6 @@ SPDLOG_INLINE void spdlog::async_logger::backend_flush_() spdlog::logger::flush_(); } - - SPDLOG_INLINE void spdlog::async_logger::backend_dump_backtrace_() { spdlog::logger::dump_backtrace_(); From 25d3c83d3be3d894157f7906432b8272f8efe7c6 Mon Sep 17 00:00:00 2001 From: gabime Date: Mon, 26 Aug 2019 00:53:52 +0300 Subject: [PATCH 29/59] Update async bench --- bench/async_bench.cpp | 6 ++---- 1 file changed, 2 insertions(+), 4 deletions(-) diff --git a/bench/async_bench.cpp b/bench/async_bench.cpp index 26836da0..e5dc0e6f 100644 --- a/bench/async_bench.cpp +++ b/bench/async_bench.cpp @@ -48,6 +48,7 @@ int count_lines(const char *filename) void verify_file(const char *filename, int expected_count) { + spdlog::info("Verifying {} to contain {:n} line..", filename, expected_count); auto count = count_lines(filename); if (count != expected_count) { @@ -115,11 +116,7 @@ int main(int argc, char *argv[]) auto file_sink = std::make_shared(filename, true); auto logger = std::make_shared("async_logger", std::move(file_sink), std::move(tp), async_overflow_policy::block); bench_mt(howmany, std::move(logger), threads); - verify_file(filename, howmany); -#ifdef SPDLOG_ASYNC_BENCH_VERIFY - verify_file(filename, howmany); -#endif // SPDLOG_ASYNC_BENCH_VERIFY } spdlog::info(""); @@ -127,6 +124,7 @@ int main(int argc, char *argv[]) spdlog::info("Queue Overflow Policy: overrun"); spdlog::info("*********************************"); // do same test but discard oldest if queue is full instead of blocking + filename = "logs/basic_async-overrun.log"; for (int i = 0; i < iters; i++) { auto tp = std::make_shared(queue_size, 1); From 292fc153ef15cbe45411d29dba008f099f9679d5 Mon Sep 17 00:00:00 2001 From: gabime Date: Mon, 26 Aug 2019 00:55:14 +0300 Subject: [PATCH 30/59] clang-format --- include/spdlog/async_logger-inl.h | 48 +++++++++++++++++++------------ include/spdlog/async_logger.h | 3 +- include/spdlog/logger-inl.h | 1 - 3 files changed, 30 insertions(+), 22 deletions(-) diff --git a/include/spdlog/async_logger-inl.h b/include/spdlog/async_logger-inl.h index 34ecbc5a..e63fab8a 100644 --- a/include/spdlog/async_logger-inl.h +++ b/include/spdlog/async_logger-inl.h @@ -17,38 +17,49 @@ #include SPDLOG_INLINE spdlog::async_logger::async_logger( - std::string logger_name, sinks_init_list sinks_list, std::weak_ptr tp, - async_overflow_policy overflow_policy) - : async_logger(std::move(logger_name), sinks_list.begin(), sinks_list.end(), std::move(tp), overflow_policy) {} + std::string logger_name, sinks_init_list sinks_list, std::weak_ptr tp, async_overflow_policy overflow_policy) + : async_logger(std::move(logger_name), sinks_list.begin(), sinks_list.end(), std::move(tp), overflow_policy) +{} SPDLOG_INLINE spdlog::async_logger::async_logger( - std::string logger_name, sink_ptr single_sink, std::weak_ptr tp, - async_overflow_policy overflow_policy) - : async_logger(std::move(logger_name), {std::move(single_sink)}, std::move(tp), overflow_policy) {} + std::string logger_name, sink_ptr single_sink, std::weak_ptr tp, async_overflow_policy overflow_policy) + : async_logger(std::move(logger_name), {std::move(single_sink)}, std::move(tp), overflow_policy) +{} // send the log message to the thread pool -SPDLOG_INLINE void spdlog::async_logger::sink_it_(const details::log_msg &msg) { - if (auto pool_ptr = thread_pool_.lock()) { +SPDLOG_INLINE void spdlog::async_logger::sink_it_(const details::log_msg &msg) +{ + if (auto pool_ptr = thread_pool_.lock()) + { pool_ptr->post_log(shared_from_this(), msg, overflow_policy_); - } else { + } + else + { SPDLOG_THROW(spdlog_ex("async log: thread pool doesn't exist anymore")); } } // send flush request to the thread pool -SPDLOG_INLINE void spdlog::async_logger::flush_() { - if (auto pool_ptr = thread_pool_.lock()) { +SPDLOG_INLINE void spdlog::async_logger::flush_() +{ + if (auto pool_ptr = thread_pool_.lock()) + { pool_ptr->post_flush(shared_from_this(), overflow_policy_); - } else { + } + else + { SPDLOG_THROW(spdlog_ex("async flush: thread pool doesn't exist anymore")); } } SPDLOG_INLINE void spdlog::async_logger::dump_backtrace_() { - if (auto pool_ptr = thread_pool_.lock()) { + if (auto pool_ptr = thread_pool_.lock()) + { pool_ptr->post_dump_backtrace(shared_from_this(), overflow_policy_); - } else { + } + else + { SPDLOG_THROW(spdlog_ex("async dump_backtrace: thread pool doesn't exist anymore")); } } @@ -83,13 +94,12 @@ SPDLOG_INLINE void spdlog::async_logger::backend_flush_() SPDLOG_INLINE void spdlog::async_logger::backend_dump_backtrace_() { - spdlog::logger::dump_backtrace_(); + spdlog::logger::dump_backtrace_(); } - -SPDLOG_INLINE std::shared_ptr spdlog::async_logger::clone(std::string new_name) { - auto cloned = std::make_shared(std::move(new_name), sinks_.begin(), sinks_.end(), - thread_pool_, overflow_policy_); +SPDLOG_INLINE std::shared_ptr spdlog::async_logger::clone(std::string new_name) +{ + auto cloned = std::make_shared(std::move(new_name), sinks_.begin(), sinks_.end(), thread_pool_, overflow_policy_); cloned->set_level(this->level()); cloned->flush_on(this->flush_level()); diff --git a/include/spdlog/async_logger.h b/include/spdlog/async_logger.h index bee24015..497c9522 100644 --- a/include/spdlog/async_logger.h +++ b/include/spdlog/async_logger.h @@ -51,11 +51,10 @@ public: std::shared_ptr clone(std::string new_name) override; - protected: void sink_it_(const details::log_msg &msg) override; void flush_() override; - void dump_backtrace_() override ; + void dump_backtrace_() override; void backend_sink_it_(const details::log_msg &incoming_log_msg); void backend_flush_(); void backend_dump_backtrace_(); diff --git a/include/spdlog/logger-inl.h b/include/spdlog/logger-inl.h index 2c27551b..caed0faa 100644 --- a/include/spdlog/logger-inl.h +++ b/include/spdlog/logger-inl.h @@ -161,7 +161,6 @@ SPDLOG_INLINE void logger::dump_backtrace() dump_backtrace_(); } - // flush functions SPDLOG_INLINE void logger::flush() { From 29e21cc7f3cbe44763b01e8850cfa0f2184fd534 Mon Sep 17 00:00:00 2001 From: gabime Date: Mon, 26 Aug 2019 00:56:05 +0300 Subject: [PATCH 31/59] Comment --- example/example.cpp | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/example/example.cpp b/example/example.cpp index 3040ef4f..c84caef3 100644 --- a/example/example.cpp +++ b/example/example.cpp @@ -42,8 +42,7 @@ int main(int, char *[]) spdlog::info("This an info message with custom format"); spdlog::set_pattern("%+"); // back to default format - // Backtrace support. - // Auto trigger backtrace of latest debug/trace messages upon when error/critical messages happen.. + // Backtrace support of latest debug/trace messages spdlog::enable_backtrace(16); spdlog::trace("Backtrace message 1"); spdlog::debug("Backtrace message 2"); From 1fd43fe673c3f1b1ea725509e943182cfce4f28d Mon Sep 17 00:00:00 2001 From: gabime Date: Mon, 26 Aug 2019 01:11:22 +0300 Subject: [PATCH 32/59] Fixed async_logger::clone --- include/spdlog/async_logger-inl.h | 7 ++----- 1 file changed, 2 insertions(+), 5 deletions(-) diff --git a/include/spdlog/async_logger-inl.h b/include/spdlog/async_logger-inl.h index e63fab8a..e1c68565 100644 --- a/include/spdlog/async_logger-inl.h +++ b/include/spdlog/async_logger-inl.h @@ -99,10 +99,7 @@ SPDLOG_INLINE void spdlog::async_logger::backend_dump_backtrace_() SPDLOG_INLINE std::shared_ptr spdlog::async_logger::clone(std::string new_name) { - auto cloned = std::make_shared(std::move(new_name), sinks_.begin(), sinks_.end(), thread_pool_, overflow_policy_); - - cloned->set_level(this->level()); - cloned->flush_on(this->flush_level()); - cloned->set_error_handler(this->custom_err_handler_); + auto cloned = std::make_shared(*this); + cloned->name_ = std::move(new_name); return cloned; } From 97dc27b5faee5136fc744f4e640835e283d1f8fd Mon Sep 17 00:00:00 2001 From: gabime Date: Mon, 26 Aug 2019 01:16:53 +0300 Subject: [PATCH 33/59] minor code formatting --- include/spdlog/async_logger-inl.h | 2 -- 1 file changed, 2 deletions(-) diff --git a/include/spdlog/async_logger-inl.h b/include/spdlog/async_logger-inl.h index e1c68565..b0a6fc54 100644 --- a/include/spdlog/async_logger-inl.h +++ b/include/spdlog/async_logger-inl.h @@ -4,9 +4,7 @@ #pragma once #ifndef SPDLOG_HEADER_ONLY - #include "spdlog/async_logger.h" - #endif #include "spdlog/sinks/sink.h" From f330dd210e9cc2a260f2c9ae27461c35eaefe45d Mon Sep 17 00:00:00 2001 From: gabime Date: Mon, 26 Aug 2019 13:43:42 +0300 Subject: [PATCH 34/59] Renamed file --- include/spdlog/logger-inl.h | 2 +- include/spdlog/sinks/{backtrace-sink.h => backtrace_sink.h} | 0 2 files changed, 1 insertion(+), 1 deletion(-) rename include/spdlog/sinks/{backtrace-sink.h => backtrace_sink.h} (100%) diff --git a/include/spdlog/logger-inl.h b/include/spdlog/logger-inl.h index caed0faa..ba0e54ce 100644 --- a/include/spdlog/logger-inl.h +++ b/include/spdlog/logger-inl.h @@ -8,7 +8,7 @@ #endif #include "spdlog/sinks/sink.h" -#include "spdlog/sinks/backtrace-sink.h" +#include "spdlog/sinks/backtrace_sink.h" #include "spdlog/details/pattern_formatter.h" #include diff --git a/include/spdlog/sinks/backtrace-sink.h b/include/spdlog/sinks/backtrace_sink.h similarity index 100% rename from include/spdlog/sinks/backtrace-sink.h rename to include/spdlog/sinks/backtrace_sink.h From 04a8485b17fe5227fbbb99d1384eea2832ef1857 Mon Sep 17 00:00:00 2001 From: gabime Date: Mon, 26 Aug 2019 19:59:16 +0300 Subject: [PATCH 35/59] Replaced backtace implementation --- example/example.cpp | 211 +---------------------- include/spdlog/async_logger-inl.h | 17 -- include/spdlog/async_logger.h | 2 - include/spdlog/details/backtracer.h | 45 +++++ include/spdlog/details/thread_pool-inl.h | 18 +- include/spdlog/details/thread_pool.h | 4 +- include/spdlog/logger-inl.h | 56 +++--- include/spdlog/logger.h | 31 +++- include/spdlog/sinks/backtrace_sink.h | 89 ---------- 9 files changed, 104 insertions(+), 369 deletions(-) create mode 100644 include/spdlog/details/backtracer.h delete mode 100644 include/spdlog/sinks/backtrace_sink.h diff --git a/example/example.cpp b/example/example.cpp index c84caef3..1d01b0ae 100644 --- a/example/example.cpp +++ b/example/example.cpp @@ -23,217 +23,12 @@ void clone_example(); int main(int, char *[]) { - spdlog::info("Welcome to spdlog version {}.{}.{} !", SPDLOG_VER_MAJOR, SPDLOG_VER_MINOR, SPDLOG_VER_PATCH); - spdlog::warn("Easy padding in numbers like {:08d}", 12); - spdlog::critical("Support for int: {0:d}; hex: {0:x}; oct: {0:o}; bin: {0:b}", 42); - spdlog::info("Support for floats {:03.2f}", 1.23456); - spdlog::info("Positional args are {1} {0}..", "too", "supported"); - spdlog::info("{:>8} aligned, {:<8} aligned", "right", "left"); - - // Runtime log levels - spdlog::set_level(spdlog::level::info); // Set global log level to info - spdlog::debug("This message should not be displayed!"); - spdlog::set_level(spdlog::level::trace); // Set specific logger's log level - spdlog::debug("This message should be displayed.."); - spdlog::set_level(spdlog::level::info); // Set specific logger's log level - - // Customize msg format for all loggers - spdlog::set_pattern("[%H:%M:%S %z] [%^%L%$] [thread %t] %v"); - spdlog::info("This an info message with custom format"); - spdlog::set_pattern("%+"); // back to default format // Backtrace support of latest debug/trace messages spdlog::enable_backtrace(16); + spdlog::trace("Backtrace message 1"); spdlog::debug("Backtrace message 2"); + spdlog::info("Hello"); spdlog::dump_backtrace(); - - try - { - stdout_logger_example(); - basic_example(); - rotating_example(); - daily_example(); - clone_example(); - async_example(); - binary_example(); - multi_sink_example(); - user_defined_example(); - err_handler_example(); - trace_example(); - - // Flush all *registered* loggers using a worker thread every 3 seconds. - // note: registered loggers *must* be thread safe for this to work correctly! - spdlog::flush_every(std::chrono::seconds(3)); - - // Apply some function on all registered loggers - spdlog::apply_all([&](std::shared_ptr l) { l->info("End of example."); }); - - // Release all spdlog resources, and drop all loggers in the registry. - // This is optional (only mandatory if using windows + async log). - spdlog::shutdown(); - } - - // Exceptions will only be thrown upon failed logger or sink construction (not during logging). - catch (const spdlog::spdlog_ex &ex) - { - std::printf("Log initialization failed: %s\n", ex.what()); - return 1; - } -} - -#include "spdlog/sinks/stdout_color_sinks.h" -// or #include "spdlog/sinks/stdout_sinks.h" if no colors needed. -void stdout_logger_example() -{ - // Create color multi threaded logger. - auto console = spdlog::stdout_color_mt("console"); - // or for stderr: - // auto console = spdlog::stderr_color_mt("error-logger"); -} - -#include "spdlog/sinks/basic_file_sink.h" -void basic_example() -{ - // Create basic file logger (not rotated). - auto my_logger = spdlog::basic_logger_mt("file_logger", "logs/basic-log.txt"); -} - -#include "spdlog/sinks/rotating_file_sink.h" -void rotating_example() -{ - // Create a file rotating logger with 5mb size max and 3 rotated files. - auto rotating_logger = spdlog::rotating_logger_mt("some_logger_name", "logs/rotating.txt", 1048576 * 5, 3); -} - -#include "spdlog/sinks/daily_file_sink.h" -void daily_example() -{ - // Create a daily logger - a new file is created every day on 2:30am. - auto daily_logger = spdlog::daily_logger_mt("daily_logger", "logs/daily.txt", 2, 30); -} - -// Clone a logger and give it new name. -// Useful for creating component/subsystem loggers from some "root" logger. -void clone_example() -{ - auto network_logger = spdlog::default_logger()->clone("network"); - network_logger->info("Logging network stuff.."); -} - -#include "spdlog/async.h" -void async_example() -{ - // Default thread pool settings can be modified *before* creating the async logger: - // spdlog::init_thread_pool(32768, 1); // queue with max 32k items 1 backing thread. - auto async_file = spdlog::basic_logger_mt("async_file_logger", "logs/async_log.txt"); - // alternatively: - // auto async_file = spdlog::create_async("async_file_logger", "logs/async_log.txt"); - - for (int i = 1; i < 101; ++i) - { - async_file->info("Async message #{}", i); - } -} - -// Log binary data as hex. -// Many types of std::container types can be used. -// Iterator ranges are supported too. -// Format flags: -// {:X} - print in uppercase. -// {:s} - don't separate each byte with space. -// {:p} - don't print the position on each line start. -// {:n} - don't split the output to lines. - -#include "spdlog/fmt/bin_to_hex.h" -void binary_example() -{ - std::vector buf; - for (int i = 0; i < 80; i++) - { - buf.push_back(static_cast(i & 0xff)); - } - spdlog::info("Binary example: {}", spdlog::to_hex(buf)); - spdlog::info("Another binary example:{:n}", spdlog::to_hex(std::begin(buf), std::begin(buf) + 10)); - // more examples: - // logger->info("uppercase: {:X}", spdlog::to_hex(buf)); - // logger->info("uppercase, no delimiters: {:Xs}", spdlog::to_hex(buf)); - // logger->info("uppercase, no delimiters, no position info: {:Xsp}", spdlog::to_hex(buf)); -} - -// Compile time log levels. -// define SPDLOG_ACTIVE_LEVEL to required level (e.g. SPDLOG_LEVEL_TRACE) -void trace_example() -{ - // trace from default logger - SPDLOG_TRACE("Some trace message.. {} ,{}", 1, 3.23); - // debug from default logger - SPDLOG_DEBUG("Some debug message.. {} ,{}", 1, 3.23); - - // trace from logger object - auto logger = spdlog::get("file_logger"); - SPDLOG_LOGGER_TRACE(logger, "another trace message"); -} - -// A logger with multiple sinks (stdout and file) - each with a different format and log level. -void multi_sink_example() -{ - auto console_sink = std::make_shared(); - console_sink->set_level(spdlog::level::warn); - console_sink->set_pattern("[multi_sink_example] [%^%l%$] %v"); - - auto file_sink = std::make_shared("logs/multisink.txt", true); - file_sink->set_level(spdlog::level::trace); - - spdlog::logger logger("multi_sink", {console_sink, file_sink}); - logger.set_level(spdlog::level::debug); - logger.warn("this should appear in both console and file"); - logger.info("this message should not appear in the console, only in the file"); -} - -// User defined types logging by implementing operator<< -#include "spdlog/fmt/ostr.h" // must be included -struct my_type -{ - int i; - template - friend OStream &operator<<(OStream &os, const my_type &c) - { - return os << "[my_type i=" << c.i << "]"; - } -}; - -void user_defined_example() -{ - spdlog::info("user defined type: {}", my_type{14}); -} - -// Custom error handler. Will be triggered on log failure. -void err_handler_example() -{ - // can be set globally or per logger(logger->set_error_handler(..)) - spdlog::set_error_handler([](const std::string &msg) { printf("*** Custom log error handler: %s ***\n", msg.c_str()); }); -} - -// syslog example (linux/osx/freebsd) -#ifndef _WIN32 -#include "spdlog/sinks/syslog_sink.h" -void syslog_example() -{ - std::string ident = "spdlog-example"; - auto syslog_logger = spdlog::syslog_logger_mt("syslog", ident, LOG_PID); - syslog_logger->warn("This is warning that will end up in syslog."); -} -#endif - -// Android example. -#if defined(__ANDROID__) -#include "spdlog/sinks/android_sink.h" -void android_example() -{ - std::string tag = "spdlog-android"; - auto android_logger = spdlog::android_logger_mt("android", tag); - android_logger->critical("Use \"adb shell logcat\" to view this message."); -} - -#endif +} \ No newline at end of file diff --git a/include/spdlog/async_logger-inl.h b/include/spdlog/async_logger-inl.h index b0a6fc54..96137921 100644 --- a/include/spdlog/async_logger-inl.h +++ b/include/spdlog/async_logger-inl.h @@ -50,18 +50,6 @@ SPDLOG_INLINE void spdlog::async_logger::flush_() } } -SPDLOG_INLINE void spdlog::async_logger::dump_backtrace_() -{ - if (auto pool_ptr = thread_pool_.lock()) - { - pool_ptr->post_dump_backtrace(shared_from_this(), overflow_policy_); - } - else - { - SPDLOG_THROW(spdlog_ex("async dump_backtrace: thread pool doesn't exist anymore")); - } -} - // // backend functions - called from the thread pool to do the actual job // @@ -90,11 +78,6 @@ SPDLOG_INLINE void spdlog::async_logger::backend_flush_() spdlog::logger::flush_(); } -SPDLOG_INLINE void spdlog::async_logger::backend_dump_backtrace_() -{ - spdlog::logger::dump_backtrace_(); -} - SPDLOG_INLINE std::shared_ptr spdlog::async_logger::clone(std::string new_name) { auto cloned = std::make_shared(*this); diff --git a/include/spdlog/async_logger.h b/include/spdlog/async_logger.h index 497c9522..0a685186 100644 --- a/include/spdlog/async_logger.h +++ b/include/spdlog/async_logger.h @@ -54,10 +54,8 @@ public: protected: void sink_it_(const details::log_msg &msg) override; void flush_() override; - void dump_backtrace_() override; void backend_sink_it_(const details::log_msg &incoming_log_msg); void backend_flush_(); - void backend_dump_backtrace_(); private: std::weak_ptr thread_pool_; diff --git a/include/spdlog/details/backtracer.h b/include/spdlog/details/backtracer.h new file mode 100644 index 00000000..bdd151ae --- /dev/null +++ b/include/spdlog/details/backtracer.h @@ -0,0 +1,45 @@ +// Copyright(c) 2015-present, Gabi Melman & spdlog contributors. +// Distributed under the MIT License (http://opensource.org/licenses/MIT) + +#pragma once + +#include "spdlog/common.h" +#include "spdlog/details/log_msg_buffer.h" +#include "spdlog/details/circular_q.h" +#include "spdlog/sinks/sink.h" +#include + +// Store log messages in circular buffer. +// Useful for storing debug data in case of error/warning happens. + +namespace spdlog { +namespace details { +class backtracer +{ + std::mutex mutex_; + circular_q messages_; + +public: + explicit backtracer(size_t n_message) + : messages_{n_message} + {} + + void add_msg(const log_msg &msg) + { + std::lock_guard lock{mutex_}; + messages_.push_back(log_msg_buffer{msg}); + } + + // pop all items in the q and apply the give fun on each of them. + void foreach_pop(std::function fun) + { + while (!messages_.empty()) + { + log_msg_buffer popped; + messages_.pop_front(popped); + fun(popped); + } + } +}; +} // namespace details +} // namespace spdlog \ No newline at end of file diff --git a/include/spdlog/details/thread_pool-inl.h b/include/spdlog/details/thread_pool-inl.h index c9b4852c..77d0b1fb 100644 --- a/include/spdlog/details/thread_pool-inl.h +++ b/include/spdlog/details/thread_pool-inl.h @@ -62,11 +62,6 @@ void SPDLOG_INLINE thread_pool::post_flush(async_logger_ptr &&worker_ptr, async_ post_async_msg_(async_msg(std::move(worker_ptr), async_msg_type::flush), overflow_policy); } -void SPDLOG_INLINE thread_pool::post_dump_backtrace(async_logger_ptr &&worker_ptr, async_overflow_policy overflow_policy) -{ - post_async_msg_(async_msg(std::move(worker_ptr), async_msg_type::dump_backtrace), overflow_policy); -} - size_t SPDLOG_INLINE thread_pool::overrun_counter() { return q_.overrun_counter(); @@ -114,18 +109,17 @@ bool SPDLOG_INLINE thread_pool::process_next_msg_() return true; } - case async_msg_type ::dump_backtrace: - { - incoming_async_msg.worker_ptr->backend_dump_backtrace_(); - return true; - } - case async_msg_type::terminate: { return false; } + + default: + { + assert(false && "Unexpected async_msg_type"); } - assert(false && "Unexpected async_msg_type"); + } + return true; } diff --git a/include/spdlog/details/thread_pool.h b/include/spdlog/details/thread_pool.h index 577e1243..81bd12de 100644 --- a/include/spdlog/details/thread_pool.h +++ b/include/spdlog/details/thread_pool.h @@ -24,8 +24,7 @@ enum class async_msg_type { log, flush, - terminate, - dump_backtrace + terminate }; #include "spdlog/details/log_msg_buffer.h" @@ -97,7 +96,6 @@ public: void post_log(async_logger_ptr &&worker_ptr, const details::log_msg &msg, async_overflow_policy overflow_policy); void post_flush(async_logger_ptr &&worker_ptr, async_overflow_policy overflow_policy); - void post_dump_backtrace(async_logger_ptr &&worker_ptr, async_overflow_policy overflow_policy); size_t overrun_counter(); private: diff --git a/include/spdlog/logger-inl.h b/include/spdlog/logger-inl.h index ba0e54ce..a482d17e 100644 --- a/include/spdlog/logger-inl.h +++ b/include/spdlog/logger-inl.h @@ -8,7 +8,7 @@ #endif #include "spdlog/sinks/sink.h" -#include "spdlog/sinks/backtrace_sink.h" +#include "spdlog/details/backtracer.h" #include "spdlog/details/pattern_formatter.h" #include @@ -22,7 +22,7 @@ SPDLOG_INLINE logger::logger(const logger &other) , level_(other.level_.load(std::memory_order_relaxed)) , flush_level_(other.flush_level_.load(std::memory_order_relaxed)) , custom_err_handler_(other.custom_err_handler_) - , backtrace_sink_(other.backtrace_sink_) + , tracer_(other.tracer_) {} SPDLOG_INLINE logger::logger(logger &&other) SPDLOG_NOEXCEPT : name_(std::move(other.name_)), @@ -30,7 +30,7 @@ SPDLOG_INLINE logger::logger(logger &&other) SPDLOG_NOEXCEPT : name_(std::move(o level_(other.level_.load(std::memory_order_relaxed)), flush_level_(other.flush_level_.load(std::memory_order_relaxed)), custom_err_handler_(std::move(other.custom_err_handler_)), - backtrace_sink_(std::move(other.backtrace_sink_)) + tracer_(std::move(other.tracer_)) {} @@ -56,7 +56,7 @@ SPDLOG_INLINE void logger::swap(spdlog::logger &other) SPDLOG_NOEXCEPT other.flush_level_.store(tmp); custom_err_handler_.swap(other.custom_err_handler_); - backtrace_sink_.swap(other.backtrace_sink_); + tracer_.swap(other.tracer_); } SPDLOG_INLINE void swap(logger &a, logger &b) @@ -66,6 +66,11 @@ SPDLOG_INLINE void swap(logger &a, logger &b) SPDLOG_INLINE void logger::log(source_loc loc, level::level_enum lvl, string_view_t msg) { + if (tracer_) + { + save_backtrace_(details::log_msg(loc, string_view_t(name_), lvl, msg)); + } + if (!should_log(lvl)) { return; @@ -87,16 +92,7 @@ SPDLOG_INLINE bool logger::should_log(level::level_enum msg_level) const SPDLOG_INLINE void logger::set_level(level::level_enum log_level) { - if (backtrace_sink_) - { - auto tracer = static_cast(backtrace_sink_.get()); - tracer->set_filter_level(log_level); - level_.store(level::trace); - } - else - { - level_.store(log_level); - } + level_.store(log_level); } SPDLOG_INLINE level::level_enum logger::level() const @@ -136,24 +132,13 @@ SPDLOG_INLINE void logger::set_pattern(std::string pattern, pattern_time_type ti // create new backtrace sink and move to it all our child sinks SPDLOG_INLINE void logger::enable_backtrace(size_t n_messages) { - if (!backtrace_sink_) - { - backtrace_sink_ = std::make_shared(std::move(sinks_), level(), n_messages); - sinks().push_back(backtrace_sink_); - level_.store(level::trace); // pass all messages to the backtrace sink. - } + tracer_ = std::make_shared(n_messages); } // restore orig sinks and level and delete the backtrace sink SPDLOG_INLINE void logger::disable_backtrace() { - if (backtrace_sink_) - { - auto tracer = static_cast(backtrace_sink_.get()); - sinks_ = std::move(tracer->sinks()); - level_.store(tracer->get_filter_level()); - backtrace_sink_.reset(); - } + tracer_.reset(); } SPDLOG_INLINE void logger::dump_backtrace() @@ -235,16 +220,19 @@ SPDLOG_INLINE void logger::flush_() } } +SPDLOG_INLINE void logger::save_backtrace_(const details::log_msg &msg) +{ + tracer_->add_msg(msg); +} + SPDLOG_INLINE void logger::dump_backtrace_() { - if (backtrace_sink_) + using details::log_msg; + if (tracer_) { - auto tracer = static_cast(backtrace_sink_.get()); - SPDLOG_TRY - { - tracer->dump_backtrace(name()); - } - SPDLOG_LOGGER_CATCH() + sink_it_(log_msg{name(), level::info, "****************** Backtrace Start ******************"}); + tracer_->foreach_pop([this](const details::log_msg &msg) { this->sink_it_(msg); }); + sink_it_(log_msg{name(), level::info, "****************** Backtrace End ********************"}); } } diff --git a/include/spdlog/logger.h b/include/spdlog/logger.h index 3fea1965..4c686ba8 100644 --- a/include/spdlog/logger.h +++ b/include/spdlog/logger.h @@ -38,6 +38,11 @@ #endif namespace spdlog { + +namespace details { +class backtracer; +} + class logger { public: @@ -81,6 +86,10 @@ public: fmt::format_to(buf, fmt, args...); details::log_msg log_msg(loc, name_, lvl, string_view_t(buf.data(), buf.size())); sink_it_(log_msg); + if (tracer_) + { + save_backtrace_(log_msg); + } } SPDLOG_LOGGER_CATCH() } @@ -149,6 +158,10 @@ public: template::value, T>::type * = nullptr> void log(source_loc loc, level::level_enum lvl, const T &msg) { + if (tracer_) + { + save_backtrace_(details::log_msg(loc, name_, lvl, msg)); + } if (!should_log(lvl)) { return; @@ -164,6 +177,13 @@ public: T>::type * = nullptr> void log(source_loc loc, level::level_enum lvl, const T &msg) { + if (tracer_) + { + fmt::memory_buffer buf; + fmt::format_to(buf, "{}", msg); + save_backtrace_(details::log_msg(loc, name_, lvl, string_view_t(buf.data(), buf.size()))); + } + if (!should_log(lvl)) { return; @@ -323,7 +343,9 @@ public: void set_pattern(std::string pattern, pattern_time_type time_type = pattern_time_type::local); - void enable_backtrace(size_t n_messages = 16); + // backtrace support. + // efficiently store all debug/trace messages in a circular buffer until needed for debugging. + void enable_backtrace(size_t n_messages); void disable_backtrace(); void dump_backtrace(); @@ -349,12 +371,13 @@ protected: spdlog::level_t level_{level::info}; spdlog::level_t flush_level_{level::off}; err_handler custom_err_handler_{nullptr}; - sink_ptr backtrace_sink_; - // bool backtrace_enabled_{false}; + std::shared_ptr tracer_; virtual void sink_it_(const details::log_msg &msg); virtual void flush_(); - virtual void dump_backtrace_(); + + void save_backtrace_(const details::log_msg &msg); + void dump_backtrace_(); bool should_flush_(const details::log_msg &msg); // handle errors during logging. diff --git a/include/spdlog/sinks/backtrace_sink.h b/include/spdlog/sinks/backtrace_sink.h deleted file mode 100644 index fe265ac5..00000000 --- a/include/spdlog/sinks/backtrace_sink.h +++ /dev/null @@ -1,89 +0,0 @@ -// Copyright(c) 2015-present, Gabi Melman & spdlog contributors. -// Distributed under the MIT License (http://opensource.org/licenses/MIT) - -#pragma once - -#include "dist_sink.h" -#include "spdlog/common.h" -#include "spdlog/details/log_msg_buffer.h" -#include "spdlog/details/circular_q.h" - -#include -#include -#include - -// Store log messages in circular buffer. -// If it encounters a message with high enough level, it will send all previous message to it child sinks. -// Useful for storing debug data in case of error/warning happens. - -namespace spdlog { -namespace sinks { -template -class backtrace_sink : public dist_sink -{ -public: - backtrace_sink(std::vector> &&child_sinks, spdlog::level::level_enum filter_level, size_t n_messages) - : filter_level_{filter_level} - , traceback_msgs_{n_messages} - { - dist_sink::set_sinks(std::move(child_sinks)); - } - - void set_filter_level(spdlog::level::level_enum filter_level) - { - std::lock_guard lock(base_sink::mutex_); - filter_level_ = filter_level; - } - - spdlog::level::level_enum get_filter_level() - { - std::lock_guard lock(base_sink::mutex_); - return filter_level_; - } - - void dump_backtrace(string_view_t logger_name) - { - std::lock_guard lock(base_sink::mutex_); - dump_backtrace_(logger_name); - } - -protected: - spdlog::level::level_enum filter_level_; - details::circular_q traceback_msgs_; - - // save the messages in a circular queue - void sink_it_(const details::log_msg &msg) override - { - traceback_msgs_.push_back(details::log_msg_buffer(msg)); - - if (msg.level >= filter_level_) - { - dist_sink::sink_it_(msg); - } - } - - void dump_backtrace_(string_view_t logger_name) - { - if (traceback_msgs_.empty()) - { - return; - } - dist_sink::sink_it_( - details::log_msg{logger_name, level::info, "********************* Backtrace Start *********************"}); - - do - { - details::log_msg_buffer popped; - traceback_msgs_.pop_front(popped); - dist_sink::sink_it_(popped); - } while (!traceback_msgs_.empty()); - - dist_sink::sink_it_( - details::log_msg{logger_name, level::info, "********************* Backtrace End ***********************"}); - } -}; - -using backtrace_sink_mt = backtrace_sink; - -} // namespace sinks -} // namespace spdlog From e1be7f3d6f65ec16551ade0a7939ad24834f5070 Mon Sep 17 00:00:00 2001 From: gabime Date: Tue, 27 Aug 2019 00:56:49 +0300 Subject: [PATCH 36/59] Refactoring to better support backtrace --- include/spdlog/details/backtracer.h | 2 +- include/spdlog/logger-inl.h | 24 +--------- include/spdlog/logger.h | 68 ++++++++++------------------- include/spdlog/spdlog.h | 8 +--- 4 files changed, 28 insertions(+), 74 deletions(-) diff --git a/include/spdlog/details/backtracer.h b/include/spdlog/details/backtracer.h index bdd151ae..91dfea90 100644 --- a/include/spdlog/details/backtracer.h +++ b/include/spdlog/details/backtracer.h @@ -24,7 +24,7 @@ public: : messages_{n_message} {} - void add_msg(const log_msg &msg) + void add(const log_msg &msg) { std::lock_guard lock{mutex_}; messages_.push_back(log_msg_buffer{msg}); diff --git a/include/spdlog/logger-inl.h b/include/spdlog/logger-inl.h index a482d17e..c86ba426 100644 --- a/include/spdlog/logger-inl.h +++ b/include/spdlog/logger-inl.h @@ -64,26 +64,6 @@ SPDLOG_INLINE void swap(logger &a, logger &b) a.swap(b); } -SPDLOG_INLINE void logger::log(source_loc loc, level::level_enum lvl, string_view_t msg) -{ - if (tracer_) - { - save_backtrace_(details::log_msg(loc, string_view_t(name_), lvl, msg)); - } - - if (!should_log(lvl)) - { - return; - } - - details::log_msg log_msg(loc, string_view_t(name_), lvl, msg); - sink_it_(log_msg); -} - -SPDLOG_INLINE void logger::log(level::level_enum lvl, string_view_t msg) -{ - log(source_loc{}, lvl, msg); -} SPDLOG_INLINE bool logger::should_log(level::level_enum msg_level) const { @@ -220,9 +200,9 @@ SPDLOG_INLINE void logger::flush_() } } -SPDLOG_INLINE void logger::save_backtrace_(const details::log_msg &msg) +SPDLOG_INLINE void logger::backtrace_add_(const details::log_msg &msg) { - tracer_->add_msg(msg); + tracer_->add(msg); } SPDLOG_INLINE void logger::dump_backtrace_() diff --git a/include/spdlog/logger.h b/include/spdlog/logger.h index 4c686ba8..09815447 100644 --- a/include/spdlog/logger.h +++ b/include/spdlog/logger.h @@ -78,40 +78,30 @@ public: void swap(spdlog::logger &other) SPDLOG_NOEXCEPT; template - void force_log(source_loc loc, level::level_enum lvl, string_view_t fmt, const Args &... args) + void log(source_loc loc, level::level_enum lvl, string_view_t fmt, const Args &... args) { + auto level_enabled = should_log(lvl); + if(!level_enabled && !tracer_) + { + return; + } SPDLOG_TRY { fmt::memory_buffer buf; fmt::format_to(buf, fmt, args...); details::log_msg log_msg(loc, name_, lvl, string_view_t(buf.data(), buf.size())); - sink_it_(log_msg); - if (tracer_) - { - save_backtrace_(log_msg); - } + if (level_enabled) sink_it_(log_msg); + if (tracer_) backtrace_add_(log_msg); } SPDLOG_LOGGER_CATCH() } - template - void log(source_loc loc, level::level_enum lvl, string_view_t fmt, const Args &... args) - { - if (should_log(lvl)) - { - force_log(loc, lvl, fmt, args...); - } - } - template void log(level::level_enum lvl, string_view_t fmt, const Args &... args) { log(source_loc{}, lvl, fmt, args...); } - void log(source_loc loc, level::level_enum lvl, const string_view_t msg); - void log(level::level_enum lvl, string_view_t msg); - template void trace(string_view_t fmt, const Args &... args) { @@ -158,17 +148,23 @@ public: template::value, T>::type * = nullptr> void log(source_loc loc, level::level_enum lvl, const T &msg) { - if (tracer_) - { - save_backtrace_(details::log_msg(loc, name_, lvl, msg)); - } - if (!should_log(lvl)) + auto level_enabled = should_log(lvl); + if(!level_enabled && !tracer_) { return; } + SPDLOG_TRY + { + details::log_msg log_msg(loc, name_, lvl, msg); + if (level_enabled) sink_it_(log_msg); + if (tracer_) backtrace_add_(log_msg); + } + SPDLOG_LOGGER_CATCH() + } - details::log_msg log_msg(loc, name_, lvl, msg); - sink_it_(log_msg); + void log(level::level_enum lvl, string_view_t msg) + { + log(source_loc{}, lvl, msg); } // T cannot be statically converted to string_view or wstring_view @@ -177,25 +173,7 @@ public: T>::type * = nullptr> void log(source_loc loc, level::level_enum lvl, const T &msg) { - if (tracer_) - { - fmt::memory_buffer buf; - fmt::format_to(buf, "{}", msg); - save_backtrace_(details::log_msg(loc, name_, lvl, string_view_t(buf.data(), buf.size()))); - } - - if (!should_log(lvl)) - { - return; - } - SPDLOG_TRY - { - fmt::memory_buffer buf; - fmt::format_to(buf, "{}", msg); - details::log_msg log_msg(loc, name_, lvl, string_view_t(buf.data(), buf.size())); - sink_it_(log_msg); - } - SPDLOG_LOGGER_CATCH() + log(loc, lvl, "{}", msg); } template @@ -376,7 +354,7 @@ protected: virtual void sink_it_(const details::log_msg &msg); virtual void flush_(); - void save_backtrace_(const details::log_msg &msg); + void backtrace_add_(const details::log_msg &msg); void dump_backtrace_(); bool should_flush_(const details::log_msg &msg); diff --git a/include/spdlog/spdlog.h b/include/spdlog/spdlog.h index 4563c900..cf20dba8 100644 --- a/include/spdlog/spdlog.h +++ b/include/spdlog/spdlog.h @@ -285,12 +285,8 @@ inline void critical(wstring_view_t fmt, const Args &... args) // SPDLOG_LEVEL_OFF // -#define SPDLOG_LOGGER_CALL(logger, level, ...) \ - do \ - { \ - if (logger->should_log(level)) \ - logger->force_log(spdlog::source_loc{__FILE__, __LINE__, SPDLOG_FUNCTION}, level, __VA_ARGS__); \ - } while (0) +#define SPDLOG_LOGGER_CALL(logger, level, ...)\ + logger->log(spdlog::source_loc{__FILE__, __LINE__, SPDLOG_FUNCTION}, level, __VA_ARGS__); \ #if SPDLOG_ACTIVE_LEVEL <= SPDLOG_LEVEL_TRACE #define SPDLOG_LOGGER_TRACE(logger, ...) SPDLOG_LOGGER_CALL(logger, spdlog::level::trace, __VA_ARGS__) From 7bfb6d6b76c89a15c0e1867d7f47c737158f5f81 Mon Sep 17 00:00:00 2001 From: gabime Date: Tue, 27 Aug 2019 00:58:01 +0300 Subject: [PATCH 37/59] Fixed example --- example/example.cpp | 212 ++++++++++++++++++++++++++++++++++++++++++-- 1 file changed, 205 insertions(+), 7 deletions(-) diff --git a/example/example.cpp b/example/example.cpp index 1d01b0ae..ce57fc9d 100644 --- a/example/example.cpp +++ b/example/example.cpp @@ -23,12 +23,210 @@ void clone_example(); int main(int, char *[]) { + spdlog::info("Welcome to spdlog version {}.{}.{} !", SPDLOG_VER_MAJOR, SPDLOG_VER_MINOR, SPDLOG_VER_PATCH); + spdlog::warn("Easy padding in numbers like {:08d}", 12); + spdlog::critical("Support for int: {0:d}; hex: {0:x}; oct: {0:o}; bin: {0:b}", 42); + spdlog::info("Support for floats {:03.2f}", 1.23456); + spdlog::info("Positional args are {1} {0}..", "too", "supported"); + spdlog::info("{:>8} aligned, {:<8} aligned", "right", "left"); - // Backtrace support of latest debug/trace messages - spdlog::enable_backtrace(16); + // Runtime log levels + spdlog::set_level(spdlog::level::info); // Set global log level to info + spdlog::debug("This message should not be displayed!"); + spdlog::set_level(spdlog::level::trace); // Set specific logger's log level + spdlog::debug("This message should be displayed.."); - spdlog::trace("Backtrace message 1"); - spdlog::debug("Backtrace message 2"); - spdlog::info("Hello"); - spdlog::dump_backtrace(); -} \ No newline at end of file + // Customize msg format for all loggers + spdlog::set_pattern("[%H:%M:%S %z] [%^%L%$] [thread %t] %v"); + spdlog::info("This an info message with custom format"); + spdlog::set_pattern("%+"); // back to default format + + try + { + stdout_logger_example(); + basic_example(); + rotating_example(); + daily_example(); + clone_example(); + async_example(); + binary_example(); + multi_sink_example(); + user_defined_example(); + err_handler_example(); + trace_example(); + + // Flush all *registered* loggers using a worker thread every 3 seconds. + // note: registered loggers *must* be thread safe for this to work correctly! + spdlog::flush_every(std::chrono::seconds(3)); + + // Apply some function on all registered loggers + spdlog::apply_all([&](std::shared_ptr l) { l->info("End of example."); }); + + // Release all spdlog resources, and drop all loggers in the registry. + // This is optional (only mandatory if using windows + async log). + spdlog::shutdown(); + } + + // Exceptions will only be thrown upon failed logger or sink construction (not during logging). + catch (const spdlog::spdlog_ex &ex) + { + std::printf("Log initialization failed: %s\n", ex.what()); + return 1; + } +} + +#include "spdlog/sinks/stdout_color_sinks.h" +// or #include "spdlog/sinks/stdout_sinks.h" if no colors needed. +void stdout_logger_example() +{ + // Create color multi threaded logger. + auto console = spdlog::stdout_color_mt("console"); + // or for stderr: + // auto console = spdlog::stderr_color_mt("error-logger"); +} + +#include "spdlog/sinks/basic_file_sink.h" +void basic_example() +{ + // Create basic file logger (not rotated). + auto my_logger = spdlog::basic_logger_mt("file_logger", "logs/basic-log.txt"); +} + +#include "spdlog/sinks/rotating_file_sink.h" +void rotating_example() +{ + // Create a file rotating logger with 5mb size max and 3 rotated files. + auto rotating_logger = spdlog::rotating_logger_mt("some_logger_name", "logs/rotating.txt", 1048576 * 5, 3); +} + +#include "spdlog/sinks/daily_file_sink.h" +void daily_example() +{ + // Create a daily logger - a new file is created every day on 2:30am. + auto daily_logger = spdlog::daily_logger_mt("daily_logger", "logs/daily.txt", 2, 30); +} + +// Clone a logger and give it new name. +// Useful for creating component/subsystem loggers from some "root" logger. +void clone_example() +{ + auto network_logger = spdlog::default_logger()->clone("network"); + network_logger->info("Logging network stuff.."); +} + +#include "spdlog/async.h" +void async_example() +{ + // Default thread pool settings can be modified *before* creating the async logger: + // spdlog::init_thread_pool(32768, 1); // queue with max 32k items 1 backing thread. + auto async_file = spdlog::basic_logger_mt("async_file_logger", "logs/async_log.txt"); + // alternatively: + // auto async_file = spdlog::create_async("async_file_logger", "logs/async_log.txt"); + + for (int i = 1; i < 101; ++i) + { + async_file->info("Async message #{}", i); + } +} + +// Log binary data as hex. +// Many types of std::container types can be used. +// Iterator ranges are supported too. +// Format flags: +// {:X} - print in uppercase. +// {:s} - don't separate each byte with space. +// {:p} - don't print the position on each line start. +// {:n} - don't split the output to lines. + +#include "spdlog/fmt/bin_to_hex.h" +void binary_example() +{ + std::vector buf; + for (int i = 0; i < 80; i++) + { + buf.push_back(static_cast(i & 0xff)); + } + spdlog::info("Binary example: {}", spdlog::to_hex(buf)); + spdlog::info("Another binary example:{:n}", spdlog::to_hex(std::begin(buf), std::begin(buf) + 10)); + // more examples: + // logger->info("uppercase: {:X}", spdlog::to_hex(buf)); + // logger->info("uppercase, no delimiters: {:Xs}", spdlog::to_hex(buf)); + // logger->info("uppercase, no delimiters, no position info: {:Xsp}", spdlog::to_hex(buf)); +} + +// Compile time log levels. +// define SPDLOG_ACTIVE_LEVEL to required level (e.g. SPDLOG_LEVEL_TRACE) +void trace_example() +{ + // trace from default logger + SPDLOG_TRACE("Some trace message.. {} ,{}", 1, 3.23); + // debug from default logger + SPDLOG_DEBUG("Some debug message.. {} ,{}", 1, 3.23); + + // trace from logger object + auto logger = spdlog::get("file_logger"); + SPDLOG_LOGGER_TRACE(logger, "another trace message"); +} + +// A logger with multiple sinks (stdout and file) - each with a different format and log level. +void multi_sink_example() +{ + auto console_sink = std::make_shared(); + console_sink->set_level(spdlog::level::warn); + console_sink->set_pattern("[multi_sink_example] [%^%l%$] %v"); + + auto file_sink = std::make_shared("logs/multisink.txt", true); + file_sink->set_level(spdlog::level::trace); + + spdlog::logger logger("multi_sink", {console_sink, file_sink}); + logger.set_level(spdlog::level::debug); + logger.warn("this should appear in both console and file"); + logger.info("this message should not appear in the console, only in the file"); +} + +// User defined types logging by implementing operator<< +#include "spdlog/fmt/ostr.h" // must be included +struct my_type +{ + int i; + template + friend OStream &operator<<(OStream &os, const my_type &c) + { + return os << "[my_type i=" << c.i << "]"; + } +}; + +void user_defined_example() +{ + spdlog::info("user defined type: {}", my_type{14}); +} + +// Custom error handler. Will be triggered on log failure. +void err_handler_example() +{ + // can be set globally or per logger(logger->set_error_handler(..)) + spdlog::set_error_handler([](const std::string &msg) { printf("*** Custom log error handler: %s ***\n", msg.c_str()); }); +} + +// syslog example (linux/osx/freebsd) +#ifndef _WIN32 +#include "spdlog/sinks/syslog_sink.h" +void syslog_example() +{ + std::string ident = "spdlog-example"; + auto syslog_logger = spdlog::syslog_logger_mt("syslog", ident, LOG_PID); + syslog_logger->warn("This is warning that will end up in syslog."); +} +#endif + +// Android example. +#if defined(__ANDROID__) +#include "spdlog/sinks/android_sink.h" +void android_example() +{ + std::string tag = "spdlog-android"; + auto android_logger = spdlog::android_logger_mt("android", tag); + android_logger->critical("Use \"adb shell logcat\" to view this message."); +} + +#endif From 7d6444491ca00d15490e0e055c380ff784263669 Mon Sep 17 00:00:00 2001 From: gabime Date: Tue, 27 Aug 2019 01:08:48 +0300 Subject: [PATCH 38/59] Fixed registy::disable_backtrace() --- include/spdlog/details/registry-inl.h | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/include/spdlog/details/registry-inl.h b/include/spdlog/details/registry-inl.h index a2205ebd..075a0c7e 100644 --- a/include/spdlog/details/registry-inl.h +++ b/include/spdlog/details/registry-inl.h @@ -154,7 +154,7 @@ SPDLOG_INLINE void registry::enable_backtrace(size_t n_messages) SPDLOG_INLINE void registry::disable_backtrace() { std::lock_guard lock(logger_map_mutex_); - + backtrace_n_messages_ = 0; for (auto &l : loggers_) { l.second->disable_backtrace(); From 408a1620447e69ffda61568fd6595fd2716ba1f7 Mon Sep 17 00:00:00 2001 From: gabime Date: Tue, 27 Aug 2019 01:16:57 +0300 Subject: [PATCH 39/59] Removed logger::clone() from API --- example/example.cpp | 9 ------- include/spdlog/async_logger-inl.h | 6 ----- include/spdlog/async_logger.h | 1 - include/spdlog/logger-inl.h | 9 ------- include/spdlog/logger.h | 26 ++++++++++++++------ include/spdlog/spdlog.h | 3 +-- tests/test_misc.cpp | 41 ------------------------------- 7 files changed, 19 insertions(+), 76 deletions(-) diff --git a/example/example.cpp b/example/example.cpp index ce57fc9d..9a070c1e 100644 --- a/example/example.cpp +++ b/example/example.cpp @@ -47,7 +47,6 @@ int main(int, char *[]) basic_example(); rotating_example(); daily_example(); - clone_example(); async_example(); binary_example(); multi_sink_example(); @@ -106,14 +105,6 @@ void daily_example() auto daily_logger = spdlog::daily_logger_mt("daily_logger", "logs/daily.txt", 2, 30); } -// Clone a logger and give it new name. -// Useful for creating component/subsystem loggers from some "root" logger. -void clone_example() -{ - auto network_logger = spdlog::default_logger()->clone("network"); - network_logger->info("Logging network stuff.."); -} - #include "spdlog/async.h" void async_example() { diff --git a/include/spdlog/async_logger-inl.h b/include/spdlog/async_logger-inl.h index 96137921..f8dee643 100644 --- a/include/spdlog/async_logger-inl.h +++ b/include/spdlog/async_logger-inl.h @@ -78,9 +78,3 @@ SPDLOG_INLINE void spdlog::async_logger::backend_flush_() spdlog::logger::flush_(); } -SPDLOG_INLINE std::shared_ptr spdlog::async_logger::clone(std::string new_name) -{ - auto cloned = std::make_shared(*this); - cloned->name_ = std::move(new_name); - return cloned; -} diff --git a/include/spdlog/async_logger.h b/include/spdlog/async_logger.h index 0a685186..f56e2dd1 100644 --- a/include/spdlog/async_logger.h +++ b/include/spdlog/async_logger.h @@ -49,7 +49,6 @@ public: async_logger(std::string logger_name, sink_ptr single_sink, std::weak_ptr tp, async_overflow_policy overflow_policy = async_overflow_policy::block); - std::shared_ptr clone(std::string new_name) override; protected: void sink_it_(const details::log_msg &msg) override; diff --git a/include/spdlog/logger-inl.h b/include/spdlog/logger-inl.h index c86ba426..cc7be86d 100644 --- a/include/spdlog/logger-inl.h +++ b/include/spdlog/logger-inl.h @@ -64,7 +64,6 @@ SPDLOG_INLINE void swap(logger &a, logger &b) a.swap(b); } - SPDLOG_INLINE bool logger::should_log(level::level_enum msg_level) const { return msg_level >= level_.load(std::memory_order_relaxed); @@ -159,14 +158,6 @@ SPDLOG_INLINE void logger::set_error_handler(err_handler handler) custom_err_handler_ = handler; } -// create new logger with same sinks and configuration. -SPDLOG_INLINE std::shared_ptr logger::clone(std::string logger_name) -{ - auto cloned = std::make_shared(*this); - cloned->name_ = std::move(logger_name); - return cloned; -} - // protected methods SPDLOG_INLINE void logger::sink_it_(const details::log_msg &msg) { diff --git a/include/spdlog/logger.h b/include/spdlog/logger.h index 09815447..bce77396 100644 --- a/include/spdlog/logger.h +++ b/include/spdlog/logger.h @@ -81,7 +81,7 @@ public: void log(source_loc loc, level::level_enum lvl, string_view_t fmt, const Args &... args) { auto level_enabled = should_log(lvl); - if(!level_enabled && !tracer_) + if (!level_enabled && !tracer_) { return; } @@ -90,8 +90,14 @@ public: fmt::memory_buffer buf; fmt::format_to(buf, fmt, args...); details::log_msg log_msg(loc, name_, lvl, string_view_t(buf.data(), buf.size())); - if (level_enabled) sink_it_(log_msg); - if (tracer_) backtrace_add_(log_msg); + if (level_enabled) + { + sink_it_(log_msg); + } + if (tracer_) + { + backtrace_add_(log_msg); + } } SPDLOG_LOGGER_CATCH() } @@ -149,15 +155,21 @@ public: void log(source_loc loc, level::level_enum lvl, const T &msg) { auto level_enabled = should_log(lvl); - if(!level_enabled && !tracer_) + if (!level_enabled && !tracer_) { return; } SPDLOG_TRY { details::log_msg log_msg(loc, name_, lvl, msg); - if (level_enabled) sink_it_(log_msg); - if (tracer_) backtrace_add_(log_msg); + if (level_enabled) + { + sink_it_(log_msg); + } + if (tracer_) + { + backtrace_add_(log_msg); + } } SPDLOG_LOGGER_CATCH() } @@ -340,8 +352,6 @@ public: // error handler void set_error_handler(err_handler); - // create new logger with same sinks and configuration. - virtual std::shared_ptr clone(std::string logger_name); protected: std::string name_; diff --git a/include/spdlog/spdlog.h b/include/spdlog/spdlog.h index cf20dba8..72ba8974 100644 --- a/include/spdlog/spdlog.h +++ b/include/spdlog/spdlog.h @@ -285,8 +285,7 @@ inline void critical(wstring_view_t fmt, const Args &... args) // SPDLOG_LEVEL_OFF // -#define SPDLOG_LOGGER_CALL(logger, level, ...)\ - logger->log(spdlog::source_loc{__FILE__, __LINE__, SPDLOG_FUNCTION}, level, __VA_ARGS__); \ +#define SPDLOG_LOGGER_CALL(logger, level, ...) logger->log(spdlog::source_loc{__FILE__, __LINE__, SPDLOG_FUNCTION}, level, __VA_ARGS__); #if SPDLOG_ACTIVE_LEVEL <= SPDLOG_LEVEL_TRACE #define SPDLOG_LOGGER_TRACE(logger, ...) SPDLOG_LOGGER_CALL(logger, spdlog::level::trace, __VA_ARGS__) diff --git a/tests/test_misc.cpp b/tests/test_misc.cpp index 7400dd8f..e5bc3b43 100644 --- a/tests/test_misc.cpp +++ b/tests/test_misc.cpp @@ -92,47 +92,6 @@ TEST_CASE("periodic flush", "[periodic_flush]") spdlog::drop_all(); } -TEST_CASE("clone-logger", "[clone]") -{ - using namespace spdlog; - - auto logger = spdlog::create("orig"); - auto cloned = logger->clone("clone"); - - REQUIRE(cloned->name() == "clone"); - REQUIRE(logger->sinks() == cloned->sinks()); - REQUIRE(logger->level() == cloned->level()); - REQUIRE(logger->flush_level() == cloned->flush_level()); - logger->info("Some message 1"); - cloned->info("Some message 2"); - - auto test_sink = std::static_pointer_cast(cloned->sinks()[0]); - - spdlog::drop_all(); -} - -TEST_CASE("clone async", "[clone]") -{ - using namespace spdlog; - - auto logger = spdlog::create_async("orig"); - auto cloned = logger->clone("clone"); - - REQUIRE(cloned->name() == "clone"); - REQUIRE(logger->sinks() == cloned->sinks()); - REQUIRE(logger->level() == cloned->level()); - REQUIRE(logger->flush_level() == cloned->flush_level()); - - logger->info("Some message 1"); - cloned->info("Some message 2"); - - spdlog::details::os::sleep_for_millis(10); - - auto test_sink = std::static_pointer_cast(cloned->sinks()[0]); - - spdlog::drop_all(); -} - #include "spdlog/fmt/bin_to_hex.h" TEST_CASE("to_hex", "[to_hex]") From 72b0f9e8f729cecf44d699c409cc98fc01a9d264 Mon Sep 17 00:00:00 2001 From: gabime Date: Tue, 27 Aug 2019 01:51:59 +0300 Subject: [PATCH 40/59] Updated example --- example/example.cpp | 12 ++++++++++++ 1 file changed, 12 insertions(+) diff --git a/example/example.cpp b/example/example.cpp index 9a070c1e..144e0401 100644 --- a/example/example.cpp +++ b/example/example.cpp @@ -40,6 +40,18 @@ int main(int, char *[]) spdlog::set_pattern("[%H:%M:%S %z] [%^%L%$] [thread %t] %v"); spdlog::info("This an info message with custom format"); spdlog::set_pattern("%+"); // back to default format + spdlog::set_level(spdlog::level::info); + + // Backtrace support + // Loggers can store in a ring buffer all messages (including debug/trace) for later inspection. + // When needed, call dump_backtrace() to see what happened: + spdlog::enable_backtrace(10); // create ring buffer with capacity of 10 messages + for(int i = 0; i < 100; i++) + { + spdlog::debug("Backtrace message {}", i); // not logged.. + } + // e.g. if some error happened: + spdlog::dump_backtrace(); // log them now! try { From 11e9752536b8c5cc7eaaed2a875f42ff02fe0aeb Mon Sep 17 00:00:00 2001 From: gabime Date: Tue, 27 Aug 2019 01:56:48 +0300 Subject: [PATCH 41/59] Fixed logger's copy ctor --- include/spdlog/details/backtracer.h | 10 ++++++++-- include/spdlog/logger-inl.h | 7 ++++++- 2 files changed, 14 insertions(+), 3 deletions(-) diff --git a/include/spdlog/details/backtracer.h b/include/spdlog/details/backtracer.h index 91dfea90..e09c6128 100644 --- a/include/spdlog/details/backtracer.h +++ b/include/spdlog/details/backtracer.h @@ -17,13 +17,19 @@ namespace details { class backtracer { std::mutex mutex_; + size_t n_messages_; circular_q messages_; public: - explicit backtracer(size_t n_message) - : messages_{n_message} + explicit backtracer(size_t n_messages) + : n_messages_{n_messages}, messages_{n_messages} {} + size_t n_messages() + { + return n_messages_; + } + void add(const log_msg &msg) { std::lock_guard lock{mutex_}; diff --git a/include/spdlog/logger-inl.h b/include/spdlog/logger-inl.h index cc7be86d..0c380c1d 100644 --- a/include/spdlog/logger-inl.h +++ b/include/spdlog/logger-inl.h @@ -23,7 +23,12 @@ SPDLOG_INLINE logger::logger(const logger &other) , flush_level_(other.flush_level_.load(std::memory_order_relaxed)) , custom_err_handler_(other.custom_err_handler_) , tracer_(other.tracer_) -{} +{ + if(other.tracer_) + { + enable_backtrace(other.tracer_->n_messages()); + } +} SPDLOG_INLINE logger::logger(logger &&other) SPDLOG_NOEXCEPT : name_(std::move(other.name_)), sinks_(std::move(other.sinks_)), From 79334ca5ab6c56d6ed39f93385af372f84f9d797 Mon Sep 17 00:00:00 2001 From: gabime Date: Tue, 27 Aug 2019 02:02:35 +0300 Subject: [PATCH 42/59] Fixed bench --- bench/async_bench.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/bench/async_bench.cpp b/bench/async_bench.cpp index e5dc0e6f..c2cbe79d 100644 --- a/bench/async_bench.cpp +++ b/bench/async_bench.cpp @@ -116,7 +116,7 @@ int main(int argc, char *argv[]) auto file_sink = std::make_shared(filename, true); auto logger = std::make_shared("async_logger", std::move(file_sink), std::move(tp), async_overflow_policy::block); bench_mt(howmany, std::move(logger), threads); - verify_file(filename, howmany); + //verify_file(filename, howmany); } spdlog::info(""); From 755ce0a016fefe90267fffbfef1ad8f7754523ca Mon Sep 17 00:00:00 2001 From: gabime Date: Tue, 27 Aug 2019 02:15:08 +0300 Subject: [PATCH 43/59] Updated async_logger flush --- bench/async_bench.cpp | 1 - include/spdlog/async_logger-inl.h | 9 ++++++++- 2 files changed, 8 insertions(+), 2 deletions(-) diff --git a/bench/async_bench.cpp b/bench/async_bench.cpp index c2cbe79d..3beff462 100644 --- a/bench/async_bench.cpp +++ b/bench/async_bench.cpp @@ -141,7 +141,6 @@ int main(int argc, char *argv[]) perror("Last error"); return 1; } - return 0; } diff --git a/include/spdlog/async_logger-inl.h b/include/spdlog/async_logger-inl.h index f8dee643..4ac8ccd6 100644 --- a/include/spdlog/async_logger-inl.h +++ b/include/spdlog/async_logger-inl.h @@ -75,6 +75,13 @@ SPDLOG_INLINE void spdlog::async_logger::backend_sink_it_(const details::log_msg SPDLOG_INLINE void spdlog::async_logger::backend_flush_() { - spdlog::logger::flush_(); + for (auto &sink : sinks_) + { + SPDLOG_TRY + { + sink->flush(); + } + SPDLOG_LOGGER_CATCH() + } } From d1b97c0ba961ad635b7218ac4472546b3f8f1fec Mon Sep 17 00:00:00 2001 From: gabime Date: Tue, 27 Aug 2019 02:16:29 +0300 Subject: [PATCH 44/59] Updated async_logger include --- include/spdlog/async_logger-inl.h | 1 - 1 file changed, 1 deletion(-) diff --git a/include/spdlog/async_logger-inl.h b/include/spdlog/async_logger-inl.h index 4ac8ccd6..47002d3e 100644 --- a/include/spdlog/async_logger-inl.h +++ b/include/spdlog/async_logger-inl.h @@ -10,7 +10,6 @@ #include "spdlog/sinks/sink.h" #include "spdlog/details/thread_pool.h" -#include #include #include From c6d558b6f26287a4b3cd06e2d9973c082293b13f Mon Sep 17 00:00:00 2001 From: Gabi Melman Date: Tue, 27 Aug 2019 02:20:17 +0300 Subject: [PATCH 45/59] Update README.md --- README.md | 14 ++++++++------ 1 file changed, 8 insertions(+), 6 deletions(-) diff --git a/README.md b/README.md index 4fcef570..af41614f 100644 --- a/README.md +++ b/README.md @@ -137,15 +137,17 @@ void daily_example() ``` --- -#### Cloning loggers +#### Backtrace support ```c++ -// clone a logger and give it new name. -// Useful for creating subsystem loggers from some "root" logger -void clone_example() +// Loggers can store in a ring buffer all messages (including debug/trace) for later inspection. +// When needed, call dump_backtrace() to see what happened: +spdlog::enable_backtrace(32); // create ring buffer with capacity of 32 messages +for(int i = 0; i < 100; i++) { - auto network_logger = spdlog::get("root")->clone("network"); - network_logger->info("Logging network stuff.."); + spdlog::debug("Backtrace message {}", i); // not logged yet.. } +// e.g. if some error happened: +spdlog::dump_backtrace(); // log them now! ``` --- From a2de7cf0707fc305e082ff82b361f389abcbfe3e Mon Sep 17 00:00:00 2001 From: Gabi Melman Date: Tue, 27 Aug 2019 02:23:22 +0300 Subject: [PATCH 46/59] Update README.md --- README.md | 1 + 1 file changed, 1 insertion(+) diff --git a/README.md b/README.md index af41614f..359a25c2 100644 --- a/README.md +++ b/README.md @@ -37,6 +37,7 @@ Very fast, header-only/compiled, C++ logging library. [![Build Status](https://t * Very fast (see [benchmarks](#benchmarks) below). * Headers only, just copy and use. Or use as a compiled library. * Feature rich formatting, using the excellent [fmt](https://github.com/fmtlib/fmt) library. +* Backtrace support - save latest debugging messages for later inspection. * Fast asynchronous mode (optional) * [Custom](https://github.com/gabime/spdlog/wiki/3.-Custom-formatting) formatting. * Multi/Single threaded loggers. From 2ba7d1639ed78f0e7f580ab2988b803b53c2a57d Mon Sep 17 00:00:00 2001 From: Gabi Melman Date: Tue, 27 Aug 2019 02:26:28 +0300 Subject: [PATCH 47/59] Update README.md --- README.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/README.md b/README.md index 359a25c2..dd011aa8 100644 --- a/README.md +++ b/README.md @@ -37,7 +37,7 @@ Very fast, header-only/compiled, C++ logging library. [![Build Status](https://t * Very fast (see [benchmarks](#benchmarks) below). * Headers only, just copy and use. Or use as a compiled library. * Feature rich formatting, using the excellent [fmt](https://github.com/fmtlib/fmt) library. -* Backtrace support - save latest debugging messages for later inspection. +* [Backtrace](#backtrace-support) support - save latest debugging messages for later inspection. * Fast asynchronous mode (optional) * [Custom](https://github.com/gabime/spdlog/wiki/3.-Custom-formatting) formatting. * Multi/Single threaded loggers. From 15faf742f1f9afc49184d30a04fdffea52d81c78 Mon Sep 17 00:00:00 2001 From: Gabi Melman Date: Tue, 27 Aug 2019 02:27:21 +0300 Subject: [PATCH 48/59] Update README.md --- README.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/README.md b/README.md index dd011aa8..6ff4be59 100644 --- a/README.md +++ b/README.md @@ -37,7 +37,7 @@ Very fast, header-only/compiled, C++ logging library. [![Build Status](https://t * Very fast (see [benchmarks](#benchmarks) below). * Headers only, just copy and use. Or use as a compiled library. * Feature rich formatting, using the excellent [fmt](https://github.com/fmtlib/fmt) library. -* [Backtrace](#backtrace-support) support - save latest debugging messages for later inspection. +* [Backtrace](#backtrace-support) support - store debugging messages in a ring buffer for later inspection. * Fast asynchronous mode (optional) * [Custom](https://github.com/gabime/spdlog/wiki/3.-Custom-formatting) formatting. * Multi/Single threaded loggers. From b15534756046394ec970dadb7899244399d7a6af Mon Sep 17 00:00:00 2001 From: gabime Date: Tue, 27 Aug 2019 02:28:49 +0300 Subject: [PATCH 49/59] Added forgotten lock in backtracer --- include/spdlog/details/backtracer.h | 1 + 1 file changed, 1 insertion(+) diff --git a/include/spdlog/details/backtracer.h b/include/spdlog/details/backtracer.h index e09c6128..a68d32b4 100644 --- a/include/spdlog/details/backtracer.h +++ b/include/spdlog/details/backtracer.h @@ -39,6 +39,7 @@ public: // pop all items in the q and apply the give fun on each of them. void foreach_pop(std::function fun) { + std::lock_guard lock{mutex_}; while (!messages_.empty()) { log_msg_buffer popped; From 813536d4c6780a30e0e95a9be587695532bea2ff Mon Sep 17 00:00:00 2001 From: gabime Date: Tue, 27 Aug 2019 02:35:00 +0300 Subject: [PATCH 50/59] Update latency bench --- bench/latency.cpp | 9 +++++++-- 1 file changed, 7 insertions(+), 2 deletions(-) diff --git a/bench/latency.cpp b/bench/latency.cpp index 7cf0ed8b..e57c739d 100644 --- a/bench/latency.cpp +++ b/bench/latency.cpp @@ -120,7 +120,7 @@ int main(int argc, char *argv[]) // with backtrace of 64 auto tracing_rotating_st = spdlog::rotating_logger_st("tracing_rotating_st", "latency_logs/tracing_rotating_st.log", file_size, rotating_files); - benchmark::RegisterBenchmark("rotating_st/tracing", bench_logger, std::move(tracing_rotating_st))->UseRealTime(); + benchmark::RegisterBenchmark("rotating_st/backtrace", bench_logger, std::move(tracing_rotating_st))->UseRealTime(); spdlog::drop("tracing_rotating_st"); // daily st @@ -128,7 +128,7 @@ int main(int argc, char *argv[]) benchmark::RegisterBenchmark("daily_st", bench_logger, std::move(daily_st))->UseRealTime(); spdlog::drop("daily_st"); auto tracing_daily_st = spdlog::daily_logger_mt("tracing_daily_st", "latency_logs/daily_st.log"); - benchmark::RegisterBenchmark("daily_st/tracing", bench_logger, std::move(tracing_daily_st))->UseRealTime(); + benchmark::RegisterBenchmark("daily_st/backtrace", bench_logger, std::move(tracing_daily_st))->UseRealTime(); spdlog::drop("tracing_daily_st"); // @@ -159,6 +159,11 @@ int main(int argc, char *argv[]) "async_logger", std::make_shared(), std::move(tp), spdlog::async_overflow_policy::overrun_oldest); benchmark::RegisterBenchmark("async_logger", bench_logger, async_logger)->Threads(n_threads)->UseRealTime(); + auto async_logger_tracing = std::make_shared( + "async_logger_tracing", std::make_shared(), std::move(tp), spdlog::async_overflow_policy::overrun_oldest); + async_logger_tracing->enable_backtrace(32); + benchmark::RegisterBenchmark("async_logger/tracing", bench_logger, async_logger_tracing)->Threads(n_threads)->UseRealTime(); + benchmark::Initialize(&argc, argv); benchmark::RunSpecifiedBenchmarks(); } From d7e58ce10e04b6299bc66ffd1bdacca2c9d766e2 Mon Sep 17 00:00:00 2001 From: gabime Date: Tue, 27 Aug 2019 13:08:45 +0300 Subject: [PATCH 51/59] Fixed example --- example/example.cpp | 1 - 1 file changed, 1 deletion(-) diff --git a/example/example.cpp b/example/example.cpp index 144e0401..5aead62d 100644 --- a/example/example.cpp +++ b/example/example.cpp @@ -17,7 +17,6 @@ void multi_sink_example(); void user_defined_example(); void err_handler_example(); void syslog_example(); -void clone_example(); #include "spdlog/spdlog.h" From 011ed270e8e92ab754fa2c89ef0f67aaba1fb1f6 Mon Sep 17 00:00:00 2001 From: gabime Date: Tue, 27 Aug 2019 15:06:53 +0300 Subject: [PATCH 52/59] backtrace support for wchar api under windows --- include/spdlog/logger.h | 29 +++++++++++++++++++++++++---- 1 file changed, 25 insertions(+), 4 deletions(-) diff --git a/include/spdlog/logger.h b/include/spdlog/logger.h index bce77396..a43b3e8f 100644 --- a/include/spdlog/logger.h +++ b/include/spdlog/logger.h @@ -246,15 +246,36 @@ public: SPDLOG_LOGGER_CATCH() } - template + template void log(source_loc loc, level::level_enum lvl, wstring_view_t fmt, const Args &... args) { - if (should_log(lvl)) + auto level_enabled = should_log(lvl); + if (!level_enabled && !tracer_) { - force_log(loc, lvl, fmt, args...); + return; } - } + SPDLOG_TRY + { + // format to wmemory_buffer and convert to utf8 + fmt::wmemory_buffer wbuf; + fmt::format_to(wbuf, fmt, args...); + fmt::memory_buffer buf; + details::os::wstr_to_utf8buf(wstring_view_t(wbuf.data(), wbuf.size()), buf); + details::log_msg log_msg(loc, name_, lvl, string_view_t(buf.data(), buf.size())); + + if (level_enabled) + { + sink_it_(log_msg); + } + if (tracer_) + { + backtrace_add_(log_msg); + } + } + SPDLOG_LOGGER_CATCH() + } + template void log(level::level_enum lvl, wstring_view_t fmt, const Args &... args) { From 0fa09f6af46aabe9e9e879a39bfb9df6f9f14c73 Mon Sep 17 00:00:00 2001 From: gabime Date: Tue, 27 Aug 2019 16:39:18 +0300 Subject: [PATCH 53/59] Removed dead clode --- include/spdlog/logger.h | 21 ++------------------- 1 file changed, 2 insertions(+), 19 deletions(-) diff --git a/include/spdlog/logger.h b/include/spdlog/logger.h index a43b3e8f..3b99615e 100644 --- a/include/spdlog/logger.h +++ b/include/spdlog/logger.h @@ -228,26 +228,9 @@ public: #ifndef _WIN32 #error SPDLOG_WCHAR_TO_UTF8_SUPPORT only supported on windows #else + template - void force_log(source_loc loc, level::level_enum lvl, wstring_view_t fmt, const Args &... args) - { - try - { - // format to wmemory_buffer and convert to utf8 - fmt::wmemory_buffer wbuf; - fmt::format_to(wbuf, fmt, args...); - - fmt::memory_buffer buf; - details::os::wstr_to_utf8buf(wstring_view_t(wbuf.data(), wbuf.size()), buf); - - details::log_msg log_msg(loc, name_, lvl, string_view_t(buf.data(), buf.size())); - sink_it_(log_msg); - } - SPDLOG_LOGGER_CATCH() - } - - template - void log(source_loc loc, level::level_enum lvl, wstring_view_t fmt, const Args &... args) + void log(source_loc loc, level::level_enum lvl, wstring_view_t fmt, const Args &... args) { auto level_enabled = should_log(lvl); if (!level_enabled && !tracer_) From 75adf9e75ecef9ab55650d80c1b7224a75726a62 Mon Sep 17 00:00:00 2001 From: gabime Date: Tue, 27 Aug 2019 17:18:09 +0300 Subject: [PATCH 54/59] Improved test_sink in unit tests --- tests/test_sink.h | 23 ++++++++++++++++++----- 1 file changed, 18 insertions(+), 5 deletions(-) diff --git a/tests/test_sink.h b/tests/test_sink.h index ae08e980..98484964 100644 --- a/tests/test_sink.h +++ b/tests/test_sink.h @@ -7,7 +7,7 @@ #include "spdlog/details/null_mutex.h" #include "spdlog/sinks/base_sink.h" - +#include "spdlog/fmt/fmt.h" #include #include #include @@ -36,20 +36,33 @@ public: delay_ = delay; } + // return last output without the eol + std::string last_output() + { + std::lock_guard lock(base_sink::mutex_); + auto eol_len = strlen(spdlog::details::os::default_eol); + return std::string(last_output_.begin(), last_output_.end() - eol_len); + } + protected: - void sink_it_(const details::log_msg &) override - { - msg_counter_++; - std::this_thread::sleep_for(delay_); + void sink_it_(const details::log_msg &msg) override + { + fmt::memory_buffer formatted; + base_sink::formatter_->format(msg, formatted); + last_output_.assign(formatted.begin(), formatted.end()); + msg_counter_++; + std::this_thread::sleep_for(delay_); } void flush_() override { flush_counter_++; } + size_t msg_counter_{0}; size_t flush_counter_{0}; std::chrono::milliseconds delay_{std::chrono::milliseconds::zero()}; + std::string last_output_; }; using test_sink_mt = test_sink; From 5c1e44a93d518e9e684266aa7d519103a19c67f5 Mon Sep 17 00:00:00 2001 From: gabime Date: Tue, 27 Aug 2019 18:06:27 +0300 Subject: [PATCH 55/59] Added bactrace tests --- tests/CMakeLists.txt | 3 ++- tests/test_backtrace.cpp | 36 ++++++++++++++++++++++++++++++++++++ tests/test_sink.h | 17 ++++++++++++----- 3 files changed, 50 insertions(+), 6 deletions(-) create mode 100644 tests/test_backtrace.cpp diff --git a/tests/CMakeLists.txt b/tests/CMakeLists.txt index 0c64ba43..6a1fe138 100644 --- a/tests/CMakeLists.txt +++ b/tests/CMakeLists.txt @@ -23,7 +23,8 @@ set(SPDLOG_UTESTS_SOURCES test_sink.h test_fmt_helper.cpp test_stdout_api.cpp - test_dup_filter.cpp) + test_dup_filter.cpp + test_backtrace.cpp) if(NOT SPDLOG_NO_EXCEPTIONS) list(APPEND SPDLOG_UTESTS_SOURCES test_errors.cpp) diff --git a/tests/test_backtrace.cpp b/tests/test_backtrace.cpp new file mode 100644 index 00000000..2cef6215 --- /dev/null +++ b/tests/test_backtrace.cpp @@ -0,0 +1,36 @@ +#include "includes.h" +#include "test_sink.h" + + + + +TEST_CASE("bactrace1", "[bactrace]") +{ + + using spdlog::sinks::test_sink_st; + auto test_sink = std::make_shared(); + int backtrace_size = 5; + + spdlog::logger logger("test", test_sink); + logger.set_pattern("%v"); + logger.enable_backtrace(backtrace_size); + + logger.info("info message"); + for(int i = 0; i < 100; i++) + logger.debug("debug message {}", i); + + REQUIRE(test_sink->lines().size() == 1); + REQUIRE(test_sink->lines()[0] == "info message"); + + logger.dump_backtrace(); + REQUIRE(test_sink->lines().size() == 8); + REQUIRE(test_sink->lines()[1] == "****************** Backtrace Start ******************"); + + for(int i = 0; i < backtrace_size; i++) + { + REQUIRE(test_sink->lines()[i+2] == fmt::format("debug message {}", 100 - backtrace_size + i)); + } + REQUIRE(test_sink->lines()[7] == "****************** Backtrace End ********************"); + +} + diff --git a/tests/test_sink.h b/tests/test_sink.h index 98484964..0d4a7d67 100644 --- a/tests/test_sink.h +++ b/tests/test_sink.h @@ -18,6 +18,7 @@ namespace sinks { template class test_sink : public base_sink { + const size_t lines_to_save = 100; public: size_t msg_counter() { @@ -33,23 +34,29 @@ public: void set_delay(std::chrono::milliseconds delay) { + std::lock_guard lock(base_sink::mutex_); delay_ = delay; } // return last output without the eol - std::string last_output() + std::vector lines() { std::lock_guard lock(base_sink::mutex_); - auto eol_len = strlen(spdlog::details::os::default_eol); - return std::string(last_output_.begin(), last_output_.end() - eol_len); + return lines_; } + protected: void sink_it_(const details::log_msg &msg) override { fmt::memory_buffer formatted; base_sink::formatter_->format(msg, formatted); - last_output_.assign(formatted.begin(), formatted.end()); + // save the line without the eol + auto eol_len = strlen(details::os::default_eol); + if(lines_.size() < lines_to_save) + { + lines_.emplace_back(formatted.begin(), formatted.end()-eol_len); + } msg_counter_++; std::this_thread::sleep_for(delay_); } @@ -62,7 +69,7 @@ protected: size_t msg_counter_{0}; size_t flush_counter_{0}; std::chrono::milliseconds delay_{std::chrono::milliseconds::zero()}; - std::string last_output_; + std::vector lines_; }; using test_sink_mt = test_sink; From 13e9135935da599c95e7ea656eaf2e9897ec64a3 Mon Sep 17 00:00:00 2001 From: gabime Date: Tue, 27 Aug 2019 19:45:21 +0300 Subject: [PATCH 56/59] Update test_backtrace.cpp --- tests/test_backtrace.cpp | 52 +++++++++++++++++++++++++++++++++------- 1 file changed, 43 insertions(+), 9 deletions(-) diff --git a/tests/test_backtrace.cpp b/tests/test_backtrace.cpp index 2cef6215..4c6f123f 100644 --- a/tests/test_backtrace.cpp +++ b/tests/test_backtrace.cpp @@ -1,5 +1,6 @@ #include "includes.h" #include "test_sink.h" +#include "spdlog/async.h" @@ -11,7 +12,7 @@ TEST_CASE("bactrace1", "[bactrace]") auto test_sink = std::make_shared(); int backtrace_size = 5; - spdlog::logger logger("test", test_sink); + spdlog::logger logger("test-backtrace", test_sink); logger.set_pattern("%v"); logger.enable_backtrace(backtrace_size); @@ -23,14 +24,47 @@ TEST_CASE("bactrace1", "[bactrace]") REQUIRE(test_sink->lines()[0] == "info message"); logger.dump_backtrace(); - REQUIRE(test_sink->lines().size() == 8); + REQUIRE(test_sink->lines().size() == backtrace_size +3); REQUIRE(test_sink->lines()[1] == "****************** Backtrace Start ******************"); - - for(int i = 0; i < backtrace_size; i++) - { - REQUIRE(test_sink->lines()[i+2] == fmt::format("debug message {}", 100 - backtrace_size + i)); - } - REQUIRE(test_sink->lines()[7] == "****************** Backtrace End ********************"); - + REQUIRE(test_sink->lines()[2] == "debug message 95"); + REQUIRE(test_sink->lines()[3] == "debug message 96"); + REQUIRE(test_sink->lines()[4] == "debug message 97"); + REQUIRE(test_sink->lines()[5] == "debug message 98"); + REQUIRE(test_sink->lines()[6] == "debug message 99"); + REQUIRE(test_sink->lines()[7] == "****************** Backtrace End ********************"); +} + + +TEST_CASE("bactrace-async", "[bactrace]") +{ + using spdlog::sinks::test_sink_mt; + auto test_sink = std::make_shared(); + using spdlog::details::os::sleep_for_millis; + + int backtrace_size = 5; + + spdlog::init_thread_pool(120, 1); + auto logger = std::make_shared("test-bactrace-async", test_sink, spdlog::thread_pool()); + logger->set_pattern("%v"); + logger->enable_backtrace(backtrace_size); + + logger->info("info message"); + for(int i = 0; i < 100; i++) + logger->debug("debug message {}", i); + + sleep_for_millis(10); + REQUIRE(test_sink->lines().size() == 1); + REQUIRE(test_sink->lines()[0] == "info message"); + + logger->dump_backtrace(); + sleep_for_millis(100); // give time for the async dump to complete + REQUIRE(test_sink->lines().size() == backtrace_size +3); + REQUIRE(test_sink->lines()[1] == "****************** Backtrace Start ******************"); + REQUIRE(test_sink->lines()[2] == "debug message 95"); + REQUIRE(test_sink->lines()[3] == "debug message 96"); + REQUIRE(test_sink->lines()[4] == "debug message 97"); + REQUIRE(test_sink->lines()[5] == "debug message 98"); + REQUIRE(test_sink->lines()[6] == "debug message 99"); + REQUIRE(test_sink->lines()[7] == "****************** Backtrace End ********************"); } From c55336e78dba5753c7071516df1b4245f601281a Mon Sep 17 00:00:00 2001 From: gabime Date: Tue, 27 Aug 2019 20:20:15 +0300 Subject: [PATCH 57/59] Better support for logger copy with backtrace --- include/spdlog/details/backtracer.h | 6 +++++- include/spdlog/details/log_msg_buffer.h | 8 ++++++++ include/spdlog/logger-inl.h | 3 +-- 3 files changed, 14 insertions(+), 3 deletions(-) diff --git a/include/spdlog/details/backtracer.h b/include/spdlog/details/backtracer.h index a68d32b4..66dd0196 100644 --- a/include/spdlog/details/backtracer.h +++ b/include/spdlog/details/backtracer.h @@ -25,7 +25,11 @@ public: : n_messages_{n_messages}, messages_{n_messages} {} - size_t n_messages() + backtracer(const backtracer &other): + n_messages_{other.n_messages_}, messages_{other.messages_} + {} + + size_t n_messages() const { return n_messages_; } diff --git a/include/spdlog/details/log_msg_buffer.h b/include/spdlog/details/log_msg_buffer.h index fd49ba7b..d1912492 100644 --- a/include/spdlog/details/log_msg_buffer.h +++ b/include/spdlog/details/log_msg_buffer.h @@ -32,6 +32,14 @@ public: update_string_views(); } + log_msg_buffer(const log_msg_buffer &other) + : log_msg{other} + { + buffer.append(logger_name.begin(), logger_name.end()); + buffer.append(payload.begin(), payload.end()); + update_string_views(); + } + log_msg_buffer(log_msg_buffer &&other) : log_msg{std::move(other)} , buffer{std::move(other.buffer)} diff --git a/include/spdlog/logger-inl.h b/include/spdlog/logger-inl.h index 0c380c1d..102e943c 100644 --- a/include/spdlog/logger-inl.h +++ b/include/spdlog/logger-inl.h @@ -22,11 +22,10 @@ SPDLOG_INLINE logger::logger(const logger &other) , level_(other.level_.load(std::memory_order_relaxed)) , flush_level_(other.flush_level_.load(std::memory_order_relaxed)) , custom_err_handler_(other.custom_err_handler_) - , tracer_(other.tracer_) { if(other.tracer_) { - enable_backtrace(other.tracer_->n_messages()); + tracer_ = std::make_shared(*other.tracer_); } } From c97c025adb3f1724f80d5f9580f44c81793c2ffc Mon Sep 17 00:00:00 2001 From: gabime Date: Tue, 27 Aug 2019 20:22:07 +0300 Subject: [PATCH 58/59] clang-format --- bench/async_bench.cpp | 2 +- bench/latency.cpp | 2 +- example/example.cpp | 2 +- include/spdlog/async_logger-inl.h | 1 - include/spdlog/async_logger.h | 1 - include/spdlog/details/backtracer.h | 8 +- include/spdlog/details/log_msg_buffer.h | 2 +- include/spdlog/logger-inl.h | 2 +- include/spdlog/logger.h | 9 +-- tests/test_backtrace.cpp | 97 ++++++++++++------------- tests/test_sink.h | 44 +++++------ 11 files changed, 82 insertions(+), 88 deletions(-) diff --git a/bench/async_bench.cpp b/bench/async_bench.cpp index 3beff462..fc49cdd8 100644 --- a/bench/async_bench.cpp +++ b/bench/async_bench.cpp @@ -116,7 +116,7 @@ int main(int argc, char *argv[]) auto file_sink = std::make_shared(filename, true); auto logger = std::make_shared("async_logger", std::move(file_sink), std::move(tp), async_overflow_policy::block); bench_mt(howmany, std::move(logger), threads); - //verify_file(filename, howmany); + // verify_file(filename, howmany); } spdlog::info(""); diff --git a/bench/latency.cpp b/bench/latency.cpp index e57c739d..730226ca 100644 --- a/bench/latency.cpp +++ b/bench/latency.cpp @@ -160,7 +160,7 @@ int main(int argc, char *argv[]) benchmark::RegisterBenchmark("async_logger", bench_logger, async_logger)->Threads(n_threads)->UseRealTime(); auto async_logger_tracing = std::make_shared( - "async_logger_tracing", std::make_shared(), std::move(tp), spdlog::async_overflow_policy::overrun_oldest); + "async_logger_tracing", std::make_shared(), std::move(tp), spdlog::async_overflow_policy::overrun_oldest); async_logger_tracing->enable_backtrace(32); benchmark::RegisterBenchmark("async_logger/tracing", bench_logger, async_logger_tracing)->Threads(n_threads)->UseRealTime(); diff --git a/example/example.cpp b/example/example.cpp index 5aead62d..2a18677a 100644 --- a/example/example.cpp +++ b/example/example.cpp @@ -45,7 +45,7 @@ int main(int, char *[]) // Loggers can store in a ring buffer all messages (including debug/trace) for later inspection. // When needed, call dump_backtrace() to see what happened: spdlog::enable_backtrace(10); // create ring buffer with capacity of 10 messages - for(int i = 0; i < 100; i++) + for (int i = 0; i < 100; i++) { spdlog::debug("Backtrace message {}", i); // not logged.. } diff --git a/include/spdlog/async_logger-inl.h b/include/spdlog/async_logger-inl.h index 47002d3e..93dbab7c 100644 --- a/include/spdlog/async_logger-inl.h +++ b/include/spdlog/async_logger-inl.h @@ -83,4 +83,3 @@ SPDLOG_INLINE void spdlog::async_logger::backend_flush_() SPDLOG_LOGGER_CATCH() } } - diff --git a/include/spdlog/async_logger.h b/include/spdlog/async_logger.h index f56e2dd1..f98ba715 100644 --- a/include/spdlog/async_logger.h +++ b/include/spdlog/async_logger.h @@ -49,7 +49,6 @@ public: async_logger(std::string logger_name, sink_ptr single_sink, std::weak_ptr tp, async_overflow_policy overflow_policy = async_overflow_policy::block); - protected: void sink_it_(const details::log_msg &msg) override; void flush_() override; diff --git a/include/spdlog/details/backtracer.h b/include/spdlog/details/backtracer.h index 66dd0196..9b265a7d 100644 --- a/include/spdlog/details/backtracer.h +++ b/include/spdlog/details/backtracer.h @@ -22,11 +22,13 @@ class backtracer public: explicit backtracer(size_t n_messages) - : n_messages_{n_messages}, messages_{n_messages} + : n_messages_{n_messages} + , messages_{n_messages} {} - backtracer(const backtracer &other): - n_messages_{other.n_messages_}, messages_{other.messages_} + backtracer(const backtracer &other) + : n_messages_{other.n_messages_} + , messages_{other.messages_} {} size_t n_messages() const diff --git a/include/spdlog/details/log_msg_buffer.h b/include/spdlog/details/log_msg_buffer.h index d1912492..3015d26a 100644 --- a/include/spdlog/details/log_msg_buffer.h +++ b/include/spdlog/details/log_msg_buffer.h @@ -33,7 +33,7 @@ public: } log_msg_buffer(const log_msg_buffer &other) - : log_msg{other} + : log_msg{other} { buffer.append(logger_name.begin(), logger_name.end()); buffer.append(payload.begin(), payload.end()); diff --git a/include/spdlog/logger-inl.h b/include/spdlog/logger-inl.h index 102e943c..f6f05343 100644 --- a/include/spdlog/logger-inl.h +++ b/include/spdlog/logger-inl.h @@ -23,7 +23,7 @@ SPDLOG_INLINE logger::logger(const logger &other) , flush_level_(other.flush_level_.load(std::memory_order_relaxed)) , custom_err_handler_(other.custom_err_handler_) { - if(other.tracer_) + if (other.tracer_) { tracer_ = std::make_shared(*other.tracer_); } diff --git a/include/spdlog/logger.h b/include/spdlog/logger.h index 3b99615e..8151603e 100644 --- a/include/spdlog/logger.h +++ b/include/spdlog/logger.h @@ -230,7 +230,7 @@ public: #else template - void log(source_loc loc, level::level_enum lvl, wstring_view_t fmt, const Args &... args) + void log(source_loc loc, level::level_enum lvl, wstring_view_t fmt, const Args &... args) { auto level_enabled = should_log(lvl); if (!level_enabled && !tracer_) @@ -239,14 +239,14 @@ public: } SPDLOG_TRY { - // format to wmemory_buffer and convert to utf8 + // format to wmemory_buffer and convert to utf8 fmt::wmemory_buffer wbuf; fmt::format_to(wbuf, fmt, args...); fmt::memory_buffer buf; details::os::wstr_to_utf8buf(wstring_view_t(wbuf.data(), wbuf.size()), buf); details::log_msg log_msg(loc, name_, lvl, string_view_t(buf.data(), buf.size())); - + if (level_enabled) { sink_it_(log_msg); @@ -258,7 +258,7 @@ public: } SPDLOG_LOGGER_CATCH() } - + template void log(level::level_enum lvl, wstring_view_t fmt, const Args &... args) { @@ -356,7 +356,6 @@ public: // error handler void set_error_handler(err_handler); - protected: std::string name_; std::vector sinks_; diff --git a/tests/test_backtrace.cpp b/tests/test_backtrace.cpp index 4c6f123f..98257684 100644 --- a/tests/test_backtrace.cpp +++ b/tests/test_backtrace.cpp @@ -2,69 +2,64 @@ #include "test_sink.h" #include "spdlog/async.h" - - - TEST_CASE("bactrace1", "[bactrace]") { - using spdlog::sinks::test_sink_st; - auto test_sink = std::make_shared(); - int backtrace_size = 5; + using spdlog::sinks::test_sink_st; + auto test_sink = std::make_shared(); + int backtrace_size = 5; - spdlog::logger logger("test-backtrace", test_sink); - logger.set_pattern("%v"); - logger.enable_backtrace(backtrace_size); + spdlog::logger logger("test-backtrace", test_sink); + logger.set_pattern("%v"); + logger.enable_backtrace(backtrace_size); - logger.info("info message"); - for(int i = 0; i < 100; i++) - logger.debug("debug message {}", i); - - REQUIRE(test_sink->lines().size() == 1); - REQUIRE(test_sink->lines()[0] == "info message"); + logger.info("info message"); + for (int i = 0; i < 100; i++) + logger.debug("debug message {}", i); - logger.dump_backtrace(); - REQUIRE(test_sink->lines().size() == backtrace_size +3); - REQUIRE(test_sink->lines()[1] == "****************** Backtrace Start ******************"); - REQUIRE(test_sink->lines()[2] == "debug message 95"); - REQUIRE(test_sink->lines()[3] == "debug message 96"); - REQUIRE(test_sink->lines()[4] == "debug message 97"); - REQUIRE(test_sink->lines()[5] == "debug message 98"); - REQUIRE(test_sink->lines()[6] == "debug message 99"); - REQUIRE(test_sink->lines()[7] == "****************** Backtrace End ********************"); + REQUIRE(test_sink->lines().size() == 1); + REQUIRE(test_sink->lines()[0] == "info message"); + + logger.dump_backtrace(); + REQUIRE(test_sink->lines().size() == backtrace_size + 3); + REQUIRE(test_sink->lines()[1] == "****************** Backtrace Start ******************"); + REQUIRE(test_sink->lines()[2] == "debug message 95"); + REQUIRE(test_sink->lines()[3] == "debug message 96"); + REQUIRE(test_sink->lines()[4] == "debug message 97"); + REQUIRE(test_sink->lines()[5] == "debug message 98"); + REQUIRE(test_sink->lines()[6] == "debug message 99"); + REQUIRE(test_sink->lines()[7] == "****************** Backtrace End ********************"); } - TEST_CASE("bactrace-async", "[bactrace]") { - using spdlog::sinks::test_sink_mt; - auto test_sink = std::make_shared(); - using spdlog::details::os::sleep_for_millis; + using spdlog::sinks::test_sink_mt; + auto test_sink = std::make_shared(); + using spdlog::details::os::sleep_for_millis; - int backtrace_size = 5; + int backtrace_size = 5; - spdlog::init_thread_pool(120, 1); - auto logger = std::make_shared("test-bactrace-async", test_sink, spdlog::thread_pool()); - logger->set_pattern("%v"); - logger->enable_backtrace(backtrace_size); + spdlog::init_thread_pool(120, 1); + auto logger = std::make_shared("test-bactrace-async", test_sink, spdlog::thread_pool()); + logger->set_pattern("%v"); + logger->enable_backtrace(backtrace_size); - logger->info("info message"); - for(int i = 0; i < 100; i++) - logger->debug("debug message {}", i); - - sleep_for_millis(10); - REQUIRE(test_sink->lines().size() == 1); - REQUIRE(test_sink->lines()[0] == "info message"); + logger->info("info message"); + for (int i = 0; i < 100; i++) + logger->debug("debug message {}", i); - logger->dump_backtrace(); - sleep_for_millis(100); // give time for the async dump to complete - REQUIRE(test_sink->lines().size() == backtrace_size +3); - REQUIRE(test_sink->lines()[1] == "****************** Backtrace Start ******************"); - REQUIRE(test_sink->lines()[2] == "debug message 95"); - REQUIRE(test_sink->lines()[3] == "debug message 96"); - REQUIRE(test_sink->lines()[4] == "debug message 97"); - REQUIRE(test_sink->lines()[5] == "debug message 98"); - REQUIRE(test_sink->lines()[6] == "debug message 99"); - REQUIRE(test_sink->lines()[7] == "****************** Backtrace End ********************"); + sleep_for_millis(10); + REQUIRE(test_sink->lines().size() == 1); + REQUIRE(test_sink->lines()[0] == "info message"); + + logger->dump_backtrace(); + sleep_for_millis(100); // give time for the async dump to complete + REQUIRE(test_sink->lines().size() == backtrace_size + 3); + REQUIRE(test_sink->lines()[1] == "****************** Backtrace Start ******************"); + REQUIRE(test_sink->lines()[2] == "debug message 95"); + REQUIRE(test_sink->lines()[3] == "debug message 96"); + REQUIRE(test_sink->lines()[4] == "debug message 97"); + REQUIRE(test_sink->lines()[5] == "debug message 98"); + REQUIRE(test_sink->lines()[6] == "debug message 99"); + REQUIRE(test_sink->lines()[7] == "****************** Backtrace End ********************"); } - diff --git a/tests/test_sink.h b/tests/test_sink.h index 0d4a7d67..08945a85 100644 --- a/tests/test_sink.h +++ b/tests/test_sink.h @@ -18,7 +18,8 @@ namespace sinks { template class test_sink : public base_sink { - const size_t lines_to_save = 100; + const size_t lines_to_save = 100; + public: size_t msg_counter() { @@ -34,42 +35,41 @@ public: void set_delay(std::chrono::milliseconds delay) { - std::lock_guard lock(base_sink::mutex_); + std::lock_guard lock(base_sink::mutex_); delay_ = delay; } - // return last output without the eol - std::vector lines() - { - std::lock_guard lock(base_sink::mutex_); - return lines_; - } - + // return last output without the eol + std::vector lines() + { + std::lock_guard lock(base_sink::mutex_); + return lines_; + } protected: void sink_it_(const details::log_msg &msg) override - { - fmt::memory_buffer formatted; - base_sink::formatter_->format(msg, formatted); - // save the line without the eol - auto eol_len = strlen(details::os::default_eol); - if(lines_.size() < lines_to_save) - { - lines_.emplace_back(formatted.begin(), formatted.end()-eol_len); - } - msg_counter_++; - std::this_thread::sleep_for(delay_); + { + fmt::memory_buffer formatted; + base_sink::formatter_->format(msg, formatted); + // save the line without the eol + auto eol_len = strlen(details::os::default_eol); + if (lines_.size() < lines_to_save) + { + lines_.emplace_back(formatted.begin(), formatted.end() - eol_len); + } + msg_counter_++; + std::this_thread::sleep_for(delay_); } void flush_() override { flush_counter_++; } - + size_t msg_counter_{0}; size_t flush_counter_{0}; std::chrono::milliseconds delay_{std::chrono::milliseconds::zero()}; - std::vector lines_; + std::vector lines_; }; using test_sink_mt = test_sink; From f4d3616c4bcb6c5b33fcecb97818bd249ba70d52 Mon Sep 17 00:00:00 2001 From: gabime Date: Wed, 28 Aug 2019 15:59:58 +0300 Subject: [PATCH 59/59] Update test_backtrace.cpp --- tests/test_backtrace.cpp | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/tests/test_backtrace.cpp b/tests/test_backtrace.cpp index 98257684..89f4426d 100644 --- a/tests/test_backtrace.cpp +++ b/tests/test_backtrace.cpp @@ -7,7 +7,7 @@ TEST_CASE("bactrace1", "[bactrace]") using spdlog::sinks::test_sink_st; auto test_sink = std::make_shared(); - int backtrace_size = 5; + size_t backtrace_size = 5; spdlog::logger logger("test-backtrace", test_sink); logger.set_pattern("%v"); @@ -37,7 +37,7 @@ TEST_CASE("bactrace-async", "[bactrace]") auto test_sink = std::make_shared(); using spdlog::details::os::sleep_for_millis; - int backtrace_size = 5; + size_t backtrace_size = 5; spdlog::init_thread_pool(120, 1); auto logger = std::make_shared("test-bactrace-async", test_sink, spdlog::thread_pool());