(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)?
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.
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:
-Xloggc:test.gclog -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCApplicationConcurrentTime
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?
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.