RFR (S): JDK-8129549 G1: Make sure the concurrnet thread does not mix its logging with the STW pauses
bengt.rutisson at oracle.com
Tue Jun 23 08:09:21 UTC 2015
Could I have a couple of reviews for this patch?
From the bug report:
Currently the ConcurrentMarkThread in G1 does not take part in the
safepoint synchronization for its logging. This means that logging from
the concurrent thread can be interleaved with loggging from a normal GC
1,491: #49: [GC concurrent-root-region-scan-start]
1,500: #50: [GC pause (G1 Evacuation Pause) (young)1,501: #49: [GC
concurrent-root-region-scan-end, 0,0100111 secs]
1,501: #49: [GC concurrent-mark-start]
, 0,0162226 secs]
[Root Region Scan Waiting: 1,1 ms]
[Parallel Time: 6,1 ms, GC Workers: 23]
In the log section above it looks like the root region scanning is
completed inside of the G1 evacuation pause and the concurrent mark is
started while the pause is running.
This is not really what is happening. In fact the evacuation pause waits
for the root region scanning to start before it proceeds with the actual
GC work. And the mark tasks that actually do the concurrent marking work
will be blocked by the safepoint so, the concurrent marking is not
started until after the evacuation pause.
So, apart from being a bit ugly this interleaved logging is actually a
The root region scanning can be fixed by moving the code that waits for
the root region scanning to complete to the very start of the evacuation
pause. Before any logging from the pause is done.
The other concurrent logging can be fixed by joining the STS before
doing the actual logging.
Doing these fixes makes the output look like this:
1,364: #40: [GC concurrent-root-region-scan-start]
1,374: #40: [GC concurrent-root-region-scan-end, 0,0106570 secs]
1,375: #41: [GC pause (G1 Evacuation Pause) (young), 0,0169416 secs]
[Root Region Scan Waiting: 2,6 ms]
[Parallel Time: 5,5 ms, GC Workers: 23]
[Times: user=0,10 sys=0,00 real=0,02 secs]
1,392: #40: [GC concurrent-mark-start]
More information about the hotspot-gc-dev