8152711: Create a non-template Log wrapper class

Reviewed-by: kbarrett, rehn

hotspot/src/share/vm/gc/shared/gcTraceTime.hpp

@@ -26,6 +26,8 @@
 #define SHARE_VM_GC_SHARED_GCTRACETIME_HPP
 
 #include "logging/log.hpp"
+#include "logging/logHandle.hpp"
+#include "logging/logStream.hpp"
 #include "memory/allocation.hpp"
 #include "utilities/ticks.hpp"
 
@@ -41,10 +43,10 @@ class GCTraceCPUTime : public StackObj {
 
 class GCTimer;
 
-template <LogLevelType Level, LogTagType T0, LogTagType T1 = LogTag::__NO_TAG, LogTagType T2 = LogTag::__NO_TAG, LogTagType T3 = LogTag::__NO_TAG,
-    LogTagType T4 = LogTag::__NO_TAG, LogTagType GuardTag = LogTag::__NO_TAG>
 class GCTraceTimeImpl : public StackObj {
  private:
+  LogTargetHandle _out_start;
+  LogTargetHandle _out_stop;
   bool _enabled;
   Ticks _start_ticks;
   const char* _title;
@@ -57,10 +59,18 @@ class GCTraceTimeImpl : public StackObj {
   void time_stamp(Ticks& ticks);
 
  public:
-  GCTraceTimeImpl(const char* title, GCTimer* timer = NULL, GCCause::Cause gc_cause = GCCause::_no_gc, bool log_heap_usage = false);
+  GCTraceTimeImpl(LogTargetHandle out_start, LogTargetHandle out_end, const char* title, GCTimer* timer = NULL, GCCause::Cause gc_cause = GCCause::_no_gc, bool log_heap_usage = false);
   ~GCTraceTimeImpl();
 };
 
+template <LogLevelType Level, LogTagType T0, LogTagType T1, LogTagType T2, LogTagType T3, LogTagType T4, LogTagType GuardTag>
+class GCTraceTimeImplWrapper : public StackObj {
+  GCTraceTimeImpl _impl;
+public:
+  GCTraceTimeImplWrapper(const char* title, GCTimer* timer = NULL, GCCause::Cause gc_cause = GCCause::_no_gc, bool log_heap_usage = false);
+  ~GCTraceTimeImplWrapper();
+};
+
 // Similar to GCTraceTimeImpl but is intended for concurrent phase logging,
 // which is a bit simpler and should always print the start line, i.e. not add the "start" tag.
 template <LogLevelType Level, LogTagType T0, LogTagType T1 = LogTag::__NO_TAG, LogTagType T2 = LogTag::__NO_TAG, LogTagType T3 = LogTag::__NO_TAG,

hotspot/src/share/vm/gc/shared/gcTraceTime.inline.hpp

@@ -30,6 +30,7 @@
 #include "gc/shared/gcTrace.hpp"
 #include "gc/shared/gcTraceTime.hpp"
 #include "logging/log.hpp"
+#include "logging/logStream.inline.hpp"
 #include "memory/universe.hpp"
 #include "prims/jni_md.h"
 #include "utilities/ticks.hpp"
@@ -37,64 +38,52 @@
 #define LOG_STOP_TIME_FORMAT "(%.3fs, %.3fs) %.3fms"
 #define LOG_STOP_HEAP_FORMAT SIZE_FORMAT "M->" SIZE_FORMAT "M("  SIZE_FORMAT "M)"
 
-template <LogLevelType Level, LogTagType T0, LogTagType T1, LogTagType T2, LogTagType T3, LogTagType T4, LogTagType GuardTag >
-void GCTraceTimeImpl<Level, T0, T1, T2, T3, T4, GuardTag>::log_start(jlong start_counter) {
-  STATIC_ASSERT(T0 != LogTag::__NO_TAG); // Need some tag to log on.
-  STATIC_ASSERT(T4 == LogTag::__NO_TAG); // Need to leave at least the last tag for the "start" tag in log_start()
+inline void GCTraceTimeImpl::log_start(jlong start_counter) {
+  if (_out_start.is_enabled()) {
+    LogStream out(_out_start);
 
-  // Get log with start tag appended (replace first occurrence of NO_TAG)
-  const LogTagType start_tag = PREFIX_LOG_TAG(start);
-  const LogTagType no_tag = PREFIX_LOG_TAG(_NO_TAG);
-  LogImpl<T0,
-          T1 == no_tag ? start_tag : T1,
-          T1 != no_tag && T2 == no_tag ? start_tag : T2,
-          T2 != no_tag && T3 == no_tag ? start_tag : T3,
-          T3 != no_tag && T4 == no_tag ? start_tag : T4
-    > log;
-
-  if (log.is_level(Level)) {
-    FormatBuffer<> start_msg("%s", _title);
+    out.print("%s", _title);
     if (_gc_cause != GCCause::_no_gc) {
-      start_msg.append(" (%s)", GCCause::to_string(_gc_cause));
+      out.print(" (%s)", GCCause::to_string(_gc_cause));
     }
-    start_msg.append(" (%.3fs)", TimeHelper::counter_to_seconds(start_counter));
-    // Make sure to put the "start" tag last in the tag set
-    log.template write<Level>("%s", start_msg.buffer());
+    out.print_cr(" (%.3fs)", TimeHelper::counter_to_seconds(start_counter));
   }
 }
 
-template <LogLevelType Level, LogTagType T0, LogTagType T1, LogTagType T2, LogTagType T3, LogTagType T4, LogTagType GuardTag >
-void GCTraceTimeImpl<Level, T0, T1, T2, T3, T4, GuardTag>::log_stop(jlong start_counter, jlong stop_counter) {
+inline void GCTraceTimeImpl::log_stop(jlong start_counter, jlong stop_counter) {
   double duration_in_ms = TimeHelper::counter_to_millis(stop_counter - start_counter);
   double start_time_in_secs = TimeHelper::counter_to_seconds(start_counter);
   double stop_time_in_secs = TimeHelper::counter_to_seconds(stop_counter);
-  FormatBuffer<> stop_msg("%s", _title);
+
+  LogStream out(_out_stop);
+
+  out.print("%s", _title);
+
   if (_gc_cause != GCCause::_no_gc) {
-    stop_msg.append(" (%s)", GCCause::to_string(_gc_cause));
+    out.print(" (%s)", GCCause::to_string(_gc_cause));
   }
-  if (_heap_usage_before == SIZE_MAX) {
-    LogImpl<T0, T1, T2, T3, T4>::template write<Level>("%s " LOG_STOP_TIME_FORMAT,
-        stop_msg.buffer(), start_time_in_secs, stop_time_in_secs, duration_in_ms);
-  } else {
+
+  if (_heap_usage_before != SIZE_MAX) {
     CollectedHeap* heap = Universe::heap();
     size_t used_before_m = _heap_usage_before / M;
     size_t used_m = heap->used() / M;
     size_t capacity_m = heap->capacity() / M;
-    LogImpl<T0, T1, T2, T3, T4>::template write<Level>("%s " LOG_STOP_HEAP_FORMAT " " LOG_STOP_TIME_FORMAT,
-        stop_msg.buffer(), used_before_m, used_m, capacity_m, start_time_in_secs, stop_time_in_secs, duration_in_ms);
+    out.print(" " LOG_STOP_HEAP_FORMAT, used_before_m, used_m, capacity_m);
   }
+
+  out.print_cr(" " LOG_STOP_TIME_FORMAT, start_time_in_secs, stop_time_in_secs, duration_in_ms);
 }
 
-template <LogLevelType Level, LogTagType T0, LogTagType T1, LogTagType T2, LogTagType T3, LogTagType T4, LogTagType GuardTag >
-void GCTraceTimeImpl<Level, T0, T1, T2, T3, T4, GuardTag>::time_stamp(Ticks& ticks) {
+inline void GCTraceTimeImpl::time_stamp(Ticks& ticks) {
   if (_enabled || _timer != NULL) {
     ticks.stamp();
   }
 }
 
-template <LogLevelType Level, LogTagType T0, LogTagType T1, LogTagType T2, LogTagType T3, LogTagType T4, LogTagType GuardTag >
-GCTraceTimeImpl<Level, T0, T1, T2, T3, T4, GuardTag>::GCTraceTimeImpl(const char* title, GCTimer* timer, GCCause::Cause gc_cause, bool log_heap_usage) :
-  _enabled(LogImpl<T0, T1, T2, T3, T4, GuardTag>::is_level(Level)),
+inline GCTraceTimeImpl::GCTraceTimeImpl(LogTargetHandle out_start, LogTargetHandle out_stop, const char* title, GCTimer* timer, GCCause::Cause gc_cause, bool log_heap_usage) :
+  _enabled(out_stop.is_enabled()),
+  _out_start(out_start),
+  _out_stop(out_stop),
   _start_ticks(),
   _heap_usage_before(SIZE_MAX),
   _title(title),
@@ -113,8 +102,7 @@ GCTraceTimeImpl<Level, T0, T1, T2, T3, T4, GuardTag>::GCTraceTimeImpl(const char
   }
 }
 
-template <LogLevelType Level, LogTagType T0, LogTagType T1, LogTagType T2, LogTagType T3, LogTagType T4, LogTagType GuardTag >
-GCTraceTimeImpl<Level, T0, T1, T2, T3, T4, GuardTag>::~GCTraceTimeImpl() {
+inline GCTraceTimeImpl::~GCTraceTimeImpl() {
   Ticks stop_ticks;
   time_stamp(stop_ticks);
   if (_enabled) {
@@ -145,7 +133,34 @@ GCTraceConcTimeImpl<Level, T0, T1, T2, T3, T4, GuardTag>::~GCTraceConcTimeImpl()
   }
 }
 
-#define GCTraceTime(Level, ...) GCTraceTimeImpl<LogLevel::Level, LOG_TAGS(__VA_ARGS__)>
+// Figure out the first __NO_TAG position and replace it with 'start'.
+#define INJECT_START_TAG(T1, T2, T3, T4) \
+    ((                          T1 == LogTag::__NO_TAG) ? PREFIX_LOG_TAG(start) : T1), \
+    ((T1 != LogTag::__NO_TAG && T2 == LogTag::__NO_TAG) ? PREFIX_LOG_TAG(start) : T2), \
+    ((T2 != LogTag::__NO_TAG && T3 == LogTag::__NO_TAG) ? PREFIX_LOG_TAG(start) : T3), \
+    ((T3 != LogTag::__NO_TAG && T4 == LogTag::__NO_TAG) ? PREFIX_LOG_TAG(start) : T4)
+
+template <LogLevelType level, LogTagType T0, LogTagType T1, LogTagType T2, LogTagType T3, LogTagType T4, LogTagType GuardTag>
+GCTraceTimeImplWrapper<level, T0, T1, T2, T3, T4, GuardTag>::GCTraceTimeImplWrapper(
+    const char* title, GCTimer* timer, GCCause::Cause gc_cause, bool log_heap_usage)
+    : _impl(
+        LogTargetHandle::create<level, T0, INJECT_START_TAG(T1, T2, T3, T4), GuardTag>(),
+        LogTargetHandle::create<level, T0, T1, T2, T3, T4, GuardTag>(),
+        title,
+        timer,
+        gc_cause,
+        log_heap_usage) {
+
+  STATIC_ASSERT(T0 != LogTag::__NO_TAG); // Need some tag to log on.
+  STATIC_ASSERT(T4 == LogTag::__NO_TAG); // Need to leave at least the last tag for the "start" tag in log_start()
+}
+
+#undef INJECT_START_TAG
+
+template <LogLevelType Level, LogTagType T0, LogTagType T1, LogTagType T2, LogTagType T3, LogTagType T4, LogTagType GuardTag>
+GCTraceTimeImplWrapper<Level, T0, T1, T2, T3, T4, GuardTag>::~GCTraceTimeImplWrapper() {}
+
+#define GCTraceTime(Level, ...) GCTraceTimeImplWrapper<LogLevel::Level, LOG_TAGS(__VA_ARGS__)>
 #define GCTraceConcTime(Level, ...) GCTraceConcTimeImpl<LogLevel::Level, LOG_TAGS(__VA_ARGS__)>
 
 #endif // SHARE_VM_GC_SHARED_GCTRACETIME_INLINE_HPP

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

@@ -28,6 +28,7 @@
 
 #ifndef PRODUCT
 
+#include "gc/shared/gcTraceTime.inline.hpp"
 #include "logging/log.hpp"
 #include "logging/logConfiguration.hpp"
 #include "logging/logOutput.hpp"
@@ -370,4 +371,347 @@ void Test_logstream() {
   Test_logstream_no_rm();
 }
 
+void Test_loghandle_on() {
+  TestLogFile log_file("log_handle");
+  TestLogSavedConfig tlsc(log_file.name(), "gc=debug");
+
+  Log(gc) log;
+  LogHandle log_handle(log);
+
+  assert(log_handle.is_debug(), "assert");
+
+  // Try to log trough a LogHandle.
+  log_handle.debug("%d workers", 3);
+
+  FILE* fp = fopen(log_file.name(), "r");
+  assert(fp, "File read error");
+
+  char output[256 /* Large enough buffer */];
+  char* res = fgets(output, sizeof(output), fp);
+  assert(res != NULL, "assert");
+
+  assert(strstr(output, "3 workers") != NULL, "log line missing");
+
+  fclose(fp);
+}
+
+void Test_loghandle_off() {
+  TestLogFile log_file("log_handle");
+  TestLogSavedConfig tlsc(log_file.name(), "gc=info");
+
+  Log(gc) log;
+  LogHandle log_handle(log);
+
+  if (log_handle.is_debug()) {
+    // The log config could have been redirected gc=debug to a file. If gc=debug
+    // is enabled, we can only test that the LogTarget returns the same value
+    // as the log_is_enabled function. The rest of the test will be ignored.
+    assert(log_handle.is_debug() == log_is_enabled(Debug, gc), "assert");
+    log_warning(logging)("This test doesn't support runs with -Xlog");
+    return;
+  }
+
+  // Try to log trough a LogHandle. Should fail, since only info is turned on.
+  log_handle.debug("%d workers", 3);
+
+  // Log a dummy line so that fgets doesn't return NULL because the file is empty.
+  log_info(gc)("Dummy line");
+
+  FILE* fp = fopen(log_file.name(), "r");
+  assert(fp, "File read error");
+
+  char output[256 /* Large enough buffer */];
+  char* res = fgets(output, sizeof(output), fp);
+  assert(res != NULL, "assert");
+
+  assert(strstr(output, "3 workers") == NULL, "log line missing");
+
+  fclose(fp);
+}
+
+void Test_loghandle() {
+  Test_loghandle_on();
+  Test_loghandle_off();
+}
+
+static void Test_logtargethandle_on() {
+  TestLogFile log_file("log_handle");
+  TestLogSavedConfig tlsc(log_file.name(), "gc=debug");
+
+  LogTarget(Debug, gc) log;
+  LogTargetHandle log_handle(log);
+
+  assert(log_handle.is_enabled(), "assert");
+
+  // Try to log trough a LogHandle.
+  log_handle.print("%d workers", 3);
+
+  FILE* fp = fopen(log_file.name(), "r");
+  assert(fp, "File read error");
+
+  char output[256 /* Large enough buffer */];
+  char* res = fgets(output, sizeof(output), fp);
+  assert(res != NULL, "assert");
+
+  assert(strstr(output, "3 workers") != NULL, "log line missing");
+
+  fclose(fp);
+}
+
+static void Test_logtargethandle_off() {
+  TestLogFile log_file("log_handle");
+  TestLogSavedConfig tlsc(log_file.name(), "gc=info");
+
+  LogTarget(Debug, gc) log;
+  LogTargetHandle log_handle(log);
+
+  if (log_handle.is_enabled()) {
+    // The log config could have been redirected gc=debug to a file. If gc=debug
+    // is enabled, we can only test that the LogTarget returns the same value
+    // as the log_is_enabled function. The rest of the test will be ignored.
+    assert(log_handle.is_enabled() == log_is_enabled(Debug, gc), "assert");
+    log_warning(logging)("This test doesn't support runs with -Xlog");
+    return;
+  }
+
+  // Try to log trough a LogHandle. Should fail, since only info is turned on.
+  log_handle.print("%d workers", 3);
+
+  // Log a dummy line so that fgets doesn't return NULL because the file is empty.
+  log_info(gc)("Dummy line");
+
+  FILE* fp = fopen(log_file.name(), "r");
+  assert(fp, "File read error");
+
+  char output[256 /* Large enough buffer */];
+  char* res = fgets(output, sizeof(output), fp);
+  assert(res != NULL, "assert");
+
+  assert(strstr(output, "3 workers") == NULL, "log line missing");
+
+  fclose(fp);
+}
+
+void Test_logtargethandle() {
+  Test_logtargethandle_on();
+  Test_logtargethandle_off();
+}
+
+static void Test_log_gctracetime_full() {
+  TestLogFile log_file("log_gctracetime");
+  TestLogSavedConfig tlsc(log_file.name(), "gc=debug,gc+start=debug");
+
+  LogTarget(Debug, gc) gc_debug;
+  LogTarget(Debug, gc, start) gc_start_debug;
+
+  assert(gc_debug.is_enabled(), "assert");
+  assert(gc_start_debug.is_enabled(), "assert");
+
+  {
+    MutexLocker lock(Heap_lock); // Needed to read heap usage
+    GCTraceTime(Debug, gc) timer("Test GC", NULL, GCCause::_allocation_failure, true);
+  }
+
+  FILE* fp = fopen(log_file.name(), "r");
+  assert(fp, "File read error");
+
+  char output[256 /* Large enough buffer */];
+
+  char* res = fgets(output, sizeof(output), fp);
+  assert(res != NULL, "assert");
+
+  // [2.975s][debug][gc,start] Test GC (Allocation Failure) (2.975s)
+  assert(strstr(output, "[gc,start") != NULL, "Incorrect tag set");
+  assert(strstr(output, "] Test GC (Allocation Failure) (") != NULL, "Incorrect log line");
+  assert(strstr(output, "s)") != NULL, "Incorrect log line");
+
+  res = fgets(output, sizeof(output), fp);
+  assert(res != NULL, "assert");
+
+  // [2.975s][debug][gc      ] Test GC (Allocation Failure) 59M->59M(502M) (2.975s, 2.975s) 0.026ms
+  assert(strstr(output, "[gc ") != NULL, "Incorrect tag set");
+  assert(strstr(output, "] Test GC (Allocation Failure) ") != NULL, "Incorrect log line");
+  assert(strstr(output, "M) (") != NULL, "Incorrect log line");
+  assert(strstr(output, "s, ") != NULL, "Incorrect log line");
+  assert(strstr(output, "s) ") != NULL, "Incorrect log line");
+  assert(strstr(output, "ms") != NULL, "Incorrect log line");
+
+  fclose(fp);
+}
+
+static void Test_log_gctracetime_full_multitag() {
+  TestLogFile log_file("log_gctracetime");
+  TestLogSavedConfig tlsc(log_file.name(), "gc+ref=debug,gc+ref+start=debug");
+
+  LogTarget(Debug, gc, ref) gc_debug;
+  LogTarget(Debug, gc, ref, start) gc_start_debug;
+
+  assert(gc_debug.is_enabled(), "assert");
+  assert(gc_start_debug.is_enabled(), "assert");
+
+  {
+    MutexLocker lock(Heap_lock); // Needed to read heap usage
+    GCTraceTime(Debug, gc, ref) timer("Test GC", NULL, GCCause::_allocation_failure, true);
+  }
+
+  FILE* fp = fopen(log_file.name(), "r");
+  assert(fp, "File read error");
+
+  char output[256 /* Large enough buffer */];
+
+  char* res = fgets(output, sizeof(output), fp);
+  assert(res != NULL, "assert");
+
+  // [2.975s][debug][gc,start] Test GC (Allocation Failure) (2.975s)
+  assert(strstr(output, "[gc,ref,start") != NULL, "Incorrect tag set");
+  assert(strstr(output, "] Test GC (Allocation Failure) (") != NULL, "Incorrect log line");
+  assert(strstr(output, "s)") != NULL, "Incorrect log line");
+
+  res = fgets(output, sizeof(output), fp);
+  assert(res != NULL, "assert");
+
+  // [2.975s][debug][gc      ] Test GC (Allocation Failure) 59M->59M(502M) (2.975s, 2.975s) 0.026ms
+  assert(strstr(output, "[gc,ref ") != NULL, "Incorrect tag set");
+  assert(strstr(output, "] Test GC (Allocation Failure) ") != NULL, "Incorrect log line");
+  assert(strstr(output, "M) (") != NULL, "Incorrect log line");
+  assert(strstr(output, "s, ") != NULL, "Incorrect log line");
+  assert(strstr(output, "s) ") != NULL, "Incorrect log line");
+  assert(strstr(output, "ms") != NULL, "Incorrect log line");
+
+  fclose(fp);
+}
+
+static void Test_log_gctracetime_no_heap() {
+  TestLogFile log_file("log_gctracetime");
+  TestLogSavedConfig tlsc(log_file.name(), "gc=debug,gc+start=debug");
+
+  LogTarget(Debug, gc) gc_debug;
+  LogTarget(Debug, gc, start) gc_start_debug;
+
+  assert(gc_debug.is_enabled(), "assert");
+  assert(gc_start_debug.is_enabled(), "assert");
+
+  {
+    GCTraceTime(Debug, gc) timer("Test GC", NULL, GCCause::_allocation_failure, false);
+  }
+
+  FILE* fp = fopen(log_file.name(), "r");
+  assert(fp, "File read error");
+
+  char output[256 /* Large enough buffer */];
+
+  char* res = fgets(output, sizeof(output), fp);
+  assert(res != NULL, "assert");
+
+  // [2.975s][debug][gc,start] Test GC (Allocation Failure) (2.975s)
+  assert(strstr(output, "[gc,start") != NULL, "Incorrect tag set");
+  assert(strstr(output, "] Test GC (Allocation Failure) (") != NULL, "Incorrect log line");
+  assert(strstr(output, "s)") != NULL, "Incorrect log line");
+
+  res = fgets(output, sizeof(output), fp);
+  assert(res != NULL, "assert");
+
+  // [2.975s][debug][gc      ] Test GC (Allocation Failure) (2.975s, 2.975s) 0.026ms
+  assert(strstr(output, "[gc ") != NULL, "Incorrect tag set");
+  assert(strstr(output, "] Test GC (Allocation Failure) (") != NULL, "Incorrect log line");
+  assert(strstr(output, "M) (") == NULL, "Incorrect log line");
+  assert(strstr(output, "s, ") != NULL, "Incorrect log line");
+  assert(strstr(output, "s) ") != NULL, "Incorrect log line");
+  assert(strstr(output, "ms") != NULL, "Incorrect log line");
+
+  fclose(fp);
+}
+
+static void Test_log_gctracetime_no_cause() {
+  TestLogFile log_file("log_gctracetime");
+  TestLogSavedConfig tlsc(log_file.name(), "gc=debug,gc+start=debug");
+
+  LogTarget(Debug, gc) gc_debug;
+  LogTarget(Debug, gc, start) gc_start_debug;
+
+  assert(gc_debug.is_enabled(), "assert");
+  assert(gc_start_debug.is_enabled(), "assert");
+
+  {
+    MutexLocker lock(Heap_lock); // Needed to read heap usage
+    GCTraceTime(Debug, gc) timer("Test GC", NULL, GCCause::_no_gc, true);
+  }
+
+  FILE* fp = fopen(log_file.name(), "r");
+  assert(fp, "File read error");
+
+  char output[256 /* Large enough buffer */];
+
+  char* res = fgets(output, sizeof(output), fp);
+  assert(res != NULL, "assert");
+
+  // [2.975s][debug][gc,start] Test GC (2.975s)
+  assert(strstr(output, "[gc,start") != NULL, "Incorrect tag set");
+  assert(strstr(output, "] Test GC (") != NULL, "Incorrect log line");
+  assert(strstr(output, "s)") != NULL, "Incorrect log line");
+
+  res = fgets(output, sizeof(output), fp);
+  assert(res != NULL, "assert");
+
+  // [2.975s][debug][gc      ] Test GC 59M->59M(502M) (2.975s, 2.975s) 0.026ms
+  assert(strstr(output, "[gc ") != NULL, "Incorrect tag set");
+  assert(strstr(output, "] Test GC ") != NULL, "Incorrect log line");
+  assert(strstr(output, "M) (") != NULL, "Incorrect log line");
+  assert(strstr(output, "s, ") != NULL, "Incorrect log line");
+  assert(strstr(output, "s) ") != NULL, "Incorrect log line");
+  assert(strstr(output, "ms") != NULL, "Incorrect log line");
+
+  fclose(fp);
+}
+
+static void Test_log_gctracetime_no_heap_no_cause() {
+  TestLogFile log_file("log_gctracetime");
+  TestLogSavedConfig tlsc(log_file.name(), "gc=debug,gc+start=debug");
+
+  LogTarget(Debug, gc) gc_debug;
+  LogTarget(Debug, gc, start) gc_start_debug;
+
+  assert(gc_debug.is_enabled(), "assert");
+  assert(gc_start_debug.is_enabled(), "assert");
+
+  {
+    MutexLocker lock(Heap_lock); // Needed to read heap usage
+    GCTraceTime(Debug, gc) timer("Test GC", NULL, GCCause::_no_gc, false);
+  }
+
+  FILE* fp = fopen(log_file.name(), "r");
+  assert(fp, "File read error");
+
+  char output[256 /* Large enough buffer */];
+
+  char* res = fgets(output, sizeof(output), fp);
+  assert(res != NULL, "assert");
+
+  // [2.975s][debug][gc,start] Test GC (2.975s)
+  assert(strstr(output, "[gc,start") != NULL, "Incorrect tag set");
+  assert(strstr(output, "] Test GC (") != NULL, "Incorrect log line");
+  assert(strstr(output, "s)") != NULL, "Incorrect log line");
+
+  res = fgets(output, sizeof(output), fp);
+  assert(res != NULL, "assert");
+
+  // [2.975s][debug][gc      ] Test GC (2.975s, 2.975s) 0.026ms
+  assert(strstr(output, "[gc ") != NULL, "Incorrect tag set");
+  assert(strstr(output, "] Test GC (") != NULL, "Incorrect log line");
+  assert(strstr(output, "M) (") == NULL, "Incorrect log line");
+  assert(strstr(output, "s, ") != NULL, "Incorrect log line");
+  assert(strstr(output, "s) ") != NULL, "Incorrect log line");
+  assert(strstr(output, "ms") != NULL, "Incorrect log line");
+
+  fclose(fp);
+}
+
+void Test_log_gctracetime() {
+  Test_log_gctracetime_full();
+  Test_log_gctracetime_full_multitag();
+  Test_log_gctracetime_no_heap();
+  Test_log_gctracetime_no_cause();
+  Test_log_gctracetime_no_heap_no_cause();
+}
+
 #endif // PRODUCT

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

@@ -0,0 +1,105 @@
+/*
+ * Copyright (c) 2016, Oracle and/or its affiliates. All rights reserved.
+ * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
+ *
+ * This code is free software; you can redistribute it and/or modify it
+ * under the terms of the GNU General Public License version 2 only, as
+ * published by the Free Software Foundation.
+ *
+ * This code is distributed in the hope that it will be useful, but WITHOUT
+ * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
+ * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
+ * version 2 for more details (a copy is included in the LICENSE file that
+ * accompanied this code).
+ *
+ * You should have received a copy of the GNU General Public License version
+ * 2 along with this work; if not, write to the Free Software Foundation,
+ * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
+ *
+ * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
+ * or visit www.oracle.com if you need additional information or have any
+ * questions.
+ *
+ */
+#ifndef SHARE_VM_LOGGING_LOGHANDLE_HPP
+#define SHARE_VM_LOGGING_LOGHANDLE_HPP
+
+#include "logging/log.hpp"
+
+// Wraps a Log instance and throws away the template information.
+//
+// This can be used to pass a Log instance as a parameter without
+// polluting the surrounding API with template functions.
+class LogHandle {
+private:
+  LogTagSet* _tagset;
+
+public:
+  template <LogTagType T0, LogTagType T1, LogTagType T2, LogTagType T3, LogTagType T4, LogTagType GuardTag>
+  LogHandle(const LogImpl<T0, T1, T2, T3, T4, GuardTag>& type_carrier) :
+      _tagset(&LogTagSetMapping<T0, T1, T2, T3, T4>::tagset()) {}
+
+  bool is_level(LogLevelType level) {
+    return _tagset->is_level(level);
+  }
+
+#define LOG_LEVEL(level, name) ATTRIBUTE_PRINTF(2, 0)   \
+  LogHandle& v##name(const char* fmt, va_list args) { \
+    _tagset->vwrite(LogLevel::level, fmt, args); \
+    return *this; \
+  } \
+  LogHandle& name(const char* fmt, ...) ATTRIBUTE_PRINTF(2, 3) { \
+    va_list args; \
+    va_start(args, fmt); \
+    _tagset->vwrite(LogLevel::level, fmt, args); \
+    va_end(args); \
+    return *this; \
+  } \
+  bool is_##name() { \
+    return _tagset->is_level(LogLevel::level); \
+  }
+  LOG_LEVEL_LIST
+#undef LOG_LEVEL
+};
+
+// Wraps a LogTarget instance and throws away the template information.
+//
+// This can be used to pass a Log instance as a parameter without
+// polluting the surrounding API with template functions.
+class LogTargetHandle {
+  friend class LogStream;
+
+private:
+  const LogLevelType _level;
+  LogTagSet*         _tagset;
+
+public:
+  template <LogLevelType level, LogTagType T0, LogTagType T1, LogTagType T2, LogTagType T3, LogTagType T4, LogTagType GuardTag>
+  LogTargetHandle(const LogTargetImpl<level, T0, T1, T2, T3, T4, GuardTag>& type_carrier) :
+      _level(level),
+      _tagset(&LogTagSetMapping<T0, T1, T2, T3, T4>::tagset()) {}
+
+  template <LogLevelType level, LogTagType T0, LogTagType T1, LogTagType T2, LogTagType T3, LogTagType T4, LogTagType GuardTag>
+  static LogTargetHandle create() {
+    return LogTargetHandle(LogTargetImpl<level, T0, T1, T2, T3, T4, GuardTag>());
+  }
+
+  void print(const char* fmt, ...) ATTRIBUTE_PRINTF(2, 3) {
+    va_list args;
+    va_start(args, fmt);
+    _tagset->vwrite(_level, fmt, args);
+    va_end(args);
+  }
+
+  bool is_enabled() const {
+    return _tagset->is_level(_level);
+  }
+
+  // Creates a log stream from the information stored in this instance.
+  // Callers need a ResourceMark on the stack.
+  outputStream* stream() {
+    return create_log_stream(_level, _tagset);;
+  }
+};
+
+#endif // SHARE_VM_LOGGING_LOGHANDLE_HPP

hotspot/src/share/vm/logging/logStream.inline.hpp

@@ -25,6 +25,7 @@
 #define SHARE_VM_LOGGING_LOGSTREAM_INLINE_HPP
 
 #include "logging/log.hpp"
+#include "logging/logHandle.hpp"
 #include "logging/logStream.hpp"
 #include "memory/resourceArea.hpp"
 #include "utilities/ostream.hpp"
@@ -68,6 +69,15 @@ public:
       _embedded_resource_mark(),
       _stream(level, &LogTagSetMapping<T0, T1, T2, T3, T4>::tagset()) {}
 
+  // Constructor to support creation from a LogTargetHandle.
+  //
+  // LogTarget(Debug, gc) log;
+  // LogTargetHandle(log) handle;
+  // LogStream stream(handle);
+  LogStream(LogTargetHandle handle) :
+      _embedded_resource_mark(),
+      _stream(handle._level, handle._tagset) {}
+
   // Override of outputStream::write.
   void write(const char* s, size_t len) { _stream.write(s, len); }
 };

hotspot/src/share/vm/utilities/internalVMTests.cpp

@@ -69,6 +69,9 @@ void InternalVMTests::run() {
   run_unit_test(JSON_test);
   run_unit_test(Test_logtarget);
   run_unit_test(Test_logstream);
+  run_unit_test(Test_loghandle);
+  run_unit_test(Test_logtargethandle);
+  run_unit_test(Test_log_gctracetime);
   run_unit_test(Test_configure_stdout);
   run_unit_test(Test_logconfiguration_subscribe);
   run_unit_test(Test_log_prefix);