--- old/src/share/vm/gc/g1/g1CollectedHeap.cpp 2016-02-25 17:21:30.184596611 +0100 +++ new/src/share/vm/gc/g1/g1CollectedHeap.cpp 2016-02-25 17:21:30.092593843 +0100 @@ -4594,6 +4594,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; @@ -4696,7 +4702,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(); --- old/src/share/vm/gc/g1/g1CollectedHeap.hpp 2016-02-25 17:21:30.872617315 +0100 +++ new/src/share/vm/gc/g1/g1CollectedHeap.hpp 2016-02-25 17:21:30.779614516 +0100 @@ -522,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; } --- old/src/share/vm/gc/g1/g1GCPhaseTimes.cpp 2016-02-25 17:21:31.438634347 +0100 +++ new/src/share/vm/gc/g1/g1GCPhaseTimes.cpp 2016-02-25 17:21:31.336631278 +0100 @@ -413,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); } --- old/src/share/vm/gc/g1/g1GCPhaseTimes.hpp 2016-02-25 17:21:31.949649724 +0100 +++ new/src/share/vm/gc/g1/g1GCPhaseTimes.hpp 2016-02-25 17:21:31.857646956 +0100 @@ -111,6 +111,8 @@ 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; @@ -241,6 +243,10 @@ _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; } --- old/test/gc/g1/TestGCLogMessages.java 2016-02-25 17:21:32.454664921 +0100 +++ new/test/gc/g1/TestGCLogMessages.java 2016-02-25 17:21:32.361662122 +0100 @@ -23,7 +23,7 @@ /* * @test TestGCLogMessages - * @bug 8035406 8027295 8035398 8019342 8027959 8048179 8027962 8069330 8076463 + * @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 @@ -88,6 +88,8 @@ 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 {