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 << " ----- "; _______________________________________________ cfe-commits mailing list cfe-commits@lists.llvm.org https://lists.llvm.org/cgi-bin/mailman/listinfo/cfe-commits
