[Time-report ](2): Recursive timers in Clang

[avt77]

Summary

I introduce the new infrastructure supporting recursive timers in Clang. This patch is based on D45619 [Time-report] (1) and it is not the last one in this series. The main idea is a possibilty to have "horizontal" timers instead of "vertical" ones which we have today. The patch alows to find the most critical functions (from compilation time of view) and to to analyze them.

[mgrang]

include/clang/Frontend/Utils.h

428

Please use llvm::sort instead of std::sort. See https://llvm.org/docs/CodingStandards.html#beware-of-non-deterministic-sorting-order-of-equal-elements.

448

Same here.

[avt77]

• switched to llvm::sort - from std::sort (tnx to mgrang)
• added a new counter (hope it will improve the output numbers)
• slightly changed a couple of existing counters
• seriously improved debug/monitor logging

[avt77]

The sources were re-based to fit in LLVM_DEBUG rename.
One more counter was added.
Debug logging was improved again.

[avt77]

Hi All,
What should I do to simplify the review?
I could remove all LLVM_DEBUG related stuff; I could remove all addtional counters and leave only necessary one or two of them. As result the patch will become shorter.

Should I do all these truncations to simplify the review?
Or maybe I should add comments and/or docs in Utils.h describing the new infrastructure?
Maybe you need examples of the produced output?

[avt77]

To simplify the review I removed all LLVM_DEBUG items - now the patch is really shorter than it was before.

[efriedma]

Can you give an example of what the output looks like?

Please don't define multiple different classes with the same name SortClassName.

It seems like you've scattered the "start" and "stop" calls all over the place; can you put the start and stop calls in the same place, somehow?

lib/CodeGen/CodeGenAction.cpp

860

The use of getWithDecl here is weird; can you just do GlobalDecl(FD)? If not, please add a comment explaining what you're doing.

Why does it matter whether the function has a body? IIRC you should be able to mangle the name of functions without a body.

[avt77]

In D47196#1134185, @efriedma wrote:

Can you give an example of what the output looks like?

First of all excuse me for such delay with my answer: I was on my vacations.
During bootstrap we could see something like here:

[ 84%] Building CXX object tools/clang/lib/StaticAnalyzer/Core/CMakeFiles/clangStaticAnalyzerCore.dir/BlockCounter.cpp.o

------------ Clang Timers: CodeGen Functions ------------

0.0080 (2) _ZN5clang7tooling20getOccurrencesOfUSRsEN4llvm8ArrayRefINSt7cxx1112basic_stringIcSt11char_traitsIcESaIcEEEEENS1_9StringRefEPNS_4DeclE (*)
0.0080 (2) _ZN5clang19RecursiveASTVisitorINS_7tooling12_GLOBALN_115RenameLocFinderEE12TraverseAttrEPNS_4AttrE (*)
0.0080 (2) _ZN5clang19RecursiveASTVisitorINS_7tooling12_GLOBALN_115RenameLocFinderEE29TraverseOMPTaskyieldDirectiveEPNS_21OMPTaskyieldDirectiveEPN4llvm15SmallVectorImplINS7_14PointerIntPairIPNS_4StmtELj1EbNS7_21PointerLikeTypeTraitsISB_EENS7_18PointerIntPairInfoISB_Lj1ESD_EEEEEE (*)
0.0080 (2) _ZN5clang19RecursiveASTVisitorINS_7tooling22RecursiveSymbolVisitorINS1_12_GLOBALN_123USRLocFindingASTVisitorEEEE16TraverseBinCommaEPNS_14BinaryOperatorEPN4llvm15SmallVectorImplINS9_14PointerIntPairIPNS_4StmtELj1EbNS9_21PointerLikeTypeTraitsISD_EENS9_18PointerIntPairInfoISD_Lj1ESF_EEEEEE (*)
0.0080 (2) _ZN5clang19RecursiveASTVisitorINS_7tooling22RecursiveSymbolVisitorINS1_12_GLOBALN_123USRLocFindingASTVisitorEEEE21TraverseTypeAliasDeclEPNS_13TypeAliasDeclE (*)
0.0080 (2) _ZN5clang19RecursiveASTVisitorINS_7tooling22RecursiveSymbolVisitorINS1_12_GLOBALN_123USRLocFindingASTVisitorEEEE22TraverseObjCObjectTypeEPNS_14ObjCObjectTypeE (*)
0.0080 (2) _ZN5clang19RecursiveASTVisitorINS_7tooling12_GLOBALN_115RenameLocFinderEE12TraverseDeclEPNS_4DeclE (*)
0.0080 (2) _ZN5clang19RecursiveASTVisitorINS_7tooling12_GLOBALN_115RenameLocFinderEE37TraverseVarTemplateSpecializationDeclEPNS_29VarTemplateSpecializationDeclE (*)
0.0080 (2) _ZN5clang19RecursiveASTVisitorINS_7tooling12_GLOBALN_115RenameLocFinderEE13TraverseBinGTEPNS_14BinaryOperatorEPN4llvm15SmallVectorImplINS7_14PointerIntPairIPNS_4StmtELj1EbNS7_21PointerLikeTypeTraitsISB_EENS7_18PointerIntPairInfoISB_Lj1ESD_EEEEEE (*)
0.0080 (2) _ZN5clang19RecursiveASTVisitorINS_7tooling12_GLOBALN_115RenameLocFinderEE31TraverseCXXPseudoDestructorExprEPNS_23CXXPseudoDestructorExprEPN4llvm15SmallVectorImplINS7_14PointerIntPairIPNS_4StmtELj1EbNS7_21PointerLikeTypeTraitsISB_EENS7_18PointerIntPairInfoISB_Lj1ESD_EEEEEE (*)
0.0120 (2) _ZN5clang7tooling25createRenameAtomicChangesEN4llvm8ArrayRefINSt7cxx1112basic_stringIcSt11char_traitsIcESaIcEEEEENS1_9StringRefEPNS_4DeclE (*)
0.0120 (2) _ZN5clang19RecursiveASTVisitorINS_7tooling22RecursiveSymbolVisitorINS1_12_GLOBALN_123USRLocFindingASTVisitorEEEE15TraverseTypeLocENS_7TypeLocE (*)
0.0160 (2) _ZN5clang19RecursiveASTVisitorINS_7tooling12_GLOBALN_115RenameLocFinderEE13PostVisitStmtEPNS_4StmtE (*)
0.0200 (2) _ZN5clang19RecursiveASTVisitorINS_7tooling22RecursiveSymbolVisitorINS1_12_GLOBALN_123USRLocFindingASTVisitorEEEE12TraverseAttrEPNS_4AttrE (*)
0.0200 (2) _ZN5clang19RecursiveASTVisitorINS_7tooling22RecursiveSymbolVisitorINS1_12_GLOBALN_123USRLocFindingASTVisitorEEEE13PostVisitStmtEPNS_4StmtE (*)
0.0400 (2) _ZN5clang19RecursiveASTVisitorINS_7tooling12_GLOBALN_115RenameLocFinderEE16dataTraverseNodeEPNS_4StmtEPN4llvm15SmallVectorImplINS7_14PointerIntPairIS6_Lj1EbNS7_21PointerLikeTypeTraitsIS6_EENS7_18PointerIntPairInfoIS6_Lj1ESB_EEEEEE (*)
0.0440 (2) _ZN5clang19RecursiveASTVisitorINS_7tooling22RecursiveSymbolVisitorINS1_12_GLOBAL__N_123USRLocFindingASTVisitorEEEE16dataTraverseNodeEPNS_4StmtEPN4llvm15SmallVectorImplINS9_14PointerIntPairIS8_Lj1EbNS9_21PointerLikeTypeTraitsIS8_EENS9_18PointerIntPairInfoIS8_Lj1ESD_EEEEEE (*)
0.0720 (1) _ZN5clang19RecursiveASTVisitor12TraverseAttrEPNS_4AttrE (*)

If we collect the full build log, grep and sort it then we could see the longest compilation times like here:

0.3240 (2) _ZN4llvm18HexagonInstPrinter16printInstructionEPKNS_6MCInstERNS_11raw_ostreamE (*)
0.4520 (2) _ZNK4llvm19AMDGPUMCCodeEmitter27verifyInstructionPredicatesERKNS_6MCInstEm (*)
0.4680 (2) _ZN12_GLOBALN_119SystemZDAGToDAGISel10SelectCodeEPN4llvm6SDNodeE (*)
0.5960 (2) _ZL20validateOperandClassRN4llvm18MCParsedAsmOperandEN12_GLOBALN_114MatchClassKindE (*)
0.6200 (2) _ZN12_GLOBALN_115ARMDAGToDAGISel10SelectCodeEPN4llvm6SDNodeE (*)
0.7280 (2) _ZN12_GLOBALN_115PPCDAGToDAGISel10SelectCodeEPN4llvm6SDNodeE (*)
0.7920 (2) _ZN12_GLOBALN_119AArch64DAGToDAGISel10SelectCodeEPN4llvm6SDNodeE (*)
1.3160 (3) _ZN4llvm19HexagonDAGToDAGISel10SelectCodeEPNS_6SDNodeE (*)
1.4760 (2) _ZN12_GLOBALN_118AMDGPUDAGToDAGISel10SelectCodeEPN4llvm6SDNodeE (*)
5.2520 (2) _ZN12_GLOBAL__N_115X86DAGToDAGISel10SelectCodeEPN4llvm6SDNodeE (*)

