Kyle's Notebook

JVM jstat 监控分析

Word count: 3.4kReading time: 18 min
2020/02/03

JVM jstat 监控分析

jstat 基本用法

jstat 是 JDK 提供的 JVM 统计信息监控工具,可用于查看各 JVM 内存占用与垃圾收集的统计信息。

如每 250ms 查询一次 2764 进程的统计信息、共 20 次,可执行:

1
jstat -gc 2764 250 20

运行输出:

1
2
3
S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT
0.0 4096.0 0.0 4096.0 656384.0 126976.0 388096.0 160782.0 41856.0 37421.6 5504.0 4997.2 264 2.640 0 0.000 2.640 0.0 4096.0
0.0 4096.0 656384.0 126976.0 388096.0 160782.0 41856.0 37421.6 5504.0 4997.2 264 2.640 0 0.000 2.640

其中每个字段的含义:

序号 字段 描述
1 S0C 新生代中第一个 survivor 的容量(字节)
2 S1C 新生代中第二个 survivor 的容量(字节)
3 S0U 新生代中第一个 survivor 目前已使用空间(字节)
4 S1U 新生代中第二个survivor 目前已使用空间(字节)
5 EC 新生代中 Eden 的容量(字节)
6 EU 新生代中 Eden 目前已使用空间(字节)
7 OC Old 的容量(字节)
8 OU Old 目前已使用空间(字节)
9 PC Perm 的容量(字节)
10 PU Perm 目前已使用空间(字节)
11 YGC 从应用程序启动到采样时 Young GC 次数
12 YGCT 从应用程序启动到采样时 Young GC 所用时间(秒)
13 FGC 从应用程序启动到采样时 Full GC 次数
14 FGCT 从应用程序启动到采样时 Full GC 所用时间(秒)
15 GCT 从应用程序启动到采样时 GC 用的总时间(秒)

其他选项的用法直接在命令行输入 jstat 查看提示即可,此处不再赘述。

Young GC

JVM 参数

序号 参数 备注
1 -XX:NewSize=104857600
-XX:MaxNewSize=104857600
新生代初始值和最大值:100MB
2 -XX:InitialHeapSize=209715200
-XX:MaxHeapSize=209715200
堆初始值和最大值:200MB
3 -XX:PretenureSizeThreshold=3145728 进入老年代的对象内存阈值:3MB
4 -XX:MaxTenuringThreshold 进入老年代的对象年龄阈值:15
5 -XX:SurvivorRatio=8 新生代 Eden 占比(Eden 80% 即 80MB,Survivor 各 10% 即 10 MB)
6 -XX:+UseParNewGC 使用 ParNew 收集器(新生代)
7 -XX:+UseConcMarkSweepGC 使用 CMS 收集器
8 -XX:+PrintGCDetails
-XX:+PrintGCTimeStamps
-Xloggc:gc.log
输出日志

测试代码

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
public class Demo {
public static void main(String[] args) throws Exception {
Thread.sleep(30000);
while (true) {
loadData();
}
}

private static void loadData() throws Exception {
byte[] data = null;
for (int i = 0; i < 50; i++) {
data = new byte[200 * 1024];
}
data = null;
Thread.sleep(1000);
}
}

启动:

1
java -jar -XX:NewSize=104857600 -XX:MaxNewSize=104857600 -XX:InitialHeapSize=209715200 -XX:MaxHeapSize=209715200 -XX:SurvivorRatio=8 -XX:MaxTenuringThreshold=15 -XX:PretenureSizeThreshold=3145728 -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -Xloggc:gc.log Demo.jar

使用 jstat 查看 JVM 统计信息(可以先用 jps 找到具体进程号):

1
jstat -gc pid 1000 1000

有以下输出:

1
2
3
4
5
6
7
8
9
10
11
12
13
 S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT
