[llvm] 0de18e7 - -ftime-report: reorganize timers
via llvm-commits
llvm-commits at lists.llvm.org
Fri Jan 10 19:25:22 PST 2025
Author: Fangrui Song
Date: 2025-01-10T19:25:18-08:00
New Revision: 0de18e72c607c1b52be2c60d45cf2f9fc3af4542
URL: https://github.com/llvm/llvm-project/commit/0de18e72c607c1b52be2c60d45cf2f9fc3af4542
DIFF: https://github.com/llvm/llvm-project/commit/0de18e72c607c1b52be2c60d45cf2f9fc3af4542.diff
LOG: -ftime-report: reorganize timers
The code generation time is unclear in the -ftime-report output:
* The two clang timers "Code Generation Time" and "LLVM IR Generation
Time" are in the default group "Miscellaneous Ungrouped Timers".
* There is also a "Clang front-end time" group, which actually includes
code generation time.
```
===-------------------------------------------------------------------------===
Miscellaneous Ungrouped Timers
===-------------------------------------------------------------------------===
---User Time--- --System Time-- --User+System-- ---Wall Time--- --- Name ---
0.0611 ( 1.7%) 0.0099 ( 4.4%) 0.0710 ( 1.9%) 0.0713 ( 1.9%) LLVM IR Generation Time
3.5140 ( 98.3%) 0.2165 ( 95.6%) 3.7306 ( 98.1%) 3.7342 ( 98.1%) Code Generation Time
3.5751 (100.0%) 0.2265 (100.0%) 3.8016 (100.0%) 3.8055 (100.0%) Total
...
===-------------------------------------------------------------------------===
Clang front-end time report
===-------------------------------------------------------------------------===
Total Execution Time: 3.9108 seconds (3.9146 wall clock)
---User Time--- --System Time-- --User+System-- ---Wall Time--- --- Name ---
3.6802 (100.0%) 0.2306 (100.0%) 3.9108 (100.0%) 3.9146 (100.0%) Clang front-end timer
3.6802 (100.0%) 0.2306 (100.0%) 3.9108 (100.0%) 3.9146 (100.0%) Total
```
This patch
* renames "Clang front-end time report" (FrontendAction time) to "Clang
time report",
* renames "Clang front-end" to "Front end",
* moves "LLVM IR Generation" into the group,
* replaces "Code Generation time" with "Optimizer" (middle end) and
"Machine code generation" (back end).
```
% clang -c sqlite3.i -w -ftime-report -mllvm -sort-timers=0
...
===-------------------------------------------------------------------------===
Clang time report
===-------------------------------------------------------------------------===
Total Execution Time: 1.5922 seconds (1.5972 wall clock)
---User Time--- --System Time-- --User+System-- ---Wall Time--- --- Name ---
0.5107 ( 35.9%) 0.0105 ( 6.2%) 0.5211 ( 32.7%) 0.5222 ( 32.7%) Front end
0.2464 ( 17.3%) 0.0340 ( 20.0%) 0.2804 ( 17.6%) 0.2814 ( 17.6%) LLVM IR generation
0.6240 ( 43.9%) 0.1235 ( 72.7%) 0.7475 ( 47.0%) 0.7503 ( 47.0%) Machine code generation
0.0413 ( 2.9%) 0.0018 ( 1.0%) 0.0431 ( 2.7%) 0.0433 ( 2.7%) Optimizer
1.4224 (100.0%) 0.1698 (100.0%) 1.5922 (100.0%) 1.5972 (100.0%) Total
```
Pull Request: https://github.com/llvm/llvm-project/pull/122225
Added:
Modified:
clang/docs/ReleaseNotes.rst
clang/include/clang/Frontend/CompilerInstance.h
clang/lib/CodeGen/BackendUtil.cpp
clang/lib/CodeGen/CodeGenAction.cpp
clang/lib/Frontend/CompilerInstance.cpp
clang/test/Frontend/ftime-report-template-decl.cpp
llvm/include/llvm/Support/Timer.h
llvm/lib/Support/Timer.cpp
Removed:
################################################################################
diff --git a/clang/docs/ReleaseNotes.rst b/clang/docs/ReleaseNotes.rst
index 190843f2aa6c96..197b3692b8a181 100644
--- a/clang/docs/ReleaseNotes.rst
+++ b/clang/docs/ReleaseNotes.rst
@@ -445,6 +445,10 @@ Non-comprehensive list of changes in this release
- Matrix types (a Clang extension) can now be used in pseudo-destructor expressions,
which allows them to be stored in STL containers.
+- In the ``-ftime-report`` output, the new "Clang time report" group replaces
+ the old "Clang front-end time report" and includes "Front end", "LLVM IR
+ generation", "Optimizer", and "Machine code generation".
+
New Compiler Flags
------------------
diff --git a/clang/include/clang/Frontend/CompilerInstance.h b/clang/include/clang/Frontend/CompilerInstance.h
index 1220a4e29471d1..4a79b8d107171a 100644
--- a/clang/include/clang/Frontend/CompilerInstance.h
+++ b/clang/include/clang/Frontend/CompilerInstance.h
@@ -118,7 +118,7 @@ class CompilerInstance : public ModuleLoader {
std::unique_ptr<Sema> TheSema;
/// The frontend timer group.
- std::unique_ptr<llvm::TimerGroup> FrontendTimerGroup;
+ std::unique_ptr<llvm::TimerGroup> timerGroup;
/// The frontend timer.
std::unique_ptr<llvm::Timer> FrontendTimer;
@@ -630,6 +630,8 @@ class CompilerInstance : public ModuleLoader {
/// @name Frontend timer
/// @{
+ llvm::TimerGroup &getTimerGroup() const { return *timerGroup; }
+
bool hasFrontendTimer() const { return (bool)FrontendTimer; }
llvm::Timer &getFrontendTimer() const {
diff --git a/clang/lib/CodeGen/BackendUtil.cpp b/clang/lib/CodeGen/BackendUtil.cpp
index 2863887fd4d2f9..bcf6db1467ffce 100644
--- a/clang/lib/CodeGen/BackendUtil.cpp
+++ b/clang/lib/CodeGen/BackendUtil.cpp
@@ -16,6 +16,7 @@
#include "clang/Frontend/FrontendDiagnostic.h"
#include "clang/Frontend/Utils.h"
#include "clang/Lex/HeaderSearchOptions.h"
+#include "llvm/ADT/ScopeExit.h"
#include "llvm/ADT/StringExtras.h"
#include "llvm/ADT/StringSwitch.h"
#include "llvm/Analysis/GlobalsModRef.h"
@@ -137,8 +138,6 @@ class EmitAssemblyHelper {
llvm::Module *TheModule;
IntrusiveRefCntPtr<llvm::vfs::FileSystem> VFS;
- Timer CodeGenerationTime;
-
std::unique_ptr<raw_pwrite_stream> OS;
Triple TargetTriple;
@@ -208,7 +207,6 @@ class EmitAssemblyHelper {
: CI(CI), Diags(CI.getDiagnostics()), CodeGenOpts(CI.getCodeGenOpts()),
TargetOpts(CI.getTargetOpts()), LangOpts(CI.getLangOpts()),
TheModule(M), VFS(std::move(VFS)),
- CodeGenerationTime("codegen", "Code Generation Time"),
TargetTriple(TheModule->getTargetTriple()) {}
~EmitAssemblyHelper() {
@@ -1157,7 +1155,14 @@ void EmitAssemblyHelper::RunOptimizationPipeline(
{
PrettyStackTraceString CrashInfo("Optimizer");
llvm::TimeTraceScope TimeScope("Optimizer");
+ Timer timer;
+ if (CI.getCodeGenOpts().TimePasses) {
+ timer.init("optimizer", "Optimizer", CI.getTimerGroup());
+ CI.getFrontendTimer().yieldTo(timer);
+ }
MPM.run(*TheModule, MAM);
+ if (CI.getCodeGenOpts().TimePasses)
+ timer.yieldTo(CI.getFrontendTimer());
}
}
@@ -1200,14 +1205,20 @@ void EmitAssemblyHelper::RunCodegenPipeline(
{
PrettyStackTraceString CrashInfo("Code generation");
llvm::TimeTraceScope TimeScope("CodeGenPasses");
+ Timer timer;
+ if (CI.getCodeGenOpts().TimePasses) {
+ timer.init("codegen", "Machine code generation", CI.getTimerGroup());
+ CI.getFrontendTimer().yieldTo(timer);
+ }
CodeGenPasses.run(*TheModule);
+ if (CI.getCodeGenOpts().TimePasses)
+ timer.yieldTo(CI.getFrontendTimer());
}
}
void EmitAssemblyHelper::emitAssembly(BackendAction Action,
std::unique_ptr<raw_pwrite_stream> OS,
BackendConsumer *BC) {
- TimeRegion Region(CodeGenOpts.TimePasses ? &CodeGenerationTime : nullptr);
setCommandLineOpts(CodeGenOpts);
bool RequiresCodeGen = actionRequiresCodeGen(Action);
diff --git a/clang/lib/CodeGen/CodeGenAction.cpp b/clang/lib/CodeGen/CodeGenAction.cpp
index 7446bddc11345b..15311fb2078101 100644
--- a/clang/lib/CodeGen/CodeGenAction.cpp
+++ b/clang/lib/CodeGen/CodeGenAction.cpp
@@ -115,8 +115,7 @@ BackendConsumer::BackendConsumer(CompilerInstance &CI, BackendAction Action,
llvm::Module *CurLinkModule)
: CI(CI), Diags(CI.getDiagnostics()), CodeGenOpts(CI.getCodeGenOpts()),
TargetOpts(CI.getTargetOpts()), LangOpts(CI.getLangOpts()),
- AsmOutStream(std::move(OS)), FS(VFS),
- LLVMIRGeneration("irgen", "LLVM IR Generation Time"), Action(Action),
+ AsmOutStream(std::move(OS)), FS(VFS), Action(Action),
Gen(CreateLLVMCodeGen(Diags, InFile, std::move(VFS),
CI.getHeaderSearchOpts(), CI.getPreprocessorOpts(),
CI.getCodeGenOpts(), C, CoverageInfo)),
@@ -124,6 +123,8 @@ BackendConsumer::BackendConsumer(CompilerInstance &CI, BackendAction Action,
TimerIsEnabled = CodeGenOpts.TimePasses;
llvm::TimePassesIsEnabled = CodeGenOpts.TimePasses;
llvm::TimePassesPerRun = CodeGenOpts.TimePassesPerRun;
+ if (CodeGenOpts.TimePasses)
+ LLVMIRGeneration.init("irgen", "LLVM IR generation", CI.getTimerGroup());
}
llvm::Module* BackendConsumer::getModule() const {
@@ -162,19 +163,13 @@ bool BackendConsumer::HandleTopLevelDecl(DeclGroupRef D) {
"LLVM IR generation of declaration");
// Recurse.
- if (TimerIsEnabled) {
- LLVMIRGenerationRefCount += 1;
- if (LLVMIRGenerationRefCount == 1)
- LLVMIRGeneration.startTimer();
- }
+ if (TimerIsEnabled && !LLVMIRGenerationRefCount++)
+ CI.getFrontendTimer().yieldTo(LLVMIRGeneration);
Gen->HandleTopLevelDecl(D);
- if (TimerIsEnabled) {
- LLVMIRGenerationRefCount -= 1;
- if (LLVMIRGenerationRefCount == 0)
- LLVMIRGeneration.stopTimer();
- }
+ if (TimerIsEnabled && !--LLVMIRGenerationRefCount)
+ LLVMIRGeneration.yieldTo(CI.getFrontendTimer());
return true;
}
@@ -184,12 +179,12 @@ void BackendConsumer::HandleInlineFunctionDefinition(FunctionDecl *D) {
Context->getSourceManager(),
"LLVM IR generation of inline function");
if (TimerIsEnabled)
- LLVMIRGeneration.startTimer();
+ CI.getFrontendTimer().yieldTo(LLVMIRGeneration);
Gen->HandleInlineFunctionDefinition(D);
if (TimerIsEnabled)
- LLVMIRGeneration.stopTimer();
+ LLVMIRGeneration.yieldTo(CI.getFrontendTimer());
}
void BackendConsumer::HandleInterestingDecl(DeclGroupRef D) {
@@ -239,19 +234,13 @@ void BackendConsumer::HandleTranslationUnit(ASTContext &C) {
{
llvm::TimeTraceScope TimeScope("Frontend");
PrettyStackTraceString CrashInfo("Per-file LLVM IR generation");
- if (TimerIsEnabled) {
- LLVMIRGenerationRefCount += 1;
- if (LLVMIRGenerationRefCount == 1)
- LLVMIRGeneration.startTimer();
- }
+ if (TimerIsEnabled && !LLVMIRGenerationRefCount++)
+ CI.getFrontendTimer().yieldTo(LLVMIRGeneration);
Gen->HandleTranslationUnit(C);
- if (TimerIsEnabled) {
- LLVMIRGenerationRefCount -= 1;
- if (LLVMIRGenerationRefCount == 0)
- LLVMIRGeneration.stopTimer();
- }
+ if (TimerIsEnabled && !--LLVMIRGenerationRefCount)
+ LLVMIRGeneration.yieldTo(CI.getFrontendTimer());
IRGenFinished = true;
}
diff --git a/clang/lib/Frontend/CompilerInstance.cpp b/clang/lib/Frontend/CompilerInstance.cpp
index fbfc305ca06a04..b00a4ac0757763 100644
--- a/clang/lib/Frontend/CompilerInstance.cpp
+++ b/clang/lib/Frontend/CompilerInstance.cpp
@@ -722,11 +722,8 @@ void CompilerInstance::createCodeCompletionConsumer() {
}
void CompilerInstance::createFrontendTimer() {
- FrontendTimerGroup.reset(
- new llvm::TimerGroup("frontend", "Clang front-end time report"));
- FrontendTimer.reset(
- new llvm::Timer("frontend", "Clang front-end timer",
- *FrontendTimerGroup));
+ timerGroup.reset(new llvm::TimerGroup("clang", "Clang time report"));
+ FrontendTimer.reset(new llvm::Timer("frontend", "Front end", *timerGroup));
}
CodeCompleteConsumer *
@@ -1726,10 +1723,9 @@ void CompilerInstance::createASTReader() {
const FrontendOptions &FEOpts = getFrontendOpts();
std::unique_ptr<llvm::Timer> ReadTimer;
- if (FrontendTimerGroup)
+ if (timerGroup)
ReadTimer = std::make_unique<llvm::Timer>("reading_modules",
- "Reading modules",
- *FrontendTimerGroup);
+ "Reading modules", *timerGroup);
TheASTReader = new ASTReader(
getPreprocessor(), getModuleCache(), &getASTContext(),
getPCHContainerReader(), getFrontendOpts().ModuleFileExtensions,
@@ -1758,10 +1754,10 @@ void CompilerInstance::createASTReader() {
bool CompilerInstance::loadModuleFile(
StringRef FileName, serialization::ModuleFile *&LoadedModuleFile) {
llvm::Timer Timer;
- if (FrontendTimerGroup)
+ if (timerGroup)
Timer.init("preloading." + FileName.str(), "Preloading " + FileName.str(),
- *FrontendTimerGroup);
- llvm::TimeRegion TimeLoading(FrontendTimerGroup ? &Timer : nullptr);
+ *timerGroup);
+ llvm::TimeRegion TimeLoading(timerGroup ? &Timer : nullptr);
// If we don't already have an ASTReader, create one now.
if (!TheASTReader)
@@ -1892,10 +1888,10 @@ ModuleLoadResult CompilerInstance::findOrCompileModuleAndReadAST(
// Time how long it takes to load the module.
llvm::Timer Timer;
- if (FrontendTimerGroup)
+ if (timerGroup)
Timer.init("loading." + ModuleFilename, "Loading " + ModuleFilename,
- *FrontendTimerGroup);
- llvm::TimeRegion TimeLoading(FrontendTimerGroup ? &Timer : nullptr);
+ *timerGroup);
+ llvm::TimeRegion TimeLoading(timerGroup ? &Timer : nullptr);
llvm::TimeTraceScope TimeScope("Module Load", ModuleName);
// Try to load the module file. If we are not trying to load from the
diff --git a/clang/test/Frontend/ftime-report-template-decl.cpp b/clang/test/Frontend/ftime-report-template-decl.cpp
index 9ba9107b980408..45ce0dc15c56fd 100644
--- a/clang/test/Frontend/ftime-report-template-decl.cpp
+++ b/clang/test/Frontend/ftime-report-template-decl.cpp
@@ -1,5 +1,6 @@
-// RUN: %clang_cc1 %s -emit-llvm -o - -ftime-report 2>&1 | FileCheck %s
-// RUN: %clang_cc1 %s -emit-llvm -o - -fdelayed-template-parsing -DDELAYED_TEMPLATE_PARSING -ftime-report 2>&1 | FileCheck %s
+// REQUIRES: x86-registered-target
+// RUN: %clang_cc1 %s -S -triple=x86_64 -mllvm -sort-timers=0 -o - -ftime-report 2>&1 | FileCheck %s
+// RUN: %clang_cc1 %s -S -triple=x86_64 -mllvm -sort-timers=0 -o - -fdelayed-template-parsing -DDELAYED_TEMPLATE_PARSING -ftime-report 2>&1 | FileCheck %s
// Template function declarations
template <typename T>
@@ -150,10 +151,9 @@ struct _Wrap_alloc {
};
_Wrap_alloc<int>::rebind<int> w;
-// CHECK: Miscellaneous Ungrouped Timers
-// CHECK-DAG: LLVM IR Generation Time
-// CHECK-DAG: Code Generation Time
-// CHECK: Total
-// CHECK: Clang front-end time report
-// CHECK: Clang front-end timer
-// CHECK: Total
+// CHECK: Clang time report
+// CHECK: Front end
+// CHECK-NEXT: LLVM IR generation
+// CHECK-NEXT: Machine code generation
+// CHECK-NEXT: Optimizer
+// CHECK-NEXT: Total
diff --git a/llvm/include/llvm/Support/Timer.h b/llvm/include/llvm/Support/Timer.h
index d21859905d4a7b..abe30451dd2f21 100644
--- a/llvm/include/llvm/Support/Timer.h
+++ b/llvm/include/llvm/Support/Timer.h
@@ -131,6 +131,9 @@ class Timer {
/// Clear the timer state.
void clear();
+ /// Stop the timer and start another timer.
+ void yieldTo(Timer &);
+
/// Return the duration for which this timer has been running.
TimeRecord getTotalTime() const { return Time; }
diff --git a/llvm/lib/Support/Timer.cpp b/llvm/lib/Support/Timer.cpp
index 1fa2cdf297aae6..fbf3becf39fa13 100644
--- a/llvm/lib/Support/Timer.cpp
+++ b/llvm/lib/Support/Timer.cpp
@@ -166,6 +166,11 @@ void Timer::clear() {
Time = StartTime = TimeRecord();
}
+void Timer::yieldTo(Timer &O) {
+ stopTimer();
+ O.startTimer();
+}
+
static void printVal(double Val, double Total, raw_ostream &OS) {
if (Total < 1e-7) // Avoid dividing by zero.
OS << " ----- ";
More information about the llvm-commits
mailing list