JVM监控与调优:jstat命令实战

无涯WuYa

发布于 2023-09-21 16:35:43

1550

发布于 2023-09-21 16:35:43

在生产环境中执行的应用程序当出现响应时间慢以及过于频繁的GC，那么此时就需要收集JVM运行的数据来分析是什么原因导致了应用程序响应时间慢，也许在这个过程中出现了大量的文件I/O加载导致都有可能导致程序出现内存泄露等情况。特别是在企业级的生产环境中，在出现问题的时候很难使用主流的可视化工具来查看JVM运行过程中的数据，此时可以使用jstat命令工具来收集JVM运行过程中的数据，下面详细地阐述jstat命令行工具的案例应用与实战。

jstat全称为JVM Statistics Monitoring Tool，它主要用于收集JVM在执行过程中运行的各种数据，如垃圾收集，GC次数以及YGC、YGCT等数据。jstat是一个命令行的工具，下面汇总了jstat命令行使用过程中常用到的选项，具体如下所示。

-gc:监视JAVA的堆情况，包含了老年代、新生代、GC次数&时间等
gcnew:监视新生代GC状况
-gcold:监视老生代GC状况
-gcutil:输出的内容与“-gc”基本一致，重点关注已使用空间占总空间的百分比
-class:监视类装、卸载数量、总空间、类装载所消耗费的时间

jstat案例实战

在案例代码中编写了不断的加载对象，持续的进行最终会导致程序出现内存泄露，涉及到的案例代码如下。

import java.util.ArrayList;
import java.util.List;
import java.util.UUID;

@RestController
public class HeapController
{
  @RequestMapping("/heap")
  public void   heap ()
{
    List<Person> lists=new ArrayList<Person>();
    while (true)
    {
      int i=0;
      lists.add(new Person(i++,UUID.randomUUID().toString()));
    }
  }
}

启动应用程序，逐步地演示下上面阐述到的各个命令行选项工具的应用。首先来看“-class”中需要输出的信息，每隔1秒打印一次并且加上时间戳,打印10次，每5行输出表头信息，执行命令以及输出的结果信息如下：

localhost:~ $ jps
48199 Jps
48143 DbPlusApplication
localhost:~ $ jstat -class -t -h5 48143 1000 10
Timestamp       Loaded  Bytes  Unloaded  Bytes     Time
          146.6   8356 15240.6        0     0.0       3.09
          147.6   8356 15240.6        0     0.0       3.09
          148.6   8356 15240.6        0     0.0       3.09
          149.6   8601 15672.1       43    58.6       3.23
          150.6   8601 15672.1       43    58.6       3.23
Timestamp       Loaded  Bytes  Unloaded  Bytes     Time
          151.6   8601 15672.1       43    58.6       3.23
          152.6   8752 15925.3       43    58.6       3.33
          153.6   8771 15948.6       43    58.6       3.33
          154.6   8771 15948.6       43    58.6       3.33
          155.6   8771 15948.6       43    58.6       3.33

备注：如上可以看到类装载、卸载数量、装载耗时都是呈上升的趋势。

下面再演示下可能出现内存泄露的情况下新生代指标的变化趋势，执行命令以及输出结果信息如下：

localhost:~ $ jps
48354 DbPlusApplication
48367 Jps
localhost:~ $ jstat -gcnew -t -h5 48354 1000 10
Timestamp        S0C    S1C    S0U    S1U   TT MTT  DSS      EC       EU     YGC     YGCT
           50.1 2048.0 2048.0    0.0  584.8  1  15 2048.0   6656.0   1738.5     65    0.121
           51.1 2048.0 2048.0    0.0  584.8  1  15 2048.0   6656.0   1789.4     65    0.121
           52.1 2048.0 2048.0    0.0  950.9  1  15 2048.0   6656.0      0.0     69    0.133
           53.2 2048.0 2048.0    0.0    0.0  1  15 2048.0   6656.0   6656.0     75    0.146
           54.2 2048.0 2048.0    0.0    0.0  1  15 2048.0   6656.0   6656.0     75    0.146