10240.0 10240.0 0.0 0.0 81920.0 6553.7 102400.0 0.0 4480.0 775.1 384.0 76.4 0 0.000 0 0.000 0.000
10240.0 10240.0 0.0 0.0 81920.0 6553.7 102400.0 0.0 4480.0 775.1 384.0 76.4 0 0.000 0 0.000 0.000
10240.0 10240.0 0.0 0.0 81920.0 16354.4 102400.0 0.0 4480.0 775.1 384.0 76.4 0 0.000 0 0.000 0.000
10240.0 10240.0 0.0 0.0 81920.0 26355.2 102400.0 0.0 4480.0 775.1 384.0 76.4 0 0.000 0 0.000 0.000
10240.0 10240.0 0.0 0.0 81920.0 36356.0 102400.0 0.0 4480.0 775.1 384.0 76.4 0 0.000 0 0.000 0.000
10240.0 10240.0 0.0 0.0 81920.0 46356.8 102400.0 0.0 4480.0 775.1 384.0 76.4 0 0.000 0 0.000 0.000
10240.0 10240.0 0.0 0.0 81920.0 56357.6 102400.0 0.0 4480.0 775.1 384.0 76.4 0 0.000 0 0.000 0.000
10240.0 10240.0 0.0 0.0 81920.0 66358.4 102400.0 0.0 4480.0 775.1 384.0 76.4 0 0.000 0 0.000 0.000
10240.0 10240.0 0.0 0.0 81920.0 76359.1 102400.0 0.0 4480.0 775.1 384.0 76.4 0 0.000 0 0.000 0.000
10240.0 10240.0 0.0 1010.6 81920.0 4773.0 102400.0 0.0 4864.0 3836.6 512.0 427.1 1 0.001 0 0.000 0.001
10240.0 10240.0 0.0 1010.6 81920.0 14773.8 102400.0 0.0 4864.0 3836.6 512.0 427.1 1 0.001 0 0.000 0.001
10240.0 10240.0 0.0 1010.6 81920.0 24774.5 102400.0 0.0 4864.0 3836.6 512.0 427.1 1 0.001 0 0.000 0.001

留意 S1U、EU、YGC、YGCT 列:

  • Eden 使用空间从 76359 下降到 4773 时发生了一次 Young GC,用时 0.001s,回收了 70MB 的对象;

  • 再根据从 6553.7 到 76359.1 增长所需 8s,可推断出这个程序每过 8s 就需要发生一次用时 0.001s 的 YGC;

  • 留意 S1U 列,之前一直是 0.0,发生一次 YGC 后变成 1010.6,表示存活的对象约 1MB,可轻松放入 10MB 的 Survivor(下次 YGC 发生后会迁到另一个 Survivor,因此完全够用)。

1
2
3
4
5
6
7
8
9
10
11
12
13
 S1U       EU    YGC    YGCT    
0.0 6553.7 0 0.000
0.0 6553.7 0 0.000
0.0 16354.4 0 0.000
0.0 26355.2 0 0.000
0.0 36356.0 0 0.000
0.0 46356.8 0 0.000
0.0 56357.6 0 0.000
0.0 66358.4 0 0.000
0.0 76359.1 0 0.000
1010.6 4773.0 1 0.001
1010.6 14773.8 1 0.001
1010.6 24774.5 1 0.001

Full GC

JVM 参数

基本同上一节,并把大对象阈值 20MB,避免分配的对象直接存入老年代:

序号 参数 备注
1 -XX:PretenureSizeThreshold=20971520 进入老年代的对象内存阈值:20MB

测试代码

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
public class Demo {

public static void main(String[] args) throws Exception {
Thread.sleep(30000);
while (true) {
loadData();
}
}

private static void loadData() throws Exception {
byte[] data = null;
for (int i = 0; i < 4; i++) {
data = new byte[10 * 1024 * 1024];
}
data = null;
byte[] data1 = new byte[10 * 1024 * 1024];
byte[] data2 = new byte[10 * 1024 * 1024];
byte[] data3 = new byte[10 * 1024 * 1024];
data3 = new byte[10 * 1024 * 1024];

Thread.sleep(1000);
}
}

启动:

1
java -jar -XX:NewSize=104857600 -XX:MaxNewSize=104857600 -XX:InitialHeapSize=209715200 -XX:MaxHeapSize=209715200 -XX:SurvivorRatio=8 -XX:MaxTenuringThreshold=15 -XX:PretenureSizeThreshold=20971520 -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -Xloggc:gc.log Demo.jar

使用 jstat 查看 JVM 统计信息(可以先用 jps 找到具体进程号):

1
jstat -gc pid 1000 1000

有以下输出:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
 S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT
