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

2 files changed, 46 insertions, 22 deletions

diff --git a/src/timers.cc b/src/timers.cc
index 7613ff9..221b594 100644
--- a/src/timers.cc
+++ b/src/timers.cc
@@ -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.
-  return std::string(storage);
-}
 
-}  // end namespace
+  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::string LocalDateTimeString() { return DateTimeString(true); }
+  std::strncat(storage, tz_offset, kTzOffsetLen + 1);
+  return std::string(storage);
+}
 
 }  // end namespace benchmark
diff --git a/test/reporter_output_test.cc b/test/reporter_output_test.cc
index 1a96b5f..d806a4e 100644
--- a/test/reporter_output_test.cc
+++ b/test/reporter_output_test.cc
@@ -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},
            });