After Full GC, young generation collection decreases 10 times

1
votes

Here I have an extract of my gc.log:

2013-02-28T12:02:13.209+0100: 1486457.849: [GC 1486457.850: [ParNew 3483368K->96838K(3774912K), 0.2273030 secs] 8085678K->4710336K(49912256K), 0.2278070 secs] [Times: user=1.54 sys=0.01, real=0.23 secs]

2013-02-28T12:02:26.551+0100: 1486471.191: [GC 1486471.191: [ParNew 3452358K->125528K(3774912K), 0.2386800 secs] 8065856K->4748772K(49912256K), 0.2392150 secs] [Times: user=1.64 sys=0.01, real=0.24 secs]

2013-02-28T12:02:27.398+0100: 1486472.038: [Full GC 1486472.039: [CMS: 4623244K->3323834K(46137344K), 3.0873920 secs] 5034629K->3323834K(49912256K), [CMS Perm : 97619K->54323K(98304K)], 3.0878880 secs] [Times: user=3.04 sys=0.01, real=3.08 secs]

2013-02-28T12:02:42.758+0100: 1486487.398: [GC 1486487.399: [ParNew 3355519K->50321K(3774912K), 0.0289980 secs] 6679353K->3374156K(49912256K), 0.0295550 secs] [Times: user=0.20 sys=0.00, real=0.03 secs]

2013-02-28T12:02:59.045+0100: 1486503.685: [GC 1486503.685: [ParNew 3405841K->71853K(3774912K), 0.0316570 secs] 6729676K->3395688K(49912256K), 0.0321860 secs] [Times: user=0.22 sys=0.00, real=0.03 secs]

After a Full GC (because of perm space exhausted), the young generation collections decreases from 0,23 seconds to 0,03 seconds (10 times).

I have to find out the reason why the perm space becomes full, but what I don't understand is why the young generation collection time decreases 10 times because of the Full GC.

Can anybody help me?

Thanks, Joan.

1
javagarbage-collection
Well you can see it's increasing again afterwards, so the logical view is that there's not much in that space after a Full GC does a proper clear-up. You could consider just increasing the PermGen space and seeing if it's stable at a higher value. – Philip Whitehouse

1 Answers

1
votes

With the logs mentioned , i can tell few points .

The reason can be :

As the program runs, allocations occur and referencing takes place . Short-lived objects die and rest are promoted to survivor space or perm space .

Possible situation of referencing are as follows .

1) objects in eden space (younger generation) and survivor space reference objects in perm space and tenured space making them live longer .

2) sometimes objects in perm space and tenured space references younger generation objects(in eden space and survivor space) .

Since garbage collection in tenured and perm space are not as frequent as younger generation .

There might be situation where object say obj1 in perm space or tenured space are no longer referenced and are ready to be claimed by GC , so this obj1 is waiting for GC, which happens infrequently .Again this obj1 could have had references to objects in survivor and eden space . So this objects in eden space and survivor space referenced by obj1 are not eligible for garbage collection . So there might be many objects like this in eden space and survivor space which are being referenced by objects like obj1 from perm space which leads to more number of objects in eden and survivor space .So minor GC takes more time .

In full GC ,objects like obj1 are collected ,so no of objects in eden and survivor referenced by objects like obj1 are also claimed by GC leading to less no of objects in eden and survivor space . Since number of objects are less, minor GC takes less time . If you observe further logs slowly minor Gc time is again increasing(0.0289980 secs ,0.0316570 as mentioned in your logs) , it might increase till next FULL GC .

You can also observe pattern of GC time before Full GC , it is increasing .(0.2273030 secs,0.2386800 secs as mentioned in your logs)