[PATCH] D36492: [RFC][time-report] Add preprocessor timer

Brian Gesiak via Phabricator via cfe-commits cfe-commits at lists.llvm.org
Tue Aug 8 15:25:55 PDT 2017


modocache created this revision.

`gcc -ftime-report` provides a breakdown of how much time GCC spends
doing preprocessing, parsing, template instantiation, and more:

  g++ -ftime-report foo.cpp
  Execution times (seconds)
   phase setup             :   0.00 ( 0%) usr   0.00 ( 0%) sys   0.00 ( 0%) wall    1414 kB ( 8%) ggc
   phase parsing           :   0.10 (100%) usr   0.08 (100%) sys   0.18 (95%) wall   15955 kB (88%) ggc
   phase opt and generate  :   0.00 ( 0%) usr   0.00 ( 0%) sys   0.01 ( 5%) wall     489 kB ( 3%) ggc
   |name lookup            :   0.00 ( 0%) usr   0.00 ( 0%) sys   0.04 (21%) wall    1054 kB ( 6%) ggc
   preprocessing           :   0.02 (20%) usr   0.01 (13%) sys   0.03 (16%) wall     896 kB ( 5%) ggc
   parser (global)         :   0.00 ( 0%) usr   0.03 (38%) sys   0.04 (21%) wall    6603 kB (37%) ggc
   parser struct body      :   0.04 (40%) usr   0.00 ( 0%) sys   0.04 (21%) wall    2791 kB (15%) ggc
   parser enumerator list  :   0.01 (10%) usr   0.00 ( 0%) sys   0.00 ( 0%) wall      44 kB ( 0%) ggc
   parser function body    :   0.00 ( 0%) usr   0.02 (25%) sys   0.02 (11%) wall    1047 kB ( 6%) ggc
   parser inl. meth. body  :   0.01 (10%) usr   0.01 (13%) sys   0.03 (16%) wall    1093 kB ( 6%) ggc
   template instantiation  :   0.02 (20%) usr   0.01 (12%) sys   0.02 (11%) wall    3280 kB (18%) ggc
   LRA non-specific        :   0.00 ( 0%) usr   0.00 ( 0%) sys   0.01 ( 5%) wall       0 kB ( 0%) ggc
   TOTAL                 :   0.10             0.08             0.19              18028 kB

`clang -ftime-report` gives an incredibly detailed breakdown of how long
each LLVM pass takes, but when it comes to front-end times, only
provides the generic "Clang front-end timer", or "Code Generation Time".
Here's an example of its output:
https://gist.github.com/modocache/d74833818107ed50d11387a5a4e3fb72

As a result, when attempting to diagnose slow compile times with Clang,
users are forced to use external profiling tools in order to determine
whether the bottleneck is in parsing, template instantiation, or LLVM.

This diff adds the first of several timers that aim to match
`gcc -ftime-report`: a timer that outputs the amount of time spent in the Clang
preprocessor.

I'm curious whether Clang maintainers think this timer is useful, and whether
there's interest in adding more timers, especially around the Clang parser.


https://reviews.llvm.org/D36492

Files:
  include/clang/Lex/Preprocessor.h
  include/clang/Lex/PreprocessorOptions.h
  lib/Frontend/CompilerInstance.cpp
  lib/Lex/PPDirectives.cpp
  lib/Lex/Preprocessor.cpp


Index: lib/Lex/Preprocessor.cpp
===================================================================
--- lib/Lex/Preprocessor.cpp
+++ lib/Lex/Preprocessor.cpp
@@ -88,6 +88,7 @@
       CurDirLookup(nullptr), CurLexerKind(CLK_Lexer),
       CurLexerSubmodule(nullptr), Callbacks(nullptr),
       CurSubmoduleState(&NullSubmoduleState), MacroArgCache(nullptr),
