RFR (S): [8u] Re-implement verbose GC logging

[Roman Kennke]

Nice!!

Yes, please commit!

Roman

Am Donnerstag, den 16.02.2017, 17:50 +0100 schrieb Aleksey Shipilev:
> Hi,
> 
> This makes Shenandoah print saner -verbose:gc in 8u, matching what 9
> prints:
>   http://cr.openjdk.java.net/~shade/shenandoah/jdk9-8u/verbose-gc-log
> ging/webrev.01/
> 
> Ended up doing our own GCTraceTime implementation. Also touches up
> handling of
> log(gc,ergo) printouts that are disabled by default on 9. In 8u
> current macros
> for log(...) spam into stdout.
> 
> Testing: hotspot_gc_shenandoah
> 
> Output on 9:
> 
> [15.015s][info][gc] GC(1) Pause Init Mark 8.219ms
> [15.406s][info][gc] GC(1) Concurrent marking 5115M->5783M(10240M)
> 390.467ms
> [15.410s][info][gc] GC(1) Pause Final Mark 5783M->4823M(10240M)
> 3.562ms
> [15.451s][info][gc] GC(1) Concurrent evacuation  4823M->5287M(10240M) 
> 40.576ms
> [15.451s][info][gc] GC(1) Concurrent reset bitmaps 0.089ms
> 
> Output on current 8u:
> 
> predicted cset threshold: 28
> Starting concurrent mark at 2322432K CSet (22%)
> 24.076: [Pause Init-Mark, 0.0056708 secs]
> 24.711: [Pause Final Mark, 0.0067279 secs]
> 
> Output on patched 8u:
> 
> 31.314: #4: [Pause Init Mark, 0.967 ms]
> 31.315: #4: [Concurrent marking 8964M->9690M(10G), 619.847 ms]
> 31.935: #4: [Pause Final Mark 9690M->6725M(10G), 9.763 ms]
> 31.945: #4: [Concurrent evacuation 6729M->7163M(10G), 52.714 ms]
> 31.998: #4: [Concurrent reset bitmaps, 3.247 ms]
> 
> 
> Thanks,
> -Aleksey
> 
>