JVM常用命令整理以及CPU过高排查实战

图论

概述

先概括几个命令：

• jps（JVM Process Status Tool）：显示指定系统内所有的HotSpot虚拟机进程。
• jstat（JVM statistics Monitoring）：用于监视虚拟机运行时状态信息的命令，它可以显示出虚拟机进程中的类装载、内存、垃圾收集、JIT编译等运行数据。
• jmap（JVM Memory Map）：用于生成heap dump文件，如果不使用这个命令，还可以使用-XX:+HeapDumpOnOutOfMemoryError参数来让虚拟机出现OOM的时候·自动生成dump文件。
• jhat（JVM Heap Analysis Tool）：命令是与jmap搭配使用，用来分析jmap生成的dump，jhat内置了一个微型的HTTP/HTML服务器，生成dump的分析结果后，可以在浏览器中查看

命令详解

jps

描述：显示指定系统内所有的HotSpot虚拟机进程。 命令格式：jps [options] [hostid]

实例：在下图可以看到，类的路径，以及启动时配置的JVM参数。

$ jps -l -m
1711535 jdk.jcmd/sun.tools.jps.Jps -l -m
1540987 /var/www/xxx/xxx-service.jar --server.port=8090 --spring.profiles.active=pre --swagger.enable=false --logging.config=./logback-spring.xml --server.tomcat.max-threads=1500 --server.tomcat.max-connections=10000

jstat

描述：用于监视虚拟机运行时状态信息的命令，它可以显示出虚拟机进程中的类装载、内存、垃圾收集、JIT编译等运行数据

命令格式：jstat [option] LVMID [interval] [count]

option参数总览：

实例（-class）

描述：监视类装载、卸载数量、总空间以及耗费的时间

$ jstat -class 15408
Loaded  Bytes  Unloaded  Bytes     Time   
19057 35755.7        0     0.0       9.33

解析：

实例（-compiler）

描述：输出JIT编译过的方法数量耗时等

$ jstat -compiler 15408
 Compiled Failed Invalid   Time   FailedType FailedMethod
  14524      5       0    43.33          1 org/springframework/core/annotation/AnnotationsScanner processMethodHierarchy

解析：

实例（-gc）

描述：垃圾回收堆的行为统计

$ jstat -gc 1540987
 S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT    CGC    CGCT     GCT   
  -      -      -      -       -        -     3932160.0   153600.0  113152.0 111545.7  0.0    0.0        -        -   -          -   -          -    0.000

解析：

如下命令，意思是每隔2000ms输出15408的gc情况，一共输出20次

jstat -gc 15408 2000 20

实例（-gccapacity）

描述：同-gc，不过还会输出Java堆各区域使用到的最大、最小空间。

$ jstat -gccapacity 15408
 NGCMN    NGCMX     NGC     S0C   S1C       EC      OGCMN      OGCMX       OGC         OC       MCMN     MCMX      MC     CCSMN    CCSMX     CCSC    YGC    FGC   CGC 
       -        -        -      -      -        -  3932160.0  3932160.0  3932160.0  3932160.0      0.0 114688.0 113152.0      0.0      0.0      0.0      -     -     -

解析：

实例（-gcutil）

描述：同-gc，不过输出的是已使用空间占总空间的百分比

$ jstat -gcutil 15408
  S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT    CGC   CGCT     GCT   
     -      -      -   3.06  92.21      -      -        -     -        -     -        -    0.000

实例（-gccause）

$ jstat -gccause  15408
  S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT    CGC    CGCT     GCT    LGCC                 GCC                 
     -      -      -   3.06  98.21      -      -        -     -        -     -        -    0.000 Proactive            No GC  

解析：

实例（-gcnew）

描述：统计新生代的行为

$ jstat -gcnew 15408
 S0C      S1C      S0U        S1U  TT  MTT  DSS      EC        EU         YGC     YGCT  
 419392.0 419392.0 52231.8    0.0  6   6    209696.0 3355520.0 1172246.0  4       0.242

解析：

实例（–gcnewcapacity）

描述：新生代与其相应的内存空间的统计

$ jstat -gcnewcapacity 15408
  NGCMN      NGCMX       NGC      S0CMX     S0C     S1CMX     S1C       ECMX        EC        YGC   FGC 
 4194304.0  4194304.0  4194304.0 419392.0 419392.0 419392.0 419392.0  3355520.0  3355520.0     4     0

