CODEWITHSUNDEEP
javagarbage-collectionjvmjvm-hotspot
devoured elysium
devoured elysium

Reputation: 105077

How can the Old Generation size decrease even in the absence of Full GCs with CMS in HotSpot?

When looking at VisualVM in the "Visual GC" tab, I've noticed that for applications running with the Concurrent Mark & Sweep (CMS) collector, the Old generation size can decrease (in absolute terms), even if no Full GCs are being kicked in.

I thought this could not be possible? As you can see on this chart, the heap evolution has ups and downs even though the Old Gen collection count = 4:

enter image description here

I'd expect to either see exactly 4 decreases (one for each Full GC) or the only theory coming to mind is that the Full GCs take forever to execute and that instead of seeing a huge drop in available memory at a time, I'm seeing it slowly being released in small batches. But the total collection time 1min 18s seems to low for this theory to make sense.

Here are my application settings (in this case, the application is CLion and these are its default settings, other than heap size):

-Xss2m
-Xms256m
-Xmx4g
-XX:NewSize=128m
-XX:MaxNewSize=128m
-XX:ReservedCodeCacheSize=240m
-XX:+UseConcMarkSweepGC
-XX:SoftRefLRUPolicyMSPerMB=50
-ea
-XX:CICompilerCount=2

Upvotes: 0

Views: 800

Answers (1)

devoured elysium
devoured elysium

Reputation: 105077

Well, after some digging, looking at HotSpot's source and looking at the GC logs, it seems the reason for the shown behavior is that what is being shown as "Old Gen Collections" are not actual CMS collections (those seem to abound, right from the start of the application), but of (Sliding) Mark & Compact GCs.

A (Sliding) Mark & Compact will be triggered when the JVM comes to the conclusion that no new memory is going to be reclaimed by subsequent young generation GCs or even by running CMS again. Just before calling it quits with an OoM error, it will still attempt stop the whole application and run a M&C -- as CMS is a non-compacting algorithm, there's still the possibility that new memory can be made available by rearranging the objects in memory in a more compacted way. This will be a STW operation.

How did I came to this conclusion? Well, if you run the GC logs at trace level, you'll realize that from time to time you'll be getting some CMS:MSC (Concurrent Mark&Sweep : Mark-Sweep-Compact) statements, that seem to coincide with the updates in the OldGen in JVisualVM. Here's the HotSpot code that triggers that statement:

// A work method used by the foreground collector to do
// a mark-sweep-compact.
void CMSCollector::do_compaction_work(bool clear_all_soft_refs) {
  CMSHeap* heap = CMSHeap::heap();

  STWGCTimer* gc_timer = GenMarkSweep::gc_timer();
  gc_timer->register_gc_start();

  SerialOldTracer* gc_tracer = GenMarkSweep::gc_tracer();
  gc_tracer->report_gc_start(heap->gc_cause(), gc_timer->gc_start());

  heap->pre_full_gc_dump(gc_timer);

  GCTraceTime(Trace, gc, phases) t("CMS:MSC");

And actually, by looking at the logs carefully, you can see that it's indeed a Mark Compact happening (I'm filtering out anything below INFO level here, so the original CMS:MSC statement won't show up):

GC(257) Pause Full (Allocation Failure)
GC(257) Phase 1: Mark live objects                       <-- marking
GC(257) Phase 1: Mark live objects 4675.159ms
GC(257) Phase 2: Compute new object addresses
GC(257) Phase 2: Compute new object addresses 1123.827ms
GC(257) Phase 3: Adjust pointers
GC(257) Phase 3: Adjust pointers 2906.019ms
GC(257) Phase 4: Move objects                            <-- compacting
GC(257) Phase 4: Move objects 630.602ms
GC(257) ParNew: 118016K->116364K(118016K)
GC(257) CMS: 1966080K->1966079K(1966080K)
GC(257) Metaspace: 181716K->181716K(1214464K)
GC(257) Pause Full (Allocation Failure) 2035M->2033M(2035M) 16031.595ms
GC(257) User=18.01s Sys=0.15s Real=16.04s

Upvotes: 1

Related Questions