上一篇:编译OpenJDK 性能监控与调优实战 下一篇:线上问题排查经验总结

2675 2019-12-20 2020-06-25

前言：当服务端出现不稳定或异常情况的时候，本篇可能能帮上不小的忙。

一、基本命令

给一个系统定位问题的时候，知识、经验是关键基础，数据是依据，工具是运用知识处理数据的手段。我们先来看下JDK提供的命令工具。

1、jps

jps（JVM Process Status Tool），显示指定系统内所有的虚拟机进程。一般运行jps -l即可满足大部分需求。

jps [ options ] [ hostid ]

[root@izwz93pwxi9qhdp46ajo0qz ~]# jps
13269 jar
3132 Jps

[root@izwz93pwxi9qhdp46ajo0qz ~]# jps -l
13269 ROOT.jar
3173 sun.tools.jps.Jps

[root@izwz93pwxi9qhdp46ajo0qz ~]# jps -v
3204 Jps -Dapplication.home=/usr/lib/jvm/java-1.8.0-openjdk-1.8.0.201.b09-2.el7_6.x86_64 -Xms8m
13269 jar

这个查出PID与系统进程PID是一致的，因此可以直接kill pid。下面介绍的命令也需要通过jps率先查出java进程id，然后进行其他的操作。

这里介绍一个实用的linux命令：tee -- read from standard input and write to standard output and files。用法如下

# 将当前屏幕输出转存一份进指定文件
[root@izwz93pwxi9qhdp46ajo0qz ~]# jps | tee test.txt
7652 Jps
5541 jar

2、jstat

jstat（JVM Statistics Monitoring Tool）是用于监视虚拟机各种运行状态信息的命令行工具。它可以显示本地或远程虚拟机进程中的类加载、内存、垃圾收集、JIT编译等运行数据。在没有GUI图形界面的服务器上，它将是运行期间定位虚拟机性能问题的首选工具。

选项作用
-class监视类装载、卸载数量、总空间以及装载所耗费的时间
-gc监视Java堆状况，包括Eden区、两个Survivor区、老年代、永久代等的容量、已用空间、GC时间合计等信息
-gccapacity监视内容与-gc基本相同，但输出主要关注Java堆各个区域使用到的最大、最小空间
-gcutil监视内容与-gc基本相同，但输出主要关注已使用空间占总空间的百分比
-gccause与-gcutil功能一样，但是会额外输出导致上一次GC产生的原因
-gcnew监视新生代GC状况。-gcnewcapacity，主要关注使用到的最大、最小空间
-gcold监视老年代GC状况。-gcoldcapacity，主要关注使用到的最大、最小空间
-gcpermcapacity输出永久代使用到的最大、最小空间
-compiler输出JIT编译器编译过的方法、耗时情况
-printcompilation输出已经被JIT编译的方法

以下是实例演示

# 命令格式 vmid代表虚拟机进程id，interval和count代表查询间隔和次数（默认1）
jstat -<option> [-t] [-h<lines>] <vmid> [<interval> [<count>]]

# 用idea启动了tomcat
hk@hk-LPC:/usr/share/man$ jps -l
8357 sun.tools.jps.Jps
6554 com.intellij.idea.Main
8030 org.apache.catalina.startup.Bootstrap
8015 org.jetbrains.jps.cmdline.Launcher

hk@hk-LPC:/usr/share/man$ jstat -class 8030
Loaded  Bytes  Unloaded  Bytes     Time   
  2579  4974.3        0     0.0       2.85
  
# s0c = survivor0 capacity, s0u = survivor0 used, 7680k = 7.5M
# EC = Eden capacity, EU = Eden Used, OU = Old Used, 48640k = 47.5M, 128512k = 125.5M
# MC = Method/Perm Capacity, 16256k = 15.875M, 15566.4k = 15.2M 
# CCSC = Compress Class Capacity
# YGC = 年轻代垃圾回收次数
# YGCT = 年轻代垃圾回收消耗时间
# FGC = 老年代垃圾回收次数(major GC和full GC通常是等价的，因为major GC通常由minor GC触发)
# FGCT = 老年代垃圾回收消耗时间
# GCT = 垃圾回收消耗总时间
hk@hk-LPC:/usr/share/man$ jstat -gc 8030
 S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT   
7680.0 7680.0 6175.5  0.0   48640.0   9598.1   128512.0     96.0    16256.0 15566.4 1920.0 1695.6      2    0.018   0      0.000    0.018

3、jinfo

jinfo（Configuration Info for Java），显示/调整虚拟机配置信息。

选项作用
no option输出全部的参数和系统属性
-flag name输出对应名称的参数
-flag [+|-]name开启或者关闭对应名称的参数（如果可以）
-flag name=value设定对应名称的参数（如果可以）
-flags输出全部的参数
-sysprops输出系统属性

以下是实例演示

# 命令格式
jinfo [option] <pid>

