PassTimingInfo.cpp 9.5 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293
  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. #include "llvm/IR/PassTimingInfo.h"
  18. #include "llvm/ADT/Statistic.h"
  19. #include "llvm/IR/PassInstrumentation.h"
  20. #include "llvm/Pass.h"
  21. #include "llvm/Support/CommandLine.h"
  22. #include "llvm/Support/Debug.h"
  23. #include "llvm/Support/FormatVariadic.h"
  24. #include "llvm/Support/ManagedStatic.h"
  25. #include "llvm/Support/Mutex.h"
  26. #include "llvm/Support/TypeName.h"
  27. #include "llvm/Support/raw_ostream.h"
  28. #include <string>
  29. using namespace llvm;
  30. #define DEBUG_TYPE "time-passes"
  31. namespace llvm {
  32. bool TimePassesIsEnabled = false;
  33. bool TimePassesPerRun = false;
  34. static cl::opt<bool, true> EnableTiming(
  35. "time-passes", cl::location(TimePassesIsEnabled), cl::Hidden,
  36. cl::desc("Time each pass, printing elapsed time for each on exit"));
  37. static cl::opt<bool, true> EnableTimingPerRun(
  38. "time-passes-per-run", cl::location(TimePassesPerRun), cl::Hidden,
  39. cl::desc("Time each pass run, printing elapsed time for each run on exit"),
  40. cl::callback([](const bool &) { TimePassesIsEnabled = true; }));
  41. namespace {
  42. namespace legacy {
  43. //===----------------------------------------------------------------------===//
  44. // Legacy pass manager's PassTimingInfo implementation
  45. /// Provides an interface for collecting pass timing information.
  46. ///
  47. /// It was intended to be generic but now we decided to split
  48. /// interfaces completely. This is now exclusively for legacy-pass-manager use.
  49. class PassTimingInfo {
  50. public:
  51. using PassInstanceID = void *;
  52. private:
  53. StringMap<unsigned> PassIDCountMap; ///< Map that counts instances of passes
  54. DenseMap<PassInstanceID, std::unique_ptr<Timer>> TimingData; ///< timers for pass instances
  55. TimerGroup TG;
  56. public:
  57. /// Default constructor for yet-inactive timeinfo.
  58. /// Use \p init() to activate it.
  59. PassTimingInfo();
  60. /// Print out timing information and release timers.
  61. ~PassTimingInfo();
  62. /// Initializes the static \p TheTimeInfo member to a non-null value when
  63. /// -time-passes is enabled. Leaves it null otherwise.
  64. ///
  65. /// This method may be called multiple times.
  66. static void init();
  67. /// Prints out timing information and then resets the timers.
  68. /// By default it uses the stream created by CreateInfoOutputFile().
  69. void print(raw_ostream *OutStream = nullptr);
  70. /// Returns the timer for the specified pass if it exists.
  71. Timer *getPassTimer(Pass *, PassInstanceID);
  72. static PassTimingInfo *TheTimeInfo;
  73. private:
  74. Timer *newPassTimer(StringRef PassID, StringRef PassDesc);
  75. };
  76. static ManagedStatic<sys::SmartMutex<true>> TimingInfoMutex;
  77. PassTimingInfo::PassTimingInfo()
  78. : TG("pass", "... Pass execution timing report ...") {}
  79. PassTimingInfo::~PassTimingInfo() {
  80. // Deleting the timers accumulates their info into the TG member.
  81. // Then TG member is (implicitly) deleted, actually printing the report.
  82. TimingData.clear();
  83. }
  84. void PassTimingInfo::init() {
  85. if (!TimePassesIsEnabled || TheTimeInfo)
  86. return;
  87. // Constructed the first time this is called, iff -time-passes is enabled.
  88. // This guarantees that the object will be constructed after static globals,
  89. // thus it will be destroyed before them.
  90. static ManagedStatic<PassTimingInfo> TTI;
  91. TheTimeInfo = &*TTI;
  92. }
  93. /// Prints out timing information and then resets the timers.
  94. void PassTimingInfo::print(raw_ostream *OutStream) {
  95. TG.print(OutStream ? *OutStream : *CreateInfoOutputFile(), true);
  96. }
  97. Timer *PassTimingInfo::newPassTimer(StringRef PassID, StringRef PassDesc) {
  98. unsigned &num = PassIDCountMap[PassID];
  99. num++;
  100. // Appending description with a pass-instance number for all but the first one
  101. std::string PassDescNumbered =
  102. num <= 1 ? PassDesc.str() : formatv("{0} #{1}", PassDesc, num).str();
  103. return new Timer(PassID, PassDescNumbered, TG);
  104. }
  105. Timer *PassTimingInfo::getPassTimer(Pass *P, PassInstanceID Pass) {
  106. if (P->getAsPMDataManager())
  107. return nullptr;
  108. init();
  109. sys::SmartScopedLock<true> Lock(*TimingInfoMutex);
  110. std::unique_ptr<Timer> &T = TimingData[Pass];
  111. if (!T) {
  112. StringRef PassName = P->getPassName();
  113. StringRef PassArgument;
  114. if (const PassInfo *PI = Pass::lookupPassInfo(P->getPassID()))
  115. PassArgument = PI->getPassArgument();
  116. T.reset(newPassTimer(PassArgument.empty() ? PassName : PassArgument, PassName));
  117. }
  118. return T.get();
  119. }
  120. PassTimingInfo *PassTimingInfo::TheTimeInfo;
  121. } // namespace legacy
  122. } // namespace
  123. Timer *getPassTimer(Pass *P) {
  124. legacy::PassTimingInfo::init();
  125. if (legacy::PassTimingInfo::TheTimeInfo)
  126. return legacy::PassTimingInfo::TheTimeInfo->getPassTimer(P, P);
  127. return nullptr;
  128. }
  129. /// If timing is enabled, report the times collected up to now and then reset
  130. /// them.
  131. void reportAndResetTimings(raw_ostream *OutStream) {
  132. if (legacy::PassTimingInfo::TheTimeInfo)
  133. legacy::PassTimingInfo::TheTimeInfo->print(OutStream);
  134. }
  135. //===----------------------------------------------------------------------===//
  136. // Pass timing handling for the New Pass Manager
  137. //===----------------------------------------------------------------------===//
  138. /// Returns the timer for the specified pass invocation of \p PassID.
  139. /// Each time it creates a new timer.
  140. Timer &TimePassesHandler::getPassTimer(StringRef PassID) {
  141. if (!PerRun) {
  142. TimerVector &Timers = TimingData[PassID];
  143. if (Timers.size() == 0)
  144. Timers.emplace_back(new Timer(PassID, PassID, TG));
  145. return *Timers.front();
  146. }
  147. // Take a vector of Timers created for this \p PassID and append
  148. // one more timer to it.
  149. TimerVector &Timers = TimingData[PassID];
  150. unsigned Count = Timers.size() + 1;
  151. std::string FullDesc = formatv("{0} #{1}", PassID, Count).str();
  152. Timer *T = new Timer(PassID, FullDesc, TG);
  153. Timers.emplace_back(T);
  154. assert(Count == Timers.size() && "Timers vector not adjusted correctly.");
  155. return *T;
  156. }
  157. TimePassesHandler::TimePassesHandler(bool Enabled, bool PerRun)
  158. : TG("pass", "... Pass execution timing report ..."), Enabled(Enabled),
  159. PerRun(PerRun) {}
  160. TimePassesHandler::TimePassesHandler()
  161. : TimePassesHandler(TimePassesIsEnabled, TimePassesPerRun) {}
  162. void TimePassesHandler::setOutStream(raw_ostream &Out) {
  163. OutStream = &Out;
  164. }
  165. void TimePassesHandler::print() {
  166. if (!Enabled)
  167. return;
  168. TG.print(OutStream ? *OutStream : *CreateInfoOutputFile(), true);
  169. }
  170. LLVM_DUMP_METHOD void TimePassesHandler::dump() const {
  171. dbgs() << "Dumping timers for " << getTypeName<TimePassesHandler>()
  172. << ":\n\tRunning:\n";
  173. for (auto &I : TimingData) {
  174. StringRef PassID = I.getKey();
  175. const TimerVector& MyTimers = I.getValue();
  176. for (unsigned idx = 0; idx < MyTimers.size(); idx++) {
  177. const Timer* MyTimer = MyTimers[idx].get();
  178. if (MyTimer && MyTimer->isRunning())
  179. dbgs() << "\tTimer " << MyTimer << " for pass " << PassID << "(" << idx << ")\n";
  180. }
  181. }
  182. dbgs() << "\tTriggered:\n";
  183. for (auto &I : TimingData) {
  184. StringRef PassID = I.getKey();
  185. const TimerVector& MyTimers = I.getValue();
  186. for (unsigned idx = 0; idx < MyTimers.size(); idx++) {
  187. const Timer* MyTimer = MyTimers[idx].get();
  188. if (MyTimer && MyTimer->hasTriggered() && !MyTimer->isRunning())
  189. dbgs() << "\tTimer " << MyTimer << " for pass " << PassID << "(" << idx << ")\n";
  190. }
  191. }
  192. }
  193. void TimePassesHandler::startTimer(StringRef PassID) {
  194. Timer &MyTimer = getPassTimer(PassID);
  195. TimerStack.push_back(&MyTimer);
  196. if (!MyTimer.isRunning())
  197. MyTimer.startTimer();
  198. }
  199. void TimePassesHandler::stopTimer(StringRef PassID) {
  200. assert(TimerStack.size() > 0 && "empty stack in popTimer");
  201. Timer *MyTimer = TimerStack.pop_back_val();
  202. assert(MyTimer && "timer should be present");
  203. if (MyTimer->isRunning())
  204. MyTimer->stopTimer();
  205. }
  206. void TimePassesHandler::runBeforePass(StringRef PassID) {
  207. if (isSpecialPass(PassID,
  208. {"PassManager", "PassAdaptor", "AnalysisManagerProxy"}))
  209. return;
  210. startTimer(PassID);
  211. LLVM_DEBUG(dbgs() << "after runBeforePass(" << PassID << ")\n");
  212. LLVM_DEBUG(dump());
  213. }
  214. void TimePassesHandler::runAfterPass(StringRef PassID) {
  215. if (isSpecialPass(PassID,
  216. {"PassManager", "PassAdaptor", "AnalysisManagerProxy"}))
  217. return;
  218. stopTimer(PassID);
  219. LLVM_DEBUG(dbgs() << "after runAfterPass(" << PassID << ")\n");
  220. LLVM_DEBUG(dump());
  221. }
  222. void TimePassesHandler::registerCallbacks(PassInstrumentationCallbacks &PIC) {
  223. if (!Enabled)
  224. return;
  225. PIC.registerBeforeNonSkippedPassCallback(
  226. [this](StringRef P, Any) { this->runBeforePass(P); });
  227. PIC.registerAfterPassCallback(
  228. [this](StringRef P, Any, const PreservedAnalyses &) {
  229. this->runAfterPass(P);
  230. });
  231. PIC.registerAfterPassInvalidatedCallback(
  232. [this](StringRef P, const PreservedAnalyses &) {
  233. this->runAfterPass(P);
  234. });
  235. PIC.registerBeforeAnalysisCallback(
  236. [this](StringRef P, Any) { this->runBeforePass(P); });
  237. PIC.registerAfterAnalysisCallback(
  238. [this](StringRef P, Any) { this->runAfterPass(P); });
  239. }
  240. } // namespace llvm