--- old/src/share/vm/gc/g1/g1GCPhaseTimes.cpp 2016-03-30 16:04:37.484788991 +0200 +++ new/src/share/vm/gc/g1/g1GCPhaseTimes.cpp 2016-03-30 16:04:37.344788985 +0200 @@ -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) { - // 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); + 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, worker_time - worker_known_time); + 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_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) { --- old/src/share/vm/gc/g1/g1GCPhaseTimes.hpp 2016-03-30 16:04:37.728789001 +0200 +++ new/src/share/vm/gc/g1/g1GCPhaseTimes.hpp 2016-03-30 16:04:37.588788996 +0200 @@ -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 --- old/src/share/vm/gc/g1/workerDataArray.cpp 2016-03-30 16:04:37.956789011 +0200 +++ new/src/share/vm/gc/g1/workerDataArray.cpp 2016-03-30 16:04:37.828789006 +0200 @@ -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(); } --- old/src/share/vm/gc/g1/workerDataArray.hpp 2016-03-30 16:04:38.176789020 +0200 +++ new/src/share/vm/gc/g1/workerDataArray.hpp 2016-03-30 16:04:38.052789015 +0200 @@ -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); --- old/src/share/vm/gc/g1/workerDataArray.inline.hpp 2016-03-30 16:04:38.388789029 +0200 +++ new/src/share/vm/gc/g1/workerDataArray.inline.hpp 2016-03-30 16:04:38.256789024 +0200 @@ -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