RFR: JDK-8058944: Unify the time reporting strings in G1 remark (original) (raw)

Bengt Rutisson bengt.rutisson at oracle.com
Tue Mar 1 10:03:00 UTC 2016


Hi Stefa,

Thanks for looking at this!

On 2016-03-01 10:22, Stefan Johansson wrote:

Hi Beng

On 2016-03-01 09:47, Bengt Rutisson wrote:

Hi all, Could I have a couple of reviews for this small cleanup to the G1 remark logging? http://cr.openjdk.java.net/~brutisso/8058944/webrev.00/ https://bugs.openjdk.java.net/browse/JDK-8058944 Currently the remark logging looks like this on debug level: [0,937s][info ][gc,start ] GC(2) Pause Remark (0,937s) [0,937s][debug][gc,start ] GC(2) Finalize Marking (0,937s) [0,955s][debug][gc ] GC(2) Finalize Marking (0,937s, 0,955s) 17,949ms [0,955s][debug][gc,start ] GC(2) GC Ref Proc (0,955s) [0,956s][debug][gc ] GC(2) GC Ref Proc (0,955s, 0,956s) 0,279ms [0,956s][debug][gc,start ] GC(2) Unloading (0,956s) [0,965s][debug][gc ] GC(2) Unloading (0,956s, 0,965s) 9,623ms [0,965s][debug][gc,start ] GC(2) GC Aggregate Data (0,965s) [0,966s][debug][gc ] GC(2) GC Aggregate Data (0,965s, 0,966s) 0,614ms [0,966s][info ][gc ] GC(2) Pause Remark 89M->89M(507M) (0,937s, 0,966s) 28,653ms

With the proposed change it will look like this: [0,946s][info ][gc,start ] GC(2) Pause Remark (0,946s) [0,946s][debug][gc,start ] GC(2) Finalize Marking (0,946s) [0,960s][debug][gc ] GC(2) Finalize Marking (0,946s, 0,960s) 13,677ms [0,960s][debug][gc,start ] GC(2) Ref Proc (0,960s) [0,961s][debug][gc ] GC(2) Ref Proc (0,960s, 0,960s) 0,524ms Should we take this opportunity to improve the "Ref Proc" message even more? "Reference Processing" would look nicer I think. Otherwise the change looks good.

Good point. I changed to "Reference Processing". It now looks like this:

[0,878s][info ][gc,start ] GC(2) Pause Remark (0,878s) [0,878s][debug][gc,start ] GC(2) Finalize Marking (0,878s) [0,888s][debug][gc ] GC(2) Finalize Marking (0,878s, 0,888s) 10,187ms [0,888s][debug][gc,start ] GC(2) Refeference Processing (0,888s) [0,888s][debug][gc ] GC(2) Refeference Processing (0,888s, 0,888s) 0,515ms [0,888s][debug][gc,start ] GC(2) Unloading (0,888s) [0,902s][debug][gc ] GC(2) Unloading (0,888s, 0,902s) 13,100ms [0,902s][debug][gc,start ] GC(2) Aggregate Data (0,902s) [0,902s][debug][gc ] GC(2) Aggregate Data (0,902s, 0,902s) 0,387ms [0,902s][info ][gc ] GC(2) Pause Remark 72M->72M(506M) (0,878s, 0,902s) 24,406ms

However, there is also a "Ref Proc" and a "Ref Enq" in the "Other" section of a normal G1 GC:

[0,913s][info ][gc,phases ] GC(9) Other: 1,2ms [0,913s][debug][gc,phases ] GC(9) Choose CSet: 0,0ms [0,913s][debug][gc,phases ] GC(9) Preserve CM Refs: 0,1ms [0,913s][debug][gc,phases ] GC(9) Ref Proc: 0,1ms [0,913s][debug][gc,phases ] GC(9) Ref Enq: 0,0ms [0,913s][debug][gc,phases ] GC(9) Redirty Cards: 0,1ms [0,913s][debug][gc,phases ] GC(9) Humongous Register: 0,0ms [0,913s][debug][gc,phases ] GC(9) Humongous Reclaim: 0,0ms

I change those as well:

[0,868s][info ][gc,phases ] GC(9) Other: 0,9ms [0,868s][debug][gc,phases ] GC(9) Choose CSet: 0,0ms [0,868s][debug][gc,phases ] GC(9) Preserve CM Refs: 0,2ms [0,868s][debug][gc,phases ] GC(9) Reference Processing: 0,0ms [0,868s][debug][gc,phases ] GC(9) Reference Enqueuing: 0,0ms [0,868s][debug][gc,phases ] GC(9) Redirty Cards: 0,1ms [0,868s][debug][gc,phases ] GC(9) Humongous Register: 0,0ms [0,868s][debug][gc,phases ] GC(9) Humongous Reclaim: 0,0ms

Here's an updated webrev: http://cr.openjdk.java.net/~brutisso/8058944/webrev.01/

If you find this ok I will change the title of the bug report to be "Unify the reporting strings for the GC debug level logging in G1" since it no longer concerns just the remark phase.

Thanks, Bengt

Thanks, Stefan [0,961s][debug][gc,start ] GC(2) Unloading (0,961s) [0,972s][debug][gc ] GC(2) Unloading (0,961s, 0,972s) 11,425ms [0,972s][debug][gc,start ] GC(2) Aggregate Data (0,972s) [0,972s][debug][gc ] GC(2) Aggregate Data (0,972s, 0,972s) 0,377ms [0,972s][info ][gc ] GC(2) Pause Remark 62M->62M(506M) (0,946s, 0,972s) 26,243ms

Thanks, Bengt



More information about the hotspot-gc-dev mailing list