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 34using namespace llvm; 35 36#define DEBUG_TYPE "time-passes" 37 38namespace llvm { 39 40bool TimePassesIsEnabled = false; 41 42static 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 46namespace { 47namespace 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. 56class PassTimingInfo { 57public: 58 using PassInstanceID = void *; 59 60private: 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 65public: 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 88private: 89 Timer *newPassTimer(StringRef PassID, StringRef PassDesc); 90}; 91 92static ManagedStatic<sys::SmartMutex<true>> TimingInfoMutex; 93 94PassTimingInfo::PassTimingInfo() 95 : TG("pass", "... Pass execution timing report ...") {} 96 97PassTimingInfo::~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 103void 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. 115void PassTimingInfo::print(raw_ostream *OutStream) { 116 TG.print(OutStream ? *OutStream : *CreateInfoOutputFile(), true); 117} 118 119Timer *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 128Timer *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 146PassTimingInfo *PassTimingInfo::TheTimeInfo; 147} // namespace legacy 148} // namespace 149 150Timer *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. 159void 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. 170Timer &TimePassesHandler::getPassTimer(StringRef PassID) { 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("{0} #{1}", PassID, Count).str(); 177 178 Timer *T = new Timer(PassID, FullDesc, TG); 179 Timers.emplace_back(T); 180 assert(Count == Timers.size() && "sanity check"); 181 182 return *T; 183} 184 185TimePassesHandler::TimePassesHandler(bool Enabled) 186 : TG("pass", "... Pass execution timing report ..."), Enabled(Enabled) {} 187 188void TimePassesHandler::setOutStream(raw_ostream &Out) { 189 OutStream = &Out; 190} 191 192void TimePassesHandler::print() { 193 if (!Enabled) 194 return; 195 TG.print(OutStream ? *OutStream : *CreateInfoOutputFile(), true); 196} 197 198LLVM_DUMP_METHOD void TimePassesHandler::dump() const { 199 dbgs() << "Dumping timers for " << getTypeName<TimePassesHandler>() 200 << ":\n\tRunning:\n"; 201 for (auto &I : TimingData) { 202 StringRef PassID = I.getKey(); 203 const TimerVector& MyTimers = I.getValue(); 204 for (unsigned idx = 0; idx < MyTimers.size(); idx++) { 205 const Timer* MyTimer = MyTimers[idx].get(); 206 if (MyTimer && MyTimer->isRunning()) 207 dbgs() << "\tTimer " << MyTimer << " for pass " << PassID << "(" << idx << ")\n"; 208 } 209 } 210 dbgs() << "\tTriggered:\n"; 211 for (auto &I : TimingData) { 212 StringRef PassID = I.getKey(); 213 const TimerVector& MyTimers = I.getValue(); 214 for (unsigned idx = 0; idx < MyTimers.size(); idx++) { 215 const Timer* MyTimer = MyTimers[idx].get(); 216 if (MyTimer && MyTimer->hasTriggered() && !MyTimer->isRunning()) 217 dbgs() << "\tTimer " << MyTimer << " for pass " << PassID << "(" << idx << ")\n"; 218 } 219 } 220} 221 222void TimePassesHandler::startTimer(StringRef PassID) { 223 Timer &MyTimer = getPassTimer(PassID); 224 TimerStack.push_back(&MyTimer); 225 if (!MyTimer.isRunning()) 226 MyTimer.startTimer(); 227} 228 229void TimePassesHandler::stopTimer(StringRef PassID) { 230 assert(TimerStack.size() > 0 && "empty stack in popTimer"); 231 Timer *MyTimer = TimerStack.pop_back_val(); 232 assert(MyTimer && "timer should be present"); 233 if (MyTimer->isRunning()) 234 MyTimer->stopTimer(); 235} 236 237static bool matchPassManager(StringRef PassID) { 238 size_t prefix_pos = PassID.find('<'); 239 if (prefix_pos == StringRef::npos) 240 return false; 241 StringRef Prefix = PassID.substr(0, prefix_pos); 242 return Prefix.endswith("PassManager") || Prefix.endswith("PassAdaptor") || 243 Prefix.endswith("AnalysisManagerProxy"); 244} 245 246bool TimePassesHandler::runBeforePass(StringRef PassID) { 247 if (matchPassManager(PassID)) 248 return true; 249 250 startTimer(PassID); 251 252 LLVM_DEBUG(dbgs() << "after runBeforePass(" << PassID << ")\n"); 253 LLVM_DEBUG(dump()); 254 255 // we are not going to skip this pass, thus return true. 256 return true; 257} 258 259void TimePassesHandler::runAfterPass(StringRef PassID) { 260 if (matchPassManager(PassID)) 261 return; 262 263 stopTimer(PassID); 264 265 LLVM_DEBUG(dbgs() << "after runAfterPass(" << PassID << ")\n"); 266 LLVM_DEBUG(dump()); 267} 268 269void TimePassesHandler::registerCallbacks(PassInstrumentationCallbacks &PIC) { 270 if (!Enabled) 271 return; 272 273 PIC.registerBeforePassCallback( 274 [this](StringRef P, Any) { return this->runBeforePass(P); }); 275 PIC.registerAfterPassCallback( 276 [this](StringRef P, Any) { this->runAfterPass(P); }); 277 PIC.registerAfterPassInvalidatedCallback( 278 [this](StringRef P) { this->runAfterPass(P); }); 279 PIC.registerBeforeAnalysisCallback( 280 [this](StringRef P, Any) { this->runBeforePass(P); }); 281 PIC.registerAfterAnalysisCallback( 282 [this](StringRef P, Any) { this->runAfterPass(P); }); 283} 284 285} // namespace llvm 286