--- old/src/hotspot/share/gc/g1/g1CollectedHeap.cpp 2018-04-13 11:49:55.636121435 +0200 +++ new/src/hotspot/share/gc/g1/g1CollectedHeap.cpp 2018-04-13 11:49:55.255109758 +0200 @@ -3126,7 +3126,7 @@ double start_strong_roots_sec = os::elapsedTime(); - _root_processor->evacuate_roots(pss, pss->closures(), worker_id); + _root_processor->evacuate_roots(pss, worker_id); // We pass a weak code blobs closure to the remembered set scanning because we want to avoid // treating the nmethods visited to act as roots for concurrent marking. --- old/src/hotspot/share/gc/g1/g1GCPhaseTimes.cpp 2018-04-13 11:49:57.838188920 +0200 +++ new/src/hotspot/share/gc/g1/g1GCPhaseTimes.cpp 2018-04-13 11:49:57.398175436 +0200 @@ -26,6 +26,7 @@ #include "gc/g1/g1CollectedHeap.inline.hpp" #include "gc/g1/g1GCPhaseTimes.hpp" #include "gc/g1/g1HotCardCache.hpp" +#include "gc/g1/g1ParScanThreadState.inline.hpp" #include "gc/g1/g1StringDedup.hpp" #include "gc/shared/workerDataArray.inline.hpp" #include "memory/resourceArea.hpp" @@ -229,9 +230,12 @@ _gc_par_phases[phase]->add(worker_i, secs); } -void G1GCPhaseTimes::move_time_secs(GCParPhases from, GCParPhases to, uint worker_i, double secs) { - add_time_secs(from, worker_i, -secs); - add_time_secs(to, worker_i, secs); +void G1GCPhaseTimes::record_or_add_objcopy_time_secs(uint worker_i, double secs) { + if (_gc_par_phases[ObjCopy]->get(worker_i) == _gc_par_phases[ObjCopy]->uninitialized()) { + record_time_secs(ObjCopy, worker_i, secs); + } else { + add_time_secs(ObjCopy, worker_i, secs); + } } void G1GCPhaseTimes::record_thread_work_item(GCParPhases phase, uint worker_i, size_t count, uint index) { @@ -469,6 +473,21 @@ } } +G1EvacPhaseWithTrimTimeTracker::G1EvacPhaseWithTrimTimeTracker(G1ParScanThreadState* pss, Tickspan& total_time, Tickspan& trim_time) : + _pss(pss), + _start(Ticks::now()), + _total_time(total_time), + _trim_time(trim_time) { + + assert(_pss->trim_ticks().value() == 0, "Possibly remaining trim ticks left over from previous use"); +} + +G1EvacPhaseWithTrimTimeTracker::~G1EvacPhaseWithTrimTimeTracker() { + _total_time += (Ticks::now() - _start) + _pss->trim_ticks(); + _trim_time += _pss->trim_ticks(); + _pss->reset_trim_ticks(); +} + G1GCParPhaseTimesTracker::G1GCParPhaseTimesTracker(G1GCPhaseTimes* phase_times, G1GCPhaseTimes::GCParPhases phase, uint worker_id) : _phase_times(phase_times), _phase(phase), _worker_id(worker_id) { if (_phase_times != NULL) { @@ -482,3 +501,20 @@ } } +G1EvacPhaseTimesTracker::G1EvacPhaseTimesTracker(G1GCPhaseTimes* phase_times, + G1ParScanThreadState* pss, + G1GCPhaseTimes::GCParPhases phase, + uint worker_id) : + G1GCParPhaseTimesTracker(phase_times, phase, worker_id), + _total_time(), + _trim_time(), + _trim_tracker(pss, _total_time, _trim_time) { +} + +G1EvacPhaseTimesTracker::~G1EvacPhaseTimesTracker() { + if (_phase_times != NULL) { + _start_time += TicksToTimeHelper::seconds(_trim_time); + _phase_times->record_or_add_objcopy_time_secs(_worker_id, TicksToTimeHelper::seconds(_trim_time)); + } +} + --- old/src/hotspot/share/gc/g1/g1GCPhaseTimes.hpp 2018-04-13 11:50:00.103258337 +0200 +++ new/src/hotspot/share/gc/g1/g1GCPhaseTimes.hpp 2018-04-13 11:49:59.659244729 +0200 @@ -31,6 +31,7 @@ #include "utilities/macros.hpp" class LineBuffer; +class G1ParScanThreadState; class STWGCTimer; template class WorkerDataArray; @@ -196,8 +197,7 @@ // add a number of seconds to a phase void add_time_secs(GCParPhases phase, uint worker_i, double secs); - // Move a number of seconds from one phase to another. - void move_time_secs(GCParPhases from, GCParPhases to, uint worker_i, double secs); + void record_or_add_objcopy_time_secs(uint worker_i, double secs); void record_thread_work_item(GCParPhases phase, uint worker_i, size_t count, uint index = 0); @@ -366,14 +366,36 @@ ReferenceProcessorPhaseTimes* ref_phase_times() { return &_ref_phase_times; } }; -class G1GCParPhaseTimesTracker : public StackObj { +class G1EvacPhaseWithTrimTimeTracker : public StackObj { + G1ParScanThreadState* _pss; + Ticks _start; + + Tickspan& _total_time; + Tickspan& _trim_time; +public: + G1EvacPhaseWithTrimTimeTracker(G1ParScanThreadState* pss, Tickspan& total_time, Tickspan& trim_time); + ~G1EvacPhaseWithTrimTimeTracker(); +}; + +class G1GCParPhaseTimesTracker : public CHeapObj { +protected: double _start_time; G1GCPhaseTimes::GCParPhases _phase; G1GCPhaseTimes* _phase_times; uint _worker_id; public: G1GCParPhaseTimesTracker(G1GCPhaseTimes* phase_times, G1GCPhaseTimes::GCParPhases phase, uint worker_id); - ~G1GCParPhaseTimesTracker(); + virtual ~G1GCParPhaseTimesTracker(); +}; + +class G1EvacPhaseTimesTracker : public G1GCParPhaseTimesTracker { + Tickspan _total_time; + Tickspan _trim_time; + + G1EvacPhaseWithTrimTimeTracker _trim_tracker; +public: + G1EvacPhaseTimesTracker(G1GCPhaseTimes* phase_times, G1ParScanThreadState* pss, G1GCPhaseTimes::GCParPhases phase, uint worker_id); + virtual ~G1EvacPhaseTimesTracker(); }; #endif // SHARE_VM_GC_G1_G1GCPHASETIMES_HPP --- old/src/hotspot/share/gc/g1/g1ParScanThreadState.cpp 2018-04-13 11:50:02.192322359 +0200 +++ new/src/hotspot/share/gc/g1/g1ParScanThreadState.cpp 2018-04-13 11:50:01.770309426 +0200 @@ -45,15 +45,12 @@ _closures(NULL), _plab_allocator(NULL), _age_table(false), -// _dest _tenuring_threshold(g1h->g1_policy()->tenuring_threshold()), _scanner(g1h, this), _hash_seed(17), _worker_id(worker_id), _stack_drain_upper_threshold(GCDrainStackTargetSize * 2 + 1), _stack_drain_lower_threshold(GCDrainStackTargetSize), -// _surviving_young_words(NULL), -// _surviving_young_words_base(NULL), _trim_ticks(), _old_gen_is_full(false) { @@ -145,16 +142,8 @@ void G1ParScanThreadState::trim_queue() { StarTask ref; do { - // Drain the overflow stack first, so other threads can steal. - while (_refs->pop_overflow(ref)) { - if (!_refs->try_push_to_taskqueue(ref)) { - dispatch_reference(ref); - } - } - - while (_refs->pop_local(ref)) { - dispatch_reference(ref); - } + // Fully drain the queue. + trim_queue_to_threshold(0); } while (!_refs->is_empty()); } --- old/src/hotspot/share/gc/g1/g1ParScanThreadState.hpp 2018-04-13 11:50:04.249385400 +0200 +++ new/src/hotspot/share/gc/g1/g1ParScanThreadState.hpp 2018-04-13 11:50:03.806371824 +0200 @@ -191,17 +191,18 @@ oop const old, size_t word_sz, uint age, HeapWord * const obj_ptr) const; - inline bool should_start_trim_queue_partially() const; - inline bool should_end_trim_queue_partially() const; + inline bool needs_partial_trimming() const; + inline bool is_partially_trimmed() const; - inline void trim_queue_partially_internal(); + inline void trim_queue_to_threshold(uint threshold); public: oop copy_to_survivor_space(InCSetState const state, oop const obj, markOop const old_mark); void trim_queue(); void trim_queue_partially(); - Tickspan trim_ticks_and_reset(); + Tickspan trim_ticks(); + void reset_trim_ticks(); inline void steal_and_trim_queue(RefToScanQueueSet *task_queues); --- old/src/hotspot/share/gc/g1/g1ParScanThreadState.inline.hpp 2018-04-13 11:50:06.384450832 +0200 +++ new/src/hotspot/share/gc/g1/g1ParScanThreadState.inline.hpp 2018-04-13 11:50:05.945437378 +0200 @@ -152,42 +152,46 @@ } } -inline bool G1ParScanThreadState::should_start_trim_queue_partially() const { +inline bool G1ParScanThreadState::needs_partial_trimming() const { return !_refs->overflow_empty() || _refs->size() > _stack_drain_upper_threshold; } -inline bool G1ParScanThreadState::should_end_trim_queue_partially() const { +inline bool G1ParScanThreadState::is_partially_trimmed() const { return _refs->overflow_empty() && _refs->size() <= _stack_drain_lower_threshold; } -inline void G1ParScanThreadState::trim_queue_partially_internal() { +inline void G1ParScanThreadState::trim_queue_to_threshold(uint threshold) { StarTask ref; - do { - // Drain the overflow stack first, so other threads can potentially steal. - while (_refs->pop_overflow(ref)) { - if (!_refs->try_push_to_taskqueue(ref)) { - dispatch_reference(ref); - } - } - - while (_refs->pop_local(ref, _stack_drain_lower_threshold)) { + // Drain the overflow stack first, so other threads can potentially steal. + while (_refs->pop_overflow(ref)) { + if (!_refs->try_push_to_taskqueue(ref)) { dispatch_reference(ref); } - } while (!should_end_trim_queue_partially()); + } + + while (_refs->pop_local(ref, threshold)) { + dispatch_reference(ref); + } } inline void G1ParScanThreadState::trim_queue_partially() { - if (should_start_trim_queue_partially()) { - const Ticks start = Ticks::now(); - trim_queue_partially_internal(); - _trim_ticks += Ticks::now() - start; + if (!needs_partial_trimming()) { + return; } + + const Ticks start = Ticks::now(); + do { + trim_queue_to_threshold(_stack_drain_lower_threshold); + } while (!is_partially_trimmed()); + _trim_ticks += Ticks::now() - start; +} + +inline Tickspan G1ParScanThreadState::trim_ticks() { + return _trim_ticks; } -inline Tickspan G1ParScanThreadState::trim_ticks_and_reset() { - Tickspan result = _trim_ticks; +inline void G1ParScanThreadState::reset_trim_ticks() { _trim_ticks = Tickspan(); - return result; } #endif // SHARE_VM_GC_G1_G1PARSCANTHREADSTATE_INLINE_HPP --- old/src/hotspot/share/gc/g1/g1RemSet.cpp 2018-04-13 11:50:08.569517797 +0200 +++ new/src/hotspot/share/gc/g1/g1RemSet.cpp 2018-04-13 11:50:08.119504005 +0200 @@ -393,9 +393,7 @@ } void G1ScanRSForRegionClosure::scan_strong_code_roots(HeapRegion* r) { - Ticks const scan_start = Ticks::now(); r->strong_code_roots_do(_pss->closures()->weak_codeblobs()); - _strong_code_root_scan_time += (Ticks::now() - scan_start); } bool G1ScanRSForRegionClosure::do_heap_region(HeapRegion* r) { @@ -410,20 +408,14 @@ } { - Ticks const start = Ticks::now(); + G1EvacPhaseWithTrimTimeTracker timer(_pss, _rem_set_root_scan_time, _rem_set_trim_partially_time); scan_rem_set_roots(r); - Tickspan const trim_partially_time = _pss->trim_ticks_and_reset(); - _rem_set_root_scan_time += (Ticks::now() - start) - trim_partially_time; - _rem_set_trim_partially_time += trim_partially_time; } if (_scan_state->set_iter_complete(region_idx)) { - Ticks const start = Ticks::now(); + G1EvacPhaseWithTrimTimeTracker timer(_pss, _strong_code_root_scan_time, _strong_code_trim_partially_time); // Scan the strong code root list attached to the current region scan_strong_code_roots(r); - Tickspan const trim_partially_time = _pss->trim_ticks_and_reset(); - _strong_code_root_scan_time += (Ticks::now() - start) - trim_partially_time; - _strong_code_trim_partially_time += trim_partially_time; } return false; } @@ -485,31 +477,24 @@ // Apply closure to log entries in the HCC. if (G1HotCardCache::default_use_cache()) { - { - G1GCParPhaseTimesTracker x(p, G1GCPhaseTimes::ScanHCC, worker_i); + G1EvacPhaseTimesTracker x(p, pss, G1GCPhaseTimes::ScanHCC, worker_i); - G1ScanObjsDuringUpdateRSClosure scan_hcc_cl(_g1h, pss, worker_i); - G1RefineCardClosure refine_card_cl(_g1h, &scan_hcc_cl); - - _g1h->iterate_hcc_closure(&refine_card_cl, worker_i); - } - double const scan_hcc_trim_queue_time = TicksToTimeHelper::seconds(pss->trim_ticks_and_reset()); - p->move_time_secs(G1GCPhaseTimes::ScanHCC, G1GCPhaseTimes::ObjCopy, worker_i, scan_hcc_trim_queue_time); + G1ScanObjsDuringUpdateRSClosure scan_hcc_cl(_g1h, pss, worker_i); + G1RefineCardClosure refine_card_cl(_g1h, &scan_hcc_cl); + _g1h->iterate_hcc_closure(&refine_card_cl, worker_i); } // Now apply the closure to all remaining log entries. - G1ScanObjsDuringUpdateRSClosure update_rs_cl(_g1h, pss, worker_i); - G1RefineCardClosure refine_card_cl(_g1h, &update_rs_cl); { - G1GCParPhaseTimesTracker x(p, G1GCPhaseTimes::UpdateRS, worker_i); - _g1h->iterate_dirty_card_closure(&refine_card_cl, worker_i); - } + G1EvacPhaseTimesTracker x(p, pss, G1GCPhaseTimes::UpdateRS, worker_i); - double const update_rs_trim_queue_time = TicksToTimeHelper::seconds(pss->trim_ticks_and_reset()); - p->move_time_secs(G1GCPhaseTimes::UpdateRS, G1GCPhaseTimes::ObjCopy, worker_i, update_rs_trim_queue_time); + G1ScanObjsDuringUpdateRSClosure update_rs_cl(_g1h, pss, worker_i); + G1RefineCardClosure refine_card_cl(_g1h, &update_rs_cl); + _g1h->iterate_dirty_card_closure(&refine_card_cl, worker_i); - p->record_thread_work_item(G1GCPhaseTimes::UpdateRS, worker_i, refine_card_cl.cards_scanned(), G1GCPhaseTimes::UpdateRSScannedCards); - p->record_thread_work_item(G1GCPhaseTimes::UpdateRS, worker_i, refine_card_cl.cards_skipped(), G1GCPhaseTimes::UpdateRSSkippedCards); + p->record_thread_work_item(G1GCPhaseTimes::UpdateRS, worker_i, refine_card_cl.cards_scanned(), G1GCPhaseTimes::UpdateRSScannedCards); + p->record_thread_work_item(G1GCPhaseTimes::UpdateRS, worker_i, refine_card_cl.cards_skipped(), G1GCPhaseTimes::UpdateRSSkippedCards); + } } void G1RemSet::cleanupHRRS() { --- old/src/hotspot/share/gc/g1/g1RootProcessor.cpp 2018-04-13 11:50:10.655581727 +0200 +++ new/src/hotspot/share/gc/g1/g1RootProcessor.cpp 2018-04-13 11:50:10.298570786 +0200 @@ -72,10 +72,12 @@ _lock(Mutex::leaf, "G1 Root Scanning barrier lock", false, Monitor::_safepoint_check_never), _n_workers_discovered_strong_classes(0) {} -void G1RootProcessor::evacuate_roots(G1ParScanThreadState* pss, G1EvacuationRootClosures* closures, uint worker_i) { - double ext_roots_start = os::elapsedTime(); +void G1RootProcessor::evacuate_roots(G1ParScanThreadState* pss, uint worker_i) { G1GCPhaseTimes* phase_times = _g1h->g1_policy()->phase_times(); + G1EvacPhaseTimesTracker timer(phase_times, pss, G1GCPhaseTimes::ExtRootScan, worker_i); + + G1EvacuationRootClosures* closures = pss->closures(); process_java_roots(closures, phase_times, worker_i); // This is the point where this worker thread will not find more strong CLDs/nmethods. @@ -117,14 +119,6 @@ assert(closures->second_pass_weak_clds() == NULL, "Should be null if not tracing metadata."); } - double const obj_copy_time_sec = TicksToTimeHelper::seconds(pss->trim_ticks_and_reset()); - - phase_times->record_time_secs(G1GCPhaseTimes::ObjCopy, worker_i, obj_copy_time_sec); - - double ext_root_time_sec = os::elapsedTime() - ext_roots_start - obj_copy_time_sec; - - phase_times->record_time_secs(G1GCPhaseTimes::ExtRootScan, worker_i, ext_root_time_sec); - // During conc marking we have to filter the per-thread SATB buffers // to make sure we remove any oops into the CSet (which will show up // as implicitly live). --- old/src/hotspot/share/gc/g1/g1RootProcessor.hpp 2018-04-13 11:50:12.639642531 +0200 +++ new/src/hotspot/share/gc/g1/g1RootProcessor.hpp 2018-04-13 11:50:12.270631222 +0200 @@ -1,5 +1,5 @@ /* - * Copyright (c) 2015, 2017, Oracle and/or its affiliates. All rights reserved. + * Copyright (c) 2015, 2018, 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 @@ -98,10 +98,10 @@ public: G1RootProcessor(G1CollectedHeap* g1h, uint n_workers); - // Apply closures to the strongly and weakly reachable roots in the system + // Apply correct closures from pss to the strongly and weakly reachable roots in the system // in a single pass. // Record and report timing measurements for sub phases using the worker_i - void evacuate_roots(G1ParScanThreadState* pss, G1EvacuationRootClosures* closures, uint worker_i); + void evacuate_roots(G1ParScanThreadState* pss, uint worker_id); // Apply oops, clds and blobs to all strongly reachable roots in the system void process_strong_roots(OopClosure* oops, --- old/src/hotspot/share/gc/g1/g1SharedClosures.hpp 2018-04-13 11:50:14.767707749 +0200 +++ new/src/hotspot/share/gc/g1/g1SharedClosures.hpp 2018-04-13 11:50:14.366695459 +0200 @@ -44,9 +44,4 @@ _oops_in_cld(g1h, pss), _clds(&_oops_in_cld, process_only_dirty, must_claim_cld), _codeblobs(&_oops) {} - - double trim_time_sec() { - return TicksToTimeHelper::seconds(_oops.trim_ticks_and_reset()) + - TicksToTimeHelper::seconds(_oops_in_cld.trim_ticks_and_reset()); - } };