Why no FullGC but old gen from 99% to 14% display in results of the jstat -gcutil?

4
votes

jstat -gcutil as shown below:

enter image description here

The old gen first from 13.78 to 99.98,then to 14.81,but the FGCT is always 1, Why?

In addition to FullGC, there are other reasons to cause this situation?

GC is CMS and JVM parameters:

-Xms4096m -Xmx4096m -Xss256k -XX:PermSize=256m -XX:MaxPermSize=256m -XX:NewSize=512m -XX:MaxNewSize=512m -XX:SurvivorRatio=16 -XX:+UseParNewGC -XX:ParallelGCThreads=16 -XX:MaxTenuringThreshold=32 -XX:+UseConcMarkSweepGC -XX:ParallelCMSThreads=8 -XX:+CMSParallelRemarkEnabled -XX:+CMSPermGenPrecleaningEnabled -XX:CMSInitiatingOccupancyFraction=70 -XX:+UseCMSCompactAtFullCollection

2
javagarbage-collectionjvm
Which JVM version are you on? – K Erlandsson
Java HotSpot(TM) 64-Bit Server VM Version 24.55-b03 – Jindong
Can you reproduce this? If so, please provide the output from jstat -gc (not -gcutil) as well. Running the JVM with -XX:+PrintGCDetails provides additional detail, such a log file could also help. – K Erlandsson
this occurred in my production environment,difficult to reproduce – Jindong

2 Answers

2
votes

I did some tests on my own and my conclusion is that it seems to be a bug in jstat when running with your JVM parameters. I ran jstat -gc and jstat -gcutil at the same time on a simple test application and I had the following output:

jstat -gc:

S0C    S1C    S0U    S1U      EC       EU        OC         OU
29120,0 29120,0  0,0    0,0   466048,0 18642,2  3670016,0     0,0
29120,0 29120,0  0,0    0,0   466048,0 18642,2  3670016,0     0,0
29120,0 29120,0  0,0    0,0   466048,0 18642,2  3670016,0     0,0
29120,0 29120,0  0,0    0,0   466048,0 18642,2  3670016,0     0,0
29120,0 29120,0  0,0    0,0   466048,0 18642,2  3670016,0     0,0
29120,0 29120,0  0,0    0,0   466048,0 55926,2  3670016,0     0,0
29120,0 29120,0  0,0    0,0   466048,0 369663,6 3670016,0     0,0
29120,0 29120,0  0,0   29120,0 466048,0 466048,0 3670016,0   94773,6
29120,0 29120,0  0,0   29120,0 466048,0 299100,8 3670016,0   118478,6
29120,0 29120,0 29120,0  0,0   466048,0  9163,2  3670016,0   254498,6

jstat -gcutil

 S0     S1     E      O      P     YGC     YGCT    FGC    FGCT     GCT
  0,00   0,00   4,00   0,00   0,93      0    0,000     0    0,000    0,000
  0,00   0,00   4,00   0,00   0,93      0    0,000     0    0,000    0,000
  0,00   0,00   4,00   0,00   0,93      0    0,000     0    0,000    0,000
  0,00   0,00   4,00   0,00   0,93      0    0,000     0    0,000    0,000
  0,00   0,00   4,00   0,00   0,93      0    0,000     0    0,000    0,000
  0,00   0,00  26,00   0,00   0,97      0    0,000     0    0,000    0,000
  0,00   0,00  89,32   0,00   0,97      0    0,000     0    0,000    0,000
  0,00 100,00 100,00 100,00   0,97      1    0,000     0    0,000    0,000
  0,00 100,00  80,02   3,23   0,97      1    0,905     0    0,000    0,905
100,00   0,00  13,76   6,93   0,97      2    1,441     0    0,000    1,441

As you can see, my Old used when running -gcutil jumps to 100 even though the application just started filling old gen. jstat -gc shows the old generation almost entirely empty. The application is very simple and just fills up a HashMap, why there is no way that old gen would be 100% full when jstat -gcutil says so.

1
votes

  1. A HotSpot JVM full GC is counted when the young generation and the permanent generation are collected... (Source: Analyzing the Performance Impact of Memory Utilization and Garbage Collection, goto section Major vs. Minor Garbage Collections)

  2. There is a ambigious use out there of the term "full garbage collection" in different tools, some show no GC events and others report gc events if run at the same time and the same JVM. Keep this in mind if you have to compare output/reports.

So back to your question:

When I take a look at your output I can see that the permantent space utilization is increasing. It started with 19.59 and is 19.70 in the last line of your output. No permanent generation GC occured until that moment. That is the reason why FGC is still 1.

Additional some notes regarding the jstats -gcutil output.

  • O: Old space utilization, or as you call it old gen.
  • P: Permanent space utilization
  • YGC: young generation garbage collection count
  • FGC: full garbage collection count
  • GCT: Total garbage collection time.

. S0 S1 E O P YGC YGCT FGC FGCT GCT 12.44 0.00 27.20 9.49 96.70 78 0.176 5 0.495 0.672 12.44 0.00 62.16 9.49 96.70 78 0.176 5 0.495 0.672 12.44 0.00 83.97 9.49 96.70 78 0.176 5 0.495 0.672 0.00 7.74 0.00 9.51 96.70 79 0.177 5 0.495 0.673

The shown values for YGC, YGCT, FGC and FGCT refer to the moment the Hotspot JVM started and no to the moment when you started jstat -gcutil. Just the case you are wondering the output might start with e.g. 12 FGC in the first line.

Here is the jstat doc: Java 6 jstat doc