Timestamp        S0C    S1C    S0U    S1U   TT MTT  DSS      EC       EU     YGC     YGCT
           55.2 2048.0 2048.0    0.0    0.0  1  15 2048.0   6656.0   6656.0     75    0.146
           56.2 2048.0 1536.0 1089.8    0.0  2  15 1536.0   7168.0   6184.5     76    0.149
           57.2 2048.0 1536.0 1089.8    0.0  2  15 1536.0   7168.0   6527.5     76    0.149
           58.2 2048.0 1536.0 1089.8    0.0  2  15 1536.0   7168.0   6601.6     76    0.149
           59.2 2048.0 1536.0 1089.8    0.0  2  15 1536.0   7168.0   6665.8     77    0.149

备注：如上输出信息中，可以看到新生代空间EU从1738.5一直上升到6665.8，YGC的次数最多是77，YGCT耗时时间从0.121s一直上升到0.149s。

如下演示可能出现内存泄露的情况下老年代指标变化的趋势过程，执行的命令以及输出的结果信息如下：

localhost:~ $ jps
48518 DbPlusApplication
48523 Jps
localhost:~ $ jstat -gcold -t -h5 48518 1000 15
Timestamp          MC       MU      CCSC     CCSU       OC          OU       YGC    FGC    FGCT     GCT
           31.0  46168.0  43040.7   6272.0   5611.1     22016.0     19029.5     65     2    0.081    0.235
           32.1  46168.0  43040.7   6272.0   5611.1     22016.0     19029.5     65     2    0.081    0.235
           33.1  46168.0  43040.7   6272.0   5611.1     22016.0     19029.5     65     2    0.081    0.235
           34.1  46168.0  43040.7   6272.0   5611.1     22016.0     19029.5     65     2    0.081    0.235
           35.0  47576.0  44156.6   6400.0   5750.3     22016.0     21703.9     75    16    0.813    1.000
Timestamp          MC       MU      CCSC     CCSU       OC          OU       YGC    FGC    FGCT     GCT
           36.0  47576.0  44156.8   6400.0   5750.3     22016.0     21703.6     75    36    1.805    1.992
           37.1  47576.0  44156.9   6400.0   5750.3     22016.0     21703.6     75    55    2.769    2.956
           38.1  47832.0  44645.1   6400.0   5818.2     22016.0     15092.8     76    57    3.009    3.198
           39.1  48728.0  45331.7   6528.0   5905.2     22016.0     21948.4     86    71    3.724    3.934
           40.1  48728.0  45331.7   6528.0   5905.2     22016.0     21670.1     86    94    4.744    4.954
Timestamp          MC       MU      CCSC     CCSU       OC          OU       YGC    FGC    FGCT     GCT
           41.1  48728.0  45333.8   6528.0   5905.8     22016.0     21670.1     86   116    5.721    5.931
           42.1  48728.0  45333.8   6528.0   5905.8     22016.0     15336.1     86   120    5.951    6.161
           43.1  48728.0  45343.0   6528.0   5905.8     22016.0     21711.1     98   137    6.692    6.926
           44.1  48728.0  45343.0   6528.0   5905.8     22016.0     21710.9     98   160    7.723    7.957
           45.1  48728.0  45343.0   6528.0   5905.8     22016.0     15346.2     98   176    8.434    8.669

备注：在如上可以看到OU的变化趋势是上升到21711.1最后是下降的趋势，而YGC、FGC的次数一直是上升的趋势，FGCT、GCT的耗时也是上升的趋势，其中GCT的总耗时最大是8.669s。

判断是否内存泄露

在jstat命令行工具中可以根据如下的思路来判断是否可能出现了内存泄露，具体思路如下：

