<div dir="ltr">Hi folks,<div><br>I'm looking into a report of expected reductions in the number of G1 eden regions on our compute platform, where we use CFS on our shared compute tier.<br><br>Reading through G1Policy it occurred to me that the measured cost_per_byte_ms is critical, and that if the measured workers were throttled, it would cause this weighted average to be artificially inflated, blowing out pause time estimates and clamping the eden length.<br><br>Does my reading of the code and the log snippet below support that hypothesis, or can a trained eye spot something I'm missing?<br><br>Cheers,<br>Danny<br><br>[93957.673s][1152][trace][gc,ergo,heap  ] Predicted base time: total 61.367096 lb_cards 102041 rs_length 0 effective_scanned_cards 102041 card_merge_time 0.699990 card_scan_time 22.050733 constant_other_time 6.205279 survivor_evac_time 32.411094<br>[93957.673s][1152][trace][gc,ergo,heap  ] Young desired length 860 survivor length 11 allocated young length 859 absolute min young length 859 absolute max young length 860 desired eden length by mmu 0 desired eden length by pause 849<br>[93957.673s][1152][trace][gc,ergo,heap  ] Young target length: Common free regions at end of collection 1113 desired young length 860 reserve region 144 max to eat into reserve 71<br>[93957.673s][1152][trace][gc,ergo,heap  ] Young target length: No need to use reserve receiving additional eden 1<br>[93957.673s][1152][trace][gc,ergo,heap  ] Young target length: young target length 860 allocated young length 859 received additional eden 1<br>[93957.673s][1152][trace][gc,ergo,heap  ] Young list length update: pending cards 102041 rs_length 0 old target 860 desired: 860 target: 860 max: 903<br>[93957.709s][1152][info ][gc,start      ] GC(2837) Pause Young (Mixed) (G1 Evacuation Pause)<br>[93957.709s][1152][info ][gc,task       ] GC(2837) Using 4 workers of 4 for evacuation<br>[93957.710s][1152][trace][gc,ergo,cset  ] GC(2837) Start choosing CSet. Pending cards: 97118 target pause time: 200.00ms<br>[93957.710s][1152][trace][gc,ergo,heap  ] GC(2837) Predicted base time: total 63.263775 lb_cards 97118 rs_length 25934 effective_scanned_cards 110151 card_merge_time 0.844123 card_scan_time 23.803278 constant_other_time 6.205279 survivor_evac_time 32.411094<br>[93957.710s][1152][trace][gc,ergo,cset  ] GC(2837) Added young regions to CSet. Eden: 849 regions, Survivors: 11 regions, predicted eden time: 61.51ms, predicted base time: 63.26ms, target pause time: 200.00ms, remaining time: 75.22ms<br>[93957.710s][1152][debug][gc,ergo,cset  ] GC(2837) Start adding marking candidates to collection set. Min 2 regions, max 144 regions, time remaining 75.22ms, optional threshold 15.04ms<br>[93957.710s][1152][debug][gc,ergo,cset  ] GC(2837) Marking candidates exhausted.<br>[93957.710s][1152][debug][gc,ergo,cset  ] GC(2837) Finish adding marking candidates to collection set. Initial: 13, optional: 0, predicted initial time: 17.97ms, predicted optional time: 0.00ms, time remaining: 57.25ms<br>[93957.710s][1152][debug][gc,ergo       ] GC(2837) Running G1 Merge Heap Roots using 4 workers for 873 regions<br>[93958.042s][1152][debug][gc,ergo       ] GC(2837) Running G1 Rebuild Free List Task using 4 workers for rebuilding free list of regions<br>[93958.042s][1152][debug][gc,ergo,heap  ] GC(2837) Heap expansion: short term pause time ratio 0.35% long term pause time ratio 0.33% threshold 7.69% pause time ratio 7.69% fully expanded true resize by 0B<br>[93958.042s][1152][debug][gc,ergo,ihop  ] GC(2837) Do not request concurrent cycle initiation (still doing mixed collections) occupancy: 2508193792B allocation request: 0B threshold: 0B (0.00) source: end of GC<br>[93958.042s][1152][info ][gc,mmu        ] GC(2837) MMU target violated: 201.0ms (200.0ms/201.0ms)<br>[93958.042s][1152][debug][gc,ergo       ] GC(2837) do not continue mixed GCs (candidate old regions not available)<br>[93958.042s][1152][debug][gc,ergo,ihop  ] GC(2837) Request concurrent cycle initiation (occupancy higher than threshold) occupancy: 2508193792B allocation request: 0B threshold: 0B (0.00) source: end of GC<br>[93958.042s][1152][trace][gc,ergo,heap  ] GC(2837) Predicted base time: total 164.552708 lb_cards 86379 rs_length 50370 effective_scanned_cards 88850 card_merge_time 0.930841 card_scan_time 18.267386 constant_other_time 6.197170 survivor_evac_time 139.157311<br>[93958.042s][1152][trace][gc,ergo,heap  ] GC(2837) Young desired length 159 survivor length 36 allocated young length 36 absolute min young length 71 absolute max young length 860 desired eden length by mmu 1 desired eden length by pause 123<br>[93958.042s][1152][trace][gc,ergo,heap  ] GC(2837) Young target length: Common free regions at end of collection 1099 desired young length 159 reserve region 144 max to eat into reserve 71<br>[93958.042s][1152][trace][gc,ergo,heap  ] GC(2837) Young target length: No need to use reserve receiving additional eden 123<br>[93958.042s][1152][trace][gc,ergo,heap  ] GC(2837) Young target length: young target length 159 allocated young length 36 received additional eden 123<br>[93958.042s][1152][trace][gc,ergo,heap  ] GC(2837) Young list length update: pending cards 86379 rs_length 50370 old target 860 desired: 159 target: 159 max: 202<br>[93958.042s][1152][debug][gc,ergo,refine] GC(2837) GC refinement: goal: 91539 + 6762 / 20.00ms, actual: 80518 / 17.06ms,<br>[93958.042s][1152][debug][gc,ergo,refine] GC(2837) New pending cards target: 89589<br>[93958.042s][1152][info ][gc,phases     ] GC(2837)   Pre Evacuate Collection Set: 0.9ms<br>[93958.042s][1152][info ][gc,phases     ] GC(2837)   Merge Heap Roots: 1.5ms<br>[93958.042s][1152][info ][gc,phases     ] GC(2837)   Evacuate Collection Set: 325.0ms<br>[93958.042s][1152][info ][gc,phases     ] GC(2837)   Post Evacuate Collection Set: 5.3ms<br>[93958.042s][1152][info ][gc,phases     ] GC(2837)   Other: 0.2ms<br>[93958.042s][1152][info ][gc,heap       ] GC(2837) Eden regions: 849->0(123)<br>[93958.042s][1152][info ][gc,heap       ] GC(2837) Survivor regions: 11->36(108)<br>[93958.042s][1152][info ][gc,heap       ] GC(2837) Old regions: 310->299<br>[93958.042s][1152][info ][gc,heap       ] GC(2837) Humongous regions: 0->0<br>[93958.042s][1152][info ][gc,metaspace  ] GC(2837) Metaspace: 450519K(457984K)->450519K(457984K) NonClass: 399480K(403584K)->399480K(403584K) Class: 51038K(54400K)->51038K(54400K)<br>[93958.042s][1152][info ][gc            ] GC(2837) Pause Young (Mixed) (G1 Evacuation Pause) 9349M->2668M(11472M) 333.112ms<br>[93958.043s][1152][info ][gc,cpu        ] GC(2837) User=1.19s Sys=0.00s Real=0.34s<div class="gmail-yj6qo"></div><br class="gmail-Apple-interchange-newline"></div></div>