Skip to content

perf_tests: let a test declare its iteration rate - #314

Draft
travisdowns wants to merge 5 commits into
redpanda-data:v26.3.xfrom
travisdowns:td-perf-bench-fixed-iter
Draft

travisdowns wants to merge 5 commits into
redpanda-data:v26.3.xfrom
travisdowns:td-perf-bench-fixed-iter

Conversation

@travisdowns

Copy link
Copy Markdown
Member
  • perf_tests: honor an explicit --iterations
  • perf_tests: let a test declare its iteration rate
  • perf_tests: report a declared iteration rate that has gone stale
  • perf_tests: measure the wall-clock length of a run
  • perf_tests: add --suggest-rates
.

The iteration count of a perf_tests run is normally chosen by a timed dry
run, so it depends on how fast the machine is and on whatever else it was doing
at the time. Any test that is not deterministic across iterations, which covers
anything using randomness as input or mutating its own structures, therefore
reports a different instruction count and runtime from one invocation to the
next even when nothing changed. That noise is the motivation: it shows up
directly in redpanda's microbenchmark comparisons.

A test can now declare how many iterations it completes in one second, as an
optional trailing argument to any of the four PERF_TEST macros:

PERF_TEST(example, declared_rate, .iters_per_sec = 10'000'000) { ... }

The count of every run is then iters_per_sec * --duration, with no dry run,
which trades the fixed quantity: the iteration count stops depending on the
machine and the duration of a run becomes the approximation instead.

Notes on the design:

  • The argument is a perf_tests::test_options aggregate filled with designated
    initializers rather than a bare number, so further per-test declarations can
    be added later without touching the macros again. __VA_OPT__ makes it
    optional in all four macros, so every existing two-argument PERF_TEST
    calibrates exactly as before.
  • The rate is a double, which allows 1.2e6 as well as 1'200'000. A value
    that is not finite and positive is ignored.
  • The rate is expressed in the same iterations that --iterations limits and
    the iters column reports, so a test returning an iteration count from its
    body declares its rate in those inner iterations rather than in outer ones.
  • A declared rate is only honored where its measurement still holds, which is a
    release build. SEASTAR_PERF_TESTS_HONOR_DECLARED_RATE is the switch, set by
    a tri-state Seastar_PERF_TESTS_HONOR_DECLARED_RATE option whose DEFAULT
    covers the Release and RelWithDebInfo build types, and overridable either
    way through configure.py --enable-perf-test-declared-rates. The Bazel build
    gets the same switch in a companion redpanda change. Elsewhere the count is
    calibrated as before and the configuration header says so.
  • Drift is checked against the wall-clock length of a run rather than its timed
    length, because --duration bounds wall clock. For a test using
    start_measuring_time/stop_measuring_time the two differ by exactly the
    untimed part of each iteration, which would otherwise have produced spurious
    warnings for tests whose setup dominates their measured region.

Testing. Two self-tests in perf_tests_perf.cc cover both paths: one declares a
rate it meets, the other declares one it cannot, so the drift warning fires.
With .iters_per_sec = 2.8e7 the counts are exactly 14,000,000 at -d 0.5 and
28,000,000 at -d 1. The cmake option was checked across build types and all
three option values, and the framework was run in a build that honors declared
rates and one that does not.

Measured effect on the benchmark that motivated this, redpanda's
role_store_bench.role_authz_512_roles_1Ki_members_mixed, over 7 commits and 5
invocations each:

calibrated .iters_per_sec = 300'000
iterations per run 289,000 to 307,000 300,000 every time
distinct results in 35 runs 19 2
spread 68.95 inst 0.39 inst

The residual tracks an unrelated address-dependent term rather than the
iteration count.

The release-build restriction is measured too: the same benchmarks run 8.5x to
18x slower under redpanda's --config=dev, which is -Og plus ASan plus the
system allocator. Holding the count fixed there would multiply the length of
every run by that factor to produce numbers that are not comparable to a
release build's anyway.

Follow-up worth considering separately: a runtime cap so that a run cannot
overshoot --duration by an unbounded factor whatever the cause, whether a
stale declaration, a much slower machine, or a build that no compile-time switch
can distinguish. Seastar's cmake Dev mode is the case in point, being
optimized and free of debug checks yet not a release build.

