bench: switch to std::chrono for time measurements

std::chrono removes portability issues.

Rather than storing doubles, store the untouched time_points. Then
convert to nanoseconds for display. This allows for maximum precision, while
keeping results comparable between differing hardware/operating systems.

Also, display full nanosecond counts rather than sub-second floats.

Author: theuni

src/bench/bench.cpp

@@ -8,29 +8,22 @@
 #include <assert.h>
 #include <iostream>
 #include <iomanip>
-#include <sys/time.h>
 
 benchmark::BenchRunner::BenchmarkMap &benchmark::BenchRunner::benchmarks() {
     static std::map<std::string, benchmark::BenchFunction> benchmarks_map;
     return benchmarks_map;
 }
 
-static double gettimedouble(void) {
-    struct timeval tv;
-    gettimeofday(&tv, nullptr);
-    return tv.tv_usec * 0.000001 + tv.tv_sec;
-}
-
 benchmark::BenchRunner::BenchRunner(std::string name, benchmark::BenchFunction func)
 {
     benchmarks().insert(std::make_pair(name, func));
 }
 
 void
-benchmark::BenchRunner::RunAll(double elapsedTimeForOne)
+benchmark::BenchRunner::RunAll(benchmark::duration elapsedTimeForOne)
 {
     perf_init();
-    std::cout << "#Benchmark" << "," << "count" << "," << "min" << "," << "max" << "," << "average" << ","
+    std::cout << "#Benchmark" << "," << "count" << "," << "min(ns)" << "," << "max(ns)" << "," << "average(ns)" << ","
               << "min_cycles" << "," << "max_cycles" << "," << "average_cycles" << "\n";
 
     for (const auto &p: benchmarks()) {
@@ -46,16 +39,17 @@ bool benchmark::State::KeepRunning()
       ++count;
       return true;
     }
-    double now;
+    time_point now;
+
     uint64_t nowCycles;
     if (count == 0) {
-        lastTime = beginTime = now = gettimedouble();
+        lastTime = beginTime = now = clock::now();
         lastCycles = beginCycles = nowCycles = perf_cpucycles();
     }
     else {
-        now = gettimedouble();
-        double elapsed = now - lastTime;
-        double elapsedOne = elapsed / (countMask + 1);
+        now = clock::now();
+        auto elapsed = now - lastTime;
+        auto elapsedOne = elapsed / (countMask + 1);
         if (elapsedOne < minTime) minTime = elapsedOne;
         if (elapsedOne > maxTime) maxTime = elapsedOne;
 
@@ -70,8 +64,8 @@ bool benchmark::State::KeepRunning()
           // The restart avoids including the overhead of this code in the measurement.
           countMask = ((countMask<<3)|7) & ((1LL<<60)-1);
           count = 0;
-          minTime = std::numeric_limits<double>::max();
-          maxTime = std::numeric_limits<double>::min();
+          minTime = duration::max();
+          maxTime = duration::zero();
           minCycles = std::numeric_limits<uint64_t>::max();
           maxCycles = std::numeric_limits<uint64_t>::min();
           return true;
@@ -94,9 +88,13 @@ bool benchmark::State::KeepRunning()
     assert(count != 0 && "count == 0 => (now == 0 && beginTime == 0) => return above");
 
     // Output results
-    double average = (now-beginTime)/count;
+    // Duration casts are only necessary here because hardware with sub-nanosecond clocks
+    // will lose precision.
+    int64_t min_elapsed = std::chrono::duration_cast<std::chrono::nanoseconds>(minTime).count();
+    int64_t max_elapsed = std::chrono::duration_cast<std::chrono::nanoseconds>(maxTime).count();
+    int64_t avg_elapsed = std::chrono::duration_cast<std::chrono::nanoseconds>((now-beginTime)/count).count();
     int64_t averageCycles = (nowCycles-beginCycles)/count;
-    std::cout << std::fixed << std::setprecision(15) << name << "," << count << "," << minTime << "," << maxTime << "," << average << ","
+    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));
 

src/bench/bench.h

@@ -9,6 +9,7 @@
 #include <limits>
 #include <map>
 #include <string>
+#include <chrono>
 
 #include <boost/preprocessor/cat.hpp>
 #include <boost/preprocessor/stringize.hpp>
@@ -37,21 +38,25 @@ BENCHMARK(CODE_TO_TIME);
 
 namespace benchmark {
 
+    using clock = std::chrono::high_resolution_clock;
+    using time_point = clock::time_point;
+    using duration = clock::duration;
+
     class State {
         std::string name;
-        double maxElapsed;
-        double beginTime;
-        double lastTime, minTime, maxTime;
+        duration maxElapsed;
+        time_point beginTime, lastTime;
+        duration minTime, maxTime;
         uint64_t count;
         uint64_t countMask;
         uint64_t beginCycles;
         uint64_t lastCycles;
         uint64_t minCycles;
         uint64_t maxCycles;
     public:
-        State(std::string _name, double _maxElapsed) : name(_name), maxElapsed(_maxElapsed), count(0) {
-            minTime = std::numeric_limits<double>::max();
-            maxTime = std::numeric_limits<double>::min();
+        State(std::string _name, duration _maxElapsed) : name(_name), maxElapsed(_maxElapsed), count(0) {
+            minTime = duration::max();
+            maxTime = duration::zero();
             minCycles = std::numeric_limits<uint64_t>::max();
             maxCycles = std::numeric_limits<uint64_t>::min();
             countMask = 1;
@@ -69,7 +74,7 @@ namespace benchmark {
     public:
         BenchRunner(std::string name, BenchFunction func);
 
-        static void RunAll(double elapsedTimeForOne=1.0);
+        static void RunAll(duration elapsedTimeForOne = std::chrono::seconds(1));
     };
 }
 

src/bench/rollingbloom.cpp

@@ -6,7 +6,6 @@
 
 #include "bench.h"
 #include "bloom.h"
-#include "utiltime.h"
 
 static void RollingBloom(benchmark::State& state)
 {
@@ -23,10 +22,10 @@ static void RollingBloom(benchmark::State& state)
         data[2] = count >> 16;
         data[3] = count >> 24;
         if (countnow == nEntriesPerGeneration) {
-            int64_t b = GetTimeMicros();
+            auto b = benchmark::clock::now();
             filter.insert(data);
-            int64_t e = GetTimeMicros();
-            std::cout << "RollingBloom-refresh,1," << (e-b)*0.000001 << "," << (e-b)*0.000001 << "," << (e-b)*0.000001 << "\n";
+            auto total = std::chrono::duration_cast<std::chrono::nanoseconds>(benchmark::clock::now() - b).count();
+            std::cout << "RollingBloom-refresh,1," << total << "," << total << "," << total << "\n";
             countnow = 0;
         } else {
             filter.insert(data);