318 lines · cpp
1//===- PassTimingInfo.cpp - LLVM Pass Timing Implementation ---------------===//2//3// Part of the LLVM Project, under the Apache License v2.0 with LLVM Exceptions.4// See https://llvm.org/LICENSE.txt for license information.5// SPDX-License-Identifier: Apache-2.0 WITH LLVM-exception6//7//===----------------------------------------------------------------------===//8//9// This file implements the LLVM Pass Timing infrastructure for both10// new and legacy pass managers.11//12// PassTimingInfo Class - This class is used to calculate information about the13// amount of time each pass takes to execute. This only happens when14// -time-passes is enabled on the command line.15//16//===----------------------------------------------------------------------===//17 18#include "llvm/IR/PassTimingInfo.h"19#include "llvm/ADT/Statistic.h"20#include "llvm/IR/PassInstrumentation.h"21#include "llvm/Pass.h"22#include "llvm/Support/CommandLine.h"23#include "llvm/Support/Debug.h"24#include "llvm/Support/FormatVariadic.h"25#include "llvm/Support/ManagedStatic.h"26#include "llvm/Support/Mutex.h"27#include "llvm/Support/TypeName.h"28#include "llvm/Support/raw_ostream.h"29#include <string>30 31using namespace llvm;32 33#define DEBUG_TYPE "time-passes"34 35using namespace llvm;36 37bool llvm::TimePassesIsEnabled = false;38bool llvm::TimePassesPerRun = false;39 40static cl::opt<bool, true> EnableTiming(41 "time-passes", cl::location(TimePassesIsEnabled), cl::Hidden,42 cl::desc("Time each pass, printing elapsed time for each on exit"));43 44static cl::opt<bool, true> EnableTimingPerRun(45 "time-passes-per-run", cl::location(TimePassesPerRun), cl::Hidden,46 cl::desc("Time each pass run, printing elapsed time for each run on exit"),47 cl::callback([](const bool &) { TimePassesIsEnabled = true; }));48 49namespace {50namespace legacy {51 52//===----------------------------------------------------------------------===//53// Legacy pass manager's PassTimingInfo implementation54 55/// Provides an interface for collecting pass timing information.56///57/// It was intended to be generic but now we decided to split58/// interfaces completely. This is now exclusively for legacy-pass-manager use.59class PassTimingInfo {60public:61 using PassInstanceID = void *;62 63private:64 StringMap<unsigned> PassIDCountMap; ///< Map that counts instances of passes65 DenseMap<PassInstanceID, std::unique_ptr<Timer>> TimingData; ///< timers for pass instances66 TimerGroup *PassTG = nullptr;67 68public:69 /// Initializes the static \p TheTimeInfo member to a non-null value when70 /// -time-passes is enabled. Leaves it null otherwise.71 ///72 /// This method may be called multiple times.73 static void init();74 75 /// Prints out timing information and then resets the timers.76 /// By default it uses the stream created by CreateInfoOutputFile().77 void print(raw_ostream *OutStream = nullptr);78 79 /// Returns the timer for the specified pass if it exists.80 Timer *getPassTimer(Pass *, PassInstanceID);81 82 static PassTimingInfo *TheTimeInfo;83 84private:85 Timer *newPassTimer(StringRef PassID, StringRef PassDesc);86};87 88static ManagedStatic<sys::SmartMutex<true>> TimingInfoMutex;89 90void PassTimingInfo::init() {91 if (TheTimeInfo || !TimePassesIsEnabled)92 return;93 94 // Constructed the first time this is called, iff -time-passes is enabled.95 // This guarantees that the object will be constructed after static globals,96 // thus it will be destroyed before them.97 static ManagedStatic<PassTimingInfo> TTI;98 if (!TTI->PassTG)99 TTI->PassTG = &NamedRegionTimer::getNamedTimerGroup(100 TimePassesHandler::PassGroupName, TimePassesHandler::PassGroupDesc);101 TheTimeInfo = &*TTI;102}103 104/// Prints out timing information and then resets the timers.105void PassTimingInfo::print(raw_ostream *OutStream) {106 assert(PassTG && "PassTG is null, did you call PassTimingInfo::Init()?");107 PassTG->print(OutStream ? *OutStream : *CreateInfoOutputFile(), true);108}109 110Timer *PassTimingInfo::newPassTimer(StringRef PassID, StringRef PassDesc) {111 unsigned &num = PassIDCountMap[PassID];112 num++;113 // Appending description with a pass-instance number for all but the first one114 std::string PassDescNumbered =115 num <= 1 ? PassDesc.str() : formatv("{0} #{1}", PassDesc, num).str();116 assert(PassTG && "PassTG is null, did you call PassTimingInfo::Init()?");117 return new Timer(PassID, PassDescNumbered, *PassTG);118}119 120Timer *PassTimingInfo::getPassTimer(Pass *P, PassInstanceID Pass) {121 if (P->getAsPMDataManager())122 return nullptr;123 124 init();125 sys::SmartScopedLock<true> Lock(*TimingInfoMutex);126 std::unique_ptr<Timer> &T = TimingData[Pass];127 128 if (!T) {129 StringRef PassName = P->getPassName();130 StringRef PassArgument;131 if (const PassInfo *PI = Pass::lookupPassInfo(P->getPassID()))132 PassArgument = PI->getPassArgument();133 T.reset(newPassTimer(PassArgument.empty() ? PassName : PassArgument, PassName));134 }135 return T.get();136}137 138PassTimingInfo *PassTimingInfo::TheTimeInfo;139} // namespace legacy140} // namespace141 142Timer *llvm::getPassTimer(Pass *P) {143 legacy::PassTimingInfo::init();144 if (legacy::PassTimingInfo::TheTimeInfo)145 return legacy::PassTimingInfo::TheTimeInfo->getPassTimer(P, P);146 return nullptr;147}148 149/// If timing is enabled, report the times collected up to now and then reset150/// them.151void llvm::reportAndResetTimings(raw_ostream *OutStream) {152 if (legacy::PassTimingInfo::TheTimeInfo)153 legacy::PassTimingInfo::TheTimeInfo->print(OutStream);154}155 156//===----------------------------------------------------------------------===//157// Pass timing handling for the New Pass Manager158//===----------------------------------------------------------------------===//159 160/// Returns the timer for the specified pass invocation of \p PassID.161/// Each time it creates a new timer.162Timer &TimePassesHandler::getPassTimer(StringRef PassID, bool IsPass) {163 TimerGroup &TG = IsPass ? PassTG : AnalysisTG;164 if (!PerRun) {165 TimerVector &Timers = TimingData[PassID];166 if (Timers.size() == 0)167 Timers.emplace_back(new Timer(PassID, PassID, TG));168 return *Timers.front();169 }170 171 // Take a vector of Timers created for this \p PassID and append172 // one more timer to it.173 TimerVector &Timers = TimingData[PassID];174 unsigned Count = Timers.size() + 1;175 176 std::string FullDesc = formatv("{0} #{1}", PassID, Count).str();177 178 Timer *T = new Timer(PassID, FullDesc, TG);179 Timers.emplace_back(T);180 assert(Count == Timers.size() && "Timers vector not adjusted correctly.");181 182 return *T;183}184 185TimePassesHandler::TimePassesHandler(bool Enabled, bool PerRun)186 : Enabled(Enabled), PerRun(PerRun) {}187 188TimePassesHandler::TimePassesHandler()189 : TimePassesHandler(TimePassesIsEnabled, TimePassesPerRun) {}190 191void TimePassesHandler::setOutStream(raw_ostream &Out) {192 OutStream = &Out;193}194 195void TimePassesHandler::print() {196 if (!Enabled)197 return;198 std::unique_ptr<raw_ostream> MaybeCreated;199 raw_ostream *OS = OutStream;200 if (OutStream) {201 OS = OutStream;202 } else {203 MaybeCreated = CreateInfoOutputFile();204 OS = &*MaybeCreated;205 }206 PassTG.print(*OS, true);207 AnalysisTG.print(*OS, true);208}209 210LLVM_DUMP_METHOD void TimePassesHandler::dump() const {211 dbgs() << "Dumping timers for " << getTypeName<TimePassesHandler>()212 << ":\n\tRunning:\n";213 for (auto &I : TimingData) {214 StringRef PassID = I.getKey();215 const TimerVector& MyTimers = I.getValue();216 for (unsigned idx = 0; idx < MyTimers.size(); idx++) {217 const Timer* MyTimer = MyTimers[idx].get();218 if (MyTimer && MyTimer->isRunning())219 dbgs() << "\tTimer " << MyTimer << " for pass " << PassID << "(" << idx << ")\n";220 }221 }222 dbgs() << "\tTriggered:\n";223 for (auto &I : TimingData) {224 StringRef PassID = I.getKey();225 const TimerVector& MyTimers = I.getValue();226 for (unsigned idx = 0; idx < MyTimers.size(); idx++) {227 const Timer* MyTimer = MyTimers[idx].get();228 if (MyTimer && MyTimer->hasTriggered() && !MyTimer->isRunning())229 dbgs() << "\tTimer " << MyTimer << " for pass " << PassID << "(" << idx << ")\n";230 }231 }232}233 234static bool shouldIgnorePass(StringRef PassID) {235 return isSpecialPass(PassID,236 {"PassManager", "PassAdaptor", "AnalysisManagerProxy",237 "ModuleInlinerWrapperPass", "DevirtSCCRepeatedPass"});238}239 240void TimePassesHandler::startPassTimer(StringRef PassID) {241 if (shouldIgnorePass(PassID))242 return;243 // Stop the previous pass timer to prevent double counting when a244 // pass requests another pass.245 if (!PassActiveTimerStack.empty()) {246 assert(PassActiveTimerStack.back()->isRunning());247 PassActiveTimerStack.back()->stopTimer();248 }249 Timer &MyTimer = getPassTimer(PassID, /*IsPass*/ true);250 PassActiveTimerStack.push_back(&MyTimer);251 assert(!MyTimer.isRunning());252 MyTimer.startTimer();253}254 255void TimePassesHandler::stopPassTimer(StringRef PassID) {256 if (shouldIgnorePass(PassID))257 return;258 assert(!PassActiveTimerStack.empty() && "empty stack in popTimer");259 Timer *MyTimer = PassActiveTimerStack.pop_back_val();260 assert(MyTimer && "timer should be present");261 assert(MyTimer->isRunning());262 MyTimer->stopTimer();263 264 // Restart the previously stopped timer.265 if (!PassActiveTimerStack.empty()) {266 assert(!PassActiveTimerStack.back()->isRunning());267 PassActiveTimerStack.back()->startTimer();268 }269}270 271void TimePassesHandler::startAnalysisTimer(StringRef PassID) {272 // Stop the previous analysis timer to prevent double counting when an273 // analysis requests another analysis.274 if (!AnalysisActiveTimerStack.empty()) {275 assert(AnalysisActiveTimerStack.back()->isRunning());276 AnalysisActiveTimerStack.back()->stopTimer();277 }278 279 Timer &MyTimer = getPassTimer(PassID, /*IsPass*/ false);280 AnalysisActiveTimerStack.push_back(&MyTimer);281 if (!MyTimer.isRunning())282 MyTimer.startTimer();283}284 285void TimePassesHandler::stopAnalysisTimer(StringRef PassID) {286 assert(!AnalysisActiveTimerStack.empty() && "empty stack in popTimer");287 Timer *MyTimer = AnalysisActiveTimerStack.pop_back_val();288 assert(MyTimer && "timer should be present");289 if (MyTimer->isRunning())290 MyTimer->stopTimer();291 292 // Restart the previously stopped timer.293 if (!AnalysisActiveTimerStack.empty()) {294 assert(!AnalysisActiveTimerStack.back()->isRunning());295 AnalysisActiveTimerStack.back()->startTimer();296 }297}298 299void TimePassesHandler::registerCallbacks(PassInstrumentationCallbacks &PIC) {300 if (!Enabled)301 return;302 303 PIC.registerBeforeNonSkippedPassCallback(304 [this](StringRef P, Any) { this->startPassTimer(P); });305 PIC.registerAfterPassCallback(306 [this](StringRef P, Any, const PreservedAnalyses &) {307 this->stopPassTimer(P);308 });309 PIC.registerAfterPassInvalidatedCallback(310 [this](StringRef P, const PreservedAnalyses &) {311 this->stopPassTimer(P);312 });313 PIC.registerBeforeAnalysisCallback(314 [this](StringRef P, Any) { this->startAnalysisTimer(P); });315 PIC.registerAfterAnalysisCallback(316 [this](StringRef P, Any) { this->stopAnalysisTimer(P); });317}318