From f2d4372e0e660720bbe4d1d266da2cf783868666 Mon Sep 17 00:00:00 2001 From: Fedor Sergeev Date: Tue, 4 Sep 2018 06:12:28 +0000 Subject: [PATCH] [PassTiming] reporting time-passes separately for multiple pass instances of the same pass Summary: Refactoring done by rL340872 accidentally appeared to be non-NFC, changing the way how multiple instances of the same pass are handled - aggregation of results by PassName forced data for multiple instances to be merged together and reported as one line. Getting back to creating/reporting timers per pass instance. Reporting was a bit enhanced by counting pass instances and adding # suffix to the pass description. Note that it is instances that are being counted, not invocations of them. time-passes test updated to account for multiple passes being run. Reviewers: paquette, jhenderson, MatzeB, skatkov Reviewed By: skatkov Subscribers: llvm-commits Differential Revision: https://reviews.llvm.org/D51535 llvm-svn: 341346 --- llvm/include/llvm/IR/PassTimingInfo.h | 13 +++++++-- llvm/lib/IR/PassTimingInfo.cpp | 42 +++++++++++++++++++-------- llvm/test/Other/time-passes.ll | 26 ++++++++++++++++- 3 files changed, 66 insertions(+), 15 deletions(-) diff --git a/llvm/include/llvm/IR/PassTimingInfo.h b/llvm/include/llvm/IR/PassTimingInfo.h index 5f3bdcd02cef..e02a4179c912 100644 --- a/llvm/include/llvm/IR/PassTimingInfo.h +++ b/llvm/include/llvm/IR/PassTimingInfo.h @@ -16,6 +16,7 @@ #ifndef LLVM_IR_PASSTIMINGINFO_H #define LLVM_IR_PASSTIMINGINFO_H +#include "llvm/ADT/DenseMap.h" #include "llvm/ADT/StringMap.h" #include "llvm/ADT/StringRef.h" #include "llvm/Support/Timer.h" @@ -30,7 +31,12 @@ class TimerGroup; /// Legacy pass managers should specialize with \p PassInfo*. /// New pass managers should specialize with \p StringRef. template class PassTimingInfo { - StringMap TimingData; +public: + using PassInstanceID = void *; + +private: + StringMap PassIDCountMap; ///< Map that counts instances of passes + DenseMap TimingData; ///< timers for pass instances TimerGroup TG; public: @@ -51,9 +57,12 @@ public: void print(); /// Returns the timer for the specified pass if it exists. - Timer *getPassTimer(PassInfoT); + Timer *getPassTimer(PassInfoT, PassInstanceID); static PassTimingInfo *TheTimeInfo; + +private: + Timer *newPassTimer(StringRef PassID, StringRef PassDesc); }; Timer *getPassTimer(Pass *); diff --git a/llvm/lib/IR/PassTimingInfo.cpp b/llvm/lib/IR/PassTimingInfo.cpp index c1efc651b7eb..56e02ef37172 100644 --- a/llvm/lib/IR/PassTimingInfo.cpp +++ b/llvm/lib/IR/PassTimingInfo.cpp @@ -23,6 +23,7 @@ #include "llvm/Pass.h" #include "llvm/Support/CommandLine.h" #include "llvm/Support/Debug.h" +#include "llvm/Support/FormatVariadic.h" #include "llvm/Support/ManagedStatic.h" #include "llvm/Support/Mutex.h" #include "llvm/Support/Timer.h" @@ -53,7 +54,7 @@ template 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.getValue(); + delete I.getSecond(); } template void PassTimingInfo::init() { @@ -61,7 +62,7 @@ template void PassTimingInfo::init() { return; // Constructed the first time this is called, iff -time-passes is enabled. - // This guarantees that the object will be constructed before static globals, + // This guarantees that the object will be constructed after static globals, // thus it will be destroyed before them. static ManagedStatic TTI; TheTimeInfo = &*TTI; @@ -72,30 +73,46 @@ template void PassTimingInfo::print() { TG.print(*CreateInfoOutputFile()); } -/// Return the timer for the specified pass if it exists. -template <> Timer *PassTimingInfo::getPassTimer(StringRef PassName) { +template +Timer *PassTimingInfo::newPassTimer(StringRef PassID, + StringRef PassDesc) { + unsigned &num = PassIDCountMap[PassID]; + num++; + // Appending description with a pass-instance number for all but the first one + std::string PassDescNumbered = + num <= 1 ? PassDesc.str() : formatv("{0} #{1}", PassDesc, num).str(); + 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[PassName]; + Timer *&T = TimingData[Pass]; if (!T) - T = new Timer(PassName, PassName, TG); + T = newPassTimer(PassID, PassID); return T; } -template <> Timer *PassTimingInfo::getPassTimer(Pass *P) { +template <> +Timer *PassTimingInfo::getPassTimer(Pass *P, PassInstanceID Pass) { if (P->getAsPMDataManager()) return nullptr; init(); sys::SmartScopedLock Lock(*TimingInfoMutex); - StringRef PassName = P->getPassName(); - Timer *&T = TimingData[PassName]; + Timer *&T = TimingData[Pass]; if (!T) { + StringRef PassName = P->getPassName(); StringRef PassArgument; if (const PassInfo *PI = Pass::lookupPassInfo(P->getPassID())) PassArgument = PI->getPassArgument(); - T = new Timer(PassArgument.empty() ? PassName : PassArgument, PassName, TG); + T = newPassTimer(PassArgument.empty() ? PassName : PassArgument, PassName); } return T; } @@ -109,14 +126,15 @@ template class PassTimingInfo; Timer *getPassTimer(Pass *P) { PassTimingInfo::init(); if (PassTimingInfo::TheTimeInfo) - return PassTimingInfo::TheTimeInfo->getPassTimer(P); + return PassTimingInfo::TheTimeInfo->getPassTimer(P, P); return nullptr; } Timer *getPassTimer(StringRef PassName) { PassTimingInfo::init(); if (PassTimingInfo::TheTimeInfo) - return PassTimingInfo::TheTimeInfo->getPassTimer(PassName); + return PassTimingInfo::TheTimeInfo->getPassTimer(PassName, + nullptr); return nullptr; } diff --git a/llvm/test/Other/time-passes.ll b/llvm/test/Other/time-passes.ll index b8322ed1394c..b53c28485d84 100644 --- a/llvm/test/Other/time-passes.ll +++ b/llvm/test/Other/time-passes.ll @@ -1,9 +1,18 @@ -; RUN: opt < %s -disable-output -instcombine -time-passes 2>&1 | FileCheck %s --check-prefix=TIME --check-prefix=TIME-LEGACY +; 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 ; ; TIME: Pass execution timing report ; TIME: Total Execution Time: ; TIME: Name ; 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-LEGACY-DAG: Scalar Evolution Analysis +; TIME-LEGACY-DAG: Loop-Closed SSA Form Pass +; TIME-LEGACY-DAG: LCSSA Verifier +; TIME-LEGACY-DAG: Canonicalize natural loops +; TIME-LEGACY-DAG: Natural Loop Information ; TIME-LEGACY-DAG: Dominator Tree Construction ; TIME-LEGACY-DAG: Module Verifier ; TIME-LEGACY-DAG: Target Library Information @@ -11,5 +20,20 @@ define i32 @foo() { %res = add i32 5, 4 + br label %loop1 +loop1: + br i1 false, label %loop1, label %end +end: ret i32 %res } + +define void @bar_with_loops() { + br label %loop1 +loop1: + br i1 false, label %loop1, label %loop2 +loop2: + br i1 true, label %loop2, label %end +end: + ret void + +}