运行中的Java程序，运行jstat命令行工具获取JVM运行的数据，重点关注OU值的数据(OU:老年代目前已使用空间)
重复如上的操作，如果OU的值呈上升的趋势，说明Java程序的老年代内存已使用量在不断上涨，那么也就意味着无法回收的对象在不断的增加，很有可能存在内存泄露。

根据如上的思路，下面调用应用程序的不同接口，关注所有的GC指标，执行的命令以及输出的值信息如下

localhost:~ $ jps
49066 DbPlusApplication
49083 Jps
localhost:~ $ jstat -gc -t -h5 49066   1000  30
Timestamp        S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT
           33.4 2560.0 2560.0 608.0   0.0    5632.0   4355.3   22016.0    19491.3   45904.0 42710.0 6224.0 5572.1     64    0.186   2      0.108    0.294
           34.4 2560.0 2560.0 608.0   0.0    5632.0   4468.2   22016.0    19491.3   45904.0 42710.0 6224.0 5572.1     64    0.186   2      0.108    0.294
           35.4 2560.0 2560.0 608.0   0.0    5632.0   4524.6   22016.0    19491.3   45904.0 42710.0 6224.0 5572.1     64    0.186   2      0.108    0.294
           36.4 2560.0 2560.0 608.0   0.0    5632.0   4637.4   22016.0    19491.3   45904.0 42710.0 6224.0 5572.1     64    0.186   2      0.108    0.294
           37.4 2560.0 2560.0 608.0   0.0    5632.0   4694.1   22016.0    19491.3   45904.0 42710.0 6224.0 5572.1     64    0.186   2      0.108    0.294
Timestamp        S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT
           38.4 2048.0 2048.0  0.0   1113.9  6656.0   2269.6   22016.0    20336.9   47952.0 44524.5 6480.0 5821.6     67    0.198   2      0.108    0.305
           39.4 2048.0 2048.0  0.0   1113.9  6656.0   2354.7   22016.0    20336.9   47952.0 44524.5 6480.0 5821.6     67    0.198   2      0.108    0.305
           40.4 2048.0 2048.0 1118.5  0.0    6656.0   726.2    22016.0    20800.9   48720.0 45417.2 6480.0 5915.8     68    0.200   2      0.108    0.308
           41.4 2048.0 2048.0 1118.5  0.0    6656.0   1594.6   22016.0    20800.9   48720.0 45417.2 6480.0 5915.8     68    0.200   2      0.108    0.308
           42.4 2048.0 2048.0  0.0    0.0    6656.0   698.4    22016.0    16514.3   49360.0 46074.2 6608.0 5989.8     69    0.204   3      0.215    0.418
Timestamp        S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT
           43.4 2048.0 2048.0  0.0   985.3   6656.0    0.0     22016.0    20549.8   49360.0 46117.1 6608.0 5995.6     75    0.230   3      0.215    0.445
           44.4 2048.0 2048.0  0.0    0.0    6656.0   5995.1   22016.0    21668.7   49360.0 46110.1 6608.0 5994.5     76    0.236  20      1.133    1.369
           45.4 2048.0 2048.0  0.0    0.0    6656.0   6624.6   22016.0    21576.5   49360.0 46110.1 6608.0 5994.5     76    0.236  39      2.139    2.376
           46.4 2048.0 2048.0  0.0    0.0    6656.0   6652.9   22016.0    21525.2   49360.0 46110.1 6608.0 5994.5     76    0.236  58      3.157    3.393
           47.4 2048.0 2048.0  0.0    0.0    6656.0   6656.0   22016.0    21525.7   49360.0 46110.1 6608.0 5994.5     76    0.236  77      4.113    4.349
