[llvm] 233ca84 - [exegesis] Benchmark: provide optional progress meter / ETA

Roman Lebedev via llvm-commits llvm-commits at lists.llvm.org
Tue Dec 13 04:31:04 PST 2022


Author: Roman Lebedev
Date: 2022-12-13T15:30:34+03:00
New Revision: 233ca84a25a7ba14aac7bcbd1956d6f528d4395f

URL: https://github.com/llvm/llvm-project/commit/233ca84a25a7ba14aac7bcbd1956d6f528d4395f
DIFF: https://github.com/llvm/llvm-project/commit/233ca84a25a7ba14aac7bcbd1956d6f528d4395f.diff

LOG: [exegesis] Benchmark: provide optional progress meter / ETA

Now that `--opcode-index=-1` is mostly stable,
and i can migrate off of my custom tooling that emulated it,
there comes a bit of confusion as to the status of the run.

It is normal for the single all-opcode run to take ~3 minutes,
and it's a bit more than one can be comfortable with,
without having some sort of visual indication of the progress.

Thus, i present:
```
$ ./bin/llvm-exegesis -mode=inverse_throughput --opcode-index=-1 --benchmarks-file=/dev/null --dump-object-to-disk=0 --measurements-print-progress --skip-measurements
<...>
XAM_Fp80: unsupported opcode: pseudo instruction
XBEGIN: Unsupported opcode: isPseudo/usesCustomInserter
XBEGIN_2: Unsupported opcode: isBranch/isIndirectBranch
XBEGIN_4: Unsupported opcode: isBranch/isIndirectBranch
XCH_F: unsupported second-form X87 instruction
Processing...   1%, ETA 02:10
Processing...   2%, ETA 02:03
Processing...   3%, ETA 02:00
Processing...   4%, ETA 01:57
Processing...   5%, ETA 01:54
Processing...   6%, ETA 01:53
Processing...   7%, ETA 01:51
Processing...   8%, ETA 01:50
Processing...   9%, ETA 01:49
Processing...  10%, ETA 01:48
Processing...  11%, ETA 01:46
Processing...  12%, ETA 01:45
Processing...  13%, ETA 01:44
Processing...  14%, ETA 01:43
Processing...  15%, ETA 01:42
Processing...  16%, ETA 01:42
Processing...  17%, ETA 01:41
```

As usual, the ETA estimation is statically-insignificant,
and is a lie/does not converge at least until 50% through.
It would be nice to have an actual progress indicator like in LIT,
but i'm not sure we have such a luxury in C++ form in LLVM codebase already.

Reviewed By: courbet

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

Added: 
    llvm/tools/llvm-exegesis/lib/ProgressMeter.h
    llvm/unittests/tools/llvm-exegesis/ProgressMeterTest.cpp

Modified: 
    llvm/tools/llvm-exegesis/llvm-exegesis.cpp
    llvm/unittests/tools/llvm-exegesis/CMakeLists.txt

Removed: 
    


