From 568411dc5ebc527cd9a32c518bd4d1bc96816b71 Mon Sep 17 00:00:00 2001 From: Matthew Russell Date: Tue, 28 May 2024 15:30:22 -0400 Subject: [PATCH] Implement slog2 logging capability slog2 is enabled by default, but guarded with #ifdef __QNX__. It can be controlled with /etc/vsomeip/logging.json, i.e.: ```json "logging": { "slog2": true } ``` This code allocates 4 pages (16kB) by default, but the caller can provide an environment variable VSOMEIP_SLOG2_NUM_PAGES to control the allocation Minimal CMake changes were made to link against the slog2 library on QNX This commit also modifies the routingmanager example to set the LogApplication property which is used as the log tag for AOSP logcat logging. --- CMakeLists.txt | 62 ++++++++-- examples/routingmanagerd/routingmanagerd.cpp | 3 + .../configuration/include/configuration.hpp | 1 + .../include/configuration_impl.hpp | 5 +- .../configuration/src/configuration_impl.cpp | 19 +++ implementation/logger/include/logger_impl.hpp | 104 ++++++++++++++++ implementation/logger/src/logger_impl.cpp | 37 ++++++ implementation/logger/src/message.cpp | 112 +++--------------- test/CMakeLists.txt | 2 + 9 files changed, 238 insertions(+), 107 deletions(-) diff --git a/CMakeLists.txt b/CMakeLists.txt index 3501e02c5..f59fc12ac 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -64,27 +64,65 @@ endif() set(CMAKE_CXX_STANDARD 17) # OS +add_library(OS_INTERFACE INTERFACE IMPORTED) +target_link_libraries(OS_INTERFACE INTERFACE Threads::Threads) + if (${CMAKE_SYSTEM_NAME} MATCHES "Linux") set(DL_LIBRARY "dl") -if (CMAKE_CXX_COMPILER_ID STREQUAL "GNU") - # This is only relevant for GCC and causes warnings on Clang - set(EXPORTSYMBOLS "-Wl,-export-dynamic -Wl,--version-script=${CMAKE_CURRENT_SOURCE_DIR}/exportmap.gcc") - set(OS_CXX_FLAGS "${OS_CXX_FLAGS} -pie -Wno-tsan -Wl,-z,relro,-z,now") -endif() + if (CMAKE_CXX_COMPILER_ID STREQUAL "GNU") + # This is only relevant for GCC and causes warnings on Clang + set(EXPORTSYMBOLS "-Wl,-export-dynamic -Wl,--version-script=${CMAKE_CURRENT_SOURCE_DIR}/exportmap.gcc") + set(OS_CXX_FLAGS "${OS_CXX_FLAGS} -Wno-tsan -Wl,-z,now") + set(CMAKE_POSITION_INDEPENDENT_CODE ON) + endif() set(NO_DEPRECATED "") set(OPTIMIZE "") - if(NOT DEFINED _FORTIFY_SOURCE) - set(_FORTIFY_SOURCE 2) - endif() - set(OS_CXX_FLAGS "${OS_CXX_FLAGS} -D_GLIBCXX_USE_NANOSLEEP -pthread -O -Wall -Wextra -Wformat -Wformat-security -Wconversion -fexceptions -fstrict-aliasing -fstack-protector-strong -fasynchronous-unwind-tables -fno-omit-frame-pointer -D_FORTIFY_SOURCE=${_FORTIFY_SOURCE} -Wformat -Wformat-security -Wpedantic -Werror -fPIE") + if(NOT DEFINED _FORTIFY_SOURCE) + set(_FORTIFY_SOURCE 2) + endif() + + add_compile_options( + -Wall + -Wextra + -Wformat + -Wformat-security + -Wconversion + -fexceptions + -fstrict-aliasing + -fstack-protector-strong + -fasynchronous-unwind-tables + -fno-omit-frame-pointer + -Wformat + -Wformat-security + -Wpedantic + -Werror + ) # force all use of std::mutex and std::recursive_mutex to use runtime init # instead of static initialization so mutexes can be hooked to enable PI as needed - add_definitions(-D_GTHREAD_USE_MUTEX_INIT_FUNC -D_GTHREAD_USE_RECURSIVE_MUTEX_INIT_FUNC) + add_definitions(-D_GTHREAD_USE_MUTEX_INIT_FUNC -D_GTHREAD_USE_RECURSIVE_MUTEX_INIT_FUNC -D_FORTIFY_SOURCE=${_FORTIFY_SOURCE}) + + add_link_options(-Wl,--wrap=socket,--wrap=accept,--wrap=open) endif (${CMAKE_SYSTEM_NAME} MATCHES "Linux") +if(${CMAKE_SYSTEM_NAME} MATCHES "QNX") + set(OS "QNX") + set(CMAKE_POSITION_INDEPENDENT_CODE ON) + + add_compile_options( + -fexceptions + -fstrict-aliasing + -fstack-protector + -fasynchronous-unwind-tables + -fno-omit-frame-pointer + ) + add_link_options(-Wl,-export-dynamic) + add_link_options(-Wl,--wrap=socket,--wrap=accept,--wrap=open) + target_link_libraries(OS_INTERFACE INTERFACE slog2 socket) +endif (${CMAKE_SYSTEM_NAME} MATCHES "QNX") + if (${CMAKE_SYSTEM_NAME} MATCHES "FreeBSD") set(DL_LIBRARY "") set(EXPORTSYMBOLS "") @@ -308,8 +346,6 @@ set_target_properties (${VSOMEIP_NAME} PROPERTIES VERSION ${VSOMEIP_VERSION} SOV target_compile_features(${VSOMEIP_NAME} PRIVATE cxx_std_17) if (MSVC) set_target_properties(${VSOMEIP_NAME} PROPERTIES COMPILE_DEFINITIONS "VSOMEIP_DLL_COMPILATION") -else () - set_target_properties(${VSOMEIP_NAME} PROPERTIES LINK_FLAGS "-Wl,-wrap,socket -Wl,-wrap,accept -Wl,-wrap,open") endif () target_include_directories(${VSOMEIP_NAME} INTERFACE $ @@ -320,7 +356,7 @@ target_include_directories(${VSOMEIP_NAME} INTERFACE # them (which shouldn't be required). ${Boost_LIBRARIES} includes absolute # build host paths as of writing, which also makes this important as it breaks # the build. -target_link_libraries(${VSOMEIP_NAME} PRIVATE ${Boost_LIBRARIES} ${USE_RT} ${DL_LIBRARY} ${DLT_LIBRARIES} ${SystemD_LIBRARIES} ${CMAKE_THREAD_LIBS_INIT}) +target_link_libraries(${VSOMEIP_NAME} PRIVATE ${Boost_LIBRARIES} ${USE_RT} ${DL_LIBRARY} ${DLT_LIBRARIES} ${SystemD_LIBRARIES} ${CMAKE_THREAD_LIBS_INIT} OS_INTERFACE) if(NOT WIN32) target_link_options(${VSOMEIP_NAME} PRIVATE "LINKER:-as-needed") diff --git a/examples/routingmanagerd/routingmanagerd.cpp b/examples/routingmanagerd/routingmanagerd.cpp index 65d9d016a..7811479f0 100644 --- a/examples/routingmanagerd/routingmanagerd.cpp +++ b/examples/routingmanagerd/routingmanagerd.cpp @@ -21,6 +21,8 @@ #endif #endif +extern char * __progname; + static std::shared_ptr its_application; #ifndef VSOMEIP_ENABLE_SIGNAL_HANDLING @@ -75,6 +77,7 @@ int routingmanagerd_process(bool _is_quiet) { std::shared_ptr its_runtime = vsomeip::runtime::get(); + its_runtime->set_property("LogApplication", __progname); if (!its_runtime) { return -1; diff --git a/implementation/configuration/include/configuration.hpp b/implementation/configuration/include/configuration.hpp index 8b32a0c99..64c9baf4f 100644 --- a/implementation/configuration/include/configuration.hpp +++ b/implementation/configuration/include/configuration.hpp @@ -81,6 +81,7 @@ class configuration { virtual bool has_console_log() const = 0; virtual bool has_file_log() const = 0; virtual bool has_dlt_log() const = 0; + virtual bool has_slog2_log() const = 0; virtual const std::string &get_logfile() const = 0; virtual logger::level_e get_loglevel() const = 0; diff --git a/implementation/configuration/include/configuration_impl.hpp b/implementation/configuration/include/configuration_impl.hpp index f30e0ecf5..205efab26 100644 --- a/implementation/configuration/include/configuration_impl.hpp +++ b/implementation/configuration/include/configuration_impl.hpp @@ -97,6 +97,7 @@ class configuration_impl: VSOMEIP_EXPORT bool has_console_log() const; VSOMEIP_EXPORT bool has_file_log() const; VSOMEIP_EXPORT bool has_dlt_log() const; + VSOMEIP_EXPORT bool has_slog2_log() const; VSOMEIP_EXPORT const std::string & get_logfile() const; VSOMEIP_EXPORT vsomeip_v3::logger::level_e get_loglevel() const; @@ -491,6 +492,7 @@ class configuration_impl: bool has_console_log_; bool has_file_log_; bool has_dlt_log_; + bool has_slog2_log_; std::string logfile_; mutable std::mutex mutex_loglevel_; vsomeip_v3::logger::level_e loglevel_; @@ -561,6 +563,7 @@ class configuration_impl: ET_LOGGING_CONSOLE, ET_LOGGING_FILE, ET_LOGGING_DLT, + ET_LOGGING_SLOG2, ET_LOGGING_LEVEL, ET_ROUTING, ET_SERVICE_DISCOVERY_ENABLE, @@ -598,7 +601,7 @@ class configuration_impl: ET_PARTITIONS, ET_SECURITY_AUDIT_MODE, ET_SECURITY_REMOTE_ACCESS, - ET_MAX = 45 + ET_MAX = 46 }; bool is_configured_[ET_MAX]; diff --git a/implementation/configuration/src/configuration_impl.cpp b/implementation/configuration/src/configuration_impl.cpp index 380b29060..8312555c9 100644 --- a/implementation/configuration/src/configuration_impl.cpp +++ b/implementation/configuration/src/configuration_impl.cpp @@ -54,6 +54,11 @@ configuration_impl::configuration_impl(const std::string &_path) has_console_log_(true), has_file_log_(false), has_dlt_log_(false), +#ifdef __QNX__ + has_slog2_log_(true), +#else + has_slog2_log_(false), +#endif logfile_("/tmp/vsomeip.log"), loglevel_(vsomeip_v3::logger::level_e::LL_INFO), is_sd_enabled_(VSOMEIP_SD_DEFAULT_ENABLED), @@ -162,6 +167,7 @@ configuration_impl::configuration_impl(const configuration_impl &_other) has_console_log_ = _other.has_console_log_; has_file_log_ = _other.has_file_log_; has_dlt_log_ = _other.has_dlt_log_; + has_slog2_log_ = _other.has_slog2_log_; logfile_ = _other.logfile_; loglevel_ = _other.loglevel_; @@ -655,6 +661,15 @@ bool configuration_impl::load_logging( has_dlt_log_ = (its_value == "true"); is_configured_[ET_LOGGING_DLT] = true; } + } else if (its_key == "slog2") { + if (is_configured_[ET_LOGGING_SLOG2]) { + _warnings.insert("Multiple definitions for logging.slog2." + " Ignoring definition from " + _element.name_); + } else { + std::string its_value(i->second.data()); + has_slog2_log_ = (its_value == "true"); + is_configured_[ET_LOGGING_SLOG2] = true; + } } else if (its_key == "level") { if (is_configured_[ET_LOGGING_LEVEL]) { _warnings.insert("Multiple definitions for logging.level." @@ -2894,6 +2909,10 @@ bool configuration_impl::has_dlt_log() const { return has_dlt_log_; } +bool configuration_impl::has_slog2_log() const { + return has_slog2_log_; +} + const std::string & configuration_impl::get_logfile() const { return logfile_; } diff --git a/implementation/logger/include/logger_impl.hpp b/implementation/logger/include/logger_impl.hpp index 34f006468..291dcbc2b 100644 --- a/implementation/logger/include/logger_impl.hpp +++ b/implementation/logger/include/logger_impl.hpp @@ -9,6 +9,13 @@ #include #include +#ifdef __QNX__ +#include +#endif + +#ifdef ANDROID +#include +#endif #ifdef USE_DLT #ifndef ANDROID #include @@ -34,6 +41,19 @@ class logger_impl { std::shared_ptr get_configuration() const; void set_configuration(const std::shared_ptr &_configuration); +#ifdef __QNX__ + static slog2_buffer_set_config_t buffer_config; + static slog2_buffer_t buffer_handle[1]; + + auto slog2_is_initialized() const -> bool { + return slog2_is_initialized_; + } + + auto set_slog2_initialized(bool initialized) -> void { + slog2_is_initialized_ = initialized; + } +#endif + #ifdef USE_DLT void log(level_e _level, const char *_data); @@ -41,12 +61,96 @@ class logger_impl { void enable_dlt(const std::string &_application, const std::string &_context); #endif + static auto constexpr levelAsString(level_e const _level) -> const char * + { + const char* its_level = nullptr; + switch (_level) { + case level_e::LL_FATAL: + its_level = "fatal"; + break; + case level_e::LL_ERROR: + its_level = "error"; + break; + case level_e::LL_WARNING: + its_level = "warning"; + break; + case level_e::LL_INFO: + its_level = "info"; + break; + case level_e::LL_DEBUG: + its_level = "debug"; + break; + case level_e::LL_VERBOSE: + its_level = "verbose"; + break; + default: + its_level = "none"; + } + + return its_level; + } + +#ifdef __QNX__ + static auto constexpr levelAsSlog2(level_e const _level) -> std::uint8_t + { + uint8_t severity = 0; + switch (_level) { + case level_e::LL_FATAL: + severity = SLOG2_CRITICAL; + break; + case level_e::LL_ERROR: + severity = SLOG2_ERROR; + break; + case level_e::LL_WARNING: + severity = SLOG2_WARNING; + break; + case level_e::LL_INFO: + severity = SLOG2_INFO; + break; + case level_e::LL_DEBUG: + severity = SLOG2_DEBUG1; + break; + case level_e::LL_VERBOSE: + default: + severity = SLOG2_DEBUG2; + break; + } + return severity; + } +#endif + +#ifdef ANDROID + static constexpr auto levelAsAospLevel(level_e _level) -> android_LogPriority { + switch (_level) { + case level_e::LL_FATAL: + return ANDROID_LOG_ERROR; + case level_e::LL_ERROR: + return ANDROID_LOG_ERROR; + case level_e::LL_WARNING: + return ANDROID_LOG_WARN; + case level_e::LL_INFO: + return ANDROID_LOG_INFO; + case level_e::LL_DEBUG: + return ANDROID_LOG_DEBUG; + case level_e::LL_VERBOSE: + return ANDROID_LOG_VERBOSE; + default: + return ANDROID_LOG_INFO; + } + } +#endif // !ANDROID + private: static std::mutex mutex__; std::shared_ptr configuration_; mutable std::mutex configuration_mutex_; +#ifdef __QNX__ + // Flag whether slog2 was successfully initialized. + bool slog2_is_initialized_ = false; +#endif + #ifdef USE_DLT #ifndef ANDROID DLT_DECLARE_CONTEXT(dlt_) diff --git a/implementation/logger/src/logger_impl.cpp b/implementation/logger/src/logger_impl.cpp index b7cd57e31..0d6779acc 100644 --- a/implementation/logger/src/logger_impl.cpp +++ b/implementation/logger/src/logger_impl.cpp @@ -10,6 +10,14 @@ #include "../include/logger_impl.hpp" #include "../../configuration/include/configuration.hpp" +#ifdef __QNX__ +#include +extern char * __progname; +#elif __linux__ +extern char * __progname; +#endif + + namespace vsomeip_v3 { namespace logger { @@ -21,6 +29,35 @@ logger_impl::init(const std::shared_ptr &_configuration) { auto its_logger = logger_impl::get(); its_logger->set_configuration(_configuration); +#ifdef __QNX__ + logger_impl::buffer_config.buffer_set_name = __progname; + logger_impl::buffer_config.num_buffers = 1; + logger_impl::buffer_config.verbosity_level = levelAsSlog2(its_logger->configuration_->get_loglevel()); + + // Use a 16kB log buffer by default + // Override with a size specified by environment variable + long unsigned int num_pages = 4; + auto s = getenv("VSOMEIP_SLOG2_NUM_PAGES"); + if (s != nullptr) + { + char * endptr = nullptr; + num_pages = strtoul(s, &endptr, 0); + } + logger_impl::buffer_config.buffer_config[0].buffer_name = "vsomeip"; + logger_impl::buffer_config.buffer_config[0].num_pages = static_cast(num_pages); + + // Register the buffer set. + if (-1 == slog2_register(&logger_impl::buffer_config, logger_impl::buffer_handle, 0)) + { + std::fprintf(stderr, "Error registering slogger2 buffer!\n"); + return; + } + else + { + its_logger->set_slog2_initialized(true); + } +#endif + #ifdef USE_DLT # define VSOMEIP_LOG_DEFAULT_CONTEXT_ID "VSIP" # define VSOMEIP_LOG_DEFAULT_CONTEXT_NAME "vSomeIP context" diff --git a/implementation/logger/src/message.cpp b/implementation/logger/src/message.cpp index 015e8e35b..8bed66145 100644 --- a/implementation/logger/src/message.cpp +++ b/implementation/logger/src/message.cpp @@ -11,52 +11,6 @@ #ifdef ANDROID #include - -#ifdef ALOGE -#undef ALOGE -#endif - -#define ALOGE(LOG_TAG, ...) ((void)ALOG(LOG_ERROR, LOG_TAG, __VA_ARGS__)) -#ifndef LOGE -#define LOGE ALOGE -#endif - -#ifdef ALOGW -#undef ALOGW -#endif - -#define ALOGW(LOG_TAG, ...) ((void)ALOG(LOG_WARN, LOG_TAG, __VA_ARGS__)) -#ifndef LOGE -#define LOGW ALOGW -#endif - -#ifdef ALOGI -#undef ALOGI -#endif - -#define ALOGI(LOG_TAG, ...) ((void)ALOG(LOG_INFO, LOG_TAG, __VA_ARGS__)) -#ifndef LOGE -#define LOGI ALOGI -#endif - -#ifdef ALOGD -#undef ALOGD -#endif - -#define ALOGD(LOG_TAG, ...) ((void)ALOG(LOG_DEBUG, LOG_TAG, __VA_ARGS__)) -#ifndef LOGE -#define LOGD ALOGD -#endif - -#ifdef ALOGV -#undef ALOGV -#endif - -#define ALOGV(LOG_TAG, ...) ((void)ALOG(LOG_VERBOSE, LOG_TAG, __VA_ARGS__)) -#ifndef LOGE -#define LOGV ALOGV -#endif - #endif #include @@ -70,6 +24,12 @@ namespace logger { std::mutex message::mutex__; +#ifdef __QNX__ +slog2_buffer_set_config_t logger_impl::buffer_config = {0}; +slog2_buffer_t logger_impl::buffer_handle[1] = {0}; +#endif + + message::message(level_e _level) : std::ostream(&buffer_), level_(_level) { @@ -85,6 +45,16 @@ message::~message() try { if (!its_configuration) return; +#ifdef __QNX__ + // Write to slog without filtering on the level. This way we can modify + // the threshold in the pps settings, e.g. + // echo buffer_name:n:7 >> /var/pps/slog2/verbose + if (its_configuration->has_slog2_log() && its_logger->slog2_is_initialized()) { + // Truncates after 508 characters (and adds ellipsis) + slog2c(its_logger->buffer_handle[0], 0x0000, logger_impl::levelAsSlog2(level_), buffer_.data_.str().c_str()); + } +#endif + if (level_ > its_configuration->get_loglevel()) return; @@ -92,29 +62,7 @@ message::~message() try { || its_configuration->has_file_log()) { // Prepare log level - const char *its_level; - switch (level_) { - case level_e::LL_FATAL: - its_level = "fatal"; - break; - case level_e::LL_ERROR: - its_level = "error"; - break; - case level_e::LL_WARNING: - its_level = "warning"; - break; - case level_e::LL_INFO: - its_level = "info"; - break; - case level_e::LL_DEBUG: - its_level = "debug"; - break; - case level_e::LL_VERBOSE: - its_level = "verbose"; - break; - default: - its_level = "none"; - }; + const auto its_level = logger_impl::levelAsString(level_); // Prepare time stamp auto its_time_t = std::chrono::system_clock::to_time_t(when_); @@ -143,29 +91,7 @@ message::~message() try { << std::endl; #else std::string app = runtime::get_property("LogApplication"); - - switch (level_) { - case level_e::LL_FATAL: - ALOGE(app.c_str(), ("VSIP: " + buffer_.data_.str()).c_str()); - break; - case level_e::LL_ERROR: - ALOGE(app.c_str(), ("VSIP: " + buffer_.data_.str()).c_str()); - break; - case level_e::LL_WARNING: - ALOGW(app.c_str(), ("VSIP: " + buffer_.data_.str()).c_str()); - break; - case level_e::LL_INFO: - ALOGI(app.c_str(), ("VSIP: " + buffer_.data_.str()).c_str()); - break; - case level_e::LL_DEBUG: - ALOGD(app.c_str(), ("VSIP: " + buffer_.data_.str()).c_str()); - break; - case level_e::LL_VERBOSE: - ALOGV(app.c_str(), ("VSIP: " + buffer_.data_.str()).c_str()); - break; - default: - ALOGI(app.c_str(), ("VSIP: " + buffer_.data_.str()).c_str()); - }; + static_cast(__android_log_print(logger_impl::levelAsAospLevel(level_), app.c_str(), "VSIP: %s", buffer_.data_.str().c_str())); #endif // !ANDROID } @@ -204,7 +130,7 @@ message::~message() try { std::streambuf::int_type message::buffer::overflow(std::streambuf::int_type c) { if (c != EOF) { - data_ << (char)c; + data_ << static_cast(c); } return c; diff --git a/test/CMakeLists.txt b/test/CMakeLists.txt index f66ac5d33..51d578401 100644 --- a/test/CMakeLists.txt +++ b/test/CMakeLists.txt @@ -102,6 +102,8 @@ endif() add_custom_target(build_tests) +link_libraries(OS_INTERFACE) + set(CMAKE_CTEST_COMMAND ctest -V) add_custom_target(check COMMAND ${CMAKE_CTEST_COMMAND}) add_dependencies(check build_tests)