From 30dcacf8b604e52c8adac67529951987b27549f2 Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Wed, 7 Aug 2024 13:59:43 +0200 Subject: [PATCH 01/47] WIP: use spdlog instead of Boost.Log Signed-off-by: Kai-Uwe Hermann --- CMakeLists.txt | 7 +- dependencies.yaml | 10 ++ include/everest/logging.hpp | 108 ++++++++++----- lib/CMakeLists.txt | 9 ++ lib/logging.cpp | 268 ++++++++++++++++++++++++++++-------- 5 files changed, 310 insertions(+), 92 deletions(-) create mode 100644 dependencies.yaml diff --git a/CMakeLists.txt b/CMakeLists.txt index 3946e0e..05a4cfb 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -1,7 +1,7 @@ cmake_minimum_required(VERSION 3.11) project(everest-log - VERSION 0.2.1 + VERSION 0.3 DESCRIPTION "EVerest logging library" LANGUAGES CXX C ) @@ -18,6 +18,11 @@ option(BUILD_EXAMPLES "Build liblog example binaries." OFF) option(LOG_INSTALL "Install the library (shared data might be installed anyway)" ${EVC_MAIN_PROJECT}) option(CMAKE_RUN_CLANG_TIDY "Run clang-tidy" OFF) option(LIBLOG_USE_BOOST_FILESYSTEM "Usage of boost/filesystem.hpp instead of std::filesystem" OFF) +option(LIBLOG_OMIT_FILE_AND_LINE_NUMBERS "Always omit file and line numbers in logs" OFF) + +if(NOT DISABLE_EDM) + evc_setup_edm() +endif() # library dependencies diff --git a/dependencies.yaml b/dependencies.yaml new file mode 100644 index 0000000..44bb715 --- /dev/null +++ b/dependencies.yaml @@ -0,0 +1,10 @@ +libfmt: + git: https://github.com/fmtlib/fmt.git + git_tag: 10.1.0 + options: + ["FMT_TEST OFF", "FMT_DOC OFF", "BUILD_SHARED_LIBS ON", "FMT_INSTALL ON"] +spdlog: + git: https://github.com/gabime/spdlog.git + git_tag: v1.14.1 + options: + ["SPDLOG_NO_TLS ON", "SPDLOG_FMT_EXTERNAL ON"] diff --git a/include/everest/logging.hpp b/include/everest/logging.hpp index 200c208..a87cda1 100644 --- a/include/everest/logging.hpp +++ b/include/everest/logging.hpp @@ -1,19 +1,18 @@ // SPDX-License-Identifier: Apache-2.0 -// Copyright 2020 - 2022 Pionix GmbH and Contributors to EVerest +// Copyright Pionix GmbH and Contributors to EVerest #ifndef LOGGING_HPP #define LOGGING_HPP +#include #include #include -#include -#include #include -#include -#include #include -#include #include + #include +#include +#include #include namespace Everest { @@ -32,34 +31,83 @@ void init(const std::string& logconf); void init(const std::string& logconf, std::string process_name); void update_process_name(std::string process_name); std::string trace(); -} // namespace Logging -// clang-format off -#define EVLOG_verbose \ - BOOST_LOG_SEV(::global_logger::get(), ::Everest::Logging::verbose) \ - << boost::log::BOOST_LOG_VERSION_NAMESPACE::add_value("file", __FILE__) \ - << boost::log::BOOST_LOG_VERSION_NAMESPACE::add_value("line", __LINE__) \ - << boost::log::BOOST_LOG_VERSION_NAMESPACE::add_value("function", BOOST_CURRENT_FUNCTION) +struct LogSource { + std::string file; + int line = 0; + std::string function; + + bool log_file = true; + bool log_line = true; + bool log_function = true; + + LogSource(const std::string& file, int line, const std::string& function) : + file(file), line(line), function(function) { + } + + LogSource(const std::string& function) : function(function), log_file(false), log_line(false) { + } +}; + +class EverestLogger { +public: + EverestLogger(const std::string& file, int line, const std::string& function, spdlog::level::level_enum level) : + file(file), line(line), function(function), level(level), log_file(true), log_line(true), log_function(true) { + } + EverestLogger(const std::string& function, spdlog::level::level_enum level) : + function(function), level(level), log_file(false), log_line(false), log_function(true) { + } + EverestLogger(spdlog::level::level_enum level) : + level(level), log_file(false), log_line(false), log_function(false) { + } -#define EVLOG_debug \ - BOOST_LOG_SEV(::global_logger::get(), ::Everest::Logging::debug) \ - << boost::log::BOOST_LOG_VERSION_NAMESPACE::add_value("function", BOOST_CURRENT_FUNCTION) + ~EverestLogger() { +#ifdef LIBLOG_OMIT_FILE_AND_LINE_NUMBERS + log_file = false; + log_line = false; +#endif + if (log_file and log_line and log_function) { + spdlog::default_logger_raw()->log(spdlog::source_loc{file.c_str(), line, function.c_str()}, level, + log.str()); + } else if ((not log_file) and (not log_line) and log_function) { + spdlog::default_logger_raw()->log(spdlog::source_loc{"", 0, function.c_str()}, level, log.str()); + } else { + spdlog::default_logger_raw()->log(level, log.str()); + } + } -#define EVLOG_info \ - BOOST_LOG_SEV(::global_logger::get(), ::Everest::Logging::info) + template EverestLogger& operator<<(T const& message) { + log << message; + return *this; + } -#define EVLOG_warning \ - BOOST_LOG_SEV(::global_logger::get(), ::Everest::Logging::warning) \ - << boost::log::BOOST_LOG_VERSION_NAMESPACE::add_value("function", BOOST_CURRENT_FUNCTION) + EverestLogger& operator<<(std::ostream& (*message)(std::ostream&)) { + log << message; + return *this; + } -#define EVLOG_error \ - BOOST_LOG_SEV(::global_logger::get(), ::Everest::Logging::error) \ - << boost::log::BOOST_LOG_VERSION_NAMESPACE::add_value("function", BOOST_CURRENT_FUNCTION) -#define EVLOG_critical \ - BOOST_LOG_SEV(::global_logger::get(), ::Everest::Logging::critical) \ - << boost::log::BOOST_LOG_VERSION_NAMESPACE::add_value("function", BOOST_CURRENT_FUNCTION) -// clang-format on + +private: + std::stringstream log; + std::string file; + int line; + std::string function; + spdlog::level::level_enum level; + bool log_file; + bool log_line; + bool log_function; +}; + +} // namespace Logging + +// clang-format off +#define EVLOG_verbose (::Everest::Logging::EverestLogger(__FILE__, __LINE__, BOOST_CURRENT_FUNCTION, spdlog::level::trace)) +#define EVLOG_debug (::Everest::Logging::EverestLogger(BOOST_CURRENT_FUNCTION, spdlog::level::debug)) +#define EVLOG_info (::Everest::Logging::EverestLogger(spdlog::level::info)) +#define EVLOG_warning (::Everest::Logging::EverestLogger(BOOST_CURRENT_FUNCTION, spdlog::level::warn)) +#define EVLOG_error (::Everest::Logging::EverestLogger(BOOST_CURRENT_FUNCTION, spdlog::level::err)) +#define EVLOG_critical (::Everest::Logging::EverestLogger(BOOST_CURRENT_FUNCTION, spdlog::level::critical)) #define EVLOG_AND_THROW(ex) \ do { \ @@ -79,8 +127,4 @@ std::string trace(); } while (0) } // namespace Everest -BOOST_LOG_INLINE_GLOBAL_LOGGER_DEFAULT( - global_logger, - boost::log::BOOST_LOG_VERSION_NAMESPACE::sources::severity_logger_mt) - #endif // LOGGING_HPP diff --git a/lib/CMakeLists.txt b/lib/CMakeLists.txt index de24462..92ca468 100644 --- a/lib/CMakeLists.txt +++ b/lib/CMakeLists.txt @@ -16,6 +16,7 @@ target_include_directories(log target_link_libraries(log PUBLIC Boost::log + spdlog::spdlog PRIVATE Boost::log_setup ) @@ -31,6 +32,14 @@ if (LIBLOG_USE_BOOST_FILESYSTEM) ) endif() +if (LIBLOG_OMIT_FILE_AND_LINE_NUMBERS) + message(STATUS "liblog: Omitting file names and line numbers in all log messages") + target_compile_definitions(log + PRIVATE + LIBLOG_OMIT_FILE_AND_LINE_NUMBERS + ) +endif() + # FIXME (aw): in case FindBoost.cmake was used we need to add things # this should be removed no support for Boost < 1.74 is needed if (NOT Boost_DIR) diff --git a/lib/logging.cpp b/lib/logging.cpp index ada2e51..f0ad9a1 100644 --- a/lib/logging.cpp +++ b/lib/logging.cpp @@ -1,23 +1,25 @@ // SPDX-License-Identifier: Apache-2.0 -// Copyright 2020 - 2023 Pionix GmbH and Contributors to EVerest +// Copyright Pionix GmbH and Contributors to EVerest #ifdef LIBLOG_USE_BOOST_FILESYSTEM #include #else #include #endif -#include -#include -#include -#include -#include -#include + +#ifdef __linux__ +#include +#endif + +#include + +#include +#include +#include #include -#include -#include -#include -#include #include -#include + +#include +#include #include #include @@ -26,7 +28,7 @@ // NOLINTNEXTLINE(cppcoreguidelines-macro-usage) #define EVEREST_INTERNAL_LOG_AND_THROW(exception) \ do { \ - BOOST_LOG_TRIVIAL(fatal) << (exception).what(); \ + spdlog::critical("{}", (exception).what()); \ throw(exception); \ } while (0); @@ -58,29 +60,165 @@ std::array severity_strings_colors = { "", // }; -std::string process_name_padding(const std::string& process_name) { - const unsigned int process_name_padding_length = 15; - std::string padded_process_name = process_name; - if (process_name_padding_length > padded_process_name.size()) - padded_process_name.insert(padded_process_name.size(), process_name_padding_length, ' '); - if (padded_process_name.size() > process_name_padding_length) - padded_process_name = padded_process_name.substr(0, process_name_padding_length); - return padded_process_name; +std::string clear_color = "\033[0m"; + +std::string current_process_name; + +std::string get_process_name() { + std::string process_name; +#ifndef __linux__ + return process_name; +#endif + // first get pid and use it to get the binary name of the running process + auto pid = getpid(); + auto proc = "/proc/" + std::to_string(pid) + "/cmdline"; + fs::path proc_path = fs::path(proc); + std::ifstream cmdline_file(proc_path.c_str()); + if (cmdline_file.is_open()) { + std::string cmdline; + cmdline_file >> cmdline; + auto cmdline_path = fs::path(cmdline); + process_name = cmdline_path.filename(); + } + return process_name; } -attrs::mutable_constant current_process_name(process_name_padding(logging::aux::get_process_name())); -// The operator puts a human-friendly representation of the severity level to the stream -std::ostream& operator<<(std::ostream& strm, severity_level level) { - if (static_cast(level) < severity_strings.size()) { - strm << severity_strings_colors.at(level) << severity_strings.at(level) << "\033[0m"; - } else { - strm << static_cast(level); + +void init(const std::string& logconf) { + init(logconf, ""); +} + +class FilterSink : public spdlog::sinks::ansicolor_stdout_sink_mt { +public: + explicit FilterSink(const logging::filter& filter) : filter(filter) { } - return strm; +protected: + logging::filter filter; + + void log(const spdlog::details::log_msg& msg) override { + if (not filter_msg(msg)) { + return; + } + + spdlog::sinks::ansicolor_stdout_sink_mt::log(msg); + } + + bool filter_msg(const spdlog::details::log_msg& msg) { + auto src = logging::attribute_set(); + // TODO: proper conversion function between msg.level an severity_level + src["Severity"] = attrs::constant(static_cast(msg.level)); + src["Process"] = attrs::constant(msg.logger_name.data()); + // FIXME: support more of the boost log Filter syntax? + auto set = logging::attribute_value_set(src, logging::attribute_set(), logging::attribute_set()); + return filter(set); + } +}; + +bool is_level(const logging::filter& filter, severity_level level) { + auto src = logging::attribute_set(); + src["Severity"] = attrs::constant(level); + src["Process"] = attrs::constant(""); + auto set = logging::attribute_value_set(src, logging::attribute_set(), logging::attribute_set()); + return filter(set); +} + +spdlog::level::level_enum get_level_from_filter(const logging::filter& filter) { + if (is_level(filter, severity_level::verbose)) { + return spdlog::level::level_enum::trace; + } else if (is_level(filter, severity_level::debug)) { + return spdlog::level::level_enum::debug; + } else if (is_level(filter, severity_level::info)) { + return spdlog::level::level_enum::info; + } else if (is_level(filter, severity_level::warning)) { + return spdlog::level::level_enum::warn; + } else if (is_level(filter, severity_level::error)) { + return spdlog::level::level_enum::err; + } else if (is_level(filter, severity_level::critical)) { + return spdlog::level::level_enum::critical; + } + return spdlog::level::level_enum::info; } +class EverestLevelFormatter : public spdlog::custom_flag_formatter { +public: + void format(const spdlog::details::log_msg& msg, const std::tm&, spdlog::memory_buf_t& dest) override { + switch (msg.level) { + case spdlog::level::level_enum::trace: { + auto& color = severity_strings_colors.at(0); + auto& verb = severity_strings.at(0); + format_message(color, verb, dest); + break; + } + case spdlog::level::level_enum::debug: { + auto& color = severity_strings_colors.at(1); + auto& debg = severity_strings.at(1); + format_message(color, debg, dest); + break; + } + case spdlog::level::level_enum::info: { + auto& color = severity_strings_colors.at(2); + auto& info = severity_strings.at(2); + format_message(color, info, dest); + break; + } + case spdlog::level::level_enum::warn: { + auto& color = severity_strings_colors.at(3); + auto& warn = severity_strings.at(3); + format_message(color, warn, dest); + break; + } + case spdlog::level::level_enum::err: { + auto& color = severity_strings_colors.at(4); + auto& erro = severity_strings.at(4); + format_message(color, erro, dest); + break; + } + case spdlog::level::level_enum::critical: { + auto& color = severity_strings_colors.at(5); + auto& crit = severity_strings.at(5); + format_message(color, crit, dest); + break; + } + case spdlog::level::level_enum::off: + break; + case spdlog::level::level_enum::n_levels: + break; + } + } + + std::unique_ptr clone() const override { + return spdlog::details::make_unique(); + } + +private: + void format_message(const std::string& color, const std::string& loglevel, spdlog::memory_buf_t& dest) { + if (not color.empty()) { + dest.append(color.data(), color.data() + color.size()); + } + dest.append(loglevel.data(), loglevel.data() + loglevel.size()); + if (not color.empty()) { + dest.append(clear_color.data(), clear_color.data() + clear_color.size()); + } + } +}; + +class EverestFuncnameFormatter : public spdlog::custom_flag_formatter { +public: + void format(const spdlog::details::log_msg& msg, const std::tm&, spdlog::memory_buf_t& dest) override { + if (msg.source.funcname == nullptr) { + return; + } + std::string funcname = msg.source.funcname; + dest.append(funcname.data(), funcname.data() + funcname.size()); + } + + std::unique_ptr clone() const override { + return spdlog::details::make_unique(); + } +}; + // The operator parses the severity level from the stream std::istream& operator>>(std::istream& strm, severity_level& level) { if (strm.good()) { @@ -100,34 +238,12 @@ std::istream& operator>>(std::istream& strm, severity_level& level) { return strm; } -void init(const std::string& logconf) { - init(logconf, ""); -} +std::shared_ptr filter_sink; void init(const std::string& logconf, std::string process_name) { - BOOST_LOG_FUNCTION(); - - // add useful attributes - logging::add_common_attributes(); - - std::string padded_process_name; + current_process_name = get_process_name(); - if (!process_name.empty()) { - padded_process_name = process_name_padding(process_name); - } - - logging::core::get()->add_global_attribute("Process", current_process_name); - if (!padded_process_name.empty()) { - current_process_name.set(padded_process_name); - } - logging::core::get()->add_global_attribute("Scope", attrs::named_scope()); - - // Before initializing the library from settings, we need to register any custom filter and formatter factories - logging::register_simple_filter_factory("Severity"); - logging::register_simple_formatter_factory("Severity"); - - // open logging.ini config file located at our base_dir and use it to configure boost::log logging (filters and - // format) + // open logging.ini config file located at our base_dir and use it to configure filters and format fs::path logging_path = fs::path(logconf); std::ifstream logging_config(logging_path.c_str()); if (!logging_config.is_open()) { @@ -136,6 +252,7 @@ void init(const std::string& logconf, std::string process_name) { } auto settings = logging::parse_settings(logging_config); + logging::register_simple_filter_factory("Severity"); auto sink = settings["Sinks.Console"].get_section(); @@ -151,17 +268,50 @@ void init(const std::string& logconf, std::string process_name) { severity_strings_colors[severity_level::critical] = sink["SeverityStringColorCritical"].get().get_value_or(""); - logging::init_from_settings(settings); + auto core = settings["Core"].get_section(); + + auto filter = core["Filter"].get().get_value_or(""); + + auto parsed_filter = logging::parse_filter(filter); + + filter_sink = std::make_shared(parsed_filter); + update_process_name(process_name); + + auto format = sink["Format"].get().get_value_or(""); + + // parse the format into a format string that spdlog can use + std::vector> replacements = {{"%TimeStamp%", "%Y-%m-%d %H:%M:%S.%f"}, + {"%Process%", "%-15!n"}, + {"%ProcessID%", "%P"}, + {"%Severity%", "%l"}, + {"%ThreadID%", "%t"}, + {"%function%", "%!"}, + {"%file%", "%s"}, + {"%line%", "%#"}, + {"%Message%", "%v"}}; + for (auto& replace : replacements) { + auto pos = format.find(replace.first); + while (pos != std::string::npos) { + format.replace(pos, replace.first.size(), replace.second); + pos = format.find(replace.first, pos + replace.second.size()); + } + } + + auto formatter = std::make_unique(); + formatter->add_flag('l').set_pattern(format); + formatter->add_flag('!').set_pattern(format); + spdlog::set_formatter(std::move(formatter)); + + spdlog::set_level(get_level_from_filter(parsed_filter)); EVLOG_debug << "Logger initialized (using " << logconf << ")..."; } void update_process_name(std::string process_name) { if (!process_name.empty()) { - std::string padded_process_name; - - padded_process_name = process_name_padding(process_name); - current_process_name.set(padded_process_name); + current_process_name = process_name; + auto filter_logger = std::make_shared(current_process_name, filter_sink); + spdlog::set_default_logger(filter_logger); } } } // namespace Logging From 182d3eb1607e982b6d938c30226b68711828a026 Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Wed, 7 Aug 2024 15:47:09 +0200 Subject: [PATCH 02/47] Initialize line with 0 Signed-off-by: Kai-Uwe Hermann --- include/everest/logging.hpp | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/include/everest/logging.hpp b/include/everest/logging.hpp index a87cda1..070fe67 100644 --- a/include/everest/logging.hpp +++ b/include/everest/logging.hpp @@ -86,12 +86,10 @@ class EverestLogger { return *this; } - - private: std::stringstream log; std::string file; - int line; + int line = 0; std::string function; spdlog::level::level_enum level; bool log_file; From 1dd6462a6d5553ca12cbdb22690b80a1a1a99b65 Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Wed, 7 Aug 2024 15:48:09 +0200 Subject: [PATCH 03/47] Replace EVLOG_AND_THROW and EVTHROW macros with constrexpr functions Signed-off-by: Kai-Uwe Hermann --- include/everest/logging.hpp | 27 +++++++++++---------------- 1 file changed, 11 insertions(+), 16 deletions(-) diff --git a/include/everest/logging.hpp b/include/everest/logging.hpp index 070fe67..313b6e7 100644 --- a/include/everest/logging.hpp +++ b/include/everest/logging.hpp @@ -107,22 +107,17 @@ class EverestLogger { #define EVLOG_error (::Everest::Logging::EverestLogger(BOOST_CURRENT_FUNCTION, spdlog::level::err)) #define EVLOG_critical (::Everest::Logging::EverestLogger(BOOST_CURRENT_FUNCTION, spdlog::level::critical)) -#define EVLOG_AND_THROW(ex) \ - do { \ - try { \ - BOOST_THROW_EXCEPTION(boost::enable_error_info(ex) \ - << boost::log::BOOST_LOG_VERSION_NAMESPACE::current_scope()); \ - } catch (std::exception & e) { \ - EVLOG_error << e.what(); \ - throw; \ - } \ - } while (0) - -#define EVTHROW(ex) \ - do { \ - BOOST_THROW_EXCEPTION(boost::enable_error_info(ex) \ - << boost::log::BOOST_LOG_VERSION_NAMESPACE::current_scope()); \ - } while (0) } // namespace Everest +template constexpr void EVLOG_AND_THROW(const T& ex) { + EVLOG_error << ex.what(); + BOOST_THROW_EXCEPTION(boost::enable_error_info(ex) + << boost::log::BOOST_LOG_VERSION_NAMESPACE::current_scope()); +} + +template constexpr void EVTHROW(const T& ex) { + BOOST_THROW_EXCEPTION(boost::enable_error_info(ex) + << boost::log::BOOST_LOG_VERSION_NAMESPACE::current_scope()); +} + #endif // LOGGING_HPP From bda0c1905f2b8ea5674ea04b517fcbe0ad581bdc Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Wed, 7 Aug 2024 19:00:21 +0200 Subject: [PATCH 04/47] Address some clang-tidy issues Signed-off-by: Kai-Uwe Hermann --- include/everest/logging.hpp | 5 +++ lib/logging.cpp | 68 ++++++++++++++++++++----------------- 2 files changed, 42 insertions(+), 31 deletions(-) diff --git a/include/everest/logging.hpp b/include/everest/logging.hpp index 313b6e7..0bf621c 100644 --- a/include/everest/logging.hpp +++ b/include/everest/logging.hpp @@ -61,6 +61,11 @@ class EverestLogger { level(level), log_file(false), log_line(false), log_function(false) { } + EverestLogger(const EverestLogger&) = delete; + void operator=(const EverestLogger&) = delete; + EverestLogger(const EverestLogger&&) = delete; + void operator=(const EverestLogger&&) = delete; + ~EverestLogger() { #ifdef LIBLOG_OMIT_FILE_AND_LINE_NUMBERS log_file = false; diff --git a/lib/logging.cpp b/lib/logging.cpp index f0ad9a1..07694d3 100644 --- a/lib/logging.cpp +++ b/lib/logging.cpp @@ -42,25 +42,33 @@ namespace attrs = logging::attributes; namespace Everest { namespace Logging { -std::array severity_strings = { - "VERB", // - "DEBG", // - "INFO", // - "WARN", // - "ERRO", // - "CRIT", // + +inline constexpr auto level_verb = 0; +inline constexpr auto level_debg = 1; +inline constexpr auto level_info = 2; +inline constexpr auto level_warn = 3; +inline constexpr auto level_erro = 4; +inline constexpr auto level_crit = 5; + +const std::array severity_strings = { + std::string("VERB"), // + std::string("DEBG"), // + std::string("INFO"), // + std::string("WARN"), // + std::string("ERRO"), // + std::string("CRIT"), // }; -std::array severity_strings_colors = { - "", // - "", // - "", // - "", // - "", // - "", // +std::array severity_strings_colors = { + std::string(""), // + std::string(""), // + std::string(""), // + std::string(""), // + std::string(""), // + std::string(""), // }; -std::string clear_color = "\033[0m"; +const std::string clear_color = "\033[0m"; std::string current_process_name; @@ -83,8 +91,6 @@ std::string get_process_name() { return process_name; } - - void init(const std::string& logconf) { init(logconf, ""); } @@ -94,7 +100,7 @@ class FilterSink : public spdlog::sinks::ansicolor_stdout_sink_mt { explicit FilterSink(const logging::filter& filter) : filter(filter) { } -protected: +private: logging::filter filter; void log(const spdlog::details::log_msg& msg) override { @@ -146,43 +152,43 @@ class EverestLevelFormatter : public spdlog::custom_flag_formatter { void format(const spdlog::details::log_msg& msg, const std::tm&, spdlog::memory_buf_t& dest) override { switch (msg.level) { case spdlog::level::level_enum::trace: { - auto& color = severity_strings_colors.at(0); - auto& verb = severity_strings.at(0); + auto& color = severity_strings_colors.at(level_verb); + auto& verb = severity_strings.at(level_verb); format_message(color, verb, dest); break; } case spdlog::level::level_enum::debug: { - auto& color = severity_strings_colors.at(1); - auto& debg = severity_strings.at(1); + auto& color = severity_strings_colors.at(level_debg); + auto& debg = severity_strings.at(level_debg); format_message(color, debg, dest); break; } case spdlog::level::level_enum::info: { - auto& color = severity_strings_colors.at(2); - auto& info = severity_strings.at(2); + auto& color = severity_strings_colors.at(level_info); + auto& info = severity_strings.at(level_info); format_message(color, info, dest); break; } case spdlog::level::level_enum::warn: { - auto& color = severity_strings_colors.at(3); - auto& warn = severity_strings.at(3); + auto& color = severity_strings_colors.at(level_warn); + auto& warn = severity_strings.at(level_warn); format_message(color, warn, dest); break; } case spdlog::level::level_enum::err: { - auto& color = severity_strings_colors.at(4); - auto& erro = severity_strings.at(4); + auto& color = severity_strings_colors.at(level_erro); + auto& erro = severity_strings.at(level_erro); format_message(color, erro, dest); break; } case spdlog::level::level_enum::critical: { - auto& color = severity_strings_colors.at(5); - auto& crit = severity_strings.at(5); + auto& color = severity_strings_colors.at(level_crit); + auto& crit = severity_strings.at(level_crit); format_message(color, crit, dest); break; } case spdlog::level::level_enum::off: - break; + [[fallthrough]]; case spdlog::level::level_enum::n_levels: break; } From bd393743356e3348fea1a4d654175d59f81e879e Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Thu, 8 Aug 2024 11:02:43 +0200 Subject: [PATCH 05/47] Add LogSource operator<< to control file name, line number and function in the log Signed-off-by: Kai-Uwe Hermann --- include/everest/logging.hpp | 10 ++++++++++ 1 file changed, 10 insertions(+) diff --git a/include/everest/logging.hpp b/include/everest/logging.hpp index 0bf621c..5e21136 100644 --- a/include/everest/logging.hpp +++ b/include/everest/logging.hpp @@ -91,6 +91,16 @@ class EverestLogger { return *this; } + EverestLogger& operator<<(const LogSource& source) { + file = source.file; + line = source.line; + function = source.function; + log_file = source.log_file; + log_line = source.log_line; + log_function = source.log_function; + return *this; + } + private: std::stringstream log; std::string file; From 362be389267bbbd762c2bc9d6cd5accbb1601c10 Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Thu, 8 Aug 2024 11:03:22 +0200 Subject: [PATCH 06/47] Update example to showcase more features Signed-off-by: Kai-Uwe Hermann --- examples/main.cpp | 44 ++++++++++++++++++++++++++++++++++++++++++-- 1 file changed, 42 insertions(+), 2 deletions(-) diff --git a/examples/main.cpp b/examples/main.cpp index a549fb2..a2f0069 100644 --- a/examples/main.cpp +++ b/examples/main.cpp @@ -1,14 +1,26 @@ // SPDX-License-Identifier: Apache-2.0 -// Copyright 2020 - 2021 Pionix GmbH and Contributors to EVerest +// Copyright Pionix GmbH and Contributors to EVerest +#include #include #include +#include #include #include namespace po = boost::program_options; +struct TestStruct { + std::string hello; + int integer; +}; + +std::ostream& operator<<(std::ostream& os, const TestStruct& test) { + os << "TestStruct: hello " << test.hello << " " << test.integer; + return os; +} + int main(int argc, char* argv[]) { po::options_description desc("EVerest::log example"); desc.add_options()("help,h", "produce help message"); @@ -28,7 +40,7 @@ int main(int argc, char* argv[]) { if (vm.count("logconf") != 0) { logging_config = vm["logconf"].as(); } - Everest::Logging::init(logging_config, "hello there"); + Everest::Logging::init(logging_config, "hello there. EVerest"); EVLOG_debug << "logging_config was set to " << logging_config; @@ -39,5 +51,33 @@ int main(int argc, char* argv[]) { EVLOG_error << "This is a ERROR message."; EVLOG_critical << "This is a CRITICAL message."; + TestStruct test_struct{"there", 42}; + EVLOG_info << "This logs a TestStruct using a < Date: Fri, 9 Aug 2024 11:17:42 +0200 Subject: [PATCH 07/47] Fix gtest integration, add some first unit tests, fix coverage generation Signed-off-by: Kai-Uwe Hermann --- CMakeLists.txt | 32 +++++++++++++++--------- dependencies.yaml | 4 +++ tests/CMakeLists.txt | 11 ++++----- tests/liblog_test.cpp | 57 ++++++++++++++++++++++++++++++++++++++++--- 4 files changed, 83 insertions(+), 21 deletions(-) diff --git a/CMakeLists.txt b/CMakeLists.txt index 05a4cfb..5109b37 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -20,12 +20,20 @@ option(CMAKE_RUN_CLANG_TIDY "Run clang-tidy" OFF) option(LIBLOG_USE_BOOST_FILESYSTEM "Usage of boost/filesystem.hpp instead of std::filesystem" OFF) option(LIBLOG_OMIT_FILE_AND_LINE_NUMBERS "Always omit file and line numbers in logs" OFF) +if((${CMAKE_PROJECT_NAME} STREQUAL ${PROJECT_NAME} OR ${PROJECT_NAME}_BUILD_TESTING) AND BUILD_TESTING) + set(LIBLOG_BUILD_TESTING ON) + evc_include(CodeCoverage) + + append_coverage_compiler_flags() +endif() + if(NOT DISABLE_EDM) evc_setup_edm() endif() # library dependencies - +# use cmakes FindBoost module until we require Boost 1.70+ which provides its own BoostConfig.cmake +cmake_policy(SET CMP0167 OLD) if (LIBLOG_USE_BOOST_FILESYSTEM) message(STATUS "Using boost/filesystem instead of std::filesystem") find_package(Boost COMPONENTS log_setup log filesystem REQUIRED) @@ -73,26 +81,26 @@ endif() # testing -if((${CMAKE_PROJECT_NAME} STREQUAL ${PROJECT_NAME} OR ${PROJECT_NAME}_BUILD_TESTING) AND BUILD_TESTING) - include(CTest) - add_subdirectory(tests) - +if(LIBLOG_BUILD_TESTING) set(CMAKE_BUILD_TYPE Debug CACHE STRING "Build type" FORCE) - evc_include(CodeCoverage) - - append_coverage_compiler_flags() + include(CTest) + enable_testing() + add_subdirectory(tests) setup_target_for_coverage_gcovr_html( NAME gcovr_coverage_liblog - EXECUTABLE test_config - DEPENDENCIES test_config everest + EXECUTABLE ctest + DEPENDENCIES ${PROJECT_NAME}_tests + EXCLUDE "examples/*" ) setup_target_for_coverage_lcov( NAME lcov_coverage_liblog - EXECUTABLE test_config - DEPENDENCIES test_config everest + EXECUTABLE ctest + DEPENDENCIES ${PROJECT_NAME}_tests + LCOV_ARGS "--ignore-errors=empty,missing" + EXCLUDE "examples/*" ) else() message("Not running unit tests") diff --git a/dependencies.yaml b/dependencies.yaml index 44bb715..1d8baf3 100644 --- a/dependencies.yaml +++ b/dependencies.yaml @@ -8,3 +8,7 @@ spdlog: git_tag: v1.14.1 options: ["SPDLOG_NO_TLS ON", "SPDLOG_FMT_EXTERNAL ON"] +gtest: + git: https://github.com/google/googletest.git + git_tag: release-1.12.1 + cmake_condition: "LIBLOG_BUILD_TESTING" \ No newline at end of file diff --git a/tests/CMakeLists.txt b/tests/CMakeLists.txt index 7751b2e..4ad290f 100644 --- a/tests/CMakeLists.txt +++ b/tests/CMakeLists.txt @@ -1,17 +1,16 @@ -find_package(GTest REQUIRED) - set(TEST_TARGET_NAME ${PROJECT_NAME}_tests) add_executable(${TEST_TARGET_NAME} liblog_test.cpp) -target_include_directories(${TEST_TARGET_NAME} PUBLIC ${GTEST_INCLUDE_DIRS}) +#target_include_directories(${TEST_TARGET_NAME} PUBLIC ${GTEST_INCLUDE_DIRS}) target_include_directories(log PUBLIC $ $ ) target_link_libraries(${TEST_TARGET_NAME} PRIVATE - ${GTEST_LIBRARIES} - ${GTEST_MAIN_LIBRARIES} + everest::log + GTest::gmock_main + GTest::gtest_main ) -gtest_discover_tests(${TEST_TARGET_NAME}) +add_test(${TEST_TARGET_NAME} ${TEST_TARGET_NAME}) diff --git a/tests/liblog_test.cpp b/tests/liblog_test.cpp index 578b41d..d2268e9 100644 --- a/tests/liblog_test.cpp +++ b/tests/liblog_test.cpp @@ -1,10 +1,32 @@ // SPDX-License-Identifier: Apache-2.0 -// Copyright 2020 - 2023 Pionix GmbH and Contributors to EVerest +// Copyright Pionix GmbH and Contributors to EVerest +#include +#include + #include +#include + +#include namespace Everest { namespace Logging { +class TestSink : public spdlog::sinks::base_sink { +public: + // return number of log messages logged + size_t count() { + return this->counter; + } + +protected: + void sink_it_(const spdlog::details::log_msg& message) override { + this->counter += 1; + } + + void flush_() override {} + size_t counter = 0; +}; + class LibLogUnitTest : public ::testing::Test { protected: void SetUp() override { @@ -14,8 +36,37 @@ class LibLogUnitTest : public ::testing::Test { } }; -TEST(LibLogUnitTest, test_truth) { - ASSERT_TRUE(1 == 1); +TEST_F(LibLogUnitTest, test_log_source_file_linenr_function) { + auto log_source = LogSource("file", 42, "function"); + EXPECT_TRUE(log_source.log_file); + EXPECT_TRUE(log_source.log_line); + EXPECT_TRUE(log_source.log_function); +} + +TEST_F(LibLogUnitTest, test_log_source_function) { + auto log_source = LogSource("function"); + EXPECT_FALSE(log_source.log_file); + EXPECT_FALSE(log_source.log_line); + EXPECT_TRUE(log_source.log_function); +} + +TEST_F(LibLogUnitTest, test_evthrow) { + ASSERT_THROW(EVTHROW(std::runtime_error("hello there")), std::runtime_error); +} + +TEST_F(LibLogUnitTest, test_evlog_and_throw) { + ASSERT_THROW(EVLOG_AND_THROW(std::runtime_error("hello there")), std::runtime_error); +} + +TEST_F(LibLogUnitTest, test_everest_logger) { + auto test_sink = std::make_shared(); + auto test_logger = std::make_shared("", test_sink); + spdlog::set_default_logger(test_logger); + spdlog::set_level(spdlog::level::level_enum::trace); + EVLOG_verbose << "hello there"; + EVLOG_info << "hello there"; + EVLOG_warning << "hello there"; + ASSERT_EQ(test_sink->count(), 3); } } // namespace Logging From 6bfd5ed54d2b521ec1c2c01e3c42a2f03f7725ad Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Mon, 12 Aug 2024 19:24:37 +0200 Subject: [PATCH 08/47] Change Filter in example logging.ini to show the %Process% contains syntax Signed-off-by: Kai-Uwe Hermann --- examples/logging.ini | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/examples/logging.ini b/examples/logging.ini index 988aebd..b07a1ac 100644 --- a/examples/logging.ini +++ b/examples/logging.ini @@ -3,7 +3,7 @@ [Core] DisableLogging=false -Filter="%Severity% >= DEBG" +Filter="(%Severity% >= VERB and %Process% contains EVerest)" [Sinks.Console] Destination=Console From 6846122d77949370b71d573d7820a3209da8dc2c Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Mon, 12 Aug 2024 19:24:56 +0200 Subject: [PATCH 09/47] Small log fix Signed-off-by: Kai-Uwe Hermann --- examples/main.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/examples/main.cpp b/examples/main.cpp index a2f0069..1a5797d 100644 --- a/examples/main.cpp +++ b/examples/main.cpp @@ -52,7 +52,7 @@ int main(int argc, char* argv[]) { EVLOG_critical << "This is a CRITICAL message."; TestStruct test_struct{"there", 42}; - EVLOG_info << "This logs a TestStruct using a < Date: Mon, 12 Aug 2024 19:29:55 +0200 Subject: [PATCH 10/47] Fix is_level with and without %Process% contains Signed-off-by: Kai-Uwe Hermann --- lib/logging.cpp | 15 +++++++++++---- 1 file changed, 11 insertions(+), 4 deletions(-) diff --git a/lib/logging.cpp b/lib/logging.cpp index 07694d3..9c26141 100644 --- a/lib/logging.cpp +++ b/lib/logging.cpp @@ -72,6 +72,8 @@ const std::string clear_color = "\033[0m"; std::string current_process_name; +spdlog::level::level_enum global_level = spdlog::level::level_enum::trace; + std::string get_process_name() { std::string process_name; #ifndef __linux__ @@ -125,7 +127,7 @@ class FilterSink : public spdlog::sinks::ansicolor_stdout_sink_mt { bool is_level(const logging::filter& filter, severity_level level) { auto src = logging::attribute_set(); src["Severity"] = attrs::constant(level); - src["Process"] = attrs::constant(""); + src["Process"] = attrs::constant(current_process_name); auto set = logging::attribute_value_set(src, logging::attribute_set(), logging::attribute_set()); return filter(set); } @@ -247,7 +249,11 @@ std::istream& operator>>(std::istream& strm, severity_level& level) { std::shared_ptr filter_sink; void init(const std::string& logconf, std::string process_name) { - current_process_name = get_process_name(); + if (process_name.empty()) { + current_process_name = get_process_name(); + } else { + current_process_name = process_name; + } // open logging.ini config file located at our base_dir and use it to configure filters and format fs::path logging_path = fs::path(logconf); @@ -280,8 +286,8 @@ void init(const std::string& logconf, std::string process_name) { auto parsed_filter = logging::parse_filter(filter); + global_level = get_level_from_filter(parsed_filter); filter_sink = std::make_shared(parsed_filter); - update_process_name(process_name); auto format = sink["Format"].get().get_value_or(""); @@ -308,7 +314,7 @@ void init(const std::string& logconf, std::string process_name) { formatter->add_flag('!').set_pattern(format); spdlog::set_formatter(std::move(formatter)); - spdlog::set_level(get_level_from_filter(parsed_filter)); + update_process_name(process_name); EVLOG_debug << "Logger initialized (using " << logconf << ")..."; } @@ -318,6 +324,7 @@ void update_process_name(std::string process_name) { current_process_name = process_name; auto filter_logger = std::make_shared(current_process_name, filter_sink); spdlog::set_default_logger(filter_logger); + spdlog::set_level(global_level); } } } // namespace Logging From 37e5b9c0163cbca994bff20a71ac5fe90203f59f Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Mon, 12 Aug 2024 19:36:58 +0200 Subject: [PATCH 11/47] Implement a (hopefully) Boost.Log TextFile settings compatible rotating file sink based on the rotating file sink example of spdlog Signed-off-by: Kai-Uwe Hermann --- examples/logging.ini | 7 + include/everest/rotating_file_sink.hpp | 141 +++++++++++++++++ lib/CMakeLists.txt | 1 + lib/logging.cpp | 205 ++++++++++++++++++------- 4 files changed, 302 insertions(+), 52 deletions(-) create mode 100644 include/everest/rotating_file_sink.hpp diff --git a/examples/logging.ini b/examples/logging.ini index b07a1ac..1b0800d 100644 --- a/examples/logging.ini +++ b/examples/logging.ini @@ -16,3 +16,10 @@ SeverityStringColorInfo="\033[1;37m" SeverityStringColorWarning="\033[1;33m" SeverityStringColorError="\033[1;31m" SeverityStringColorCritical="\033[1;35m" + +[Sinks.TextFile] +Destination=TextFile +FileName="FileLog%5N.log" +Format = "%TimeStamp% [%Severity%] %Message%" +RotationSize = 500 # bytes +MaxFiles = 5 diff --git a/include/everest/rotating_file_sink.hpp b/include/everest/rotating_file_sink.hpp new file mode 100644 index 0000000..e95b179 --- /dev/null +++ b/include/everest/rotating_file_sink.hpp @@ -0,0 +1,141 @@ +// Copyright(c) 2015-present, Gabi Melman & spdlog contributors. +// Distributed under the MIT License (http://opensource.org/licenses/MIT) +// Based on +// https://github.com/gabime/spdlog/blob/5ebfc927306fd7ce551fa22244be801cf2b9fdd9/include/spdlog/sinks/rotating_file_sink.h + +#pragma once + +#include +#include +#include +#include +#include + +#include +#include +#include + +namespace Everest { +namespace Logging { + +/// \brief Rotating file sink based on size +template class rotating_file_sink : public spdlog::sinks::base_sink { +public: + rotating_file_sink(spdlog::filename_t base_filename, std::size_t max_size, std::size_t max_files, + bool rotate_on_open) : + base_filename_(std::move(base_filename)), max_size_(max_size), max_files_(max_files) { + file_helper_.open(calc_filename(base_filename_, 0)); + current_size_ = file_helper_.size(); // expensive. called only once + if (max_size != 0 and rotate_on_open && current_size_ > 0) { + rotate_(); + current_size_ = 0; + } + } + + static spdlog::filename_t calc_filename(const spdlog::filename_t& filename, std::size_t index) { + std::string format_str = filename; + std::string log_file_name = filename; + try { + // find any %5N like constructs in the filename + size_t pos_percent = 0; + while ((pos_percent = format_str.find('%', pos_percent)) != std::string::npos) { + size_t pos_n = pos_percent; + pos_n = format_str.find('N', pos_n); + if (pos_n != std::string::npos) { + format_str = format_str.replace(pos_n, 1, "d"); + format_str = format_str.replace(pos_percent, 1, "%0"); + } else { + break; + } + } + log_file_name = fmt::sprintf(format_str, index); + } catch (const fmt::format_error& e) { + } + + if (log_file_name == filename) { + log_file_name = fmt::format("{:05}.log", index); + } + + return log_file_name; + } + spdlog::filename_t filename() { + std::lock_guard lock(spdlog::sinks::base_sink::mutex_); + return file_helper_.filename(); + } + +protected: + void sink_it_(const spdlog::details::log_msg& msg) override { + spdlog::memory_buf_t formatted; + spdlog::sinks::base_sink::formatter_->format(msg, formatted); + auto new_size = current_size_ + formatted.size(); + + // rotate if the new estimated file size exceeds max size. + // rotate only if the real size > 0 to better deal with full disk (see issue #2261). + // we only check the real size when new_size > max_size_ because it is relatively expensive. + if (max_size_ != 0 and new_size > max_size_) { + file_helper_.flush(); + if (file_helper_.size() > 0) { + rotate_(); + new_size = formatted.size(); + } + } + file_helper_.write(formatted); + current_size_ = new_size; + } + void flush_() override { + file_helper_.flush(); + } + +private: + // Rotate files: + // log.txt -> log.1.txt + // log.1.txt -> log.2.txt + // log.2.txt -> log.3.txt + // log.3.txt -> delete + void rotate_() { + using spdlog::details::os::filename_to_str; + using spdlog::details::os::path_exists; + + file_helper_.close(); + for (auto i = max_files_; i > 0; --i) { + spdlog::filename_t src = calc_filename(base_filename_, i - 1); + if (!path_exists(src)) { + continue; + } + spdlog::filename_t target = calc_filename(base_filename_, i); + + if (!rename_file_(src, target)) { + // if failed try again after a small delay. + // this is a workaround to a windows issue, where very high rotation + // rates can cause the rename to fail with permission denied (because of antivirus?). + spdlog::details::os::sleep_for_millis(100); + if (!rename_file_(src, target)) { + file_helper_.reopen(true); // truncate the log file anyway to prevent it to grow beyond its limit! + current_size_ = 0; + spdlog::throw_spdlog_ex("rotating_file_sink: failed renaming " + filename_to_str(src) + " to " + + filename_to_str(target), + errno); + } + } + } + file_helper_.reopen(true); + } + + // delete the target if exists, and rename the src file to target + // return true on success, false otherwise. + bool rename_file_(const spdlog::filename_t& src_filename, const spdlog::filename_t& target_filename) { + // try to delete the target file in case it already exists. + (void)spdlog::details::os::remove(target_filename); + return spdlog::details::os::rename(src_filename, target_filename) == 0; + } + spdlog::filename_t base_filename_; + std::size_t max_size_; + std::size_t max_files_; + std::size_t current_size_; + spdlog::details::file_helper file_helper_; +}; + +using rotating_file_sink_mt = rotating_file_sink; + +} // namespace Logging +} // namespace Everest diff --git a/lib/CMakeLists.txt b/lib/CMakeLists.txt index 92ca468..f4cd0d3 100644 --- a/lib/CMakeLists.txt +++ b/lib/CMakeLists.txt @@ -19,6 +19,7 @@ target_link_libraries(log spdlog::spdlog PRIVATE Boost::log_setup + fmt::fmt ) if (LIBLOG_USE_BOOST_FILESYSTEM) diff --git a/lib/logging.cpp b/lib/logging.cpp index 9c26141..b86afeb 100644 --- a/lib/logging.cpp +++ b/lib/logging.cpp @@ -21,6 +21,9 @@ #include #include +// FIXME: move this into a detail header so we do not have to expose this to the world +#include + #include #include @@ -97,14 +100,31 @@ void init(const std::string& logconf) { init(logconf, ""); } -class FilterSink : public spdlog::sinks::ansicolor_stdout_sink_mt { +class Filter { public: - explicit FilterSink(const logging::filter& filter) : filter(filter) { + explicit Filter(const logging::filter& filter) : filter(filter) { + } + + bool filter_msg(const spdlog::details::log_msg& msg) { + auto src = logging::attribute_set(); + // TODO: proper conversion function between msg.level an severity_level + src["Severity"] = attrs::constant(static_cast(msg.level)); + src["Process"] = attrs::constant(msg.logger_name.data()); + // FIXME: support more of the boost log Filter syntax? + auto set = logging::attribute_value_set(src, logging::attribute_set(), logging::attribute_set()); + return filter(set); } private: logging::filter filter; +}; + +class ConsoleFilterSink : public spdlog::sinks::ansicolor_stdout_sink_mt, public Filter { +public: + explicit ConsoleFilterSink(const logging::filter& filter) : Filter(filter) { + } +private: void log(const spdlog::details::log_msg& msg) override { if (not filter_msg(msg)) { return; @@ -112,15 +132,22 @@ class FilterSink : public spdlog::sinks::ansicolor_stdout_sink_mt { spdlog::sinks::ansicolor_stdout_sink_mt::log(msg); } +}; - bool filter_msg(const spdlog::details::log_msg& msg) { - auto src = logging::attribute_set(); - // TODO: proper conversion function between msg.level an severity_level - src["Severity"] = attrs::constant(static_cast(msg.level)); - src["Process"] = attrs::constant(msg.logger_name.data()); - // FIXME: support more of the boost log Filter syntax? - auto set = logging::attribute_value_set(src, logging::attribute_set(), logging::attribute_set()); - return filter(set); +class TextFileFilterSink : public Everest::Logging::rotating_file_sink_mt, public Filter { +public: + explicit TextFileFilterSink(const logging::filter& filter, spdlog::filename_t base_filename, std::size_t max_size, + std::size_t max_files, bool rotate_on_open) : + rotating_file_sink_mt(base_filename, max_size, max_files, rotate_on_open), Filter(filter) { + } + +private: + void sink_it_(const spdlog::details::log_msg& msg) override { + if (not filter_msg(msg)) { + return; + } + + Everest::Logging::rotating_file_sink_mt::sink_it_(msg); } }; @@ -149,7 +176,7 @@ spdlog::level::level_enum get_level_from_filter(const logging::filter& filter) { return spdlog::level::level_enum::info; } -class EverestLevelFormatter : public spdlog::custom_flag_formatter { +class EverestColorLevelFormatter : public spdlog::custom_flag_formatter { public: void format(const spdlog::details::log_msg& msg, const std::tm&, spdlog::memory_buf_t& dest) override { switch (msg.level) { @@ -197,7 +224,7 @@ class EverestLevelFormatter : public spdlog::custom_flag_formatter { } std::unique_ptr clone() const override { - return spdlog::details::make_unique(); + return spdlog::details::make_unique(); } private: @@ -212,6 +239,57 @@ class EverestLevelFormatter : public spdlog::custom_flag_formatter { } }; +class EverestLevelFormatter : public spdlog::custom_flag_formatter { +public: + void format(const spdlog::details::log_msg& msg, const std::tm&, spdlog::memory_buf_t& dest) override { + switch (msg.level) { + case spdlog::level::level_enum::trace: { + auto& verb = severity_strings.at(level_verb); + format_message(verb, dest); + break; + } + case spdlog::level::level_enum::debug: { + auto& debg = severity_strings.at(level_debg); + format_message(debg, dest); + break; + } + case spdlog::level::level_enum::info: { + auto& info = severity_strings.at(level_info); + format_message(info, dest); + break; + } + case spdlog::level::level_enum::warn: { + auto& warn = severity_strings.at(level_warn); + format_message(warn, dest); + break; + } + case spdlog::level::level_enum::err: { + auto& erro = severity_strings.at(level_erro); + format_message(erro, dest); + break; + } + case spdlog::level::level_enum::critical: { + auto& crit = severity_strings.at(level_crit); + format_message(crit, dest); + break; + } + case spdlog::level::level_enum::off: + [[fallthrough]]; + case spdlog::level::level_enum::n_levels: + break; + } + } + + std::unique_ptr clone() const override { + return spdlog::details::make_unique(); + } + +private: + void format_message(const std::string& loglevel, spdlog::memory_buf_t& dest) { + dest.append(loglevel.data(), loglevel.data() + loglevel.size()); + } +}; + class EverestFuncnameFormatter : public spdlog::custom_flag_formatter { public: void format(const spdlog::details::log_msg& msg, const std::tm&, spdlog::memory_buf_t& dest) override { @@ -246,7 +324,7 @@ std::istream& operator>>(std::istream& strm, severity_level& level) { return strm; } -std::shared_ptr filter_sink; +std::vector> sinks; void init(const std::string& logconf, std::string process_name) { if (process_name.empty()) { @@ -266,20 +344,6 @@ void init(const std::string& logconf, std::string process_name) { auto settings = logging::parse_settings(logging_config); logging::register_simple_filter_factory("Severity"); - auto sink = settings["Sinks.Console"].get_section(); - - severity_strings_colors[severity_level::verbose] = - sink["SeverityStringColorTrace"].get().get_value_or(""); - severity_strings_colors[severity_level::debug] = - sink["SeverityStringColorDebug"].get().get_value_or(""); - severity_strings_colors[severity_level::info] = sink["SeverityStringColorInfo"].get().get_value_or(""); - severity_strings_colors[severity_level::warning] = - sink["SeverityStringColorWarning"].get().get_value_or(""); - severity_strings_colors[severity_level::error] = - sink["SeverityStringColorError"].get().get_value_or(""); - severity_strings_colors[severity_level::critical] = - sink["SeverityStringColorCritical"].get().get_value_or(""); - auto core = settings["Core"].get_section(); auto filter = core["Filter"].get().get_value_or(""); @@ -287,32 +351,69 @@ void init(const std::string& logconf, std::string process_name) { auto parsed_filter = logging::parse_filter(filter); global_level = get_level_from_filter(parsed_filter); - filter_sink = std::make_shared(parsed_filter); - - auto format = sink["Format"].get().get_value_or(""); - - // parse the format into a format string that spdlog can use - std::vector> replacements = {{"%TimeStamp%", "%Y-%m-%d %H:%M:%S.%f"}, - {"%Process%", "%-15!n"}, - {"%ProcessID%", "%P"}, - {"%Severity%", "%l"}, - {"%ThreadID%", "%t"}, - {"%function%", "%!"}, - {"%file%", "%s"}, - {"%line%", "%#"}, - {"%Message%", "%v"}}; - for (auto& replace : replacements) { - auto pos = format.find(replace.first); - while (pos != std::string::npos) { - format.replace(pos, replace.first.size(), replace.second); - pos = format.find(replace.first, pos + replace.second.size()); - } + + if (not settings.has_section("Sinks")) { + std::cerr << "No \"Sinks\" section in the logging configuration, at least one sink has be be present" + << std::endl; + return; // FIXME: throw an exception here? } - auto formatter = std::make_unique(); - formatter->add_flag('l').set_pattern(format); - formatter->add_flag('!').set_pattern(format); - spdlog::set_formatter(std::move(formatter)); + for (auto sink : settings["Sinks"].get_section()) { + auto format = sink["Format"].get().get_value_or("%TimeStamp% [%Severity%] %Message%"); + + // parse the format into a format string that spdlog can use + std::vector> replacements = {{"%TimeStamp%", "%Y-%m-%d %H:%M:%S.%f"}, + {"%Process%", "%-15!n"}, + {"%ProcessID%", "%P"}, + {"%Severity%", "%l"}, + {"%ThreadID%", "%t"}, + {"%function%", "%!"}, + {"%file%", "%s"}, + {"%line%", "%#"}, + {"%Message%", "%v"}}; + for (auto& replace : replacements) { + auto pos = format.find(replace.first); + while (pos != std::string::npos) { + format.replace(pos, replace.first.size(), replace.second); + pos = format.find(replace.first, pos + replace.second.size()); + } + } + + auto formatter = std::make_unique(); + formatter->add_flag('!').set_pattern(format); + + auto destination = sink["Destination"].get().get_value_or(""); + if (destination == "Console") { + formatter->add_flag('l').set_pattern(format); + + severity_strings_colors[severity_level::verbose] = + sink["SeverityStringColorTrace"].get().get_value_or(""); + severity_strings_colors[severity_level::debug] = + sink["SeverityStringColorDebug"].get().get_value_or(""); + severity_strings_colors[severity_level::info] = + sink["SeverityStringColorInfo"].get().get_value_or(""); + severity_strings_colors[severity_level::warning] = + sink["SeverityStringColorWarning"].get().get_value_or(""); + severity_strings_colors[severity_level::error] = + sink["SeverityStringColorError"].get().get_value_or(""); + severity_strings_colors[severity_level::critical] = + sink["SeverityStringColorCritical"].get().get_value_or(""); + auto console_sink = std::make_shared(parsed_filter); + console_sink->set_formatter(std::move(formatter)); + sinks.push_back(console_sink); + } else if (destination == "TextFile") { + formatter->add_flag('l').set_pattern(format); + + auto file_name = sink["FileName"].get().get_value_or("%5N.log"); + auto rotation_size = sink["RotationSize"].get().get_value_or(0); + auto max_files = sink["MaxFiles"].get().get_value_or(0); + + auto file_sink = + std::make_shared(parsed_filter, file_name, rotation_size, max_files, false); + file_sink->set_formatter(std::move(formatter)); + sinks.push_back(file_sink); + } + } update_process_name(process_name); @@ -322,7 +423,7 @@ void init(const std::string& logconf, std::string process_name) { void update_process_name(std::string process_name) { if (!process_name.empty()) { current_process_name = process_name; - auto filter_logger = std::make_shared(current_process_name, filter_sink); + auto filter_logger = std::make_shared(current_process_name, std::begin(sinks), std::end(sinks)); spdlog::set_default_logger(filter_logger); spdlog::set_level(global_level); } From ee92a5722ec0b35d9922865c13f9825baa883fdc Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Mon, 12 Aug 2024 20:02:22 +0200 Subject: [PATCH 12/47] Implement a simple Syslog sink Signed-off-by: Kai-Uwe Hermann --- examples/logging.ini | 5 +++++ lib/logging.cpp | 26 ++++++++++++++++++++++++++ 2 files changed, 31 insertions(+) diff --git a/examples/logging.ini b/examples/logging.ini index 1b0800d..cc9a6b6 100644 --- a/examples/logging.ini +++ b/examples/logging.ini @@ -23,3 +23,8 @@ FileName="FileLog%5N.log" Format = "%TimeStamp% [%Severity%] %Message%" RotationSize = 500 # bytes MaxFiles = 5 + +[Sinks.Syslog] +Destination=Syslog +Format="%TimeStamp% [%Severity%] %Message%" +EnableFormatting=false diff --git a/lib/logging.cpp b/lib/logging.cpp index b86afeb..208338b 100644 --- a/lib/logging.cpp +++ b/lib/logging.cpp @@ -20,6 +20,7 @@ #include #include +#include // FIXME: move this into a detail header so we do not have to expose this to the world #include @@ -151,6 +152,22 @@ class TextFileFilterSink : public Everest::Logging::rotating_file_sink_mt, publi } }; +class SyslogFilterSink : public spdlog::sinks::syslog_sink_mt, public Filter { +public: + explicit SyslogFilterSink(const logging::filter& filter, std::string indet, int syslog_option, int syslog_facility, + bool enable_formatting) : + spdlog::sinks::syslog_sink_mt(indet, syslog_option, syslog_facility, enable_formatting), Filter(filter) { + } + +private: + void sink_it_(const spdlog::details::log_msg& msg) override { + if (not filter_msg(msg)) { + return; + } + + spdlog::sinks::syslog_sink_mt::sink_it_(msg); + } +}; bool is_level(const logging::filter& filter, severity_level level) { auto src = logging::attribute_set(); src["Severity"] = attrs::constant(level); @@ -412,6 +429,15 @@ void init(const std::string& logconf, std::string process_name) { std::make_shared(parsed_filter, file_name, rotation_size, max_files, false); file_sink->set_formatter(std::move(formatter)); sinks.push_back(file_sink); + } else if (destination == "Syslog") { + // TODO implement LocalAddress and TargetAddress settings + auto enable_formatting = sink["EnableFormatting"].get().get_value_or(false); + + formatter->add_flag('l').set_pattern(format); + auto syslog_sink = + std::make_shared(parsed_filter, process_name, 0, LOG_USER, enable_formatting); + syslog_sink->set_formatter(std::move(formatter)); + sinks.push_back(syslog_sink); } } From 2133f3cbdfe0598aa56a40478bad46a022f24f87 Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Tue, 13 Aug 2024 15:04:20 +0200 Subject: [PATCH 13/47] Correctly limit maximum number of files in log rotation Signed-off-by: Kai-Uwe Hermann --- include/everest/rotating_file_sink.hpp | 3 +++ 1 file changed, 3 insertions(+) diff --git a/include/everest/rotating_file_sink.hpp b/include/everest/rotating_file_sink.hpp index e95b179..a550c69 100644 --- a/include/everest/rotating_file_sink.hpp +++ b/include/everest/rotating_file_sink.hpp @@ -24,6 +24,9 @@ template class rotating_file_sink : public spdlog::sinks::base_ rotating_file_sink(spdlog::filename_t base_filename, std::size_t max_size, std::size_t max_files, bool rotate_on_open) : base_filename_(std::move(base_filename)), max_size_(max_size), max_files_(max_files) { + if (max_files_ > 0) { + max_files_ = max_files_ - 1; + } file_helper_.open(calc_filename(base_filename_, 0)); current_size_ = file_helper_.size(); // expensive. called only once if (max_size != 0 and rotate_on_open && current_size_ > 0) { From 47aa3daf81b0bcfd91f41697f8a08efb78a7072a Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Tue, 13 Aug 2024 15:04:55 +0200 Subject: [PATCH 14/47] Respect file name and extension set in FileName when using default format string Signed-off-by: Kai-Uwe Hermann --- include/everest/rotating_file_sink.hpp | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/include/everest/rotating_file_sink.hpp b/include/everest/rotating_file_sink.hpp index a550c69..bbdd615 100644 --- a/include/everest/rotating_file_sink.hpp +++ b/include/everest/rotating_file_sink.hpp @@ -56,7 +56,9 @@ template class rotating_file_sink : public spdlog::sinks::base_ } if (log_file_name == filename) { - log_file_name = fmt::format("{:05}.log", index); + spdlog::filename_t basename, ext; + std::tie(basename, ext) = spdlog::details::file_helper::split_by_extension(filename); + log_file_name = fmt::format("{}{:05}{}", basename, index, ext); } return log_file_name; From 78ab778dc20af14e228578f88c2c063690a35f24 Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Tue, 13 Aug 2024 15:05:36 +0200 Subject: [PATCH 15/47] Convert EVEREST_INTERNAL_LOG_AND_THROW into constexpr template function Signed-off-by: Kai-Uwe Hermann --- lib/logging.cpp | 10 ++++------ 1 file changed, 4 insertions(+), 6 deletions(-) diff --git a/lib/logging.cpp b/lib/logging.cpp index 208338b..bf6e8c7 100644 --- a/lib/logging.cpp +++ b/lib/logging.cpp @@ -29,12 +29,10 @@ #include // this will only be used while bootstrapping our logging (e.g. the logging settings aren't yet applied) -// NOLINTNEXTLINE(cppcoreguidelines-macro-usage) -#define EVEREST_INTERNAL_LOG_AND_THROW(exception) \ - do { \ - spdlog::critical("{}", (exception).what()); \ - throw(exception); \ - } while (0); +template constexpr void EVEREST_INTERNAL_LOG_AND_THROW(const T& exception) { + spdlog::critical("{}", (exception).what()); + throw exception; +} #ifdef LIBLOG_USE_BOOST_FILESYSTEM namespace fs = boost::filesystem; From 5729b5d8d88dd019ea1ef4db6b13af5ca48068c8 Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Tue, 13 Aug 2024 15:06:05 +0200 Subject: [PATCH 16/47] Throw EverestConfigError when no sinks are configured Signed-off-by: Kai-Uwe Hermann --- lib/logging.cpp | 5 ++--- 1 file changed, 2 insertions(+), 3 deletions(-) diff --git a/lib/logging.cpp b/lib/logging.cpp index bf6e8c7..1fb7f74 100644 --- a/lib/logging.cpp +++ b/lib/logging.cpp @@ -368,9 +368,8 @@ void init(const std::string& logconf, std::string process_name) { global_level = get_level_from_filter(parsed_filter); if (not settings.has_section("Sinks")) { - std::cerr << "No \"Sinks\" section in the logging configuration, at least one sink has be be present" - << std::endl; - return; // FIXME: throw an exception here? + EVEREST_INTERNAL_LOG_AND_THROW(EverestConfigError( + std::string("No \"Sinks\" section in the logging configuration, at least one sink has be be present"))); } for (auto sink : settings["Sinks"].get_section()) { From 989eb46479789ee6e169d1d5fb291fd421eb882a Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Tue, 13 Aug 2024 15:08:32 +0200 Subject: [PATCH 17/47] Add unit tests for Console and TextFile sinks Signed-off-by: Kai-Uwe Hermann --- tests/CMakeLists.txt | 24 ++- tests/liblog_test.cpp | 174 +++++++++++++++++- tests/logging_configs/console.ini | 14 ++ tests/logging_configs/console_crit.ini | 14 ++ tests/logging_configs/console_debg.ini | 14 ++ tests/logging_configs/console_erro.ini | 14 ++ tests/logging_configs/console_info.ini | 14 ++ tests/logging_configs/console_warn.ini | 14 ++ tests/logging_configs/no_sinks.ini | 3 + tests/logging_configs/textfile_crit.ini | 10 + tests/logging_configs/textfile_debg.ini | 10 + tests/logging_configs/textfile_erro.ini | 10 + tests/logging_configs/textfile_info.ini | 10 + tests/logging_configs/textfile_off.ini | 10 + tests/logging_configs/textfile_verb.ini | 10 + .../textfile_verb_broken_filename.ini | 10 + .../logging_configs/textfile_verb_rotate.ini | 10 + tests/logging_configs/textfile_warn.ini | 10 + 18 files changed, 371 insertions(+), 4 deletions(-) create mode 100644 tests/logging_configs/console.ini create mode 100644 tests/logging_configs/console_crit.ini create mode 100644 tests/logging_configs/console_debg.ini create mode 100644 tests/logging_configs/console_erro.ini create mode 100644 tests/logging_configs/console_info.ini create mode 100644 tests/logging_configs/console_warn.ini create mode 100644 tests/logging_configs/no_sinks.ini create mode 100644 tests/logging_configs/textfile_crit.ini create mode 100644 tests/logging_configs/textfile_debg.ini create mode 100644 tests/logging_configs/textfile_erro.ini create mode 100644 tests/logging_configs/textfile_info.ini create mode 100644 tests/logging_configs/textfile_off.ini create mode 100644 tests/logging_configs/textfile_verb.ini create mode 100644 tests/logging_configs/textfile_verb_broken_filename.ini create mode 100644 tests/logging_configs/textfile_verb_rotate.ini create mode 100644 tests/logging_configs/textfile_warn.ini diff --git a/tests/CMakeLists.txt b/tests/CMakeLists.txt index 4ad290f..a04ee14 100644 --- a/tests/CMakeLists.txt +++ b/tests/CMakeLists.txt @@ -1,16 +1,34 @@ set(TEST_TARGET_NAME ${PROJECT_NAME}_tests) -add_executable(${TEST_TARGET_NAME} liblog_test.cpp) +add_executable(${TEST_TARGET_NAME}) -#target_include_directories(${TEST_TARGET_NAME} PUBLIC ${GTEST_INCLUDE_DIRS}) target_include_directories(log PUBLIC $ $ ) + target_link_libraries(${TEST_TARGET_NAME} PRIVATE everest::log - GTest::gmock_main GTest::gtest_main + GTest::gtest_main +) + +target_sources(${TEST_TARGET_NAME} PRIVATE + liblog_test.cpp ) add_test(${TEST_TARGET_NAME} ${TEST_TARGET_NAME}) + +# copy logging configs +configure_file(logging_configs/no_sinks.ini logging_configs/no_sinks.ini COPYONLY) +configure_file(logging_configs/console.ini logging_configs/console.ini COPYONLY) + +configure_file(logging_configs/textfile_verb.ini logging_configs/textfile_verb.ini COPYONLY) +configure_file(logging_configs/textfile_verb_rotate.ini logging_configs/textfile_verb_rotate.ini COPYONLY) +configure_file(logging_configs/textfile_verb_broken_filename.ini logging_configs/textfile_verb_broken_filename.ini COPYONLY) +configure_file(logging_configs/textfile_debg.ini logging_configs/textfile_debg.ini COPYONLY) +configure_file(logging_configs/textfile_info.ini logging_configs/textfile_info.ini COPYONLY) +configure_file(logging_configs/textfile_warn.ini logging_configs/textfile_warn.ini COPYONLY) +configure_file(logging_configs/textfile_erro.ini logging_configs/textfile_erro.ini COPYONLY) +configure_file(logging_configs/textfile_crit.ini logging_configs/textfile_crit.ini COPYONLY) +configure_file(logging_configs/textfile_off.ini logging_configs/textfile_off.ini COPYONLY) \ No newline at end of file diff --git a/tests/liblog_test.cpp b/tests/liblog_test.cpp index d2268e9..f73f4d4 100644 --- a/tests/liblog_test.cpp +++ b/tests/liblog_test.cpp @@ -1,15 +1,19 @@ // SPDX-License-Identifier: Apache-2.0 // Copyright Pionix GmbH and Contributors to EVerest #include +#include +#include #include #include #include +#include #include namespace Everest { namespace Logging { +namespace tests { class TestSink : public spdlog::sinks::base_sink { public: @@ -23,7 +27,8 @@ class TestSink : public spdlog::sinks::base_sink { this->counter += 1; } - void flush_() override {} + void flush_() override { + } size_t counter = 0; }; @@ -33,6 +38,31 @@ class LibLogUnitTest : public ::testing::Test { } void TearDown() override { + auto logger = spdlog::default_logger(); + for (auto& sink : logger->sinks()) { + sink->set_level(spdlog::level::off); + } + } + + void log_with_all_loglevels() { + EVLOG_verbose << "This is a VERBOSE message."; + EVLOG_debug << "This is a DEBUG message."; + EVLOG_info << "This is a INFO message."; + EVLOG_warning << "This is a WARNING message."; + EVLOG_error << "This is a ERROR message."; + EVLOG_critical << "This is a CRITICAL message."; + } + + int count_log_entries(const std::filesystem::path& file_name) { + std::ifstream log(file_name.string()); + EXPECT_TRUE(log.is_open()); + std::string line; + auto count = 0; + while (std::getline(log, line)) { + count += 1; + } + log.close(); + return count; } }; @@ -69,5 +99,147 @@ TEST_F(LibLogUnitTest, test_everest_logger) { ASSERT_EQ(test_sink->count(), 3); } +TEST_F(LibLogUnitTest, test_init_wrong_filename) { + auto test_sink = std::make_shared(); + auto test_logger = std::make_shared("", test_sink); + spdlog::set_default_logger(test_logger); + spdlog::set_level(spdlog::level::level_enum::trace); + ASSERT_THROW(Everest::Logging::init("this_file_does_not_exist", "liblog_test"), Everest::EverestConfigError); +} + +TEST_F(LibLogUnitTest, test_init_no_sinks) { + auto test_sink = std::make_shared(); + auto test_logger = std::make_shared("", test_sink); + spdlog::set_default_logger(test_logger); + spdlog::set_level(spdlog::level::level_enum::trace); + ASSERT_THROW(Everest::Logging::init("logging_configs/no_sinks.ini", "liblog_test"), Everest::EverestConfigError); +} + +TEST_F(LibLogUnitTest, test_init_console_sink) { + Everest::Logging::init("logging_configs/console.ini", "liblog_test"); + log_with_all_loglevels(); +} + +TEST_F(LibLogUnitTest, test_init_console_sink_no_process_name) { + Everest::Logging::init("logging_configs/console.ini"); + log_with_all_loglevels(); +} + +TEST_F(LibLogUnitTest, test_init_console_sink_correct_filter) { + Everest::Logging::init("logging_configs/console.ini", "EVerest"); + log_with_all_loglevels(); +} + +TEST_F(LibLogUnitTest, test_init_textfile_sink_verb) { + auto log_dir = std::filesystem::path("liblog_test_logs_verb"); + std::filesystem::remove_all(log_dir); + auto file_name = log_dir / "FileLog00000.log"; + Everest::Logging::init("logging_configs/textfile_verb.ini", "EVerest"); + log_with_all_loglevels(); + spdlog::default_logger()->flush(); + + ASSERT_EQ(count_log_entries(file_name), 7); +} + +TEST_F(LibLogUnitTest, test_init_textfile_sink_debg) { + auto log_dir = std::filesystem::path("liblog_test_logs_debg"); + std::filesystem::remove_all(log_dir); + auto file_name = log_dir / "FileLog00000.log"; + Everest::Logging::init("logging_configs/textfile_debg.ini", "EVerest"); + log_with_all_loglevels(); + spdlog::default_logger()->flush(); + + ASSERT_EQ(count_log_entries(file_name), 6); +} + +TEST_F(LibLogUnitTest, test_init_textfile_sink_info) { + auto log_dir = std::filesystem::path("liblog_test_logs_info"); + std::filesystem::remove_all(log_dir); + auto file_name = log_dir / "FileLog00000.log"; + Everest::Logging::init("logging_configs/textfile_info.ini", "EVerest"); + log_with_all_loglevels(); + spdlog::default_logger()->flush(); + + ASSERT_EQ(count_log_entries(file_name), 4); +} + +TEST_F(LibLogUnitTest, test_init_textfile_sink_warn) { + auto log_dir = std::filesystem::path("liblog_test_logs_warn"); + std::filesystem::remove_all(log_dir); + auto file_name = log_dir / "FileLog00000.log"; + Everest::Logging::init("logging_configs/textfile_warn.ini", "EVerest"); + log_with_all_loglevels(); + spdlog::default_logger()->flush(); + + ASSERT_EQ(count_log_entries(file_name), 3); +} + +TEST_F(LibLogUnitTest, test_init_textfile_sink_erro) { + auto log_dir = std::filesystem::path("liblog_test_logs_erro"); + std::filesystem::remove_all(log_dir); + auto file_name = log_dir / "FileLog00000.log"; + Everest::Logging::init("logging_configs/textfile_erro.ini", "EVerest"); + log_with_all_loglevels(); + spdlog::default_logger()->flush(); + + ASSERT_EQ(count_log_entries(file_name), 2); +} + +TEST_F(LibLogUnitTest, test_init_textfile_sink_crit) { + auto log_dir = std::filesystem::path("liblog_test_logs_crit"); + std::filesystem::remove_all(log_dir); + auto file_name = log_dir / "FileLog00000.log"; + Everest::Logging::init("logging_configs/textfile_crit.ini", "EVerest"); + log_with_all_loglevels(); + spdlog::default_logger()->flush(); + + ASSERT_EQ(count_log_entries(file_name), 1); +} + +TEST_F(LibLogUnitTest, test_init_textfile_sink_off) { + auto log_dir = std::filesystem::path("liblog_test_logs_off"); + std::filesystem::remove_all(log_dir); + auto file_name = log_dir / "FileLog00000.log"; + Everest::Logging::init("logging_configs/textfile_off.ini", "EVerest"); + log_with_all_loglevels(); + spdlog::default_logger()->flush(); + + ASSERT_EQ(count_log_entries(file_name), 0); +} + +TEST_F(LibLogUnitTest, test_init_textfile_sink_verb_rotate) { + auto log_dir = std::filesystem::path("liblog_test_logs_verb_rotate"); + std::filesystem::remove_all(log_dir); + Everest::Logging::init("logging_configs/textfile_verb_rotate.ini", "EVerest"); + log_with_all_loglevels(); + spdlog::default_logger()->flush(); + + auto count = 0; + for (auto& entry : std::filesystem::directory_iterator(log_dir)) { + count += 1; + } + + ASSERT_EQ(count, 5); +} + +TEST_F(LibLogUnitTest, test_init_textfile_sink_verb_broken_filename) { + auto log_dir = std::filesystem::path("liblog_test_logs_verb_rotate_broken_filename"); + std::filesystem::remove_all(log_dir); + auto file_name = log_dir / "NoFormatString00000.log"; + Everest::Logging::init("logging_configs/textfile_verb_broken_filename.ini", "EVerest"); + log_with_all_loglevels(); + spdlog::default_logger()->flush(); + + auto count = 0; + for (auto& entry : std::filesystem::directory_iterator(log_dir)) { + count += 1; + } + + ASSERT_EQ(count, 5); + + ASSERT_EQ(count_log_entries(file_name), 1); +} + +} // namespace tests } // namespace Logging } // namespace Everest diff --git a/tests/logging_configs/console.ini b/tests/logging_configs/console.ini new file mode 100644 index 0000000..b239832 --- /dev/null +++ b/tests/logging_configs/console.ini @@ -0,0 +1,14 @@ +[Core] +DisableLogging=false +Filter="(%Severity% >= VERB and %Process% contains EVerest)" + +[Sinks.Console] +Destination=Console +Format="%TimeStamp% \033[1;32m%Process%\033[0m [\033[1;32m%ProcessID%\033[0m] [%Severity%] {\033[1;34m%ThreadID%\033[0m} \033[1;36m%function%\033[0m \033[1;30m%file%:\033[0m\033[1;32m%line%\033[0m: %Message%" +Asynchronous=false +AutoFlush=true +SeverityStringColorDebug="\033[1;30m" +SeverityStringColorInfo="\033[1;37m" +SeverityStringColorWarning="\033[1;33m" +SeverityStringColorError="\033[1;31m" +SeverityStringColorCritical="\033[1;35m" diff --git a/tests/logging_configs/console_crit.ini b/tests/logging_configs/console_crit.ini new file mode 100644 index 0000000..56f99e0 --- /dev/null +++ b/tests/logging_configs/console_crit.ini @@ -0,0 +1,14 @@ +[Core] +DisableLogging=false +Filter="(%Severity% >= CRIT and %Process% contains EVerest)" + +[Sinks.Console] +Destination=Console +Format="%TimeStamp% \033[1;32m%Process%\033[0m [\033[1;32m%ProcessID%\033[0m] [%Severity%] {\033[1;34m%ThreadID%\033[0m} \033[1;36m%function%\033[0m \033[1;30m%file%:\033[0m\033[1;32m%line%\033[0m: %Message%" +Asynchronous=false +AutoFlush=true +SeverityStringColorDebug="\033[1;30m" +SeverityStringColorInfo="\033[1;37m" +SeverityStringColorWarning="\033[1;33m" +SeverityStringColorError="\033[1;31m" +SeverityStringColorCritical="\033[1;35m" diff --git a/tests/logging_configs/console_debg.ini b/tests/logging_configs/console_debg.ini new file mode 100644 index 0000000..1601fd1 --- /dev/null +++ b/tests/logging_configs/console_debg.ini @@ -0,0 +1,14 @@ +[Core] +DisableLogging=false +Filter="(%Severity% >= DEBG and %Process% contains EVerest)" + +[Sinks.Console] +Destination=Console +Format="%TimeStamp% \033[1;32m%Process%\033[0m [\033[1;32m%ProcessID%\033[0m] [%Severity%] {\033[1;34m%ThreadID%\033[0m} \033[1;36m%function%\033[0m \033[1;30m%file%:\033[0m\033[1;32m%line%\033[0m: %Message%" +Asynchronous=false +AutoFlush=true +SeverityStringColorDebug="\033[1;30m" +SeverityStringColorInfo="\033[1;37m" +SeverityStringColorWarning="\033[1;33m" +SeverityStringColorError="\033[1;31m" +SeverityStringColorCritical="\033[1;35m" diff --git a/tests/logging_configs/console_erro.ini b/tests/logging_configs/console_erro.ini new file mode 100644 index 0000000..44fdeba --- /dev/null +++ b/tests/logging_configs/console_erro.ini @@ -0,0 +1,14 @@ +[Core] +DisableLogging=false +Filter="(%Severity% >= ERRO and %Process% contains EVerest)" + +[Sinks.Console] +Destination=Console +Format="%TimeStamp% \033[1;32m%Process%\033[0m [\033[1;32m%ProcessID%\033[0m] [%Severity%] {\033[1;34m%ThreadID%\033[0m} \033[1;36m%function%\033[0m \033[1;30m%file%:\033[0m\033[1;32m%line%\033[0m: %Message%" +Asynchronous=false +AutoFlush=true +SeverityStringColorDebug="\033[1;30m" +SeverityStringColorInfo="\033[1;37m" +SeverityStringColorWarning="\033[1;33m" +SeverityStringColorError="\033[1;31m" +SeverityStringColorCritical="\033[1;35m" diff --git a/tests/logging_configs/console_info.ini b/tests/logging_configs/console_info.ini new file mode 100644 index 0000000..354074d --- /dev/null +++ b/tests/logging_configs/console_info.ini @@ -0,0 +1,14 @@ +[Core] +DisableLogging=false +Filter="(%Severity% >= INFO and %Process% contains EVerest)" + +[Sinks.Console] +Destination=Console +Format="%TimeStamp% \033[1;32m%Process%\033[0m [\033[1;32m%ProcessID%\033[0m] [%Severity%] {\033[1;34m%ThreadID%\033[0m} \033[1;36m%function%\033[0m \033[1;30m%file%:\033[0m\033[1;32m%line%\033[0m: %Message%" +Asynchronous=false +AutoFlush=true +SeverityStringColorDebug="\033[1;30m" +SeverityStringColorInfo="\033[1;37m" +SeverityStringColorWarning="\033[1;33m" +SeverityStringColorError="\033[1;31m" +SeverityStringColorCritical="\033[1;35m" diff --git a/tests/logging_configs/console_warn.ini b/tests/logging_configs/console_warn.ini new file mode 100644 index 0000000..86ec5d5 --- /dev/null +++ b/tests/logging_configs/console_warn.ini @@ -0,0 +1,14 @@ +[Core] +DisableLogging=false +Filter="(%Severity% >= WARN and %Process% contains EVerest)" + +[Sinks.Console] +Destination=Console +Format="%TimeStamp% \033[1;32m%Process%\033[0m [\033[1;32m%ProcessID%\033[0m] [%Severity%] {\033[1;34m%ThreadID%\033[0m} \033[1;36m%function%\033[0m \033[1;30m%file%:\033[0m\033[1;32m%line%\033[0m: %Message%" +Asynchronous=false +AutoFlush=true +SeverityStringColorDebug="\033[1;30m" +SeverityStringColorInfo="\033[1;37m" +SeverityStringColorWarning="\033[1;33m" +SeverityStringColorError="\033[1;31m" +SeverityStringColorCritical="\033[1;35m" diff --git a/tests/logging_configs/no_sinks.ini b/tests/logging_configs/no_sinks.ini new file mode 100644 index 0000000..6aa70a5 --- /dev/null +++ b/tests/logging_configs/no_sinks.ini @@ -0,0 +1,3 @@ +[Core] +DisableLogging=false +Filter="(%Severity% >= VERB and %Process% contains EVerest)" diff --git a/tests/logging_configs/textfile_crit.ini b/tests/logging_configs/textfile_crit.ini new file mode 100644 index 0000000..df79f1f --- /dev/null +++ b/tests/logging_configs/textfile_crit.ini @@ -0,0 +1,10 @@ +[Core] +DisableLogging=false +Filter="(%Severity% >= CRIT and %Process% contains EVerest)" + +[Sinks.TextFile] +Destination=TextFile +FileName="liblog_test_logs_crit/FileLog%5N.log" +Format = "%TimeStamp% [%Severity%] %Message%" +RotationSize = 500 # bytes +MaxFiles = 5 diff --git a/tests/logging_configs/textfile_debg.ini b/tests/logging_configs/textfile_debg.ini new file mode 100644 index 0000000..a8ecd1b --- /dev/null +++ b/tests/logging_configs/textfile_debg.ini @@ -0,0 +1,10 @@ +[Core] +DisableLogging=false +Filter="(%Severity% >= DEBG and %Process% contains EVerest)" + +[Sinks.TextFile] +Destination=TextFile +FileName="liblog_test_logs_debg/FileLog%5N.log" +Format = "%TimeStamp% [%Severity%] %Message%" +RotationSize = 500 # bytes +MaxFiles = 5 diff --git a/tests/logging_configs/textfile_erro.ini b/tests/logging_configs/textfile_erro.ini new file mode 100644 index 0000000..87ec90d --- /dev/null +++ b/tests/logging_configs/textfile_erro.ini @@ -0,0 +1,10 @@ +[Core] +DisableLogging=false +Filter="(%Severity% >= ERRO and %Process% contains EVerest)" + +[Sinks.TextFile] +Destination=TextFile +FileName="liblog_test_logs_erro/FileLog%5N.log" +Format = "%TimeStamp% [%Severity%] %Message%" +RotationSize = 500 # bytes +MaxFiles = 5 diff --git a/tests/logging_configs/textfile_info.ini b/tests/logging_configs/textfile_info.ini new file mode 100644 index 0000000..33699a3 --- /dev/null +++ b/tests/logging_configs/textfile_info.ini @@ -0,0 +1,10 @@ +[Core] +DisableLogging=false +Filter="(%Severity% >= INFO and %Process% contains EVerest)" + +[Sinks.TextFile] +Destination=TextFile +FileName="liblog_test_logs_info/FileLog%5N.log" +Format = "%TimeStamp% [%Severity%] %Message%" +RotationSize = 500 # bytes +MaxFiles = 5 diff --git a/tests/logging_configs/textfile_off.ini b/tests/logging_configs/textfile_off.ini new file mode 100644 index 0000000..89e3f58 --- /dev/null +++ b/tests/logging_configs/textfile_off.ini @@ -0,0 +1,10 @@ +[Core] +DisableLogging=false +Filter="(%Severity% > CRIT and %Process% contains EVerest)" + +[Sinks.TextFile] +Destination=TextFile +FileName="liblog_test_logs_off/FileLog%5N.log" +Format = "%TimeStamp% [%Severity%] %Message%" +RotationSize = 500 # bytes +MaxFiles = 5 diff --git a/tests/logging_configs/textfile_verb.ini b/tests/logging_configs/textfile_verb.ini new file mode 100644 index 0000000..2299649 --- /dev/null +++ b/tests/logging_configs/textfile_verb.ini @@ -0,0 +1,10 @@ +[Core] +DisableLogging=false +Filter="(%Severity% >= VERB and %Process% contains EVerest)" + +[Sinks.TextFile] +Destination=TextFile +FileName="liblog_test_logs_verb/FileLog%5N.log" +Format = "%TimeStamp% [%Severity%] %Message%" +RotationSize = 500 # bytes +MaxFiles = 5 diff --git a/tests/logging_configs/textfile_verb_broken_filename.ini b/tests/logging_configs/textfile_verb_broken_filename.ini new file mode 100644 index 0000000..80aef15 --- /dev/null +++ b/tests/logging_configs/textfile_verb_broken_filename.ini @@ -0,0 +1,10 @@ +[Core] +DisableLogging=false +Filter="(%Severity% >= VERB and %Process% contains EVerest)" + +[Sinks.TextFile] +Destination=TextFile +FileName="liblog_test_logs_verb_rotate_broken_filename/NoFormatString.log" +Format = "%TimeStamp% [%Severity%] %Message%" +RotationSize = 10 # bytes +MaxFiles = 5 diff --git a/tests/logging_configs/textfile_verb_rotate.ini b/tests/logging_configs/textfile_verb_rotate.ini new file mode 100644 index 0000000..f802b5f --- /dev/null +++ b/tests/logging_configs/textfile_verb_rotate.ini @@ -0,0 +1,10 @@ +[Core] +DisableLogging=false +Filter="(%Severity% >= VERB and %Process% contains EVerest)" + +[Sinks.TextFile] +Destination=TextFile +FileName="liblog_test_logs_verb_rotate/FileLog%5N.log" +Format = "%TimeStamp% [%Severity%] %Message%" +RotationSize = 10 # bytes +MaxFiles = 5 diff --git a/tests/logging_configs/textfile_warn.ini b/tests/logging_configs/textfile_warn.ini new file mode 100644 index 0000000..da28711 --- /dev/null +++ b/tests/logging_configs/textfile_warn.ini @@ -0,0 +1,10 @@ +[Core] +DisableLogging=false +Filter="(%Severity% >= WARN and %Process% contains EVerest)" + +[Sinks.TextFile] +Destination=TextFile +FileName="liblog_test_logs_warn/FileLog%5N.log" +Format = "%TimeStamp% [%Severity%] %Message%" +RotationSize = 500 # bytes +MaxFiles = 5 From c65ff9d6f65689afb4799f9d7fb64cf05081596d Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Tue, 13 Aug 2024 15:08:52 +0200 Subject: [PATCH 18/47] Set LOG_INSTALL to OFF in edm mode Signed-off-by: Kai-Uwe Hermann --- CMakeLists.txt | 3 +++ 1 file changed, 3 insertions(+) diff --git a/CMakeLists.txt b/CMakeLists.txt index 5109b37..a1e0487 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -29,6 +29,9 @@ endif() if(NOT DISABLE_EDM) evc_setup_edm() + + # In EDM mode, we can't install exports (because the dependencies usually do not install their exports) + set(LOG_INSTALL OFF) endif() # library dependencies From db29554d790ba6a97edaca40cca2db69683ad057 Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Tue, 13 Aug 2024 15:09:37 +0200 Subject: [PATCH 19/47] Prefix coverage targets with PROJECT_NAME Signed-off-by: Kai-Uwe Hermann --- CMakeLists.txt | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/CMakeLists.txt b/CMakeLists.txt index a1e0487..64b3fe9 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -92,14 +92,14 @@ if(LIBLOG_BUILD_TESTING) add_subdirectory(tests) setup_target_for_coverage_gcovr_html( - NAME gcovr_coverage_liblog + NAME ${PROJECT_NAME}_gcovr_coverage EXECUTABLE ctest DEPENDENCIES ${PROJECT_NAME}_tests EXCLUDE "examples/*" ) setup_target_for_coverage_lcov( - NAME lcov_coverage_liblog + NAME ${PROJECT_NAME}_lcov_coverage EXECUTABLE ctest DEPENDENCIES ${PROJECT_NAME}_tests LCOV_ARGS "--ignore-errors=empty,missing" From e221a543d66823c15c9e3629b43de48034b77db8 Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Tue, 13 Aug 2024 17:44:03 +0200 Subject: [PATCH 20/47] Add syslog smoketests Signed-off-by: Kai-Uwe Hermann --- tests/CMakeLists.txt | 3 ++- tests/liblog_test.cpp | 10 ++++++++++ tests/logging_configs/syslog.ini | 8 ++++++++ 3 files changed, 20 insertions(+), 1 deletion(-) create mode 100644 tests/logging_configs/syslog.ini diff --git a/tests/CMakeLists.txt b/tests/CMakeLists.txt index a04ee14..1c20f78 100644 --- a/tests/CMakeLists.txt +++ b/tests/CMakeLists.txt @@ -31,4 +31,5 @@ configure_file(logging_configs/textfile_info.ini logging_configs/textfile_info.i configure_file(logging_configs/textfile_warn.ini logging_configs/textfile_warn.ini COPYONLY) configure_file(logging_configs/textfile_erro.ini logging_configs/textfile_erro.ini COPYONLY) configure_file(logging_configs/textfile_crit.ini logging_configs/textfile_crit.ini COPYONLY) -configure_file(logging_configs/textfile_off.ini logging_configs/textfile_off.ini COPYONLY) \ No newline at end of file +configure_file(logging_configs/textfile_off.ini logging_configs/textfile_off.ini COPYONLY) +configure_file(logging_configs/syslog.ini logging_configs/syslog.ini COPYONLY) diff --git a/tests/liblog_test.cpp b/tests/liblog_test.cpp index f73f4d4..92107f1 100644 --- a/tests/liblog_test.cpp +++ b/tests/liblog_test.cpp @@ -240,6 +240,16 @@ TEST_F(LibLogUnitTest, test_init_textfile_sink_verb_broken_filename) { ASSERT_EQ(count_log_entries(file_name), 1); } +TEST_F(LibLogUnitTest, test_init_syslog_sink) { + Everest::Logging::init("logging_configs/syslog.ini", "EVerest"); + log_with_all_loglevels(); +} + +TEST_F(LibLogUnitTest, test_init_syslog_sink_filtered) { + Everest::Logging::init("logging_configs/syslog.ini", "Everest"); + log_with_all_loglevels(); +} + } // namespace tests } // namespace Logging } // namespace Everest diff --git a/tests/logging_configs/syslog.ini b/tests/logging_configs/syslog.ini new file mode 100644 index 0000000..76dc5ca --- /dev/null +++ b/tests/logging_configs/syslog.ini @@ -0,0 +1,8 @@ +[Core] +DisableLogging=false +Filter="(%Severity% >= VERB and %Process% contains EVerest)" + +[Sinks.Syslog] +Destination=Syslog +Format="%TimeStamp% [%Severity%] %Message%" +EnableFormatting=false From a4d8c2c3a3e0f904f4df3dfdc82ec82f8344d8e2 Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Tue, 13 Aug 2024 17:44:29 +0200 Subject: [PATCH 21/47] Add console defaults smoketest Signed-off-by: Kai-Uwe Hermann --- tests/CMakeLists.txt | 2 +- tests/liblog_test.cpp | 5 +++++ tests/logging_configs/console_defaults.ini | 5 +++++ 3 files changed, 11 insertions(+), 1 deletion(-) create mode 100644 tests/logging_configs/console_defaults.ini diff --git a/tests/CMakeLists.txt b/tests/CMakeLists.txt index 1c20f78..1e8b448 100644 --- a/tests/CMakeLists.txt +++ b/tests/CMakeLists.txt @@ -22,7 +22,7 @@ add_test(${TEST_TARGET_NAME} ${TEST_TARGET_NAME}) # copy logging configs configure_file(logging_configs/no_sinks.ini logging_configs/no_sinks.ini COPYONLY) configure_file(logging_configs/console.ini logging_configs/console.ini COPYONLY) - +configure_file(logging_configs/console_defaults.ini logging_configs/console_defaults.ini COPYONLY) configure_file(logging_configs/textfile_verb.ini logging_configs/textfile_verb.ini COPYONLY) configure_file(logging_configs/textfile_verb_rotate.ini logging_configs/textfile_verb_rotate.ini COPYONLY) configure_file(logging_configs/textfile_verb_broken_filename.ini logging_configs/textfile_verb_broken_filename.ini COPYONLY) diff --git a/tests/liblog_test.cpp b/tests/liblog_test.cpp index 92107f1..3a8ccd4 100644 --- a/tests/liblog_test.cpp +++ b/tests/liblog_test.cpp @@ -120,6 +120,11 @@ TEST_F(LibLogUnitTest, test_init_console_sink) { log_with_all_loglevels(); } +TEST_F(LibLogUnitTest, test_init_console_sink_defaults) { + Everest::Logging::init("logging_configs/console_defaults.ini", "liblog_test"); + log_with_all_loglevels(); +} + TEST_F(LibLogUnitTest, test_init_console_sink_no_process_name) { Everest::Logging::init("logging_configs/console.ini"); log_with_all_loglevels(); diff --git a/tests/logging_configs/console_defaults.ini b/tests/logging_configs/console_defaults.ini new file mode 100644 index 0000000..d4aa642 --- /dev/null +++ b/tests/logging_configs/console_defaults.ini @@ -0,0 +1,5 @@ +[Core] +DisableLogging=false + +[Sinks.Console] +Destination=Console From be05d337586f5a6e25e0482c9d4e23963f2eeafa Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Thu, 15 Aug 2024 15:59:18 +0200 Subject: [PATCH 22/47] Add unit test for trace functionality Signed-off-by: Kai-Uwe Hermann --- tests/CMakeLists.txt | 6 +++++- tests/liblog_test.cpp | 10 ++++++++++ 2 files changed, 15 insertions(+), 1 deletion(-) diff --git a/tests/CMakeLists.txt b/tests/CMakeLists.txt index 1e8b448..1ed3531 100644 --- a/tests/CMakeLists.txt +++ b/tests/CMakeLists.txt @@ -10,13 +10,17 @@ target_include_directories(log target_link_libraries(${TEST_TARGET_NAME} PRIVATE everest::log GTest::gtest_main - GTest::gtest_main + GTest::gmock_main ) target_sources(${TEST_TARGET_NAME} PRIVATE liblog_test.cpp ) +if (BUILD_BACKTRACE_SUPPORT) + target_compile_definitions(${TEST_TARGET_NAME} PRIVATE WITH_LIBBACKTRACE) +endif() + add_test(${TEST_TARGET_NAME} ${TEST_TARGET_NAME}) # copy logging configs diff --git a/tests/liblog_test.cpp b/tests/liblog_test.cpp index 3a8ccd4..ce2f3cb 100644 --- a/tests/liblog_test.cpp +++ b/tests/liblog_test.cpp @@ -6,6 +6,7 @@ #include #include +#include #include #include @@ -255,6 +256,15 @@ TEST_F(LibLogUnitTest, test_init_syslog_sink_filtered) { log_with_all_loglevels(); } +TEST_F(LibLogUnitTest, test_trace) { + auto trace_str = Everest::Logging::trace(); +#ifdef WITH_LIBBACKTRACE + EXPECT_THAT(trace_str, ::testing::StartsWith("#0: Everest::Logging::tests::LibLogUnitTest_test_trace_Test::TestBody()")); +#else + ASSERT_EQ(trace_str, "Backtrace functionality not built in\n"); +#endif +} + } // namespace tests } // namespace Logging } // namespace Everest From 4922edb014c068527e259f2ed37d63255ae52e3e Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Thu, 15 Aug 2024 16:00:18 +0200 Subject: [PATCH 23/47] Generate code coverage and upload gcovr coverage report as artifact Signed-off-by: Kai-Uwe Hermann --- .ci/build-kit/install_and_test.sh | 2 ++ .github/workflows/build_and_test.yaml | 9 +++++++-- 2 files changed, 9 insertions(+), 2 deletions(-) diff --git a/.ci/build-kit/install_and_test.sh b/.ci/build-kit/install_and_test.sh index 26b42a2..43e4a26 100755 --- a/.ci/build-kit/install_and_test.sh +++ b/.ci/build-kit/install_and_test.sh @@ -13,3 +13,5 @@ cmake \ ninja -j$(nproc) -C build install ninja -j$(nproc) -C build test + +ninja -j$(nproc) -C build everest-log_gcovr_coverage diff --git a/.github/workflows/build_and_test.yaml b/.github/workflows/build_and_test.yaml index cc4457f..526f42c 100644 --- a/.github/workflows/build_and_test.yaml +++ b/.github/workflows/build_and_test.yaml @@ -53,8 +53,13 @@ jobs: build-kit run-script install_and_test - name: Archive test results if: always() - uses: actions/upload-artifact@v3 + uses: actions/upload-artifact@v4 with: name: ctest-report path: /workspace/build/tests/Testing/Temporary/LastTest.log - + - name: Archive coverage report + if: always() + uses: actions/upload-artifact@v4 + with: + name: gcovr-coverage + path: /workspace/build/everest-log_gcovr_coverage From 5e1ddc33c7db827ea59583e7db1f484acde49c67 Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Thu, 15 Aug 2024 16:11:01 +0200 Subject: [PATCH 24/47] clang-format Signed-off-by: Kai-Uwe Hermann --- tests/liblog_test.cpp | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/tests/liblog_test.cpp b/tests/liblog_test.cpp index ce2f3cb..ef4b836 100644 --- a/tests/liblog_test.cpp +++ b/tests/liblog_test.cpp @@ -5,8 +5,8 @@ #include #include -#include #include +#include #include #include @@ -259,7 +259,8 @@ TEST_F(LibLogUnitTest, test_init_syslog_sink_filtered) { TEST_F(LibLogUnitTest, test_trace) { auto trace_str = Everest::Logging::trace(); #ifdef WITH_LIBBACKTRACE - EXPECT_THAT(trace_str, ::testing::StartsWith("#0: Everest::Logging::tests::LibLogUnitTest_test_trace_Test::TestBody()")); + EXPECT_THAT(trace_str, + ::testing::StartsWith("#0: Everest::Logging::tests::LibLogUnitTest_test_trace_Test::TestBody()")); #else ASSERT_EQ(trace_str, "Backtrace functionality not built in\n"); #endif From c2bb12452e1472fa60d783746d2a9f22b306341a Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Thu, 15 Aug 2024 16:18:32 +0200 Subject: [PATCH 25/47] Only set cmake_policy CMP0167 (FindBoost handling) in cmake >= 3.30 Signed-off-by: Kai-Uwe Hermann --- CMakeLists.txt | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/CMakeLists.txt b/CMakeLists.txt index 64b3fe9..24c7897 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -36,7 +36,9 @@ endif() # library dependencies # use cmakes FindBoost module until we require Boost 1.70+ which provides its own BoostConfig.cmake -cmake_policy(SET CMP0167 OLD) +if("${CMAKE_VERSION}" VERSION_GREATER_EQUAL "3.30") + cmake_policy(SET CMP0167 OLD) +endif() if (LIBLOG_USE_BOOST_FILESYSTEM) message(STATUS "Using boost/filesystem instead of std::filesystem") find_package(Boost COMPONENTS log_setup log filesystem REQUIRED) From e40185a51d14634182431f2cfb4253f488b93c66 Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Thu, 15 Aug 2024 16:21:38 +0200 Subject: [PATCH 26/47] install gcovr 6 Signed-off-by: Kai-Uwe Hermann --- .ci/build-kit/install_and_test.sh | 2 ++ 1 file changed, 2 insertions(+) diff --git a/.ci/build-kit/install_and_test.sh b/.ci/build-kit/install_and_test.sh index 43e4a26..93ce108 100755 --- a/.ci/build-kit/install_and_test.sh +++ b/.ci/build-kit/install_and_test.sh @@ -14,4 +14,6 @@ ninja -j$(nproc) -C build install ninja -j$(nproc) -C build test +pip install gcovr==6 + ninja -j$(nproc) -C build everest-log_gcovr_coverage From 4e876bb2133a0326e0207fa8ed329edb019fccca Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Thu, 15 Aug 2024 16:38:00 +0200 Subject: [PATCH 27/47] Copy ctest-report and gcovr-coverage after install_and_test.sh for uploading as artifacts Signed-off-by: Kai-Uwe Hermann --- .ci/build-kit/install_and_test.sh | 3 +++ .github/workflows/build_and_test.yaml | 4 ++-- 2 files changed, 5 insertions(+), 2 deletions(-) diff --git a/.ci/build-kit/install_and_test.sh b/.ci/build-kit/install_and_test.sh index 93ce108..4cc5b63 100755 --- a/.ci/build-kit/install_and_test.sh +++ b/.ci/build-kit/install_and_test.sh @@ -12,6 +12,9 @@ cmake \ ninja -j$(nproc) -C build install +trap "cp build/Testing/Temporary/LastTest.log /ext/ctest-report" EXIT +trap "cp -R /workspace/build/everest-log_gcovr_coverage /ext/gcovr_coverage" EXIT + ninja -j$(nproc) -C build test pip install gcovr==6 diff --git a/.github/workflows/build_and_test.yaml b/.github/workflows/build_and_test.yaml index 526f42c..2966e30 100644 --- a/.github/workflows/build_and_test.yaml +++ b/.github/workflows/build_and_test.yaml @@ -56,10 +56,10 @@ jobs: uses: actions/upload-artifact@v4 with: name: ctest-report - path: /workspace/build/tests/Testing/Temporary/LastTest.log + path: ${{ github.workspace }}/ctest-report - name: Archive coverage report if: always() uses: actions/upload-artifact@v4 with: name: gcovr-coverage - path: /workspace/build/everest-log_gcovr_coverage + path: ${{ github.workspace }}/gcovr-coverage From 7e1245243c1a7990ac0952e421d682e81012aa48 Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Thu, 15 Aug 2024 16:44:24 +0200 Subject: [PATCH 28/47] Attempt to fix path of gcovr output dir Signed-off-by: Kai-Uwe Hermann --- .ci/build-kit/install_and_test.sh | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.ci/build-kit/install_and_test.sh b/.ci/build-kit/install_and_test.sh index 4cc5b63..23e3fdc 100755 --- a/.ci/build-kit/install_and_test.sh +++ b/.ci/build-kit/install_and_test.sh @@ -13,7 +13,7 @@ cmake \ ninja -j$(nproc) -C build install trap "cp build/Testing/Temporary/LastTest.log /ext/ctest-report" EXIT -trap "cp -R /workspace/build/everest-log_gcovr_coverage /ext/gcovr_coverage" EXIT +trap "cp -R build/everest-log_gcovr_coverage /ext/gcovr_coverage" EXIT ninja -j$(nproc) -C build test From 84ab5a7b7a63e599af1ca3be37b7d307f29744bd Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Thu, 15 Aug 2024 16:46:50 +0200 Subject: [PATCH 29/47] path fix Signed-off-by: Kai-Uwe Hermann --- .github/workflows/build_and_test.yaml | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/.github/workflows/build_and_test.yaml b/.github/workflows/build_and_test.yaml index 2966e30..de7d992 100644 --- a/.github/workflows/build_and_test.yaml +++ b/.github/workflows/build_and_test.yaml @@ -56,10 +56,10 @@ jobs: uses: actions/upload-artifact@v4 with: name: ctest-report - path: ${{ github.workspace }}/ctest-report + path: ${{ github.workspace }}/../ctest-report - name: Archive coverage report if: always() uses: actions/upload-artifact@v4 with: name: gcovr-coverage - path: ${{ github.workspace }}/gcovr-coverage + path: ${{ github.workspace }}/../gcovr-coverage From 68294cd2485dd6ac657c9e09efe159d9b2fdfdb8 Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Thu, 15 Aug 2024 16:48:34 +0200 Subject: [PATCH 30/47] revert last commit Signed-off-by: Kai-Uwe Hermann --- .github/workflows/build_and_test.yaml | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/.github/workflows/build_and_test.yaml b/.github/workflows/build_and_test.yaml index de7d992..2966e30 100644 --- a/.github/workflows/build_and_test.yaml +++ b/.github/workflows/build_and_test.yaml @@ -56,10 +56,10 @@ jobs: uses: actions/upload-artifact@v4 with: name: ctest-report - path: ${{ github.workspace }}/../ctest-report + path: ${{ github.workspace }}/ctest-report - name: Archive coverage report if: always() uses: actions/upload-artifact@v4 with: name: gcovr-coverage - path: ${{ github.workspace }}/../gcovr-coverage + path: ${{ github.workspace }}/gcovr-coverage From 213f21bf796e45953c65e172ac73451b246461b3 Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Thu, 15 Aug 2024 16:57:11 +0200 Subject: [PATCH 31/47] fix trap Signed-off-by: Kai-Uwe Hermann --- .ci/build-kit/install_and_test.sh | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/.ci/build-kit/install_and_test.sh b/.ci/build-kit/install_and_test.sh index 23e3fdc..e9e26d7 100755 --- a/.ci/build-kit/install_and_test.sh +++ b/.ci/build-kit/install_and_test.sh @@ -12,8 +12,7 @@ cmake \ ninja -j$(nproc) -C build install -trap "cp build/Testing/Temporary/LastTest.log /ext/ctest-report" EXIT -trap "cp -R build/everest-log_gcovr_coverage /ext/gcovr_coverage" EXIT +trap "cp build/Testing/Temporary/LastTest.log /ext/ctest-report && cp -R build/everest-log_gcovr_coverage /ext/gcovr_coverage" EXIT ninja -j$(nproc) -C build test From 0abde84e383f9e991e67cb9b07d34ffdd9778211 Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Thu, 15 Aug 2024 17:04:35 +0200 Subject: [PATCH 32/47] Rewrite trap Signed-off-by: Kai-Uwe Hermann --- .ci/build-kit/install_and_test.sh | 9 ++++++++- 1 file changed, 8 insertions(+), 1 deletion(-) diff --git a/.ci/build-kit/install_and_test.sh b/.ci/build-kit/install_and_test.sh index e9e26d7..07cb880 100755 --- a/.ci/build-kit/install_and_test.sh +++ b/.ci/build-kit/install_and_test.sh @@ -2,6 +2,11 @@ set -e +copy_logs() { + cp build/Testing/Temporary/LastTest.log /ext/ctest-report + cp -R build/everest-log_gcovr_coverage /ext/gcovr_coverage +} + cmake \ -B build \ -S "$EXT_MOUNT/source" \ @@ -12,10 +17,12 @@ cmake \ ninja -j$(nproc) -C build install -trap "cp build/Testing/Temporary/LastTest.log /ext/ctest-report && cp -R build/everest-log_gcovr_coverage /ext/gcovr_coverage" EXIT +trap "copy_logs" ERR ninja -j$(nproc) -C build test pip install gcovr==6 ninja -j$(nproc) -C build everest-log_gcovr_coverage + +copy_logs From 18280b8c711100f7755f0d227ea8c912ebebcd2b Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Thu, 15 Aug 2024 17:19:13 +0200 Subject: [PATCH 33/47] ls build Signed-off-by: Kai-Uwe Hermann --- .ci/build-kit/install_and_test.sh | 1 + 1 file changed, 1 insertion(+) diff --git a/.ci/build-kit/install_and_test.sh b/.ci/build-kit/install_and_test.sh index 07cb880..510f7e7 100755 --- a/.ci/build-kit/install_and_test.sh +++ b/.ci/build-kit/install_and_test.sh @@ -3,6 +3,7 @@ set -e copy_logs() { + ls build cp build/Testing/Temporary/LastTest.log /ext/ctest-report cp -R build/everest-log_gcovr_coverage /ext/gcovr_coverage } From 8e6227dd3d3cf3202aeb4665043e4d8bea82f237 Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Thu, 15 Aug 2024 17:21:35 +0200 Subject: [PATCH 34/47] Fix gcovr-coverage path Signed-off-by: Kai-Uwe Hermann --- .ci/build-kit/install_and_test.sh | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/.ci/build-kit/install_and_test.sh b/.ci/build-kit/install_and_test.sh index 510f7e7..9afe14e 100755 --- a/.ci/build-kit/install_and_test.sh +++ b/.ci/build-kit/install_and_test.sh @@ -3,9 +3,8 @@ set -e copy_logs() { - ls build cp build/Testing/Temporary/LastTest.log /ext/ctest-report - cp -R build/everest-log_gcovr_coverage /ext/gcovr_coverage + cp -R build/everest-log_gcovr_coverage /ext/gcovr-coverage } cmake \ From e3902036ffce29a0cceb8e0c401b46d3b1fc5160 Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Fri, 16 Aug 2024 11:18:26 +0200 Subject: [PATCH 35/47] Fix usage of current_process_name Signed-off-by: Kai-Uwe Hermann --- lib/logging.cpp | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/lib/logging.cpp b/lib/logging.cpp index 1fb7f74..693b2d5 100644 --- a/lib/logging.cpp +++ b/lib/logging.cpp @@ -432,13 +432,13 @@ void init(const std::string& logconf, std::string process_name) { formatter->add_flag('l').set_pattern(format); auto syslog_sink = - std::make_shared(parsed_filter, process_name, 0, LOG_USER, enable_formatting); + std::make_shared(parsed_filter, current_process_name, 0, LOG_USER, enable_formatting); syslog_sink->set_formatter(std::move(formatter)); sinks.push_back(syslog_sink); } } - update_process_name(process_name); + update_process_name(current_process_name); EVLOG_debug << "Logger initialized (using " << logconf << ")..."; } From 3d07bb96107788f3f52e526d3576f38f56c7b4b2 Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Fri, 16 Aug 2024 11:19:53 +0200 Subject: [PATCH 36/47] Make ctors with one argument explicit Signed-off-by: Kai-Uwe Hermann --- include/everest/logging.hpp | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/include/everest/logging.hpp b/include/everest/logging.hpp index 5e21136..f871917 100644 --- a/include/everest/logging.hpp +++ b/include/everest/logging.hpp @@ -45,7 +45,7 @@ struct LogSource { file(file), line(line), function(function) { } - LogSource(const std::string& function) : function(function), log_file(false), log_line(false) { + explicit LogSource(const std::string& function) : function(function), log_file(false), log_line(false) { } }; @@ -57,7 +57,7 @@ class EverestLogger { EverestLogger(const std::string& function, spdlog::level::level_enum level) : function(function), level(level), log_file(false), log_line(false), log_function(true) { } - EverestLogger(spdlog::level::level_enum level) : + explicit EverestLogger(spdlog::level::level_enum level) : level(level), log_file(false), log_line(false), log_function(false) { } From b4e088c343bf22c7900ae42ca15dc24f7bad89aa Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Mon, 19 Aug 2024 12:51:28 +0200 Subject: [PATCH 37/47] Fix get_process_name() /proc/PID/cmdline is NUL separated, treat it as such for parsing Signed-off-by: Kai-Uwe Hermann --- lib/logging.cpp | 20 ++++++++++++++++---- 1 file changed, 16 insertions(+), 4 deletions(-) diff --git a/lib/logging.cpp b/lib/logging.cpp index 693b2d5..e2a73c9 100644 --- a/lib/logging.cpp +++ b/lib/logging.cpp @@ -86,11 +86,23 @@ std::string get_process_name() { auto proc = "/proc/" + std::to_string(pid) + "/cmdline"; fs::path proc_path = fs::path(proc); std::ifstream cmdline_file(proc_path.c_str()); + std::vector cmdline; if (cmdline_file.is_open()) { - std::string cmdline; - cmdline_file >> cmdline; - auto cmdline_path = fs::path(cmdline); - process_name = cmdline_path.filename(); + std::string entry; + char input; + while (cmdline_file.get(input)) { + if (input == '\0') { + cmdline.push_back(entry); + entry = ""; + } else { + entry += input; + } + } + if (not cmdline.empty()) { + auto cmdline_path = fs::path(cmdline.at(0)); + process_name = cmdline_path.filename(); + } + cmdline_file.close(); } return process_name; } From 0175b707c42a313d5e37c916329720d2cd2a44e2 Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Mon, 19 Aug 2024 12:52:32 +0200 Subject: [PATCH 38/47] Add RotateOnOpen option to TextFile sink Signed-off-by: Kai-Uwe Hermann --- lib/logging.cpp | 5 ++-- tests/CMakeLists.txt | 1 + tests/liblog_test.cpp | 26 +++++++++++++++++++ .../textfile_verb_rotate_on_open.ini | 11 ++++++++ 4 files changed, 41 insertions(+), 2 deletions(-) create mode 100644 tests/logging_configs/textfile_verb_rotate_on_open.ini diff --git a/lib/logging.cpp b/lib/logging.cpp index e2a73c9..fe5b27c 100644 --- a/lib/logging.cpp +++ b/lib/logging.cpp @@ -432,10 +432,11 @@ void init(const std::string& logconf, std::string process_name) { auto file_name = sink["FileName"].get().get_value_or("%5N.log"); auto rotation_size = sink["RotationSize"].get().get_value_or(0); + auto rotate_on_open = sink["RotateOnOpen"].get().get_value_or(false); auto max_files = sink["MaxFiles"].get().get_value_or(0); - auto file_sink = - std::make_shared(parsed_filter, file_name, rotation_size, max_files, false); + auto file_sink = std::make_shared(parsed_filter, file_name, rotation_size, max_files, + rotate_on_open); file_sink->set_formatter(std::move(formatter)); sinks.push_back(file_sink); } else if (destination == "Syslog") { diff --git a/tests/CMakeLists.txt b/tests/CMakeLists.txt index 1ed3531..14f3667 100644 --- a/tests/CMakeLists.txt +++ b/tests/CMakeLists.txt @@ -29,6 +29,7 @@ configure_file(logging_configs/console.ini logging_configs/console.ini COPYONLY) configure_file(logging_configs/console_defaults.ini logging_configs/console_defaults.ini COPYONLY) configure_file(logging_configs/textfile_verb.ini logging_configs/textfile_verb.ini COPYONLY) configure_file(logging_configs/textfile_verb_rotate.ini logging_configs/textfile_verb_rotate.ini COPYONLY) +configure_file(logging_configs/textfile_verb_rotate_on_open.ini logging_configs/textfile_verb_rotate_on_open.ini COPYONLY) configure_file(logging_configs/textfile_verb_broken_filename.ini logging_configs/textfile_verb_broken_filename.ini COPYONLY) configure_file(logging_configs/textfile_debg.ini logging_configs/textfile_debg.ini COPYONLY) configure_file(logging_configs/textfile_info.ini logging_configs/textfile_info.ini COPYONLY) diff --git a/tests/liblog_test.cpp b/tests/liblog_test.cpp index ef4b836..b0284aa 100644 --- a/tests/liblog_test.cpp +++ b/tests/liblog_test.cpp @@ -228,6 +228,32 @@ TEST_F(LibLogUnitTest, test_init_textfile_sink_verb_rotate) { ASSERT_EQ(count, 5); } +TEST_F(LibLogUnitTest, test_init_textfile_sink_verb_rotate_on_open) { + auto log_dir = std::filesystem::path("liblog_test_logs_verb_rotate_on_open"); + std::filesystem::remove_all(log_dir); + Everest::Logging::init("logging_configs/textfile_verb_rotate_on_open.ini", "EVerest"); + log_with_all_loglevels(); + spdlog::default_logger()->flush(); + + auto count = 0; + for (auto& entry : std::filesystem::directory_iterator(log_dir)) { + count += 1; + } + + ASSERT_EQ(count, 4); + + Everest::Logging::init("logging_configs/textfile_verb_rotate_on_open.ini", "EVerest"); + log_with_all_loglevels(); + spdlog::default_logger()->flush(); + + auto count2 = 0; + for (auto& entry : std::filesystem::directory_iterator(log_dir)) { + count2 += 1; + } + + ASSERT_EQ(count2, 5); +} + TEST_F(LibLogUnitTest, test_init_textfile_sink_verb_broken_filename) { auto log_dir = std::filesystem::path("liblog_test_logs_verb_rotate_broken_filename"); std::filesystem::remove_all(log_dir); diff --git a/tests/logging_configs/textfile_verb_rotate_on_open.ini b/tests/logging_configs/textfile_verb_rotate_on_open.ini new file mode 100644 index 0000000..b324392 --- /dev/null +++ b/tests/logging_configs/textfile_verb_rotate_on_open.ini @@ -0,0 +1,11 @@ +[Core] +DisableLogging=false +Filter="(%Severity% >= VERB and %Process% contains EVerest)" + +[Sinks.TextFile] +Destination=TextFile +FileName="liblog_test_logs_verb_rotate_on_open/FileLog%5N.log" +Format = "%TimeStamp% [%Severity%] %Message%" +RotationSize = 150 # bytes +RotateOnOpen = true +MaxFiles = 5 From cfba2e3bba2148b4aad22cc21037f859c83e0b1d Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Mon, 19 Aug 2024 12:53:08 +0200 Subject: [PATCH 39/47] Add test for a broken format string in TextFile FileName Signed-off-by: Kai-Uwe Hermann --- tests/CMakeLists.txt | 1 + tests/liblog_test.cpp | 18 ++++++++++++++++++ .../textfile_verb_broken_format_string.ini | 10 ++++++++++ 3 files changed, 29 insertions(+) create mode 100644 tests/logging_configs/textfile_verb_broken_format_string.ini diff --git a/tests/CMakeLists.txt b/tests/CMakeLists.txt index 14f3667..e369c32 100644 --- a/tests/CMakeLists.txt +++ b/tests/CMakeLists.txt @@ -31,6 +31,7 @@ configure_file(logging_configs/textfile_verb.ini logging_configs/textfile_verb.i configure_file(logging_configs/textfile_verb_rotate.ini logging_configs/textfile_verb_rotate.ini COPYONLY) configure_file(logging_configs/textfile_verb_rotate_on_open.ini logging_configs/textfile_verb_rotate_on_open.ini COPYONLY) configure_file(logging_configs/textfile_verb_broken_filename.ini logging_configs/textfile_verb_broken_filename.ini COPYONLY) +configure_file(logging_configs/textfile_verb_broken_format_string.ini logging_configs/textfile_verb_broken_format_string.ini COPYONLY) configure_file(logging_configs/textfile_debg.ini logging_configs/textfile_debg.ini COPYONLY) configure_file(logging_configs/textfile_info.ini logging_configs/textfile_info.ini COPYONLY) configure_file(logging_configs/textfile_warn.ini logging_configs/textfile_warn.ini COPYONLY) diff --git a/tests/liblog_test.cpp b/tests/liblog_test.cpp index b0284aa..1036c28 100644 --- a/tests/liblog_test.cpp +++ b/tests/liblog_test.cpp @@ -272,6 +272,24 @@ TEST_F(LibLogUnitTest, test_init_textfile_sink_verb_broken_filename) { ASSERT_EQ(count_log_entries(file_name), 1); } +TEST_F(LibLogUnitTest, test_init_textfile_sink_verb_broken_format_string) { + auto log_dir = std::filesystem::path("liblog_test_logs_verb_rotate_broken_format_string"); + std::filesystem::remove_all(log_dir); + auto file_name = log_dir / "BrokenFormatString%s00000.log"; + Everest::Logging::init("logging_configs/textfile_verb_broken_format_string.ini", "EVerest"); + log_with_all_loglevels(); + spdlog::default_logger()->flush(); + + auto count = 0; + for (auto& entry : std::filesystem::directory_iterator(log_dir)) { + count += 1; + } + + ASSERT_EQ(count, 5); + + ASSERT_EQ(count_log_entries(file_name), 1); +} + TEST_F(LibLogUnitTest, test_init_syslog_sink) { Everest::Logging::init("logging_configs/syslog.ini", "EVerest"); log_with_all_loglevels(); diff --git a/tests/logging_configs/textfile_verb_broken_format_string.ini b/tests/logging_configs/textfile_verb_broken_format_string.ini new file mode 100644 index 0000000..9251a57 --- /dev/null +++ b/tests/logging_configs/textfile_verb_broken_format_string.ini @@ -0,0 +1,10 @@ +[Core] +DisableLogging=false +Filter="(%Severity% >= VERB and %Process% contains EVerest)" + +[Sinks.TextFile] +Destination=TextFile +FileName="liblog_test_logs_verb_rotate_broken_format_string/BrokenFormatString%s.log" +Format = "%TimeStamp% [%Severity%] %Message%" +RotationSize = 10 # bytes +MaxFiles = 5 From 501a003a78e1b7772ba23f1d8bc3b98fdea81e7a Mon Sep 17 00:00:00 2001 From: Andreas Heinrich Date: Mon, 2 Sep 2024 15:43:02 +0200 Subject: [PATCH 40/47] Update CI * Add `build-kit-liblog` * Use newer `build-kit-base` * Split up scripts * Refactor `build_and_test` workflow file Signed-off-by: Andreas Heinrich --- .ci/build-kit/docker/Dockerfile | 3 + .ci/build-kit/install_and_test.sh | 28 ------- .ci/build-kit/scripts/compile.sh | 21 ++++++ .ci/build-kit/scripts/install.sh | 9 +++ .ci/build-kit/scripts/run_coverage.sh | 12 +++ .ci/build-kit/scripts/run_unit_tests.sh | 12 +++ .github/workflows/build_and_test.yaml | 99 +++++++++++++++++++++---- 7 files changed, 142 insertions(+), 42 deletions(-) create mode 100644 .ci/build-kit/docker/Dockerfile delete mode 100755 .ci/build-kit/install_and_test.sh create mode 100755 .ci/build-kit/scripts/compile.sh create mode 100755 .ci/build-kit/scripts/install.sh create mode 100755 .ci/build-kit/scripts/run_coverage.sh create mode 100755 .ci/build-kit/scripts/run_unit_tests.sh diff --git a/.ci/build-kit/docker/Dockerfile b/.ci/build-kit/docker/Dockerfile new file mode 100644 index 0000000..ca655b1 --- /dev/null +++ b/.ci/build-kit/docker/Dockerfile @@ -0,0 +1,3 @@ +# syntax=docker/dockerfile:1 +ARG BASE_IMAGE_TAG=latest +FROM ghcr.io/everest/everest-ci/build-kit-base:${BASE_IMAGE_TAG} diff --git a/.ci/build-kit/install_and_test.sh b/.ci/build-kit/install_and_test.sh deleted file mode 100755 index 9afe14e..0000000 --- a/.ci/build-kit/install_and_test.sh +++ /dev/null @@ -1,28 +0,0 @@ -#!/bin/sh - -set -e - -copy_logs() { - cp build/Testing/Temporary/LastTest.log /ext/ctest-report - cp -R build/everest-log_gcovr_coverage /ext/gcovr-coverage -} - -cmake \ - -B build \ - -S "$EXT_MOUNT/source" \ - -G Ninja \ - -DBUILD_TESTING=ON \ - -DCMAKE_BUILD_TYPE=Debug \ - -DCMAKE_INSTALL_PREFIX="$WORKSPACE_PATH/dist" - -ninja -j$(nproc) -C build install - -trap "copy_logs" ERR - -ninja -j$(nproc) -C build test - -pip install gcovr==6 - -ninja -j$(nproc) -C build everest-log_gcovr_coverage - -copy_logs diff --git a/.ci/build-kit/scripts/compile.sh b/.ci/build-kit/scripts/compile.sh new file mode 100755 index 0000000..70e0b79 --- /dev/null +++ b/.ci/build-kit/scripts/compile.sh @@ -0,0 +1,21 @@ +#!/bin/sh + +cmake \ + -B "$EXT_MOUNT/build" \ + -S "$EXT_MOUNT/source" \ + -G Ninja \ + -DBUILD_TESTING=ON \ + -DCMAKE_BUILD_TYPE=Debug \ + -DCMAKE_INSTALL_PREFIX="$EXT_MOUNT/dist" +retVal=$? +if [ $retVal -ne 0 ]; then + echo "Configuring failed with return code $retVal" + exit $retVal +fi + +ninja -C build +retVal=$? +if [ $retVal -ne 0 ]; then + echo "Compiling failed with return code $retVal" + exit $retVal +fi diff --git a/.ci/build-kit/scripts/install.sh b/.ci/build-kit/scripts/install.sh new file mode 100755 index 0000000..f6db6f2 --- /dev/null +++ b/.ci/build-kit/scripts/install.sh @@ -0,0 +1,9 @@ +#!/bin/sh + +ninja -C build install +retVal=$? + +if [ $retVal -ne 0 ]; then + echo "Installation failed with return code $retVal" + exit $retVal +fi diff --git a/.ci/build-kit/scripts/run_coverage.sh b/.ci/build-kit/scripts/run_coverage.sh new file mode 100755 index 0000000..f011262 --- /dev/null +++ b/.ci/build-kit/scripts/run_coverage.sh @@ -0,0 +1,12 @@ +#!/bin/sh + +ninja -C build everest-log_gcovr_coverage +retVal=$? + +# Copy the generated coverage report to the mounted directory in any case +cp -R "$EXT_MOUNT/build/everest-log_gcovr_coverage" "$EXT_MOUNT/gcovr-coverage" + +if [ $retVal -ne 0 ]; then + echo "Coverage failed with return code $retVal" + exit $retVal +fi diff --git a/.ci/build-kit/scripts/run_unit_tests.sh b/.ci/build-kit/scripts/run_unit_tests.sh new file mode 100755 index 0000000..afcf937 --- /dev/null +++ b/.ci/build-kit/scripts/run_unit_tests.sh @@ -0,0 +1,12 @@ +#!/bin/sh + +ninja -C build test +retVal=$? + +# Copy the LastTest.log file to the mounted directory in any case +cp "$EXT_MOUNT/build/Testing/Temporary/LastTest.log" "$EXT_MOUNT/ctest-report" + +if [ $retVal -ne 0 ]; then + echo "Unit tests failed with return code $retVal" + exit $retValUnitTests +fi diff --git a/.github/workflows/build_and_test.yaml b/.github/workflows/build_and_test.yaml index 2966e30..2977ca1 100644 --- a/.github/workflows/build_and_test.yaml +++ b/.github/workflows/build_and_test.yaml @@ -1,7 +1,4 @@ -# Please reference work here https://github.com/EVerest/everest-core/tree/main/.github/workflows -# TODO: modify to reuse the above workflow to DRY up CI. - -name: Build and test liblog +name: Build, Lint and Test on: pull_request: workflow_dispatch: @@ -14,6 +11,13 @@ on: options: - 'ubuntu-22.04' - 'large-ubuntu-22.04-xxl' + schedule: + - cron: '33 13,1 * * *' + +env: + DOCKER_REGISTRY: ghcr.io + EVEREST_CI_VERSION: v1.3.1 + jobs: lint: name: Lint @@ -24,14 +28,53 @@ jobs: with: path: source - name: Run clang-format - uses: everest/everest-ci/github-actions/run-clang-format@v1.1.0 + uses: everest/everest-ci/github-actions/run-clang-format@v1.3.1 with: source-dir: source extensions: hpp,cpp exclude: cache - install_and_test: - name: Install and test + + # Since env variables can't be passed to reusable workflows, we need to pass them as outputs + setup-env: + name: Setup Environment + runs-on: ${{ inputs.runner || 'ubuntu-22.04' }} + outputs: + docker_registry: ${{ env.DOCKER_REGISTRY }} + everest_ci_version: ${{ env.EVEREST_CI_VERSION }} + steps: + - id: check + run: | + echo "Setting up environment" + + build-and-push-build-kit: + name: Build and Push Build Kit + uses: everest/everest-ci/.github/workflows/deploy-single-docker-image.yml@v1.3.1 + needs: setup-env + secrets: + SA_GITHUB_PAT: ${{ github.token }} + SA_GITHUB_USERNAME: ${{ github.actor }} + permissions: + contents: read + packages: write + with: + image_name: ${{ github.event.repository.name }}/build-kit-${{ github.event.repository.name }} + directory: .ci/build-kit/docker + docker_registry: ${{ needs.setup-env.outputs.docker_registry }} + github_ref_before: ${{ github.event.before }} + github_ref_after: ${{ github.event.after }} + platforms: linux/amd64 + depends_on_paths: | + .ci/build-kit + .github/workflows/build_and_test.yaml + build_args: | + BASE_IMAGE_TAG=${{ needs.setup-env.outputs.everest_ci_version }} + + build: + name: Build and Unit Tests + needs: build-and-push-build-kit runs-on: ${{ inputs.runner || 'ubuntu-22.04' }} + env: + BUILD_KIT_IMAGE: ${{ needs.build-and-push-build-kit.outputs.one_image_tag_long }} steps: - name: Checkout liblog uses: actions/checkout@v3 @@ -40,26 +83,54 @@ jobs: - name: Setup run scripts run: | mkdir scripts - rsync -a source/.ci/build-kit/ scripts + rsync -a source/.ci/build-kit/scripts scripts - name: Pull docker container run: | - docker pull --platform=linux/x86_64 --quiet ghcr.io/everest/build-kit-alpine:latest - docker image tag ghcr.io/everest/build-kit-alpine:latest build-kit - - name: Run install with tests + docker pull --platform=linux/x86_64 --quiet ${{ env.BUILD_KIT_IMAGE }} + docker image tag ${{ env.BUILD_KIT_IMAGE }} build-kit + - name: Compile run: | docker run \ - --volume "$(pwd):/ext" \ - --name test-container \ - build-kit run-script install_and_test + --volume "${{ github.workspace }}:/ext" \ + --name compile-container \ + build-kit run-script compile + docker commit compile-container build-image + - name: Run unit tests + run: | + docker run \ + --volume "${{ github.workspace }}:/ext" \ + --name unit-test-container \ + build-image run-script run_unit_tests + docker commit unit-test-container unit-test-image - name: Archive test results if: always() uses: actions/upload-artifact@v4 with: name: ctest-report path: ${{ github.workspace }}/ctest-report + - name: Run coverage + run: | + docker run \ + --volume "${{ github.workspace }}:/ext" \ + --name coverage-container \ + unit-test-image run-script run_coverage - name: Archive coverage report if: always() uses: actions/upload-artifact@v4 with: name: gcovr-coverage path: ${{ github.workspace }}/gcovr-coverage + - name: Create dist + run: | + docker run \ + --volume "${{ github.workspace }}:/ext" \ + --name install-container \ + build-image run-script install + - name: Tar dist dir and keep permissions + run: | + tar -czf dist.tar.gz dist + - name: Upload dist artifact + uses: actions/upload-artifact@v4.3.3 + with: + path: dist.tar.gz + name: dist From 6a15995152d89992c23d5311ead4569800e3d60a Mon Sep 17 00:00:00 2001 From: Andreas Heinrich Date: Mon, 2 Sep 2024 15:47:06 +0200 Subject: [PATCH 41/47] github.token -> secrets.GITHUB_TOKEN Signed-off-by: Andreas Heinrich --- .github/workflows/build_and_test.yaml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.github/workflows/build_and_test.yaml b/.github/workflows/build_and_test.yaml index 2977ca1..a29d854 100644 --- a/.github/workflows/build_and_test.yaml +++ b/.github/workflows/build_and_test.yaml @@ -51,7 +51,7 @@ jobs: uses: everest/everest-ci/.github/workflows/deploy-single-docker-image.yml@v1.3.1 needs: setup-env secrets: - SA_GITHUB_PAT: ${{ github.token }} + SA_GITHUB_PAT: ${{ secrets.GITHUB_TOKEN }} SA_GITHUB_USERNAME: ${{ github.actor }} permissions: contents: read From ee0455630935a468f1f8a8f13c40214d7bf2defc Mon Sep 17 00:00:00 2001 From: Andreas Heinrich Date: Mon, 2 Sep 2024 15:51:01 +0200 Subject: [PATCH 42/47] Add trailing slash Signed-off-by: Andreas Heinrich --- .github/workflows/build_and_test.yaml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.github/workflows/build_and_test.yaml b/.github/workflows/build_and_test.yaml index a29d854..4bb71d8 100644 --- a/.github/workflows/build_and_test.yaml +++ b/.github/workflows/build_and_test.yaml @@ -83,7 +83,7 @@ jobs: - name: Setup run scripts run: | mkdir scripts - rsync -a source/.ci/build-kit/scripts scripts + rsync -a source/.ci/build-kit/scripts/ scripts - name: Pull docker container run: | docker pull --platform=linux/x86_64 --quiet ${{ env.BUILD_KIT_IMAGE }} From 72467691d33134c65b271418ab96cdab6b120bb0 Mon Sep 17 00:00:00 2001 From: Andreas Heinrich Date: Mon, 2 Sep 2024 15:54:45 +0200 Subject: [PATCH 43/47] Fix build dir path Signed-off-by: Andreas Heinrich --- .ci/build-kit/scripts/compile.sh | 2 +- .ci/build-kit/scripts/install.sh | 2 +- .ci/build-kit/scripts/run_coverage.sh | 2 +- .ci/build-kit/scripts/run_unit_tests.sh | 2 +- 4 files changed, 4 insertions(+), 4 deletions(-) diff --git a/.ci/build-kit/scripts/compile.sh b/.ci/build-kit/scripts/compile.sh index 70e0b79..1c7a914 100755 --- a/.ci/build-kit/scripts/compile.sh +++ b/.ci/build-kit/scripts/compile.sh @@ -13,7 +13,7 @@ if [ $retVal -ne 0 ]; then exit $retVal fi -ninja -C build +ninja -C "$EXT_MOUNT/build" retVal=$? if [ $retVal -ne 0 ]; then echo "Compiling failed with return code $retVal" diff --git a/.ci/build-kit/scripts/install.sh b/.ci/build-kit/scripts/install.sh index f6db6f2..174dbc7 100755 --- a/.ci/build-kit/scripts/install.sh +++ b/.ci/build-kit/scripts/install.sh @@ -1,6 +1,6 @@ #!/bin/sh -ninja -C build install +ninja -C "$EXT_MOUNT/build" install retVal=$? if [ $retVal -ne 0 ]; then diff --git a/.ci/build-kit/scripts/run_coverage.sh b/.ci/build-kit/scripts/run_coverage.sh index f011262..7fda31f 100755 --- a/.ci/build-kit/scripts/run_coverage.sh +++ b/.ci/build-kit/scripts/run_coverage.sh @@ -1,6 +1,6 @@ #!/bin/sh -ninja -C build everest-log_gcovr_coverage +ninja -C "$EXT_MOUNT/build" everest-log_gcovr_coverage retVal=$? # Copy the generated coverage report to the mounted directory in any case diff --git a/.ci/build-kit/scripts/run_unit_tests.sh b/.ci/build-kit/scripts/run_unit_tests.sh index afcf937..c1a29d1 100755 --- a/.ci/build-kit/scripts/run_unit_tests.sh +++ b/.ci/build-kit/scripts/run_unit_tests.sh @@ -1,6 +1,6 @@ #!/bin/sh -ninja -C build test +ninja -C "$EXT_MOUNT/build" test retVal=$? # Copy the LastTest.log file to the mounted directory in any case From ffb6ef1b2d1527a5024caa1a05c846b9294f7626 Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Tue, 3 Sep 2024 09:16:02 +0200 Subject: [PATCH 44/47] Add missing newline Signed-off-by: Kai-Uwe Hermann --- dependencies.yaml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/dependencies.yaml b/dependencies.yaml index 1d8baf3..70602ef 100644 --- a/dependencies.yaml +++ b/dependencies.yaml @@ -11,4 +11,4 @@ spdlog: gtest: git: https://github.com/google/googletest.git git_tag: release-1.12.1 - cmake_condition: "LIBLOG_BUILD_TESTING" \ No newline at end of file + cmake_condition: "LIBLOG_BUILD_TESTING" From 7e93da5050ae7fe5138a6e778938df6d1395cc9b Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Tue, 3 Sep 2024 09:16:23 +0200 Subject: [PATCH 45/47] Remove redundant enable_testing() Signed-off-by: Kai-Uwe Hermann --- CMakeLists.txt | 1 - 1 file changed, 1 deletion(-) diff --git a/CMakeLists.txt b/CMakeLists.txt index 24c7897..90b1920 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -90,7 +90,6 @@ if(LIBLOG_BUILD_TESTING) set(CMAKE_BUILD_TYPE Debug CACHE STRING "Build type" FORCE) include(CTest) - enable_testing() add_subdirectory(tests) setup_target_for_coverage_gcovr_html( From eb62bb24384d6ef85e9d1959d99070c2320ad4bf Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Tue, 3 Sep 2024 09:16:46 +0200 Subject: [PATCH 46/47] Move coverage targt setup to tests subdir Signed-off-by: Kai-Uwe Hermann --- CMakeLists.txt | 15 --------------- tests/CMakeLists.txt | 15 +++++++++++++++ 2 files changed, 15 insertions(+), 15 deletions(-) diff --git a/CMakeLists.txt b/CMakeLists.txt index 90b1920..3cc877c 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -91,21 +91,6 @@ if(LIBLOG_BUILD_TESTING) include(CTest) add_subdirectory(tests) - - setup_target_for_coverage_gcovr_html( - NAME ${PROJECT_NAME}_gcovr_coverage - EXECUTABLE ctest - DEPENDENCIES ${PROJECT_NAME}_tests - EXCLUDE "examples/*" - ) - - setup_target_for_coverage_lcov( - NAME ${PROJECT_NAME}_lcov_coverage - EXECUTABLE ctest - DEPENDENCIES ${PROJECT_NAME}_tests - LCOV_ARGS "--ignore-errors=empty,missing" - EXCLUDE "examples/*" - ) else() message("Not running unit tests") endif() diff --git a/tests/CMakeLists.txt b/tests/CMakeLists.txt index e369c32..f1442f0 100644 --- a/tests/CMakeLists.txt +++ b/tests/CMakeLists.txt @@ -1,3 +1,18 @@ +setup_target_for_coverage_gcovr_html( + NAME ${PROJECT_NAME}_gcovr_coverage + EXECUTABLE ctest + DEPENDENCIES ${PROJECT_NAME}_tests + EXCLUDE "examples/*" +) + +setup_target_for_coverage_lcov( + NAME ${PROJECT_NAME}_lcov_coverage + EXECUTABLE ctest + DEPENDENCIES ${PROJECT_NAME}_tests + LCOV_ARGS "--ignore-errors=empty,missing" + EXCLUDE "examples/*" +) + set(TEST_TARGET_NAME ${PROJECT_NAME}_tests) add_executable(${TEST_TARGET_NAME}) From 608bb48b5bfbd5f50a7eb4aa4ce6940b4043a080 Mon Sep 17 00:00:00 2001 From: Kai-Uwe Hermann Date: Mon, 9 Sep 2024 17:52:27 +0200 Subject: [PATCH 47/47] Add gcovr coverage xml target Signed-off-by: Kai-Uwe Hermann --- tests/CMakeLists.txt | 7 +++++++ 1 file changed, 7 insertions(+) diff --git a/tests/CMakeLists.txt b/tests/CMakeLists.txt index f1442f0..bce6bca 100644 --- a/tests/CMakeLists.txt +++ b/tests/CMakeLists.txt @@ -5,6 +5,13 @@ setup_target_for_coverage_gcovr_html( EXCLUDE "examples/*" ) +setup_target_for_coverage_gcovr_xml( + NAME ${PROJECT_NAME}_gcovr_coverage_xml + EXECUTABLE ctest + DEPENDENCIES ${PROJECT_NAME}_tests + EXCLUDE "examples/*" +) + setup_target_for_coverage_lcov( NAME ${PROJECT_NAME}_lcov_coverage EXECUTABLE ctest