Add support for profiling the matchers used.

[sbenza]

Summary

Add support for profiling the matchers used.
This will be connected with clang-tidy to generate a report to determine
and debug slow checks.

[alexfh]

Awesome! A couple of comments inline.

include/clang/ASTMatchers/ASTMatchFinder.h

125

I'd prefer a more structured interface, e.g. a map from string to some struct containing collected timings + a method to convert this map to string or print it to a stream. Not sure if this fits well with LLVM timing facilities you use, though.

lib/ASTMatchers/ASTMatchFinder.cpp

312

You can check EnableCheckProfiling inside getTimerForBucket to reduce code repetition.

[sbenza]

include/clang/ASTMatchers/ASTMatchFinder.h

125

The current TimerGroup interface is a little awkward.
TimerGroup will print to llvm::errs() when the last timer is destroyed, unless you print() yourself to your own ostream.
I could skip the TimerGroup class and export the TimeRecords directly.
You could not use the TimerGroup printing logic, though. Most of it comes from TimeRecord anyway, so it wouldn't be that bad.

So, would you prefer if this was:

struct ProfileChecks {

llvm::StringMap<llvm::TimeRecord> *Records;

};

?

lib/ASTMatchers/ASTMatchFinder.cpp

312

I put it outside to avoid calling the function when disabled.

[sbenza]

Export the raw TimeRecord elements.

[alexfh]

This is even better. One nit below.

include/clang/ASTMatchers/ASTMatchFinder.h

134

Maybe just "CheckProfiling"? "Enable" hints that this is a bool, but it's not (though is used as a bool in some places).

[sbenza]

Fix some names.

include/clang/ASTMatchers/ASTMatchFinder.h

134

It used to be a bool on the first iterations of the code.
Then it evolved into having the ostream.
And now has the record map =)

[alexfh]

Looks good!

[sbenza]

Closed by commit rL220418 (authored by @sbenza).

include/clang/ASTMatchers/ASTMatchFinder.h

 //  }
 //
 //===----------------------------------------------------------------------===//
 
 #ifndef LLVM_CLANG_ASTMATCHERS_ASTMATCHFINDER_H
 #define LLVM_CLANG_ASTMATCHERS_ASTMATCHFINDER_H
 
 #include "clang/ASTMatchers/ASTMatchers.h"
+#include "llvm/ADT/StringMap.h"
+#include "llvm/Support/Timer.h"
 
 namespace clang {
 
 namespace ast_matchers {
 
 /// \brief A class to allow finding matches over the Clang AST.
 ///
 /// After creation, you can add multiple matchers to the MatchFinder via
public:
     ///
     /// Optionally override to do per translation unit tasks.
     virtual void onStartOfTranslationUnit() {}
 
     /// \brief Called at the end of each translation unit.
     ///
     /// Optionally override to do per translation unit tasks.
     virtual void onEndOfTranslationUnit() {}
+
+    /// \brief An id used to group the matchers.
+    ///
+    /// This id is used, for example, for the profiling output.
+    /// It defaults to "<unknown>".
+    virtual StringRef getID() const;
   };
 
   /// \brief Called when parsing is finished. Intended for testing only.
   class ParsingDoneTestCallback {
   public:
     virtual ~ParsingDoneTestCallback();
     virtual void run() = 0;
   };
 
-  MatchFinder();
+  struct MatchFinderOptions {
+    struct Profiling {
+      Profiling(llvm::StringMap<llvm::TimeRecord> &Records)
+          : Records(Records) {}
+
+      /// \brief Per bucket timing information.
+      llvm::StringMap<llvm::TimeRecord> &Records;
+    };
+
+    /// \brief Enables per-check timers.
+    ///
+    /// It prints a report after match.
+    llvm::Optional<Profiling> CheckProfiling;
+  };
+
+  MatchFinder(MatchFinderOptions Options = MatchFinderOptions());
   ~MatchFinder();
 
   /// \brief Adds a matcher to execute when running over the AST.
   ///
   /// Calls 'Action' with the BoundNodes on every match.
   /// Adding more than one 'NodeMatch' allows finding different matches in a
   /// single pass over the AST.
   ///
struct MatchersByType {
     std::vector<std::pair<TypeLocMatcher, MatchCallback *>> TypeLoc;
     /// \brief All the callbacks in one container to simplify iteration.
     std::vector<MatchCallback *> AllCallbacks;
   };
 
 private:
   MatchersByType Matchers;
 
+  MatchFinderOptions Options;
+
   /// \brief Called when parsing is done.
   ParsingDoneTestCallback *ParsingDone;
 };
 
 /// \brief Returns the results of matching \p Matcher on \p Node.
 ///
 /// Collects the \c BoundNodes of all callback invocations when matching
 /// \p Matcher on \p Node and returns the collected results.

