llvm/lib/IR/PassTimingInfo.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-exception
   6 //
   7 //===----------------------------------------------------------------------===//
   8 //
   9 // This file implements the LLVM Pass Timing infrastructure for both
  10 // new and legacy pass managers.
  11 //
  12 // PassTimingInfo Class - This class is used to calculate information about the
  13 // amount of time each pass takes to execute.  This only happens when
  14 // -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
  31 using namespace llvm;
  32
  33 #define DEBUG_TYPE "time-passes"
  34
  35 namespace llvm {
  36
  37 bool TimePassesIsEnabled = false;
  38 bool TimePassesPerRun = false;
  39
  40 static 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
  44 static 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
  49 namespace {
  50 namespace legacy {
  51
  52 //===----------------------------------------------------------------------===//
  53 // Legacy pass manager's PassTimingInfo implementation
  54
  55 /// Provides an interface for collecting pass timing information.
  56 ///
  57 /// It was intended to be generic but now we decided to split
  58 /// interfaces completely. This is now exclusively for legacy-pass-manager use.
  59 class PassTimingInfo {
  60 public:
  61   using PassInstanceID = void *;
  62
  63 private:
  64   StringMap<unsigned> PassIDCountMap; ///< Map that counts instances of passes
  65   DenseMap<PassInstanceID, std::unique_ptr<Timer>> TimingData; ///< timers for pass instances
  66   TimerGroup TG;
  67
  68 public:
  69   /// Default constructor for yet-inactive timeinfo.
  70   /// Use \p init() to activate it.
  71   PassTimingInfo();
  72
  73   /// Print out timing information and release timers.
  74   ~PassTimingInfo();
  75
  76   /// Initializes the static \p TheTimeInfo member to a non-null value when
  77   /// -time-passes is enabled. Leaves it null otherwise.
  78   ///
  79   /// This method may be called multiple times.
  80   static void init();
  81
  82   /// Prints out timing information and then resets the timers.
  83   /// By default it uses the stream created by CreateInfoOutputFile().
  84   void print(raw_ostream *OutStream = nullptr);
  85
  86   /// Returns the timer for the specified pass if it exists.
  87   Timer *getPassTimer(Pass *, PassInstanceID);
  88
  89   static PassTimingInfo *TheTimeInfo;
  90
  91 private:
  92   Timer *newPassTimer(StringRef PassID, StringRef PassDesc);
  93 };
  94
  95 static ManagedStatic<sys::SmartMutex<true>> TimingInfoMutex;
  96
  97 PassTimingInfo::PassTimingInfo()
  98     : TG("pass", "... Pass execution timing report ...") {}
  99
 100 PassTimingInfo::~PassTimingInfo() {
 101   // Deleting the timers accumulates their info into the TG member.
 102   // Then TG member is (implicitly) deleted, actually printing the report.
 103   TimingData.clear();
 104 }
 105
 106 void PassTimingInfo::init() {
 107   if (!TimePassesIsEnabled || TheTimeInfo)
 108     return;
 109
 110   // Constructed the first time this is called, iff -time-passes is enabled.
 111   // This guarantees that the object will be constructed after static globals,
 112   // thus it will be destroyed before them.
 113   static ManagedStatic<PassTimingInfo> TTI;
 114   TheTimeInfo = &*TTI;
 115 }
 116
 117 /// Prints out timing information and then resets the timers.
 118 void PassTimingInfo::print(raw_ostream *OutStream) {
 119   TG.print(OutStream ? *OutStream : *CreateInfoOutputFile(), true);
 120 }
 121
 122 Timer *PassTimingInfo::newPassTimer(StringRef PassID, StringRef PassDesc) {
 123   unsigned &num = PassIDCountMap[PassID];
 124   num++;
 125   // Appending description with a pass-instance number for all but the first one
 126   std::string PassDescNumbered =
 127       num <= 1 ? PassDesc.str() : formatv("{0} #{1}", PassDesc, num).str();
 128   return new Timer(PassID, PassDescNumbered, TG);
 129 }
 130
 131 Timer *PassTimingInfo::getPassTimer(Pass *P, PassInstanceID Pass) {
 132   if (P->getAsPMDataManager())
 133     return nullptr;
 134
 135   init();
 136   sys::SmartScopedLock<true> Lock(*TimingInfoMutex);
 137   std::unique_ptr<Timer> &T = TimingData[Pass];
 138
 139   if (!T) {
 140     StringRef PassName = P->getPassName();
 141     StringRef PassArgument;
 142     if (const PassInfo *PI = Pass::lookupPassInfo(P->getPassID()))
 143       PassArgument = PI->getPassArgument();
 144     T.reset(newPassTimer(PassArgument.empty() ? PassName : PassArgument, PassName));
 145   }
 146   return T.get();
 147 }
 148
 149 PassTimingInfo *PassTimingInfo::TheTimeInfo;
 150 } // namespace legacy
 151 } // namespace
 152
 153 Timer *getPassTimer(Pass *P) {
 154   legacy::PassTimingInfo::init();
 155   if (legacy::PassTimingInfo::TheTimeInfo)
 156     return legacy::PassTimingInfo::TheTimeInfo->getPassTimer(P, P);
 157   return nullptr;
 158 }
 159
 160 /// If timing is enabled, report the times collected up to now and then reset
 161 /// them.
 162 void reportAndResetTimings(raw_ostream *OutStream) {
 163   if (legacy::PassTimingInfo::TheTimeInfo)
 164     legacy::PassTimingInfo::TheTimeInfo->print(OutStream);
 165 }
 166
 167 //===----------------------------------------------------------------------===//
 168 // Pass timing handling for the New Pass Manager
 169 //===----------------------------------------------------------------------===//
 170
 171 /// Returns the timer for the specified pass invocation of \p PassID.
 172 /// Each time it creates a new timer.
 173 Timer &TimePassesHandler::getPassTimer(StringRef PassID) {
 174   if (!PerRun) {
 175     TimerVector &Timers = TimingData[PassID];
 176     if (Timers.size() == 0)
 177       Timers.emplace_back(new Timer(PassID, PassID, TG));
 178     return *Timers.front();
 179   }
 180
 181   // Take a vector of Timers created for this \p PassID and append
 182   // one more timer to it.
 183   TimerVector &Timers = TimingData[PassID];
 184   unsigned Count = Timers.size() + 1;
 185
 186   std::string FullDesc = formatv("{0} #{1}", PassID, Count).str();
 187
 188   Timer *T = new Timer(PassID, FullDesc, TG);
 189   Timers.emplace_back(T);
 190   assert(Count == Timers.size() && "sanity check");
 191
 192   return *T;
 193 }
 194
 195 TimePassesHandler::TimePassesHandler(bool Enabled, bool PerRun)
 196     : TG("pass", "... Pass execution timing report ..."), Enabled(Enabled),
 197       PerRun(PerRun) {}
 198
 199 TimePassesHandler::TimePassesHandler()
 200     : TimePassesHandler(TimePassesIsEnabled, TimePassesPerRun) {}
 201
 202 void TimePassesHandler::setOutStream(raw_ostream &Out) {
 203   OutStream = &Out;
 204 }
 205
 206 void TimePassesHandler::print() {
 207   if (!Enabled)
 208     return;
 209   TG.print(OutStream ? *OutStream : *CreateInfoOutputFile(), true);
 210 }
 211
 212 LLVM_DUMP_METHOD void TimePassesHandler::dump() const {
 213   dbgs() << "Dumping timers for " << getTypeName<TimePassesHandler>()
 214          << ":\n\tRunning:\n";
 215   for (auto &I : TimingData) {
 216     StringRef PassID = I.getKey();
 217     const TimerVector& MyTimers = I.getValue();
 218     for (unsigned idx = 0; idx < MyTimers.size(); idx++) {
 219       const Timer* MyTimer = MyTimers[idx].get();
 220       if (MyTimer && MyTimer->isRunning())
 221         dbgs() << "\tTimer " << MyTimer << " for pass " << PassID << "(" << idx << ")\n";
 222     }
 223   }
 224   dbgs() << "\tTriggered:\n";
 225   for (auto &I : TimingData) {
 226     StringRef PassID = I.getKey();
 227     const TimerVector& MyTimers = I.getValue();
 228     for (unsigned idx = 0; idx < MyTimers.size(); idx++) {
 229       const Timer* MyTimer = MyTimers[idx].get();
 230       if (MyTimer && MyTimer->hasTriggered() && !MyTimer->isRunning())
 231         dbgs() << "\tTimer " << MyTimer << " for pass " << PassID << "(" << idx << ")\n";
 232     }
 233   }
 234 }
 235
 236 void TimePassesHandler::startTimer(StringRef PassID) {
 237   Timer &MyTimer = getPassTimer(PassID);
 238   TimerStack.push_back(&MyTimer);
 239   if (!MyTimer.isRunning())
 240     MyTimer.startTimer();
 241 }
 242
 243 void TimePassesHandler::stopTimer(StringRef PassID) {
 244   assert(TimerStack.size() > 0 && "empty stack in popTimer");
 245   Timer *MyTimer = TimerStack.pop_back_val();
 246   assert(MyTimer && "timer should be present");
 247   if (MyTimer->isRunning())
 248     MyTimer->stopTimer();
 249 }
 250
 251 void TimePassesHandler::runBeforePass(StringRef PassID) {
 252   if (isSpecialPass(PassID,
 253                     {"PassManager", "PassAdaptor", "AnalysisManagerProxy"}))
 254     return;
 255
 256   startTimer(PassID);
 257
 258   LLVM_DEBUG(dbgs() << "after runBeforePass(" << PassID << ")\n");
 259   LLVM_DEBUG(dump());
 260 }
 261
 262 void TimePassesHandler::runAfterPass(StringRef PassID) {
 263   if (isSpecialPass(PassID,
 264                     {"PassManager", "PassAdaptor", "AnalysisManagerProxy"}))
 265     return;
 266
 267   stopTimer(PassID);
 268
 269   LLVM_DEBUG(dbgs() << "after runAfterPass(" << PassID << ")\n");
 270   LLVM_DEBUG(dump());
 271 }
 272
 273 void TimePassesHandler::registerCallbacks(PassInstrumentationCallbacks &PIC) {
 274   if (!Enabled)
 275     return;
 276
 277   PIC.registerBeforeNonSkippedPassCallback(
 278       [this](StringRef P, Any) { this->runBeforePass(P); });
 279   PIC.registerAfterPassCallback(
 280       [this](StringRef P, Any, const PreservedAnalyses &) {
 281         this->runAfterPass(P);
 282       });
 283   PIC.registerAfterPassInvalidatedCallback(
 284       [this](StringRef P, const PreservedAnalyses &) {
 285         this->runAfterPass(P);
 286       });
 287   PIC.registerBeforeAnalysisCallback(
 288       [this](StringRef P, Any) { this->runBeforePass(P); });
 289   PIC.registerAfterAnalysisCallback(
 290       [this](StringRef P, Any) { this->runAfterPass(P); });
 291 }
 292
 293 } // namespace llvm