From e8395c74741bd2fd5fe448381f5687d92ffc3b05 Mon Sep 17 00:00:00 2001 From: faluco Date: Mon, 22 Mar 2021 10:46:32 +0100 Subject: [PATCH] - Implement a pool to store dyn arg store objects in srslog to avoid allocations when passing arguments to the backend. - Use string views inside the log formatters to avoid allocations. - Avoid a std::string when using fmt::vsprintf, instead favour fmt::vprintf. --- .../srsran/srslog/detail/log_backend.h | 5 + .../srsran/srslog/detail/log_entry_metadata.h | 16 +- .../srslog/detail/support/backend_capacity.h | 21 ++ .../detail/support/dyn_arg_store_pool.h | 78 +++++++ .../srsran/srslog/detail/support/work_queue.h | 9 +- lib/include/srsran/srslog/formatter.h | 88 +++----- lib/include/srsran/srslog/log_channel.h | 191 +++++++++--------- lib/src/srslog/backend_worker.cpp | 6 + lib/src/srslog/backend_worker.h | 25 ++- lib/src/srslog/formatters/json_formatter.cpp | 82 ++++---- lib/src/srslog/formatters/json_formatter.h | 49 ++--- lib/src/srslog/formatters/text_formatter.cpp | 99 +++++---- lib/src/srslog/formatters/text_formatter.h | 56 +++-- lib/src/srslog/log_backend_impl.h | 17 +- lib/src/srslog/srslog.cpp | 1 + lib/test/srslog/event_trace_test.cpp | 21 +- lib/test/srslog/json_formatter_test.cpp | 89 ++++---- lib/test/srslog/log_backend_test.cpp | 62 +++--- lib/test/srslog/log_channel_test.cpp | 96 ++++----- lib/test/srslog/test_dummies.h | 55 ++--- lib/test/srslog/text_formatter_test.cpp | 153 ++++++-------- 21 files changed, 593 insertions(+), 626 deletions(-) create mode 100644 lib/include/srsran/srslog/detail/support/backend_capacity.h create mode 100644 lib/include/srsran/srslog/detail/support/dyn_arg_store_pool.h diff --git a/lib/include/srsran/srslog/detail/log_backend.h b/lib/include/srsran/srslog/detail/log_backend.h index b4332d49f..d1765b498 100644 --- a/lib/include/srsran/srslog/detail/log_backend.h +++ b/lib/include/srsran/srslog/detail/log_backend.h @@ -13,6 +13,8 @@ #ifndef SRSLOG_DETAIL_LOG_BACKEND_H #define SRSLOG_DETAIL_LOG_BACKEND_H +#include "srsran/srslog/bundled/fmt/printf.h" + namespace srslog { namespace detail { @@ -31,6 +33,9 @@ public: /// NOTE: Calling this function more than once has no side effects. virtual void start() = 0; + /// Allocates a dyn_arg_store and returns a pointer to it on success, otherwise returns nullptr. + virtual fmt::dynamic_format_arg_store* alloc_arg_store() = 0; + /// Pushes a log entry into the backend. Returns true on success, otherwise /// false. virtual bool push(log_entry&& entry) = 0; diff --git a/lib/include/srsran/srslog/detail/log_entry_metadata.h b/lib/include/srsran/srslog/detail/log_entry_metadata.h index a2d50df3a..b33db0424 100644 --- a/lib/include/srsran/srslog/detail/log_entry_metadata.h +++ b/lib/include/srsran/srslog/detail/log_entry_metadata.h @@ -34,14 +34,14 @@ struct log_context { /// Metadata fields carried for each log entry. struct log_entry_metadata { - std::chrono::high_resolution_clock::time_point tp; - log_context context; - const char* fmtstring; - fmt::dynamic_format_arg_store store; - std::string log_name; - char log_tag; - small_str_buffer small_str; - std::vector hex_dump; + std::chrono::high_resolution_clock::time_point tp; + log_context context; + const char* fmtstring; + fmt::dynamic_format_arg_store* store; + std::string log_name; + char log_tag; + small_str_buffer small_str; + std::vector hex_dump; }; } // namespace detail diff --git a/lib/include/srsran/srslog/detail/support/backend_capacity.h b/lib/include/srsran/srslog/detail/support/backend_capacity.h new file mode 100644 index 000000000..21340d3a5 --- /dev/null +++ b/lib/include/srsran/srslog/detail/support/backend_capacity.h @@ -0,0 +1,21 @@ +/** + * + * \section COPYRIGHT + * + * Copyright 2013-2021 Software Radio Systems Limited + * + * By using this file, you agree to the terms and conditions set + * forth in the LICENSE file which can be found at the top level of + * the distribution. + * + */ + +#ifndef SRSLOG_DETAIL_SUPPORT_BACKEND_CAPACITY_H +#define SRSLOG_DETAIL_SUPPORT_BACKEND_CAPACITY_H + +/// Take this default value if users did not specify any custom size. +#ifndef SRSLOG_QUEUE_CAPACITY +#define SRSLOG_QUEUE_CAPACITY 8192 +#endif + +#endif // SRSLOG_DETAIL_SUPPORT_BACKEND_CAPACITY_H diff --git a/lib/include/srsran/srslog/detail/support/dyn_arg_store_pool.h b/lib/include/srsran/srslog/detail/support/dyn_arg_store_pool.h new file mode 100644 index 000000000..595181988 --- /dev/null +++ b/lib/include/srsran/srslog/detail/support/dyn_arg_store_pool.h @@ -0,0 +1,78 @@ +/** + * + * \section COPYRIGHT + * + * Copyright 2013-2021 Software Radio Systems Limited + * + * By using this file, you agree to the terms and conditions set + * forth in the LICENSE file which can be found at the top level of + * the distribution. + * + */ + +#ifndef SRSLOG_DETAIL_SUPPORT_DYN_ARG_STORE_POOL_H +#define SRSLOG_DETAIL_SUPPORT_DYN_ARG_STORE_POOL_H + +#include "srsran/srslog/bundled/fmt/printf.h" +#include "srsran/srslog/detail/support/backend_capacity.h" + +namespace srslog { + +namespace detail { + +/// Keeps a pool of dynamic_format_arg_store objects. The main reason for this class is that the arg store objects are +/// implemented with std::vectors, so we want to avoid allocating memory each time we create a new object. Instead, +/// reserve memory for each vector during initialization and recycle the objects. +class dyn_arg_store_pool +{ +public: + dyn_arg_store_pool() + { + pool.resize(SRSLOG_QUEUE_CAPACITY); + for (auto& elem : pool) { + // Reserve for 10 normal and 2 named arguments. + elem.reserve(10, 2); + } + free_list.reserve(SRSLOG_QUEUE_CAPACITY); + for (auto& elem : pool) { + free_list.push_back(&elem); + } + } + + /// Returns a pointer to a free dyn arg store object, otherwise returns nullptr. + fmt::dynamic_format_arg_store* alloc() + { + scoped_lock lock(m); + if (free_list.empty()) { + return nullptr; + } + + auto* p = free_list.back(); + free_list.pop_back(); + + return p; + } + + /// Deallocate the given dyn arg store object returning it to the pool. + void dealloc(fmt::dynamic_format_arg_store* p) + { + if (!p) { + return; + } + + scoped_lock lock(m); + p->clear(); + free_list.push_back(p); + } + +private: + std::vector > pool; + std::vector*> free_list; + mutable mutex m; +}; + +} // namespace detail + +} // namespace srslog + +#endif // SRSLOG_DETAIL_SUPPORT_DYN_ARG_STORE_POOL_H diff --git a/lib/include/srsran/srslog/detail/support/work_queue.h b/lib/include/srsran/srslog/detail/support/work_queue.h index b20a360bd..d1589f877 100644 --- a/lib/include/srsran/srslog/detail/support/work_queue.h +++ b/lib/include/srsran/srslog/detail/support/work_queue.h @@ -13,13 +13,10 @@ #ifndef SRSLOG_DETAIL_SUPPORT_WORK_QUEUE_H #define SRSLOG_DETAIL_SUPPORT_WORK_QUEUE_H +#include "srsran/srslog/detail/support/backend_capacity.h" #include "srsran/srslog/detail/support/thread_utils.h" #include -#ifndef SRSLOG_QUEUE_CAPACITY -#define SRSLOG_QUEUE_CAPACITY 8192 -#endif - namespace srslog { namespace detail { @@ -30,9 +27,9 @@ namespace detail { template class work_queue { - std::queue queue; + std::queue queue; mutable condition_variable cond_var; - static constexpr size_t threshold = capacity * 0.98; + static constexpr size_t threshold = capacity * 0.98; public: work_queue() = default; diff --git a/lib/include/srsran/srslog/formatter.h b/lib/include/srsran/srslog/formatter.h index be69c1730..3dcd85897 100644 --- a/lib/include/srsran/srslog/formatter.h +++ b/lib/include/srsran/srslog/formatter.h @@ -34,7 +34,7 @@ struct metric_value_formatter { /// Default metric value formatter. Users that want to override this behaviour /// should add an specialization of the metric they want to customize. template -struct metric_value_formatter> { +struct metric_value_formatter > { template void format(const T& v, fmt::memory_buffer& buffer) { @@ -59,54 +59,38 @@ public: virtual std::unique_ptr clone() const = 0; /// Formats the log entry into the input buffer. - virtual void format(detail::log_entry_metadata&& metadata, - fmt::memory_buffer& buffer) = 0; + virtual void format(detail::log_entry_metadata&& metadata, fmt::memory_buffer& buffer) = 0; /// Formats the context and log entry into the input buffer. template - void format_ctx(const srslog::context& ctx, - detail::log_entry_metadata&& metadata, - fmt::memory_buffer& buffer) + void format_ctx(const srslog::context& ctx, detail::log_entry_metadata&& metadata, fmt::memory_buffer& buffer) { format_context_begin(metadata, ctx.name(), sizeof...(Ts), buffer); - iterate_tuple(ctx.contents(), - 1, - buffer, - detail::make_index_sequence{}); + iterate_tuple(ctx.contents(), 1, buffer, detail::make_index_sequence{}); format_context_end(metadata, ctx.name(), buffer); } private: /// Processes all elements in a tuple. template - void iterate_tuple(const std::tuple& t, - unsigned level, - fmt::memory_buffer& buffer, - detail::index_sequence) + void + iterate_tuple(const std::tuple& t, unsigned level, fmt::memory_buffer& buffer, detail::index_sequence) { - (void)std::initializer_list{ - (process_element(std::get(t), level, buffer), 0)...}; + (void)std::initializer_list{(process_element(std::get(t), level, buffer), 0)...}; } /// Processes the input metric set. template - void process_element(const metric_set& ms, - unsigned level, - fmt::memory_buffer& buffer) + void process_element(const metric_set& ms, unsigned level, fmt::memory_buffer& buffer) { format_metric_set_begin(ms.name(), sizeof...(Ts), level, buffer); - iterate_tuple(ms.contents(), - level + 1, - buffer, - detail::make_index_sequence{}); + iterate_tuple(ms.contents(), level + 1, buffer, detail::make_index_sequence{}); format_metric_set_end(ms.name(), level, buffer); } /// Processes the input metric list. template - void process_element(const metric_list& list, - unsigned level, - fmt::memory_buffer& buffer) + void process_element(const metric_list& list, unsigned level, fmt::memory_buffer& buffer) { format_list_begin(list.name(), list.size(), level, buffer); for (const auto& elem : list) { @@ -117,16 +101,13 @@ private: /// Processes the input metric. template - void process_element(const metric& t, - unsigned level, - fmt::memory_buffer& buffer) + void process_element(const metric& t, unsigned level, fmt::memory_buffer& buffer) { fmt::memory_buffer value; - metric_value_formatter::type>{}.format( - t.value, value); + metric_value_formatter::type>{}.format(t.value, value); + value.push_back('\0'); - format_metric( - t.name(), fmt::to_string(value), t.units(), t.kind(), level, buffer); + format_metric(t.name(), value.data(), t.units(), t.kind(), level, buffer); } private: @@ -137,46 +118,37 @@ private: /// This callback gets called at the beginning of the context formatting /// algorithm. virtual void format_context_begin(const detail::log_entry_metadata& md, - const std::string& ctx_name, - unsigned size, - fmt::memory_buffer& buffer) = 0; + fmt::string_view ctx_name, + unsigned size, + fmt::memory_buffer& buffer) = 0; /// This callback gets called at the end of the context formatting algorithm. - virtual void format_context_end(const detail::log_entry_metadata& md, - const std::string& ctx_name, - fmt::memory_buffer& buffer) = 0; + virtual void + format_context_end(const detail::log_entry_metadata& md, fmt::string_view ctx_name, fmt::memory_buffer& buffer) = 0; /// This callback gets called at the beginning of a metric set formatting /// procedure. - virtual void format_metric_set_begin(const std::string& set_name, - unsigned size, - unsigned level, - fmt::memory_buffer& buffer) = 0; + virtual void + format_metric_set_begin(fmt::string_view set_name, unsigned size, unsigned level, fmt::memory_buffer& buffer) = 0; /// This callback gets called at the beginning of a metric set formatting end. - virtual void format_metric_set_end(const std::string& set_name, - unsigned level, - fmt::memory_buffer& buffer) = 0; + virtual void format_metric_set_end(fmt::string_view set_name, unsigned level, fmt::memory_buffer& buffer) = 0; /// This callback gets called at the beginning of a metric list formatting /// procedure. - virtual void format_list_begin(const std::string& list_name, - unsigned size, - unsigned level, - fmt::memory_buffer& buffer) = 0; + virtual void + format_list_begin(fmt::string_view list_name, unsigned size, unsigned level, fmt::memory_buffer& buffer) = 0; /// This callback gets called at the end of a metric list formatting /// procedure. - virtual void format_list_end(const std::string& list_name, - unsigned level, - fmt::memory_buffer& buffer) = 0; + virtual void format_list_end(fmt::string_view list_name, unsigned level, fmt::memory_buffer& buffer) = 0; /// This callback gets called for each metric. - virtual void format_metric(const std::string& metric_name, - const std::string& metric_value, - const std::string& metric_units, - metric_kind kind, - unsigned level, + virtual void format_metric(fmt::string_view metric_name, + fmt::string_view metric_value, + fmt::string_view metric_units, + metric_kind kind, + unsigned level, fmt::memory_buffer& buffer) = 0; }; diff --git a/lib/include/srsran/srslog/log_channel.h b/lib/include/srsran/srslog/log_channel.h index 8fa0387d9..273debf67 100644 --- a/lib/include/srsran/srslog/log_channel.h +++ b/lib/include/srsran/srslog/log_channel.h @@ -47,14 +47,9 @@ struct log_channel_config { class log_channel { public: - log_channel(std::string id, sink& s, detail::log_backend& backend) : - log_channel(std::move(id), s, backend, {}) - {} + log_channel(std::string id, sink& s, detail::log_backend& backend) : log_channel(std::move(id), s, backend, {}) {} - log_channel(std::string id, - sink& s, - detail::log_backend& backend, - log_channel_config config) : + log_channel(std::string id, sink& s, detail::log_backend& backend, log_channel_config config) : log_id(std::move(id)), log_sink(s), backend(backend), @@ -96,91 +91,87 @@ public: } // Populate the store with all incoming arguments. - fmt::dynamic_format_arg_store store; - (void)std::initializer_list{ - (store.push_back(std::forward(args)), 0)...}; + auto* store = backend.alloc_arg_store(); + if (!store) { + return; + } + (void)std::initializer_list{(store->push_back(std::forward(args)), 0)...}; // Send the log entry to the backend. - log_formatter& formatter = log_sink.get_formatter(); - detail::log_entry entry = { - &log_sink, - [&formatter](detail::log_entry_metadata&& metadata, - fmt::memory_buffer& buffer) { - formatter.format(std::move(metadata), buffer); - }, - {std::chrono::high_resolution_clock::now(), - {ctx_value, should_print_context}, - fmtstr, - std::move(store), - log_name, - log_tag, - small_str_buffer()}}; + log_formatter& formatter = log_sink.get_formatter(); + detail::log_entry entry = {&log_sink, + [&formatter](detail::log_entry_metadata&& metadata, fmt::memory_buffer& buffer) { + formatter.format(std::move(metadata), buffer); + }, + {std::chrono::high_resolution_clock::now(), + {ctx_value, should_print_context}, + fmtstr, + store, + log_name, + log_tag, + small_str_buffer()}}; backend.push(std::move(entry)); } /// Builds the provided log entry and passes it to the backend. When the /// channel is disabled the log entry will be discarded. - void operator()(small_str_buffer &&str) + void operator()(small_str_buffer&& str) { if (!enabled()) { return; } // Send the log entry to the backend. - log_formatter& formatter = log_sink.get_formatter(); - detail::log_entry entry = { - &log_sink, - [&formatter](detail::log_entry_metadata&& metadata, - fmt::memory_buffer& buffer) { - formatter.format(std::move(metadata), buffer); - }, - {std::chrono::high_resolution_clock::now(), - {ctx_value, should_print_context}, - nullptr, - {}, - log_name, - log_tag, - std::move(str)}}; + log_formatter& formatter = log_sink.get_formatter(); + detail::log_entry entry = {&log_sink, + [&formatter](detail::log_entry_metadata&& metadata, fmt::memory_buffer& buffer) { + formatter.format(std::move(metadata), buffer); + }, + {std::chrono::high_resolution_clock::now(), + {ctx_value, should_print_context}, + nullptr, + nullptr, + log_name, + log_tag, + std::move(str)}}; backend.push(std::move(entry)); } /// Builds the provided log entry and passes it to the backend. When the /// channel is disabled the log entry will be discarded. template - void operator()(const uint8_t* buffer, - size_t len, - const char* fmtstr, - Args&&... args) + void operator()(const uint8_t* buffer, size_t len, const char* fmtstr, Args&&... args) { if (!enabled()) { return; } // Populate the store with all incoming arguments. - fmt::dynamic_format_arg_store store; - (void)std::initializer_list{ - (store.push_back(std::forward(args)), 0)...}; + auto* store = backend.alloc_arg_store(); + if (!store) { + return; + } + (void)std::initializer_list{(store->push_back(std::forward(args)), 0)...}; // Calculate the length to capture in the buffer. - if (hex_max_size >= 0) + if (hex_max_size >= 0) { len = std::min(len, hex_max_size); + } // Send the log entry to the backend. - log_formatter& formatter = log_sink.get_formatter(); - detail::log_entry entry = { - &log_sink, - [&formatter](detail::log_entry_metadata&& metadata, - fmt::memory_buffer& buffer) { - formatter.format(std::move(metadata), buffer); - }, - {std::chrono::high_resolution_clock::now(), - {ctx_value, should_print_context}, - fmtstr, - std::move(store), - log_name, - log_tag, - small_str_buffer(), - std::vector(buffer, buffer + len)}}; + log_formatter& formatter = log_sink.get_formatter(); + detail::log_entry entry = {&log_sink, + [&formatter](detail::log_entry_metadata&& metadata, fmt::memory_buffer& buffer) { + formatter.format(std::move(metadata), buffer); + }, + {std::chrono::high_resolution_clock::now(), + {ctx_value, should_print_context}, + fmtstr, + store, + log_name, + log_tag, + small_str_buffer(), + std::vector(buffer, buffer + len)}}; backend.push(std::move(entry)); } @@ -194,20 +185,18 @@ public: } // Send the log entry to the backend. - log_formatter& formatter = log_sink.get_formatter(); - detail::log_entry entry = { - &log_sink, - [&formatter, ctx](detail::log_entry_metadata&& metadata, - fmt::memory_buffer& buffer) { - formatter.format_ctx(ctx, std::move(metadata), buffer); - }, - {std::chrono::high_resolution_clock::now(), - {ctx_value, should_print_context}, - nullptr, - {}, - log_name, - log_tag, - small_str_buffer()}}; + log_formatter& formatter = log_sink.get_formatter(); + detail::log_entry entry = {&log_sink, + [&formatter, ctx](detail::log_entry_metadata&& metadata, fmt::memory_buffer& buffer) { + formatter.format_ctx(ctx, std::move(metadata), buffer); + }, + {std::chrono::high_resolution_clock::now(), + {ctx_value, should_print_context}, + nullptr, + nullptr, + log_name, + log_tag, + small_str_buffer()}}; backend.push(std::move(entry)); } @@ -221,38 +210,38 @@ public: } // Populate the store with all incoming arguments. - fmt::dynamic_format_arg_store store; - (void)std::initializer_list{ - (store.push_back(std::forward(args)), 0)...}; + auto* store = backend.alloc_arg_store(); + if (!store) { + return; + } + (void)std::initializer_list{(store->push_back(std::forward(args)), 0)...}; // Send the log entry to the backend. - log_formatter& formatter = log_sink.get_formatter(); - detail::log_entry entry = { - &log_sink, - [&formatter, ctx](detail::log_entry_metadata&& metadata, - fmt::memory_buffer& buffer) { - formatter.format_ctx(ctx, std::move(metadata), buffer); - }, - {std::chrono::high_resolution_clock::now(), - {ctx_value, should_print_context}, - fmtstr, - std::move(store), - log_name, - log_tag, - small_str_buffer()}}; + log_formatter& formatter = log_sink.get_formatter(); + detail::log_entry entry = {&log_sink, + [&formatter, ctx](detail::log_entry_metadata&& metadata, fmt::memory_buffer& buffer) { + formatter.format_ctx(ctx, std::move(metadata), buffer); + }, + {std::chrono::high_resolution_clock::now(), + {ctx_value, should_print_context}, + fmtstr, + store, + log_name, + log_tag, + small_str_buffer()}}; backend.push(std::move(entry)); } private: - const std::string log_id; - sink& log_sink; - detail::log_backend& backend; - const std::string log_name; - const char log_tag; - const bool should_print_context; + const std::string log_id; + sink& log_sink; + detail::log_backend& backend; + const std::string log_name; + const char log_tag; + const bool should_print_context; detail::shared_variable ctx_value; - detail::shared_variable hex_max_size; - detail::shared_variable is_enabled; + detail::shared_variable hex_max_size; + detail::shared_variable is_enabled; }; } // namespace srslog diff --git a/lib/src/srslog/backend_worker.cpp b/lib/src/srslog/backend_worker.cpp index 50692fdd0..a564b69fe 100644 --- a/lib/src/srslog/backend_worker.cpp +++ b/lib/src/srslog/backend_worker.cpp @@ -95,8 +95,14 @@ void backend_worker::process_log_entry(detail::log_entry&& entry) if (entry.metadata.small_str.size()) { entry.metadata.fmtstring = entry.metadata.small_str.data(); } + + // Save the pointer before moving the entry. + auto* arg_store = entry.metadata.store; + entry.format_func(std::move(entry.metadata), fmt_buffer); + arg_pool.dealloc(arg_store); + if (auto err_str = entry.s->write({fmt_buffer.data(), fmt_buffer.size()})) { err_handler(err_str.get_error()); } diff --git a/lib/src/srslog/backend_worker.h b/lib/src/srslog/backend_worker.h index 92612b77b..641c024c2 100644 --- a/lib/src/srslog/backend_worker.h +++ b/lib/src/srslog/backend_worker.h @@ -14,6 +14,7 @@ #define SRSLOG_BACKEND_WORKER_H #include "srsran/srslog/detail/log_entry.h" +#include "srsran/srslog/detail/support/dyn_arg_store_pool.h" #include "srsran/srslog/detail/support/work_queue.h" #include "srsran/srslog/shared_types.h" #include @@ -31,8 +32,8 @@ class backend_worker static constexpr unsigned sleep_period_ms = 500; public: - explicit backend_worker(detail::work_queue& queue) : - queue(queue), running_flag(false) + explicit backend_worker(detail::work_queue& queue, detail::dyn_arg_store_pool& arg_pool) : + queue(queue), arg_pool(arg_pool), running_flag(false) {} backend_worker(const backend_worker&) = delete; @@ -94,23 +95,21 @@ private: void report_queue_on_full_once() { if (queue.is_almost_full()) { - err_handler( - fmt::format("The backend queue size is about to reach its maximum " - "capacity of {} elements, new log entries will get " - "discarded.\nConsider increasing the queue capacity.", - queue.get_capacity())); + err_handler(fmt::format("The backend queue size is about to reach its maximum " + "capacity of {} elements, new log entries will get " + "discarded.\nConsider increasing the queue capacity.", + queue.get_capacity())); err_handler = [](const std::string&) {}; } } private: detail::work_queue& queue; - detail::shared_variable running_flag; - error_handler err_handler = [](const std::string& error) { - fmt::print(stderr, "srsLog error - {}\n", error); - }; - std::once_flag start_once_flag; - std::thread worker_thread; + detail::dyn_arg_store_pool& arg_pool; + detail::shared_variable running_flag; + error_handler err_handler = [](const std::string& error) { fmt::print(stderr, "srsLog error - {}\n", error); }; + std::once_flag start_once_flag; + std::thread worker_thread; fmt::memory_buffer fmt_buffer; }; diff --git a/lib/src/srslog/formatters/json_formatter.cpp b/lib/src/srslog/formatters/json_formatter.cpp index 499703a1d..c7953501e 100644 --- a/lib/src/srslog/formatters/json_formatter.cpp +++ b/lib/src/srslog/formatters/json_formatter.cpp @@ -20,28 +20,33 @@ std::unique_ptr json_formatter::clone() const return std::unique_ptr(new json_formatter); } -void json_formatter::format(detail::log_entry_metadata&& metadata, - fmt::memory_buffer& buffer) +void json_formatter::format(detail::log_entry_metadata&& metadata, fmt::memory_buffer& buffer) { fmt::format_to(buffer, "{{\n" - " \"log_entry\": \"{}\"", - fmt::vsprintf(metadata.fmtstring, std::move(metadata.store))); + " \"log_entry\": \""); + if (metadata.fmtstring) { + if (metadata.store) { + fmt::basic_format_args > args(*metadata.store); + fmt::vprintf(buffer, fmt::to_string_view(metadata.fmtstring), args); + fmt::format_to(buffer, fmt::to_string_view("\"")); + } else { + fmt::format_to(buffer, "{}\"", metadata.fmtstring); + } + } if (!metadata.hex_dump.empty()) { fmt::format_to( - buffer, - ",\n \"hex_dump\": \"{:02x}\"", - fmt::join(metadata.hex_dump.cbegin(), metadata.hex_dump.cend(), " ")); + buffer, ",\n \"hex_dump\": \"{:02x}\"", fmt::join(metadata.hex_dump.cbegin(), metadata.hex_dump.cend(), " ")); } fmt::format_to(buffer, "\n}}\n"); } void json_formatter::format_context_begin(const detail::log_entry_metadata& md, - const std::string& ctx_name, - unsigned size, - fmt::memory_buffer& buffer) + fmt::string_view ctx_name, + unsigned size, + fmt::memory_buffer& buffer) { assert(scope_stack.empty() && "Stack should be empty"); assert(nest_level == 0 && "Nesting level should be 0"); @@ -50,15 +55,20 @@ void json_formatter::format_context_begin(const detail::log_entry_metadata& md, push_scope(size); if (md.fmtstring) { - fmt::format_to(buffer, - " \"log_entry\": \"{}\",\n", - fmt::vsprintf(md.fmtstring, std::move(md.store))); + if (md.store) { + fmt::format_to(buffer, " \"log_entry\": \""); + fmt::basic_format_args > args(*md.store); + fmt::vprintf(buffer, fmt::to_string_view(md.fmtstring), args); + fmt::format_to(buffer, "\",\n"); + } else { + fmt::format_to(buffer, " \"log_entry\": \"{}\",\n", md.fmtstring); + } } } void json_formatter::format_context_end(const detail::log_entry_metadata& md, - const std::string& ctx_name, - fmt::memory_buffer& buffer) + fmt::string_view ctx_name, + fmt::memory_buffer& buffer) { pop_scope(); fmt::format_to(buffer, "}}\n"); @@ -67,9 +77,9 @@ void json_formatter::format_context_end(const detail::log_entry_metadata& md, assert(nest_level == 0 && "Nesting level should be 0"); } -void json_formatter::format_metric_set_begin(const std::string& set_name, - unsigned size, - unsigned level, +void json_formatter::format_metric_set_begin(fmt::string_view set_name, + unsigned size, + unsigned level, fmt::memory_buffer& buffer) { // Arrays in JSON require an additional nesting level before inserting the @@ -90,29 +100,22 @@ void json_formatter::format_metric_set_begin(const std::string& set_name, push_scope(size); } -void json_formatter::format_metric_set_end(const std::string& set_name, - unsigned level, - fmt::memory_buffer& buffer) +void json_formatter::format_metric_set_end(fmt::string_view set_name, unsigned level, fmt::memory_buffer& buffer) { pop_scope(); - fmt::format_to(buffer, - "{: <{}}}}{}\n", - ' ', - indents(level), - needs_comma() && !in_list_scope() ? "," : ""); + fmt::format_to(buffer, "{: <{}}}}{}\n", ' ', indents(level), needs_comma() && !in_list_scope() ? "," : ""); if (in_list_scope()) { decrement_nest_level(); - fmt::format_to( - buffer, "{: <{}}}}{}\n", ' ', indents(level), needs_comma() ? "," : ""); + fmt::format_to(buffer, "{: <{}}}}{}\n", ' ', indents(level), needs_comma() ? "," : ""); } } -void json_formatter::format_metric(const std::string& metric_name, - const std::string& metric_value, - const std::string& metric_units, - metric_kind kind, - unsigned level, +void json_formatter::format_metric(fmt::string_view metric_name, + fmt::string_view metric_value, + fmt::string_view metric_units, + metric_kind kind, + unsigned level, fmt::memory_buffer& buffer) { consume_element(); @@ -128,9 +131,9 @@ void json_formatter::format_metric(const std::string& metric_name, needs_comma() ? "," : ""); } -void json_formatter::format_list_begin(const std::string& list_name, - unsigned size, - unsigned level, +void json_formatter::format_list_begin(fmt::string_view list_name, + unsigned size, + unsigned level, fmt::memory_buffer& buffer) { consume_element(); @@ -139,11 +142,8 @@ void json_formatter::format_list_begin(const std::string& list_name, push_list_scope(size); } -void json_formatter::format_list_end(const std::string& list_name, - unsigned level, - fmt::memory_buffer& buffer) +void json_formatter::format_list_end(fmt::string_view list_name, unsigned level, fmt::memory_buffer& buffer) { pop_scope(); - fmt::format_to( - buffer, "{: <{}}]{}\n", ' ', indents(level), needs_comma() ? "," : ""); + fmt::format_to(buffer, "{: <{}}]{}\n", ' ', indents(level), needs_comma() ? "," : ""); } diff --git a/lib/src/srslog/formatters/json_formatter.h b/lib/src/srslog/formatters/json_formatter.h index 4c7391835..751db1c84 100644 --- a/lib/src/srslog/formatters/json_formatter.h +++ b/lib/src/srslog/formatters/json_formatter.h @@ -29,42 +29,35 @@ public: std::unique_ptr clone() const override; - void format(detail::log_entry_metadata&& metadata, - fmt::memory_buffer& buffer) override; + void format(detail::log_entry_metadata&& metadata, fmt::memory_buffer& buffer) override; private: void format_context_begin(const detail::log_entry_metadata& md, - const std::string& ctx_name, - unsigned size, - fmt::memory_buffer& buffer) override; + fmt::string_view ctx_name, + unsigned size, + fmt::memory_buffer& buffer) override; void format_context_end(const detail::log_entry_metadata& md, - const std::string& ctx_name, - fmt::memory_buffer& buffer) override; + fmt::string_view ctx_name, + fmt::memory_buffer& buffer) override; - void format_metric_set_begin(const std::string& set_name, - unsigned size, - unsigned level, + void format_metric_set_begin(fmt::string_view set_name, + unsigned size, + unsigned level, fmt::memory_buffer& buffer) override; - void format_metric_set_end(const std::string& set_name, - unsigned level, - fmt::memory_buffer& buffer) override; + void format_metric_set_end(fmt::string_view set_name, unsigned level, fmt::memory_buffer& buffer) override; - void format_list_begin(const std::string& list_name, - unsigned size, - unsigned level, - fmt::memory_buffer& buffer) override; + void + format_list_begin(fmt::string_view list_name, unsigned size, unsigned level, fmt::memory_buffer& buffer) override; - void format_list_end(const std::string& list_name, - unsigned level, - fmt::memory_buffer& buffer) override; + void format_list_end(fmt::string_view list_name, unsigned level, fmt::memory_buffer& buffer) override; - void format_metric(const std::string& metric_name, - const std::string& metric_value, - const std::string& metric_units, - metric_kind kind, - unsigned level, + void format_metric(fmt::string_view metric_name, + fmt::string_view metric_value, + fmt::string_view metric_units, + metric_kind kind, + unsigned level, fmt::memory_buffer& buffer) override; /// Pushes a new entry in the scope stack. @@ -118,9 +111,7 @@ private: private: /// Keeps track of some information about a JSON scope. struct scope { - scope(unsigned size, bool inside_list) : - size(size), inside_list(inside_list) - {} + scope(unsigned size, bool inside_list) : size(size), inside_list(inside_list) {} /// Number of elements this scope holds. unsigned size; /// If true, indicates this scope belongs to a list. @@ -128,7 +119,7 @@ private: }; private: - unsigned nest_level = 0; + unsigned nest_level = 0; std::vector scope_stack; }; diff --git a/lib/src/srslog/formatters/text_formatter.cpp b/lib/src/srslog/formatters/text_formatter.cpp index 7e620f2a7..c47f5e884 100644 --- a/lib/src/srslog/formatters/text_formatter.cpp +++ b/lib/src/srslog/formatters/text_formatter.cpp @@ -23,39 +23,26 @@ std::unique_ptr text_formatter::clone() const /// Formats into a hex dump a range of elements, storing the result in the input /// buffer. -static void format_hex_dump(const std::vector& v, - fmt::memory_buffer& buffer) +static void format_hex_dump(const std::vector& v, fmt::memory_buffer& buffer) { - if (v.empty()) { - return; - } - const size_t elements_per_line = 16; for (auto i = v.cbegin(), e = v.cend(); i != e;) { - auto num_elements = - std::min(elements_per_line, std::distance(i, e)); + auto num_elements = std::min(elements_per_line, std::distance(i, e)); - fmt::format_to(buffer, - " {:04x}: {:02x}\n", - std::distance(v.cbegin(), i), - fmt::join(i, i + num_elements, " ")); + fmt::format_to(buffer, " {:04x}: {:02x}\n", std::distance(v.cbegin(), i), fmt::join(i, i + num_elements, " ")); std::advance(i, num_elements); } } /// Format the log metadata into the input buffer. -static void format_metadata(const detail::log_entry_metadata& metadata, - fmt::memory_buffer& buffer) +static void format_metadata(const detail::log_entry_metadata& metadata, fmt::memory_buffer& buffer) { // Time stamp data preparation. - std::tm current_time = - fmt::gmtime(std::chrono::high_resolution_clock::to_time_t(metadata.tp)); - auto us_fraction = std::chrono::duration_cast( - metadata.tp.time_since_epoch()) - .count() % - 1000000u; + std::tm current_time = fmt::gmtime(std::chrono::high_resolution_clock::to_time_t(metadata.tp)); + auto us_fraction = + std::chrono::duration_cast(metadata.tp.time_since_epoch()).count() % 1000000u; fmt::format_to(buffer, "{:%H:%M:%S}.{:06} ", current_time, us_fraction); // Format optional fields if present. @@ -70,25 +57,30 @@ static void format_metadata(const detail::log_entry_metadata& metadata, } } -void text_formatter::format(detail::log_entry_metadata&& metadata, - fmt::memory_buffer& buffer) +void text_formatter::format(detail::log_entry_metadata&& metadata, fmt::memory_buffer& buffer) { // Prefix first. format_metadata(metadata, buffer); // Message formatting. - fmt::format_to(buffer, - "{}\n", - fmt::vsprintf(metadata.fmtstring, std::move(metadata.store))); + if (metadata.fmtstring) { + if (metadata.store) { + fmt::basic_format_args > args(*metadata.store); + fmt::vprintf(buffer, fmt::to_string_view(metadata.fmtstring), args); + fmt::format_to(buffer, "\n"); + } else { + fmt::format_to(buffer, "{}\n", metadata.fmtstring); + } + } // Optional hex dump formatting. format_hex_dump(metadata.hex_dump, buffer); } void text_formatter::format_context_begin(const detail::log_entry_metadata& md, - const std::string& ctx_name, - unsigned size, - fmt::memory_buffer& buffer) + fmt::string_view ctx_name, + unsigned size, + fmt::memory_buffer& buffer) { // Entries without a log message are printed using a richer format. do_one_line_ctx_format = md.fmtstring; @@ -104,35 +96,39 @@ void text_formatter::format_context_begin(const detail::log_entry_metadata& md, } void text_formatter::format_context_end(const detail::log_entry_metadata& md, - const std::string& ctx_name, - fmt::memory_buffer& buffer) + fmt::string_view ctx_name, + fmt::memory_buffer& buffer) { if (!do_one_line_ctx_format) { return; } - fmt::format_to(buffer, "]: {}\n", fmt::vsprintf(md.fmtstring, md.store)); + if (md.store) { + fmt::format_to(buffer, "]: "); + fmt::basic_format_args > args(*md.store); + fmt::vprintf(buffer, fmt::to_string_view(md.fmtstring), args); + fmt::format_to(buffer, "\n"); + } else { + fmt::format_to(buffer, "]: {}\n", md.fmtstring); + } assert(scope_stack.empty() && "Stack should be empty"); } -void text_formatter::format_metric_set_begin(const std::string& set_name, - unsigned size, - unsigned level, +void text_formatter::format_metric_set_begin(fmt::string_view set_name, + unsigned size, + unsigned level, fmt::memory_buffer& buffer) { if (do_one_line_ctx_format) { - scope_stack.emplace_back(size, set_name); + scope_stack.emplace_back(size, set_name.data()); fmt::format_to(buffer, "["); return; } - fmt::format_to( - buffer, "{: <{}}> Set: {}\n", ' ', get_indents(level), set_name); + fmt::format_to(buffer, "{: <{}}> Set: {}\n", ' ', get_indents(level), set_name); } -void text_formatter::format_metric_set_end(const std::string& set_name, - unsigned level, - fmt::memory_buffer& buffer) +void text_formatter::format_metric_set_end(fmt::string_view set_name, unsigned level, fmt::memory_buffer& buffer) { if (!do_one_line_ctx_format) { return; @@ -142,11 +138,11 @@ void text_formatter::format_metric_set_end(const std::string& set_name, fmt::format_to(buffer, "]"); } -void text_formatter::format_metric(const std::string& metric_name, - const std::string& metric_value, - const std::string& metric_units, - metric_kind kind, - unsigned level, +void text_formatter::format_metric(fmt::string_view metric_name, + fmt::string_view metric_value, + fmt::string_view metric_units, + metric_kind kind, + unsigned level, fmt::memory_buffer& buffer) { if (do_one_line_ctx_format) { @@ -156,7 +152,7 @@ void text_formatter::format_metric(const std::string& metric_name, get_current_set_name(), metric_name, metric_value, - metric_units.empty() ? "" : " ", + metric_units.size() == 0 ? "" : " ", metric_units, needs_comma() ? ", " : ""); return; @@ -168,18 +164,17 @@ void text_formatter::format_metric(const std::string& metric_name, get_indents(level), metric_name, metric_value, - metric_units.empty() ? "" : " ", + metric_units.size() == 0 ? "" : " ", metric_units); } -void text_formatter::format_list_begin(const std::string& list_name, - unsigned size, - unsigned level, +void text_formatter::format_list_begin(fmt::string_view list_name, + unsigned size, + unsigned level, fmt::memory_buffer& buffer) { if (do_one_line_ctx_format) { return; } - fmt::format_to( - buffer, "{: <{}}> List: {}\n", ' ', get_indents(level), list_name); + fmt::format_to(buffer, "{: <{}}> List: {}\n", ' ', get_indents(level), list_name); } diff --git a/lib/src/srslog/formatters/text_formatter.h b/lib/src/srslog/formatters/text_formatter.h index 4dc1d8407..b7b5d6016 100644 --- a/lib/src/srslog/formatters/text_formatter.h +++ b/lib/src/srslog/formatters/text_formatter.h @@ -25,43 +25,35 @@ public: std::unique_ptr clone() const override; - void format(detail::log_entry_metadata&& metadata, - fmt::memory_buffer& buffer) override; + void format(detail::log_entry_metadata&& metadata, fmt::memory_buffer& buffer) override; private: void format_context_begin(const detail::log_entry_metadata& md, - const std::string& ctx_name, - unsigned size, - fmt::memory_buffer& buffer) override; + fmt::string_view ctx_name, + unsigned size, + fmt::memory_buffer& buffer) override; void format_context_end(const detail::log_entry_metadata& md, - const std::string& ctx_name, - fmt::memory_buffer& buffer) override; + fmt::string_view ctx_name, + fmt::memory_buffer& buffer) override; - void format_metric_set_begin(const std::string& set_name, - unsigned size, - unsigned level, + void format_metric_set_begin(fmt::string_view set_name, + unsigned size, + unsigned level, fmt::memory_buffer& buffer) override; - void format_metric_set_end(const std::string& set_name, - unsigned level, - fmt::memory_buffer& buffer) override; - - void format_list_begin(const std::string& list_name, - unsigned size, - unsigned level, - fmt::memory_buffer& buffer) override; - - void format_list_end(const std::string& list_name, - unsigned level, - fmt::memory_buffer& buffer) override - {} - - void format_metric(const std::string& metric_name, - const std::string& metric_value, - const std::string& metric_units, - metric_kind kind, - unsigned level, + void format_metric_set_end(fmt::string_view set_name, unsigned level, fmt::memory_buffer& buffer) override; + + void + format_list_begin(fmt::string_view list_name, unsigned size, unsigned level, fmt::memory_buffer& buffer) override; + + void format_list_end(fmt::string_view list_name, unsigned level, fmt::memory_buffer& buffer) override {} + + void format_metric(fmt::string_view metric_name, + fmt::string_view metric_value, + fmt::string_view metric_units, + metric_kind kind, + unsigned level, fmt::memory_buffer& buffer) override; /// Returns the set name of current scope. @@ -92,9 +84,7 @@ private: private: /// Keeps track of some state required for formatting. struct scope { - scope(unsigned size, std::string set_name) : - size(size), set_name(std::move(set_name)) - {} + scope(unsigned size, std::string set_name) : size(size), set_name(std::move(set_name)) {} /// Number of elements this scope holds. unsigned size; /// Set name in this scope. @@ -103,7 +93,7 @@ private: private: /// Flags that the formatting should take place into a single line. - bool do_one_line_ctx_format = false; + bool do_one_line_ctx_format = false; std::vector scope_stack; }; diff --git a/lib/src/srslog/log_backend_impl.h b/lib/src/srslog/log_backend_impl.h index 02b9548ad..23ca4b215 100644 --- a/lib/src/srslog/log_backend_impl.h +++ b/lib/src/srslog/log_backend_impl.h @@ -33,23 +33,28 @@ public: bool push(detail::log_entry&& entry) override { - return queue.push(std::move(entry)); + auto* arg_store = entry.metadata.store; + if (!queue.push(std::move(entry))) { + arg_pool.dealloc(arg_store); + return false; + } + return true; } + fmt::dynamic_format_arg_store* alloc_arg_store() override { return arg_pool.alloc(); } + bool is_running() const override { return worker.is_running(); } /// Installs the specified error handler into the backend worker. - void set_error_handler(error_handler err_handler) - { - worker.set_error_handler(std::move(err_handler)); - } + void set_error_handler(error_handler err_handler) { worker.set_error_handler(std::move(err_handler)); } /// Stops the backend worker thread. void stop() { worker.stop(); } private: detail::work_queue queue; - backend_worker worker{queue}; + detail::dyn_arg_store_pool arg_pool; + backend_worker worker{queue, arg_pool}; }; } // namespace srslog diff --git a/lib/src/srslog/srslog.cpp b/lib/src/srslog/srslog.cpp index 9026a63f8..c349c0318 100644 --- a/lib/src/srslog/srslog.cpp +++ b/lib/src/srslog/srslog.cpp @@ -198,6 +198,7 @@ void srslog::flush() } detail::log_entry cmd; + cmd.metadata.store = nullptr; cmd.flush_cmd = std::unique_ptr( new detail::flush_backend_cmd{completion_flag, std::move(sinks)}); diff --git a/lib/test/srslog/event_trace_test.cpp b/lib/test/srslog/event_trace_test.cpp index 94d8b063b..173089960 100644 --- a/lib/test/srslog/event_trace_test.cpp +++ b/lib/test/srslog/event_trace_test.cpp @@ -32,6 +32,8 @@ public: return true; } + fmt::dynamic_format_arg_store* alloc_arg_store() override { return &store; } + bool is_running() const override { return true; } void reset() { count = 0; } @@ -39,13 +41,13 @@ public: unsigned push_invocation_count() const { return count; } private: - unsigned count = 0; + unsigned count = 0; + fmt::dynamic_format_arg_store store; }; } // namespace -static bool -when_tracing_with_duration_event_then_two_events_are_generated(backend_spy& spy) +static bool when_tracing_with_duration_event_then_two_events_are_generated(backend_spy& spy) { trace_duration_begin("a", "b"); ASSERT_EQ(spy.push_invocation_count(), 1); @@ -56,8 +58,7 @@ when_tracing_with_duration_event_then_two_events_are_generated(backend_spy& spy) return true; } -static bool -when_tracing_with_complete_event_then_one_event_is_generated(backend_spy& spy) +static bool when_tracing_with_complete_event_then_one_event_is_generated(backend_spy& spy) { { trace_complete_event("a", "b"); @@ -70,17 +71,15 @@ when_tracing_with_complete_event_then_one_event_is_generated(backend_spy& spy) int main() { test_dummies::sink_dummy s; - backend_spy backend; - log_channel c("test", s, backend); + backend_spy backend; + log_channel c("test", s, backend); // Inject our spy into the framework. event_trace_init(c); - TEST_FUNCTION(when_tracing_with_duration_event_then_two_events_are_generated, - backend); + TEST_FUNCTION(when_tracing_with_duration_event_then_two_events_are_generated, backend); backend.reset(); - TEST_FUNCTION(when_tracing_with_complete_event_then_one_event_is_generated, - backend); + TEST_FUNCTION(when_tracing_with_complete_event_then_one_event_is_generated, backend); return 0; } diff --git a/lib/test/srslog/json_formatter_test.cpp b/lib/test/srslog/json_formatter_test.cpp index a1f8b1e3a..76d9fc0c5 100644 --- a/lib/test/srslog/json_formatter_test.cpp +++ b/lib/test/srslog/json_formatter_test.cpp @@ -18,23 +18,25 @@ using namespace srslog; /// Helper to build a log entry. -static detail::log_entry_metadata build_log_entry_metadata() +static detail::log_entry_metadata build_log_entry_metadata(fmt::dynamic_format_arg_store* store) { // Create a time point 50000us from epoch. using tp_ty = std::chrono::time_point; tp_ty tp(std::chrono::microseconds(50000)); - fmt::dynamic_format_arg_store store; - store.push_back(88); + if (store) { + store->push_back(88); + } - return {tp, {10, true}, "Text %d", std::move(store), "ABC", 'Z', small_str_buffer()}; + return {tp, {10, true}, "Text %d", store, "ABC", 'Z', small_str_buffer()}; } static bool when_fully_filled_log_entry_then_everything_is_formatted() { - fmt::memory_buffer buffer; - json_formatter{}.format(build_log_entry_metadata(), buffer); - std::string result = fmt::to_string(buffer); + fmt::dynamic_format_arg_store store; + fmt::memory_buffer buffer; + json_formatter{}.format(build_log_entry_metadata(&store), buffer); + std::string result = fmt::to_string(buffer); std::string expected = "{\n" " \"log_entry\": \"Text 88\"\n" "}\n"; @@ -44,21 +46,20 @@ static bool when_fully_filled_log_entry_then_everything_is_formatted() return true; } -static bool -when_fully_filled_log_entry_with_hex_dump_then_everything_is_formatted() +static bool when_fully_filled_log_entry_with_hex_dump_then_everything_is_formatted() { - auto entry = build_log_entry_metadata(); + fmt::dynamic_format_arg_store store; + auto entry = build_log_entry_metadata(&store); entry.hex_dump.resize(12); std::iota(entry.hex_dump.begin(), entry.hex_dump.end(), 0); fmt::memory_buffer buffer; json_formatter{}.format(std::move(entry), buffer); - std::string result = fmt::to_string(buffer); - std::string expected = - "{\n" - " \"log_entry\": \"Text 88\",\n" - " \"hex_dump\": \"00 01 02 03 04 05 06 07 08 09 0a 0b\"\n" - "}\n"; + std::string result = fmt::to_string(buffer); + std::string expected = "{\n" + " \"log_entry\": \"Text 88\",\n" + " \"hex_dump\": \"00 01 02 03 04 05 06 07 08 09 0a 0b\"\n" + "}\n"; ASSERT_EQ(result, expected); @@ -78,10 +79,9 @@ DECLARE_METRIC_SET("Network", myset2, thr_t, ip_addr_t); using basic_ctx_t = srslog::build_context_type; } // namespace -static bool -when_log_entry_with_only_basic_context_is_passed_then_context_is_formatted() +static bool when_log_entry_with_only_basic_context_is_passed_then_context_is_formatted() { - auto entry = build_log_entry_metadata(); + auto entry = build_log_entry_metadata(nullptr); entry.fmtstring = nullptr; basic_ctx_t ctx("UL Context"); @@ -93,7 +93,7 @@ when_log_entry_with_only_basic_context_is_passed_then_context_is_formatted() fmt::memory_buffer buffer; json_formatter{}.format_ctx(ctx, std::move(entry), buffer); - std::string result = fmt::to_string(buffer); + std::string result = fmt::to_string(buffer); std::string expected = "{\n" " \"RF\": {\n" " \"SNR\": -55.1,\n" @@ -111,11 +111,11 @@ when_log_entry_with_only_basic_context_is_passed_then_context_is_formatted() return true; } -static bool -when_log_entry_with_message_and_basic_context_is_passed_then_context_is_formatted() +static bool when_log_entry_with_message_and_basic_context_is_passed_then_context_is_formatted() { - auto entry = build_log_entry_metadata(); - basic_ctx_t ctx("UL Context"); + fmt::dynamic_format_arg_store store; + auto entry = build_log_entry_metadata(&store); + basic_ctx_t ctx("UL Context"); ctx.get().write(-55.1); ctx.get().write(-10); @@ -125,7 +125,7 @@ when_log_entry_with_message_and_basic_context_is_passed_then_context_is_formatte fmt::memory_buffer buffer; json_formatter{}.format_ctx(ctx, std::move(entry), buffer); - std::string result = fmt::to_string(buffer); + std::string result = fmt::to_string(buffer); std::string expected = "{\n" " \"log_entry\": \"Text 88\",\n" " \"RF\": {\n" @@ -157,23 +157,18 @@ DECLARE_METRIC_SET("ue_container", ue_set, ue_rnti_t, dl_cqi_t, bearer_list_t); DECLARE_METRIC("type", entry_type_t, std::string, ""); DECLARE_METRIC("sector_id", sector_id_t, unsigned, ""); DECLARE_METRIC_LIST("ue_list", ue_list_t, std::vector); -DECLARE_METRIC_SET("sector_metrics", - sector_set, - entry_type_t, - sector_id_t, - ue_list_t); +DECLARE_METRIC_SET("sector_metrics", sector_set, entry_type_t, sector_id_t, ue_list_t); DECLARE_METRIC_LIST("sector_list", sector_list_t, std::vector); using complex_ctx_t = srslog::build_context_type; } // namespace -static bool -when_log_entry_with_only_complex_context_is_passed_then_context_is_formatted() +static bool when_log_entry_with_only_complex_context_is_passed_then_context_is_formatted() { complex_ctx_t ctx("UL Context"); - auto entry = build_log_entry_metadata(); - entry.fmtstring = nullptr; + auto entry = build_log_entry_metadata(nullptr); + entry.fmtstring = nullptr; ctx.get().emplace_back(); ctx.at(0).get().emplace_back(); @@ -187,7 +182,7 @@ when_log_entry_with_only_complex_context_is_passed_then_context_is_formatted() fmt::memory_buffer buffer; json_formatter{}.format_ctx(ctx, std::move(entry), buffer); - std::string result = fmt::to_string(buffer); + std::string result = fmt::to_string(buffer); std::string expected = "{\n" " \"sector_list\": [\n" " {\n" @@ -252,19 +247,18 @@ DECLARE_METRIC_SET("metric_list_set", metric_list_set, list_metric2); DECLARE_METRIC_LIST("metrics_list", metrics_list, std::vector); DECLARE_METRIC("list_metric3", list_metric3, unsigned, ""); DECLARE_METRIC("list_metric4", list_metric4, unsigned, ""); -using list_ctx_t = - srslog::build_context_type; +using list_ctx_t = srslog::build_context_type; }; // namespace static bool when_context_with_empty_list_is_passed_then_list_object_is_empty() { list_ctx_t ctx("UL Context"); - auto entry = build_log_entry_metadata(); - entry.fmtstring = nullptr; + auto entry = build_log_entry_metadata(nullptr); + entry.fmtstring = nullptr; fmt::memory_buffer buffer; json_formatter{}.format_ctx(ctx, std::move(entry), buffer); - std::string result = fmt::to_string(buffer); + std::string result = fmt::to_string(buffer); std::string expected = "{\n" " \"list_metric3\": 0,\n" " \"list_metric4\": 0,\n" @@ -280,16 +274,11 @@ static bool when_context_with_empty_list_is_passed_then_list_object_is_empty() int main() { TEST_FUNCTION(when_fully_filled_log_entry_then_everything_is_formatted); - TEST_FUNCTION( - when_fully_filled_log_entry_with_hex_dump_then_everything_is_formatted); - TEST_FUNCTION( - when_log_entry_with_only_basic_context_is_passed_then_context_is_formatted); - TEST_FUNCTION( - when_log_entry_with_message_and_basic_context_is_passed_then_context_is_formatted); - TEST_FUNCTION( - when_log_entry_with_only_complex_context_is_passed_then_context_is_formatted); - TEST_FUNCTION( - when_context_with_empty_list_is_passed_then_list_object_is_empty); + TEST_FUNCTION(when_fully_filled_log_entry_with_hex_dump_then_everything_is_formatted); + TEST_FUNCTION(when_log_entry_with_only_basic_context_is_passed_then_context_is_formatted); + TEST_FUNCTION(when_log_entry_with_message_and_basic_context_is_passed_then_context_is_formatted); + TEST_FUNCTION(when_log_entry_with_only_complex_context_is_passed_then_context_is_formatted); + TEST_FUNCTION(when_context_with_empty_list_is_passed_then_list_object_is_empty); return 0; } diff --git a/lib/test/srslog/log_backend_test.cpp b/lib/test/srslog/log_backend_test.cpp index 1ef1b56ca..39a395a0c 100644 --- a/lib/test/srslog/log_backend_test.cpp +++ b/lib/test/srslog/log_backend_test.cpp @@ -46,9 +46,7 @@ namespace { class sink_spy : public sink { public: - sink_spy() : - sink(std::unique_ptr(new test_dummies::log_formatter_dummy)) - {} + sink_spy() : sink(std::unique_ptr(new test_dummies::log_formatter_dummy)) {} detail::error_string write(detail::memory_buffer buffer) override { @@ -64,33 +62,33 @@ public: const std::string& received_buffer() const { return str; } private: - unsigned count = 0; + unsigned count = 0; std::string str; }; } // namespace /// Builds a basic log entry. -static detail::log_entry build_log_entry(sink* s) +static detail::log_entry build_log_entry(sink* s, fmt::dynamic_format_arg_store* store) { using tp_ty = std::chrono::time_point; tp_ty tp; - fmt::dynamic_format_arg_store store; - store.push_back(88); + if (store) { + store->push_back(88); + } - return { - s, - [](detail::log_entry_metadata&& metadata, fmt::memory_buffer& buffer) {}, - {tp, {0, false}, "Text %d", std::move(store), "", '\0', small_str_buffer()}}; + return {s, + [](detail::log_entry_metadata&& metadata, fmt::memory_buffer& buffer) {}, + {tp, {0, false}, "Text %d", store, "", '\0', small_str_buffer()}}; } static bool when_backend_is_not_started_then_pushed_log_entries_are_ignored() { - sink_spy spy; + sink_spy spy; log_backend_impl backend; - backend.push(build_log_entry(&spy)); + backend.push(build_log_entry(&spy, backend.alloc_arg_store())); ASSERT_EQ(spy.write_invocation_count(), 0); @@ -104,7 +102,7 @@ static bool when_backend_is_started_then_pushed_log_entries_are_sent_to_sink() log_backend_impl backend; backend.start(); - backend.push(build_log_entry(&spy)); + backend.push(build_log_entry(&spy, backend.alloc_arg_store())); // Stop the backend to ensure the entry has been processed. backend.stop(); @@ -121,10 +119,9 @@ static bool when_backend_is_started_then_backend_invokes_format_func() log_backend_impl backend; backend.start(); - auto entry = build_log_entry(&s); - unsigned counter = 0; - entry.format_func = [&counter](detail::log_entry_metadata&& metadata, - fmt::memory_buffer& buffer) { ++counter; }; + auto entry = build_log_entry(&s, backend.alloc_arg_store()); + unsigned counter = 0; + entry.format_func = [&counter](detail::log_entry_metadata&& metadata, fmt::memory_buffer& buffer) { ++counter; }; backend.push(std::move(entry)); // Stop the backend to ensure the entry has been processed. @@ -144,14 +141,10 @@ class sink_error_stub : public sink { public: explicit sink_error_stub(std::string err) : - sink(std::unique_ptr(new test_dummies::log_formatter_dummy)), - err(std::move(err)) + sink(std::unique_ptr(new test_dummies::log_formatter_dummy)), err(std::move(err)) {} - detail::error_string write(detail::memory_buffer buffer) override - { - return err; - } + detail::error_string write(detail::memory_buffer buffer) override { return err; } detail::error_string flush() override { return err; } @@ -163,11 +156,11 @@ private: static bool when_sink_write_fails_then_error_handler_is_invoked() { - std::string error_str("error"); + std::string error_str("error"); sink_error_stub s(error_str); - bool valid_err = false; - unsigned count = 0; + bool valid_err = false; + unsigned count = 0; // valid_err checks that the input error matches the expected string. // The count variable counts the number of calls. auto handler = [&count, &valid_err, error_str](const std::string& error) { @@ -179,7 +172,7 @@ static bool when_sink_write_fails_then_error_handler_is_invoked() backend.set_error_handler(handler); backend.start(); - backend.push(build_log_entry(&s)); + backend.push(build_log_entry(&s, backend.alloc_arg_store())); // Stop the backend to ensure the entry has been processed. backend.stop(); @@ -204,7 +197,7 @@ static bool when_handler_is_set_after_start_then_handler_is_not_used() backend.start(); backend.set_error_handler(handler); - backend.push(build_log_entry(&s)); + backend.push(build_log_entry(&s, backend.alloc_arg_store())); // Stop the backend to ensure the entry has been processed. backend.stop(); @@ -223,7 +216,7 @@ static bool when_empty_handler_is_used_then_backend_does_not_crash() backend.set_error_handler({}); backend.start(); - backend.push(build_log_entry(&s)); + backend.push(build_log_entry(&s, backend.alloc_arg_store())); // Stop the backend to ensure the entry has been processed. backend.stop(); @@ -234,12 +227,9 @@ static bool when_empty_handler_is_used_then_backend_does_not_crash() int main() { TEST_FUNCTION(when_backend_is_started_then_is_started_returns_true); - TEST_FUNCTION( - when_backend_is_started_and_stopped_then_is_started_returns_false); - TEST_FUNCTION( - when_backend_is_not_started_then_pushed_log_entries_are_ignored); - TEST_FUNCTION( - when_backend_is_started_then_pushed_log_entries_are_sent_to_sink); + TEST_FUNCTION(when_backend_is_started_and_stopped_then_is_started_returns_false); + TEST_FUNCTION(when_backend_is_not_started_then_pushed_log_entries_are_ignored); + TEST_FUNCTION(when_backend_is_started_then_pushed_log_entries_are_sent_to_sink); TEST_FUNCTION(when_backend_is_started_then_backend_invokes_format_func); TEST_FUNCTION(when_sink_write_fails_then_error_handler_is_invoked); TEST_FUNCTION(when_handler_is_set_after_start_then_handler_is_not_used); diff --git a/lib/test/srslog/log_channel_test.cpp b/lib/test/srslog/log_channel_test.cpp index eb425bdc9..af231903b 100644 --- a/lib/test/srslog/log_channel_test.cpp +++ b/lib/test/srslog/log_channel_test.cpp @@ -19,8 +19,8 @@ using namespace srslog; static bool when_log_channel_is_created_then_id_matches_expected_value() { test_dummies::backend_dummy backend; - test_dummies::sink_dummy s; - log_channel log("id", s, backend); + test_dummies::sink_dummy s; + log_channel log("id", s, backend); ASSERT_EQ(log.id(), "id"); @@ -30,8 +30,8 @@ static bool when_log_channel_is_created_then_id_matches_expected_value() static bool when_log_channel_is_disabled_then_enabled_returns_false() { test_dummies::backend_dummy backend; - test_dummies::sink_dummy s; - log_channel log("id", s, backend); + test_dummies::sink_dummy s; + log_channel log("id", s, backend); log.set_enabled(false); @@ -43,8 +43,8 @@ static bool when_log_channel_is_disabled_then_enabled_returns_false() static bool when_log_channel_is_enabled_then_enabled_returns_true() { test_dummies::backend_dummy backend; - test_dummies::sink_dummy s; - log_channel log("id", s, backend); + test_dummies::sink_dummy s; + log_channel log("id", s, backend); log.set_enabled(true); @@ -71,23 +71,25 @@ public: bool is_running() const override { return true; } + fmt::dynamic_format_arg_store* alloc_arg_store() override { return &store; } + unsigned push_invocation_count() const { return count; } const detail::log_entry& last_entry() const { return e; } private: - unsigned count = 0; - detail::log_entry e; + unsigned count = 0; + detail::log_entry e; + fmt::dynamic_format_arg_store store; }; } // namespace -static bool -when_logging_in_log_channel_then_log_entry_is_pushed_into_the_backend() +static bool when_logging_in_log_channel_then_log_entry_is_pushed_into_the_backend() { - backend_spy backend; + backend_spy backend; test_dummies::sink_dummy s; - log_channel log("id", s, backend); + log_channel log("id", s, backend); log("test", 42, "Hello"); @@ -98,9 +100,9 @@ when_logging_in_log_channel_then_log_entry_is_pushed_into_the_backend() static bool when_logging_in_disabled_log_channel_then_log_entry_is_ignored() { - backend_spy backend; + backend_spy backend; test_dummies::sink_dummy s; - log_channel log("id", s, backend); + log_channel log("id", s, backend); log.set_enabled(false); log("test", 42, "Hello"); @@ -112,11 +114,11 @@ static bool when_logging_in_disabled_log_channel_then_log_entry_is_ignored() static bool when_logging_then_filled_in_log_entry_is_pushed_into_the_backend() { - backend_spy backend; + backend_spy backend; test_dummies::sink_dummy s; std::string name = "name"; - char tag = 'A'; + char tag = 'A'; log_channel log("id", s, backend, {name, tag, true}); @@ -141,14 +143,13 @@ static bool when_logging_then_filled_in_log_entry_is_pushed_into_the_backend() return true; } -static bool -when_logging_with_hex_dump_then_filled_in_log_entry_is_pushed_into_the_backend() +static bool when_logging_with_hex_dump_then_filled_in_log_entry_is_pushed_into_the_backend() { - backend_spy backend; + backend_spy backend; test_dummies::sink_dummy s; std::string name = "name"; - char tag = 'A'; + char tag = 'A'; log_channel log("id", s, backend, {name, tag, true}); @@ -171,18 +172,14 @@ when_logging_with_hex_dump_then_filled_in_log_entry_is_pushed_into_the_backend() ASSERT_EQ(entry.metadata.log_name, name); ASSERT_EQ(entry.metadata.log_tag, tag); ASSERT_EQ(entry.metadata.hex_dump.size(), 4); - ASSERT_EQ(std::equal(entry.metadata.hex_dump.begin(), - entry.metadata.hex_dump.end(), - std::begin(hex)), - true); + ASSERT_EQ(std::equal(entry.metadata.hex_dump.begin(), entry.metadata.hex_dump.end(), std::begin(hex)), true); return true; } -static bool -when_hex_array_length_is_less_than_hex_log_max_size_then_array_length_is_used() +static bool when_hex_array_length_is_less_than_hex_log_max_size_then_array_length_is_used() { - backend_spy backend; + backend_spy backend; test_dummies::sink_dummy s; std::string name = "name"; @@ -197,10 +194,7 @@ when_hex_array_length_is_less_than_hex_log_max_size_then_array_length_is_used() const detail::log_entry& entry = backend.last_entry(); ASSERT_EQ(entry.metadata.hex_dump.size(), 3); - ASSERT_EQ(std::equal(entry.metadata.hex_dump.begin(), - entry.metadata.hex_dump.end(), - std::begin(hex)), - true); + ASSERT_EQ(std::equal(entry.metadata.hex_dump.begin(), entry.metadata.hex_dump.end(), std::begin(hex)), true); return true; } @@ -213,14 +207,13 @@ using my_ctx = srslog::build_context_type; } // namespace -static bool -when_logging_with_context_then_filled_in_log_entry_is_pushed_into_the_backend() +static bool when_logging_with_context_then_filled_in_log_entry_is_pushed_into_the_backend() { - backend_spy backend; + backend_spy backend; test_dummies::sink_dummy s; std::string name = "name"; - char tag = 'A'; + char tag = 'A'; log_channel log("id", s, backend, {name, tag, true}); @@ -245,14 +238,13 @@ when_logging_with_context_then_filled_in_log_entry_is_pushed_into_the_backend() return true; } -static bool -when_logging_with_context_and_message_then_filled_in_log_entry_is_pushed_into_the_backend() +static bool when_logging_with_context_and_message_then_filled_in_log_entry_is_pushed_into_the_backend() { - backend_spy backend; + backend_spy backend; test_dummies::sink_dummy s; std::string name = "name"; - char tag = 'A'; + char tag = 'A'; log_channel log("id", s, backend, {name, tag, true}); @@ -278,10 +270,9 @@ when_logging_with_context_and_message_then_filled_in_log_entry_is_pushed_into_th return true; } -static bool -when_logging_with_small_string_then_filled_in_log_entry_is_pushed_into_the_backend() +static bool when_logging_with_small_string_then_filled_in_log_entry_is_pushed_into_the_backend() { - backend_spy backend; + backend_spy backend; test_dummies::sink_dummy s; log_channel log("id", s, backend); @@ -308,21 +299,14 @@ int main() TEST_FUNCTION(when_log_channel_is_created_then_id_matches_expected_value); TEST_FUNCTION(when_log_channel_is_disabled_then_enabled_returns_false); TEST_FUNCTION(when_log_channel_is_enabled_then_enabled_returns_true); - TEST_FUNCTION( - when_logging_in_log_channel_then_log_entry_is_pushed_into_the_backend); + TEST_FUNCTION(when_logging_in_log_channel_then_log_entry_is_pushed_into_the_backend); TEST_FUNCTION(when_logging_in_disabled_log_channel_then_log_entry_is_ignored); - TEST_FUNCTION( - when_logging_then_filled_in_log_entry_is_pushed_into_the_backend); - TEST_FUNCTION( - when_logging_with_hex_dump_then_filled_in_log_entry_is_pushed_into_the_backend); - TEST_FUNCTION( - when_hex_array_length_is_less_than_hex_log_max_size_then_array_length_is_used); - TEST_FUNCTION( - when_logging_with_context_then_filled_in_log_entry_is_pushed_into_the_backend); - TEST_FUNCTION( - when_logging_with_context_and_message_then_filled_in_log_entry_is_pushed_into_the_backend); - TEST_FUNCTION( - when_logging_with_small_string_then_filled_in_log_entry_is_pushed_into_the_backend); + TEST_FUNCTION(when_logging_then_filled_in_log_entry_is_pushed_into_the_backend); + TEST_FUNCTION(when_logging_with_hex_dump_then_filled_in_log_entry_is_pushed_into_the_backend); + TEST_FUNCTION(when_hex_array_length_is_less_than_hex_log_max_size_then_array_length_is_used); + TEST_FUNCTION(when_logging_with_context_then_filled_in_log_entry_is_pushed_into_the_backend); + TEST_FUNCTION(when_logging_with_context_and_message_then_filled_in_log_entry_is_pushed_into_the_backend); + TEST_FUNCTION(when_logging_with_small_string_then_filled_in_log_entry_is_pushed_into_the_backend); return 0; } diff --git a/lib/test/srslog/test_dummies.h b/lib/test/srslog/test_dummies.h index 8d78ef5d1..412f1e42b 100644 --- a/lib/test/srslog/test_dummies.h +++ b/lib/test/srslog/test_dummies.h @@ -22,45 +22,32 @@ namespace test_dummies { class log_formatter_dummy : public srslog::log_formatter { public: - void format(srslog::detail::log_entry_metadata&& metadata, - fmt::memory_buffer& buffer) override - {} + void format(srslog::detail::log_entry_metadata&& metadata, fmt::memory_buffer& buffer) override {} std::unique_ptr clone() const override { return nullptr; } private: void format_context_begin(const srslog::detail::log_entry_metadata& md, - const std::string& ctx_name, - unsigned size, - fmt::memory_buffer& buffer) override + fmt::string_view ctx_name, + unsigned size, + fmt::memory_buffer& buffer) override {} void format_context_end(const srslog::detail::log_entry_metadata& md, - const std::string& ctx_name, - fmt::memory_buffer& buffer) override - {} - void format_metric_set_begin(const std::string& set_name, - unsigned size, - unsigned level, - fmt::memory_buffer& buffer) override - {} - void format_metric_set_end(const std::string& set_name, - unsigned level, - fmt::memory_buffer& buffer) override + fmt::string_view ctx_name, + fmt::memory_buffer& buffer) override {} - void format_list_begin(const std::string& list_name, - unsigned size, - unsigned level, - fmt::memory_buffer& buffer) override + void + format_metric_set_begin(fmt::string_view set_name, unsigned size, unsigned level, fmt::memory_buffer& buffer) override {} - void format_list_end(const std::string& list_name, - unsigned level, - fmt::memory_buffer& buffer) override + void format_metric_set_end(fmt::string_view set_name, unsigned level, fmt::memory_buffer& buffer) override {} + void format_list_begin(fmt::string_view list_name, unsigned size, unsigned level, fmt::memory_buffer& buffer) override {} - void format_metric(const std::string& metric_name, - const std::string& metric_value, - const std::string& metric_units, + void format_list_end(fmt::string_view list_name, unsigned level, fmt::memory_buffer& buffer) override {} + void format_metric(fmt::string_view metric_name, + fmt::string_view metric_value, + fmt::string_view metric_units, srslog::metric_kind kind, - unsigned level, + unsigned level, fmt::memory_buffer& buffer) override {} }; @@ -69,15 +56,9 @@ private: class sink_dummy : public srslog::sink { public: - sink_dummy() : - sink(std::unique_ptr(new log_formatter_dummy)) - {} + sink_dummy() : sink(std::unique_ptr(new log_formatter_dummy)) {} - srslog::detail::error_string - write(srslog::detail::memory_buffer buffer) override - { - return {}; - } + srslog::detail::error_string write(srslog::detail::memory_buffer buffer) override { return {}; } srslog::detail::error_string flush() override { return {}; } }; @@ -91,6 +72,8 @@ public: bool push(srslog::detail::log_entry&& entry) override { return true; } bool is_running() const override { return true; } + + fmt::dynamic_format_arg_store* alloc_arg_store() override { return nullptr; } }; } // namespace test_dummies diff --git a/lib/test/srslog/text_formatter_test.cpp b/lib/test/srslog/text_formatter_test.cpp index 429f06ed1..d98a07cfe 100644 --- a/lib/test/srslog/text_formatter_test.cpp +++ b/lib/test/srslog/text_formatter_test.cpp @@ -18,23 +18,25 @@ using namespace srslog; /// Helper to build a log entry. -static detail::log_entry_metadata build_log_entry_metadata() +static detail::log_entry_metadata build_log_entry_metadata(fmt::dynamic_format_arg_store* store) { // Create a time point 50000us from epoch. using tp_ty = std::chrono::time_point; tp_ty tp(std::chrono::microseconds(50000)); - fmt::dynamic_format_arg_store store; - store.push_back(88); + if (store) { + store->push_back(88); + } - return {tp, {10, true}, "Text %d", std::move(store), "ABC", 'Z', small_str_buffer()}; + return {tp, {10, true}, "Text %d", store, "ABC", 'Z', small_str_buffer()}; } static bool when_fully_filled_log_entry_then_everything_is_formatted() { - fmt::memory_buffer buffer; - text_formatter{}.format(build_log_entry_metadata(), buffer); - std::string result = fmt::to_string(buffer); + fmt::memory_buffer buffer; + fmt::dynamic_format_arg_store store; + text_formatter{}.format(build_log_entry_metadata(&store), buffer); + std::string result = fmt::to_string(buffer); std::string expected = "00:00:00.050000 [ABC ] [Z] [ 10] Text 88\n"; ASSERT_EQ(result, expected); @@ -44,12 +46,13 @@ static bool when_fully_filled_log_entry_then_everything_is_formatted() static bool when_log_entry_without_name_is_passed_then_name_is_not_formatted() { - auto entry = build_log_entry_metadata(); - entry.log_name = ""; + fmt::dynamic_format_arg_store store; + auto entry = build_log_entry_metadata(&store); + entry.log_name = ""; fmt::memory_buffer buffer; text_formatter{}.format(std::move(entry), buffer); - std::string result = fmt::to_string(buffer); + std::string result = fmt::to_string(buffer); std::string expected = "00:00:00.050000 [Z] [ 10] Text 88\n"; ASSERT_EQ(result, expected); @@ -59,12 +62,13 @@ static bool when_log_entry_without_name_is_passed_then_name_is_not_formatted() static bool when_log_entry_without_tag_is_passed_then_tag_is_not_formatted() { - auto entry = build_log_entry_metadata(); - entry.log_tag = '\0'; + fmt::dynamic_format_arg_store store; + auto entry = build_log_entry_metadata(&store); + entry.log_tag = '\0'; fmt::memory_buffer buffer; text_formatter{}.format(std::move(entry), buffer); - std::string result = fmt::to_string(buffer); + std::string result = fmt::to_string(buffer); std::string expected = "00:00:00.050000 [ABC ] [ 10] Text 88\n"; ASSERT_EQ(result, expected); @@ -72,15 +76,15 @@ static bool when_log_entry_without_tag_is_passed_then_tag_is_not_formatted() return true; } -static bool -when_log_entry_without_context_is_passed_then_context_is_not_formatted() +static bool when_log_entry_without_context_is_passed_then_context_is_not_formatted() { - auto entry = build_log_entry_metadata(); - entry.context.enabled = false; + fmt::dynamic_format_arg_store store; + auto entry = build_log_entry_metadata(&store); + entry.context.enabled = false; fmt::memory_buffer buffer; text_formatter{}.format(std::move(entry), buffer); - std::string result = fmt::to_string(buffer); + std::string result = fmt::to_string(buffer); std::string expected = "00:00:00.050000 [ABC ] [Z] Text 88\n"; ASSERT_EQ(result, expected); @@ -90,17 +94,17 @@ when_log_entry_without_context_is_passed_then_context_is_not_formatted() static bool when_log_entry_with_hex_dump_is_passed_then_hex_dump_is_formatted() { - auto entry = build_log_entry_metadata(); + fmt::dynamic_format_arg_store store; + auto entry = build_log_entry_metadata(&store); entry.hex_dump.resize(20); std::iota(entry.hex_dump.begin(), entry.hex_dump.end(), 0); fmt::memory_buffer buffer; text_formatter{}.format(std::move(entry), buffer); - std::string result = fmt::to_string(buffer); - std::string expected = - "00:00:00.050000 [ABC ] [Z] [ 10] Text 88\n" - " 0000: 00 01 02 03 04 05 06 07 08 09 0a 0b 0c 0d 0e 0f\n" - " 0010: 10 11 12 13\n"; + std::string result = fmt::to_string(buffer); + std::string expected = "00:00:00.050000 [ABC ] [Z] [ 10] Text 88\n" + " 0000: 00 01 02 03 04 05 06 07 08 09 0a 0b 0c 0d 0e 0f\n" + " 0010: 10 11 12 13\n"; ASSERT_EQ(result, expected); @@ -120,11 +124,7 @@ DECLARE_METRIC_SET("ue_container", ue_set, thr_t, ip_addr_t, antenna_list_t); DECLARE_METRIC("type", entry_type_t, std::string, ""); DECLARE_METRIC("sector_id", sector_id_t, unsigned, ""); DECLARE_METRIC_LIST("ue_list", ue_list_t, std::vector); -DECLARE_METRIC_SET("sector_metrics", - sector_set, - entry_type_t, - sector_id_t, - ue_list_t); +DECLARE_METRIC_SET("sector_metrics", sector_set, entry_type_t, sector_id_t, ue_list_t); DECLARE_METRIC_LIST("sector_list", sector_list_t, std::vector); @@ -149,54 +149,33 @@ static complex_ctx_t build_complex_context() ctx.at(0).at(1).write(10.2); ctx.at(0).at(1).write("10.20.30.41"); - ctx.at(0) - .at(0) - .get() - .emplace_back(); - ctx.at(0).at(0).at(0).write( - 5.1); - ctx.at(0).at(0).at(0).write( - -11.5); - - ctx.at(0) - .at(0) - .get() - .emplace_back(); - ctx.at(0).at(0).at(1).write( - 10.1); - ctx.at(0).at(0).at(1).write( - -20.5); - - ctx.at(0) - .at(1) - .get() - .emplace_back(); - ctx.at(0).at(1).at(0).write( - 20.1); - ctx.at(0).at(1).at(0).write( - -30.5); - ctx.at(0) - .at(1) - .get() - .emplace_back(); - ctx.at(0).at(1).at(1).write( - 30.1); - ctx.at(0).at(1).at(1).write( - -40.5); + ctx.at(0).at(0).get().emplace_back(); + ctx.at(0).at(0).at(0).write(5.1); + ctx.at(0).at(0).at(0).write(-11.5); + + ctx.at(0).at(0).get().emplace_back(); + ctx.at(0).at(0).at(1).write(10.1); + ctx.at(0).at(0).at(1).write(-20.5); + + ctx.at(0).at(1).get().emplace_back(); + ctx.at(0).at(1).at(0).write(20.1); + ctx.at(0).at(1).at(0).write(-30.5); + ctx.at(0).at(1).get().emplace_back(); + ctx.at(0).at(1).at(1).write(30.1); + ctx.at(0).at(1).at(1).write(-40.5); return ctx; } -static bool -when_log_entry_with_only_context_is_passed_then_context_is_formatted() +static bool when_log_entry_with_only_context_is_passed_then_context_is_formatted() { - auto ctx = build_complex_context(); - auto entry = build_log_entry_metadata(); + auto ctx = build_complex_context(); + auto entry = build_log_entry_metadata(nullptr); entry.fmtstring = nullptr; fmt::memory_buffer buffer; text_formatter{}.format_ctx(ctx, std::move(entry), buffer); - std::string result = fmt::to_string(buffer); + std::string result = fmt::to_string(buffer); std::string expected = "00:00:00.050000 [ABC ] [Z] [ 10] Context dump for " "\"Complex Context\"\n" " > List: sector_list\n" @@ -230,22 +209,21 @@ when_log_entry_with_only_context_is_passed_then_context_is_formatted() return true; } -static bool -when_log_entry_with_context_and_message_is_passed_then_context_is_formatted() +static bool when_log_entry_with_context_and_message_is_passed_then_context_is_formatted() { - auto entry = build_log_entry_metadata(); - auto ctx = build_complex_context(); + fmt::dynamic_format_arg_store store; + auto entry = build_log_entry_metadata(&store); + auto ctx = build_complex_context(); fmt::memory_buffer buffer; text_formatter{}.format_ctx(ctx, std::move(entry), buffer); - std::string result = fmt::to_string(buffer); - std::string expected = - "00:00:00.050000 [ABC ] [Z] [ 10] [[sector_metrics_type: event, " - "sector_metrics_sector_id: 1, [ue_container_Throughput: 1.2 MB/s, " - "ue_container_Address: 10.20.30.40, [RF_SNR: 5.1 dB, RF_PWR: -11 " - "dBm][RF_SNR: 10.1 dB, RF_PWR: -20 dBm]][ue_container_Throughput: 10.2 " - "MB/s, ue_container_Address: 10.20.30.41, [RF_SNR: 20.1 dB, RF_PWR: -30 " - "dBm][RF_SNR: 30.1 dB, RF_PWR: -40 dBm]]]]: Text 88\n"; + std::string result = fmt::to_string(buffer); + std::string expected = "00:00:00.050000 [ABC ] [Z] [ 10] [[sector_metrics_type: event, " + "sector_metrics_sector_id: 1, [ue_container_Throughput: 1.2 MB/s, " + "ue_container_Address: 10.20.30.40, [RF_SNR: 5.1 dB, RF_PWR: -11 " + "dBm][RF_SNR: 10.1 dB, RF_PWR: -20 dBm]][ue_container_Throughput: 10.2 " + "MB/s, ue_container_Address: 10.20.30.41, [RF_SNR: 20.1 dB, RF_PWR: -30 " + "dBm][RF_SNR: 30.1 dB, RF_PWR: -40 dBm]]]]: Text 88\n"; ASSERT_EQ(result, expected); @@ -255,17 +233,12 @@ when_log_entry_with_context_and_message_is_passed_then_context_is_formatted() int main() { TEST_FUNCTION(when_fully_filled_log_entry_then_everything_is_formatted); - TEST_FUNCTION( - when_log_entry_without_name_is_passed_then_name_is_not_formatted); + TEST_FUNCTION(when_log_entry_without_name_is_passed_then_name_is_not_formatted); TEST_FUNCTION(when_log_entry_without_tag_is_passed_then_tag_is_not_formatted); - TEST_FUNCTION( - when_log_entry_without_context_is_passed_then_context_is_not_formatted); - TEST_FUNCTION( - when_log_entry_with_hex_dump_is_passed_then_hex_dump_is_formatted); - TEST_FUNCTION( - when_log_entry_with_only_context_is_passed_then_context_is_formatted); - TEST_FUNCTION( - when_log_entry_with_context_and_message_is_passed_then_context_is_formatted); + TEST_FUNCTION(when_log_entry_without_context_is_passed_then_context_is_not_formatted); + TEST_FUNCTION(when_log_entry_with_hex_dump_is_passed_then_hex_dump_is_formatted); + TEST_FUNCTION(when_log_entry_with_only_context_is_passed_then_context_is_formatted); + TEST_FUNCTION(when_log_entry_with_context_and_message_is_passed_then_context_is_formatted); return 0; }