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 // 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 184TimePassesHandler::TimePassesHandler(bool Enabled) 185 : TG("pass", "... Pass execution timing report ..."), Enabled(Enabled) {} 186 187void TimePassesHandler::setOutStream(raw_ostream &Out) { 188 OutStream = &Out; 189} 190 191void TimePassesHandler::print() { 192 if (!Enabled) 193 return; 194 TG.print(OutStream ? *OutStream : *CreateInfoOutputFile(), true); 195} 196 197LLVM_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 215void TimePassesHandler::startTimer(StringRef PassID) { 216 Timer &MyTimer = getPassTimer(PassID); 217 TimerStack.push_back(&MyTimer); 218 if (!MyTimer.isRunning()) 219 MyTimer.startTimer(); 220} 221 222void 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 230static 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 239bool 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 252void 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 262void 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