diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 9eb0f1d5b1..7f1a4fd25d 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -15,7 +15,7 @@ jobs: fail-fast: true matrix: os: [ubuntu-24.04, ubuntu-24.04-arm] - compiler: [ [clang++-20, clang-20, "clang-20 libclang-rt-20-dev clang-tools-20"] ] + compiler: [ [clang++-21, clang-21, "clang-21 libclang-rt-21-dev clang-tools-21"] ] build: [ Debug, Release, DebugLibdeps, DebugCov ] llvm-version: [ 16, "22.1" ] include: @@ -31,7 +31,7 @@ jobs: - build: DebugCov cmake_build_type: Debug flags: -DCODE_COVERAGE=ON - extra_dependencies: llvm-20 # For coverage + extra_dependencies: llvm-21 # For coverage - llvm-version: 16 llvm-major-version: 16 - llvm-version: "22.1" @@ -75,6 +75,7 @@ jobs: -DBUILD_PHASAR_CLANG=OFF \ -DPHASAR_USE_Z3=ON \ -DPHASAR_BUILD_MODULES=ON \ + -DPHASAR_TARGET_ARCH="" \ -DPHASAR_LLVM_VERSION=${{ matrix.llvm-version }} \ ${{ matrix.flags }} \ -G Ninja diff --git a/CMakeLists.txt b/CMakeLists.txt index e0f081ae3f..0742d7c122 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -197,18 +197,16 @@ if (PHASAR_ENABLE_PIC) endif (PHASAR_ENABLE_PIC) # PAMM -if (NOT PHASAR_ENABLE_PAMM) - set(PHASAR_ENABLE_PAMM "Off" CACHE STRING "Enable the performance measurement mechanism ('Off', 'Core' or 'Full', default is 'Off')" FORCE) - set_property(CACHE PHASAR_ENABLE_PAMM PROPERTY STRINGS "Off" "Core" "Full") -endif() -if(PHASAR_ENABLE_PAMM STREQUAL "Core" AND NOT PHASAR_BUILD_UNITTESTS) +set(PHASAR_ENABLE_PAMM "Off" CACHE STRING "Enable the performance measurement mechanism ('Off', 'Core' or 'Full', default is 'Off')") +set_property(CACHE PHASAR_ENABLE_PAMM PROPERTY STRINGS "Off" "Core" "Full") +option(PHASAR_THREAD_SAFE_PAMM "Use a thread-safe version of PAMM, if PAMM is enabled" ON) + +if(PHASAR_ENABLE_PAMM STREQUAL "Core") set(PAMM_CORE ON) message(STATUS "PAMM metric severity level: Core") -elseif(PHASAR_ENABLE_PAMM STREQUAL "Full" AND NOT PHASAR_BUILD_UNITTESTS) +elseif(PHASAR_ENABLE_PAMM STREQUAL "Full") set(PAMM_FULL ON) message(STATUS "PAMM metric severity level: Full") -elseif(PHASAR_BUILD_UNITTESTS AND (PHASAR_ENABLE_PAMM STREQUAL "Core" OR PHASAR_ENABLE_PAMM STREQUAL "Full")) - message(WARNING "PAMM metric severity level: Off (due to unittests)") else() message(STATUS "PAMM metric severity level: Off") endif() diff --git a/config.h.in b/config.h.in index 926d69b0bf..b8d5423b9a 100644 --- a/config.h.in +++ b/config.h.in @@ -7,6 +7,7 @@ #cmakedefine PAMM_CORE #cmakedefine PAMM_FULL +#cmakedefine PHASAR_THREAD_SAFE_PAMM #cmakedefine DYNAMIC_LOG #cmakedefine BUILD_PHASAR_CLANG diff --git a/include/phasar/DataFlow/IfdsIde/Solver/FlowEdgeFunctionCache.h b/include/phasar/DataFlow/IfdsIde/Solver/FlowEdgeFunctionCache.h index 7521fb865c..884ddb0280 100644 --- a/include/phasar/DataFlow/IfdsIde/Solver/FlowEdgeFunctionCache.h +++ b/include/phasar/DataFlow/IfdsIde/Solver/FlowEdgeFunctionCache.h @@ -69,6 +69,45 @@ class LLVMMapKeyCompressor { llvm::DenseMap Map{}; }; +namespace detail { +struct FlowEdgeFunctionCachePerf { + PAMM_CATEGORY(FlowEdgeFunctionCache); + + // NOLINTBEGIN + PAMM_COUNTER(NormalFF_Construction, Full); + PAMM_COUNTER(NormalFF_CacheHit, Full); + // Counters for the call flow functions + PAMM_COUNTER(CallFF_Construction, Full); + PAMM_COUNTER(CallFF_CacheHit, Full); + // Counters for return flow functions + PAMM_COUNTER(ReturnFF_Construction, Full); + PAMM_COUNTER(ReturnFF_CacheHit, Full); + // Counters for the call to return flow functions + PAMM_COUNTER(CallToRetFF_Construction, Full); + PAMM_COUNTER(CallToRetFF_CacheHit, Full); + // Counters for the summary flow functions + PAMM_COUNTER(SummaryFF_Construction, Full); + PAMM_COUNTER(SummaryFF_CacheHit, Full); + // Counters for the normal edge functions + PAMM_COUNTER(NormalEF_Construction, Full); + PAMM_COUNTER(NormalEF_CacheHit, Full); + // Counters for the call edge functions + PAMM_COUNTER(CallEF_Construction, Full); + PAMM_COUNTER(CallEF_CacheHit, Full); + // Counters for the return edge functions + PAMM_COUNTER(ReturnEF_Construction, Full); + PAMM_COUNTER(ReturnEF_CacheHit, Full); + // Counters for the call to return edge functions + PAMM_COUNTER(CallToRetEF_Construction, Full); + PAMM_COUNTER(CallToRetEF_CacheHit, Full); + // Counters for the summary edge functions + PAMM_COUNTER(SummaryEF_Construction, Full); + PAMM_COUNTER(SummaryEF_CacheHit, Full); + + // NOLINTEND +}; +} // namespace detail + /** * This class caches flow and edge functions to avoid their reconstruction. * When a flow or edge function must be applied to multiple times, a cached @@ -77,7 +116,7 @@ class LLVMMapKeyCompressor { */ template > -class FlowEdgeFunctionCache { +class FlowEdgeFunctionCache : private detail::FlowEdgeFunctionCachePerf { using IDEProblemType = IDETabulationProblem; using FlowFunctionPtrType = typename IDEProblemType::FlowFunctionPtrType; @@ -97,38 +136,7 @@ class FlowEdgeFunctionCache { IDETabulationProblem &Problem) : Problem(Problem), AutoAddZero(Problem.getIFDSIDESolverConfig().autoAddZero()), - ZV(Problem.getZeroValue()) { - PAMM_GET_INSTANCE; - REG_COUNTER("Normal-FF Construction", 0, Full); - REG_COUNTER("Normal-FF Cache Hit", 0, Full); - // Counters for the call flow functions - REG_COUNTER("Call-FF Construction", 0, Full); - REG_COUNTER("Call-FF Cache Hit", 0, Full); - // Counters for return flow functions - REG_COUNTER("Return-FF Construction", 0, Full); - REG_COUNTER("Return-FF Cache Hit", 0, Full); - // Counters for the call to return flow functions - REG_COUNTER("CallToRet-FF Construction", 0, Full); - REG_COUNTER("CallToRet-FF Cache Hit", 0, Full); - // Counters for the summary flow functions - REG_COUNTER("Summary-FF Construction", 0, Full); - REG_COUNTER("Summary-FF Cache Hit", 0, Full); - // Counters for the normal edge functions - REG_COUNTER("Normal-EF Construction", 0, Full); - REG_COUNTER("Normal-EF Cache Hit", 0, Full); - // Counters for the call edge functions - REG_COUNTER("Call-EF Construction", 0, Full); - REG_COUNTER("Call-EF Cache Hit", 0, Full); - // Counters for the return edge functions - REG_COUNTER("Return-EF Construction", 0, Full); - REG_COUNTER("Return-EF Cache Hit", 0, Full); - // Counters for the call to return edge functions - REG_COUNTER("CallToRet-EF Construction", 0, Full); - REG_COUNTER("CallToRet-EF Cache Hit", 0, Full); - // Counters for the summary edge functions - REG_COUNTER("Summary-EF Construction", 0, Full); - REG_COUNTER("Summary-EF Cache Hit", 0, Full); - } + ZV(Problem.getZeroValue()) {} ~FlowEdgeFunctionCache() = default; @@ -143,7 +151,6 @@ class FlowEdgeFunctionCache { n_t Succ) { assertNotNull(Curr); assertNotNull(Succ); - PAMM_GET_INSTANCE; IF_LOG_ENABLED( PHASAR_LOG_LEVEL(DEBUG, "Normal flow function factory call"); PHASAR_LOG_LEVEL(DEBUG, "(N) Curr Inst : " << NToString(Curr)); @@ -155,7 +162,7 @@ class FlowEdgeFunctionCache { // key, so getNormalEdgeFunction shares this entry via the same lookup. auto &NormalFE = NormalFunctionCache[std::move(Key)]; if (!NormalFE.FlowFuncPtr) { - INC_COUNTER("Normal-FF Construction", 1, Full); + NormalFF_Construction++; auto FF = Problem.getNormalFlowFunction(Curr, Succ); NormalFE.FlowFuncPtr = AutoAddZero ? std::make_unique(std::move(FF), ZV) @@ -163,7 +170,7 @@ class FlowEdgeFunctionCache { PHASAR_LOG_LEVEL(DEBUG, "Flow function constructed"); } else { PHASAR_LOG_LEVEL(DEBUG, "Flow function fetched from cache"); - INC_COUNTER("Normal-FF Cache Hit", 1, Full); + NormalFF_CacheHit++; } return getPointerFrom(NormalFE.FlowFuncPtr); @@ -173,7 +180,6 @@ class FlowEdgeFunctionCache { f_t DestFun) { assertNotNull(CallSite); assertNotNull(DestFun); - PAMM_GET_INSTANCE; IF_LOG_ENABLED( PHASAR_LOG_LEVEL(DEBUG, "Call flow function factory call"); PHASAR_LOG_LEVEL(DEBUG, "(N) Call Stmt : " << NToString(CallSite)); @@ -182,14 +188,14 @@ class FlowEdgeFunctionCache { auto [It, Inserted] = CallFlowFunctionCache.try_emplace(std::move(Key)); if (Inserted) { - INC_COUNTER("Call-FF Construction", 1, Full); + CallFF_Construction++; auto FF = Problem.getCallFlowFunction(CallSite, DestFun); It->second = AutoAddZero ? std::make_unique(std::move(FF), ZV) : std::move(FF); PHASAR_LOG_LEVEL(DEBUG, "Flow function constructed"); } else { PHASAR_LOG_LEVEL(DEBUG, "Flow function fetched from cache"); - INC_COUNTER("Call-FF Cache Hit", 1, Full); + CallFF_CacheHit++; } return getPointerFrom(It->second); @@ -201,7 +207,6 @@ class FlowEdgeFunctionCache { assertNotNull(CalleeFun); assertNotNull(ExitInst); assertNotNull(RetSite); - PAMM_GET_INSTANCE; IF_LOG_ENABLED( PHASAR_LOG_LEVEL(DEBUG, "Return flow function factory call"); PHASAR_LOG_LEVEL(DEBUG, "(N) Call Site : " << NToString(CallSite)); @@ -212,7 +217,7 @@ class FlowEdgeFunctionCache { auto [It, Inserted] = ReturnFlowFunctionCache.try_emplace(std::move(Key)); if (Inserted) { - INC_COUNTER("Return-FF Construction", 1, Full); + ReturnFF_Construction++; auto FF = Problem.getRetFlowFunction(CallSite, CalleeFun, ExitInst, RetSite); It->second = AutoAddZero ? std::make_unique(std::move(FF), ZV) @@ -221,7 +226,7 @@ class FlowEdgeFunctionCache { PHASAR_LOG_LEVEL(DEBUG, "Flow function constructed"); } else { PHASAR_LOG_LEVEL(DEBUG, "Flow function fetched from cache"); - INC_COUNTER("Return-FF Cache Hit", 1, Full); + ReturnFF_CacheHit++; } return getPointerFrom(It->second); } @@ -232,7 +237,6 @@ class FlowEdgeFunctionCache { assertNotNull(CallSite); assertNotNull(RetSite); assertAllNotNull(Callees); - PAMM_GET_INSTANCE; IF_LOG_ENABLED( PHASAR_LOG_LEVEL(DEBUG, "Call-to-Return flow function factory call"); @@ -247,7 +251,7 @@ class FlowEdgeFunctionCache { auto [It, Inserted] = CallToRetFlowFunctionCache.try_emplace(std::move(Key)); if (Inserted) { - INC_COUNTER("CallToRet-FF Construction", 1, Full); + CallToRetFF_Construction++; auto FF = Problem.getCallToRetFlowFunction(CallSite, RetSite, Callees); It->second = AutoAddZero ? std::make_unique(std::move(FF), ZV) : std::move(FF); @@ -255,7 +259,8 @@ class FlowEdgeFunctionCache { PHASAR_LOG_LEVEL(DEBUG, "Flow function constructed"); } else { PHASAR_LOG_LEVEL(DEBUG, "Flow function fetched from cache"); - INC_COUNTER("CallToRet-FF Cache Hit", 1, Full); + CallToRetFF_CacheHit++; + CallToRetFF_CacheHit++; } return getPointerFrom(It->second); @@ -269,8 +274,8 @@ class FlowEdgeFunctionCache { f_t DestFun) { assertNotNull(CallSite); assertNotNull(DestFun); - // PAMM_GET_INSTANCE; - // INC_COUNTER("Summary-FF Construction", 1, Full); + + SummaryFF_Construction++; IF_LOG_ENABLED( PHASAR_LOG_LEVEL(DEBUG, "Summary flow function factory call"); PHASAR_LOG_LEVEL(DEBUG, "(N) Call Stmt : " << NToString(CallSite)); @@ -285,7 +290,6 @@ class FlowEdgeFunctionCache { assertNotNull(Curr); assertNotNull(Succ); - PAMM_GET_INSTANCE; IF_LOG_ENABLED( PHASAR_LOG_LEVEL(DEBUG, "Normal edge function factory call"); PHASAR_LOG_LEVEL(DEBUG, "(N) Curr Inst : " << NToString(Curr)); @@ -298,14 +302,14 @@ class FlowEdgeFunctionCache { auto Ret = NormalFE.EdgeFunctionMap.getOrInsertLazy( createEdgeFunctionNodeKey(CurrNode, SuccNode), [&] { - INC_COUNTER("Normal-EF Construction", 1, Full); + NormalEF_Construction++; auto EF = Problem.getNormalEdgeFunction(Curr, CurrNode, Succ, SuccNode); PHASAR_LOG_LEVEL(DEBUG, "Edge function constructed"); return EF; }, [&] { - INC_COUNTER("Normal-EF Cache Hit", 1, Full); + NormalEF_CacheHit++; PHASAR_LOG_LEVEL(DEBUG, "Edge function fetched from cache"); }); PHASAR_LOG_LEVEL(DEBUG, "Provide Edge Function: " << Ret); @@ -319,7 +323,6 @@ class FlowEdgeFunctionCache { assertNotNull(CallSite); assertNotNull(DestinationFunction); - PAMM_GET_INSTANCE; IF_LOG_ENABLED( PHASAR_LOG_LEVEL(DEBUG, "Call edge function factory call"); PHASAR_LOG_LEVEL(DEBUG, "(N) Call Stmt : " << NToString(CallSite)); @@ -332,13 +335,13 @@ class FlowEdgeFunctionCache { auto [It, Inserted] = CallEdgeFunctionCache.try_emplace(std::move(Key)); if (Inserted) { - INC_COUNTER("Call-EF Construction", 1, Full); + CallEF_Construction++; It->second = Problem.getCallEdgeFunction(CallSite, SrcNode, DestinationFunction, DestNode); PHASAR_LOG_LEVEL(DEBUG, "Edge function constructed"); } else { - INC_COUNTER("Call-EF Cache Hit", 1, Full); + CallEF_CacheHit++; PHASAR_LOG_LEVEL(DEBUG, "Edge function fetched from cache"); } @@ -354,7 +357,6 @@ class FlowEdgeFunctionCache { assertNotNull(ExitInst); assertNotNull(RetSite); - PAMM_GET_INSTANCE; IF_LOG_ENABLED( PHASAR_LOG_LEVEL(DEBUG, "Return edge function factory call"); PHASAR_LOG_LEVEL(DEBUG, "(N) Call Site : " << NToString(CallSite)); @@ -369,10 +371,13 @@ class FlowEdgeFunctionCache { auto [It, Inserted] = ReturnEdgeFunctionCache.try_emplace(std::move(Key)); if (Inserted) { - INC_COUNTER("Return-EF Construction", 1, Full); + ReturnEF_Construction++; It->second = Problem.getReturnEdgeFunction( CallSite, CalleeFunction, ExitInst, ExitNode, RetSite, RetNode); PHASAR_LOG_LEVEL(DEBUG, "Edge function constructed"); + } else { + ReturnEF_CacheHit++; + PHASAR_LOG_LEVEL(DEBUG, "Edge function fetched from cache"); } PHASAR_LOG_LEVEL(DEBUG, "Provide Edge Function: " << It->second); @@ -386,7 +391,6 @@ class FlowEdgeFunctionCache { assertNotNull(RetSite); assertAllNotNull(Callees); - PAMM_GET_INSTANCE; IF_LOG_ENABLED( PHASAR_LOG_LEVEL(DEBUG, "Call-to-Return edge function factory call"); @@ -406,14 +410,14 @@ class FlowEdgeFunctionCache { auto Ret = Outer.getOrInsertLazy( std::move(createEdgeFunctionNodeKey(CallNode, RetSiteNode)), [&] { - INC_COUNTER("CallToRet-EF Construction", 1, Full); + CallToRetEF_Construction++; auto Ret = Problem.getCallToRetEdgeFunction( CallSite, CallNode, RetSite, RetSiteNode, Callees); PHASAR_LOG_LEVEL(DEBUG, "Edge function constructed"); return Ret; }, [&] { - INC_COUNTER("CallToRet-EF Cache Hit", 1, Full); + CallToRetEF_CacheHit++; PHASAR_LOG_LEVEL(DEBUG, "Edge function fetched from cache"); }); PHASAR_LOG_LEVEL(DEBUG, "Provide Edge Function: " << Ret); @@ -427,7 +431,6 @@ class FlowEdgeFunctionCache { assertNotNull(CallSite); assertNotNull(RetSite); - PAMM_GET_INSTANCE; IF_LOG_ENABLED( PHASAR_LOG_LEVEL(DEBUG, "Summary edge function factory call"); PHASAR_LOG_LEVEL(DEBUG, "(N) Call Site : " << NToString(CallSite)); @@ -438,12 +441,12 @@ class FlowEdgeFunctionCache { auto Key = std::tie(CallSite, CallNode, RetSite, RetSiteNode); auto [It, Inserted] = SummaryEdgeFunctionCache.try_emplace(std::move(Key)); if (Inserted) { - INC_COUNTER("Summary-EF Construction", 1, Full); + SummaryEF_Construction++; It->second = Problem.getSummaryEdgeFunction(CallSite, CallNode, RetSite, RetSiteNode); PHASAR_LOG_LEVEL(DEBUG, "Edge function constructed"); } else { - INC_COUNTER("Summary-EF Cache Hit", 1, Full); + SummaryEF_CacheHit++; PHASAR_LOG_LEVEL(DEBUG, "Edge function fetched from cache"); } @@ -453,69 +456,67 @@ class FlowEdgeFunctionCache { void print() { if constexpr (PAMM_CURR_SEV_LEVEL >= PAMM_SEVERITY_LEVEL::Full) { - PAMM_GET_INSTANCE; PHASAR_LOG_LEVEL(INFO, "=== Flow-Edge-Function Cache Statistics ==="); PHASAR_LOG_LEVEL(INFO, "Normal-flow function cache hits: " - << GET_COUNTER("Normal-FF Cache Hit")); + << NormalFF_CacheHit.value()); PHASAR_LOG_LEVEL(INFO, "Normal-flow function constructions: " - << GET_COUNTER("Normal-FF Construction")); - PHASAR_LOG_LEVEL(INFO, "Call-flow function cache hits: " - << GET_COUNTER("Call-FF Cache Hit")); + << NormalFF_Construction.value()); + PHASAR_LOG_LEVEL( + INFO, "Call-flow function cache hits: " << CallFF_CacheHit.value()); PHASAR_LOG_LEVEL(INFO, "Call-flow function constructions: " - << GET_COUNTER("Call-FF Construction")); + << CallFF_Construction.value()); PHASAR_LOG_LEVEL(INFO, "Return-flow function cache hits: " - << GET_COUNTER("Return-FF Cache Hit")); + << ReturnFF_CacheHit.value()); PHASAR_LOG_LEVEL(INFO, "Return-flow function constructions: " - << GET_COUNTER("Return-FF Construction")); + << ReturnFF_Construction.value()); PHASAR_LOG_LEVEL(INFO, "Call-to-Return-flow function cache hits: " - << GET_COUNTER("CallToRet-FF Cache Hit")); + << CallToRetFF_CacheHit.value()); PHASAR_LOG_LEVEL(INFO, "Call-to-Return-flow function constructions: " - << GET_COUNTER("CallToRet-FF Construction")); + << CallToRetFF_Construction.value()); PHASAR_LOG_LEVEL(INFO, "Summary-flow function cache hits: " - << GET_COUNTER("Summary-FF Cache Hit")); + << SummaryFF_CacheHit.value()); PHASAR_LOG_LEVEL(INFO, "Summary-flow function constructions: " - << GET_COUNTER("Summary-FF Construction")); - PHASAR_LOG_LEVEL(INFO, - "Total flow function cache hits: " << GET_SUM_COUNT( - {"Normal-FF Cache Hit", "Call-FF Cache Hit", - "Return-FF Cache Hit", "CallToRet-FF Cache Hit"})); + << SummaryFF_Construction.value()); + PHASAR_LOG_LEVEL( + INFO, "Total flow function cache hits: " << GET_SUM_COUNT( + NormalFF_CacheHit, CallFF_CacheHit, ReturnFF_CacheHit, + CallToRetFF_CacheHit, SummaryFF_CacheHit)); //"Summary-FF Cache Hit"}); - PHASAR_LOG_LEVEL(INFO, "Total flow function constructions: " - << GET_SUM_COUNT({"Normal-FF Construction", "Call-FF Construction", - "Return-FF Construction", - "CallToRet-FF Construction" /*, - "Summary-FF Construction"*/})); + PHASAR_LOG_LEVEL(INFO, + "Total flow function constructions: " << GET_SUM_COUNT( + NormalFF_Construction, CallFF_Construction, + CallToRetFF_Construction, ReturnFF_Construction, + SummaryFF_Construction)); PHASAR_LOG_LEVEL(INFO, ' '); - PHASAR_LOG_LEVEL(INFO, "Normal edge function cache hits: " - << GET_COUNTER("Normal-EF Cache Hit")); + PHASAR_LOG_LEVEL( + INFO, "Normal edge function cache hits: " << NormalEF_CacheHit); PHASAR_LOG_LEVEL(INFO, "Normal edge function constructions: " - << GET_COUNTER("Normal-EF Construction")); - PHASAR_LOG_LEVEL(INFO, "Call edge function cache hits: " - << GET_COUNTER("Call-EF Cache Hit")); - PHASAR_LOG_LEVEL(INFO, "Call edge function constructions: " - << GET_COUNTER("Call-EF Construction")); - PHASAR_LOG_LEVEL(INFO, "Return edge function cache hits: " - << GET_COUNTER("Return-EF Cache Hit")); + << NormalEF_Construction); + PHASAR_LOG_LEVEL(INFO, + "Call edge function cache hits: " << CallEF_CacheHit); + PHASAR_LOG_LEVEL( + INFO, "Call edge function constructions: " << CallEF_Construction); + PHASAR_LOG_LEVEL( + INFO, "Return edge function cache hits: " << ReturnEF_CacheHit); PHASAR_LOG_LEVEL(INFO, "Return edge function constructions: " - << GET_COUNTER("Return-EF Construction")); + << ReturnEF_Construction); PHASAR_LOG_LEVEL(INFO, "Call-to-Return edge function cache hits: " - << GET_COUNTER("CallToRet-EF Cache Hit")); + << CallToRetEF_CacheHit); PHASAR_LOG_LEVEL(INFO, "Call-to-Return edge function constructions: " - << GET_COUNTER("CallToRet-EF Construction")); - PHASAR_LOG_LEVEL(INFO, "Summary edge function cache hits: " - << GET_COUNTER("Summary-EF Cache Hit")); + << CallToRetEF_Construction); + PHASAR_LOG_LEVEL( + INFO, "Summary edge function cache hits: " << SummaryEF_CacheHit); PHASAR_LOG_LEVEL(INFO, "Summary edge function constructions: " - << GET_COUNTER("Summary-EF Construction")); - PHASAR_LOG_LEVEL(INFO, - "Total edge function cache hits: " << GET_SUM_COUNT( - {"Normal-EF Cache Hit", "Call-EF Cache Hit", - "Return-EF Cache Hit", "CallToRet-EF Cache Hit", - "Summary-EF Cache Hit"})); + << SummaryEF_Construction); PHASAR_LOG_LEVEL( - INFO, "Total edge function constructions: " << GET_SUM_COUNT( - {"Normal-EF Construction", "Call-EF Construction", - "Return-EF Construction", "CallToRet-EF Construction", - "Summary-EF Construction"})); + INFO, "Total edge function cache hits: " << GET_SUM_COUNT( + NormalEF_CacheHit, CallEF_CacheHit, ReturnEF_CacheHit, + CallToRetEF_CacheHit, SummaryEF_CacheHit)); + PHASAR_LOG_LEVEL(INFO, + "Total edge function constructions: " << GET_SUM_COUNT( + NormalEF_Construction, CallEF_Construction, + ReturnEF_Construction, CallToRetEF_Construction, + SummaryEF_Construction)); PHASAR_LOG_LEVEL(INFO, "----------------------------------------------"); } else { PHASAR_LOG_LEVEL( diff --git a/include/phasar/DataFlow/IfdsIde/Solver/IDESolver.h b/include/phasar/DataFlow/IfdsIde/Solver/IDESolver.h index 8a4c512b9c..c755406b3d 100644 --- a/include/phasar/DataFlow/IfdsIde/Solver/IDESolver.h +++ b/include/phasar/DataFlow/IfdsIde/Solver/IDESolver.h @@ -54,6 +54,7 @@ #include "nlohmann/json.hpp" #include +#include #include #include #include @@ -64,6 +65,36 @@ namespace psr { +namespace detail { +struct IDESolverPerf { + PAMM_CATEGORY(IDESolver); + + // NOLINTBEGIN + PAMM_COUNTER(Genfacts, Core); + PAMM_COUNTER(Killfacts, Core); + PAMM_COUNTER(Summaryreuse, Core); + PAMM_COUNTER(IntraPathEdges, Core); + PAMM_COUNTER(InterPathEdges, Core); + PAMM_COUNTER(FFQueries, Full); + PAMM_COUNTER(EFQueries, Full); + PAMM_COUNTER(ValuePropagation, Full); + PAMM_COUNTER(ValueComputation, Full); + PAMM_COUNTER(SpecialSummaryFF_Application, Full); + PAMM_COUNTER(SpecialSummaryEF_Queries, Full); + PAMM_COUNTER(JumpFnConstruction, Full); + PAMM_COUNTER(ProcessCall, Full); + PAMM_COUNTER(ProcessNormal, Full); + PAMM_COUNTER(ProcessExit, Full); + + PAMM_HISTOGRAM(DataFlowFacts, Full); + PAMM_HISTOGRAM(PointsTo, Full); + + PAMM_TIMER(DFAPhase1, Full); + PAMM_TIMER(DFAPhase2, Full); + // NOLINTEND +}; +} // namespace detail + /// Solves the given IDETabulationProblem as described in the 1996 paper by /// Sagiv, Horwitz and Reps. To solve the problem, call solve(). Results /// can then be queried by using resultAt() and resultsAt(). @@ -71,7 +102,8 @@ template , ICFG ICFGTy = typename AnalysisDomainTy::i_t> class IDESolver - : public IDESolverAPIMixin> { + : private detail::IDESolverPerf, + public IDESolverAPIMixin> { friend IDESolverAPIMixin>; public: @@ -382,8 +414,7 @@ class IDESolver /// @param edge an edge whose target node resembles a method call /// virtual void processCall(const PathEdge Edge) { - PAMM_GET_INSTANCE; - INC_COUNTER("Process Call", 1, Full); + ProcessCall++; PHASAR_LOG_LEVEL(DEBUG, "Process call at target: " << NToString(Edge.getTarget())); d_t d1 = Edge.factAtSource(); @@ -400,20 +431,20 @@ class IDESolver PHASAR_LOG_LEVEL(DEBUG, " " << Callee->getName()); } PHASAR_LOG_LEVEL(DEBUG, "Possible return sites:"); - for (auto ret : ReturnSiteNs) { - PHASAR_LOG_LEVEL(DEBUG, " " << NToString(ret)); + for (auto Ret : ReturnSiteNs) { + PHASAR_LOG_LEVEL(DEBUG, " " << NToString(Ret)); } }); bool HasNoCalleeInformation = true; auto &&Fun = ICF->getFunctionOf(n); - auto GetNextUse = [this, &Fun, &n](n_t nPrime, ByConstRef d3) { + auto GetNextUse = [this, &Fun, &n](n_t NPrime, ByConstRef d3) { if (auto &&NextUser = getNextUserOrNull(Fun, d3, n)) { return psr::unwrapNullable(PSR_FWD(NextUser)); } - return nPrime; + return NPrime; }; // for each possible callee @@ -430,13 +461,13 @@ class IDESolver PHASAR_LOG_LEVEL(DEBUG, "Found and process special summary"); for (n_t ReturnSiteN : ReturnSiteNs) { container_type Res = computeSummaryFlowFunction(SpecialSum, d1, d2); - INC_COUNTER("SpecialSummary-FF Application", 1, Full); - ADD_TO_HISTOGRAM("Data-flow facts", Res.size(), 1, Full); + SpecialSummaryFF_Application++; + DataFlowFacts.add(Res.size(), 1); saveEdges(n, ReturnSiteN, d2, Res, ESGEdgeKind::Summary); for (d_t d3 : Res) { auto SumEdgFnE = CachedFlowEdgeFunctions.getSummaryEdgeFunction( n, d2, ReturnSiteN, d3); - INC_COUNTER("SpecialSummary-EF Queries", 1, Full); + SpecialSummaryEF_Queries++; PHASAR_LOG_LEVEL(DEBUG, "Queried Summary Edge Function: " << SumEdgFnE); @@ -452,9 +483,9 @@ class IDESolver // compute the call-flow function auto Function = CachedFlowEdgeFunctions.getCallFlowFunction(n, SCalledProcN); - INC_COUNTER("FF Queries", 1, Full); + FFQueries++; container_type Res = computeCallFlowFunction(Function, d1, d2); - ADD_TO_HISTOGRAM("Data-flow facts", Res.size(), 1, Full); + DataFlowFacts.add(Res.size(), 1); // for each callee's start point(s) auto StartPointsOf = ICF->getStartPointsOf(SCalledProcN); if (StartPointsOf.empty()) { @@ -500,11 +531,10 @@ class IDESolver // compute return-flow function auto RetFunction = CachedFlowEdgeFunctions.getRetFlowFunction( n, SCalledProcN, eP, RetSiteN); - INC_COUNTER("FF Queries", 1, Full); + FFQueries++; const container_type ReturnedFacts = computeReturnFlowFunction( RetFunction, d3, d4, n, Container{d2}); - ADD_TO_HISTOGRAM("Data-flow facts", ReturnedFacts.size(), 1, - Full); + DataFlowFacts.add(ReturnedFacts.size(), 1); saveEdges(eP, RetSiteN, d4, ReturnedFacts, ESGEdgeKind::Ret); // for each target value of the function for (d_t d5 : ReturnedFacts) { @@ -527,7 +557,7 @@ class IDESolver d5)] .push_back(f5); } - INC_COUNTER("EF Queries", 2, Full); + EFQueries++; // compose call * calleeSummary * return edge functions PHASAR_LOG_LEVEL(DEBUG, "Compose: " << f5 << " * " << fCalleeSummary << " * " @@ -557,10 +587,10 @@ class IDESolver for (n_t ReturnSiteN : ReturnSiteNs) { auto CallToReturnFF = CachedFlowEdgeFunctions.getCallToRetFlowFunction( n, ReturnSiteN, Callees); - INC_COUNTER("FF Queries", 1, Full); + FFQueries++; container_type ReturnFacts = computeCallToReturnFlowFunction(CallToReturnFF, d1, d2); - ADD_TO_HISTOGRAM("Data-flow facts", ReturnFacts.size(), 1, Full); + DataFlowFacts.add(ReturnFacts.size(), 1); saveEdges(n, ReturnSiteN, d2, ReturnFacts, HasNoCalleeInformation ? ESGEdgeKind::SkipUnknownFn : ESGEdgeKind::CallToRet); @@ -573,7 +603,7 @@ class IDESolver IntermediateEdgeFunctions[std::make_tuple(n, d2, ReturnSiteN, d3)] .push_back(EdgeFnE); } - INC_COUNTER("EF Queries", 1, Full); + EFQueries++; auto fPrime = IDEProblem.extend(f, EdgeFnE); PHASAR_LOG_LEVEL(DEBUG, "Compose: " << EdgeFnE << " * " << f << " = " << fPrime); @@ -589,8 +619,7 @@ class IDESolver /// @param edge /// virtual void processNormalFlow(PathEdge Edge) { - PAMM_GET_INSTANCE; - INC_COUNTER("Process Normal", 1, Full); + ProcessNormal++; PHASAR_LOG_LEVEL( DEBUG, "Process normal at target: " << NToString(Edge.getTarget())); auto f = jumpFunction(Edge); @@ -600,13 +629,14 @@ class IDESolver for (const auto nPrime : ICF->getSuccsOf(n)) { auto FlowFunc = CachedFlowEdgeFunctions.getNormalFlowFunction(n, nPrime); - INC_COUNTER("FF Queries", 1, Full); + FFQueries++; const container_type Res = computeNormalFlowFunction(FlowFunc, d1, d2); - ADD_TO_HISTOGRAM("Data-flow facts", Res.size(), 1, Full); + DataFlowFacts.add(Res.size(), 1); saveEdges(n, nPrime, d2, Res, ESGEdgeKind::Normal); for (const d_t &d3 : Res) { auto g = CachedFlowEdgeFunctions.getNormalEdgeFunction(n, d2, nPrime, d3); + EFQueries++; PHASAR_LOG_LEVEL(DEBUG, "Queried Normal Edge Function: " << g); auto fPrime = IDEProblem.extend(f, g); @@ -624,7 +654,7 @@ class IDESolver } PHASAR_LOG_LEVEL(DEBUG, "Compose: " << g << " * " << f << " = " << fPrime); - INC_COUNTER("EF Queries", 1, Full); + WorkList.emplace_back(PathEdge(d1, DestN, std::move(d3)), std::move(fPrime)); } @@ -632,7 +662,6 @@ class IDESolver } void propagateValueAtStart(const std::pair NAndD, n_t Stmt) { - PAMM_GET_INSTANCE; d_t Fact = NAndD.second; f_t Func = ICF->getFunctionOf(Stmt); for (const n_t CallSite : ICF->getCallsFromWithin(Func)) { @@ -646,19 +675,18 @@ class IDESolver auto fPrime = Entry.second; n_t SP = Stmt; l_t Val = val(SP, Fact); - INC_COUNTER("Value Propagation", 1, Full); + ValuePropagation++; propagateValue(CallSite, dPrime, fPrime.computeTarget(Val)); } } } void propagateValueAtCall(const std::pair NAndD, n_t Stmt) { - PAMM_GET_INSTANCE; d_t Fact = NAndD.second; for (const f_t Callee : ICF->getCalleesOfCallAt(Stmt)) { auto CallFlowFunction = CachedFlowEdgeFunctions.getCallFlowFunction(Stmt, Callee); - INC_COUNTER("FF Queries", 1, Full); + FFQueries++; for (const d_t dPrime : CallFlowFunction->computeTargets(Fact)) { auto EdgeFn = CachedFlowEdgeFunctions.getCallEdgeFunction( Stmt, Fact, Callee, dPrime); @@ -669,9 +697,9 @@ class IDESolver .push_back(EdgeFn); } } - INC_COUNTER("EF Queries", 1, Full); + EFQueries++; for (const n_t StartPoint : ICF->getStartPointsOf(Callee)) { - INC_COUNTER("Value Propagation", 1, Full); + ValuePropagation++; propagateValue(StartPoint, dPrime, EdgeFn.computeTarget(val(Stmt, Fact))); } @@ -751,8 +779,7 @@ class IDESolver // should be made a callable at some point void pathEdgeProcessingTask(PathEdge Edge) { - PAMM_GET_INSTANCE; - INC_COUNTER("JumpFn Construction", 1, Full); + JumpFnConstruction++; IF_LOG_LEVEL_ENABLED(DEBUG, { PHASAR_LOG_LEVEL( DEBUG, @@ -802,7 +829,6 @@ class IDESolver // should be made a callable at some point void valueComputationTask(const std::vector &Values) { - PAMM_GET_INSTANCE; for (n_t n : Values) { for (n_t SP : ICF->getStartPointsOf(ICF->getFunctionOf(n))) { using TableCell = typename Table>::Cell; @@ -817,7 +843,7 @@ class IDESolver setVal(n, d, IDEProblem.join(val(n, d), fPrime.computeTarget(std::move(TargetVal)))); - INC_COUNTER("Value Computation", 1, Full); + ValueComputation++; } } } @@ -882,7 +908,6 @@ class IDESolver /// Clients should only call this methods if performing synchronization on /// their own. Normally, solve() should be called instead. void submitInitialSeeds() { - PAMM_GET_INSTANCE; // Check if the initial seeds contain the zero value at every starting // point. If not, the zero value needs to be added to allow for correct // solving of the problem. @@ -914,7 +939,7 @@ class IDESolver PHASAR_LOG_LEVEL(DEBUG, "\tFact: " << DToString(Fact)); PHASAR_LOG_LEVEL(DEBUG, "\tValue: " << LToString(Value)); if (!IDEProblem.isZeroValue(Fact)) { - INC_COUNTER("Gen facts", 1, Core); + Genfacts++; } WorkList.emplace_back(PathEdge(Fact, StartPoint, Fact), EdgeIdentity{}); @@ -931,8 +956,7 @@ class IDESolver /// @param edge an edge whose target node resembles a method exit /// virtual void processExit(const PathEdge Edge) { - PAMM_GET_INSTANCE; - INC_COUNTER("Process Exit", 1, Full); + ProcessExit++; PHASAR_LOG_LEVEL(DEBUG, "Process exit at target: " << NToString(Edge.getTarget())); n_t n = Edge.getTarget(); // an exit node; line 21... @@ -964,12 +988,12 @@ class IDESolver // compute return-flow function auto RetFunction = CachedFlowEdgeFunctions.getRetFlowFunction( c, FunctionThatNeedsSummary, n, RetSiteC); - INC_COUNTER("FF Queries", 1, Full); + FFQueries++; // for each incoming-call value for (d_t d4 : Entry.second) { const container_type Targets = computeReturnFlowFunction(RetFunction, d1, d2, c, Entry.second); - ADD_TO_HISTOGRAM("Data-flow facts", Targets.size(), 1, Full); + DataFlowFacts.add(Targets.size(), 1); saveEdges(n, RetSiteC, d2, Targets, ESGEdgeKind::Ret); // for each target value at the return site // line 23 @@ -991,7 +1015,7 @@ class IDESolver IntermediateEdgeFunctions[std::make_tuple(n, d2, RetSiteC, d5)] .push_back(f5); } - INC_COUNTER("EF Queries", 2, Full); + EFQueries += 2; // compose call function * function * return function PHASAR_LOG_LEVEL(DEBUG, "Compose: " << f5 << " * " << f << " * " << f4); @@ -1043,10 +1067,10 @@ class IDESolver for (n_t RetSiteC : ICF->getReturnSitesOfCallAt(Caller)) { auto RetFunction = CachedFlowEdgeFunctions.getRetFlowFunction( Caller, FunctionThatNeedsSummary, n, RetSiteC); - INC_COUNTER("FF Queries", 1, Full); + FFQueries++; const container_type Targets = computeReturnFlowFunction( RetFunction, d1, d2, Caller, Container{ZeroValue}); - ADD_TO_HISTOGRAM("Data-flow facts", Targets.size(), 1, Full); + DataFlowFacts.add(Targets.size(), 1); saveEdges(n, RetSiteC, d2, Targets, ESGEdgeKind::Ret); for (d_t d5 : Targets) { auto f5 = CachedFlowEdgeFunctions.getReturnEdgeFunction( @@ -1056,7 +1080,7 @@ class IDESolver IntermediateEdgeFunctions[std::make_tuple(n, d2, RetSiteC, d5)] .push_back(f5); } - INC_COUNTER("EF Queries", 1, Full); + EFQueries++; PHASAR_LOG_LEVEL(DEBUG, "Compose: " << f5 << " * " << f); propagteUnbalancedReturnFlow(RetSiteC, d5, IDEProblem.extend(f, f5), Caller); @@ -1379,13 +1403,12 @@ class IDESolver /// generated/killed facts, number of summary-reuses etc. /// void computeAndPrintStatistics() { - PAMM_GET_INSTANCE; // Stores all valid facts at return site in caller context; return-site is // key std::unordered_map> ValidInCallerContext; - size_t NumGenFacts = 0; - size_t NumIntraPathEdges = 0; - size_t NumInterPathEdges = 0; + ptrdiff_t NumGenFacts = 0; + ptrdiff_t NumIntraPathEdges = 0; + ptrdiff_t NumInterPathEdges = 0; // --- Intra-procedural Path Edges --- // d1 --> d2-Set // Case 1: d1 in d2-Set @@ -1409,7 +1432,7 @@ class IDESolver if (ICF->isCallSite(Edge.first)) { ValidInCallerContext[Edge.second].insert(D2s.begin(), D2s.end()); } - IF_LOG_LEVEL_ENABLED(DEBUG, [this](const auto &D2s) { + IF_LOG_LEVEL_ENABLED(DEBUG, [](const auto &D2s) { for (auto D2 : D2s) { PHASAR_LOG_LEVEL(DEBUG, "d2: " << DToString(D2)); } @@ -1454,8 +1477,9 @@ class IDESolver std::set SummaryDSet; EndsummaryTab.get(Edge.second, D2) - .foreachCell([&SummaryDSet](const auto &Row, const auto &Col, - const auto &Val) { + .foreachCell([&SummaryDSet](const auto & /*Row*/, + const auto &Col, + const auto & /*Val*/) { SummaryDSet.insert(Col); }); @@ -1498,46 +1522,40 @@ class IDESolver PHASAR_LOG_LEVEL(DEBUG, " "); } PHASAR_LOG_LEVEL(DEBUG, "SUMMARY REUSE"); - std::size_t TotalSummaryReuse = 0; + ptrdiff_t TotalSummaryReuse = 0; for (const auto &Entry : FSummaryReuse) { PHASAR_LOG_LEVEL(DEBUG, "N1: " << NToString(Entry.first.first)); PHASAR_LOG_LEVEL(DEBUG, "D1: " << DToString(Entry.first.second)); PHASAR_LOG_LEVEL(DEBUG, "#Reuse: " << Entry.second); TotalSummaryReuse += Entry.second; } - INC_COUNTER("Gen facts", NumGenFacts, Core); - INC_COUNTER("Summary-reuse", TotalSummaryReuse, Core); - INC_COUNTER("Intra Path Edges", NumIntraPathEdges, Core); - INC_COUNTER("Inter Path Edges", NumInterPathEdges, Core); + Genfacts += NumGenFacts; + Summaryreuse += TotalSummaryReuse; + IntraPathEdges += NumIntraPathEdges; + InterPathEdges += NumInterPathEdges; PHASAR_LOG_LEVEL(INFO, "----------------------------------------------"); PHASAR_LOG_LEVEL(INFO, "=== Solver Statistics ==="); - PHASAR_LOG_LEVEL(INFO, "#Facts generated : " << GET_COUNTER("Gen facts")); - PHASAR_LOG_LEVEL(INFO, "#Facts killed : " << GET_COUNTER("Kill facts")); - PHASAR_LOG_LEVEL(INFO, - "#Summary-reuse : " << GET_COUNTER("Summary-reuse")); - PHASAR_LOG_LEVEL(INFO, - "#Intra Path Edges: " << GET_COUNTER("Intra Path Edges")); - PHASAR_LOG_LEVEL(INFO, - "#Inter Path Edges: " << GET_COUNTER("Inter Path Edges")); + PHASAR_LOG_LEVEL(INFO, "#Facts generated : " << Genfacts.value()); + PHASAR_LOG_LEVEL(INFO, "#Facts killed : " << Killfacts.value()); + PHASAR_LOG_LEVEL(INFO, "#Summary-reuse : " << Summaryreuse.value()); + PHASAR_LOG_LEVEL(INFO, "#Intra Path Edges: " << IntraPathEdges.value()); + PHASAR_LOG_LEVEL(INFO, "#Inter Path Edges: " << InterPathEdges.value()); if constexpr (PAMM_CURR_SEV_LEVEL >= PAMM_SEVERITY_LEVEL::Full) { - PHASAR_LOG_LEVEL( - INFO, "Flow function query count: " << GET_COUNTER("FF Queries")); - PHASAR_LOG_LEVEL( - INFO, "Edge function query count: " << GET_COUNTER("EF Queries")); + PHASAR_LOG_LEVEL(INFO, + "Flow function query count: " << FFQueries.value()); + PHASAR_LOG_LEVEL(INFO, + "Edge function query count: " << EFQueries.value()); PHASAR_LOG_LEVEL(INFO, "Data-flow value propagation count: " - << GET_COUNTER("Value Propagation")); + << ValuePropagation.value()); PHASAR_LOG_LEVEL(INFO, "Data-flow value computation count: " - << GET_COUNTER("Value Computation")); - PHASAR_LOG_LEVEL(INFO, - "Special flow function usage count: " - << GET_COUNTER("SpecialSummary-FF Application")); + << ValueComputation.value()); + PHASAR_LOG_LEVEL(INFO, "Special flow function usage count: " + << SpecialSummaryFF_Application.value()); PHASAR_LOG_LEVEL(INFO, "Jump function construciton count: " - << GET_COUNTER("JumpFn Construction")); - PHASAR_LOG_LEVEL(INFO, - "Phase I duration: " << PRINT_TIMER("DFA Phase I")); - PHASAR_LOG_LEVEL(INFO, - "Phase II duration: " << PRINT_TIMER("DFA Phase II")); + << JumpFnConstruction.value()); + PHASAR_LOG_LEVEL(INFO, "Phase I duration: " << DFAPhase1.elapsed()); + PHASAR_LOG_LEVEL(INFO, "Phase II duration: " << DFAPhase2.elapsed()); PHASAR_LOG_LEVEL(INFO, "----------------------------------------------"); CachedFlowEdgeFunctions.print(); } @@ -1775,31 +1793,11 @@ class IDESolver /// -- InteractiveIDESolverMixin implementation void doInitialize() { - PAMM_GET_INSTANCE; - REG_COUNTER("Gen facts", 0, Core); - REG_COUNTER("Kill facts", 0, Core); - REG_COUNTER("Summary-reuse", 0, Core); - REG_COUNTER("Intra Path Edges", 0, Core); - REG_COUNTER("Inter Path Edges", 0, Core); - REG_COUNTER("FF Queries", 0, Full); - REG_COUNTER("EF Queries", 0, Full); - REG_COUNTER("Value Propagation", 0, Full); - REG_COUNTER("Value Computation", 0, Full); - REG_COUNTER("SpecialSummary-FF Application", 0, Full); - REG_COUNTER("SpecialSummary-EF Queries", 0, Full); - REG_COUNTER("JumpFn Construction", 0, Full); - REG_COUNTER("Process Call", 0, Full); - REG_COUNTER("Process Normal", 0, Full); - REG_COUNTER("Process Exit", 0, Full); - REG_COUNTER("[Calls] getAliasSet", 0, Full); - REG_HISTOGRAM("Data-flow facts", Full); - REG_HISTOGRAM("Points-to", Full); - PHASAR_LOG_LEVEL(INFO, "IDE solver is solving the specified problem"); PHASAR_LOG_LEVEL(INFO, "Submit initial seeds, construct exploded super graph"); // computations starting here - START_TIMER("DFA Phase I", Full); + DFAPhase1.start(); // We start our analysis and construct exploded supergraph submitInitialSeeds(); @@ -1821,17 +1819,15 @@ class IDESolver } void finalizeInternal() { - PAMM_GET_INSTANCE; - STOP_TIMER("DFA Phase I", Full); + DFAPhase1.stop(); PHASAR_LOG_LEVEL(INFO, "[info]: IDE Phase I completed"); if (SolverConfig.computeValues()) { - START_TIMER("DFA Phase II", Full); + PAMM_SCOPED_TIMER(DFAPhase2); // Computing the final values for the edge functions PHASAR_LOG_LEVEL( INFO, "Compute the final values according to the edge functions"); computeValues(); - STOP_TIMER("DFA Phase II", Full); } PHASAR_LOG_LEVEL(INFO, "Problem solved"); diff --git a/include/phasar/DataFlow/IfdsIde/SolverResults.h b/include/phasar/DataFlow/IfdsIde/SolverResults.h index 12cc2a9e6a..52bc985daa 100644 --- a/include/phasar/DataFlow/IfdsIde/SolverResults.h +++ b/include/phasar/DataFlow/IfdsIde/SolverResults.h @@ -40,8 +40,15 @@ namespace psr { std::string getMetaDataID(const llvm::Value *V); namespace detail { + +struct SolverResultsRoot { + PAMM_CATEGORY(SolverResults); + PAMM_TIMER(ResultsDumping, Full); +}; + template -class SolverResultsBase { +class SolverResultsBase : private SolverResultsRoot { + public: using n_t = N; using d_t = D; @@ -160,8 +167,8 @@ class SolverResultsBase { llvm::raw_ostream &OS = llvm::outs()) const { using f_t = typename ICFGTy::f_t; - PAMM_GET_INSTANCE; - START_TIMER("DFA IDE Result Dumping", Full); + PAMM_SCOPED_TIMER(ResultsDumping); + OS << "\n***************************************************************\n" << "* Raw IDESolver results *\n" << "***************************************************************\n"; @@ -202,7 +209,6 @@ class SolverResultsBase { } } OS << '\n'; - STOP_TIMER("DFA IDE Result Dumping", Full); } template diff --git a/include/phasar/PhasarLLVM/DataFlow/IfdsIde/CFLFieldSensIFDSProblem.h b/include/phasar/PhasarLLVM/DataFlow/IfdsIde/CFLFieldSensIFDSProblem.h index 9ed5419ced..2a9d80a076 100644 --- a/include/phasar/PhasarLLVM/DataFlow/IfdsIde/CFLFieldSensIFDSProblem.h +++ b/include/phasar/PhasarLLVM/DataFlow/IfdsIde/CFLFieldSensIFDSProblem.h @@ -517,7 +517,6 @@ class CFLFieldSensIFDSProblem UserProblem->getZeroValue()), UserProblem(UserProblem), Config(std::move(Config)) { Mgr.reserve(UserProblem->getProjectIRDB()->getNumInstructions()); - regCounters(); } /// Constructs an IDETabulationProblem with the usual arguments, forwarded @@ -620,8 +619,6 @@ class CFLFieldSensIFDSProblem [[nodiscard]] EFResultPtr makeEFPtr(cfl_fieldsens::CFLFieldSensEdgeFunctionImpl &&EF); - static void regCounters() noexcept; - IFDSTabulationProblem *UserProblem{}; cfl_fieldsens::FieldStringManager Mgr{}; cfl_fieldsens::IFDSProblemConfig Config{}; diff --git a/include/phasar/Utils/Macros.h b/include/phasar/Utils/Macros.h index 74d3c6690f..519d3e7a21 100644 --- a/include/phasar/Utils/Macros.h +++ b/include/phasar/Utils/Macros.h @@ -10,6 +10,9 @@ #ifndef PHASAR_UTILS_MACROS_H #define PHASAR_UTILS_MACROS_H +#define PSR_CONCAT_IMPL(X, Y) X##Y +#define PSR_CONCAT(X, Y) PSR_CONCAT_IMPL(X, Y) + #define PSR_FWD(...) ::std::forward(__VA_ARGS__) #define PSR_CONCEPT concept diff --git a/include/phasar/Utils/PAMM.h b/include/phasar/Utils/PAMM.h index 00f4bb3c78..1e89f865cc 100644 --- a/include/phasar/Utils/PAMM.h +++ b/include/phasar/Utils/PAMM.h @@ -1,39 +1,803 @@ +#pragma once + /****************************************************************************** * Copyright (c) 2017 Philipp Schubert. * All rights reserved. This program and the accompanying materials are made * available under the terms of LICENSE.txt. * * Contributors: - * Philipp Schubert and others + * Philipp Schubert, Fabian Schiebel, and others *****************************************************************************/ -/* - * PAMM.h - * - * Created on: 06.12.2017 - * Author: rleer - */ - -#ifndef PHASAR_UTILS_PAMM_H_ -#define PHASAR_UTILS_PAMM_H_ +#include "phasar/Config/phasar-config.h" +#include "phasar/Utils/ChronoUtils.h" +#include "phasar/Utils/NonNullPtr.h" +#include "phasar/Utils/TemplateString.h" +#include "phasar/Utils/TypeTraits.h" +#include "phasar/Utils/Utilities.h" -#include "llvm/ADT/ArrayRef.h" +#include "llvm/ADT/DenseMap.h" #include "llvm/ADT/StringMap.h" #include "llvm/ADT/StringRef.h" +#include "llvm/ADT/Twine.h" +#include "llvm/Support/Compiler.h" +#include "llvm/Support/ErrorHandling.h" +#include "llvm/Support/Format.h" +#include "llvm/Support/WithColor.h" #include // high_resolution_clock::time_point, milliseconds -#include +#include +#include +#include #include -#include // set +#include #include // string -#include // vector +#include +#include + +#ifdef PHASAR_THREAD_SAFE_PAMM +#include +#include +#else +#include "phasar/Utils/Average.h" +#endif namespace llvm { class raw_ostream; } // namespace llvm +/// \file +/// PhASAR's performance measurement mechanism (PAMM). +/// Provides counters, histograms, and timers for fine-grained performance +/// tracking. Use the macros from PAMMMacros.h to declare static instances +/// of these metrics. On construction, they are automatically registered in the +/// static pamm::Registry, so that report-generation can be automated. +/// The macros expect a valid C++ identifier as name, and a severify-level +/// (Core/Full) under which the metric should be active. +/// +/// Metrics are categorizable via a pamm::Category. The +/// performance report groups by category; categories can be enabled/disabled at +/// runtime. By convention, the macros register the metrics under the category +/// 'PAMMCategory'; create a new category with PAMM_CATEGORY(name). +/// +/// Currently, PAMM can be run with all metrics (severity level 2 = Full) or +/// only core metrics (severity level 1 = Core) enabled. The severity level can +/// be changed when building PhASAR. The CMake option is +/// -DPHASAR_ENABLE_PAMM=[Off/Core/Full]. +/// +/// Thread-safety: +/// If PhASAR is configured with the cmake-option -DPHASAR_THREAD_SAFE_PAMM=ON, +/// PAMM provides some thread-safety guarentees. Generally, construction and +/// destruction of metrics is NOT thread-safe. The pamm::Registry is therefore +/// also NOT thread-safe. Adding data, i.e, incrementing counters, adding to +/// histograms, starting/stopping timers is protected by suitable +/// synchronization primitives and can therefore be safely performed +/// concurrently. + namespace psr { +/// Defines the different level of severity of PAMM's performance evaluation +enum class PAMM_SEVERITY_LEVEL { Off = 0, Core, Full }; // NOLINT + +// NOLINTNEXTLINE +inline constexpr PAMM_SEVERITY_LEVEL PAMM_CURR_SEV_LEVEL = +#if defined(PAMM_FULL) + PAMM_SEVERITY_LEVEL::Full; +#elif defined(PAMM_CORE) + PAMM_SEVERITY_LEVEL::Core; +#else + PAMM_SEVERITY_LEVEL::Off; +#endif + +namespace pamm { + +class Registry; + +template +class Category { +public: + explicit constexpr Category(llvm::StringLiteral Name, + bool IsEnabled = true) noexcept + : Name(Name), IsEnabled(IsEnabled) {} + + constexpr operator llvm::StringRef() const noexcept { return Name; } + + [[nodiscard]] constexpr llvm::StringRef name() const noexcept { return Name; } + + [[nodiscard]] constexpr bool isEnabled() const noexcept { + return IsEnabled +#ifdef PHASAR_THREAD_SAFE_PAMM + .load(std::memory_order_relaxed) +#endif + ; + } + + constexpr void disable() noexcept { IsEnabled = false; } + constexpr void enable() noexcept { IsEnabled = true; } + +private: + llvm::StringRef Name; +#ifdef PHASAR_THREAD_SAFE_PAMM + std::atomic_bool +#else + bool +#endif + IsEnabled = true; +}; + +template <> class Category { +public: + explicit constexpr Category(llvm::StringLiteral Name, + bool /*IsEnabled*/ = true) noexcept + : Name(Name) {} + + constexpr operator llvm::StringRef() const noexcept { return Name; } + + [[nodiscard]] constexpr llvm::StringRef name() const noexcept { return Name; } + + [[nodiscard]] constexpr auto isEnabled() const noexcept { + return std::false_type{}; + } + + constexpr void disable() noexcept {} + + void enable() noexcept { + llvm::WithColor::warning() + << "Cannot enable PAMM category '" << Name + << "', because PAMM is disabled at compile time\n"; + } + +private: + llvm::StringRef Name; +}; + +template +concept IsCategory = + std::same_as> || std::same_as>; + +template +concept IsCategoryVar = + IsCategory>>; + +namespace detail { +struct PAMMBase { + std::source_location Loc{}; +}; +#ifdef PHASAR_THREAD_SAFE_PAMM +struct CounterBase : PAMMBase { + std::atomic_ptrdiff_t Ctr{}; + + constexpr void add(ptrdiff_t Offset) noexcept { + Ctr.fetch_add(Offset, std::memory_order_relaxed); + } + + [[nodiscard]] constexpr ptrdiff_t value() const noexcept { + return Ctr.load(std::memory_order_relaxed); + } +}; + +struct MinMaxCounterBase : PAMMBase { + std::atomic_size_t Min = SIZE_MAX; + std::atomic_size_t Max = 0; + std::atomic_size_t Sum{}; + std::atomic_size_t NumSamples{}; + + constexpr void add(size_t Offset) noexcept { + Sum.fetch_add(Offset, std::memory_order_relaxed); + NumSamples.fetch_add(1, std::memory_order_relaxed); + + { + auto PrevMin = Min.load(std::memory_order_relaxed); + while (PrevMin > Offset && + Min.compare_exchange_weak(PrevMin, Offset, + std::memory_order_relaxed)) { + } + } + { + auto PrevMax = Max.load(std::memory_order_relaxed); + while (PrevMax < Offset && + Max.compare_exchange_weak(PrevMax, Offset, + std::memory_order_relaxed)) { + } + } + }; + + [[nodiscard]] double getAverage() const noexcept { + return double(Sum.load(std::memory_order_relaxed)) / + double(getNumSamples()); + } + [[nodiscard]] size_t getNumSamples() const noexcept { + return NumSamples.load(std::memory_order_relaxed); + } + + void clear() noexcept { + Min = SIZE_MAX; + Max = 0; + Sum = 0; + NumSamples = 0; + } +}; + +struct TimerBase : PAMMBase { + + static constexpr std::chrono::steady_clock::time_point None = + std::chrono::steady_clock::time_point::max(); + + std::atomic StartPoint = None; + // no atomic arithmetic with nanoseconds, so use int64_t here: + std::atomic Acc{}; + + [[nodiscard]] constexpr bool isStarted() const noexcept { + // XXX: Revisit the memory-order here: Can it be relaxed? + return StartPoint.load(std::memory_order_acquire) != None; + } + + void start() noexcept { + assert(!isStarted() && "Starting an already running timer is not allowed"); + StartPoint.store(std::chrono::steady_clock::now(), + std::memory_order_release); + } + + void stop() noexcept { + auto EndPoint = std::chrono::steady_clock::now(); + auto StartPoint = + this->StartPoint.exchange(None, std::memory_order_acq_rel); + assert(StartPoint != None && "Stopping a not-running timer is not allowed"); + Acc.fetch_add((EndPoint - StartPoint).count(), std::memory_order_relaxed); + } + + void reset() noexcept { + Acc = 0; + StartPoint = None; + } + + [[nodiscard]] constexpr auto elapsedNanos() const noexcept { + return std::chrono::nanoseconds(Acc.load(std::memory_order_relaxed)); + } + + [[nodiscard]] constexpr std::chrono::nanoseconds + pendingNanos() const noexcept { + auto StartPoint = this->StartPoint.load(std::memory_order_relaxed); + if (StartPoint == None) { + return {}; + } + auto EndPoint = std::chrono::steady_clock::now(); + return EndPoint - StartPoint; + } + + [[nodiscard]] hms elapsed() const noexcept { return elapsedNanos(); } +}; + +#else +struct CounterBase : PAMMBase { + ptrdiff_t Ctr{}; + + constexpr void add(ptrdiff_t Offset) noexcept { Ctr += Offset; } + + [[nodiscard]] constexpr ptrdiff_t value() const noexcept { return Ctr; } +}; + +struct MinMaxCounterBase : PAMMBase { + size_t Min = SIZE_MAX; + size_t Max = 0; + Sampler Avg{}; + + constexpr void add(size_t Offset) noexcept { + Avg.addSample(Offset); + if (Offset > Max) { + Max = Offset; + } + if (Offset < Min) { + Min = Offset; + } + }; + + [[nodiscard]] double getAverage() const noexcept { return Avg.getAverage(); } + [[nodiscard]] size_t getNumSamples() const noexcept { + return Avg.getNumSamples(); + } + + void clear() noexcept { + Min = SIZE_MAX; + Max = 0; + Avg = {}; + } +}; + +struct TimerBase : PAMMBase { + + static constexpr std::chrono::steady_clock::time_point None = + std::chrono::steady_clock::time_point::max(); + + std::chrono::steady_clock::time_point StartPoint = None; + std::chrono::nanoseconds Acc{}; + + [[nodiscard]] constexpr bool isStarted() const noexcept { + return StartPoint != None; + } + + void start() noexcept { + assert(!isStarted() && "Starting an already running timer is not allowed"); + StartPoint = std::chrono::steady_clock::now(); + } + + void stop() noexcept { + assert(isStarted() && "Stopping a not-running timer is not allowed"); + auto EndPoint = std::chrono::steady_clock::now(); + Acc += (EndPoint - StartPoint); + StartPoint = None; + } + + void reset() noexcept { + Acc = {}; + StartPoint = None; + } + + [[nodiscard]] constexpr std::chrono::nanoseconds + elapsedNanos() const noexcept { + return Acc; + } + + [[nodiscard]] constexpr std::chrono::nanoseconds + pendingNanos() const noexcept { + if (!isStarted()) { + return {}; + } + auto EndPoint = std::chrono::steady_clock::now(); + return EndPoint - StartPoint; + } + + [[nodiscard]] hms elapsed() const noexcept { return Acc; } +}; + +#endif + +struct HistogramBase : PAMMBase { + llvm::StringMap HistData{}; +#ifdef PHASAR_THREAD_SAFE_PAMM + std::mutex Mx{}; +#endif +}; + +template struct Qualified { + [[nodiscard]] constexpr std::string qualifier() const { + auto Ret = std::string(Cat->name()); + Ret += "::"; + Ret += llvm::StringRef(Name); + return Ret; + } +}; +} // namespace detail + +class Registry; + +template + requires IsCategoryVar +class Counter : private detail::CounterBase, + private detail::Qualified { + friend Registry; + +public: + using detail::Qualified::qualifier; + + inline explicit Counter( + std::source_location Loc = std::source_location::current()) noexcept; + + using detail::CounterBase::add; + using detail::CounterBase::value; + + constexpr void operator++() noexcept { add(1); } + constexpr void operator++(int) noexcept { add(1); } + constexpr void operator+=(ptrdiff_t Offset) noexcept { add(Offset); } + constexpr void operator-=(ptrdiff_t Offset) noexcept { add(-Offset); } + + friend llvm::raw_ostream &operator<<(llvm::raw_ostream &OS, + const Counter &C) { + return OS << Cat->name() << "::" << Name << ": " << C.Ctr; + } + +private: + [[nodiscard]] constexpr detail::CounterBase *base() noexcept { return this; } +}; + +template + requires IsCategoryVar +class Counter : private detail::Qualified { +public: + using detail::Qualified::qualifier; + + LLVM_ATTRIBUTE_ALWAYS_INLINE constexpr void add(ptrdiff_t Offset) noexcept {} + LLVM_ATTRIBUTE_ALWAYS_INLINE constexpr void operator++() noexcept {} + LLVM_ATTRIBUTE_ALWAYS_INLINE constexpr void operator++(int) noexcept {} + LLVM_ATTRIBUTE_ALWAYS_INLINE constexpr void + operator+=(ptrdiff_t Offset) noexcept {} + LLVM_ATTRIBUTE_ALWAYS_INLINE constexpr void + operator-=(ptrdiff_t Offset) noexcept {} + + friend llvm::raw_ostream &operator<<(llvm::raw_ostream &OS, Counter /*C*/) { + return OS << Cat->name() << "::" << Name; + } + + [[nodiscard]] constexpr std::nullopt_t value() const noexcept { + return std::nullopt; + } +}; + +namespace detail { +struct IsCounterImpl { + template + requires IsCategoryVar + static std::true_type test(const Counter &); + + static std::false_type test(...); +}; + +template +concept IsCounter = + decltype(IsCounterImpl::test(std::declval()))::value; +} // namespace detail + +template + requires IsCategoryVar +class MinMaxCounter : private detail::MinMaxCounterBase, + private detail::Qualified { + friend Registry; + +public: + using detail::Qualified::qualifier; + + inline explicit MinMaxCounter( + std::source_location Loc = std::source_location::current()) noexcept; + + using detail::MinMaxCounterBase::add; + + constexpr void operator++() noexcept { add(1); } + constexpr void operator++(int) noexcept { add(1); } + constexpr void operator+=(size_t Offset) noexcept { add(Offset); } + + friend llvm::raw_ostream &operator<<(llvm::raw_ostream &OS, + const MinMaxCounter &C) { + return OS << Cat->name() << "::" << Name << ": min(" << C.Min << "), max(" + << C.Max << "), avg: " << llvm::format("%g", C.getAverage()) + << ", #samples(" << C.getNumSamples() << ')'; + } + +private: + [[nodiscard]] constexpr detail::CounterBase *base() noexcept { return this; } +}; + +template + requires IsCategoryVar +class MinMaxCounter : private detail::Qualified { +public: + using detail::Qualified::qualifier; + + LLVM_ATTRIBUTE_ALWAYS_INLINE constexpr void add(size_t Offset) noexcept {} + + LLVM_ATTRIBUTE_ALWAYS_INLINE constexpr void operator++() noexcept {} + LLVM_ATTRIBUTE_ALWAYS_INLINE constexpr void operator++(int) noexcept {} + LLVM_ATTRIBUTE_ALWAYS_INLINE constexpr void + operator+=(size_t Offset) noexcept {} + + friend llvm::raw_ostream &operator<<(llvm::raw_ostream &OS, + MinMaxCounter /*C*/) { + return OS << Cat->name() << "::" << Name; + } +}; + +template + requires IsCategoryVar +class Histogram : private detail::HistogramBase, + private detail::Qualified { + friend Registry; + +public: + using detail::Qualified::qualifier; + + inline explicit Histogram( + std::source_location Loc = std::source_location::current()) noexcept; + + friend llvm::raw_ostream &operator<<(llvm::raw_ostream &OS, + const Histogram &H) { + OS << Cat->name() << "::" << Name << ":\n"; + OS << "Value\t| #Occurrences\n"; +#ifdef PHASAR_THREAD_SAFE_PAMM + std::lock_guard Lck(H.Mx); +#endif + for (const auto &[Dat, Val] : H.HistData) { + OS << Dat << "\t| " << Val << '\n'; + } + return OS; + } + + void add(llvm::StringRef DataPointId, uint64_t Increment) { + if (Cat->isEnabled()) { +#ifdef PHASAR_THREAD_SAFE_PAMM + std::lock_guard Lck(Mx); +#endif + this->HistData[DataPointId] += Increment; + } + } + template + requires(!std::convertible_to) + void add(T &&DataPointId, uint64_t Increment) { + add(psr::adl_to_string(PSR_FWD(DataPointId)), Increment); + } + + // For unit-tests + [[nodiscard]] const auto &internalRawData() const noexcept { + return HistData; + } + +private: + [[nodiscard]] constexpr detail::HistogramBase *base() noexcept { + return this; + } +}; + +template + requires IsCategoryVar +class Histogram : private detail::Qualified { + friend Registry; + +public: + using detail::Qualified::qualifier; + + friend llvm::raw_ostream &operator<<(llvm::raw_ostream &OS, Histogram /*H*/) { + return OS << Cat->name() << "::" << Name << "\n"; + } + + LLVM_ATTRIBUTE_ALWAYS_INLINE constexpr void + add(llvm::StringRef /*DataPointId*/, uint64_t /*Increment*/) {} + + template + requires(!std::convertible_to) + LLVM_ATTRIBUTE_ALWAYS_INLINE constexpr void add(T && /*DataPointId*/, + uint64_t /*Increment*/) {} +}; + +template + requires IsCategoryVar +class Timer : private detail::TimerBase, private detail::Qualified { + friend Registry; + template friend class ScopedTimer; + +public: + using detail::Qualified::qualifier; + + inline explicit Timer( + std::source_location Loc = std::source_location::current()) noexcept; + + using detail::TimerBase::elapsed; + using detail::TimerBase::elapsedNanos; + using detail::TimerBase::reset; + using detail::TimerBase::start; + using detail::TimerBase::stop; + + friend llvm::raw_ostream &operator<<(llvm::raw_ostream &OS, const Timer &T) { + return OS << Cat->name() << "::" << Name << ": " << T.elapsed(); + } + +private: + [[nodiscard]] constexpr detail::TimerBase *base() noexcept { return this; } +}; + +template + requires IsCategoryVar +class Timer : private detail::Qualified { +public: + using detail::Qualified::qualifier; + + LLVM_ATTRIBUTE_ALWAYS_INLINE void start() noexcept {} + LLVM_ATTRIBUTE_ALWAYS_INLINE void stop() noexcept {} + + [[nodiscard]] constexpr std::chrono::nanoseconds + elapsedNanos() const noexcept { + return {}; + } + + [[nodiscard]] hms elapsed() const noexcept { return {}; } + + friend llvm::raw_ostream &operator<<(llvm::raw_ostream &OS, Timer /*T*/) { + return OS << Cat->name() << "::" << Name; + } +}; + +template class ScopedTimer { +public: + template + constexpr ScopedTimer(Timer &Tm) : Tm(&Tm) { + if (Cat->isEnabled()) { + Tm.start(); + } + } + + ~ScopedTimer() { + if (Tm->isStarted()) { + Tm->stop(); + } + } + + ScopedTimer(const ScopedTimer &) = delete; + ScopedTimer &operator=(const ScopedTimer &) = delete; + ScopedTimer(ScopedTimer &&) = delete; + ScopedTimer &operator=(ScopedTimer &&) = delete; + +private: + NonNullPtr Tm; +}; + +template <> class ScopedTimer { +public: + template + constexpr ScopedTimer(Timer &Tm) {} +}; + +class Registry { + template + requires IsCategoryVar + friend class Counter; + template + requires IsCategoryVar + friend class MinMaxCounter; + template + requires IsCategoryVar + friend class Histogram; + template + requires IsCategoryVar + friend class Timer; + +public: + static Registry &instance() { + static Registry Reg; + return Reg; + } + + void printCounters(llvm::raw_ostream &OS) const; + void printCounters(llvm::raw_ostream &OS, const Category &Cat) const; + void printCounters(llvm::raw_ostream &OS, const Category &Cat) const {} + + void printMinMaxCounters(llvm::raw_ostream &OS) const; + void printMinMaxCounters(llvm::raw_ostream &OS, + const Category &Cat) const; + void printMinMaxCounters(llvm::raw_ostream &OS, + const Category &Cat) const {} + + void printHistograms(llvm::raw_ostream &OS) const; + void printHistograms(llvm::raw_ostream &OS, const Category &Cat) const; + void printHistograms(llvm::raw_ostream &OS, + const Category &Cat) const {} + + void printTimers(llvm::raw_ostream &OS) const; + void printTimers(llvm::raw_ostream &OS, const Category &Cat) const; + void printTimers(llvm::raw_ostream &OS, const Category &Cat) const {} + + [[nodiscard]] const Category *findCategory(llvm::StringRef Name) const; + + // Sets all counters, histograms and timers back to 0. Useful for unit-tests + void reset() noexcept; + + // Erases all registered PAMM-elements. Useful for unit-tests + void clear() noexcept; + +private: + void registerImpl(auto *Elem, auto &Into, const Category *Cat, + llvm::StringRef Name, llvm::StringRef ElemKind, + std::source_location Loc) { + assert(Elem != nullptr); + assert(Cat != nullptr); + + RegisteredCategories.try_emplace(Cat->name(), Cat); + + auto [It, Inserted] = + Into[Cat].try_emplace(llvm::StringRef(Name), Elem->base()); + if (!Inserted) [[unlikely]] { + llvm::report_fatal_error( + "At " + llvm::Twine(locToString(Loc)) + ": " + ElemKind + " " + + llvm::Twine(Elem->qualifier()) + + " already registered! Previous definition was here: " + + llvm::Twine(locToString(It->second->Loc))); + } + } + + template *Cat> + void registerCounter( + Counter *Ctr, + std::source_location Loc = std::source_location::current()) noexcept { + registerImpl(Ctr, Counters, Cat, Name, "Counter", Loc); + } + + template *Cat> + void registerMMCounter( + MinMaxCounter *Ctr, + std::source_location Loc = std::source_location::current()) noexcept { + registerImpl(Ctr, MMCounters, Cat, Name, "MinMaxCounter", Loc); + } + + template *Cat> + void registerHistogram( + Histogram *Hist, + std::source_location Loc = std::source_location::current()) noexcept { + registerImpl(Hist, Histograms, Cat, Name, "Histogram", Loc); + } + + template *Cat> + void registerTimer( + Timer *Tm, + std::source_location Loc = std::source_location::current()) noexcept { + registerImpl(Tm, Timers, Cat, Name, "Timer", Loc); + } + + llvm::DenseMap *, + llvm::DenseMap> + Counters; + + llvm::DenseMap *, + llvm::DenseMap> + MMCounters; + + llvm::DenseMap *, + llvm::DenseMap> + Histograms; + + llvm::DenseMap *, + llvm::DenseMap> + Timers; + + llvm::StringMap *> RegisteredCategories; +}; + +template + requires IsCategoryVar +inline Counter::Counter(std::source_location Loc) noexcept { + static_assert(Cat != nullptr); + this->Loc = Loc; + Registry::instance().registerCounter(this, Loc); +} + +template + requires IsCategoryVar +inline MinMaxCounter::MinMaxCounter( + std::source_location Loc) noexcept { + static_assert(Cat != nullptr); + this->Loc = Loc; + Registry::instance().registerMMCounter(this, Loc); +} + +template + requires IsCategoryVar +inline Histogram::Histogram( + std::source_location Loc) noexcept { + static_assert(Cat != nullptr); + this->Loc = Loc; + Registry::instance().registerHistogram(this, Loc); +} + +template + requires IsCategoryVar +inline Timer::Timer(std::source_location Loc) noexcept { + static_assert(Cat != nullptr); + this->Loc = Loc; + Registry::instance().registerTimer(this, Loc); +} + +/// \brief Prints the measured data from all registered categories into the +/// given output stream +void printMeasuredData(llvm::raw_ostream &OS); + +/// \brief Prints the measured data from the given category into the given +/// output stream +void printMeasuredData(llvm::raw_ostream &OS, const pamm::Category &Cat); +inline void printMeasuredData(llvm::raw_ostream &OS, + const pamm::Category &Cat) {} + +[[nodiscard]] inline ptrdiff_t +getSumCount(pamm::detail::IsCounter auto const &...Counters) noexcept { + return (Counters.value() + ...); +} + +} // namespace pamm + /// This class offers functionality to measure different performance metrics. /// All relevant functions are wrapped into preprocessor macros and should only /// be used through those macros. Using these macros allows us to disable PAMM @@ -54,10 +818,11 @@ namespace psr { /// @note This class implements the Singleton Pattern - use the /// PAMM_GET_INSTANCE macro to retrieve an instance of PAMM before you use any /// other macro from this class. -class PAMM final { +class [[deprecated("Use the new PAMM functionality from the psr::pamm " + "namespace instead")]] PAMM final { public: - using TimePoint_t = std::chrono::high_resolution_clock::time_point; - using Duration_t = std::chrono::milliseconds; + using TimePoint_t = std::chrono::steady_clock::time_point; + using Duration_t = std::chrono::nanoseconds; PAMM() noexcept = default; ~PAMM() = default; @@ -71,108 +836,10 @@ class PAMM final { /// macro: PAMM_GET_INSTANCE. [[nodiscard]] static PAMM &getInstance(); - /// \brief Resets PAMM, i.e. discards all gathered information (timer, counter - /// etc.) - associated macro: RESET_PAMM. - /// \note Only used for unit testing to reset PAMM in between test runs. - void reset(); - - /// \brief Starts a timer under the given timer id - associated macro: - /// START_TIMER(TIMER_ID, SEV_LVL). - /// \param TimerId Unique timer id. - void startTimer(llvm::StringRef TimerId); - - /// \brief Resets timer under the given timer id - associated macro: - /// RESET_TIMER(TIMER_ID, SEV_LVL). - /// \param TimerId Unique timer id. - void resetTimer(llvm::StringRef TimerId); - - /// If pauseTimer is true, a running timer gets paused, its start time point - /// will paired with a current time point, and stored as an accumulated timer. - /// This enables us to repeatedly compute execution time for a certain portion - /// of code which is executed multiple times, e.g. a loop or a function - /// call, without using a different timer id for every time computation. - /// Times of all executions of one timer are saved as distinct time point - /// pairs. Associated macro: - /// PAUSE_TIMER(TIMER_ID, SEV_LVL) - /// - /// Otherwise, the timer will be simply stopped. Associated macro: - /// STOP_TIMER(TIMER_ID, SEV_LVL) - /// \brief Stops or pauses a timer under the given timer id. - /// \param TimerId Unique timer id. - /// \param PauseTimer If true, timer will be paused instead of stopped. - void stopTimer(llvm::StringRef TimerId, bool PauseTimer = false); - - /// \brief Computes the elapsed time of the given timer up until now or up to - /// the moment the timer was stopped - associated macro: GET_TIMER(TIMERID) - /// \param TimerId Unique timer id. - /// \return Timer duration. - uint64_t elapsedTime(llvm::StringRef TimerId); - - /// For each accumulated timer a vector holds all recorded durations. - /// \brief Computes the elapsed time for all accumulated timer being used. - /// \return Map containing measured durations of all accumulated timer. - [[nodiscard]] llvm::StringMap> - elapsedTimeOfRepeatingTimer(); - - /// A running timer will not be stopped. The precision for time computation - /// is set to milliseconds and the output is similar to a timestamp, e.g. - /// '4h 8m 15sec 16ms'. - /// - /// Associated macro PRINT_TIMER(TIMERID) does not check PAMM's severity level - /// explicitly. - /// \brief Returns the elapsed time for a given timer id. - /// \param timerId Unique timer id. - [[nodiscard]] static std::string getPrintableDuration(uint64_t Duration); - - /// \brief Registers a new counter under the given counter id - associated - /// macro: REG_COUNTER(COUNTER_ID, INIT_VALUE, SEV_LVL). - /// \param CounterId Unique counter id. - void regCounter(llvm::StringRef CounterId, unsigned IntialValue = 0); - - /// \brief Increases the count for the given counter - associated macro: - /// INC_COUNTER(COUNTER_ID, VALUE, SEV_LVL). - /// \param CounterId Unique counter id. - /// \param CValue to be added to the current counter. - void incCounter(llvm::StringRef CounterId, unsigned CValue = 1); - - /// \brief Decreases the count for the given counter - associated macro: - /// DEC_COUNTER(COUNTER_ID, VALUE, SEV_LVL). - /// \param CounterId Unique counter id. - /// \param CValue to be subtracted from the current counter. - void decCounter(llvm::StringRef CounterId, unsigned CValue = 1); - - /// The associated macro does not check PAMM's severity level explicitly. - /// \brief Returns the current count for the given counter - associated macro: - /// GET_COUNTER(COUNTER_ID). - /// \param CounterId Unique counter id. - std::optional getCounter(llvm::StringRef CounterId); - - /// The associated macro does not check PAMM's severity level explicitly. - /// \brief Sums the counts for the given counter ids - associated macro: - /// GET_SUM_COUNT(...). - /// \param CounterIds Unique counter ids. - /// \note Macro uses variadic parameters, e.g. GET_SUM_COUNT({"foo", "bar"}). - std::optional getSumCount(const std::set &CounterIds); - std::optional - getSumCount(llvm::ArrayRef CounterIds); - std::optional - getSumCount(std::initializer_list CounterIds); - - /// \brief Registers a new histogram - associated macro: - /// REG_HISTOGRAM(HISTOGRAM_ID, SEV_LVL). - /// \param HistogramId Unique hitogram id. - void regHistogram(llvm::StringRef HistogramId); - - /// \brief Adds a new observed data point to the corresponding histogram - - /// associated macro: ADD_TO_HISTOGRAM(HISTOGRAM_ID, DATAPOINT_ID, - /// DATAPOINT_VALUE, SEV_LVL). - /// \param HistogramId ID of the histogram that tracks given data points. - /// \param DataPointId ID of the given data point. - /// \param DataPointValue Value of the given data point. - void addToHistogram(llvm::StringRef HistogramId, llvm::StringRef DataPointId, - uint64_t DataPointValue = 1); - - void stopAllTimers(); + [[nodiscard]] static ptrdiff_t + getSumCount(pamm::detail::IsCounter auto const &...Counters) { + return (Counters.value() + ...); + } void printTimers(llvm::raw_ostream &OS); @@ -180,30 +847,14 @@ class PAMM final { void printHistograms(llvm::raw_ostream &OS); - /// \brief Prints the measured data to the commandline - associated macro: - /// PRINT_MEASURED_DATA - void printMeasuredData(llvm::raw_ostream &OS); - - /// \brief Exports the measured data to JSON - associated macro: - /// EXPORT_MEASURED_DATA(PATH). - /// \param OutputPath to exported JSON file. - void exportMeasuredData( - const llvm::Twine &OutputPath, - llvm::StringRef ProjectId = "default-phasar-project", - const std::vector *Modules = nullptr, - const std::vector *DataFlowAnalyses = nullptr); - - [[nodiscard]] const auto &getHistogram() const noexcept { return Histogram; } - -private: - llvm::StringMap RunningTimer; - llvm::StringMap> StoppedTimer; - llvm::StringMap>> - RepeatingTimer; - llvm::StringMap Counter; - llvm::StringMap> Histogram; + /// \brief Prints the measured data to the commandline + void printMeasuredData(llvm::raw_ostream &OS) { pamm::printMeasuredData(OS); } + void printMeasuredData(llvm::raw_ostream &OS, + const pamm::Category &Cat) { + pamm::printMeasuredData(OS, Cat); + } }; } // namespace psr -#endif +inline constexpr psr::pamm::Category PAMMCategory{""}; diff --git a/include/phasar/Utils/PAMMMacros.h b/include/phasar/Utils/PAMMMacros.h index cc74e66319..1d7f2d42c3 100644 --- a/include/phasar/Utils/PAMMMacros.h +++ b/include/phasar/Utils/PAMMMacros.h @@ -18,30 +18,46 @@ #define PHASAR_UTILS_PAMMMACROS_H_ #include "phasar/Config/phasar-config.h" +#include "phasar/Utils/Macros.h" +#include "phasar/Utils/PAMM.h" -namespace psr { -/// Defines the different level of severity of PAMM's performance evaluation -enum class PAMM_SEVERITY_LEVEL { Off = 0, Core, Full }; // NOLINT - -#if defined(PAMM_FULL) -// NOLINTNEXTLINE -static constexpr PAMM_SEVERITY_LEVEL PAMM_CURR_SEV_LEVEL = - PAMM_SEVERITY_LEVEL::Full; -#elif defined(PAMM_CORE) -// NOLINTNEXTLINE -static constexpr PAMM_SEVERITY_LEVEL PAMM_CURR_SEV_LEVEL = - PAMM_SEVERITY_LEVEL::Core; -#else -// NOLINTNEXTLINE -static constexpr PAMM_SEVERITY_LEVEL PAMM_CURR_SEV_LEVEL = - PAMM_SEVERITY_LEVEL::Off; -#endif +// optional second parameter: boolean whether the category is enabled by default +#define PAMM_CATEGORY(NAME, ...) \ + static inline ::psr::pamm::Category<> PAMMCategory { \ + #NAME __VA_OPT__(, ) __VA_ARGS__ \ + } + +#define PAMM_COUNTER(COUNTER_ID, SEV_LVL) \ + static inline ::psr::pamm::Counter= \ + PAMM_SEVERITY_LEVEL::SEV_LVL, \ + #COUNTER_ID, &PAMMCategory> \ + COUNTER_ID + +#define PAMM_MINMAX_COUNTER(COUNTER_ID, SEV_LVL) \ + static inline ::psr::pamm::MinMaxCounter= \ + PAMM_SEVERITY_LEVEL::SEV_LVL, \ + #COUNTER_ID, &PAMMCategory> \ + COUNTER_ID -} // namespace psr +#define PAMM_HISTOGRAM(HISTOGRAM_ID, SEV_LVL) \ + static inline ::psr::pamm::Histogram= \ + PAMM_SEVERITY_LEVEL::SEV_LVL, \ + #HISTOGRAM_ID, &PAMMCategory> \ + HISTOGRAM_ID + +#define PAMM_TIMER(TIMER_ID, SEV_LVL) \ + static inline ::psr::pamm::Timer= \ + PAMM_SEVERITY_LEVEL::SEV_LVL, \ + #TIMER_ID, &PAMMCategory> \ + TIMER_ID + +#define PAMM_SCOPED_TIMER(TIMER_ID) \ + [[maybe_unused]] ::psr::pamm::ScopedTimer PSR_CONCAT(PAMMScopedTimer, \ + __COUNTER__) { \ + TIMER_ID \ + } #if defined(PAMM_FULL) || defined(PAMM_CORE) -// Only include PAMM header if it is used -#include "phasar/Utils/PAMM.h" #define PAMM_GET_INSTANCE PAMM &pamm = PAMM::getInstance() #define PAMM_RESET pamm.reset() @@ -65,30 +81,7 @@ static constexpr PAMM_SEVERITY_LEVEL PAMM_CURR_SEV_LEVEL = #define PRINT_TIMER(TIMER_ID) \ pamm.getPrintableDuration(pamm.elapsedTime(TIMER_ID)) -#define REG_COUNTER(COUNTER_ID, INIT_VALUE, SEV_LVL) \ - if constexpr (PAMM_CURR_SEV_LEVEL >= PAMM_SEVERITY_LEVEL::SEV_LVL) { \ - pamm.regCounter(COUNTER_ID, INIT_VALUE); \ - } -#define INC_COUNTER(COUNTER_ID, VALUE, SEV_LVL) \ - if constexpr (PAMM_CURR_SEV_LEVEL >= PAMM_SEVERITY_LEVEL::SEV_LVL) { \ - pamm.incCounter(COUNTER_ID, VALUE); \ - } -#define DEC_COUNTER(COUNTER_ID, VALUE, SEV_LVL) \ - if constexpr (PAMM_CURR_SEV_LEVEL >= PAMM_SEVERITY_LEVEL::SEV_LVL) { \ - pamm.decCounter(COUNTER_ID, VALUE); \ - } -#define GET_COUNTER(COUNTER_ID) pamm.getCounter(COUNTER_ID) -#define GET_SUM_COUNT(...) pamm.getSumCount(__VA_ARGS__) - -#define REG_HISTOGRAM(HISTOGRAM_ID, SEV_LVL) \ - if constexpr (PAMM_CURR_SEV_LEVEL >= PAMM_SEVERITY_LEVEL::SEV_LVL) { \ - pamm.regHistogram(HISTOGRAM_ID); \ - } -#define ADD_TO_HISTOGRAM(HISTOGRAM_ID, DATAPOINT_ID, DATAPOINT_VALUE, SEV_LVL) \ - if constexpr (PAMM_CURR_SEV_LEVEL >= PAMM_SEVERITY_LEVEL::SEV_LVL) { \ - pamm.addToHistogram(HISTOGRAM_ID, adl_to_string(DATAPOINT_ID), \ - DATAPOINT_VALUE); \ - } +#define GET_SUM_COUNT(...) ::psr::pamm::getSumCount(__VA_ARGS__) #define PRINT_MEASURED_DATA(OUTPUT_STREAM) pamm.printMeasuredData(OUTPUT_STREAM) #define EXPORT_MEASURED_DATA(PATH) pamm.exportMeasuredData(PATH) @@ -100,17 +93,11 @@ static constexpr PAMM_SEVERITY_LEVEL PAMM_CURR_SEV_LEVEL = #define RESET_TIMER(TIMER_ID, SEV_LVL) #define PAUSE_TIMER(TIMER_ID, SEV_LVL) #define STOP_TIMER(TIMER_ID, SEV_LVL) -#define REG_COUNTER(COUNTER_ID, INIT_VALUE, SEV_LVL) -#define INC_COUNTER(COUNTER_ID, VALUE, SEV_LVL) -#define DEC_COUNTER(COUNTER_ID, VALUE, SEV_LVL) -#define REG_HISTOGRAM(HISTOGRAM_ID, SEV_LVL) -#define ADD_TO_HISTOGRAM(HISTOGRAM_ID, DATAPOINT_ID, DATAPOINT_VALUE, SEV_LVL) #define PRINT_MEASURED_DATA(OUTPUT_STREAM) #define EXPORT_MEASURED_DATA(PATH) // The following macros could be used in log messages, thus they have to // provide some default value to avoid compiler errors #define PRINT_TIMER(TIMER_ID) "" -#define GET_COUNTER(COUNTER_ID) "" #define GET_SUM_COUNT(...) "" #endif diff --git a/include/phasar/Utils/TemplateString.h b/include/phasar/Utils/TemplateString.h new file mode 100644 index 0000000000..9841d9984a --- /dev/null +++ b/include/phasar/Utils/TemplateString.h @@ -0,0 +1,21 @@ +#pragma once + +#include "llvm/ADT/StringRef.h" + +#include + +namespace psr { +template struct TemplateString { + char Buf[N + 1]{}; + + constexpr TemplateString(const char (&Str)[N + 1]) noexcept { + static_assert(N != SIZE_MAX); + for (size_t I = 0; I != N; ++I) { + Buf[I] = Str[I]; + } + } + + constexpr operator llvm::StringRef() const noexcept { return {Buf, N}; } +}; +template TemplateString(const char (&)[N]) -> TemplateString; +} // namespace psr diff --git a/include/phasar/Utils/Utilities.h b/include/phasar/Utils/Utilities.h index 24422d96bf..c122152674 100644 --- a/include/phasar/Utils/Utilities.h +++ b/include/phasar/Utils/Utilities.h @@ -20,6 +20,7 @@ #include #include #include +#include #include #include #include @@ -341,6 +342,8 @@ template void assertAllNotNull([[maybe_unused]] const T &Range) { } } +[[nodiscard]] std::string locToString(std::source_location Loc); + template > constexpr void sortUnique(auto &Range, CompareFn Cmp = {}) { auto It = llvm::adl_begin(Range); diff --git a/lib/PhasarLLVM/ControlFlow/LLVMBasedCallGraphBuilder.cpp b/lib/PhasarLLVM/ControlFlow/LLVMBasedCallGraphBuilder.cpp index 6a8191401f..b0cf21329d 100644 --- a/lib/PhasarLLVM/ControlFlow/LLVMBasedCallGraphBuilder.cpp +++ b/lib/PhasarLLVM/ControlFlow/LLVMBasedCallGraphBuilder.cpp @@ -23,6 +23,12 @@ namespace { using namespace psr; + +PAMM_CATEGORY(CallGraphBuilder); + +PAMM_COUNTER(CGFunctions, Full); +PAMM_COUNTER(CGCallSites, Full); + struct Builder { const LLVMProjectIRDB *IRDB = nullptr; Resolver *Res = nullptr; @@ -94,11 +100,6 @@ auto Builder::buildCallGraph(Soundness S) -> LLVMBasedCallGraph { } } - PAMM_GET_INSTANCE; - REG_COUNTER("CG Functions", CGBuilder.viewCallGraph().getNumVertexFunctions(), - Full); - REG_COUNTER("CG CallSites", CGBuilder.viewCallGraph().getNumVertexCallSites(), - Full); PHASAR_LOG_LEVEL_CAT(INFO, "LLVMBasedICFG", "Call graph has been constructed"); return CGBuilder.consumeCallGraph(); @@ -143,6 +144,8 @@ bool Builder::processFunction(const llvm::Function *F) { return true; } + ++CGFunctions; + assert(Res != nullptr); // add a node for function F to the call graph (if not present already) @@ -158,6 +161,8 @@ bool Builder::processFunction(const llvm::Function *F) { continue; } + ++CGCallSites; + FixpointReached &= fillPossibleTargets(PossibleTargets, *Res, CS, IndirectCalls); diff --git a/lib/PhasarLLVM/DataFlow/IfdsIde/CFLFieldSensIFDSProblem.cpp b/lib/PhasarLLVM/DataFlow/IfdsIde/CFLFieldSensIFDSProblem.cpp index f02934c5db..a383dfd698 100644 --- a/lib/PhasarLLVM/DataFlow/IfdsIde/CFLFieldSensIFDSProblem.cpp +++ b/lib/PhasarLLVM/DataFlow/IfdsIde/CFLFieldSensIFDSProblem.cpp @@ -30,6 +30,25 @@ using namespace psr; using namespace psr::cfl_fieldsens; +namespace psr::cfl_fieldsens { +PAMM_CATEGORY(CFLFieldSens); + +PAMM_COUNTER(ExtendCacheRefs, Full); +PAMM_COUNTER(ExtendCacheMisses, Full); +PAMM_COUNTER(CombineCacheRefs, Full); +PAMM_COUNTER(CombineCacheMisses, Full); +PAMM_COUNTER(CombineCallsTotal, Full); +PAMM_COUNTER(CombineLIdentity, Full); +PAMM_COUNTER(CombineLIdentitySlow, Full); +PAMM_COUNTER(CombineRIdentity, Full); +PAMM_COUNTER(CombineRIdentitySlow, Full); + +PAMM_COUNTER(GetResultEFTop, Full); +PAMM_COUNTER(GetResultEFBot, Full); +PAMM_COUNTER(GetResultEFPtr, Full); + +} // namespace psr::cfl_fieldsens + FieldStringManager::FieldStringManager() { // Sentinel NodeCompressor.insertDummy( @@ -749,10 +768,9 @@ allTopPtr() noexcept { [[nodiscard]] static EdgeFunction getResultEF(llvm::PointerIntPair Ptr) noexcept { - PAMM_GET_INSTANCE; switch (Ptr.getInt()) { [[likely]] case AllEFPtrId: - INC_COUNTER("getResultEF Ptr", 1, Full); + GetResultEFPtr++; assert(Ptr.getPointer() != nullptr); assert(Ptr.getPointer() == Ptr.getOpaqueValue() && "Zero-tag does not pollute the alignment bits"); @@ -760,35 +778,16 @@ getResultEF(llvm::PointerIntPair static_cast( Ptr.getOpaqueValue())}; case AllBottomId: - INC_COUNTER("getResultEF Bot", 1, Full); + GetResultEFBot++; return AllBottom{}; case AllTopId: - INC_COUNTER("getResultEF Top", 1, Full); + GetResultEFTop++; return AllTop{}; default: llvm_unreachable("All valid tags should be handled explicitly"); } } -void CFLFieldSensIFDSProblem::regCounters() noexcept { - PAMM_GET_INSTANCE; - - REG_COUNTER("ExtendCache Refs", 0, Full); - REG_COUNTER("ExtendCache Misses", 0, Full); - - REG_COUNTER("CombineCache Refs", 0, Full); - REG_COUNTER("CombineCache Misses", 0, Full); - REG_COUNTER("Combine CallsTotal", 0, Full); - REG_COUNTER("Combine LIdentity", 0, Full); - REG_COUNTER("Combine LIdentitySlow", 0, Full); - REG_COUNTER("Combine RIdentity", 0, Full); - REG_COUNTER("Combine RIdentitySlow", 0, Full); - - REG_COUNTER("getResultEF Top", 0, Full); - REG_COUNTER("getResultEF Bot", 0, Full); - REG_COUNTER("getResultEF Ptr", 0, Full); -} - auto CFLFieldSensIFDSProblem::extend(const EdgeFunction &L, const EdgeFunction &R) -> EdgeFunction { @@ -811,13 +810,11 @@ auto CFLFieldSensIFDSProblem::extend(const EdgeFunction &L, return L; } - PAMM_GET_INSTANCE; - - INC_COUNTER("ExtendCache Refs", 1, Full); + ExtendCacheRefs++; auto [It, Inserted] = ExtendCache.try_emplace( std::pair{FldSensL->Impl, FldSensR->Impl}, lazy{[&]() -> EFResultPtr { - INC_COUNTER("ExtendCache Misses", 1, Full); + ExtendCacheMisses++; auto Txn = FldSensL->Impl->Transform; Txn.applyTransforms(FldSensR->Impl->Transform, DepthKLimit); @@ -855,21 +852,18 @@ auto CFLFieldSensIFDSProblem::combine(const EdgeFunction &L, return Dflt; } auto Ret = [&]() -> EdgeFunction { - PAMM_GET_INSTANCE; - INC_COUNTER("Combine CallsTotal", 1, Full); + CombineCallsTotal++; const auto *FldSensL = L.dyn_cast(); const auto *FldSensR = R.dyn_cast(); if (FldSensL) { if (FldSensR) { - - INC_COUNTER("CombineCache Refs", 1, Full); + CombineCacheRefs++; auto [CacheIt, CacheInserted] = CombineCache.try_emplace( psr::minmaxVal(FldSensL->Impl, FldSensR->Impl), lazy{[this, FldSensL{*FldSensL}, FldSensR{*FldSensR}]() -> EFResultPtr { - PAMM_GET_INSTANCE; - INC_COUNTER("CombineCache Misses", 1, Full); + CombineCacheMisses++; // A complicated way of expressing set-union of LPaths and RPaths. // Reason being that we don't want to unnecessarily copy the sets. @@ -915,24 +909,24 @@ auto CFLFieldSensIFDSProblem::combine(const EdgeFunction &L, } if (R.isa>()) { - INC_COUNTER("Combine RIdentity", 1, Full); + CombineRIdentity++; if (FldSensL->Impl->Transform.Paths.contains(AccessPath{})) { return L; } - INC_COUNTER("Combine RIdentitySlow", 1, Full); + CombineRIdentitySlow++; auto Txn = FldSensL->Impl->Transform; Txn.Paths.insert(AccessPath{}); return makeEF( CFLFieldSensEdgeFunctionImpl::from(std::move(Txn), DepthKLimit)); } } else if (FldSensR && L.isa>()) { - INC_COUNTER("Combine LIdentity", 1, Full); + CombineLIdentity++; if (FldSensR->Impl->Transform.Paths.contains(AccessPath{})) { return R; } - INC_COUNTER("Combine LIdentitySlow", 1, Full); + CombineLIdentitySlow++; auto Txn = FldSensR->Impl->Transform; Txn.Paths.insert(AccessPath{}); return makeEF( diff --git a/lib/PhasarLLVM/DataFlow/IfdsIde/Problems/IFDSConstAnalysis.cpp b/lib/PhasarLLVM/DataFlow/IfdsIde/Problems/IFDSConstAnalysis.cpp index ecc95e0fa5..bb1e219d00 100644 --- a/lib/PhasarLLVM/DataFlow/IfdsIde/Problems/IFDSConstAnalysis.cpp +++ b/lib/PhasarLLVM/DataFlow/IfdsIde/Problems/IFDSConstAnalysis.cpp @@ -31,7 +31,15 @@ #include #include -namespace psr { +using namespace psr; + +namespace { +PAMM_CATEGORY(IFDSConstAnalysis); + +PAMM_COUNTER(Calls_getContextRelevantAliasSet, Full); // NOLINT +PAMM_HISTOGRAM(ContextRelevantPointer, Full); +PAMM_TIMER(ContextRelevantAliasComputationTm, Full); +} // namespace IFDSConstAnalysis::IFDSConstAnalysis(const LLVMProjectIRDB *IRDB, LLVMAliasInfoRef PT, @@ -39,9 +47,6 @@ IFDSConstAnalysis::IFDSConstAnalysis(const LLVMProjectIRDB *IRDB, : IFDSTabulationProblem(IRDB, std::move(EntryPoints), createZeroValue()), PT(PT) { assert(PT); - PAMM_GET_INSTANCE; - REG_HISTOGRAM("Context-relevant Pointer", Full); - REG_COUNTER("[Calls] getContextRelevantAliasSet", 0, Full); } IFDSConstAnalysis::FlowFunctionPtrType @@ -191,9 +196,8 @@ void IFDSConstAnalysis::printInitMemoryLocations() { std::set IFDSConstAnalysis::getContextRelevantAliasSet( std::set &AliasSet, IFDSConstAnalysis::f_t CurrentContext) { - PAMM_GET_INSTANCE; - INC_COUNTER("[Calls] getContextRelevantAliasSet", 1, Full); - START_TIMER("Context-Relevant-Alias-Set Computation", Full); + Calls_getContextRelevantAliasSet++; + PAMM_SCOPED_TIMER(ContextRelevantAliasComputationTm); std::set ToGenerate; for (const auto *Alias : AliasSet) { PHASAR_LOG_LEVEL(DEBUG, "Alias: " << llvmIRToString(Alias)); @@ -221,13 +225,12 @@ std::set IFDSConstAnalysis::getContextRelevantAliasSet( } } // ignore everything else } - PAUSE_TIMER("Context-Relevant-Alias-Set Computation", Full); - ADD_TO_HISTOGRAM("Context-relevant Pointer", ToGenerate.size(), 1, Full); + ContextRelevantPointer.add(ToGenerate.size(), 1); return ToGenerate; } bool IFDSConstAnalysis::isInitialized(IFDSConstAnalysis::d_t Fact) const { - return llvm::isa(Fact) || Initialized.count(Fact); + return llvm::isa(Fact) || Initialized.contains(Fact); } void IFDSConstAnalysis::markAsInitialized(IFDSConstAnalysis::d_t Fact) { @@ -288,5 +291,3 @@ void IFDSConstAnalysis::emitTextReport( } OS << "\n===================================================\n"; } - -} // namespace psr diff --git a/lib/PhasarLLVM/Passes/GeneralStatisticsAnalysis.cpp b/lib/PhasarLLVM/Passes/GeneralStatisticsAnalysis.cpp index d46bbc92dc..614ecf62e8 100644 --- a/lib/PhasarLLVM/Passes/GeneralStatisticsAnalysis.cpp +++ b/lib/PhasarLLVM/Passes/GeneralStatisticsAnalysis.cpp @@ -14,7 +14,6 @@ #include "phasar/Utils/AlignNum.h" #include "phasar/Utils/Logger.h" #include "phasar/Utils/NlohmannLogging.h" -#include "phasar/Utils/PAMMMacros.h" #include "llvm/IR/CFG.h" #include "llvm/IR/Function.h" @@ -29,7 +28,7 @@ #include -namespace psr { +using namespace psr; static bool isAddressTaken(const llvm::Function &Fun) noexcept { for (const auto &Use : Fun.uses()) { @@ -188,16 +187,7 @@ GeneralStatisticsAnalysis::runOnModule(const llvm::Module &M) { // For performance reasons (and out of sheer convenience) we simply initialize // the counter with the values of the counter varibles, i.e. PAMM simply // holds the results. - PAMM_GET_INSTANCE; - REG_COUNTER("GS Instructions", Stats.Instructions, Core); - REG_COUNTER("GS Allocated Types", Stats.AllocatedTypes.size(), Full); - REG_COUNTER("GS Basic Blocks", Stats.BasicBlocks, Full); - REG_COUNTER("GS Call-Sites", Stats.CallSites, Full); - REG_COUNTER("GS Functions", Stats.Functions, Full); - REG_COUNTER("GS Globals", Stats.Globals, Full); - REG_COUNTER("GS Memory Intrinsics", Stats.MemIntrinsics, Full); - REG_COUNTER("GS Store Instructions", Stats.StoreInstructions, Full); - REG_COUNTER("GS Load Instructions", Stats.LoadInstructions, Full); + // Using the logging guard explicitly since we are printing allocated types // manually IF_LOG_LEVEL_ENABLED(INFO, { @@ -269,8 +259,6 @@ void GeneralStatistics::printAsJson(llvm::raw_ostream &OS) const { OS << Json << '\n'; } -} // namespace psr - llvm::raw_ostream &psr::operator<<(llvm::raw_ostream &OS, const GeneralStatistics &Statistics) { return OS diff --git a/lib/Utils/PAMM.cpp b/lib/Utils/PAMM.cpp index fe7072d59b..b4b9f58fe4 100644 --- a/lib/Utils/PAMM.cpp +++ b/lib/Utils/PAMM.cpp @@ -17,393 +17,232 @@ #include "phasar/Utils/PAMM.h" #include "phasar/Utils/ChronoUtils.h" -#include "phasar/Utils/NlohmannLogging.h" +#include "phasar/Utils/Fn.h" +#include "phasar/Utils/MapUtils.h" -#include "llvm/ADT/SmallString.h" #include "llvm/ADT/StringRef.h" #include "llvm/ADT/Twine.h" -#include "llvm/Support/Compiler.h" #include "llvm/Support/ErrorHandling.h" #include "llvm/Support/raw_ostream.h" -#include "nlohmann/json.hpp" - #include #include -#include -#include -#include -#include -#include -#include +#include using namespace psr; -using json = nlohmann::json; - -namespace psr { PAMM &PAMM::getInstance() { static PAMM Instance{}; return Instance; } -void PAMM::startTimer(llvm::StringRef TimerId) { - if (LLVM_UNLIKELY(StoppedTimer.count(TimerId))) { - llvm::report_fatal_error("Do not start an already stopped timer"); - } - - auto [It, Inserted] = RunningTimer.try_emplace(TimerId); - if (LLVM_UNLIKELY(!Inserted)) { - llvm::report_fatal_error("Do not start an already running timer"); - } - - PAMM::TimePoint_t Start = std::chrono::high_resolution_clock::now(); - It->second = Start; -} - -void PAMM::resetTimer(llvm::StringRef TimerId) { - [[maybe_unused]] bool InRunningTimers = RunningTimer.erase(TimerId); - [[maybe_unused]] bool InStoppedTimers = StoppedTimer.erase(TimerId); - - assert((InRunningTimers && !InStoppedTimers) || - (!InRunningTimers && InStoppedTimers) && - "resetTimer failed due to an invalid timer id"); -} - -void PAMM::stopTimer(llvm::StringRef TimerId, bool PauseTimer) { - auto RunningIt = RunningTimer.find(TimerId); - auto StoppedIt = StoppedTimer.find(TimerId); - bool TimerRunning = RunningIt != RunningTimer.end(); - bool TimerStopped = StoppedIt != StoppedTimer.end(); - bool ValidTimerId = TimerRunning || TimerStopped; - assert(ValidTimerId && "stopTimer failed due to an invalid timer id or timer " - "was already stopped"); - assert(TimerRunning && "stopTimer failed because timer was already stopped"); - - if (LLVM_LIKELY(ValidTimerId)) { - PAMM::TimePoint_t End = std::chrono::high_resolution_clock::now(); - PAMM::TimePoint_t Start = RunningIt->second; - RunningTimer.erase(RunningIt); - auto P = make_pair(Start, End); - if (PauseTimer) { - RepeatingTimer[TimerId].push_back(P); - } else { - StoppedTimer[TimerId] = P; +template +static void printAllHelper(llvm::raw_ostream &OS, const MapTy &Map, + llvm::StringRef Header, llvm::StringRef Separator, + llvm::StringRef EmptyMsg, ImplFn Impl) { + OS << '\n' << Header << '\n' << Separator << '\n'; + for (const auto &[Cat, Items] : Map) { + if (Cat->isEnabled()) { + Impl(OS, *Cat, Items); } } + if (Map.empty()) { + OS << EmptyMsg << '\n'; + } } -uint64_t PAMM::elapsedTime(llvm::StringRef TimerId) { - auto RunningIt = RunningTimer.find(TimerId); - - if (RunningIt != RunningTimer.end()) { - PAMM::TimePoint_t End = std::chrono::high_resolution_clock::now(); - PAMM::TimePoint_t Start = RunningIt->second; - auto Duration = std::chrono::duration_cast(End - Start); - return Duration.count(); +template +static void printCategoryHelper(llvm::raw_ostream &OS, + const pamm::Category &Cat, + const MapTy &Map, llvm::StringRef TypeName, + llvm::StringRef Separator, ImplFn Impl) { + if (!Cat.isEnabled()) { + OS << "Category '" << Cat.name() << "' is disabled\n"; + return; } - if (auto StoppedIt = StoppedTimer.find(TimerId); - StoppedIt != StoppedTimer.end()) { - auto [Start, End] = StoppedIt->second; - auto Duration = std::chrono::duration_cast(End - Start); - return Duration.count(); + const auto *Items = getOrNull(Map, &Cat); + if (!Items || Items->empty()) { + OS << "No " << TypeName << " for category '" << Cat.name() + << "' registered!\n"; + return; } - - assert(false && "elapsedTime failed due to an invalid timer id"); - return 0; + OS << '\n' << TypeName << '\n' << Separator << '\n'; + Impl(OS, Cat, *Items); } -template -static void foreachElapsedTimeOfRepeatingTimer( - llvm::StringMap< - std::vector>> - &RepeatingTimer, - HandlerFn Handler) { - for (const auto &Timer : RepeatingTimer) { - std::invoke( - Handler, Timer.first(), [&Timer](std::vector &AccTimeVec) { - AccTimeVec.reserve(Timer.second.size()); - - for (auto [Start, End] : Timer.second) { - auto Duration = - std::chrono::duration_cast(End - Start); - AccTimeVec.push_back(Duration.count()); - } - }); +static void printCountersImpl( + llvm::raw_ostream &OS, const pamm::Category &Cat, + const llvm::DenseMap + &CatCtrs) { + OS << Cat.name() << ":\n"; + for (const auto &[Name, C] : CatCtrs) { + OS << " " << Name << ": " << C->Ctr << '\n'; } + OS << '\n'; } -llvm::StringMap> PAMM::elapsedTimeOfRepeatingTimer() { - llvm::StringMap> AccTimes; - - foreachElapsedTimeOfRepeatingTimer( - RepeatingTimer, [&AccTimes](llvm::StringRef Id, auto Handler) { - std::invoke(std::move(Handler), AccTimes[Id]); - }); - - return AccTimes; +void pamm::Registry::printCounters(llvm::raw_ostream &OS) const { + printAllHelper(OS, Counters, "Counters", "--------", "No Counter registered!", + printCountersImpl); } -std::string PAMM::getPrintableDuration(uint64_t Duration) { - return hms(std::chrono::milliseconds{Duration}).str(); +void pamm::Registry::printCounters(llvm::raw_ostream &OS, + const Category &Cat) const { + printCategoryHelper(OS, Cat, Counters, "Counters", "--------", + printCountersImpl); } -void PAMM::regCounter(llvm::StringRef CounterId, unsigned IntialValue) { - [[maybe_unused]] auto [It, Inserted] = - Counter.try_emplace(CounterId, IntialValue); - assert(Inserted && "regCounter failed due to an invalid counter id"); +static void printMMCountersImpl( + llvm::raw_ostream &OS, const pamm::Category &Cat, + const llvm::DenseMap + &CatCtrs) { + OS << Cat.name() << ":\n"; + for (const auto &[Name, C] : CatCtrs) { + OS << " " << Name << ": min(" << C->Min << "), max(" << C->Max + << "), avg: " << llvm::format("%g", C->getAverage()) << ", #samples(" + << C->getNumSamples() << ")\n"; + } + OS << '\n'; } -void PAMM::incCounter(llvm::StringRef CounterId, unsigned CValue) { - auto It = Counter.find(CounterId); - bool ValidCounterId = It != Counter.end(); - assert(ValidCounterId && "incCounter failed due to an invalid counter id"); - if (ValidCounterId) { - It->second += CValue; - } +void pamm::Registry::printMinMaxCounters(llvm::raw_ostream &OS) const { + printAllHelper(OS, MMCounters, "Min-Max-Counters", "--------", + "No MinMax-Counter registered!", printMMCountersImpl); } -void PAMM::decCounter(llvm::StringRef CounterId, unsigned CValue) { - auto It = Counter.find(CounterId); - bool ValidCounterId = It != Counter.end(); - assert(ValidCounterId && "decCounter failed due to an invalid counter id"); - if (ValidCounterId) { - It->second -= CValue; - } +void pamm::Registry::printMinMaxCounters(llvm::raw_ostream &OS, + const Category &Cat) const { + printCategoryHelper(OS, Cat, MMCounters, "Min-Max-Counters", "--------", + printMMCountersImpl); } -std::optional PAMM::getCounter(llvm::StringRef CounterId) { - auto It = Counter.find(CounterId); - bool ValidCounterId = It != Counter.end(); - assert(ValidCounterId && "getCounter failed due to an invalid counter id"); - if (ValidCounterId) { - return It->second; - } - return std::nullopt; +void PAMM::printCounters(llvm::raw_ostream &OS) { + pamm::Registry::instance().printCounters(OS); } -template -static std::optional -getSumCountInternal(PAMM &P, ForwardIterator It, - ForwardIteratorSentinel End) noexcept { - uint64_t Ctr = 0; - for (; It != End; ++It) { - auto Count = P.getCounter(*It); - if (!Count) { - return std::nullopt; +void PAMM::printHistograms(llvm::raw_ostream &OS) { + pamm::Registry::instance().printHistograms(OS); +} + +static void printHistogramsImpl( + llvm::raw_ostream &OS, const pamm::Category &Cat, + const llvm::DenseMap + &Hists) { + for (const auto &[Name, H] : Hists) { + OS << Cat.name() << "::" << Name << " Histogram:\n"; + OS << " Value\t| #Occurrences\n"; + OS << " -----\t| ------------\n"; + for (const auto &[Dat, Val] : H->HistData) { + OS << " " << Dat << "\t| " << Val << '\n'; } - - Ctr += *Count; + OS << '\n'; } - - return Ctr; -} - -std::optional -PAMM::getSumCount(const std::set &CounterIds) { - return getSumCountInternal(*this, CounterIds.begin(), CounterIds.end()); -} - -std::optional -PAMM::getSumCount(llvm::ArrayRef CounterIds) { - return getSumCountInternal(*this, CounterIds.begin(), CounterIds.end()); } -std::optional -PAMM::getSumCount(std::initializer_list CounterIds) { - return getSumCountInternal(*this, CounterIds.begin(), CounterIds.end()); +void pamm::Registry::printHistograms(llvm::raw_ostream &OS) const { + printAllHelper(OS, Histograms, "Histograms", "--------------", + "No histograms tracked!", fn); } -void PAMM::regHistogram(llvm::StringRef HistogramId) { - [[maybe_unused]] auto [It, Inserted] = Histogram.try_emplace(HistogramId); - assert(Inserted && "failed to register new histogram due to an invalid id"); +void pamm::Registry::printHistograms(llvm::raw_ostream &OS, + const Category &Cat) const { + printCategoryHelper(OS, Cat, Histograms, "Histograms", "--------------", + fn); } -void PAMM::addToHistogram(llvm::StringRef HistogramId, - llvm::StringRef DataPointId, - uint64_t DataPointValue) { - auto HistIt = Histogram.find(HistogramId); - if (HistIt == Histogram.end()) { - assert(false && "adding data point to histogram failed due to invalid id"); - return; - } - - auto [DataIt, Inserted] = - HistIt->second.try_emplace(DataPointId, DataPointValue); - if (!Inserted) { - DataIt->second += DataPointValue; +static void printTimersImpl( + llvm::raw_ostream &OS, const pamm::Category &Cat, + const llvm::DenseMap &CatTms) { + OS << Cat.name() << ":\n"; + for (const auto &[Name, Tm] : CatTms) { + auto Time = Tm->elapsedNanos(); + bool StillRunning = Tm->isStarted(); + OS << " " << Name << ":\t"; + if (StillRunning) { + Time += Tm->pendingNanos(); + OS << hms{Time} << " (still running)\n"; + } else { + OS << hms{Time} << '\n'; + } } + OS << '\n'; } -void PAMM::stopAllTimers() { - while (!RunningTimer.empty()) { - // safe copy - auto Id = RunningTimer.begin()->first().str(); - stopTimer(Id); - } +void pamm::Registry::printTimers(llvm::raw_ostream &OS) const { + printAllHelper(OS, Timers, "Timers", "--------------", "No timers tracked!", + fn); } void PAMM::printTimers(llvm::raw_ostream &OS) { - // stop all running timer - stopAllTimers(); - - OS << "Single Timer\n"; - OS << "------------\n"; - for (const auto &Timer : StoppedTimer) { - uint64_t Time = elapsedTime(Timer.first()); - OS << Timer.first() << " : " << getPrintableDuration(Time) << '\n'; - } - if (StoppedTimer.empty()) { - OS << "No single Timer started!\n\n"; - } else { - OS << "\n"; - } - OS << "Repeating Timer\n"; - OS << "---------------\n"; - - foreachElapsedTimeOfRepeatingTimer(RepeatingTimer, - [&OS](llvm::StringRef Id, auto Handler) { - OS << Id << " Timer:\n"; - std::vector Times; - std::invoke(std::move(Handler), Times); - - uint64_t Sum = 0; - for (auto Duration : Times) { - Sum += Duration; - OS << Duration << '\n'; - } - OS << "===\n" << Sum << "\n\n"; - }); - - if (RepeatingTimer.empty()) { - OS << "No repeating Timer found!\n"; - } else { - OS << '\n'; - } + pamm::Registry::instance().printTimers(OS); } -void PAMM::printCounters(llvm::raw_ostream &OS) { - OS << "\nCounter\n"; - OS << "-------\n"; - for (const auto &Counter : Counter) { - OS << Counter.first() << " : " << Counter.second << '\n'; - } - if (Counter.empty()) { - OS << "No Counter registered!\n"; - } else { - OS << "\n"; - } +void pamm::Registry::printTimers(llvm::raw_ostream &OS, + const Category &Cat) const { + printCategoryHelper(OS, Cat, Timers, "Timers", "--------------", + fn); } -void PAMM::printHistograms(llvm::raw_ostream &OS) { - OS << "\nHistograms\n"; - OS << "--------------\n"; - for (const auto &H : Histogram) { - OS << H.first() << " Histogram\n"; - OS << "Value : #Occurrences\n"; - for (const auto &Entry : H.second) { - OS << Entry.first() << " : " << Entry.second << '\n'; - } - OS << '\n'; - } - if (Histogram.empty()) { - OS << "No histograms tracked!\n"; - } +void pamm::printMeasuredData(llvm::raw_ostream &OS) { + OS << "\n----- START OF EVALUATION DATA -----\n\n"; + auto &Reg = pamm::Registry::instance(); + Reg.printTimers(OS); + Reg.printCounters(OS); + Reg.printMinMaxCounters(OS); + Reg.printHistograms(OS); + OS << "\n----- END OF EVALUATION DATA -----\n\n"; } -void PAMM::printMeasuredData(llvm::raw_ostream &Os) { - Os << "\n----- START OF EVALUATION DATA -----\n\n"; - printTimers(Os); - printCounters(Os); - printHistograms(Os); - Os << "\n----- END OF EVALUATION DATA -----\n\n"; +void pamm::printMeasuredData(llvm::raw_ostream &OS, + const pamm::Category &Cat) { + OS << "\n----- START OF EVALUATION DATA -----\n\n"; + scope_exit Pop = [&] { OS << "\n----- END OF EVALUATION DATA -----\n\n"; }; + if (!Cat.isEnabled()) { + OS << "Category '" << Cat.name() << "' is disabled\n"; + return; + } + auto &Reg = pamm::Registry::instance(); + Reg.printTimers(OS, Cat); + Reg.printCounters(OS, Cat); + Reg.printMinMaxCounters(OS, Cat); + Reg.printHistograms(OS, Cat); } -void PAMM::exportMeasuredData( - const llvm::Twine &OutputPath, llvm::StringRef ProjectId, - const std::vector *Modules, - const std::vector *DataFlowAnalyses) { - // json file for holding all data - json JsonData; - - stopAllTimers(); - { - // add timer data - json JTimer; - for (const auto &Timer : StoppedTimer) { - uint64_t Time = elapsedTime(Timer.first()); - JTimer[Timer.first().str()] = Time; +void pamm::Registry::reset() noexcept { + for (const auto &[Cat, Ctrs] : Counters) { + for (const auto &[_, Ctr] : Ctrs) { + Ctr->Ctr = 0; } - - foreachElapsedTimeOfRepeatingTimer( - RepeatingTimer, [&JTimer](llvm::StringRef Id, auto Handler) { - std::vector Times; - std::invoke(std::move(Handler), Times); - JTimer[Id.str()] = std::move(Times); - }); - - JsonData["Timer"] = std::move(JTimer); } - { - // add histogram data if available - json JHistogram; - for (const auto &H : Histogram) { - json JSetH; - for (const auto &Entry : H.second) { - JSetH[Entry.first()] = Entry.second; - } - JHistogram[H.first()] = std::move(JSetH); - } - if (!JHistogram.is_null()) { - JsonData["Histogram"] = std::move(JHistogram); - } - } - { - // add counter data - json JCounter; - for (const auto &Counter : Counter) { - JCounter[Counter.first()] = Counter.second; + for (const auto &[Cat, Ctrs] : MMCounters) { + for (const auto &[_, Ctr] : Ctrs) { + Ctr->clear(); } - JsonData["Counter"] = std::move(JCounter); } - { - // add analysis/project/source file information if available - json JInfo; - JInfo["Project-ID"] = ProjectId; - if (Modules) { - JInfo["Module(s)"] = *Modules; - } - if (DataFlowAnalyses) { - JInfo["Data-flow analysis"] = *DataFlowAnalyses; + for (const auto &[Cat, Hists] : Histograms) { + for (const auto &[_, Hist] : Hists) { + Hist->HistData.clear(); } - if (!JInfo.is_null()) { - JsonData["Info"] = std::move(JInfo); - } - } - - llvm::SmallString<128> Buf; - OutputPath.toStringRef(Buf); - if (!llvm::StringRef(Buf).ends_with(".json")) { - Buf.append(".json"); } - std::error_code EC; - llvm::raw_fd_ostream OS(Buf, EC); - - if (EC) { - throw std::system_error(EC); + for (const auto &[Cat, Tms] : Timers) { + for (const auto &[_, Tm] : Tms) { + Tm->reset(); + } } +} - OS << JsonData << '\n'; +void pamm::Registry::clear() noexcept { + Counters.clear(); + MMCounters.clear(); + Histograms.clear(); + Timers.clear(); + RegisteredCategories.clear(); } -void PAMM::reset() { - RunningTimer.clear(); - StoppedTimer.clear(); - RepeatingTimer.clear(); - Counter.clear(); - Histogram.clear(); +auto pamm::Registry::findCategory(llvm::StringRef Name) const + -> const Category * { + return RegisteredCategories.lookup(Name); } -} // namespace psr diff --git a/lib/Utils/Utilities.cpp b/lib/Utils/Utilities.cpp index 9d8be8ab88..433580b98b 100644 --- a/lib/Utils/Utilities.cpp +++ b/lib/Utils/Utilities.cpp @@ -9,22 +9,16 @@ #include "phasar/Utils/Utilities.h" -#include "phasar/Utils/Logger.h" - -#include "llvm/ADT/StringExtras.h" #include "llvm/ADT/StringRef.h" #include "llvm/Demangle/Demangle.h" -#include "llvm/IR/DerivedTypes.h" #include #include +#include -using namespace std; using namespace psr; -namespace psr { - -std::string createTimeStamp() { +std::string psr::createTimeStamp() { auto Now = std::chrono::system_clock::now(); auto NowTime = std::chrono::system_clock::to_time_t(Now); std::string TimeStr(std::ctime(&NowTime)); @@ -34,7 +28,7 @@ std::string createTimeStamp() { return TimeStr; } -bool isConstructor(llvm::StringRef MangledName) { +bool psr::isConstructor(llvm::StringRef MangledName) { // WARNING: Doesn't work for templated classes, should // the best way to do it I can think of is to use a lexer // on the name to detect the constructor point explained @@ -61,7 +55,7 @@ bool isConstructor(llvm::StringRef MangledName) { return false; } -bool isMangled(llvm::StringRef Name) { +bool psr::isMangled(llvm::StringRef Name) { // See llvm/Demangle/Demangle.cpp if (Name.starts_with("_Z") || Name.starts_with("___Z")) { // Itanium ABI @@ -98,4 +92,11 @@ bool StringIDLess::operator()(const std::string &Lhs, return LhsVal < RhsVal; } -} // namespace psr +std::string psr::locToString(std::source_location Loc) { + std::string Ret = Loc.file_name(); + Ret += ':'; + Ret += std::to_string(Loc.line()); + Ret += ':'; + Ret += std::to_string(Loc.column()); + return Ret; +} diff --git a/unittests/PhasarLLVM/DataFlow/IfdsIde/InteractiveIDESolverTest.cpp b/unittests/PhasarLLVM/DataFlow/IfdsIde/InteractiveIDESolverTest.cpp index 0848925e45..01f5c7a64e 100644 --- a/unittests/PhasarLLVM/DataFlow/IfdsIde/InteractiveIDESolverTest.cpp +++ b/unittests/PhasarLLVM/DataFlow/IfdsIde/InteractiveIDESolverTest.cpp @@ -97,7 +97,9 @@ TEST_P(LinearConstant, ResultsEquivalentSolveUntilAsync) { EXPECT_EQ(std::nullopt, Result); if (!Result) { IsCancelled = false; - return std::move(Solver).solveWithAsyncCancellation(IsCancelled).value(); + return std::move(Solver) + .continueWithAsyncCancellation(IsCancelled) + .value(); } return Solver.consumeSolverResults(); }(); diff --git a/unittests/Utils/PAMMTest.cpp b/unittests/Utils/PAMMTest.cpp index 71aa2982e5..9935a07bd0 100644 --- a/unittests/Utils/PAMMTest.cpp +++ b/unittests/Utils/PAMMTest.cpp @@ -9,7 +9,11 @@ #include +namespace { using namespace psr; +using namespace std::chrono_literals; + +static constexpr pamm::Category TestingCat("PAMMTest"); /* Test fixture */ class PAMMTest : public ::testing::Test { @@ -20,121 +24,134 @@ class PAMMTest : public ::testing::Test { void SetUp() override {} - void TearDown() override { - PAMM &Pamm = PAMM::getInstance(); - Pamm.printMeasuredData(llvm::outs()); - Pamm.reset(); - } + void TearDown() override { pamm::Registry::instance().clear(); } }; TEST_F(PAMMTest, HandleTimer) { - // PAMM &pamm = PAMM::getInstance(); - PAMM::getInstance().startTimer("timer1"); - std::this_thread::sleep_for(std::chrono::milliseconds(120)); - PAMM::getInstance().stopTimer("timer1"); - auto Elapsed = PAMM::getInstance().elapsedTime("timer1"); - EXPECT_GE(Elapsed, 120U) << "Bad time measurement"; - EXPECT_LT(Elapsed, 240U) << "Too much tolerance"; + + pamm::Timer Tm1; + + { + pamm::ScopedTimer TmScope{Tm1}; + std::this_thread::sleep_for(std::chrono::milliseconds(120)); + } + auto Elapsed = Tm1.elapsedNanos(); + EXPECT_GE(Elapsed, 120ms) << "Bad time measurement"; + EXPECT_LT(Elapsed, 240ms) << "Too much tolerance"; + + pamm::printMeasuredData(llvm::outs()); } TEST_F(PAMMTest, HandleCounter) { - PAMM &Pamm = PAMM::getInstance(); - Pamm.regCounter("first"); - Pamm.regCounter("second"); - Pamm.regCounter("third"); - Pamm.incCounter("first", 42); - Pamm.incCounter("second"); - Pamm.incCounter("second"); - Pamm.incCounter("third", 2); - Pamm.decCounter("third", 2); - EXPECT_EQ(Pamm.getCounter("first"), 42); - EXPECT_EQ(Pamm.getCounter("second"), 2); - EXPECT_EQ(Pamm.getCounter("third"), 0); + pamm::Counter First; + pamm::Counter Second; + pamm::Counter Third; + + First += 42; + Second++; + ++Second; + + Third += 2; + Third -= 2; + + EXPECT_EQ(First.value(), 42); + EXPECT_EQ(Second.value(), 2); + EXPECT_EQ(Third.value(), 0); + + pamm::printMeasuredData(llvm::outs()); } -TEST_F(PAMMTest, HandleJSONOutput) { - PAMM &Pamm = PAMM::getInstance(); - Pamm.regCounter("timerCount"); - Pamm.regCounter("setOpCount"); - Pamm.startTimer("timer1"); - Pamm.incCounter("timerCount"); - Pamm.startTimer("timer2"); - Pamm.incCounter("timerCount"); - Pamm.regHistogram("Test-Set"); - Pamm.addToHistogram("Test-Set", "13"); - Pamm.addToHistogram("Test-Set", "13"); - Pamm.addToHistogram("Test-Set", "13"); - Pamm.addToHistogram("Test-Set", "42"); - Pamm.addToHistogram("Test-Set", "42"); - Pamm.addToHistogram("Test-Set", "42"); - Pamm.addToHistogram("Test-Set", "42"); - Pamm.addToHistogram("Test-Set", "42"); - Pamm.addToHistogram("Test-Set", "54"); - Pamm.addToHistogram("Test-Set", "54"); - Pamm.addToHistogram("Test-Set", "54"); - Pamm.addToHistogram("Test-Set", "42"); - Pamm.incCounter("setOpCount", 11); - - std::this_thread::sleep_for(std::chrono::milliseconds(180)); - Pamm.stopTimer("timer2"); - - Pamm.addToHistogram("Test-Set", "42"); - Pamm.addToHistogram("Test-Set", "42"); - Pamm.addToHistogram("Test-Set", "42"); - Pamm.addToHistogram("Test-Set", "42"); - Pamm.addToHistogram("Test-Set", "42"); - Pamm.addToHistogram("Test-Set", "42"); - Pamm.addToHistogram("Test-Set", "42"); - Pamm.addToHistogram("Test-Set", "1"); - Pamm.addToHistogram("Test-Set", "1"); - Pamm.addToHistogram("Test-Set", "1"); - Pamm.addToHistogram("Test-Set", "1"); - Pamm.incCounter("setOpCount", 10); - - Pamm.startTimer("timer3"); - Pamm.incCounter("timerCount"); - std::this_thread::sleep_for(std::chrono::milliseconds(230)); - - Pamm.addToHistogram("Test-Set", "1"); - Pamm.addToHistogram("Test-Set", "1"); - Pamm.addToHistogram("Test-Set", "1"); - Pamm.addToHistogram("Test-Set", "1"); - Pamm.addToHistogram("Test-Set", "1"); - Pamm.addToHistogram("Test-Set", "1"); - Pamm.addToHistogram("Test-Set", "2"); - Pamm.addToHistogram("Test-Set", "2"); - Pamm.addToHistogram("Test-Set", "2"); - Pamm.addToHistogram("Test-Set", "2"); - Pamm.incCounter("setOpCount", 9); - Pamm.stopTimer("timer3"); - Pamm.exportMeasuredData("HandleJSONOutputTest"); - - EXPECT_EQ(30, Pamm.getCounter("setOpCount")); - EXPECT_EQ(3, Pamm.getCounter("timerCount")); - - auto Timer1Elapsed = Pamm.elapsedTime("timer1"); - auto Timer2Elapsed = Pamm.elapsedTime("timer2"); - auto Timer3Elapsed = Pamm.elapsedTime("timer3"); - - EXPECT_GE(Timer1Elapsed, 410); // 180+230 - EXPECT_LT(Timer1Elapsed, 820); // 180+230 - - EXPECT_GE(Timer2Elapsed, 180); - EXPECT_LT(Timer2Elapsed, 360); - - EXPECT_GE(Timer3Elapsed, 230); - EXPECT_LT(Timer3Elapsed, 460); - - EXPECT_EQ(1, Pamm.getHistogram().size()); - EXPECT_EQ("Test-Set", Pamm.getHistogram().begin()->first()); +TEST_F(PAMMTest, HandleHistogram) { + pamm::Histogram TestSet; + TestSet.add(13, 1); + TestSet.add(13, 1); + TestSet.add(13, 1); + + TestSet.add(42, 1); + TestSet.add(42, 1); + TestSet.add(42, 1); + TestSet.add(42, 1); + TestSet.add(42, 1); + + TestSet.add(54, 1); + TestSet.add(54, 1); + TestSet.add(54, 1); + + TestSet.add(42, 1); + + TestSet.add(42, 7); + + TestSet.add(1, 4); + TestSet.add(1, 1); + TestSet.add(1, 1); + TestSet.add(1, 1); + TestSet.add(1, 1); + TestSet.add(1, 1); + TestSet.add(1, 1); + + TestSet.add(2, 4); llvm::StringMap Gt = { {"1", 10}, {"2", 4}, {"13", 3}, {"42", 13}, {"54", 3}, }; - const auto &Hist = Pamm.getHistogram().begin()->second; + const auto &Hist = TestSet.internalRawData(); EXPECT_EQ(Hist, Gt); + + pamm::printMeasuredData(llvm::outs()); } +// TEST_F(PAMMTest, HandleJSONOutput) { +// PAMM &Pamm = PAMM::getInstance(); +// Pamm.regCounter("timerCount"); +// Pamm.regCounter("setOpCount"); +// Pamm.startTimer("timer1"); +// Pamm.incCounter("timerCount"); +// Pamm.startTimer("timer2"); +// Pamm.incCounter("timerCount"); +// Pamm.regHistogram("Test-Set"); + +// Pamm.incCounter("setOpCount", 11); + +// std::this_thread::sleep_for(std::chrono::milliseconds(180)); +// Pamm.stopTimer("timer2"); + +// Pamm.incCounter("setOpCount", 10); + +// Pamm.startTimer("timer3"); +// Pamm.incCounter("timerCount"); +// std::this_thread::sleep_for(std::chrono::milliseconds(230)); + +// Pamm.incCounter("setOpCount", 9); +// Pamm.stopTimer("timer3"); +// Pamm.exportMeasuredData("HandleJSONOutputTest"); + +// EXPECT_EQ(30, Pamm.getCounter("setOpCount")); +// EXPECT_EQ(3, Pamm.getCounter("timerCount")); + +// auto Timer1Elapsed = Pamm.elapsedTime("timer1"); +// auto Timer2Elapsed = Pamm.elapsedTime("timer2"); +// auto Timer3Elapsed = Pamm.elapsedTime("timer3"); + +// EXPECT_GE(Timer1Elapsed, 410); // 180+230 +// EXPECT_LT(Timer1Elapsed, 820); // 180+230 + +// EXPECT_GE(Timer2Elapsed, 180); +// EXPECT_LT(Timer2Elapsed, 360); + +// EXPECT_GE(Timer3Elapsed, 230); +// EXPECT_LT(Timer3Elapsed, 460); + +// EXPECT_EQ(1, Pamm.getHistogram().size()); +// EXPECT_EQ("Test-Set", Pamm.getHistogram().begin()->first()); + +// llvm::StringMap Gt = { +// {"1", 10}, {"2", 4}, {"13", 3}, {"42", 13}, {"54", 3}, +// }; +// const auto &Hist = Pamm.getHistogram().begin()->second; +// EXPECT_EQ(Hist, Gt); +// } +} // namespace + // main function for the test case int main(int Argc, char **Argv) { ::testing::InitGoogleTest(&Argc, Argv);