# HG changeset patch # User brutisso # Date 1459258329 -7200 # Tue Mar 29 15:32:09 2016 +0200 # Node ID d978ce221cd4547492c1b5925c97dfc99f9990b8 # Parent 2bf42f25d7ed2fdc594e72cf4b014cd01f9c9055 imported patch active_threads diff --git a/src/share/vm/gc/g1/g1CollectedHeap.cpp b/src/share/vm/gc/g1/g1CollectedHeap.cpp --- a/src/share/vm/gc/g1/g1CollectedHeap.cpp +++ b/src/share/vm/gc/g1/g1CollectedHeap.cpp @@ -3228,7 +3228,7 @@ Threads::number_of_non_daemon_threads()); workers()->set_active_workers(active_workers); - g1_policy()->note_gc_start(active_workers); + g1_policy()->note_gc_start(); TraceCollectorStats tcs(g1mm()->incremental_collection_counters()); TraceMemoryManagerStats tms(false /* fullGC */, gc_cause()); diff --git a/src/share/vm/gc/g1/g1CollectorPolicy.cpp b/src/share/vm/gc/g1/g1CollectorPolicy.cpp --- a/src/share/vm/gc/g1/g1CollectorPolicy.cpp +++ b/src/share/vm/gc/g1/g1CollectorPolicy.cpp @@ -186,8 +186,8 @@ _collection_set->start_incremental_building(); } -void G1CollectorPolicy::note_gc_start(uint num_active_workers) { - phase_times()->note_gc_start(num_active_workers); +void G1CollectorPolicy::note_gc_start() { + phase_times()->note_gc_start(); } // Create the jstat counters for the policy. diff --git a/src/share/vm/gc/g1/g1CollectorPolicy.hpp b/src/share/vm/gc/g1/g1CollectorPolicy.hpp --- a/src/share/vm/gc/g1/g1CollectorPolicy.hpp +++ b/src/share/vm/gc/g1/g1CollectorPolicy.hpp @@ -317,7 +317,7 @@ void init(); - virtual void note_gc_start(uint num_active_workers); + virtual void note_gc_start(); // Create jstat counters for the policy. virtual void initialize_gc_policy_counters(); diff --git a/src/share/vm/gc/g1/g1GCPhaseTimes.cpp b/src/share/vm/gc/g1/g1GCPhaseTimes.cpp --- a/src/share/vm/gc/g1/g1GCPhaseTimes.cpp +++ b/src/share/vm/gc/g1/g1GCPhaseTimes.cpp @@ -33,7 +33,7 @@ #include "runtime/timer.hpp" #include "runtime/os.hpp" -static const char* Indents[5] = {"", " ", " ", " ", " "}; +static const char* Indents[5] = {"", " ", " ", " ", " "}; G1GCPhaseTimes::G1GCPhaseTimes(uint max_gc_threads) : _max_gc_threads(max_gc_threads) @@ -94,11 +94,8 @@ _gc_par_phases[PreserveCMReferents] = new WorkerDataArray(max_gc_threads, "Parallel Preserve CM Refs (ms):"); } -void G1GCPhaseTimes::note_gc_start(uint active_gc_threads) { - assert(active_gc_threads > 0, "The number of threads must be > 0"); - assert(active_gc_threads <= _max_gc_threads, "The number of active threads must be <= the max number of threads"); +void G1GCPhaseTimes::note_gc_start() { _gc_start_counter = os::elapsed_counter(); - _active_gc_threads = active_gc_threads; _cur_expand_heap_time_ms = 0.0; _external_accounted_time_ms = 0.0; @@ -109,31 +106,56 @@ } } +#define ASSERT_PHASE_UNINITILAIZED(phase) \ + assert(_gc_par_phases[phase]->get(i) == uninitialized, "Phase " #phase " reported for thread that was not started"); + +#define ADD_WORKER_KNOWN_TIME(phase) \ + do { \ + double value = _gc_par_phases[phase]->get(i); \ + if (value != uninitialized) { \ + worker_known_time += value; \ + } \ + } while(false) + void G1GCPhaseTimes::note_gc_end() { _gc_pause_time_ms = TimeHelper::counter_to_millis(os::elapsed_counter() - _gc_start_counter); - for (uint i = 0; i < _active_gc_threads; i++) { - double worker_time = _gc_par_phases[GCWorkerEnd]->get(i) - _gc_par_phases[GCWorkerStart]->get(i); - record_time_secs(GCWorkerTotal, i , worker_time); - double worker_known_time = - _gc_par_phases[ExtRootScan]->get(i) + - _gc_par_phases[SATBFiltering]->get(i) + - _gc_par_phases[UpdateRS]->get(i) + - _gc_par_phases[ScanRS]->get(i) + - _gc_par_phases[CodeRoots]->get(i) + - _gc_par_phases[ObjCopy]->get(i) + - _gc_par_phases[Termination]->get(i); + double uninitialized = _gc_par_phases[GCWorkerStart]->uninitialized(); - record_time_secs(Other, i, worker_time - worker_known_time); - } + for (uint i = 0; i < _max_gc_threads; i++) { + double worker_start = _gc_par_phases[GCWorkerStart]->get(i); + if (worker_start == uninitialized) { + // Make sure all slots are uninitialized since this thread did not seem to have been started + ASSERT_PHASE_UNINITILAIZED(GCWorkerEnd); + ASSERT_PHASE_UNINITILAIZED(ExtRootScan); + ASSERT_PHASE_UNINITILAIZED(SATBFiltering); + ASSERT_PHASE_UNINITILAIZED(UpdateRS); + ASSERT_PHASE_UNINITILAIZED(ScanRS); + ASSERT_PHASE_UNINITILAIZED(CodeRoots); + ASSERT_PHASE_UNINITILAIZED(ObjCopy); + ASSERT_PHASE_UNINITILAIZED(Termination); + } else { + assert(_gc_par_phases[GCWorkerEnd]->get(i) != _gc_par_phases[GCWorkerEnd]->uninitialized(), "Worker started but not ended."); + double worker_time = _gc_par_phases[GCWorkerEnd]->get(i) - _gc_par_phases[GCWorkerStart]->get(i); + record_time_secs(GCWorkerTotal, i , worker_time); - for (int i = 0; i < GCParPhasesSentinel; i++) { - if (_gc_par_phases[i] != NULL) { - _gc_par_phases[i]->verify(_active_gc_threads); + double worker_known_time = 0.0; + ADD_WORKER_KNOWN_TIME(ExtRootScan); + ADD_WORKER_KNOWN_TIME(SATBFiltering); + ADD_WORKER_KNOWN_TIME(UpdateRS); + ADD_WORKER_KNOWN_TIME(ScanRS); + ADD_WORKER_KNOWN_TIME(CodeRoots); + ADD_WORKER_KNOWN_TIME(ObjCopy); + ADD_WORKER_KNOWN_TIME(Termination); + + record_time_secs(Other, i, worker_time - worker_known_time); } } } +#undef ADD_WORKER_KNOWN_TIME +#undef ASSERT_PHASE_UNINITILAIZED + // record the time a phase took in seconds void G1GCPhaseTimes::record_time_secs(GCParPhases phase, uint worker_i, double secs) { _gc_par_phases[phase]->set(worker_i, secs); @@ -150,12 +172,12 @@ // return the average time for a phase in milliseconds double G1GCPhaseTimes::average_time_ms(GCParPhases phase) { - return _gc_par_phases[phase]->average(_active_gc_threads) * 1000.0; + return _gc_par_phases[phase]->average() * 1000.0; } size_t G1GCPhaseTimes::sum_thread_work_items(GCParPhases phase) { assert(_gc_par_phases[phase]->thread_work_items() != NULL, "No sub count"); - return _gc_par_phases[phase]->thread_work_items()->sum(_active_gc_threads); + return _gc_par_phases[phase]->thread_work_items()->sum(); } template @@ -164,19 +186,19 @@ if (log.is_level(LogLevel::Trace)) { outputStream* trace_out = log.trace_stream(); trace_out->print("%s", indent); - phase->print_details_on(trace_out, _active_gc_threads); + phase->print_details_on(trace_out); } } void G1GCPhaseTimes::log_phase(WorkerDataArray* phase, uint indent, outputStream* out, bool print_sum) { out->print("%s", Indents[indent]); - phase->print_summary_on(out, _active_gc_threads, print_sum); + phase->print_summary_on(out, print_sum); details(phase, Indents[indent]); WorkerDataArray* work_items = phase->thread_work_items(); if (work_items != NULL) { out->print("%s", Indents[indent + 1]); - work_items->print_summary_on(out, _active_gc_threads, true); + work_items->print_summary_on(out, true); details(work_items, Indents[indent + 1]); } } diff --git a/src/share/vm/gc/g1/g1GCPhaseTimes.hpp b/src/share/vm/gc/g1/g1GCPhaseTimes.hpp --- a/src/share/vm/gc/g1/g1GCPhaseTimes.hpp +++ b/src/share/vm/gc/g1/g1GCPhaseTimes.hpp @@ -32,7 +32,6 @@ template class WorkerDataArray; class G1GCPhaseTimes : public CHeapObj { - uint _active_gc_threads; uint _max_gc_threads; jlong _gc_start_counter; double _gc_pause_time_ms; @@ -133,7 +132,7 @@ public: G1GCPhaseTimes(uint max_gc_threads); - void note_gc_start(uint active_gc_threads); + void note_gc_start(); void print(); // record the time a phase took in seconds diff --git a/src/share/vm/gc/g1/workerDataArray.cpp b/src/share/vm/gc/g1/workerDataArray.cpp --- a/src/share/vm/gc/g1/workerDataArray.cpp +++ b/src/share/vm/gc/g1/workerDataArray.cpp @@ -47,19 +47,29 @@ } template <> -void WorkerDataArray::WDAPrinter::details(const WorkerDataArray* phase, outputStream* out, uint active_threads) { +void WorkerDataArray::WDAPrinter::details(const WorkerDataArray* phase, outputStream* out) { out->print("%-25s", ""); - for (uint i = 0; i < active_threads; ++i) { - out->print(" %4.1lf", phase->get(i) * 1000.0); + for (uint i = 0; i < phase->_length; ++i) { + double value = phase->get(i); + if (value != phase->uninitialized()) { + out->print(" %4.1lf", phase->get(i) * 1000.0); + } else { + out->print(" -"); + } } out->cr(); } template <> -void WorkerDataArray::WDAPrinter::details(const WorkerDataArray* phase, outputStream* out, uint active_threads) { +void WorkerDataArray::WDAPrinter::details(const WorkerDataArray* phase, outputStream* out) { out->print("%-25s", ""); - for (uint i = 0; i < active_threads; ++i) { - out->print(" " SIZE_FORMAT, phase->get(i)); + for (uint i = 0; i < phase->_length; ++i) { + size_t value = phase->get(i); + if (value != phase->uninitialized()) { + out->print(" " SIZE_FORMAT, phase->get(i)); + } else { + out->print(" -"); + } } out->cr(); } @@ -80,8 +90,8 @@ assert(array.get(i) == expected[i], "Expected elements to match"); } - assert(array.sum(length) == (5 + 3 + 7), "Expected sums to match"); - assert(array.average(length) == 5.0, "Expected averages to match"); + assert(array.sum() == (5 + 3 + 7), "Expected sums to match"); + assert(array.average() == 5.0, "Expected averages to match"); for (uint i = 0; i < length; i++) { array.add(i, 1); diff --git a/src/share/vm/gc/g1/workerDataArray.hpp b/src/share/vm/gc/g1/workerDataArray.hpp --- a/src/share/vm/gc/g1/workerDataArray.hpp +++ b/src/share/vm/gc/g1/workerDataArray.hpp @@ -32,16 +32,13 @@ template class WorkerDataArray : public CHeapObj { + friend class WDAPrinter; T* _data; uint _length; const char* _title; WorkerDataArray* _thread_work_items; - NOT_PRODUCT(inline T uninitialized() const;) - - void set_all(T value); - public: WorkerDataArray(uint length, const char* title); ~WorkerDataArray(); @@ -52,22 +49,22 @@ return _thread_work_items; } + inline T uninitialized() const; + void set(uint worker_i, T value); T get(uint worker_i) const; void add(uint worker_i, T value); - double average(uint active_threads) const; - T sum(uint active_threads) const; + double average() const; + T sum() const; const char* title() const { return _title; } - void clear(); - - void reset() PRODUCT_RETURN; - void verify(uint active_threads) const PRODUCT_RETURN; + void reset(); + void set_all(T value); private: @@ -76,13 +73,13 @@ static void summary(outputStream* out, const char* title, double min, double avg, double max, double diff, double sum, bool print_sum); static void summary(outputStream* out, const char* title, size_t min, double avg, size_t max, size_t diff, size_t sum, bool print_sum); - static void details(const WorkerDataArray* phase, outputStream* out, uint active_threads); - static void details(const WorkerDataArray* phase, outputStream* out, uint active_threads); + static void details(const WorkerDataArray* phase, outputStream* out); + static void details(const WorkerDataArray* phase, outputStream* out); }; public: - void print_summary_on(outputStream* out, uint active_threads, bool print_sum = true) const; - void print_details_on(outputStream* out, uint active_threads) const; + void print_summary_on(outputStream* out, bool print_sum = true) const; + void print_details_on(outputStream* out) const; }; #endif // SHARE_VM_GC_G1_WORKERDATAARRAY_HPP diff --git a/src/share/vm/gc/g1/workerDataArray.inline.hpp b/src/share/vm/gc/g1/workerDataArray.inline.hpp --- a/src/share/vm/gc/g1/workerDataArray.inline.hpp +++ b/src/share/vm/gc/g1/workerDataArray.inline.hpp @@ -50,7 +50,6 @@ template T WorkerDataArray::get(uint worker_i) const { assert(worker_i < _length, "Worker %d is greater than max: %d", worker_i, _length); - assert(_data[worker_i] != uninitialized(), "No data added for worker %d", worker_i); return _data[worker_i]; } @@ -78,25 +77,31 @@ } template -double WorkerDataArray::average(uint active_threads) const { - return sum(active_threads) / (double) active_threads; +double WorkerDataArray::average() const { + uint active_threads = 0; + for (uint i = 0; i < _length; ++i) { + if (get(i) != uninitialized()) { + active_threads++; + } + } + if (active_threads == 0) { + return 0.0; + } + return sum() / (double) active_threads; } template -T WorkerDataArray::sum(uint active_threads) const { - T s = get(0); - for (uint i = 1; i < active_threads; ++i) { - s += get(i); +T WorkerDataArray::sum() const { + T s = 0; + for (uint i = 0; i < _length; ++i) { + if (get(i) != uninitialized()) { + s += get(i); + } } return s; } template -void WorkerDataArray::clear() { - set_all(0); -} - -template void WorkerDataArray::set_all(T value) { for (uint i = 0; i < _length; i++) { _data[i] = value; @@ -104,27 +109,36 @@ } template -void WorkerDataArray::print_summary_on(outputStream* out, uint active_threads, bool print_sum) const { - T max = get(0); - T min = max; +void WorkerDataArray::print_summary_on(outputStream* out, bool print_sum) const { + uint start = 0; + while (get(start) == uninitialized()) { + assert(start < _length, "Printing unused WorkerDataArray."); + start++; + } + T min = get(start); + T max = min; T sum = 0; - for (uint i = 1; i < active_threads; ++i) { + uint active_threads = 0; + for (uint i = start; i < _length; ++i) { T value = get(i); - max = MAX2(max, value); - min = MIN2(min, value); - sum += value; + if (value != uninitialized()) { + max = MAX2(max, value); + min = MIN2(min, value); + sum += value; + active_threads++; + } } T diff = max - min; + assert(active_threads != 0, "Must be since we found a used value for the start index"); double avg = sum / (double) active_threads; WDAPrinter::summary(out, title(), min, avg, max, diff, sum, print_sum); } template -void WorkerDataArray::print_details_on(outputStream* out, uint active_threads) const { - WDAPrinter::details(this, out, active_threads); +void WorkerDataArray::print_details_on(outputStream* out) const { + WDAPrinter::details(this, out); } -#ifndef PRODUCT template void WorkerDataArray::reset() { set_all(uninitialized()); @@ -133,18 +147,6 @@ } } -template -void WorkerDataArray::verify(uint active_threads) const { - assert(active_threads <= _length, "Wrong number of active threads"); - for (uint i = 0; i < active_threads; i++) { - assert(_data[i] != uninitialized(), - "Invalid data for worker %u in '%s'", i, _title); - } - if (_thread_work_items != NULL) { - _thread_work_items->verify(active_threads); - } -} - template <> inline size_t WorkerDataArray::uninitialized() const { return (size_t)-1; @@ -154,6 +156,5 @@ inline double WorkerDataArray::uninitialized() const { return -1.0; } -#endif #endif // SHARE_VM_GC_G1_WORKERDATAARRAY_INLINE_HPP diff --git a/src/share/vm/gc/shared/workgroup.hpp b/src/share/vm/gc/shared/workgroup.hpp --- a/src/share/vm/gc/shared/workgroup.hpp +++ b/src/share/vm/gc/shared/workgroup.hpp @@ -152,7 +152,7 @@ _active_workers = MAX2(1U, _active_workers); assert(UseDynamicNumberOfGCThreads || _active_workers == _total_workers, "Unless dynamic should use total workers"); - log_info(gc, task)("GC Workers: %d", _active_workers); + log_info(gc, task)("GC Workers: using %d out of %d", _active_workers, _total_workers); } // Return the Ith worker. # HG changeset patch # User brutisso # Date 1459258338 -7200 # Tue Mar 29 15:32:18 2016 +0200 # Node ID 31322305489e1e3da93a9454369843fd0b72d665 # Parent d978ce221cd4547492c1b5925c97dfc99f9990b8 imported patch tests diff --git a/src/share/vm/gc/g1/workerDataArray.cpp b/src/share/vm/gc/g1/workerDataArray.cpp --- a/src/share/vm/gc/g1/workerDataArray.cpp +++ b/src/share/vm/gc/g1/workerDataArray.cpp @@ -75,7 +75,10 @@ } #ifndef PRODUCT -void WorkerDataArray_test() { + +#include "memory/resourceArea.hpp" + +void WorkerDataArray_test_basic() { const uint length = 3; const char* title = "Test array"; @@ -100,4 +103,83 @@ assert(array.get(i) == expected[i] + 1, "Expected add to increment values"); } } + +void WorkerDataArray_test_with_uninitialized() { + const uint length = 3; + const size_t uninitilized = (size_t)-1; + WorkerDataArray array(length, "Test array"); + + const size_t expected[length] = {5, uninitilized, 7}; + for (uint i = 0; i < length; i++) { + array.set(i, expected[i]); + } + for (uint i = 0; i < length; i++) { + assert(array.get(i) == expected[i], "Expected elements to match"); + } + + assert(array.sum() == (5 + 7), "Expected sums to match"); + assert(array.average() == 6.0, "Expected averages to match"); +} + +void WorkerDataArray_test_uninitialized() { + const uint length = 3; + const size_t uninitilized = (size_t)-1; + WorkerDataArray array(length, "Test array"); + + for (uint i = 0; i < length; i++) { + array.set(i, uninitilized); + } + + assert(array.sum() == 0, "Sum should be 0 when no slots have been used."); + assert(array.average() == 0.0, "Average should be 0.0 when no slots have been used."); +} + +void WorkerDataArray_test_print_summary() { + const uint length = 4; + const size_t uninitilized = (size_t)-1; + WorkerDataArray array(length, "Test array"); + + const size_t expected[length] = {5, uninitilized, 7, uninitilized}; + for (uint i = 0; i < length; i++) { + array.set(i, expected[i]); + } + + ResourceMark rm; + stringStream out; + array.print_summary_on(&out); + const char* out_string = out.as_string(); + const char* expected_string = "Test array Min: 5, Avg: 6,0, Max: 7, Diff: 2, Sum: 12\n"; + const size_t expected_len = strlen(expected_string); + assert(expected_len == strlen(out_string), "Wrong string length, expected " SIZE_FORMAT " but got " SIZE_FORMAT, expected_len, strlen(out_string)); + assert(strncmp(expected_string, out_string, expected_len) == 0, "Expected '%s' but got: '%s'", expected_string, out_string); +} + +void WorkerDataArray_test_print_details() { + const uint length = 4; + const size_t uninitilized = (size_t)-1; + WorkerDataArray array(length, "Test array"); + + const size_t expected[length] = {5, uninitilized, 7, uninitilized}; + for (uint i = 0; i < length; i++) { + array.set(i, expected[i]); + } + + ResourceMark rm; + stringStream out; + array.print_details_on(&out); + const char* out_string = out.as_string(); + const char* expected_string = " 5 - 7 -\n"; + const size_t expected_len = strlen(expected_string); + assert(expected_len == strlen(out_string), "Wrong string length, expected " SIZE_FORMAT " but got " SIZE_FORMAT, expected_len, strlen(out_string)); + assert(strncmp(expected_string, out_string, expected_len) == 0, "Expected '%s' but got: '%s'", expected_string, out_string); +} + +void WorkerDataArray_test() { + WorkerDataArray_test_basic(); + WorkerDataArray_test_with_uninitialized(); + WorkerDataArray_test_uninitialized(); + WorkerDataArray_test_print_summary(); + WorkerDataArray_test_print_details(); +} + #endif # HG changeset patch # User brutisso # Date 1459346547 -7200 # Wed Mar 30 16:02:27 2016 +0200 # Node ID 474f52bdae5cd2b6f760ba9616512a55633849d8 # Parent 31322305489e1e3da93a9454369843fd0b72d665 [mq]: thomas-review diff --git a/src/share/vm/gc/g1/g1GCPhaseTimes.cpp b/src/share/vm/gc/g1/g1GCPhaseTimes.cpp --- a/src/share/vm/gc/g1/g1GCPhaseTimes.cpp +++ b/src/share/vm/gc/g1/g1GCPhaseTimes.cpp @@ -106,55 +106,54 @@ } } -#define ASSERT_PHASE_UNINITILAIZED(phase) \ +#define ASSERT_PHASE_UNINITILIAZED(phase) \ assert(_gc_par_phases[phase]->get(i) == uninitialized, "Phase " #phase " reported for thread that was not started"); -#define ADD_WORKER_KNOWN_TIME(phase) \ - do { \ - double value = _gc_par_phases[phase]->get(i); \ - if (value != uninitialized) { \ - worker_known_time += value; \ - } \ - } while(false) +double G1GCPhaseTimes::worker_time(GCParPhases phase, uint worker) { + double value = _gc_par_phases[phase]->get(worker); + if (value != WorkerDataArray::uninitialized()) { + return value; + } + return 0.0; +} void G1GCPhaseTimes::note_gc_end() { _gc_pause_time_ms = TimeHelper::counter_to_millis(os::elapsed_counter() - _gc_start_counter); - double uninitialized = _gc_par_phases[GCWorkerStart]->uninitialized(); + double uninitialized = WorkerDataArray::uninitialized(); for (uint i = 0; i < _max_gc_threads; i++) { double worker_start = _gc_par_phases[GCWorkerStart]->get(i); - if (worker_start == uninitialized) { + if (worker_start != uninitialized) { + assert(_gc_par_phases[GCWorkerEnd]->get(i) != uninitialized, "Worker started but not ended."); + double total_worker_time = _gc_par_phases[GCWorkerEnd]->get(i) - _gc_par_phases[GCWorkerStart]->get(i); + record_time_secs(GCWorkerTotal, i , total_worker_time); + + double worker_known_time = + worker_time(ExtRootScan, i) + + worker_time(SATBFiltering, i) + + worker_time(UpdateRS, i) + + worker_time(ScanRS, i) + + worker_time(CodeRoots, i) + + worker_time(ObjCopy, i) + + worker_time(Termination, i); + + record_time_secs(Other, i, total_worker_time - worker_known_time); + } else { // Make sure all slots are uninitialized since this thread did not seem to have been started - ASSERT_PHASE_UNINITILAIZED(GCWorkerEnd); - ASSERT_PHASE_UNINITILAIZED(ExtRootScan); - ASSERT_PHASE_UNINITILAIZED(SATBFiltering); - ASSERT_PHASE_UNINITILAIZED(UpdateRS); - ASSERT_PHASE_UNINITILAIZED(ScanRS); - ASSERT_PHASE_UNINITILAIZED(CodeRoots); - ASSERT_PHASE_UNINITILAIZED(ObjCopy); - ASSERT_PHASE_UNINITILAIZED(Termination); - } else { - assert(_gc_par_phases[GCWorkerEnd]->get(i) != _gc_par_phases[GCWorkerEnd]->uninitialized(), "Worker started but not ended."); - double worker_time = _gc_par_phases[GCWorkerEnd]->get(i) - _gc_par_phases[GCWorkerStart]->get(i); - record_time_secs(GCWorkerTotal, i , worker_time); - - double worker_known_time = 0.0; - ADD_WORKER_KNOWN_TIME(ExtRootScan); - ADD_WORKER_KNOWN_TIME(SATBFiltering); - ADD_WORKER_KNOWN_TIME(UpdateRS); - ADD_WORKER_KNOWN_TIME(ScanRS); - ADD_WORKER_KNOWN_TIME(CodeRoots); - ADD_WORKER_KNOWN_TIME(ObjCopy); - ADD_WORKER_KNOWN_TIME(Termination); - - record_time_secs(Other, i, worker_time - worker_known_time); + ASSERT_PHASE_UNINITILIAZED(GCWorkerEnd); + ASSERT_PHASE_UNINITILIAZED(ExtRootScan); + ASSERT_PHASE_UNINITILIAZED(SATBFiltering); + ASSERT_PHASE_UNINITILIAZED(UpdateRS); + ASSERT_PHASE_UNINITILIAZED(ScanRS); + ASSERT_PHASE_UNINITILIAZED(CodeRoots); + ASSERT_PHASE_UNINITILIAZED(ObjCopy); + ASSERT_PHASE_UNINITILIAZED(Termination); } } } -#undef ADD_WORKER_KNOWN_TIME -#undef ASSERT_PHASE_UNINITILAIZED +#undef ASSERT_PHASE_UNINITILIAZED // record the time a phase took in seconds void G1GCPhaseTimes::record_time_secs(GCParPhases phase, uint worker_i, double secs) { diff --git a/src/share/vm/gc/g1/g1GCPhaseTimes.hpp b/src/share/vm/gc/g1/g1GCPhaseTimes.hpp --- a/src/share/vm/gc/g1/g1GCPhaseTimes.hpp +++ b/src/share/vm/gc/g1/g1GCPhaseTimes.hpp @@ -122,6 +122,7 @@ double _cur_verify_before_time_ms; double _cur_verify_after_time_ms; + double worker_time(GCParPhases phase, uint worker); void note_gc_end(); template diff --git a/src/share/vm/gc/g1/workerDataArray.cpp b/src/share/vm/gc/g1/workerDataArray.cpp --- a/src/share/vm/gc/g1/workerDataArray.cpp +++ b/src/share/vm/gc/g1/workerDataArray.cpp @@ -27,22 +27,28 @@ #include "utilities/ostream.hpp" template <> -void WorkerDataArray::WDAPrinter::summary(outputStream* out, const char* title, double min, double avg, double max, double diff, double sum, bool print_sum) { - out->print("%-25s Min: %4.1lf, Avg: %4.1lf, Max: %4.1lf, Diff: %4.1lf", title, min * MILLIUNITS, avg * MILLIUNITS, max * MILLIUNITS, diff* MILLIUNITS); +size_t WorkerDataArray::uninitialized() { + return (size_t)-1; +} + +template <> +double WorkerDataArray::uninitialized() { + return -1.0; +} + +template <> +void WorkerDataArray::WDAPrinter::summary(outputStream* out, double min, double avg, double max, double diff, double sum, bool print_sum) { + out->print(" Min: %4.1lf, Avg: %4.1lf, Max: %4.1lf, Diff: %4.1lf", min * MILLIUNITS, avg * MILLIUNITS, max * MILLIUNITS, diff* MILLIUNITS); if (print_sum) { - out->print_cr(", Sum: %4.1lf", sum * MILLIUNITS); - } else { - out->cr(); + out->print(", Sum: %4.1lf", sum * MILLIUNITS); } } template <> -void WorkerDataArray::WDAPrinter::summary(outputStream* out, const char* title, size_t min, double avg, size_t max, size_t diff, size_t sum, bool print_sum) { - out->print("%-25s Min: " SIZE_FORMAT ", Avg: %4.1lf, Max: " SIZE_FORMAT ", Diff: " SIZE_FORMAT, title, min, avg, max, diff); +void WorkerDataArray::WDAPrinter::summary(outputStream* out, size_t min, double avg, size_t max, size_t diff, size_t sum, bool print_sum) { + out->print(" Min: " SIZE_FORMAT ", Avg: %4.1lf, Max: " SIZE_FORMAT ", Diff: " SIZE_FORMAT, min, avg, max, diff); if (print_sum) { - out->print_cr(", Sum: " SIZE_FORMAT, sum); - } else { - out->cr(); + out->print(", Sum: " SIZE_FORMAT, sum); } } @@ -54,7 +60,7 @@ if (value != phase->uninitialized()) { out->print(" %4.1lf", phase->get(i) * 1000.0); } else { - out->print(" -"); + out->print(" -"); } } out->cr(); @@ -68,7 +74,7 @@ if (value != phase->uninitialized()) { out->print(" " SIZE_FORMAT, phase->get(i)); } else { - out->print(" -"); + out->print(" -"); } } out->cr(); @@ -106,7 +112,7 @@ void WorkerDataArray_test_with_uninitialized() { const uint length = 3; - const size_t uninitilized = (size_t)-1; + const size_t uninitilized = WorkerDataArray::uninitialized(); WorkerDataArray array(length, "Test array"); const size_t expected[length] = {5, uninitilized, 7}; @@ -123,7 +129,7 @@ void WorkerDataArray_test_uninitialized() { const uint length = 3; - const size_t uninitilized = (size_t)-1; + const size_t uninitilized = WorkerDataArray::uninitialized(); WorkerDataArray array(length, "Test array"); for (uint i = 0; i < length; i++) { @@ -136,7 +142,7 @@ void WorkerDataArray_test_print_summary() { const uint length = 4; - const size_t uninitilized = (size_t)-1; + const size_t uninitilized = WorkerDataArray::uninitialized(); WorkerDataArray array(length, "Test array"); const size_t expected[length] = {5, uninitilized, 7, uninitilized}; @@ -148,7 +154,27 @@ stringStream out; array.print_summary_on(&out); const char* out_string = out.as_string(); - const char* expected_string = "Test array Min: 5, Avg: 6,0, Max: 7, Diff: 2, Sum: 12\n"; + const char* expected_string = "Test array Min: 5, Avg: 6,0, Max: 7, Diff: 2, Sum: 12, Workers: 2\n"; + const size_t expected_len = strlen(expected_string); + assert(expected_len == strlen(out_string), "Wrong string length, expected " SIZE_FORMAT " but got " SIZE_FORMAT, expected_len, strlen(out_string)); + assert(strncmp(expected_string, out_string, expected_len) == 0, "Expected '%s' but got: '%s'", expected_string, out_string); +} + +void WorkerDataArray_test_print_summary_skipped() { + const uint length = 2; + const size_t uninitilized = WorkerDataArray::uninitialized(); + WorkerDataArray array(length, "Test array"); + + const size_t expected[length] = {uninitilized, uninitilized}; + for (uint i = 0; i < length; i++) { + array.set(i, expected[i]); + } + + ResourceMark rm; + stringStream out; + array.print_summary_on(&out); + const char* out_string = out.as_string(); + const char* expected_string = "Test array skipped\n"; const size_t expected_len = strlen(expected_string); assert(expected_len == strlen(out_string), "Wrong string length, expected " SIZE_FORMAT " but got " SIZE_FORMAT, expected_len, strlen(out_string)); assert(strncmp(expected_string, out_string, expected_len) == 0, "Expected '%s' but got: '%s'", expected_string, out_string); @@ -156,7 +182,7 @@ void WorkerDataArray_test_print_details() { const uint length = 4; - const size_t uninitilized = (size_t)-1; + const size_t uninitilized = WorkerDataArray::uninitialized(); WorkerDataArray array(length, "Test array"); const size_t expected[length] = {5, uninitilized, 7, uninitilized}; @@ -168,7 +194,7 @@ stringStream out; array.print_details_on(&out); const char* out_string = out.as_string(); - const char* expected_string = " 5 - 7 -\n"; + const char* expected_string = " 5 - 7 -\n"; const size_t expected_len = strlen(expected_string); assert(expected_len == strlen(out_string), "Wrong string length, expected " SIZE_FORMAT " but got " SIZE_FORMAT, expected_len, strlen(out_string)); assert(strncmp(expected_string, out_string, expected_len) == 0, "Expected '%s' but got: '%s'", expected_string, out_string); @@ -179,6 +205,7 @@ WorkerDataArray_test_with_uninitialized(); WorkerDataArray_test_uninitialized(); WorkerDataArray_test_print_summary(); + WorkerDataArray_test_print_summary_skipped(); WorkerDataArray_test_print_details(); } diff --git a/src/share/vm/gc/g1/workerDataArray.hpp b/src/share/vm/gc/g1/workerDataArray.hpp --- a/src/share/vm/gc/g1/workerDataArray.hpp +++ b/src/share/vm/gc/g1/workerDataArray.hpp @@ -49,13 +49,14 @@ return _thread_work_items; } - inline T uninitialized() const; + static T uninitialized(); void set(uint worker_i, T value); T get(uint worker_i) const; void add(uint worker_i, T value); + // The sum() and average() methods below consider uninitialized slots to be 0. double average() const; T sum() const; @@ -70,8 +71,8 @@ private: class WDAPrinter { public: - static void summary(outputStream* out, const char* title, double min, double avg, double max, double diff, double sum, bool print_sum); - static void summary(outputStream* out, const char* title, size_t min, double avg, size_t max, size_t diff, size_t sum, bool print_sum); + static void summary(outputStream* out, double min, double avg, double max, double diff, double sum, bool print_sum); + static void summary(outputStream* out, size_t min, double avg, size_t max, size_t diff, size_t sum, bool print_sum); static void details(const WorkerDataArray* phase, outputStream* out); static void details(const WorkerDataArray* phase, outputStream* out); diff --git a/src/share/vm/gc/g1/workerDataArray.inline.hpp b/src/share/vm/gc/g1/workerDataArray.inline.hpp --- a/src/share/vm/gc/g1/workerDataArray.inline.hpp +++ b/src/share/vm/gc/g1/workerDataArray.inline.hpp @@ -110,28 +110,34 @@ template void WorkerDataArray::print_summary_on(outputStream* out, bool print_sum) const { + out->print("%-25s", title()); uint start = 0; - while (get(start) == uninitialized()) { - assert(start < _length, "Printing unused WorkerDataArray."); + while (start < _length && get(start) == uninitialized()) { start++; } - T min = get(start); - T max = min; - T sum = 0; - uint active_threads = 0; - for (uint i = start; i < _length; ++i) { - T value = get(i); - if (value != uninitialized()) { - max = MAX2(max, value); - min = MIN2(min, value); - sum += value; - active_threads++; + if (start < _length) { + T min = get(start); + T max = min; + T sum = 0; + uint active_threads = 0; + for (uint i = start; i < _length; ++i) { + T value = get(i); + if (value != uninitialized()) { + max = MAX2(max, value); + min = MIN2(min, value); + sum += value; + active_threads++; + } } + T diff = max - min; + assert(active_threads != 0, "Must be since we found a used value for the start index"); + double avg = sum / (double) active_threads; + WDAPrinter::summary(out, min, avg, max, diff, sum, print_sum); + out->print_cr(", Workers: %d", active_threads); + } else { + // No data for this phase. + out->print_cr(" skipped"); } - T diff = max - min; - assert(active_threads != 0, "Must be since we found a used value for the start index"); - double avg = sum / (double) active_threads; - WDAPrinter::summary(out, title(), min, avg, max, diff, sum, print_sum); } template @@ -147,14 +153,4 @@ } } -template <> -inline size_t WorkerDataArray::uninitialized() const { - return (size_t)-1; -} - -template <> -inline double WorkerDataArray::uninitialized() const { - return -1.0; -} - #endif // SHARE_VM_GC_G1_WORKERDATAARRAY_INLINE_HPP