RFR: JDK-8058944: Unify the time reporting strings in G1 remark

[Stefan Johansson]

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.

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