lib/ASTMatchers/ASTMatchFinder.cpp

 //  AST node. The matcher can recurse via the ASTMatchFinder interface.
 //
 //===----------------------------------------------------------------------===//
 
 #include "clang/ASTMatchers/ASTMatchFinder.h"
 #include "clang/AST/ASTConsumer.h"
 #include "clang/AST/ASTContext.h"
 #include "clang/AST/RecursiveASTVisitor.h"
+#include "llvm/ADT/StringMap.h"
+#include "llvm/Support/Timer.h"
 #include <deque>
+#include <memory>
 #include <set>
 
 namespace clang {
 namespace ast_matchers {
 namespace internal {
 namespace {
 
 typedef MatchFinder::MatchCallback MatchCallback;
private:
   bool Matches;
 };
 
 // Controls the outermost traversal of the AST and allows to match multiple
 // matchers.
 class MatchASTVisitor : public RecursiveASTVisitor<MatchASTVisitor>,
                         public ASTMatchFinder {
 public:
- MatchASTVisitor(const MatchFinder::MatchersByType *Matchers)
-     : Matchers(Matchers), ActiveASTContext(nullptr) {}
+  MatchASTVisitor(const MatchFinder::MatchersByType *Matchers,
+                  const MatchFinder::MatchFinderOptions &Options)
+      : Matchers(Matchers), Options(Options), ActiveASTContext(nullptr) {}
+
+  ~MatchASTVisitor() {
+    if (Options.CheckProfiling) {
+      Options.CheckProfiling->Records = std::move(TimeByBucket);
+    }
+  }
 
   void onStartOfTranslationUnit() {
-    for (MatchCallback *MC : Matchers->AllCallbacks)
+    const bool EnableCheckProfiling = Options.CheckProfiling.hasValue();
+    for (MatchCallback *MC : Matchers->AllCallbacks) {
+      TimeRegion Timer(EnableCheckProfiling ? &TimeByBucket[MC->getID()]
+                                            : nullptr);
       MC->onStartOfTranslationUnit();
     }
+  }
 
   void onEndOfTranslationUnit() {
-    for (MatchCallback *MC : Matchers->AllCallbacks)
+    const bool EnableCheckProfiling = Options.CheckProfiling.hasValue();
+    for (MatchCallback *MC : Matchers->AllCallbacks) {
+      TimeRegion Timer(EnableCheckProfiling ? &TimeByBucket[MC->getID()]
+                                            : nullptr);
       MC->onEndOfTranslationUnit();
     }
+  }
 
   void set_active_ast_context(ASTContext *NewActiveASTContext) {
     ActiveASTContext = NewActiveASTContext;
   }
 
   // The following Visit*() and Traverse*() functions "override"
   // methods in RecursiveASTVisitor.
 
public:
 
   bool shouldVisitTemplateInstantiations() const { return true; }
   bool shouldVisitImplicitCode() const { return true; }
   // Disables data recursion. We intercept Traverse* methods in the RAV, which
   // are not triggered during data recursion.
   bool shouldUseDataRecursionFor(clang::Stmt *S) const { return false; }
 
 private:
+  class TimeRegion {
+  public:
+    TimeRegion(llvm::TimeRecord *Record) : Record(Record) {
+      if (Record)
+        *Record -= llvm::TimeRecord::getCurrentTime(true);
+    }
+    ~TimeRegion() {
+      if (Record)
+        *Record += llvm::TimeRecord::getCurrentTime(false);
+    }
+
+  private:
+    llvm::TimeRecord *Record;
+  };
+
   /// \brief Runs all the \p Matchers on \p Node.
   ///
   /// Used by \c matchDispatch() below.
   template <typename T, typename MC>
   void matchImpl(const T &Node, const MC &Matchers) {
+    const bool EnableCheckProfiling = Options.CheckProfiling.hasValue();
     for (const auto &MP : Matchers) {
+      TimeRegion Timer(EnableCheckProfiling ? &TimeByBucket[MP.second->getID()]
+                                            : nullptr);
       BoundNodesTreeBuilder Builder;
       if (MP.first.matches(Node, this, &Builder)) {
         MatchVisitor Visitor(ActiveASTContext, MP.second);
         Builder.visitMatches(&Visitor);
       }
     }
   }
 
for (const TypedefNameDecl *Alias : TypeAliases.lookup(CanonicalType)) {
       if (Matcher.matches(*Alias, this, &Result)) {
         *Builder = std::move(Result);
         return true;
       }
     }
     return false;
   }
 
+  /// \brief Bucket to record map.
+  ///
+  /// Used to get the appropriate bucket for each matcher.
+  llvm::StringMap<llvm::TimeRecord> TimeByBucket;
+
   const MatchFinder::MatchersByType *Matchers;
+  const MatchFinder::MatchFinderOptions &Options;
   ASTContext *ActiveASTContext;
 
   // Maps a canonical type to its TypedefDecls.
   llvm::DenseMap<const Type*, std::set<const TypedefNameDecl*> > TypeAliases;
 
   // Maps (matcher, node) -> the match result for memoization.
   typedef std::map<MatchKey, MemoizedMatchResult> MemoizationMap;
   MemoizationMap ResultCache;

 MatchFinder::MatchResult::MatchResult(const BoundNodes &Nodes,
                                       ASTContext *Context)
   : Nodes(Nodes), Context(Context),
     SourceManager(&Context->getSourceManager()) {}
 
 MatchFinder::MatchCallback::~MatchCallback() {}
 MatchFinder::ParsingDoneTestCallback::~ParsingDoneTestCallback() {}
 
-MatchFinder::MatchFinder() : ParsingDone(nullptr) {}
+MatchFinder::MatchFinder(MatchFinderOptions Options)
+    : Options(std::move(Options)), ParsingDone(nullptr) {}
 
 MatchFinder::~MatchFinder() {}
 
 void MatchFinder::addMatcher(const DeclarationMatcher &NodeMatch,
                              MatchCallback *Action) {
   Matchers.Decl.push_back(std::make_pair(NodeMatch, Action));
   Matchers.AllCallbacks.push_back(Action);
 }

 }
 
 std::unique_ptr<ASTConsumer> MatchFinder::newASTConsumer() {
   return llvm::make_unique<internal::MatchASTConsumer>(this, ParsingDone);
 }
 
 void MatchFinder::match(const clang::ast_type_traits::DynTypedNode &Node,
                         ASTContext &Context) {
-  internal::MatchASTVisitor Visitor(&Matchers);
+  internal::MatchASTVisitor Visitor(&Matchers, Options);
   Visitor.set_active_ast_context(&Context);
   Visitor.match(Node);
 }
 
 void MatchFinder::matchAST(ASTContext &Context) {
-  internal::MatchASTVisitor Visitor(&Matchers);
+  internal::MatchASTVisitor Visitor(&Matchers, Options);
   Visitor.set_active_ast_context(&Context);
   Visitor.onStartOfTranslationUnit();
   Visitor.TraverseDecl(Context.getTranslationUnitDecl());
   Visitor.onEndOfTranslationUnit();
 }
 
 void MatchFinder::registerTestCallbackAfterParsing(
     MatchFinder::ParsingDoneTestCallback *NewParsingDone) {
   ParsingDone = NewParsingDone;
 }
 
+StringRef MatchFinder::MatchCallback::getID() const { return "<unknown>"; }
+
 } // end namespace ast_matchers
 } // end namespace clang