# 某些命令可能并不能正确执行
[root@izwz93pwxi9qhdp46ajo0qz ~]# jinfo -flags 13269
Attaching to process ID 13269, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.201-b09
Non-default VM flags: -XX:CICompilerCount=2 -XX:InitialHeapSize=31457280 -XX:MaxHeapSize=482344960 -XX:MaxNewSize=160759808 -XX:MinHeapDeltaBytes=196608 -XX:NewSize=10485760 -XX:OldSize=20971520 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops 
Command line:  

[root@izwz93pwxi9qhdp46ajo0qz ~]# jinfo -flag NewSize 13269
-XX:NewSize=10485760

4、jmap

jmap（Memory Map for Java），生成虚拟机的内存转储快照（headdump文件）。

选项作用
-dump生成Java堆转储快照。格式为：-dump:[live, ]format=b, file=<filename>，其中live子参数说明是否只dump出存活的对象
-finalizerinfo显示在F-Queue中等待Finalizer线程执行finalize方法的对象
-heap显示Java堆详细信息，如使用哪种回收器、参数配置、分代状况等
-histo显示堆中对象统计信息，包括类、实例数量、合计数量
-permstat以ClassLoader为统计口径显示永久代内存状态
-F当虚拟机进程对-dump选项没有响应时，可使用这个选项强制生成dump快照

以下是实例演示

# 命令格式
jmap [option] <pid>

hk@hk-LPC:~$ jmap -dump:live,format=b,file=dump.bin 11086
Dumping heap to /home/hk/dump.bin ...
Heap dump file created


[root@izwz93pwxi9qhdp46ajo0qz ~]# jmap -heap 13269
Attaching to process ID 13269, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.201-b09

using thread-local object allocation.
Mark Sweep Compact GC

Heap Configuration:
   MinHeapFreeRatio         = 40
   MaxHeapFreeRatio         = 70
   MaxHeapSize              = 482344960 (460.0MB)
   NewSize                  = 10485760 (10.0MB)
   MaxNewSize               = 160759808 (153.3125MB)
   OldSize                  = 20971520 (20.0MB)
   NewRatio                 = 2
   SurvivorRatio            = 8
   MetaspaceSize            = 21807104 (20.796875MB)
   CompressedClassSpaceSize = 1073741824 (1024.0MB)
   MaxMetaspaceSize         = 17592186044415 MB
   G1HeapRegionSize         = 0 (0.0MB)

5、jhat

jhat（Java Heap Analysis Tool），用于分析生成的heapdump文件。它会建立一个HTTP/HTML服务器，让用户可以在浏览器上查看分析结果。由于分析是一项比较耗时而且消耗硬件的过程，一般做法是将服务器dump文件复制下来并采用第三方专业工具来分析。

# 大致了解即可
hk@hk-LPC:~$ jhat dump.bin 
Reading from dump.bin...
Dump file created Thu Dec 12 10:11:30 CST 2019
Snapshot read, resolving...
Resolving 128505 objects...
Chasing references, expect 25 dots.........................
Eliminating duplicate references.........................
Snapshot resolved.
Started HTTP server on port 7000
Server is ready.

6、jstack*

jstack（Stack Trace for Java），用于生成虚拟机当前时刻的线程快照（一般称为threaddump或javacore文件）。线程快照就是当前虚拟机每一条线程正在执行的方法堆栈的集合，用来定位线程出现长时间停顿的原因。

选项作用
-F当正常输出的请求不被响应时，强制输出线程堆栈
-l除堆栈外，显示关于锁的附加信息
-m如果调用本地方法的话，可以显示C/C++的堆栈

实例演示如下

# 命令格式
jstack [option] vmid

hk@hk-LPC:~$ jstack 11086
2019-12-12 10:36:14
Full thread dump OpenJDK 64-Bit Server VM (25.181-b13 mixed mode):

"Attach Listener" #60 daemon prio=9 os_prio=0 tid=0x00007f7b10001000 nid=0x2f14 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"ajp-nio-8009-AsyncTimeout" #52 daemon prio=5 os_prio=0 tid=0x00007f7b50625800 nid=0x2b9a waiting on condition [0x00007f7b2e6e5000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
	at java.lang.Thread.sleep(Native Method)
	at org.apache.coyote.AbstractProtocol$AsyncTimeout.run(AbstractProtocol.java:1154)
	at java.lang.Thread.run(Thread.java:748)

"ajp-nio-8009-Acceptor-0" #51 daemon prio=5 os_prio=0 tid=0x00007f7b50623800 nid=0x2b99 runnable [0x00007f7b2e7e6000]
   java.lang.Thread.State: RUNNABLE
	at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method)
	at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422)
	at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250)
	- locked <0x00000007060260f8> (a java.lang.Object)
	at org.apache.tomcat.util.net.NioEndpoint$Acceptor.run(NioEndpoint.java:482)
	at java.lang.Thread.run(Thread.java:748)
# 省略其他

当定位线上问题时，这个命令应该率先被使用，这样我们可以清楚的知道问题大致发生在哪个地方以及大致原因。

二、可视化工具-jconsole