It seems like you've scattered the "start" and "stop" calls all over the place; can you put the start and stop calls in the same place, somehow?

I use now startFrontendTimer/stopFronendTimer: you can find it in several files and inside RAII objects.

[avt77]

I fixed all issues raised by efriedma: GlobalDecl(FD), function body, class names, etc. Many tnx for your help.

[efriedma]

Adding startFrontendTimer/stopFrontendTimer helps a little, but it's still difficult to match a given startFrontendTimer to the corresponding stopFrontendTimer because they're in completely different functions in some cases. Do they really need to be scattered like that? If they do, please add comments so someone reading the code can match them up.

Does getFrontendFunctionTimeCtx need to be a template, given it's always instantiated with const FunctionDecl *?

include/clang/Frontend/Utils.h

338

Why 0.00001? Should it be configurable?

385

This is merging together the times for functions with the same name? Why is that necessary?

This function could use a few comments describing what it's doing.

462

Commented-out code?

[avt77]

In D47196#1162321, @efriedma wrote:

Adding startFrontendTimer/stopFrontendTimer helps a little, but it's still difficult to match a given startFrontendTimer to the corresponding stopFrontendTimer because they're in completely different functions in some cases. Do they really need to be scattered like that? If they do, please add comments so someone reading the code can match them up.

I'll do it.

Does getFrontendFunctionTimeCtx need to be a template, given it's always instantiated with const FunctionDecl *?

Initially there were 2 types of instantiations: std::string and const FunctionDecl *. Trying to simplify the patch (and to make it shorter) I removed string instantiations (hoping to return them back later). And I thought it could be useful to have some other types of instantiations in the future. Do you think it's redundant? I used std::string in places where we don't have FunctionDecl yet. And this counter infrastructure could be used in general with any other data types.

include/clang/Frontend/Utils.h

338

Yes, of course. I'll do it.

385

We merge times for the funcs with the same name because we'd like to get the total time spending for every function. The idea of this report is to collect all time pieces for separate functions and to show the longest times. As result we'll be able to see functions with longest compilation times and that's exactly our goal.
And, yes I'll add comments soon.

[avt77]

I added required comments and did the required changes.

[avt77]

Ping!

efriedma, do you have any other comments/requirements?

[efriedma]

lib/Sema/SemaLambda.cpp

1440

This seems sort of late? You're starting the timer after the body has already been parsed.

lib/Sema/TreeTransform.h

10954

What happens if we never hit ActOnFinishFunctionBody()? TransformLambdaExpr has an early return if the body doesn't typecheck.

More generally, given that we have early returns all over the place in Sema, I would be more comfortable using the RAII helper, rather than explicitly calling start/stop, even if that means you have to insert FrontendTimeRAII variables in half a dozen different places in the parser. (Note I'm specifically talking about the parser here; the explicit stopFrontendTimer in ~CodeGenFunction seems fine.)

[avt77]

lib/Sema/SemaLambda.cpp

1440

Yes and no but if we decided to extend usage of RAII objects - it deos not matter. I'll change it.

lib/Sema/TreeTransform.h

10954

It seems you're right: usage of RAII objects is safely. OK, I'll change it.

[avt77]

Accordingly to efriedma suggestion I removed start/stopFrontendTimer where it's possible and inserted FrontendTimeRAII in several new places. As result the patch becomes bigger and bigger. And as another result I got output like here (on compiler bootstrap):
....
0.5920 (165) _ZSt7declvalv (*)
0.5960 (155) _ZSt7declvalv (*)
0.5960 (162) _ZSt7declvalv (*)
0.6000 (167) _ZSt7declvalv (*)
0.6040 (155) _ZSt7declvalv (*)
0.6040 (160) _ZSt7declvalv (*)
0.6040 (169) _ZSt7declvalv (*)
....
(the above is grep output from build log file)

It means we compile the same function many times inside many files and it should be optimised in some way.
Another thought: I should add "human" names to simplify the mangling names resolution.

[efriedma]

I think there's something weird happening with your timers if they're showing half a second spent parsing or instantiating std::declval: it doesn't have a definition, anywhere (it's just a placeholder for template metaprogramming tricks).

lib/AST/Expr.cpp

544 ↗

