Added mdc from pull #2907

This commit is contained in:
gabime 2024-03-29 15:51:45 +03:00
parent a627f5c43a
commit 8815f81e5d
5 changed files with 203 additions and 21 deletions

View File

@ -218,7 +218,8 @@ set(SPDLOG_HEADERS
"include/spdlog/sinks/systemd_sink.h" "include/spdlog/sinks/systemd_sink.h"
"include/spdlog/sinks/tcp_sink.h" "include/spdlog/sinks/tcp_sink.h"
"include/spdlog/sinks/udp_sink.h" "include/spdlog/sinks/udp_sink.h"
) "include/spdlog/mdc.h"
)
set(SPDLOG_SRCS set(SPDLOG_SRCS
"src/async_logger.cpp" "src/async_logger.cpp"

View File

@ -138,23 +138,6 @@ void daily_example()
``` ```
---
#### Backtrace support
```c++
// Debug messages can be stored in a ring buffer instead of being logged immediately.
// This is useful to display debug logs only when needed (e.g. when an error happens).
// When needed, call dump_backtrace() to dump them to your log.
spdlog::enable_backtrace(32); // Store the latest 32 messages in a buffer.
// or my_logger->enable_backtrace(32)..
for(int i = 0; i < 100; i++)
{
spdlog::debug("Backtrace message {}", i); // not logged yet..
}
// e.g. if some error happened:
spdlog::dump_backtrace(); // log them now! show the last 32 messages
// or my_logger->dump_backtrace(32)..
```
--- ---
#### Periodic flush #### Periodic flush
@ -207,6 +190,22 @@ void binary_example()
``` ```
---
#### Mapped diagnostic context (MDC)
MDC is a map of contextual information that can be used to enrich log messages.
It is a map of key-value pairs that can be set on a per-thread basis since it is stored in thread-local storage.
```c++
#include "spdlog/spdlog.h"
#include "spdlog/mdc"
{
spdlog::mdc::put("key1", "value1");
spdlog::mdc::put("key2", "value2");
// use the %& formatter flag to print all MDC values
spdlog::set_pattern("[%H:%M:%S %z] [%^%L%$] [%&] %v");
spdlog::info("Some log message with context");
}
```
--- ---
#### Logger with multi sinks - each with a different format and log level #### Logger with multi sinks - each with a different format and log level
```c++ ```c++

View File

@ -26,7 +26,7 @@ void udp_example();
void custom_flags_example(); void custom_flags_example();
void file_events_example(); void file_events_example();
void replace_default_logger_example(); void replace_default_logger_example();
void mdc_example();
// Uncomment to enable source location support. // Uncomment to enable source location support.
// This will add filename/line/column info to the log (and in to the resulting binary so take care). // This will add filename/line/column info to the log (and in to the resulting binary so take care).
// #define SPDLOG_SOURCE_LOCATION // #define SPDLOG_SOURCE_LOCATION
@ -75,6 +75,7 @@ int main(int, char *[]) {
custom_flags_example(); custom_flags_example();
file_events_example(); file_events_example();
replace_default_logger_example(); replace_default_logger_example();
mdc_example();
// Flush all *registered* loggers using a worker thread every 3 seconds. // Flush all *registered* loggers using a worker thread every 3 seconds.
// note: registered loggers *must* be thread safe for this to work correctly! // note: registered loggers *must* be thread safe for this to work correctly!
@ -350,3 +351,13 @@ void replace_default_logger_example() {
spdlog::set_default_logger(old_logger); spdlog::set_default_logger(old_logger);
} }
#include "spdlog/mdc.h"
void mdc_example()
{
spdlog::mdc::put("key1", "value1");
spdlog::mdc::put("key2", "value2");
// use the %& formatter flag to print all MDC values
spdlog::set_pattern("[%H:%M:%S %z] [%^%L%$] [%&] %v");
spdlog::info("Some log message with context");
}

View File

@ -7,7 +7,6 @@
#include <array> #include <array>
#include <cctype> #include <cctype>
#include <chrono> #include <chrono>
#include <cstring>
#include <ctime> #include <ctime>
#include <string> #include <string>
#include <thread> #include <thread>
@ -17,6 +16,7 @@
#include "spdlog/details/fmt_helper.h" #include "spdlog/details/fmt_helper.h"
#include "spdlog/details/log_msg.h" #include "spdlog/details/log_msg.h"
#include "spdlog/details/os.h" #include "spdlog/details/os.h"
#include <spdlog/mdc.h>
#include "spdlog/fmt/fmt.h" #include "spdlog/fmt/fmt.h"
#include "spdlog/formatter.h" #include "spdlog/formatter.h"
@ -811,7 +811,6 @@ public:
dest.push_back(']'); dest.push_back(']');
dest.push_back(' '); dest.push_back(' ');
} }
// fmt_helper::append_string_view(msg.msg(), dest);
fmt_helper::append_string_view(msg.payload, dest); fmt_helper::append_string_view(msg.payload, dest);
} }
@ -820,6 +819,44 @@ private:
memory_buf_t cached_datetime_; memory_buf_t cached_datetime_;
}; };
// Class for formatting Mapped Diagnostic Context (MDC) in log messages.
// Example: [logger-name] [info] [mdc_key_1:mdc_value_1 mdc_key_2:mdc_value_2] some message
template <typename ScopedPadder>
class mdc_formatter : public flag_formatter {
public:
explicit mdc_formatter(padding_info padinfo)
: flag_formatter(padinfo) {}
void format(const details::log_msg &, const std::tm &, memory_buf_t &dest) override {
auto mdc_map = mdc::get_context();
if (mdc_map.empty()) {
ScopedPadder p(0, padinfo_, dest);
return;
} else {
auto last_element = --mdc_map.end();
for (auto it = mdc_map.begin(); it != mdc_map.end(); ++it) {
auto &pair = *it;
const auto &key = pair.first;
const auto &value = pair.second;
size_t content_size = key.size() + value.size() + 1; // 1 for ':'
if (it != last_element) {
content_size++; // 1 for ' '
}
ScopedPadder p(content_size, padinfo_, dest);
fmt_helper::append_string_view(key, dest);
fmt_helper::append_string_view(":", dest);
fmt_helper::append_string_view(value, dest);
if (it != last_element) {
fmt_helper::append_string_view(" ", dest);
}
}
}
}
};
} // namespace details } // namespace details
pattern_formatter::pattern_formatter(std::string pattern, pattern_formatter::pattern_formatter(std::string pattern,
@ -1096,6 +1133,10 @@ void pattern_formatter::handle_flag_(char flag, details::padding_info padding) {
formatters_.push_back(std::make_unique<details::elapsed_formatter<Padder, std::chrono::seconds>>(padding)); formatters_.push_back(std::make_unique<details::elapsed_formatter<Padder, std::chrono::seconds>>(padding));
break; break;
case ('&'):
formatters_.push_back(std::make_unique<details::mdc_formatter<Padder>>(padding));
break;
default: // Unknown flag appears as is default: // Unknown flag appears as is
auto unknown_flag = std::make_unique<details::aggregate_formatter>(); auto unknown_flag = std::make_unique<details::aggregate_formatter>();

View File

@ -1,6 +1,7 @@
#include "includes.h" #include "includes.h"
#include "spdlog/sinks/ostream_sink.h" #include "spdlog/sinks/ostream_sink.h"
#include "test_sink.h" #include "test_sink.h"
#include "spdlog/mdc.h"
using spdlog::memory_buf_t; using spdlog::memory_buf_t;
using spdlog::details::to_string_view; using spdlog::details::to_string_view;
@ -456,3 +457,132 @@ TEST_CASE("override need_localtime", "[pattern_formatter]") {
REQUIRE(to_string_view(formatted) == oss.str()); REQUIRE(to_string_view(formatted) == oss.str());
} }
} }
// Test Mapped Diagnostic Context (mdc)
TEST_CASE("mdc formatter test-1", "[pattern_formatter]") {
spdlog::mdc::put("mdc_key_1", "mdc_value_1");
spdlog::mdc::put("mdc_key_2", "mdc_value_2");
auto formatter = std::make_shared<spdlog::pattern_formatter>();
formatter->set_pattern("[%n] [%l] [%&] %v");
memory_buf_t formatted;
spdlog::details::log_msg msg(spdlog::source_loc{}, "logger-name", spdlog::level::info,
"some message");
formatter->format(msg, formatted);
auto expected = spdlog::fmt_lib::format(
"[logger-name] [info] [mdc_key_1:mdc_value_1 mdc_key_2:mdc_value_2] some message{}",
spdlog::details::os::default_eol);
REQUIRE(to_string_view(formatted) == expected);
SECTION("Tear down") { spdlog::mdc::clear(); }
}
TEST_CASE("mdc formatter value update", "[pattern_formatter]") {
spdlog::mdc::put("mdc_key_1", "mdc_value_1");
spdlog::mdc::put("mdc_key_2", "mdc_value_2");
auto formatter = std::make_shared<spdlog::pattern_formatter>();
formatter->set_pattern("[%n] [%l] [%&] %v");
memory_buf_t formatted_1;
spdlog::details::log_msg msg(spdlog::source_loc{}, "logger-name", spdlog::level::info,
"some message");
formatter->format(msg, formatted_1);
auto expected = spdlog::fmt_lib::format(
"[logger-name] [info] [mdc_key_1:mdc_value_1 mdc_key_2:mdc_value_2] some message{}",
spdlog::details::os::default_eol);
REQUIRE(to_string_view(formatted_1) == expected);
spdlog::mdc::put("mdc_key_1", "new_mdc_value_1");
memory_buf_t formatted_2;
formatter->format(msg, formatted_2);
expected = spdlog::fmt_lib::format(
"[logger-name] [info] [mdc_key_1:new_mdc_value_1 mdc_key_2:mdc_value_2] some message{}",
spdlog::details::os::default_eol);
REQUIRE(to_string_view(formatted_2) == expected);
SECTION("Tear down") { spdlog::mdc::clear(); }
}
TEST_CASE("mdc different threads", "[pattern_formatter]") {
auto formatter = std::make_shared<spdlog::pattern_formatter>();
formatter->set_pattern("[%n] [%l] [%&] %v");
spdlog::details::log_msg msg(spdlog::source_loc{}, "logger-name", spdlog::level::info,
"some message");
memory_buf_t formatted_2;
auto lambda_1 = [formatter, msg]() {
spdlog::mdc::put("mdc_key", "thread_1_id");
memory_buf_t formatted;
formatter->format(msg, formatted);
auto expected =
spdlog::fmt_lib::format("[logger-name] [info] [mdc_key:thread_1_id] some message{}",
spdlog::details::os::default_eol);
REQUIRE(to_string_view(formatted) == expected);
};
auto lambda_2 = [formatter, msg]() {
spdlog::mdc::put("mdc_key", "thread_2_id");
memory_buf_t formatted;
formatter->format(msg, formatted);
auto expected =
spdlog::fmt_lib::format("[logger-name] [info] [mdc_key:thread_2_id] some message{}",
spdlog::details::os::default_eol);
REQUIRE(to_string_view(formatted) == expected);
};
std::thread thread_1(lambda_1);
std::thread thread_2(lambda_2);
thread_1.join();
thread_2.join();
SECTION("Tear down") { spdlog::mdc::clear(); }
}
TEST_CASE("mdc remove key", "[pattern_formatter]") {
spdlog::mdc::put("mdc_key_1", "mdc_value_1");
spdlog::mdc::put("mdc_key_2", "mdc_value_2");
spdlog::mdc::remove("mdc_key_1");
auto formatter = std::make_shared<spdlog::pattern_formatter>();
formatter->set_pattern("[%n] [%l] [%&] %v");
memory_buf_t formatted;
spdlog::details::log_msg msg(spdlog::source_loc{}, "logger-name", spdlog::level::info,
"some message");
formatter->format(msg, formatted);
auto expected =
spdlog::fmt_lib::format("[logger-name] [info] [mdc_key_2:mdc_value_2] some message{}",
spdlog::details::os::default_eol);
REQUIRE(to_string_view(formatted) == expected);
SECTION("Tear down") { spdlog::mdc::clear(); }
}
TEST_CASE("mdc empty", "[pattern_formatter]") {
auto formatter = std::make_shared<spdlog::pattern_formatter>();
formatter->set_pattern("[%n] [%l] [%&] %v");
memory_buf_t formatted;
spdlog::details::log_msg msg(spdlog::source_loc{}, "logger-name", spdlog::level::info,
"some message");
formatter->format(msg, formatted);
auto expected = spdlog::fmt_lib::format("[logger-name] [info] [] some message{}",
spdlog::details::os::default_eol);
REQUIRE(to_string_view(formatted) == expected);
SECTION("Tear down") { spdlog::mdc::clear(); }
}