From 3aca4324601764ad3c6c80e23f9231631d8a227d Mon Sep 17 00:00:00 2001 From: Fabian Schiebel <52407375+fabianbs96@users.noreply.github.com> Date: Sat, 25 Nov 2023 12:11:13 +0100 Subject: [PATCH] Improve Logger Performance (#683) * Make use of LoggerFilterLevel to conditionally disable message formatting * Move more from the Logger header to the implementation file * Refactor StdStream + some cleanup * Re-enable PIC by default to support ASLR --- .../DataFlow/IfdsIde/Solver/IDESolver.h | 175 ++++++++------- include/phasar/Utils/Logger.h | 139 ++++++------ include/phasar/Utils/TypeTraits.h | 22 +- lib/Utils/Logger.cpp | 210 ++++++++++-------- 4 files changed, 288 insertions(+), 258 deletions(-) diff --git a/include/phasar/DataFlow/IfdsIde/Solver/IDESolver.h b/include/phasar/DataFlow/IfdsIde/Solver/IDESolver.h index ac730de2a..cfe82bacf 100644 --- a/include/phasar/DataFlow/IfdsIde/Solver/IDESolver.h +++ b/include/phasar/DataFlow/IfdsIde/Solver/IDESolver.h @@ -286,15 +286,16 @@ class IDESolver const auto &ReturnSiteNs = ICF->getReturnSitesOfCallAt(n); const auto &Callees = ICF->getCalleesOfCallAt(n); - IF_LOG_ENABLED( - PHASAR_LOG_LEVEL(DEBUG, "Possible callees:"); for (auto Callee - : Callees) { - PHASAR_LOG_LEVEL(DEBUG, " " << Callee->getName()); - } PHASAR_LOG_LEVEL(DEBUG, "Possible return sites:"); - for (auto ret - : ReturnSiteNs) { - PHASAR_LOG_LEVEL(DEBUG, " " << NToString(ret)); - }); + IF_LOG_LEVEL_ENABLED(DEBUG, { + PHASAR_LOG_LEVEL(DEBUG, "Possible callees:"); + for (auto Callee : Callees) { + PHASAR_LOG_LEVEL(DEBUG, " " << Callee->getName()); + } + PHASAR_LOG_LEVEL(DEBUG, "Possible return sites:"); + for (auto ret : ReturnSiteNs) { + PHASAR_LOG_LEVEL(DEBUG, " " << NToString(ret)); + } + }); // for each possible callee for (f_t SCalledProcN : Callees) { // still line 14 @@ -315,11 +316,11 @@ class IDESolver CachedFlowEdgeFunctions.getSummaryEdgeFunction(n, d2, ReturnSiteN, d3); INC_COUNTER("SpecialSummary-EF Queries", 1, Full); - IF_LOG_ENABLED( - PHASAR_LOG_LEVEL( - DEBUG, "Queried Summary Edge Function: " << SumEdgFnE); - PHASAR_LOG_LEVEL(DEBUG, "Compose: " << SumEdgFnE << " * " << f - << '\n')); + + PHASAR_LOG_LEVEL(DEBUG, + "Queried Summary Edge Function: " << SumEdgFnE); + PHASAR_LOG_LEVEL(DEBUG, + "Compose: " << SumEdgFnE << " * " << f << '\n'); WorkList.emplace_back(PathEdge(d1, ReturnSiteN, std::move(d3)), f.composeWith(SumEdgFnE)); } @@ -562,7 +563,7 @@ class IDESolver } void setVal(n_t NHashN, d_t NHashD, l_t L) { - IF_LOG_ENABLED({ + IF_LOG_LEVEL_ENABLED(DEBUG, { PHASAR_LOG_LEVEL(DEBUG, "Function : " << ICF->getFunctionOf(NHashN)->getName()); PHASAR_LOG_LEVEL(DEBUG, "Inst. : " << NToString(NHashN)); @@ -580,13 +581,14 @@ class IDESolver } EdgeFunction jumpFunction(const PathEdge Edge) { - IF_LOG_ENABLED( - PHASAR_LOG_LEVEL(DEBUG, "JumpFunctions Forward-Lookup:"); - PHASAR_LOG_LEVEL(DEBUG, - " Source D: " << DToString(Edge.factAtSource())); - PHASAR_LOG_LEVEL(DEBUG, " Target N: " << NToString(Edge.getTarget())); - PHASAR_LOG_LEVEL(DEBUG, - " Target D: " << DToString(Edge.factAtTarget()))); + IF_LOG_LEVEL_ENABLED(DEBUG, { + PHASAR_LOG_LEVEL(DEBUG, "JumpFunctions Forward-Lookup:"); + PHASAR_LOG_LEVEL(DEBUG, + " Source D: " << DToString(Edge.factAtSource())); + PHASAR_LOG_LEVEL(DEBUG, " Target N: " << NToString(Edge.getTarget())); + PHASAR_LOG_LEVEL(DEBUG, + " Target D: " << DToString(Edge.factAtTarget())); + }); auto FwdLookupRes = JumpFn->forwardLookup(Edge.factAtSource(), Edge.getTarget()); @@ -617,21 +619,22 @@ class IDESolver void pathEdgeProcessingTask(PathEdge Edge) { PAMM_GET_INSTANCE; INC_COUNTER("JumpFn Construction", 1, Full); - IF_LOG_ENABLED( - PHASAR_LOG_LEVEL( - DEBUG, - "-------------------------------------------- " - << PathEdgeCount - << ". Path Edge --------------------------------------------"); - PHASAR_LOG_LEVEL(DEBUG, ' '); - PHASAR_LOG_LEVEL(DEBUG, "Process " << PathEdgeCount << ". path edge:"); - PHASAR_LOG_LEVEL(DEBUG, "< D source: " << DToString(Edge.factAtSource()) - << " ;"); - PHASAR_LOG_LEVEL(DEBUG, - " N target: " << NToString(Edge.getTarget()) << " ;"); - PHASAR_LOG_LEVEL(DEBUG, " D target: " << DToString(Edge.factAtTarget()) - << " >"); - PHASAR_LOG_LEVEL(DEBUG, ' ')); + IF_LOG_LEVEL_ENABLED(DEBUG, { + PHASAR_LOG_LEVEL( + DEBUG, + "-------------------------------------------- " + << PathEdgeCount + << ". Path Edge --------------------------------------------"); + PHASAR_LOG_LEVEL(DEBUG, ' '); + PHASAR_LOG_LEVEL(DEBUG, "Process " << PathEdgeCount << ". path edge:"); + PHASAR_LOG_LEVEL(DEBUG, "< D source: " << DToString(Edge.factAtSource()) + << " ;"); + PHASAR_LOG_LEVEL(DEBUG, + " N target: " << NToString(Edge.getTarget()) << " ;"); + PHASAR_LOG_LEVEL(DEBUG, " D target: " << DToString(Edge.factAtTarget()) + << " >"); + PHASAR_LOG_LEVEL(DEBUG, ' '); + }); if (!ICF->isCallSite(Edge.getTarget())) { if (ICF->isExitInst(Edge.getTarget())) { @@ -1063,28 +1066,31 @@ class IDESolver EdgeFunction fPrime = JumpFnE.joinWith(f); bool NewFunction = fPrime != JumpFnE; - IF_LOG_ENABLED( - PHASAR_LOG_LEVEL( - DEBUG, "Join: " << JumpFnE << " & " << f - << (JumpFnE == f ? " (EF's are equal)" : " ")); - PHASAR_LOG_LEVEL(DEBUG, - " = " << fPrime + IF_LOG_LEVEL_ENABLED(DEBUG, { + PHASAR_LOG_LEVEL(DEBUG, + "Join: " << JumpFnE << " & " << f + << (JumpFnE == f ? " (EF's are equal)" : " ")); + PHASAR_LOG_LEVEL(DEBUG, " = " + << fPrime << (NewFunction ? " (new jump func)" : " ")); - PHASAR_LOG_LEVEL(DEBUG, ' ')); + PHASAR_LOG_LEVEL(DEBUG, ' '); + }); if (NewFunction) { JumpFn->addFunction(SourceVal, Target, TargetVal, fPrime); PathEdge Edge(SourceVal, Target, TargetVal); PathEdgeCount++; pathEdgeProcessingTask(std::move(Edge)); - IF_LOG_ENABLED(if (!IDEProblem.isZeroValue(TargetVal)) { - PHASAR_LOG_LEVEL(DEBUG, "EDGE: getFunction()->getName() - << ", D: " << DToString(SourceVal) - << '>'); - PHASAR_LOG_LEVEL(DEBUG, " ---> '); - PHASAR_LOG_LEVEL(DEBUG, ' '); + IF_LOG_LEVEL_ENABLED(DEBUG, { + if (!IDEProblem.isZeroValue(TargetVal)) { + PHASAR_LOG_LEVEL( + DEBUG, "EDGE: getFunction()->getName() + << ", D: " << DToString(SourceVal) << '>'); + PHASAR_LOG_LEVEL(DEBUG, " ---> '); + PHASAR_LOG_LEVEL(DEBUG, ' '); + } }); } else { PHASAR_LOG_LEVEL(DEBUG, "PROPAGATE: No new function!"); @@ -1118,41 +1124,43 @@ class IDESolver } void printIncomingTab() const { - IF_LOG_ENABLED( - PHASAR_LOG_LEVEL(DEBUG, "Start of incomingtab entry"); - for (const auto &Cell - : IncomingTab.cellSet()) { - PHASAR_LOG_LEVEL(DEBUG, "sP: " << NToString(Cell.getRowKey())); - PHASAR_LOG_LEVEL(DEBUG, "d3: " << DToString(Cell.getColumnKey())); - for (const auto &Entry : Cell.getValue()) { - PHASAR_LOG_LEVEL(DEBUG, " n: " << NToString(Entry.first)); - for (const auto &Fact : Entry.second) { - PHASAR_LOG_LEVEL(DEBUG, " d2: " << DToString(Fact)); - } + IF_LOG_LEVEL_ENABLED(DEBUG, { + PHASAR_LOG_LEVEL(DEBUG, "Start of incomingtab entry"); + for (const auto &Cell : IncomingTab.cellSet()) { + PHASAR_LOG_LEVEL(DEBUG, "sP: " << NToString(Cell.getRowKey())); + PHASAR_LOG_LEVEL(DEBUG, "d3: " << DToString(Cell.getColumnKey())); + for (const auto &Entry : Cell.getValue()) { + PHASAR_LOG_LEVEL(DEBUG, " n: " << NToString(Entry.first)); + for (const auto &Fact : Entry.second) { + PHASAR_LOG_LEVEL(DEBUG, " d2: " << DToString(Fact)); } - PHASAR_LOG_LEVEL(DEBUG, "---------------"); - } PHASAR_LOG_LEVEL(DEBUG, "End of incomingtab entry");) + } + PHASAR_LOG_LEVEL(DEBUG, "---------------"); + } + PHASAR_LOG_LEVEL(DEBUG, "End of incomingtab entry"); + }) } void printEndSummaryTab() const { - IF_LOG_ENABLED( - PHASAR_LOG_LEVEL(DEBUG, "Start of endsummarytab entry"); - - EndsummaryTab.foreachCell( - [](const auto &Row, const auto &Col, const auto &Val) { - PHASAR_LOG_LEVEL(DEBUG, "sP: " << NToString(Row)); - PHASAR_LOG_LEVEL(DEBUG, "d1: " << DToString(Col)); - - Val.foreachCell([](const auto &InnerRow, const auto &InnerCol, - const auto &InnerVal) { - PHASAR_LOG_LEVEL(DEBUG, " eP: " << NToString(InnerRow)); - PHASAR_LOG_LEVEL(DEBUG, " d2: " << DToString(InnerCol)); - PHASAR_LOG_LEVEL(DEBUG, " EF: " << InnerVal); - }); - PHASAR_LOG_LEVEL(DEBUG, "---------------"); + IF_LOG_LEVEL_ENABLED(DEBUG, { + PHASAR_LOG_LEVEL(DEBUG, "Start of endsummarytab entry"); + + EndsummaryTab.foreachCell( + [](const auto &Row, const auto &Col, const auto &Val) { + PHASAR_LOG_LEVEL(DEBUG, "sP: " << NToString(Row)); + PHASAR_LOG_LEVEL(DEBUG, "d1: " << DToString(Col)); + + Val.foreachCell([](const auto &InnerRow, const auto &InnerCol, + const auto &InnerVal) { + PHASAR_LOG_LEVEL(DEBUG, " eP: " << NToString(InnerRow)); + PHASAR_LOG_LEVEL(DEBUG, " d2: " << DToString(InnerCol)); + PHASAR_LOG_LEVEL(DEBUG, " EF: " << InnerVal); }); + PHASAR_LOG_LEVEL(DEBUG, "---------------"); + }); - PHASAR_LOG_LEVEL(DEBUG, "End of endsummarytab entry");) + PHASAR_LOG_LEVEL(DEBUG, "End of endsummarytab entry"); + }) } void printComputedPathEdges() { @@ -1259,7 +1267,7 @@ class IDESolver if (ICF->isCallSite(Edge.first)) { ValidInCallerContext[Edge.second].insert(D2s.begin(), D2s.end()); } - IF_LOG_ENABLED([this](const auto &D2s) { + IF_LOG_LEVEL_ENABLED(DEBUG, [this](const auto &D2s) { for (auto D2 : D2s) { PHASAR_LOG_LEVEL(DEBUG, "d2: " << DToString(D2)); } @@ -1671,6 +1679,8 @@ class IDESolver void finalizeInternal() { PAMM_GET_INSTANCE; STOP_TIMER("DFA Phase I", Full); + PHASAR_LOG_LEVEL(INFO, "[info]: IDE Phase I completed"); + if (SolverConfig.computeValues()) { START_TIMER("DFA Phase II", Full); // Computing the final values for the edge functions @@ -1679,6 +1689,7 @@ class IDESolver computeValues(); STOP_TIMER("DFA Phase II", Full); } + PHASAR_LOG_LEVEL(INFO, "Problem solved"); if constexpr (PAMM_CURR_SEV_LEVEL >= PAMM_SEVERITY_LEVEL::Core) { computeAndPrintStatistics(); diff --git a/include/phasar/Utils/Logger.h b/include/phasar/Utils/Logger.h index b35b3f806..6b3ea5e18 100644 --- a/include/phasar/Utils/Logger.h +++ b/include/phasar/Utils/Logger.h @@ -12,17 +12,12 @@ #include "phasar/Config/phasar-config.h" -#include "llvm/ADT/StringMap.h" #include "llvm/ADT/StringRef.h" #include "llvm/Support/Compiler.h" // LLVM_UNLIKELY -#include "llvm/Support/ErrorHandling.h" #include "llvm/Support/raw_ostream.h" -#include #include #include -#include -#include namespace psr { @@ -32,33 +27,40 @@ enum SeverityLevel { INVALID }; -SeverityLevel parseSeverityLevel(llvm::StringRef Str); +[[nodiscard]] SeverityLevel parseSeverityLevel(llvm::StringRef Str) noexcept; +[[nodiscard]] llvm::StringRef to_string(SeverityLevel Level) noexcept; class Logger final { public: /** * Set the filter level. */ - static void setLoggerFilterLevel(SeverityLevel Level); + static void setLoggerFilterLevel(SeverityLevel Level) noexcept; - static SeverityLevel getLoggerFilterLevel(); - - static bool isLoggingEnabled(); + static SeverityLevel getLoggerFilterLevel() noexcept { + return LogFilterLevel; + } - static void enable() { LoggingEnabled = true; }; + static bool isLoggingEnabled() noexcept { return LoggingEnabled; } - static void disable() { LoggingEnabled = false; }; + static void enable() noexcept { LoggingEnabled = true; }; + static void disable() noexcept { LoggingEnabled = false; }; static llvm::raw_ostream & getLogStream(std::optional Level, const std::optional &Category); - static bool logCategory(llvm::StringRef Category, - std::optional Level); + static llvm::raw_ostream & + getLogStreamWithLinePrefix(std::optional Level, + const std::optional &Category); + + [[nodiscard]] static bool + logCategory(llvm::StringRef Category, + std::optional Level) noexcept; static void addLinePrefix(llvm::raw_ostream &, std::optional Level, - const std::optional &Category); + const std::optional &Category); static void initializeStdoutLogger( std::optional Level = std::nullopt, @@ -75,32 +77,15 @@ class Logger final { bool Append = false); private: - enum class StdStream : uint8_t { STDOUT = 0, STDERR }; static inline bool LoggingEnabled = false; - static inline llvm::StringMap, - std::variant>> - CategoriesToStreamVariant; - static inline std::map, - std::variant> - LevelsToStreamVariant; - static inline SeverityLevel LogFilterLevel = DEBUG; - static std::string toString(SeverityLevel Level); - static inline llvm::StringMap LogfileStreams; - // static inline auto StartTime = std::chrono::steady_clock::now(); - [[nodiscard]] static llvm::raw_ostream & - getLogStream(std::optional Level, - const std::map, - std::variant> - &PassedLevelsToStreamVariant); - [[nodiscard]] static llvm::raw_ostream &getLogStreamFromStreamVariant( - const std::variant &StreamVariant); + static inline SeverityLevel LogFilterLevel = CRITICAL; }; #ifdef DYNAMIC_LOG // For performance reason, we want to disable any // formatting computation that would go straight into -// logs if logs are deactivated This macro does just +// logs if logs are deactivated. This macro does just // that #define IF_LOG_ENABLED_BOOL(condition, computation) \ if (LLVM_UNLIKELY(condition)) { \ @@ -108,66 +93,66 @@ class Logger final { } #define IS_LOG_ENABLED ::psr::Logger::isLoggingEnabled() - #define IF_LOG_ENABLED(computation) \ IF_LOG_ENABLED_BOOL(::psr::Logger::isLoggingEnabled(), computation) +#define IS_LOG_LEVEL_ENABLED(level) \ + (::psr::Logger::isLoggingEnabled() && \ + (::psr::SeverityLevel::level) >= ::psr::Logger::getLoggerFilterLevel()) +#define IF_LOG_LEVEL_ENABLED(level, computation) \ + IF_LOG_ENABLED_BOOL(IS_LOG_LEVEL_ENABLED(level), computation) + #define PHASAR_LOG_LEVEL(level, message) \ - IF_LOG_ENABLED_BOOL( \ - ::psr::Logger::isLoggingEnabled() && \ - (::psr::SeverityLevel::level) >= \ - ::psr::Logger::getLoggerFilterLevel(), \ - do { \ - auto &Stream = ::psr::Logger::getLogStream( \ - ::psr::SeverityLevel::level, std::nullopt); \ - ::psr::Logger::addLinePrefix(Stream, ::psr::SeverityLevel::level, \ - std::nullopt); \ - /* NOLINTNEXTLINE(bugprone-macro-parentheses) */ \ - Stream << message << '\n'; \ - } while (false);) + do { \ + IF_LOG_ENABLED_BOOL(IS_LOG_LEVEL_ENABLED(level), { \ + auto &Stream = ::psr::Logger::getLogStreamWithLinePrefix( \ + ::psr::SeverityLevel::level, std::nullopt); \ + /* NOLINTNEXTLINE(bugprone-macro-parentheses) */ \ + Stream << message << '\n'; \ + }) \ + } while (false) #define PHASAR_LOG(message) PHASAR_LOG_LEVEL(DEBUG, message) #define PHASAR_LOG_LEVEL_CAT(level, cat, message) \ - IF_LOG_ENABLED_BOOL( \ - ::psr::Logger::isLoggingEnabled() && \ - (::psr::SeverityLevel::level) >= \ - ::psr::Logger::getLoggerFilterLevel() && \ - ::psr::Logger::logCategory(cat, ::psr::SeverityLevel::level), \ - do { \ - auto &Stream = \ - ::psr::Logger::getLogStream(::psr::SeverityLevel::level, cat); \ - ::psr::Logger::addLinePrefix(Stream, ::psr::SeverityLevel::level, \ - cat); \ - /* NOLINTNEXTLINE(bugprone-macro-parentheses) */ \ - Stream << message << '\n'; \ - } while (false);) + do { \ + IF_LOG_ENABLED_BOOL( \ + IS_LOG_LEVEL_ENABLED(level) && \ + ::psr::Logger::logCategory(cat, ::psr::SeverityLevel::level), \ + { \ + auto &Stream = ::psr::Logger::getLogStreamWithLinePrefix( \ + ::psr::SeverityLevel::level, cat); \ + /* NOLINTNEXTLINE(bugprone-macro-parentheses) */ \ + Stream << message << '\n'; \ + }) \ + } while (false) #define PHASAR_LOG_CAT(cat, message) \ - IF_LOG_ENABLED_BOOL( \ - ::psr::Logger::isLoggingEnabled() && \ - ::psr::Logger::logCategory(cat, std::nullopt), \ - do { \ - auto &Stream = ::psr::Logger::getLogStream(std::nullopt, cat); \ - ::psr::Logger::addLinePrefix(Stream, std::nullopt, cat); \ - /* NOLINTNEXTLINE(bugprone-macro-parentheses) */ \ - Stream << message << '\n'; \ - } while (false);) + do { \ + IF_LOG_ENABLED_BOOL(::psr::Logger::isLoggingEnabled() && \ + ::psr::Logger::logCategory(cat, std::nullopt), \ + { \ + auto &Stream = \ + ::psr::Logger::getLogStreamWithLinePrefix( \ + std::nullopt, cat); \ + /* NOLINTNEXTLINE(bugprone-macro-parentheses) */ \ + Stream << message << '\n'; \ + }) \ + } while (false) #else +#define IS_LOG_ENABLED false #define IF_LOG_ENABLED_BOOL(condition, computation) \ {} #define IF_LOG_ENABLED(computation) \ {} -#define PHASAR_LOG(computation) \ +#define IS_LOG_LEVEL_ENABLED(level) false +#define IF_LOG_LEVEL_ENABLED(level, computation) \ {} -#define PHASAR_LOG_CAT(cat, message) \ - {} -#define PHASAR_LOG_LEVEL_CAT(level, cat, message) \ - {} -#define PHASAR_LOG_LEVEL(level, message) \ - {} -#define IS_LOG_ENABLED false +#define PHASAR_LOG(computation) (void)0 +#define PHASAR_LOG_CAT(cat, message) (void)0 +#define PHASAR_LOG_LEVEL_CAT(level, cat, message) (void)0 +#define PHASAR_LOG_LEVEL(level, message) (void)0 #endif /** diff --git a/include/phasar/Utils/TypeTraits.h b/include/phasar/Utils/TypeTraits.h index 77bcfa36a..d3022d72c 100644 --- a/include/phasar/Utils/TypeTraits.h +++ b/include/phasar/Utils/TypeTraits.h @@ -21,6 +21,12 @@ namespace psr { +#if __cplusplus < 202002L +template struct type_identity { using type = T; }; +#else +template using type_identity = std::type_identity; +#endif + // NOLINTBEGIN(readability-identifier-naming) namespace detail { @@ -147,6 +153,13 @@ struct AreEqualityComparable() == std::declval())> : std::true_type {}; +template struct variant_idx; +template +struct variant_idx, T> + : std::integral_constant< + size_t, + std::variant...>(type_identity{}).index()> {}; + } // namespace detail template @@ -217,14 +230,11 @@ template static inline constexpr bool AreEqualityComparable = detail::AreEqualityComparable::value; -#if __cplusplus < 202002L -template struct type_identity { using type = T; }; -#else -template using type_identity = std::type_identity; -#endif - template using type_identity_t = typename type_identity::type; +template +static constexpr size_t variant_idx = detail::variant_idx::value; + struct TrueFn { template [[nodiscard]] bool operator()(const Args &.../*unused*/) const noexcept { diff --git a/lib/Utils/Logger.cpp b/lib/Utils/Logger.cpp index 85b88f290..35cd18a29 100644 --- a/lib/Utils/Logger.cpp +++ b/lib/Utils/Logger.cpp @@ -16,19 +16,24 @@ #include "phasar/Utils/Logger.h" +#include "phasar/Utils/TypeTraits.h" + +#include "llvm/ADT/STLExtras.h" +#include "llvm/ADT/StringMap.h" #include "llvm/ADT/StringSwitch.h" #include "llvm/Support/FileSystem.h" -namespace psr { +#include +#include -SeverityLevel parseSeverityLevel(llvm::StringRef Str) { +auto psr::parseSeverityLevel(llvm::StringRef Str) noexcept -> SeverityLevel { return llvm::StringSwitch(Str) #define SEVERITY_LEVEL(NAME, TYPE) .Case(NAME, SeverityLevel::TYPE) #include "phasar/Utils/SeverityLevel.def" .Default(SeverityLevel::INVALID); } -std::string Logger::toString(SeverityLevel Level) { +llvm::StringRef psr::to_string(SeverityLevel Level) noexcept { switch (Level) { default: #define SEVERITY_LEVEL(NAME, TYPE) \ @@ -39,63 +44,116 @@ std::string Logger::toString(SeverityLevel Level) { } } -void Logger::setLoggerFilterLevel(SeverityLevel Level) { - LogFilterLevel = Level; +namespace psr { +namespace logger { + +struct StdOut {}; +struct StdErr {}; +using StreamVariantTy = std::variant; + +static llvm::StringMap, StreamVariantTy>> + CategoriesToStreamVariant; +static std::map, StreamVariantTy> + LevelsToStreamVariant; + +static llvm::StringMap LogfileStreams; +// static inline auto StartTime = std::chrono::steady_clock::now(); + +// --- + +[[nodiscard]] static llvm::raw_ostream & +getLogStreamFromStreamVariant(const StreamVariantTy &StreamVariant) { + switch (StreamVariant.index()) { + case variant_idx: + return llvm::outs(); + case variant_idx: + return llvm::errs(); + case variant_idx: { + const auto &Filename = std::get(StreamVariant); + auto It = LogfileStreams.find(Filename); + assert(It != LogfileStreams.end()); + return It->second; + } + } + llvm_unreachable("All stream variants should be handled in the switch above"); +} + +[[nodiscard]] static llvm::raw_ostream & +getLogStream(std::optional Level, + const std::map, StreamVariantTy> + &PassedLevelsToStreamVariant) { + if (Level.has_value()) { + for (const auto &[LevelThreshold, StreamVar] : + llvm::reverse(PassedLevelsToStreamVariant)) { + if (LevelThreshold <= *Level) { + return getLogStreamFromStreamVariant(StreamVar); + } + } + // fallthrough + } + + auto StreamVariantIt = PassedLevelsToStreamVariant.find(std::nullopt); + if (StreamVariantIt != PassedLevelsToStreamVariant.end()) { + return getLogStreamFromStreamVariant(StreamVariantIt->second); + } + return llvm::nulls(); } -SeverityLevel Logger::getLoggerFilterLevel() { return LogFilterLevel; } +template +void initializeLoggerImpl(std::optional Level, + const std::optional &Category, + StdStreamTy Stream) { + using namespace logger; + if (Category.has_value()) { + CategoriesToStreamVariant[*Category].insert_or_assign(Level, + std::move(Stream)); + } else { + LevelsToStreamVariant.insert_or_assign(Level, std::move(Stream)); + } +} -bool Logger::isLoggingEnabled() { return LoggingEnabled; } +} // namespace logger + +void Logger::setLoggerFilterLevel(SeverityLevel Level) noexcept { + assert(Level >= SeverityLevel::DEBUG && Level < SeverityLevel::INVALID); + LogFilterLevel = Level; +} void Logger::initializeStdoutLogger( std::optional Level, const std::optional &Category) { LoggingEnabled = true; - if (Category.has_value()) { - CategoriesToStreamVariant[Category.value()][Level] = StdStream::STDOUT; - } else { - LevelsToStreamVariant[Level] = StdStream::STDOUT; - } + logger::initializeLoggerImpl(Level, Category, logger::StdOut{}); + LogFilterLevel = std::min(LogFilterLevel, Level.value_or(CRITICAL)); } void Logger::initializeStderrLogger( std::optional Level, const std::optional &Category) { LoggingEnabled = true; - if (Category.has_value()) { - CategoriesToStreamVariant[Category.value()][Level] = StdStream::STDERR; - } else { - LevelsToStreamVariant[Level] = StdStream::STDERR; - } + logger::initializeLoggerImpl(Level, Category, logger::StdErr{}); + LogFilterLevel = std::min(LogFilterLevel, Level.value_or(CRITICAL)); } -[[nodiscard]] bool Logger::initializeFileLogger( - llvm::StringRef Filename, std::optional Level, - const std::optional &Category, bool Append) { +bool Logger::initializeFileLogger(llvm::StringRef Filename, + std::optional Level, + const std::optional &Category, + bool Append) { + using logger::LogfileStreams; + LoggingEnabled = true; - if (Category.has_value()) { - CategoriesToStreamVariant[Category.value()][Level] = Filename.str(); - } else { - LevelsToStreamVariant[Level] = Filename.str(); + logger::initializeLoggerImpl(Level, Category, Filename.str()); + LogFilterLevel = std::min(LogFilterLevel, Level.value_or(CRITICAL)); + + auto Flags = llvm::sys::fs::OpenFlags::OF_ChildInherit; + if (Append) { + Flags |= llvm::sys::fs::OpenFlags::OF_Append; } std::error_code EC; - auto [It, Inserted] = [&] { - if (Append) { - return LogfileStreams.try_emplace( - Filename, Filename, EC, - llvm::sys::fs::OpenFlags::OF_Append | - llvm::sys::fs::OpenFlags::OF_ChildInherit); - } - - return LogfileStreams.try_emplace( - Filename, Filename, EC, llvm::sys::fs::OpenFlags::OF_ChildInherit); - }(); - - if (!Inserted) { - return true; - } + LogfileStreams.try_emplace(Filename, Filename, EC, Flags); + // EC can only be true, if a new filestream was inserted if (EC) { LogfileStreams.erase(Filename); llvm::errs() << "Failed to open logfile: " << Filename << '\n'; @@ -108,99 +166,67 @@ void Logger::initializeStderrLogger( llvm::raw_ostream & Logger::getLogStream(std::optional Level, const std::optional &Category) { + using namespace logger; if (Category.has_value()) { - auto CategoryLookupIt = CategoriesToStreamVariant.find(Category.value()); + auto CategoryLookupIt = CategoriesToStreamVariant.find(*Category); if (CategoryLookupIt == CategoriesToStreamVariant.end()) { return llvm::nulls(); } - return getLogStream(Level, CategoryLookupIt->second); + return logger::getLogStream(Level, CategoryLookupIt->second); } - return getLogStream(Level, LevelsToStreamVariant); + return logger::getLogStream(Level, LevelsToStreamVariant); } -llvm::raw_ostream & -Logger::getLogStream(std::optional Level, - const std::map, - std::variant> - &PassedLevelsToStreamVariant) { - if (Level.has_value()) { - std::optional ClosestLevel = std::nullopt; - for (const auto &[LevelThreshold, _] : PassedLevelsToStreamVariant) { - if (LevelThreshold <= Level.value()) { - if (!ClosestLevel || ClosestLevel.value() < LevelThreshold) { - ClosestLevel = LevelThreshold; - } - } - } - auto StreamVariantIt = PassedLevelsToStreamVariant.find(ClosestLevel); - if (StreamVariantIt != PassedLevelsToStreamVariant.end()) { - return getLogStreamFromStreamVariant(StreamVariantIt->second); - } - return llvm::nulls(); - } - auto StreamVariantIt = PassedLevelsToStreamVariant.find(Level); - if (StreamVariantIt != PassedLevelsToStreamVariant.end()) { - return getLogStreamFromStreamVariant(StreamVariantIt->second); - } - return llvm::nulls(); -} - -llvm::raw_ostream &Logger::getLogStreamFromStreamVariant( - const std::variant &StreamVariant) { - if (std::holds_alternative(StreamVariant)) { - auto StdStreamKind = std::get(StreamVariant); - if (StdStreamKind == StdStream::STDOUT) { - return llvm::outs(); - } - if (StdStreamKind == StdStream::STDERR) { - return llvm::errs(); - } - return llvm::nulls(); - } - auto It = LogfileStreams.find(std::get(StreamVariant)); - assert(It != LogfileStreams.end()); - return It->second; +llvm::raw_ostream &Logger::getLogStreamWithLinePrefix( + std::optional Level, + const std::optional &Category) { + auto &OS = getLogStream(Level, Category); + addLinePrefix(OS, Level, Category); + return OS; } bool Logger::logCategory(llvm::StringRef Category, - std::optional Level) { + std::optional Level) noexcept { + using namespace logger; auto CategoryLookupIt = CategoriesToStreamVariant.find(Category); if (CategoryLookupIt == CategoriesToStreamVariant.end()) { return false; } if (Level.has_value()) { for (const auto &[LevelThreshold, Stream] : CategoryLookupIt->second) { - if (LevelThreshold <= Level.value()) { + if (LevelThreshold <= *Level) { return true; } } return false; } - return CategoryLookupIt->second.count(Level) > 0; + return CategoryLookupIt->second.count(Level); } void Logger::addLinePrefix(llvm::raw_ostream &OS, std::optional Level, - const std::optional &Category) { + const std::optional &Category) { // const auto NowTime = std::chrono::steady_clock::now(); // const auto MillisecondsDuration = // chrono::duration_cast(NowTime - // StartTime).count(); // OS << MillisecondsDuration; if (Level.has_value()) { - OS << '[' << toString(Level.value()) << ']'; + OS << '[' << to_string(*Level) << ']'; } // else { // OS << ' '; // } if (Category.has_value()) { - OS << '[' << Category.value() << ']'; + OS << '[' << *Category << ']'; } // else { // OS << ' '; // } OS << ' '; } -void initializeLogger(bool UseLogger, const std::string &LogFile) { +} // namespace psr + +void psr::initializeLogger(bool UseLogger, const std::string &LogFile) { if (!UseLogger) { Logger::disable(); return; @@ -212,5 +238,3 @@ void initializeLogger(bool UseLogger, const std::string &LogFile) { Logger::initializeFileLogger(LogFile, Logger::getLoggerFilterLevel()); } } - -} // namespace psr