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

Stefan Johansson stefan.johansson at oracle.com
Tue Mar 1 09:22:13 UTC 2016

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

More information about the hotspot-gc-dev mailing list