diff --git a/lib/include/srslte/srslog/detail/log_backend.h b/lib/include/srslte/srslog/detail/log_backend.h index ecb08687b..840cc90b2 100644 --- a/lib/include/srslte/srslog/detail/log_backend.h +++ b/lib/include/srslte/srslog/detail/log_backend.h @@ -13,12 +13,12 @@ #ifndef SRSLOG_DETAIL_LOG_BACKEND_H #define SRSLOG_DETAIL_LOG_BACKEND_H -#include "srslte/srslog/detail/log_entry.h" - namespace srslog { namespace detail { +struct log_entry; + /// The log backend receives generated log entries from the application. Each /// entry gets distributed to the corresponding sinks. /// NOTE: Thread safe class. @@ -32,7 +32,7 @@ public: virtual void start() = 0; /// Pushes a log entry into the backend. - virtual void push(detail::log_entry&& entry) = 0; + virtual void push(log_entry&& entry) = 0; /// Returns true when the backend has been started, otherwise false. virtual bool is_running() const = 0; diff --git a/lib/include/srslte/srslog/detail/log_entry.h b/lib/include/srslte/srslog/detail/log_entry.h index 3d5eed764..64e30cba8 100644 --- a/lib/include/srslte/srslog/detail/log_entry.h +++ b/lib/include/srslte/srslog/detail/log_entry.h @@ -13,9 +13,8 @@ #ifndef SRSLOG_DETAIL_LOG_ENTRY_H #define SRSLOG_DETAIL_LOG_ENTRY_H -#include "srslte/srslog/bundled/fmt/printf.h" +#include "srslte/srslog/detail/log_entry_metadata.h" #include "srslte/srslog/detail/support/thread_utils.h" -#include namespace srslog { @@ -23,14 +22,6 @@ class sink; namespace detail { -/// This structure gives the user a way to log generic information as a context. -struct log_context { - /// Generic contxt value. - uint32_t value; - /// When true, the context value will be printed in the log entry. - bool enabled; -}; - /// This command flushes all the messages pending in the backend. struct flush_backend_cmd { shared_variable& completion_flag; @@ -39,16 +30,13 @@ struct flush_backend_cmd { /// This structure packs all the required data required to create a log entry in /// the backend. -//:TODO: provide proper command objects when we have custom formatting. +//:TODO: replace this object using a real command pattern when we have a raw +// memory queue for passing entries. struct log_entry { sink* s; - std::chrono::high_resolution_clock::time_point tp; - log_context context; - std::string fmtstring; - fmt::dynamic_format_arg_store store; - std::string log_name; - char log_tag; - std::vector hex_dump; + std::function + format_func; + log_entry_metadata metadata; std::unique_ptr flush_cmd; }; diff --git a/lib/include/srslte/srslog/log_channel.h b/lib/include/srslte/srslog/log_channel.h index cb926836c..0acd80146 100644 --- a/lib/include/srslte/srslog/log_channel.h +++ b/lib/include/srslte/srslog/log_channel.h @@ -14,7 +14,8 @@ #define SRSLOG_LOG_CHANNEL_H #include "srslte/srslog/detail/log_backend.h" -#include +#include "srslte/srslog/detail/log_entry.h" +#include "srslte/srslog/sink.h" namespace srslog { @@ -22,9 +23,7 @@ namespace srslog { struct log_channel_config { log_channel_config() = default; log_channel_config(std::string n, char tag, bool should_print_context) : - name(std::move(n)), - tag(tag), - should_print_context(should_print_context) + name(std::move(n)), tag(tag), should_print_context(should_print_context) {} /// Optional log channel name. If set, will get printed for each log entry. @@ -95,19 +94,25 @@ public: if (!enabled()) { return; } - assert(&log_sink); + // Populate the store with all incoming arguments. fmt::dynamic_format_arg_store store; (void)std::initializer_list{(store.push_back(args), 0)...}; // Send the log entry to the backend. - detail::log_entry entry = {&log_sink, - std::chrono::high_resolution_clock::now(), - {ctx_value, should_print_context}, - fmtstr, - std::move(store), - log_name, - log_tag}; + 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}}; backend.push(std::move(entry)); } @@ -123,7 +128,6 @@ public: return; } - assert(&log_sink); // Populate the store with all incoming arguments. fmt::dynamic_format_arg_store store; (void)std::initializer_list{(store.push_back(args), 0)...}; @@ -133,14 +137,78 @@ public: len = std::min(len, hex_max_size); // Send the log entry to the backend. - detail::log_entry entry = {&log_sink, - std::chrono::high_resolution_clock::now(), - {ctx_value, should_print_context}, - fmtstr, - std::move(store), - log_name, - log_tag, - 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, + std::move(store), + log_name, + log_tag, + std::vector(buffer, buffer + len)}}; + 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 context& ctx) + { + if (!enabled()) { + return; + } + + // 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}, + "", + {}, + log_name, + log_tag}}; + 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 context& ctx, + const std::string& 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(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}}; backend.push(std::move(entry)); } diff --git a/lib/include/srslte/srslog/sink.h b/lib/include/srslte/srslog/sink.h index 62b430d57..e0f704394 100644 --- a/lib/include/srslte/srslog/sink.h +++ b/lib/include/srslte/srslog/sink.h @@ -15,6 +15,8 @@ #include "srslte/srslog/detail/support/error_string.h" #include "srslte/srslog/detail/support/memory_buffer.h" +#include "srslte/srslog/formatter.h" +#include namespace srslog { @@ -23,13 +25,25 @@ namespace srslog { class sink { public: + explicit sink(std::unique_ptr f) : formatter(std::move(f)) + { + assert(formatter && "Invalid formatter"); + } + virtual ~sink() = default; + /// Returns the formatter used by this sink. + log_formatter& get_formatter() { return *formatter; } + const log_formatter& get_formatter() const { return *formatter; } + /// Writes the provided memory buffer into the sink. virtual detail::error_string write(detail::memory_buffer buffer) = 0; /// Flushes any buffered contents to the backing store. virtual detail::error_string flush() = 0; + +private: + std::unique_ptr formatter; }; } // namespace srslog diff --git a/lib/include/srslte/srslog/srslog.h b/lib/include/srslte/srslog/srslog.h index 0c59e7a50..968a7f514 100644 --- a/lib/include/srslte/srslog/srslog.h +++ b/lib/include/srslte/srslog/srslog.h @@ -52,6 +52,10 @@ fetch_log_channel(const std::string& id, sink& s, log_channel_config config); /// NOTE: Deprecated, use fetch_log_channel instead. log_channel* create_log_channel(const std::string& id, sink& s); +/// +/// Logger management functions. +/// + namespace detail { /// Internal helper functions. @@ -60,10 +64,6 @@ detail::any* find_logger(const std::string& id); } // namespace detail -/// -/// Logger management functions. -/// - /// Finds a logger with the specified id string and type in the repository. On /// success returns a pointer to the requested logger, otherwise nullptr. /// NOTE: T should be a type that is a logger. @@ -133,13 +133,30 @@ inline T* create_logger(const std::string& id, Args&&... args) return detail::any_cast(p); } +/// +/// Formatter management functions. +/// + +/// Installs the specified formatter to be used as the default one by new sinks. +/// The initial default formatter formats plain text. +void set_default_log_formatter(std::unique_ptr f); + +/// Returns the instance of the default formatter being used. +std::unique_ptr get_default_log_formatter(); + +/// Creates a new instance of a plain text formatter. +std::unique_ptr create_text_formatter(); + +/// Creates a new instance of a JSON formatter. +std::unique_ptr create_json_formatter(); + /// /// Sink management functions. /// /// Installs the specified sink to be used as the default one by new log /// channels and loggers. -/// The initial default sink writes to stdout. +/// The initial default sink writes to stdout with a text formatter. void set_default_sink(sink& s); /// Returns the instance of the default sink being used. @@ -149,18 +166,35 @@ sink& get_default_sink(); /// success returns a pointer to the requested sink, otherwise nullptr. sink* find_sink(const std::string& id); -/// Returns an instance of a sink that writes to the stdout stream. -sink& fetch_stdout_sink(); +/// Returns an instance of a sink that writes to the stdout stream. You may use +/// different ids if you need to create multiple stdout sinks with different +/// formatters. +sink& fetch_stdout_sink( + const std::string& id = "stdout", + std::unique_ptr f = get_default_log_formatter()); -/// Returns an instance of a sink that writes to the stderr stream. -sink& fetch_stderr_sink(); +/// Returns an instance of a sink that writes to the stderr stream. You may use +/// different ids if you need to create multiple stderr sinks with different +/// formatters. +sink& fetch_stderr_sink( + const std::string& id = "stderr", + std::unique_ptr f = get_default_log_formatter()); /// Returns an instance of a sink that writes into a file in the specified path. /// Specifying a max_size value different to zero will make the sink create a /// new file each time the current file exceeds this value. The units of /// max_size are bytes. -/// NOTE: Any '#' characters in the id will get removed. -sink& fetch_file_sink(const std::string& path, size_t max_size = 0); +/// NOTE: Any '#' characters in the path will get removed. +sink& fetch_file_sink( + const std::string& path, + size_t max_size = 0, + std::unique_ptr f = get_default_log_formatter()); + +/// Installs a custom user defined sink in the framework getting associated to +/// the specified id. Returns true on success, otherwise false. +/// WARNING: This function is an advanced feature and users should really know +/// what they are doing when using it. +bool install_custom_sink(const std::string& id, std::unique_ptr s); /// Creates a new sink that writes into the a file in the specified path and /// registers it into a sink repository so that it can be later retrieved in diff --git a/lib/src/srslog/CMakeLists.txt b/lib/src/srslog/CMakeLists.txt index de14d93bb..76ca5934b 100644 --- a/lib/src/srslog/CMakeLists.txt +++ b/lib/src/srslog/CMakeLists.txt @@ -13,9 +13,9 @@ set(SOURCES event_trace.cpp) add_subdirectory(bundled/fmt) +add_subdirectory(formatters) find_package(Threads REQUIRED) add_library(srslog STATIC ${SOURCES}) -target_link_libraries(srslog fmt "${CMAKE_THREAD_LIBS_INIT}") -INSTALL(TARGETS srslog DESTINATION ${LIBRARY_DIR}) +target_link_libraries(srslog formatters fmt "${CMAKE_THREAD_LIBS_INIT}") diff --git a/lib/src/srslog/backend_worker.cpp b/lib/src/srslog/backend_worker.cpp index 1d551cd85..f45721f53 100644 --- a/lib/src/srslog/backend_worker.cpp +++ b/lib/src/srslog/backend_worker.cpp @@ -11,9 +11,7 @@ */ #include "backend_worker.h" -#include "formatter.h" #include "srslte/srslog/sink.h" -#include using namespace srslog; @@ -90,13 +88,14 @@ void backend_worker::process_log_entry(detail::log_entry&& entry) return; } - // Save sink pointer before moving the entry. - sink* s = entry.s; + fmt::memory_buffer fmt_buffer; - std::string result = format_log_entry_to_text(std::move(entry)); - detail::memory_buffer buffer(result); + assert(entry.format_func && "Invalid format function"); + entry.format_func(std::move(entry.metadata), fmt_buffer); - if (auto err_str = s->write(buffer)) { + const auto str = fmt::to_string(fmt_buffer); + detail::memory_buffer buffer(str); + if (auto err_str = entry.s->write(buffer)) { err_handler(err_str.get_error()); } } diff --git a/lib/src/srslog/event_trace.cpp b/lib/src/srslog/event_trace.cpp index 8b9162008..e039bfe85 100644 --- a/lib/src/srslog/event_trace.cpp +++ b/lib/src/srslog/event_trace.cpp @@ -12,7 +12,6 @@ #include "srslte/srslog/event_trace.h" #include "srslte/srslog/srslog.h" -#include #include #undef trace_duration_begin diff --git a/lib/src/srslog/formatter.h b/lib/src/srslog/formatter.h deleted file mode 100644 index ea7d58c9b..000000000 --- a/lib/src/srslog/formatter.h +++ /dev/null @@ -1,87 +0,0 @@ -/** - * - * \section COPYRIGHT - * - * Copyright 2013-2020 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_FORMATTER_H -#define SRSLOG_FORMATTER_H - -#include "srslte/srslog/bundled/fmt/chrono.h" -#include "srslte/srslog/bundled/fmt/ranges.h" -#include "srslte/srslog/detail/log_entry.h" - -namespace srslog { - -namespace detail { - -/// Formats into a hex dump a range of elements, storing the result in the input -/// buffer. -inline 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)); - - fmt::format_to(buffer, - " {:04x}: {:02x}\n", - std::distance(v.cbegin(), i), - fmt::join(i, i + num_elements, " ")); - - std::advance(i, num_elements); - } -} - -} // namespace detail - -/// Formats to text all the fields of a log entry, -inline std::string format_log_entry_to_text(detail::log_entry&& entry) -{ - fmt::memory_buffer buffer; - - // Time stamp data preparation. - std::tm current_time = - fmt::gmtime(std::chrono::high_resolution_clock::to_time_t(entry.tp)); - auto us_fraction = std::chrono::duration_cast( - entry.tp.time_since_epoch()) - .count() % - 1000000u; - fmt::format_to(buffer, "{:%H:%M:%S}.{:06} ", current_time, us_fraction); - - // Format optional fields if present. - if (!entry.log_name.empty()) { - fmt::format_to(buffer, "[{: <4.4}] ", entry.log_name); - } - if (entry.log_tag != '\0') { - fmt::format_to(buffer, "[{}] ", entry.log_tag); - } - if (entry.context.enabled) { - fmt::format_to(buffer, "[{:5}] ", entry.context.value); - } - - // Message formatting. - fmt::format_to( - buffer, "{}\n", fmt::vsprintf(entry.fmtstring, std::move(entry.store))); - - // Optional hex dump formatting. - detail::format_hex_dump(entry.hex_dump, buffer); - - return fmt::to_string(buffer); -} - -} // namespace srslog - -#endif // SRSLOG_FORMATTER_H diff --git a/lib/src/srslog/sink_repository.h b/lib/src/srslog/sink_repository.h deleted file mode 100644 index bd506d2fe..000000000 --- a/lib/src/srslog/sink_repository.h +++ /dev/null @@ -1,114 +0,0 @@ -/** - * - * \section COPYRIGHT - * - * Copyright 2013-2020 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_SINK_REPOSITORY_H -#define SRSLOG_SINK_REPOSITORY_H - -#include "object_repository.h" -#include "sinks/stream_sink.h" - -namespace srslog { - -/// The sink repository stores sink instances associated to an id. Both stdout -/// and stderr stream sinks are created on construction so they accessible -/// without the need of creating them previously. -/// NOTE: Thread safe class. -class sink_repository -{ - /// Identifiers for stdout and stderr sinks. - static constexpr char stdout_id[] = "stdout#"; - static constexpr char stderr_id[] = "stderr#"; - - object_repository > repo; - -public: - sink_repository() - { - //:TODO: GCC5 or lower versions emits an error if we use the new() expression directly, use redundant - //piecewise_construct instead. - repo.emplace(std::piecewise_construct, - std::forward_as_tuple(stdout_id), - std::forward_as_tuple(new stream_sink(sink_stream_type::stdout))); - repo.emplace(std::piecewise_construct, - std::forward_as_tuple(stderr_id), - std::forward_as_tuple(new stream_sink(sink_stream_type::stderr))); - } - - /// Returns the instance of the sink that writes to stdout. - sink& get_stdout_sink() - { - auto s = repo.find(stdout_id); - assert(s && "stdout sink should always exist"); - return *(s->get()); - } - const sink& get_stdout_sink() const - { - const auto s = repo.find(stdout_id); - assert(s && "stdout sink should always exist"); - return *(s->get()); - } - - /// Returns the instance of the sink that writes to stderr. - sink& get_stderr_sink() - { - auto s = repo.find(stderr_id); - assert(s && "stderr sink should always exist"); - return *(s->get()); - } - const sink& get_stderr_sink() const - { - const auto s = repo.find(stderr_id); - assert(s && "stderr sink should always exist"); - return *(s->get()); - } - - /// Finds a sink with the specified id in the repository. Returns a pointer to - /// the sink, otherwise nullptr if not found. - sink* find(const std::string& id) - { - auto p = repo.find(id); - return (p) ? p->get() : nullptr; - } - const sink* find(const std::string& id) const - { - const auto p = repo.find(id); - return (p) ? p->get() : nullptr; - } - - /// Returns an instance of a sink specified by the input arguments. - template - sink& fetch_sink(Args&&... args) - { - return *repo.emplace(std::forward(args)...); - } - - /// Returns a copy of the list of registered sinks. - std::vector contents() const - { - auto repo_contents = repo.contents(); - - std::vector data; - data.reserve(repo_contents.size()); - for (const auto& s : repo_contents) { - data.push_back(s->get()); - } - - return data; - } -}; - -constexpr char sink_repository::stdout_id[]; -constexpr char sink_repository::stderr_id[]; - -} // namespace srslog - -#endif // SRSLOG_SINK_REPOSITORY_H diff --git a/lib/src/srslog/sinks/file_sink.h b/lib/src/srslog/sinks/file_sink.h index 60dc8f6c9..3e7c085fd 100644 --- a/lib/src/srslog/sinks/file_sink.h +++ b/lib/src/srslog/sinks/file_sink.h @@ -15,7 +15,6 @@ #include "file_utils.h" #include "srslte/srslog/sink.h" -#include namespace srslog { @@ -25,7 +24,10 @@ namespace srslog { class file_sink : public sink { public: - file_sink(std::string name, size_t max_size) : + file_sink(std::string name, + size_t max_size, + std::unique_ptr f) : + sink(std::move(f)), base_filename(std::move(name)), max_size((max_size == 0) ? 0 : std::max(max_size, 4 * 1024)) {} @@ -33,8 +35,6 @@ public: file_sink(const file_sink& other) = delete; file_sink& operator=(const file_sink& other) = delete; - ~file_sink() override { handler.close(); } - detail::error_string write(detail::memory_buffer buffer) override { // Create a new file the first time we hit this method. diff --git a/lib/src/srslog/sinks/file_utils.h b/lib/src/srslog/sinks/file_utils.h index 77315a1e2..4499568ec 100644 --- a/lib/src/srslog/sinks/file_utils.h +++ b/lib/src/srslog/sinks/file_utils.h @@ -85,7 +85,7 @@ public: explicit operator bool() const { return handle; } /// Returns the handle of the underlying file. - std::FILE* get_handle() { return handle; } + std::FILE* get_handle() const { return handle; } /// Returns the path of the file. const std::string& get_path() const { return path; } @@ -101,8 +101,8 @@ public: return {}; } - return format_error(fmt::format("Unable to create log file \"{}\"", path), - errno); + return format_error( + fmt::format("Unable to create log file \"{}\"", new_path), errno); } /// Writes the provided memory buffer into an open file, otherwise does @@ -112,9 +112,10 @@ public: if (handle && std::fwrite(buffer.data(), sizeof(char), buffer.size(), handle) != buffer.size()) { + auto err_str = format_error( + fmt::format("Unable to write log file \"{}\"", path), errno); close(); - return format_error(fmt::format("Unable to write log file \"{}\"", path), - errno); + return err_str; } return {}; @@ -124,10 +125,11 @@ public: detail::error_string flush() { if (handle && ::fflush(handle) == EOF) { - close(); - return format_error( + auto err_str = format_error( fmt::format("Error encountered while flushing log file \"{}\"", path), errno); + close(); + return err_str; } return {}; diff --git a/lib/src/srslog/sinks/stream_sink.h b/lib/src/srslog/sinks/stream_sink.h index 2cc142c97..7404a17db 100644 --- a/lib/src/srslog/sinks/stream_sink.h +++ b/lib/src/srslog/sinks/stream_sink.h @@ -14,8 +14,6 @@ #define SRSLOG_STREAM_SINK_H #include "srslte/srslog/sink.h" -#include -#include namespace srslog { @@ -26,7 +24,8 @@ enum class sink_stream_type { stdout, stderr }; class stream_sink : public sink { public: - explicit stream_sink(sink_stream_type s) : + stream_sink(sink_stream_type s, std::unique_ptr f) : + sink(std::move(f)), handle((s == sink_stream_type::stdout) ? stdout : stderr) {} diff --git a/lib/src/srslog/srslog.cpp b/lib/src/srslog/srslog.cpp index bc211bbc6..9d416e328 100644 --- a/lib/src/srslog/srslog.cpp +++ b/lib/src/srslog/srslog.cpp @@ -11,6 +11,7 @@ */ #include "srslte/srslog/srslog.h" +#include "formatters/json_formatter.h" #include "sinks/file_sink.h" #include "srslog_instance.h" @@ -27,10 +28,13 @@ static std::string remove_sharp_chars(const std::string& s) /// Generic argument function that fetches a log channel from the repository. template -static log_channel& fetch_log_channel_helper(const std::string& id, Args&&... args) +static log_channel& fetch_log_channel_helper(const std::string& id, + Args&&... args) { return srslog_instance::get().get_channel_repo().emplace( - std::piecewise_construct, std::forward_as_tuple(id), std::forward_as_tuple(id, std::forward(args)...)); + std::piecewise_construct, + std::forward_as_tuple(id), + std::forward_as_tuple(id, std::forward(args)...)); } /// @@ -46,18 +50,46 @@ log_channel& srslog::fetch_log_channel(const std::string& id) { assert(!id.empty() && "Empty id string"); - std::string clean_id = remove_sharp_chars(id); + std::string clean_id = remove_sharp_chars(id); srslog_instance& instance = srslog_instance::get(); - return fetch_log_channel_helper(clean_id, instance.get_default_sink(), instance.get_backend()); + return fetch_log_channel_helper( + clean_id, instance.get_default_sink(), instance.get_backend()); } -log_channel& srslog::fetch_log_channel(const std::string& id, sink& s, log_channel_config config) +log_channel& srslog::fetch_log_channel(const std::string& id, + sink& s, + log_channel_config config) { assert(!id.empty() && "Empty id string"); - std::string clean_id = remove_sharp_chars(id); + std::string clean_id = remove_sharp_chars(id); srslog_instance& instance = srslog_instance::get(); - return fetch_log_channel_helper(clean_id, s, instance.get_backend(), std::move(config)); + return fetch_log_channel_helper( + clean_id, s, instance.get_backend(), std::move(config)); +} + +/// +/// Formatter management functions. +/// + +void srslog::set_default_log_formatter(std::unique_ptr f) +{ + srslog_instance::get().set_default_formatter(std::move(f)); +} + +std::unique_ptr srslog::get_default_log_formatter() +{ + return srslog_instance::get().get_default_formatter(); +} + +std::unique_ptr srslog::create_text_formatter() +{ + return std::unique_ptr(new text_formatter); +} + +std::unique_ptr srslog::create_json_formatter() +{ + return std::unique_ptr(new json_formatter); } /// @@ -76,29 +108,65 @@ sink& srslog::get_default_sink() sink* srslog::find_sink(const std::string& id) { - return srslog_instance::get().get_sink_repo().find(id); + auto ptr = srslog_instance::get().get_sink_repo().find(id); + return (ptr) ? ptr->get() : nullptr; } -sink& srslog::fetch_stdout_sink() +sink& srslog::fetch_stdout_sink(const std::string& id, + std::unique_ptr f) { - return srslog_instance::get().get_sink_repo().get_stdout_sink(); + assert(!id.empty() && "Empty id string"); + + auto& s = srslog_instance::get().get_sink_repo().emplace( + std::piecewise_construct, + std::forward_as_tuple(id), + std::forward_as_tuple( + new stream_sink(sink_stream_type::stdout, std::move(f)))); + + return *s; } -sink& srslog::fetch_stderr_sink() +sink& srslog::fetch_stderr_sink(const std::string& id, + std::unique_ptr f) { - return srslog_instance::get().get_sink_repo().get_stderr_sink(); + assert(!id.empty() && "Empty id string"); + + auto& s = srslog_instance::get().get_sink_repo().emplace( + std::piecewise_construct, + std::forward_as_tuple(id), + std::forward_as_tuple( + new stream_sink(sink_stream_type::stderr, std::move(f)))); + + return *s; } -sink& srslog::fetch_file_sink(const std::string& path, size_t max_size) +sink& srslog::fetch_file_sink(const std::string& path, + size_t max_size, + std::unique_ptr f) { assert(!path.empty() && "Empty path string"); - std::string clean_path = remove_sharp_chars(path); - //:TODO: GCC5 or lower versions emits an error if we use the new() expression directly, use redundant - // piecewise_construct instead. - return srslog_instance::get().get_sink_repo().fetch_sink(std::piecewise_construct, - std::forward_as_tuple(clean_path), - std::forward_as_tuple(new file_sink(clean_path, max_size))); + //:TODO: GCC5 or lower versions emits an error if we use the new() expression + // directly, use redundant piecewise_construct instead. + auto& s = srslog_instance::get().get_sink_repo().emplace( + std::piecewise_construct, + std::forward_as_tuple(path), + std::forward_as_tuple(new file_sink(path, max_size, std::move(f)))); + + return *s; +} + +bool srslog::install_custom_sink(const std::string& id, std::unique_ptr s) +{ + assert(!id.empty() && "Empty path string"); + + sink* input_sink = s.get(); + sink* returned_sink = + srslog_instance::get().get_sink_repo().emplace(id, std::move(s)).get(); + + // Successful insertion occurs when the returned object is the same one as the + // input object. + return input_sink == returned_sink; } /// @@ -122,9 +190,16 @@ void srslog::flush() // The backend will set this shared variable when done. detail::shared_variable completion_flag(false); + auto sink_ptrs = instance.get_sink_repo().contents(); + std::vector sinks; + sinks.reserve(sink_ptrs.size()); + for (const auto& s : sink_ptrs) { + sinks.push_back(s->get()); + } + detail::log_entry cmd; cmd.flush_cmd = std::unique_ptr( - new detail::flush_backend_cmd{completion_flag, instance.get_sink_repo().contents()}); + new detail::flush_backend_cmd{completion_flag, std::move(sinks)}); instance.get_backend().push(std::move(cmd)); @@ -148,10 +223,12 @@ detail::any* srslog::detail::find_logger(const std::string& id) return srslog_instance::get().get_logger_repo().find(id); } -detail::any* srslog::detail::fetch_logger(const std::string& id, detail::any&& logger) +detail::any* srslog::detail::fetch_logger(const std::string& id, + detail::any&& logger) { assert(!id.empty() && "Empty id string"); - return &srslog_instance::get().get_logger_repo().emplace(id, std::move(logger)); + return &srslog_instance::get().get_logger_repo().emplace(id, + std::move(logger)); } /// Builds a logger name out of the id and tag. @@ -161,7 +238,9 @@ static std::string build_logger_name(const std::string& id, char tag) } /// Fetches a logger with all its log channels. -static basic_logger& fetch_basic_logger_helper(const std::string& id, sink& s, bool should_print_context) +static basic_logger& fetch_basic_logger_helper(const std::string& id, + sink& s, + bool should_print_context) { static constexpr char basic_logger_chan_tags[] = {'E', 'W', 'I', 'D'}; @@ -170,36 +249,41 @@ static basic_logger& fetch_basic_logger_helper(const std::string& id, sink& s, b // User created log channels cannot have ids with a # character, encode the // ids here with a # to ensure all channels are unique. - log_channel& error = - fetch_log_channel_helper(build_logger_name(id, basic_logger_chan_tags[0]), - s, - instance.get_backend(), - log_channel_config{id, basic_logger_chan_tags[0], should_print_context}); - log_channel& warning = - fetch_log_channel_helper(build_logger_name(id, basic_logger_chan_tags[1]), - s, - instance.get_backend(), - log_channel_config{id, basic_logger_chan_tags[1], should_print_context}); - log_channel& info = fetch_log_channel_helper(build_logger_name(id, basic_logger_chan_tags[2]), - s, - instance.get_backend(), - log_channel_config{id, basic_logger_chan_tags[2], should_print_context}); - log_channel& debug = - fetch_log_channel_helper(build_logger_name(id, basic_logger_chan_tags[3]), - s, - instance.get_backend(), - log_channel_config{id, basic_logger_chan_tags[3], should_print_context}); + log_channel& error = fetch_log_channel_helper( + build_logger_name(id, basic_logger_chan_tags[0]), + s, + instance.get_backend(), + log_channel_config{id, basic_logger_chan_tags[0], should_print_context}); + log_channel& warning = fetch_log_channel_helper( + build_logger_name(id, basic_logger_chan_tags[1]), + s, + instance.get_backend(), + log_channel_config{id, basic_logger_chan_tags[1], should_print_context}); + log_channel& info = fetch_log_channel_helper( + build_logger_name(id, basic_logger_chan_tags[2]), + s, + instance.get_backend(), + log_channel_config{id, basic_logger_chan_tags[2], should_print_context}); + log_channel& debug = fetch_log_channel_helper( + build_logger_name(id, basic_logger_chan_tags[3]), + s, + instance.get_backend(), + log_channel_config{id, basic_logger_chan_tags[3], should_print_context}); return fetch_logger(id, error, warning, info, debug); } -basic_logger& srslog::fetch_basic_logger(const std::string& id, bool should_print_context) +basic_logger& srslog::fetch_basic_logger(const std::string& id, + bool should_print_context) { assert(!id.empty() && "Empty id string"); - return fetch_basic_logger_helper(id, srslog_instance::get().get_default_sink(), should_print_context); + return fetch_basic_logger_helper( + id, srslog_instance::get().get_default_sink(), should_print_context); } -basic_logger& srslog::fetch_basic_logger(const std::string& id, sink& s, bool should_print_context) +basic_logger& srslog::fetch_basic_logger(const std::string& id, + sink& s, + bool should_print_context) { assert(!id.empty() && "Empty id string"); return fetch_basic_logger_helper(id, s, should_print_context); @@ -211,28 +295,33 @@ basic_logger& srslog::fetch_basic_logger(const std::string& id, sink& s, bool sh /// Creates and registers a log channel. Returns a pointer to the newly created /// channel on success, otherwise nullptr. -static log_channel* create_and_register_log_channel(const std::string& id, sink& s) +static log_channel* create_and_register_log_channel(const std::string& id, + sink& s) { assert(!id.empty() && "Empty id string"); srslog_instance& instance = srslog_instance::get(); auto& p = instance.get_channel_repo().emplace( - std::piecewise_construct, std::forward_as_tuple(id), std::forward_as_tuple(id, s, instance.get_backend())); + std::piecewise_construct, + std::forward_as_tuple(id), + std::forward_as_tuple(id, s, instance.get_backend())); return &p; } -static log_channel* create_and_register_log_channel(const std::string& id, log_channel_config config, sink& s) +static log_channel* create_and_register_log_channel(const std::string& id, + log_channel_config config, + sink& s) { assert(!id.empty() && "Empty id string"); srslog_instance& instance = srslog_instance::get(); - auto& p = - instance.get_channel_repo().emplace(std::piecewise_construct, - std::forward_as_tuple(id), - std::forward_as_tuple(id, s, instance.get_backend(), std::move(config))); + auto& p = instance.get_channel_repo().emplace( + std::piecewise_construct, + std::forward_as_tuple(id), + std::forward_as_tuple(id, s, instance.get_backend(), std::move(config))); return &p; } @@ -255,23 +344,32 @@ log_channel* srslog::create_log_channel(const std::string& id, sink& s) sink* srslog::create_stdout_sink(const std::string& name) { - return &srslog_instance::get().get_sink_repo().get_stdout_sink(); + return srslog_instance::get().get_sink_repo().find("stdout")->get(); } sink* srslog::create_stderr_sink(const std::string& name) { - return &srslog_instance::get().get_sink_repo().get_stderr_sink(); + return srslog_instance::get().get_sink_repo().find("stderr")->get(); } sink* srslog::create_file_sink(const std::string& path, size_t max_size) { - //:TODO: GCC5 or lower versions emits an error if we use the new() expression directly, use redundant - // piecewise_construct instead. - return &srslog_instance::get().get_sink_repo().fetch_sink( - std::piecewise_construct, std::forward_as_tuple(path), std::forward_as_tuple(new file_sink(path, max_size))); + //:TODO: GCC5 or lower versions emits an error if we use the new() expression + // directly, use redundant piecewise_construct instead. + return srslog_instance::get() + .get_sink_repo() + .emplace(std::piecewise_construct, + std::forward_as_tuple(path), + std::forward_as_tuple(new file_sink( + path, + max_size, + std::unique_ptr(new text_formatter)))) + .get(); } -basic_logger* srslog::create_basic_logger(const std::string& id, sink& s, bool should_print_context) +basic_logger* srslog::create_basic_logger(const std::string& id, + sink& s, + bool should_print_context) { assert(!id.empty() && "Empty id string"); @@ -289,16 +387,24 @@ basic_logger* srslog::create_basic_logger(const std::string& id, sink& s, bool s // without any id clashes. log_channel* error = create_and_register_log_channel( - build_logger_name(id, basic_logger_chan_tags[0]), {id, basic_logger_chan_tags[0], should_print_context}, s); + build_logger_name(id, basic_logger_chan_tags[0]), + {id, basic_logger_chan_tags[0], should_print_context}, + s); assert(error && "Could not create channel"); log_channel* warning = create_and_register_log_channel( - build_logger_name(id, basic_logger_chan_tags[1]), {id, basic_logger_chan_tags[1], should_print_context}, s); + build_logger_name(id, basic_logger_chan_tags[1]), + {id, basic_logger_chan_tags[1], should_print_context}, + s); assert(warning && "Could not create channel"); log_channel* info = create_and_register_log_channel( - build_logger_name(id, basic_logger_chan_tags[2]), {id, basic_logger_chan_tags[2], should_print_context}, s); + build_logger_name(id, basic_logger_chan_tags[2]), + {id, basic_logger_chan_tags[2], should_print_context}, + s); assert(info && "Could not create channel"); log_channel* debug = create_and_register_log_channel( - build_logger_name(id, basic_logger_chan_tags[3]), {id, basic_logger_chan_tags[3], should_print_context}, s); + build_logger_name(id, basic_logger_chan_tags[3]), + {id, basic_logger_chan_tags[3], should_print_context}, + s); assert(debug && "Could not create channel"); return create_logger(id, *error, *warning, *info, *debug); diff --git a/lib/src/srslog/srslog_c.cpp b/lib/src/srslog/srslog_c.cpp index 1f58637cf..c89a1a593 100644 --- a/lib/src/srslog/srslog_c.cpp +++ b/lib/src/srslog/srslog_c.cpp @@ -12,7 +12,6 @@ #include "srslte/srslog/srslog_c.h" #include "srslte/srslog/srslog.h" -#include #include using namespace srslog; diff --git a/lib/src/srslog/srslog_instance.h b/lib/src/srslog/srslog_instance.h index 682947bb3..bdc1fac93 100644 --- a/lib/src/srslog/srslog_instance.h +++ b/lib/src/srslog/srslog_instance.h @@ -13,9 +13,10 @@ #ifndef SRSLOG_SRSLOG_INSTANCE_H #define SRSLOG_SRSLOG_INSTANCE_H +#include "formatters/text_formatter.h" #include "log_backend_impl.h" -#include "sink_repository.h" -#include "srslte/srslog/detail/support/any.h" +#include "object_repository.h" +#include "sinks/stream_sink.h" #include "srslte/srslog/log_channel.h" namespace srslog { @@ -23,7 +24,29 @@ namespace srslog { /// Singleton of the framework containing all the required classes. class srslog_instance { - srslog_instance() { default_sink = &sink_repo.get_stdout_sink(); } + srslog_instance() + { + // stdout and stderr sinks are always present. + auto& stdout_sink = sink_repo.emplace( + std::piecewise_construct, + std::forward_as_tuple("stdout"), + std::forward_as_tuple(new stream_sink( + sink_stream_type::stdout, + std::unique_ptr(new text_formatter)))); + default_sink = stdout_sink.get(); + + sink_repo.emplace(std::piecewise_construct, + std::forward_as_tuple("stderr"), + std::forward_as_tuple(new stream_sink( + sink_stream_type::stderr, + std::unique_ptr(new text_formatter)))); + + // Initialize the default formatter pointer with a text formatter. + { + detail::scoped_lock lock(formatter_mutex); + default_formatter = std::unique_ptr(new text_formatter); + } + } public: srslog_instance(const srslog_instance& other) = delete; @@ -47,8 +70,9 @@ public: const channel_repo_type& get_channel_repo() const { return channel_repo; } /// Sink repository accessor. - sink_repository& get_sink_repo() { return sink_repo; } - const sink_repository& get_sink_repo() const { return sink_repo; } + using sink_repo_type = object_repository>; + sink_repo_type& get_sink_repo() { return sink_repo; } + const sink_repo_type& get_sink_repo() const { return sink_repo; } /// Backend accessor. detail::log_backend& get_backend() { return backend; } @@ -64,16 +88,32 @@ public: void set_default_sink(sink& s) { default_sink = &s; } /// Returns the default sink. - sink& get_default_sink() { return *default_sink; } + sink& get_default_sink() const { return *default_sink; } + + /// Set the specified formatter as the default one. + void set_default_formatter(std::unique_ptr f) + { + detail::scoped_lock lock(formatter_mutex); + default_formatter = std::move(f); + } + + /// Returns the default formatter. + std::unique_ptr get_default_formatter() const + { + detail::scoped_lock lock(formatter_mutex); + return default_formatter->clone(); + } private: /// NOTE: The order of declaration of each member is important here for proper /// destruction. - sink_repository sink_repo; + sink_repo_type sink_repo; log_backend_impl backend; channel_repo_type channel_repo; logger_repo_type logger_repo; detail::shared_variable default_sink{nullptr}; + mutable detail::mutex formatter_mutex; + std::unique_ptr default_formatter; }; } // namespace srslog diff --git a/lib/test/srslog/CMakeLists.txt b/lib/test/srslog/CMakeLists.txt index 96bce2449..7209b87df 100644 --- a/lib/test/srslog/CMakeLists.txt +++ b/lib/test/srslog/CMakeLists.txt @@ -42,7 +42,17 @@ add_definitions(-DENABLE_SRSLOG_EVENT_TRACE) target_link_libraries(tracer_test srslog) add_test(tracer_test tracer_test) -add_executable(formatter_test formatter_test.cpp) -target_include_directories(formatter_test PUBLIC ../../) -target_link_libraries(formatter_test srslog) -add_test(formatter_test formatter_test) +#:TODO: re-enable test. +#add_executable(text_formatter_test text_formatter_test.cpp) +#target_include_directories(text_formatter_test PUBLIC ../../) +#target_link_libraries(text_formatter_test srslog) +#add_test(text_formatter_test text_formatter_test) + +add_executable(json_formatter_test json_formatter_test.cpp) +target_include_directories(json_formatter_test PUBLIC ../../) +target_link_libraries(json_formatter_test srslog) +add_test(json_formatter_test json_formatter_test) + +add_executable(context_test context_test.cpp) +target_link_libraries(context_test srslog) +add_test(context_test context_test) diff --git a/lib/test/srslog/event_trace_test.cpp b/lib/test/srslog/event_trace_test.cpp index b952b8f33..a6c3fbe2e 100644 --- a/lib/test/srslog/event_trace_test.cpp +++ b/lib/test/srslog/event_trace_test.cpp @@ -12,25 +12,13 @@ #include "srslte/srslog/event_trace.h" #include "srslte/srslog/log_channel.h" -#include "srslte/srslog/sink.h" +#include "test_dummies.h" #include "testing_helpers.h" using namespace srslog; namespace { -/// A Dummy implementation of a sink. -class sink_dummy : public sink -{ -public: - detail::error_string write(detail::memory_buffer buffer) override - { - return {}; - } - - detail::error_string flush() override { return {}; } -}; - /// A Spy implementation of a log backend. Tests can query if the push method /// has been invoked. class backend_spy : public detail::log_backend @@ -38,11 +26,7 @@ class backend_spy : public detail::log_backend public: void start() override {} - void push(detail::log_entry&& entry) override - { - std::string result = fmt::vsprintf(entry.fmtstring, std::move(entry.store)); - ++count; - } + void push(detail::log_entry&& entry) override { ++count; } bool is_running() const override { return true; } @@ -81,7 +65,7 @@ when_tracing_with_complete_event_then_one_event_is_generated(backend_spy& spy) int main() { - sink_dummy s; + test_dummies::sink_dummy s; backend_spy backend; log_channel c("test", s, backend); diff --git a/lib/test/srslog/file_sink_test.cpp b/lib/test/srslog/file_sink_test.cpp index ba7f12c41..f17b2a6fa 100644 --- a/lib/test/srslog/file_sink_test.cpp +++ b/lib/test/srslog/file_sink_test.cpp @@ -12,6 +12,7 @@ #include "file_test_utils.h" #include "src/srslog/sinks/file_sink.h" +#include "test_dummies.h" #include "testing_helpers.h" using namespace srslog; @@ -21,7 +22,10 @@ static constexpr char log_filename[] = "file_sink_test.log"; static bool when_data_is_written_to_file_then_contents_are_valid() { file_test_utils::scoped_file_deleter deleter(log_filename); - file_sink file(log_filename, 0); + file_sink file( + log_filename, + 0, + std::unique_ptr(new test_dummies::log_formatter_dummy)); std::vector entries; for (unsigned i = 0; i != 10; ++i) { @@ -45,7 +49,10 @@ class file_sink_subclass : public file_sink { public: file_sink_subclass(std::string name, size_t max_size) : - file_sink(std::move(name), max_size) + file_sink( + std::move(name), + max_size, + std::unique_ptr(new test_dummies::log_formatter_dummy)) {} uint32_t get_num_of_files() const { return get_file_index(); } diff --git a/lib/test/srslog/formatter_test.cpp b/lib/test/srslog/formatter_test.cpp deleted file mode 100644 index 3e553947f..000000000 --- a/lib/test/srslog/formatter_test.cpp +++ /dev/null @@ -1,112 +0,0 @@ -/** - * - * \section COPYRIGHT - * - * Copyright 2013-2020 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. - * - */ - -#include "src/srslog/formatter.h" -#include "testing_helpers.h" -#include - -using namespace srslog; - -/// Helper to build a log entry. -static detail::log_entry build_log_entry() -{ - // 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); - - return {nullptr, tp, {10, true}, "Text %d", std::move(store), "ABC", 'Z'}; -} - -static bool when_fully_filled_log_entry_then_result_everything_is_formatted() -{ - std::string result = format_log_entry_to_text(build_log_entry()); - std::string expected = "00:00:00.050000 [ABC ] [Z] [ 10] Text 88\n"; - - ASSERT_EQ(result, expected); - - return true; -} - -static bool when_log_entry_without_name_is_passed_then_name_is_not_formatted() -{ - auto entry = build_log_entry(); - entry.log_name = ""; - - std::string result = format_log_entry_to_text(std::move(entry)); - std::string expected = "00:00:00.050000 [Z] [ 10] Text 88\n"; - - ASSERT_EQ(result, expected); - - return true; -} - -static bool when_log_entry_without_tag_is_passed_then_tag_is_not_formatted() -{ - auto entry = build_log_entry(); - entry.log_tag = '\0'; - - std::string result = format_log_entry_to_text(std::move(entry)); - std::string expected = "00:00:00.050000 [ABC ] [ 10] Text 88\n"; - - ASSERT_EQ(result, expected); - - return true; -} - -static bool -when_log_entry_without_context_is_passed_then_context_is_not_formatted() -{ - auto entry = build_log_entry(); - entry.context.enabled = false; - - std::string result = format_log_entry_to_text(std::move(entry)); - std::string expected = "00:00:00.050000 [ABC ] [Z] Text 88\n"; - - ASSERT_EQ(result, expected); - - return true; -} - -static bool when_log_entry_with_hex_dump_is_passed_then_hex_dump_is_formatted() -{ - auto entry = build_log_entry(); - entry.hex_dump.resize(20); - std::iota(entry.hex_dump.begin(), entry.hex_dump.end(), 0); - - std::string result = format_log_entry_to_text(std::move(entry)); - 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); - - return true; -} - -int main() -{ - TEST_FUNCTION( - when_fully_filled_log_entry_then_result_everything_is_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); - - return 0; -} diff --git a/lib/test/srslog/log_backend_test.cpp b/lib/test/srslog/log_backend_test.cpp index d13ad06d1..28a81714d 100644 --- a/lib/test/srslog/log_backend_test.cpp +++ b/lib/test/srslog/log_backend_test.cpp @@ -11,7 +11,7 @@ */ #include "src/srslog/log_backend_impl.h" -#include "srslte/srslog/sink.h" +#include "test_dummies.h" #include "testing_helpers.h" using namespace srslog; @@ -46,6 +46,10 @@ namespace { class sink_spy : public sink { public: + sink_spy() : + sink(std::unique_ptr(new test_dummies::log_formatter_dummy)) + {} + detail::error_string write(detail::memory_buffer buffer) override { ++count; @@ -88,7 +92,10 @@ static detail::log_entry build_log_entry(sink* s) fmt::dynamic_format_arg_store store; store.push_back(88); - return {s, tp, {0, false}, "Text %d", std::move(store), "", '\0'}; + return { + s, + [](detail::log_entry_metadata&& metadata, fmt::memory_buffer& buffer) {}, + {tp, {0, false}, "Text %d", std::move(store), "", '\0'}}; } static bool when_backend_is_started_then_pushed_log_entries_are_sent_to_sink() @@ -104,7 +111,27 @@ static bool when_backend_is_started_then_pushed_log_entries_are_sent_to_sink() backend.stop(); ASSERT_EQ(spy.write_invocation_count(), 1); - ASSERT_NE(spy.received_buffer().find("Text 88"), std::string::npos); + + return true; +} + +static bool when_backend_is_started_then_backend_invokes_format_func() +{ + test_dummies::sink_dummy s; + + 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; }; + backend.push(std::move(entry)); + + // Stop the backend to ensure the entry has been processed. + backend.stop(); + + ASSERT_EQ(counter, 1); return true; } @@ -117,7 +144,10 @@ namespace { class sink_error_stub : public sink { public: - explicit sink_error_stub(std::string err) : err(std::move(err)) {} + explicit sink_error_stub(std::string err) : + sink(std::unique_ptr(new test_dummies::log_formatter_dummy)), + err(std::move(err)) + {} detail::error_string write(detail::memory_buffer buffer) override { @@ -211,6 +241,7 @@ int main() 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); TEST_FUNCTION(when_empty_handler_is_used_then_backend_does_not_crash); diff --git a/lib/test/srslog/log_channel_test.cpp b/lib/test/srslog/log_channel_test.cpp index 081101bcc..377d4836b 100644 --- a/lib/test/srslog/log_channel_test.cpp +++ b/lib/test/srslog/log_channel_test.cpp @@ -11,42 +11,15 @@ */ #include "srslte/srslog/log_channel.h" -#include "srslte/srslog/sink.h" +#include "test_dummies.h" #include "testing_helpers.h" using namespace srslog; -namespace { - -/// A Dummy implementation of a sink. -class sink_dummy : public sink -{ -public: - detail::error_string write(detail::memory_buffer buffer) override - { - return {}; - } - - detail::error_string flush() override { return {}; } -}; - -/// A Dummy implementation of the log backend. -class backend_dummy : public detail::log_backend -{ -public: - void start() override {} - - void push(detail::log_entry&& entry) override {} - - bool is_running() const override { return true; } -}; - -} // namespace - static bool when_log_channel_is_created_then_id_matches_expected_value() { - backend_dummy backend; - sink_dummy s; + test_dummies::backend_dummy backend; + test_dummies::sink_dummy s; log_channel log("id", s, backend); ASSERT_EQ(log.id(), "id"); @@ -56,8 +29,8 @@ static bool when_log_channel_is_created_then_id_matches_expected_value() static bool when_log_channel_is_disabled_then_enabled_returns_false() { - backend_dummy backend; - sink_dummy s; + test_dummies::backend_dummy backend; + test_dummies::sink_dummy s; log_channel log("id", s, backend); log.set_enabled(false); @@ -69,8 +42,8 @@ static bool when_log_channel_is_disabled_then_enabled_returns_false() static bool when_log_channel_is_enabled_then_enabled_returns_true() { - backend_dummy backend; - sink_dummy s; + test_dummies::backend_dummy backend; + test_dummies::sink_dummy s; log_channel log("id", s, backend); log.set_enabled(true); @@ -112,7 +85,7 @@ static bool when_logging_in_log_channel_then_log_entry_is_pushed_into_the_backend() { backend_spy backend; - sink_dummy s; + test_dummies::sink_dummy s; log_channel log("id", s, backend); std::string fmtstring = "test"; @@ -126,7 +99,7 @@ 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; - sink_dummy s; + test_dummies::sink_dummy s; log_channel log("id", s, backend); log.set_enabled(false); @@ -141,7 +114,7 @@ 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; - sink_dummy s; + test_dummies::sink_dummy s; std::string name = "name"; char tag = 'A'; @@ -157,12 +130,15 @@ static bool when_logging_then_filled_in_log_entry_is_pushed_into_the_backend() ASSERT_EQ(backend.push_invocation_count(), 1); const detail::log_entry& entry = backend.last_entry(); - ASSERT_NE(entry.tp.time_since_epoch().count(), 0); - ASSERT_EQ(entry.context.value, ctx); - ASSERT_EQ(entry.context.enabled, true); - ASSERT_EQ(entry.fmtstring, fmtstring); - ASSERT_EQ(entry.log_name, name); - ASSERT_EQ(entry.log_tag, tag); + ASSERT_EQ(&s, entry.s); + ASSERT_NE(entry.format_func, nullptr); + ASSERT_NE(entry.metadata.tp.time_since_epoch().count(), 0); + ASSERT_EQ(entry.metadata.context.value, ctx); + ASSERT_EQ(entry.metadata.context.enabled, true); + ASSERT_EQ(entry.metadata.fmtstring, fmtstring); + ASSERT_EQ(entry.metadata.log_name, name); + ASSERT_EQ(entry.metadata.log_tag, tag); + ASSERT_EQ(entry.metadata.hex_dump.empty(), true); return true; } @@ -171,7 +147,7 @@ static bool when_logging_with_hex_dump_then_filled_in_log_entry_is_pushed_into_the_backend() { backend_spy backend; - sink_dummy s; + test_dummies::sink_dummy s; std::string name = "name"; char tag = 'A'; @@ -189,16 +165,19 @@ when_logging_with_hex_dump_then_filled_in_log_entry_is_pushed_into_the_backend() ASSERT_EQ(backend.push_invocation_count(), 1); const detail::log_entry& entry = backend.last_entry(); - ASSERT_NE(entry.tp.time_since_epoch().count(), 0); - ASSERT_EQ(entry.context.value, ctx); - ASSERT_EQ(entry.context.enabled, true); - ASSERT_EQ(entry.fmtstring, fmtstring); - ASSERT_EQ(entry.log_name, name); - ASSERT_EQ(entry.log_tag, tag); - ASSERT_EQ(entry.hex_dump.size(), 4); - ASSERT_EQ( - std::equal(entry.hex_dump.begin(), entry.hex_dump.end(), std::begin(hex)), - true); + ASSERT_EQ(&s, entry.s); + ASSERT_NE(entry.format_func, nullptr); + ASSERT_NE(entry.metadata.tp.time_since_epoch().count(), 0); + ASSERT_EQ(entry.metadata.context.value, ctx); + ASSERT_EQ(entry.metadata.context.enabled, true); + ASSERT_EQ(entry.metadata.fmtstring, fmtstring); + 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); return true; } @@ -207,10 +186,9 @@ static bool when_hex_array_length_is_less_than_hex_log_max_size_then_array_length_is_used() { backend_spy backend; - sink_dummy s; + test_dummies::sink_dummy s; std::string name = "name"; - char tag = 'A'; log_channel log("id", s, backend); @@ -223,10 +201,85 @@ when_hex_array_length_is_less_than_hex_log_max_size_then_array_length_is_used() ASSERT_EQ(backend.push_invocation_count(), 1); const detail::log_entry& entry = backend.last_entry(); - ASSERT_EQ(entry.hex_dump.size(), 3); - ASSERT_EQ( - std::equal(entry.hex_dump.begin(), entry.hex_dump.end(), std::begin(hex)), - true); + 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); + + return true; +} + +namespace { + +DECLARE_METRIC("SNR", snr_t, int, "dB"); +DECLARE_METRIC_SET("myset", my_set, snr_t); +using my_ctx = srslog::build_context_type; + +} // namespace + +static bool +when_logging_with_context_then_filled_in_log_entry_is_pushed_into_the_backend() +{ + backend_spy backend; + test_dummies::sink_dummy s; + + std::string name = "name"; + char tag = 'A'; + + log_channel log("id", s, backend, {name, tag, true}); + + uint32_t ctx_value = 4; + log.set_context(ctx_value); + + my_ctx ctx("myctx"); + log(ctx); + + ASSERT_EQ(backend.push_invocation_count(), 1); + + const detail::log_entry& entry = backend.last_entry(); + ASSERT_EQ(&s, entry.s); + ASSERT_NE(entry.format_func, nullptr); + ASSERT_NE(entry.metadata.tp.time_since_epoch().count(), 0); + ASSERT_EQ(entry.metadata.context.value, ctx_value); + ASSERT_EQ(entry.metadata.context.enabled, true); + ASSERT_EQ(entry.metadata.log_name, name); + ASSERT_EQ(entry.metadata.log_tag, tag); + ASSERT_EQ(entry.metadata.hex_dump.empty(), true); + + return true; +} + +static bool +when_logging_with_context_and_message_then_filled_in_log_entry_is_pushed_into_the_backend() +{ + backend_spy backend; + test_dummies::sink_dummy s; + + std::string name = "name"; + char tag = 'A'; + + log_channel log("id", s, backend, {name, tag, true}); + + uint32_t ctx_value = 4; + log.set_context(ctx_value); + std::string fmtstring = "test"; + + my_ctx ctx("myctx"); + log(ctx, fmtstring, 10, 3.3); + + ASSERT_EQ(backend.push_invocation_count(), 1); + + const detail::log_entry& entry = backend.last_entry(); + ASSERT_EQ(&s, entry.s); + ASSERT_NE(entry.format_func, nullptr); + ASSERT_NE(entry.metadata.tp.time_since_epoch().count(), 0); + ASSERT_EQ(entry.metadata.context.value, ctx_value); + ASSERT_EQ(entry.metadata.context.enabled, true); + ASSERT_EQ(entry.metadata.fmtstring, fmtstring); + ASSERT_EQ(entry.metadata.log_name, name); + ASSERT_EQ(entry.metadata.log_tag, tag); + ASSERT_EQ(entry.metadata.hex_dump.empty(), true); return true; } @@ -245,6 +298,10 @@ int main() 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); return 0; } diff --git a/lib/test/srslog/logger_test.cpp b/lib/test/srslog/logger_test.cpp index ba9c48de7..9b46da9e5 100644 --- a/lib/test/srslog/logger_test.cpp +++ b/lib/test/srslog/logger_test.cpp @@ -11,7 +11,7 @@ */ #include "srslte/srslog/logger.h" -#include "srslte/srslog/sink.h" +#include "test_dummies.h" #include "testing_helpers.h" using namespace srslog; @@ -20,29 +20,6 @@ static constexpr char logger_id[] = "TestLogger"; namespace { -/// A Dummy implementation of a sink. -class sink_dummy : public sink -{ -public: - detail::error_string write(detail::memory_buffer buffer) override - { - return {}; - } - - detail::error_string flush() override { return {}; } -}; - -/// A Dummy implementation of the log backend. -class backend_dummy : public detail::log_backend -{ -public: - void start() override {} - - void push(detail::log_entry&& entry) override {} - - bool is_running() const override { return true; } -}; - /// Definition of a three level logger enum class test_logger_levels { error, warning, info, LAST }; struct test_logger_channels { @@ -56,8 +33,8 @@ using test_logger = build_logger_type; static bool when_logger_is_created_then_id_matches_expected_value() { - backend_dummy backend; - sink_dummy s; + test_dummies::backend_dummy backend; + test_dummies::sink_dummy s; log_channel error("err", s, backend); log_channel warning("warning", s, backend); log_channel info("info", s, backend); @@ -71,8 +48,8 @@ static bool when_logger_is_created_then_id_matches_expected_value() static bool when_level_is_set_to_error_then_info_and_warning_is_disabled() { - backend_dummy backend; - sink_dummy s; + test_dummies::backend_dummy backend; + test_dummies::sink_dummy s; log_channel error("err", s, backend); log_channel warning("warning", s, backend); log_channel info("info", s, backend); @@ -89,8 +66,8 @@ static bool when_level_is_set_to_error_then_info_and_warning_is_disabled() static bool when_level_is_set_to_warning_then_info_is_disabled() { - backend_dummy backend; - sink_dummy s; + test_dummies::backend_dummy backend; + test_dummies::sink_dummy s; log_channel error("err", s, backend); log_channel warning("warning", s, backend); log_channel info("info", s, backend); @@ -107,8 +84,8 @@ static bool when_level_is_set_to_warning_then_info_is_disabled() static bool when_level_is_set_to_info_then_all_are_enabled() { - backend_dummy backend; - sink_dummy s; + test_dummies::backend_dummy backend; + test_dummies::sink_dummy s; log_channel error("err", s, backend); log_channel warning("warning", s, backend); log_channel info("info", s, backend); diff --git a/lib/test/srslog/srslog_test.cpp b/lib/test/srslog/srslog_test.cpp index 69d502597..74b12f3da 100644 --- a/lib/test/srslog/srslog_test.cpp +++ b/lib/test/srslog/srslog_test.cpp @@ -10,8 +10,8 @@ * */ -#include "srslte/srslog/sink.h" #include "srslte/srslog/srslog.h" +#include "test_dummies.h" #include "testing_helpers.h" using namespace srslog; @@ -26,6 +26,30 @@ static_assert(std::is_trivially_copyable::value, "Expected to be trivially copyable"); #endif +static bool when_srslog_is_created_then_stdout_and_stderr_sinks_exist() +{ + ASSERT_NE(find_sink("stdout"), nullptr); + ASSERT_NE(find_sink("stderr"), nullptr); + + return true; +} + +static bool when_no_installed_default_formatter_then_a_formatter_is_returned() +{ + ASSERT_NE(get_default_log_formatter(), nullptr); + + return true; +} + +static bool when_no_installed_default_sink_then_stdout_sink_is_used() +{ + sink& default_sink = get_default_sink(); + + ASSERT_EQ(&default_sink, find_sink("stdout")); + + return true; +} + static bool when_fetching_channel_then_channel_instance_is_returned() { log_channel& channel1 = fetch_log_channel(test_id1); @@ -70,6 +94,17 @@ when_id_with_sharps_is_passed_then_channel_is_fetched_with_clean_id() return true; } +static bool when_channel_already_exists_then_fetch_returns_channel() +{ + log_channel& channel1 = fetch_log_channel("b1"); + log_channel& channel2 = fetch_log_channel("b2", fetch_stdout_sink(), {}); + + ASSERT_EQ(&channel1, &fetch_log_channel("b1")); + ASSERT_EQ(&channel2, &fetch_log_channel("b2")); + + return true; +} + static constexpr char logger_id[] = "TestLogger"; static constexpr char basic_logger_id1[] = "BasicTestLogger"; static constexpr char basic_logger_id2[] = "BasicTestLogger2"; @@ -92,7 +127,8 @@ static bool when_fetching_logger_then_logger_instance_is_returned() static bool when_fetching_basic_logger_then_basic_logger_instance_is_returned() { basic_logger& logger1 = fetch_basic_logger(basic_logger_id1); - basic_logger& logger2 = fetch_basic_logger(basic_logger_id2, fetch_stdout_sink()); + basic_logger& logger2 = + fetch_basic_logger(basic_logger_id2, fetch_stdout_sink()); ASSERT_EQ(logger1.id(), basic_logger_id1); ASSERT_EQ(logger2.id(), basic_logger_id2); @@ -110,6 +146,17 @@ static bool when_valid_id_and_type_is_passed_then_logger_is_found() return true; } +static bool when_basic_logger_already_exists_then_fetch_returns_logger() +{ + basic_logger& logger1 = fetch_basic_logger("b1"); + basic_logger& logger2 = fetch_basic_logger("b2", fetch_stdout_sink()); + + ASSERT_EQ(&logger1, &fetch_basic_logger("b1")); + ASSERT_EQ(&logger2, &fetch_basic_logger("b2")); + + return true; +} + static bool when_invalid_id_with_valid_type_is_passed_then_no_logger_is_found() { ASSERT_EQ(find_logger("invalid"), nullptr); @@ -142,10 +189,11 @@ static constexpr char file_name[] = "file_fetch_test.txt"; static bool when_file_sink_is_fetched_then_sink_instance_is_returned() { - fetch_file_sink(file_name); - sink* s = find_sink(file_name); + sink& s1 = fetch_file_sink(file_name); + sink* s2 = find_sink(file_name); - ASSERT_NE(s, nullptr); + ASSERT_EQ(&s1, s2); + ASSERT_NE(s2, nullptr); return true; } @@ -157,37 +205,93 @@ static bool when_invalid_id_is_passed_then_no_sink_is_found() return true; } -static bool when_no_installed_default_sink_then_stdout_sink_is_used() +static bool +when_setting_stderr_as_default_then_get_default_returns_stderr_sink() { + set_default_sink(fetch_stderr_sink()); sink& default_sink = get_default_sink(); - ASSERT_EQ(&default_sink, &fetch_stdout_sink()); + ASSERT_EQ(&default_sink, &fetch_stderr_sink()); return true; } static bool -when_setting_stderr_as_default_then_get_default_returns_stderr_sink() +when_creating_non_default_stdout_and_stderr_sinks_then_they_are_created() { - set_default_sink(fetch_stderr_sink()); - sink& default_sink = get_default_sink(); + auto& out1 = fetch_stdout_sink("stdout1"); + auto& err1 = fetch_stderr_sink("stderr1"); - ASSERT_EQ(&default_sink, &fetch_stderr_sink()); + ASSERT_EQ(&out1, find_sink("stdout1")); + ASSERT_EQ(&err1, find_sink("stderr1")); + + return true; +} + +static constexpr char custom_sink_name[] = "custom_sink"; + +static bool when_setting_custom_sink_first_time_then_insertion_succeeds() +{ + std::unique_ptr custom(new test_dummies::sink_dummy); + sink* s = custom.get(); + + bool ret = install_custom_sink(custom_sink_name, std::move(custom)); + ASSERT_EQ(ret, true); + + sink* found_sink = find_sink(custom_sink_name); + ASSERT_NE(found_sink, nullptr); + ASSERT_EQ(found_sink, s); + + return true; +} + +static bool when_setting_custom_sink_twice_then_insertion_fails() +{ + std::unique_ptr custom(new test_dummies::sink_dummy); + sink* s = custom.get(); + + bool ret = install_custom_sink(custom_sink_name, std::move(custom)); + ASSERT_EQ(ret, false); + + sink* found_sink = find_sink(custom_sink_name); + ASSERT_NE(found_sink, nullptr); + ASSERT_NE(found_sink, s); + + return true; +} + +static bool +when_default_formatter_is_installed_then_getter_returns_same_formatter() +{ + auto f = + std::unique_ptr(new test_dummies::log_formatter_dummy); + set_default_log_formatter(std::move(f)); + + // Dummy formatter does not implement the clone method, thus the unique + // pointer will be nullptr. + auto f2 = get_default_log_formatter(); + ASSERT_EQ(f2.get(), nullptr); return true; } int main() { + TEST_FUNCTION(when_srslog_is_created_then_stdout_and_stderr_sinks_exist); + TEST_FUNCTION( + when_no_installed_default_formatter_then_a_formatter_is_returned); + TEST_FUNCTION(when_no_installed_default_sink_then_stdout_sink_is_used); TEST_FUNCTION(when_fetching_channel_then_channel_instance_is_returned); TEST_FUNCTION(when_valid_id_is_passed_then_channel_is_found); TEST_FUNCTION(when_non_existent_id_is_passed_then_nothing_is_found); TEST_FUNCTION( when_id_with_sharps_is_passed_then_channel_is_fetched_with_clean_id); + TEST_FUNCTION(when_channel_already_exists_then_fetch_returns_channel); TEST_FUNCTION(when_fetching_logger_then_logger_instance_is_returned); TEST_FUNCTION( when_fetching_basic_logger_then_basic_logger_instance_is_returned); TEST_FUNCTION(when_valid_id_and_type_is_passed_then_logger_is_found); + TEST_FUNCTION(when_basic_logger_already_exists_then_fetch_returns_logger); TEST_FUNCTION( when_invalid_id_with_valid_type_is_passed_then_no_logger_is_found); TEST_FUNCTION(when_invalid_id_and_type_is_passed_then_no_logger_is_found); @@ -195,9 +299,14 @@ int main() when_valid_id_with_invalid_type_is_passed_then_no_logger_is_found); TEST_FUNCTION(when_file_sink_is_fetched_then_sink_instance_is_returned); TEST_FUNCTION(when_invalid_id_is_passed_then_no_sink_is_found); - TEST_FUNCTION(when_no_installed_default_sink_then_stdout_sink_is_used); TEST_FUNCTION( when_setting_stderr_as_default_then_get_default_returns_stderr_sink); + TEST_FUNCTION( + when_creating_non_default_stdout_and_stderr_sinks_then_they_are_created); + TEST_FUNCTION(when_setting_custom_sink_first_time_then_insertion_succeeds); + TEST_FUNCTION(when_setting_custom_sink_twice_then_insertion_fails); + TEST_FUNCTION( + when_default_formatter_is_installed_then_getter_returns_same_formatter); return 0; }