主要是以JConsole（jconsole）和VisualVM（jvisualvm）为主，由于jconsole是各版本JDK都会有的，而其他的却不一定有，这里以jconsole为例进行演示。

1、远程连接jvm

需要加入以下参数

# 如果是以tomcat为载体，则需要在tomcat的catalina.sh中加入
# 如果是以java -jar启动，则需要在后面补上这些参数
-Djava.rmi.server.hostname=120.79.20.49
-Dcom.sun.management.jmxremote
-Dcom.sun.management.jmxremote.port=8076
-Dcom.sun.management.jmxremote.rmi.port=8077 
-Dcom.sun.management.jmxremote.ssl=false
-Dcom.sun.management.jmxremote.authenticate=false

# 下面是一个例子
java -jar -Djava.rmi.server.hostname=120.79.20.49 -Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.port=7076 -Dcom.sun.management.jmxremote.rmi.port=7077 -Dcom.sun.management.jmxremote.ssl=false -Dcom.sun.management.jmxremote.authenticate=false ROOT.jar --spring.profiles.active=local

2、查看当前垃圾收集器

# 本地环境，使用Parrallel Scavenge + Parallel Old收集器组合，注重吞吐量以及对CPU资源敏感
hk@hk-LPC:/usr/lib/jvm/java-8-openjdk-amd64/bin$ java -XX:+PrintCommandLineFlags -version
-XX:InitialHeapSize=195128768 -XX:MaxHeapSize=3122060288 -XX:+PrintCommandLineFlags -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseParallelGC 
openjdk version "1.8.0_181"
OpenJDK Runtime Environment (build 1.8.0_181-8u181-b13-2~deb9u1-b13)
OpenJDK 64-Bit Server VM (build 25.181-b13, mixed mode)

# 远程服务器环境
# 上面命令绝大部分下可以直接查看到所使用的，但不排除例外，此时可以采用下面命令
# java -XX:+PrintFlagsFinal -version | grep Use | grep true
[root@izwz93pwxi9qhdp46ajo0qz xiaokui]# java -XX:+PrintCommandLineFlags -version
-XX:InitialHeapSize=30113344 -XX:MaxHeapSize=481813504 -XX:+PrintCommandLineFlags -XX:+UseCompressedClassPointers -XX:+UseCompressedOops 
openjdk version "1.8.0_201"
OpenJDK Runtime Environment (build 1.8.0_201-b09)
OpenJDK 64-Bit Server VM (build 25.201-b09, mixed mode)

其他关于图形界面的操作就不在多做介绍了。

三、理论调优

案例均精裁剪自周志明 - 《深入理解Java虚拟机》。

1、Java堆过大

具体案例如下：Java堆过大，且产生了许多大对象，这些大对象大部分直接进入了老年代，避过了Minor GC。长时间后导致Java堆内存不足，触发Major GC，一次Major GC可高达10秒。对外表现为后台服务器卡死。

解决思路（抛开代码层面）：

  1. 如果不嫌硬件浪费，可以直接缩小Java堆的大小，外加提高对象直接进入老年代的门槛，这样可以保证Minor GC能够回收一部分大对象，Major GC次数减少且回收对象数量/大小降低。
  2. 如果不想浪费硬件资源，就采用集群部署 + 负载均衡，单个机器开多个虚拟机进程，每个进程大致优化思路同上。
  3. 抛开具体的业务场景和最新的垃圾收集器（假设限定JDK8），如果后台需要长时间数据运算，则可以采用注重吞吐量（垃圾收集时间占总时间比例）的Parallel Scavenge + Parallel Old组合（+XX:UseParallelGC）。如果后台需要快速响应，追求低延迟，那么注重低延迟的ParNew + CMS + Serial Old（作为CMS收集器出现Concurrent Mode Failure失败后的后备收集器使用）组合是个不错的选择（+XX:UseConcMarkSweepGC）。
  4. 如果JDK想体验最新垃圾收集器的研究成果，那么G1（目标是替代CMS）、Shenandoah、ZGC是个不错的选择。

2、代码导致的GC问题

一般来说可能由以下几种情况导致：

  1. 堆内存过小，堆内存快速填满，GC过于频繁，表现为系统吞吐量降低。堆内存过大，长时间后堆内存不足，单次GC耗时较长，表现为系统假死。
  2. 非堆内存异常，这时也可能抛出java.lang.OutOfMemoryError。可能出问题原的区域有：直接内存、线程堆栈、Socket缓存区、JNI代码。
  3. 内部线程可能导致的一系列问题，有待完善。

3、打印GC日志

下面是一些常用的打印GC参数：

选项说明
-XX:+PrintGCTimeStamps打印GC停顿时间
-XX:+PrintGCDetails打印GC详细信息
-verbose：gc打印GC信息，输出内容已被前一个参数包括
-Xloggc：gc.log将GC日志转储至文件

四、调优实战一

有待完善。

总访问次数: 427次, 一般般帅 创建于 2019-12-20, 最后更新于 2020-06-25

进大厂！ 欢迎关注微信公众号，第一时间掌握最新动态！