The dry run preceding the measured runs armed the --duration timer even
when --iterations had already fixed the iteration count, then overwrote
that count with however many iterations fit in the duration. An
--iterations value larger than the duration allowed was therefore
silently reduced, while the configuration header still reported the
requested value:

    single run iterations:    100000000
    test                          iters
    output_check.low_runtime   28075516

Skip the timer and keep the requested count when it is known up front.
The leading run then serves as a warm-up of the same length as the
measured runs rather than as a calibration run.
Currently when test duration is specified but iterations are not,
the (outer) iteration count of a run is calibrated by a timed dry run,
which decides how many outer iterations are needed to hit the specified
runtime.

This results in run to run noise, as this calibration will often result
in different number of outer iterations, which results in different
measured instruction counts and runtime for any test which isn't
deterministic across iterations (common for tests with use randomness
as input, or for which internal structures are mutated).

Rather than try to fix each test to make them completely deterministic
across outer iterations, we optionally change the way the outer durations
are calculated, so the value is always the same for a given input
duration.

This works by allowing a test to state how many iterations it completes in one
second, as an optional trailing argument to the PERF_TEST macros:

    PERF_TEST(example, declared_rate, .iters_per_sec = 10'000'000) { ... }

The count of every run is then fixed at that rate times --duration. If
the value drifts, the effect is only that the actual duration drifts,
e.g., if the value is half of the true value (due to drift or different
HW, for example), the duration will be half of that specified on the
command line, a small price to pay for fixed duration counts.

The argument is a perf_tests::test_options aggregate rather than a bare
number, so that further per-test declarations can be added to it without
touching the macros again, and it is optional in all four macros: a
two-argument PERF_TEST calibrates exactly as before. An explicit
--iterations still takes precedence over a declared rate.

This number is intended to be calibrated and used in "release" builds,
which is where the important benchmarking happens. Outside of those builds
we just use the old approach of dynamic calibration since (a) perf results
are not relevant anyway and (b) due to order of magnitude difference in
performance between release and debug, debug runs would miss their target
time by a lot.
A declared rate is measured on one machine and decays as the test it
describes changes, and nothing about a fixed iteration count reveals
that: the results stay valid, the runs just quietly stop taking the
duration that was asked for.

Report the rate the test actually achieved once a run strays more than a
factor of two from the requested duration, so the declaration can be
refreshed from the warning itself:

    WARNING: test 'fixed_iters.stale_declared_rate' declares 100000
    iterations/s but achieved 4.92e+07/s, so each run took 2.033ms
    rather than the requested 1.000s
The drift check compared a declared rate against the *timed* length of a
run, but --duration bounds wall-clock time: for a test using
start_measuring_time/stop_measuring_time, the untimed part of each
iteration is exactly what the two disagree about. A test whose setup
dominates its measured region would have been told its runs were far
shorter than requested when they were not.

Record the wall-clock length of each run alongside the timed one and
check drift against that. It is deliberately not a reported column - it
exists to answer "how long did --duration let this run be", which no
existing series answers.
A declared iteration rate is a measurement, so writing one by hand means
running the test, reading its iteration count, and dividing - and doing
it again whenever the test changes enough to matter.

Report it instead. --suggest-rates prints one pasteable declaration per
test after the results:

    measured iteration rates, to declare in the PERF_TEST macro so that a
    run's iteration count no longer depends on the speed of the machine:

      perf_tests.test_simple_1         .iters_per_sec = 2'700'000'000
      perf_tests.test_simple_n_big     .iters_per_sec = 540
      output_check.low_runtime         .iters_per_sec = 53'000'000

The rate comes from the wall-clock length of a run, so it predicts what
--duration will allow, and is rounded to two significant digits because
that is all the accuracy a declaration can carry from one machine to
another. Tests that already declare a rate are reported too, so the same
command writes the declarations and later refreshes them.
Comment thread tests/perf/perf_tests.cc
double measured_rate = median_runtime > 0 ? ns_per_second / median_runtime : 0;
double drift = measured_rate / _options.iters_per_sec;
if (drift > DECLARED_RATE_DRIFT_FACTOR || drift < 1. / DECLARED_RATE_DRIFT_FACTOR) {
fmt::print("WARNING: test '{}' declares {} iterations/s but achieved {:.3g}/s, "

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Little Bob achieved being 10th out of 10. Congratulations!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants