Full GC performed when not needed

alevine

I've been monitoring a stress test being done and need to understand why a Full GC occurs?

The jstat -gccause shows:

  S0     S1     E      O      P     YGC     YGCT    FGC    FGCT     GCT    LGCC                 GCC                

  0.00   0.00  78.12  15.57  99.83    234   16.378   154  163.136  179.514 System.gc()          No GC              

  0.00   0.00  80.65  15.57  99.83    234   16.378   154  163.136  179.514 System.gc()          No GC              

  0.00  33.97   0.00  15.57  99.83    235   16.430   155  163.136  179.566 No GC                System.gc()

As far as I understand, system.gc is a manual request for Full GC? Can this be called by the jvm itself for some reason?

The jstat -gccapacity shows:

NGCMN    NGCMX     NGC     S0C   S1C       EC      OGCMN      OGCMX       OGC         OC      PGCMN    PGCMX     PGC       PC     YGC    FGC

1048576.0 1048576.0 1048576.0 83968.0 80896.0 883712.0  2097152.0  2097152.0  2097152.0  2097152.0  21504.0 524288.0 243200.0 243200.0    266   181

1048576.0 1048576.0 1048576.0 77824.0 80896.0 883712.0  2097152.0  2097152.0  2097152.0  2097152.0  21504.0 524288.0 243200.0 243200.0    267   182

1048576.0 1048576.0 1048576.0 77824.0 80896.0 883712.0  2097152.0  2097152.0  2097152.0  2097152.0  21504.0 524288.0 243200.0 243200.0    267   182

The jstat -gcutil shows:

S0     S1     E      O      P     YGC     YGCT    FGC    FGCT     GCT  

  0.00   0.00  46.76  15.26  99.89    270   18.568   185  195.039  213.607

  0.00  36.94   0.00  15.26  99.89    271   18.620   186  195.039  213.659

  0.00   0.00   7.90  15.14  99.89    271   18.620   186  196.042  214.663

  0.00   0.00  46.57  15.14  99.89    271   18.620   186  196.042  214.663

  0.00   0.00  65.36  15.14  99.89    271   18.620   186  196.042  214.663

  0.00   0.00  70.43  15.14  99.89    271   18.620   186  196.042  214.663

  0.00   0.00  73.01  15.14  99.89    271   18.620   186  196.042  214.663

40.18   0.00   0.00  15.14  99.89    272   18.676   187  196.042  214.718

  0.00   0.00   3.20  15.17  99.89    272   18.676   187  196.998  215.674

And verbosegc shows:

[GC [PSYoungGen: 723691K->39704K(962048K)] 1041343K->357355K(3059200K), 0.0484510 secs] [Times: user=0.09 sys=0.00, real=0.05 secs]

[Full GC [PSYoungGen: 39704K->0K(962048K)] [ParOldGen: 317651K->327322K(2097152K)] 357355K->327322K(3059200K) [PSPermGen: 243053K->243053K(243200K)], 1.0875260 secs] [Times: user=1.58 sys=0.01, real=1.09 secs]

[GC [PSYoungGen: 623020K->38985K(957952K)] 950343K->366308K(3055104K), 0.0537650 secs] [Times: user=0.08 sys=0.00, real=0.05 secs]

[Full GC [PSYoungGen: 38985K->0K(957952K)] [ParOldGen: 327322K->326737K(2097152K)] 366308K->326737K(3055104K) [PSPermGen: 243053K->243053K(243200K)], 0.9313790 secs] [Times: user=1.57 sys=0.00, real=0.93 secs]

[GC [PSYoungGen: 684235K->29918K(966656K)] 1010972K->356655K(3063808K), 0.0459150 secs] [Times: user=0.08 sys=0.01, real=0.05 secs]

[Full GC [PSYoungGen: 29918K->0K(966656K)] [ParOldGen: 326737K->317554K(2097152K)] 356655K->317554K(3063808K) [PSPermGen: 243054K->243054K(243200K)], 0.9135880 secs] [Times: user=1.55 sys=0.00, real=0.91 secs]

Why would a Full GC be performed to clean up PSYoungGen, using System.gc() calls?

Any help would be greatly appreciated.