# HG changeset patch # User mlarsson # Date 1477037891 -7200 # Node ID 46f6db750b176c0a75f384a5539e00af6413b4a9 # Parent 6032b31e37196c62737678ae08d5584d7def681b 8166117: Add UTC timestamp decorator for UL Reviewed-by: rehn, rprotacio diff -r 6032b31e3719 -r 46f6db750b17 hotspot/src/os/posix/vm/os_posix.cpp --- a/hotspot/src/os/posix/vm/os_posix.cpp Thu Oct 13 14:49:34 2016 +0200 +++ b/hotspot/src/os/posix/vm/os_posix.cpp Fri Oct 21 10:18:11 2016 +0200 @@ -188,6 +188,10 @@ 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]; diff -r 6032b31e3719 -r 46f6db750b17 hotspot/src/os/windows/vm/os_windows.cpp --- a/hotspot/src/os/windows/vm/os_windows.cpp Thu Oct 13 14:49:34 2016 +0200 +++ b/hotspot/src/os/windows/vm/os_windows.cpp Fri Oct 21 10:18:11 2016 +0200 @@ -403,6 +403,15 @@ 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 diff -r 6032b31e3719 -r 46f6db750b17 hotspot/src/share/vm/logging/logDecorations.cpp --- a/hotspot/src/share/vm/logging/logDecorations.cpp Thu Oct 13 14:49:34 2016 +0200 +++ b/hotspot/src/share/vm/logging/logDecorations.cpp Fri Oct 21 10:18:11 2016 +0200 @@ -72,6 +72,12 @@ 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) diff -r 6032b31e3719 -r 46f6db750b17 hotspot/src/share/vm/logging/logDecorators.hpp --- a/hotspot/src/share/vm/logging/logDecorators.hpp Thu Oct 13 14:49:34 2016 +0200 +++ b/hotspot/src/share/vm/logging/logDecorators.hpp Fri Oct 21 10:18:11 2016 +0200 @@ -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) \ diff -r 6032b31e3719 -r 46f6db750b17 hotspot/src/share/vm/runtime/os.cpp --- a/hotspot/src/share/vm/runtime/os.cpp Thu Oct 13 14:49:34 2016 +0200 +++ b/hotspot/src/share/vm/runtime/os.cpp Fri Oct 21 10:18:11 2016 +0200 @@ -97,7 +97,7 @@ // 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 @@ 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 @@ 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. diff -r 6032b31e3719 -r 46f6db750b17 hotspot/src/share/vm/runtime/os.hpp --- a/hotspot/src/share/vm/runtime/os.hpp Thu Oct 13 14:49:34 2016 +0200 +++ b/hotspot/src/share/vm/runtime/os.hpp Fri Oct 21 10:18:11 2016 +0200 @@ -197,10 +197,11 @@ // 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() { diff -r 6032b31e3719 -r 46f6db750b17 hotspot/test/native/logging/test_logDecorations.cpp --- a/hotspot/test/native/logging/test_logDecorations.cpp Thu Oct 13 14:49:34 2016 +0200 +++ b/hotspot/test/native/logging/test_logDecorations.cpp Fri Oct 21 10:18:11 2016 +0200 @@ -133,8 +133,8 @@ // 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 @@ << ", 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; diff -r 6032b31e3719 -r 46f6db750b17 hotspot/test/native/logging/test_logDecorators.cpp --- a/hotspot/test/native/logging/test_logDecorators.cpp Thu Oct 13 14:49:34 2016 +0200 +++ b/hotspot/test/native/logging/test_logDecorators.cpp Fri Oct 21 10:18:11 2016 +0200 @@ -172,20 +172,20 @@ // 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); }