(On Diff #158221)

You shouldn't need a separate timer here; __func__ should only show up inside a function definition anyway.

lib/Analysis/AnalysisDeclContext.cpp

99 ↗

(On Diff #158221)

Not sure what you're trying to time here.

lib/Parse/Parser.cpp

1131 ↗

(On Diff #158221)

CheckForFunctionRedefinition and MarkAsLateParsedTemplate are both pretty cheap; not sure it's worth separately timing them.

lib/Sema/SemaDecl.cpp

2983

MergeFunctionDecl only has one caller: CheckFunctionDeclaration. Probably makes more sense to time that, instead?

3579

MergeCompatibleFunctionDecls is only called by MergeFunctionDecl.

[avt77]

efriedma, I removed redundant RAII objects but I still have the following:

1.0800 (271) _ZSt7declvalv (*)
1.0840 (273) _ZSt7declvalv (*)
1.0880 (269) _ZSt7declvalv (*)
1.1000 (276) _ZSt7declvalv (*)
1.1200 (282) _ZSt7declvalv (*)
1.1360 (279) _ZSt7declvalv (*)
1.1440 (286) _ZSt7declvalv (*)
1.1760 (292) _ZSt7declvalv (*)
1.1760 (295) _ZSt7declvalv (*)
1.1800 (294) _ZSt7declvalv (*)
1.1880 (298) _ZSt7declvalv (*)
1.5960 (397) _ZSt7declvalv (*)

Every line corresponds to one unit and the number in parenthesis means the number of times we're dealing with the given function during the compilation of one unit. You say it's impossible but one time invocation of this function costs 0.0040 and 397 times invocations cost 1.588 (very close to the above number).

Do you have any ideas how to deal with all this stuff? Should I add/remove RAIIs somewhere?

[efriedma]

"0.0040" is four milliseconds? You're probably crediting time incorrectly, somehow. Can you tell which FrontendTimeRAII the time is coming from?

[avt77]

In D47196#1186460, @efriedma wrote:

"0.0040" is four milliseconds? You're probably crediting time incorrectly, somehow. Can you tell which FrontendTimeRAII the time is coming from?

Not sure I understand you. What do you like to know exactly? Please, clarify.

[efriedma]

I mean, which of the callers of startFrontendTimer() is calling it with a pointer to std::declval()?

[avt77]

The ability to produce debug output for 'ftiming' was added. As result now it's possible to check places where timers start/stop and for what functions it's being done (see changes in Utils.h).

[avt77]

In D47196#1190377, @efriedma wrote:

I mean, which of the callers of startFrontendTimer() is calling it with a pointer to std::declval()?

declval.log576 KBDownload

The attachment keeps debug output for

....../bin/clang -cc1 -triple x86_64-unknown-linux-gnu -emit-obj -mrelax-all -disable-free -disable-llvm-verifier -discard-value-names -main-file-name TransGCCalls.cpp -mrelocation-model pic -pic-level 2 -mthread-model posix -mdisable-fp-elim -fmath-errno -masm-verbose -mconstructor-aliases -munwind-tables -fuse-init-array -target-cpu x86-64 -dwarf-column-info -debugger-tuning=gdb -v -v -coverage-notes-file /home/atischenko/workspaces/bootstrap/Release-patch/tools/clang/lib/ARCMigrate/CMakeFiles/clangARCMigrate.dir/TransGCCalls.cpp.gcno -resource-dir /home/atischenko/workspaces/time-report-recursive-4/RelWithDebug/lib/clang/8.0.0 -D GTEST_HAS_RTTI=0 -D _DEBUG -D _GNU_SOURCE -D STDC_CONSTANT_MACROS -D STDC_FORMAT_MACROS -D __STDC_LIMIT_MACROS -I /home/atischenko/workspaces/bootstrap/Release-patch/tools/clang/lib/ARCMigrate -I /home/atischenko/workspaces/bootstrap/llvm/tools/clang/lib/ARCMigrate -I /home/atischenko/workspaces/bootstrap/llvm/tools/clang/include -I /home/atischenko/workspaces/bootstrap/Release-patch/tools/clang/include -I /usr/include/libxml2 -I /home/atischenko/workspaces/bootstrap/Release-patch/include -I /home/atischenko/workspaces/bootstrap/llvm/include -internal-isystem /usr/lib/gcc/x86_64-linux-gnu/5.4.0/../../../../include/c++/5.4.0 -internal-isystem /usr/lib/gcc/x86_64-linux-gnu/5.4.0/../../../../include/x86_64-linux-gnu/c++/5.4.0 -internal-isystem /usr/lib/gcc/x86_64-linux-gnu/5.4.0/../../../../include/x86_64-linux-gnu/c++/5.4.0 -internal-isystem /usr/lib/gcc/x86_64-linux-gnu/5.4.0/../../../../include/c++/5.4.0/backward -internal-isystem /usr/local/include -internal-isystem /home/atischenko/workspaces/time-report-recursive-4/RelWithDebug/lib/clang/8.0.0/include -internal-externc-isystem /usr/include/x86_64-linux-gnu -internal-externc-isystem /include -internal-externc-isystem /usr/include -Werror=date-time -Werror=unguarded-availability-new -Wall -Wextra -Wno-unused-parameter -Wwrite-strings -Wcast-qual -Wmissing-field-initializers -Wno-long-long -Wcovered-switch-default -Wnon-virtual-dtor -Wdelete-non-virtual-dtor -Wstring-conversion -Woverloaded-virtual -Wno-nested-anon-types -pedantic -std=c++11 -fdeprecated-macro -fdebug-compilation-dir /home/atischenko/workspaces/bootstrap/Release-patch/tools/clang/lib/ARCMigrate -ferror-limit 19 -fmessage-length 0 -fvisibility-inlines-hidden -ftime-report -fno-rtti -fobjc-runtime=gcc -fno-common -fdiagnostics-show-option -o TransGCCalls.cpp.o -x c++ /home/atischenko/workspaces/bootstrap/llvm/tools/clang/lib/ARCMigrate/TransGCCalls.cpp -faddrsig -mllvm -debug-only=ftiming

The full log is too big that's why I grepped "declval" only:

• :start: means the timer was started
• :stop-zero: means the timer was stopped and nothing was added to the calculated time period
• :stop-add:<double> means the timer was stoped and the time slice was added to the time period.

There are DeclFunc* names and Tags to look for corresponding RAII objects inside sources. For example:

ActOnFunctionDeclarator:start:declval:

means

Tag:start:Name:

BTW, I see a lot of broken DeclFunc names: do you have any idea why it's possible? Example:

ActOnFunctionDeclarator:start:....._exception:

Here ...... means non-ASCII symbols.

[efriedma]

:start: means the timer was started

In some cases, the ChildTime is already non-zero at the "start" point; what does that mean?

ActOnFunctionDeclarator:start:....._exception:

That's weird... DeclarationName::print should generally return something ASCII; do you know what kind of declaration it is?

[avt77]

In D47196#1202805, @efriedma wrote:

:start: means the timer was started

In some cases, the ChildTime is already non-zero at the "start" point; what does that mean?

It means there was recursive call and this child time should be removed from the time of the current func (parent) otherwise it could be calculated twice.

ActOnFunctionDeclarator:start:....._exception:

That's weird... DeclarationName::print should generally return something ASCII; do you know what kind of declaration it is?

There are a lot of such names (see the attach as example.)

b.log153 KBDownload

BTW, I use getNameAsString() (see getFirstName). I tried getIdentifier () ->getName() but it was broken rather often.

[Trass3r]

Is this still in progress?

[anton-afanasyev]

In D47196#1324540, @Trass3r wrote:

Is this still in progress?

AFAIK, this is abandoned by author now. I'm working on other implementation which is similar but with another angle of view. The implementation projected by author measures time of _compiler_ code, whereas _user_ source code compilation time looks more useful.
There are also another two differentials related to this one which may require revertion: https://reviews.llvm.org/D45619 and https://reviews.llvm.org/D43578.

include/clang/Frontend/Utils.h

 //===----------------------------------------------------------------------===//
 
 #ifndef LLVM_CLANG_FRONTEND_UTILS_H
 #define LLVM_CLANG_FRONTEND_UTILS_H
 
 #include "clang/Basic/Diagnostic.h"
 #include "clang/Basic/LLVM.h"
 #include "clang/Basic/VirtualFileSystem.h"
-#include "llvm/ADT/IntrusiveRefCntPtr.h"
 #include "llvm/ADT/ArrayRef.h"
+#include "llvm/ADT/IntrusiveRefCntPtr.h"
+#include "llvm/ADT/Statistic.h"
 #include "llvm/ADT/StringMap.h"
 #include "llvm/ADT/StringRef.h"
 #include "llvm/ADT/StringSet.h"
 #include "llvm/Option/OptSpecifier.h"
+#include "llvm/Support/Format.h"
+#include "llvm/Support/Timer.h"
 #include <cstdint>
 #include <memory>
 #include <string>
 #include <system_error>
 #include <utility>
 #include <vector>
 
 namespace llvm {
template <typename T> void BuryPointer(std::unique_ptr<T> Ptr) {
   BuryPointer(Ptr.release());
 }
 
 // Frontend timing utils
 
 /// If the user specifies the -ftime-report argument on an Clang command line
 /// then the value of this boolean will be true, otherwise false.
 extern bool FrontendTimesIsEnabled;
+extern llvm::TimerGroup *FDefTimeGroup;
+
+template <typename T> bool isFirstValid(T First);
+
+template <typename T> struct FrontendTimeCtx {
+  using FTimePair = std::pair<T, double>;
+  std::vector<FTimePair> FrontendTimes;
+  llvm::Timer FrontendTimer;
+  llvm::TimerGroup *TGroup = nullptr;
+  bool DeleteTGroup = false;
+  double ChildTime;
+  std::vector<FTimePair> ChildStack;
+
+  static double getCurProcessTime(llvm::Timer &FT) {
+    assert(FT.isRunning() && "FrontendTimer must be running");
+    FT.stopTimer();
+    return FT.getTotalTime().getProcessTime();
+  }
+
+  static llvm::TimerGroup *getFrontendDefaultTimerGroup() {
+    if (!FDefTimeGroup)
+      FDefTimeGroup = (llvm::TimerGroup *)new llvm::TimerGroup(
+          "clangdeftg", "Clang Timers Group");
+    return FDefTimeGroup;
+  }
+
+public:
+  bool IsValid;
+  FrontendTimeCtx() : IsValid(false){};
+  void init(llvm::StringRef TimerName, llvm::StringRef TimerDsc,
+            llvm::StringRef GroupName, llvm::StringRef GroupDsc) {
+    if (FrontendTimesIsEnabled) {
+      TGroup = (llvm::TimerGroup *)new llvm::TimerGroup(GroupName, GroupDsc);
+      DeleteTGroup = true;
+      init(TimerName, TimerDsc, TGroup);
+    } else
+      IsValid = false;
+  };
+
+  void init(llvm::StringRef TimerName, llvm::StringRef TimerDsc,
+            llvm::TimerGroup *TG) {
+    if (FrontendTimesIsEnabled) {
+      FrontendTimer.init(TimerName, TimerDsc, *TG);
+      TGroup = TG;
+      ChildStack.clear();
+      ChildTime = 0.0;
+      IsValid = true;
+    } else
+      IsValid = false;
+  };
+
+  ~FrontendTimeCtx() {
+    if (FrontendTimesIsEnabled && IsValid && DeleteTGroup)
+      delete TGroup;
+  }
+
+  void startFrontendTimer(FTimePair TDsc) {
+    if (FrontendTimesIsEnabled) {
+      assert(IsValid && "Time Context must be initialized");
+      if (FrontendTimer.isRunning())
+        // It stops the timer as a side effect
+        TDsc.second = getCurProcessTime(FrontendTimer);
+      else
+        TDsc.second = FrontendTimer.getTotalTime().getProcessTime();
+      ChildStack.push_back(TDsc);
+      FrontendTimer.startTimer();
+    }
+  }
+
+  bool stopFrontendTimer(bool UseEl = false, FTimePair El = FTimePair()) {
+    if (FrontendTimesIsEnabled) {
+      assert(IsValid && "Time Context must be initialized");
+      assert(FrontendTimer.isRunning() && "FrontendTimer must be running");
+      assert(!ChildStack.empty() &&
+             "There should be at least one running time slice");
+      FTimePair Result = ChildStack.back();
+      ChildStack.pop_back();
+      // As side effect getCurProcessTime does stopTimer().
+      // Should we fix such a side effect?
+      double CurProcTime = getCurProcessTime(FrontendTimer) - Result.second;
+      Result.second = CurProcTime - ChildTime;
+      if (ChildStack.empty())
+        ChildTime = 0;
+      else {
+        ChildTime += Result.second;
+        FrontendTimer.startTimer();
+      }
+      if (UseEl) {
+        if (El.second > 0)
+          Result.first = El.first;
+        else
+          return false;
+      }
+      if (isFirstValid(Result.first) && Result.second > 0.00001) {
+        FrontendTimes.push_back(Result);
+        return true;
+      }
+    }
+    return false;
+  }
+
+  using FTimePair2 = std::pair<FTimePair, unsigned>;
+  static bool ftimeSort2(FTimePair2 I, FTimePair2 J) {
+    return I.first.second < J.first.second;
+  }
+
+  static bool ftimeSort(FTimePair I, FTimePair J) {
+    return I.second < J.second;
+  }
+
+  llvm::TimerGroup *getTimerGroup() {
+    assert(IsValid && "Time Context must be initialized");
+    return TGroup;
+  }
+
+  llvm::Timer *getFrontendTimer() { return &FrontendTimer; }
 
+  std::vector<FTimePair> *getFrontendTimes() { return &FrontendTimes; }
+
+  template <typename Compare>
+  void print(Compare SortName, StringRef SubGroup, StringRef Mark = " (+)") {
+    if (FrontendTimesIsEnabled && !FrontendTimes.empty()) {
+      std::unique_ptr<llvm::raw_ostream> OutStream =
+          llvm::CreateInfoOutputFile();
+      llvm::sort(FrontendTimes.begin(), FrontendTimes.end(), SortName);
+      using FTPIterator = typename std::vector<FTimePair>::iterator;
+      std::pair<FTPIterator, FTPIterator> range;
+
+      std::vector<FTimePair2> FinalTimes;
+
+      *OutStream << "===------------ Clang Timers: " << SubGroup
+                 << " ------------==\n";
+      for (unsigned i = 0; i < FrontendTimes.size();) {
+        range = std::equal_range(FrontendTimes.begin() + i, FrontendTimes.end(),
+                                 FrontendTimes[i], SortName);
+        auto dist = std::distance(range.first, range.second);
+        FTimePair E = {FrontendTimes[i].first, 0};
+        while (range.first != range.second) {
+          E.second += range.first->second;
+          range.first++;
+        }
+        FinalTimes.push_back({E, dist});
+        i += dist;
+      }
+      llvm::sort(FinalTimes.begin(), FinalTimes.end(), ftimeSort2);
+      double TimeThreshold =
+          (FinalTimes.front().first.second + FinalTimes.back().first.second) /
+          2;
+      for (auto E : FinalTimes) {
+        if ((E.first.second > TimeThreshold) || (E.second > 1))
+          *OutStream << llvm::format("%7.4f (%d) ", E.second, E.first.second)
+                     << SortName.getName(E.first) << Mark << "\n";
+      }
+    }
+  }
+  void debugPrint(StringRef H, const void *P) {
+    llvm::dbgs() << H << P
+                 << llvm::format("FrontendTimes.size=%d,ChildStack.size=%d,"
+                                 "ChildTime=%7.4f, ProcessTime=%7.4f\n",
+                                 FrontendTimes.size(), ChildStack.size(),
+                                 ChildTime,
+                                 FrontendTimer.getTotalTime().getProcessTime());
+  }
+};
+
+template <typename T> FrontendTimeCtx<T> *getFrontendFunctionTimeCtx();
+
+template <typename T> class FrontendTimeRAII {
+  using FTimePair = std::pair<T, double>;
+  FrontendTimeCtx<T> *Ctx = nullptr;
+  void init(FTimePair E, llvm::StringRef TName, llvm::StringRef TDsc,
+            llvm::StringRef GName, llvm::StringRef GDsc) {
+    if (Ctx) {
+      if (!Ctx->IsValid)
+        Ctx->init(TName, TDsc, GName, GDsc);
+      Ctx->startFrontendTimer(E);
+    }
+  }
+
+  void init(FTimePair E, llvm::StringRef TName, llvm::StringRef TDsc,
+            llvm::TimerGroup *TG) {
+    if (Ctx) {
+      if (!Ctx->IsValid)
+        Ctx->init(TName, TDsc, TG);
+      Ctx->startFrontendTimer(E);
+    }
+  }
+
+public:
+  FrontendTimeRAII(bool Enabled, FrontendTimeCtx<T> *FTC, FTimePair E,
+                   llvm::StringRef TName, llvm::StringRef TDsc,
+                   llvm::TimerGroup *TG) {
+    if (Enabled) {
+      Ctx = FTC;
+      init(E, TName, TDsc);
+    }
+  }
+
+  FrontendTimeRAII(bool Enabled, FrontendTimeCtx<T> *FTC, FTimePair E,
+                   llvm::StringRef TName, llvm::StringRef TDsc,
+                   llvm::StringRef GName, llvm::StringRef GDsc) {
+    if (Enabled) {
+      Ctx = FTC;
+      init(E, TName, TDsc, GName, GDsc);
+    }
+  }
+
+  FrontendTimeRAII(bool Enabled, FrontendTimeCtx<T> *FTC, FTimePair E) {
+    if (Enabled) {
+      Ctx = FTC;
+      init(E, "clangtimer", "Clang Func Timer",
+           FrontendTimeCtx<T>::getFrontendDefaultTimerGroup());
+    }
+  }
+
+  ~FrontendTimeRAII() {
+    if (Ctx && Ctx->IsValid) {
+      //      Ctx->stopFrontendTimer(true, {T(), -1.0});
+      Ctx->stopFrontendTimer();
+    }
+  }
+};
 } // namespace clang
 
 #endif // LLVM_CLANG_FRONTEND_UTILS_H

lib/CodeGen/BackendUtil.cpp

 #include "llvm/Transforms/Scalar/GVN.h"
 #include "llvm/Transforms/Utils.h"
 #include "llvm/Transforms/Utils/NameAnonGlobals.h"
 #include "llvm/Transforms/Utils/SymbolRewriter.h"
 #include <memory>
 using namespace clang;
 using namespace llvm;
 
+namespace clang {
+void BuryPointer(const void *Ptr);
+extern bool FrontendTimesIsEnabled;
+}
+
 namespace {
 
 // Default filename used for profile generation.
 static constexpr StringLiteral DefaultProfileGenName = "default_%m.profraw";
 
 class EmitAssemblyHelper {
   DiagnosticsEngine &Diags;
   const HeaderSearchOptions &HSOpts;

lib/CodeGen/CodeGenAction.cpp

 #include "clang/AST/DeclGroup.h"
 #include "clang/Basic/FileManager.h"
 #include "clang/Basic/SourceManager.h"
 #include "clang/Basic/TargetInfo.h"
 #include "clang/CodeGen/BackendUtil.h"
 #include "clang/CodeGen/ModuleBuilder.h"
 #include "clang/Frontend/CompilerInstance.h"
 #include "clang/Frontend/FrontendDiagnostic.h"
+#include "clang/Frontend/Utils.h"
 #include "clang/Lex/Preprocessor.h"
+#include "llvm/ADT/Statistic.h"
 #include "llvm/Bitcode/BitcodeReader.h"
 #include "llvm/CodeGen/MachineOptimizationRemarkEmitter.h"
 #include "llvm/IR/DebugInfo.h"
 #include "llvm/IR/DiagnosticInfo.h"
 #include "llvm/IR/DiagnosticPrinter.h"
 #include "llvm/IR/GlobalValue.h"
 #include "llvm/IR/LLVMContext.h"
 #include "llvm/IR/Module.h"
 #include "llvm/IRReader/IRReader.h"
 #include "llvm/Linker/Linker.h"
 #include "llvm/Pass.h"
 #include "llvm/Support/MemoryBuffer.h"
 #include "llvm/Support/SourceMgr.h"
-#include "llvm/Support/Timer.h"
 #include "llvm/Support/ToolOutputFile.h"
 #include "llvm/Support/YAMLTraits.h"
 #include "llvm/Transforms/IPO/Internalize.h"
 
 #include <memory>
 using namespace clang;
 using namespace llvm;
 
+#define DEBUG_TYPE "codegenaction"
+
 namespace clang {
   class BackendConsumer;
   class ClangDiagnosticHandler final : public DiagnosticHandler {
   public:
     ClangDiagnosticHandler(const CodeGenOptions &CGOpts, BackendConsumer *BCon)
         : CodeGenOpts(CGOpts), BackendCon(BCon) {}
   
     bool handleDiagnostics(const DiagnosticInfo &DI) override;
class BackendConsumer : public ASTConsumer {
     std::unique_ptr<CodeGenerator> Gen;
 
     SmallVector<LinkModule, 4> LinkModules;
 
     // This is here so that the diagnostic printer knows the module a diagnostic
     // refers to.
     llvm::Module *CurLinkModule = nullptr;
 
+    using FTimeMark = StringRef;
+    using FTP = std::pair<FTimeMark, double>;
+    using FTPIterator = std::vector<FTP>::iterator;
+
+    class SortClassName {
+    public:
+      bool operator()(FTP i, FTP j) { return i.first.compare(j.first) < 0; }
+      StringRef getName(FTP E) { return E.first; }
+    };
+
+    FrontendTimeCtx<FTimeMark> BCTimerCtx;
+
   public:
     BackendConsumer(BackendAction Action, DiagnosticsEngine &Diags,
                     const HeaderSearchOptions &HeaderSearchOpts,
                     const PreprocessorOptions &PPOpts,
                     const CodeGenOptions &CodeGenOpts,
                     const TargetOptions &TargetOpts,
                     const LangOptions &LangOpts, bool TimePasses,
                     const std::string &InFile,
                     SmallVector<LinkModule, 4> LinkModules,
                     std::unique_ptr<raw_pwrite_stream> OS, LLVMContext &C,
                     CoverageSourceInfo *CoverageInfo = nullptr)
         : Diags(Diags), Action(Action), HeaderSearchOpts(HeaderSearchOpts),
           CodeGenOpts(CodeGenOpts), TargetOpts(TargetOpts), LangOpts(LangOpts),
           AsmOutStream(std::move(OS)), Context(nullptr),
           LLVMIRGeneration("irgen", "LLVM IR Generation Time"),
           LLVMIRGenerationRefCount(0),
           Gen(CreateLLVMCodeGen(Diags, InFile, HeaderSearchOpts, PPOpts,
                                 CodeGenOpts, C, CoverageInfo)),
           LinkModules(std::move(LinkModules)) {
       FrontendTimesIsEnabled = TimePasses;
+      LLVM_DEBUG(llvm::dbgs()
+                 << "BackendConsumer "
+                    "(FrontendTimes.size():ChildStack.size():ChildTime)"
+                    " "
+                 << BCTimerCtx.FrontendTimes.size() << ":"
+                 << BCTimerCtx.ChildStack.size() << ":" << BCTimerCtx.ChildTime
+                 << "\n");
     }
+
+    ~BackendConsumer() {
+      if (FrontendTimesIsEnabled)
+        BCTimerCtx.print<SortClassName>(SortClassName(), "BackendConsumer");
+    }
+
     llvm::Module *getModule() const { return Gen->GetModule(); }
     std::unique_ptr<llvm::Module> takeModule() {
       return std::unique_ptr<llvm::Module>(Gen->ReleaseModule());
     }
 
     CodeGenerator *getCodeGenerator() { return Gen.get(); }
 
     void HandleCXXStaticMemberVarInstantiation(VarDecl *VD) override {
       Gen->HandleCXXStaticMemberVarInstantiation(VD);
     }
 
     void Initialize(ASTContext &Ctx) override {
+      LLVM_DEBUG(llvm::dbgs()
+                 << "BackendConsumer::Initialize "
+                    "(FrontendTimes.size():ChildStack.size():ChildTime)"
+                    " "
+                 << BCTimerCtx.FrontendTimes.size() << ":"
+                 << BCTimerCtx.ChildStack.size() << ":" << BCTimerCtx.ChildTime
+                 << "\n");
       assert(!Context && "initialized multiple times");
 
       Context = &Ctx;
 
       if (FrontendTimesIsEnabled)
         LLVMIRGeneration.startTimer();
 
       Gen->Initialize(Ctx);
bool HandleTopLevelDecl(DeclGroupRef D) override {
         if (LLVMIRGenerationRefCount == 0)
           LLVMIRGeneration.stopTimer();
       }
 
       return true;
     }
 
     void HandleInlineFunctionDefinition(FunctionDecl *D) override {
+      LLVM_DEBUG(getFrontendFunctionTimeCtx<const FunctionDecl *>()->debugPrint(
+          "FrontendTimeRAII(HandleInlineFunctionDefinition): ", D));
+      FrontendTimeRAII<const FunctionDecl *> FTRAII(
+          FrontendTimesIsEnabled,
+          getFrontendFunctionTimeCtx<const FunctionDecl *>(), {D, 0});
       PrettyStackTraceDecl CrashInfo(D, SourceLocation(),
                                      Context->getSourceManager(),
                                      "LLVM IR generation of inline function");
       if (FrontendTimesIsEnabled)
         LLVMIRGeneration.startTimer();
 
       Gen->HandleInlineFunctionDefinition(D);
 
bool LinkInModules() {
 
         if (Err)
           return true;
       }
       return false; // success
     }
 
     void HandleTranslationUnit(ASTContext &C) override {
+      LLVM_DEBUG(llvm::dbgs()
+                 << "BackendConsumer::HandleTranslationUnit "
+                    "(FrontendTimes.size():ChildStack.size():ChildTime)"
+                    " "
+                 << BCTimerCtx.FrontendTimes.size() << ":"
+                 << BCTimerCtx.ChildStack.size() << ":" << BCTimerCtx.ChildTime
+                 << "\n");
       {
         PrettyStackTraceString CrashInfo("Per-file LLVM IR generation");
         if (FrontendTimesIsEnabled) {
           LLVMIRGenerationRefCount += 1;
           if (LLVMIRGenerationRefCount == 1)
             LLVMIRGeneration.startTimer();
         }
 

 CodeGenAction::~CodeGenAction() {
   TheModule.reset();
   if (OwnsVMContext)
     delete VMContext;
 }
 
 bool CodeGenAction::hasIRSupport() const { return true; }
 
+static StringRef getFDName(CodeGen::CodeGenModule &CGM,
+                           const FunctionDecl *FD) {
+  assert(isFirstValid<const FunctionDecl *>(FD) && "Invalid FD");
+  if (FD->hasBody()) {
+    GlobalDecl GD;
+    return CGM.getMangledName(GD.getWithDecl(FD));
+  }
+  return FD->getName();
+}
+
+using FTimeBase = const FunctionDecl *;
+using FTP = std::pair<FTimeBase, double>;
+
+class SortClassName {
+  CodeGen::CodeGenModule &CGM;
+
+public:
+  SortClassName(CodeGen::CodeGenModule &_CGM) : CGM(_CGM) {}
+  bool operator()(FTP i, FTP j) {
+    StringRef NameI = getFDName(CGM, i.first);
+    StringRef NameJ = getFDName(CGM, j.first);
+    return NameI.compare(NameJ) < 0;
+  }
+
+  StringRef getName(FTP E) { return getFDName(CGM, E.first); }
+};
+
 void CodeGenAction::EndSourceFileAction() {
   // If the consumer creation failed, do nothing.
   if (!getCompilerInstance().hasASTConsumer())
     return;
-
+  if (FrontendTimesIsEnabled)
+    getFrontendFunctionTimeCtx<FTimeBase>()->print<SortClassName>(
+        SortClassName(BEConsumer->getCodeGenerator()->CGM()),
+        "CodeGen Functions", " (*)");
   // Steal the module from the consumer.
   TheModule = BEConsumer->takeModule();
 }
 
 std::unique_ptr<llvm::Module> CodeGenAction::takeModule() {
   return std::move(TheModule);
 }
 

lib/CodeGen/CodeGenFunction.cpp

 //===--- CodeGenFunction.cpp - Emit LLVM Code from ASTs for a Function ----===//
 //
 //                     The LLVM Compiler Infrastructure
 //
 // This file is distributed under the University of Illinois Open Source
 // License. See LICENSE.TXT for details.
 //
 //===----------------------------------------------------------------------===//
 //
 // This coordinates the per-function state used while generating code.
 //
 //===----------------------------------------------------------------------===//
 
 #include "CodeGenFunction.h"
 #include "CGBlocks.h"
-#include "CGCleanup.h"
 #include "CGCUDARuntime.h"
 #include "CGCXXABI.h"
+#include "CGCleanup.h"
 #include "CGDebugInfo.h"
 #include "CGOpenMPRuntime.h"
 #include "CodeGenModule.h"
 #include "CodeGenPGO.h"
 #include "TargetInfo.h"
 #include "clang/AST/ASTContext.h"
 #include "clang/AST/ASTLambda.h"
 #include "clang/AST/Decl.h"
 #include "clang/AST/DeclCXX.h"
 #include "clang/AST/StmtCXX.h"
 #include "clang/AST/StmtObjC.h"
 #include "clang/Basic/Builtins.h"
 #include "clang/Basic/TargetInfo.h"
 #include "clang/CodeGen/CGFunctionInfo.h"
 #include "clang/Frontend/CodeGenOptions.h"
+#include "clang/Frontend/Utils.h"
 #include "clang/Sema/SemaDiagnostic.h"
 #include "llvm/IR/DataLayout.h"
 #include "llvm/IR/Dominators.h"
 #include "llvm/IR/Intrinsics.h"
 #include "llvm/IR/MDBuilder.h"
 #include "llvm/IR/Operator.h"
 #include "llvm/Transforms/Utils/PromoteMemToReg.h"
 using namespace clang;
 using namespace CodeGen;
 
+#define DEBUG_TYPE "codegenfunction"
+
 /// shouldEmitLifetimeMarkers - Decide whether we need emit the life-time
 /// markers.
 static bool shouldEmitLifetimeMarkers(const CodeGenOptions &CGOpts,
                                       const LangOptions &LangOpts) {
   if (CGOpts.DisableLifetimeMarkers)
     return false;
 
   // Disable lifetime markers in msan builds.
if (CGM.getCodeGenOpts().ReciprocalMath) {
     FMF.setAllowReciprocal();
   }
   if (CGM.getCodeGenOpts().Reassociate) {
     FMF.setAllowReassoc();
   }
   Builder.setFastMathFlags(FMF);
 }
 
+using FTimeBase = const FunctionDecl *;
+
 CodeGenFunction::~CodeGenFunction() {
   assert(LifetimeExtendedCleanupStack.empty() && "failed to emit a cleanup");
 
   // If there are any unclaimed block infos, go ahead and destroy them
   // now.  This can happen if IR-gen gets clever and skips evaluating
   // something.
   if (FirstBlockInfo)
     destroyBlockInfos(FirstBlockInfo);
 
   if (getLangOpts().OpenMP && CurFn)
     CGM.getOpenMPRuntime().functionFinished(*this);
+  if (FrontendTimesIsEnabled && CurFuncDecl) {
+    LLVM_DEBUG(getFrontendFunctionTimeCtx<const FunctionDecl *>()->debugPrint(
+        "stopFrontendTimer(~CodeGenFunction): ", CurFuncDecl));
+    getFrontendFunctionTimeCtx<FTimeBase>()->stopFrontendTimer();
+  }
 }
 
 CharUnits CodeGenFunction::getNaturalPointeeTypeAlignment(QualType T,
                                                     LValueBaseInfo *BaseInfo,
                                                     TBAAAccessInfo *TBAAInfo) {
   return getNaturalTypeAlignment(T->getPointeeType(), BaseInfo, TBAAInfo,
                                  /* forPointeeType= */ true);
 }
void CodeGenFunction::StartFunction(GlobalDecl GD,
                                     SourceLocation StartLoc) {
   assert(!CurFn &&
          "Do not use a CodeGenFunction object for more than one function");
 
   const Decl *D = GD.getDecl();
 
   DidCallStackSave = false;
   CurCodeDecl = D;
-  if (const auto *FD = dyn_cast_or_null<FunctionDecl>(D))
+  if (const auto *FD = dyn_cast_or_null<FunctionDecl>(D)) {
     if (FD->usesSEHTry())
       CurSEHParent = FD;
+    if (FrontendTimesIsEnabled) {
+      LLVM_DEBUG(getFrontendFunctionTimeCtx<const FunctionDecl *>()->debugPrint(
+          "startFrontendTimer(StartFunction): ", FD));
+      getFrontendFunctionTimeCtx<FTimeBase>()->startFrontendTimer({FD, 0.0});
+    }
+  }
   CurFuncDecl = (D ? D->getNonClosureContext() : nullptr);
   FnRetTy = RetTy;
   CurFn = Fn;
   CurFnInfo = &FnInfo;
   assert(CurFn->isDeclaration() && "Function already has body?");
 
   // If this function has been blacklisted for any of the enabled sanitizers,
   // disable the sanitizer for the function.

lib/CodeGen/CodeGenModule.cpp

 #include "clang/Basic/CharInfo.h"
 #include "clang/Basic/Diagnostic.h"
 #include "clang/Basic/Module.h"
 #include "clang/Basic/SourceManager.h"
 #include "clang/Basic/TargetInfo.h"
 #include "clang/Basic/Version.h"
 #include "clang/CodeGen/ConstantInitBuilder.h"
 #include "clang/Frontend/CodeGenOptions.h"
+#include "clang/Frontend/Utils.h"
 #include "clang/Sema/SemaDiagnostic.h"
 #include "llvm/ADT/Triple.h"
 #include "llvm/Analysis/TargetLibraryInfo.h"
 #include "llvm/IR/CallSite.h"
 #include "llvm/IR/CallingConv.h"
 #include "llvm/IR/DataLayout.h"
 #include "llvm/IR/Intrinsics.h"
 #include "llvm/IR/LLVMContext.h"
 #include "llvm/IR/Module.h"
 #include "llvm/ProfileData/InstrProfReader.h"
 #include "llvm/Support/ConvertUTF.h"
 #include "llvm/Support/ErrorHandling.h"
 #include "llvm/Support/MD5.h"
 
 using namespace clang;
 using namespace CodeGen;
 
+#define DEBUG_TYPE "codegenmodule"
+
 static llvm::cl::opt<bool> LimitedCoverage(
     "limited-coverage-experimental", llvm::cl::ZeroOrMore, llvm::cl::Hidden,
     llvm::cl::desc("Emit limited coverage mapping information (experimental)"),
     llvm::cl::init(false));
 
 static const char AnnotationSection[] = "llvm.metadata";
 
 static CGCXXABI *createCXXABI(CodeGenModule &CGM) {

 void CodeGenModule::EmitTopLevelDecl(Decl *D) {
   // Ignore dependent declarations.
   if (D->isTemplated())
     return;
 
   switch (D->getKind()) {
   case Decl::CXXConversion:
   case Decl::CXXMethod:
-  case Decl::Function:
+  case Decl::Function: {
+    LLVM_DEBUG(getFrontendFunctionTimeCtx<const FunctionDecl *>()->debugPrint(
+        "FrontendTimeRAII(EmitTopLevelDecl)", cast<FunctionDecl>(D)));
+    FrontendTimeRAII<const FunctionDecl *> FTRAII(
+        FrontendTimesIsEnabled,
+        getFrontendFunctionTimeCtx<const FunctionDecl *>(),
+        {cast<FunctionDecl>(D), 0});
     EmitGlobal(cast<FunctionDecl>(D));
     // Always provide some coverage mapping
     // even for the functions that aren't emitted.
     AddDeferredUnusedCoverageMapping(D);
     break;
-
+  }
   case Decl::CXXDeductionGuide:
     // Function-like, but does not result in code emission.
     break;
 
   case Decl::Var:
   case Decl::Decomposition:
   case Decl::VarTemplateSpecialization:
     EmitGlobal(cast<VarDecl>(D));

lib/Frontend/FrontendTiming.cpp

 //===- FronendTiming.cpp - Implements Frontend timing utils  --------------===//
 //
 //                     The LLVM Compiler Infrastructure
 //
 // This file is distributed under the University of Illinois Open Source
 // License. See LICENSE.TXT for details.
 //
 //===----------------------------------------------------------------------===//
 //
 // This file keps implementation of frontend timing utils.
 //
 //===----------------------------------------------------------------------===//
 
+#include "clang/AST/Decl.h"
 #include "clang/Frontend/Utils.h"
+#include "llvm/ADT/StringRef.h"
 
 namespace clang {
 
 bool FrontendTimesIsEnabled = false;
+llvm::TimerGroup *FDefTimeGroup = nullptr;
 
+using FTimeBase = const FunctionDecl *;
+FrontendTimeCtx<FTimeBase> FuncTimeCtx;
+
+template <>
+FrontendTimeCtx<FTimeBase> *getFrontendFunctionTimeCtx<FTimeBase>() {
+  if (FrontendTimesIsEnabled && !FuncTimeCtx.IsValid)
+    FuncTimeCtx.init("cftimer", "Clang Function Timer",
+                     FuncTimeCtx.getFrontendDefaultTimerGroup());
+  return &FuncTimeCtx;
+}
+
+template <> bool isFirstValid<FTimeBase>(FTimeBase First) {
+  assert(First && "Invalid First");
+  if (FrontendTimesIsEnabled && FuncTimeCtx.IsValid &&
+      !First->isInvalidDecl() && First->getIdentifier()) {
+    if (First->getVisibility() == DefaultVisibility && First->hasBody())
+      return true;
+  }
+  return false;
+}
+
+template <> bool isFirstValid<llvm::StringRef>(llvm::StringRef First) {
+  assert(!First.empty() && "Invalid First");
+  return FrontendTimesIsEnabled;
+}
 }

lib/Parse/CMakeLists.txt

add_clang_library(clangParse
   ParseStmtAsm.cpp
   ParseTemplate.cpp
   ParseTentative.cpp
   Parser.cpp
 
   LINK_LIBS
   clangAST
   clangBasic
+  clangFrontend
   clangLex
   clangSema
   )

lib/Parse/ParseTemplate.cpp

 //===--- ParseTemplate.cpp - Template Parsing -----------------------------===//
 //
 //                     The LLVM Compiler Infrastructure
 //
 // This file is distributed under the University of Illinois Open Source
 // License. See LICENSE.TXT for details.
 //
 //===----------------------------------------------------------------------===//
 //
 //  This file implements parsing of C++ templates.
 //
 //===----------------------------------------------------------------------===//
 
 #include "clang/AST/ASTContext.h"
 #include "clang/AST/DeclTemplate.h"
+#include "clang/Frontend/Utils.h"
 #include "clang/Parse/ParseDiagnostic.h"
 #include "clang/Parse/Parser.h"
 #include "clang/Parse/RAIIObjectsForParser.h"
 #include "clang/Sema/DeclSpec.h"
 #include "clang/Sema/ParsedTemplate.h"
 #include "clang/Sema/Scope.h"
 using namespace clang;
 
+#define DEBUG_TYPE "parsetemplate"
+
 /// Parse a template declaration, explicit instantiation, or
 /// explicit specialization.
 Decl *
 Parser::ParseDeclarationStartingWithTemplate(DeclaratorContext Context,
                                              SourceLocation &DeclEnd,
                                              AccessSpecifier AS,
                                              AttributeList *AccessAttrs) {
   ObjCDeclContextSwitch ObjCDC(*this);
-  
-  if (Tok.is(tok::kw_template) && NextToken().isNot(tok::less)) {
-    return ParseExplicitInstantiation(Context,
-                                      SourceLocation(), ConsumeToken(),
-                                      DeclEnd, AS);
+  Decl *Result;
+  if (FrontendTimesIsEnabled) {
+    LLVM_DEBUG(getFrontendFunctionTimeCtx<const FunctionDecl *>()->debugPrint(
+        "ParseDeclarationStartingWithTemplate: ", nullptr));
+    getFrontendFunctionTimeCtx<const FunctionDecl *>()->startFrontendTimer(
+        {nullptr, 0.0});
   }
-  return ParseTemplateDeclarationOrSpecialization(Context, DeclEnd, AS,
+  if (Tok.is(tok::kw_template) && NextToken().isNot(tok::less)) {
+    Result = ParseExplicitInstantiation(Context, SourceLocation(),
+                                        ConsumeToken(), DeclEnd, AS);
+  } else
+    Result = ParseTemplateDeclarationOrSpecialization(Context, DeclEnd, AS,
                                                       AccessAttrs);
+  if (FrontendTimesIsEnabled) {
+    bool Done = false;
+    if (const auto *F = dyn_cast_or_null<FunctionDecl>(Result)) {
+      if (F->isFunctionOrFunctionTemplate() && F->hasBody()) {
+        LLVM_DEBUG(
+            getFrontendFunctionTimeCtx<const FunctionDecl *>()->debugPrint(
+                "stopFrontendTimer(ParseDeclarationStartingWithTemplate): ",
+                F));
+        getFrontendFunctionTimeCtx<const FunctionDecl *>()->stopFrontendTimer(
+            true, {F, 0.0});
+        Done = true;
+      }
+    }
+    if (!Done) {
+      getFrontendFunctionTimeCtx<const FunctionDecl *>()->stopFrontendTimer(
+          true, {nullptr, -1.0});
+      LLVM_DEBUG(llvm::dbgs() << "ParseDeclarationStartingWithTemplate: simply "
+                                 "remove the non-func time slot from times\n");
+    }
+  }
+  return Result;
 }
 
 
 
 /// Parse a template declaration or an explicit specialization.
 ///
 /// Template declarations include one or more template parameter lists
 /// and either the function or class template declaration. Explicit

lib/Sema/SemaDecl.cpp

 #include "clang/AST/DeclTemplate.h"
 #include "clang/AST/EvaluatedExprVisitor.h"
 #include "clang/AST/ExprCXX.h"
 #include "clang/AST/StmtCXX.h"
 #include "clang/Basic/Builtins.h"
 #include "clang/Basic/PartialDiagnostic.h"
 #include "clang/Basic/SourceManager.h"
 #include "clang/Basic/TargetInfo.h"
+#include "clang/Frontend/Utils.h"
 #include "clang/Lex/HeaderSearch.h" // TODO: Sema shouldn't depend on Lex
 #include "clang/Lex/Lexer.h" // TODO: Extract static functions to fix layering.
 #include "clang/Lex/ModuleLoader.h" // TODO: Sema shouldn't depend on Lex
 #include "clang/Lex/Preprocessor.h" // Included for isCodeCompletionEnabled()
 #include "clang/Sema/CXXFieldCollector.h"
 #include "clang/Sema/DeclSpec.h"
 #include "clang/Sema/DelayedDiagnostic.h"
 #include "clang/Sema/Initialization.h"
 #include "clang/Sema/Lookup.h"
 #include "clang/Sema/ParsedTemplate.h"
 #include "clang/Sema/Scope.h"
 #include "clang/Sema/ScopeInfo.h"
 #include "clang/Sema/SemaInternal.h"
 #include "clang/Sema/Template.h"
 #include "llvm/ADT/SmallString.h"
 #include "llvm/ADT/Triple.h"
 #include <algorithm>
 #include <cstring>
 #include <functional>
 
 using namespace clang;
 using namespace sema;
 
+#define DEBUG_TYPE "semadecl"
+
 Sema::DeclGroupPtrTy Sema::ConvertDeclToDeclGroup(Decl *Ptr, Decl *OwnedType) {
   if (OwnedType) {
     Decl *Group[2] = { OwnedType, Ptr };
     return DeclGroupPtrTy::make(DeclGroupRef::Create(Context, Group, 2));
   }
 
   return DeclGroupPtrTy::make(DeclGroupRef(Ptr));
 }

 /// merging decls or emitting diagnostics as appropriate.
 ///
 /// In C++, New and Old must be declarations that are not
 /// overloaded. Use IsOverload to determine whether New and Old are
 /// overloaded, and to select the Old declaration that New should be
 /// merged with.
 ///
 /// Returns true if there was an error, false otherwise.
 bool Sema::MergeFunctionDecl(FunctionDecl *New, NamedDecl *&OldD,
                              Scope *S, bool MergeTypeWithOld) {
   // Verify the old decl was also a function.
   FunctionDecl *Old = OldD->getAsFunction();
   if (!Old) {
     if (UsingShadowDecl *Shadow = dyn_cast<UsingShadowDecl>(OldD)) {
       if (New->getFriendObjectKind()) {
         Diag(New->getLocation(), diag::err_using_decl_friend);
         Diag(Shadow->getTargetDecl()->getLocation(),

 ///
 /// This routine handles the merging of attributes and other
 /// properties of function declarations from the old declaration to
 /// the new declaration, once we know that New is in fact a
 /// redeclaration of Old.
 ///
 /// \returns false
 bool Sema::MergeCompatibleFunctionDecls(FunctionDecl *New, FunctionDecl *Old,
                                         Scope *S, bool MergeTypeWithOld) {
   // Merge the attributes
   mergeDeclAttributes(New, Old);
 
   // Merge "pure" flag.
   if (Old->isPure())
     New->setPure();
 
   // Merge "used" flag.
Sema::ActOnFunctionDeclarator(Scope *S, Declarator &D, DeclContext *DC,
 
   DeclContext *OriginalDC = DC;
   bool IsLocalExternDecl = adjustContextForLocalExternDecl(DC);
 
   FunctionDecl *NewFD = CreateNewFunctionDecl(*this, D, DC, R, TInfo, SC,
                                               isVirtualOkay);
   if (!NewFD) return nullptr;
 
+  LLVM_DEBUG(getFrontendFunctionTimeCtx<const FunctionDecl *>()->debugPrint(
+      "FrontendTimeRAII(ActOnFunctionDeclarator): ", NewFD));
+  FrontendTimeRAII<const FunctionDecl *> FTRAII(
+      FrontendTimesIsEnabled,
+      getFrontendFunctionTimeCtx<const FunctionDecl *>(), {NewFD, 0});
+
   if (OriginalLexicalContext && OriginalLexicalContext->isObjCContainer())
     NewFD->setTopLevelDeclInObjCContainer();
 
   // Set the lexical context. If this is a function-scope declaration, or has a
   // C++ scope specifier, or is the object of a friend declaration, the lexical
   // context will be different from the semantic context.
   NewFD->setLexicalDeclContext(CurContext);
 
Decl *Sema::ActOnStartOfFunctionDef(Scope *FnBodyScope, Decl *D,
 
   FunctionDecl *FD = nullptr;
 
   if (FunctionTemplateDecl *FunTmpl = dyn_cast<FunctionTemplateDecl>(D))
     FD = FunTmpl->getTemplatedDecl();
   else
     FD = cast<FunctionDecl>(D);
 
+  if (FrontendTimesIsEnabled) {
+    LLVM_DEBUG(getFrontendFunctionTimeCtx<const FunctionDecl *>()->debugPrint(
+        "startFrontendTimer(ActOnStartFuncionDef): ", FD));
+    getFrontendFunctionTimeCtx<const FunctionDecl *>()->startFrontendTimer(
+        {FD, 0.0});
+  }
+
   // Check for defining attributes before the check for redefinition.
   if (const auto *Attr = FD->getAttr<AliasAttr>()) {
     Diag(Attr->getLocation(), diag::err_alias_is_definition) << FD << 0;
     FD->dropAttr<AliasAttr>();
     FD->setInvalidDecl();
   }
   if (const auto *Attr = FD->getAttr<IFuncAttr>()) {
     Diag(Attr->getLocation(), diag::err_alias_is_definition) << FD << 1;
Decl *Sema::ActOnFinishFunctionBody(Decl *dcl, Stmt *Body,
   PopFunctionScopeInfo(ActivePolicy, dcl);
   // If any errors have occurred, clear out any temporaries that may have
   // been leftover. This ensures that these temporaries won't be picked up for
   // deletion in some later function.
   if (getDiagnostics().hasErrorOccurred()) {
     DiscardCleanupsInEvaluationContext();
   }
 
+  if (FrontendTimesIsEnabled) {
+    LLVM_DEBUG(getFrontendFunctionTimeCtx<const FunctionDecl *>()->debugPrint(
+        "stopFrontendTimer(ActOnFinishFunctionBody): ", FD));
+    assert(getFrontendFunctionTimeCtx<const FunctionDecl *>()
+                   ->ChildStack.back()
+                   .first == FD &&
+           "Invalid FD");
+    getFrontendFunctionTimeCtx<const FunctionDecl *>()->stopFrontendTimer();
+  }
+
   return dcl;
 }
 
 /// When we finish delayed parsing of an attribute, we must attach it to the
 /// relevant Decl.
 void Sema::ActOnFinishDelayedAttribute(Scope *S, Decl *D,
                                        ParsedAttributes &Attrs) {
   // Always attach attributes to the underlying decl.

lib/Sema/SemaLambda.cpp

 //===--- SemaLambda.cpp - Semantic Analysis for C++11 Lambdas -------------===//
 //
 //                     The LLVM Compiler Infrastructure
 //
 // This file is distributed under the University of Illinois Open Source
 // License. See LICENSE.TXT for details.
 //
 //===----------------------------------------------------------------------===//
 //
 //  This file implements semantic analysis for C++ lambda expressions.
 //
 //===----------------------------------------------------------------------===//
-#include "clang/Sema/DeclSpec.h"
+#include "clang/Sema/SemaLambda.h"
 #include "TypeLocBuilder.h"
 #include "clang/AST/ASTLambda.h"
 #include "clang/AST/ExprCXX.h"
 #include "clang/Basic/TargetInfo.h"
+#include "clang/Frontend/Utils.h"
+#include "clang/Sema/DeclSpec.h"
 #include "clang/Sema/Initialization.h"
 #include "clang/Sema/Lookup.h"
 #include "clang/Sema/Scope.h"
 #include "clang/Sema/ScopeInfo.h"
 #include "clang/Sema/SemaInternal.h"
-#include "clang/Sema/SemaLambda.h"
 using namespace clang;
 using namespace sema;
 
+#define DEBUG_TYPE "semalambda"
+
 /// Examines the FunctionScopeInfo stack to determine the nearest
 /// enclosing lambda (to the current lambda) that is 'capture-ready' for 
 /// the variable referenced in the current lambda (i.e. \p VarToCapture).
 /// If successful, returns the index into Sema's FunctionScopeInfo stack
 /// of the capture-ready lambda's LambdaScopeInfo.
 ///  
 /// Climbs down the stack of lambdas (deepest nested lambda - i.e. current 
 /// lambda - is on top) to determine the index of the nearest enclosing/outer
static ExprResult performLambdaVarCaptureInitialization(Sema &S,
   InitializationKind InitKind = InitializationKind::CreateDirect(Loc, Loc, Loc);
   InitializationSequence Init(S, Entity, InitKind, Ref);
   return Init.Perform(S, Entity, InitKind, Ref);
 }
          
 ExprResult Sema::ActOnLambdaExpr(SourceLocation StartLoc, Stmt *Body, 
                                  Scope *CurScope) {
   LambdaScopeInfo LSI = *cast<LambdaScopeInfo>(FunctionScopes.back());
+
+  if (FrontendTimesIsEnabled) {
+    LLVM_DEBUG(getFrontendFunctionTimeCtx<const FunctionDecl *>()->debugPrint(
+        "startFrontendTimer(ActOnLambdaExpr): ", LSI.CallOperator));
+    getFrontendFunctionTimeCtx<const FunctionDecl *>()->startFrontendTimer(
+        {LSI.CallOperator, 0.0});
+  }
   ActOnFinishFunctionBody(LSI.CallOperator, Body);
   return BuildLambdaExpr(StartLoc, Body->getLocEnd(), &LSI);
 }
 
 static LambdaCaptureDefault
 mapImplicitCaptureStyle(CapturingScopeInfo::ImplicitCaptureStyle ICS) {
   switch (ICS) {
   case CapturingScopeInfo::ImpCap_None:

lib/Sema/SemaTemplateInstantiateDecl.cpp

-//===--- SemaTemplateInstantiateDecl.cpp - C++ Template Decl Instantiation ===/
+//===--- SemaTemplateInstantiateDecl.cpp - C++ T--emplate Decl Instantiation
+//===/
 //
 //                     The LLVM Compiler Infrastructure
 //
 // This file is distributed under the University of Illinois Open Source
 // License. See LICENSE.TXT for details.
 //===----------------------------------------------------------------------===/
 //
 //  This file implements C++ template instantiation for declarations.
 //
 //===----------------------------------------------------------------------===/
-#include "clang/Sema/SemaInternal.h"
 #include "clang/AST/ASTConsumer.h"
 #include "clang/AST/ASTContext.h"
 #include "clang/AST/ASTMutationListener.h"
 #include "clang/AST/DeclTemplate.h"
 #include "clang/AST/DeclVisitor.h"
 #include "clang/AST/DependentDiagnostic.h"
 #include "clang/AST/Expr.h"
 #include "clang/AST/ExprCXX.h"
 #include "clang/AST/PrettyDeclStackTrace.h"
 #include "clang/AST/TypeLoc.h"
+#include "clang/Frontend/Utils.h"
 #include "clang/Sema/Initialization.h"
 #include "clang/Sema/Lookup.h"
+#include "clang/Sema/SemaInternal.h"
 #include "clang/Sema/Template.h"
 #include "clang/Sema/TemplateInstCallback.h"
 
+#define DEBUG_TYPE "templateinst"
 using namespace clang;
 
 static bool isDeclWithinFunction(const Decl *D) {
   const DeclContext *DC = D->getDeclContext();
   if (DC->isFunctionOrMethod())
     return true;
 
   if (DC->isRecord())

lib/Sema/TreeTransform.h

 #include "clang/AST/Expr.h"
 #include "clang/AST/ExprCXX.h"
 #include "clang/AST/ExprObjC.h"
 #include "clang/AST/ExprOpenMP.h"
 #include "clang/AST/Stmt.h"
 #include "clang/AST/StmtCXX.h"
 #include "clang/AST/StmtObjC.h"
 #include "clang/AST/StmtOpenMP.h"
+#include "clang/Frontend/Utils.h"
 #include "clang/Sema/Designator.h"
 #include "clang/Sema/Lookup.h"
 #include "clang/Sema/Ownership.h"
 #include "clang/Sema/ParsedTemplate.h"
 #include "clang/Sema/ScopeInfo.h"
 #include "clang/Sema/SemaDiagnostic.h"
 #include "clang/Sema/SemaInternal.h"
 #include "llvm/ADT/ArrayRef.h"
TreeTransform<Derived>::TransformLambdaExpr(LambdaExpr *E) {
   CXXMethodDecl *NewCallOperator = getSema().startLambdaDefinition(
       Class, E->getIntroducerRange(), NewCallOpTSI,
       E->getCallOperator()->getLocEnd(),
       NewCallOpTSI->getTypeLoc().castAs<FunctionProtoTypeLoc>().getParams(),
       E->getCallOperator()->isConstexpr());
 
   LSI->CallOperator = NewCallOperator;
 
+  if (FrontendTimesIsEnabled) {
+    getFrontendFunctionTimeCtx<const FunctionDecl *>()->startFrontendTimer(
+        {NewCallOperator, 0.0});
+  }
+
   for (unsigned I = 0, NumParams = NewCallOperator->getNumParams();
        I != NumParams; ++I) {
     auto *P = NewCallOperator->getParamDecl(I);
     if (P->hasUninstantiatedDefaultArg()) {
       EnterExpressionEvaluationContext Eval(
           getSema(),
           Sema::ExpressionEvaluationContext::PotentiallyEvaluatedIfUsed, P);
       ExprResult R = getDerived().TransformExpr(
           E->getCallOperator()->getParamDecl(I)->getDefaultArg());

test/Frontend/ftime-report-template-decl.cpp

 // 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
 
 // Template function declarations
 template <typename T>
-void foo();
+T foo(T bar) {
+  T Result = bar * bar + bar / 1.2 + bar;
+  return Result;
+};
 template <typename T, typename U>
-void foo();
+T foo(T bar, U bar2) {
+  T Result = bar2 * bar + bar / 1.2 + bar2;
+  return Result;
+};
 
 // Template function definitions.
 template <typename T>
 void foo() {}
 
 // Template class (forward) declarations
 template <typename T>
 struct A;

 template <typename U>
 oneT L<k>::O<T>::Fun(U) { return one; }
 
 template <>
 template <>
 template <typename U>
 oneT L<0>::O<char>::Fun(U) { return one; }
 
-void Instantiate() {
+double Instantiate() {
   sassert(sizeof(L<0>::O<int>::Fun(0)) == sizeof(one));
   sassert(sizeof(L<0>::O<char>::Fun(0)) == sizeof(one));
+  int R1 = foo<int>(123);
+  char R2 = foo<char, int>('d', 1234);
+  int R3 = foo<double>(1.2);
+  double R4 = foo<double, int>(34.56, 1234);
+  double R5 = R1 + R2 * R3 - R4 + one[0] - two[1];
+  return R5 * R1 + R4 / R3 + R2;
 }
 }
 
 template <class>
 struct Foo {
   template <class _Other>
   using rebind_alloc = _Other;
 };
 template <class _Alloc>
 struct _Wrap_alloc {
   template <class _Other>
   using rebind_alloc = typename Foo<_Alloc>::template rebind_alloc<_Other>;
   template <class>
   using rebind = _Wrap_alloc;
 };
 _Wrap_alloc<int>::rebind<int> w;
 
-// CHECK: Miscellaneous Ungrouped Timers
+// CHECK: Clang Timers: CodeGen Functions
+// CHECK-DAG: 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

test/Headers/opencl-c-header.cl

 
 // CHECK20: _Z12write_imagef14ocl_image3d_wo
 #if __OPENCL_C_VERSION__ >= CL_VERSION_2_0
 void test_image3dwo(write_only image3d_t img) {
   write_imagef(img, (0), (0.0f));
 }
 #endif //__OPENCL_C_VERSION__
 
-// CHECK-MOD: Reading modules
+// CHECK-DAG-MOD: Clang Timers: CodeGen Functions
+// CHECK-DAG-MOD: Reading modules