From 535ed9223dcb32bf90ead5b2c95052838b780620 Mon Sep 17 00:00:00 2001 From: Gavin Andresen Date: Thu, 24 Sep 2015 13:13:38 -0400 Subject: Simple benchmarking framework Benchmarking framework, loosely based on google's micro-benchmarking library (https://github.com/google/benchmark) Wny not use the Google Benchmark framework? Because adding Even More Dependencies isn't worth it. If we get a dozen or three benchmarks and need nanosecond-accurate timings of threaded code then switching to the full-blown Google Benchmark library should be considered. The benchmark framework is hard-coded to run each benchmark for one wall-clock second, and then spits out .csv-format timing information to stdout. It is left as an exercise for later (or maybe never) to add command-line arguments to specify which benchmark(s) to run, how long to run them for, how to format results, etc etc etc. Again, see the Google Benchmark framework for where that might end up. See src/bench/MilliSleep.cpp for a sanity-test benchmark that just benchmarks 'sleep 100 milliseconds.' To compile and run benchmarks: cd src; make bench Sample output: Benchmark,count,min,max,average Sleep100ms,10,0.101854,0.105059,0.103881 --- src/bench/bench.cpp | 60 +++++++++++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 60 insertions(+) create mode 100644 src/bench/bench.cpp (limited to 'src/bench/bench.cpp') diff --git a/src/bench/bench.cpp b/src/bench/bench.cpp new file mode 100644 index 000000000..572080760 --- /dev/null +++ b/src/bench/bench.cpp @@ -0,0 +1,60 @@ +// Copyright (c) 2015 The Bitcoin Core developers +// Distributed under the MIT software license, see the accompanying +// file COPYING or http://www.opensource.org/licenses/mit-license.php. +#include "bench.h" +#include +#include + +using namespace benchmark; + +std::map BenchRunner::benchmarks; + +static double gettimedouble(void) { + struct timeval tv; + gettimeofday(&tv, NULL); + return tv.tv_usec * 0.000001 + tv.tv_sec; +} + +BenchRunner::BenchRunner(std::string name, BenchFunction func) +{ + benchmarks.insert(std::make_pair(name, func)); +} + +void +BenchRunner::RunAll(double elapsedTimeForOne) +{ + std::cout << "Benchmark" << "," << "count" << "," << "min" << "," << "max" << "," << "average" << "\n"; + + for (std::map::iterator it = benchmarks.begin(); + it != benchmarks.end(); ++it) { + + State state(it->first, elapsedTimeForOne); + BenchFunction& func = it->second; + func(state); + } +} + +bool State::KeepRunning() +{ + double now = gettimedouble(); + if (count == 0) { + beginTime = now; + } + else { + double elapsedOne = now - lastTime; + if (elapsedOne < minTime) minTime = elapsedOne; + if (elapsedOne > maxTime) maxTime = elapsedOne; + } + lastTime = now; + ++count; + + if (now - beginTime < maxElapsed) return true; // Keep going + + --count; + + // Output results + double average = (now-beginTime)/count; + std::cout << name << "," << count << "," << minTime << "," << maxTime << "," << average << "\n"; + + return false; +} -- cgit v1.2.3 From 7072c544b52774ac5a22835121e8e2747ad61158 Mon Sep 17 00:00:00 2001 From: Gavin Andresen Date: Tue, 29 Sep 2015 17:17:24 -0400 Subject: Support very-fast-running benchmarks Avoid calling gettimeofday every time through the benchmarking loop, by keeping track of how long each loop takes and doubling the number of iterations done between time checks when they take less than 1/16'th of the total elapsed time. --- src/bench/bench.cpp | 14 +++++++++++--- 1 file changed, 11 insertions(+), 3 deletions(-) (limited to 'src/bench/bench.cpp') diff --git a/src/bench/bench.cpp b/src/bench/bench.cpp index 572080760..89c3b0cc2 100644 --- a/src/bench/bench.cpp +++ b/src/bench/bench.cpp @@ -36,14 +36,22 @@ BenchRunner::RunAll(double elapsedTimeForOne) bool State::KeepRunning() { - double now = gettimedouble(); + double now; if (count == 0) { - beginTime = now; + beginTime = now = gettimedouble(); } else { - double elapsedOne = now - lastTime; + // timeCheckCount is used to avoid calling gettime most of the time, + // so benchmarks that run very quickly get consistent results. + if ((count+1)%timeCheckCount != 0) { + ++count; + return true; // keep going + } + now = gettimedouble(); + double elapsedOne = (now - lastTime)/timeCheckCount; if (elapsedOne < minTime) minTime = elapsedOne; if (elapsedOne > maxTime) maxTime = elapsedOne; + if (elapsedOne*timeCheckCount < maxElapsed/16) timeCheckCount *= 2; } lastTime = now; ++count; -- cgit v1.2.3 From 214de7e54c282f7d452d9b628baaa94e6af51727 Mon Sep 17 00:00:00 2001 From: Philip Kaufmann Date: Tue, 27 Oct 2015 17:44:13 +0100 Subject: [Trivial] ensure minimal header conventions - ensure header namespaces and end comments are correct - add missing header end comments - ensure minimal formatting (add newlines etc.) --- src/bench/bench.cpp | 2 ++ 1 file changed, 2 insertions(+) (limited to 'src/bench/bench.cpp') diff --git a/src/bench/bench.cpp b/src/bench/bench.cpp index 89c3b0cc2..6ee3cdc27 100644 --- a/src/bench/bench.cpp +++ b/src/bench/bench.cpp @@ -1,7 +1,9 @@ // Copyright (c) 2015 The Bitcoin Core developers // Distributed under the MIT software license, see the accompanying // file COPYING or http://www.opensource.org/licenses/mit-license.php. + #include "bench.h" + #include #include -- cgit v1.2.3 From 63ff57db4beb2e92b3d8ed396da016f29f790195 Mon Sep 17 00:00:00 2001 From: Gregory Maxwell Date: Sun, 29 May 2016 01:36:52 +0000 Subject: Avoid integer division in the benchmark inner-most loop. Previously the benchmark code used an integer division (%) with a non-constant in the inner-loop. This is quite slow on many processors, especially ones like ARM that lack a hardware divide. Even on fairly recent x86_64 like haswell an integer division can take something like 100 cycles-- making it comparable to the runtime of siphash. This change avoids the division by using bitmasking instead. This was especially easy since the count was only increased by doubling. This change also restarts the timing when the execution time was very low this avoids mintimes of zero in cases where one execution ends up below the timer resolution. It also reduces the impact of the overhead on the final result. The formatting of the prints is changed to not use scientific notation make it more machine readable (in particular, gnuplot croaks on the non-fixedpoint, and it doesn't sort correctly). This also hoists out all the floating point divisions out of the semi-hot path because it was easy to do so. It might be prudent to break out the critical test into a macro just to guarantee that it gets inlined. It might also make sense to just save out the intermediate counts and times and get the floating point completely out of the timing loop (because e.g. on hardware without a fast hardware FPU like some ARM it will still be slow enough to distort the results). I haven't done either of these in this commit. --- src/bench/bench.cpp | 35 ++++++++++++++++++++++++----------- 1 file changed, 24 insertions(+), 11 deletions(-) (limited to 'src/bench/bench.cpp') diff --git a/src/bench/bench.cpp b/src/bench/bench.cpp index 6ee3cdc27..227546a7a 100644 --- a/src/bench/bench.cpp +++ b/src/bench/bench.cpp @@ -5,6 +5,7 @@ #include "bench.h" #include +#include #include using namespace benchmark; @@ -25,7 +26,7 @@ BenchRunner::BenchRunner(std::string name, BenchFunction func) void BenchRunner::RunAll(double elapsedTimeForOne) { - std::cout << "Benchmark" << "," << "count" << "," << "min" << "," << "max" << "," << "average" << "\n"; + std::cout << "#Benchmark" << "," << "count" << "," << "min" << "," << "max" << "," << "average" << "\n"; for (std::map::iterator it = benchmarks.begin(); it != benchmarks.end(); ++it) { @@ -38,22 +39,34 @@ BenchRunner::RunAll(double elapsedTimeForOne) bool State::KeepRunning() { + if (count & countMask) { + ++count; + return true; + } double now; if (count == 0) { - beginTime = now = gettimedouble(); + lastTime = beginTime = now = gettimedouble(); } else { - // timeCheckCount is used to avoid calling gettime most of the time, - // so benchmarks that run very quickly get consistent results. - if ((count+1)%timeCheckCount != 0) { - ++count; - return true; // keep going - } now = gettimedouble(); - double elapsedOne = (now - lastTime)/timeCheckCount; + double elapsed = now - lastTime; + double elapsedOne = elapsed * countMaskInv; if (elapsedOne < minTime) minTime = elapsedOne; if (elapsedOne > maxTime) maxTime = elapsedOne; - if (elapsedOne*timeCheckCount < maxElapsed/16) timeCheckCount *= 2; + 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); + countMaskInv = 1./(countMask+1); + count = 0; + minTime = std::numeric_limits::max(); + maxTime = std::numeric_limits::min(); + return true; + } + if (elapsed*16 < maxElapsed) { + countMask = ((countMask<<1)|1) & ((1LL<<60)-1); + countMaskInv = 1./(countMask+1); + } } lastTime = now; ++count; @@ -64,7 +77,7 @@ bool State::KeepRunning() // Output results double average = (now-beginTime)/count; - std::cout << name << "," << count << "," << minTime << "," << maxTime << "," << average << "\n"; + std::cout << std::fixed << std::setprecision(15) << name << "," << count << "," << minTime << "," << maxTime << "," << average << "\n"; return false; } -- cgit v1.2.3 From e0a9cb25b0af87723d50cb8d8cffa10f1ebf7dcc Mon Sep 17 00:00:00 2001 From: "Wladimir J. van der Laan" Date: Tue, 22 Nov 2016 09:59:50 +0100 Subject: bench: Fix subtle counting issue when rescaling iteration count Make sure that the count is a zero modulo the new mask before scaling, otherwise the next time until a measure triggers will take only 1/2 as long as accounted for. This caused the 'min time' to be potentially off by as much as 100%. --- src/bench/bench.cpp | 7 +++++-- 1 file changed, 5 insertions(+), 2 deletions(-) (limited to 'src/bench/bench.cpp') diff --git a/src/bench/bench.cpp b/src/bench/bench.cpp index 227546a7a..8942da8c7 100644 --- a/src/bench/bench.cpp +++ b/src/bench/bench.cpp @@ -64,8 +64,11 @@ bool State::KeepRunning() return true; } if (elapsed*16 < maxElapsed) { - countMask = ((countMask<<1)|1) & ((1LL<<60)-1); - countMaskInv = 1./(countMask+1); + uint64_t newCountMask = ((countMask<<1)|1) & ((1LL<<60)-1); + if ((count & newCountMask)==0) { + countMask = newCountMask; + countMaskInv = 1./(countMask+1); + } } } lastTime = now; -- cgit v1.2.3 From 35328187463a7078b4206e394c21d5515929c7de Mon Sep 17 00:00:00 2001 From: "Wladimir J. van der Laan" Date: Tue, 22 Nov 2016 10:22:08 +0100 Subject: bench: Add support for measuring CPU cycles This adds cycle min/max/avg to the statistics. Supported on x86 and x86_64 (natively through rdtsc), as well as Linux (perf syscall). --- src/bench/bench.cpp | 22 ++++++++++++++++++++-- 1 file changed, 20 insertions(+), 2 deletions(-) (limited to 'src/bench/bench.cpp') diff --git a/src/bench/bench.cpp b/src/bench/bench.cpp index 8942da8c7..af3d152c9 100644 --- a/src/bench/bench.cpp +++ b/src/bench/bench.cpp @@ -3,6 +3,7 @@ // file COPYING or http://www.opensource.org/licenses/mit-license.php. #include "bench.h" +#include "perf.h" #include #include @@ -26,7 +27,9 @@ BenchRunner::BenchRunner(std::string name, BenchFunction func) void BenchRunner::RunAll(double elapsedTimeForOne) { - std::cout << "#Benchmark" << "," << "count" << "," << "min" << "," << "max" << "," << "average" << "\n"; + perf_init(); + std::cout << "#Benchmark" << "," << "count" << "," << "min" << "," << "max" << "," << "average" << "," + << "min_cycles" << "," << "max_cycles" << "," << "average_cycles" << "\n"; for (std::map::iterator it = benchmarks.begin(); it != benchmarks.end(); ++it) { @@ -35,6 +38,7 @@ BenchRunner::RunAll(double elapsedTimeForOne) BenchFunction& func = it->second; func(state); } + perf_fini(); } bool State::KeepRunning() @@ -44,8 +48,10 @@ bool State::KeepRunning() return true; } double now; + uint64_t nowCycles; if (count == 0) { lastTime = beginTime = now = gettimedouble(); + lastCycles = beginCycles = nowCycles = perf_cpucycles(); } else { now = gettimedouble(); @@ -53,6 +59,13 @@ bool State::KeepRunning() double elapsedOne = elapsed * countMaskInv; 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) * countMaskInv; + 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. @@ -61,6 +74,8 @@ bool State::KeepRunning() count = 0; minTime = std::numeric_limits::max(); maxTime = std::numeric_limits::min(); + minCycles = std::numeric_limits::max(); + maxCycles = std::numeric_limits::min(); return true; } if (elapsed*16 < maxElapsed) { @@ -72,6 +87,7 @@ bool State::KeepRunning() } } lastTime = now; + lastCycles = nowCycles; ++count; if (now - beginTime < maxElapsed) return true; // Keep going @@ -80,7 +96,9 @@ bool State::KeepRunning() // Output results double average = (now-beginTime)/count; - std::cout << std::fixed << std::setprecision(15) << name << "," << count << "," << minTime << "," << maxTime << "," << average << "\n"; + int64_t averageCycles = (nowCycles-beginCycles)/count; + std::cout << std::fixed << std::setprecision(15) << name << "," << count << "," << minTime << "," << maxTime << "," << average << "," + << minCycles << "," << maxCycles << "," << averageCycles << "\n"; return false; } -- cgit v1.2.3 From 27765b6403cece54320374b37afb01a0cfe571c3 Mon Sep 17 00:00:00 2001 From: isle2983 Date: Sat, 31 Dec 2016 11:01:21 -0700 Subject: Increment MIT Licence copyright header year on files modified in 2016 Edited via: $ contrib/devtools/copyright_header.py update . --- src/bench/bench.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'src/bench/bench.cpp') diff --git a/src/bench/bench.cpp b/src/bench/bench.cpp index af3d152c9..aa9dfef57 100644 --- a/src/bench/bench.cpp +++ b/src/bench/bench.cpp @@ -1,4 +1,4 @@ -// Copyright (c) 2015 The Bitcoin Core developers +// Copyright (c) 2015-2016 The Bitcoin Core developers // Distributed under the MIT software license, see the accompanying // file COPYING or http://www.opensource.org/licenses/mit-license.php. -- cgit v1.2.3 From 73f41190b91dce9c125b1828b18f7625e0200145 Mon Sep 17 00:00:00 2001 From: Karl-Johan Alm Date: Mon, 5 Dec 2016 16:03:53 +0900 Subject: Refactoring: Removed using namespace from bench/ and test/ source files. --- src/bench/bench.cpp | 14 ++++++-------- 1 file changed, 6 insertions(+), 8 deletions(-) (limited to 'src/bench/bench.cpp') diff --git a/src/bench/bench.cpp b/src/bench/bench.cpp index af3d152c9..8f9432e11 100644 --- a/src/bench/bench.cpp +++ b/src/bench/bench.cpp @@ -9,9 +9,7 @@ #include #include -using namespace benchmark; - -std::map BenchRunner::benchmarks; +std::map benchmark::BenchRunner::benchmarks; static double gettimedouble(void) { struct timeval tv; @@ -19,29 +17,29 @@ static double gettimedouble(void) { return tv.tv_usec * 0.000001 + tv.tv_sec; } -BenchRunner::BenchRunner(std::string name, BenchFunction func) +benchmark::BenchRunner::BenchRunner(std::string name, benchmark::BenchFunction func) { benchmarks.insert(std::make_pair(name, func)); } void -BenchRunner::RunAll(double elapsedTimeForOne) +benchmark::BenchRunner::RunAll(double elapsedTimeForOne) { perf_init(); std::cout << "#Benchmark" << "," << "count" << "," << "min" << "," << "max" << "," << "average" << "," << "min_cycles" << "," << "max_cycles" << "," << "average_cycles" << "\n"; - for (std::map::iterator it = benchmarks.begin(); + for (std::map::iterator it = benchmarks.begin(); it != benchmarks.end(); ++it) { State state(it->first, elapsedTimeForOne); - BenchFunction& func = it->second; + benchmark::BenchFunction& func = it->second; func(state); } perf_fini(); } -bool State::KeepRunning() +bool benchmark::State::KeepRunning() { if (count & countMask) { ++count; -- cgit v1.2.3 From 29c53289a9e6bb34a098ea87d923968e3ac6d75d Mon Sep 17 00:00:00 2001 From: "Wladimir J. van der Laan" Date: Tue, 7 Feb 2017 19:07:29 +0100 Subject: bench: Fix initialization order in registration The initialization order of global data structures in different implementation units is undefined. Making use of this is essentially gambling on what the linker does, the so-called [Static initialization order fiasco](https://isocpp.org/wiki/faq/ctors#static-init-order). In this case it apparently worked on Linux but failed on OpenBSD and FreeBSD. To create it on first use, make the registration structure local to a function. Fixes #8910. --- src/bench/bench.cpp | 16 ++++++++-------- 1 file changed, 8 insertions(+), 8 deletions(-) (limited to 'src/bench/bench.cpp') diff --git a/src/bench/bench.cpp b/src/bench/bench.cpp index 1bd9d06b8..3c9df4f71 100644 --- a/src/bench/bench.cpp +++ b/src/bench/bench.cpp @@ -9,7 +9,10 @@ #include #include -std::map benchmark::BenchRunner::benchmarks; +benchmark::BenchRunner::BenchmarkMap &benchmark::BenchRunner::benchmarks() { + static std::map benchmarks_map; + return benchmarks_map; +} static double gettimedouble(void) { struct timeval tv; @@ -19,7 +22,7 @@ static double gettimedouble(void) { benchmark::BenchRunner::BenchRunner(std::string name, benchmark::BenchFunction func) { - benchmarks.insert(std::make_pair(name, func)); + benchmarks().insert(std::make_pair(name, func)); } void @@ -29,12 +32,9 @@ benchmark::BenchRunner::RunAll(double elapsedTimeForOne) std::cout << "#Benchmark" << "," << "count" << "," << "min" << "," << "max" << "," << "average" << "," << "min_cycles" << "," << "max_cycles" << "," << "average_cycles" << "\n"; - for (std::map::iterator it = benchmarks.begin(); - it != benchmarks.end(); ++it) { - - State state(it->first, elapsedTimeForOne); - benchmark::BenchFunction& func = it->second; - func(state); + for (const auto &p: benchmarks()) { + State state(p.first, elapsedTimeForOne); + p.second(state); } perf_fini(); } -- cgit v1.2.3