[clang] 27d8eed - [clang] Add time profile for constant evaluation

Evgeny Shulgin via cfe-commits cfe-commits at lists.llvm.org
Fri Oct 21 16:25:00 PDT 2022


Author: Evgeny Shulgin
Date: 2022-10-21T23:24:44Z
New Revision: 27d8eedd5a3cd7fd644be4f06225ffa1ff04cccf

URL: https://github.com/llvm/llvm-project/commit/27d8eedd5a3cd7fd644be4f06225ffa1ff04cccf
DIFF: https://github.com/llvm/llvm-project/commit/27d8eedd5a3cd7fd644be4f06225ffa1ff04cccf.diff

LOG: [clang] Add time profile for constant evaluation

Add time profiler for various constexpr evaluation events
so that slow event could be visible on the visualized flame chart.

Reviewed By: aaron.ballman

Differential Revision: https://reviews.llvm.org/D136022

Added: 
    clang/unittests/Support/CMakeLists.txt
    clang/unittests/Support/TimeProfilerTest.cpp

Modified: 
    clang/docs/ReleaseNotes.rst
    clang/lib/AST/ExprConstant.cpp
    clang/unittests/CMakeLists.txt

Removed: 
    


################################################################################
diff  --git a/clang/docs/ReleaseNotes.rst b/clang/docs/ReleaseNotes.rst
index 3f952334c3d9a..79112e9420211 100644
--- a/clang/docs/ReleaseNotes.rst
+++ b/clang/docs/ReleaseNotes.rst
@@ -363,6 +363,8 @@ Non-comprehensive list of changes in this release
 - Clang now supports ``__has_constexpr_builtin`` function-like macro that
   evaluates to 1 if the builtin is supported and can be constant evaluated.
   It can be used to writing conditionally constexpr code that uses builtins.
+- The time profiler (using ``-ftime-trace`` option) now traces various constant
+  evaluation events.
 
 New Compiler Flags
 ------------------

diff  --git a/clang/lib/AST/ExprConstant.cpp b/clang/lib/AST/ExprConstant.cpp
index 6adc63d0f5f0d..4160aa6458c87 100644
--- a/clang/lib/AST/ExprConstant.cpp
+++ b/clang/lib/AST/ExprConstant.cpp
@@ -56,6 +56,7 @@
 #include "llvm/ADT/SmallBitVector.h"
 #include "llvm/Support/Debug.h"
 #include "llvm/Support/SaveAndRestore.h"
+#include "llvm/Support/TimeProfiler.h"
 #include "llvm/Support/raw_ostream.h"
 #include <cstring>
 #include <functional>
@@ -660,6 +661,19 @@ namespace {
     CallStackFrame &Frame;
     const LValue *OldThis;
   };
