From ef2e9bdbc0204956d90e34c3bc362023c9886fa5 Mon Sep 17 00:00:00 2001 From: Olaf Krzikalla Date: Tue, 25 Aug 2020 12:08:51 +0200 Subject: [PATCH] Fix real time measurement for multi-threaded benchmarks --- src/benchmark_runner.cc | 7 ++--- test/CMakeLists.txt | 3 ++ test/internal_threading_test.cc | 21 +------------- test/spinning.h | 29 +++++++++++++++++++ test/threaded_timer_test.cc | 51 +++++++++++++++++++++++++++++++++ 5 files changed, 87 insertions(+), 24 deletions(-) create mode 100644 test/spinning.h create mode 100644 test/threaded_timer_test.cc diff --git a/src/benchmark_runner.cc b/src/benchmark_runner.cc index 7bc6b6329e..ecb7f11294 100644 --- a/src/benchmark_runner.cc +++ b/src/benchmark_runner.cc @@ -122,9 +122,9 @@ void RunInThread(const BenchmarkInstance* b, IterationCount iters, { MutexLock l(manager->GetBenchmarkMutex()); internal::ThreadManager::Result& results = manager->results; - results.iterations += st.iterations(); + results.iterations = st.iterations(); results.cpu_time_used += timer.cpu_time_used(); - results.real_time_used += timer.real_time_used(); + results.real_time_used = std::max(results.real_time_used, timer.real_time_used()); results.manual_time_used += timer.manual_time_used(); results.complexity_n += st.complexity_length_n(); internal::Increment(&results.counters, st.counters); @@ -227,8 +227,7 @@ class BenchmarkRunner { // And get rid of the manager. manager.reset(); - // Adjust real/manual time stats since they were reported per thread. - i.results.real_time_used /= b.threads; + // Adjust manual time stats since they were reported per thread. i.results.manual_time_used /= b.threads; // If we were measuring whole-process CPU usage, adjust the CPU time too. if (b.measure_process_cpu_time) i.results.cpu_time_used /= b.threads; diff --git a/test/CMakeLists.txt b/test/CMakeLists.txt index 0d228b85cb..b8a6b85a4d 100644 --- a/test/CMakeLists.txt +++ b/test/CMakeLists.txt @@ -128,6 +128,9 @@ add_test(NAME user_counters_test COMMAND user_counters_test --benchmark_min_time compile_output_test(internal_threading_test) add_test(NAME internal_threading_test COMMAND internal_threading_test --benchmark_min_time=0.01) +compile_output_test(threaded_timer_test) +add_test(NAME threaded_timer_test COMMAND threaded_timer_test --benchmark_min_time=0.01) + compile_output_test(report_aggregates_only_test) add_test(NAME report_aggregates_only_test COMMAND report_aggregates_only_test --benchmark_min_time=0.01) diff --git a/test/internal_threading_test.cc b/test/internal_threading_test.cc index 039d7c14a8..9e94373ea4 100644 --- a/test/internal_threading_test.cc +++ b/test/internal_threading_test.cc @@ -3,28 +3,9 @@ #include #include -#include "../src/timers.h" #include "benchmark/benchmark.h" #include "output_test.h" - -static const std::chrono::duration time_frame(50); -static const double time_frame_in_sec( - std::chrono::duration_cast>>( - time_frame) - .count()); - -void MyBusySpinwait() { - const auto start = benchmark::ChronoClockNow(); - - while (true) { - const auto now = benchmark::ChronoClockNow(); - const auto elapsed = now - start; - - if (std::chrono::duration(elapsed) >= - time_frame) - return; - } -} +#include "spinning.h" // ========================================================================= // // --------------------------- TEST CASES BEGIN ---------------------------- // diff --git a/test/spinning.h b/test/spinning.h new file mode 100644 index 0000000000..538c474fb2 --- /dev/null +++ b/test/spinning.h @@ -0,0 +1,29 @@ +#ifndef TEST_SPINNING_H +#define TEST_SPINNING_H + +#include +#include "../src/timers.h" + +static const std::chrono::duration time_frame(50); +static const double time_frame_in_sec( + std::chrono::duration_cast>>( + time_frame) + .count()); + +void TimedBusySpinwait(const std::chrono::duration& tf) { + const auto start = benchmark::ChronoClockNow(); + + while (true) { + const auto now = benchmark::ChronoClockNow(); + const auto elapsed = now - start; + + if (std::chrono::duration(elapsed) >= tf) + return; + } +} + +inline void MyBusySpinwait() { + TimedBusySpinwait(time_frame); +} + +#endif // TEST_SPINNING_H \ No newline at end of file diff --git a/test/threaded_timer_test.cc b/test/threaded_timer_test.cc new file mode 100644 index 0000000000..06e62ba269 --- /dev/null +++ b/test/threaded_timer_test.cc @@ -0,0 +1,51 @@ + +#undef NDEBUG + +#include +#include +#include "benchmark/benchmark.h" +#include "output_test.h" +#include "spinning.h" + +// ========================================================================= // +// --------------------------- TEST CASES BEGIN ---------------------------- // +// ========================================================================= // + +// ========================================================================= // +// BM_MainThread + +void BM_UnbalancedThreads(benchmark::State& state) { + const std::chrono::duration tf( + state.thread_index == 0 ? 100 : 20); + const double tf_in_sec( + std::chrono::duration_cast>>( + tf).count()); + + for (auto _ : state) { + TimedBusySpinwait(tf); + state.SetIterationTime(tf_in_sec); + } +} + +BENCHMARK(BM_UnbalancedThreads)->Iterations(1)->ThreadRange(1, 4); +BENCHMARK(BM_UnbalancedThreads)->Iterations(1)->ThreadRange(1, 4)->UseRealTime(); + +void CheckTimings(Results const& e) { + // check that the real time is between 100 and 110 ms + CHECK_FLOAT_RESULT_VALUE(e, "real_time", GE, 1e08, 0.01); + CHECK_FLOAT_RESULT_VALUE(e, "real_time", LT, 1.1e08, 0.01); + + // check that the cpu time is in an reasonable interval + double min_cpu_time = ((e.NumThreads() - 1) * 20 + 100) * 1e06; + double max_cpu_time = ((e.NumThreads() - 1) * 30 + 110) * 1e06; + CHECK_FLOAT_RESULT_VALUE(e, "cpu_time", GE, min_cpu_time, 0.01); + CHECK_FLOAT_RESULT_VALUE(e, "cpu_time", LT, max_cpu_time, 0.01); +} + +CHECK_BENCHMARK_RESULTS("BM_UnbalancedThreads", &CheckTimings); + +// ========================================================================= // +// ---------------------------- TEST CASES END ----------------------------- // +// ========================================================================= // + +int main(int argc, char* argv[]) { RunOutputTests(argc, argv); }