Line data Source code
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 :
94 12 : PassTimingInfo::PassTimingInfo()
95 12 : : TG("pass", "... Pass execution timing report ...") {}
96 :
97 24 : 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 12 : TimingData.clear();
101 12 : }
102 :
103 101534865 : void PassTimingInfo::init() {
104 101534865 : 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 12 : static ManagedStatic<PassTimingInfo> TTI;
111 12 : TheTimeInfo = &*TTI;
112 : }
113 :
114 : /// Prints out timing information and then resets the timers.
115 0 : void PassTimingInfo::print() { TG.print(*CreateInfoOutputFile()); }
116 :
117 1033 : Timer *PassTimingInfo::newPassTimer(StringRef PassID, StringRef PassDesc) {
118 1033 : unsigned &num = PassIDCountMap[PassID];
119 1033 : num++;
120 : // Appending description with a pass-instance number for all but the first one
121 : std::string PassDescNumbered =
122 1033 : num <= 1 ? PassDesc.str() : formatv("{0} #{1}", PassDesc, num).str();
123 2066 : return new Timer(PassID, PassDescNumbered, TG);
124 : }
125 :
126 2337 : Timer *PassTimingInfo::getPassTimer(Pass *P, PassInstanceID Pass) {
127 2337 : if (P->getAsPMDataManager())
128 : return nullptr;
129 :
130 2269 : init();
131 2269 : sys::SmartScopedLock<true> Lock(*TimingInfoMutex);
132 2269 : std::unique_ptr<Timer> &T = TimingData[Pass];
133 :
134 2269 : if (!T) {
135 1033 : StringRef PassName = P->getPassName();
136 1033 : StringRef PassArgument;
137 1033 : if (const PassInfo *PI = Pass::lookupPassInfo(P->getPassID()))
138 1019 : PassArgument = PI->getPassArgument();
139 2052 : 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 :
148 101532587 : Timer *getPassTimer(Pass *P) {
149 101532587 : legacy::PassTimingInfo::init();
150 101532605 : if (legacy::PassTimingInfo::TheTimeInfo)
151 2337 : 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.
157 70 : void reportAndResetTimings() {
158 70 : if (legacy::PassTimingInfo::TheTimeInfo)
159 0 : legacy::PassTimingInfo::TheTimeInfo->print();
160 70 : }
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.
168 302 : Timer &TimePassesHandler::getPassTimer(StringRef PassID) {
169 : // Bump counts for each request of the timer.
170 302 : unsigned Count = nextPassID(PassID);
171 :
172 : // Unconditionally appending description with a pass-invocation number.
173 604 : std::string FullDesc = formatv("{0} #{1}", PassID, Count).str();
174 :
175 : PassInvocationID UID{PassID, Count};
176 604 : Timer *T = new Timer(PassID, FullDesc, TG);
177 302 : auto Pair = TimingData.try_emplace(UID, T);
178 : assert(Pair.second && "should always create a new timer");
179 302 : return *(Pair.first->second.get());
180 : }
181 :
182 936 : TimePassesHandler::TimePassesHandler(bool Enabled)
183 1872 : : TG("pass", "... Pass execution timing report ..."), Enabled(Enabled) {}
184 :
185 0 : void TimePassesHandler::print() { TG.print(*CreateInfoOutputFile()); }
186 :
187 0 : LLVM_DUMP_METHOD void TimePassesHandler::dump() const {
188 0 : dbgs() << "Dumping timers for " << getTypeName<TimePassesHandler>()
189 0 : << ":\n\tRunning:\n";
190 0 : for (auto &I : TimingData) {
191 : const Timer *MyTimer = I.second.get();
192 0 : if (!MyTimer || MyTimer->isRunning())
193 0 : dbgs() << "\tTimer " << MyTimer << " for pass " << I.first.first << "("
194 0 : << I.first.second << ")\n";
195 : }
196 0 : dbgs() << "\tTriggered:\n";
197 0 : for (auto &I : TimingData) {
198 : const Timer *MyTimer = I.second.get();
199 0 : if (!MyTimer || (MyTimer->hasTriggered() && !MyTimer->isRunning()))
200 0 : dbgs() << "\tTimer " << MyTimer << " for pass " << I.first.first << "("
201 0 : << I.first.second << ")\n";
202 : }
203 0 : }
204 :
205 302 : void TimePassesHandler::startTimer(StringRef PassID) {
206 302 : Timer &MyTimer = getPassTimer(PassID);
207 302 : TimerStack.push_back(&MyTimer);
208 302 : if (!MyTimer.isRunning())
209 302 : MyTimer.startTimer();
210 302 : }
211 :
212 302 : 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 302 : if (MyTimer->isRunning())
217 302 : MyTimer->stopTimer();
218 302 : }
219 :
220 790 : static bool matchPassManager(StringRef PassID) {
221 586 : size_t prefix_pos = PassID.find('<');
222 204 : if (prefix_pos == StringRef::npos)
223 586 : return false;
224 204 : StringRef Prefix = PassID.substr(0, prefix_pos);
225 : return Prefix.endswith("PassManager") || Prefix.endswith("PassAdaptor") ||
226 : Prefix.endswith("AnalysisManagerProxy");
227 : }
228 :
229 395 : bool TimePassesHandler::runBeforePass(StringRef PassID, Any IR) {
230 395 : if (matchPassManager(PassID))
231 : return true;
232 :
233 302 : 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 302 : return true;
240 : }
241 :
242 395 : void TimePassesHandler::runAfterPass(StringRef PassID, Any IR) {
243 395 : if (matchPassManager(PassID))
244 : return;
245 :
246 302 : stopTimer(PassID);
247 :
248 : LLVM_DEBUG(dbgs() << "after runAfterPass(" << PassID << ")\n");
249 : LLVM_DEBUG(dump());
250 : }
251 :
252 936 : void TimePassesHandler::registerCallbacks(PassInstrumentationCallbacks &PIC) {
253 936 : if (!Enabled)
254 : return;
255 :
256 3 : PIC.registerBeforePassCallback(
257 : [this](StringRef P, Any IR) { return this->runBeforePass(P, IR); });
258 3 : PIC.registerAfterPassCallback(
259 : [this](StringRef P, Any IR) { this->runAfterPass(P, IR); });
260 3 : PIC.registerBeforeAnalysisCallback(
261 : [this](StringRef P, Any IR) { this->runBeforePass(P, IR); });
262 3 : PIC.registerAfterAnalysisCallback(
263 : [this](StringRef P, Any IR) { this->runAfterPass(P, IR); });
264 : }
265 :
266 : } // namespace llvm
|
