What does “GC--” mean in a java garbage collection

问题:

We've turned on verbose GC logging to keep track of a known memory leak and got the following entries in the log:

...
3607872.687: [GC 471630K->390767K(462208K), 0.0325540 secs]
3607873.213: [GC-- 458095K->462181K(462208K), 0.2757790 secs]
3607873.488: [Full GC 462181K->382186K(462208K), 1.5346420 secs]
...

I understand the first and third of those, but what does the "GC--" one mean?

回答1:

I got these kind of lines in my gc output:

44871.602: [GC-- [PSYoungGen: 342848K->342848K(345600K)] 961401K->1041877K(1044672K), 0.1018780 secs] [Times: user=0.16 sys=0.00, real=0.11 secs]

I read Yishai's answer and it would make sense, but I wanted to see it for myself in the Java GC source code, when the JVM prints "--" in the GC log and why.

Because to my knowledge "Parallel Scavenge" of the Young Gen is a stop-the-world GC, so there couldn't be any objects created parallel to this GC. (see https://blogs.oracle.com/jonthecollector/entry/our_collectors)

You can find this in the jdk source code (see http://hg.openjdk.java.net/jdk7/jdk7) g1CollectedHeap.cpp and psScavenge.cpp

jdk7-ee67ee3bd597/hotspot/src/share$ egrep -h -A2 -B5 -r '"\-\-"' *
# G1 Collector
if (evacuation_failed()) {
  remove_self_forwarding_pointers();
  if (PrintGCDetails) {
    gclog_or_tty->print(" (to-space overflow)");
  } else if (PrintGC) {
    gclog_or_tty->print("--");
  }
}
--
# Parallel Scavenge Collector
promotion_failure_occurred = promotion_failed();
if (promotion_failure_occurred) {
  clean_up_failed_promotion();
  if (PrintGC) {
    gclog_or_tty->print("--");
  }
}

Reason for GC-- with the Parallel Scavenge Collector

The Young GC encountered a promotion failure (see http://mail.openjdk.java.net/pipermail/hotspot-gc-use/2010-March/000567.html):

A promotion failure is a scavenge that does not succeed because there is not enough space in the old gen to do all the needed promotions. The scavenge is in essence unwound and then a full STW compaction of the entire heap is done.

'Not enough space' doesn't necessarily mean that there isn't enough space in old, but that the old space is heavily fragmented (see http://blog.ragozin.info/2011/10/java-cg-hotspots-cms-and-heap.html):

[...] it is impossible to find certain amount of continuous memory to promote particular large object, even though total number of free bytes is large enough.

These two JVM options could help you analyze your heap fragmentation (see http://blog.ragozin.info/2011/10/java-cg-hotspots-cms-and-heap.html):

-XX:+PrintPromotionFailure
-XX:PrintFLSStatistics=1

Reason for GC-- with the G1 Collector

A evacuation failure with the G1 is when a Survivor Region hasn't enough space for the surviving objects from a Young Region.

I don't know if the G1 Collector responds to a evacuation failure with a Full GC or not.

回答2:

I got the following from here:

The first two lines indicate you had two minor collections and one major one. The numbers before and after the arrow indicate the combined size of live objects before and after garbage collection, respectively. After minor collections the count includes objects that aren't necessarily alive but can't be reclaimed, either because they are directly alive, or because they are within or referenced from the tenured generation. The number in parenthesis s the total available space, not counting the space in the permanent generation, which is the total heap minus one The format for the major collection in the third line is similar. The flag -XX:+PrintGCDetails prints additional information about the collections. The additional information printed with this flag is liable to change with each version of the virtual machine. The additional output with the -XX:+PrintGCDetails flag in particular changes with the needs of the development of the Java Virtual Machine. of the survivor spaces. The minor collection took about a quarter of a second.

回答3:

Actually, after encountering this in our own logs, a co-worker and I have an alternative explanation that seems to fit the facts more tightly.

You'll notice in this example that a Full GC follows this weird minor GC line. I can confirm that this is always the case when it crops up in our logs. You can also see that the beginning and end size of the Young Gen is equal, and I can again confirm that this is always the case.

We believe that what is happening here is that the VM has started a Minor GC and, after either not being able to free anything or spending too long without being able to free anything, decides to do a Full instead.

回答4:

It is not on the Java GC FAQ

http://java.sun.com/docs/hotspot/gc1.4.2/faq.html

Nor is anything like that mentioned in the Java GC examples page

http://java.sun.com/docs/hotspot/gc1.4.2/example.html

I've never seen that before.

Do you have any special Garbage Collector running? What VM are you running? Does it always occur before Full GC? Are you calling System.gc()?

回答5:

Yishai said in the comments:

Given the timestamps and memory amounts I would guess it performed a garbage collection but lost available memory (because other objects were created in parallel)