Json reporter: don't cast floating-point to int; adjust tooling (#426)

* Json reporter: passthrough fp, don't cast it to int; adjust tooling

Json output format is generally meant for further processing
using some automated tools. Thus, it makes sense not to
intentionally limit the precision of the values contained
in the report.

As it can be seen, FormatKV() for doubles, used %.2f format,
which was meant to preserve at least some of the precision.
However, before that function is ever called, the doubles
were already cast to the integer via RoundDouble()...

This is also the case for console reporter, where it makes
sense because the screen space is limited, and this reporter,
however the CSV reporter does output some( decimal digits.

Thus i can only conclude that the loss of the precision
was not really considered, so i have decided to adjust the
code of the json reporter to output the full fp precision.

There can be several reasons why that is the right thing
to do, the bigger the time_unit used, the greater the
precision loss, so i'd say any sort of further processing
(like e.g. tools/compare_bench.py does) is best done
on the values with most precision.

Also, that cast skewed the data away from zero, which
i think may or may not result in false- positives/negatives
in the output of tools/compare_bench.py

* Json reporter: FormatKV(double): address review note

* tools/gbench/report.py: skip benchmarks with different time units

While it may be useful to teach it to operate on the
measurements with different time units, which is now
possible since floats are stored, and not the integers,
but for now at least doing such a sanity-checking
is better than providing misinformation.
This commit is contained in:
Roman Lebedev 2017-07-25 02:13:55 +03:00 committed by Dominic Hamon
parent 5b7683f49e
commit b9be142d1e
8 changed files with 120 additions and 64 deletions

View File

@ -21,6 +21,8 @@
#include <string>
#include <tuple>
#include <vector>
#include <iomanip> // for setprecision
#include <limits>
#include "string_util.h"
#include "timers.h"
@ -48,7 +50,14 @@ std::string FormatKV(std::string const& key, int64_t value) {
}
std::string FormatKV(std::string const& key, double value) {
return StringPrintF("\"%s\": %.2f", key.c_str(), value);
std::stringstream ss;
ss << '"' << key << "\": ";
const auto max_digits10 = std::numeric_limits<decltype (value)>::max_digits10;
const auto max_fractional_digits10 = max_digits10 - 1;
ss << std::scientific << std::setprecision(max_fractional_digits10) << value;
return ss.str();
}
int64_t RoundDouble(double v) { return static_cast<int64_t>(v + 0.5); }
@ -125,18 +134,18 @@ void JSONReporter::PrintRunData(Run const& run) {
if (!run.report_big_o && !run.report_rms) {
out << indent << FormatKV("iterations", run.iterations) << ",\n";
out << indent
<< FormatKV("real_time", RoundDouble(run.GetAdjustedRealTime()))
<< FormatKV("real_time", run.GetAdjustedRealTime())
<< ",\n";
out << indent
<< FormatKV("cpu_time", RoundDouble(run.GetAdjustedCPUTime()));
<< FormatKV("cpu_time", run.GetAdjustedCPUTime());
out << ",\n"
<< indent << FormatKV("time_unit", GetTimeUnitString(run.time_unit));
} else if (run.report_big_o) {
out << indent
<< FormatKV("cpu_coefficient", RoundDouble(run.GetAdjustedCPUTime()))
<< FormatKV("cpu_coefficient", run.GetAdjustedCPUTime())
<< ",\n";
out << indent
<< FormatKV("real_coefficient", RoundDouble(run.GetAdjustedRealTime()))
<< FormatKV("real_coefficient", run.GetAdjustedRealTime())
<< ",\n";
out << indent << FormatKV("big_o", GetBigOString(run.complexity)) << ",\n";
out << indent << FormatKV("time_unit", GetTimeUnitString(run.time_unit));
@ -147,17 +156,17 @@ void JSONReporter::PrintRunData(Run const& run) {
if (run.bytes_per_second > 0.0) {
out << ",\n"
<< indent
<< FormatKV("bytes_per_second", RoundDouble(run.bytes_per_second));
<< FormatKV("bytes_per_second", run.bytes_per_second);
}
if (run.items_per_second > 0.0) {
out << ",\n"
<< indent
<< FormatKV("items_per_second", RoundDouble(run.items_per_second));
<< FormatKV("items_per_second", run.items_per_second);
}
for(auto &c : run.counters) {
out << ",\n"
<< indent
<< FormatKV(c.first, RoundDouble(c.second));
<< FormatKV(c.first, c.second);
}
if (!run.report_label.empty()) {
out << ",\n" << indent << FormatKV("label", run.report_label);

View File

@ -25,8 +25,8 @@ int AddComplexityTest(std::string big_o_test_name, std::string rms_test_name,
{"^%bigo_name", MR_Not}, // Assert we we didn't only matched a name.
{"^%rms_name %rms %rms[ ]*$", MR_Next}});
AddCases(TC_JSONOut, {{"\"name\": \"%bigo_name\",$"},
{"\"cpu_coefficient\": [0-9]+,$", MR_Next},
{"\"real_coefficient\": [0-9]{1,5},$", MR_Next},
{"\"cpu_coefficient\": %float,$", MR_Next},
{"\"real_coefficient\": %float,$", MR_Next},
{"\"big_o\": \"%bigo\",$", MR_Next},
{"\"time_unit\": \"ns\"$", MR_Next},
{"}", MR_Next},

View File

@ -27,9 +27,9 @@ BENCHMARK(BM_basic);
ADD_CASES(TC_ConsoleOut, {{"^BM_basic %console_report$"}});
ADD_CASES(TC_JSONOut, {{"\"name\": \"BM_basic\",$"},
{"\"iterations\": %int,$", MR_Next},
{"\"real_time\": %int,$", MR_Next},
{"\"cpu_time\": %int,$", MR_Next},
{"\"iterations\": %float,$", MR_Next},
{"\"real_time\": %float,$", MR_Next},
{"\"cpu_time\": %float,$", MR_Next},
{"\"time_unit\": \"ns\"$", MR_Next},
{"}", MR_Next}});
ADD_CASES(TC_CSVOut, {{"^\"BM_basic\",%csv_report$"}});
@ -48,11 +48,11 @@ BENCHMARK(BM_bytes_per_second);
ADD_CASES(TC_ConsoleOut,
{{"^BM_bytes_per_second %console_report +%floatB/s$"}});
ADD_CASES(TC_JSONOut, {{"\"name\": \"BM_bytes_per_second\",$"},
{"\"iterations\": %int,$", MR_Next},
{"\"real_time\": %int,$", MR_Next},
{"\"cpu_time\": %int,$", MR_Next},
{"\"iterations\": %float,$", MR_Next},
{"\"real_time\": %float,$", MR_Next},
{"\"cpu_time\": %float,$", MR_Next},
{"\"time_unit\": \"ns\",$", MR_Next},
{"\"bytes_per_second\": %int$", MR_Next},
{"\"bytes_per_second\": %float$", MR_Next},
{"}", MR_Next}});
ADD_CASES(TC_CSVOut, {{"^\"BM_bytes_per_second\",%csv_bytes_report$"}});
@ -70,11 +70,11 @@ BENCHMARK(BM_items_per_second);
ADD_CASES(TC_ConsoleOut,
{{"^BM_items_per_second %console_report +%float items/s$"}});
ADD_CASES(TC_JSONOut, {{"\"name\": \"BM_items_per_second\",$"},
{"\"iterations\": %int,$", MR_Next},
{"\"real_time\": %int,$", MR_Next},
{"\"cpu_time\": %int,$", MR_Next},
{"\"iterations\": %float,$", MR_Next},
{"\"real_time\": %float,$", MR_Next},
{"\"cpu_time\": %float,$", MR_Next},
{"\"time_unit\": \"ns\",$", MR_Next},
{"\"items_per_second\": %int$", MR_Next},
{"\"items_per_second\": %float$", MR_Next},
{"}", MR_Next}});
ADD_CASES(TC_CSVOut, {{"^\"BM_items_per_second\",%csv_items_report$"}});
@ -91,9 +91,9 @@ BENCHMARK(BM_label);
ADD_CASES(TC_ConsoleOut, {{"^BM_label %console_report some label$"}});
ADD_CASES(TC_JSONOut, {{"\"name\": \"BM_label\",$"},
{"\"iterations\": %int,$", MR_Next},
{"\"real_time\": %int,$", MR_Next},
{"\"cpu_time\": %int,$", MR_Next},
{"\"iterations\": %float,$", MR_Next},
{"\"real_time\": %float,$", MR_Next},
{"\"cpu_time\": %float,$", MR_Next},
{"\"time_unit\": \"ns\",$", MR_Next},
{"\"label\": \"some label\"$", MR_Next},
{"}", MR_Next}});

View File

@ -68,9 +68,9 @@ void BM_Counters_Tabular(benchmark::State& state) {
}
BENCHMARK(BM_Counters_Tabular)->ThreadRange(1, 16);
ADD_CASES(TC_JSONOut, {{"\"name\": \"BM_Counters_Tabular/threads:%int\",$"},
{"\"iterations\": %int,$", MR_Next},
{"\"real_time\": %int,$", MR_Next},
{"\"cpu_time\": %int,$", MR_Next},
{"\"iterations\": %float,$", MR_Next},
{"\"real_time\": %float,$", MR_Next},
{"\"cpu_time\": %float,$", MR_Next},
{"\"time_unit\": \"ns\",$", MR_Next},
{"\"Bar\": %float,$", MR_Next},
{"\"Bat\": %float,$", MR_Next},
@ -112,9 +112,9 @@ void BM_CounterRates_Tabular(benchmark::State& state) {
}
BENCHMARK(BM_CounterRates_Tabular)->ThreadRange(1, 16);
ADD_CASES(TC_JSONOut, {{"\"name\": \"BM_CounterRates_Tabular/threads:%int\",$"},
{"\"iterations\": %int,$", MR_Next},
{"\"real_time\": %int,$", MR_Next},
{"\"cpu_time\": %int,$", MR_Next},
{"\"iterations\": %float,$", MR_Next},
{"\"real_time\": %float,$", MR_Next},
{"\"cpu_time\": %float,$", MR_Next},
{"\"time_unit\": \"ns\",$", MR_Next},
{"\"Bar\": %float,$", MR_Next},
{"\"Bat\": %float,$", MR_Next},
@ -156,9 +156,9 @@ void BM_CounterSet0_Tabular(benchmark::State& state) {
}
BENCHMARK(BM_CounterSet0_Tabular)->ThreadRange(1, 16);
ADD_CASES(TC_JSONOut, {{"\"name\": \"BM_CounterSet0_Tabular/threads:%int\",$"},
{"\"iterations\": %int,$", MR_Next},
{"\"real_time\": %int,$", MR_Next},
{"\"cpu_time\": %int,$", MR_Next},
{"\"iterations\": %float,$", MR_Next},
{"\"real_time\": %float,$", MR_Next},
{"\"cpu_time\": %float,$", MR_Next},
{"\"time_unit\": \"ns\",$", MR_Next},
{"\"Bar\": %float,$", MR_Next},
{"\"Baz\": %float,$", MR_Next},
@ -188,9 +188,9 @@ void BM_CounterSet1_Tabular(benchmark::State& state) {
}
BENCHMARK(BM_CounterSet1_Tabular)->ThreadRange(1, 16);
ADD_CASES(TC_JSONOut, {{"\"name\": \"BM_CounterSet1_Tabular/threads:%int\",$"},
{"\"iterations\": %int,$", MR_Next},
{"\"real_time\": %int,$", MR_Next},
{"\"cpu_time\": %int,$", MR_Next},
{"\"iterations\": %float,$", MR_Next},
{"\"real_time\": %float,$", MR_Next},
{"\"cpu_time\": %float,$", MR_Next},
{"\"time_unit\": \"ns\",$", MR_Next},
{"\"Bar\": %float,$", MR_Next},
{"\"Baz\": %float,$", MR_Next},
@ -224,9 +224,9 @@ void BM_CounterSet2_Tabular(benchmark::State& state) {
}
BENCHMARK(BM_CounterSet2_Tabular)->ThreadRange(1, 16);
ADD_CASES(TC_JSONOut, {{"\"name\": \"BM_CounterSet2_Tabular/threads:%int\",$"},
{"\"iterations\": %int,$", MR_Next},
{"\"real_time\": %int,$", MR_Next},
{"\"cpu_time\": %int,$", MR_Next},
{"\"iterations\": %float,$", MR_Next},
{"\"real_time\": %float,$", MR_Next},
{"\"cpu_time\": %float,$", MR_Next},
{"\"time_unit\": \"ns\",$", MR_Next},
{"\"Bat\": %float,$", MR_Next},
{"\"Baz\": %float,$", MR_Next},

View File

@ -27,9 +27,9 @@ void BM_Counters_Simple(benchmark::State& state) {
BENCHMARK(BM_Counters_Simple);
ADD_CASES(TC_ConsoleOut, {{"^BM_Counters_Simple %console_report bar=%hrfloat foo=%hrfloat$"}});
ADD_CASES(TC_JSONOut, {{"\"name\": \"BM_Counters_Simple\",$"},
{"\"iterations\": %int,$", MR_Next},
{"\"real_time\": %int,$", MR_Next},
{"\"cpu_time\": %int,$", MR_Next},
{"\"iterations\": %float,$", MR_Next},
{"\"real_time\": %float,$", MR_Next},
{"\"cpu_time\": %float,$", MR_Next},
{"\"time_unit\": \"ns\",$", MR_Next},
{"\"bar\": %float,$", MR_Next},
{"\"foo\": %float$", MR_Next},
@ -63,12 +63,12 @@ ADD_CASES(TC_ConsoleOut,
{{"^BM_Counters_WithBytesAndItemsPSec %console_report "
"bar=%hrfloat foo=%hrfloat +%hrfloatB/s +%hrfloat items/s$"}});
ADD_CASES(TC_JSONOut, {{"\"name\": \"BM_Counters_WithBytesAndItemsPSec\",$"},
{"\"iterations\": %int,$", MR_Next},
{"\"real_time\": %int,$", MR_Next},
{"\"cpu_time\": %int,$", MR_Next},
{"\"iterations\": %float,$", MR_Next},
{"\"real_time\": %float,$", MR_Next},
{"\"cpu_time\": %float,$", MR_Next},
{"\"time_unit\": \"ns\",$", MR_Next},
{"\"bytes_per_second\": %int,$", MR_Next},
{"\"items_per_second\": %int,$", MR_Next},
{"\"bytes_per_second\": %float,$", MR_Next},
{"\"items_per_second\": %float,$", MR_Next},
{"\"bar\": %float,$", MR_Next},
{"\"foo\": %float$", MR_Next},
{"}", MR_Next}});
@ -101,9 +101,9 @@ void BM_Counters_Rate(benchmark::State& state) {
BENCHMARK(BM_Counters_Rate);
ADD_CASES(TC_ConsoleOut, {{"^BM_Counters_Rate %console_report bar=%hrfloat/s foo=%hrfloat/s$"}});
ADD_CASES(TC_JSONOut, {{"\"name\": \"BM_Counters_Rate\",$"},
{"\"iterations\": %int,$", MR_Next},
{"\"real_time\": %int,$", MR_Next},
{"\"cpu_time\": %int,$", MR_Next},
{"\"iterations\": %float,$", MR_Next},
{"\"real_time\": %float,$", MR_Next},
{"\"cpu_time\": %float,$", MR_Next},
{"\"time_unit\": \"ns\",$", MR_Next},
{"\"bar\": %float,$", MR_Next},
{"\"foo\": %float$", MR_Next},
@ -132,9 +132,9 @@ void BM_Counters_Threads(benchmark::State& state) {
BENCHMARK(BM_Counters_Threads)->ThreadRange(1, 8);
ADD_CASES(TC_ConsoleOut, {{"^BM_Counters_Threads/threads:%int %console_report bar=%hrfloat foo=%hrfloat$"}});
ADD_CASES(TC_JSONOut, {{"\"name\": \"BM_Counters_Threads/threads:%int\",$"},
{"\"iterations\": %int,$", MR_Next},
{"\"real_time\": %int,$", MR_Next},
{"\"cpu_time\": %int,$", MR_Next},
{"\"iterations\": %float,$", MR_Next},
{"\"real_time\": %float,$", MR_Next},
{"\"cpu_time\": %float,$", MR_Next},
{"\"time_unit\": \"ns\",$", MR_Next},
{"\"bar\": %float,$", MR_Next},
{"\"foo\": %float$", MR_Next},
@ -162,9 +162,9 @@ void BM_Counters_AvgThreads(benchmark::State& state) {
BENCHMARK(BM_Counters_AvgThreads)->ThreadRange(1, 8);
ADD_CASES(TC_ConsoleOut, {{"^BM_Counters_AvgThreads/threads:%int %console_report bar=%hrfloat foo=%hrfloat$"}});
ADD_CASES(TC_JSONOut, {{"\"name\": \"BM_Counters_AvgThreads/threads:%int\",$"},
{"\"iterations\": %int,$", MR_Next},
{"\"real_time\": %int,$", MR_Next},
{"\"cpu_time\": %int,$", MR_Next},
{"\"iterations\": %float,$", MR_Next},
{"\"real_time\": %float,$", MR_Next},
{"\"cpu_time\": %float,$", MR_Next},
{"\"time_unit\": \"ns\",$", MR_Next},
{"\"bar\": %float,$", MR_Next},
{"\"foo\": %float$", MR_Next},
@ -193,9 +193,9 @@ void BM_Counters_AvgThreadsRate(benchmark::State& state) {
BENCHMARK(BM_Counters_AvgThreadsRate)->ThreadRange(1, 8);
ADD_CASES(TC_ConsoleOut, {{"^BM_Counters_AvgThreadsRate/threads:%int %console_report bar=%hrfloat/s foo=%hrfloat/s$"}});
ADD_CASES(TC_JSONOut, {{"\"name\": \"BM_Counters_AvgThreadsRate/threads:%int\",$"},
{"\"iterations\": %int,$", MR_Next},
{"\"real_time\": %int,$", MR_Next},
{"\"cpu_time\": %int,$", MR_Next},
{"\"iterations\": %float,$", MR_Next},
{"\"real_time\": %float,$", MR_Next},
{"\"cpu_time\": %float,$", MR_Next},
{"\"time_unit\": \"ns\",$", MR_Next},
{"\"bar\": %float,$", MR_Next},
{"\"foo\": %float$", MR_Next},

View File

@ -28,6 +28,20 @@
"cpu_time": 50,
"time_unit": "ns"
},
{
"name": "BM_1PercentFaster",
"iterations": 1000,
"real_time": 100,
"cpu_time": 100,
"time_unit": "ns"
},
{
"name": "BM_1PercentSlower",
"iterations": 1000,
"real_time": 100,
"cpu_time": 100,
"time_unit": "ns"
},
{
"name": "BM_10PercentFaster",
"iterations": 1000,
@ -55,6 +69,13 @@
"real_time": 10000,
"cpu_time": 10000,
"time_unit": "ns"
},
{
"name": "BM_DifferentTimeUnit",
"iterations": 1,
"real_time": 1,
"cpu_time": 1,
"time_unit": "s"
}
]
}
}

View File

@ -28,6 +28,20 @@
"cpu_time": 100,
"time_unit": "ns"
},
{
"name": "BM_1PercentFaster",
"iterations": 1000,
"real_time": 98.9999999,
"cpu_time": 98.9999999,
"time_unit": "ns"
},
{
"name": "BM_1PercentSlower",
"iterations": 1000,
"real_time": 100.9999999,
"cpu_time": 100.9999999,
"time_unit": "ns"
},
{
"name": "BM_10PercentFaster",
"iterations": 1000,
@ -45,8 +59,8 @@
{
"name": "BM_100xSlower",
"iterations": 1000,
"real_time": 10000,
"cpu_time": 10000,
"real_time": 1.0000e+04,
"cpu_time": 1.0000e+04,
"time_unit": "ns"
},
{
@ -55,6 +69,13 @@
"real_time": 100,
"cpu_time": 100,
"time_unit": "ns"
},
{
"name": "BM_DifferentTimeUnit",
"iterations": 1,
"real_time": 1,
"cpu_time": 1,
"time_unit": "ns"
}
]
}
}

View File

@ -87,6 +87,9 @@ def generate_difference_report(json1, json2, use_color=True):
if not other_bench:
continue
if bn['time_unit'] != other_bench['time_unit']:
continue
def get_color(res):
if res > 0.05:
return BC_FAIL
@ -94,7 +97,7 @@ def generate_difference_report(json1, json2, use_color=True):
return BC_WHITE
else:
return BC_CYAN
fmt_str = "{}{:<{}s}{endc}{}{:+9.2f}{endc}{}{:+14.2f}{endc}{:14d}{:14d}"
fmt_str = "{}{:<{}s}{endc}{}{:+9.2f}{endc}{}{:+14.2f}{endc}{:14.0f}{:14.0f}"
tres = calculate_change(bn['real_time'], other_bench['real_time'])
cpures = calculate_change(bn['cpu_time'], other_bench['cpu_time'])
output_strs += [color_format(use_color, fmt_str,
@ -126,6 +129,8 @@ class TestReportDifference(unittest.TestCase):
['BM_SameTimes', '+0.00', '+0.00', '10', '10'],
['BM_2xFaster', '-0.50', '-0.50', '50', '25'],
['BM_2xSlower', '+1.00', '+1.00', '50', '100'],
['BM_1PercentFaster', '-0.01', '-0.01', '100', '99'],
['BM_1PercentSlower', '+0.01', '+0.01', '100', '101'],
['BM_10PercentFaster', '-0.10', '-0.10', '100', '90'],
['BM_10PercentSlower', '+0.10', '+0.10', '100', '110'],
['BM_100xSlower', '+99.00', '+99.00', '100', '10000'],