/*
 * Copyright (c) 2017, 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.
 *
 */

#include "precompiled.hpp"
#include "gc/shared/gcTimer.hpp"
#include "gc/shared/referenceProcessorPhaseTimes.hpp"
#include "gc/shared/referenceProcessor.inline.hpp"
#include "logging/log.hpp"

RefProcWorkerTimeTracker::RefProcWorkerTimeTracker(WorkerDataArray<double>* worker_time, uint worker_id) :
  _worker_time(worker_time), _start_time(0.0), _worker_id(worker_id) {
  if (_worker_time != NULL) {
    _start_time = os::elapsedTime();
  }
}

RefProcWorkerTimeTracker::~RefProcWorkerTimeTracker() {
  if (_worker_time != NULL) {
    _worker_time->set(_worker_id, os::elapsedTime() - _start_time);
  }
}

static size_t total_count_from_list(DiscoveredList lists[], uint max_num_q) {
  size_t total = 0;
  for (uint i = 0; i < max_num_q; ++i) {
    total += lists[i].length();
  }
  return total;
}

RefProcPhaseTimeBaseTracker::RefProcPhaseTimeBaseTracker(const char* title,
                                                         ReferenceProcessorPhaseTimes* phase_times,
                                                         GCTimer* gc_timer) :
  _title(title), _phase_times(phase_times), _start_ticks(), _end_ticks(), _gc_timer(gc_timer) {
  assert(_phase_times != NULL, "Invariant");

  _start_ticks.stamp();
  if (_gc_timer != NULL) {
    _gc_timer->register_gc_phase_start(_title, _start_ticks);
  }
}

static const char* phase_enum_2_string(ReferenceProcessorPhaseTimes::RefProcPhases phase) {
  switch(phase) {
    case ReferenceProcessorPhaseTimes::RefPhase1:
      return "Phase1";
    case ReferenceProcessorPhaseTimes::RefPhase2:
      return "Phase2";
    case ReferenceProcessorPhaseTimes::RefPhase3:
      return "Phase3";
    case ReferenceProcessorPhaseTimes::RefEnqueue:
      return "Enqueue reference lists";
    default:
      ShouldNotReachHere();
      return NULL;
  }
}

static const char* Indents[5] = {"", "  ", "    ", "      ", "        "};

void RefProcPhaseTimeBaseTracker::print_phase(ReferenceProcessorPhaseTimes::RefProcPhases phase, uint indent) {
  double phase_time = phase_times()->phase_time_ms(phase);
  if (phase_time != ReferenceProcessorPhaseTimes::uninitialized()) {
    Log(gc, ref) log;

    log.debug_stream()->print_cr("%s%s%s %0.3fms",
                                 Indents[indent],
                                 phase_enum_2_string(phase),
                                 indent == 0 ? "" : ":", /* 0 indent logs don't need colon. */
                                 phase_time);
    if (phase_times()->processing_is_mt() && log.is_level(LogLevel::Trace)) {
      outputStream* out = log.trace_stream();

      out->print("%s", Indents[2]);
      // worker_time_sec is recorded in seconds but it will be printed in milliseconds.
      phase_times()->worker_time_sec(phase)->print_summary_on(out, true);
    }
  }
}

Ticks RefProcPhaseTimeBaseTracker::end_ticks() {
  // If ASSERT is defined, the default value of Ticks will be -2.
  if (_end_ticks.value() <= 0) {
    _end_ticks.stamp();
  }

  return _end_ticks;
}

double RefProcPhaseTimeBaseTracker::elapsed_time() {
  jlong end_value = end_ticks().value();

  return TimeHelper::counter_to_millis(end_value - _start_ticks.value());
}

RefProcPhaseTimeBaseTracker::~RefProcPhaseTimeBaseTracker() {
  if (_gc_timer != NULL) {
    Ticks ticks = end_ticks();
    _gc_timer->register_gc_phase_end(ticks);
  }
}

RefProcBalanceQueuesTimeTracker::RefProcBalanceQueuesTimeTracker(ReferenceProcessorPhaseTimes* phase_times,
                                                                 GCTimer* gc_timer) :
  RefProcPhaseTimeBaseTracker("Balance queues", phase_times, gc_timer) {}

RefProcBalanceQueuesTimeTracker::~RefProcBalanceQueuesTimeTracker() {
  double elapsed = elapsed_time();
  phase_times()->set_balance_queues_time_ms(elapsed);
}

RefProcPhaseTimeTracker::RefProcPhaseTimeTracker(ReferenceProcessorPhaseTimes::RefProcPhases phase,
                                                 ReferenceProcessorPhaseTimes* phase_times,
                                                 GCTimer* gc_timer) :
  _phase(phase), RefProcPhaseTimeBaseTracker(phase_enum_2_string(phase), phase_times, gc_timer) {}

RefProcPhaseTimeTracker::~RefProcPhaseTimeTracker() {
  double elapsed = elapsed_time();
  phase_times()->set_phase_time_ms(_phase, elapsed);
}