Timestamp        S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT
           48.4 2048.0 2048.0  0.0    0.0    6656.0   6656.0   22016.0    21528.9   49360.0 46110.1 6608.0 5994.5     76    0.236  97      5.120    5.356
           49.5 2048.0 2048.0  0.0    0.0    6656.0   6656.0   22016.0    21532.5   49360.0 46110.4 6608.0 5994.5     76    0.236  116     6.105    6.341
           50.5 2048.0 2048.0  0.0    0.0    6656.0   6656.0   22016.0    21538.4   49360.0 46110.4 6608.0 5994.5     76    0.236  136     7.124    7.360
           51.4 2048.0 2048.0  0.0    0.0    6656.0   6656.0   22016.0    21540.8   49360.0 46110.4 6608.0 5994.5     76    0.236  156     8.141    8.377
           52.4 2048.0 2048.0  0.0    0.0    6656.0   6656.0   22016.0    21548.3   49360.0 46110.4 6608.0 5994.5     76    0.236  175     9.101    9.337
Timestamp        S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT
           53.4 2048.0 2048.0  0.0    0.0    6656.0   6656.0   22016.0    21558.3   49360.0 46110.4 6608.0 5994.5     76    0.236  195    10.106   10.342
           54.4 2048.0 2048.0  0.0    0.0    6656.0   6656.0   22016.0    21566.5   49360.0 46110.7 6608.0 5994.5     76    0.236  215    11.110   11.346
           55.5 2048.0 2048.0  0.0    0.0    6656.0   6656.0   22016.0    21572.2   49360.0 46111.4 6608.0 5994.5     76    0.236  235    12.134   12.370
           56.5 2048.0 2048.0  0.0    0.0    6656.0   6656.0   22016.0    21575.0   49360.0 46111.8 6608.0 5994.5     76    0.236  255    13.137   13.374
           57.4 2048.0 2048.0  0.0    0.0    6656.0   6655.8   22016.0    21571.3   49360.0 46113.0 6608.0 5994.5     76    0.236  274    14.102   14.338
Timestamp        S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT
           58.5 2048.0 2048.0  0.0    0.0    6656.0   6656.0   22016.0    21578.2   49360.0 46114.4 6608.0 5994.5     76    0.236  294    15.112   15.348
           59.5 2048.0 2048.0  0.0    0.0    6656.0   4720.5   22016.0    15587.7   49616.0 46116.6 6608.0 5994.5     76    0.236  309    15.962   16.198
           60.5 2048.0 2048.0  0.0    0.0    6656.0   4790.8   22016.0    15587.7   49616.0 46116.6 6608.0 5994.5     76    0.236  309    15.962   16.198
           61.5 2048.0 2048.0  0.0    0.0    6656.0   4855.1   22016.0    15587.7   49616.0 46116.6 6608.0 5994.5     76    0.236  309    15.962   16.198
           62.5 2048.0 2048.0  0.0    0.0    6656.0   4921.3   22016.0    15587.7   49616.0 46116.6 6608.0 5994.5     76    0.236  309    15.962   16.198

备注：在如上中依据每5行输出一次表头信息，而OU的值分别是：19491.3、20336.9、20549.8、21528.9、21558.3、21578.2，可以看到OU的值呈上升的趋势，根据之前的判断思路程序很有可能出现内存泄露，程序端运行错误确实显示了内存泄露的错误信息，具体为：java.lang.OutOfMemoryError: Java heap space。在上面的数据中也可以看到YGC、FGC都在上升，特别是FGC从2一直上升到了309，变化趋势很大，对应的FGCT它的耗时也是从0.108一直到最后的15.962，而YGC、YGCT有变化趋势但是不是那么很明显。FGCT耗时拉高了整体的GCT的耗时，总耗时最后是16.198，等于FGCT占用了总耗时的98.54%。因此在工作中当程序很有可能内存泄露的时候重点关注OU的值，以及对应的FGC次数、FGCT耗时情况。

本文参与腾讯云自媒体分享计划，分享自微信公众号。

原始发表：2023-09-18 08:11，如有侵权请联系 cloudcommunity@tencent.com 删除

jvm