use rfc3339-formatted timestamps in output [output format change] (#965)

* timestamp: use rfc3339-formatted timestamps in output

Replace localized timestamps with machine-readable IETF RFC 3339 format
timestamps. This is an attempt to make the output timestamps easily
machine-readable. ISO8601 specifies standards for time interchange
formats. IETF RFC 3339: https://tools.ietf.org/html/rfc3339 defines a
subset of these for use in the internet. The general form for these
timestamps is:

YYYY-MM-DDTHH:mm:SS[+-]hhmm

This replaces the localized time formats that are currently being used
in the benchmark output to prioritize interchangeability and
machine-readability.

This might break existing programs that rely on the particular date-time
format. This might also may make times less human readable. RFC3339 was
intended to balance human readability and simplicity for machine
readability, but it is primarily intended as an internal representation.

* timers: remove utc string formatting

We only ever need local time printing. Remove the UTC printing
and cosnolidate the logic slightly.

* timers: manually create rfc3339 string

The C++ standard library does not output the time offset in RFC3339
format, it is missing the : between hours and minutes. VS does not
appear to support timezone information by default. To avoid adding too
much complexity to benchmark around timezone handling e.g. a full
date library like https://github.com/HowardHinnant/date, we fall back
to outputting GMT time with a -00:00 offset for those cases.

* timers: use reentrant form for localtime_r & tmtime_r

For non-windows, use the reentrant form for the time conversion
functions.

* timers: cleanup

Use strtol instead of brittle moving characters around.

* timers: only call strftime twice.

Also size buffers to known maximum necessary size and name constants
more appropriately.

* timers: fix unused variable warning
This commit is contained in:
Brian Wolfe 2020-06-15 09:28:17 -07:00 committed by GitHub
parent 8039b40307
commit 99c52f1414
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
2 changed files with 46 additions and 22 deletions

View File

@ -178,40 +178,64 @@ double ThreadCPUUsage() {
#endif
}
namespace {
std::string DateTimeString(bool local) {
std::string LocalDateTimeString() {
// Write the local time in RFC3339 format yyyy-mm-ddTHH:MM:SS+/-HH:MM.
typedef std::chrono::system_clock Clock;
std::time_t now = Clock::to_time_t(Clock::now());
const std::size_t kStorageSize = 128;
char storage[kStorageSize];
std::size_t written;
const std::size_t kTzOffsetLen = 6;
const std::size_t kTimestampLen = 19;
std::size_t tz_len;
std::size_t timestamp_len;
long int offset_minutes;
char tz_offset_sign = '+';
char tz_offset[kTzOffsetLen + 1];
char storage[kTimestampLen + kTzOffsetLen + 1];
if (local) {
#if defined(BENCHMARK_OS_WINDOWS)
written =
std::strftime(storage, sizeof(storage), "%x %X", ::localtime(&now));
std::tm *timeinfo_p = ::localtime(&now);
#else
std::tm timeinfo;
::localtime_r(&now, &timeinfo);
written = std::strftime(storage, sizeof(storage), "%F %T", &timeinfo);
std::tm timeinfo;
std::tm *timeinfo_p = &timeinfo;
::localtime_r(&now, &timeinfo);
#endif
tz_len = std::strftime(tz_offset, sizeof(tz_offset), "%z", timeinfo_p);
if (tz_len < kTzOffsetLen && tz_len > 1) {
// Timezone offset was written. strftime writes offset as +HHMM or -HHMM,
// RFC3339 specifies an offset as +HH:MM or -HH:MM. To convert, we parse
// the offset as an integer, then reprint it to a string.
offset_minutes = ::strtol(tz_offset, NULL, 10);
if (offset_minutes < 0) {
offset_minutes *= -1;
tz_offset_sign = '-';
}
tz_len = ::sprintf(tz_offset, "%c%02li:%02li", tz_offset_sign,
offset_minutes / 100, offset_minutes % 100);
CHECK(tz_len == 6);
((void)tz_len); // Prevent unused variable warning in optimized build.
} else {
// Unknown offset. RFC3339 specifies that unknown local offsets should be
// written as UTC time with -00:00 timezone.
#if defined(BENCHMARK_OS_WINDOWS)
written = std::strftime(storage, sizeof(storage), "%x %X", ::gmtime(&now));
// Potential race condition if another thread calls localtime or gmtime.
timeinfo_p = ::gmtime(&now);
#else
std::tm timeinfo;
::gmtime_r(&now, &timeinfo);
written = std::strftime(storage, sizeof(storage), "%F %T", &timeinfo);
#endif
strncpy(tz_offset, "-00:00", kTzOffsetLen + 1);
}
CHECK(written < kStorageSize);
((void)written); // prevent unused variable in optimized mode.
timestamp_len = std::strftime(storage, sizeof(storage), "%Y-%m-%dT%H:%M:%S",
timeinfo_p);
CHECK(timestamp_len == kTimestampLen);
((void)timestamp_len); // Prevent unused variable warning in optimized build.
std::strncat(storage, tz_offset, kTzOffsetLen + 1);
return std::string(storage);
}
} // end namespace
std::string LocalDateTimeString() { return DateTimeString(true); }
} // end namespace benchmark

View File

@ -15,7 +15,7 @@ ADD_CASES(TC_ConsoleOut, {{"^[-]+$", MR_Next},
static int AddContextCases() {
AddCases(TC_ConsoleErr,
{
{"%int[-/]%int[-/]%int %int:%int:%int$", MR_Default},
{"^%int-%int-%intT%int:%int:%int[-+]%int:%int$", MR_Default},
{"Running .*/reporter_output_test(\\.exe)?$", MR_Next},
{"Run on \\(%int X %float MHz CPU s?\\)", MR_Next},
});