10240.0 10240.0 0.0 0.0 81920.0 6553.7 102400.0 0.0 4480.0 775.1 384.0 76.4 0 0.000 0 0.000 0.000
10240.0 10240.0 0.0 803.1 81920.0 10240.0 102400.0 30722.1 4864.0 3831.0 512.0 427.1 1 0.016 0 0.000 0.016
10240.0 10240.0 1161.5 0.0 81920.0 23630.5 102400.0 51204.2 4864.0 3831.3 512.0 427.1 2 0.027 1 0.001 0.027
10240.0 10240.0 0.0 1280.8 81920.0 32252.2 102400.0 61446.2 4864.0 3831.5 512.0 427.1 3 0.032 1 0.001 0.033
10240.0 10240.0 1022.0 0.0 81920.0 42517.4 102400.0 30726.2 4864.0 3831.5 512.0 427.1 4 0.033 2 0.002 0.036
10240.0 10240.0 0.0 1152.2 81920.0 52773.6 102400.0 40966.2 4864.0 3831.5 512.0 427.1 5 0.035 2 0.002 0.038
10240.0 10240.0 1278.4 0.0 81920.0 63024.0 102400.0 51206.2 4864.0 3831.5 512.0 427.1 6 0.037 2 0.002 0.039
10240.0 10240.0 0.0 1013.4 81920.0 73270.7 102400.0 61446.2 4864.0 3831.5 512.0 427.1 7 0.039 3 0.003 0.042
10240.0 10240.0 0.0 1260.0 81920.0 10240.0 102400.0 40966.2 4864.0 3831.5 512.0 427.1 9 0.056 4 0.004 0.060
10240.0 10240.0 999.8 0.0 81920.0 22079.4 102400.0 61448.3 4864.0 3831.5 512.0 427.1 10 0.059 5 0.004 0.064
10240.0 10240.0 0.0 1104.2 81920.0 32320.6 102400.0 71688.3 4864.0 3831.5 512.0 427.1 11 0.061 5 0.004 0.066
10240.0 10240.0 1082.0 0.0 81920.0 42561.3 102400.0 30728.2 4864.0 3831.5 512.0 427.1 12 0.062 6 0.006 0.068
10240.0 10240.0 0.0 1119.4 81920.0 52801.8 102400.0 40968.2 4864.0 3831.5 512.0 427.1 13 0.066 6 0.006 0.072

重点关注以下几列:

  • 可见除了 S0U、S1U 以外,OU 也不断变更,这是因为每次 GC 都有超过 10MB 的对象存活,Survivor 区放不下,直接被迁到老年代;

  • 由于老年代也不够用,会频繁发生 Full GC,每次清理后仍有约 3MB;

  • 此时也可以发现随着 Full GC 的发生, YGCT 耗时也慢了很多,因为每次 Full GC 都是由 Young GC 触发的(Young GC 后迁入老年代,但老年代不足,要先清理),Young GC 需要等待 Full GC 执行完毕才能把存活对象放入老年代。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
S0U     S1U       EU       OU     YGC   YGCT   FGC  FGCT     GCT
0.0 0.0 6553.7 0.0 0 0.000 0 0.000 0.000
0.0 803.1 10240.0 30722.1 1 0.016 0 0.000 0.016
1161.5 0.0 23630.5 51204.2 2 0.027 1 0.001 0.027
0.0 1280.8 32252.2 61446.2 3 0.032 1 0.001 0.033
1022.0 0.0 42517.4 30726.2 4 0.033 2 0.002 0.036
0.0 1152.2 52773.6 40966.2 5 0.035 2 0.002 0.038
1278.4 0.0 63024.0 51206.2 6 0.037 2 0.002 0.039
0.0 1013.4 73270.7 61446.2 7 0.039 3 0.003 0.042
0.0 1260.0 10240.0 40966.2 9 0.056 4 0.004 0.060
999.8 0.0 22079.4 61448.3 10 0.059 5 0.004 0.064
0.0 1104.2 32320.6 71688.3 11 0.061 5 0.004 0.066
1082.0 0.0 42561.3 30728.2 12 0.062 6 0.006 0.068
0.0 1119.4 52801.8 40968.2 13 0.066 6 0.006 0.072

优化:只需要增加 Survivor 内存,使其可以存放每次 Young GC 后存活的对象即可(此处为使效果更明显,增大了堆和新生代内存)。

序号 参数 备注
1 -XX:NewSize=209715200
-XX:MaxNewSize=209715200
新生代初始值和最大值:200MB
2 -XX:InitialHeapSize=314572800
-XX:MaxHeapSize=314572800
堆初始值和最大值:300MB
5 -XX:SurvivorRatio=2 新生代 Eden 占比(Eden 50% 即 100MB,Survivor 各 25% 即 50 MB)

重新运行后输出日志:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
 S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT
