src/hotspot/share/gc/shared/referenceProcessorPhaseTimes.cpp - platform/libcore - Gitiles

 /*
  * 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"
 #include "logging/logStream.hpp"

 RefProcWorkerTimeTracker::RefProcWorkerTimeTracker(ReferenceProcessorPhaseTimes::RefProcPhaseNumbers number,
                                                    ReferenceProcessorPhaseTimes* phase_times,
                                                    uint worker_id) :
   _worker_time(NULL), _start_time(os::elapsedTime()), _worker_id(worker_id) {
   assert (phase_times != NULL, "Invariant");

   _worker_time = phase_times->worker_time_sec(phase_times->par_phase(number));
 }

 RefProcWorkerTimeTracker::RefProcWorkerTimeTracker(ReferenceProcessorPhaseTimes::RefProcParPhases phase,
                                                    ReferenceProcessorPhaseTimes* phase_times,
                                                    uint worker_id) :
   _worker_time(NULL), _start_time(os::elapsedTime()), _worker_id(worker_id) {
   assert (phase_times != NULL, "Invariant");

   _worker_time = phase_times->worker_time_sec(phase);
 }

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

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

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

 static const char* phase_enum_2_phase_string(ReferenceProcessorPhaseTimes::RefProcParPhases phase) {
   switch(phase) {
     case ReferenceProcessorPhaseTimes::SoftRefPhase1:
       return "Phase1";
     case ReferenceProcessorPhaseTimes::SoftRefPhase2:
     case ReferenceProcessorPhaseTimes::WeakRefPhase2:
     case ReferenceProcessorPhaseTimes::FinalRefPhase2:
     case ReferenceProcessorPhaseTimes::PhantomRefPhase2:
       return "Phase2";
     case ReferenceProcessorPhaseTimes::SoftRefPhase3:
     case ReferenceProcessorPhaseTimes::WeakRefPhase3:
     case ReferenceProcessorPhaseTimes::FinalRefPhase3:
     case ReferenceProcessorPhaseTimes::PhantomRefPhase3:
       return "Phase3";
     case ReferenceProcessorPhaseTimes::RefEnqueue:
       return "Reference Enqueuing";
     default:
       ShouldNotReachHere();
       return NULL;
   }
 }

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

 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 (_phase_times->gc_timer() != NULL) {
     Ticks ticks = end_ticks();
     _phase_times->gc_timer()->register_gc_phase_end(ticks);
   }
 }

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

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

 #define ASSERT_REF_TYPE(ref_type) assert(ref_type >= REF_SOFT && ref_type <= REF_PHANTOM, \
                                          "Invariant (%d)", (int)ref_type)

 #define ASSERT_PHASE_NUMBER(phase_number) assert(phase_number >= ReferenceProcessorPhaseTimes::RefPhase1 && \
                                                  phase_number <= ReferenceProcessorPhaseTimes::RefPhaseMax, \
                                                  "Invariant (%d)", phase_number);

 static const char* phase_number_2_string(ReferenceProcessorPhaseTimes::RefProcPhaseNumbers phase_number) {
   ASSERT_PHASE_NUMBER(phase_number);

   switch(phase_number) {
     case ReferenceProcessorPhaseTimes::RefPhase1:
       return "Phase1";
     case ReferenceProcessorPhaseTimes::RefPhase2:
       return "Phase2";
     case ReferenceProcessorPhaseTimes::RefPhase3:
       return "Phase3";
     default:
       ShouldNotReachHere();
       return NULL;
   }
 }

 RefProcParPhaseTimeTracker::RefProcParPhaseTimeTracker(ReferenceProcessorPhaseTimes::RefProcPhaseNumbers phase_number,
                                                        ReferenceProcessorPhaseTimes* phase_times) :
   _phase_number(phase_number),
   RefProcPhaseTimeBaseTracker(phase_number_2_string(phase_number), phase_times) {}

 RefProcParPhaseTimeTracker::~RefProcParPhaseTimeTracker() {
   double elapsed = elapsed_time();
   ReferenceProcessorPhaseTimes::RefProcParPhases phase = phase_times()->par_phase(_phase_number);
   phase_times()->set_par_phase_time_ms(phase, elapsed);
 }

 static const char* ref_type_2_string(ReferenceType ref_type) {
   ASSERT_REF_TYPE(ref_type);

   switch(ref_type) {
     case REF_SOFT:
       return "SoftReference";
     case REF_WEAK:
       return "WeakReference";
     case REF_FINAL:
       return "FinalReference";
     case REF_PHANTOM:
       return "PhantomReference";
     default:
       ShouldNotReachHere();
       return NULL;
   }
 }

 RefProcPhaseTimesTracker::RefProcPhaseTimesTracker(ReferenceType ref_type,
                                                    ReferenceProcessorPhaseTimes* phase_times,
                                                    ReferenceProcessor* rp) :
   _rp(rp), RefProcPhaseTimeBaseTracker(ref_type_2_string(ref_type), phase_times) {
   phase_times->set_processing_ref_type(ref_type);

   size_t discovered = rp->total_reference_count(ref_type);
   phase_times->set_ref_discovered(ref_type, discovered);
 }

 RefProcPhaseTimesTracker::~RefProcPhaseTimesTracker() {
   double elapsed = elapsed_time();
   ReferenceProcessorPhaseTimes* times = phase_times();
   ReferenceType ref_type = times->processing_ref_type();
   times->set_ref_proc_time_ms(ref_type, elapsed);

   size_t after_count = _rp->total_reference_count(ref_type);
   size_t discovered = times->ref_discovered(ref_type);
   times->set_ref_cleared(ref_type, discovered - after_count);
 }

 RefProcEnqueueTimeTracker::RefProcEnqueueTimeTracker(ReferenceProcessorPhaseTimes* phase_times,
                                                      ReferenceProcessorStats& stats) :
   RefProcPhaseTimeBaseTracker("Reference Enqueuing", phase_times) {
     phase_times->set_ref_enqueued(REF_SOFT, stats.soft_count());
     phase_times->set_ref_enqueued(REF_WEAK, stats.weak_count());
     phase_times->set_ref_enqueued(REF_FINAL, stats.final_count());
     phase_times->set_ref_enqueued(REF_PHANTOM, stats.phantom_count());
 }

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

   phase_times()->set_par_phase_time_ms(ReferenceProcessorPhaseTimes::RefEnqueue, elapsed);
 }

 ReferenceProcessorPhaseTimes::ReferenceProcessorPhaseTimes(GCTimer* gc_timer, uint max_gc_threads) :
   _gc_timer(gc_timer), _processing_is_mt(false) {

   for (int i = 0; i < RefParPhaseMax; i++) {
     _worker_time_sec[i] = new WorkerDataArray<double>(max_gc_threads, "Process lists (ms)");
     _par_phase_time_ms[i] = uninitialized();
   }

   for (int i = 0; i < number_of_subclasses_of_ref; i++) {
     _ref_proc_time_ms[i] = uninitialized();
     _balance_queues_time_ms[i] = uninitialized();
     _ref_cleared[i] = 0;
     _ref_discovered[i] = 0;
     _ref_enqueued[i] = 0;
   }
 }

 inline int ref_type_2_index(ReferenceType ref_type) {
   return ref_type - REF_SOFT;
 }

 #define ASSERT_PAR_PHASE(phase) assert(phase >= ReferenceProcessorPhaseTimes::SoftRefPhase1 && \
                                        phase < ReferenceProcessorPhaseTimes::RefParPhaseMax, \
                                        "Invariant (%d)", (int)phase);

 WorkerDataArray<double>* ReferenceProcessorPhaseTimes::worker_time_sec(RefProcParPhases par_phase) const {
   ASSERT_PAR_PHASE(par_phase);
   return _worker_time_sec[par_phase];
 }

 double ReferenceProcessorPhaseTimes::par_phase_time_ms(RefProcParPhases par_phase) const {
   ASSERT_PAR_PHASE(par_phase);
   return _par_phase_time_ms[par_phase];
 }

 void ReferenceProcessorPhaseTimes::set_par_phase_time_ms(RefProcParPhases par_phase,
                                                          double par_phase_time_ms) {
   ASSERT_PAR_PHASE(par_phase);
   _par_phase_time_ms[par_phase] = par_phase_time_ms;
 }

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

   for (int i = 0; i < number_of_subclasses_of_ref; i++) {
     _ref_proc_time_ms[i] = uninitialized();
     _balance_queues_time_ms[i] = uninitialized();
     _ref_cleared[i] = 0;
     _ref_discovered[i] = 0;
     _ref_enqueued[i] = 0;
   }

   _total_time_ms = uninitialized();

   _processing_is_mt = false;
 }

 ReferenceProcessorPhaseTimes::~ReferenceProcessorPhaseTimes() {
   for (int i = 0; i < RefParPhaseMax; i++) {
     delete _worker_time_sec[i];
   }
 }

 double ReferenceProcessorPhaseTimes::ref_proc_time_ms(ReferenceType ref_type) const {
   ASSERT_REF_TYPE(ref_type);
   return _par_phase_time_ms[ref_type_2_index(ref_type)];
 }

 void ReferenceProcessorPhaseTimes::set_ref_proc_time_ms(ReferenceType ref_type,
                                                         double ref_proc_time_ms) {
   ASSERT_REF_TYPE(ref_type);
   _ref_proc_time_ms[ref_type_2_index(ref_type)] = ref_proc_time_ms;
 }

 size_t ReferenceProcessorPhaseTimes::ref_cleared(ReferenceType ref_type) const {
   ASSERT_REF_TYPE(ref_type);
   return _ref_cleared[ref_type_2_index(ref_type)];
 }

 void ReferenceProcessorPhaseTimes::set_ref_cleared(ReferenceType ref_type, size_t count) {
   ASSERT_REF_TYPE(ref_type);
   _ref_cleared[ref_type_2_index(ref_type)] = count;
 }

 size_t ReferenceProcessorPhaseTimes::ref_discovered(ReferenceType ref_type) const {
   ASSERT_REF_TYPE(ref_type);
   return _ref_discovered[ref_type_2_index(ref_type)];
 }

 void ReferenceProcessorPhaseTimes::set_ref_discovered(ReferenceType ref_type, size_t count) {
   ASSERT_REF_TYPE(ref_type);
   _ref_discovered[ref_type_2_index(ref_type)] = count;
 }

 size_t ReferenceProcessorPhaseTimes::ref_enqueued(ReferenceType ref_type) const {
   ASSERT_REF_TYPE(ref_type);
   return _ref_enqueued[ref_type_2_index(ref_type)];
 }

 void ReferenceProcessorPhaseTimes::set_ref_enqueued(ReferenceType ref_type, size_t count) {
   ASSERT_REF_TYPE(ref_type);
   _ref_enqueued[ref_type_2_index(ref_type)] = count;
 }

 double ReferenceProcessorPhaseTimes::balance_queues_time_ms(ReferenceType ref_type) const {
   ASSERT_REF_TYPE(ref_type);
   return _balance_queues_time_ms[ref_type_2_index(ref_type)];
 }

 void ReferenceProcessorPhaseTimes::set_balance_queues_time_ms(ReferenceType ref_type, double time_ms) {
   ASSERT_REF_TYPE(ref_type);
   _balance_queues_time_ms[ref_type_2_index(ref_type)] = time_ms;
 }

 ReferenceProcessorPhaseTimes::RefProcParPhases
 ReferenceProcessorPhaseTimes::par_phase(RefProcPhaseNumbers phase_number) const {
   ASSERT_PHASE_NUMBER(phase_number);
   ASSERT_REF_TYPE(_processing_ref_type);

   int result = SoftRefPhase1;

   switch(_processing_ref_type) {
     case REF_SOFT:
       result = (int)SoftRefPhase1;
       result += phase_number;

       assert((RefProcParPhases)result >= SoftRefPhase1 &&
              (RefProcParPhases)result <= SoftRefPhase3,
              "Invariant (%d)", result);
       break;
     case REF_WEAK:
       result = (int)WeakRefPhase2;
       result += (phase_number - 1);
       assert((RefProcParPhases)result >= WeakRefPhase2 &&
              (RefProcParPhases)result <= WeakRefPhase3,
              "Invariant (%d)", result);
       break;
     case REF_FINAL:
       result = (int)FinalRefPhase2;
       result += (phase_number - 1);
       assert((RefProcParPhases)result >= FinalRefPhase2 &&
              (RefProcParPhases)result <= FinalRefPhase3,
              "Invariant (%d)", result);
       break;
     case REF_PHANTOM:
       result = (int)PhantomRefPhase2;
       result += (phase_number - 1);
       assert((RefProcParPhases)result >= PhantomRefPhase2 &&
              (RefProcParPhases)result <= PhantomRefPhase3,
              "Invariant (%d)", result);
       break;
     default:
       ShouldNotReachHere();
   }

   ASSERT_PAR_PHASE(result);

   return (RefProcParPhases)result;
 }

 void ReferenceProcessorPhaseTimes::print_enqueue_phase(uint base_indent, bool print_total) const {
   if (print_total) {
     print_phase(RefEnqueue, base_indent);
   }

   log_debug(gc, phases, ref)("%sReference Counts:  Soft: " SIZE_FORMAT "  Weak: " SIZE_FORMAT
                              "  Final: " SIZE_FORMAT "  Phantom: " SIZE_FORMAT ,
                              Indents[base_indent + 1], ref_enqueued(REF_SOFT), ref_enqueued(REF_WEAK),
                              ref_enqueued(REF_FINAL), ref_enqueued(REF_PHANTOM));
 }

 #define TIME_FORMAT "%.1lfms"

 void ReferenceProcessorPhaseTimes::print_all_references(uint base_indent, bool print_total) const {
   if (print_total) {
     LogTarget(Debug, gc, phases, ref) lt;

     if (lt.is_enabled()) {
       LogStream ls(lt);
       ls.print_cr("%s%s: " TIME_FORMAT,
                   Indents[base_indent], "Reference Processing", total_time_ms());
     }
   }

   uint next_indent = base_indent + 1;
   print_reference(REF_SOFT, next_indent);
   print_reference(REF_WEAK, next_indent);
   print_reference(REF_FINAL, next_indent);
   print_reference(REF_PHANTOM, next_indent);
 }

 void ReferenceProcessorPhaseTimes::print_reference(ReferenceType ref_type, uint base_indent) const {
   LogTarget(Debug, gc, phases, ref) lt;

   if (lt.is_enabled()) {
     LogStream ls(lt);
     uint next_indent = base_indent + 1;
     ResourceMark rm;

     ls.print_cr("%s%s: " TIME_FORMAT,
                 Indents[base_indent], ref_type_2_string(ref_type), ref_proc_time_ms(ref_type));

     double balance_time = balance_queues_time_ms(ref_type);
     if (balance_time != uninitialized()) {
       ls.print_cr("%s%s " TIME_FORMAT, Indents[next_indent], "Balance queues:", balance_time);
     }

     switch(ref_type) {
       case REF_SOFT:
         print_phase(SoftRefPhase1, next_indent);
         print_phase(SoftRefPhase2, next_indent);
         print_phase(SoftRefPhase3, next_indent);
         break;

       case REF_WEAK:
         print_phase(WeakRefPhase2, next_indent);
         print_phase(WeakRefPhase3, next_indent);
         break;

       case REF_FINAL:
         print_phase(FinalRefPhase2, next_indent);
         print_phase(FinalRefPhase3, next_indent);
         break;

       case REF_PHANTOM:
         print_phase(PhantomRefPhase2, next_indent);
         print_phase(PhantomRefPhase3, next_indent);
         break;

       default:
         ShouldNotReachHere();
     }

     ls.print_cr("%s%s " SIZE_FORMAT, Indents[next_indent], "Discovered:", ref_discovered(ref_type));
     ls.print_cr("%s%s " SIZE_FORMAT, Indents[next_indent], "Cleared:", ref_cleared(ref_type));
   }
 }

 void ReferenceProcessorPhaseTimes::print_phase(RefProcParPhases phase, uint indent) const {
   double phase_time = par_phase_time_ms(phase);
   if (phase_time != uninitialized()) {
     LogTarget(Debug, gc, phases, ref) lt;

     LogStream ls(lt);

     ls.print_cr("%s%s%s " TIME_FORMAT,
                 Indents[indent],
                 phase_enum_2_phase_string(phase),
                 indent == 0 ? "" : ":", /* 0 indent logs don't need colon. */
                 phase_time);

     LogTarget(Trace, gc, phases, ref) lt2;
     if (_processing_is_mt && lt2.is_enabled()) {
       LogStream ls(lt2);

       ls.print("%s", Indents[indent + 1]);
       // worker_time_sec is recorded in seconds but it will be printed in milliseconds.
       worker_time_sec(phase)->print_summary_on(&ls, true);
     }
   }
 }

 #undef ASSERT_REF_TYPE
 #undef ASSERT_PHASE_NUMBER
 #undef ASSERT_PAR_PHASE
 #undef TIME_FORMAT
	/*
	* 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"
	#include "logging/logStream.hpp"

	RefProcWorkerTimeTracker::RefProcWorkerTimeTracker(ReferenceProcessorPhaseTimes::RefProcPhaseNumbers number,
	ReferenceProcessorPhaseTimes* phase_times,
	uint worker_id) :
	_worker_time(NULL), _start_time(os::elapsedTime()), _worker_id(worker_id) {
	assert (phase_times != NULL, "Invariant");

	_worker_time = phase_times->worker_time_sec(phase_times->par_phase(number));
	}

	RefProcWorkerTimeTracker::RefProcWorkerTimeTracker(ReferenceProcessorPhaseTimes::RefProcParPhases phase,
	ReferenceProcessorPhaseTimes* phase_times,
	uint worker_id) :
	_worker_time(NULL), _start_time(os::elapsedTime()), _worker_id(worker_id) {
	assert (phase_times != NULL, "Invariant");

	_worker_time = phase_times->worker_time_sec(phase);
	}

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

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

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

	static const char* phase_enum_2_phase_string(ReferenceProcessorPhaseTimes::RefProcParPhases phase) {
	switch(phase) {
	case ReferenceProcessorPhaseTimes::SoftRefPhase1:
	return "Phase1";
	case ReferenceProcessorPhaseTimes::SoftRefPhase2:
	case ReferenceProcessorPhaseTimes::WeakRefPhase2:
	case ReferenceProcessorPhaseTimes::FinalRefPhase2:
	case ReferenceProcessorPhaseTimes::PhantomRefPhase2:
	return "Phase2";
	case ReferenceProcessorPhaseTimes::SoftRefPhase3:
	case ReferenceProcessorPhaseTimes::WeakRefPhase3:
	case ReferenceProcessorPhaseTimes::FinalRefPhase3:
	case ReferenceProcessorPhaseTimes::PhantomRefPhase3:
	return "Phase3";
	case ReferenceProcessorPhaseTimes::RefEnqueue:
	return "Reference Enqueuing";
	default:
	ShouldNotReachHere();
	return NULL;
	}
	}

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

	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 (_phase_times->gc_timer() != NULL) {
	Ticks ticks = end_ticks();
	_phase_times->gc_timer()->register_gc_phase_end(ticks);
	}
	}

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

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

	#define ASSERT_REF_TYPE(ref_type) assert(ref_type >= REF_SOFT && ref_type <= REF_PHANTOM, \
	"Invariant (%d)", (int)ref_type)

	#define ASSERT_PHASE_NUMBER(phase_number) assert(phase_number >= ReferenceProcessorPhaseTimes::RefPhase1 && \
	phase_number <= ReferenceProcessorPhaseTimes::RefPhaseMax, \
	"Invariant (%d)", phase_number);

	static const char* phase_number_2_string(ReferenceProcessorPhaseTimes::RefProcPhaseNumbers phase_number) {
	ASSERT_PHASE_NUMBER(phase_number);

	switch(phase_number) {
	case ReferenceProcessorPhaseTimes::RefPhase1:
	return "Phase1";
	case ReferenceProcessorPhaseTimes::RefPhase2:
	return "Phase2";
	case ReferenceProcessorPhaseTimes::RefPhase3:
	return "Phase3";
	default:
	ShouldNotReachHere();
	return NULL;
	}
	}

	RefProcParPhaseTimeTracker::RefProcParPhaseTimeTracker(ReferenceProcessorPhaseTimes::RefProcPhaseNumbers phase_number,
	ReferenceProcessorPhaseTimes* phase_times) :
	_phase_number(phase_number),
	RefProcPhaseTimeBaseTracker(phase_number_2_string(phase_number), phase_times) {}

	RefProcParPhaseTimeTracker::~RefProcParPhaseTimeTracker() {
	double elapsed = elapsed_time();
	ReferenceProcessorPhaseTimes::RefProcParPhases phase = phase_times()->par_phase(_phase_number);
	phase_times()->set_par_phase_time_ms(phase, elapsed);
	}

	static const char* ref_type_2_string(ReferenceType ref_type) {
	ASSERT_REF_TYPE(ref_type);

	switch(ref_type) {
	case REF_SOFT:
	return "SoftReference";
	case REF_WEAK:
	return "WeakReference";
	case REF_FINAL:
	return "FinalReference";
	case REF_PHANTOM:
	return "PhantomReference";
	default:
	ShouldNotReachHere();
	return NULL;
	}
	}

	RefProcPhaseTimesTracker::RefProcPhaseTimesTracker(ReferenceType ref_type,
	ReferenceProcessorPhaseTimes* phase_times,
	ReferenceProcessor* rp) :
	_rp(rp), RefProcPhaseTimeBaseTracker(ref_type_2_string(ref_type), phase_times) {
	phase_times->set_processing_ref_type(ref_type);

	size_t discovered = rp->total_reference_count(ref_type);
	phase_times->set_ref_discovered(ref_type, discovered);
	}

	RefProcPhaseTimesTracker::~RefProcPhaseTimesTracker() {
	double elapsed = elapsed_time();
	ReferenceProcessorPhaseTimes* times = phase_times();
	ReferenceType ref_type = times->processing_ref_type();
	times->set_ref_proc_time_ms(ref_type, elapsed);

	size_t after_count = _rp->total_reference_count(ref_type);
	size_t discovered = times->ref_discovered(ref_type);
	times->set_ref_cleared(ref_type, discovered - after_count);
	}

	RefProcEnqueueTimeTracker::RefProcEnqueueTimeTracker(ReferenceProcessorPhaseTimes* phase_times,
	ReferenceProcessorStats& stats) :
	RefProcPhaseTimeBaseTracker("Reference Enqueuing", phase_times) {
	phase_times->set_ref_enqueued(REF_SOFT, stats.soft_count());
	phase_times->set_ref_enqueued(REF_WEAK, stats.weak_count());
	phase_times->set_ref_enqueued(REF_FINAL, stats.final_count());
	phase_times->set_ref_enqueued(REF_PHANTOM, stats.phantom_count());
	}

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

	phase_times()->set_par_phase_time_ms(ReferenceProcessorPhaseTimes::RefEnqueue, elapsed);
	}

	ReferenceProcessorPhaseTimes::ReferenceProcessorPhaseTimes(GCTimer* gc_timer, uint max_gc_threads) :
	_gc_timer(gc_timer), _processing_is_mt(false) {

	for (int i = 0; i < RefParPhaseMax; i++) {
	_worker_time_sec[i] = new WorkerDataArray<double>(max_gc_threads, "Process lists (ms)");
	_par_phase_time_ms[i] = uninitialized();
	}

	for (int i = 0; i < number_of_subclasses_of_ref; i++) {
	_ref_proc_time_ms[i] = uninitialized();
	_balance_queues_time_ms[i] = uninitialized();
	_ref_cleared[i] = 0;
	_ref_discovered[i] = 0;
	_ref_enqueued[i] = 0;
	}
	}

	inline int ref_type_2_index(ReferenceType ref_type) {
	return ref_type - REF_SOFT;
	}

	#define ASSERT_PAR_PHASE(phase) assert(phase >= ReferenceProcessorPhaseTimes::SoftRefPhase1 && \
	phase < ReferenceProcessorPhaseTimes::RefParPhaseMax, \
	"Invariant (%d)", (int)phase);

	WorkerDataArray<double>* ReferenceProcessorPhaseTimes::worker_time_sec(RefProcParPhases par_phase) const {
	ASSERT_PAR_PHASE(par_phase);
	return _worker_time_sec[par_phase];
	}

	double ReferenceProcessorPhaseTimes::par_phase_time_ms(RefProcParPhases par_phase) const {
	ASSERT_PAR_PHASE(par_phase);
	return _par_phase_time_ms[par_phase];
	}

	void ReferenceProcessorPhaseTimes::set_par_phase_time_ms(RefProcParPhases par_phase,
	double par_phase_time_ms) {
	ASSERT_PAR_PHASE(par_phase);
	_par_phase_time_ms[par_phase] = par_phase_time_ms;
	}

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

	for (int i = 0; i < number_of_subclasses_of_ref; i++) {
	_ref_proc_time_ms[i] = uninitialized();
	_balance_queues_time_ms[i] = uninitialized();
	_ref_cleared[i] = 0;
	_ref_discovered[i] = 0;
	_ref_enqueued[i] = 0;
	}

	_total_time_ms = uninitialized();

	_processing_is_mt = false;
	}

	ReferenceProcessorPhaseTimes::~ReferenceProcessorPhaseTimes() {
	for (int i = 0; i < RefParPhaseMax; i++) {
	delete _worker_time_sec[i];
	}
	}

	double ReferenceProcessorPhaseTimes::ref_proc_time_ms(ReferenceType ref_type) const {
	ASSERT_REF_TYPE(ref_type);
	return _par_phase_time_ms[ref_type_2_index(ref_type)];
	}

	void ReferenceProcessorPhaseTimes::set_ref_proc_time_ms(ReferenceType ref_type,
	double ref_proc_time_ms) {
	ASSERT_REF_TYPE(ref_type);
	_ref_proc_time_ms[ref_type_2_index(ref_type)] = ref_proc_time_ms;
	}

	size_t ReferenceProcessorPhaseTimes::ref_cleared(ReferenceType ref_type) const {
	ASSERT_REF_TYPE(ref_type);
	return _ref_cleared[ref_type_2_index(ref_type)];
	}

	void ReferenceProcessorPhaseTimes::set_ref_cleared(ReferenceType ref_type, size_t count) {
	ASSERT_REF_TYPE(ref_type);
	_ref_cleared[ref_type_2_index(ref_type)] = count;
	}

	size_t ReferenceProcessorPhaseTimes::ref_discovered(ReferenceType ref_type) const {
	ASSERT_REF_TYPE(ref_type);
	return _ref_discovered[ref_type_2_index(ref_type)];
	}

	void ReferenceProcessorPhaseTimes::set_ref_discovered(ReferenceType ref_type, size_t count) {
	ASSERT_REF_TYPE(ref_type);
	_ref_discovered[ref_type_2_index(ref_type)] = count;
	}

	size_t ReferenceProcessorPhaseTimes::ref_enqueued(ReferenceType ref_type) const {
	ASSERT_REF_TYPE(ref_type);
	return _ref_enqueued[ref_type_2_index(ref_type)];
	}

	void ReferenceProcessorPhaseTimes::set_ref_enqueued(ReferenceType ref_type, size_t count) {
	ASSERT_REF_TYPE(ref_type);
	_ref_enqueued[ref_type_2_index(ref_type)] = count;
	}

	double ReferenceProcessorPhaseTimes::balance_queues_time_ms(ReferenceType ref_type) const {
	ASSERT_REF_TYPE(ref_type);
	return _balance_queues_time_ms[ref_type_2_index(ref_type)];
	}

	void ReferenceProcessorPhaseTimes::set_balance_queues_time_ms(ReferenceType ref_type, double time_ms) {
	ASSERT_REF_TYPE(ref_type);
	_balance_queues_time_ms[ref_type_2_index(ref_type)] = time_ms;
	}

	ReferenceProcessorPhaseTimes::RefProcParPhases
	ReferenceProcessorPhaseTimes::par_phase(RefProcPhaseNumbers phase_number) const {
	ASSERT_PHASE_NUMBER(phase_number);
	ASSERT_REF_TYPE(_processing_ref_type);

	int result = SoftRefPhase1;

	switch(_processing_ref_type) {
	case REF_SOFT:
	result = (int)SoftRefPhase1;
	result += phase_number;

	assert((RefProcParPhases)result >= SoftRefPhase1 &&
	(RefProcParPhases)result <= SoftRefPhase3,
	"Invariant (%d)", result);
	break;
	case REF_WEAK:
	result = (int)WeakRefPhase2;
	result += (phase_number - 1);
	assert((RefProcParPhases)result >= WeakRefPhase2 &&
	(RefProcParPhases)result <= WeakRefPhase3,
	"Invariant (%d)", result);
	break;
	case REF_FINAL:
	result = (int)FinalRefPhase2;
	result += (phase_number - 1);
	assert((RefProcParPhases)result >= FinalRefPhase2 &&
	(RefProcParPhases)result <= FinalRefPhase3,
	"Invariant (%d)", result);
	break;
	case REF_PHANTOM:
	result = (int)PhantomRefPhase2;
	result += (phase_number - 1);
	assert((RefProcParPhases)result >= PhantomRefPhase2 &&
	(RefProcParPhases)result <= PhantomRefPhase3,
	"Invariant (%d)", result);
	break;
	default:
	ShouldNotReachHere();
	}

	ASSERT_PAR_PHASE(result);

	return (RefProcParPhases)result;
	}

	void ReferenceProcessorPhaseTimes::print_enqueue_phase(uint base_indent, bool print_total) const {
	if (print_total) {
	print_phase(RefEnqueue, base_indent);
	}

	log_debug(gc, phases, ref)("%sReference Counts: Soft: " SIZE_FORMAT " Weak: " SIZE_FORMAT
	" Final: " SIZE_FORMAT " Phantom: " SIZE_FORMAT ,
	Indents[base_indent + 1], ref_enqueued(REF_SOFT), ref_enqueued(REF_WEAK),
	ref_enqueued(REF_FINAL), ref_enqueued(REF_PHANTOM));
	}

	#define TIME_FORMAT "%.1lfms"

	void ReferenceProcessorPhaseTimes::print_all_references(uint base_indent, bool print_total) const {
	if (print_total) {
	LogTarget(Debug, gc, phases, ref) lt;

	if (lt.is_enabled()) {
	LogStream ls(lt);
	ls.print_cr("%s%s: " TIME_FORMAT,
	Indents[base_indent], "Reference Processing", total_time_ms());
	}
	}

	uint next_indent = base_indent + 1;
	print_reference(REF_SOFT, next_indent);
	print_reference(REF_WEAK, next_indent);
	print_reference(REF_FINAL, next_indent);
	print_reference(REF_PHANTOM, next_indent);
	}

	void ReferenceProcessorPhaseTimes::print_reference(ReferenceType ref_type, uint base_indent) const {
	LogTarget(Debug, gc, phases, ref) lt;

	if (lt.is_enabled()) {
	LogStream ls(lt);
	uint next_indent = base_indent + 1;
	ResourceMark rm;

	ls.print_cr("%s%s: " TIME_FORMAT,
	Indents[base_indent], ref_type_2_string(ref_type), ref_proc_time_ms(ref_type));

	double balance_time = balance_queues_time_ms(ref_type);
	if (balance_time != uninitialized()) {
	ls.print_cr("%s%s " TIME_FORMAT, Indents[next_indent], "Balance queues:", balance_time);
	}

	switch(ref_type) {
	case REF_SOFT:
	print_phase(SoftRefPhase1, next_indent);
	print_phase(SoftRefPhase2, next_indent);
	print_phase(SoftRefPhase3, next_indent);
	break;

	case REF_WEAK:
	print_phase(WeakRefPhase2, next_indent);
	print_phase(WeakRefPhase3, next_indent);
	break;

	case REF_FINAL:
	print_phase(FinalRefPhase2, next_indent);
	print_phase(FinalRefPhase3, next_indent);
	break;

	case REF_PHANTOM:
	print_phase(PhantomRefPhase2, next_indent);
	print_phase(PhantomRefPhase3, next_indent);
	break;

	default:
	ShouldNotReachHere();
	}

	ls.print_cr("%s%s " SIZE_FORMAT, Indents[next_indent], "Discovered:", ref_discovered(ref_type));
	ls.print_cr("%s%s " SIZE_FORMAT, Indents[next_indent], "Cleared:", ref_cleared(ref_type));
	}
	}

	void ReferenceProcessorPhaseTimes::print_phase(RefProcParPhases phase, uint indent) const {
	double phase_time = par_phase_time_ms(phase);
	if (phase_time != uninitialized()) {
	LogTarget(Debug, gc, phases, ref) lt;

	LogStream ls(lt);

	ls.print_cr("%s%s%s " TIME_FORMAT,
	Indents[indent],
	phase_enum_2_phase_string(phase),
	indent == 0 ? "" : ":", /* 0 indent logs don't need colon. */
	phase_time);

	LogTarget(Trace, gc, phases, ref) lt2;
	if (_processing_is_mt && lt2.is_enabled()) {
	LogStream ls(lt2);

	ls.print("%s", Indents[indent + 1]);
	// worker_time_sec is recorded in seconds but it will be printed in milliseconds.
	worker_time_sec(phase)->print_summary_on(&ls, true);
	}
	}
	}

	#undef ASSERT_REF_TYPE
	#undef ASSERT_PHASE_NUMBER
	#undef ASSERT_PAR_PHASE
	#undef TIME_FORMAT