changeset 10382:8c1a2e4f633f

Merge
author tschatzl
date Fri, 26 Feb 2016 17:55:05 +0100
parents 69f183dacdb4 96124925d5aa
children 63a9e10565c4
files src/share/vm/gc/g1/g1CollectedHeap.cpp src/share/vm/gc/g1/g1CollectedHeap.hpp
diffstat 8 files changed, 80 insertions(+), 23 deletions(-) [+]
line wrap: on
line diff
--- a/src/share/vm/gc/g1/g1CollectedHeap.cpp	Thu Feb 25 11:20:03 2016 +0100
+++ b/src/share/vm/gc/g1/g1CollectedHeap.cpp	Fri Feb 26 17:55:05 2016 +0100
@@ -4395,6 +4395,8 @@
   { }
 
   void work(uint worker_id) {
+    G1GCParPhaseTimesTracker x(_g1h->g1_policy()->phase_times(), G1GCPhaseTimes::PreserveCMReferents, worker_id);
+
     ResourceMark rm;
     HandleMark   hm;
 
@@ -4458,13 +4460,8 @@
   g1_policy()->phase_times()->record_ref_proc_time(ref_proc_time * 1000.0);
 }
 
-// Weak Reference processing during an evacuation pause (part 1).
-void G1CollectedHeap::process_discovered_references(G1ParScanThreadStateSet* per_thread_states) {
-  double ref_proc_start = os::elapsedTime();
-
-  ReferenceProcessor* rp = _ref_processor_stw;
-  assert(rp->discovery_enabled(), "should have been enabled");
-
+void G1CollectedHeap::preserve_cm_referents(G1ParScanThreadStateSet* per_thread_states) {
+  double preserve_cm_referents_start = os::elapsedTime();
   // Any reference objects, in the collection set, that were 'discovered'
   // by the CM ref processor should have already been copied (either by
   // applying the external root copy closure to the discovered lists, or
@@ -4492,9 +4489,18 @@
                                                  per_thread_states,
                                                  no_of_gc_workers,
                                                  _task_queues);
-
   workers()->run_task(&keep_cm_referents);
 
+  g1_policy()->phase_times()->record_preserve_cm_referents_time_ms((os::elapsedTime() - preserve_cm_referents_start) * 1000.0);
+}
+
+// Weak Reference processing during an evacuation pause (part 1).
+void G1CollectedHeap::process_discovered_references(G1ParScanThreadStateSet* per_thread_states) {
+  double ref_proc_start = os::elapsedTime();
+
+  ReferenceProcessor* rp = _ref_processor_stw;
+  assert(rp->discovery_enabled(), "should have been enabled");
+
   // Closure to test whether a referent is alive.
   G1STWIsAliveClosure is_alive(this);
 
@@ -4526,6 +4532,8 @@
                                               NULL,
                                               _gc_timer_stw);
   } else {
+    uint no_of_gc_workers = workers()->active_workers();
+
     // Parallel reference processing
     assert(rp->num_q() == no_of_gc_workers, "sanity");
     assert(no_of_gc_workers <= rp->max_num_q(), "sanity");
@@ -4583,6 +4591,12 @@
   g1_policy()->phase_times()->record_ref_enq_time(ref_enq_time * 1000.0);
 }
 