51200.0 51200.0 0.0 0.0 102400.0 8192.1 102400.0 0.0 4480.0 775.1 384.0 76.4 0 0.000 0 0.000 0.000
51200.0 51200.0 0.0 0.0 102400.0 8192.1 102400.0 0.0 4480.0 775.1 384.0 76.4 0 0.000 0 0.000 0.000
51200.0 51200.0 0.0 0.0 102400.0 90112.2 102400.0 0.0 4480.0 775.1 384.0 76.4 0 0.000 0 0.000 0.000
51200.0 51200.0 0.0 11037.3 102400.0 73644.5 102400.0 0.0 4864.0 3833.1 512.0 427.1 1 0.007 0 0.000 0.007
51200.0 51200.0 11302.1 0.0 102400.0 65399.2 102400.0 0.0 4864.0 3833.5 512.0 427.1 2 0.013 0 0.000 0.013
51200.0 51200.0 0.0 11334.0 102400.0 53129.6 102400.0 0.0 4864.0 3833.6 512.0 427.1 3 0.015 0 0.000 0.015
51200.0 51200.0 1028.8 0.0 102400.0 42916.3 102400.0 0.0 4864.0 3833.6 512.0 427.1 4 0.016 0 0.000 0.016
51200.0 51200.0 0.0 11369.4 102400.0 32693.5 102400.0 0.0 4864.0 3833.6 512.0 427.1 5 0.017 0 0.000 0.017
51200.0 51200.0 21517.0 0.0 102400.0 22464.6 102400.0 0.0 4864.0 3833.6 512.0 427.1 6 0.024 0 0.000 0.024
51200.0 51200.0 0.0 31851.7 102400.0 10240.0 102400.0 0.0 4864.0 3833.6 512.0 427.1 7 0.038 0 0.000 0.038
51200.0 51200.0 0.0 31851.7 102400.0 94151.8 102400.0 0.0 4864.0 3833.6 512.0 427.1 7 0.038 0 0.000 0.038
51200.0 51200.0 0.0 0.0 102400.0 83916.3 102400.0 826.8 4864.0 3833.6 512.0 427.1 8 0.042 0 0.000 0.042
51200.0 51200.0 0.0 10240.0 102400.0 73679.2 102400.0 826.8 4864.0 3833.6 512.0 427.1 9 0.044 0 0.000 0.044
51200.0 51200.0 10240.0 0.0 102400.0 63441.1 102400.0 826.8 4864.0 3833.6 512.0 427.1 10 0.046 0 0.000 0.046
51200.0 51200.0 0.0 10240.0 102400.0 53202.3 102400.0 826.8 4864.0 3833.6 512.0 427.1 11 0.048 0 0.000 0.048

可见已经不会发生 Full GC,每次 Young GC 后存活的对象都只在 Survivor 之间移动,老年代也稳定在 826.8KB。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
 S0U    S1U       EU       OU    YGC    YGCT  FGC  FGCT     GCT
0.0 0.0 8192.1 0.0 0 0.000 0 0.000 0.000
0.0 0.0 8192.1 0.0 0 0.000 0 0.000 0.000
0.0 0.0 90112.2 0.0 0 0.000 0 0.000 0.000
0.0 11037.3 73644.5 0.0 1 0.007 0 0.000 0.007
11302.1 0.0 65399.2 0.0 2 0.013 0 0.000 0.013
0.0 11334.0 53129.6 0.0 3 0.015 0 0.000 0.015
1028.8 0.0 42916.3 0.0 4 0.016 0 0.000 0.016
0.0 11369.4 32693.5 0.0 5 0.017 0 0.000 0.017
21517.0 0.0 22464.6 0.0 6 0.024 0 0.000 0.024
0.0 31851.7 10240.0 0.0 7 0.038 0 0.000 0.038
0.0 31851.7 94151.8 0.0 7 0.038 0 0.000 0.038
0.0 0.0 83916.3 826.8 8 0.042 0 0.000 0.042
0.0 10240.0 73679.2 826.8 9 0.044 0 0.000 0.044
10240.0 0.0 63441.1 826.8 10 0.046 0 0.000 0.046
0.0 10240.0 53202.3 826.8 11 0.048 0 0.000 0.048

总结

这里只是简单举例讲解了最基本的用法,实际上可以总结为:

  • 重点关注新生代对象增长速率,Young GC 触发频率、耗时、存活对象、进入老年代的对象,老年代对象增长速率,Full GC 触发频率、耗时;

  • 对于一般系统,老年代对象增长速度很慢(比如每 n 分钟发生一次 YGC,老年代增长 xMB),如果每次 Young GC 发生后老年代增长较快,则很可能是每次 Young GC 存活对象太多、触发动态年龄判断规则,或 Survivor 太小放不下存活对象;

  • 从 Young GC 发生频率得出老年代增长速度,从而可以推断出 Full GC 发生频率。

CATALOG
  1. 1. JVM jstat 监控分析
    1. 1.1. jstat 基本用法
    2. 1.2. Young GC
      1. 1.2.1. JVM 参数
      2. 1.2.2. 测试代码
    3. 1.3. Full GC
      1. 1.3.1. JVM 参数
      2. 1.3.2. 测试代码
    4. 1.4. 总结