--- a/hotspot/src/share/vm/gc/shared/gcTraceTime.hpp Tue Apr 05 10:35:39 2016 +0200
+++ b/hotspot/src/share/vm/gc/shared/gcTraceTime.hpp Tue Apr 05 10:41:52 2016 +0200
@@ -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 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 @@
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,
--- a/hotspot/src/share/vm/gc/shared/gcTraceTime.inline.hpp Tue Apr 05 10:35:39 2016 +0200
+++ b/hotspot/src/share/vm/gc/shared/gcTraceTime.inline.hpp Tue Apr 05 10:41:52 2016 +0200
@@ -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 @@
}
}
-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 @@
}
}
-#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
--- a/hotspot/src/share/vm/logging/log.cpp Tue Apr 05 10:35:39 2016 +0200
+++ b/hotspot/src/share/vm/logging/log.cpp Tue Apr 05 10:41:52 2016 +0200
@@ -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 @@
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
--- /dev/null Thu Jan 01 00:00:00 1970 +0000
+++ b/hotspot/src/share/vm/logging/logHandle.hpp Tue Apr 05 10:41:52 2016 +0200
@@ -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
--- a/hotspot/src/share/vm/logging/logStream.inline.hpp Tue Apr 05 10:35:39 2016 +0200
+++ b/hotspot/src/share/vm/logging/logStream.inline.hpp Tue Apr 05 10:41:52 2016 +0200
@@ -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 @@
_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); }
};
--- a/hotspot/src/share/vm/utilities/internalVMTests.cpp Tue Apr 05 10:35:39 2016 +0200
+++ b/hotspot/src/share/vm/utilities/internalVMTests.cpp Tue Apr 05 10:41:52 2016 +0200
@@ -69,6 +69,9 @@
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);