Repository navigation
share jdk11_eden_space
ceragon edited this page Feb 25, 2022
·
5 revisions
-Xms19500M
-Xmx19500M
-XX:+UseG1GC
-XX:+AlwaysPreTouch
-XX:MaxGCPauseMillis=400
-XX:+UnlockExperimentalVMOptions
-XX:G1MaxNewSizePercent=80
-Xlog:gc*=info:file=/usr/local/tomcat/logs/gc.log:time,tags,level
- region size: 8Mb
- region max num: 2438
- _min_heap_byte_size: 20451426304(byte) = 19972096(kb) = 19504(Mb) = 8 * 2438
- min young length: 2438 * 5% = 121
- max young length: 2438 * 80% = 1950
- _reserve_regions: 2438 * 10% = 243.8 = 244(ceil)
- use regions: 2438 - 244 = 2194
[2022-01-25T19:23:57.286+0000][info][gc,start ] GC(36) Pause Young (Normal) (G1 Evacuation Pause)
[2022-01-25T19:23:57.287+0000][info][gc,task ] GC(36) Using 11 workers of 11 for evacuation
[2022-01-25T19:23:57.366+0000][info][gc,phases ] GC(36) Pre Evacuate Collection Set: 0.2ms
[2022-01-25T19:23:57.366+0000][info][gc,phases ] GC(36) Evacuate Collection Set: 73.3ms
[2022-01-25T19:23:57.366+0000][info][gc,phases ] GC(36) Post Evacuate Collection Set: 5.7ms
[2022-01-25T19:23:57.366+0000][info][gc,phases ] GC(36) Other: 0.6ms
[2022-01-25T19:23:57.366+0000][info][gc,heap ] GC(36) Eden regions: 1893->0(1898)
[2022-01-25T19:23:57.366+0000][info][gc,heap ] GC(36) Survivor regions: 57->52(244)
[2022-01-25T19:23:57.366+0000][info][gc,heap ] GC(36) Old regions: 64->65
[2022-01-25T19:23:57.366+0000][info][gc,heap ] GC(36) Humongous regions: 0->0
[2022-01-25T19:23:57.366+0000][info][gc,metaspace ] GC(36) Metaspace: 114532K->114532K(1153024K)
[2022-01-25T19:23:57.366+0000][info][gc ] GC(36) Pause Young (Normal) (G1 Evacuation Pause) 16098M->921M(19504M) 79.885ms
[2022-01-25T19:23:57.366+0000][info][gc,cpu ] GC(36) User=0.86s Sys=0.00s Real=0.08s
[2022-01-25T19:24:12.305+0000][info][gc,start ] GC(37) Pause Young (Normal) (G1 Evacuation Pause)
[2022-01-25T19:24:12.305+0000][info][gc,task ] GC(37) Using 11 workers of 11 for evacuation
[2022-01-25T19:24:12.376+0000][info][gc,phases ] GC(37) Pre Evacuate Collection Set: 0.2ms
[2022-01-25T19:24:12.376+0000][info][gc,phases ] GC(37) Evacuate Collection Set: 63.7ms
[2022-01-25T19:24:12.376+0000][info][gc,phases ] GC(37) Post Evacuate Collection Set: 6.2ms
[2022-01-25T19:24:12.376+0000][info][gc,phases ] GC(37) Other: 0.6ms
[2022-01-25T19:24:12.376+0000][info][gc,heap ] GC(37) Eden regions: 1898->0(80)
[2022-01-25T19:24:12.376+0000][info][gc,heap ] GC(37) Survivor regions: 52->41(244)
[2022-01-25T19:24:12.376+0000][info][gc,heap ] GC(37) Old regions: 65->65
[2022-01-25T19:24:12.376+0000][info][gc,heap ] GC(37) Humongous regions: 0->0
[2022-01-25T19:24:12.376+0000][info][gc,metaspace ] GC(37) Metaspace: 114534K->114534K(1153024K)
[2022-01-25T19:24:12.376+0000][info][gc ] GC(37) Pause Young (Normal) (G1 Evacuation Pause) 16105M->834M(19504M) 70.736ms
[2022-01-25T19:24:12.376+0000][info][gc,cpu ] GC(37) User=0.75s Sys=0.00s Real=0.07s
[2022-01-25T19:24:12.980+0000][info][gc,start ] GC(38) Pause Young (Normal) (G1 Evacuation Pause)
[2022-01-25T19:24:12.980+0000][info][gc,task ] GC(38) Using 11 workers of 11 for evacuation
[2022-01-25T19:24:13.087+0000][info][gc,phases ] GC(38) Pre Evacuate Collection Set: 0.2ms
[2022-01-25T19:24:13.087+0000][info][gc,phases ] GC(38) Evacuate Collection Set: 104.9ms
[2022-01-25T19:24:13.087+0000][info][gc,phases ] GC(38) Post Evacuate Collection Set: 1.3ms
[2022-01-25T19:24:13.087+0000][info][gc,phases ] GC(38) Other: 0.5ms
[2022-01-25T19:24:13.087+0000][info][gc,heap ] GC(38) Eden regions: 80->0(1933)
[2022-01-25T19:24:13.087+0000][info][gc,heap ] GC(38) Survivor regions: 41->16(16)
[2022-01-25T19:24:13.087+0000][info][gc,heap ] GC(38) Old regions: 65->111
[2022-01-25T19:24:13.087+0000][info][gc,heap ] GC(38) Humongous regions: 0->0
[2022-01-25T19:24:13.087+0000][info][gc,metaspace ] GC(38) Metaspace: 114534K->114534K(1153024K)
[2022-01-25T19:24:13.087+0000][info][gc ] GC(38) Pause Young (Normal) (G1 Evacuation Pause) 1474M->1006M(19504M) 107.010ms
[2022-01-25T19:24:13.087+0000][info][gc,cpu ] GC(38) User=1.16s Sys=0.00s Real=0.10s
[2022-01-25T19:24:13.857+0000][info][gc,start ] GC(39) Pause Young (Normal) (G1 Evacuation Pause)
[2022-01-25T19:24:13.857+0000][info][gc,task ] GC(39) Using 11 workers of 11 for evacuation
[2022-01-25T19:24:14.026+0000][info][gc,phases ] GC(39) Pre Evacuate Collection Set: 0.2ms
[2022-01-25T19:24:14.026+0000][info][gc,phases ] GC(39) Evacuate Collection Set: 166.8ms
[2022-01-25T19:24:14.026+0000][info][gc,phases ] GC(39) Post Evacuate Collection Set: 1.5ms
[2022-01-25T19:24:14.026+0000][info][gc,phases ] GC(39) Other: 0.5ms
[2022-01-25T19:24:14.026+0000][info][gc,heap ] GC(39) Eden regions: 105->0(105)
[2022-01-25T19:24:14.026+0000][info][gc,heap ] GC(39) Survivor regions: 16->16(16)
[2022-01-25T19:24:14.026+0000][info][gc,heap ] GC(39) Old regions: 111->188
[2022-01-25T19:24:14.026+0000][info][gc,heap ] GC(39) Humongous regions: 0->0
[2022-01-25T19:24:14.026+0000][info][gc,metaspace ] GC(39) Metaspace: 114535K->114535K(1153024K)
[2022-01-25T19:24:14.026+0000][info][gc ] GC(39) Pause Young (Normal) (G1 Evacuation Pause) 1846M->1623M(19504M) 169.080ms
[2022-01-25T19:24:14.026+0000][info][gc,cpu ] GC(39) User=1.83s Sys=0.00s Real=0.17s
| gc times | eden num | min young num | survivor num | young gen num | old gen num | heap use num | free list num | base_free_regions |
|---|---|---|---|---|---|---|---|---|
| 36(before) | 1893 | 121-57=64 | 57 | 1950 | 64 | 2014 | ||
| 36(after) | 1898 | 121-52=69 | 52 | 1950 | 65 | 2015 | 2438-52-65=2321 | |
| 37(before) | 1898 | 121-52=69 | 52 | 1950 | 65 | 2015 | 2438-52-65=2321 | 2321-244=2087 |
| 37(after) | 80 | 121-41=80 | 41 | 121 | 65 | 186 | 2438-41-65=2332 | 2332-244=2088 |
| 38(before) | 80 | 121-41=80 | 41 | 121 | 65 | 186 | ||
| 38(after) | 1933 | 121-16=105 | 16 | 1949 | 111 | 2060 | ||
| 39(before) | 105 | 121-16=105 | 16 | 121 | 111 | 232 | ||
| 39(after) | 105 | 121-16=105 | 16 | 121 | 188 | 309 |
uint G1Policy::calculate_young_list_target_length(size_t rs_lengths,
uint base_min_length,
uint desired_min_length,
uint desired_max_length) const {
if (desired_max_length <= desired_min_length) {
return desired_min_length;
}
}desired_max_length 的赋值
void G1YoungGenSizer::adjust_max_new_size(uint number_of_heap_regions) {
uint temp = _min_desired_young_length;
uint result = _max_desired_young_length;
recalculate_min_max_young_length(number_of_heap_regions, &temp, &result);
}计算可知,desired_max_length == 2438 * 80% = 1950
uint G1YoungGenSizer::calculate_default_max_length(uint new_number_of_heap_regions) {
uint default_value = (new_number_of_heap_regions * G1MaxNewSizePercent) / 100;
return MAX2(1U, default_value);
}uint G1Policy::calculate_young_list_target_length(size_t rs_lengths,
uint base_min_length,
uint desired_min_length,
uint desired_max_length) const {
uint min_young_length = desired_min_length - base_min_length;
const double base_time_ms =
predict_base_elapsed_time_ms(pending_cards, rs_length);
const uint available_free_regions = _free_regions_at_end_of_collection;
// _reserve_regions 是 244
const uint base_free_regions =
available_free_regions > _reserve_regions ? available_free_regions - _reserve_regions : 0;
G1YoungLengthPredictor p(collector_state()->mark_or_rebuild_in_progress(),
base_time_ms,
base_free_regions,
target_pause_time_ms,
this);
if (p.will_fit(min_young_length)) {
if (p.will_fit(max_young_length)) {
min_young_length = max_young_length;
} else {
}
}
return base_min_length + min_young_length;
}分析如下:
参数
- free list num: 2438 - 41 - 65 = 2332
- safety_factor: 2.2
- young_length: 121
- _reserve_regions: 2438 * 10% = 243.8 = 244(ceil)
- _base_free_regions: 2332 - 244 = 2088
- free_bytes: (2088 - 121) * 8Mb = 1967 * 8Mb = 15736Mb
- expected_bytes_to_copy: 1967 / 2.2 * 8Mb = 894 * 8Mb = 7184Mb
条件
- condition 1: 不好说,因为 _base_free_regions 在每次 GC 后就会把 eden 区清空并加入该列表
- condition 2: 上一次是 79ms,而最大值是 400ms
- condition 3: 如果走到了这里,则 _base_free_regions 至少大于 365。_base_free_regions - young_length >= 244
假设 _available_free_regions == 2321,则
- base_free_regions = 2321 - 244 = 2087
- _base_free_regions - young_length = 2087 - 121 = 1966 (free_bytes)
- safety_factor = (100 / 50) * (100 + 10) / 100 = 2.2
- 需要 copy 的空间 >= 894
class G1YoungLengthPredictor {
const double _base_time_ms;
const double _base_free_regions;
const double _target_pause_time_ms;
bool will_fit(uint young_length) const {
// young_length 在出问题的时刻是 80,因为 121-41=80
// _base_free_regions = available_free_regions - _reserve_regions
// available_free_regions = 2438 - 41 - 65 = 2332
// _reserve_regions = 244
// _base_free_regions = 2332 - 244 = 2088
// 80 >= 2088,所以是 false
if (young_length >= _base_free_regions) {
// end condition 1: not enough space for the young regions
return false;
}
const double accum_surv_rate = _policy->accum_yg_surv_rate_pred((int) young_length - 1);
const size_t bytes_to_copy = (size_t) (accum_surv_rate *
(double) HeapRegion::GrainBytes);
const double copy_time_ms = _policy->analytics()->
predict_object_copy_time_ms(bytes_to_copy, _during_cm);
const double young_other_time_ms = _policy->analytics()->
predict_young_other_time_ms(young_length);
const double pause_time_ms = _base_time_ms + copy_time_ms
+ young_other_time_ms;
// _target_pause_time_ms == 400
if (pause_time_ms > _target_pause_time_ms) {
// end condition 2: prediction is over the target pause time
return false;
}
// 2088 - 80 = 2008
const size_t free_bytes = (_base_free_regions - young_length) * HeapRegion::GrainBytes;
// safety_factor = 2.2
const double safety_factor = (100.0 / G1ConfidencePercent) * (100 + TargetPLABWastePct) / 100.0;
// 极端假设,所有 eden 区都会复制到 survivor 或者 old,
// 那么 bytes_to_copy 最大 region 个数是 121
// 即使 121 * 2.2 = 266.2,所以远远达不到 2008 这个水平
const size_t expected_bytes_to_copy = (size_t) (safety_factor * bytes_to_copy);
if (expected_bytes_to_copy > free_bytes) {
// end condition 3: out-of-space
return false;
}
// success!
return true;
}
};class G1YoungLengthPredictor {
const double _base_time_ms;
const double _base_free_regions;
const double _target_pause_time_ms;
bool will_fit(uint young_length) const {
// young_length 在出问题之前的时刻是 80,因为 1950-52=1898
// _base_free_regions = available_free_regions - _reserve_regions
// available_free_regions = 2438 - 52 - 65 = 2321
// _reserve_regions = 244
// _base_free_regions = 2321 - 244 = 2077
// 1898 >= 2077,所以为假
if (young_length >= _base_free_regions) {
// end condition 1: not enough space for the young regions
return false;
}
const double accum_surv_rate = _policy->accum_yg_surv_rate_pred((int) young_length - 1);
// accum_surv_rate <= 81
const size_t bytes_to_copy = (size_t) (accum_surv_rate *
(double) HeapRegion::GrainBytes);
const double copy_time_ms = _policy->analytics()->
predict_object_copy_time_ms(bytes_to_copy, _during_cm);
const double young_other_time_ms = _policy->analytics()->
predict_young_other_time_ms(young_length);
const double pause_time_ms = _base_time_ms + copy_time_ms
+ young_other_time_ms;
// _target_pause_time_ms == 400
if (pause_time_ms > _target_pause_time_ms) {
// end condition 2: prediction is over the target pause time
return false;
}
// (2077 - 1898) * 8Mb = 179 * 8Mb
const size_t free_bytes = (_base_free_regions - young_length) * HeapRegion::GrainBytes;
// safety_factor = 2.2
const double safety_factor = (100.0 / G1ConfidencePercent) * (100 + TargetPLABWastePct) / 100.0;
const size_t expected_bytes_to_copy = (size_t) (safety_factor * bytes_to_copy);
// expected_bytes_to_copy <= 179 * 8Mb / 2.2 = 81 * 8Mb
if (expected_bytes_to_copy > free_bytes) {
// end condition 3: out-of-space
return false;
}
// success!
return true;
}
};void G1Policy::record_new_heap_size(uint new_number_of_regions) {
double reserve_regions_d = (double) new_number_of_regions * _reserve_factor;
_reserve_regions = (uint) ceil(reserve_regions_d);
}void G1Policy::record_collection_pause_end(double pause_time_ms, bool concurrent_operation_is_full_mark) {
_free_regions_at_end_of_collection = _g1h->num_free_regions();
}class G1CollectedHeap : public CollectedHeap {
uint num_free_regions() const { return _hrm.num_free_regions(); }
};class HeapRegionManager: public CHeapObj<mtGC> {
FreeRegionList _free_list;
uint num_free_regions() const {
return _free_list.length();
}
};G1Policy::YoungTargetLengths G1Policy::young_list_target_lengths(size_t rs_length) const {
YoungTargetLengths result;
young_list_target_length =
calculate_young_list_target_length(rs_length,
base_min_length,
desired_min_length,
desired_max_length);
result.first = young_list_target_length;
return result;
}uint G1Policy::update_young_list_target_length(size_t rs_length) {
YoungTargetLengths young_lengths = young_list_target_lengths(rs_length);
_young_list_target_length = young_lengths.first;
return young_lengths.second;
}uint G1Policy::update_young_list_max_and_target_length(size_t rs_length) {
uint unbounded_target_length = update_young_list_target_length(rs_length);
}uint G1Policy::update_young_list_max_and_target_length() {
return update_young_list_max_and_target_length(_analytics->predict_rs_length());
}void G1Policy::record_collection_pause_end(double pause_time_ms, bool concurrent_operation_is_full_mark) {
size_t last_unrestrained_young_length = update_young_list_max_and_target_length();
}void G1CollectedHeap::do_collection_pause_at_safepoint_helper(double target_pause_time_ms) {
policy()->record_collection_pause_end(pause_time_ms, concurrent_operation_is_full_mark);
}-Xlog:gc*=info,gc+phases=debug:file=/usr/local/tomcat/logs/gc.log:time,tags,level
效果如下
[2022-02-16T10:19:46.747+0800][info ][gc,start ] GC(47) Pause Young (Normal) (G1 Evacuation Pause)
[2022-02-16T10:19:46.747+0800][info ][gc,task ] GC(47) Using 13 workers of 13 for evacuation
[2022-02-16T10:19:46.811+0800][info ][gc,phases ] GC(47) Pre Evacuate Collection Set: 0.0ms
[2022-02-16T10:19:46.811+0800][debug][gc,phases ] GC(47) Prepare TLABs: 0.0ms
[2022-02-16T10:19:46.811+0800][debug][gc,phases ] GC(47) Choose Collection Set: 0.0ms
[2022-02-16T10:19:46.811+0800][debug][gc,phases ] GC(47) Humongous Register: 0.0ms
[2022-02-16T10:19:46.811+0800][info ][gc,phases ] GC(47) Evacuate Collection Set: 63.3ms
[2022-02-16T10:19:46.811+0800][debug][gc,phases ] GC(47) Ext Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.4, Workers: 13
[2022-02-16T10:19:46.811+0800][debug][gc,phases ] GC(47) Update RS (ms): Min: 0.6, Avg: 0.8, Max: 1.1, Diff: 0.5, Sum: 9.9, Workers: 13
[2022-02-16T10:19:46.811+0800][debug][gc,phases ] GC(47) Processed Buffers: Min: 1, Avg: 1.7, Max: 4, Diff: 3, Sum: 22, Workers: 13
[2022-02-16T10:19:46.812+0800][debug][gc,phases ] GC(47) Scanned Cards: Min: 193, Avg: 255.5, Max: 364, Diff: 171, Sum: 3321, Workers: 13
[2022-02-16T10:19:46.812+0800][debug][gc,phases ] GC(47) Skipped Cards: Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 13
[2022-02-16T10:19:46.812+0800][debug][gc,phases ] GC(47) Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1, Workers: 13
[2022-02-16T10:19:46.812+0800][debug][gc,phases ] GC(47) Scanned Cards: Min: 0, Avg: 0.2, Max: 2, Diff: 2, Sum: 2, Workers: 13
[2022-02-16T10:19:46.812+0800][debug][gc,phases ] GC(47) Claimed Cards: Min: 0, Avg: 0.2, Max: 2, Diff: 2, Sum: 2, Workers: 13
[2022-02-16T10:19:46.812+0800][debug][gc,phases ] GC(47) Skipped Cards: Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 13
[2022-02-16T10:19:46.812+0800][debug][gc,phases ] GC(47) Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0, Workers: 13
[2022-02-16T10:19:46.812+0800][debug][gc,phases ] GC(47) AOT Root Scanning (ms): skipped
[2022-02-16T10:19:46.812+0800][debug][gc,phases ] GC(47) Object Copy (ms): Min: 62.1, Avg: 62.4, Max: 62.5, Diff: 0.4, Sum: 811.4, Workers: 13
[2022-02-16T10:19:46.812+0800][debug][gc,phases ] GC(47) Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.3, Workers: 13
[2022-02-16T10:19:46.812+0800][debug][gc,phases ] GC(47) Termination Attempts: Min: 45, Avg: 59.4, Max: 71, Diff: 26, Sum: 772, Workers: 13
[2022-02-16T10:19:46.812+0800][debug][gc,phases ] GC(47) GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1, Workers: 13
[2022-02-16T10:19:46.812+0800][debug][gc,phases ] GC(47) GC Worker Total (ms): Min: 63.2, Avg: 63.2, Max: 63.3, Diff: 0.0, Sum: 822.2, Workers: 13
[2022-02-16T10:19:46.812+0800][info ][gc,phases ] GC(47) Post Evacuate Collection Set: 0.6ms
[2022-02-16T10:19:46.812+0800][debug][gc,phases ] GC(47) Code Roots Fixup: 0.0ms
[2022-02-16T10:19:46.812+0800][debug][gc,phases ] GC(47) Clear Card Table: 0.1ms
[2022-02-16T10:19:46.812+0800][debug][gc,phases ] GC(47) Reference Processing: 0.0ms
[2022-02-16T10:19:46.812+0800][debug][gc,phases ] GC(47) Weak Processing: 0.2ms
[2022-02-16T10:19:46.812+0800][debug][gc,phases ] GC(47) Merge Per-Thread State: 0.0ms
[2022-02-16T10:19:46.812+0800][debug][gc,phases ] GC(47) Code Roots Purge: 0.0ms
[2022-02-16T10:19:46.812+0800][debug][gc,phases ] GC(47) Redirty Cards: 0.1ms
[2022-02-16T10:19:46.812+0800][debug][gc,phases ] GC(47) DerivedPointerTable Update: 0.0ms
[2022-02-16T10:19:46.812+0800][debug][gc,phases ] GC(47) Free Collection Set: 0.1ms
[2022-02-16T10:19:46.812+0800][debug][gc,phases ] GC(47) Humongous Reclaim: 0.0ms
[2022-02-16T10:19:46.812+0800][debug][gc,phases ] GC(47) Start New Collection Set: 0.0ms
[2022-02-16T10:19:46.812+0800][debug][gc,phases ] GC(47) Resize TLABs: 0.0ms
[2022-02-16T10:19:46.812+0800][debug][gc,phases ] GC(47) Expand Heap After Collection: 0.0ms
[2022-02-16T10:19:46.812+0800][info ][gc,phases ] GC(47) Other: 0.1ms
[2022-02-16T10:19:46.812+0800][info ][gc,heap ] GC(47) Eden regions: 125->0(101)
[2022-02-16T10:19:46.812+0800][info ][gc,heap ] GC(47) Survivor regions: 4->17(17)
[2022-02-16T10:19:46.812+0800][info ][gc,heap ] GC(47) Old regions: 114->162
[2022-02-16T10:19:46.812+0800][info ][gc,heap ] GC(47) Humongous regions: 95->57
[2022-02-16T10:19:46.812+0800][info ][gc,metaspace ] GC(47) Metaspace: 39200K->39200K(552960K)
[2022-02-16T10:19:46.812+0800][info ][gc ] GC(47) Pause Young (Normal) (G1 Evacuation Pause) 1352M->941M(2048M) 64.412ms
[2022-02-16T10:19:46.812+0800][info ][gc,cpu ] GC(47) User=0.81s Sys=0.00s Real=0.07s