+      PreprocessingTimer("preprocessor", "Preprocessing"),
       Record(nullptr), MIChainHead(nullptr) {
   OwnsHeaderSearch = OwnsHeaders;
   
@@ -656,6 +657,8 @@
 
   IdentifierInfo &II = *Identifier.getIdentifierInfo();
 
+  llvm::TimeRegion(PPOpts->ShowTimers ? &PreprocessingTimer : nullptr);
+
   // If the information about this identifier is out of date, update it from
   // the external source.
   // We have to treat __VA_ARGS__ in a special way, since it gets
Index: lib/Lex/PPDirectives.cpp
===================================================================
--- lib/Lex/PPDirectives.cpp
+++ lib/Lex/PPDirectives.cpp
@@ -871,6 +871,8 @@
 /// lexer/preprocessor state, and advances the lexer(s) so that the next token
 /// read is the correct one.
 void Preprocessor::HandleDirective(Token &Result) {
+  llvm::TimeRegion(PPOpts->ShowTimers ? &PreprocessingTimer : nullptr);
+
   // FIXME: Traditional: # with whitespace before it not recognized by K&R?
 
   // We just parsed a # character at the start of a line, so we're in directive
Index: lib/Frontend/CompilerInstance.cpp
===================================================================
--- lib/Frontend/CompilerInstance.cpp
+++ lib/Frontend/CompilerInstance.cpp
@@ -367,7 +367,9 @@
 // Preprocessor
 
 void CompilerInstance::createPreprocessor(TranslationUnitKind TUKind) {
-  const PreprocessorOptions &PPOpts = getPreprocessorOpts();
+  PreprocessorOptions &PPOpts = getPreprocessorOpts();
+  if (getFrontendOpts().ShowTimers)
+    PPOpts.ShowTimers = true;
 
   // Create a PTH manager if we are using some form of a token cache.
   PTHManager *PTHMgr = nullptr;
Index: include/clang/Lex/PreprocessorOptions.h
===================================================================
--- include/clang/Lex/PreprocessorOptions.h
+++ include/clang/Lex/PreprocessorOptions.h
@@ -127,7 +127,11 @@
   /// manipulation of the compiler invocation object, in cases where the 
   /// compiler invocation and its buffers will be reused.
   bool RetainRemappedFileBuffers;
-  
+
+  /// \brief Whether to measure the amount of time spent in code related to
+  /// preprocessing. This flag defaults to false.
+  bool ShowTimers;
+
   /// \brief The Objective-C++ ARC standard library that we should support,
   /// by providing appropriate definitions to retrofit the standard library
   /// with support for lifetime-qualified pointers.
@@ -164,6 +168,7 @@
                           GeneratePreamble(false),
                           RemappedFilesKeepOriginalName(true),
                           RetainRemappedFileBuffers(false),
+                          ShowTimers(false),
                           ObjCXXARCStandardLibrary(ARCXX_nolib) { }
 
   void addMacroDef(StringRef Name) { Macros.emplace_back(Name, false); }
Index: include/clang/Lex/Preprocessor.h
===================================================================
--- include/clang/Lex/Preprocessor.h
+++ include/clang/Lex/Preprocessor.h
@@ -33,6 +33,7 @@
 #include "llvm/ADT/TinyPtrVector.h"
 #include "llvm/Support/Allocator.h"
 #include "llvm/Support/Registry.h"
+#include "llvm/Support/Timer.h"
 #include <memory>
 #include <vector>
 
@@ -624,6 +625,9 @@
   unsigned NumFastMacroExpanded, NumTokenPaste, NumFastTokenPaste;
   unsigned NumSkipped;
 
+  // A timer to keep track of how much time was spent on preprocessing.
+  llvm::Timer PreprocessingTimer;
+
   /// \brief The predefined macros that preprocessor should use from the
   /// command line etc.
   std::string Predefines;


-------------- next part --------------
A non-text attachment was scrubbed...
Name: D36492.110291.patch
Type: text/x-patch
Size: 3873 bytes
Desc: not available
URL: <http://lists.llvm.org/pipermail/cfe-commits/attachments/20170808/aefd03a6/attachment-0001.bin>


More information about the cfe-commits mailing list