327 uint max_young_length = desired_max_length - base_min_length; |
327 uint max_young_length = desired_max_length - base_min_length; |
328 |
328 |
329 const double target_pause_time_ms = _mmu_tracker->max_gc_time() * 1000.0; |
329 const double target_pause_time_ms = _mmu_tracker->max_gc_time() * 1000.0; |
330 const double survivor_regions_evac_time = predict_survivor_regions_evac_time(); |
330 const double survivor_regions_evac_time = predict_survivor_regions_evac_time(); |
331 const size_t pending_cards = _analytics->predict_pending_cards(); |
331 const size_t pending_cards = _analytics->predict_pending_cards(); |
332 const size_t scanned_cards = _analytics->predict_card_num(rs_length, true /* for_young_gc */); |
|
333 const double base_time_ms = |
332 const double base_time_ms = |
334 predict_base_elapsed_time_ms(pending_cards, scanned_cards) + |
333 predict_base_elapsed_time_ms(pending_cards, rs_length) + |
335 survivor_regions_evac_time; |
334 survivor_regions_evac_time; |
336 const uint available_free_regions = _free_regions_at_end_of_collection; |
335 const uint available_free_regions = _free_regions_at_end_of_collection; |
337 const uint base_free_regions = |
336 const uint base_free_regions = |
338 available_free_regions > _reserve_regions ? available_free_regions - _reserve_regions : 0; |
337 available_free_regions > _reserve_regions ? available_free_regions - _reserve_regions : 0; |
339 |
338 |
711 maybe_start_marking(); |
710 maybe_start_marking(); |
712 } |
711 } |
713 } |
712 } |
714 |
713 |
715 _short_lived_surv_rate_group->start_adding_regions(); |
714 _short_lived_surv_rate_group->start_adding_regions(); |
716 // Do that for any other surv rate groups |
715 |
717 |
716 double merge_hcc_time_ms = average_time_ms(G1GCPhaseTimes::MergeHCC); |
718 double scan_hcc_time_ms = G1HotCardCache::default_use_cache() ? average_time_ms(G1GCPhaseTimes::MergeHCC) : 0.0; |
|
719 |
|
720 if (update_stats) { |
717 if (update_stats) { |
721 double cost_per_logged_card = 0.0; |
718 size_t const total_log_buffer_cards = p->sum_thread_work_items(G1GCPhaseTimes::MergeHCC, G1GCPhaseTimes::MergeHCCDirtyCards) + |
722 size_t const pending_logged_cards = p->sum_thread_work_items(G1GCPhaseTimes::MergeLB, G1GCPhaseTimes::MergeLBDirtyCards); |
719 p->sum_thread_work_items(G1GCPhaseTimes::MergeLB, G1GCPhaseTimes::MergeLBDirtyCards); |
723 if (pending_logged_cards > 0) { |
720 // Update prediction for card merge; MergeRSDirtyCards includes the cards from the Eager Reclaim phase. |
724 cost_per_logged_card = logged_cards_processing_time() / pending_logged_cards; |
721 size_t const total_cards_merged = p->sum_thread_work_items(G1GCPhaseTimes::MergeRS, G1GCPhaseTimes::MergeRSDirtyCards) + |
725 _analytics->report_cost_per_logged_card_ms(cost_per_logged_card); |
722 p->sum_thread_work_items(G1GCPhaseTimes::OptMergeRS, G1GCPhaseTimes::MergeRSDirtyCards) + |
726 } |
723 total_log_buffer_cards; |
727 _analytics->report_cost_scan_hcc(scan_hcc_time_ms); |
724 |
728 |
725 // The threshold for the number of cards in a given sampling which we consider |
|
726 // large enough so that the impact from setup and other costs is negligible. |
|
727 size_t const CardsNumSamplingThreshold = 10; |
|
728 |
|
729 if (total_cards_merged > CardsNumSamplingThreshold) { |
|
730 double avg_time_merge_cards = average_time_ms(G1GCPhaseTimes::MergeER) + |
|
731 average_time_ms(G1GCPhaseTimes::MergeRS) + |
|
732 average_time_ms(G1GCPhaseTimes::MergeHCC) + |
|
733 average_time_ms(G1GCPhaseTimes::MergeLB) + |
|
734 average_time_ms(G1GCPhaseTimes::OptMergeRS); |
|
735 _analytics->report_cost_per_card_merge_ms(avg_time_merge_cards / total_cards_merged, this_pause_was_young_only); |
|
736 } |
|
737 |
|
738 // Update prediction for card scan |
729 size_t const total_cards_scanned = p->sum_thread_work_items(G1GCPhaseTimes::ScanHR, G1GCPhaseTimes::ScanHRScannedCards) + |
739 size_t const total_cards_scanned = p->sum_thread_work_items(G1GCPhaseTimes::ScanHR, G1GCPhaseTimes::ScanHRScannedCards) + |
730 p->sum_thread_work_items(G1GCPhaseTimes::OptScanHR, G1GCPhaseTimes::ScanHRScannedCards); |
740 p->sum_thread_work_items(G1GCPhaseTimes::OptScanHR, G1GCPhaseTimes::ScanHRScannedCards); |
731 size_t remset_cards_scanned = 0; |
741 |
732 // There might have been duplicate log buffer entries in the queues which could |
742 if (total_cards_scanned > CardsNumSamplingThreshold) { |
733 // increase this value beyond the cards scanned. In this case attribute all cards |
743 double avg_time_dirty_card_scan = average_time_ms(G1GCPhaseTimes::ScanHR) + |
734 // to the log buffers. |
744 average_time_ms(G1GCPhaseTimes::OptScanHR); |
735 if (pending_logged_cards <= total_cards_scanned) { |
745 |
736 remset_cards_scanned = total_cards_scanned - pending_logged_cards; |
746 _analytics->report_cost_per_card_scan_ms(avg_time_dirty_card_scan / total_cards_scanned, this_pause_was_young_only); |
737 } |
747 } |
738 |
748 |
739 double cost_per_remset_card_ms = 0.0; |
749 // Update prediction for the ratio between cards from the remembered |
740 if (remset_cards_scanned > 10) { |
750 // sets and actually scanned cards from the remembered sets. |
741 double avg_time_remset_scan = ((average_time_ms(G1GCPhaseTimes::ScanHR) + average_time_ms(G1GCPhaseTimes::OptScanHR)) * |
751 // Cards from the remembered sets are all cards not duplicated by cards from |
742 remset_cards_scanned / total_cards_scanned) + |
752 // the logs. |
743 average_time_ms(G1GCPhaseTimes::MergeER) + |
753 // Due to duplicates in the log buffers, the number of actually scanned cards |
744 average_time_ms(G1GCPhaseTimes::MergeRS) + |
754 // can be smaller than the cards in the log buffers. |
745 average_time_ms(G1GCPhaseTimes::OptMergeRS); |
755 const size_t from_rs_length_cards = (total_cards_scanned > total_log_buffer_cards) ? total_cards_scanned - total_log_buffer_cards : 0; |
746 |
756 double merge_to_scan_ratio = 0.0; |
747 cost_per_remset_card_ms = avg_time_remset_scan / remset_cards_scanned; |
757 if (total_cards_scanned > 0) { |
748 _analytics->report_cost_per_remset_card_ms(cost_per_remset_card_ms, this_pause_was_young_only); |
758 merge_to_scan_ratio = (double) from_rs_length_cards / total_cards_scanned; |
749 } |
759 } |
750 |
760 _analytics->report_card_merge_to_scan_ratio(merge_to_scan_ratio, this_pause_was_young_only); |
751 if (_rs_length > 0) { |
761 |
752 double cards_per_entry_ratio = |
762 const size_t recorded_rs_length = _collection_set->recorded_rs_length(); |
753 (double) remset_cards_scanned / (double) _rs_length; |
763 const size_t rs_length_diff = _rs_length > recorded_rs_length ? _rs_length - recorded_rs_length : 0; |
754 _analytics->report_cards_per_entry_ratio(cards_per_entry_ratio, this_pause_was_young_only); |
764 _analytics->report_rs_length_diff(rs_length_diff); |
755 } |
765 |
756 |
766 // Update prediction for copy cost per byte |
757 // This is defensive. For a while _rs_length could get |
|
758 // smaller than _recorded_rs_length which was causing |
|
759 // rs_length_diff to get very large and mess up the RSet length |
|
760 // predictions. The reason was unsafe concurrent updates to the |
|
761 // _inc_cset_recorded_rs_length field which the code below guards |
|
762 // against (see CR 7118202). This bug has now been fixed (see CR |
|
763 // 7119027). However, I'm still worried that |
|
764 // _inc_cset_recorded_rs_length might still end up somewhat |
|
765 // inaccurate. The concurrent refinement thread calculates an |
|
766 // RSet's length concurrently with other CR threads updating it |
|
767 // which might cause it to calculate the length incorrectly (if, |
|
768 // say, it's in mid-coarsening). So I'll leave in the defensive |
|
769 // conditional below just in case. |
|
770 size_t rs_length_diff = 0; |
|
771 size_t recorded_rs_length = _collection_set->recorded_rs_length(); |
|
772 if (_rs_length > recorded_rs_length) { |
|
773 rs_length_diff = _rs_length - recorded_rs_length; |
|
774 } |
|
775 _analytics->report_rs_length_diff((double) rs_length_diff); |
|
776 |
|
777 size_t copied_bytes = p->sum_thread_work_items(G1GCPhaseTimes::MergePSS, G1GCPhaseTimes::MergePSSCopiedBytes); |
767 size_t copied_bytes = p->sum_thread_work_items(G1GCPhaseTimes::MergePSS, G1GCPhaseTimes::MergePSSCopiedBytes); |
778 |
768 |
779 if (copied_bytes > 0) { |
769 if (copied_bytes > 0) { |
780 double cost_per_byte_ms = (average_time_ms(G1GCPhaseTimes::ObjCopy) + average_time_ms(G1GCPhaseTimes::OptObjCopy)) / copied_bytes; |
770 double cost_per_byte_ms = (average_time_ms(G1GCPhaseTimes::ObjCopy) + average_time_ms(G1GCPhaseTimes::OptObjCopy)) / copied_bytes; |
781 _analytics->report_cost_per_byte_ms(cost_per_byte_ms, collector_state()->mark_or_rebuild_in_progress()); |
771 _analytics->report_cost_per_byte_ms(cost_per_byte_ms, collector_state()->mark_or_rebuild_in_progress()); |
840 } |
830 } |
841 |
831 |
842 // Note that _mmu_tracker->max_gc_time() returns the time in seconds. |
832 // Note that _mmu_tracker->max_gc_time() returns the time in seconds. |
843 double scan_logged_cards_time_goal_ms = _mmu_tracker->max_gc_time() * MILLIUNITS * G1RSetUpdatingPauseTimePercent / 100.0; |
833 double scan_logged_cards_time_goal_ms = _mmu_tracker->max_gc_time() * MILLIUNITS * G1RSetUpdatingPauseTimePercent / 100.0; |
844 |
834 |
845 if (scan_logged_cards_time_goal_ms < scan_hcc_time_ms) { |
835 if (scan_logged_cards_time_goal_ms < merge_hcc_time_ms) { |
846 log_debug(gc, ergo, refine)("Adjust concurrent refinement thresholds (scanning the HCC expected to take longer than Update RS time goal)." |
836 log_debug(gc, ergo, refine)("Adjust concurrent refinement thresholds (scanning the HCC expected to take longer than Update RS time goal)." |
847 "Logged Cards Scan time goal: %1.2fms Scan HCC time: %1.2fms", |
837 "Logged Cards Scan time goal: %1.2fms Scan HCC time: %1.2fms", |
848 scan_logged_cards_time_goal_ms, scan_hcc_time_ms); |
838 scan_logged_cards_time_goal_ms, merge_hcc_time_ms); |
849 |
839 |
850 scan_logged_cards_time_goal_ms = 0; |
840 scan_logged_cards_time_goal_ms = 0; |
851 } else { |
841 } else { |
852 scan_logged_cards_time_goal_ms -= scan_hcc_time_ms; |
842 scan_logged_cards_time_goal_ms -= merge_hcc_time_ms; |
853 } |
843 } |
854 |
844 |
855 _pending_cards_at_prev_gc_end = _g1h->pending_card_num(); |
845 _pending_cards_at_prev_gc_end = _g1h->pending_card_num(); |
856 double const logged_cards_time = logged_cards_processing_time(); |
846 double const logged_cards_time = logged_cards_processing_time(); |
857 |
847 |
858 log_debug(gc, ergo, refine)("Concurrent refinement times: Logged Cards Scan time goal: %1.2fms Logged Cards Scan time: %1.2fms HCC time: %1.2fms", |
848 log_debug(gc, ergo, refine)("Concurrent refinement times: Logged Cards Scan time goal: %1.2fms Logged Cards Scan time: %1.2fms HCC time: %1.2fms", |
859 scan_logged_cards_time_goal_ms, logged_cards_time, scan_hcc_time_ms); |
849 scan_logged_cards_time_goal_ms, logged_cards_time, merge_hcc_time_ms); |
860 |
850 |
861 _g1h->concurrent_refine()->adjust(logged_cards_time, |
851 _g1h->concurrent_refine()->adjust(logged_cards_time, |
862 phase_times()->sum_thread_work_items(G1GCPhaseTimes::MergeLB, G1GCPhaseTimes::MergeLBDirtyCards), |
852 phase_times()->sum_thread_work_items(G1GCPhaseTimes::MergeLB, G1GCPhaseTimes::MergeLBDirtyCards), |
863 scan_logged_cards_time_goal_ms); |
853 scan_logged_cards_time_goal_ms); |
864 } |
854 } |
934 double G1Policy::accum_yg_surv_rate_pred(int age) const { |
924 double G1Policy::accum_yg_surv_rate_pred(int age) const { |
935 return _short_lived_surv_rate_group->accum_surv_rate_pred(age); |
925 return _short_lived_surv_rate_group->accum_surv_rate_pred(age); |
936 } |
926 } |
937 |
927 |
938 double G1Policy::predict_base_elapsed_time_ms(size_t pending_cards, |
928 double G1Policy::predict_base_elapsed_time_ms(size_t pending_cards, |
939 size_t scanned_cards) const { |
929 size_t rs_length) const { |
|
930 size_t effective_scanned_cards = _analytics->predict_scan_card_num(rs_length, collector_state()->in_young_only_phase()); |
940 return |
931 return |
941 _analytics->predict_rs_update_time_ms(pending_cards) + |
932 _analytics->predict_card_merge_time_ms(pending_cards + rs_length, collector_state()->in_young_only_phase()) + |
942 _analytics->predict_rs_scan_time_ms(scanned_cards, collector_state()->in_young_only_phase()) + |
933 _analytics->predict_card_scan_time_ms(effective_scanned_cards, collector_state()->in_young_only_phase()) + |
943 _analytics->predict_constant_other_time_ms(); |
934 _analytics->predict_constant_other_time_ms(); |
944 } |
935 } |
945 |
936 |
946 double G1Policy::predict_base_elapsed_time_ms(size_t pending_cards) const { |
937 double G1Policy::predict_base_elapsed_time_ms(size_t pending_cards) const { |
947 size_t rs_length = _analytics->predict_rs_length(); |
938 size_t rs_length = _analytics->predict_rs_length(); |
948 size_t card_num = _analytics->predict_card_num(rs_length, collector_state()->in_young_only_phase()); |
939 return predict_base_elapsed_time_ms(pending_cards, rs_length); |
949 return predict_base_elapsed_time_ms(pending_cards, card_num); |
|
950 } |
940 } |
951 |
941 |
952 size_t G1Policy::predict_bytes_to_copy(HeapRegion* hr) const { |
942 size_t G1Policy::predict_bytes_to_copy(HeapRegion* hr) const { |
953 size_t bytes_to_copy; |
943 size_t bytes_to_copy; |
954 if (!hr->is_young()) { |
944 if (!hr->is_young()) { |
963 } |
953 } |
964 |
954 |
965 double G1Policy::predict_region_elapsed_time_ms(HeapRegion* hr, |
955 double G1Policy::predict_region_elapsed_time_ms(HeapRegion* hr, |
966 bool for_young_gc) const { |
956 bool for_young_gc) const { |
967 size_t rs_length = hr->rem_set()->occupied(); |
957 size_t rs_length = hr->rem_set()->occupied(); |
968 // Predicting the number of cards is based on which type of GC |
958 size_t scan_card_num = _analytics->predict_scan_card_num(rs_length, for_young_gc); |
969 // we're predicting for. |
959 |
970 size_t card_num = _analytics->predict_card_num(rs_length, for_young_gc); |
|
971 size_t bytes_to_copy = predict_bytes_to_copy(hr); |
960 size_t bytes_to_copy = predict_bytes_to_copy(hr); |
972 |
961 |
973 double region_elapsed_time_ms = |
962 double region_elapsed_time_ms = |
974 _analytics->predict_rs_scan_time_ms(card_num, collector_state()->in_young_only_phase()) + |
963 _analytics->predict_card_merge_time_ms(rs_length, collector_state()->in_young_only_phase()) + |
|
964 _analytics->predict_card_scan_time_ms(scan_card_num, collector_state()->in_young_only_phase()) + |
975 _analytics->predict_object_copy_time_ms(bytes_to_copy, collector_state()->mark_or_rebuild_in_progress()); |
965 _analytics->predict_object_copy_time_ms(bytes_to_copy, collector_state()->mark_or_rebuild_in_progress()); |
976 |
966 |
977 // The prediction of the "other" time for this region is based |
967 // The prediction of the "other" time for this region is based |
978 // upon the region type and NOT the GC type. |
968 // upon the region type and NOT the GC type. |
979 if (hr->is_young()) { |
969 if (hr->is_young()) { |