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