Mercurial Mercurial > jdk-sandbox / comparison
summary | shortlog | changelog | graph | tags | bookmarks | branches | files | changeset | file | latest | revisions | annotate | diff | comparison | raw | help
Find changesets by keywords (author, files, the commit message), revision number or hash, or revset expression.
hotspot/src/share/vm/gc/shared/gcTraceTime.inline.hpp
changeset 37255 100d4a515df0
parent 37242 91e5f98fff6f
child 41723 88393c6dd24e
equal deleted inserted replaced
37254:8631304f255c 37255:100d4a515df0 
    28 #include "gc/shared/collectedHeap.hpp"
 
    28 #include "gc/shared/collectedHeap.hpp"
 
    29 #include "gc/shared/gcTimer.hpp"
 
    29 #include "gc/shared/gcTimer.hpp"
 
    30 #include "gc/shared/gcTrace.hpp"
 
    30 #include "gc/shared/gcTrace.hpp"
 
    31 #include "gc/shared/gcTraceTime.hpp"
 
    31 #include "gc/shared/gcTraceTime.hpp"
 
    32 #include "logging/log.hpp"
 
    32 #include "logging/log.hpp"
 
       
    33 #include "logging/logStream.inline.hpp"
 
    33 #include "memory/universe.hpp"
 
    34 #include "memory/universe.hpp"
 
    34 #include "prims/jni_md.h"
 
    35 #include "prims/jni_md.h"
 
    35 #include "utilities/ticks.hpp"
 
    36 #include "utilities/ticks.hpp"
 
    36 
    37 
    37 #define LOG_STOP_TIME_FORMAT "(%.3fs, %.3fs) %.3fms"
 
    38 #define LOG_STOP_TIME_FORMAT "(%.3fs, %.3fs) %.3fms"
 
    38 #define LOG_STOP_HEAP_FORMAT SIZE_FORMAT "M->" SIZE_FORMAT "M("  SIZE_FORMAT "M)"
 
    39 #define LOG_STOP_HEAP_FORMAT SIZE_FORMAT "M->" SIZE_FORMAT "M("  SIZE_FORMAT "M)"
 
    39 
    40 
    40 template <LogLevelType Level, LogTagType T0, LogTagType T1, LogTagType T2, LogTagType T3, LogTagType T4, LogTagType GuardTag >
 
    41 inline void GCTraceTimeImpl::log_start(jlong start_counter) {
 
    41 void GCTraceTimeImpl<Level, T0, T1, T2, T3, T4, GuardTag>::log_start(jlong start_counter) {
 
    42   if (_out_start.is_enabled()) {
 
    42   STATIC_ASSERT(T0 != LogTag::__NO_TAG); // Need some tag to log on.
 
    43     LogStream out(_out_start);
 
    43   STATIC_ASSERT(T4 == LogTag::__NO_TAG); // Need to leave at least the last tag for the "start" tag in log_start()
 
       
    44 
    44 
    45   // Get log with start tag appended (replace first occurrence of NO_TAG)
 
    45     out.print("%s", _title);
 
    46   const LogTagType start_tag = PREFIX_LOG_TAG(start);
 
       
    47   const LogTagType no_tag = PREFIX_LOG_TAG(_NO_TAG);
 
       
    48   LogImpl<T0,
 
       
    49           T1 == no_tag ? start_tag : T1,
 
       
    50           T1 != no_tag && T2 == no_tag ? start_tag : T2,
 
       
    51           T2 != no_tag && T3 == no_tag ? start_tag : T3,
 
       
    52           T3 != no_tag && T4 == no_tag ? start_tag : T4
 
       
    53     > log;
 
       
    54 
       
    55   if (log.is_level(Level)) {
 
       
    56     FormatBuffer<> start_msg("%s", _title);
 
       
    57     if (_gc_cause != GCCause::_no_gc) {
 
    46     if (_gc_cause != GCCause::_no_gc) {
 
    58       start_msg.append(" (%s)", GCCause::to_string(_gc_cause));
 
    47       out.print(" (%s)", GCCause::to_string(_gc_cause));
 
    59     }
 
    48     }
 
    60     start_msg.append(" (%.3fs)", TimeHelper::counter_to_seconds(start_counter));
 
    49     out.print_cr(" (%.3fs)", TimeHelper::counter_to_seconds(start_counter));
 
    61     // Make sure to put the "start" tag last in the tag set
 
       
    62     log.template write<Level>("%s", start_msg.buffer());
 
       
    63   }
 
    50   }
 
    64 }
 
    51 }
 
    65 
    52 
    66 template <LogLevelType Level, LogTagType T0, LogTagType T1, LogTagType T2, LogTagType T3, LogTagType T4, LogTagType GuardTag >
 
    53 inline void GCTraceTimeImpl::log_stop(jlong start_counter, jlong stop_counter) {
 
    67 void GCTraceTimeImpl<Level, T0, T1, T2, T3, T4, GuardTag>::log_stop(jlong start_counter, jlong stop_counter) {
 
       
    68   double duration_in_ms = TimeHelper::counter_to_millis(stop_counter - start_counter);
 
    54   double duration_in_ms = TimeHelper::counter_to_millis(stop_counter - start_counter);
 
    69   double start_time_in_secs = TimeHelper::counter_to_seconds(start_counter);
 
    55   double start_time_in_secs = TimeHelper::counter_to_seconds(start_counter);
 
    70   double stop_time_in_secs = TimeHelper::counter_to_seconds(stop_counter);
 
    56   double stop_time_in_secs = TimeHelper::counter_to_seconds(stop_counter);
 
    71   FormatBuffer<> stop_msg("%s", _title);
 
    57 
       
    58   LogStream out(_out_stop);
 
       
    59 
       
    60   out.print("%s", _title);
 
       
    61 
    72   if (_gc_cause != GCCause::_no_gc) {
 
    62   if (_gc_cause != GCCause::_no_gc) {
 
    73     stop_msg.append(" (%s)", GCCause::to_string(_gc_cause));
 
    63     out.print(" (%s)", GCCause::to_string(_gc_cause));
 
    74   }
 
    64   }
 
    75   if (_heap_usage_before == SIZE_MAX) {
 
    65 
    76     LogImpl<T0, T1, T2, T3, T4>::template write<Level>("%s " LOG_STOP_TIME_FORMAT,
 
    66   if (_heap_usage_before != SIZE_MAX) {
 
    77         stop_msg.buffer(), start_time_in_secs, stop_time_in_secs, duration_in_ms);
 
       
    78   } else {
 
       
    79     CollectedHeap* heap = Universe::heap();
 
    67     CollectedHeap* heap = Universe::heap();
 
    80     size_t used_before_m = _heap_usage_before / M;
 
    68     size_t used_before_m = _heap_usage_before / M;
 
    81     size_t used_m = heap->used() / M;
 
    69     size_t used_m = heap->used() / M;
 
    82     size_t capacity_m = heap->capacity() / M;
 
    70     size_t capacity_m = heap->capacity() / M;
 
    83     LogImpl<T0, T1, T2, T3, T4>::template write<Level>("%s " LOG_STOP_HEAP_FORMAT " " LOG_STOP_TIME_FORMAT,
 
    71     out.print(" " LOG_STOP_HEAP_FORMAT, used_before_m, used_m, capacity_m);
 
    84         stop_msg.buffer(), used_before_m, used_m, capacity_m, start_time_in_secs, stop_time_in_secs, duration_in_ms);
 
       
    85   }
 
    72   }
 
       
    73 
       
    74   out.print_cr(" " LOG_STOP_TIME_FORMAT, start_time_in_secs, stop_time_in_secs, duration_in_ms);
 
    86 }
 
    75 }
 
    87 
    76 
    88 template <LogLevelType Level, LogTagType T0, LogTagType T1, LogTagType T2, LogTagType T3, LogTagType T4, LogTagType GuardTag >
 
    77 inline void GCTraceTimeImpl::time_stamp(Ticks& ticks) {
 
    89 void GCTraceTimeImpl<Level, T0, T1, T2, T3, T4, GuardTag>::time_stamp(Ticks& ticks) {
 
       
    90   if (_enabled || _timer != NULL) {
 
    78   if (_enabled || _timer != NULL) {
 
    91     ticks.stamp();
 
    79     ticks.stamp();
 
    92   }
 
    80   }
 
    93 }
 
    81 }
 
    94 
    82 
    95 template <LogLevelType Level, LogTagType T0, LogTagType T1, LogTagType T2, LogTagType T3, LogTagType T4, LogTagType GuardTag >
 
    83 inline GCTraceTimeImpl::GCTraceTimeImpl(LogTargetHandle out_start, LogTargetHandle out_stop, const char* title, GCTimer* timer, GCCause::Cause gc_cause, bool log_heap_usage) :
 
    96 GCTraceTimeImpl<Level, T0, T1, T2, T3, T4, GuardTag>::GCTraceTimeImpl(const char* title, GCTimer* timer, GCCause::Cause gc_cause, bool log_heap_usage) :
 
    84   _enabled(out_stop.is_enabled()),
 
    97   _enabled(LogImpl<T0, T1, T2, T3, T4, GuardTag>::is_level(Level)),
 
    85   _out_start(out_start),
 
       
    86   _out_stop(out_stop),
 
    98   _start_ticks(),
 
    87   _start_ticks(),
 
    99   _heap_usage_before(SIZE_MAX),
 
    88   _heap_usage_before(SIZE_MAX),
 
   100   _title(title),
 
    89   _title(title),
 
   101   _gc_cause(gc_cause),
 
    90   _gc_cause(gc_cause),
 
   102   _timer(timer) {
 
    91   _timer(timer) {
 
   111   if (_timer != NULL) {
 
   100   if (_timer != NULL) {
 
   112     _timer->register_gc_phase_start(_title, _start_ticks);
 
   101     _timer->register_gc_phase_start(_title, _start_ticks);
 
   113   }
 
   102   }
 
   114 }
 
   103 }
 
   115 
   104 
   116 template <LogLevelType Level, LogTagType T0, LogTagType T1, LogTagType T2, LogTagType T3, LogTagType T4, LogTagType GuardTag >
 
   105 inline GCTraceTimeImpl::~GCTraceTimeImpl() {
 
   117 GCTraceTimeImpl<Level, T0, T1, T2, T3, T4, GuardTag>::~GCTraceTimeImpl() {
 
       
   118   Ticks stop_ticks;
 
   106   Ticks stop_ticks;
 
   119   time_stamp(stop_ticks);
 
   107   time_stamp(stop_ticks);
 
   120   if (_enabled) {
 
   108   if (_enabled) {
 
   121     log_stop(_start_ticks.value(), stop_ticks.value());
 
   109     log_stop(_start_ticks.value(), stop_ticks.value());
 
   122   }
 
   110   }
 
   143                                                    TimeHelper::counter_to_seconds(stop_time),
 
   131                                                    TimeHelper::counter_to_seconds(stop_time),
 
   144                                                    TimeHelper::counter_to_millis(stop_time - _start_time));
 
   132                                                    TimeHelper::counter_to_millis(stop_time - _start_time));
 
   145   }
 
   133   }
 
   146 }
 
   134 }
 
   147 
   135 
   148 #define GCTraceTime(Level, ...) GCTraceTimeImpl<LogLevel::Level, LOG_TAGS(__VA_ARGS__)>
 
   136 // Figure out the first __NO_TAG position and replace it with 'start'.
 
       
   137 #define INJECT_START_TAG(T1, T2, T3, T4) \
 
       
   138     ((                          T1 == LogTag::__NO_TAG) ? PREFIX_LOG_TAG(start) : T1), \
 
       
   139     ((T1 != LogTag::__NO_TAG && T2 == LogTag::__NO_TAG) ? PREFIX_LOG_TAG(start) : T2), \
 
       
   140     ((T2 != LogTag::__NO_TAG && T3 == LogTag::__NO_TAG) ? PREFIX_LOG_TAG(start) : T3), \
 
       
   141     ((T3 != LogTag::__NO_TAG && T4 == LogTag::__NO_TAG) ? PREFIX_LOG_TAG(start) : T4)
 
       
   142 
       
   143 template <LogLevelType level, LogTagType T0, LogTagType T1, LogTagType T2, LogTagType T3, LogTagType T4, LogTagType GuardTag>
 
       
   144 GCTraceTimeImplWrapper<level, T0, T1, T2, T3, T4, GuardTag>::GCTraceTimeImplWrapper(
 
       
   145     const char* title, GCTimer* timer, GCCause::Cause gc_cause, bool log_heap_usage)
 
       
   146     : _impl(
 
       
   147         LogTargetHandle::create<level, T0, INJECT_START_TAG(T1, T2, T3, T4), GuardTag>(),
 
       
   148         LogTargetHandle::create<level, T0, T1, T2, T3, T4, GuardTag>(),
 
       
   149         title,
 
       
   150         timer,
 
       
   151         gc_cause,
 
       
   152         log_heap_usage) {
 
       
   153 
       
   154   STATIC_ASSERT(T0 != LogTag::__NO_TAG); // Need some tag to log on.
 
       
   155   STATIC_ASSERT(T4 == LogTag::__NO_TAG); // Need to leave at least the last tag for the "start" tag in log_start()
 
       
   156 }
 
       
   157 
       
   158 #undef INJECT_START_TAG
 
       
   159 
       
   160 template <LogLevelType Level, LogTagType T0, LogTagType T1, LogTagType T2, LogTagType T3, LogTagType T4, LogTagType GuardTag>
 
       
   161 GCTraceTimeImplWrapper<Level, T0, T1, T2, T3, T4, GuardTag>::~GCTraceTimeImplWrapper() {}
 
       
   162 
       
   163 #define GCTraceTime(Level, ...) GCTraceTimeImplWrapper<LogLevel::Level, LOG_TAGS(__VA_ARGS__)>
 
   149 #define GCTraceConcTime(Level, ...) GCTraceConcTimeImpl<LogLevel::Level, LOG_TAGS(__VA_ARGS__)>
 
   164 #define GCTraceConcTime(Level, ...) GCTraceConcTimeImpl<LogLevel::Level, LOG_TAGS(__VA_ARGS__)>
 
   150 
   165 
   151 #endif // SHARE_VM_GC_SHARED_GCTRACETIME_INLINE_HPP
 
   166 #endif // SHARE_VM_GC_SHARED_GCTRACETIME_INLINE_HPP
jdk-sandbox