From cff08eea02de69c66bd25765601ebfe5c20af8bc Mon Sep 17 00:00:00 2001 From: Theodor Arsenij Date: Wed, 22 Nov 2023 23:39:02 +0100 Subject: [PATCH] Improved logging subsystem. Now logger is always available but controlled with the `MPP_LOG_LEVEL` environment variable. --- README.md | 6 +- fuzzer/src/fuzzer_main.cpp | 20 ++--- libmemplusplus/CMakeLists.txt | 3 +- libmemplusplus/include/mpplib/gcptr.hpp | 2 +- .../include/mpplib/utils/colours.hpp | 1 + .../include/mpplib/utils/env_options.hpp | 13 ++++ libmemplusplus/include/mpplib/utils/log.hpp | 77 +++++++++++++++++++ .../include/mpplib/utils/macros.hpp | 31 ++------ libmemplusplus/include/mpplib/utils/utils.hpp | 2 +- libmemplusplus/src/arena.cpp | 2 +- libmemplusplus/src/memory_manager.cpp | 6 +- libmemplusplus/src/utils/env_options.cpp | 17 +++- libmemplusplus/src/utils/log.cpp | 15 ++++ 13 files changed, 148 insertions(+), 47 deletions(-) create mode 100644 libmemplusplus/include/mpplib/utils/log.hpp create mode 100644 libmemplusplus/src/utils/log.cpp diff --git a/README.md b/README.md index 6db55a4..0d47994 100644 --- a/README.md +++ b/README.md @@ -12,7 +12,7 @@ - [How to use the library as a dependency (external project)](#how-to-use-the-library-as-a-dependency-external-project) - [How to use the library internally](#how-to-use-the-library-internally) - [📀 Build options](#-build-options) - - [🔳 Environment options](#-environment-options) + - [🔳 Environment variables](#-environment-variables) - [📚 Examples](#-examples) - [💻 Debugging/profiling library](#-debuggingprofiling-library) - [🔥 Heuristic layouting](#-heuristic-layouting) @@ -123,12 +123,14 @@ Library options: - `MPP_STATS` - Add statistics instrumentation. - `MPP_ENABLE_LOGGING` - Enable logging (even in release mode) -## 🔳 Environment options +## 🔳 Environment variables - `MPP_DUMP_OBJECTS_GRAPH=1` / `MPP_DUMP_OBJECTS_GRAPH=2` - dump objects graph to file `objects.dot`, while performing `CollectGarbage()` (only possible in debug mode) - `MPP_SHOW_STATISTICS=1` - display statistics after program termination (should be built with `MPP_STATS` set to ON) +- `MPP_LOG_LEVEL` - set log level (default: `FATAL`). Supported values: `TRACE`, `DEBUG`, `INFO`, `WARNING`, `ERROR`, `FATAL`, `DISABLED` + ## 📚 Examples - Automatic memory management diff --git a/fuzzer/src/fuzzer_main.cpp b/fuzzer/src/fuzzer_main.cpp index f1d1213..273174a 100644 --- a/fuzzer/src/fuzzer_main.cpp +++ b/fuzzer/src/fuzzer_main.cpp @@ -3,7 +3,7 @@ #include "fuzzer/tokenizer.hpp" #include "mpplib/memory_manager.hpp" #include "mpplib/shared_gcptr.hpp" -#include "mpplib/utils/macros.hpp" +#include "mpplib/utils/log.hpp" #include #include @@ -82,7 +82,7 @@ int MppFuzzGcApi(const uint8_t* Data, std::size_t Size) case Tokenizer::Operation::CreateVertex: { MPP_DEBUG_ASSERT(cmd.GetArgs().size() == 1, "Got incorrect number of arguments for CreateVertex operation!"); - MPP_LOG_DBG("CreateVertex(" + std::to_string(cmd.GetArgs()[0]) + ")"); + MPP_LOG_DEBUG("CreateVertex(%d)\n", cmd.GetArgs()[0]); auto vtx = mpp::MakeShared(); pointers.at(cmd.GetArgs()[0]) = std::move(vtx); @@ -91,7 +91,7 @@ int MppFuzzGcApi(const uint8_t* Data, std::size_t Size) case Tokenizer::Operation::RemoveVertex: { MPP_DEBUG_ASSERT(cmd.GetArgs().size() == 1, "Got incorrect number of arguments for RemoveVertex operation!"); - MPP_LOG_DBG("RemoveVertex(" + std::to_string(cmd.GetArgs()[0]) + ")"); + MPP_LOG_DEBUG("RemoveVertex(%d)\n", cmd.GetArgs()[0]); pointers.at(cmd.GetArgs()[0]) = nullptr; break; @@ -99,9 +99,10 @@ int MppFuzzGcApi(const uint8_t* Data, std::size_t Size) case Tokenizer::Operation::CreateEdge: { MPP_DEBUG_ASSERT(cmd.GetArgs().size() == 3, "Got incorrect number of arguments for CreateEdge operation!"); - MPP_LOG_DBG("CreateEdge(" + std::to_string(cmd.GetArgs()[0]) + ", " + - std::to_string(cmd.GetArgs()[1]) + ", " + - std::to_string(cmd.GetArgs()[2]) + ")"); + MPP_LOG_DEBUG("CreateEdge(%d, %d, %d)\n", + cmd.GetArgs()[0], + cmd.GetArgs()[1], + cmd.GetArgs()[2]); auto [vtxIdx1, vtxIdx2, ptrIdx] = std::tie(cmd.GetArgs()[0], cmd.GetArgs()[1], cmd.GetArgs()[2]); @@ -116,8 +117,7 @@ int MppFuzzGcApi(const uint8_t* Data, std::size_t Size) case Tokenizer::Operation::RemoveEdge: { MPP_DEBUG_ASSERT(cmd.GetArgs().size() == 2, "Got incorrect number of arguments for RemoveEdge operation!"); - MPP_LOG_DBG("RemoveEdge(" + std::to_string(cmd.GetArgs()[0]) + ", " + - std::to_string(cmd.GetArgs()[1]) + ")"); + MPP_LOG_DEBUG("RemoveEdge(%d, %d)\n", cmd.GetArgs()[0], cmd.GetArgs()[1]); auto [vtxIdx, ptrIdx] = std::tie(cmd.GetArgs()[0], cmd.GetArgs()[1]); mpp::SharedGcPtr& vertex = pointers.at(vtxIdx); @@ -129,7 +129,7 @@ int MppFuzzGcApi(const uint8_t* Data, std::size_t Size) case Tokenizer::Operation::ReadSharedData: { MPP_DEBUG_ASSERT(cmd.GetArgs().size() == 1, "Got incorrect number of arguments for ReadSharedData operation!"); - MPP_LOG_DBG("ReadSharedData(" + std::to_string(cmd.GetArgs()[0]) + ")"); + MPP_LOG_DEBUG("ReadSharedData(%d)\n", cmd.GetArgs()[0]); auto vtxIdx = cmd.GetArgs()[0]; mpp::SharedGcPtr& vertex = pointers.at(vtxIdx); @@ -140,7 +140,7 @@ int MppFuzzGcApi(const uint8_t* Data, std::size_t Size) break; } case Tokenizer::Operation::CollectGarbage: { - MPP_LOG_DBG("CollectGarbage()"); + MPP_LOG_DEBUG("CollectGarbage()\n"); mpp::CollectGarbage(); break; } diff --git a/libmemplusplus/CMakeLists.txt b/libmemplusplus/CMakeLists.txt index 0969714..53ed826 100644 --- a/libmemplusplus/CMakeLists.txt +++ b/libmemplusplus/CMakeLists.txt @@ -39,13 +39,11 @@ endif() if(CMAKE_BUILD_TYPE MATCHES ".*(D|d)ebug$") # standart debug defines set(MPP_DEBUG ON) - list(APPEND MPP_DEFINES DEBUG=1) list(APPEND MPP_DEFINES MPP_DEBUG=1) list(APPEND MPP_DEFINES MPP_FILL_CHAR='\\x99') else() set(MPP_DEBUG OFF) list(APPEND MPP_DEFINES MPP_DEBUG=0) - list(APPEND MPP_DEFINES DEBUG=0) endif() if(MPP_ENABLE_LOGGING MATCHES "ON") @@ -154,6 +152,7 @@ list(APPEND MPP_SOURCES src/gc.cpp src/utils/utils.cpp src/utils/env_options.cpp + src/utils/log.cpp ) # ################ ADD SPECIFIC SOURCES ################# diff --git a/libmemplusplus/include/mpplib/gcptr.hpp b/libmemplusplus/include/mpplib/gcptr.hpp index e0e4843..baa820f 100644 --- a/libmemplusplus/include/mpplib/gcptr.hpp +++ b/libmemplusplus/include/mpplib/gcptr.hpp @@ -7,7 +7,7 @@ namespace mpp { /** - * @brief Base class to all types of smart pointers (shared, unique, ...) + * @brief Base class for all GcPtr types. */ class GcPtr { diff --git a/libmemplusplus/include/mpplib/utils/colours.hpp b/libmemplusplus/include/mpplib/utils/colours.hpp index 0792f70..060bcaa 100644 --- a/libmemplusplus/include/mpplib/utils/colours.hpp +++ b/libmemplusplus/include/mpplib/utils/colours.hpp @@ -4,6 +4,7 @@ namespace mpp { namespace utils { namespace colours { constexpr std::string_view RESET = "\u001b[0m"; + constexpr std::string_view GREY = "\u001b[90m"; constexpr std::string_view BLACK = "\u001b[30m"; constexpr std::string_view RED = "\u001b[31m"; constexpr std::string_view GREEN = "\u001b[32m"; diff --git a/libmemplusplus/include/mpplib/utils/env_options.hpp b/libmemplusplus/include/mpplib/utils/env_options.hpp index 0740e41..467406b 100644 --- a/libmemplusplus/include/mpplib/utils/env_options.hpp +++ b/libmemplusplus/include/mpplib/utils/env_options.hpp @@ -1,6 +1,8 @@ #pragma once +#include "mpplib/utils/log.hpp" #include "mpplib/utils/profiler_definitions.hpp" + #include namespace mpp { namespace utils { @@ -28,6 +30,11 @@ namespace mpp { namespace utils { */ bool m_showStatistics; + /** + * @brief Environment variable MPP_LOG_LEVEL. + */ + logging::LogLevel m_logLevel; + /** * @brief Constructor, that gets called before program start, to setup all * environment variables. @@ -52,6 +59,12 @@ namespace mpp { namespace utils { */ bool GetMppShowStatistics() const; + /** + * @brief Get the MppLogLevel variable. + * @return LogLevel + */ + logging::LogLevel GetMppLogLevel() const; + /** * @brief Get static instance * @return EnvOptions& diff --git a/libmemplusplus/include/mpplib/utils/log.hpp b/libmemplusplus/include/mpplib/utils/log.hpp new file mode 100644 index 0000000..f643958 --- /dev/null +++ b/libmemplusplus/include/mpplib/utils/log.hpp @@ -0,0 +1,77 @@ +#pragma once + +#include +#include +#include + +namespace mpp { namespace logging { + enum class LogLevel + { + TRACE, + DEBUG, + INFO, + WARNING, + ERROR, + FATAL, + DISABLED + }; + + static const std::unordered_map s_LogLevelToString = { + { LogLevel::TRACE, "TRACE" }, { LogLevel::DEBUG, "DEBUG" }, + { LogLevel::INFO, "INFO" }, { LogLevel::WARNING, "WARNING" }, + { LogLevel::ERROR, "ERROR" }, { LogLevel::FATAL, "FATAL" }, + { LogLevel::DISABLED, "DISABLED" } + }; + + static const std::unordered_map s_StringToLogLevel = { + { "TRACE", LogLevel::TRACE }, { "DEBUG", LogLevel::DEBUG }, + { "INFO", LogLevel::INFO }, { "WARNING", LogLevel::WARNING }, + { "ERROR", LogLevel::ERROR }, { "FATAL", LogLevel::FATAL }, + { "DISABLED", LogLevel::DISABLED } + }; + + LogLevel LogLevelFromString(const std::string& logLevel); +}} + +#define MPP_COLOR_GREY "\u001b[90m" +#define MPP_COLOR_YELLOW "\u001b[33m" +#define MPP_COLOR_RED "\u001b[31m" +#define MPP_COLOR_RESET "\u001b[0m" + +#define MPP_LOG(LEVEL, LEVEL_FMT, FMT, ...) \ + if (LEVEL >= mpp::utils::EnvOptions::Get().GetMppLogLevel()) { \ + /* NOLINTNEXTLINE(cppcoreguidelines-pro-type-vararg, hicpp-vararg) */ \ + std::printf(LEVEL_FMT FMT __VA_OPT__(, ) __VA_ARGS__); \ + } + +#define MPP_LOG_TRACE(FMT, ...) \ + MPP_LOG(mpp::logging::LogLevel::TRACE, \ + MPP_COLOR_GREY "🐾 [TRACE] ", \ + FMT MPP_COLOR_RESET, \ + __VA_ARGS__) +#define MPP_LOG_DEBUG(FMT, ...) \ + MPP_LOG(mpp::logging::LogLevel::DEBUG, \ + MPP_COLOR_GREY "❓ [DEBUG] ", \ + FMT MPP_COLOR_RESET, \ + __VA_ARGS__) +#define MPP_LOG_INFO(FMT, ...) \ + MPP_LOG(mpp::logging::LogLevel::INFO, \ + MPP_COLOR_GREY "📘 [INFO] ", \ + FMT MPP_COLOR_RESET, \ + __VA_ARGS__) +#define MPP_LOG_WARNING(FMT, ...) \ + MPP_LOG(mpp::logging::LogLevel::WARNING, \ + MPP_COLOR_YELLOW "🚧 [WARNING] ", \ + FMT MPP_COLOR_RESET, \ + __VA_ARGS__) +#define MPP_LOG_ERROR(FMT, ...) \ + MPP_LOG(mpp::logging::LogLevel::ERROR, \ + MPP_COLOR_RED "❌ [ERROR] ", \ + FMT MPP_COLOR_RESET, \ + __VA_ARGS__) +#define MPP_LOG_FATAL(FMT, ...) \ + MPP_LOG(mpp::logging::LogLevel::FATAL, \ + MPP_COLOR_RED "⛔ [FATAL] ", \ + FMT MPP_COLOR_RESET, \ + __VA_ARGS__) \ + mpp::utils::ErrorAbort("Fatal error occurred!"); \ No newline at end of file diff --git a/libmemplusplus/include/mpplib/utils/macros.hpp b/libmemplusplus/include/mpplib/utils/macros.hpp index 3b97cf5..534e8d2 100644 --- a/libmemplusplus/include/mpplib/utils/macros.hpp +++ b/libmemplusplus/include/mpplib/utils/macros.hpp @@ -2,8 +2,6 @@ #include "mpplib/utils/utils.hpp" -#include - #if __has_include() && defined (MPP_SANITIZERS) #include #endif @@ -30,41 +28,26 @@ namespace mpp { #define MPP_RELEASE_ASSERT(expr, msg) PRIVATE_MPP_ASSERT((expr), (msg)) -#if MPP_DEBUG == 1 || MPP_ENABLE_LOGGING == 1 -#define MPP_LOG(level, msg) \ - std::cout << level << " " << __FILE__ << ":" << __LINE__ << " > " << msg << std::endl; -#define MPP_LOG_DBG(msg) MPP_LOG("❓ DBG:", msg) -#define MPP_LOG_WARN(msg) MPP_LOG("🚧 WARN:", msg) -#define MPP_LOG_INFO(msg) MPP_LOG("📘 INFO:", msg) -#define MPP_LOG_ERROR(msg) MPP_LOG("❌ ERR:", msg) -#else -#define MPP_LOG(level, msg) -#define MPP_LOG_DBG(msg) -#define MPP_LOG_WARN(msg) -#define MPP_LOG_INFO(msg) -#define MPP_LOG_ERROR(msg) -#endif - #if MPP_FULL_DEBUG == 1 || MPP_SECURE == 1 -#define MPP_SECURE_MEMSET(ptr, value, size) \ +#define MPP_MEMSET_SECURE_ONLY(ptr, value, size) \ do { \ MPP_DEBUG_ASSERT(ptr != nullptr, "Null pointer"); \ MPP_DEBUG_ASSERT(size > 0, "Size must be greater than 0"); \ utils::SecureMemset(ptr, size, value, size); \ } while (0) #else -#define MPP_SECURE_MEMSET(ptr, value, size) +#define MPP_MEMSET_SECURE_ONLY(ptr, value, size) #endif #if MPP_FULL_DEBUG == 1 || MPP_SECURE == 1 -#define MPP_SECURE_WIPE_CHUNK(chunk) \ +#define MPP_WIPE_CHUNK_SECURE_ONLY(chunk) \ do { \ - MPP_SECURE_MEMSET(Chunk::GetUserDataPtr(chunk), \ - MPP_FILL_CHAR, \ - chunk->GetSize() - sizeof(Chunk::ChunkHeader)); \ + MPP_MEMSET_SECURE_ONLY(Chunk::GetUserDataPtr(chunk), \ + MPP_FILL_CHAR, \ + chunk->GetSize() - sizeof(Chunk::ChunkHeader)); \ } while (0) #else -#define MPP_SECURE_WIPE_CHUNK(chunk) +#define MPP_WIPE_CHUNK_SECURE_ONLY(chunk) #endif #if defined MPP_SANITIZERS diff --git a/libmemplusplus/include/mpplib/utils/utils.hpp b/libmemplusplus/include/mpplib/utils/utils.hpp index 72a6bd4..d444718 100644 --- a/libmemplusplus/include/mpplib/utils/utils.hpp +++ b/libmemplusplus/include/mpplib/utils/utils.hpp @@ -12,7 +12,7 @@ namespace mpp { namespace utils { static const uint32_t s_MAX_STACK_LEVELS = 50; /** - * @brief Secure implementation of memset. + * @brief Secure implementation of memset, that ensures that compiler will not optimize it out. * @param t_pointer Pointer to memory to be set. * @param t_targetBufferSize Destination buffer size. * @param t_fillChar Character to fill memory with. diff --git a/libmemplusplus/src/arena.cpp b/libmemplusplus/src/arena.cpp index 186e08d..73c8666 100644 --- a/libmemplusplus/src/arena.cpp +++ b/libmemplusplus/src/arena.cpp @@ -187,7 +187,7 @@ namespace mpp { // Update currently used space variable m_currentlyAllocatedSpace -= t_chunk->GetSize(); - MPP_SECURE_WIPE_CHUNK(t_chunk); + MPP_WIPE_CHUNK_SECURE_ONLY(t_chunk); // try to merge deallocated chunk forward and backwards Chunk* newChunk = MergeNeighborsChunks(t_chunk); diff --git a/libmemplusplus/src/memory_manager.cpp b/libmemplusplus/src/memory_manager.cpp index 874a93d..d8f4214 100644 --- a/libmemplusplus/src/memory_manager.cpp +++ b/libmemplusplus/src/memory_manager.cpp @@ -164,7 +164,7 @@ namespace mpp { if (realChunkSize > g_DEFAULT_ARENA_SIZE) { Chunk* bigChunk = AllocateBigChunk(Align(realChunkSize, g_PAGE_SIZE)); MPP_VALGRIND_DEFINE_CHUNK(bigChunk); - MPP_SECURE_WIPE_CHUNK(bigChunk); + MPP_WIPE_CHUNK_SECURE_ONLY(bigChunk); return Chunk::GetUserDataPtr(bigChunk); } @@ -178,7 +178,7 @@ namespace mpp { Chunk* chunk = GetSuitableChunk(realChunkSize); if (chunk != nullptr) { MPP_VALGRIND_DEFINE_CHUNK(chunk); - MPP_SECURE_WIPE_CHUNK(chunk); + MPP_WIPE_CHUNK_SECURE_ONLY(chunk); return Chunk::GetUserDataPtr(chunk); } @@ -187,7 +187,7 @@ namespace mpp { auto& arena = CreateArena(g_DEFAULT_ARENA_SIZE); Chunk* userChunk = arena->AllocateFromTopChunk(realChunkSize); MPP_VALGRIND_DEFINE_CHUNK(userChunk); - MPP_SECURE_WIPE_CHUNK(userChunk); + MPP_WIPE_CHUNK_SECURE_ONLY(userChunk); return Chunk::GetUserDataPtr(userChunk); } diff --git a/libmemplusplus/src/utils/env_options.cpp b/libmemplusplus/src/utils/env_options.cpp index 63b390d..154bb82 100644 --- a/libmemplusplus/src/utils/env_options.cpp +++ b/libmemplusplus/src/utils/env_options.cpp @@ -4,6 +4,7 @@ namespace mpp { namespace utils { EnvOptions::EnvOptions() : m_dumpObjectsGraph{ ObjectsGraphDumpType::DISABLED } , m_showStatistics{ false } + , m_logLevel{ logging::LogLevel::FATAL } { SetOptions(); } @@ -12,16 +13,21 @@ namespace mpp { namespace utils { { char* dump_graph = std::getenv("MPP_DUMP_OBJECTS_GRAPH"); char* show_stats = std::getenv("MPP_SHOW_STATISTICS"); + char* log_level = std::getenv("MPP_LOG_LEVEL"); - if ((dump_graph != nullptr) && dump_graph[0] == '1') { + if (dump_graph && dump_graph[0] == '1') { m_dumpObjectsGraph = ObjectsGraphDumpType::SIMPLE; - } else if ((dump_graph != nullptr) && dump_graph[0] == '2') { + } else if (dump_graph && dump_graph[0] == '2') { m_dumpObjectsGraph = ObjectsGraphDumpType::ADVANCED; } else { m_dumpObjectsGraph = ObjectsGraphDumpType::DISABLED; } - m_showStatistics = (show_stats != nullptr) && show_stats[0] == '1'; + m_showStatistics = show_stats && show_stats[0] == '1'; + + if (log_level != nullptr) { + m_logLevel = logging::LogLevelFromString(log_level); + } } ObjectsGraphDumpType EnvOptions::GetMppDumpObjectsGraph() const @@ -34,6 +40,11 @@ namespace mpp { namespace utils { return m_showStatistics; } + logging::LogLevel EnvOptions::GetMppLogLevel() const + { + return m_logLevel; + } + EnvOptions& EnvOptions::Get() { static EnvOptions s_instance; diff --git a/libmemplusplus/src/utils/log.cpp b/libmemplusplus/src/utils/log.cpp new file mode 100644 index 0000000..873bf69 --- /dev/null +++ b/libmemplusplus/src/utils/log.cpp @@ -0,0 +1,15 @@ +#include "mpplib/utils/log.hpp" +#include + +namespace mpp { namespace logging { + LogLevel LogLevelFromString(const std::string& logLevel) + { + std::string logLevelStr = logLevel; + std::transform(logLevelStr.begin(), logLevelStr.end(), logLevelStr.begin(), ::toupper); + + if (s_StringToLogLevel.find(logLevelStr) != s_StringToLogLevel.end()) + return s_StringToLogLevel.at(logLevelStr); + + return LogLevel::FATAL; + } +}} \ No newline at end of file