8166117: Add UTC timestamp decorator for UL

Reviewed-by: rehn, rprotacio

hotspot/src/os/posix/vm/os_posix.cpp

@@ -188,6 +188,10 @@ int os::get_fileno(FILE* fp) {
   return NOT_AIX(::)fileno(fp);
 }
 
+struct tm* os::gmtime_pd(const time_t* clock, struct tm*  res) {
+  return gmtime_r(clock, res);
+}
+
 void os::Posix::print_load_average(outputStream* st) {
   st->print("load average:");
   double loadavg[3];

hotspot/src/os/windows/vm/os_windows.cpp

@@ -403,6 +403,15 @@ struct tm* os::localtime_pd(const time_t* clock, struct tm* res) {
   return NULL;
 }
 
+struct tm* os::gmtime_pd(const time_t* clock, struct tm* res) {
+  const struct tm* time_struct_ptr = gmtime(clock);
+  if (time_struct_ptr != NULL) {
+    *res = *time_struct_ptr;
+    return res;
+  }
+  return NULL;
+}
+
 LONG WINAPI topLevelExceptionFilter(struct _EXCEPTION_POINTERS* exceptionInfo);
 
 // Thread start routine for all newly created threads

hotspot/src/share/vm/logging/logDecorations.cpp

@@ -72,6 +72,12 @@ char* LogDecorations::create_time_decoration(char* pos) {
   ASSERT_AND_RETURN(written, pos)
 }
 
+char* LogDecorations::create_utctime_decoration(char* pos) {
+  char* buf = os::iso8601_time(pos, 29, true);
+  int written = buf == NULL ? -1 : 29;
+  ASSERT_AND_RETURN(written, pos)
+}
+
 char * LogDecorations::create_uptime_decoration(char* pos) {
   int written = jio_snprintf(pos, DecorationsBufferSize - (pos - _decorations_buffer), "%.3fs", os::elapsedTime());
   ASSERT_AND_RETURN(written, pos)

hotspot/src/share/vm/logging/logDecorators.hpp

@@ -41,6 +41,7 @@
 // tags         - The tag-set associated with the log message
 #define DECORATOR_LIST          \
   DECORATOR(time,         t)    \
+  DECORATOR(utctime,      utc)  \
   DECORATOR(uptime,       u)    \
   DECORATOR(timemillis,   tm)   \
   DECORATOR(uptimemillis, um)   \

hotspot/src/share/vm/runtime/os.cpp

@@ -97,7 +97,7 @@ void os_init_globals() {
 // except that on Windows the %z behaves badly, so we do it ourselves.
 // Also, people wanted milliseconds on there,
 // and strftime doesn't do milliseconds.
-char* os::iso8601_time(char* buffer, size_t buffer_length) {
+char* os::iso8601_time(char* buffer, size_t buffer_length, bool utc) {
   // Output will be of the form "YYYY-MM-DDThh:mm:ss.mmm+zzzz\0"
   //                                      1         2
   //                             12345678901234567890123456789
@@ -122,9 +122,16 @@ char* os::iso8601_time(char* buffer, size_t buffer_length) {
     milliseconds_since_19700101 % milliseconds_per_microsecond;
   // Convert the time value to a tm and timezone variable
   struct tm time_struct;
-  if (localtime_pd(&seconds_since_19700101, &time_struct) == NULL) {
-    assert(false, "Failed localtime_pd");
-    return NULL;
+  if (utc) {
+    if (gmtime_pd(&seconds_since_19700101, &time_struct) == NULL) {
+      assert(false, "Failed gmtime_pd");
+      return NULL;
+    }
+  } else {
+    if (localtime_pd(&seconds_since_19700101, &time_struct) == NULL) {
+      assert(false, "Failed localtime_pd");
+      return NULL;
+    }
   }
 #if defined(_ALLBSD_SOURCE)
   const time_t zone = (time_t) time_struct.tm_gmtoff;
@@ -141,6 +148,12 @@ char* os::iso8601_time(char* buffer, size_t buffer_length) {
   if (time_struct.tm_isdst > 0) {
     UTC_to_local = UTC_to_local - seconds_per_hour;
   }
+
+  // No offset when dealing with UTC
+  if (utc) {
+    UTC_to_local = 0;
+  }
+
   // Compute the time zone offset.
   //    localtime_pd() sets timezone to the difference (in seconds)
   //    between UTC and and local time.

hotspot/src/share/vm/runtime/os.hpp

@@ -197,10 +197,11 @@ class os: AllStatic {
   // information may require a lock on some platforms.
   static char*      local_time_string(char *buf, size_t buflen);
   static struct tm* localtime_pd     (const time_t* clock, struct tm*  res);
+  static struct tm* gmtime_pd        (const time_t* clock, struct tm*  res);
   // Fill in buffer with current local time as an ISO-8601 string.
   // E.g., YYYY-MM-DDThh:mm:ss.mmm+zzzz.
   // Returns buffer, or NULL if it failed.
-  static char* iso8601_time(char* buffer, size_t buffer_length);
+  static char* iso8601_time(char* buffer, size_t buffer_length, bool utc = false);
 
   // Interface for detecting multiprocessor system
   static inline bool is_MP() {

hotspot/test/native/logging/test_logDecorations.cpp

@@ -133,8 +133,8 @@ TEST(LogDecorations, iso8601_time) {
   // Verify format
   int y, M, d, h, m;
   double s;
-  int read = sscanf(timestr, "%d-%d-%dT%d:%d:%lfZ", &y, &M, &d, &h, &m, &s);
-  ASSERT_EQ(6, read);
+  int read = sscanf(timestr, "%d-%d-%dT%d:%d:%lf", &y, &M, &d, &h, &m, &s);
+  ASSERT_EQ(6, read) << "Invalid format: " << timestr;
 
   // Verify reported time & date
   struct tm reported_time = {0};
@@ -156,6 +156,48 @@ TEST(LogDecorations, iso8601_time) {
       << ", expected time: " << expected_ts;
 }
 
+// Test the utctime decoration
+TEST(LogDecorations, iso8601_utctime) {
+  LogDecorators decorator_selection;
+  ASSERT_TRUE(decorator_selection.parse("utctime"));
+  LogDecorations decorations(LogLevel::Info, tagset, decorator_selection);
+
+  const char *timestr = decorations.decoration(LogDecorators::utctime_decorator);
+  time_t expected_ts = time(NULL);
+
+  // Verify format
+  char trailing_character;
+  int y, M, d, h, m, offset;
+  double s;
+  int read = sscanf(timestr, "%d-%d-%dT%d:%d:%lf%c%d", &y, &M, &d, &h, &m, &s, &trailing_character, &offset);
+  ASSERT_GT(read, 7) << "Invalid format: " << timestr;
+
+  // Ensure time is UTC (no offset)
+  if (trailing_character == '+') {
+    ASSERT_EQ(0, offset) << "Invalid offset: " << timestr;
+  } else {
+    ASSERT_EQ('Z', trailing_character) << "Invalid offset: " << timestr;
+  }
+
+  struct tm reported_time = {0};
+  reported_time.tm_year = y - 1900;
+  reported_time.tm_mon = M - 1;
+  reported_time.tm_mday = d;
+  reported_time.tm_hour = h;
+  reported_time.tm_min = m;
+  reported_time.tm_sec = s;
+  reported_time.tm_isdst = 0; // No DST for UTC timestamps
+  time_t reported_ts = mktime(&reported_time);
+  expected_ts = mktime(gmtime(&expected_ts));
+  time_t diff = reported_ts - expected_ts;
+  if (diff < 0) {
+    diff = -diff;
+  }
+  // Allow up to 10 seconds in difference
+  ASSERT_LE(diff, 10) << "Reported time: " << reported_ts << " (" << timestr << ")"
+      << ", expected time: " << expected_ts;
+}
+
 // Test the pid and tid decorations
 TEST(LogDecorations, identifiers) {
   LogDecorators decorator_selection;

hotspot/test/native/logging/test_logDecorators.cpp

@@ -172,20 +172,20 @@ TEST(LogDecorators, combine_with) {
 
   // Select first and third decorator for dec1
   char input[64];
-  sprintf(input, "%s,%s", decorator_name_array[0], decorator_name_array[2]);
+  sprintf(input, "%s,%s", decorator_name_array[0], decorator_name_array[3]);
   dec1.parse(input);
   EXPECT_TRUE(dec1.is_decorator(decorator_array[0]));
-  EXPECT_TRUE(dec1.is_decorator(decorator_array[2]));
+  EXPECT_TRUE(dec1.is_decorator(decorator_array[3]));
 
   // Select the default decorators for dec2
   EXPECT_FALSE(dec2.is_decorator(decorator_array[0]));
-  EXPECT_FALSE(dec2.is_decorator(decorator_array[2]));
+  EXPECT_FALSE(dec2.is_decorator(decorator_array[3]));
   assert_default_decorators(&dec2);
 
   // Combine and verify that the combination includes first, third and default decorators
   dec2.combine_with(dec1);
   EXPECT_TRUE(dec2.is_decorator(decorator_array[0]));
-  EXPECT_TRUE(dec2.is_decorator(decorator_array[2]));
+  EXPECT_TRUE(dec2.is_decorator(decorator_array[3]));
   assert_default_decorators(&dec2, false);
 }