2016-03-10 00:11:17 +00:00
|
|
|
#ifndef MAPNIK_BENCH_FRAMEWORK_HPP
|
|
|
|
#define MAPNIK_BENCH_FRAMEWORK_HPP
|
2013-11-15 07:11:21 +00:00
|
|
|
|
|
|
|
// mapnik
|
2016-02-16 17:37:24 +00:00
|
|
|
#include <mapnik/debug.hpp>
|
2013-11-15 07:11:21 +00:00
|
|
|
#include <mapnik/params.hpp>
|
2016-08-02 14:34:59 +00:00
|
|
|
#include <mapnik/value/types.hpp>
|
2015-06-14 02:23:36 +00:00
|
|
|
#include <mapnik/safe_cast.hpp>
|
2015-06-13 02:52:58 +00:00
|
|
|
#include "../test/cleanup.hpp"
|
2013-11-15 07:11:21 +00:00
|
|
|
|
|
|
|
// stl
|
2014-10-01 09:38:08 +00:00
|
|
|
#include <chrono>
|
2016-02-28 00:04:35 +00:00
|
|
|
#include <cmath> // log10, round
|
2016-02-16 15:27:32 +00:00
|
|
|
#include <cstdio> // snprintf
|
2018-07-11 13:44:25 +00:00
|
|
|
#include <iomanip>
|
2013-11-15 07:11:21 +00:00
|
|
|
#include <iostream>
|
2014-10-01 09:38:08 +00:00
|
|
|
#include <set>
|
|
|
|
#include <sstream>
|
2013-11-15 07:11:21 +00:00
|
|
|
#include <thread>
|
2021-03-25 16:26:29 +00:00
|
|
|
#include <mutex>
|
2013-11-15 07:11:21 +00:00
|
|
|
#include <vector>
|
|
|
|
|
|
|
|
namespace benchmark {
|
|
|
|
|
2016-02-27 21:23:28 +00:00
|
|
|
template <typename T>
|
|
|
|
using milliseconds = std::chrono::duration<T, std::milli>;
|
|
|
|
|
|
|
|
template <typename T>
|
|
|
|
using seconds = std::chrono::duration<T>;
|
|
|
|
|
2013-11-15 07:11:21 +00:00
|
|
|
class test_case
|
|
|
|
{
|
|
|
|
protected:
|
|
|
|
mapnik::parameters params_;
|
|
|
|
std::size_t threads_;
|
|
|
|
std::size_t iterations_;
|
|
|
|
public:
|
|
|
|
test_case(mapnik::parameters const& params)
|
|
|
|
: params_(params),
|
2018-01-10 10:04:10 +00:00
|
|
|
threads_(mapnik::safe_cast<std::size_t>(*params.get<mapnik::value_integer>("threads", 0))),
|
|
|
|
iterations_(mapnik::safe_cast<std::size_t>(*params.get<mapnik::value_integer>("iterations", 0)))
|
2013-11-15 07:11:21 +00:00
|
|
|
{}
|
|
|
|
std::size_t threads() const
|
|
|
|
{
|
|
|
|
return threads_;
|
|
|
|
}
|
|
|
|
std::size_t iterations() const
|
|
|
|
{
|
|
|
|
return iterations_;
|
|
|
|
}
|
2016-02-17 00:30:32 +00:00
|
|
|
mapnik::parameters const& params() const
|
|
|
|
{
|
|
|
|
return params_;
|
|
|
|
}
|
2013-11-15 07:11:21 +00:00
|
|
|
virtual bool validate() const = 0;
|
2014-12-12 16:59:45 +00:00
|
|
|
virtual bool operator()() const = 0;
|
2013-11-15 07:11:21 +00:00
|
|
|
};
|
|
|
|
|
2016-02-16 17:37:24 +00:00
|
|
|
// gathers --long-option values in 'params';
|
|
|
|
// returns the index of the first non-option argument,
|
|
|
|
// or negated index of an ill-formed option argument
|
|
|
|
inline int parse_args(int argc, char** argv, mapnik::parameters & params)
|
2013-11-15 07:11:21 +00:00
|
|
|
{
|
2016-02-16 17:37:24 +00:00
|
|
|
for (int i = 1; i < argc; ++i) {
|
|
|
|
const char* opt = argv[i];
|
|
|
|
if (opt[0] != '-') {
|
|
|
|
// non-option argument, return its index
|
|
|
|
return i;
|
|
|
|
}
|
|
|
|
if (opt[1] != '-') {
|
|
|
|
// we only accept --long-options, but instead of throwing,
|
|
|
|
// just issue a warning and let the caller decide what to do
|
|
|
|
std::clog << argv[0] << ": invalid option '" << opt << "'\n";
|
|
|
|
return -i; // negative means ill-formed option #i
|
|
|
|
}
|
|
|
|
if (opt[2] == '\0') {
|
|
|
|
// option-list terminator '--'
|
|
|
|
return i + 1;
|
|
|
|
}
|
|
|
|
|
|
|
|
// take option name without the leading '--'
|
|
|
|
std::string key(opt + 2);
|
|
|
|
size_t eq = key.find('=');
|
|
|
|
if (eq != std::string::npos) {
|
|
|
|
// one-argument form '--foo=bar'
|
|
|
|
params[key.substr(0, eq)] = key.substr(eq + 1);
|
|
|
|
}
|
|
|
|
else if (i + 1 < argc) {
|
|
|
|
// two-argument form '--foo' 'bar'
|
|
|
|
params[key] = std::string(argv[++i]);
|
|
|
|
}
|
|
|
|
else {
|
|
|
|
// missing second argument
|
|
|
|
std::clog << argv[0] << ": missing option '" << opt << "' value\n";
|
|
|
|
return -i; // negative means ill-formed option #i
|
2013-11-15 07:11:21 +00:00
|
|
|
}
|
|
|
|
}
|
2016-02-16 17:37:24 +00:00
|
|
|
return argc; // there were no non-option arguments
|
|
|
|
}
|
|
|
|
|
|
|
|
inline void handle_common_args(mapnik::parameters const& params)
|
|
|
|
{
|
2016-02-27 21:19:08 +00:00
|
|
|
if (auto severity = params.get<std::string>("log")) {
|
2016-02-16 17:37:24 +00:00
|
|
|
if (*severity == "debug")
|
|
|
|
mapnik::logger::set_severity(mapnik::logger::debug);
|
|
|
|
else if (*severity == "warn")
|
|
|
|
mapnik::logger::set_severity(mapnik::logger::warn);
|
|
|
|
else if (*severity == "error")
|
|
|
|
mapnik::logger::set_severity(mapnik::logger::error);
|
|
|
|
else if (*severity == "none")
|
|
|
|
mapnik::logger::set_severity(mapnik::logger::none);
|
|
|
|
else
|
2016-02-27 21:19:08 +00:00
|
|
|
std::clog << "ignoring option --log='" << *severity
|
2016-02-16 17:37:24 +00:00
|
|
|
<< "' (allowed values are: debug, warn, error, none)\n";
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
inline int handle_args(int argc, char** argv, mapnik::parameters & params)
|
|
|
|
{
|
|
|
|
int res = parse_args(argc, argv, params);
|
|
|
|
handle_common_args(params);
|
|
|
|
return res;
|
2013-11-15 07:11:21 +00:00
|
|
|
}
|
|
|
|
|
2013-11-22 06:47:55 +00:00
|
|
|
#define BENCHMARK(test_class,name) \
|
|
|
|
int main(int argc, char** argv) \
|
|
|
|
{ \
|
|
|
|
try \
|
|
|
|
{ \
|
|
|
|
mapnik::parameters params; \
|
|
|
|
benchmark::handle_args(argc,argv,params); \
|
|
|
|
test_class test_runner(params); \
|
2015-06-13 03:51:18 +00:00
|
|
|
auto result = run(test_runner,name); \
|
|
|
|
testing::run_cleanup(); \
|
|
|
|
return result; \
|
2013-11-22 06:47:55 +00:00
|
|
|
} \
|
|
|
|
catch (std::exception const& ex) \
|
|
|
|
{ \
|
|
|
|
std::clog << ex.what() << "\n"; \
|
2015-06-13 03:51:18 +00:00
|
|
|
testing::run_cleanup(); \
|
2013-11-22 06:47:55 +00:00
|
|
|
return -1; \
|
|
|
|
} \
|
|
|
|
} \
|
2013-11-15 07:11:21 +00:00
|
|
|
|
2016-02-27 21:23:28 +00:00
|
|
|
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;
|
|
|
|
|
2016-02-28 00:04:35 +00:00
|
|
|
while (v > 1 && std::log10(std::round(v)) >= width && u[2])
|
2016-02-27 21:23:28 +00:00
|
|
|
{
|
|
|
|
v /= base;
|
|
|
|
u += 2;
|
|
|
|
}
|
|
|
|
|
|
|
|
// adjust width for proper alignment without suffix
|
|
|
|
w += (u == suffixes);
|
|
|
|
}
|
|
|
|
};
|
|
|
|
|
2013-11-15 07:11:21 +00:00
|
|
|
template <typename T>
|
|
|
|
int run(T const& test_runner, std::string const& name)
|
|
|
|
{
|
|
|
|
try
|
|
|
|
{
|
|
|
|
if (!test_runner.validate())
|
|
|
|
{
|
|
|
|
std::clog << "test did not validate: " << name << "\n";
|
2016-02-17 00:30:32 +00:00
|
|
|
return 1;
|
2013-11-15 07:11:21 +00:00
|
|
|
}
|
2014-12-12 16:59:45 +00:00
|
|
|
// run test once before timing
|
|
|
|
// if it returns false then we'll abort timing
|
2016-02-17 00:30:32 +00:00
|
|
|
if (!test_runner())
|
2013-11-15 07:11:21 +00:00
|
|
|
{
|
2016-02-17 00:30:32 +00:00
|
|
|
return 2;
|
|
|
|
}
|
|
|
|
|
|
|
|
std::chrono::high_resolution_clock::time_point start;
|
|
|
|
std::chrono::high_resolution_clock::duration elapsed;
|
|
|
|
auto opt_min_duration = test_runner.params().template get<double>("min-duration", 0.0);
|
|
|
|
std::chrono::duration<double> min_seconds(*opt_min_duration);
|
|
|
|
auto min_duration = std::chrono::duration_cast<decltype(elapsed)>(min_seconds);
|
2016-02-27 21:23:28 +00:00
|
|
|
auto num_iters = test_runner.iterations();
|
2016-02-27 23:28:00 +00:00
|
|
|
auto num_threads = test_runner.threads();
|
2016-02-27 21:23:28 +00:00
|
|
|
auto total_iters = 0;
|
2016-02-16 15:27:32 +00:00
|
|
|
|
2016-02-27 23:28:00 +00:00
|
|
|
if (num_threads > 0)
|
2016-02-17 00:30:32 +00:00
|
|
|
{
|
2016-02-27 23:28:00 +00:00
|
|
|
std::mutex mtx_ready;
|
|
|
|
std::unique_lock<std::mutex> lock_ready(mtx_ready);
|
|
|
|
|
|
|
|
auto stub = [&](T const& test_copy)
|
|
|
|
{
|
|
|
|
// workers will wait on this mutex until the main thread
|
|
|
|
// constructs all of them and starts measuring time
|
|
|
|
std::unique_lock<std::mutex> my_lock(mtx_ready);
|
|
|
|
my_lock.unlock();
|
|
|
|
test_copy();
|
|
|
|
};
|
|
|
|
|
|
|
|
std::vector<std::thread> tg;
|
|
|
|
tg.reserve(num_threads);
|
|
|
|
for (auto i = num_threads; i-- > 0; )
|
2013-11-15 07:11:21 +00:00
|
|
|
{
|
2016-02-27 23:28:00 +00:00
|
|
|
tg.emplace_back(stub, test_runner);
|
2013-11-15 07:11:21 +00:00
|
|
|
}
|
2016-02-17 00:30:32 +00:00
|
|
|
start = std::chrono::high_resolution_clock::now();
|
2016-02-27 23:28:00 +00:00
|
|
|
lock_ready.unlock();
|
|
|
|
// wait for all workers to finish
|
|
|
|
for (auto & t : tg)
|
|
|
|
{
|
|
|
|
if (t.joinable())
|
|
|
|
t.join();
|
|
|
|
}
|
2016-02-17 00:30:32 +00:00
|
|
|
elapsed = std::chrono::high_resolution_clock::now() - start;
|
2016-02-27 23:28:00 +00:00
|
|
|
// this is actually per-thread count, not total, but I think
|
|
|
|
// reporting average 'iters/thread/second' is more useful
|
|
|
|
// than 'iters/second' multiplied by the number of threads
|
2016-02-27 21:23:28 +00:00
|
|
|
total_iters += num_iters;
|
2016-02-17 00:30:32 +00:00
|
|
|
}
|
|
|
|
else
|
|
|
|
{
|
|
|
|
start = std::chrono::high_resolution_clock::now();
|
|
|
|
do {
|
2014-12-12 16:59:45 +00:00
|
|
|
test_runner();
|
|
|
|
elapsed = std::chrono::high_resolution_clock::now() - start;
|
2016-02-27 21:23:28 +00:00
|
|
|
total_iters += num_iters;
|
2016-02-17 00:30:32 +00:00
|
|
|
} while (elapsed < min_duration);
|
|
|
|
}
|
2016-02-16 15:27:32 +00:00
|
|
|
|
2016-02-17 00:30:32 +00:00
|
|
|
char msg[200];
|
2016-02-27 21:23:28 +00:00
|
|
|
double dur_total = milliseconds<double>(elapsed).count();
|
2016-02-27 23:28:00 +00:00
|
|
|
auto elapsed_nonzero = std::max(elapsed, decltype(elapsed){1});
|
2016-02-27 21:23:28 +00:00
|
|
|
big_number_fmt itersf(4, total_iters);
|
2016-02-27 23:28:00 +00:00
|
|
|
big_number_fmt ips(5, total_iters / seconds<double>(elapsed_nonzero).count());
|
2016-02-17 00:30:32 +00:00
|
|
|
|
2018-07-11 13:44:25 +00:00
|
|
|
std::clog << std::left << std::setw(43) << name;
|
|
|
|
std::clog << std::resetiosflags(std::ios::adjustfield);
|
|
|
|
if (num_threads > 0) {
|
|
|
|
std::clog << ' ' << std::setw(3) << num_threads
|
|
|
|
<< " worker" << (num_threads > 1 ? "s" : " ");
|
|
|
|
}
|
|
|
|
else {
|
|
|
|
std::clog << " main thread";
|
|
|
|
}
|
2016-02-17 00:30:32 +00:00
|
|
|
std::snprintf(msg, sizeof(msg),
|
2018-07-11 13:44:25 +00:00
|
|
|
" %*.0f%s iters %6.0f milliseconds %*.0f%s i/t/s\n",
|
|
|
|
itersf.w, itersf.v, itersf.u, dur_total,
|
|
|
|
ips.w, ips.v, ips.u);
|
2016-02-17 00:30:32 +00:00
|
|
|
std::clog << msg;
|
2013-11-15 07:11:21 +00:00
|
|
|
return 0;
|
|
|
|
}
|
|
|
|
catch (std::exception const& ex)
|
|
|
|
{
|
|
|
|
std::clog << "test runner did not complete: " << ex.what() << "\n";
|
2016-02-17 00:30:32 +00:00
|
|
|
return 4;
|
2013-11-15 07:11:21 +00:00
|
|
|
}
|
|
|
|
}
|
|
|
|
|
2016-02-16 18:53:03 +00:00
|
|
|
struct sequencer
|
|
|
|
{
|
|
|
|
sequencer(int argc, char** argv)
|
|
|
|
: exit_code_(0)
|
|
|
|
{
|
|
|
|
benchmark::handle_args(argc, argv, params_);
|
|
|
|
}
|
|
|
|
|
|
|
|
int done() const
|
|
|
|
{
|
|
|
|
return exit_code_;
|
|
|
|
}
|
|
|
|
|
|
|
|
template <typename Test, typename... Args>
|
|
|
|
sequencer & run(std::string const& name, Args && ...args)
|
|
|
|
{
|
|
|
|
// Test instance lifetime is confined to this function
|
|
|
|
Test test_runner(params_, std::forward<Args>(args)...);
|
|
|
|
// any failing test run will make exit code non-zero
|
|
|
|
exit_code_ |= benchmark::run(test_runner, name);
|
|
|
|
return *this; // allow chaining calls
|
|
|
|
}
|
|
|
|
|
|
|
|
protected:
|
|
|
|
mapnik::parameters params_;
|
|
|
|
int exit_code_;
|
|
|
|
};
|
|
|
|
|
2013-11-15 07:11:21 +00:00
|
|
|
}
|
|
|
|
|
2016-03-10 00:11:17 +00:00
|
|
|
#endif // MAPNIK_BENCH_FRAMEWORK_HPP
|