解析：

实例（–gcold）

描述：统计旧生代的行为

$ jstat -gcold 15408
   PC       PU        OC           OU       YGC    FGC    FGCT     GCT   
10485723.0  12122.7   344345.0     0.0      4      0      0.000    0.242

实例（-gcoldcapacity）

描述：统计旧生代的大小和空间

$ jstat -gcoldcapacity 15408
   OGCMN       OGCMX        OGC         OC         YGC   FGC    FGCT     GCT   
  6291456.0   6291456.0   6291456.0   6291456.0     4     0    0.000    0.242

jmap

描述：

• 用于生成heap dump文件.
• 如果不使用jmap，还可以以使用-XX:+HeapDumpOnOutOfMemoryError参数来让虚拟机出现OOM的时候，自动生成dump文件。
• jmap不仅能生成dump文件，还可以查询finalize执行队列、Java堆和永久代的详细信息，如当前使用率、当前使用的是哪种收集器等。

命令格式： jmap [option] LVMID

实例（-dump）

描述：dump堆到文件,format指定输出格式，live指明是活着的对象,file指定文件名，为了后续可以直接用MAT(Memory Anlysis Tool)打开。

命令格式：-dump:live,format=b,file=<filename> pid

 $ jmap -dump:live,format=b,file=dump.hprof 32390
  Dumping heap to /home/xxx/dump.hprof ...
  Heap dump file created

实例（-finalizerinfo）

描述：打印等待回收对象的信息

$ jmap -finalizerinfo 32390
  Attaching to process ID 32390, please wait...
  Debugger attached successfully.
  Server compiler detected.
  JVM version is 24.71-b01
  Number of objects pending for finalization: 0

实例（-heap）

描述：打印heap的概要信息，GC使用的算法，heap的配置及wise heap的使用情况,可以用此来判断内存目前的使用情况以及垃圾回收情况。

$ jmap -heap 32390
  Attaching to process ID 32390, please wait...
  Debugger attached successfully.
  Server compiler detected.
  JVM version is 24.71-b01  

  using thread-local object allocation.
  Parallel GC with 4 thread(s)//GC 方式  

  Heap Configuration: //堆内存初始化配置
     MinHeapFreeRatio = 0 //对应jvm启动参数-XX:MinHeapFreeRatio设置JVM堆最小空闲比率(default 40)
     MaxHeapFreeRatio = 100 //对应jvm启动参数 -XX:MaxHeapFreeRatio设置JVM堆最大空闲比率(default 70)
     MaxHeapSize      = 2082471936 (1986.0MB) //对应jvm启动参数-XX:MaxHeapSize=设置JVM堆的最大大小
     NewSize          = 1310720 (1.25MB)//对应jvm启动参数-XX:NewSize=设置JVM堆的‘新生代’的默认大小
     MaxNewSize       = 17592186044415 MB//对应jvm启动参数-XX:MaxNewSize=设置JVM堆的‘新生代’的最大大小
     OldSize          = 5439488 (5.1875MB)//对应jvm启动参数-XX:OldSize=<value>:设置JVM堆的‘老生代’的大小
     NewRatio         = 2 //对应jvm启动参数-XX:NewRatio=:‘新生代’和‘老生代’的大小比率
     SurvivorRatio    = 8 //对应jvm启动参数-XX:SurvivorRatio=设置年轻代中Eden区与Survivor区的大小比值 
     PermSize         = 21757952 (20.75MB)  //对应jvm启动参数-XX:PermSize=<value>:设置JVM堆的‘永生代’的初始大小
     MaxPermSize      = 85983232 (82.0MB)//对应jvm启动参数-XX:MaxPermSize=<value>:设置JVM堆的‘永生代’的最大大小
     G1HeapRegionSize = 0 (0.0MB)  

  Heap Usage://堆内存使用情况
  PS Young Generation
  Eden Space://Eden区内存分布
     capacity = 33030156 (31.5MB)//Eden区总容量
     used     = 1524042 (1.4534378051757812MB)  //Eden区已使用
     free     = 315061046 (30.04656219482422MB)  //Eden区剩余容量
     4.614088270399305% used //Eden区使用比率
  From Space:  //其中一个Survivor区的内存分布
     capacity = 5242880 (5.0MB)
     used     = 0 (0.0MB)
     free     = 5242880 (5.0MB)
     0.0% used
  To Space:  //另一个Survivor区的内存分布
     capacity = 5242880 (5.0MB)
     used     = 0 (0.0MB)
     free     = 5242880 (5.0MB)
     0.0% used
  PS Old Generation //当前的Old区内存分布
     capacity = 86507520 (82.5MB)
     used     = 0 (0.0MB)
     free     = 86507520 (82.5MB)
     0.0% used
  PS Perm Generation//当前的 “永生代” 内存分布
     capacity = 22020096 (21.0MB)
     used     = 2496528 (2.3808746337890625MB)
     free     = 19523568 (18.619125366210938MB)
     11.337498256138392% used  

  670 interned Strings occupying 43720 bytes.

