RFR: 8027423: Parallel compact GC class unloading measurement includes symbol and string table time (original) (raw)

Jon Masamitsu jon.masamitsu at oracle.com
Tue Mar 15 22:51:26 UTC 2016

On 3/15/2016 3:18 PM, Stefan Karlsson wrote:

Hi Jon,

On 15/03/16 22:25, Jon Masamitsu wrote: Stefan,

Thanks for this enhancement. http://cr.openjdk.java.net/~stefank/8027423/webrev.00/src/share/vm/gc/g1/g1MarkSweep.cpp.frames.html

The timing for unlinkstringandsymboltable() 170 { 171 GCTraceTime(Debug, gc) t("Scrub String and Symbol Tables", gctimer()); 172 // Delete entries for dead interned string and clean up unreferenced symbols in symbol table. 173 g1h->unlinkstringandsymboltable(&GenMarkSweep::isalive); 174 } will include unlinking of the string Dedup table 4092 if (G1StringDedup::isenabled()) { 4093 G1StringDedup::unlink(isalive); 4094 } The other call to G1StringDedup::unlink() in "share/vm/gc/g1/g1ConcurrentMark.cpp" has its own GCTraceTime 2127 if (G1StringDedup::isenabled()) { 2128 GCTraceTime(Trace, gc) trace("String Deduplication Unlink", g1h->gctimercm()); 2129 G1StringDedup::unlink(&g1isalive); 2130 } Why not give the first G1StringDedup::unlink() call its own timer? And bring the GCTraceTime(Debug, gc) t("Scrub String and Symbol Tables", gctimer()); into unlinkstringandsymboltable()? Good point. If I may, I would like to move the call to G1StringDedup::unlink out of unlinkstringandsymboltable and into G1MarkSweep::marksweepphase1. That way it will be easier to see what timers we have, and it will be a little bit more similar to G1ConcurrentMark::weakRefsWork.

I like that.

http://cr.openjdk.java.net/~stefank/8027423/webrev.01.delta

Looks good.

Jon

http://cr.openjdk.java.net/~stefank/8027423/webrev.01

For a future RFE I think we should change the log levels from Trace to Debug and get rid of the GCTraceTimer nesting in G1ConcurrentMark::weakRefsWork. I also found that ~G1StringSymbolTableUnlinkTask incorrectly logs with the stringdedup tag, so that also have to be a new bug. Thanks, StefanK

Jon On 3/14/2016 7:22 AM, Stefan Karlsson wrote: Hi all, Please review this patch to get more detailed phase measurements of the unloading phases of the parallel and serial collectors. It mimics the way CMS reports the unloading phase. G1 parallelizes the unloading phase, so it is slightly different. http://cr.openjdk.java.net/~stefank/8027423/webrev.00/ https://bugs.openjdk.java.net/browse/JDK-8027423 Example of the output that you get with -Xlog:gc=debug: [2.257s][debug][gc] GC(45) Class Unloading (2.256s, 2.257s) 1.669ms [2.258s][debug][gc] GC(45) Scrub String Table (2.257s, 2.258s) 0.412ms [2.259s][debug][gc] GC(45) Scrub Symbol Table (2.258s, 2.259s) 1.027ms [2.292s][info ][gc] GC(45) Pause Full (System.gc()) 80M->2M(98M) (2.248s, 2.292s) 44.631ms Thanks, StefanK

More information about the hotspot-gc-dev mailing list