From 02286bb7d16d295c6cb3e7b2726ff29232f50524 Mon Sep 17 00:00:00 2001 From: Mickey Rose Date: Sat, 27 Feb 2016 22:23:28 +0100 Subject: [PATCH] benchmarks: report iterations per second instead of the inverse --- benchmark/bench_framework.hpp | 61 ++++++++++++++++++++++++----------- 1 file changed, 43 insertions(+), 18 deletions(-) diff --git a/benchmark/bench_framework.hpp b/benchmark/bench_framework.hpp index 585ba0bb8..5c1192d2e 100644 --- a/benchmark/bench_framework.hpp +++ b/benchmark/bench_framework.hpp @@ -10,6 +10,7 @@ // stl #include +#include // log10 #include // snprintf #include #include @@ -19,6 +20,12 @@ namespace benchmark { +template +using milliseconds = std::chrono::duration; + +template +using seconds = std::chrono::duration; + class test_case { protected: @@ -134,6 +141,29 @@ inline int handle_args(int argc, char** argv, mapnik::parameters & params) } \ } \ +struct big_number_fmt +{ + int w; + double v; + const char* u; + + big_number_fmt(int width, double value, int base = 1000) + : w(width), v(value), u("") + { + static const char* suffixes = "\0\0k\0M\0G\0T\0P\0E\0Z\0Y\0\0"; + u = suffixes; + + while (v > 1 && std::log10(v) >= width && u[2]) + { + v /= base; + u += 2; + } + + // adjust width for proper alignment without suffix + w += (u == suffixes); + } +}; + template int run(T const& test_runner, std::string const& name) { @@ -156,7 +186,8 @@ int run(T const& test_runner, std::string const& name) auto opt_min_duration = test_runner.params().template get("min-duration", 0.0); std::chrono::duration min_seconds(*opt_min_duration); auto min_duration = std::chrono::duration_cast(min_seconds); - std::size_t loops = 0; + auto num_iters = test_runner.iterations(); + auto total_iters = 0; if (test_runner.threads() > 0) { @@ -170,7 +201,7 @@ int run(T const& test_runner, std::string const& name) start = std::chrono::high_resolution_clock::now(); std::for_each(tg.begin(), tg.end(), [](value_type & t) {if (t->joinable()) t->join();}); elapsed = std::chrono::high_resolution_clock::now() - start; - loops = 1; + total_iters += num_iters; } else { @@ -178,35 +209,29 @@ int run(T const& test_runner, std::string const& name) do { test_runner(); elapsed = std::chrono::high_resolution_clock::now() - start; - ++loops; + total_iters += num_iters; } while (elapsed < min_duration); } - double iters = loops * test_runner.iterations(); - double dur_total = std::chrono::duration(elapsed).count(); - double dur_avg = dur_total / iters; - char iters_unit = ' '; char msg[200]; - - if (iters >= 1e7) iters *= 1e-6, iters_unit = 'M'; - else if (iters >= 1e4) iters *= 1e-3, iters_unit = 'k'; + double dur_total = milliseconds(elapsed).count(); + big_number_fmt itersf(4, total_iters); std::snprintf(msg, sizeof(msg), - "%-43s %3zu threads %4.0f%c iters %6.0f milliseconds", + "%-43s %3zu threads %*.0f%s iters %6.0f milliseconds", name.c_str(), test_runner.threads(), - iters, iters_unit, + itersf.w, itersf.v, itersf.u, dur_total); std::clog << msg; - // log average time per iteration, currently only for non-threaded runs + // log average # of iterations per second, currently only for + // non-threaded runs if (test_runner.threads() == 0) { - char unit = 'm'; - if (dur_avg < 1e-5) dur_avg *= 1e+9, unit = 'p'; - else if (dur_avg < 1e-2) dur_avg *= 1e+6, unit = 'n'; - else if (dur_avg < 1e+1) dur_avg *= 1e+3, unit = 'u'; - std::snprintf(msg, sizeof(msg), " %4.0f%cs/iter", dur_avg, unit); + auto elapsed_nonzero = std::max(elapsed, decltype(elapsed){1}); + big_number_fmt ips(5, total_iters / seconds(elapsed_nonzero).count()); + std::snprintf(msg, sizeof(msg), " %*.0f%s i/s", ips.w, ips.v, ips.u); std::clog << msg; }