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
31using namespace llvm;
32
33#define DEBUG_TYPE "time-passes"
34
35namespace llvm {
36
37bool TimePassesIsEnabled = false;
38bool TimePassesPerRun = false;
39
40static cl::opt<bool, true> EnableTiming(
41 "time-passes", cl::location(L&: TimePassesIsEnabled), cl::Hidden,
42 cl::desc("Time each pass, printing elapsed time for each on exit"));
43
44static cl::opt<bool, true> EnableTimingPerRun(
45 "time-passes-per-run", cl::location(L&: TimePassesPerRun), cl::Hidden,
46 cl::desc("Time each pass run, printing elapsed time for each run on exit"),
47 cl::callback(CB: [](const bool &) { TimePassesIsEnabled = true; }));
48
49namespace {
50namespace 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.
59class PassTimingInfo {
60public:
61 using PassInstanceID = void *;
62
63private:
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
68public:
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
91private:
92 Timer *newPassTimer(StringRef PassID, StringRef PassDesc);
93};
94
95static ManagedStatic<sys::SmartMutex<true>> TimingInfoMutex;
96
97PassTimingInfo::PassTimingInfo() : TG("pass", "Pass execution timing report") {}
98
99PassTimingInfo::~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
105void 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.
117void PassTimingInfo::print(raw_ostream *OutStream) {
118 TG.print(OS&: OutStream ? *OutStream : *CreateInfoOutputFile(), ResetAfterPrint: true);
119}
120
121Timer *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(Fmt: "{0} #{1}", Vals&: PassDesc, Vals&: num).str();
127 return new Timer(PassID, PassDescNumbered, TG);
128}
129
130Timer *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(TI: P->getPassID()))
142 PassArgument = PI->getPassArgument();
143 T.reset(p: newPassTimer(PassID: PassArgument.empty() ? PassName : PassArgument, PassDesc: PassName));
144 }
145 return T.get();
146}
147
148PassTimingInfo *PassTimingInfo::TheTimeInfo;
149} // namespace legacy
150} // namespace
151
152Timer *getPassTimer(Pass *P) {
153 legacy::PassTimingInfo::init();
154 if (legacy::PassTimingInfo::TheTimeInfo)
155 return legacy::PassTimingInfo::TheTimeInfo->getPassTimer(P, Pass: P);
156 return nullptr;
157}
158
159/// If timing is enabled, report the times collected up to now and then reset
160/// them.
161void 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.
172Timer &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(Args: 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(Fmt: "{0} #{1}", Vals&: PassID, Vals&: Count).str();
187
188 Timer *T = new Timer(PassID, FullDesc, TG);
189 Timers.emplace_back(Args&: T);
190 assert(Count == Timers.size() && "Timers vector not adjusted correctly.");
191
192 return *T;
193}
194
195TimePassesHandler::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
200TimePassesHandler::TimePassesHandler()
201 : TimePassesHandler(TimePassesIsEnabled, TimePassesPerRun) {}
202
203void TimePassesHandler::setOutStream(raw_ostream &Out) {
204 OutStream = &Out;
205}
206
207void 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&: *OS, ResetAfterPrint: true);
219 AnalysisTG.print(OS&: *OS, ResetAfterPrint: true);
220}
221
222LLVM_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
246static bool shouldIgnorePass(StringRef PassID) {
247 return isSpecialPass(PassID,
248 Specials: {"PassManager", "PassAdaptor", "AnalysisManagerProxy",
249 "ModuleInlinerWrapperPass", "DevirtSCCRepeatedPass"});
250}
251
252void 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(Elt: &MyTimer);
263 assert(!MyTimer.isRunning());
264 MyTimer.startTimer();
265}
266
267void 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
283void 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(Elt: &MyTimer);
293 if (!MyTimer.isRunning())
294 MyTimer.startTimer();
295}
296
297void 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
311void TimePassesHandler::registerCallbacks(PassInstrumentationCallbacks &PIC) {
312 if (!Enabled)
313 return;
314
315 PIC.registerBeforeNonSkippedPassCallback(
316 C: [this](StringRef P, Any) { this->startPassTimer(PassID: P); });
317 PIC.registerAfterPassCallback(
318 C: [this](StringRef P, Any, const PreservedAnalyses &) {
319 this->stopPassTimer(PassID: P);
320 });
321 PIC.registerAfterPassInvalidatedCallback(
322 C: [this](StringRef P, const PreservedAnalyses &) {
323 this->stopPassTimer(PassID: P);
324 });
325 PIC.registerBeforeAnalysisCallback(
326 C: [this](StringRef P, Any) { this->startAnalysisTimer(PassID: P); });
327 PIC.registerAfterAnalysisCallback(
328 C: [this](StringRef P, Any) { this->stopAnalysisTimer(PassID: P); });
329}
330
331} // namespace llvm
332