+
+  // A shorthand time trace scope struct, prints source range, for example
+  // {"name":"EvaluateAsRValue","args":{"detail":"<test.cc:8:21, col:25>"}}}
+  class ExprTimeTraceScope {
+  public:
+    ExprTimeTraceScope(const Expr *E, const ASTContext &Ctx, StringRef Name)
+        : TimeScope(Name, [E, &Ctx] {
+            return E->getSourceRange().printToString(Ctx.getSourceManager());
+          }) {}
+
+  private:
+    llvm::TimeTraceScope TimeScope;
+  };
 }
 
 static bool HandleDestruction(EvalInfo &Info, const Expr *E,
@@ -15105,6 +15119,7 @@ bool Expr::EvaluateAsRValue(EvalResult &Result, const ASTContext &Ctx,
                             bool InConstantContext) const {
   assert(!isValueDependent() &&
          "Expression evaluator can't be called on a dependent expression.");
+  ExprTimeTraceScope TimeScope(this, Ctx, "EvaluateAsRValue");
   EvalInfo Info(Ctx, Result, EvalInfo::EM_IgnoreSideEffects);
   Info.InConstantContext = InConstantContext;
   return ::EvaluateAsRValue(this, Result, Ctx, Info);
@@ -15114,6 +15129,7 @@ bool Expr::EvaluateAsBooleanCondition(bool &Result, const ASTContext &Ctx,
                                       bool InConstantContext) const {
   assert(!isValueDependent() &&
          "Expression evaluator can't be called on a dependent expression.");
+  ExprTimeTraceScope TimeScope(this, Ctx, "EvaluateAsBooleanCondition");
   EvalResult Scratch;
   return EvaluateAsRValue(Scratch, Ctx, InConstantContext) &&
          HandleConversionToBool(Scratch.Val, Result);
@@ -15124,6 +15140,7 @@ bool Expr::EvaluateAsInt(EvalResult &Result, const ASTContext &Ctx,
                          bool InConstantContext) const {
   assert(!isValueDependent() &&
          "Expression evaluator can't be called on a dependent expression.");
+  ExprTimeTraceScope TimeScope(this, Ctx, "EvaluateAsInt");
   EvalInfo Info(Ctx, Result, EvalInfo::EM_IgnoreSideEffects);
   Info.InConstantContext = InConstantContext;
   return ::EvaluateAsInt(this, Result, Ctx, AllowSideEffects, Info);
@@ -15134,6 +15151,7 @@ bool Expr::EvaluateAsFixedPoint(EvalResult &Result, const ASTContext &Ctx,
                                 bool InConstantContext) const {
   assert(!isValueDependent() &&
          "Expression evaluator can't be called on a dependent expression.");
+  ExprTimeTraceScope TimeScope(this, Ctx, "EvaluateAsFixedPoint");
   EvalInfo Info(Ctx, Result, EvalInfo::EM_IgnoreSideEffects);
   Info.InConstantContext = InConstantContext;
   return ::EvaluateAsFixedPoint(this, Result, Ctx, AllowSideEffects, Info);
@@ -15148,6 +15166,7 @@ bool Expr::EvaluateAsFloat(APFloat &Result, const ASTContext &Ctx,
   if (!getType()->isRealFloatingType())
     return false;
 
+  ExprTimeTraceScope TimeScope(this, Ctx, "EvaluateAsFloat");
   EvalResult ExprResult;
   if (!EvaluateAsRValue(ExprResult, Ctx, InConstantContext) ||
       !ExprResult.Val.isFloat() ||
@@ -15163,6 +15182,7 @@ bool Expr::EvaluateAsLValue(EvalResult &Result, const ASTContext &Ctx,
   assert(!isValueDependent() &&
          "Expression evaluator can't be called on a dependent expression.");
 
+  ExprTimeTraceScope TimeScope(this, Ctx, "EvaluateAsLValue");
   EvalInfo Info(Ctx, Result, EvalInfo::EM_ConstantFold);
   Info.InConstantContext = InConstantContext;
   LValue LV;
@@ -15207,6 +15227,7 @@ bool Expr::EvaluateAsConstantExpr(EvalResult &Result, const ASTContext &Ctx,
   assert(!isValueDependent() &&
          "Expression evaluator can't be called on a dependent expression.");
 
+  ExprTimeTraceScope TimeScope(this, Ctx, "EvaluateAsConstantExpr");
   EvalInfo::EvaluationMode EM = EvalInfo::EM_ConstantExpression;
   EvalInfo Info(Ctx, Result, EM);
   Info.InConstantContext = true;
@@ -15259,6 +15280,13 @@ bool Expr::EvaluateAsInitializer(APValue &Value, const ASTContext &Ctx,
   assert(!isValueDependent() &&
          "Expression evaluator can't be called on a dependent expression.");
 
+  llvm::TimeTraceScope TimeScope("EvaluateAsInitializer", [&] {
+    std::string Name;
+    llvm::raw_string_ostream OS(Name);
+    VD->printQualifiedName(OS);
+    return Name;
+  });
+
   // FIXME: Evaluating initializers for large array and record types can cause
   // performance problems. Only do so in C++11 for now.
   if (isPRValue() && (getType()->isArrayType() || getType()->isRecordType()) &&
@@ -15347,6 +15375,7 @@ APSInt Expr::EvaluateKnownConstInt(const ASTContext &Ctx,
   assert(!isValueDependent() &&
          "Expression evaluator can't be called on a dependent expression.");
 
+  ExprTimeTraceScope TimeScope(this, Ctx, "EvaluateKnownConstInt");
   EvalResult EVResult;
   EVResult.Diag = Diag;
   EvalInfo Info(Ctx, EVResult, EvalInfo::EM_IgnoreSideEffects);
@@ -15365,6 +15394,7 @@ APSInt Expr::EvaluateKnownConstIntCheckOverflow(
   assert(!isValueDependent() &&
          "Expression evaluator can't be called on a dependent expression.");
 
+  ExprTimeTraceScope TimeScope(this, Ctx, "EvaluateKnownConstIntCheckOverflow");
   EvalResult EVResult;
   EVResult.Diag = Diag;
   EvalInfo Info(Ctx, EVResult, EvalInfo::EM_IgnoreSideEffects);
@@ -15383,6 +15413,7 @@ void Expr::EvaluateForOverflow(const ASTContext &Ctx) const {
   assert(!isValueDependent() &&
          "Expression evaluator can't be called on a dependent expression.");
 
+  ExprTimeTraceScope TimeScope(this, Ctx, "EvaluateForOverflow");
   bool IsConst;
   EvalResult EVResult;
   if (!FastEvaluateAsRValue(this, EVResult, Ctx, IsConst)) {
@@ -15874,6 +15905,10 @@ bool Expr::isIntegerConstantExpr(const ASTContext &Ctx,
   assert(!isValueDependent() &&
          "Expression evaluator can't be called on a dependent expression.");
 
+  llvm::TimeTraceScope TimeScope("isIntegerConstantExpr", [&] {
+    return Loc->printToString(Ctx.getSourceManager());
+  });
+
   if (Ctx.getLangOpts().CPlusPlus11)
     return EvaluateCPlusPlus11IntegralConstantExpr(Ctx, this, nullptr, Loc);
 
@@ -15966,6 +16001,14 @@ bool Expr::EvaluateWithSubstitution(APValue &Value, ASTContext &Ctx,
   assert(!isValueDependent() &&
          "Expression evaluator can't be called on a dependent expression.");
 
+  llvm::TimeTraceScope TimeScope("EvaluateWithSubstitution", [&] {
+    std::string Name;
+    llvm::raw_string_ostream OS(Name);
+    Callee->getNameForDiagnostic(OS, Ctx.getPrintingPolicy(),
+                                 /*Qualified=*/true);
+    return Name;
+  });
+
   Expr::EvalStatus Status;
   EvalInfo Info(Ctx, Status, EvalInfo::EM_ConstantExpressionUnevaluated);
   Info.InConstantContext = true;
@@ -16030,6 +16073,14 @@ bool Expr::isPotentialConstantExpr(const FunctionDecl *FD,
   if (FD->isDependentContext())
     return true;
 
+  llvm::TimeTraceScope TimeScope("isPotentialConstantExpr", [&] {
+    std::string Name;
+    llvm::raw_string_ostream OS(Name);
+    FD->getNameForDiagnostic(OS, FD->getASTContext().getPrintingPolicy(),
+                             /*Qualified=*/true);
+    return Name;
+  });
+
   Expr::EvalStatus Status;
   Status.Diag = &Diags;
 

diff  --git a/clang/unittests/CMakeLists.txt b/clang/unittests/CMakeLists.txt
index 31836198646ee..cffd4756616a2 100644
--- a/clang/unittests/CMakeLists.txt
+++ b/clang/unittests/CMakeLists.txt
@@ -47,3 +47,4 @@ add_subdirectory(DirectoryWatcher)
 add_subdirectory(Rename)
 add_subdirectory(Index)
 add_subdirectory(Serialization)
+add_subdirectory(Support)

diff  --git a/clang/unittests/Support/CMakeLists.txt b/clang/unittests/Support/CMakeLists.txt
new file mode 100644
index 0000000000000..956b3a756150e
--- /dev/null
+++ b/clang/unittests/Support/CMakeLists.txt
@@ -0,0 +1,12 @@
+set(LLVM_LINK_COMPONENTS
+  Support
+  )
+
+add_clang_unittest(ClangSupportTests
+  TimeProfilerTest.cpp
+  )
+
+clang_target_link_libraries(ClangSupportTests
+  PRIVATE
+  clangFrontend
+  )

diff  --git a/clang/unittests/Support/TimeProfilerTest.cpp b/clang/unittests/Support/TimeProfilerTest.cpp
new file mode 100644
index 0000000000000..a1b855493ab55
--- /dev/null
+++ b/clang/unittests/Support/TimeProfilerTest.cpp
@@ -0,0 +1,199 @@
+//===- unittests/Support/TimeProfilerTest.cpp -----------------------------===//
+//
+// Part of the LLVM Project, under the Apache License v2.0 with LLVM Exceptions.
+// See https://llvm.org/LICENSE.txt for license information.
+// SPDX-License-Identifier: Apache-2.0 WITH LLVM-exception
+//
+//===----------------------------------------------------------------------===//
+
+#include "clang/Frontend/CompilerInstance.h"
+#include "clang/Frontend/FrontendActions.h"
+#include "clang/Lex/PreprocessorOptions.h"
+
+#include "llvm/Support/JSON.h"
+#include "llvm/Support/TimeProfiler.h"
+
+#include "gtest/gtest.h"
+
+using namespace clang;
+using namespace llvm;
+
+namespace {
+
+// Should be called before testing.
+void setupProfiler() {
+  timeTraceProfilerInitialize(/*TimeTraceGranularity=*/0, "test");
+}
+
+// Should be called after `compileFromString()`.
+// Returns profiler's JSON dump.
+std::string teardownProfiler() {
+  SmallVector<char, 1024> SmallVec;
+  raw_svector_ostream OS(SmallVec);
+  timeTraceProfilerWrite(OS);
+  timeTraceProfilerCleanup();
+  return OS.str().str();
+}
+
+// Returns true if code compiles successfully.
+// We only parse AST here. This is enough for constexpr evaluation.
+bool compileFromString(StringRef Code) {
+  CompilerInstance Compiler;
+  Compiler.createDiagnostics();
+
+  auto Invocation = std::make_shared<CompilerInvocation>();
+  Invocation->getPreprocessorOpts().addRemappedFile(
+      "test.cc", MemoryBuffer::getMemBuffer(Code).release());
+  const char *Args[] = {"-std=c++20", "test.cc"};
+  CompilerInvocation::CreateFromArgs(*Invocation, Args,
+                                     Compiler.getDiagnostics());
+  Compiler.setInvocation(std::move(Invocation));
+
+  class TestFrontendAction : public ASTFrontendAction {
+  private:
+    std::unique_ptr<ASTConsumer> CreateASTConsumer(CompilerInstance &CI,
+                                                   StringRef InFile) override {
+      return std::make_unique<ASTConsumer>();
+    }
+  } Action;
+  return Compiler.ExecuteAction(Action);
+}
+
+// Returns pretty-printed trace graph.
+std::string buildTraceGraph(StringRef Json) {
+  struct EventRecord {
+    int64_t TimestampBegin;
+    int64_t TimestampEnd;
+    StringRef Name;
+    StringRef Detail;
+  };
+  std::vector<EventRecord> Events;
+
+  // Parse `EventRecord`s from JSON dump.
+  Expected<json::Value> Root = json::parse(Json);
+  if (!Root)
+    return "";
+  for (json::Value &TraceEventValue :
+       *Root->getAsObject()->getArray("traceEvents")) {
+    json::Object *TraceEventObj = TraceEventValue.getAsObject();
+
+    int64_t TimestampBegin = TraceEventObj->getInteger("ts").value_or(0);
+    int64_t TimestampEnd =
+        TimestampBegin + TraceEventObj->getInteger("dur").value_or(0);
+    StringRef Name = TraceEventObj->getString("name").value_or("");
+    StringRef Detail = "";
+    if (json::Object *Args = TraceEventObj->getObject("args"))
+      Detail = Args->getString("detail").value_or("");
+
+    // This is a "summary" event, like "Total PerformPendingInstantiations",
+    // skip it
+    if (TimestampBegin == 0)
+      continue;
+
+    Events.emplace_back(
+        EventRecord{TimestampBegin, TimestampEnd, Name, Detail});
+  }
+
+  // There can be nested events that are very fast, for example:
+  // {"name":"EvaluateAsBooleanCondition",... ,"ts":2380,"dur":1}
+  // {"name":"EvaluateAsRValue",... ,"ts":2380,"dur":1}
+  // Therefore we should reverse the events list, so that events that have
+  // started earlier are first in the list.
+  // Then do a stable sort, we need it for the trace graph.
+  std::reverse(Events.begin(), Events.end());
+  std::stable_sort(
+      Events.begin(), Events.end(), [](const auto &lhs, const auto &rhs) {
+        return std::make_pair(lhs.TimestampBegin, -lhs.TimestampEnd) <
+               std::make_pair(rhs.TimestampBegin, -rhs.TimestampEnd);
+      });
+
+  std::stringstream Stream;
+  // Write a newline for better testing with multiline string literal.
+  Stream << "\n";
+
+  // Keep the current event stack.
+  std::stack<const EventRecord *> EventStack;
+  for (const auto &Event : Events) {
+    // Pop every event in the stack until meeting the parent event.
+    while (!EventStack.empty()) {
+      bool InsideCurrentEvent =
+          Event.TimestampBegin >= EventStack.top()->TimestampBegin &&
+          Event.TimestampEnd <= EventStack.top()->TimestampEnd;
+      if (!InsideCurrentEvent)
+        EventStack.pop();
+      else
+        break;
+    }
+    EventStack.push(&Event);
+
+    // Write indentaion, name, detail, newline.
+    for (size_t i = 1; i < EventStack.size(); ++i) {
+      Stream << "| ";
+    }
+    Stream.write(Event.Name.data(), Event.Name.size());
+    if (!Event.Detail.empty()) {
+      Stream << " (";
+      Stream.write(Event.Detail.data(), Event.Detail.size());
+      Stream << ")";
+    }
+    Stream << "\n";
+  }
+  return Stream.str();
+}
+
+} // namespace
+
+TEST(TimeProfilerTest, ConstantEvaluation) {
+  constexpr StringRef Code = R"(
+void print(double value);
+
+namespace slow_namespace {
+
+consteval double slow_func() {
+    double d = 0.0;
+    for (int i = 0; i < 100; ++i) { // 8th line
+        d += i;                     // 9th line
+    }
+    return d;
+}
+
+} // namespace slow_namespace
+
+void slow_test() {
+    constexpr auto slow_value = slow_namespace::slow_func(); // 17th line
+    print(slow_namespace::slow_func());                      // 18th line
+    print(slow_value);
+}
+
+int slow_arr[12 + 34 * 56 +                                  // 22nd line
+             static_cast<int>(slow_namespace::slow_func())]; // 23rd line
+
+constexpr int slow_init_list[] = {1, 1, 2, 3, 5, 8, 13, 21}; // 25th line
+    )";
+
+  setupProfiler();
+  ASSERT_TRUE(compileFromString(Code));
+  std::string Json = teardownProfiler();
+  std::string TraceGraph = buildTraceGraph(Json);
+  ASSERT_TRUE(TraceGraph == R"(
+Frontend
+| EvaluateAsRValue (<test.cc:8:21>)
+| EvaluateForOverflow (<test.cc:8:21, col:25>)
+| EvaluateAsRValue (<test.cc:9:14>)
+| EvaluateForOverflow (<test.cc:9:9, col:14>)
+| isPotentialConstantExpr (slow_namespace::slow_func)
+| EvaluateAsBooleanCondition (<test.cc:8:21, col:25>)
+| | EvaluateAsRValue (<test.cc:8:21, col:25>)
+| EvaluateAsBooleanCondition (<test.cc:8:21, col:25>)
+| | EvaluateAsRValue (<test.cc:8:21, col:25>)
+| EvaluateAsInitializer (slow_value)
+| EvaluateAsConstantExpr (<test.cc:17:33, col:59>)
+| EvaluateAsConstantExpr (<test.cc:18:11, col:37>)
+| EvaluateAsRValue (<test.cc:22:14, line:23:58>)
+| EvaluateAsInitializer (slow_init_list)
+| PerformPendingInstantiations
+)");
+
+  // NOTE: If this test is failing, run this test with
+  // `llvm::errs() << TraceGraph;` and change the assert above.
+}


        


More information about the cfe-commits mailing list