Files
clang-p2996/llvm/lib/IR/PassTimingInfo.cpp
Alan Zhao 09d8e442ac [llvm][Timer] Use global TimerGroups for both new pass manager and old pass manager timers (#130375)
Additionally, remove the behavior for both pass manager's timer manager
classes (`PassTimingInfo` for the old pass manager and
`TimePassesHandler` for the new pass manager) where these classes would
print the values of their timers upon destruction.

Currently, each pass manager manages their own `TimerGroup`s. This is
problematic because of duplicate `TimerGroup`s (both pass managers have
a `TimerGroup` for pass times with identical names and descriptions).
The result is that in Clang, `-ftime-report` has two "Pass execution
timing report" sections (one for the new pass manager which manages
optimization passes, and one for the old pass manager which manages the
backend). The result of this change is that Clang's `-ftime-report` now
prints both optimization and backend pass timing info in a unified "Pass
execution timing report" section.

Moving the ownership of the `TimerGroups` to globals also makes it
easier to implement JSON-formatted `-ftime-report`. This was not
possible with the old structure because the two pass managers were
created and destroyed in far parts of the codebase and outputting JSON
requires the printing logic to be at the same place because of
formatting.

Previous discourse discussion:
https://discourse.llvm.org/t/difficulties-with-implementing-json-formatted-ftime-report/84353
2025-03-13 10:13:28 -07:00

320 lines
11 KiB
C++

