Index: llvm/trunk/include/llvm/IR/PassTimingInfo.h =================================================================== --- llvm/trunk/include/llvm/IR/PassTimingInfo.h +++ llvm/trunk/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" +#include 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,68 @@ /// This is the storage for the -time-passes option. extern bool TimePassesIsEnabled; +/// This class implements -time-passes functionality for new pass manager. +/// It provides the pass-instrumentation callbacks that measure the pass +/// execution time. They collect timing info into individual timers as +/// passes are being run. At the end of its life-time it prints the resulting +/// timing report. +class TimePassesHandler { + /// Value of this type is capable of uniquely identifying pass invocations. + /// It is a pair of string Pass-Identifier (which for now is common + /// to all the instance of a given pass) + sequential invocation counter. + using PassInvocationID = std::pair; + + /// A group of all pass-timing timers. + TimerGroup TG; + + /// Map of timers for pass invocations + DenseMap> TimingData; + + /// Map that counts invocations of passes, for use in UniqPassID construction. + StringMap PassIDCountMap; + + SmallVector TimerStack; //< Stack of currently active timers. + + bool Enabled; + +public: + TimePassesHandler(bool Enabled = TimePassesIsEnabled); + + /// Destructor handles the print action if it has not been handled before. + ~TimePassesHandler() { + // First destroying the timers from TimingData, which deploys all their + // collected data into the TG time group member, which later prints itself + // when being destroyed. + TimingData.clear(); + } + + /// 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; + + void registerCallbacks(PassInstrumentationCallbacks &PIC); + +private: + /// 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); + + /// Returns the incremented counter for the next invocation of \p PassID. + unsigned nextPassID(StringRef PassID) { return ++PassIDCountMap[PassID]; } + + void startTimer(StringRef PassID); + void stopTimer(StringRef PassID); + + // Implementation of pass instrumentation callbacks. + bool runBeforePass(StringRef PassID, Any IR); + void runAfterPass(StringRef PassID, Any IR); +}; + } // namespace llvm #endif Index: llvm/trunk/include/llvm/Passes/StandardInstrumentations.h =================================================================== --- llvm/trunk/include/llvm/Passes/StandardInstrumentations.h +++ llvm/trunk/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: llvm/trunk/lib/IR/PassTimingInfo.cpp =================================================================== --- llvm/trunk/lib/IR/PassTimingInfo.cpp +++ llvm/trunk/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" @@ -33,6 +34,8 @@ using namespace llvm; +#define DEBUG_TYPE "time-passes" + namespace llvm { bool TimePassesIsEnabled = false; @@ -45,7 +48,7 @@ namespace legacy { //===----------------------------------------------------------------------===// -// TimingInfo implementation +// Legacy pass manager's PassTimingInfo implementation /// Provides an interface for collecting pass timing information. /// @@ -156,4 +159,108 @@ 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 &TimePassesHandler::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(); + + PassInvocationID UID{PassID, Count}; + Timer *T = new Timer(PassID, FullDesc, TG); + auto Pair = TimingData.try_emplace(UID, T); + assert(Pair.second && "should always create a new timer"); + return *(Pair.first->second.get()); +} + +TimePassesHandler::TimePassesHandler(bool Enabled) + : TG("pass", "... Pass execution timing report ..."), Enabled(Enabled) {} + +void TimePassesHandler::print() { TG.print(*CreateInfoOutputFile()); } + +LLVM_DUMP_METHOD void TimePassesHandler::dump() const { + dbgs() << "Dumping timers for " << getTypeName() + << ":\n\tRunning:\n"; + for (auto &I : TimingData) { + const Timer *MyTimer = I.second.get(); + if (!MyTimer || MyTimer->isRunning()) + dbgs() << "\tTimer " << MyTimer << " for pass " << I.first.first << "(" + << I.first.second << ")\n"; + } + dbgs() << "\tTriggered:\n"; + for (auto &I : TimingData) { + const Timer *MyTimer = I.second.get(); + if (!MyTimer || (MyTimer->hasTriggered() && !MyTimer->isRunning())) + dbgs() << "\tTimer " << MyTimer << " for pass " << I.first.first << "(" + << I.first.second << ")\n"; + } +} + +void TimePassesHandler::startTimer(StringRef PassID) { + Timer &MyTimer = getPassTimer(PassID); + 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(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(dump()); +} + +void TimePassesHandler::registerCallbacks(PassInstrumentationCallbacks &PIC) { + if (!Enabled) + return; + + 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: llvm/trunk/lib/Passes/StandardInstrumentations.cpp =================================================================== --- llvm/trunk/lib/Passes/StandardInstrumentations.cpp +++ llvm/trunk/lib/Passes/StandardInstrumentations.cpp @@ -112,4 +112,5 @@ PIC.registerBeforePassCallback(PrintIR::printBeforePass); if (llvm::shouldPrintAfterPass()) PIC.registerAfterPassCallback(PrintIR::printAfterPass); + TimePasses.registerCallbacks(PIC); } Index: llvm/trunk/test/Other/time-passes.ll =================================================================== --- llvm/trunk/test/Other/time-passes.ll +++ llvm/trunk/test/Other/time-passes.ll @@ -1,5 +1,8 @@ ; 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 +; RUN: opt < %s -disable-output -passes='default' -time-passes 2>&1 | FileCheck %s --check-prefix=TIME ; ; TIME: Pass execution timing report ; TIME: Total Execution Time: @@ -7,7 +10,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 +19,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() {