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 *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 std::unique_ptr<Timer> &T = TimingData[Pass];
127
128 if (!T) {
129 StringRef PassName = P->getPassName();
130 StringRef PassArgument;
131 if (const PassInfo *PI = Pass::lookupPassInfo(TI: P->getPassID()))
132 PassArgument = PI->getPassArgument();
133 T.reset(p: newPassTimer(PassID: PassArgument.empty() ? PassName : PassArgument, PassDesc: PassName));
134 }
135 return T.get();
136}
137
138PassTimingInfo *PassTimingInfo::TheTimeInfo;
139} // namespace legacy
140} // namespace
141
142Timer *getPassTimer(Pass *P) {
143 legacy::PassTimingInfo::init();
144 if (legacy::PassTimingInfo::TheTimeInfo)
145 return legacy::PassTimingInfo::TheTimeInfo->getPassTimer(P, Pass: P);
146 return nullptr;
147}
148
149/// If timing is enabled, report the times collected up to now and then reset
150/// them.
151void reportAndResetTimings(raw_ostream *OutStream) {
152 if (legacy::PassTimingInfo::TheTimeInfo)
153 legacy::PassTimingInfo::TheTimeInfo->print(OutStream);
154}
155
156//===----------------------------------------------------------------------===//
157// Pass timing handling for the New Pass Manager
158//===----------------------------------------------------------------------===//
159
160/// Returns the timer for the specified pass invocation of \p PassID.
161/// Each time it creates a new timer.
162Timer &TimePassesHandler::getPassTimer(StringRef PassID, bool IsPass) {
163 TimerGroup &TG = IsPass ? PassTG : AnalysisTG;
164 if (!PerRun) {
165 TimerVector &Timers = TimingData[PassID];
166 if (Timers.size() == 0)
167 Timers.emplace_back(Args: new Timer(PassID, PassID, TG));
168 return *Timers.front();
169 }
170
171 // Take a vector of Timers created for this \p PassID and append
172 // one more timer to it.
173 TimerVector &Timers = TimingData[PassID];
174 unsigned Count = Timers.size() + 1;
175
176 std::string FullDesc = formatv(Fmt: "{0} #{1}", Vals&: PassID, Vals&: Count).str();
177
178 Timer *T = new Timer(PassID, FullDesc, TG);
179 Timers.emplace_back(Args&: T);
180 assert(Count == Timers.size() && "Timers vector not adjusted correctly.");
181
182 return *T;
183}
184
185TimePassesHandler::TimePassesHandler(bool Enabled, bool PerRun)
186 : Enabled(Enabled), PerRun(PerRun) {}
187
188TimePassesHandler::TimePassesHandler()
189 : TimePassesHandler(TimePassesIsEnabled, TimePassesPerRun) {}
190
191void TimePassesHandler::setOutStream(raw_ostream &Out) {
192 OutStream = &Out;
193}
194
195void TimePassesHandler::print() {
196 if (!Enabled)
197 return;
198 std::unique_ptr<raw_ostream> MaybeCreated;
199 raw_ostream *OS = OutStream;
200 if (OutStream) {
201 OS = OutStream;
202 } else {
203 MaybeCreated = CreateInfoOutputFile();
204 OS = &*MaybeCreated;
205 }
206 PassTG.print(OS&: *OS, ResetAfterPrint: true);
207 AnalysisTG.print(OS&: *OS, ResetAfterPrint: true);
208}
209
210LLVM_DUMP_METHOD void TimePassesHandler::dump() const {
211 dbgs() << "Dumping timers for " << getTypeName<TimePassesHandler>()
212 << ":\n\tRunning:\n";
213 for (auto &I : TimingData) {
214 StringRef PassID = I.getKey();
215 const TimerVector& MyTimers = I.getValue();
216 for (unsigned idx = 0; idx < MyTimers.size(); idx++) {
217 const Timer* MyTimer = MyTimers[idx].get();
218 if (MyTimer && MyTimer->isRunning())
219 dbgs() << "\tTimer " << MyTimer << " for pass " << PassID << "(" << idx << ")\n";
220 }
221 }
222 dbgs() << "\tTriggered:\n";
223 for (auto &I : TimingData) {
224 StringRef PassID = I.getKey();
225 const TimerVector& MyTimers = I.getValue();
226 for (unsigned idx = 0; idx < MyTimers.size(); idx++) {
227 const Timer* MyTimer = MyTimers[idx].get();
228 if (MyTimer && MyTimer->hasTriggered() && !MyTimer->isRunning())
229 dbgs() << "\tTimer " << MyTimer << " for pass " << PassID << "(" << idx << ")\n";
230 }
231 }
232}
233
234static bool shouldIgnorePass(StringRef PassID) {
235 return isSpecialPass(PassID,
236 Specials: {"PassManager", "PassAdaptor", "AnalysisManagerProxy",
237 "ModuleInlinerWrapperPass", "DevirtSCCRepeatedPass"});
238}
239
240void TimePassesHandler::startPassTimer(StringRef PassID) {
241 if (shouldIgnorePass(PassID))
242 return;
243 // Stop the previous pass timer to prevent double counting when a
244 // pass requests another pass.
245 if (!PassActiveTimerStack.empty()) {
246 assert(PassActiveTimerStack.back()->isRunning());
247 PassActiveTimerStack.back()->stopTimer();
248 }
249 Timer &MyTimer = getPassTimer(PassID, /*IsPass*/ true);
250 PassActiveTimerStack.push_back(Elt: &MyTimer);
251 assert(!MyTimer.isRunning());
252 MyTimer.startTimer();
253}
254
255void TimePassesHandler::stopPassTimer(StringRef PassID) {
256 if (shouldIgnorePass(PassID))
257 return;
258 assert(!PassActiveTimerStack.empty() && "empty stack in popTimer");
259 Timer *MyTimer = PassActiveTimerStack.pop_back_val();
260 assert(MyTimer && "timer should be present");
261 assert(MyTimer->isRunning());
262 MyTimer->stopTimer();
263
264 // Restart the previously stopped timer.
265 if (!PassActiveTimerStack.empty()) {
266 assert(!PassActiveTimerStack.back()->isRunning());
267 PassActiveTimerStack.back()->startTimer();
268 }
269}
270
271void TimePassesHandler::startAnalysisTimer(StringRef PassID) {
272 // Stop the previous analysis timer to prevent double counting when an
273 // analysis requests another analysis.
274 if (!AnalysisActiveTimerStack.empty()) {
275 assert(AnalysisActiveTimerStack.back()->isRunning());
276 AnalysisActiveTimerStack.back()->stopTimer();
277 }
278
279 Timer &MyTimer = getPassTimer(PassID, /*IsPass*/ false);
280 AnalysisActiveTimerStack.push_back(Elt: &MyTimer);
281 if (!MyTimer.isRunning())
282 MyTimer.startTimer();
283}
284
285void TimePassesHandler::stopAnalysisTimer(StringRef PassID) {
286 assert(!AnalysisActiveTimerStack.empty() && "empty stack in popTimer");
287 Timer *MyTimer = AnalysisActiveTimerStack.pop_back_val();
288 assert(MyTimer && "timer should be present");
289 if (MyTimer->isRunning())
290 MyTimer->stopTimer();
291
292 // Restart the previously stopped timer.
293 if (!AnalysisActiveTimerStack.empty()) {
294 assert(!AnalysisActiveTimerStack.back()->isRunning());
295 AnalysisActiveTimerStack.back()->startTimer();
296 }
297}
298
299void TimePassesHandler::registerCallbacks(PassInstrumentationCallbacks &PIC) {
300 if (!Enabled)
301 return;
302
303 PIC.registerBeforeNonSkippedPassCallback(
304 C: [this](StringRef P, Any) { this->startPassTimer(PassID: P); });
305 PIC.registerAfterPassCallback(
306 C: [this](StringRef P, Any, const PreservedAnalyses &) {
307 this->stopPassTimer(PassID: P);
308 });
309 PIC.registerAfterPassInvalidatedCallback(
310 C: [this](StringRef P, const PreservedAnalyses &) {
311 this->stopPassTimer(PassID: P);
312 });
313 PIC.registerBeforeAnalysisCallback(
314 C: [this](StringRef P, Any) { this->startAnalysisTimer(PassID: P); });
315 PIC.registerAfterAnalysisCallback(
316 C: [this](StringRef P, Any) { this->stopAnalysisTimer(PassID: P); });
317}
318
319} // namespace llvm
320