unittests/ASTMatchers/ASTMatchersTest.cpp

TEST(IsEqualTo, MatchesNodesByIdentity) {
   EXPECT_TRUE(matchAndVerifyResultTrue(
       "class X { class Y {}; };", recordDecl(hasName("::X::Y")).bind(""),
       new VerifyAncestorHasChildIsEqual<CXXRecordDecl>()));
   EXPECT_TRUE(matchAndVerifyResultTrue(
       "void f() { if (true) if(true) {} }", ifStmt().bind(""),
       new VerifyAncestorHasChildIsEqual<IfStmt>()));
 }
 
+TEST(MatchFinder, CheckProfiling) {
+  MatchFinder::MatchFinderOptions Options;
+  llvm::StringMap<llvm::TimeRecord> Records;
+  Options.CheckProfiling.emplace(Records);
+  MatchFinder Finder(std::move(Options));
+
+  struct NamedCallback : public MatchFinder::MatchCallback {
+    void run(const MatchFinder::MatchResult &Result) override {}
+    StringRef getID() const override { return "MyID"; }
+  } Callback;
+  Finder.addMatcher(decl(), &Callback);
+  std::unique_ptr<FrontendActionFactory> Factory(
+      newFrontendActionFactory(&Finder));
+  ASSERT_TRUE(tooling::runToolOnCode(Factory->create(), "int x;"));
+
+  EXPECT_EQ(1u, Records.size());
+  EXPECT_EQ("MyID", Records.begin()->getKey());
+}
+
 class VerifyStartOfTranslationUnit : public MatchFinder::MatchCallback {
 public:
   VerifyStartOfTranslationUnit() : Called(false) {}
   virtual void run(const MatchFinder::MatchResult &Result) {
     EXPECT_TRUE(Called);
   }
   virtual void onStartOfTranslationUnit() {
     Called = true;