RefProcPhaseTimesLogger::RefProcPhaseTimesLogger(const char* title,
                                                 ReferenceProcessorPhaseTimes* times,
                                                 DiscoveredList lists[],
                                                 GCTimer* gc_timer) :
  _lists(lists), RefProcPhaseTimeBaseTracker(title, times, gc_timer) {
  _ref_discovered = total_count_from_list(_lists, phase_times()->max_gc_threads());
}

RefProcPhaseTimesLogger::~RefProcPhaseTimesLogger() {
  double elapsed = elapsed_time();

  Log(gc, ref) log;

  if (log.is_level(LogLevel::Debug)) {
    outputStream* out = log.debug_stream();
    ResourceMark rm;

    out->print_cr("%s %0.3fms", _title, elapsed);

    double balance_time = phase_times()->balance_queues_time_ms();
    if (balance_time != ReferenceProcessorPhaseTimes::uninitialized()) {
      out->print_cr("  %s %0.3fms", "Balance queues:", balance_time);
    }

    // Print stats
    print_phase(ReferenceProcessorPhaseTimes::RefPhase1, 1);
    print_phase(ReferenceProcessorPhaseTimes::RefPhase2, 1);
    print_phase(ReferenceProcessorPhaseTimes::RefPhase3, 1);

    size_t after_count = total_count_from_list(_lists, phase_times()->max_gc_threads());
    out->print_cr("  %s " SIZE_FORMAT, "Cleared:", _ref_discovered - after_count);
    out->print_cr("  %s " SIZE_FORMAT, "Discovered:", _ref_discovered);
  }

  // Reset for next use.
  phase_times()->reset();
}

RefProcEnqueueTimeLogger::RefProcEnqueueTimeLogger(ReferenceProcessorPhaseTimes* phase_times,
                                                   ReferenceProcessorStats& stats,
                                                   GCTimer* gc_timer) :
  _stats(stats), RefProcPhaseTimeBaseTracker("Enqueue reference lists", phase_times, gc_timer) {}

RefProcEnqueueTimeLogger::~RefProcEnqueueTimeLogger() {
  double elapsed = elapsed_time();

  phase_times()->set_phase_time_ms(ReferenceProcessorPhaseTimes::RefEnqueue, elapsed);

  print_phase(ReferenceProcessorPhaseTimes::RefEnqueue, 0);
  phase_times()->reset();

  log_debug(gc, ref)("  Ref Counts:  Soft: " SIZE_FORMAT "  Weak: " SIZE_FORMAT
                     "  Final: " SIZE_FORMAT "  Phantom: " SIZE_FORMAT ,
                     _stats.soft_count(), _stats.weak_count(),
                     _stats.final_count(), _stats.phantom_count());
}

ReferenceProcessorPhaseTimes::ReferenceProcessorPhaseTimes(uint max_gc_threads, bool processing_is_mt) :
  _balance_queues_time_ms(uninitialized()), _max_gc_threads(max_gc_threads), _processing_is_mt(processing_is_mt) {

  _worker_time_sec[RefPhase1] = new WorkerDataArray<double>(_max_gc_threads, "Process lists (ms)");
  _worker_time_sec[RefPhase2] = new WorkerDataArray<double>(_max_gc_threads, "Process lists (ms)");
  _worker_time_sec[RefPhase3] = new WorkerDataArray<double>(_max_gc_threads, "Process lists (ms)");
  _worker_time_sec[RefEnqueue] = new WorkerDataArray<double>(_max_gc_threads, "Process lists (ms)");

  _phase_time_ms[RefPhase1] = uninitialized();
  _phase_time_ms[RefPhase2] = uninitialized();
  _phase_time_ms[RefPhase3] = uninitialized();
  _phase_time_ms[RefEnqueue] = uninitialized();
}

WorkerDataArray<double>* ReferenceProcessorPhaseTimes::worker_time_sec(RefProcPhases phase) const {
  assert(phase >= RefPhase1 && phase < RefPhaseMax, "Invariant");
  return _worker_time_sec[phase];
}

double ReferenceProcessorPhaseTimes::phase_time_ms(RefProcPhases phase) const {
  assert(phase >= RefPhase1 && phase < RefPhaseMax, "Invariant");
  return _phase_time_ms[phase];
}

void ReferenceProcessorPhaseTimes::set_phase_time_ms(RefProcPhases phase, double phase_time_ms) {
  assert(phase >= RefPhase1 && phase < RefPhaseMax, "Invariant");
  _phase_time_ms[phase] = phase_time_ms;
}

void ReferenceProcessorPhaseTimes::reset() {
  for (int i = 0; i < RefPhaseMax; i++) {
    _worker_time_sec[i]->reset();
    _phase_time_ms[i] = uninitialized();
  }

  _balance_queues_time_ms = uninitialized();

  _processing_is_mt = false;
}