lib/IR/PassTimingInfo.cpp

   1 //===- PassTimingInfo.cpp - LLVM Pass Timing Implementation ---------------===//
   2 //
   3 //                     The LLVM Compiler Infrastructure
   4 //
   5 // This file is distributed under the University of Illinois Open Source
   6 // License. See LICENSE.TXT for details.
   7 //
   8 //===----------------------------------------------------------------------===//
   9 //
  10 // This file implements the LLVM Pass Timing infrastructure for both
  11 // new and legacy pass managers.
  12 //
  13 // PassTimingInfo Class - This class is used to calculate information about the
  14 // amount of time each pass takes to execute.  This only happens when
  15 // -time-passes is enabled on the command line.
  16 //
  17 //===----------------------------------------------------------------------===//
  18
  19 #include "llvm/IR/PassTimingInfo.h"
  20 #include "llvm/ADT/DenseMap.h"
  21 #include "llvm/ADT/Statistic.h"
  22 #include "llvm/ADT/StringRef.h"
  23 #include "llvm/IR/PassInstrumentation.h"
  24 #include "llvm/Pass.h"
  25 #include "llvm/Support/CommandLine.h"
  26 #include "llvm/Support/Debug.h"
  27 #include "llvm/Support/FormatVariadic.h"
  28 #include "llvm/Support/ManagedStatic.h"
  29 #include "llvm/Support/Mutex.h"
  30 #include "llvm/Support/Timer.h"
  31 #include "llvm/Support/raw_ostream.h"
  32 #include <memory>
  33 #include <string>
  34
  35 using namespace llvm;
  36
  37 #define DEBUG_TYPE "time-passes"
  38
  39 namespace llvm {
  40
  41 bool TimePassesIsEnabled = false;
  42
  43 static cl::opt<bool, true> EnableTiming(
  44     "time-passes", cl::location(TimePassesIsEnabled), cl::Hidden,
  45     cl::desc("Time each pass, printing elapsed time for each on exit"));
  46
  47 namespace {
  48 namespace legacy {
  49
  50 //===----------------------------------------------------------------------===//
  51 // Legacy pass manager's PassTimingInfo implementation
  52
  53 /// Provides an interface for collecting pass timing information.
  54 ///
  55 /// It was intended to be generic but now we decided to split
  56 /// interfaces completely. This is now exclusively for legacy-pass-manager use.
  57 class PassTimingInfo {
  58 public:
  59   using PassInstanceID = void *;
  60
  61 private:
  62   StringMap<unsigned> PassIDCountMap; ///< Map that counts instances of passes
  63   DenseMap<PassInstanceID, std::unique_ptr<Timer>> TimingData; ///< timers for pass instances
  64   TimerGroup TG;
  65
  66 public:
  67   /// Default constructor for yet-inactive timeinfo.
  68   /// Use \p init() to activate it.
  69   PassTimingInfo();
  70
  71   /// Print out timing information and release timers.
  72   ~PassTimingInfo();
  73
  74   /// Initializes the static \p TheTimeInfo member to a non-null value when
  75   /// -time-passes is enabled. Leaves it null otherwise.
  76   ///
  77   /// This method may be called multiple times.
  78   static void init();
  79
  80   /// Prints out timing information and then resets the timers.
  81   void print();
  82
  83   /// Returns the timer for the specified pass if it exists.
  84   Timer *getPassTimer(Pass *, PassInstanceID);
  85
  86   static PassTimingInfo *TheTimeInfo;
  87
  88 private:
  89   Timer *newPassTimer(StringRef PassID, StringRef PassDesc);
  90 };
  91
  92 static ManagedStatic<sys::SmartMutex<true>> TimingInfoMutex;
  93
  94 PassTimingInfo::PassTimingInfo()
  95     : TG("pass", "... Pass execution timing report ...") {}
  96
  97 PassTimingInfo::~PassTimingInfo() {
  98   // Deleting the timers accumulates their info into the TG member.
  99   // Then TG member is (implicitly) deleted, actually printing the report.
 100   TimingData.clear();
 101 }
 102
 103 void PassTimingInfo::init() {
 104   if (!TimePassesIsEnabled || TheTimeInfo)
 105     return;
 106
 107   // Constructed the first time this is called, iff -time-passes is enabled.
 108   // This guarantees that the object will be constructed after static globals,
 109   // thus it will be destroyed before them.
 110   static ManagedStatic<PassTimingInfo> TTI;
 111   TheTimeInfo = &*TTI;
 112 }
 113
 114 /// Prints out timing information and then resets the timers.
 115 void PassTimingInfo::print() { TG.print(*CreateInfoOutputFile()); }
 116
 117 Timer *PassTimingInfo::newPassTimer(StringRef PassID, StringRef PassDesc) {
 118   unsigned &num = PassIDCountMap[PassID];
 119   num++;
 120   // Appending description with a pass-instance number for all but the first one
 121   std::string PassDescNumbered =
 122       num <= 1 ? PassDesc.str() : formatv("{0} #{1}", PassDesc, num).str();
 123   return new Timer(PassID, PassDescNumbered, TG);
 124 }
 125
 126 Timer *PassTimingInfo::getPassTimer(Pass *P, PassInstanceID Pass) {
 127   if (P->getAsPMDataManager())
 128     return nullptr;
 129
 130   init();
 131   sys::SmartScopedLock<true> Lock(*TimingInfoMutex);
 132   std::unique_ptr<Timer> &T = TimingData[Pass];
 133
 134   if (!T) {
 135     StringRef PassName = P->getPassName();
 136     StringRef PassArgument;
 137     if (const PassInfo *PI = Pass::lookupPassInfo(P->getPassID()))
 138       PassArgument = PI->getPassArgument();
 139     T.reset(newPassTimer(PassArgument.empty() ? PassName : PassArgument, PassName));
 140   }
 141   return T.get();
 142 }
 143
 144 PassTimingInfo *PassTimingInfo::TheTimeInfo;
 145 } // namespace legacy
 146 } // namespace
 147
 148 Timer *getPassTimer(Pass *P) {
 149   legacy::PassTimingInfo::init();
 150   if (legacy::PassTimingInfo::TheTimeInfo)
 151     return legacy::PassTimingInfo::TheTimeInfo->getPassTimer(P, P);
 152   return nullptr;
 153 }
 154
 155 /// If timing is enabled, report the times collected up to now and then reset
 156 /// them.
 157 void reportAndResetTimings() {
 158   if (legacy::PassTimingInfo::TheTimeInfo)
 159     legacy::PassTimingInfo::TheTimeInfo->print();
 160 }
 161
 162 //===----------------------------------------------------------------------===//
 163 // Pass timing handling for the New Pass Manager
 164 //===----------------------------------------------------------------------===//
 165
 166 /// Returns the timer for the specified pass invocation of \p PassID.
 167 /// Each time it creates a new timer.
 168 Timer &TimePassesHandler::getPassTimer(StringRef PassID) {
 169   // Bump counts for each request of the timer.
 170   unsigned Count = nextPassID(PassID);
 171
 172   // Unconditionally appending description with a pass-invocation number.
 173   std::string FullDesc = formatv("{0} #{1}", PassID, Count).str();
 174
 175   PassInvocationID UID{PassID, Count};
 176   Timer *T = new Timer(PassID, FullDesc, TG);
 177   auto Pair = TimingData.try_emplace(UID, T);
 178   assert(Pair.second && "should always create a new timer");
 179   return *(Pair.first->second.get());
 180 }
 181
 182 TimePassesHandler::TimePassesHandler(bool Enabled)
 183     : TG("pass", "... Pass execution timing report ..."), Enabled(Enabled) {}
 184
 185 void TimePassesHandler::print() { TG.print(*CreateInfoOutputFile()); }
 186
 187 LLVM_DUMP_METHOD void TimePassesHandler::dump() const {
 188   dbgs() << "Dumping timers for " << getTypeName<TimePassesHandler>()
 189          << ":\n\tRunning:\n";
 190   for (auto &I : TimingData) {
 191     const Timer *MyTimer = I.second.get();
 192     if (!MyTimer || MyTimer->isRunning())
 193       dbgs() << "\tTimer " << MyTimer << " for pass " << I.first.first << "("
 194              << I.first.second << ")\n";
 195   }
 196   dbgs() << "\tTriggered:\n";
 197   for (auto &I : TimingData) {
 198     const Timer *MyTimer = I.second.get();
 199     if (!MyTimer || (MyTimer->hasTriggered() && !MyTimer->isRunning()))
 200       dbgs() << "\tTimer " << MyTimer << " for pass " << I.first.first << "("
 201              << I.first.second << ")\n";
 202   }
 203 }
 204
 205 void TimePassesHandler::startTimer(StringRef PassID) {
 206   Timer &MyTimer = getPassTimer(PassID);
 207   TimerStack.push_back(&MyTimer);
 208   if (!MyTimer.isRunning())
 209     MyTimer.startTimer();
 210 }
 211
 212 void TimePassesHandler::stopTimer(StringRef PassID) {
 213   assert(TimerStack.size() > 0 && "empty stack in popTimer");
 214   Timer *MyTimer = TimerStack.pop_back_val();
 215   assert(MyTimer && "timer should be present");
 216   if (MyTimer->isRunning())
 217     MyTimer->stopTimer();
 218 }
 219
 220 static bool matchPassManager(StringRef PassID) {
 221   size_t prefix_pos = PassID.find('<');
 222   if (prefix_pos == StringRef::npos)
 223     return false;
 224   StringRef Prefix = PassID.substr(0, prefix_pos);
 225   return Prefix.endswith("PassManager") || Prefix.endswith("PassAdaptor") ||
 226          Prefix.endswith("AnalysisManagerProxy");
 227 }
 228
 229 bool TimePassesHandler::runBeforePass(StringRef PassID, Any IR) {
 230   if (matchPassManager(PassID))
 231     return true;
 232
 233   startTimer(PassID);
 234
 235   LLVM_DEBUG(dbgs() << "after runBeforePass(" << PassID << ")\n");
 236   LLVM_DEBUG(dump());
 237
 238   // we are not going to skip this pass, thus return true.
 239   return true;
 240 }
 241
 242 void TimePassesHandler::runAfterPass(StringRef PassID, Any IR) {
 243   if (matchPassManager(PassID))
 244     return;
 245
 246   stopTimer(PassID);
 247
 248   LLVM_DEBUG(dbgs() << "after runAfterPass(" << PassID << ")\n");
 249   LLVM_DEBUG(dump());
 250 }
 251
 252 void TimePassesHandler::registerCallbacks(PassInstrumentationCallbacks &PIC) {
 253   if (!Enabled)
 254     return;
 255
 256   PIC.registerBeforePassCallback(
 257       [this](StringRef P, Any IR) { return this->runBeforePass(P, IR); });
 258   PIC.registerAfterPassCallback(
 259       [this](StringRef P, Any IR) { this->runAfterPass(P, IR); });
 260   PIC.registerBeforeAnalysisCallback(
 261       [this](StringRef P, Any IR) { this->runBeforePass(P, IR); });
 262   PIC.registerAfterAnalysisCallback(
 263       [this](StringRef P, Any IR) { this->runAfterPass(P, IR); });
 264 }
 265
 266 } // namespace llvm