Corbin,
Do you have a benchmark that will exhibit this problem?
If not, does you application just create lots of interned strings that
are long
lived?
Thanks.
Jon
On 5/31/2016 3:36 PM, Hughes,Corbin wrote:
After coming across -XX:+PrintGCTaskTimeStamps, I noticed that the
listed tasks don’t add up to the listed PSYoungGen times, so I ended
up adding more “printf” style timing outputs to the hotspot source,
and ended up tracking it down. Turns out it’s the interned strings.
The way they’re GC’d isn’t particularly efficient for large numbers of
strings: the call to
StringTable::unlink_or_oops_do(&_is_alive_closure, &root_closure); was
taking ~185 ms of the ~200 ms. I wish there were a flag to disable GC
of interned strings, but I think we’ll be able to get away with using
something like a Guava Interner instead of the built in StringTable,
so mystery solved.
*From:*hotspot-gc-use [mailto:hotspot-gc-use-boun...@openjdk.java.net]
*On Behalf Of *Hughes,Corbin
*Sent:* Friday, May 27, 2016 9:24 PM
*To:* hotspot-gc-use@openjdk.java.net
*Subject:* Re: Unexpected Java 6 vs 8 GC performance difference
Jon,
Thanks for the interest. Hopefully this log will be more helpful. This
is Java 7 with the –XX:-UseParallelOldGC flag. Perhaps notably, the
PSYoungGen collections are even slower in Java 7 (regardless of
whether or not the serial old collector is used).
Thanks,
Corbin
{Heap before GC invocations=456 (full 0):
PSYoungGen total 2091008K, used 2087456K [0x0000000780000000,
0x0000000800000000, 0x0000000800000000)
eden space 2084864K, 100% used
[0x0000000780000000,0x00000007ff400000,0x00000007ff400000)
from space 6144K, 42% used
[0x00000007ff400000,0x00000007ff688000,0x00000007ffa00000)
to space 6144K, 0% used
[0x00000007ffa00000,0x00000007ffa00000,0x0000000800000000)
PSOldGen total 3145728K, used 2267941K [0x00000006c0000000,
0x0000000780000000, 0x0000000780000000)
object space 3145728K, 72% used
[0x00000006c0000000,0x000000074a6c9508,0x0000000780000000)
PSPermGen total 819200K, used 57100K [0x0000000680000000,
0x00000006b2000000, 0x00000006c0000000)
object space 819200K, 6% used
[0x0000000680000000,0x00000006837c3130,0x00000006b2000000)
1461.284: [GC
Desired survivor size 6291456 bytes, new threshold 1 (max 15)
[PSYoungGen: 2087456K->1482K(2091008K)] 4355397K->2269463K(5236736K),
0.2986350 secs] [Times: user=0.34 sys=0.00, real=0.30 secs]
Heap after GC invocations=456 (full 0):
PSYoungGen total 2091008K, used 1482K [0x0000000780000000,
0x0000000800000000, 0x0000000800000000)
eden space 2084864K, 0% used
[0x0000000780000000,0x0000000780000000,0x00000007ff400000)
from space 6144K, 24% used
[0x00000007ffa00000,0x00000007ffb72928,0x0000000800000000)
to space 6144K, 0% used
[0x00000007ff400000,0x00000007ff400000,0x00000007ffa00000)
PSOldGen total 3145728K, used 2267981K [0x00000006c0000000,
0x0000000780000000, 0x0000000780000000)
object space 3145728K, 72% used
[0x00000006c0000000,0x000000074a6d3528,0x0000000780000000)
PSPermGen total 819200K, used 57100K [0x0000000680000000,
0x00000006b2000000, 0x00000006c0000000)
object space 819200K, 6% used
[0x0000000680000000,0x00000006837c3130,0x00000006b2000000)
}
{Heap before GC invocations=457 (full 0):
PSYoungGen total 2091008K, used 2086346K [0x0000000780000000,
0x0000000800000000, 0x0000000800000000)
eden space 2084864K, 100% used
[0x0000000780000000,0x00000007ff400000,0x00000007ff400000)
from space 6144K, 24% used
[0x00000007ffa00000,0x00000007ffb72928,0x0000000800000000)
to space 6144K, 0% used
[0x00000007ff400000,0x00000007ff400000,0x00000007ffa00000)
PSOldGen total 3145728K, used 2267981K [0x00000006c0000000,
0x0000000780000000, 0x0000000780000000)
object space 3145728K, 72% used
[0x00000006c0000000,0x000000074a6d3528,0x0000000780000000)
PSPermGen total 819200K, used 57100K [0x0000000680000000,
0x00000006b2000000, 0x00000006c0000000)
object space 819200K, 6% used
[0x0000000680000000,0x00000006837c3130,0x00000006b2000000)
1463.560: [GC
Desired survivor size 6291456 bytes, new threshold 1 (max 15)
[PSYoungGen: 2086346K->3177K(2091008K)] 4354327K->2271183K(5236736K),
0.2974600 secs] [Times: user=0.33 sys=0.00, real=0.30 secs]
Heap after GC invocations=457 (full 0):
PSYoungGen total 2091008K, used 3177K [0x0000000780000000,
0x0000000800000000, 0x0000000800000000)
eden space 2084864K, 0% used
[0x0000000780000000,0x0000000780000000,0x00000007ff400000)
from space 6144K, 51% used
[0x00000007ff400000,0x00000007ff71a730,0x00000007ffa00000)
to space 6144K, 0% used
[0x00000007ffa00000,0x00000007ffa00000,0x0000000800000000)
PSOldGen total 3145728K, used 2268005K [0x00000006c0000000,
0x0000000780000000, 0x0000000780000000)
object space 3145728K, 72% used
[0x00000006c0000000,0x000000074a6d9528,0x0000000780000000)
PSPermGen total 819200K, used 57100K [0x0000000680000000,
0x00000006b2000000, 0x00000006c0000000)
object space 819200K, 6% used
[0x0000000680000000,0x00000006837c3130,0x00000006b2000000)
}
{Heap before GC invocations=458 (full 0):
PSYoungGen total 2091008K, used 2088041K [0x0000000780000000,
0x0000000800000000, 0x0000000800000000)
eden space 2084864K, 100% used
[0x0000000780000000,0x00000007ff400000,0x00000007ff400000)
from space 6144K, 51% used
[0x00000007ff400000,0x00000007ff71a730,0x00000007ffa00000)
to space 6144K, 0% used
[0x00000007ffa00000,0x00000007ffa00000,0x0000000800000000)
PSOldGen total 3145728K, used 2268005K [0x00000006c0000000,
0x0000000780000000, 0x0000000780000000)
object space 3145728K, 72% used
[0x00000006c0000000,0x000000074a6d9528,0x0000000780000000)
PSPermGen total 819200K, used 57100K [0x0000000680000000,
0x00000006b2000000, 0x00000006c0000000)
object space 819200K, 6% used
[0x0000000680000000,0x00000006837c31b0,0x00000006b2000000)
1465.998: [GC
Desired survivor size 6291456 bytes, new threshold 1 (max 15)
[PSYoungGen: 2088041K->1456K(2091008K)] 4356047K->2269485K(5236736K),
0.2940590 secs] [Times: user=0.33 sys=0.00, real=0.29 secs]
Heap after GC invocations=458 (full 0):
PSYoungGen total 2091008K, used 1456K [0x0000000780000000,
0x0000000800000000, 0x0000000800000000)
eden space 2084864K, 0% used
[0x0000000780000000,0x0000000780000000,0x00000007ff400000)
from space 6144K, 23% used
[0x00000007ffa00000,0x00000007ffb6c188,0x0000000800000000)
to space 6144K, 0% used
[0x00000007ff400000,0x00000007ff400000,0x00000007ffa00000)
PSOldGen total 3145728K, used 2268029K [0x00000006c0000000,
0x0000000780000000, 0x0000000780000000)
object space 3145728K, 72% used
[0x00000006c0000000,0x000000074a6df528,0x0000000780000000)
PSPermGen total 819200K, used 57100K [0x0000000680000000,
0x00000006b2000000, 0x00000006c0000000)
object space 819200K, 6% used
[0x0000000680000000,0x00000006837c31b0,0x00000006b2000000)
}
CONFIDENTIALITY NOTICE This message and any included attachments are
from Cerner Corporation and are intended only for the addressee. The
information contained in this message is confidential and may
constitute inside or non-public information under international,
federal, or state securities laws. Unauthorized forwarding, printing,
copying, distribution, or use of such information is strictly
prohibited and may be unlawful. If you are not the addressee, please
promptly delete this message and notify the sender of the delivery
error by e-mail or you may call Cerner's corporate offices in Kansas
City, Missouri, U.S.A at (+1) (816)221-1024.
_______________________________________________
hotspot-gc-use mailing list
hotspot-gc-use@openjdk.java.net
http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
_______________________________________________
hotspot-gc-use mailing list
hotspot-gc-use@openjdk.java.net
http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
