< prev index next >
src/share/vm/gc/shared/gcTraceTime.hpp
Print this page
*** 23,55 ****
*/
#ifndef SHARE_VM_GC_SHARED_GCTRACETIME_HPP
#define SHARE_VM_GC_SHARED_GCTRACETIME_HPP
#include "gc/shared/gcTrace.hpp"
#include "memory/allocation.hpp"
#include "prims/jni_md.h"
#include "utilities/ticks.hpp"
! class GCTimer;
! class GCTraceTimeImpl VALUE_OBJ_CLASS_SPEC {
const char* _title;
! bool _doit;
! bool _print_cr;
GCTimer* _timer;
! Ticks _start_counter;
public:
! GCTraceTimeImpl(const char* title, bool doit, bool print_cr, GCTimer* timer);
! ~GCTraceTimeImpl();
};
! class GCTraceTime : public StackObj {
! GCTraceTimeImpl _gc_trace_time_impl;
!
public:
! GCTraceTime(const char* title, bool doit, bool print_cr, GCTimer* timer) :
! _gc_trace_time_impl(title, doit, print_cr, timer) {};
};
#endif // SHARE_VM_GC_SHARED_GCTRACETIME_HPP
--- 23,181 ----
*/
#ifndef SHARE_VM_GC_SHARED_GCTRACETIME_HPP
#define SHARE_VM_GC_SHARED_GCTRACETIME_HPP
+ #include "gc/shared/collectedHeap.hpp"
+ #include "gc/shared/gcTimer.hpp"
#include "gc/shared/gcTrace.hpp"
+ #include "logging/log.hpp"
#include "memory/allocation.hpp"
+ #include "memory/resourceArea.hpp"
+ #include "memory/universe.hpp"
#include "prims/jni_md.h"
#include "utilities/ticks.hpp"
+ #include "runtime/timer.hpp"
+ #include "utilities/ticks.hpp"
! class GCTraceCPUTime : public StackObj {
! bool _active; // true if times will be measured and printed
! double _starting_user_time; // user time at start of measurement
! double _starting_system_time; // system time at start of measurement
! double _starting_real_time; // real time at start of measurement
! public:
! GCTraceCPUTime();
! ~GCTraceCPUTime();
! };
! #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 = 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:
! bool _enabled;
! Ticks _start_ticks;
const char* _title;
! GCCause::Cause _gc_cause;
GCTimer* _timer;
! size_t _heap_usage_before;
!
! void log_start(jlong start_counter) {
! if (Log<LogTag::start, T0, T1, T2, T3>::is_level(Level)) {
! FormatBuffer<> start_msg("%s", _title);
! if (_gc_cause != GCCause::_no_gc) {
! start_msg.append(" (%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
! 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()
! if (T1 == LogTag::__NO_TAG) {
! Log<T0, LogTag::start>::template write<Level>("%s", start_msg.buffer());
! } else if (T2 == LogTag::__NO_TAG) {
! Log<T0, T1, LogTag::start>::template write<Level>("%s", start_msg.buffer());
! } else if (T3 == LogTag::__NO_TAG) {
! Log<T0, T1, T2, LogTag::start>::template write<Level>("%s", start_msg.buffer());
! } else {
! Log<T0, T1, T2, T3, LogTag::start>::template write<Level>("%s", start_msg.buffer());
! }
! }
! }
!
! void 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);
! if (_gc_cause != GCCause::_no_gc) {
! stop_msg.append(" (%s)", GCCause::to_string(_gc_cause));
! }
! if (_heap_usage_before == SIZE_MAX) {
! Log<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 {
! 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;
! Log<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);
! }
! }
!
! void time_stamp(Ticks& ticks) {
! if (_enabled || _timer != NULL) {
! ticks.stamp();
! }
! }
public:
! GCTraceTimeImpl(const char* title, GCTimer* timer = NULL, GCCause::Cause gc_cause = GCCause::_no_gc, bool log_heap_usage = false) :
! _enabled(Log<T0, T1, T2, T3, T4, GuardTag>::is_level(Level)),
! _start_ticks(),
! _heap_usage_before(SIZE_MAX),
! _title(title),
! _gc_cause(gc_cause),
! _timer(timer) {
!
! time_stamp(_start_ticks);
! if (_enabled) {
! if (log_heap_usage) {
! _heap_usage_before = Universe::heap()->used();
! }
! log_start(_start_ticks.value());
! }
! if (_timer != NULL) {
! _timer->register_gc_phase_start(_title, _start_ticks);
! }
! }
!
! ~GCTraceTimeImpl() {
! Ticks stop_ticks;
! time_stamp(stop_ticks);
! if (_enabled) {
! log_stop(_start_ticks.value(), stop_ticks.value());
! }
! if (_timer != NULL) {
! _timer->register_gc_phase_end(stop_ticks);
! }
! }
};
! // 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,
! LogTagType T4 = LogTag::__NO_TAG, LogTagType GuardTag = LogTag::__NO_TAG>
! class GCTraceConcTimeImpl : public StackObj {
! private:
! bool _enabled;
! jlong _start_time;
! const char* _title;
public:
! GCTraceConcTimeImpl(const char* title) :
! _enabled(Log<T0, T1, T2, T3, T4, GuardTag>::is_level(Level)), _start_time(os::elapsed_counter()), _title(title) {
! if (_enabled) {
! Log<T0, T1, T2, T3, T4>::template write<Level>("%s (%.3fs)", _title, TimeHelper::counter_to_seconds(_start_time));
! }
! }
!
! ~GCTraceConcTimeImpl() {
! if (_enabled) {
! jlong stop_time = os::elapsed_counter();
! Log<T0, T1, T2, T3, T4>::template write<Level>("%s " LOG_STOP_TIME_FORMAT,
! _title,
! TimeHelper::counter_to_seconds(_start_time),
! TimeHelper::counter_to_seconds(stop_time),
! TimeHelper::counter_to_seconds(stop_time - _start_time));
! }
! }
!
! jlong start_time() { return _start_time; }
};
+
+ #define GCTraceTime(Level, ...) GCTraceTimeImpl<LogLevel::Level, LOG_TAGS(__VA_ARGS__)>
+ #define GCTraceConcTime(Level, ...) GCTraceConcTimeImpl<LogLevel::Level, LOG_TAGS(__VA_ARGS__)>
+
#endif // SHARE_VM_GC_SHARED_GCTRACETIME_HPP
< prev index next >