From 00721e69f8280f8bc59bede43b335ecc347d4fdf Mon Sep 17 00:00:00 2001 From: Martin Ankerl Date: Tue, 17 Oct 2017 16:48:02 +0200 Subject: Improved microbenchmarking with multiple features. * inline performance critical code * Average runtime is specified and used to calculate iterations. * Console: show median of multiple runs * plot: show box plot * filter benchmarks * specify scaling factor * ignore src/test and src/bench in command line check script * number of iterations instead of time * Replaced runtime in BENCHMARK makro number of iterations. * Added -? to bench_bitcoin * Benchmark plotly.js URL, width, height can be customized * Fixed incorrect precision warning --- src/bench/bench.cpp | 182 +++++++++++++++++++++++++++++++--------------------- 1 file changed, 110 insertions(+), 72 deletions(-) (limited to 'src/bench/bench.cpp') diff --git a/src/bench/bench.cpp b/src/bench/bench.cpp index 148245281..edbad09eb 100644 --- a/src/bench/bench.cpp +++ b/src/bench/bench.cpp @@ -8,98 +8,136 @@ #include #include #include +#include +#include +#include -benchmark::BenchRunner::BenchmarkMap &benchmark::BenchRunner::benchmarks() { - static std::map benchmarks_map; - return benchmarks_map; +void benchmark::ConsolePrinter::header() +{ + std::cout << "# Benchmark, evals, iterations, total, min, max, median" << std::endl; } -benchmark::BenchRunner::BenchRunner(std::string name, benchmark::BenchFunction func) +void benchmark::ConsolePrinter::result(const State& state) { - benchmarks().insert(std::make_pair(name, func)); + auto results = state.m_elapsed_results; + std::sort(results.begin(), results.end()); + + double total = state.m_num_iters * std::accumulate(results.begin(), results.end(), 0.0); + + double front = 0; + double back = 0; + double median = 0; + + if (!results.empty()) { + front = results.front(); + back = results.back(); + + size_t mid = results.size() / 2; + median = results[mid]; + if (0 == results.size() % 2) { + median = (results[mid] + results[mid + 1]) / 2; + } + } + + std::cout << std::setprecision(6); + std::cout << state.m_name << ", " << state.m_num_evals << ", " << state.m_num_iters << ", " << total << ", " << front << ", " << back << ", " << median << std::endl; } -void -benchmark::BenchRunner::RunAll(benchmark::duration elapsedTimeForOne) +void benchmark::ConsolePrinter::footer() {} +benchmark::PlotlyPrinter::PlotlyPrinter(std::string plotly_url, int64_t width, int64_t height) + : m_plotly_url(plotly_url), m_width(width), m_height(height) { - perf_init(); - if (std::ratio_less_equal::value) { - std::cerr << "WARNING: Clock precision is worse than microsecond - benchmarks may be less accurate!\n"; - } - std::cout << "#Benchmark" << "," << "count" << "," << "min(ns)" << "," << "max(ns)" << "," << "average(ns)" << "," - << "min_cycles" << "," << "max_cycles" << "," << "average_cycles" << "\n"; +} - for (const auto &p: benchmarks()) { - State state(p.first, elapsedTimeForOne); - p.second(state); - } - perf_fini(); +void benchmark::PlotlyPrinter::header() +{ + std::cout << "" + << "" + << "

" + << ""; +} - uint64_t nowCycles; - if (count == 0) { - lastTime = beginTime = now = clock::now(); - lastCycles = beginCycles = nowCycles = perf_cpucycles(); + +benchmark::BenchRunner::BenchmarkMap& benchmark::BenchRunner::benchmarks() +{ + static std::map benchmarks_map; + return benchmarks_map; +} + +benchmark::BenchRunner::BenchRunner(std::string name, benchmark::BenchFunction func, uint64_t num_iters_for_one_second) +{ + benchmarks().insert(std::make_pair(name, Bench{func, num_iters_for_one_second})); +} + +void benchmark::BenchRunner::RunAll(Printer& printer, uint64_t num_evals, double scaling, const std::string& filter, bool is_list_only) +{ + perf_init(); + if (!std::ratio_less_equal::value) { + std::cerr << "WARNING: Clock precision is worse than microsecond - benchmarks may be less accurate!\n"; } - else { - now = clock::now(); - auto elapsed = now - lastTime; - auto elapsedOne = elapsed / (countMask + 1); - if (elapsedOne < minTime) minTime = elapsedOne; - if (elapsedOne > maxTime) maxTime = elapsedOne; - - // We only use relative values, so don't have to handle 64-bit wrap-around specially - nowCycles = perf_cpucycles(); - uint64_t elapsedOneCycles = (nowCycles - lastCycles) / (countMask + 1); - if (elapsedOneCycles < minCycles) minCycles = elapsedOneCycles; - if (elapsedOneCycles > maxCycles) maxCycles = elapsedOneCycles; - - if (elapsed*128 < maxElapsed) { - // If the execution was much too fast (1/128th of maxElapsed), increase the count mask by 8x and restart timing. - // The restart avoids including the overhead of this code in the measurement. - countMask = ((countMask<<3)|7) & ((1LL<<60)-1); - count = 0; - minTime = duration::max(); - maxTime = duration::zero(); - minCycles = std::numeric_limits::max(); - maxCycles = std::numeric_limits::min(); - return true; + + std::regex reFilter(filter); + std::smatch baseMatch; + + printer.header(); + + for (const auto& p : benchmarks()) { + if (!std::regex_match(p.first, baseMatch, reFilter)) { + continue; + } + + uint64_t num_iters = static_cast(p.second.num_iters_for_one_second * scaling); + if (0 == num_iters) { + num_iters = 1; } - if (elapsed*16 < maxElapsed) { - uint64_t newCountMask = ((countMask<<1)|1) & ((1LL<<60)-1); - if ((count & newCountMask)==0) { - countMask = newCountMask; - } + State state(p.first, num_evals, num_iters, printer); + if (!is_list_only) { + p.second.func(state); } + printer.result(state); } - lastTime = now; - lastCycles = nowCycles; - ++count; - if (now - beginTime < maxElapsed) return true; // Keep going + printer.footer(); - --count; + perf_fini(); +} - assert(count != 0 && "count == 0 => (now == 0 && beginTime == 0) => return above"); +bool benchmark::State::UpdateTimer(const benchmark::time_point current_time) +{ + if (m_start_time != time_point()) { + std::chrono::duration diff = current_time - m_start_time; + m_elapsed_results.push_back(diff.count() / m_num_iters); - // Output results - // Duration casts are only necessary here because hardware with sub-nanosecond clocks - // will lose precision. - int64_t min_elapsed = std::chrono::duration_cast(minTime).count(); - int64_t max_elapsed = std::chrono::duration_cast(maxTime).count(); - int64_t avg_elapsed = std::chrono::duration_cast((now-beginTime)/count).count(); - int64_t averageCycles = (nowCycles-beginCycles)/count; - std::cout << std::fixed << std::setprecision(15) << name << "," << count << "," << min_elapsed << "," << max_elapsed << "," << avg_elapsed << "," - << minCycles << "," << maxCycles << "," << averageCycles << "\n"; - std::cout.copyfmt(std::ios(nullptr)); + if (m_elapsed_results.size() == m_num_evals) { + return false; + } + } - return false; + m_num_iters_left = m_num_iters - 1; + return true; } -- cgit v1.2.3