diff src/share/vm/gc_implementation/g1/g1GCPhaseTimes.cpp @ 18041:52b4284cb496

Merge with jdk8u20-b26
author Gilles Duboscq <duboscq@ssw.jku.at>
date Wed, 15 Oct 2014 16:02:50 +0200
parents 78bbf4d43a14
children 570cb6369f17
line wrap: on
line diff
--- a/src/share/vm/gc_implementation/g1/g1GCPhaseTimes.cpp	Thu Oct 16 10:21:29 2014 +0200
+++ b/src/share/vm/gc_implementation/g1/g1GCPhaseTimes.cpp	Wed Oct 15 16:02:50 2014 +0200
@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2013, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2013, 2014 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
@@ -27,6 +27,7 @@
 #include "gc_implementation/g1/g1CollectedHeap.inline.hpp"
 #include "gc_implementation/g1/g1GCPhaseTimes.hpp"
 #include "gc_implementation/g1/g1Log.hpp"
+#include "gc_implementation/g1/g1StringDedup.hpp"
 
 // Helper class for avoiding interleaved logging
 class LineBuffer: public StackObj {
@@ -38,7 +39,7 @@
   int _indent_level;
   int _cur;
 
-  void vappend(const char* format, va_list ap) {
+  void vappend(const char* format, va_list ap)  ATTRIBUTE_PRINTF(2, 0) {
     int res = vsnprintf(&_buffer[_cur], BUFFER_LEN - _cur, format, ap);
     if (res != -1) {
       _cur += res;
@@ -62,14 +63,14 @@
   }
 #endif
 
-  void append(const char* format, ...) {
+  void append(const char* format, ...)  ATTRIBUTE_PRINTF(2, 3) {
     va_list ap;
     va_start(ap, format);
     vappend(format, ap);
     va_end(ap);
   }
 
-  void append_and_print_cr(const char* format, ...) {
+  void append_and_print_cr(const char* format, ...)  ATTRIBUTE_PRINTF(2, 3) {
     va_list ap;
     va_start(ap, format);
     vappend(format, ap);
@@ -79,6 +80,8 @@
   }
 };
 
+PRAGMA_DIAG_PUSH
+PRAGMA_FORMAT_NONLITERAL_IGNORED
 template <class T>
 void WorkerDataArray<T>::print(int level, const char* title) {
   if (_length == 1) {
@@ -108,7 +111,7 @@
   }
 
   if (G1Log::finest()) {
-    buf.append_and_print_cr("");
+    buf.append_and_print_cr("%s", "");
   }
 
   double avg = (double)sum / (double)_length;
@@ -128,6 +131,7 @@
   }
   buf.append_and_print_cr("]");
 }
+PRAGMA_DIAG_POP
 
 #ifndef PRODUCT
 
@@ -168,7 +172,9 @@
   _last_termination_attempts(_max_gc_threads, SIZE_FORMAT),
   _last_gc_worker_end_times_ms(_max_gc_threads, "%.1lf", false),
   _last_gc_worker_times_ms(_max_gc_threads, "%.1lf"),
-  _last_gc_worker_other_times_ms(_max_gc_threads, "%.1lf")
+  _last_gc_worker_other_times_ms(_max_gc_threads, "%.1lf"),
+  _cur_string_dedup_queue_fixup_worker_times_ms(_max_gc_threads, "%.1lf"),
+  _cur_string_dedup_table_fixup_worker_times_ms(_max_gc_threads, "%.1lf")
 {
   assert(max_gc_threads > 0, "Must have some GC threads");
 }
@@ -229,12 +235,22 @@
   _last_gc_worker_other_times_ms.verify();
 }
 
+void G1GCPhaseTimes::note_string_dedup_fixup_start() {
+  _cur_string_dedup_queue_fixup_worker_times_ms.reset();
+  _cur_string_dedup_table_fixup_worker_times_ms.reset();
+}
+
+void G1GCPhaseTimes::note_string_dedup_fixup_end() {
+  _cur_string_dedup_queue_fixup_worker_times_ms.verify();
+  _cur_string_dedup_table_fixup_worker_times_ms.verify();
+}
+
 void G1GCPhaseTimes::print_stats(int level, const char* str, double value) {
   LineBuffer(level).append_and_print_cr("[%s: %.1lf ms]", str, value);
 }
 
-void G1GCPhaseTimes::print_stats(int level, const char* str, double value, int workers) {
-  LineBuffer(level).append_and_print_cr("[%s: %.1lf ms, GC Workers: %d]", str, value, workers);
+void G1GCPhaseTimes::print_stats(int level, const char* str, double value, uint workers) {
+  LineBuffer(level).append_and_print_cr("[%s: %.1lf ms, GC Workers: " UINT32_FORMAT "]", str, value, workers);
 }
 
 double G1GCPhaseTimes::accounted_time_ms() {
@@ -250,6 +266,14 @@
     // Strong code root migration time
     misc_time_ms += _cur_strong_code_root_migration_time_ms;
 
+    // Strong code root purge time
+    misc_time_ms += _cur_strong_code_root_purge_time_ms;
+
+    if (G1StringDedup::is_enabled()) {
+      // String dedup fixup time
+      misc_time_ms += _cur_string_dedup_fixup_time_ms;
+    }
+
     // Subtract the time taken to clean the card table from the
     // current value of "other time"
     misc_time_ms += _cur_clear_ct_time_ms;
@@ -299,20 +323,43 @@
   }
   print_stats(1, "Code Root Fixup", _cur_collection_code_root_fixup_time_ms);
   print_stats(1, "Code Root Migration", _cur_strong_code_root_migration_time_ms);
+  print_stats(1, "Code Root Purge", _cur_strong_code_root_purge_time_ms);
+  if (G1StringDedup::is_enabled()) {
+    print_stats(1, "String Dedup Fixup", _cur_string_dedup_fixup_time_ms, _active_gc_threads);
+    _cur_string_dedup_queue_fixup_worker_times_ms.print(2, "Queue Fixup (ms)");
+    _cur_string_dedup_table_fixup_worker_times_ms.print(2, "Table Fixup (ms)");
+  }
   print_stats(1, "Clear CT", _cur_clear_ct_time_ms);
   double misc_time_ms = pause_time_sec * MILLIUNITS - accounted_time_ms();
   print_stats(1, "Other", misc_time_ms);
   if (_cur_verify_before_time_ms > 0.0) {
     print_stats(2, "Verify Before", _cur_verify_before_time_ms);
   }
+  if (G1CollectedHeap::heap()->evacuation_failed()) {
+    double evac_fail_handling = _cur_evac_fail_recalc_used + _cur_evac_fail_remove_self_forwards +
+      _cur_evac_fail_restore_remsets;
+    print_stats(2, "Evacuation Failure", evac_fail_handling);
+    if (G1Log::finest()) {
+      print_stats(3, "Recalculate Used", _cur_evac_fail_recalc_used);
+      print_stats(3, "Remove Self Forwards", _cur_evac_fail_remove_self_forwards);
+      print_stats(3, "Restore RemSet", _cur_evac_fail_restore_remsets);
+    }
+  }
   print_stats(2, "Choose CSet",
     (_recorded_young_cset_choice_time_ms +
     _recorded_non_young_cset_choice_time_ms));
   print_stats(2, "Ref Proc", _cur_ref_proc_time_ms);
   print_stats(2, "Ref Enq", _cur_ref_enq_time_ms);
+  if (G1DeferredRSUpdate) {
+    print_stats(2, "Redirty Cards", _recorded_redirty_logged_cards_time_ms);
+  }
   print_stats(2, "Free CSet",
     (_recorded_young_free_cset_time_ms +
     _recorded_non_young_free_cset_time_ms));
+  if (G1Log::finest()) {
+    print_stats(3, "Young Free CSet", _recorded_young_free_cset_time_ms);
+    print_stats(3, "Non-Young Free CSet", _recorded_non_young_free_cset_time_ms);
+  }
   if (_cur_verify_after_time_ms > 0.0) {
     print_stats(2, "Verify After", _cur_verify_after_time_ms);
   }