+void G1CollectedHeap::merge_per_thread_state_info(G1ParScanThreadStateSet* per_thread_states) {
+  double merge_pss_time_start = os::elapsedTime();
+  per_thread_states->flush();
+  g1_policy()->phase_times()->record_merge_pss_time_ms((os::elapsedTime() - merge_pss_time_start) * 1000.0);
+}
+
 void G1CollectedHeap::pre_evacuate_collection_set() {
   _expand_heap_after_alloc_failure = true;
   _evacuation_failed = false;
@@ -4641,6 +4655,7 @@
   // objects (and their reachable sub-graphs) that were
   // not copied during the pause.
   if (g1_policy()->should_process_references()) {
+    preserve_cm_referents(per_thread_states);
     process_discovered_references(per_thread_states);
   } else {
     ref_processor_stw()->verify_no_references_recorded();
@@ -4684,7 +4699,7 @@
 
   _allocator->release_gc_alloc_regions(evacuation_info);
 
-  per_thread_states->flush();
+  merge_per_thread_state_info(per_thread_states);
 
   record_obj_copy_mem_stats();
 
--- a/src/share/vm/gc/g1/g1CollectedHeap.hpp	Thu Feb 25 11:20:03 2016 +0100
+++ b/src/share/vm/gc/g1/g1CollectedHeap.hpp	Fri Feb 26 17:55:05 2016 +0100
@@ -511,6 +511,9 @@
   // allocated block, or else "NULL".
   HeapWord* expand_and_allocate(size_t word_size, AllocationContext_t context);
 
+  // Preserve any referents discovered by concurrent marking that have not yet been
+  // copied by the STW pause.
+  void preserve_cm_referents(G1ParScanThreadStateSet* per_thread_states);
   // Process any reference objects discovered during
   // an incremental evacuation pause.
   void process_discovered_references(G1ParScanThreadStateSet* per_thread_states);
@@ -519,6 +522,9 @@
   // after processing.
   void enqueue_discovered_references(G1ParScanThreadStateSet* per_thread_states);
 
+  // Merges the information gathered on a per-thread basis for all worker threads
+  // during GC into global variables.
+  void merge_per_thread_state_info(G1ParScanThreadStateSet* per_thread_states);
 public:
   WorkGang* workers() const { return _workers; }
 
--- a/src/share/vm/gc/g1/g1GCPhaseTimes.cpp	Thu Feb 25 11:20:03 2016 +0100
+++ b/src/share/vm/gc/g1/g1GCPhaseTimes.cpp	Fri Feb 26 17:55:05 2016 +0100
@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2013, 2015, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2013, 2016, 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
@@ -129,6 +129,8 @@
   _gc_par_phases[RedirtyCards] = new WorkerDataArray<double>(max_gc_threads, "Parallel Redirty:", true, 3);
   _redirtied_cards = new WorkerDataArray<size_t>(max_gc_threads, "Redirtied Cards:", true, 3);
   _gc_par_phases[RedirtyCards]->link_thread_work_items(_redirtied_cards);
+
+  _gc_par_phases[PreserveCMReferents] = new WorkerDataArray<double>(max_gc_threads, "Parallel Preserve CM Refs:", true, 3);
 }
 
 void G1GCPhaseTimes::note_gc_start(uint active_gc_threads) {
@@ -392,10 +394,12 @@
   print_stats(Indents[2], "Choose CSet",
     (_recorded_young_cset_choice_time_ms +
     _recorded_non_young_cset_choice_time_ms));
+  print_stats(Indents[2], "Preserve CM Refs", _recorded_preserve_cm_referents_time_ms);
   print_stats(Indents[2], "Ref Proc", _cur_ref_proc_time_ms);
   print_stats(Indents[2], "Ref Enq", _cur_ref_enq_time_ms);
   print_stats(Indents[2], "Redirty Cards", _recorded_redirty_logged_cards_time_ms);
   par_phase_printer.print(RedirtyCards);
+  par_phase_printer.print(PreserveCMReferents);
   if (G1EagerReclaimHumongousObjects) {
     print_stats(Indents[2], "Humongous Register", _cur_fast_reclaim_humongous_register_time_ms);
 
@@ -409,6 +413,7 @@
     _recorded_non_young_free_cset_time_ms));
   log_trace(gc, phases)("%sYoung Free CSet: %.1lf ms", Indents[3], _recorded_young_free_cset_time_ms);
   log_trace(gc, phases)("%sNon-Young Free CSet: %.1lf ms", Indents[3], _recorded_non_young_free_cset_time_ms);
+  print_stats(Indents[2], "Merge Per-Thread State", _recorded_merge_pss_time_ms);
   if (_cur_verify_after_time_ms > 0.0) {
     print_stats(Indents[2], "Verify After", _cur_verify_after_time_ms);
   }
--- a/src/share/vm/gc/g1/g1GCPhaseTimes.hpp	Thu Feb 25 11:20:03 2016 +0100
+++ b/src/share/vm/gc/g1/g1GCPhaseTimes.hpp	Fri Feb 26 17:55:05 2016 +0100
@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2013, 2015, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2013, 2016, 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
@@ -69,6 +69,7 @@
     StringDedupQueueFixup,
     StringDedupTableFixup,
     RedirtyCards,
+    PreserveCMReferents,
     GCParPhasesSentinel
   };
 
