Index: include/llvm/IR/PassTimingInfo.h =================================================================== --- include/llvm/IR/PassTimingInfo.h +++ include/llvm/IR/PassTimingInfo.h @@ -9,7 +9,7 @@ /// \file /// /// This header defines classes/functions to handle pass execution timing -/// information with an interface suitable for both pass managers. +/// information with an interfaces for both pass managers. /// //===----------------------------------------------------------------------===// @@ -17,8 +17,10 @@ #define LLVM_IR_PASSTIMINGINFO_H #include "llvm/ADT/DenseMap.h" +#include "llvm/ADT/SmallPtrSet.h" #include "llvm/ADT/StringMap.h" #include "llvm/ADT/StringRef.h" +#include "llvm/IR/PassInstrumentation.h" #include "llvm/Support/Timer.h" #include @@ -27,9 +29,13 @@ class Pass; class TimerGroup; -/// Provides a generic interface for collecting pass timing information. -/// Legacy pass managers should specialize with \p PassInfo*. -/// New pass managers should specialize with \p StringRef. +/// Provides an interface for collecting pass timing information. +/// +/// It was intended to be generic but now we decided to split +/// interfaces completely. +/// Legacy pass managers should specialize this with \p Pass*. +/// New pass managers should use a separate explicit specialization +/// with StringRef. template class PassTimingInfo { public: using PassInstanceID = void *; @@ -66,13 +72,88 @@ }; Timer *getPassTimer(Pass *); -Timer *getPassTimer(StringRef); /// If the user specifies the -time-passes argument on an LLVM tool command line /// then the value of this boolean will be true, otherwise false. /// This is the storage for the -time-passes option. extern bool TimePassesIsEnabled; +/// Specialization of PassTimingInfo specifically for the new pass manager. +/// Unlike legacy it is not managed as a global singleton but instead +/// is owned by TimePassesHandler. +template <> +class PassTimingInfo { + public: + /// Value of this type is capable of uniquely identifying pass invocations. + using UniqPassID = std::pair; + +private: + DenseMap TimingData; ///< Map of timers for pass invocations + StringMap PassIDCountMap;///< Map that counts invocations of passes + + TimerGroup TG; ///< A group of all pass-timing timers. + +public: + /// Default initialization, intended to be called from the TimePassesCallbacks. + /// Prepares timing group for action. + PassTimingInfo(); + + /// Print out timing information and release timers. + ~PassTimingInfo(); + + /// Prints out timing information and then resets the timers. + void print(); + + /// Dumps information for running/triggered timers, useful for debugging + LLVM_DUMP_METHOD void dump() const; + + /// Returns the new timer for each new run of the pass. + Timer *getPassTimer(StringRef PassID); + +private: + unsigned nextPassID(StringRef PassID) { + return ++PassIDCountMap[PassID]; + } +}; + +class TimePassesHandler { + bool Enabled; + +public: + /// do not initialize timing info for starters + TimePassesHandler(bool Enabled = TimePassesIsEnabled) : Enabled(Enabled) { } + + /// Destructor handles the print action if it has not been handled before. + ~TimePassesHandler(); + + /// Prints out timing information and then resets the timers. + void print(); + + // We intend this to be unique per-compilation, thus no copies. + TimePassesHandler(const TimePassesHandler &) = delete; + void operator=(const TimePassesHandler &) = delete; + + /// Setup timing info and register callbacks. + void registerCallbacks(PassInstrumentationCallbacks& PIC); + +private: + // Implementation of timer callbacks. + bool runBeforePass(StringRef PassID, Any IR); + void runAfterPass(StringRef PassID, Any IR); + + // timer helpers + Timer *pushTimer(StringRef PassID); + Timer *popTimer(StringRef PassID); + void startTimer(StringRef PassID); + void stopTimer(StringRef PassID); + + static bool matchPassManager(StringRef PassID); + + SmallVector TimerStack; //< Stack of currently active timers. + + std::unique_ptr> TimingInfo; +}; + } // namespace llvm #endif Index: include/llvm/Passes/PassBuilder.h =================================================================== --- include/llvm/Passes/PassBuilder.h +++ include/llvm/Passes/PassBuilder.h @@ -19,6 +19,7 @@ #include "llvm/ADT/Optional.h" #include "llvm/Analysis/CGSCCPassManager.h" #include "llvm/IR/PassManager.h" +#include "llvm/IR/PassTimingInfo.h" #include "llvm/Transforms/Instrumentation.h" #include "llvm/Transforms/Scalar/LoopPassManager.h" #include Index: lib/IR/PassTimingInfo.cpp =================================================================== --- lib/IR/PassTimingInfo.cpp +++ lib/IR/PassTimingInfo.cpp @@ -32,6 +32,8 @@ using namespace llvm; +#define DEBUG_TYPE "time-passes" + namespace llvm { //===----------------------------------------------------------------------===// @@ -84,20 +86,6 @@ return new Timer(PassID, PassDescNumbered, TG); } -/// Returns the timer for the specified pass instance \p Pass. -/// Instances of the same pass type (uniquely identified by \p PassID) are -/// numbered by the order of appearance. -template <> -Timer *PassTimingInfo::getPassTimer(StringRef PassID, - PassInstanceID Pass) { - init(); - sys::SmartScopedLock Lock(*TimingInfoMutex); - Timer *&T = TimingData[Pass]; - if (!T) - T = newPassTimer(PassID, PassID); - return T; -} - template <> Timer *PassTimingInfo::getPassTimer(Pass *P, PassInstanceID Pass) { if (P->getAsPMDataManager()) @@ -121,7 +109,6 @@ PassTimingInfo *PassTimingInfo::TheTimeInfo; template class PassTimingInfo; -template class PassTimingInfo; Timer *getPassTimer(Pass *P) { PassTimingInfo::init(); @@ -130,21 +117,142 @@ return nullptr; } -Timer *getPassTimer(StringRef PassName) { - PassTimingInfo::init(); - if (PassTimingInfo::TheTimeInfo) - return PassTimingInfo::TheTimeInfo->getPassTimer(PassName, - nullptr); - return nullptr; -} - /// If timing is enabled, report the times collected up to now and then reset /// them. void reportAndResetTimings() { - if (PassTimingInfo::TheTimeInfo) - PassTimingInfo::TheTimeInfo->print(); if (PassTimingInfo::TheTimeInfo) PassTimingInfo::TheTimeInfo->print(); } + +//===----------------------------------------------------------------------===// +// Pass timing handling for the New Pass Manager +//===----------------------------------------------------------------------===// + + +/// Returns the timer for the specified pass invocation of \p PassID. +/// Each time it creates a new timer. +Timer *PassTimingInfo::getPassTimer(StringRef PassID) { + // Bump counts for each request of the timer. + unsigned Count = nextPassID(PassID); + + // Unconditionally appending description with a pass-invocation number. + std::string FullDesc = formatv("{0} #{1}", PassID, Count).str(); + Timer* T = new Timer(PassID, FullDesc, TG); + + UniqPassID UID{PassID, Count}; + TimingData[UID] = T; + return T; +} + +PassTimingInfo::PassTimingInfo() + : TG("pass", "... Pass execution timing report ...") {} + +PassTimingInfo::~PassTimingInfo() { + // Deleting the timers accumulates their info into the TG member. + // Then TG member is (implicitly) deleted, actually printing the report. + for (auto &I : TimingData) + delete I.getSecond(); +} + +void PassTimingInfo::print() { + TG.print(*CreateInfoOutputFile()); +} + +LLVM_DUMP_METHOD void PassTimingInfo::dump() const { + dbgs() << "Dumping timers for " << getTypeName() <<":\n\tRunning:\n"; + for (auto &I : TimingData) { + Timer *MyTimer = I.getSecond(); + if (MyTimer->isRunning()) + dbgs() << "\tTimer " << MyTimer << " for pass " << I.getFirst().first + << "(" << I.getFirst().second << ")\n"; + } + dbgs() << "\tTriggered:\n"; + for (auto &I : TimingData) { + Timer *MyTimer = I.getSecond(); + if (MyTimer->hasTriggered() && !MyTimer->isRunning()) + dbgs() << "\tTimer " << MyTimer << " for pass " << I.getFirst().first + << "(" << I.getFirst().second << ")\n"; + } +} + +TimePassesHandler::~TimePassesHandler() { + // While deleting TimingInfo it prints timing report +} + +void TimePassesHandler::print() { + TimingInfo->print(); +} + +Timer *TimePassesHandler::pushTimer(StringRef PassID) { + assert(TimingInfo && "timing info has to be initialized"); + Timer* T = TimingInfo->getPassTimer(PassID); + TimerStack.push_back(T); + return T; +} + +Timer *TimePassesHandler::popTimer(StringRef PassID) { + assert(TimerStack.size() > 0 && "empty stack in popTimer"); + return TimerStack.pop_back_val(); +} + +void TimePassesHandler::startTimer(StringRef PassID) { + Timer *MyTimer = pushTimer(PassID); + assert(MyTimer && "timer should be present"); + if (!MyTimer->isRunning()) + MyTimer->startTimer(); +} + +void TimePassesHandler::stopTimer(StringRef PassID) { + Timer *MyTimer = popTimer(PassID); + assert(MyTimer && "timer should be present"); + if (MyTimer->isRunning()) + MyTimer->stopTimer(); +} + +bool TimePassesHandler::matchPassManager(StringRef PassID) { + size_t prefix_pos = PassID.find('<'); + if (prefix_pos == StringRef::npos) + return false; + StringRef Prefix = PassID.substr(0, prefix_pos); + return Prefix.endswith("PassManager") || Prefix.endswith("PassAdaptor") || + Prefix.endswith("AnalysisManagerProxy"); +} + +bool TimePassesHandler::runBeforePass(StringRef PassID, Any IR) { + if (matchPassManager(PassID)) + return true; + + startTimer(PassID); + + LLVM_DEBUG(dbgs() << "after runBeforePass(" << PassID << ")\n"); + LLVM_DEBUG(TimingInfo->dump()); + + // we are not going to skip this pass, thus return true. + return true; +} + +void TimePassesHandler::runAfterPass(StringRef PassID, Any IR) { + if (matchPassManager(PassID)) + return; + + stopTimer(PassID); + + LLVM_DEBUG(dbgs() << "after runAfterPass(" << PassID << ")\n"); + LLVM_DEBUG(TimingInfo->dump()); +} + +void TimePassesHandler::registerCallbacks(PassInstrumentationCallbacks& PIC) { + if (!Enabled) + return; + + assert(!TimingInfo && "timing info should be empty before setup"); + TimingInfo.reset(new PassTimingInfo()); + + PIC.registerBeforePassCallback([this](StringRef P, Any IR) { return this->runBeforePass(P, IR); }); + PIC.registerAfterPassCallback([this](StringRef P, Any IR) { this->runAfterPass(P, IR); }); + PIC.registerBeforeAnalysisCallback([this](StringRef P, Any IR) { this->runBeforePass(P, IR); }); + PIC.registerAfterAnalysisCallback([this](StringRef P, Any IR) { this->runAfterPass(P, IR); }); +} + } // namespace llvm Index: lib/Passes/PassBuilder.cpp =================================================================== --- lib/Passes/PassBuilder.cpp +++ lib/Passes/PassBuilder.cpp @@ -57,6 +57,7 @@ #include "llvm/IR/Dominators.h" #include "llvm/IR/IRPrintingPasses.h" #include "llvm/IR/PassManager.h" +#include "llvm/IR/PassTimingInfo.h" #include "llvm/IR/Verifier.h" #include "llvm/Support/Debug.h" #include "llvm/Support/Regex.h" Index: test/Other/time-passes.ll =================================================================== --- test/Other/time-passes.ll +++ test/Other/time-passes.ll @@ -1,5 +1,7 @@ ; RUN: opt < %s -disable-output -instcombine -instcombine -licm -time-passes 2>&1 | FileCheck %s --check-prefix=TIME --check-prefix=TIME-LEGACY -; RUN: opt < %s -disable-output -instcombine -instcombine -licm -licm -time-passes 2>&1 | FileCheck %s --check-prefix=TIME --check-prefix=TIME-LEGACY --check-prefix=TIME-DOUBLE-LICM +; RUN: opt < %s -disable-output -instcombine -instcombine -licm -licm -time-passes 2>&1 | FileCheck %s --check-prefix=TIME --check-prefix=TIME-LEGACY --check-prefix=TIME-DOUBLE-LICM-LEGACY +; RUN: opt < %s -disable-output -passes='instcombine,instcombine,loop(licm)' -time-passes 2>&1 | FileCheck %s --check-prefix=TIME --check-prefix=TIME-NEW +; RUN: opt < %s -disable-output -passes='instcombine,loop(licm),instcombine,loop(licm)' -time-passes 2>&1 | FileCheck %s --check-prefix=TIME --check-prefix=TIME-NEW -check-prefix=TIME-DOUBLE-LICM-NEW ; ; TIME: Pass execution timing report ; TIME: Total Execution Time: @@ -7,7 +9,7 @@ ; TIME-LEGACY-DAG: Combine redundant instructions{{$}} ; TIME-LEGACY-DAG: Combine redundant instructions #2 ; TIME-LEGACY-DAG: Loop Invariant Code Motion{{$}} -; TIME-DOUBLE-LICM-DAG: Loop Invariant Code Motion #2 +; TIME-DOUBLE-LICM-LEGACY-DAG: Loop Invariant Code Motion #2 ; TIME-LEGACY-DAG: Scalar Evolution Analysis ; TIME-LEGACY-DAG: Loop-Closed SSA Form Pass ; TIME-LEGACY-DAG: LCSSA Verifier @@ -16,6 +18,23 @@ ; TIME-LEGACY-DAG: Dominator Tree Construction ; TIME-LEGACY-DAG: Module Verifier ; TIME-LEGACY-DAG: Target Library Information +; TIME-NEW-DAG: InstCombinePass #1 +; TIME-NEW-DAG: InstCombinePass #2 +; TIME-NEW-DAG: InstCombinePass #3 +; TIME-NEW-DAG: InstCombinePass #4 +; TIME-NEW-DAG: LICMPass #1 +; TIME-NEW-DAG: LICMPass #2 +; TIME-NEW-DAG: LICMPass #3 +; TIME-DOUBLE-LICM-NEW-DAG: LICMPass #4 +; TIME-DOUBLE-LICM-NEW-DAG: LICMPass #5 +; TIME-DOUBLE-LICM-NEW-DAG: LICMPass #6 +; TIME-NEW-DAG: LCSSAPass +; TIME-NEW-DAG: LoopSimplifyPass +; TIME-NEW-DAG: ScalarEvolutionAnalysis +; TIME-NEW-DAG: LoopAnalysis +; TIME-NEW-DAG: VerifierPass +; TIME-NEW-DAG: DominatorTreeAnalysis +; TIME-NEW-DAG: TargetLibraryAnalysis ; TIME: Total{{$}} define i32 @foo() { Index: tools/opt/NewPMDriver.cpp =================================================================== --- tools/opt/NewPMDriver.cpp +++ tools/opt/NewPMDriver.cpp @@ -219,6 +219,8 @@ PIC.registerBeforePassCallback(PrintIR::printBeforePass); if (llvm::shouldPrintAfterPass()) PIC.registerAfterPassCallback(PrintIR::printAfterPass); + TimePassesHandler TimePasses; + TimePasses.registerCallbacks(PIC); PassBuilder PB(TM, P, &PIC); registerEPCallbacks(PB, VerifyEachPass, DebugPM);