################################################################################
diff  --git a/llvm/tools/llvm-exegesis/lib/ProgressMeter.h b/llvm/tools/llvm-exegesis/lib/ProgressMeter.h
new file mode 100644
index 0000000000000..6667a66b811e1
--- /dev/null
+++ b/llvm/tools/llvm-exegesis/lib/ProgressMeter.h
@@ -0,0 +1,145 @@
+//===-- ProgressMeter.h -----------------------------------------*- C++ -*-===//
+//
+// 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
+//
+//===----------------------------------------------------------------------===//
+
+#ifndef LLVM_TOOLS_LLVM_EXEGESIS_PROGRESSMETER_H
+#define LLVM_TOOLS_LLVM_EXEGESIS_PROGRESSMETER_H
+
+#include "llvm/Support/Format.h"
+#include "llvm/Support/raw_ostream.h"
+#include <cassert>
+#include <chrono>
+#include <cmath>
+#include <optional>
+#include <type_traits>
+
+namespace llvm {
+namespace exegesis {
+
+/// Represents `\sum_{i=1..accumulated}{step_i} / accumulated`,
+/// where `step_i` is the value passed to the `i`-th call to `step()`,
+/// and `accumulated` is the total number of calls to `step()`.
+template <typename NumTy, typename DenTy = int> class SimpleMovingAverage {
+  NumTy Accumulated = NumTy(0);
+  DenTy Steps = 0;
+
+public:
+  SimpleMovingAverage() = default;
+
+  SimpleMovingAverage(const SimpleMovingAverage &) = delete;
+  SimpleMovingAverage(SimpleMovingAverage &&) = delete;
+  SimpleMovingAverage &operator=(const SimpleMovingAverage &) = delete;
+  SimpleMovingAverage &operator=(SimpleMovingAverage &&) = delete;
+
+  inline void step(NumTy Quantity) {
+    Accumulated += Quantity;
+    ++Steps;
+  }
+
+  inline NumTy getAccumulated() const { return Accumulated; }
+
+  inline DenTy getNumSteps() const { return Steps; }
+
+  template <typename AvgTy = NumTy>
+  inline std::optional<AvgTy> getAverage() const {
+    if (Steps == 0)
+      return std::nullopt;
+    return AvgTy(Accumulated) / Steps;
+  };
+};
+
+template <typename ClockTypeTy = std::chrono::steady_clock,
+          typename = std::enable_if_t<ClockTypeTy::is_steady>>
+class ProgressMeter {
+public:
+  using ClockType = ClockTypeTy;
+  using TimePointType = std::chrono::time_point<ClockType>;
+  using DurationType = std::chrono::duration<typename ClockType::rep,
+                                             typename ClockType::period>;
+  using CompetionPercentage = int;
+  using Sec = std::chrono::duration<double, std::chrono::seconds::period>;
+
+private:
+  raw_ostream &Out;
+  const int NumStepsTotal;
+  SimpleMovingAverage<DurationType> ElapsedTotal;
+
+public:
+  friend class ProgressMeterStep;
+  class ProgressMeterStep {
+    ProgressMeter *P;
+    const TimePointType Begin;
+
+  public:
+    inline ProgressMeterStep(ProgressMeter *P_)
+        : P(P_), Begin(P ? ProgressMeter<ClockType>::ClockType::now()
+                         : TimePointType()) {}
+
+    inline ~ProgressMeterStep() {
+      if (!P)
+        return;
+      const TimePointType End = ProgressMeter<ClockType>::ClockType::now();
+      P->step(End - Begin);
+    }
+
+    ProgressMeterStep(const ProgressMeterStep &) = delete;
+    ProgressMeterStep(ProgressMeterStep &&) = delete;
+    ProgressMeterStep &operator=(const ProgressMeterStep &) = delete;
+    ProgressMeterStep &operator=(ProgressMeterStep &&) = delete;
+  };
+
+  ProgressMeter(int NumStepsTotal_, raw_ostream &out_ = llvm::errs())
+      : Out(out_), NumStepsTotal(NumStepsTotal_) {
+    assert(NumStepsTotal > 0 && "No steps are planned?");
+  }
+
+  ProgressMeter(const ProgressMeter &) = delete;
+  ProgressMeter(ProgressMeter &&) = delete;
+  ProgressMeter &operator=(const ProgressMeter &) = delete;
+  ProgressMeter &operator=(ProgressMeter &&) = delete;
+
+private:
+  void step(DurationType Elapsed) {
+    assert((ElapsedTotal.getNumSteps() < NumStepsTotal) && "Step overflow!");
+    assert(Elapsed.count() >= 0 && "Negative time drift detected.");
+
+    auto [OldProgress, OldEta] = eta();
+    ElapsedTotal.step(Elapsed);
+    auto [NewProgress, NewEta] = eta();
+
+    if (NewProgress < OldProgress + 1)
+      return;
+
+    Out << format("Processing... %*d%%", 3, NewProgress);
+    if (NewEta) {
+      int SecondsTotal = std::ceil(NewEta->count());
+      int Seconds = SecondsTotal % 60;
+      int MinutesTotal = SecondsTotal / 60;
+
+      Out << format(", ETA %02d:%02d", MinutesTotal, Seconds);
+    }
+    Out << "\n";
+    Out.flush();
+  }
+
+  inline std::pair<CompetionPercentage, std::optional<Sec>> eta() const {
+    CompetionPercentage Progress =
+        (100 * ElapsedTotal.getNumSteps()) / NumStepsTotal;
+
+    std::optional<Sec> ETA;
+    if (std::optional<Sec> AverageStepDuration =
+            ElapsedTotal.template getAverage<Sec>())
+      ETA = (NumStepsTotal - ElapsedTotal.getNumSteps()) * *AverageStepDuration;
+
+    return {Progress, ETA};
+  }
+};
+
+} // namespace exegesis
+} // namespace llvm
+
+#endif

diff  --git a/llvm/tools/llvm-exegesis/llvm-exegesis.cpp b/llvm/tools/llvm-exegesis/llvm-exegesis.cpp
index 551988948ded2..c4baf29ab72b4 100644
--- a/llvm/tools/llvm-exegesis/llvm-exegesis.cpp
+++ b/llvm/tools/llvm-exegesis/llvm-exegesis.cpp
@@ -18,6 +18,7 @@
 #include "lib/Error.h"
 #include "lib/LlvmState.h"
 #include "lib/PerfHelper.h"
