Improved logging subsystem. Now logger is always available but contro…

…lled with the `MPP_LOG_LEVEL` environment variable.
m4drat · Nov 22, 2023 · cff08ee · cff08ee
1 parent 3950275
commit cff08ee
Show file tree

Hide file tree

Showing 13 changed files with 148 additions and 47 deletions.
diff --git 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
@@ -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 <cstdlib>
 #include <cstring>
@@ -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<Vertex>();
                 pointers.at(cmd.GetArgs()[0]) = std::move(vtx);
@@ -91,17 +91,18 @@ 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;
             }
             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>& 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>& 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
@@ -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
@@ -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
@@ -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
@@ -1,6 +1,8 @@
 #pragma once
 
+#include "mpplib/utils/log.hpp"
 #include "mpplib/utils/profiler_definitions.hpp"
+
 #include <cstdlib>
 
 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
@@ -0,0 +1,77 @@
+#pragma once
+
+#include <cstdio>
+#include <string>
+#include <unordered_map>
+
+namespace mpp { namespace logging {
+    enum class LogLevel
+    {
+        TRACE,
+        DEBUG,
+        INFO,
+        WARNING,
+        ERROR,
+        FATAL,
+        DISABLED
+    };
+
+    static const std::unordered_map<LogLevel, std::string> 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<std::string, LogLevel> 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!");
diff --git a/libmemplusplus/include/mpplib/utils/macros.hpp b/libmemplusplus/include/mpplib/utils/macros.hpp
@@ -2,8 +2,6 @@
 
 #include "mpplib/utils/utils.hpp"
 
-#include <iostream>
-
 #if __has_include(<sanitizer/asan_interface.h>) && defined (MPP_SANITIZERS)
 #include <sanitizer/asan_interface.h>
 #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
@@ -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
@@ -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
@@ -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
@@ -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;