rev 57242 : imported patch 8235341-workerdataarray-cleanup

   1 /*
   2  * Copyright (c) 2017, 2018, Oracle and/or its affiliates. All rights reserved.
   3  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
   4  *
   5  * This code is free software; you can redistribute it and/or modify it
   6  * under the terms of the GNU General Public License version 2 only, as
   7  * published by the Free Software Foundation.
   8  *
   9  * This code is distributed in the hope that it will be useful, but WITHOUT
  10  * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
  11  * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
  12  * version 2 for more details (a copy is included in the LICENSE file that
  13  * accompanied this code).
  14  *
  15  * You should have received a copy of the GNU General Public License version
  16  * 2 along with this work; if not, write to the Free Software Foundation,
  17  * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
  18  *
  19  * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
  20  * or visit www.oracle.com if you need additional information or have any
  21  * questions.
  22  *
  23  */
  24 
  25 #include "precompiled.hpp"
  26 #include "gc/shared/gcTimer.hpp"
  27 #include "gc/shared/referenceProcessorPhaseTimes.hpp"
  28 #include "gc/shared/referenceProcessor.inline.hpp"
  29 #include "gc/shared/workerDataArray.inline.hpp"
  30 #include "logging/log.hpp"
  31 #include "logging/logStream.hpp"
  32 #include "memory/allocation.inline.hpp"
  33 #include "runtime/atomic.hpp"
  34 
  35 #define ASSERT_REF_TYPE(ref_type) assert((ref_type) >= REF_SOFT && (ref_type) <= REF_PHANTOM, \
  36                                          "Invariant (%d)", (int)ref_type)
  37 
  38 #define ASSERT_PHASE(phase) assert((phase) >= ReferenceProcessor::RefPhase1 && \
  39                                    (phase) < ReferenceProcessor::RefPhaseMax,  \
  40                                    "Invariant (%d)", (int)phase);
  41 
  42 #define ASSERT_SUB_PHASE(phase) assert((phase) >= ReferenceProcessor::SoftRefSubPhase1 && \
  43                                        (phase) < ReferenceProcessor::RefSubPhaseMax, \
  44                                        "Invariant (%d)", (int)phase);
  45 
  46 static const char* SubPhasesParWorkTitle[ReferenceProcessor::RefSubPhaseMax] = {
  47        "SoftRef (ms):",
  48        "SoftRef (ms):",
  49        "WeakRef (ms):",
  50        "FinalRef (ms):",
  51        "FinalRef (ms):",
  52        "PhantomRef (ms):"
  53        };
  54 
  55 static const char* Phase2ParWorkTitle = "Total (ms):";
  56 
  57 static const char* SubPhasesSerWorkTitle[ReferenceProcessor::RefSubPhaseMax] = {
  58        "SoftRef:",
  59        "SoftRef:",
  60        "WeakRef:",
  61        "FinalRef:",
  62        "FinalRef:",
  63        "PhantomRef:"
  64        };
  65 
  66 static const char* Phase2SerWorkTitle = "Total:";
  67 
  68 static const char* Indents[6] = {"", "  ", "    ", "      ", "        ", "          "};
  69 
  70 static const char* PhaseNames[ReferenceProcessor::RefPhaseMax] = {
  71        "Reconsider SoftReferences",
  72        "Notify Soft/WeakReferences",
  73        "Notify and keep alive finalizable",
  74        "Notify PhantomReferences"
  75        };
  76 
  77 static const char* ReferenceTypeNames[REF_PHANTOM + 1] = {
  78        "None", "Other", "SoftReference", "WeakReference", "FinalReference", "PhantomReference"
  79        };
  80 
  81 STATIC_ASSERT((REF_PHANTOM + 1) == ARRAY_SIZE(ReferenceTypeNames));
  82 
  83 static const char* phase_enum_2_phase_string(ReferenceProcessor::RefProcPhases phase) {
  84   ASSERT_PHASE(phase);
  85   return PhaseNames[phase];
  86 }
  87 
  88 static const char* ref_type_2_string(ReferenceType ref_type) {
  89   ASSERT_REF_TYPE(ref_type);
  90   return ReferenceTypeNames[ref_type];
  91 }
  92 
  93 RefProcWorkerTimeTracker::RefProcWorkerTimeTracker(WorkerDataArray<double>* worker_time, uint worker_id) :
  94   _worker_time(worker_time), _start_time(os::elapsedTime()), _worker_id(worker_id) {
  95   assert(worker_time != NULL, "Invariant");
  96 }
  97 
  98 RefProcWorkerTimeTracker::~RefProcWorkerTimeTracker() {
  99   double result = os::elapsedTime() - _start_time;
 100   _worker_time->set(_worker_id, result);
 101 }
 102 
 103 RefProcSubPhasesWorkerTimeTracker::RefProcSubPhasesWorkerTimeTracker(ReferenceProcessor::RefProcSubPhases phase,
 104                                                                      ReferenceProcessorPhaseTimes* phase_times,
 105                                                                      uint worker_id) :
 106   RefProcWorkerTimeTracker(phase_times->sub_phase_worker_time_sec(phase), worker_id) {
 107 }
 108 
 109 RefProcSubPhasesWorkerTimeTracker::~RefProcSubPhasesWorkerTimeTracker() {
 110 }
 111 
 112 RefProcPhaseTimeBaseTracker::RefProcPhaseTimeBaseTracker(const char* title,
 113                                                          ReferenceProcessor::RefProcPhases phase_number,
 114                                                          ReferenceProcessorPhaseTimes* phase_times) :
 115   _phase_times(phase_times), _start_ticks(), _end_ticks(), _phase_number(phase_number) {
 116   assert(_phase_times != NULL, "Invariant");
 117 
 118   _start_ticks.stamp();
 119   if (_phase_times->gc_timer() != NULL) {
 120     _phase_times->gc_timer()->register_gc_phase_start(title, _start_ticks);
 121   }
 122 }
 123 
 124 Ticks RefProcPhaseTimeBaseTracker::end_ticks() {
 125   // If ASSERT is defined, the default value of Ticks will be -2.
 126   if (_end_ticks.value() <= 0) {
 127     _end_ticks.stamp();
 128   }
 129 
 130   return _end_ticks;
 131 }
 132 
 133 double RefProcPhaseTimeBaseTracker::elapsed_time() {
 134   jlong end_value = end_ticks().value();
 135 
 136   return TimeHelper::counter_to_millis(end_value - _start_ticks.value());
 137 }
 138 
 139 RefProcPhaseTimeBaseTracker::~RefProcPhaseTimeBaseTracker() {
 140   if (_phase_times->gc_timer() != NULL) {
 141     Ticks ticks = end_ticks();
 142     _phase_times->gc_timer()->register_gc_phase_end(ticks);
 143   }
 144 }
 145 
 146 RefProcBalanceQueuesTimeTracker::RefProcBalanceQueuesTimeTracker(ReferenceProcessor::RefProcPhases phase_number,
 147                                                                  ReferenceProcessorPhaseTimes* phase_times) :
 148   RefProcPhaseTimeBaseTracker("Balance queues", phase_number, phase_times) {}
 149 
 150 RefProcBalanceQueuesTimeTracker::~RefProcBalanceQueuesTimeTracker() {
 151   double elapsed = elapsed_time();
 152   phase_times()->set_balance_queues_time_ms(_phase_number, elapsed);
 153 }
 154 
 155 RefProcPhaseTimeTracker::RefProcPhaseTimeTracker(ReferenceProcessor::RefProcPhases phase_number,
 156                                                        ReferenceProcessorPhaseTimes* phase_times) :
 157   RefProcPhaseTimeBaseTracker(phase_enum_2_phase_string(phase_number), phase_number, phase_times) {
 158 }
 159 
 160 RefProcPhaseTimeTracker::~RefProcPhaseTimeTracker() {
 161   double elapsed = elapsed_time();
 162   phase_times()->set_phase_time_ms(_phase_number, elapsed);
 163 }
 164 
 165 RefProcTotalPhaseTimesTracker::RefProcTotalPhaseTimesTracker(ReferenceProcessor::RefProcPhases phase_number,
 166                                                              ReferenceProcessorPhaseTimes* phase_times,
 167                                                              ReferenceProcessor* rp) :
 168   RefProcPhaseTimeBaseTracker(phase_enum_2_phase_string(phase_number), phase_number, phase_times), _rp(rp) {
 169 }
 170 
 171 RefProcTotalPhaseTimesTracker::~RefProcTotalPhaseTimesTracker() {
 172   double elapsed = elapsed_time();
 173   phase_times()->set_phase_time_ms(_phase_number, elapsed);
 174 }
 175 
 176 ReferenceProcessorPhaseTimes::ReferenceProcessorPhaseTimes(GCTimer* gc_timer, uint max_gc_threads) :
 177   _processing_is_mt(false), _gc_timer(gc_timer) {
 178 
 179   for (uint i = 0; i < ReferenceProcessor::RefSubPhaseMax; i++) {
 180     _sub_phases_worker_time_sec[i] = new WorkerDataArray<double>(max_gc_threads, SubPhasesParWorkTitle[i]);
 181   }
 182   _phase2_worker_time_sec = new WorkerDataArray<double>(max_gc_threads, Phase2ParWorkTitle);
 183 
 184   reset();
 185 }
 186 
 187 inline int ref_type_2_index(ReferenceType ref_type) {
 188   return ref_type - REF_SOFT;
 189 }
 190 
 191 WorkerDataArray<double>* ReferenceProcessorPhaseTimes::sub_phase_worker_time_sec(ReferenceProcessor::RefProcSubPhases sub_phase) const {
 192   ASSERT_SUB_PHASE(sub_phase);
 193   return _sub_phases_worker_time_sec[sub_phase];
 194 }
 195 
 196 double ReferenceProcessorPhaseTimes::phase_time_ms(ReferenceProcessor::RefProcPhases phase) const {
 197   ASSERT_PHASE(phase);
 198   return _phases_time_ms[phase];
 199 }
 200 
 201 void ReferenceProcessorPhaseTimes::set_phase_time_ms(ReferenceProcessor::RefProcPhases phase,
 202                                                      double phase_time_ms) {
 203   ASSERT_PHASE(phase);
 204   _phases_time_ms[phase] = phase_time_ms;
 205 }
 206 
 207 void ReferenceProcessorPhaseTimes::reset() {
 208   for (int i = 0; i < ReferenceProcessor::RefSubPhaseMax; i++) {
 209     _sub_phases_worker_time_sec[i]->reset();
 210     _sub_phases_total_time_ms[i] = uninitialized();
 211   }
 212 
 213   for (int i = 0; i < ReferenceProcessor::RefPhaseMax; i++) {
 214     _phases_time_ms[i] = uninitialized();
 215     _balance_queues_time_ms[i] = uninitialized();
 216   }
 217 
 218   _phase2_worker_time_sec->reset();
 219 
 220   for (int i = 0; i < number_of_subclasses_of_ref; i++) {
 221     _ref_cleared[i] = 0;
 222     _ref_discovered[i] = 0;
 223   }
 224 
 225   _total_time_ms = uninitialized();
 226 
 227   _processing_is_mt = false;
 228 }
 229 
 230 ReferenceProcessorPhaseTimes::~ReferenceProcessorPhaseTimes() {
 231   for (int i = 0; i < ReferenceProcessor::RefSubPhaseMax; i++) {
 232     delete _sub_phases_worker_time_sec[i];
 233   }
 234   delete _phase2_worker_time_sec;
 235 }
 236 
 237 double ReferenceProcessorPhaseTimes::sub_phase_total_time_ms(ReferenceProcessor::RefProcSubPhases sub_phase) const {
 238   ASSERT_SUB_PHASE(sub_phase);
 239   return _sub_phases_total_time_ms[sub_phase];
 240 }
 241 
 242 void ReferenceProcessorPhaseTimes::set_sub_phase_total_phase_time_ms(ReferenceProcessor::RefProcSubPhases sub_phase,
 243                                                                      double time_ms) {
 244   ASSERT_SUB_PHASE(sub_phase);
 245   _sub_phases_total_time_ms[sub_phase] = time_ms;
 246 }
 247 
 248 void ReferenceProcessorPhaseTimes::add_ref_cleared(ReferenceType ref_type, size_t count) {
 249   ASSERT_REF_TYPE(ref_type);
 250   Atomic::add(&_ref_cleared[ref_type_2_index(ref_type)], count);
 251 }
 252 
 253 void ReferenceProcessorPhaseTimes::set_ref_discovered(ReferenceType ref_type, size_t count) {
 254   ASSERT_REF_TYPE(ref_type);
 255   _ref_discovered[ref_type_2_index(ref_type)] = count;
 256 }
 257 
 258 double ReferenceProcessorPhaseTimes::balance_queues_time_ms(ReferenceProcessor::RefProcPhases phase) const {
 259   ASSERT_PHASE(phase);
 260   return _balance_queues_time_ms[phase];
 261 }
 262 
 263 void ReferenceProcessorPhaseTimes::set_balance_queues_time_ms(ReferenceProcessor::RefProcPhases phase, double time_ms) {
 264   ASSERT_PHASE(phase);
 265   _balance_queues_time_ms[phase] = time_ms;
 266 }
 267 
 268 #define TIME_FORMAT "%.1lfms"
 269 
 270 void ReferenceProcessorPhaseTimes::print_all_references(uint base_indent, bool print_total) const {
 271   if (print_total) {
 272     LogTarget(Debug, gc, phases, ref) lt;
 273 
 274     if (lt.is_enabled()) {
 275       LogStream ls(lt);
 276       ls.print_cr("%s%s: " TIME_FORMAT,
 277                   Indents[base_indent], "Reference Processing", total_time_ms());
 278     }
 279   }
 280 
 281   uint next_indent = base_indent + 1;
 282   print_phase(ReferenceProcessor::RefPhase1, next_indent);
 283   print_phase(ReferenceProcessor::RefPhase2, next_indent);
 284   print_phase(ReferenceProcessor::RefPhase3, next_indent);
 285   print_phase(ReferenceProcessor::RefPhase4, next_indent);
 286 
 287   print_reference(REF_SOFT, next_indent);
 288   print_reference(REF_WEAK, next_indent);
 289   print_reference(REF_FINAL, next_indent);
 290   print_reference(REF_PHANTOM, next_indent);
 291 
 292 }
 293 
 294 void ReferenceProcessorPhaseTimes::print_reference(ReferenceType ref_type, uint base_indent) const {
 295   LogTarget(Debug, gc, phases, ref) lt;
 296 
 297   if (lt.is_enabled()) {
 298     LogStream ls(lt);
 299     ResourceMark rm;
 300 
 301     ls.print_cr("%s%s:", Indents[base_indent], ref_type_2_string(ref_type));
 302 
 303     uint const next_indent = base_indent + 1;
 304     int const ref_type_index = ref_type_2_index(ref_type);
 305 
 306     ls.print_cr("%sDiscovered: " SIZE_FORMAT, Indents[next_indent], _ref_discovered[ref_type_index]);
 307     ls.print_cr("%sCleared: " SIZE_FORMAT, Indents[next_indent], _ref_cleared[ref_type_index]);
 308   }
 309 }
 310 
 311 void ReferenceProcessorPhaseTimes::print_phase(ReferenceProcessor::RefProcPhases phase, uint indent) const {
 312   double phase_time = phase_time_ms(phase);
 313 
 314   if (phase_time == uninitialized()) {
 315     return;
 316   }
 317 
 318   LogTarget(Debug, gc, phases, ref) lt;
 319   LogStream ls(lt);
 320 
 321   ls.print_cr("%s%s%s " TIME_FORMAT,
 322               Indents[indent],
 323               phase_enum_2_phase_string(phase),
 324               indent == 0 ? "" : ":", /* 0 indent logs don't need colon. */
 325               phase_time);
 326 
 327   LogTarget(Debug, gc, phases, ref) lt2;
 328   if (lt2.is_enabled()) {
 329     LogStream ls(lt2);
 330 
 331     if (_processing_is_mt) {
 332       print_balance_time(&ls, phase, indent + 1);
 333     }
 334 
 335     switch (phase) {
 336       case ReferenceProcessor::RefPhase1:
 337         print_sub_phase(&ls, ReferenceProcessor::SoftRefSubPhase1, indent + 1);
 338         break;
 339       case ReferenceProcessor::RefPhase2:
 340         print_sub_phase(&ls, ReferenceProcessor::SoftRefSubPhase2, indent + 1);
 341         print_sub_phase(&ls, ReferenceProcessor::WeakRefSubPhase2, indent + 1);
 342         print_sub_phase(&ls, ReferenceProcessor::FinalRefSubPhase2, indent + 1);
 343         break;
 344       case ReferenceProcessor::RefPhase3:
 345         print_sub_phase(&ls, ReferenceProcessor::FinalRefSubPhase3, indent + 1);
 346         break;
 347       case ReferenceProcessor::RefPhase4:
 348         print_sub_phase(&ls, ReferenceProcessor::PhantomRefSubPhase4, indent + 1);
 349         break;
 350       default:
 351         ShouldNotReachHere();
 352     }
 353     if (phase == ReferenceProcessor::RefPhase2) {
 354       print_worker_time(&ls, _phase2_worker_time_sec, Phase2SerWorkTitle, indent + 1);
 355     }
 356   }
 357 }
 358 
 359 void ReferenceProcessorPhaseTimes::print_balance_time(LogStream* ls, ReferenceProcessor::RefProcPhases phase, uint indent) const {
 360   double balance_time = balance_queues_time_ms(phase);
 361   if (balance_time != uninitialized()) {
 362     ls->print_cr("%s%s " TIME_FORMAT, Indents[indent], "Balance queues:", balance_time);
 363   }
 364 }
 365 
 366 void ReferenceProcessorPhaseTimes::print_sub_phase(LogStream* ls, ReferenceProcessor::RefProcSubPhases sub_phase, uint indent) const {
 367   print_worker_time(ls, _sub_phases_worker_time_sec[sub_phase], SubPhasesSerWorkTitle[sub_phase], indent);
 368 }
 369 
 370 void ReferenceProcessorPhaseTimes::print_worker_time(LogStream* ls, WorkerDataArray<double>* worker_time, const char* ser_title, uint indent) const {
 371   ls->print("%s", Indents[indent]);
 372   if (_processing_is_mt) {
 373     worker_time->print_summary_on(ls, true);
 374     LogTarget(Trace, gc, phases, task) lt;
 375     if (lt.is_enabled()) {
 376       LogStream ls2(lt);
 377       ls2.print("%s", Indents[indent]);
 378       worker_time->print_details_on(&ls2);
 379     }
 380   } else {
 381     if (worker_time->get(0) != uninitialized()) {
 382       ls->print_cr("%s " TIME_FORMAT,
 383                    ser_title,
 384                    worker_time->get(0) * MILLIUNITS);
 385     } else {
 386       ls->print_cr("%s skipped", ser_title);
 387     }
 388   }
 389 }
 390 
 391 #undef ASSERT_REF_TYPE
 392 #undef ASSERT_SUB_PHASE
 393 #undef ASSERT_PHASE
 394 #undef TIME_FORMAT
--- EOF ---