+#include "lib/ProgressMeter.h"
 #include "lib/SnippetFile.h"
 #include "lib/SnippetRepetitor.h"
 #include "lib/Target.h"
@@ -114,6 +115,11 @@ static cl::opt<exegesis::InstructionBenchmark::RepetitionModeE> RepetitionMode(
                    "All of the above and take the minimum of measurements")),
     cl::init(exegesis::InstructionBenchmark::Duplicate));
 
+static cl::opt<bool> BenchmarkMeasurementsPrintProgress(
+    "measurements-print-progress",
+    cl::desc("Produce progress indicator when performing measurements"),
+    cl::cat(BenchmarkOptions), cl::init(false));
+
 static cl::opt<bool> BenchmarkSkipMeasurements(
     "skip-measurements",
     cl::desc("do everything except actually performing the measurements"),
@@ -395,7 +401,11 @@ void benchmarkMain() {
   if (BenchmarkFile.empty())
     BenchmarkFile = "-";
 
+  std::optional<ProgressMeter<>> Meter;
+  if (BenchmarkMeasurementsPrintProgress)
+    Meter.emplace(Configurations.size());
   for (const BenchmarkCode &Conf : Configurations) {
+    ProgressMeter<>::ProgressMeterStep MeterStep(Meter ? &*Meter : nullptr);
     InstructionBenchmark Result = ExitOnErr(Runner->runConfiguration(
         Conf, NumRepetitions, LoopBodySize, Repetitors, DumpObjectToDisk));
     ExitOnFileError(BenchmarkFile, Result.writeYaml(State, BenchmarkFile));

diff  --git a/llvm/unittests/tools/llvm-exegesis/CMakeLists.txt b/llvm/unittests/tools/llvm-exegesis/CMakeLists.txt
index 250dcf85a3da4..e7119cf1b37b1 100644
--- a/llvm/unittests/tools/llvm-exegesis/CMakeLists.txt
+++ b/llvm/unittests/tools/llvm-exegesis/CMakeLists.txt
@@ -14,6 +14,7 @@ set(exegesis_sources
   BenchmarkRunnerTest.cpp
   ClusteringTest.cpp
   PerfHelperTest.cpp
+  ProgressMeterTest.cpp
   RegisterValueTest.cpp
   )
 

diff  --git a/llvm/unittests/tools/llvm-exegesis/ProgressMeterTest.cpp b/llvm/unittests/tools/llvm-exegesis/ProgressMeterTest.cpp
new file mode 100644
index 0000000000000..0b06499c86559
--- /dev/null
+++ b/llvm/unittests/tools/llvm-exegesis/ProgressMeterTest.cpp
@@ -0,0 +1,61 @@
+//===-- ProgressMeterTest.cpp -----------------------------------*- C++ -*-===//
+//
+// 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 "ProgressMeter.h"
+#include "gmock/gmock.h"
+#include "gtest/gtest.h"
+
+namespace llvm {
+namespace exegesis {
+
+namespace {
+
+struct PreprogrammedClock {
+  using duration = std::chrono::seconds;
+  using rep = duration::rep;
+  using period = duration::period;
+  using time_point = std::chrono::time_point<PreprogrammedClock, duration>;
+
+  static constexpr bool is_steady = true;
+
+  static time_point now() noexcept;
+};
+
+static int CurrentTimePoint = 0;
+auto Pt(int i) {
+  return PreprogrammedClock::time_point(PreprogrammedClock::duration(i));
+}
+static const std::array<const PreprogrammedClock::time_point, 10> TimePoints = {
+    Pt(0),  Pt(5),  Pt(6),  Pt(20), Pt(20),
+    Pt(35), Pt(37), Pt(75), Pt(77), Pt(100)};
+
+PreprogrammedClock::time_point PreprogrammedClock::now() noexcept {
+  time_point p = TimePoints[CurrentTimePoint];
+  ++CurrentTimePoint;
+  return p;
+}
+
+TEST(ProgressMeterTest, Integration) {
+  CurrentTimePoint = 0;
+  std::string TempString;
+  raw_string_ostream SS(TempString);
+  ProgressMeter<PreprogrammedClock> m(5, SS);
+  for (int i = 0; i != 5; ++i)
+    decltype(m)::ProgressMeterStep s(&m);
+  SS.flush();
+  ASSERT_EQ("Processing...  20%, ETA 00:20\n"
+            "Processing...  40%, ETA 00:29\n"
+            "Processing...  60%, ETA 00:23\n"
+            "Processing...  80%, ETA 00:18\n"
+            "Processing... 100%, ETA 00:00\n",
+            TempString);
+}
+
+} // namespace
+} // namespace exegesis
+} // namespace llvm


        


More information about the llvm-commits mailing list