JDK-8227665 : Clearing collection set candidates takes a significant amount of time
  • Type: Enhancement
  • Component: hotspot
  • Sub-Component: gc
  • Affected Version: 12,13,14
  • Priority: P4
  • Status: Closed
  • Resolution: Duplicate
  • Submitted: 2019-07-15
  • Updated: 2021-08-31
  • Resolved: 2021-08-31
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
Other
tbdResolved
Related Reports
Duplicate :  
JDK-8017163 - G1: Refactor remembered sets
Relates :  
JDK-8152948 - More unaccounted other time on large machines
Relates :  
JDK-8227671 - G1: assert_used_and_recalculate_used_equal performs work in product builds
Relates :  
JDK-8190269 - JEP 344: Abortable Mixed Collections for G1
Relates :  
JDK-8218668 - Clean up evacuation of optional collection set
Description
After a mixed gc phase we clear the remembered sets of collection set candidates serially.

This may take a significant amount of time (BigRAMTester@50G heap@32M regions ~70ms; BigRAMTester@50G heap@1M regions ~800ms) every time at the last mixed gc in a mixed gc phase.

This started to show up with JDK13 after the refactoring in JDK-8218668 as high "Other" time, but has been a problem since introduction in JDK-8190269.  

Parallelize in some way.
Comments
After some measurements the problem seems to be that deleting and new'ing the memory for the sparse PRT tables takes most of the time. Simple parallelization does not seem to help at all (if I got it right). Replacing the delete/new with an unconditional clear() halves the time spent.
15-07-2019
Relevant log for the 1M region size case: [...] [286.008s][info ][gc,phases ] GC(21) Other: 217.1ms [...] [575.339s][info ][gc,phases ] GC(29) Other: 845.3ms [...] [867.602s][info ][gc,phases ] GC(37) Other: 681.5ms [...] [1157.822s][info ][gc,phases ] GC(45) Other: 679.6ms [...] [1471.969s][info ][gc,phases ] GC(53) Other: 694.6ms [...] [1777.130s][info ][gc,phases ] GC(61) Other: 833.7ms [...] 32M region size: [...] [318.573s][info ][gc,phases ] GC(20) Other: 19.7ms [...] [605.019s][info ][gc,phases ] GC(28) Other: 69.6ms [...] [895.217s][info ][gc,phases ] GC(36) Other: 73.7ms [...] [1213.920s][info ][gc,phases ] GC(45) Other: 75.6ms [...] [1499.127s][info ][gc,phases ] GC(53) Other: 65.2ms (This is around 8% of total pause time for this case)
15-07-2019