Index: include/llvm/IR/PassTimingInfo.h =================================================================== --- include/llvm/IR/PassTimingInfo.h +++ include/llvm/IR/PassTimingInfo.h @@ -9,17 +9,24 @@ /// \file /// /// This header defines classes/functions to handle pass execution timing -/// information with an interface suitable for both pass managers. +/// information with interfaces for both pass managers. /// //===----------------------------------------------------------------------===// #ifndef LLVM_IR_PASSTIMINGINFO_H #define LLVM_IR_PASSTIMINGINFO_H +#include "llvm/ADT/Any.h" +#include "llvm/ADT/DenseMap.h" +#include "llvm/ADT/StringMap.h" +#include "llvm/ADT/StringRef.h" +#include "llvm/Support/Timer.h" +#include "llvm/Support/TypeName.h" + namespace llvm { class Pass; -class Timer; +class PassInstrumentationCallbacks; /// If -time-passes has been specified, report the timings immediately and then /// reset the timers to zero. @@ -33,6 +40,75 @@ /// This is the storage for the -time-passes option. extern bool TimePassesIsEnabled; +/// Pass Timing info specifically for the new pass manager. +/// Intended to be owned by TimePassesHandler. +class PassTiming { +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. + PassTiming(); + + /// Print out timing information and release timers. + ~PassTiming(); + + /// 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 + void startTimer(StringRef PassID); + void stopTimer(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: include/llvm/Passes/StandardInstrumentations.h =================================================================== --- include/llvm/Passes/StandardInstrumentations.h +++ include/llvm/Passes/StandardInstrumentations.h @@ -17,13 +17,15 @@ #define LLVM_PASSES_STANDARDINSTRUMENTATIONS_H #include "llvm/IR/PassInstrumentation.h" +#include "llvm/IR/PassTimingInfo.h" namespace llvm { /// This class provides an interface to register all the standard pass /// instrumentations and manages their state (if any). class StandardInstrumentations { - // for now we do not have instrumentations with state + TimePassesHandler TimePasses; + public: StandardInstrumentations() = default; Index: lib/IR/PassTimingInfo.cpp =================================================================== --- lib/IR/PassTimingInfo.cpp +++ lib/IR/PassTimingInfo.cpp @@ -20,6 +20,7 @@ #include "llvm/ADT/DenseMap.h" #include "llvm/ADT/Statistic.h" #include "llvm/ADT/StringRef.h" +#include "llvm/IR/PassInstrumentation.h" #include "llvm/Pass.h" #include "llvm/Support/CommandLine.h" #include "llvm/Support/Debug.h" @@ -32,6 +33,8 @@ using namespace llvm; +#define DEBUG_TYPE "time-passes" + namespace llvm { bool TimePassesIsEnabled = false; @@ -139,6 +142,7 @@ } PassTimingInfo *PassTimingInfo::TheTimeInfo; + } // namespace legacy } // namespace @@ -156,4 +160,120 @@ legacy::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 *PassTiming::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; +} + +PassTiming::PassTiming() + : TG("pass", "... Pass execution timing report ...") {} + +PassTiming::~PassTiming() { + // 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 PassTiming::print() { TG.print(*CreateInfoOutputFile()); } + +LLVM_DUMP_METHOD void PassTiming::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"; + } +} + +void TimePassesHandler::print() { TimingInfo->print(); } + +void TimePassesHandler::startTimer(StringRef PassID) { + Timer *MyTimer = TimingInfo->getPassTimer(PassID); + assert(MyTimer && "timer should be present"); + TimerStack.push_back(MyTimer); + if (!MyTimer->isRunning()) + MyTimer->startTimer(); +} + +void TimePassesHandler::stopTimer(StringRef PassID) { + assert(TimerStack.size() > 0 && "empty stack in popTimer"); + Timer *MyTimer = TimerStack.pop_back_val(); + assert(MyTimer && "timer should be present"); + if (MyTimer->isRunning()) + MyTimer->stopTimer(); +} + +static bool 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 PassTiming()); + + 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 @@ -56,6 +56,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: lib/Passes/StandardInstrumentations.cpp =================================================================== --- lib/Passes/StandardInstrumentations.cpp +++ lib/Passes/StandardInstrumentations.cpp @@ -108,8 +108,12 @@ void StandardInstrumentations::registerCallbacks( PassInstrumentationCallbacks &PIC) { + // print-before instrumentation if (llvm::shouldPrintBeforePass()) PIC.registerBeforePassCallback(PrintIR::printBeforePass); + // print-after instrumentation if (llvm::shouldPrintAfterPass()) PIC.registerAfterPassCallback(PrintIR::printAfterPass); + // time-passes instrumentation + TimePasses.registerCallbacks(PIC); } 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() {