Merge pull request #1196 from gabime/backtrace_support

Backtrace support !

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](#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.
@@ -137,15 +138,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!
 ```
 
 ---

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,9 +116,7 @@ int main(int argc, char *argv[])
             auto file_sink = std::make_shared<spdlog::sinks::basic_file_sink_mt>(filename, true);
             auto logger = std::make_shared<async_logger>("async_logger", std::move(file_sink), std::move(tp), async_overflow_policy::block);
             bench_mt(howmany, std::move(logger), threads);
-#ifdef SPDLOG_ASYNC_BENCH_VERIFY
-            verify_file(filename, howmany);
-#endif // SPDLOG_ASYNC_BENCH_VERIFY
+            // verify_file(filename, howmany);
         }
 
         spdlog::info("");
@@ -125,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<details::thread_pool>(queue_size, 1);
@@ -141,7 +141,6 @@ int main(int argc, char *argv[])
         perror("Last error");
         return 1;
     }
-
     return 0;
 }
 

bench/latency.cpp

@@ -90,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<spdlog::logger>("bench", std::make_shared<null_sink_mt>());
+    tracing_disabled_logger->enable_backtrace(64);
+    benchmark::RegisterBenchmark("disabled-at-runtime/backtrace", bench_logger, tracing_disabled_logger);
 
     auto null_logger_st = std::make_shared<spdlog::logger>("bench", std::make_shared<null_sink_st>());
     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<spdlog::logger>("bench", std::make_shared<null_sink_st>());
+    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/backtrace", 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/backtrace", 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<spdlog::logger>("bench", std::make_shared<null_sink_mt>());
     benchmark::RegisterBenchmark("null_sink_mt", bench_logger, null_logger_mt)->Threads(n_threads)->UseRealTime();
 
@@ -138,6 +159,11 @@ int main(int argc, char *argv[])
         "async_logger", std::make_shared<null_sink_mt>(), 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<spdlog::async_logger>(
+        "async_logger_tracing", std::make_shared<null_sink_mt>(), 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();
 }

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"
 
@@ -40,6 +39,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
     {
@@ -47,7 +58,6 @@ int main(int, char *[])
         basic_example();
         rotating_example();
         daily_example();
-        clone_example();
         async_example();
         binary_example();
         multi_sink_example();
@@ -106,14 +116,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()
 {

include/spdlog/async_logger-inl.h

@@ -10,7 +10,6 @@
 #include "spdlog/sinks/sink.h"
 #include "spdlog/details/thread_pool.h"
 
-#include <chrono>
 #include <memory>
 #include <string>
 
@@ -25,7 +24,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())
     {
@@ -53,38 +52,34 @@ SPDLOG_INLINE void spdlog::async_logger::flush_()
 //
 // 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 &msg)
 {
-    SPDLOG_TRY
+    for (auto &sink : sinks_)
     {
-        for (auto &s : sinks_)
+        if (sink->should_log(msg.level))
         {
-            if (s->should_log(incoming_log_msg.level))
+            SPDLOG_TRY
             {
-                s->log(incoming_log_msg);
+                sink->log(msg);
             }
+            SPDLOG_LOGGER_CATCH()
         }
     }
-    SPDLOG_LOGGER_CATCH()
 
-    if (should_flush_(incoming_log_msg))
+    if (should_flush_(msg))
     {
         backend_flush_();
     }
 }
 
-SPDLOG_INLINE void spdlog::async_logger::backend_flush_(){SPDLOG_TRY{for (auto &sink : sinks_){sink->flush();
-}
-}
-SPDLOG_LOGGER_CATCH()
-}
-
-SPDLOG_INLINE std::shared_ptr<spdlog::logger> spdlog::async_logger::clone(std::string new_name)
+SPDLOG_INLINE void spdlog::async_logger::backend_flush_()
 {
-    auto cloned = std::make_shared<spdlog::async_logger>(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_);
-    return cloned;
+    for (auto &sink : sinks_)
+    {
+        SPDLOG_TRY
+        {
+            sink->flush();
+        }
+        SPDLOG_LOGGER_CATCH()
+    }
 }

include/spdlog/async_logger.h

@@ -49,13 +49,10 @@ public:
     async_logger(std::string logger_name, sink_ptr single_sink, std::weak_ptr<details::thread_pool> tp,
         async_overflow_policy overflow_policy = async_overflow_policy::block);
 
-    std::shared_ptr<logger> 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_sink_it_(const details::log_msg &incoming_log_msg);
     void backend_flush_();
 
 private:

include/spdlog/details/backtracer.h

+// 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 <mutex>
+
+// 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_;
+    size_t n_messages_;
+    circular_q<log_msg_buffer> messages_;
+
+public:
+    explicit backtracer(size_t n_messages)
+        : n_messages_{n_messages}
+        , messages_{n_messages}
+    {}
+
+    backtracer(const backtracer &other)
+        : n_messages_{other.n_messages_}
+        , messages_{other.messages_}
+    {}
+
+    size_t n_messages() const
+    {
+        return n_messages_;
+    }
+
+    void add(const log_msg &msg)
+    {
+        std::lock_guard<std::mutex> 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<void(const details::log_msg)> fun)
+    {
+        std::lock_guard<std::mutex> lock{mutex_};
+        while (!messages_.empty())
+        {
+            log_msg_buffer popped;
+            messages_.pop_front(popped);
+            fun(popped);
+        }
+    }
+};
+} // namespace details
+} // namespace spdlog
\ No newline at end of file

include/spdlog/details/log_msg.h

@@ -10,11 +10,12 @@ 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};
@@ -24,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

include/spdlog/details/log_msg_buffer.h

+// 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 {
+
+// extend log_msg with internal buffer to store its payload.
+// this is needed since log_msg holds string_views that points to stack data.
+
+class log_msg_buffer : public log_msg
+{
+    fmt::basic_memory_buffer<char, 200> buffer;
+    void update_string_views()
+    {
+        logger_name = string_view_t{buffer.data(), logger_name.size()};
+        payload = string_view_t{logger_name.end(), payload.size()};
+    }
+
+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(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)}
+    {
+        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
+} // namespace spdlog
\ No newline at end of file

include/spdlog/details/registry-inl.h

@@ -67,6 +67,11 @@ SPDLOG_INLINE void registry::initialize_logger(std::shared_ptr<logger> new_logge
     new_logger->set_level(level_);
     new_logger->flush_on(flush_level_);
 
+    if (backtrace_n_messages_ > 0)
+    {
+        new_logger->enable_backtrace(backtrace_n_messages_);
+    }
+
     if (automatic_registration_)
     {
         register_logger_(std::move(new_logger));
@@ -135,6 +140,27 @@ SPDLOG_INLINE void registry::set_formatter(std::unique_ptr<formatter> formatter)
     }
 }
 
+SPDLOG_INLINE void registry::enable_backtrace(size_t n_messages)
+{
+    std::lock_guard<std::mutex> lock(logger_map_mutex_);
+    backtrace_n_messages_ = n_messages;
+
+    for (auto &l : loggers_)
+    {
+        l.second->enable_backtrace(n_messages);
+    }
+}
+
+SPDLOG_INLINE void registry::disable_backtrace()
+{
+    std::lock_guard<std::mutex> lock(logger_map_mutex_);
+    backtrace_n_messages_ = 0;
+    for (auto &l : loggers_)
+    {
+        l.second->disable_backtrace();
+    }
+}
+
 SPDLOG_INLINE void registry::set_level(level::level_enum log_level)
 {
     std::lock_guard<std::mutex> lock(logger_map_mutex_);

include/spdlog/details/registry.h

@@ -52,6 +52,10 @@ public:
     // Set global formatter. Each sink in each logger will get a clone of this object
     void set_formatter(std::unique_ptr<formatter> formatter);
 
+    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);
@@ -94,6 +98,7 @@ private:
     std::unique_ptr<periodic_worker> periodic_flusher_;
     std::shared_ptr<logger> default_logger_;
     bool automatic_registration_ = true;
+    size_t backtrace_n_messages_ = 0;
 };
 
 } // namespace details

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);
@@ -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_sink_it_(incoming_async_msg);
         return true;
     }
     case async_msg_type::flush:
@@ -114,8 +113,13 @@ bool SPDLOG_INLINE thread_pool::process_next_msg_()
     {
         return false;
     }
-    }
+
+    default:
+    {
         assert(false && "Unexpected async_msg_type");
+    }
+    }
+
     return true;
 }
 

include/spdlog/details/thread_pool.h

@@ -3,7 +3,7 @@
 
 #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"
 
@@ -27,17 +27,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<char, 176> raw;
-
-    source_loc source;
+    async_msg_type msg_type{async_msg_type::log};
     async_logger_ptr worker_ptr;
 
     async_msg() = default;
@@ -49,25 +44,15 @@ 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<log_msg_buffer *>(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;
     }
@@ -77,41 +62,21 @@ struct async_msg
 #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)
-        , 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, const details::log_msg &m)
+        : log_msg_buffer{m}
+        , msg_type{the_type}
+        , worker_ptr{std::move(worker)}
+    {}
 
     async_msg(async_logger_ptr &&worker, async_msg_type the_type)
-        : msg_type(the_type)
-        , level(level::off)
-        , time()
-        , thread_id(0)
-        , source()
-        , 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}
     {}
-
-    // 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
@@ -129,7 +94,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();
 

include/spdlog/logger-inl.h

@@ -8,6 +8,7 @@
 #endif
 
 #include "spdlog/sinks/sink.h"
+#include "spdlog/details/backtracer.h"
 #include "spdlog/details/pattern_formatter.h"
 
 #include <cstdio>
@@ -21,13 +22,20 @@ 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_)
-{}
+{
+    if (other.tracer_)
+    {
+        tracer_ = std::make_shared<details::backtracer>(*other.tracer_);
+    }
+}
 
 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_))
+                                                               custom_err_handler_(std::move(other.custom_err_handler_)),
+                                                               tracer_(std::move(other.tracer_))
+
 {}
 
 SPDLOG_INLINE logger &logger::operator=(logger other) SPDLOG_NOEXCEPT
@@ -52,6 +60,7 @@ SPDLOG_INLINE void logger::swap(spdlog::logger &other) SPDLOG_NOEXCEPT
     other.flush_level_.store(tmp);
 
     custom_err_handler_.swap(other.custom_err_handler_);
+    tracer_.swap(other.tracer_);
 }
 
 SPDLOG_INLINE void swap(logger &a, logger &b)
@@ -59,22 +68,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 (!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
 {
     return msg_level >= level_.load(std::memory_order_relaxed);
@@ -119,6 +112,23 @@ SPDLOG_INLINE void logger::set_pattern(std::string pattern, pattern_time_type ti
     set_formatter(std::move(new_formatter));
 }
 
+// create new backtrace sink and move to it all our child sinks
+SPDLOG_INLINE void logger::enable_backtrace(size_t n_messages)
+{
+    tracer_ = std::make_shared<details::backtracer>(n_messages);
+}
+
+// restore orig sinks and level and delete the backtrace sink
+SPDLOG_INLINE void logger::disable_backtrace()
+{
+    tracer_.reset();
+}
+
+SPDLOG_INLINE void logger::dump_backtrace()
+{
+    dump_backtrace_();
+}
+
 // flush functions
 SPDLOG_INLINE void logger::flush()
 {
@@ -152,16 +162,8 @@ 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> logger::clone(std::string logger_name)
-{
-    auto cloned = std::make_shared<logger>(*this);
-    cloned->name_ = std::move(logger_name);
-    return cloned;
-}
-
 // 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_)
     {
@@ -193,6 +195,22 @@ SPDLOG_INLINE void logger::flush_()
     }
 }
 
+SPDLOG_INLINE void logger::backtrace_add_(const details::log_msg &msg)
+{
+    tracer_->add(msg);
+}
+
+SPDLOG_INLINE void logger::dump_backtrace_()
+{
+    using details::log_msg;
+    if (tracer_)
+    {
+        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 ********************"});
+    }
+}
+
 SPDLOG_INLINE bool logger::should_flush_(const details::log_msg &msg)
 {
     auto flush_level = flush_level_.load(std::memory_order_relaxed);

include/spdlog/logger.h

@@ -38,6 +38,11 @@
 #endif
 
 namespace spdlog {
+
+namespace details {
+class backtracer;
+}
+
 class logger
 {
 public:
@@ -73,25 +78,28 @@ public:
     void swap(spdlog::logger &other) SPDLOG_NOEXCEPT;
 
     template<typename... Args>
-    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()));
+            if (level_enabled)
+            {
                 sink_it_(log_msg);
             }
-        SPDLOG_LOGGER_CATCH()
-    }
-
-    template<typename... Args>
-    void log(source_loc loc, level::level_enum lvl, string_view_t fmt, const Args &... args)
+            if (tracer_)
             {
-        if (should_log(lvl))
-        {
-            force_log(loc, lvl, fmt, args...);
+                backtrace_add_(log_msg);
+            }
         }
+        SPDLOG_LOGGER_CATCH()
     }
 
     template<typename... Args>
@@ -100,9 +108,6 @@ public:
         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<typename... Args>
     void trace(string_view_t fmt, const Args &... args)
     {
@@ -149,14 +154,30 @@ public:
     template<class T, typename std::enable_if<std::is_convertible<const T &, spdlog::string_view_t>::value, T>::type * = nullptr>
     void log(source_loc loc, level::level_enum lvl, const T &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()
+    }
+
+    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
     template<class T, typename std::enable_if<!std::is_convertible<const T &, spdlog::string_view_t>::value &&
@@ -164,18 +185,7 @@ public:
                           T>::type * = nullptr>
     void log(source_loc loc, level::level_enum lvl, const T &msg)
     {
-        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<typename T>
@@ -218,10 +228,16 @@ public:
 #ifndef _WIN32
 #error SPDLOG_WCHAR_TO_UTF8_SUPPORT only supported on windows
 #else
+
     template<typename... Args>
-    void force_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)
     {
-        try
+        auto level_enabled = should_log(lvl);
+        if (!level_enabled && !tracer_)
+        {
+            return;
+        }
+        SPDLOG_TRY
         {
             // format to wmemory_buffer and convert to utf8
             fmt::wmemory_buffer wbuf;
@@ -229,21 +245,19 @@ public:
 
             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<typename... Args>
-    void log(source_loc loc, level::level_enum lvl, wstring_view_t fmt, const Args &... args)
+            if (level_enabled)
             {
-        if (should_log(lvl))
+                sink_it_(log_msg);
+            }
+            if (tracer_)
             {
-            force_log(loc, lvl, fmt, args...);
+                backtrace_add_(log_msg);
             }
         }
+        SPDLOG_LOGGER_CATCH()
+    }
 
     template<typename... Args>
     void log(level::level_enum lvl, wstring_view_t fmt, const Args &... args)
@@ -323,6 +337,12 @@ public:
 
     void set_pattern(std::string pattern, pattern_time_type time_type = pattern_time_type::local);
 
+    // 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();
+
     // flush functions
     void flush();
     void flush_on(level::level_enum log_level);
@@ -336,18 +356,19 @@ public:
     // error handler
     void set_error_handler(err_handler);
 
-    // create new logger with same sinks and configuration.
-    virtual std::shared_ptr<logger> clone(std::string logger_name);
-
 protected:
     std::string name_;
     std::vector<sink_ptr> sinks_;
     spdlog::level_t level_{level::info};
     spdlog::level_t flush_level_{level::off};
     err_handler custom_err_handler_{nullptr};
+    std::shared_ptr<details::backtracer> tracer_;
 
-    virtual void sink_it_(details::log_msg &msg);
+    virtual void sink_it_(const details::log_msg &msg);
     virtual void flush_();
+
+    void backtrace_add_(const details::log_msg &msg);
+    void dump_backtrace_();
     bool should_flush_(const details::log_msg &msg);
 
     // handle errors during logging.

include/spdlog/sinks/daily_file_sink.h

@@ -11,7 +11,6 @@
 #include "spdlog/details/os.h"
 #include "spdlog/details/synchronous_factory.h"
 
-
 #include <chrono>
 #include <cstdio>
 #include <ctime>

include/spdlog/sinks/dist_sink.h

@@ -45,6 +45,11 @@ public:
         sinks_ = std::move(sinks);
     }
 
+    std::vector<std::shared_ptr<sink>> &sinks()
+    {
+        return sinks_;
+    }
+
 protected:
     void sink_it_(const details::log_msg &msg) override
     {

include/spdlog/spdlog-inl.h

@@ -32,6 +32,21 @@ SPDLOG_INLINE void set_pattern(std::string pattern, pattern_time_type time_type)
     set_formatter(std::unique_ptr<spdlog::formatter>(new pattern_formatter(std::move(pattern), time_type)));
 }
 
+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);

include/spdlog/spdlog.h

@@ -60,6 +60,15 @@ void set_formatter(std::unique_ptr<spdlog::formatter> 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(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);
 
@@ -276,12 +285,7 @@ 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__)

src/spdlog.cpp

@@ -6,7 +6,6 @@
 #endif
 
 #include <mutex>
-#include <chrono>
 
 #include "spdlog/details/null_mutex.h"
 #include "spdlog/async.h"

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)

tests/test_backtrace.cpp

+#include "includes.h"
+#include "test_sink.h"
+#include "spdlog/async.h"
+
+TEST_CASE("bactrace1", "[bactrace]")
+{
+
+    using spdlog::sinks::test_sink_st;
+    auto test_sink = std::make_shared<test_sink_st>();
+    size_t backtrace_size = 5;
+
+    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.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<test_sink_mt>();
+    using spdlog::details::os::sleep_for_millis;
+
+    size_t backtrace_size = 5;
+
+    spdlog::init_thread_pool(120, 1);
+    auto logger = std::make_shared<spdlog::async_logger>("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 ********************");
+}

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<sinks::test_sink_mt>("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<sinks::test_sink_mt>(cloned->sinks()[0]);
-
-    spdlog::drop_all();
-}
-
-TEST_CASE("clone async", "[clone]")
-{
-    using namespace spdlog;
-
-    auto logger = spdlog::create_async<sinks::test_sink_mt>("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<sinks::test_sink_mt>(cloned->sinks()[0]);
-
-    spdlog::drop_all();
-}
-
 #include "spdlog/fmt/bin_to_hex.h"
 
 TEST_CASE("to_hex", "[to_hex]")

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 <chrono>
 #include <mutex>
 #include <thread>
@@ -18,6 +18,8 @@ namespace sinks {
 template<class Mutex>
 class test_sink : public base_sink<Mutex>
 {
+    const size_t lines_to_save = 100;
+
 public:
     size_t msg_counter()
     {
@@ -33,12 +35,28 @@ public:
 
     void set_delay(std::chrono::milliseconds delay)
     {
+        std::lock_guard<Mutex> lock(base_sink<Mutex>::mutex_);
         delay_ = delay;
     }
 
+    // return last output without the eol
+    std::vector<std::string> lines()
+    {
+        std::lock_guard<Mutex> lock(base_sink<Mutex>::mutex_);
+        return lines_;
+    }
+
 protected:
-    void sink_it_(const details::log_msg &) override
+    void sink_it_(const details::log_msg &msg) override
+    {
+        fmt::memory_buffer formatted;
+        base_sink<Mutex>::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_);
     }
@@ -47,9 +65,11 @@ protected:
     {
         flush_counter_++;
     }
+
     size_t msg_counter_{0};
     size_t flush_counter_{0};
     std::chrono::milliseconds delay_{std::chrono::milliseconds::zero()};
+    std::vector<std::string> lines_;
 };
 
 using test_sink_mt = test_sink<std::mutex>;