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