src/share/vm/gc_implementation/g1/g1GCPhaseTimes.cpp

Print this page
rev 3986 : 7176479: G1: JVM crashes on T5-8 system with 1.5 TB heap
Summary: Refactor G1's hot card cache and card counts table into their own files. Simplify the card counts table, including removing the encoding of the card index in each entry. The card counts table now has a 1:1 correspondence with the cards spanned by heap. Space for the card counts table is reserved from virtual memory (rather than C heap) during JVM startup and is committed/expanded when the heap is expanded.
Reviewed-by:
   1 /*
   2  * Copyright (c) 2012, 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  *


 132 #ifndef PRODUCT
 133 
 134 template <class T>
 135 void WorkerDataArray<T>::reset() {
 136   for (uint i = 0; i < _length; i++) {
 137     _data[i] = (T)-1;
 138   }
 139 }
 140 
 141 template <class T>
 142 void WorkerDataArray<T>::verify() {
 143   for (uint i = 0; i < _length; i++) {
 144     assert(_data[i] >= (T)0, err_msg("Invalid data for worker %d", i));
 145   }
 146 }
 147 
 148 #endif
 149 
 150 G1GCPhaseTimes::G1GCPhaseTimes(uint max_gc_threads) :
 151   _max_gc_threads(max_gc_threads),
 152   _min_clear_cc_time_ms(-1.0),
 153   _max_clear_cc_time_ms(-1.0),
 154   _cur_clear_cc_time_ms(0.0),
 155   _cum_clear_cc_time_ms(0.0),
 156   _num_cc_clears(0L),
 157   _last_gc_worker_start_times_ms(_max_gc_threads, "%.1lf", false),
 158   _last_ext_root_scan_times_ms(_max_gc_threads, "%.1lf"),
 159   _last_satb_filtering_times_ms(_max_gc_threads, "%.1lf"),
 160   _last_update_rs_times_ms(_max_gc_threads, "%.1lf"),
 161   _last_update_rs_processed_buffers(_max_gc_threads, "%d"),
 162   _last_scan_rs_times_ms(_max_gc_threads, "%.1lf"),
 163   _last_obj_copy_times_ms(_max_gc_threads, "%.1lf"),
 164   _last_termination_times_ms(_max_gc_threads, "%.1lf"),
 165   _last_termination_attempts(_max_gc_threads, SIZE_FORMAT),
 166   _last_gc_worker_end_times_ms(_max_gc_threads, "%.1lf", false),
 167   _last_gc_worker_times_ms(_max_gc_threads, "%.1lf"),
 168   _last_gc_worker_other_times_ms(_max_gc_threads, "%.1lf")
 169 {
 170   assert(max_gc_threads > 0, "Must have some GC threads");
 171 }
 172 
 173 void G1GCPhaseTimes::note_gc_start(uint active_gc_threads) {
 174   assert(active_gc_threads > 0, "The number of threads must be > 0");
 175   assert(active_gc_threads <= _max_gc_threads, "The number of active threads must be <= the max nubmer of threads");
 176   _active_gc_threads = active_gc_threads;


 262     _last_obj_copy_times_ms.print(2, "Object Copy (ms)");
 263     _last_termination_times_ms.print(2, "Termination (ms)");
 264     if (G1Log::finest()) {
 265       _last_termination_attempts.print(3, "Termination Attempts");
 266     }
 267     _last_gc_worker_other_times_ms.print(2, "GC Worker Other (ms)");
 268     _last_gc_worker_times_ms.print(2, "GC Worker Total (ms)");
 269     _last_gc_worker_end_times_ms.print(2, "GC Worker End (ms)");
 270   } else {
 271     _last_ext_root_scan_times_ms.print(1, "Ext Root Scanning (ms)");
 272     if (_last_satb_filtering_times_ms.sum() > 0.0) {
 273       _last_satb_filtering_times_ms.print(1, "SATB Filtering (ms)");
 274     }
 275     _last_update_rs_times_ms.print(1, "Update RS (ms)");
 276       _last_update_rs_processed_buffers.print(2, "Processed Buffers");
 277     _last_scan_rs_times_ms.print(1, "Scan RS (ms)");
 278     _last_obj_copy_times_ms.print(1, "Object Copy (ms)");
 279   }
 280   print_stats(1, "Code Root Fixup", _cur_collection_code_root_fixup_time_ms);
 281   print_stats(1, "Clear CT", _cur_clear_ct_time_ms);
 282   if (Verbose && G1Log::finest()) {
 283     print_stats(1, "Cur Clear CC", _cur_clear_cc_time_ms);
 284     print_stats(1, "Cum Clear CC", _cum_clear_cc_time_ms);
 285     print_stats(1, "Min Clear CC", _min_clear_cc_time_ms);
 286     print_stats(1, "Max Clear CC", _max_clear_cc_time_ms);
 287     if (_num_cc_clears > 0) {
 288       print_stats(1, "Avg Clear CC", _cum_clear_cc_time_ms / ((double)_num_cc_clears));
 289     }
 290   }
 291   double misc_time_ms = pause_time_sec * MILLIUNITS - accounted_time_ms();
 292   print_stats(1, "Other", misc_time_ms);
 293   if (_cur_verify_before_time_ms > 0.0) {
 294     print_stats(2, "Verify Before", _cur_verify_before_time_ms);
 295   }
 296   print_stats(2, "Choose CSet",
 297     (_recorded_young_cset_choice_time_ms +
 298     _recorded_non_young_cset_choice_time_ms));
 299   print_stats(2, "Ref Proc", _cur_ref_proc_time_ms);
 300   print_stats(2, "Ref Enq", _cur_ref_enq_time_ms);
 301   print_stats(2, "Free CSet",
 302     (_recorded_young_free_cset_time_ms +
 303     _recorded_non_young_free_cset_time_ms));
 304   if (_cur_verify_after_time_ms > 0.0) {
 305     print_stats(2, "Verify After", _cur_verify_after_time_ms);
 306   }
 307 }
 308 
 309 void G1GCPhaseTimes::record_cc_clear_time_ms(double ms) {
 310   if (!(Verbose && G1Log::finest())) {
 311     return;
 312   }
 313 
 314   if (_min_clear_cc_time_ms < 0.0 || ms <= _min_clear_cc_time_ms) {
 315     _min_clear_cc_time_ms = ms;
 316   }
 317   if (_max_clear_cc_time_ms < 0.0 || ms >= _max_clear_cc_time_ms) {
 318     _max_clear_cc_time_ms = ms;
 319   }
 320   _cur_clear_cc_time_ms = ms;
 321   _cum_clear_cc_time_ms += ms;
 322   _num_cc_clears++;
 323 }
   1 /*
   2  * Copyright (c) 2013, 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  *


 132 #ifndef PRODUCT
 133 
 134 template <class T>
 135 void WorkerDataArray<T>::reset() {
 136   for (uint i = 0; i < _length; i++) {
 137     _data[i] = (T)-1;
 138   }
 139 }
 140 
 141 template <class T>
 142 void WorkerDataArray<T>::verify() {
 143   for (uint i = 0; i < _length; i++) {
 144     assert(_data[i] >= (T)0, err_msg("Invalid data for worker %d", i));
 145   }
 146 }
 147 
 148 #endif
 149 
 150 G1GCPhaseTimes::G1GCPhaseTimes(uint max_gc_threads) :
 151   _max_gc_threads(max_gc_threads),





 152   _last_gc_worker_start_times_ms(_max_gc_threads, "%.1lf", false),
 153   _last_ext_root_scan_times_ms(_max_gc_threads, "%.1lf"),
 154   _last_satb_filtering_times_ms(_max_gc_threads, "%.1lf"),
 155   _last_update_rs_times_ms(_max_gc_threads, "%.1lf"),
 156   _last_update_rs_processed_buffers(_max_gc_threads, "%d"),
 157   _last_scan_rs_times_ms(_max_gc_threads, "%.1lf"),
 158   _last_obj_copy_times_ms(_max_gc_threads, "%.1lf"),
 159   _last_termination_times_ms(_max_gc_threads, "%.1lf"),
 160   _last_termination_attempts(_max_gc_threads, SIZE_FORMAT),
 161   _last_gc_worker_end_times_ms(_max_gc_threads, "%.1lf", false),
 162   _last_gc_worker_times_ms(_max_gc_threads, "%.1lf"),
 163   _last_gc_worker_other_times_ms(_max_gc_threads, "%.1lf")
 164 {
 165   assert(max_gc_threads > 0, "Must have some GC threads");
 166 }
 167 
 168 void G1GCPhaseTimes::note_gc_start(uint active_gc_threads) {
 169   assert(active_gc_threads > 0, "The number of threads must be > 0");
 170   assert(active_gc_threads <= _max_gc_threads, "The number of active threads must be <= the max nubmer of threads");
 171   _active_gc_threads = active_gc_threads;


 257     _last_obj_copy_times_ms.print(2, "Object Copy (ms)");
 258     _last_termination_times_ms.print(2, "Termination (ms)");
 259     if (G1Log::finest()) {
 260       _last_termination_attempts.print(3, "Termination Attempts");
 261     }
 262     _last_gc_worker_other_times_ms.print(2, "GC Worker Other (ms)");
 263     _last_gc_worker_times_ms.print(2, "GC Worker Total (ms)");
 264     _last_gc_worker_end_times_ms.print(2, "GC Worker End (ms)");
 265   } else {
 266     _last_ext_root_scan_times_ms.print(1, "Ext Root Scanning (ms)");
 267     if (_last_satb_filtering_times_ms.sum() > 0.0) {
 268       _last_satb_filtering_times_ms.print(1, "SATB Filtering (ms)");
 269     }
 270     _last_update_rs_times_ms.print(1, "Update RS (ms)");
 271       _last_update_rs_processed_buffers.print(2, "Processed Buffers");
 272     _last_scan_rs_times_ms.print(1, "Scan RS (ms)");
 273     _last_obj_copy_times_ms.print(1, "Object Copy (ms)");
 274   }
 275   print_stats(1, "Code Root Fixup", _cur_collection_code_root_fixup_time_ms);
 276   print_stats(1, "Clear CT", _cur_clear_ct_time_ms);









 277   double misc_time_ms = pause_time_sec * MILLIUNITS - accounted_time_ms();
 278   print_stats(1, "Other", misc_time_ms);
 279   if (_cur_verify_before_time_ms > 0.0) {
 280     print_stats(2, "Verify Before", _cur_verify_before_time_ms);
 281   }
 282   print_stats(2, "Choose CSet",
 283     (_recorded_young_cset_choice_time_ms +
 284     _recorded_non_young_cset_choice_time_ms));
 285   print_stats(2, "Ref Proc", _cur_ref_proc_time_ms);
 286   print_stats(2, "Ref Enq", _cur_ref_enq_time_ms);
 287   print_stats(2, "Free CSet",
 288     (_recorded_young_free_cset_time_ms +
 289     _recorded_non_young_free_cset_time_ms));
 290   if (_cur_verify_after_time_ms > 0.0) {
 291     print_stats(2, "Verify After", _cur_verify_after_time_ms);
 292   }
 293 }