Merge branch 'lightmare-benchanting'

2016-02-17 12:07:19 +01:00 · 2016-02-17 12:07:19 +01:00 · d7d22276c0
commit d7d22276c0
parent c72e3b7a2f 9aed60a1e6
7 changed files with 189 additions and 197 deletions
--- a/benchmark/bench_framework.hpp
+++ b/benchmark/bench_framework.hpp
@ -2,6 +2,7 @@
 #define __MAPNIK_BENCH_FRAMEWORK_HPP__

 // mapnik
+#include <mapnik/debug.hpp>
 #include <mapnik/params.hpp>
 #include <mapnik/value_types.hpp>
 #include <mapnik/safe_cast.hpp>
@ -9,7 +10,7 @@

 // stl
 #include <chrono>
-#include <iomanip>
+#include <cstdio> // snprintf
 #include <iostream>
 #include <set>
 #include <sstream>
@ -38,26 +39,79 @@ public:
    {
        return iterations_;
    }
+    mapnik::parameters const& params() const
+    {
+        return params_;
+    }
    virtual bool validate() const = 0;
    virtual bool operator()() const = 0;
    virtual ~test_case() {}
 };

-void handle_args(int argc, char** argv, mapnik::parameters & params)
+// 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)
 {
-    if (argc > 0) {
-        for (int i=1;i<argc;++i) {
-            std::string opt(argv[i]);
-            // parse --foo bar
-            if (!opt.empty() && (opt.find("--") != 0)) {
-                std::string key = std::string(argv[i-1]);
-                if (!key.empty() && (key.find("--") == 0)) {
-                    key = key.substr(key.find_first_not_of("-"));
-                    params[key] = opt;
-                }
-            }
+    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
        }
    }
+    return argc; // there were no non-option arguments
+}
+
+inline void handle_common_args(mapnik::parameters const& params)
+{
+    if (auto severity = params.get<std::string>("log-severity")) {
+        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
+            std::clog << "ignoring option --log-severity='" << *severity
+                      << "' (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;
 }

 #define BENCHMARK(test_class,name)                      \
@ -88,52 +142,112 @@ int run(T const& test_runner, std::string const& name)
        if (!test_runner.validate())
        {
            std::clog << "test did not validate: " << name << "\n";
-            return -1;
+            return 1;
        }
        // run test once before timing
        // if it returns false then we'll abort timing
-        if (test_runner())
+        if (!test_runner())
        {
-            std::chrono::high_resolution_clock::time_point start;
-            std::chrono::high_resolution_clock::duration elapsed;
-            std::stringstream s;
-            s << name << ":"
-                << std::setw(45 - (int)s.tellp()) << std::right
-                << " t:" << test_runner.threads()
-                << " i:" << test_runner.iterations();
-            if (test_runner.threads() > 0)
+            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);
+        std::size_t loops = 0;
+
+        if (test_runner.threads() > 0)
+        {
+            using thread_group = std::vector<std::unique_ptr<std::thread> >;
+            using value_type = thread_group::value_type;
+            thread_group tg;
+            for (std::size_t i=0;i<test_runner.threads();++i)
            {
-                using thread_group = std::vector<std::unique_ptr<std::thread> >;
-                using value_type = thread_group::value_type;
-                thread_group tg;
-                for (std::size_t i=0;i<test_runner.threads();++i)
-                {
-                    tg.emplace_back(new std::thread(test_runner));
-                }
-                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;
+                tg.emplace_back(new std::thread(test_runner));
            }
-            else
-            {
-                start = std::chrono::high_resolution_clock::now();
+            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;
+        }
+        else
+        {
+            start = std::chrono::high_resolution_clock::now();
+            do {
                test_runner();
                elapsed = std::chrono::high_resolution_clock::now() - start;
-            }
-            s << std::setw(65 - (int)s.tellp()) << std::right
-                << std::chrono::duration_cast<std::chrono::milliseconds>(elapsed).count() << " milliseconds\n";
-            std::clog << s.str();
+                ++loops;
+            } while (elapsed < min_duration);
        }
+
+        double iters = loops * test_runner.iterations();
+        double dur_total = std::chrono::duration<double, std::milli>(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';
+
+        std::snprintf(msg, sizeof(msg),
+                "%-43s %3zu threads %4.0f%c iters %6.0f milliseconds",
+                name.c_str(),
+                test_runner.threads(),
+                iters, iters_unit,
+                dur_total);
+        std::clog << msg;
+
+        // log average time per iteration, 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);
+            std::clog << msg;
+        }
+
+        std::clog << "\n";
        return 0;
    }
    catch (std::exception const& ex)
    {
        std::clog << "test runner did not complete: " << ex.what() << "\n";
-        return -1;
+        return 4;
    }
