From 9ddf5bff29ebac67e63940b913c58982e884c095 Mon Sep 17 00:00:00 2001 From: M4rFri Date: Fri, 5 Jul 2024 12:54:38 +0200 Subject: [PATCH 01/16] Added attributes --- CMakeLists.txt | 3 +- include/spdlog/attributes.h | 88 +++++++++++++++++++++++++++++++++++++ 2 files changed, 90 insertions(+), 1 deletion(-) create mode 100644 include/spdlog/attributes.h diff --git a/CMakeLists.txt b/CMakeLists.txt index 486d1ae3..1d5edbb4 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -146,7 +146,8 @@ set(SPDLOG_HEADERS "include/spdlog/sinks/systemd_sink.h" "include/spdlog/sinks/tcp_sink.h" "include/spdlog/sinks/udp_sink.h" - "include/spdlog/sinks/async_sink.h") + "include/spdlog/sinks/async_sink.h" + "include/spdlog/attributes.h") set(SPDLOG_SRCS "src/common.cpp" "src/logger.cpp" diff --git a/include/spdlog/attributes.h b/include/spdlog/attributes.h new file mode 100644 index 00000000..63ac12c7 --- /dev/null +++ b/include/spdlog/attributes.h @@ -0,0 +1,88 @@ +#pragma once + +#include + +#include +#include + +namespace spdlog { + +class SPDLOG_API log_attributes { +public: + using attr_map_t = std::unordered_map; + using key_t = attr_map_t::key_type; + using value_t = attr_map_t::mapped_type; + using const_iter = attr_map_t::const_iterator; + + log_attributes() = default; + log_attributes(const log_attributes& other) { + const auto& o_map = other.get_map(); + attr_ctx(o_map.begin(), o_map.end()); + } + log_attributes& operator=(const log_attributes& other) { + if (this != &other) { + clear(); + const auto& o_map = other.get_map(); + attr_ctx(o_map.begin(), o_map.end()); + } + return *this; + } + + void put(const key_t& key, const value_t& value) { + auto lck = lock(); + attrs[key] = value; + } + + void remove(const key_t& key) { + auto lck = lock(); + auto value_it = attrs.find(key); + if (value_it != attrs.end()) { + attrs.erase(key); + } + } + + void clear() { + auto lck = lock(); + attrs.clear(); + } + + bool empty() const { + auto lck = lock(); + return attrs.empty(); + } + + std::pair const get(key_t const& key) const { + auto lck = lock(); + auto value_it = attrs.find(key); + + return std::make_pair(value_it == attrs.end(), value_it); + } + + // provide a local copy of the attributes to be free of race issues + // alternative is to lock the attr_map while the formatter iterates over it + attr_map_t get_map() const { + auto lck = lock(); + return attrs; + } + + template + void attr_ctx(Attribute_Iter begin, Attribute_Iter end) { + auto lck = lock(); + attrs.insert(begin, end); + } + + void attr_ctx(std::initializer_list attributes) { attr_ctx(attributes.begin(), attributes.end()); } + + bool empty() { + auto lck = lock(); + return attrs.empty(); + } + +private: + std::lock_guard lock() const { return std::lock_guard(attrs_mtx); } + + mutable std::mutex attrs_mtx; + attr_map_t attrs; +}; + +} // namespace spdlog \ No newline at end of file From 33d0ea1f73a82d350d83c97f2fdb974ce03a1338 Mon Sep 17 00:00:00 2001 From: M4rFri Date: Fri, 5 Jul 2024 12:56:32 +0200 Subject: [PATCH 02/16] Added attribute formatter --- src/pattern_formatter.cpp | 50 +++++++++++++++++++++++++++++++++++++++ 1 file changed, 50 insertions(+) diff --git a/src/pattern_formatter.cpp b/src/pattern_formatter.cpp index 79c8c62b..c1d5a5a8 100644 --- a/src/pattern_formatter.cpp +++ b/src/pattern_formatter.cpp @@ -742,6 +742,41 @@ private: log_clock::time_point last_message_time_; }; +template +class attribute_formatter final : public flag_formatter { +public: + explicit attribute_formatter(padding_info padinfo) + : flag_formatter(padinfo) {} + + void format(const details::log_msg &msg, const std::tm &, memory_buf_t &dest) override { + if (msg.attributes.empty()) { + ScopedPadder p(0, padinfo_, dest); + return; + } else { + const auto &attributes = msg.attributes.get_map(); + format_attributes(attributes, dest); + } + } + + void format_attributes(const spdlog::log_attributes::attr_map_t &attributes, memory_buf_t &dest) { + for (auto it = attributes.begin(); it != attributes.end(); ++it) { + bool last_item = std::next(it) == attributes.end(); + auto &attribute = *it; + const auto &key = attribute.first; + const auto &value = attribute.second; + size_t content_size = key.size() + value.size() + 1; // 1 for ':' + + if (!last_item) 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 (!last_item) fmt_helper::append_string_view(" ", dest); + } + } +}; + // Full info formatter // pattern: [%Y-%m-%d %H:%M:%S.%e] [%n] [%l] [%s:%#] %v class default_format_formatter final : public flag_formatter { @@ -824,12 +859,23 @@ public: dest.push_back(']'); dest.push_back(' '); } + + // add attributes if present + if (!msg.attributes.empty()) { + dest.push_back('['); + const auto &attributes = msg.attributes.get_map(); + attribute_formatter_.format_attributes(attributes, dest); + dest.push_back(']'); + dest.push_back(' '); + } + fmt_helper::append_string_view(msg.payload, dest); } private: std::chrono::seconds cache_timestamp_{0}; memory_buf_t cached_datetime_; + attribute_formatter attribute_formatter_{padding_info{}}; }; } // namespace details @@ -1107,6 +1153,10 @@ void pattern_formatter::handle_flag_(char flag, details::padding_info padding) { formatters_.push_back(std::make_unique>(padding)); break; + case ('*'): + formatters_.push_back(std::make_unique>(padding)); + break; + default: // Unknown flag appears as is auto unknown_flag = std::make_unique(); From 457549e4ab8d9af104f549db769acd1066db4b93 Mon Sep 17 00:00:00 2001 From: M4rFri Date: Fri, 5 Jul 2024 12:57:01 +0200 Subject: [PATCH 03/16] Updated log_msg to accept attributes --- include/spdlog/details/log_msg.h | 10 +++++++ src/details/log_msg.cpp | 48 ++++++++++++++++++++++++++++++++ 2 files changed, 58 insertions(+) diff --git a/include/spdlog/details/log_msg.h b/include/spdlog/details/log_msg.h index 1badf9e8..39c054f5 100644 --- a/include/spdlog/details/log_msg.h +++ b/include/spdlog/details/log_msg.h @@ -5,14 +5,23 @@ #include +#include "../attributes.h" #include "../common.h" namespace spdlog { namespace details { struct SPDLOG_API log_msg { log_msg() = default; + log_msg(log_clock::time_point log_time, + source_loc loc, + string_view_t logger_name, + level lvl, + string_view_t msg, + log_attributes attributes); log_msg(log_clock::time_point log_time, const source_loc &loc, string_view_t logger_name, level lvl, string_view_t msg); log_msg(const source_loc &loc, string_view_t logger_name, level lvl, string_view_t msg); + log_msg(source_loc loc, string_view_t logger_name, level lvl, string_view_t msg, log_attributes attributes); + log_msg(string_view_t logger_name, level lvl, string_view_t msg, log_attributes attributes); log_msg(string_view_t logger_name, level lvl, string_view_t msg); log_msg(const log_msg &other) = default; log_msg &operator=(const log_msg &other) = default; @@ -28,6 +37,7 @@ struct SPDLOG_API log_msg { source_loc source; string_view_t payload; + log_attributes attributes; }; } // namespace details } // namespace spdlog diff --git a/src/details/log_msg.cpp b/src/details/log_msg.cpp index 80f4b0a6..73897a9c 100644 --- a/src/details/log_msg.cpp +++ b/src/details/log_msg.cpp @@ -8,6 +8,44 @@ namespace spdlog { namespace details { +log_msg::log_msg(spdlog::log_clock::time_point log_time, + spdlog::source_loc loc, + string_view_t a_logger_name, + spdlog::level lvl, + spdlog::string_view_t msg, + spdlog::log_attributes attributes) + : logger_name(a_logger_name), + log_level(lvl), + time(log_time) +#ifndef SPDLOG_NO_THREAD_ID + , + thread_id(os::thread_id()) +#endif + , + source(loc), + payload(msg), + attributes(attributes) { +} + +log_msg::log_msg(const log_clock::time_point log_time, + const source_loc loc, + const string_view_t a_logger_name, + const level lvl, + const string_view_t msg, + const log_attributes attributes) + : logger_name(a_logger_name), + log_level(lvl), + time(log_time), +#ifdef SPDLOG_NO_THREAD_ID + thread_id(0), +#else + thread_id(os::thread_id()), +#endif + source(loc), + payload(msg), + attributes(attributes) { +} + log_msg::log_msg(const log_clock::time_point log_time, const source_loc &loc, const string_view_t logger_name, @@ -28,8 +66,18 @@ log_msg::log_msg(const log_clock::time_point log_time, log_msg::log_msg(const source_loc &loc, const string_view_t logger_name, const level lvl, const string_view_t msg) : log_msg(os::now(), loc, logger_name, lvl, msg) {} +log_msg::log_msg(spdlog::source_loc loc, + string_view_t a_logger_name, + spdlog::level lvl, + spdlog::string_view_t msg, + spdlog::log_attributes attributes) + : log_msg(os::now(), loc, a_logger_name, lvl, msg, attributes) {} + log_msg::log_msg(const string_view_t logger_name, const level lvl, const string_view_t msg) : log_msg(os::now(), source_loc{}, logger_name, lvl, msg) {} +log_msg::log_msg(string_view_t a_logger_name, spdlog::level lvl, spdlog::string_view_t msg, spdlog::log_attributes attributes) + : log_msg(os::now(), source_loc{}, a_logger_name, lvl, msg, attributes) {} + } // namespace details } // namespace spdlog From 0da83dc1efab59a8b217800c5267da551c48de87 Mon Sep 17 00:00:00 2001 From: M4rFri Date: Fri, 5 Jul 2024 12:57:25 +0200 Subject: [PATCH 04/16] Updated logger to accept and log attributes --- include/spdlog/logger.h | 16 ++++++++++++---- src/logger.cpp | 16 ++++++++++++++++ 2 files changed, 28 insertions(+), 4 deletions(-) diff --git a/include/spdlog/logger.h b/include/spdlog/logger.h index ae025df0..5567ed41 100644 --- a/include/spdlog/logger.h +++ b/include/spdlog/logger.h @@ -19,6 +19,7 @@ #include "details/err_helper.h" #include "details/log_msg.h" #include "sinks/sink.h" +#include "attributes.h" namespace spdlog { @@ -63,20 +64,20 @@ public: // log with no format string, just string message void log(const source_loc &loc, level lvl, string_view_t msg) noexcept { if (should_log(lvl)) { - sink_it_(details::log_msg(loc, name_, lvl, msg)); + sink_it_(details::log_msg(loc, name_, lvl, msg, attributes)); } } void log(level lvl, string_view_t msg) noexcept { if (should_log(lvl)) { - sink_it_(details::log_msg(source_loc{}, name_, lvl, msg)); + sink_it_(details::log_msg(source_loc{}, name_, lvl, msg, attributes)); } } // support for custom time void log(log_clock::time_point log_time, const source_loc &loc, level lvl, string_view_t msg) noexcept { if (should_log(lvl)) { - sink_it_(details::log_msg(log_time, loc, name_, lvl, msg)); + sink_it_(details::log_msg(log_time, loc, name_, lvl, msg, attributes)); } } @@ -160,9 +161,16 @@ public: // create new logger with same sinks and configuration. std::shared_ptr clone(std::string logger_name); + void push_attribute(log_attributes::attr_map_t const &attributes); + void push_attribute(log_attributes::key_t const &key, log_attributes::value_t const &value); + void push_attribute(log_attributes const &attributes); + void remove_attribute(const log_attributes::key_t &key); + void clear_attribute(); + private: std::string name_; std::vector sinks_; + log_attributes attributes; atomic_level_t level_{level::info}; atomic_level_t flush_level_{level::off}; details::err_helper err_helper_; @@ -178,7 +186,7 @@ private: try { memory_buf_t buf; fmt::vformat_to(std::back_inserter(buf), format_string, fmt::make_format_args(args...)); - sink_it_(details::log_msg(loc, name_, lvl, string_view_t(buf.data(), buf.size()))); + sink_it_(details::log_msg(loc, name_, lvl, string_view_t(buf.data(), buf.size()), attributes)); } catch (const std::exception &ex) { err_helper_.handle_ex(name_, loc, ex); } catch (...) { diff --git a/src/logger.cpp b/src/logger.cpp index dc480bae..4da695af 100644 --- a/src/logger.cpp +++ b/src/logger.cpp @@ -81,4 +81,20 @@ void logger::flush_() noexcept { } } } + +void logger::push_attribute(const log_attributes::attr_map_t &attributes) { + this->attributes.attr_ctx(attributes.begin(), attributes.end()); +} +void logger::push_attribute(const log_attributes::key_t &key, const log_attributes::value_t &value) { + attributes.put(key, value); +} +void logger::push_attribute(const log_attributes &attributes) { + const auto &map = attributes.get_map(); + this->attributes.attr_ctx(map.begin(), map.end()); +} + +void logger::remove_attribute(const log_attributes::key_t &key) { attributes.remove(key); } + +void logger::clear_attribute() { attributes.clear(); } + } // namespace spdlog From d17331ec2658a9578ea9f454c423b6d612687757 Mon Sep 17 00:00:00 2001 From: M4rFri Date: Fri, 5 Jul 2024 12:57:33 +0200 Subject: [PATCH 05/16] Added some unit tests --- tests/CMakeLists.txt | 1 + tests/test_attributes.cpp | 26 +++++++++++ tests/test_pattern_formatter.cpp | 77 ++++++++++++++++++++++++++++++++ 3 files changed, 104 insertions(+) create mode 100644 tests/test_attributes.cpp diff --git a/tests/CMakeLists.txt b/tests/CMakeLists.txt index acd02d02..5a4b2c6d 100644 --- a/tests/CMakeLists.txt +++ b/tests/CMakeLists.txt @@ -51,6 +51,7 @@ set(SPDLOG_UTESTS_SOURCES test_no_source_location.cpp test_log_level.cpp test_include_sinks.cpp + test_attributes.cpp test_bin_to_hex.cpp test_errors.cpp) diff --git a/tests/test_attributes.cpp b/tests/test_attributes.cpp new file mode 100644 index 00000000..2c1f5977 --- /dev/null +++ b/tests/test_attributes.cpp @@ -0,0 +1,26 @@ +#include "includes.h" +#include "spdlog/mdc.h" +#include "spdlog/sinks/stdout_sinks.h" +#include "spdlog/spdlog.h" +#include "test_sink.h" + +TEST_CASE("Attribute test") { + auto test_sink = std::make_shared(); + spdlog::logger log_a("log_a", test_sink); + spdlog::logger log_b("log_b", test_sink); + log_a.set_pattern("[%n] [%*]"); + log_b.set_pattern("[%n] [%*]"); + + log_a.push_attribute("my_key", "my_value"); + + log_a.info("Hello"); + log_b.info("Hello"); + + auto expected_log_a = spdlog::fmt_lib::format("[log_a] [my_key:my_value]"); + auto expected_log_b = spdlog::fmt_lib::format("[log_b] []"); + + auto lines = test_sink->lines(); + REQUIRE(lines.size() == 2); + REQUIRE(lines[0] == expected_log_a); + REQUIRE(lines[1] == expected_log_b); +} \ No newline at end of file diff --git a/tests/test_pattern_formatter.cpp b/tests/test_pattern_formatter.cpp index bcc61f18..789b4dfb 100644 --- a/tests/test_pattern_formatter.cpp +++ b/tests/test_pattern_formatter.cpp @@ -481,3 +481,80 @@ TEST_CASE("override need_localtime", "[pattern_formatter]") { REQUIRE(to_string_view(formatted) == oss.str()); } } + +TEST_CASE("attribute formatter test-1", "[pattern_formatter]") { + spdlog::log_attributes attributes; + attributes.put("attribute_key_1", "attribute_value_1"); + attributes.put("attribute_key_2", "attribute_value_2"); + + auto formatter = std::make_shared(); + 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", attributes); + formatter->format(msg, formatted); + + auto expected = spdlog::fmt_lib::format( + "[logger-name] [info] [attribute_key_1:attribute_value_1 attribute_key_2:attribute_value_2] some message{}", + spdlog::details::os::default_eol); + REQUIRE(to_string_view(formatted) == expected); +} + +TEST_CASE("attribute formatter value update", "[pattern_formatter]") { + spdlog::log_attributes attributes; + attributes.put("attribute_key_1", "attribute_value_1"); + attributes.put("attribute_key_2", "attribute_value_2"); + + auto formatter = std::make_shared(); + 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", attributes); + formatter->format(msg, formatted_1); + + auto expected = spdlog::fmt_lib::format( + "[logger-name] [info] [attribute_key_1:attribute_value_1 attribute_key_2:attribute_value_2] some message{}", + spdlog::details::os::default_eol); + + REQUIRE(to_string_view(formatted_1) == expected); + + msg.attributes.put("attribute_key_1", "new_attribute_value_1"); + memory_buf_t formatted_2; + formatter->format(msg, formatted_2); + expected = spdlog::fmt_lib::format( + "[logger-name] [info] [attribute_key_1:new_attribute_value_1 attribute_key_2:attribute_value_2] some message{}", + spdlog::details::os::default_eol); + + REQUIRE(to_string_view(formatted_2) == expected); +} + +TEST_CASE("attribute remove key", "[pattern_formatter]") { + spdlog::log_attributes attributes; + attributes.put("attribute_key_1", "attribute_value_1"); + attributes.put("attribute_key_2", "attribute_value_2"); + attributes.remove("attribute_key_1"); + + auto formatter = std::make_shared(); + 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", attributes); + formatter->format(msg, formatted); + + auto expected = spdlog::fmt_lib::format("[logger-name] [info] [attribute_key_2:attribute_value_2] some message{}", + spdlog::details::os::default_eol); + REQUIRE(to_string_view(formatted) == expected); +} + +TEST_CASE("attribute empty", "[pattern_formatter]") { + spdlog::log_attributes attributes; + auto formatter = std::make_shared(); + 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", attributes); + 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); +} From b63b652d6c3ad765e8d8904c80cc487d5e8c8de1 Mon Sep 17 00:00:00 2001 From: Felix Heitmann Date: Fri, 5 Jul 2024 14:54:55 +0200 Subject: [PATCH 06/16] Attributes: Removing impact on logger The logger interface should not be bloated by additional functionality. Reducing it to a nested call to `.attrs().put()` achieves the same nesting as `.put_attribute()` but requires a smaller interface change on the logger class. --- include/spdlog/logger.h | 6 +----- src/logger.cpp | 15 +-------------- tests/test_attributes.cpp | 2 +- 3 files changed, 3 insertions(+), 20 deletions(-) diff --git a/include/spdlog/logger.h b/include/spdlog/logger.h index 5567ed41..9302483c 100644 --- a/include/spdlog/logger.h +++ b/include/spdlog/logger.h @@ -161,11 +161,7 @@ public: // create new logger with same sinks and configuration. std::shared_ptr clone(std::string logger_name); - void push_attribute(log_attributes::attr_map_t const &attributes); - void push_attribute(log_attributes::key_t const &key, log_attributes::value_t const &value); - void push_attribute(log_attributes const &attributes); - void remove_attribute(const log_attributes::key_t &key); - void clear_attribute(); + log_attributes &attrs(); private: std::string name_; diff --git a/src/logger.cpp b/src/logger.cpp index 4da695af..258c8700 100644 --- a/src/logger.cpp +++ b/src/logger.cpp @@ -82,19 +82,6 @@ void logger::flush_() noexcept { } } -void logger::push_attribute(const log_attributes::attr_map_t &attributes) { - this->attributes.attr_ctx(attributes.begin(), attributes.end()); -} -void logger::push_attribute(const log_attributes::key_t &key, const log_attributes::value_t &value) { - attributes.put(key, value); -} -void logger::push_attribute(const log_attributes &attributes) { - const auto &map = attributes.get_map(); - this->attributes.attr_ctx(map.begin(), map.end()); -} - -void logger::remove_attribute(const log_attributes::key_t &key) { attributes.remove(key); } - -void logger::clear_attribute() { attributes.clear(); } +log_attributes &logger::attrs() { return attributes; } } // namespace spdlog diff --git a/tests/test_attributes.cpp b/tests/test_attributes.cpp index 2c1f5977..fec7fa8e 100644 --- a/tests/test_attributes.cpp +++ b/tests/test_attributes.cpp @@ -11,7 +11,7 @@ TEST_CASE("Attribute test") { log_a.set_pattern("[%n] [%*]"); log_b.set_pattern("[%n] [%*]"); - log_a.push_attribute("my_key", "my_value"); + log_a.attrs().put("my_key", "my_value"); log_a.info("Hello"); log_b.info("Hello"); From fbba947af44c7943fa220b7d4af716d8148a3f13 Mon Sep 17 00:00:00 2001 From: Felix Heitmann Date: Fri, 5 Jul 2024 14:55:46 +0200 Subject: [PATCH 07/16] Attributes: moving to ordered map Otherwise the attributes are printed in pseudo-random order. --- include/spdlog/attributes.h | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/include/spdlog/attributes.h b/include/spdlog/attributes.h index 63ac12c7..f3ce23a8 100644 --- a/include/spdlog/attributes.h +++ b/include/spdlog/attributes.h @@ -2,14 +2,15 @@ #include +#include #include -#include + namespace spdlog { class SPDLOG_API log_attributes { public: - using attr_map_t = std::unordered_map; + using attr_map_t = std::map; using key_t = attr_map_t::key_type; using value_t = attr_map_t::mapped_type; using const_iter = attr_map_t::const_iterator; From d468e32a88e25822decd714eeb289534a4d4a087 Mon Sep 17 00:00:00 2001 From: Felix Heitmann Date: Fri, 5 Jul 2024 14:56:11 +0200 Subject: [PATCH 08/16] Attributes: invert attr search logic --- include/spdlog/attributes.h | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/include/spdlog/attributes.h b/include/spdlog/attributes.h index f3ce23a8..5b7fb141 100644 --- a/include/spdlog/attributes.h +++ b/include/spdlog/attributes.h @@ -52,11 +52,12 @@ public: return attrs.empty(); } + // return {true, iter} if found, {false, end} otherwise std::pair const get(key_t const& key) const { auto lck = lock(); auto value_it = attrs.find(key); - return std::make_pair(value_it == attrs.end(), value_it); + return std::make_pair(value_it != attrs.end(), value_it); } // provide a local copy of the attributes to be free of race issues From 9d708f921a0c3f8846e59b66f6b38ce1baa0c5f5 Mon Sep 17 00:00:00 2001 From: Felix Heitmann Date: Fri, 5 Jul 2024 14:57:08 +0200 Subject: [PATCH 09/16] Attributes proper insertion overloads. Previous functions were named poorly due to miscommunication between the devs. All functions to put attributes on a logger are `put`. --- include/spdlog/attributes.h | 13 +++++-------- 1 file changed, 5 insertions(+), 8 deletions(-) diff --git a/include/spdlog/attributes.h b/include/spdlog/attributes.h index 5b7fb141..7d768531 100644 --- a/include/spdlog/attributes.h +++ b/include/spdlog/attributes.h @@ -16,23 +16,20 @@ public: using const_iter = attr_map_t::const_iterator; log_attributes() = default; - log_attributes(const log_attributes& other) { - const auto& o_map = other.get_map(); - attr_ctx(o_map.begin(), o_map.end()); - } + log_attributes(const log_attributes& other) { put(other.get_map()); } log_attributes& operator=(const log_attributes& other) { if (this != &other) { clear(); - const auto& o_map = other.get_map(); - attr_ctx(o_map.begin(), o_map.end()); + put(other.get_map()); } return *this; } - void put(const key_t& key, const value_t& value) { + void put(attr_map_t const& attributes) { auto lck = lock(); - attrs[key] = value; + attrs.insert(attributes.begin(), attributes.end()); } + void put(const key_t& key, const value_t& value) { put({{key, value}}); } void remove(const key_t& key) { auto lck = lock(); From 1b2acfca20c8ebc197e56d7209496a392c56546a Mon Sep 17 00:00:00 2001 From: Felix Heitmann Date: Fri, 5 Jul 2024 14:59:56 +0200 Subject: [PATCH 10/16] Attributes: scoped contexts Oftentimes you want to put attributes into a logger (file names, ids, etc.) only for a specific scope (e.g. a function or an if-clause). Creating a scoped-context will allow this, by returning an RAII-object that will remove the inserted keys upon destruction. --- include/spdlog/attributes.h | 29 ++++++++++++++++++++++------- 1 file changed, 22 insertions(+), 7 deletions(-) diff --git a/include/spdlog/attributes.h b/include/spdlog/attributes.h index 7d768531..462803ba 100644 --- a/include/spdlog/attributes.h +++ b/include/spdlog/attributes.h @@ -15,6 +15,25 @@ public: using value_t = attr_map_t::mapped_type; using const_iter = attr_map_t::const_iterator; + class SPDLOG_API log_attr_context { + public: + log_attr_context(log_attributes& parent, attr_map_t const& attrs) + : parent_(parent), + tmp_attrs_{attrs} { + parent_.put(attrs); + } + explicit log_attr_context(log_attributes& parent) + : log_attr_context(parent, {}) {} + + ~log_attr_context() { + for (auto&& key_value : tmp_attrs_) parent_.remove(key_value.first); + } + + private: + log_attributes& parent_; + attr_map_t tmp_attrs_; + }; + log_attributes() = default; log_attributes(const log_attributes& other) { put(other.get_map()); } log_attributes& operator=(const log_attributes& other) { @@ -64,13 +83,9 @@ public: return attrs; } - template - void attr_ctx(Attribute_Iter begin, Attribute_Iter end) { - auto lck = lock(); - attrs.insert(begin, end); - } - - void attr_ctx(std::initializer_list attributes) { attr_ctx(attributes.begin(), attributes.end()); } + // RAII-wrapper that inserts a couple of attributes and removes them upon destruction + log_attr_context scoped_ctx(attr_map_t const& attributes) { return log_attr_context(*this, attributes); } + log_attr_context scoped_ctx(key_t key, value_t value) { return log_attr_context(*this, {{key, value}}); } bool empty() { auto lck = lock(); From 976af140b050a13216d9ea1558bc5f24519b463e Mon Sep 17 00:00:00 2001 From: Felix Heitmann Date: Fri, 5 Jul 2024 15:00:06 +0200 Subject: [PATCH 11/16] Attributes include unit-tests --- tests/test_attributes.cpp | 187 ++++++++++++++++++++++++++++++++++++-- 1 file changed, 181 insertions(+), 6 deletions(-) diff --git a/tests/test_attributes.cpp b/tests/test_attributes.cpp index fec7fa8e..de5482c4 100644 --- a/tests/test_attributes.cpp +++ b/tests/test_attributes.cpp @@ -1,13 +1,30 @@ +#include + #include "includes.h" #include "spdlog/mdc.h" #include "spdlog/sinks/stdout_sinks.h" #include "spdlog/spdlog.h" #include "test_sink.h" -TEST_CASE("Attribute test") { - auto test_sink = std::make_shared(); - spdlog::logger log_a("log_a", test_sink); - spdlog::logger log_b("log_b", test_sink); +using namespace spdlog; + +std::string format_attrs(std::string_view const log_name, log_attributes::attr_map_t const& attrs = {}) { + std::vector fmt_attrs; + for (auto&& attr : attrs) fmt_attrs.push_back(fmt::format("{}:{}", attr.first, attr.second)); + return fmt::format("[{}] [{}]", log_name, fmt::join(fmt_attrs, " ")); +} + +std::pair> make_logger() { + auto test_sink = std::make_shared(); + auto log = logger("logger", test_sink); + log.set_pattern("[%n] [%*]"); + return std::make_pair(log, test_sink); +} + +TEST_CASE("attribute test - multiple (single thread)") { + auto test_sink = std::make_shared(); + logger log_a("log_a", test_sink); + logger log_b("log_b", test_sink); log_a.set_pattern("[%n] [%*]"); log_b.set_pattern("[%n] [%*]"); @@ -16,11 +33,169 @@ TEST_CASE("Attribute test") { log_a.info("Hello"); log_b.info("Hello"); - auto expected_log_a = spdlog::fmt_lib::format("[log_a] [my_key:my_value]"); - auto expected_log_b = spdlog::fmt_lib::format("[log_b] []"); + auto expected_log_a = format_attrs("log_a", {{"my_key", "my_value"}}); + auto expected_log_b = format_attrs("log_b"); + + auto [found, value] = log_a.attrs().get("my_key"); + REQUIRE(found); + REQUIRE(value->first == "my_key"); + REQUIRE(value->second == "my_value"); + + auto [not_found, _] = log_a.attrs().get("my_non_existent_key"); + REQUIRE(!not_found); auto lines = test_sink->lines(); REQUIRE(lines.size() == 2); REQUIRE(lines[0] == expected_log_a); REQUIRE(lines[1] == expected_log_b); +} + +TEST_CASE("attribute test - remove") { + std::vector attrs{ + {"my_key", "my_value"}, + {"my_key2", "my_value2"}, + }; + + auto [log, test_sink] = make_logger(); + + log.attrs().put(attrs[0].first, attrs[0].second); + log.attrs().put(attrs[1].first, attrs[1].second); + + log.info(""); + auto expected_log = format_attrs("logger", {attrs.begin(), attrs.end()}); + + REQUIRE(!test_sink->lines().empty()); + REQUIRE(test_sink->lines().back() == expected_log); + + log.attrs().remove(attrs.front().first); + log.info(""); + expected_log = format_attrs("logger", {attrs.begin() + 1, attrs.end()}); + REQUIRE(test_sink->lines().back() == expected_log); + + log.attrs().remove(attrs.back().first); + log.info(""); + expected_log = format_attrs("logger"); + REQUIRE(test_sink->lines().back() == expected_log); +} + +TEST_CASE("attribute test - from range") { + std::vector attrs{ + {"my_key", "my_value"}, + {"my_key2", "my_value2"}, + }; + + auto [log, test_sink] = make_logger(); + + log.attrs().put({attrs.begin(), attrs.end()}); + log.info(""); + auto expected_log = format_attrs("logger", {attrs.begin(), attrs.end()}); + + REQUIRE(!test_sink->lines().empty()); + REQUIRE(test_sink->lines().back() == expected_log); +} + +TEST_CASE("attribute test - scoped") { + std::vector attrs{ + {"my_key", "my_value"}, + {"my_key2", "my_value2"}, + }; + + auto [log, test_sink] = make_logger(); + + auto key_value = std::make_pair("additional_key", "additional_value"); + { + // add the attributes in scope + auto ctx = log.attrs().scoped_ctx({attrs.begin(), attrs.end()}); + log.info(""); + auto expected_log = format_attrs("logger", {attrs.begin(), attrs.end()}); + + REQUIRE(!test_sink->lines().empty()); + REQUIRE(test_sink->lines().back() == expected_log); + + // remove one of the scoped attributes + log.attrs().remove(attrs.front().first); + log.info(""); + expected_log = format_attrs("logger", {attrs.begin() + 1, attrs.end()}); + REQUIRE(test_sink->lines().back() == expected_log); + + // add another non-scoped attribute + log.attrs().put(key_value.first, key_value.second); + log.info(""); + expected_log = format_attrs("logger", {attrs[1], key_value}); + REQUIRE(test_sink->lines().back() == expected_log); + } + + log.info(""); + auto expected_log = format_attrs("logger", {key_value}); +} + +TEST_CASE("attribute test - nested scoped") { + std::vector attrs{ + {"my_key", "my_value"}, + {"my_key2", "my_value2"}, + }; + std::vector nested_attrs{ + {"nested_key", "nested_value"}, + {"nested_key2", "nested_value2"}, + }; + + auto [log, test_sink] = make_logger(); + + { + // add the attributes in scope + auto ctx = log.attrs().scoped_ctx({attrs.begin(), attrs.end()}); + log.info(""); + auto expected_log = format_attrs("logger", {attrs.begin(), attrs.end()}); + + REQUIRE(!test_sink->lines().empty()); + REQUIRE(test_sink->lines().back() == expected_log); + + // add another scoped context + { + auto ctx_nested = log.attrs().scoped_ctx({nested_attrs.begin(), nested_attrs.end()}); + log.info(""); + log_attributes::attr_map_t all_attrs{attrs.begin(), attrs.end()}; + all_attrs.insert(nested_attrs.begin(), nested_attrs.end()); + expected_log = format_attrs("logger", {all_attrs.begin(), all_attrs.end()}); + REQUIRE(test_sink->lines().back() == expected_log); + } + + // delete nested scope + log.info(""); + expected_log = format_attrs("logger", {attrs.begin(), attrs.end()}); + REQUIRE(test_sink->lines().back() == expected_log); + } + + log.info(""); + auto expected_log = format_attrs("logger"); +} + +TEST_CASE("attribute test - multi threaded") { + const int n_tasks = std::thread::hardware_concurrency(); + constexpr auto n_values = 30; + auto mt_sink = std::make_shared(); + auto logger = spdlog::logger("logger", mt_sink); + logger.set_pattern("[%n] [%*]"); + + // put attributes with multiple threads simultaneously + std::vector> tasks; + for (auto i = 0; i < n_tasks; ++i) { + auto task = std::async([&logger, i, n_values] { + for (auto j = 0; j < n_values; ++j) + logger.attrs().put(fmt::format("log_{}_key_{}", i, j), fmt::format("log_{}_value_{}", i, j)); + }); + tasks.emplace_back(std::move(task)); + } + + for (auto&& task : tasks) task.wait(); + + logger.info(""); + REQUIRE(!mt_sink->lines().empty()); + auto log_line = mt_sink->lines().back(); + for (auto i = 0; i < n_tasks; ++i) { + for (auto j = 0; j < n_values; ++j) { + auto search_term = fmt::format("log_{0}_key_{1}:log_{0}_value_{1}", i, j); + REQUIRE(log_line.find(search_term) != std::string::npos); + } + } } \ No newline at end of file From 25ee4f3ffbd27e841f3087f2f57cf8cc1fdac905 Mon Sep 17 00:00:00 2001 From: Felix Heitmann Date: Tue, 9 Jul 2024 13:54:26 +0200 Subject: [PATCH 12/16] Attribute tests: remove fmtlib from tests Use the spdlog::fmt_lib wrapper instead. --- tests/test_attributes.cpp | 12 +++++++----- 1 file changed, 7 insertions(+), 5 deletions(-) diff --git a/tests/test_attributes.cpp b/tests/test_attributes.cpp index de5482c4..53feb7b9 100644 --- a/tests/test_attributes.cpp +++ b/tests/test_attributes.cpp @@ -9,9 +9,11 @@ using namespace spdlog; std::string format_attrs(std::string_view const log_name, log_attributes::attr_map_t const& attrs = {}) { - std::vector fmt_attrs; - for (auto&& attr : attrs) fmt_attrs.push_back(fmt::format("{}:{}", attr.first, attr.second)); - return fmt::format("[{}] [{}]", log_name, fmt::join(fmt_attrs, " ")); + std::string fmt_attrs; + for (auto&& attr : attrs) fmt_attrs += fmt_lib::format("{}:{} ", attr.first, attr.second); + if (!fmt_attrs.empty()) fmt_attrs.pop_back(); + + return fmt_lib::format("[{}] [{}]", log_name, fmt_attrs); } std::pair> make_logger() { @@ -182,7 +184,7 @@ TEST_CASE("attribute test - multi threaded") { for (auto i = 0; i < n_tasks; ++i) { auto task = std::async([&logger, i, n_values] { for (auto j = 0; j < n_values; ++j) - logger.attrs().put(fmt::format("log_{}_key_{}", i, j), fmt::format("log_{}_value_{}", i, j)); + logger.attrs().put(fmt_lib::format("log_{}_key_{}", i, j), fmt_lib::format("log_{}_value_{}", i, j)); }); tasks.emplace_back(std::move(task)); } @@ -194,7 +196,7 @@ TEST_CASE("attribute test - multi threaded") { auto log_line = mt_sink->lines().back(); for (auto i = 0; i < n_tasks; ++i) { for (auto j = 0; j < n_values; ++j) { - auto search_term = fmt::format("log_{0}_key_{1}:log_{0}_value_{1}", i, j); + auto search_term = fmt_lib::format("log_{0}_key_{1}:log_{0}_value_{1}", i, j); REQUIRE(log_line.find(search_term) != std::string::npos); } } From 58912623bcf951bc3647d4192ddcdfd4d29937b5 Mon Sep 17 00:00:00 2001 From: Felix Heitmann Date: Tue, 9 Jul 2024 14:52:58 +0200 Subject: [PATCH 13/16] Attributes: use proper function for overwriting attributes --- include/spdlog/attributes.h | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/include/spdlog/attributes.h b/include/spdlog/attributes.h index 462803ba..33a65c87 100644 --- a/include/spdlog/attributes.h +++ b/include/spdlog/attributes.h @@ -46,7 +46,7 @@ public: void put(attr_map_t const& attributes) { auto lck = lock(); - attrs.insert(attributes.begin(), attributes.end()); + for (auto const& attribute : attributes) attrs.insert_or_assign(attribute.first, attribute.second); } void put(const key_t& key, const value_t& value) { put({{key, value}}); } From 25cfceca04f5dbde91c5f220178edcabbf02a183 Mon Sep 17 00:00:00 2001 From: Felix Heitmann Date: Tue, 8 Oct 2024 09:37:28 +0200 Subject: [PATCH 14/16] fixing signed/unsigned in test attributes --- tests/test_attributes.cpp | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/tests/test_attributes.cpp b/tests/test_attributes.cpp index 53feb7b9..799619cc 100644 --- a/tests/test_attributes.cpp +++ b/tests/test_attributes.cpp @@ -173,7 +173,7 @@ TEST_CASE("attribute test - nested scoped") { } TEST_CASE("attribute test - multi threaded") { - const int n_tasks = std::thread::hardware_concurrency(); + const unsigned int n_tasks = std::thread::hardware_concurrency(); constexpr auto n_values = 30; auto mt_sink = std::make_shared(); auto logger = spdlog::logger("logger", mt_sink); @@ -181,7 +181,7 @@ TEST_CASE("attribute test - multi threaded") { // put attributes with multiple threads simultaneously std::vector> tasks; - for (auto i = 0; i < n_tasks; ++i) { + for (unsigned int i = 0; i < n_tasks; ++i) { auto task = std::async([&logger, i, n_values] { for (auto j = 0; j < n_values; ++j) logger.attrs().put(fmt_lib::format("log_{}_key_{}", i, j), fmt_lib::format("log_{}_value_{}", i, j)); @@ -194,7 +194,7 @@ TEST_CASE("attribute test - multi threaded") { logger.info(""); REQUIRE(!mt_sink->lines().empty()); auto log_line = mt_sink->lines().back(); - for (auto i = 0; i < n_tasks; ++i) { + for (unsigned int i = 0; i < n_tasks; ++i) { for (auto j = 0; j < n_values; ++j) { auto search_term = fmt_lib::format("log_{0}_key_{1}:log_{0}_value_{1}", i, j); REQUIRE(log_line.find(search_term) != std::string::npos); From c8596c05ce3f305dd0a430799eda40f646d080bd Mon Sep 17 00:00:00 2001 From: Felix Heitmann Date: Tue, 8 Oct 2024 09:42:12 +0200 Subject: [PATCH 15/16] Test attributes: fixing wrongful lambda capture constexpr doesn't need to be captured. failed ci/cd --- tests/test_attributes.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/tests/test_attributes.cpp b/tests/test_attributes.cpp index 799619cc..7907abb2 100644 --- a/tests/test_attributes.cpp +++ b/tests/test_attributes.cpp @@ -182,7 +182,7 @@ TEST_CASE("attribute test - multi threaded") { // put attributes with multiple threads simultaneously std::vector> tasks; for (unsigned int i = 0; i < n_tasks; ++i) { - auto task = std::async([&logger, i, n_values] { + auto task = std::async([&logger, i] { for (auto j = 0; j < n_values; ++j) logger.attrs().put(fmt_lib::format("log_{}_key_{}", i, j), fmt_lib::format("log_{}_value_{}", i, j)); }); From 0f9f7540d3508904327343da02b7c0eeb1fe9419 Mon Sep 17 00:00:00 2001 From: M4rFri Date: Tue, 11 Feb 2025 11:26:43 +0100 Subject: [PATCH 16/16] fixed some rebase errors --- include/spdlog/details/log_msg.h | 4 ++-- src/details/log_msg.cpp | 39 +++++++------------------------- tests/test_attributes.cpp | 3 +-- 3 files changed, 11 insertions(+), 35 deletions(-) diff --git a/include/spdlog/details/log_msg.h b/include/spdlog/details/log_msg.h index 39c054f5..e575597d 100644 --- a/include/spdlog/details/log_msg.h +++ b/include/spdlog/details/log_msg.h @@ -13,14 +13,14 @@ namespace details { struct SPDLOG_API log_msg { log_msg() = default; log_msg(log_clock::time_point log_time, - source_loc loc, + const source_loc &loc, string_view_t logger_name, level lvl, string_view_t msg, log_attributes attributes); log_msg(log_clock::time_point log_time, const source_loc &loc, string_view_t logger_name, level lvl, string_view_t msg); log_msg(const source_loc &loc, string_view_t logger_name, level lvl, string_view_t msg); - log_msg(source_loc loc, string_view_t logger_name, level lvl, string_view_t msg, log_attributes attributes); + log_msg(const source_loc &loc, string_view_t logger_name, level lvl, string_view_t msg, log_attributes attributes); log_msg(string_view_t logger_name, level lvl, string_view_t msg, log_attributes attributes); log_msg(string_view_t logger_name, level lvl, string_view_t msg); log_msg(const log_msg &other) = default; diff --git a/src/details/log_msg.cpp b/src/details/log_msg.cpp index 73897a9c..d2231aa7 100644 --- a/src/details/log_msg.cpp +++ b/src/details/log_msg.cpp @@ -8,32 +8,13 @@ namespace spdlog { namespace details { -log_msg::log_msg(spdlog::log_clock::time_point log_time, - spdlog::source_loc loc, - string_view_t a_logger_name, - spdlog::level lvl, - spdlog::string_view_t msg, - spdlog::log_attributes attributes) - : logger_name(a_logger_name), - log_level(lvl), - time(log_time) -#ifndef SPDLOG_NO_THREAD_ID - , - thread_id(os::thread_id()) -#endif - , - source(loc), - payload(msg), - attributes(attributes) { -} - log_msg::log_msg(const log_clock::time_point log_time, - const source_loc loc, - const string_view_t a_logger_name, + const source_loc &loc, + const string_view_t logger_name, const level lvl, const string_view_t msg, const log_attributes attributes) - : logger_name(a_logger_name), + : logger_name(logger_name), log_level(lvl), time(log_time), #ifdef SPDLOG_NO_THREAD_ID @@ -64,20 +45,16 @@ log_msg::log_msg(const log_clock::time_point log_time, } log_msg::log_msg(const source_loc &loc, const string_view_t logger_name, const level lvl, const string_view_t msg) - : log_msg(os::now(), loc, logger_name, lvl, msg) {} + : log_msg(os::now(), loc, logger_name, lvl, msg, {}) {} -log_msg::log_msg(spdlog::source_loc loc, - string_view_t a_logger_name, - spdlog::level lvl, - spdlog::string_view_t msg, - spdlog::log_attributes attributes) - : log_msg(os::now(), loc, a_logger_name, lvl, msg, attributes) {} +log_msg::log_msg(const source_loc &loc, string_view_t logger_name, level lvl, string_view_t msg, log_attributes attributes) + : log_msg(os::now(), loc, logger_name, lvl, msg, attributes) {} log_msg::log_msg(const string_view_t logger_name, const level lvl, const string_view_t msg) : log_msg(os::now(), source_loc{}, logger_name, lvl, msg) {} -log_msg::log_msg(string_view_t a_logger_name, spdlog::level lvl, spdlog::string_view_t msg, spdlog::log_attributes attributes) - : log_msg(os::now(), source_loc{}, a_logger_name, lvl, msg, attributes) {} +log_msg::log_msg(const string_view_t logger_name, const level lvl, const string_view_t msg, const log_attributes attributes) + : log_msg(os::now(), source_loc{}, logger_name, lvl, msg, attributes) {} } // namespace details } // namespace spdlog diff --git a/tests/test_attributes.cpp b/tests/test_attributes.cpp index 7907abb2..b4882057 100644 --- a/tests/test_attributes.cpp +++ b/tests/test_attributes.cpp @@ -1,7 +1,6 @@ #include #include "includes.h" -#include "spdlog/mdc.h" #include "spdlog/sinks/stdout_sinks.h" #include "spdlog/spdlog.h" #include "test_sink.h" @@ -182,7 +181,7 @@ TEST_CASE("attribute test - multi threaded") { // put attributes with multiple threads simultaneously std::vector> tasks; for (unsigned int i = 0; i < n_tasks; ++i) { - auto task = std::async([&logger, i] { + auto task = std::async([&logger, i, n_values] { for (auto j = 0; j < n_values; ++j) logger.attrs().put(fmt_lib::format("log_{}_key_{}", i, j), fmt_lib::format("log_{}_value_{}", i, j)); });