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/DenseMap.h" 20 #include "llvm/ADT/Statistic.h" 21 #include "llvm/ADT/StringRef.h" 22 #include "llvm/IR/PassInstrumentation.h" 23 #include "llvm/Pass.h" 24 #include "llvm/Support/CommandLine.h" 25 #include "llvm/Support/Debug.h" 26 #include "llvm/Support/FormatVariadic.h" 27 #include "llvm/Support/ManagedStatic.h" 28 #include "llvm/Support/Mutex.h" 29 #include "llvm/Support/Timer.h" 30 #include "llvm/Support/raw_ostream.h" 31 #include <memory> 32 #include <string> 33 34 using namespace llvm; 35 36 #define DEBUG_TYPE "time-passes" 37 38 namespace llvm { 39 40 bool TimePassesIsEnabled = false; 41 42 static cl::opt<bool, true> EnableTiming( 43 "time-passes", cl::location(TimePassesIsEnabled), cl::Hidden, 44 cl::desc("Time each pass, printing elapsed time for each on exit")); 45 46 namespace { 47 namespace legacy { 48 49 //===----------------------------------------------------------------------===// 50 // Legacy pass manager's PassTimingInfo implementation 51 52 /// Provides an interface for collecting pass timing information. 53 /// 54 /// It was intended to be generic but now we decided to split 55 /// interfaces completely. This is now exclusively for legacy-pass-manager use. 56 class PassTimingInfo { 57 public: 58 using PassInstanceID = void *; 59 60 private: 61 StringMap<unsigned> PassIDCountMap; ///< Map that counts instances of passes 62 DenseMap<PassInstanceID, std::unique_ptr<Timer>> TimingData; ///< timers for pass instances 63 TimerGroup TG; 64 65 public: 66 /// Default constructor for yet-inactive timeinfo. 67 /// Use \p init() to activate it. 68 PassTimingInfo(); 69 70 /// Print out timing information and release timers. 71 ~PassTimingInfo(); 72 73 /// Initializes the static \p TheTimeInfo member to a non-null value when 74 /// -time-passes is enabled. Leaves it null otherwise. 75 /// 76 /// This method may be called multiple times. 77 static void init(); 78 79 /// Prints out timing information and then resets the timers. 80 /// By default it uses the stream created by CreateInfoOutputFile(). 81 void print(raw_ostream *OutStream = nullptr); 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 PassTimingInfo::PassTimingInfo() 95 : TG("pass", "... Pass execution timing report ...") {} 96 97 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 TimingData.clear(); 101 } 102 103 void PassTimingInfo::init() { 104 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 static ManagedStatic<PassTimingInfo> TTI; 111 TheTimeInfo = &*TTI; 112 } 113 114 /// Prints out timing information and then resets the timers. 115 void PassTimingInfo::print(raw_ostream *OutStream) { 116 TG.print(OutStream ? *OutStream : *CreateInfoOutputFile(), true); 117 } 118 119 Timer *PassTimingInfo::newPassTimer(StringRef PassID, StringRef PassDesc) { 120 unsigned &num = PassIDCountMap[PassID]; 121 num++; 122 // Appending description with a pass-instance number for all but the first one 123 std::string PassDescNumbered = 124 num <= 1 ? PassDesc.str() : formatv("{0} #{1}", PassDesc, num).str(); 125 return new Timer(PassID, PassDescNumbered, TG); 126 } 127 128 Timer *PassTimingInfo::getPassTimer(Pass *P, PassInstanceID Pass) { 129 if (P->getAsPMDataManager()) 130 return nullptr; 131 132 init(); 133 sys::SmartScopedLock<true> Lock(*TimingInfoMutex); 134 std::unique_ptr<Timer> &T = TimingData[Pass]; 135 136 if (!T) { 137 StringRef PassName = P->getPassName(); 138 StringRef PassArgument; 139 if (const PassInfo *PI = Pass::lookupPassInfo(P->getPassID())) 140 PassArgument = PI->getPassArgument(); 141 T.reset(newPassTimer(PassArgument.empty() ? PassName : PassArgument, PassName)); 142 } 143 return T.get(); 144 } 145 146 PassTimingInfo *PassTimingInfo::TheTimeInfo; 147 } // namespace legacy 148 } // namespace 149 150 Timer *getPassTimer(Pass *P) { 151 legacy::PassTimingInfo::init(); 152 if (legacy::PassTimingInfo::TheTimeInfo) 153 return legacy::PassTimingInfo::TheTimeInfo->getPassTimer(P, P); 154 return nullptr; 155 } 156 157 /// If timing is enabled, report the times collected up to now and then reset 158 /// them. 159 void reportAndResetTimings(raw_ostream *OutStream) { 160 if (legacy::PassTimingInfo::TheTimeInfo) 161 legacy::PassTimingInfo::TheTimeInfo->print(OutStream); 162 } 163 164 //===----------------------------------------------------------------------===// 165 // Pass timing handling for the New Pass Manager 166 //===----------------------------------------------------------------------===// 167 168 /// Returns the timer for the specified pass invocation of \p PassID. 169 /// Each time it creates a new timer. 170 Timer &TimePassesHandler::getPassTimer(StringRef PassID) { 171 // Bump counts for each request of the timer. 172 unsigned Count = nextPassID(PassID); 173 174 // Unconditionally appending description with a pass-invocation number. 175 std::string FullDesc = formatv("{0} #{1}", PassID, Count).str(); 176 177 PassInvocationID UID{PassID, Count}; 178 Timer *T = new Timer(PassID, FullDesc, TG); 179 auto Pair = TimingData.try_emplace(UID, T); 180 assert(Pair.second && "should always create a new timer"); 181 return *(Pair.first->second.get()); 182 } 183 184 TimePassesHandler::TimePassesHandler(bool Enabled) 185 : TG("pass", "... Pass execution timing report ..."), Enabled(Enabled) {} 186 187 void TimePassesHandler::setOutStream(raw_ostream &Out) { 188 OutStream = &Out; 189 } 190 191 void TimePassesHandler::print() { 192 if (!Enabled) 193 return; 194 TG.print(OutStream ? *OutStream : *CreateInfoOutputFile(), true); 195 } 196 197 LLVM_DUMP_METHOD void TimePassesHandler::dump() const { 198 dbgs() << "Dumping timers for " << getTypeName<TimePassesHandler>() 199 << ":\n\tRunning:\n"; 200 for (auto &I : TimingData) { 201 const Timer *MyTimer = I.second.get(); 202 if (!MyTimer || MyTimer->isRunning()) 203 dbgs() << "\tTimer " << MyTimer << " for pass " << I.first.first << "(" 204 << I.first.second << ")\n"; 205 } 206 dbgs() << "\tTriggered:\n"; 207 for (auto &I : TimingData) { 208 const Timer *MyTimer = I.second.get(); 209 if (!MyTimer || (MyTimer->hasTriggered() && !MyTimer->isRunning())) 210 dbgs() << "\tTimer " << MyTimer << " for pass " << I.first.first << "(" 211 << I.first.second << ")\n"; 212 } 213 } 214 215 void TimePassesHandler::startTimer(StringRef PassID) { 216 Timer &MyTimer = getPassTimer(PassID); 217 TimerStack.push_back(&MyTimer); 218 if (!MyTimer.isRunning()) 219 MyTimer.startTimer(); 220 } 221 222 void TimePassesHandler::stopTimer(StringRef PassID) { 223 assert(TimerStack.size() > 0 && "empty stack in popTimer"); 224 Timer *MyTimer = TimerStack.pop_back_val(); 225 assert(MyTimer && "timer should be present"); 226 if (MyTimer->isRunning()) 227 MyTimer->stopTimer(); 228 } 229 230 static bool matchPassManager(StringRef PassID) { 231 size_t prefix_pos = PassID.find('<'); 232 if (prefix_pos == StringRef::npos) 233 return false; 234 StringRef Prefix = PassID.substr(0, prefix_pos); 235 return Prefix.endswith("PassManager") || Prefix.endswith("PassAdaptor") || 236 Prefix.endswith("AnalysisManagerProxy"); 237 } 238 239 bool TimePassesHandler::runBeforePass(StringRef PassID) { 240 if (matchPassManager(PassID)) 241 return true; 242 243 startTimer(PassID); 244 245 LLVM_DEBUG(dbgs() << "after runBeforePass(" << PassID << ")\n"); 246 LLVM_DEBUG(dump()); 247 248 // we are not going to skip this pass, thus return true. 249 return true; 250 } 251 252 void TimePassesHandler::runAfterPass(StringRef PassID) { 253 if (matchPassManager(PassID)) 254 return; 255 256 stopTimer(PassID); 257 258 LLVM_DEBUG(dbgs() << "after runAfterPass(" << PassID << ")\n"); 259 LLVM_DEBUG(dump()); 260 } 261 262 void TimePassesHandler::registerCallbacks(PassInstrumentationCallbacks &PIC) { 263 if (!Enabled) 264 return; 265 266 PIC.registerBeforePassCallback( 267 [this](StringRef P, Any) { return this->runBeforePass(P); }); 268 PIC.registerAfterPassCallback( 269 [this](StringRef P, Any) { this->runAfterPass(P); }); 270 PIC.registerAfterPassInvalidatedCallback( 271 [this](StringRef P) { this->runAfterPass(P); }); 272 PIC.registerBeforeAnalysisCallback( 273 [this](StringRef P, Any) { this->runBeforePass(P); }); 274 PIC.registerAfterAnalysisCallback( 275 [this](StringRef P, Any) { this->runAfterPass(P); }); 276 } 277 278 } // namespace llvm 279