-    return 0;
 }

+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_;
+};
+
 }

 #endif // __MAPNIK_BENCH_FRAMEWORK_HPP__
--- a/benchmark/test_array_allocation.cpp
+++ b/benchmark/test_array_allocation.cpp
@ -231,33 +231,6 @@ public:
    }
 };

-class test3d : public benchmark::test_case
-{
-public:
-    uint32_t size_;
-    std::vector<uint8_t> array_;
-    test3d(mapnik::parameters const& params)
-     : test_case(params),
-       size_(*params.get<mapnik::value_integer>("size",256*256)),
-       array_(size_,0) { }
-    bool validate() const
-    {
-        return true;
-    }
-    bool operator()() const
-    {
-         for (std::size_t i=0;i<iterations_;++i) {
-             std::deque<uint8_t> data(size_);
-             for (std::size_t i=0;i<size_;++i) {
-                 if (data[i] != 0) {
-                     throw std::runtime_error("found non zero value");
-                 }
-             }
-         }
-         return true;
-    }
-};
-
 class test4 : public benchmark::test_case
 {
 public:
@ -386,62 +359,21 @@ public:

 int main(int argc, char** argv)
 {
-    int return_value = 0;
-    mapnik::parameters params;
-    benchmark::handle_args(argc,argv,params);
-    {
-        test4 test_runner4(params);
-        return_value = return_value | run(test_runner4,"calloc");
-    }
-    {
-        test1 test_runner(params);
-        return_value = return_value | run(test_runner,"malloc/memcpy");
-    }
-    {
-        test1b test_runner(params);
-        return_value = return_value | run(test_runner,"malloc/memset");
-    }
-    {
-        test1c test_runner(params);
-        return_value = return_value | run(test_runner,"operator new/std::fill");
-    }
-    {
-        test2 test_runner(params);
-        return_value = return_value | run(test_runner,"operator new/memcpy");
-    }
-    {
-        test3 test_runner(params);
-        return_value = return_value | run(test_runner,"vector(N)");
-    }
-    {
-        test3b test_runner(params);
-        return_value = return_value | run(test_runner,"vector/resize");
-    }
-    {
-        test3c test_runner(params);
-        return_value = return_value | run(test_runner,"vector/assign");
-    }
-    {
-        test3d test_runner(params);
-        return_value = return_value | run(test_runner,"deque(N)");
-    }
-    {
-        test5 test_runner(params);
-        return_value = return_value | run(test_runner,"std::string range");
-    }
-    {
-        test5b test_runner(params);
-        return_value = return_value | run(test_runner,"std::string &[0]");
-    }
-    {
-        test6 test_runner(params);
-        return_value = return_value | run(test_runner,"valarray");
-    }
+    return benchmark::sequencer(argc, argv)
+        .run<test4>("calloc")
+        .run<test1>("malloc/memcpy")
+        .run<test1b>("malloc/memset")
+        .run<test1c>("operator new/std::fill")
+        .run<test2>("operator new/memcpy")
+        .run<test3>("vector(N)")
+        .run<test3b>("vector/resize")
+        .run<test3c>("vector/assign")
+        .run<test3d>("deque(N)")
+        .run<test5>("std::string range")
+        .run<test5b>("std::string &[0]")
+        .run<test6>("valarray")
 #if BOOST_VERSION >= 105400
-    {
-        test7 test_runner(params);
-        return_value = return_value | run(test_runner,"static_vector");
-    }
+        .run<test7>("static_vector")
 #endif
-    return return_value;
+        .done();
 }
--- a/benchmark/test_numeric_cast_vs_static_cast.cpp
+++ b/benchmark/test_numeric_cast_vs_static_cast.cpp
@ -73,16 +73,8 @@ public:

 int main(int argc, char** argv)
 {
-    mapnik::parameters params;
-    benchmark::handle_args(argc,argv,params);
-    int return_value = 0;
-    {
-        test_static test_runner(params);
-        return_value = return_value | run(test_runner,"static_cast");
-    }
-    {
-        test_numeric test_runner(params);
-        return_value = return_value | run(test_runner,"numeric_cast");
-    }
-    return return_value;
+    return benchmark::sequencer(argc, argv)
+        .run<test_static>("static_cast")
+        .run<test_numeric>("numeric_cast")
+        .done();
 }
--- a/benchmark/test_png_encoding1.cpp
+++ b/benchmark/test_png_encoding1.cpp
@ -19,8 +19,8 @@ public:
            out.clear();
            out = mapnik::save_to_string(im_,"png8:m=h:z=1");
        }
