Seeking answer to a GC pattern

Tue Nov 10 14:35:50 UTC 2015

Hi Yu,

Yes I have disabled the GC ergonomics after experimenting with many java startup parameter combinations. For all the GC algorithms I have tried, the GC behavior was more or less the same but some were definitely worse than others. Main problems I have are:

*         The saw-tooth pattern response time as measured by my load testing tool with or without -XX:+AlwaysTenure. Right before a full collection, the response time could reach a few seconds depending on the size of the young gen. The bigger the young gen the higher the highs of the response time.

*         Objects for this application seem to have a long life

*         Using the parameters I had in the previous email seems to give me the best performance so far.

A few examples of the gc log:

-XX:+UseConcMarkSweepGC -XX:+UseParNewGC -XX:MaxTenuringThreshold=10 -XX:-UseAdaptiveSizePolicy -XX:+DisableExplicitGC

31265.959: [GC 31265.959: [ParNew
Desired survivor size 53673984 bytes, new threshold 10 (max 10)
- age   1:    1695168 bytes,    1695168 total
- age   2:     825984 bytes,    2521152 total
- age   3:     823424 bytes,    3344576 total
- age   4:     770776 bytes,    4115352 total
- age   5:     822064 bytes,    4937416 total
- age   6:     816984 bytes,    5754400 total
- age   7:     777064 bytes,    6531464 total
- age   8:     850344 bytes,    7381808 total
- age   9:     836016 bytes,    8217824 total
- age  10:     810968 bytes,    9028792 total
: 853704K->10926K(943744K), 1.4887200 secs] 1602653K->760749K(4089472K), 1.4889740 secs] [Times: user=5.46 sys=0.04, real=1.49 secs]
31365.452: [GC 31365.453: [ParNew
Desired survivor size 53673984 bytes, new threshold 10 (max 10)
- age   1:    1925120 bytes,    1925120 total
- age   2:     818208 bytes,    2743328 total
- age   3:     815128 bytes,    3558456 total
- age   4:     819992 bytes,    4378448 total
- age   5:     770648 bytes,    5149096 total
- age   6:     822064 bytes,    5971160 total
- age   7:     816984 bytes,    6788144 total
- age   8:     777032 bytes,    7565176 total
- age   9:     850344 bytes,    8415520 total
- age  10:     836016 bytes,    9251536 total
: 849838K->15550K(943744K), 1.4532880 secs] 1599661K->766188K(4089472K), 1.4535550 secs] [Times: user=5.38 sys=0.02, real=1.45 secs]

~~~~~~~~~~~~~~~~~
-server -XX:+UseCompressedOops -XX:+TieredCompilation -XX:ReservedCodeCacheSize=256m -XX:+UseCodeCacheFlushing -XX:+PrintTenuringDistribution -Xms2048m -Xmx4096m -XX:MaxPermSize=256m -XX:NewSize=128m -XX:MaxNewSize=128m -XX:SurvivorRatio=126 -XX:-UseAdaptiveSizePolicy -XX:+DisableExplicitGC -XX:+AlwaysTenure

2417.702: [GC [PSYoungGen: 129024K->0K(130048K)] 2078501K->1954674K(2096128K), 0.1765730 secs] [Times: user=0.64 sys=0.01, real=0.18 secs]
2421.355: [GC [PSYoungGen: 129007K->0K(130048K)] 2083681K->1957745K(2096128K), 0.1654380 secs] [Times: user=0.60 sys=0.01, real=0.17 secs]
2426.403: [GC [PSYoungGen: 129009K->0K(130048K)] 2086754K->1961487K(2096128K), 0.1711790 secs] [Times: user=0.62 sys=0.00, real=0.17 secs]
2426.575: [Full GC [PSYoungGen: 0K->0K(130048K)] [ParOldGen: 1961487K->353838K(1966080K)] 1961487K->353838K(2096128K) [PSPermGen: 103092K->100055K(203712K)], 1.1573820 secs] [Times: user=2.27 sys=0.14, real=1.16 secs]

Thanks,
Jun

From: Yu Zhang [mailto:yu.zhang at oracle.com]
Sent: Monday, November 09, 2015 5:36 PM
To: Jun Zhuang <jun.zhuang at hobsons.com>; hotspot-gc-use at openjdk.java.net
Subject: Re: Seeking answer to a GC pattern

Jun,

Sorry for the late response.
It seems you are disabling the gc ergonomic. Can you explain why? Do you need very low pause time? If you have a gc log, that would be helpful as well.

Thanks,

Jenny
On 10/26/2015 12:33 PM, Jun Zhuang wrote:
Hi,

When running performance testing for a java web service running on JBOSS, I observed a clear saw-tooth pattern in CPU utilization that closely follows the GC cycles. see below:

[cid:image001.jpg at 01D11B95.E81C2250]

[cid:image002.jpg at 01D11B95.E81C2250]

Java startup parameters used:

-XX:+TieredCompilation -XX:+PrintTenuringDistribution -Xms2048m -Xmx4096m -XX:MaxPermSize=256m -XX:NewSize=128m -XX:MaxNewSize=128m -XX:SurvivorRatio=126 -XX:-UseAdaptiveSizePolicy -XX:+DisableExplicitGC -XX:+AlwaysTenure

With this set of parameters, the young GC pause time ranged from 0.02 to 0.25 secs. When I used 256m for the young gen, the young GC pause time ranged from 0.02 to 0.5 secs. My understanding is that the young GC pause time normally stays fairly stable, I have spent quite some time researching but have yet to find an answer to this behavior. I wonder if people in this distribution list can help me out?

Other related info

* Server Specs: VM with 4 CPUs and 8 Gb mem
* Test setup:

*         # of Vusers: 100

*         Ramp up: 10 mins

*         Pacing: 5 - 7 secs
* I tried with all other available GC algorithms, tenuring thresholds, various sizes of the generations, but the AlwaysTenure parameter seems to work the best so far.

[cid:image003.jpg at 01D11B95.E81C2250]
[cid:image004.jpg at 01D11B95.E81C2250]

Any input will be highly appreciated.

Sincerely yours,

Jun Zhuang
Sr. Performance QA Engineer | Hobsons
513-746-2288 (work)
513-227-7643 (mobile)

_______________________________________________

hotspot-gc-use mailing list

hotspot-gc-use at openjdk.java.net<mailto:hotspot-gc-use at openjdk.java.net>

http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mail.openjdk.java.net/pipermail/hotspot-gc-use/attachments/20151110/55710051/attachment-0001.html>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: image001.jpg
Type: image/jpeg
Size: 7083 bytes
Desc: image001.jpg
URL: <http://mail.openjdk.java.net/pipermail/hotspot-gc-use/attachments/20151110/55710051/image001-0001.jpg>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: image002.jpg
Type: image/jpeg
Size: 11773 bytes
Desc: image002.jpg
URL: <http://mail.openjdk.java.net/pipermail/hotspot-gc-use/attachments/20151110/55710051/image002-0001.jpg>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: image003.jpg
Type: image/jpeg
Size: 33498 bytes
Desc: image003.jpg
URL: <http://mail.openjdk.java.net/pipermail/hotspot-gc-use/attachments/20151110/55710051/image003-0001.jpg>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: image004.jpg
Type: image/jpeg
Size: 19704 bytes
Desc: image004.jpg
URL: <http://mail.openjdk.java.net/pipermail/hotspot-gc-use/attachments/20151110/55710051/image004-0001.jpg>