Summary

Add CGC column to jstat for monitoring STW (stop the world) phases in concurrent GC.

Problem

STW phases (Initial Mark and Remark) at CMS are counted in jstat FGC column. However, FGC column is incremented when Full GC is occurred. So we cannot judge Full GC is occurred or not from jstat output. Also STW phases on G1 (Remark and Cleanup) are not counted in any jstat output.

Solution

I added new PerfCounters for monitoring STW concurrent GC phases count and elapsed time. Also I added new column to jstat output: CGC (count) and CGCT (elapsed time).

Specification

http://cr.openjdk.java.net/~ysuenaga/JDK-8153333/webrev.07/

I added new CollectorCounters which is named sun.gc.collector.2 . This counter keeps STW phase metrics in concurrent GC. It is incremented at VMOperations of STW phase in concurrent GC.

G1

Neither YGC nor FGC are not counted in spite of GC is occurred via jcmd. (Target VM is added -XX:+ExplicitGCInvokesConcurrent )

$ jstat -gc 3576 1000 1
 S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT
 0.0    0.0    0.0    0.0   26624.0    0.0     487424.0     0.0      0.0    0.0    0.0    0.0        0    0.000   0      0.000    0.000
$
$ jcmd 3576 GC.run
3576:
Command executed successfully
$
$ jstat -gc 3576 1000 1
 S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT
 0.0   2048.0  0.0   2048.0 24576.0    0.0     487424.0     0.0     4864.0 3829.9 512.0  325.9       1    0.012   0      0.000    0.012

CGC / CGCT are counted when concurrent GC is occurred. They show STW phases in concurrent GC.

$ jstat -gc 16604 1000 1
 S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT    CGC    CGCT     GCT
 0.0    0.0    0.0    0.0   26624.0    0.0     487424.0     0.0      0.0    0.0    0.0    0.0        0    0.000   0      0.000   0      0.000    0.000
$
$ jcmd 16604 GC.run
16604:
Command executed successfully
$ jstat -gc 16604 1000 1
 S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT    CGC    CGCT     GCT
 0.0   2048.0  0.0   2048.0 24576.0    0.0     487424.0     0.0     4864.0 3825.5 512.0  325.9       1    0.012   0      0.000   2      0.007    0.019

CMS

FGC / FGCT are counted when GC is occurred via jcmd. (Target VM is added -XX:+ExplicitGCInvokesConcurrent )

$ jstat -gc 3714 1000 1
 S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT
17088.0 17088.0  0.0    0.0   137152.0  8229.3   342720.0     0.0      0.0    0.0    0.0    0.0        0    0.000   0      0.000    0.000
$
$ jcmd 3714 GC.run
3714:
Command executed successfully
$
$ jstat -gc 3714 1000 1
 S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT
17088.0 17088.0  0.0   547.4  137152.0   0.0     342720.0     0.0     4864.0 3830.0 512.0  325.9       1    0.012   2      0.022    0.034

CGC / CGCT are counted when concurrent GC is occurred. They show STW phases in concurrent GC, and FGC / FGCT are not counted for them.

$ jstat -gc 20651 1000 1
 S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT    CGC    CGCT     GCT
17088.0 17088.0  0.0    0.0   137152.0  8229.3   342720.0     0.0      0.0    0.0    0.0    0.0        0    0.000   0      0.000   0      0.000    0.000
$
$ jcmd 20651 GC.run
20651:
Command executed successfully
$ ~/OpenJDK/jdk-hs/build/linux-x86_64-normal-server-fastdebug/images/jdk/bin/jstat -gc 20651 1000 1
 S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT    CGC    CGCT     GCT
17088.0 17088.0  0.0   544.2  137152.0   0.0     342720.0     0.0     4864.0 3830.0 512.0  325.9       1    0.005   0      0.000   2      0.014    0.019