jQuery in Action, 3rd edition
The moose likes Performance and the fly likes generational garbage collection--please help Big Moose Saloon
  Search | Java FAQ | Recent Topics | Flagged Topics | Hot Topics | Zero Replies
Register / Login
JavaRanch » Java Forums » Java » Performance
Bookmark "generational garbage collection--please help" Watch "generational garbage collection--please help" New topic

generational garbage collection--please help

Tien Shan
Ranch Hand

Joined: Oct 08, 2004
Posts: 38
My garbage collection logs look as follows:
(1)342.003: [GC 342.003: [DefNew
Desired survivor size 819200 bytes, new threshold 1 (max 4)
- age 1: 1153152 bytes, 1153152 total
: 13184K->1126K(14784K), 0.0221720 secs] 13184K->1126K(63936K), 0.0227740 secs]
768.603: [GC [1 CMS-initial-mark: 0K(49152K)] 7114K(63936K), 0.0062870 secs]

(2)1358.802: [GC 1358.802: [DefNew
Desired survivor size 819200 bytes, new threshold 4 (max 4)
- age 1: 785520 bytes, 785520 total
: 14310K->767K(14784K), 0.0680510 secs] 14310K->1700K(63936K) icms_dc=5 , 0.0682220 secs]
1847.304: [GC [1 CMS-initial-mark: 932K(49152K)] 8210K(63936K), 0.0058360 secs]

(3)2537.684: [GC 2537.684: [DefNew
Desired survivor size 819200 bytes, new threshold 2 (max 4)
- age 1: 815688 bytes, 815688 total
- age 2: 171848 bytes, 987536 total
: 13951K->964K(14784K), 0.0402100 secs] 14800K->1813K(63936K) icms_dc=0 , 0.0407760 secs]
I don't know why a concurrent collection is initiated in (2) despite the new threshold being 4.
Why there are no age 2, age 3 and age 4 collections? In (1) and (3), collection occurs as promised, once when the new threshold is 1 and twice when the new threshold is 2.

May be the numbers in (2) tell me something, but I don't know how to interpret them.

Also, why (incremental concurrent duty cycle?) icms_dc=5 in (2) and icms_dc=0 in (3)?

Please help.

Thank you and Happy Holidays!
Peter Johnson

Joined: May 14, 2008
Posts: 5852

Which collector are you using? What are your JVM command line options? Which JVM, and version, are you using? Last time I experimented with the CMS collector, I noticed that it resets the tenuring threshold to 0 and the survivors spaces to a really small size (64K?), thus preferring to tenure objects on the first minor collection. I have also noticed that with more recent JVMs that they constantly adjust the tenuring threshold regardless of the initial setting.

JBoss In Action
Tien Shan
Ranch Hand

Joined: Oct 08, 2004
Posts: 38
Thank you for your comments. At least now I have something to work on. (Need to find out why the virtual machine decided to go for premature promotion.)

Command line options are as folows:
-XX:+UseConcMarkSweepGC -XX:+CMSIncrementalMode
-Xloggc:test.gclog -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCApplicationConcurrentTime
-XX:+PrintGCApplicationStoppedTime -XX:+PrintTenuringDistribution

Java Version 1.6.0-14
Java HotSpot build 14.0-b16

A folow-up question I am trying to understand is the opposite of the last question.
In the following garbage collection output (no 2.), even though new threshold is 2,
age=3 generation garbage is collected, and in no. 3, a 2nd generation garbage is collected even though new threshold is 1.
From where do these extra generation guys come?

My guess is that since max threshold is 4 (in all cases), JVM dynamically decided to go for an extra run. Does anyone have any other (correct) idea?

Peter Johnson

Joined: May 14, 2008
Posts: 5852

Are you asking why, if there have been only 2 garbage collection, that some objects could have age 3? I have noticed a similar thing while experimenting with the new Garbage First (G1) garbage collector. The only thing I can come up with is that the JVM is maintaining two different counts of the garbage collections and they are always one off.

Additionally, modern JVMs tend to ignore any setting for the tenuring threshold and adjust it automatically.

I am not quite sure I understand what you mean by "JVM dynamically decided to go for an extra run". The JVM will run a garbage collection only when the eden space fills up. At that time the JVM will examine the heap and if it feel it is necessary will first do a major collection of the tenured space (start a CMS collection in you case) and then perform a minor collection of the eden space. What you are seeing is three separate minor collections.
I agree. Here's the link: http://aspose.com/file-tools
subject: generational garbage collection--please help
It's not a secret anymore!