Skip to content

Commit

Permalink
[exegesis] Benchmark: provide optional progress meter / ETA
Browse files Browse the repository at this point in the history
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
  • Loading branch information
LebedevRI committed Dec 13, 2022
1 parent 43024b4 commit 233ca84
Show file tree
Hide file tree
Showing 4 changed files with 217 additions and 0 deletions.
145 changes: 145 additions & 0 deletions 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
10 changes: 10 additions & 0 deletions llvm/tools/llvm-exegesis/llvm-exegesis.cpp
Expand Up @@ -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"
Expand Down Expand Up @@ -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"),
Expand Down Expand Up @@ -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));
Expand Down
1 change: 1 addition & 0 deletions llvm/unittests/tools/llvm-exegesis/CMakeLists.txt
Expand Up @@ -14,6 +14,7 @@ set(exegesis_sources
BenchmarkRunnerTest.cpp
ClusteringTest.cpp
PerfHelperTest.cpp
ProgressMeterTest.cpp
RegisterValueTest.cpp
)

Expand Down
61 changes: 61 additions & 0 deletions 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

0 comments on commit 233ca84

Please sign in to comment.