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
34using namespace llvm;
35
36#define DEBUG_TYPE "time-passes"
37
38namespace llvm {
39
40bool TimePassesIsEnabled = false;
41
42static 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
46namespace {
47namespace 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.
56class PassTimingInfo {
57public:
58  using PassInstanceID = void *;
59
60private:
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
65public:
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
88private:
89  Timer *newPassTimer(StringRef PassID, StringRef PassDesc);
90};
91
92static ManagedStatic<sys::SmartMutex<true>> TimingInfoMutex;
93
94PassTimingInfo::PassTimingInfo()
95    : TG("pass", "... Pass execution timing report ...") {}
96
97PassTimingInfo::~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
103void 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.
115void PassTimingInfo::print(raw_ostream *OutStream) {
116  TG.print(OutStream ? *OutStream : *CreateInfoOutputFile(), true);
117}
118
119Timer *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
128Timer *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
146PassTimingInfo *PassTimingInfo::TheTimeInfo;
147} // namespace legacy
148} // namespace
149
150Timer *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.
159void 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.
170Timer &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
184TimePassesHandler::TimePassesHandler(bool Enabled)
185    : TG("pass", "... Pass execution timing report ..."), Enabled(Enabled) {}
186
187void TimePassesHandler::setOutStream(raw_ostream &Out) {
188  OutStream = &Out;
189}
190
191void TimePassesHandler::print() {
192  if (!Enabled)
193    return;
194  TG.print(OutStream ? *OutStream : *CreateInfoOutputFile(), true);
195}
196
197LLVM_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
215void TimePassesHandler::startTimer(StringRef PassID) {
216  Timer &MyTimer = getPassTimer(PassID);
217  TimerStack.push_back(&MyTimer);
218  if (!MyTimer.isRunning())
219    MyTimer.startTimer();
220}
221
222void 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
230static 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
239bool 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
252void 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
262void 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
279