JDK-8280396 : G1: Full gc mark stack draining should prefer to make work available to other threads
  • Type: Enhancement
  • Component: hotspot
  • Sub-Component: gc
  • Affected Version: 19
  • Priority: P4
  • Status: Resolved
  • Resolution: Fixed
  • Submitted: 2022-01-20
  • Updated: 2022-01-31
  • Resolved: 2022-01-25
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.
JDK 19
19 b07Fixed
Related Reports
Relates :  
JDK-8156754 - Encapsulate task queue policies into queue/task specific classes to use
Relates :  
JDK-8280705 - Parallel: Full gc mark stack draining should prefer to make work available to other threads
Relates :  
JDK-8280958 - G1/Parallel: rename transfer_from_overflow_stack to publish_or_pop_overflow
Relates :  
JDK-8152438 - Threads may do significant work out of the non-shared overflow buffer
Description
G1 full gc marking currently does not preferentially move overflow stack contents to make work available to other threads.

I.e. if there is a single thread having work in its overflow stack, it tries to work on that one by itself; other threads that steal that have nothing to do as the stack to steal from is kind of empty.

On BRT 20gb, in the initial full gcs to compact the heap, changing this saves 400ms of 1500ms total pause time.

This is a similar problem G1 young gc showed long time ago.
Comments
Changeset: 674a97b2 Author: Thomas Schatzl <tschatzl@openjdk.org> Date: 2022-01-25 16:27:30 +0000 URL: https://git.openjdk.java.net/jdk/commit/674a97b27ef621e7b54c13c121c625f91df5ee60
25-01-2022
A pull request was submitted for review. URL: https://git.openjdk.java.net/jdk/pull/7175 Date: 2022-01-21 14:33:46 +0000
21-01-2022
Added some logging measuring termination time (duration of the offer_termination() call in G1FullGCMarker::complete_marking: Before: [8.480s][debug][gc,phases ] GC(11) Marking task 17 termination time 864.255 [8.480s][trace][gc,phases ] GC(11) Marking task (17) 1567.888ms [8.480s][debug][gc,phases ] GC(11) Marking task 1 termination time 864.787 [8.480s][trace][gc,phases ] GC(11) Marking task (1) 1567.941ms [8.480s][debug][gc,phases ] GC(11) Marking task 4 termination time 863.128 [8.480s][trace][gc,phases ] GC(11) Marking task (4) 1567.961ms [8.480s][debug][gc,phases ] GC(11) Marking task 2 termination time 864.129 [8.480s][trace][gc,phases ] GC(11) Marking task (2) 1567.997ms [8.480s][debug][gc,phases ] GC(11) Marking task 10 termination time 863.783 [8.480s][trace][gc,phases ] GC(11) Marking task (10) 1568.017ms [8.480s][debug][gc,phases ] GC(11) Marking task 13 termination time 864.867 [8.480s][trace][gc,phases ] GC(11) Marking task (13) 1568.035ms [8.480s][debug][gc,phases ] GC(11) Marking task 15 termination time 863.915 [8.480s][trace][gc,phases ] GC(11) Marking task (15) 1568.040ms [8.480s][debug][gc,phases ] GC(11) Marking task 5 termination time 863.763 [8.480s][trace][gc,phases ] GC(11) Marking task (5) 1568.075ms [8.480s][debug][gc,phases ] GC(11) Marking task 14 termination time 864.736 [8.480s][trace][gc,phases ] GC(11) Marking task (14) 1568.071ms [8.480s][debug][gc,phases ] GC(11) Marking task 16 termination time 865.959 [8.480s][trace][gc,phases ] GC(11) Marking task (16) 1568.087ms [8.480s][debug][gc,phases ] GC(11) Marking task 9 termination time 865.703 [8.480s][trace][gc,phases ] GC(11) Marking task (9) 1568.125ms [8.480s][debug][gc,phases ] GC(11) Marking task 3 termination time 862.254 [8.480s][trace][gc,phases ] GC(11) Marking task (3) 1568.148ms [8.480s][debug][gc,phases ] GC(11) Marking task 8 termination time 863.132 [8.480s][trace][gc,phases ] GC(11) Marking task (8) 1568.167ms [8.480s][debug][gc,phases ] GC(11) Marking task 0 termination time 0.021 [8.480s][trace][gc,phases ] GC(11) Marking task (0) 1568.196ms [8.480s][debug][gc,phases ] GC(11) Marking task 11 termination time 864.775 [8.480s][debug][gc,phases ] GC(11) Marking task 6 termination time 864.212 [8.480s][trace][gc,phases ] GC(11) Marking task (6) 1568.205ms [8.480s][trace][gc,phases ] GC(11) Marking task (11) 1568.191ms [8.480s][debug][gc,phases ] GC(11) Marking task 7 termination time 864.050 [8.480s][trace][gc,phases ] GC(11) Marking task (7) 1568.224ms [8.480s][debug][gc,phases ] GC(11) Marking task 12 termination time 864.123 [8.481s][trace][gc,phases ] GC(11) Marking task (12) 1568.239ms Note that everyone is waiting for task 0 to complete, spending most of the time trying to terminate as task 0 is mostly working on its overflow queue. After: [7.525s][debug][gc,phases ] GC(11) Marking task 5 termination time 20.634 [7.525s][debug][gc,phases ] GC(11) Marking task 0 termination time 22.882 [7.525s][trace][gc,phases ] GC(11) Marking task (0) 794.927ms [7.525s][debug][gc,phases ] GC(11) Marking task 1 termination time 0.016 [7.525s][trace][gc,phases ] GC(11) Marking task (1) 794.937ms [7.525s][debug][gc,phases ] GC(11) Marking task 7 termination time 19.918 [7.525s][trace][gc,phases ] GC(11) Marking task (7) 794.960ms [7.525s][debug][gc,phases ] GC(11) Marking task 9 termination time 20.540 [7.525s][trace][gc,phases ] GC(11) Marking task (9) 794.991ms [7.525s][debug][gc,phases ] GC(11) Marking task 3 termination time 20.993 [7.525s][trace][gc,phases ] GC(11) Marking task (3) 795.039ms [7.525s][trace][gc,phases ] GC(11) Marking task (5) 794.901ms [7.525s][debug][gc,phases ] GC(11) Marking task 12 termination time 19.457 [7.525s][trace][gc,phases ] GC(11) Marking task (12) 795.053ms [7.525s][debug][gc,phases ] GC(11) Marking task 2 termination time 22.360 [7.525s][trace][gc,phases ] GC(11) Marking task (2) 795.089ms [7.525s][debug][gc,phases ] GC(11) Marking task 4 termination time 21.284 [7.525s][trace][gc,phases ] GC(11) Marking task (4) 795.146ms [7.525s][debug][gc,phases ] GC(11) Marking task 16 termination time 20.772 [7.525s][trace][gc,phases ] GC(11) Marking task (16) 795.142ms [7.525s][debug][gc,phases ] GC(11) Marking task 17 termination time 20.630 [7.525s][trace][gc,phases ] GC(11) Marking task (17) 792.503ms [7.525s][debug][gc,phases ] GC(11) Marking task 15 termination time 20.008 [7.525s][trace][gc,phases ] GC(11) Marking task (15) 795.251ms [7.525s][debug][gc,phases ] GC(11) Marking task 8 termination time 20.732 [7.525s][trace][gc,phases ] GC(11) Marking task (8) 795.292ms [7.525s][debug][gc,phases ] GC(11) Marking task 11 termination time 21.699 [7.525s][trace][gc,phases ] GC(11) Marking task (11) 795.309ms [7.525s][debug][gc,phases ] GC(11) Marking task 6 termination time 21.078 [7.525s][trace][gc,phases ] GC(11) Marking task (6) 795.346ms [7.525s][debug][gc,phases ] GC(11) Marking task 14 termination time 20.717 [7.525s][trace][gc,phases ] GC(11) Marking task (14) 795.355ms [7.525s][debug][gc,phases ] GC(11) Marking task 13 termination time 20.724 [7.525s][trace][gc,phases ] GC(11) Marking task (13) 795.388ms [7.525s][debug][gc,phases ] GC(11) Marking task 10 termination time 22.242 [7.525s][trace][gc,phases ] GC(11) Marking task (10) 795.422ms Much better.
21-01-2022