PassTimingInfo.cpp 11 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319
  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() : TG("pass", "Pass execution timing report") {}
  78. PassTimingInfo::~PassTimingInfo() {
  79. // Deleting the timers accumulates their info into the TG member.
  80. // Then TG member is (implicitly) deleted, actually printing the report.
  81. TimingData.clear();
  82. }
  83. void PassTimingInfo::init() {
  84. if (!TimePassesIsEnabled || TheTimeInfo)
  85. return;
  86. // Constructed the first time this is called, iff -time-passes is enabled.
  87. // This guarantees that the object will be constructed after static globals,
  88. // thus it will be destroyed before them.
  89. static ManagedStatic<PassTimingInfo> TTI;
  90. TheTimeInfo = &*TTI;
  91. }
  92. /// Prints out timing information and then resets the timers.
  93. void PassTimingInfo::print(raw_ostream *OutStream) {
  94. TG.print(OutStream ? *OutStream : *CreateInfoOutputFile(), true);
  95. }
  96. Timer *PassTimingInfo::newPassTimer(StringRef PassID, StringRef PassDesc) {
  97. unsigned &num = PassIDCountMap[PassID];
  98. num++;
  99. // Appending description with a pass-instance number for all but the first one
  100. std::string PassDescNumbered =
  101. num <= 1 ? PassDesc.str() : formatv("{0} #{1}", PassDesc, num).str();
  102. return new Timer(PassID, PassDescNumbered, TG);
  103. }
  104. Timer *PassTimingInfo::getPassTimer(Pass *P, PassInstanceID Pass) {
  105. if (P->getAsPMDataManager())
  106. return nullptr;
  107. init();
  108. sys::SmartScopedLock<true> Lock(*TimingInfoMutex);
  109. std::unique_ptr<Timer> &T = TimingData[Pass];
  110. if (!T) {
  111. StringRef PassName = P->getPassName();
  112. StringRef PassArgument;
  113. if (const PassInfo *PI = Pass::lookupPassInfo(P->getPassID()))
  114. PassArgument = PI->getPassArgument();
  115. T.reset(newPassTimer(PassArgument.empty() ? PassName : PassArgument, PassName));
  116. }
  117. return T.get();
  118. }
  119. PassTimingInfo *PassTimingInfo::TheTimeInfo;
  120. } // namespace legacy
  121. } // namespace
  122. Timer *getPassTimer(Pass *P) {
  123. legacy::PassTimingInfo::init();
  124. if (legacy::PassTimingInfo::TheTimeInfo)
  125. return legacy::PassTimingInfo::TheTimeInfo->getPassTimer(P, P);
  126. return nullptr;
  127. }
  128. /// If timing is enabled, report the times collected up to now and then reset
  129. /// them.
  130. void reportAndResetTimings(raw_ostream *OutStream) {
  131. if (legacy::PassTimingInfo::TheTimeInfo)
  132. legacy::PassTimingInfo::TheTimeInfo->print(OutStream);
  133. }
  134. //===----------------------------------------------------------------------===//
  135. // Pass timing handling for the New Pass Manager
  136. //===----------------------------------------------------------------------===//
  137. /// Returns the timer for the specified pass invocation of \p PassID.
  138. /// Each time it creates a new timer.
  139. Timer &TimePassesHandler::getPassTimer(StringRef PassID, bool IsPass) {
  140. TimerGroup &TG = IsPass ? PassTG : AnalysisTG;
  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. : PassTG("pass", "Pass execution timing report"),
  159. AnalysisTG("analysis", "Analysis execution timing report"),
  160. Enabled(Enabled), PerRun(PerRun) {}
  161. TimePassesHandler::TimePassesHandler()
  162. : TimePassesHandler(TimePassesIsEnabled, TimePassesPerRun) {}
  163. void TimePassesHandler::setOutStream(raw_ostream &Out) {
  164. OutStream = &Out;
  165. }
  166. void TimePassesHandler::print() {
  167. if (!Enabled)
  168. return;
  169. std::unique_ptr<raw_ostream> MaybeCreated;
  170. raw_ostream *OS = OutStream;
  171. if (OutStream) {
  172. OS = OutStream;
  173. } else {
  174. MaybeCreated = CreateInfoOutputFile();
  175. OS = &*MaybeCreated;
  176. }
  177. PassTG.print(*OS, true);
  178. AnalysisTG.print(*OS, true);
  179. }
  180. LLVM_DUMP_METHOD void TimePassesHandler::dump() const {
  181. dbgs() << "Dumping timers for " << getTypeName<TimePassesHandler>()
  182. << ":\n\tRunning:\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->isRunning())
  189. dbgs() << "\tTimer " << MyTimer << " for pass " << PassID << "(" << idx << ")\n";
  190. }
  191. }
  192. dbgs() << "\tTriggered:\n";
  193. for (auto &I : TimingData) {
  194. StringRef PassID = I.getKey();
  195. const TimerVector& MyTimers = I.getValue();
  196. for (unsigned idx = 0; idx < MyTimers.size(); idx++) {
  197. const Timer* MyTimer = MyTimers[idx].get();
  198. if (MyTimer && MyTimer->hasTriggered() && !MyTimer->isRunning())
  199. dbgs() << "\tTimer " << MyTimer << " for pass " << PassID << "(" << idx << ")\n";
  200. }
  201. }
  202. }
  203. static bool shouldIgnorePass(StringRef PassID) {
  204. return isSpecialPass(PassID,
  205. {"PassManager", "PassAdaptor", "AnalysisManagerProxy",
  206. "ModuleInlinerWrapperPass", "DevirtSCCRepeatedPass"});
  207. }
  208. void TimePassesHandler::startPassTimer(StringRef PassID) {
  209. if (shouldIgnorePass(PassID))
  210. return;
  211. assert(!ActivePassTimer && "should only have one pass timer at a time");
  212. Timer &MyTimer = getPassTimer(PassID, /*IsPass*/ true);
  213. ActivePassTimer = &MyTimer;
  214. assert(!MyTimer.isRunning());
  215. MyTimer.startTimer();
  216. }
  217. void TimePassesHandler::stopPassTimer(StringRef PassID) {
  218. if (shouldIgnorePass(PassID))
  219. return;
  220. assert(ActivePassTimer);
  221. assert(ActivePassTimer->isRunning());
  222. ActivePassTimer->stopTimer();
  223. ActivePassTimer = nullptr;
  224. }
  225. void TimePassesHandler::startAnalysisTimer(StringRef PassID) {
  226. // Stop the previous analysis timer to prevent double counting when an
  227. // analysis requests another analysis.
  228. if (!AnalysisActiveTimerStack.empty()) {
  229. assert(AnalysisActiveTimerStack.back()->isRunning());
  230. AnalysisActiveTimerStack.back()->stopTimer();
  231. }
  232. Timer &MyTimer = getPassTimer(PassID, /*IsPass*/ false);
  233. AnalysisActiveTimerStack.push_back(&MyTimer);
  234. if (!MyTimer.isRunning())
  235. MyTimer.startTimer();
  236. }
  237. void TimePassesHandler::stopAnalysisTimer(StringRef PassID) {
  238. assert(!AnalysisActiveTimerStack.empty() && "empty stack in popTimer");
  239. Timer *MyTimer = AnalysisActiveTimerStack.pop_back_val();
  240. assert(MyTimer && "timer should be present");
  241. if (MyTimer->isRunning())
  242. MyTimer->stopTimer();
  243. // Restart the previously stopped timer.
  244. if (!AnalysisActiveTimerStack.empty()) {
  245. assert(!AnalysisActiveTimerStack.back()->isRunning());
  246. AnalysisActiveTimerStack.back()->startTimer();
  247. }
  248. }
  249. void TimePassesHandler::registerCallbacks(PassInstrumentationCallbacks &PIC) {
  250. if (!Enabled)
  251. return;
  252. PIC.registerBeforeNonSkippedPassCallback(
  253. [this](StringRef P, Any) { this->startPassTimer(P); });
  254. PIC.registerAfterPassCallback(
  255. [this](StringRef P, Any, const PreservedAnalyses &) {
  256. this->stopPassTimer(P);
  257. });
  258. PIC.registerAfterPassInvalidatedCallback(
  259. [this](StringRef P, const PreservedAnalyses &) {
  260. this->stopPassTimer(P);
  261. });
  262. PIC.registerBeforeAnalysisCallback(
  263. [this](StringRef P, Any) { this->startAnalysisTimer(P); });
  264. PIC.registerAfterAnalysisCallback(
  265. [this](StringRef P, Any) { this->stopAnalysisTimer(P); });
  266. }
  267. } // namespace llvm