实例（-histo）

描述：打印堆的对象统计，包括对象数、内存大小等等 （因为在dump:live前会进行full gc，如果带上live则只统计活对象，因此不加live的堆大小要大于加live堆的大小 ）

$ jmap -histo:live 32390 | more
 num     #instances         #bytes  class name
----------------------------------------------
   1:         83616       12012249  <constMethodKlass>
   2:         23868       11450288  [B
   3:         83618       10716066  <methodKlass>
   4:         76288       10412128  [C
   5:          8226        9021178  <constantPoolKlass>
   6:          8222        5830258  <instanceKlassKlass>
   7:          7036        5156488  <constantPoolCacheKlass>
   8:         736272        1767048  java.lang.String
   9:          2262        1348848  <methodDataKlass>
  10:          8858         849296  java.lang.Class

B byte C char D double F float I int J long Z boolean[ 数组，如[I表示int[] [L+类名 其他对象

实例（-permstat）

描述：打印Java堆内存的永久保存区域的类加载器的智能统计信息

$ jmap -permstat 32390
  Attaching to process ID 32390, please wait...
  Debugger attached successfully.
  Server compiler detected.
  JVM version is 24.71-b01
  finding class loader instances ..done.
  computing per loader stat ..done.
  please wait.. computing liveness.liveness analysis may be inaccurate ...
  
  class_loader            classes bytes   parent_loader           alive?  type  
  <bootstrap>             3111    18154296          null          live    <internal>
  0x0000000600905cf8      1       1888    0x0000000600087f08      dead    sun/reflect/DelegatingClassLoader@0x00000007800500a0
  0x00000006008fcb48      1       1888    0x0000000600087f08      dead    sun/reflect/DelegatingClassLoader@0x00000007800500a0
  0x00000006016db798      0       0       0x00000006008d3fc0      dead    java/util/ResourceBundle$RBClassLoader@0x0000000780626ec0
  0x00000006008d6810      1       3056      null          dead    sun/reflect/DelegatingClassLoader@0x00000007800500a0

jhat

描述：命令是与jmap搭配使用，用来分析jmap生成的dump，jhat内置了一个微型的HTTP/HTML服务器，生成dump的分析结果后，可以在浏览器中查看。

jhat [dumpfile]

实例：

$ jhat -J-Xmx512m dump.hprof
  eading from dump.hprof...
  Dump file created Fri Mar 11 17:13:42 CST 2016
  Snapshot read, resolving...
  Resolving 271678 objects...
  Chasing references, expect 54 dots......................................................
  Eliminating duplicate references......................................................
  Snapshot resolved.
  Started HTTP server on port 7000
  Server is ready.

中间的-J-Xmx512m是在dump快照很大的情况下分配512M内存去启动HTTP服务器，运行完之后就可在浏览器打开Http://localhost:7000进行快照分析

jstack

描述：jstack用于生成java虚拟机当前时刻的线程快照。线程快照是当前java虚拟机内每一条线程正在执行的方法堆栈的集合，生成线程快照的主要目的是定位线程出现长时间停顿的原因，如线程间死锁、死循环、请求外部资源导致的长时间等待等。 线程出现停顿的时候通过jstack来查看各个线程的调用堆栈，就可以知道没有响应的线程到底在后台做什么事情，或者等待什么资源。 如果java程序崩溃生成core文件，jstack工具可以用来获得core文件的java stack和native stack的信息，从而可以轻松地知道java程序是如何崩溃和在程序何处发生问题。另外，jstack工具还可以附属到正在运行的java程序中，看到当时运行的java程序的java stack和native stack的信息, 如果现在运行的java程序呈现hung的状态，jstack是非常有用的。

命令：jstack [option] LVMID

$ jstack -l 11494|more
2016-07-28 13:40:04
Full thread dump Java HotSpot(TM) 64-Bit Server VM (24.71-b01 mixed mode):

"Attach Listener" daemon prio=10 tid=0x00007febb0002000 nid=0x6b6f waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
        - None

"http-bio-8005-exec-2" daemon prio=10 tid=0x00007feb94028000 nid=0x7b8c waiting on condition [0x00007fea8f56e000]
   java.lang.Thread.State: WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000000cae09b80> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
        at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:104)
        at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:32)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
        at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:
        - None
      .....

jinfo

描述：是实时查看和调整虚拟机运行参数。

命令：jinfo [option] [args] LVMID

实战cpu过高线程堆栈定位

定位进程

登录服务器，执行top命令，查看CPU占用情况：

 $top
  PID  USER      PR   NI  VIRT   RES    SHR   S  %CPU   %MEM   TIME+  COMMAND
  66529 root     20   0  4289m   874m  13312  S  150.0   10.9   10:39.73  java

top命令查看所有进程占系统CPU的排序，它是Linux下常用的性能分析工具，能够实时显示系统中各个进程的资源占用状况，类似于Windows的任务管理器,如果要排序 shift+p 快捷键

标题符具体代表含义：

PID — 进程id 
USER — 进程所有者 
PR — 进程优先级 
NI — nice值。负值表示高优先级，正值表示低优先级 
VIRT — 进程使用的虚拟内存总量，单位kb。VIRT=SWAP+RES RES — 进程使用的、未被换出的物理内存大小，单位kb。
RES=CODE+DATA 
SHR — 共享内存大小，单位kb 
S — 进程状态。D=不可中断的睡眠状态 R=运行 S=睡眠 T=跟踪/停止 Z=僵尸进程 
%CPU — 上次更新到现在的CPU时间占用百分比 
%MEM — 进程使用的物理内存百分比 TIME+ — 进程使用的CPU时间总计，单位1/100秒 
COMMAND — 进程名称（命令名/命令行）

通过执行top命令，我看到，进程ID为66529的Java进程的CPU占用率达到了150%，基本可以定位到是我们的Java应用导致整个服务器的CPU占用率飙升。

定位线程

当然，Java是单进程多线程的，那么，接下来我就看了这个PID=66529的这个Java进程中的各个线程的CPU使用情况，同样是用top命令：

$top -Hp 66529
   PID  USER     PR   NI  VIRT  RES     SHR   S  %CPU   %MEM    TIME+  COMMAND
  6680 root     20   0   4289m 874m   13312  S  16.2   10.9    3:02.96   java

通过执行top -Hp 66529命令，我发现，在66529这个进程中，ID为6680的线程占用CPU最高。

定位代码

通过top命令，我定位到了导致CPU使用率较高的具体线程， 接下来就要看一下具体是哪一行代码存在问题。

首先，我把6680这个线程转成16进制：

$printf %x 6680 
1a18

接下来，根据该16进制值去打印的堆栈日志内查询，查看该线程所驻留的方法位置。并通过jstack命令，查看栈信息

$jstack 66529 |grep -A 200 1a18
"System Clock" #28 daemon prio=5 os_prio=0 tid=0x00007efc19e8e800 nid=0xae24 waiting on condition [0x00007efbe0d91000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
    at java.lang.Thread.sleep(Native Method)
    at java.lang.Thread.sleep(Thread.java:340)
    at java.util.concurrentC.TimeUnit.sleep(TimeUnit.java:386)
    at com.*.order.Controller.ManagerController.detail(OrderController.java:37)  //业务代码阻塞点

通过以上代码，我们可以清楚的看到，ManagerController.java的第37行是有可能存在问题的。

然后我找到项目中ManagerController.java的第37行。

总结

以上就是本次问题排查的整个过程。主要用到的有:top，printf，jstack等指令。

1. 使用top指令查看当前占用CPU较高的进程PID；
2. 查看当前进程消耗资源的线程PID：    top -Hp PID
3. 将线程PID转为16进制，根据该16进制值去打印的堆栈日志内查询，查看该线程所驻留的方法位置。
4. 通过jstack命令，查看栈信息，这步基本上已经能够定位大多数问题了。