Print at least three significant digits for times. (#701)

Some benchmarks are particularly sensitive and they run in less than
a nanosecond. In order for the console reporter to provide meaningful
output for such benchmarks it needs to be able to display the times
using more resolution than a single nanosecond.

This patch changes the console reporter to print at least three
significant digits for all results.

Unlike the initial attempt, this patch does not align the decimal point.
This commit is contained in:
Eric 2018-12-13 22:49:21 -05:00 committed by GitHub
parent 57bf879d49
commit 4528c76b71
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
3 changed files with 31 additions and 12 deletions

View File

@ -53,7 +53,7 @@ bool ConsoleReporter::ReportContext(const Context& context) {
}
void ConsoleReporter::PrintHeader(const Run& run) {
std::string str = FormatString("%-*s %13s %13s %10s", static_cast<int>(name_field_width_),
std::string str = FormatString("%-*s %13s %15s %12s", static_cast<int>(name_field_width_),
"Benchmark", "Time", "CPU", "Iterations");
if(!run.counters.empty()) {
if(output_options_ & OO_Tabular) {
@ -98,6 +98,21 @@ static void IgnoreColorPrint(std::ostream& out, LogColor, const char* fmt,
va_end(args);
}
static std::string FormatTime(double time) {
// Align decimal places...
if (time < 1.0) {
return FormatString("%10.3f", time);
}
if (time < 10.0) {
return FormatString("%10.2f", time);
}
if (time < 100.0) {
return FormatString("%10.1f", time);
}
return FormatString("%10.0f", time);
}
void ConsoleReporter::PrintRunData(const Run& result) {
typedef void(PrinterFn)(std::ostream&, LogColor, const char*, ...);
auto& Out = GetOutputStream();
@ -117,18 +132,21 @@ void ConsoleReporter::PrintRunData(const Run& result) {
const double real_time = result.GetAdjustedRealTime();
const double cpu_time = result.GetAdjustedCPUTime();
const std::string real_time_str = FormatTime(real_time);
const std::string cpu_time_str = FormatTime(cpu_time);
if (result.report_big_o) {
std::string big_o = GetBigOString(result.complexity);
printer(Out, COLOR_YELLOW, "%10.2f %s %10.2f %s ", real_time, big_o.c_str(),
printer(Out, COLOR_YELLOW, "%10.2f %-4s %10.2f %-4s ", real_time, big_o.c_str(),
cpu_time, big_o.c_str());
} else if (result.report_rms) {
printer(Out, COLOR_YELLOW, "%10.0f %% %10.0f %% ", real_time * 100,
cpu_time * 100);
printer(Out, COLOR_YELLOW, "%10.0f %-4s %10.0f %-4s ", real_time * 100, "%",
cpu_time * 100, "%");
} else {
const char* timeLabel = GetTimeUnitString(result.time_unit);
printer(Out, COLOR_YELLOW, "%10.0f %s %10.0f %s ", real_time, timeLabel,
cpu_time, timeLabel);
printer(Out, COLOR_YELLOW, "%s %-4s %s %-4s ", real_time_str.c_str(), timeLabel,
cpu_time_str.c_str(), timeLabel);
}
if (!result.report_big_o && !result.report_rms) {

View File

@ -39,17 +39,18 @@ SubMap& GetSubstitutions() {
// Don't use 'dec_re' from header because it may not yet be initialized.
// clang-format off
static std::string safe_dec_re = "[0-9]*[.]?[0-9]+([eE][-+][0-9]+)?";
static std::string time_re = "([0-9]+[.])?[0-9]+";
static SubMap map = {
{"%float", "[0-9]*[.]?[0-9]+([eE][-+][0-9]+)?"},
// human-readable float
{"%hrfloat", "[0-9]*[.]?[0-9]+([eE][-+][0-9]+)?[kMGTPEZYmunpfazy]?"},
{"%int", "[ ]*[0-9]+"},
{" %s ", "[ ]+"},
{"%time", "[ ]*[0-9]+ ns"},
{"%console_report", "[ ]*[0-9]+ ns [ ]*[0-9]+ ns [ ]*[0-9]+"},
{"%console_time_only_report", "[ ]*[0-9]+ ns [ ]*[0-9]+ ns"},
{"%console_us_report", "[ ]*[0-9]+ us [ ]*[0-9]+ us [ ]*[0-9]+"},
{"%console_us_time_only_report", "[ ]*[0-9]+ us [ ]*[0-9]+ us"},
{"%time", "[ ]*" + time_re + "[ ]+ns"},
{"%console_report", "[ ]*" + time_re + "[ ]+ns [ ]*" + time_re + "[ ]+ns [ ]*[0-9]+"},
{"%console_time_only_report", "[ ]*" + time_re + "[ ]+ns [ ]*" + time_re + "[ ]+ns"},
{"%console_us_report", "[ ]*" + time_re + "[ ]+us [ ]*" + time_re + "[ ]+us [ ]*[0-9]+"},
{"%console_us_time_only_report", "[ ]*" + time_re + "[ ]+us [ ]*" + time_re + "[ ]+us"},
{"%csv_header",
"name,iterations,real_time,cpu_time,time_unit,bytes_per_second,"
"items_per_second,label,error_occurred,error_message"},

View File

@ -534,7 +534,7 @@ ADD_CASES(TC_ConsoleOut, {{"^BM_UserStats/iterations:5/repeats:3/manual_time [ "
{"^BM_UserStats/iterations:5/repeats:3/"
"manual_time_median [ ]* 150 ns %time [ ]*3$"},
{"^BM_UserStats/iterations:5/repeats:3/"
"manual_time_stddev [ ]* 0 ns %time [ ]*3$"},
"manual_time_stddev [ ]* 0.000 ns %time [ ]*3$"},
{"^BM_UserStats/iterations:5/repeats:3/manual_time_ "
"[ ]* 150 ns %time [ ]*3$"}});
ADD_CASES(