performance - Java garbage collection and young generation size -

i have been having performance difficulties java webapp running on tomcat hang short periods resulting in backlogs of traffic can make webapp unavailable minutes @ time suspect related garbage collection.

i garbage collection noob need bit of help.

i have enabled concurrent mark sweep garbage collector in hope eliminate pauses yet discover if has resolved problem yet.

i enabled verbose gc logging @ same time.

current java options follows

-xx:maxpermsize=128m -xx:+cmsclassunloadingenabled -xx:+useconcmarksweepgc -xms4g -xmx4g -xss256k -verbose:gc -xx:+printgcdetails 

i have noticed examining gc output the young generation space quite low @ 243mb , getting exhausted quickly, while examining output period of time counting 23 young generation collections in 10 seconds.

at same time total heap consumption steadily rising reaching near maximum followed full garbage collection taking down 3.5gb 260mb , pattern repeats self again.

sample output full gc

[gc [parnew: 232750k->12960k(249216k), 0.0160890 secs] 3836696k->3616934k(4166656k), 0.0162110 secs] [times: user=0.12 sys=0.01, real=0.02 secs]  [gc [parnew: 234528k->11391k(249216k), 0.0127970 secs] 3838502k->3615402k(4166656k), 0.0129370 secs] [times: user=0.12 sys=0.00, real=0.01 secs]  [gc [parnew: 232959k->10253k(249216k), 0.0097850 secs] 3836970k->3614841k(4166656k), 0.0098850 secs] [times: user=0.11 sys=0.00, real=0.01 secs]  [gc [1 cms-initial-mark: 3604588k(3917440k)] 3615964k(4166656k), 0.0096810 secs] [times: user=0.01 sys=0.00, real=0.01 secs]  [cms-concurrent-mark: 0.196/0.196 secs] [times: user=1.44 sys=0.03, real=0.20 secs]  [cms-concurrent-preclean: 0.013/0.014 secs] [times: user=0.04 sys=0.00, real=0.01 secs]  [gc [parnew: 231821k->6718k(249216k), 0.0090430 secs] 3836409k->3611789k(4166656k), 0.0091460 secs] [times: user=0.08 sys=0.01, real=0.01 secs]  [cms-concurrent-abortable-preclean: 0.176/0.390 secs] [times: user=0.97 sys=0.04, real=0.39 secs]  [gc[yg occupancy: 124723 k (249216 k)][rescan (parallel) , 0.0698120 secs][weak refs processing, 0.0038070 secs][class unloading, 0.0170180 secs][scrub symbol & string tables, 0.0098050 secs] [1 cms-remark: 3605071k(3917440k)] 3729794k(4166656k), 0.1070920 secs] [times: user=0.78 sys=0.02, real=0.11 secs]  [gc [parnew: 228286k->6428k(249216k), 0.0079910 secs] 3755282k->3534155k(4166656k), 0.0080720 secs] [times: user=0.07 sys=0.00, real=0.01 secs]  [gc [parnew: 227996k->6880k(249216k), 0.0085010 secs] 3332282k->3111216k(4166656k), 0.0085990 secs] [times: user=0.08 sys=0.00, real=0.01 secs]  [gc [parnew: 228448k->12440k(249216k), 0.0108230 secs] 2721177k->2505200k(4166656k), 0.0109290 secs] [times: user=0.13 sys=0.00, real=0.01 secs]  [gc [parnew: 234008k->8251k(249216k), 0.0073110 secs] 2358432k->2132792k(4166656k), 0.0074120 secs] [times: user=0.07 sys=0.00, real=0.00 secs]  [gc [parnew: 229819k->5170k(249216k), 0.0071920 secs] 2056138k->1831867k(4166656k), 0.0072880 secs] [times: user=0.07 sys=0.01, real=0.01 secs]  [gc [parnew: 226738k->11119k(249216k), 0.0106230 secs] 1589903k->1374447k(4166656k), 0.0107180 secs] [times: user=0.11 sys=0.00, real=0.01 secs]  [gc [parnew: 232687k->8624k(249216k), 0.0078450 secs] 1273082k->1049051k(4166656k), 0.0079440 secs] [times: user=0.09 sys=0.00, real=0.01 secs]  [gc [parnew: 230192k->10130k(249216k), 0.0083440 secs] 733461k->513411k(4166656k), 0.0084420 secs] [times: user=0.11 sys=0.00, real=0.01 secs]  [gc [parnew: 231698k->10655k(249216k), 0.0092440 secs] 544833k->323816k(4166656k), 0.0093450 secs] [times: user=0.11 sys=0.00, real=0.01 secs]  [cms-concurrent-sweep: 4.481/4.569 secs] [times: user=13.24 sys=0.49, real=4.57 secs]  [cms-concurrent-reset: 0.008/0.008 secs] [times: user=0.02 sys=0.00, real=0.01 secs]  [gc [parnew: 232223k->9791k(249216k), 0.0095050 secs] 495665k->273758k(4166656k), 0.0096020 secs] [times: user=0.11 sys=0.00, real=0.01 secs]  [gc [parnew: 231359k->7434k(249216k), 0.0080890 secs] 495326k->271660k(4166656k), 0.0082230 secs] [times: user=0.09 sys=0.00, real=0.01 secs]  [gc [parnew: 229002k->5732k(249216k), 0.0053690 secs] 493228k->269993k(4166656k), 0.0054630 secs] [times: user=0.06 sys=0.00, real=0.01 secs]  [gc [parnew: 227300k->4017k(249216k), 0.0060080 secs] 491561k->268433k(4166656k), 0.0061010 secs] [times: user=0.07 sys=0.00, real=0.00 secs]  

i understand if pattern seems normal , can optimise , improve thisc.

i have read increasing young generation size not being familiar garbage collection i'm not sure if right approach.

this young generation size small - frequent collections aren't issue (this means have memory-intensive program), it's problematic have lot of memory being promoted next generation. few things:

1. do have resources can pool, e.g. can use threadpoolexecutor instead of creating new thread objects, or can pool database connections? slow down memory consumption - pooled resources stay in mature space , won't have keep reallocating them in young space.

2. if that's not option or if doesn't reduce mature space consumption, increase young generation size. purpose of isn't reduce number of young generation collections (if double young generation size halve number of collections each collection may cost twice much**, haven't gained anything), rather purpose of allow more time young objects go out of scope they're not promoted mature space. comparison want make frequency of full collections - if have fewer full collections after increasing young generation size you've succeeded, otherwise reduce young generation size default.

** isn't strictly true, because young generation collector copying collector - copies live objects mature space, clears young space. means collector runs in time proportional number of live objects, not in time proportional total number of objects (as case mark-sweep collection). ideally, increasing young generation size you'll reduce number of live objects , speed collection times reducing mature space consumption.