+        return true;
    }
-    return true;
 };

 BENCHMARK(test,"encoding blank png")
--- a/benchmark/test_png_encoding2.cpp
+++ b/benchmark/test_png_encoding2.cpp
@ -30,8 +30,8 @@ public:
            out.clear();
            out = mapnik::save_to_string(*im_,"png8:m=h:z=1");
        }
+        return true;
    }
-    return true;
 };

 BENCHMARK(test,"encoding multicolor png")
--- a/benchmark/test_polygon_clipping_rendering.cpp
+++ b/benchmark/test_polygon_clipping_rendering.cpp
@ -51,30 +51,10 @@ int main(int argc, char** argv)
    mapnik::box2d<double> z1(-20037508.3428,-8317435.0606,20037508.3428,18399242.7298);
    // bbox for 16/10491/22911.png
    mapnik::box2d<double> z16(-13622912.929097254,6026906.8062295765,-13621689.93664469,6028129.79868214);
-    int return_value = 0;
-    {
-        test test_runner(params,
-                          "benchmark/data/polygon_rendering_clip.xml",
-                          z1);
-        return_value = return_value | run(test_runner,"polygon clip render z1");
-    }
-    {
-        test test_runner(params,
-                          "benchmark/data/polygon_rendering_no_clip.xml",
-                          z1);
-        return_value = return_value | run(test_runner,"polygon noclip render z1");
-    }
-    {
-        test test_runner(params,
-                          "benchmark/data/polygon_rendering_clip.xml",
-                          z16);
-        return_value = return_value | run(test_runner,"polygon clip render z16");
-    }
-    {
-        test test_runner(params,
-                          "benchmark/data/polygon_rendering_no_clip.xml",
-                          z16);
-        return_value = return_value | run(test_runner,"polygon noclip render z16");
-    }
-    return return_value;
+    return benchmark::sequencer(argc, argv)
+        .run<test>("polygon clip render z1", "benchmark/data/polygon_rendering_clip.xml", z1)
+        .run<test>("polygon noclip render z1", "benchmark/data/polygon_rendering_no_clip.xml", z1)
+        .run<test>("polygon clip render z16", "benchmark/data/polygon_rendering_clip.xml", z16)
+        .run<test>("polygon noclip render z16", "benchmark/data/polygon_rendering_no_clip.xml", z16)
+        .done();
 }
--- a/benchmark/test_proj_transform1.cpp
+++ b/benchmark/test_proj_transform1.cpp
@ -59,42 +59,16 @@ public:
 // echo -180 -60 | cs2cs -f "%.10f" +init=epsg:4326 +to +init=epsg:3857
 int main(int argc, char** argv)
 {
-    mapnik::parameters params;
-    benchmark::handle_args(argc,argv,params);
    mapnik::box2d<double> from(-180,-80,180,80);
    mapnik::box2d<double> to(-20037508.3427892476,-15538711.0963092316,20037508.3427892476,15538711.0963092316);
    std::string from_str("+init=epsg:4326");
    std::string to_str("+init=epsg:3857");
    std::string from_str2("+proj=longlat +ellps=WGS84 +datum=WGS84 +no_defs");
    std::string to_str2("+proj=merc +a=6378137 +b=6378137 +lat_ts=0.0 +lon_0=0.0 +x_0=0.0 +y_0=0.0 +k=1.0 +units=m +nadgrids=@null +wktext +no_defs +over");
-    int return_value = 0;
-    test test_runner(params,
-                     from_str,
-                     to_str,
-                     from,
-                     to,
-                     true);
-    return_value = return_value | run(test_runner,"lonlat->merc epsg");
-    test test_runner2(params,
-                     from_str2,
-                     to_str2,
-                     from,
-                     to,
-                     true);
-    return_value = return_value | run(test_runner2,"lonlat->merc literal");
-    test test_runner3(params,
-                     to_str,
-                     from_str,
-                     to,
-                     from,
-                     true);
-    return_value = return_value | run(test_runner3,"merc->lonlat epsg");
-    test test_runner4(params,
-                     to_str2,
-                     from_str2,
-                     to,
-                     from,
-                     true);
-    return_value = return_value | run(test_runner4,"merc->lonlat literal");
-    return return_value;
+    return benchmark::sequencer(argc, argv)
+        .run<test>("lonlat->merc epsg", from_str, to_str, from, to, true)
+        .run<test>("lonlat->merc literal", from_str2, to_str2, from, to, true)
+        .run<test>("merc->lonlat epsg", to_str, from_str, to, from, true)
+        .run<test>("merc->lonlat literal", to_str2, from_str2, to, from, true)
+        .done();
 }