< 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,148 ---- */ #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(); ! }; ! 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()); ! } ! } ! } ! ! #define LOG_STOP_TIME_FORMAT "(%.3fs, %.3fs) %.3fms" ! #define LOG_STOP_HEAP_FORMAT SIZE_FORMAT "M->" SIZE_FORMAT "M(" SIZE_FORMAT "M)" ! ! 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); ! } ! } }; + #define GCTraceTime(Level, ...) GCTraceTimeImpl<LogLevel::Level, LOG_TAGS(__VA_ARGS__)> + #endif // SHARE_VM_GC_SHARED_GCTRACETIME_HPP
< prev index next >