//===- PassTimingInfo.cpp - LLVM Pass Timing Implementation ---------------===//
//
// Part of the LLVM Project, under the Apache License v2.0 with LLVM Exceptions.
// See https://llvm.org/LICENSE.txt for license information.
// SPDX-License-Identifier: Apache-2.0 WITH LLVM-exception
//
//===----------------------------------------------------------------------===//
//
// This file implements the LLVM Pass Timing infrastructure for both
// new and legacy pass managers.
//
// PassTimingInfo Class - This class is used to calculate information about the
// amount of time each pass takes to execute. This only happens when
// -time-passes is enabled on the command line.
//
//===----------------------------------------------------------------------===//
#include "llvm/IR/PassTimingInfo.h"
#include "llvm/ADT/Statistic.h"
#include "llvm/IR/PassInstrumentation.h"
#include "llvm/Pass.h"
#include "llvm/Support/CommandLine.h"
#include "llvm/Support/Debug.h"
#include "llvm/Support/FormatVariadic.h"
#include "llvm/Support/ManagedStatic.h"
#include "llvm/Support/Mutex.h"
#include "llvm/Support/TypeName.h"
#include "llvm/Support/raw_ostream.h"
#include <string>
using namespace llvm;
#define DEBUG_TYPE "time-passes"
namespace llvm {
bool TimePassesIsEnabled = false;
bool TimePassesPerRun = false;
static cl::opt<bool, true> EnableTiming(
"time-passes", cl::location(TimePassesIsEnabled), cl::Hidden,
cl::desc("Time each pass, printing elapsed time for each on exit"));
static cl::opt<bool, true> EnableTimingPerRun(
"time-passes-per-run", cl::location(TimePassesPerRun), cl::Hidden,
cl::desc("Time each pass run, printing elapsed time for each run on exit"),
cl::callback([](const bool &) { TimePassesIsEnabled = true; }));
namespace {
namespace legacy {
//===----------------------------------------------------------------------===//
// Legacy pass manager's PassTimingInfo implementation
/// Provides an interface for collecting pass timing information.
///
/// It was intended to be generic but now we decided to split
/// interfaces completely. This is now exclusively for legacy-pass-manager use.
class PassTimingInfo {
public:
using PassInstanceID = void *;
private:
StringMap<unsigned> PassIDCountMap; ///< Map that counts instances of passes
DenseMap<PassInstanceID, std::unique_ptr<Timer>> TimingData; ///< timers for pass instances
TimerGroup *PassTG = nullptr;
public:
/// Initializes the static \p TheTimeInfo member to a non-null value when
/// -time-passes is enabled. Leaves it null otherwise.
///
/// This method may be called multiple times.
static void init();
/// Prints out timing information and then resets the timers.
/// By default it uses the stream created by CreateInfoOutputFile().
void print(raw_ostream *OutStream = nullptr);
/// Returns the timer for the specified pass if it exists.
Timer *getPassTimer(Pass *, PassInstanceID);
static PassTimingInfo *TheTimeInfo;
private:
Timer *newPassTimer(StringRef PassID, StringRef PassDesc);
};
static ManagedStatic<sys::SmartMutex<true>> TimingInfoMutex;
void PassTimingInfo::init() {
if (TheTimeInfo || !TimePassesIsEnabled)
return;
// Constructed the first time this is called, iff -time-passes is enabled.
// This guarantees that the object will be constructed after static globals,
// thus it will be destroyed before them.
static ManagedStatic<PassTimingInfo> TTI;
if (!TTI->PassTG)
TTI->PassTG = &NamedRegionTimer::getNamedTimerGroup(
TimePassesHandler::PassGroupName, TimePassesHandler::PassGroupDesc);
TheTimeInfo = &*TTI;
}
/// Prints out timing information and then resets the timers.
void PassTimingInfo::print(raw_ostream *OutStream) {
assert(PassTG && "PassTG is null, did you call PassTimingInfo::Init()?");
PassTG->print(OutStream ? *OutStream : *CreateInfoOutputFile(), true);
}
Timer *PassTimingInfo::newPassTimer(StringRef PassID, StringRef PassDesc) {
unsigned &num = PassIDCountMap[PassID];
num++;
// Appending description with a pass-instance number for all but the first one
std::string PassDescNumbered =
num <= 1 ? PassDesc.str() : formatv("{0} #{1}", PassDesc, num).str();
assert(PassTG && "PassTG is null, did you call PassTimingInfo::Init()?");
return new Timer(PassID, PassDescNumbered, *PassTG);
}
Timer *PassTimingInfo::getPassTimer(Pass *P, PassInstanceID Pass) {
if (P->getAsPMDataManager())
return nullptr;
init();
sys::SmartScopedLock<true> Lock(*TimingInfoMutex);
std::unique_ptr<Timer> &T = TimingData[Pass];
if (!T) {
StringRef PassName = P->getPassName();
StringRef PassArgument;
if (const PassInfo *PI = Pass::lookupPassInfo(P->getPassID()))
PassArgument = PI->getPassArgument();
T.reset(newPassTimer(PassArgument.empty() ? PassName : PassArgument, PassName));
}
return T.get();
}
PassTimingInfo *PassTimingInfo::TheTimeInfo;
} // namespace legacy
} // namespace
Timer *getPassTimer(Pass *P) {
legacy::PassTimingInfo::init();
if (legacy::PassTimingInfo::TheTimeInfo)
return legacy::PassTimingInfo::TheTimeInfo->getPassTimer(P, P);
return nullptr;
}
/// If timing is enabled, report the times collected up to now and then reset
/// them.
void reportAndResetTimings(raw_ostream *OutStream) {
if (legacy::PassTimingInfo::TheTimeInfo)
legacy::PassTimingInfo::TheTimeInfo->print(OutStream);
}
//===----------------------------------------------------------------------===//
// Pass timing handling for the New Pass Manager
//===----------------------------------------------------------------------===//
/// Returns the timer for the specified pass invocation of \p PassID.
/// Each time it creates a new timer.
Timer &TimePassesHandler::getPassTimer(StringRef PassID, bool IsPass) {
TimerGroup &TG = IsPass ? PassTG : AnalysisTG;
if (!PerRun) {
TimerVector &Timers = TimingData[PassID];
if (Timers.size() == 0)
Timers.emplace_back(new Timer(PassID, PassID, TG));
return *Timers.front();
}
// Take a vector of Timers created for this \p PassID and append
// one more timer to it.
TimerVector &Timers = TimingData[PassID];
unsigned Count = Timers.size() + 1;
std::string FullDesc = formatv("{0} #{1}", PassID, Count).str();
Timer *T = new Timer(PassID, FullDesc, TG);
Timers.emplace_back(T);
assert(Count == Timers.size() && "Timers vector not adjusted correctly.");
return *T;
}
TimePassesHandler::TimePassesHandler(bool Enabled, bool PerRun)
: Enabled(Enabled), PerRun(PerRun) {}
TimePassesHandler::TimePassesHandler()
: TimePassesHandler(TimePassesIsEnabled, TimePassesPerRun) {}
void TimePassesHandler::setOutStream(raw_ostream &Out) {
OutStream = &Out;
}
void TimePassesHandler::print() {
if (!Enabled)
return;
std::unique_ptr<raw_ostream> MaybeCreated;
raw_ostream *OS = OutStream;
if (OutStream) {
OS = OutStream;
} else {
MaybeCreated = CreateInfoOutputFile();
OS = &*MaybeCreated;
}
PassTG.print(*OS, true);
AnalysisTG.print(*OS, true);
}
LLVM_DUMP_METHOD void TimePassesHandler::dump() const {
dbgs() << "Dumping timers for " << getTypeName<TimePassesHandler>()
<< ":\n\tRunning:\n";
for (auto &I : TimingData) {
StringRef PassID = I.getKey();
const TimerVector& MyTimers = I.getValue();
for (unsigned idx = 0; idx < MyTimers.size(); idx++) {
const Timer* MyTimer = MyTimers[idx].get();
if (MyTimer && MyTimer->isRunning())
dbgs() << "\tTimer " << MyTimer << " for pass " << PassID << "(" << idx << ")\n";
}
}
dbgs() << "\tTriggered:\n";
for (auto &I : TimingData) {
StringRef PassID = I.getKey();
const TimerVector& MyTimers = I.getValue();
for (unsigned idx = 0; idx < MyTimers.size(); idx++) {
const Timer* MyTimer = MyTimers[idx].get();
if (MyTimer && MyTimer->hasTriggered() && !MyTimer->isRunning())
dbgs() << "\tTimer " << MyTimer << " for pass " << PassID << "(" << idx << ")\n";
}
}
}
static bool shouldIgnorePass(StringRef PassID) {
return isSpecialPass(PassID,
{"PassManager", "PassAdaptor", "AnalysisManagerProxy",
"ModuleInlinerWrapperPass", "DevirtSCCRepeatedPass"});
}
void TimePassesHandler::startPassTimer(StringRef PassID) {
if (shouldIgnorePass(PassID))
return;
// Stop the previous pass timer to prevent double counting when a
// pass requests another pass.
if (!PassActiveTimerStack.empty()) {
assert(PassActiveTimerStack.back()->isRunning());
PassActiveTimerStack.back()->stopTimer();
}
Timer &MyTimer = getPassTimer(PassID, /*IsPass*/ true);
PassActiveTimerStack.push_back(&MyTimer);
assert(!MyTimer.isRunning());
MyTimer.startTimer();
}
void TimePassesHandler::stopPassTimer(StringRef PassID) {
if (shouldIgnorePass(PassID))
return;
assert(!PassActiveTimerStack.empty() && "empty stack in popTimer");
Timer *MyTimer = PassActiveTimerStack.pop_back_val();
assert(MyTimer && "timer should be present");
assert(MyTimer->isRunning());
MyTimer->stopTimer();
// Restart the previously stopped timer.
if (!PassActiveTimerStack.empty()) {
assert(!PassActiveTimerStack.back()->isRunning());
PassActiveTimerStack.back()->startTimer();
}
}
void TimePassesHandler::startAnalysisTimer(StringRef PassID) {
// Stop the previous analysis timer to prevent double counting when an
// analysis requests another analysis.
if (!AnalysisActiveTimerStack.empty()) {
assert(AnalysisActiveTimerStack.back()->isRunning());
AnalysisActiveTimerStack.back()->stopTimer();
}
Timer &MyTimer = getPassTimer(PassID, /*IsPass*/ false);
AnalysisActiveTimerStack.push_back(&MyTimer);
if (!MyTimer.isRunning())
MyTimer.startTimer();
}
void TimePassesHandler::stopAnalysisTimer(StringRef PassID) {
assert(!AnalysisActiveTimerStack.empty() && "empty stack in popTimer");
Timer *MyTimer = AnalysisActiveTimerStack.pop_back_val();
assert(MyTimer && "timer should be present");
if (MyTimer->isRunning())
MyTimer->stopTimer();
// Restart the previously stopped timer.
if (!AnalysisActiveTimerStack.empty()) {
assert(!AnalysisActiveTimerStack.back()->isRunning());
AnalysisActiveTimerStack.back()->startTimer();
}
}
void TimePassesHandler::registerCallbacks(PassInstrumentationCallbacks &PIC) {
if (!Enabled)
return;
PIC.registerBeforeNonSkippedPassCallback(
[this](StringRef P, Any) { this->startPassTimer(P); });
PIC.registerAfterPassCallback(
[this](StringRef P, Any, const PreservedAnalyses &) {
this->stopPassTimer(P);
});
PIC.registerAfterPassInvalidatedCallback(
[this](StringRef P, const PreservedAnalyses &) {
this->stopPassTimer(P);
});
PIC.registerBeforeAnalysisCallback(
[this](StringRef P, Any) { this->startAnalysisTimer(P); });
PIC.registerAfterAnalysisCallback(
[this](StringRef P, Any) { this->stopAnalysisTimer(P); });
}
} // namespace llvm