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
35using namespace llvm;
36
37bool llvm::TimePassesIsEnabled = false;
38bool llvm::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 *PassTG = nullptr;
67
68public:
69 /// Initializes the static \p TheTimeInfo member to a non-null value when
70 /// -time-passes is enabled. Leaves it null otherwise.
71 ///
72 /// This method may be called multiple times.
73 static void init();
74
75 /// Prints out timing information and then resets the timers.
76 /// By default it uses the stream created by CreateInfoOutputFile().
77 void print(raw_ostream *OutStream = nullptr);
78
79 /// Returns the timer for the specified pass if it exists.
80 Timer *getPassTimer(Pass *, PassInstanceID);
81
82 static PassTimingInfo *TheTimeInfo;
83
84private:
85 Timer *newPassTimer(StringRef PassID, StringRef PassDesc);
86};
87
88static ManagedStatic<sys::SmartMutex<true>> TimingInfoMutex;
89
90void PassTimingInfo::init() {
91 if (TheTimeInfo || !TimePassesIsEnabled)
92 return;
93
94 // Constructed the first time this is called, iff -time-passes is enabled.
95 // This guarantees that the object will be constructed after static globals,
96 // thus it will be destroyed before them.
97 static ManagedStatic<PassTimingInfo> TTI;
98 if (!TTI->PassTG)
99 TTI->PassTG = &NamedRegionTimer::getNamedTimerGroup(
100 GroupName: TimePassesHandler::PassGroupName, GroupDescription: TimePassesHandler::PassGroupDesc);
101 TheTimeInfo = &*TTI;
102}
103
104/// Prints out timing information and then resets the timers.
105void PassTimingInfo::print(raw_ostream *OutStream) {
106 assert(PassTG && "PassTG is null, did you call PassTimingInfo::Init()?");
107 PassTG->print(OS&: OutStream ? *OutStream : *CreateInfoOutputFile(), ResetAfterPrint: true);
108}
109
110Timer *PassTimingInfo::newPassTimer(StringRef PassID, StringRef PassDesc) {
111 unsigned &num = PassIDCountMap[PassID];
112 num++;
113 // Appending description with a pass-instance number for all but the first one
114 std::string PassDescNumbered =
115 num <= 1 ? PassDesc.str() : formatv(Fmt: "{0} #{1}", Vals&: PassDesc, Vals&: num).str();
116 assert(PassTG && "PassTG is null, did you call PassTimingInfo::Init()?");
117 return new Timer(PassID, PassDescNumbered, *PassTG);
118}
119
120Timer *PassTimingInfo::getPassTimer(Pass *P, PassInstanceID Pass) {
121 if (P->getAsPMDataManager())
122 return nullptr;
123
124 init();
125 sys::SmartScopedLock<true> Lock(*TimingInfoMutex);
126 StringRef PassName = P->getPassName();
127 StringRef PassArgument;
128 if (const PassInfo *PI = Pass::lookupPassInfo(TI: P->getPassID()))
129 PassArgument = PI->getPassArgument();
130 StringRef TimerName = PassArgument.empty() ? PassName : PassArgument;
131
132 std::unique_ptr<Timer> &T = TimingData[Pass];
133
134 // This map outlives the pass instances it is keyed on, so a new pass can be
135 // allocated at a destroyed one's address. Its timer carries the old name.
136 if (T && T->getName() != TimerName)
137 T.reset();
138
139 if (!T)
140 T.reset(p: newPassTimer(PassID: TimerName, PassDesc: PassName));
141 return T.get();
142}
143
144PassTimingInfo *PassTimingInfo::TheTimeInfo;
145} // namespace legacy
146} // namespace
147
148Timer *llvm::getPassTimer(Pass *P) {
149 legacy::PassTimingInfo::init();
150 if (legacy::PassTimingInfo::TheTimeInfo)
151 return legacy::PassTimingInfo::TheTimeInfo->getPassTimer(P, Pass: P);
152 return nullptr;
153}
154
155/// If timing is enabled, report the times collected up to now and then reset
156/// them.
157void llvm::reportAndResetTimings(raw_ostream *OutStream) {
158 if (legacy::PassTimingInfo::TheTimeInfo)
159 legacy::PassTimingInfo::TheTimeInfo->print(OutStream);
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.
168Timer &TimePassesHandler::getPassTimer(StringRef PassID, bool IsPass) {
169 TimerGroup &TG = IsPass ? PassTG : AnalysisTG;
170 if (!PerRun) {
171 TimerVector &Timers = TimingData[PassID];
172 if (Timers.size() == 0)
173 Timers.emplace_back(Args: new Timer(PassID, PassID, TG));
174 return *Timers.front();
175 }
176
177 // Take a vector of Timers created for this \p PassID and append
178 // one more timer to it.
179 TimerVector &Timers = TimingData[PassID];
180 unsigned Count = Timers.size() + 1;
181
182 std::string FullDesc = formatv(Fmt: "{0} #{1}", Vals&: PassID, Vals&: Count).str();
183
184 Timer *T = new Timer(PassID, FullDesc, TG);
185 Timers.emplace_back(Args&: T);
186 assert(Count == Timers.size() && "Timers vector not adjusted correctly.");
187
188 return *T;
189}
190
191TimePassesHandler::TimePassesHandler(bool Enabled, bool PerRun)
192 : Enabled(Enabled), PerRun(PerRun) {}
193
194TimePassesHandler::TimePassesHandler()
195 : TimePassesHandler(TimePassesIsEnabled, TimePassesPerRun) {}
196
197void TimePassesHandler::setOutStream(raw_ostream &Out) {
198 OutStream = &Out;
199}
200
201void TimePassesHandler::print() {
202 if (!Enabled)
203 return;
204 std::unique_ptr<raw_ostream> MaybeCreated;
205 raw_ostream *OS = OutStream;
206 if (OutStream) {
207 OS = OutStream;
208 } else {
209 MaybeCreated = CreateInfoOutputFile();
210 OS = &*MaybeCreated;
211 }
212 PassTG.print(OS&: *OS, ResetAfterPrint: true);
213 AnalysisTG.print(OS&: *OS, ResetAfterPrint: true);
214}
215
216LLVM_DUMP_METHOD void TimePassesHandler::dump() const {
217 dbgs() << "Dumping timers for " << getTypeName<TimePassesHandler>()
218 << ":\n\tRunning:\n";
219 for (auto &I : TimingData) {
220 StringRef PassID = I.getKey();
221 const TimerVector& MyTimers = I.getValue();
222 for (unsigned idx = 0; idx < MyTimers.size(); idx++) {
223 const Timer* MyTimer = MyTimers[idx].get();
224 if (MyTimer && MyTimer->isRunning())
225 dbgs() << "\tTimer " << MyTimer << " for pass " << PassID << "(" << idx << ")\n";
226 }
227 }
228 dbgs() << "\tTriggered:\n";
229 for (auto &I : TimingData) {
230 StringRef PassID = I.getKey();
231 const TimerVector& MyTimers = I.getValue();
232 for (unsigned idx = 0; idx < MyTimers.size(); idx++) {
233 const Timer* MyTimer = MyTimers[idx].get();
234 if (MyTimer && MyTimer->hasTriggered() && !MyTimer->isRunning())
235 dbgs() << "\tTimer " << MyTimer << " for pass " << PassID << "(" << idx << ")\n";
236 }
237 }
238}
239
240static bool shouldIgnorePass(StringRef PassID) {
241 return isSpecialPass(PassID,
242 Specials: {"PassManager", "PassAdaptor", "AnalysisManagerProxy",
243 "ModuleInlinerWrapperPass", "DevirtSCCRepeatedPass"});
244}
245
246void TimePassesHandler::startPassTimer(StringRef PassID) {
247 if (shouldIgnorePass(PassID))
248 return;
249 // Stop the previous pass timer to prevent double counting when a
250 // pass requests another pass.
251 if (!PassActiveTimerStack.empty()) {
252 assert(PassActiveTimerStack.back()->isRunning());
253 PassActiveTimerStack.back()->stopTimer();
254 }
255 Timer &MyTimer = getPassTimer(PassID, /*IsPass*/ true);
256 PassActiveTimerStack.push_back(Elt: &MyTimer);
257 assert(!MyTimer.isRunning());
258 MyTimer.startTimer();
259}
260
261void TimePassesHandler::stopPassTimer(StringRef PassID) {
262 if (shouldIgnorePass(PassID))
263 return;
264 assert(!PassActiveTimerStack.empty() && "empty stack in popTimer");
265 Timer *MyTimer = PassActiveTimerStack.pop_back_val();
266 assert(MyTimer && "timer should be present");
267 assert(MyTimer->isRunning());
268 MyTimer->stopTimer();
269
270 // Restart the previously stopped timer.
271 if (!PassActiveTimerStack.empty()) {
272 assert(!PassActiveTimerStack.back()->isRunning());
273 PassActiveTimerStack.back()->startTimer();
274 }
275}
276
277void TimePassesHandler::startAnalysisTimer(StringRef PassID) {
278 // Stop the previous analysis timer to prevent double counting when an
279 // analysis requests another analysis.
280 if (!AnalysisActiveTimerStack.empty()) {
281 assert(AnalysisActiveTimerStack.back()->isRunning());
282 AnalysisActiveTimerStack.back()->stopTimer();
283 }
284
285 Timer &MyTimer = getPassTimer(PassID, /*IsPass*/ false);
286 AnalysisActiveTimerStack.push_back(Elt: &MyTimer);
287 if (!MyTimer.isRunning())
288 MyTimer.startTimer();
289}
290
291void TimePassesHandler::stopAnalysisTimer(StringRef PassID) {
292 assert(!AnalysisActiveTimerStack.empty() && "empty stack in popTimer");
293 Timer *MyTimer = AnalysisActiveTimerStack.pop_back_val();
294 assert(MyTimer && "timer should be present");
295 if (MyTimer->isRunning())
296 MyTimer->stopTimer();
297
298 // Restart the previously stopped timer.
299 if (!AnalysisActiveTimerStack.empty()) {
300 assert(!AnalysisActiveTimerStack.back()->isRunning());
301 AnalysisActiveTimerStack.back()->startTimer();
302 }
303}
304
305void TimePassesHandler::registerCallbacks(PassInstrumentationCallbacks &PIC) {
306 if (!Enabled)
307 return;
308
309 PIC.registerBeforeNonSkippedPassCallback(
310 C: [this](StringRef P, IRUnitRef) { this->startPassTimer(PassID: P); });
311 PIC.registerAfterPassCallback(
312 C: [this](StringRef P, IRUnitRef, const PreservedAnalyses &) {
313 this->stopPassTimer(PassID: P);
314 });
315 PIC.registerAfterPassInvalidatedCallback(
316 C: [this](StringRef P, const PreservedAnalyses &) {
317 this->stopPassTimer(PassID: P);
318 });
319 PIC.registerBeforeAnalysisCallback(
320 C: [this](StringRef P, IRUnitRef) { this->startAnalysisTimer(PassID: P); });
321 PIC.registerAfterAnalysisCallback(
322 C: [this](StringRef P, IRUnitRef) { this->stopAnalysisTimer(PassID: P); });
323}
324