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/DenseMap.h"
  20 #include "llvm/ADT/Statistic.h"
  21 #include "llvm/ADT/StringRef.h"
  22 #include "llvm/IR/PassInstrumentation.h"
  23 #include "llvm/Pass.h"
  24 #include "llvm/Support/CommandLine.h"
  25 #include "llvm/Support/Debug.h"
  26 #include "llvm/Support/FormatVariadic.h"
  27 #include "llvm/Support/ManagedStatic.h"
  28 #include "llvm/Support/Mutex.h"
  29 #include "llvm/Support/Timer.h"
  30 #include "llvm/Support/raw_ostream.h"
  31 #include <memory>
  32 #include <string>
  33
  34 using namespace llvm;
  35
  36 #define DEBUG_TYPE "time-passes"
  37
  38 namespace llvm {
  39
  40 bool TimePassesIsEnabled = false;
  41
  42 static cl::opt<bool, true> EnableTiming(
  43     "time-passes", cl::location(TimePassesIsEnabled), cl::Hidden,
  44     cl::desc("Time each pass, printing elapsed time for each on exit"));
  45
  46 namespace {
  47 namespace legacy {
  48
  49 //===----------------------------------------------------------------------===//
  50 // Legacy pass manager's PassTimingInfo implementation
  51
  52 /// Provides an interface for collecting pass timing information.
  53 ///
  54 /// It was intended to be generic but now we decided to split
  55 /// interfaces completely. This is now exclusively for legacy-pass-manager use.
  56 class PassTimingInfo {
  57 public:
  58   using PassInstanceID = void *;
  59
  60 private:
  61   StringMap<unsigned> PassIDCountMap; ///< Map that counts instances of passes
  62   DenseMap<PassInstanceID, std::unique_ptr<Timer>> TimingData; ///< timers for pass instances
  63   TimerGroup TG;
  64
  65 public:
  66   /// Default constructor for yet-inactive timeinfo.
  67   /// Use \p init() to activate it.
  68   PassTimingInfo();
  69
  70   /// Print out timing information and release timers.
  71   ~PassTimingInfo();
  72
  73   /// Initializes the static \p TheTimeInfo member to a non-null value when
  74   /// -time-passes is enabled. Leaves it null otherwise.
  75   ///
  76   /// This method may be called multiple times.
  77   static void init();
  78
  79   /// Prints out timing information and then resets the timers.
  80   /// By default it uses the stream created by CreateInfoOutputFile().
  81   void print(raw_ostream *OutStream = nullptr);
  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(raw_ostream *OutStream) {
 116   TG.print(OutStream ? *OutStream : *CreateInfoOutputFile(), true);
 117 }
 118
 119 Timer *PassTimingInfo::newPassTimer(StringRef PassID, StringRef PassDesc) {
 120   unsigned &num = PassIDCountMap[PassID];
 121   num++;
 122   // Appending description with a pass-instance number for all but the first one
 123   std::string PassDescNumbered =
 124       num <= 1 ? PassDesc.str() : formatv("{0} #{1}", PassDesc, num).str();
 125   return new Timer(PassID, PassDescNumbered, TG);
 126 }
 127
 128 Timer *PassTimingInfo::getPassTimer(Pass *P, PassInstanceID Pass) {
 129   if (P->getAsPMDataManager())
 130     return nullptr;
 131
 132   init();
 133   sys::SmartScopedLock<true> Lock(*TimingInfoMutex);
 134   std::unique_ptr<Timer> &T = TimingData[Pass];
 135
 136   if (!T) {
 137     StringRef PassName = P->getPassName();
 138     StringRef PassArgument;
 139     if (const PassInfo *PI = Pass::lookupPassInfo(P->getPassID()))
 140       PassArgument = PI->getPassArgument();
 141     T.reset(newPassTimer(PassArgument.empty() ? PassName : PassArgument, PassName));
 142   }
 143   return T.get();
 144 }
 145
 146 PassTimingInfo *PassTimingInfo::TheTimeInfo;
 147 } // namespace legacy
 148 } // namespace
 149
 150 Timer *getPassTimer(Pass *P) {
 151   legacy::PassTimingInfo::init();
 152   if (legacy::PassTimingInfo::TheTimeInfo)
 153     return legacy::PassTimingInfo::TheTimeInfo->getPassTimer(P, P);
 154   return nullptr;
 155 }
 156
 157 /// If timing is enabled, report the times collected up to now and then reset
 158 /// them.
 159 void reportAndResetTimings(raw_ostream *OutStream) {
 160   if (legacy::PassTimingInfo::TheTimeInfo)
 161     legacy::PassTimingInfo::TheTimeInfo->print(OutStream);
 162 }
 163
 164 //===----------------------------------------------------------------------===//
 165 // Pass timing handling for the New Pass Manager
 166 //===----------------------------------------------------------------------===//
 167
 168 /// Returns the timer for the specified pass invocation of \p PassID.
 169 /// Each time it creates a new timer.
 170 Timer &TimePassesHandler::getPassTimer(StringRef PassID) {
 171   // Bump counts for each request of the timer.
 172   unsigned Count = nextPassID(PassID);
 173
 174   // Unconditionally appending description with a pass-invocation number.
 175   std::string FullDesc = formatv("{0} #{1}", PassID, Count).str();
 176
 177   PassInvocationID UID{PassID, Count};
 178   Timer *T = new Timer(PassID, FullDesc, TG);
 179   auto Pair = TimingData.try_emplace(UID, T);
 180   assert(Pair.second && "should always create a new timer");
 181   return *(Pair.first->second.get());
 182 }
 183
 184 TimePassesHandler::TimePassesHandler(bool Enabled)
 185     : TG("pass", "... Pass execution timing report ..."), Enabled(Enabled) {}
 186
 187 void TimePassesHandler::setOutStream(raw_ostream &Out) {
 188   OutStream = &Out;
 189 }
 190
 191 void TimePassesHandler::print() {
 192   if (!Enabled)
 193     return;
 194   TG.print(OutStream ? *OutStream : *CreateInfoOutputFile(), true);
 195 }
 196
 197 LLVM_DUMP_METHOD void TimePassesHandler::dump() const {
 198   dbgs() << "Dumping timers for " << getTypeName<TimePassesHandler>()
 199          << ":\n\tRunning:\n";
 200   for (auto &I : TimingData) {
 201     const Timer *MyTimer = I.second.get();
 202     if (!MyTimer || MyTimer->isRunning())
 203       dbgs() << "\tTimer " << MyTimer << " for pass " << I.first.first << "("
 204              << I.first.second << ")\n";
 205   }
 206   dbgs() << "\tTriggered:\n";
 207   for (auto &I : TimingData) {
 208     const Timer *MyTimer = I.second.get();
 209     if (!MyTimer || (MyTimer->hasTriggered() && !MyTimer->isRunning()))
 210       dbgs() << "\tTimer " << MyTimer << " for pass " << I.first.first << "("
 211              << I.first.second << ")\n";
 212   }
 213 }
 214
 215 void TimePassesHandler::startTimer(StringRef PassID) {
 216   Timer &MyTimer = getPassTimer(PassID);
 217   TimerStack.push_back(&MyTimer);
 218   if (!MyTimer.isRunning())
 219     MyTimer.startTimer();
 220 }
 221
 222 void TimePassesHandler::stopTimer(StringRef PassID) {
 223   assert(TimerStack.size() > 0 && "empty stack in popTimer");
 224   Timer *MyTimer = TimerStack.pop_back_val();
 225   assert(MyTimer && "timer should be present");
 226   if (MyTimer->isRunning())
 227     MyTimer->stopTimer();
 228 }
 229
 230 static bool matchPassManager(StringRef PassID) {
 231   size_t prefix_pos = PassID.find('<');
 232   if (prefix_pos == StringRef::npos)
 233     return false;
 234   StringRef Prefix = PassID.substr(0, prefix_pos);
 235   return Prefix.endswith("PassManager") || Prefix.endswith("PassAdaptor") ||
 236          Prefix.endswith("AnalysisManagerProxy");
 237 }
 238
 239 bool TimePassesHandler::runBeforePass(StringRef PassID) {
 240   if (matchPassManager(PassID))
 241     return true;
 242
 243   startTimer(PassID);
 244
 245   LLVM_DEBUG(dbgs() << "after runBeforePass(" << PassID << ")\n");
 246   LLVM_DEBUG(dump());
 247
 248   // we are not going to skip this pass, thus return true.
 249   return true;
 250 }
 251
 252 void TimePassesHandler::runAfterPass(StringRef PassID) {
 253   if (matchPassManager(PassID))
 254     return;
 255
 256   stopTimer(PassID);
 257
 258   LLVM_DEBUG(dbgs() << "after runAfterPass(" << PassID << ")\n");
 259   LLVM_DEBUG(dump());
 260 }
 261
 262 void TimePassesHandler::registerCallbacks(PassInstrumentationCallbacks &PIC) {
 263   if (!Enabled)
 264     return;
 265
 266   PIC.registerBeforePassCallback(
 267       [this](StringRef P, Any) { return this->runBeforePass(P); });
 268   PIC.registerAfterPassCallback(
 269       [this](StringRef P, Any) { this->runAfterPass(P); });
 270   PIC.registerAfterPassInvalidatedCallback(
 271       [this](StringRef P) { this->runAfterPass(P); });
 272   PIC.registerBeforeAnalysisCallback(
 273       [this](StringRef P, Any) { this->runBeforePass(P); });
 274   PIC.registerAfterAnalysisCallback(
 275       [this](StringRef P, Any) { this->runAfterPass(P); });
 276 }
 277
 278 } // namespace llvm