RFR(S): 8173335: Improve logging for j.l.ref.reference processing

sangheon sangheon.kim at oracle.com
Fri Jun 9 23:57:54 UTC 2017


Hi all,

Can I have some reviews for changes to improve logging for j.l.reference 
processing?

This patch is proposing to add logs for balance queue time, phase1~3 
time of reference processing, enqueue time for discovered references at 
debug level and workers distribution stats at trace level. And it also 
includes trace events for those cases.


The log will be changed like below:
* Before
[debug][gc,ref] GC(9) SoftReference 0.581ms
[debug][gc,ref] GC(9) WeakReference 1.066ms
[debug][gc,ref] GC(9) FinalReference 0.376ms
[debug][gc,ref] GC(9) PhantomReference 0.468ms
[debug][gc,ref] GC(9) JNI Weak Reference 0.005ms
[debug][gc,ref] GC(9) Ref Counts: Soft: 0 Weak: 0 Final: 0 Phantom: 0

* After
[debug][gc,ref] GC(5) SoftReference 0.895ms
[debug][gc,ref] GC(5)   Balance queues: 0.001ms
[debug][gc,ref] GC(5)   Phase1: 0.456ms
[trace][gc,ref] GC(5)     Process lists (ms)        Min: 0.0, Avg:  0.3, 
Max:  0.3, Diff:  0.3, Sum:  5.8, Workers: 23
[debug][gc,ref] GC(5)   Phase2: 0.059ms
[trace][gc,ref] GC(5)     Process lists (ms)        Min: 0.0, Avg:  0.0, 
Max:  0.0, Diff:  0.0, Sum:  0.0, Workers: 23
[debug][gc,ref] GC(5)   Phase3: 0.374ms
[trace][gc,ref] GC(5)     Process lists (ms)        Min: 0.0, Avg:  0.2, 
Max:  0.3, Diff:  0.3, Sum:  4.0, Workers: 23
[debug][gc,ref] GC(5)   Cleared: 0
[debug][gc,ref] GC(5)   Discovered: 0
...
[debug][gc,ref] GC(5) JNI Weak Reference 0.003ms
[debug][gc,ref] GC(5) Enqueue reference lists 0.081ms
[debug][gc,ref] GC(5)   Counts:  Soft: 0  Weak: 0  Final: 0  Phantom: 0

CR: https://bugs.openjdk.java.net/browse/JDK-8173335
webrev: http://cr.openjdk.java.net/~sangheki/8173335/webrev.0
Testing: JPRT and local tests of combinations with 
+/-ParallelRefProcEnabled and gc types.

Thanks,
Sangheon






More information about the hotspot-gc-dev mailing list