@@ -108,6 +109,10 @@
 
   double _recorded_redirty_logged_cards_time_ms;
 
+  double _recorded_preserve_cm_referents_time_ms;
+
+  double _recorded_merge_pss_time_ms;
+
   double _recorded_young_free_cset_time_ms;
   double _recorded_non_young_free_cset_time_ms;
 
@@ -234,6 +239,14 @@
     _recorded_redirty_logged_cards_time_ms = time_ms;
   }
 
+  void record_preserve_cm_referents_time_ms(double time_ms) {
+    _recorded_preserve_cm_referents_time_ms = time_ms;
+  }
+
+  void record_merge_pss_time_ms(double time_ms) {
+    _recorded_merge_pss_time_ms = time_ms;
+  }
+
   void record_cur_collection_start_sec(double time_ms) {
     _cur_collection_start_sec = time_ms;
   }
--- a/src/share/vm/gc/g1/g1IHOPControl.cpp	Thu Feb 25 11:20:03 2016 +0100
+++ b/src/share/vm/gc/g1/g1IHOPControl.cpp	Fri Feb 26 17:55:05 2016 +0100
@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2015, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2015, 2016, 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
@@ -47,14 +47,16 @@
 
 void G1IHOPControl::print() {
   size_t cur_conc_mark_start_threshold = get_conc_mark_start_threshold();
-  log_debug(gc, ihop)("Basic information (value update), threshold: " SIZE_FORMAT "B (%1.2f), target occupancy: " SIZE_FORMAT "B, current occupancy: " SIZE_FORMAT "B,"
-                      " recent old gen allocation rate: %1.2f, recent marking phase length: %1.2f",
+  log_debug(gc, ihop)("Basic information (value update), threshold: " SIZE_FORMAT "B (%1.2f), target occupancy: " SIZE_FORMAT "B, current occupancy: " SIZE_FORMAT "B, "
+                      "recent allocation size: " SIZE_FORMAT "B, recent allocation duration: %1.2fms, recent old gen allocation rate: %1.2fB/s, recent marking phase length: %1.2fms",
                       cur_conc_mark_start_threshold,
                       cur_conc_mark_start_threshold * 100.0 / _target_occupancy,
                       _target_occupancy,
                       G1CollectedHeap::heap()->used(),
+                      _last_allocated_bytes,
+                      _last_allocation_time_s * 1000.0,
                       _last_allocation_time_s > 0.0 ? _last_allocated_bytes / _last_allocation_time_s : 0.0,
-                      last_marking_length_s());
+                      last_marking_length_s() * 1000.0);
 }
 
 void G1IHOPControl::send_trace_event(G1NewTracer* tracer) {
@@ -191,13 +193,16 @@
 void G1AdaptiveIHOPControl::print() {
   G1IHOPControl::print();
   size_t actual_target = actual_target_threshold();
-  log_debug(gc, ihop)("Adaptive IHOP information (value update), threshold: " SIZE_FORMAT "B (%1.2f), internal target occupancy: " SIZE_FORMAT "B,"
-                      " predicted old gen allocation rate: %1.2f, predicted marking phase length: %1.2f, prediction active: %s",
+  log_debug(gc, ihop)("Adaptive IHOP information (value update), threshold: " SIZE_FORMAT "B (%1.2f), internal target occupancy: " SIZE_FORMAT "B, "
+                      "occupancy: " SIZE_FORMAT "B, additional buffer size: " SIZE_FORMAT "B, predicted old gen allocation rate: %1.2fB/s, "
+                      "predicted marking phase length: %1.2fms, prediction active: %s",
                       get_conc_mark_start_threshold(),
                       percent_of(get_conc_mark_start_threshold(), actual_target),
                       actual_target,
+                      G1CollectedHeap::heap()->used(),
+                      _last_unrestrained_young_size,
                       _predictor->get_new_prediction(&_allocation_rate_s),
-                      _predictor->get_new_prediction(&_marking_times_s),
+                      _predictor->get_new_prediction(&_marking_times_s) * 1000.0,
                       have_enough_data_for_prediction() ? "true" : "false");
 }
 
--- a/src/share/vm/gc/g1/g1ParScanThreadState.cpp	Thu Feb 25 11:20:03 2016 +0100
+++ b/src/share/vm/gc/g1/g1ParScanThreadState.cpp	Fri Feb 26 17:55:05 2016 +0100
@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2014, 2015, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2014, 2016, 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
@@ -327,6 +327,9 @@
 
 G1ParScanThreadState* G1ParScanThreadStateSet::state_for_worker(uint worker_id) {
   assert(worker_id < _n_workers, "out of bounds access");
+  if (_states[worker_id] == NULL) {
+    _states[worker_id] = new_par_scan_state(worker_id, _young_cset_length);
+  }
   return _states[worker_id];
 }
 
@@ -352,6 +355,10 @@
   for (uint worker_index = 0; worker_index < _n_workers; ++worker_index) {
     G1ParScanThreadState* pss = _states[worker_index];
 
+    if (pss == NULL) {
+      continue;
+    }
+
     _total_cards_scanned += _cards_scanned[worker_index];
 
     pss->flush(_surviving_young_words_total);
--- a/src/share/vm/gc/g1/g1ParScanThreadState.hpp	Thu Feb 25 11:20:03 2016 +0100
+++ b/src/share/vm/gc/g1/g1ParScanThreadState.hpp	Fri Feb 26 17:55:05 2016 +0100
@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2014, 2015, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2014, 2016, 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
@@ -200,6 +200,7 @@
   size_t* _surviving_young_words_total;
   size_t* _cards_scanned;
   size_t _total_cards_scanned;
+  size_t _young_cset_length;
   uint _n_workers;
   bool _flushed;
 
@@ -210,10 +211,11 @@
       _surviving_young_words_total(NEW_C_HEAP_ARRAY(size_t, young_cset_length, mtGC)),
       _cards_scanned(NEW_C_HEAP_ARRAY(size_t, n_workers, mtGC)),
       _total_cards_scanned(0),
+      _young_cset_length(young_cset_length),
       _n_workers(n_workers),
       _flushed(false) {
     for (uint i = 0; i < n_workers; ++i) {
-      _states[i] = new_par_scan_state(i, young_cset_length);
+      _states[i] = NULL;
     }
     memset(_surviving_young_words_total, 0, young_cset_length * sizeof(size_t));
     memset(_cards_scanned, 0, n_workers * sizeof(size_t));
--- a/test/gc/g1/TestGCLogMessages.java	Thu Feb 25 11:20:03 2016 +0100
+++ b/test/gc/g1/TestGCLogMessages.java	Fri Feb 26 17:55:05 2016 +0100
@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2014, 2015, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2014, 2016, 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
@@ -23,7 +23,7 @@
 
 /*
  * @test TestGCLogMessages
- * @bug 8035406 8027295 8035398 8019342 8027959 8048179 8027962 8069330
+ * @bug 8035406 8027295 8035398 8019342 8027959 8048179 8027962 8069330 8076463 8150630
  * @summary Ensure the output for a minor GC with G1
  * includes the expected necessary messages.
  * @key gc
@@ -86,6 +86,10 @@
         // Humongous Eager Reclaim
         new LogMessageWithLevel("Humongous Reclaim", Level.DEBUG),
         new LogMessageWithLevel("Humongous Register", Level.DEBUG),
+        // Preserve CM Referents
+        new LogMessageWithLevel("Preserve CM Refs", Level.DEBUG),
+        // Merge PSS
+        new LogMessageWithLevel("Merge Per-Thread State", Level.DEBUG),
     };
 
     void checkMessagesAtLevel(OutputAnalyzer output, LogMessageWithLevel messages[], Level level) throws Exception {