/*
 * Copyright (c) 2012, 2015, 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_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