/* * Copyright (c) 2012, 2020, 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_GC_SHARED_GCTRACETIME_INLINE_HPP #define SHARE_GC_SHARED_GCTRACETIME_INLINE_HPP #include "gc/shared/collectedHeap.hpp" #include "gc/shared/gcTimer.hpp" #include "gc/shared/gcTrace.hpp" #include "gc/shared/gcTraceTime.hpp" #include "logging/log.hpp" #include "logging/logStream.hpp" #include "memory/universe.hpp" #include "utilities/ticks.hpp" #define LOG_STOP_HEAP_FORMAT SIZE_FORMAT "M->" SIZE_FORMAT "M(" SIZE_FORMAT "M)" template inline void GCTraceTimeImpl::log_start(jlong start_counter) { if (_out_start.is_enabled()) { LogStream out(_out_start); out.print("%s", _title); if (_gc_cause != GCCause::_no_gc) { out.print(" (%s)", GCCause::to_string(_gc_cause)); } out.cr(); } } template 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); LogStream out(_out_stop); out.print("%s", _title); if (_gc_cause != GCCause::_no_gc) { out.print(" (%s)", GCCause::to_string(_gc_cause)); } 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; out.print(" " LOG_STOP_HEAP_FORMAT, used_before_m, used_m, capacity_m); } out.print_cr(" %.3fms", duration_in_ms); } template inline void GCTraceTimeImpl::time_stamp(Ticks& ticks) { if (_enabled || _timer != NULL) { ticks.stamp(); } } template inline GCTraceTimeImpl::GCTraceTimeImpl(Handle1 out_start, Handle2 out_stop, const char* title, GCTimer* timer, GCCause::Cause gc_cause, bool log_heap_usage) : _out_start(out_start), _out_stop(out_stop), _enabled(out_stop.is_enabled()), _start_ticks(), _title(title), _gc_cause(gc_cause), _timer(timer), _heap_usage_before(SIZE_MAX) { 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); } } template inline GCTraceTimeImpl::~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); } } template GCTraceConcTimeImpl::GCTraceConcTimeImpl(const char* title) : _enabled(LogImpl::is_level(Level)), _start_time(os::elapsed_counter()), _title(title) { if (_enabled) { LogImpl::template write("%s", _title); } } template GCTraceConcTimeImpl::~GCTraceConcTimeImpl() { if (_enabled) { jlong stop_time = os::elapsed_counter(); LogImpl::template write("%s %0.3fms", _title, TimeHelper::counter_to_millis(stop_time - _start_time)); } } // 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 GCTraceTimeImplWrapper::GCTraceTimeImplWrapper( const char* title, GCTimer* timer, GCCause::Cause gc_cause, bool log_heap_usage) : _impl( LogTargetHandle::create(), LogTargetHandle::create(), 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() } template GCAsyncTraceTimeImplWrapper::GCAsyncTraceTimeImplWrapper( const char* title, GCTimer* timer, GCCause::Cause gc_cause, bool log_heap_usage) : _impl( AsyncLogTargetHandle::create(), AsyncLogTargetHandle::create(), 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 #define GCTraceTime(Level, ...) GCTraceTimeImplWrapper #define GCTraceConcTime(Level, ...) GCTraceConcTimeImpl #endif // SHARE_GC_SHARED_GCTRACETIME_INLINE_HPP