JVM 故障调查教程

JVM 故障调查教程

本文主要针对java应用程序占用CPU资源过高问题进行的调查分析以及总结,CPU占用过高的主要原因是jvm的内存不足引用的GC疯狂回收空间,导致GC的回收线程把CPU资源用尽。内存不足的原因主要有。1.业务预估不合理导致请求处理暴增。2程序代码逻辑问题导致(死循环,内存异常等)。下面通过代码示例分析证明问题的原因,以及解决思路,提供详细的解决方法,工具介绍,经验介绍等。希望本文为读者解决项目中JVM相关问题提供帮助。

java 程序 cpu100%原因排查

模拟cpu占用100%代码示例

public class App {
public static void main(String[] args) throws InterruptedException {
int num = 20;
Thread[] threads = new Thread[num];
for (int i = 0; i < num; i++) {
threads[i] = new Thread(new PressureRunner());
threads[i].start();

}


}

public static class PressureRunner implements Runnable {
@Override
public void run() {
while (true) {

}
}
}

}

编译:javac App.java

执行:java App.java

第一步:确认cpu占用情况及进程ID

top

 

第二步: 显示进程下的线程占用CPU情况

top -H -p pid

找到占用CPU最高的线程

 

 

 

echo "obase=16;9758" | bc

线程id结果是

261E

 

第三步: 导出java进程的线程栈

jstack pid > pid.tdump

执行

jstack 9745 > 9745.tdump

#
查看tdump
cat 9745.tdump

代码定位

 

小结

本例子是针对业务程序引用的CPU100%的分析方法,还可能会有,并发io读写或网络读取而引起的内存资源用完引起的CPU占用100%的情况。也适用此方法来定位问题代码。一般这种情况如果计算任务释放或io读写或网络资源释放,cpu占用情况自动会下降,不会导致jvm奔溃。 还有另外一种引起的CPU占用100%情况,就是JVM空间不够引起的GC频繁回收。GC是使用多线程回收的。导致大量线程疯狂回收最终CPU资源占满。而且是不会释放的,CPU一直100%。解决办法就要调整jvm的增加内存配置。请看下节。

jvm 内存空间不足引起的CPU100% 原因排除

代码

package com.hdk.demofullgc;

import java.math.BigDecimal;
import java.util.ArrayList;
import java.util.List;
import java.util.concurrent.ScheduledThreadPoolExecutor;
import java.util.concurrent.ThreadPoolExecutor;
import java.util.concurrent.TimeUnit;

/**
* VM
参数: -XX:+PrintGC -Xms50M -Xmx50M
* GC
调优---生产服务器推荐开启(默认是关闭的)
* -XX:+HeapDumpOnOutOfMemoryError
*/

public class FullGCProblem {
//
线程池

private static ScheduledThreadPoolExecutor executor = new ScheduledThreadPoolExecutor(50,
new ThreadPoolExecutor.DiscardOldestPolicy());

public static void main(String[] args) throws Exception {
//50
个线程
executor.setMaximumPoolSize(50);
while (true){
calc();
Thread.sleep(100);
}
}

/**
*
多线程执行任务计算
*/
private static void calc(){
List<UserInfo> taskList = getAllCardInfo();
taskList.forEach(userInfo -> {
executor.scheduleWithFixedDelay(() -> {
userInfo.user();
}, 2, 3, TimeUnit.SECONDS);
});
}

/**
*
模拟从数据库读取数据,返回
* @return
*/
private static List<UserInfo> getAllCardInfo(){
List<UserInfo> taskList = new ArrayList<>();
for (int i = 0; i < 100; i++) {
UserInfo userInfo = new UserInfo();
taskList.add(userInfo);
}
return taskList;
}
private static class UserInfo {
String name = "hdk";
int age = 18;
BigDecimal money = new BigDecimal(999999.99);

public void user() {
//
}
}
}

 

运行代码:

java -cp demofullgc.jar -XX:+PrintGC -Xms50M -Xmx50M com.hdk.demofullgc.FullGCProblem 结果

GC 日志详解

 

GC 常用参数

首先JVM内存限制于实际的最大物理内存,假设物理内存无限大的话,JVM内存的最大值跟操作系统有很大的关系。简单的说就32位处理器虽然可控内存空间有4GB,但是具体的操作系统会给一个限制, 这个限制一般是2GB-3GB(一般来说Windows系统下为1.5G-2G,Linux系统下为2G-3G),而64bit以上的处理器就不会有限制了

运行:top 查看CPU占用情况及pid

 

Jstat

代码中有打印 GC 参数,生产上可以使用这个 jstat –gc 来统计

 

 

分析:jstat-gc 5953 2500 100 需要每 250 毫秒查询一次进程 5953 垃圾收集状况,一共查询 100 次。

随着GCT和GCT逐渐变大,FGC(老年代垃圾回收次数)频率也越来越高。1,1,2,2,3,3,5,6,245。

最后抛出outofmemoryerror异常。CPU占用100%

S0C:第一个幸存区的大小

S1C:第二个幸存区的大小

S0U:第一个幸存区的使用大小

S1U:第二个幸存区的使用大小

EC:伊甸园区的大小

EU:伊甸园区的使用大小

OC:老年代大小

OU:老年代使用大小

MC:方法区大小

MU:方法区使用大小

CCSC:压缩类空间大小

CCSU:压缩类空间使用大小

YGC:年轻代垃圾回收次数

YGCT:年轻代垃圾回收消耗时间

FGC:老年代垃圾回收次数

FGCT:老年代垃圾回收消耗时间

GCT:垃圾回收消耗总时间

jmap

打印出jvm中全部对象的分布情况

jmap -histo 6901 | head -20

 

分析:ScheduledThreadPoolExecutor$ScheduledFutureTask,UserInfo等对象都高达159956个。主要是类FullGCProblem里的线程池引起的。

小结

线程池中的任务数永远多于线程数,初始50个核心线程数会一直被占满,那么任务会一直进入阻塞队列,阻塞队列任务会不断地增加,每个队列元素都引用一个对象。导致内存不断的增加,而executor又是一个GCroots,所以堆中的对象空间无法回收。导致jvm内存耗尽,GC在不停地并发回收,CPU资源被占满。

内存泄露导致回收率低

内存泄露,引用内存回收率低,而导出内存的可用空间减少,导致内存快速被占满垃圾回收器不断FULLGC。最终CPU100%。

代码

//模拟栈的容器
public class Stack {

public Object[] elements;//
数组来保存

public int getSize() {
return size;
}

private int size =0;
private static final int Cap = 300000;

public Stack() {
elements = new Object[Cap];
}

public void push(Object e){ //
入栈
elements[size] = e;
size++;
}
public Object pop(){ //
出栈
    size = size -1;
Object o = elements[size];
//elements[size] =null; //
不用---引用干掉,GC可以正常回收次对象
return o;
}
}

public class UseStack {
static Stack stack = new Stack(); //new
一个栈

public static void main(String[] args) throws Exception {


for (int i = 0; i < 100000; i++) {//10
万的数据入栈
stack.push(new String[1 * 1000]); //
入栈
}
for (int i = 0; i < 100000; i++) {//10
万的数据出栈
Object o1 = stack.pop(); //
出栈
}

ArrayList al = new ArrayList();
for (int i = 0; i < 100000; i++) {
al.add(new String[1 * 1000]);
}

Thread.sleep(Integer.MAX_VALUE);

}


}

配置 -XX:+HeapDumpOnOutOfMemoryError -Xms500M -Xmx500M

启动程序: java -cp demofullgcuse.jar -XX:+HeapDumpOnOutOfMemoryError -XX:+PrintGC -Xms500M -Xmx500M com.hdk.demofullgc.UseStack 配置说明: -Xms500M -Xmx500M 配置刚好内存10万数据大小 -XX:-HeapDumpOnOutOfMemoryError 默认关闭,建议开启,在 java.lang.OutOfMemoryError 异常出现时,输出一个 dump 文件,记录当时的堆内存快照。

 

内存不够产生了oom。生成dump 文件java_pid8839.hprof。

mat分析工具

MAT 工具是基于 Eclipse 平台开发的,本身是一个 Java 程序,是一款很好的内存分析工具。

 

分析结果:同一个种类型实例,83%400M的内存。无法释放。代码定位Stack类代码中。大量的对应无法释放导致GC无法回收造成oom。解决方法:在Stack中的出栈方法pop中添加 elements[size] =null;告诉GC出栈的对象可以回收。问题即可解决。

 

总结:

在 JVM 出现性能问题的时候。(表现上是 CPU100%,内存一直占用)

CPU占用过高常见原因

 

CPU占用高的解决策略

命令行工具

JPS

列出当前机器上正在运行的虚拟机进程,JPS 从操作系统的临时目录上去找(所以有一些信息可能显示不全)

-q :仅仅显示进程,

-m:输出主函数传入的参数. 下的 hello 就是在执行程序时从命令行输入的参数

-l: 输出应用程序主类完整 package 名称或 jar 完整名称. -v: 列出 jvm 参数, -Xms20m -Xmx50m

jstat

是用于监视虚拟机各种运行状态信息的命令行工具。它可以显示本地或者远程虚拟机进程中的类装载、内存、垃圾收集、JIT 编译等运行数据,在没有 GUI图形界面,只提供了纯文本控制台环境的服务器上,它将是运行期定位虚拟机性能问题的首选工具。 常用参数: -class (类加载器)

-compiler (JIT)

-gc (GC 堆状态)

-gccapacity (各区大小)

-gccause (最近一次 GC 统计和原因)

-gcnew (新区统计)

-gcnewcapacity (新区大小)

-gcold (老区统计)

-gcoldcapacity (老区大小)

-gcpermcapacity (永久区大小)

-gcutil (GC 统计汇总)

-printcompilation (HotSpot 编译统计)

比如说:我们要统计 GC,就是垃圾回收,那么只需要使用这样的命令。 jstat-gc 13616 (这个 13616 是 JVM 的进程,通过 JPS 命令得到),这样统计出来是的实时值。 所以很多情况下,我们为了看变化值的,可以这么玩。

jinfo

查看和修改虚拟机的参数 jinfo –sysprops 可以查看由 System.getProperties()取得的参数 jinfo –flag 未被显式指定的参数的系统默认值 jinfo –flags(注意 s)显示虚拟机的参数

VM 参数分类

JVM 的命令行参数参考:https://docs.oracle.com/javase/8/docs/technotes/tools/unix/java.html

jmap

用于生成堆转储快照(一般称为 heapdump 或 dump 文件)。jmap 的作用并不仅仅是为了获取 dump 文件,它还可以查询 finalize 执行队列、Java 堆和永 久代的详细信息,如空间使用率、当前用的是哪种收集器等。和 jinfo 命令一样,jmap 有不少功能在 Windows 平台下都是受限的,除了生成 dump 文件的 -dump 选项和用于查看每个类的实例、空间占用统计的-histo 选项在所有操作系统都提供之外,其余选项都只能在 Linux/Solaris 下使用。

-heap 打印 heap 的概要信息

jmap –heap

Heap Configuration: ##堆配置情况,也就是 JVM 参数配置的结果[平常说的 tomcat 配置 JVM 参数,就是在配置这些]

MinHeapFreeRatio = 40 ##最小堆使用比例

MaxHeapFreeRatio = 70 ##最大堆可用比例

MaxHeapSize = 2147483648 (2048.0MB) ##最大堆空间大小

NewSize = 268435456 (256.0MB) ##新生代分配大小

MaxNewSize = 268435456 (256.0MB) ##最大可新生代分配大小

OldSize = 5439488 (5.1875MB) ##老年代大小

NewRatio = 2 ##新生代比例

SurvivorRatio = 8 ##新生代与 suvivor 的比例

PermSize = 134217728 (128.0MB) ##perm 区 永久代大小

MaxPermSize = 134217728 (128.0MB) ##最大可分配 perm 区 也就是永久代大小

Heap Usage: ##堆使用情况【堆内存实际的使用情况】

New Generation (Eden + 1 Survivor Space): ##新生代(伊甸区 Eden 区 + 幸存区 survior(1+2)空间)

capacity = 241631232 (230.4375MB) ##伊甸区容量

used = 77776272 (74.17323303222656MB) ##已经使用大小

free = 163854960 (156.26426696777344MB) ##剩余容量

32.188004570534986% used ##使用比例

Eden Space: ##伊甸区

capacity = 214827008 (204.875MB) ##伊甸区容量

used = 74442288 (70.99369812011719MB) ##伊甸区使用

free = 140384720 (133.8813018798828MB) ##伊甸区当前剩余容量

34.65220164496263% used ##伊甸区使用情况

From Space: ##survior1 区

capacity = 26804224 (25.5625MB) ##survior1 区容量

used = 3333984 (3.179534912109375MB) ##surviror1 区已使用情

free = 23470240 (22.382965087890625MB) ##surviror1 区剩余容量

12.43827838477995% used ##survior1 区使用比例

To Space: ##survior2 区

capacity = 26804224 (25.5625MB) ##survior2 区容量

used = 0 (0.0MB) ##survior2 区已使用情况

free = 26804224 (25.5625MB) ##survior2 区剩余容量

0.0% used ## survior2 区使用比例

PS Old Generation: ##老年代使用情况

capacity = 1879048192 (1792.0MB) ##老年代容量

used = 30847928 (29.41887664794922MB) ##老年代已使用容量

free = 1848200264 (1762.5811233520508MB) ##老年代剩余容量

1.6416783843721663% used ##老年代使用比例

 

-histo 打印每个 class 的实例数目,内存占用,类全名信息.

jmap –histo jmap –histo:live 如果 live 子参数加上后,只统计活的对象数量

 

但是这样显示太多了,一般在 linux 上会这么操作

jmap –histo 1196 | head -20 (这样只会显示排名前 20 的数据 )

-dump 生成的堆转储快照(比较重要)

jmap -dump:live,format=b,file=heap.bin

Sun JDK 提供 jhat(JVM Heap Analysis Tool)命令与 jmap 搭配使用,来分析 jmap

jhat

jhat dump 文件名 后屏幕显示"Server is ready."的提示后,用户在浏览器中键入 http://localhost:7000/就可以访问详情

 

使用 jhat 可以在服务器上生成堆转储文件分析(一般不推荐,毕竟占用服务器的资源,,比如一个文件就有 1 个 G 的话就需要大约吃一个 1G 的内存资源)

jstack

(Stack Trace for Java)命令用于生成虚拟机当前时刻的线程快照。线程快照就是当前虚拟机内每一条线程正在执行的方法堆栈的集合,生成线程快照的主要目的是定位线程出现长时间停顿的原因,如线程间死锁、死循环、请求外部资源导致的长时间等待等都是导致线程长时间停顿的常见原因。

在代码中可以用 java.lang.Thread 类的 getAllStackTraces()方法用于获取虚拟机中所有线程的StackTraceElement 对象。使用这个方法可以通过简单的几行代码就完成 jstack 的大部分功能,在实际项目中不妨调用这个方法做个管理员页面,可以随时使用浏览器来查看线程堆栈。)一般来说 jstack 主要是用来排查是否有死锁的情况。

Arthas

官方文档参考 https://alibaba.github.io/arthas/ Arthas 是 Alibaba 开源的 Java 诊断工具,深受开发者喜爱。Arthas 支持 JDK 6+,支持 Linux/Mac/Windows,采用命令行交互模式,同时提供丰富的 Tab 自动补全功能,进一步方便进行问题的定位和诊断

可视化工具

Jconsole,visualvm 这两款使用比较简单,一般java应用都是运行在linux平台。所以这里忽略了。

命令工具总结

生产服务器推荐开启 -XX:-HeapDumpOnOutOfMemoryError 默认关闭,建议开启,在 java.lang.OutOfMemoryError 异常出现时,输出一个 dump 文件,记录当时的堆内存快照。 -XX:HeapDumpPath=./java_pid.hprof 用来设置堆内存快照的存储文件路径,默认是 java

调优之前开启、调优之后关闭 -XX:+PrintGC 调试跟踪之打印简单的 GC 信息参数:

-XX:+PrintGCDetails,

+XX:+PrintGCTimeStamps 打印详细的 GC 信息 -Xlogger:logpath 设置 gc 的日志路,如: -Xlogger:log/gc.log, 将 gc.log 的路径设置到当前目录的 log 目录下. 应用场景:将 gc 的日志独立写入日志文件,将 GC 日志与系统业务日志进行了分离,方便开发人员进行追踪分析

** 考虑使用** -XX:+PrintHeapAtGC, 打印推信息 参数设置: -XX:+PrintHeapAtGC应用场景: 获取 Heap 在每次垃圾回收前后的使用状况

-XX:+TraceClassLoading参数方法: -XX:+TraceClassLoading

应用场景:在系统控制台信息中看到 class 加载的过程和具体的 class 信息,可用以分析类的加载顺序以及是否可进行精简操作。

-XX:+DisableExplicitGC 禁止在运行期显式地调用 System.gc()

调优经验分享

GC 频率 高频的 FullGC 会给系统带来非常大的性能消耗,虽然 MinorGC 相对 FullGC 来说好了许多,但过多的 MinorGC 仍会给系统带来压力。对应:调整堆内存空间减少 GC,分析堆内存基本被用完,而且存在大量 MinorGC 和 FullGC,这意味着我们的堆内存严重不足,这个时候我们需要调大堆内存空间。

添加配置 -Xms1500m -Xmx1500m 增加堆内存空间 内存比例 内存指的是堆内存大小,堆内存又分为年轻代内存和老年代内存。堆内存不足,会增加 MinorGC ,影响系统性能。

MinorGC比较频发可以通过-Xmn 增加年轻代大小,降低 Minor GC 的频率 。-XX:SurvivorRatio调整大survivor区来减少触发动态年龄判断。

-Xmn1000m -XX:SurvivorRatio=7 修改合适的大小。

-XX:MetaspaceSize= 128M -XX:MaxMetaspaceSize= 128 M 设置一个够用值

元空间一般启动后就不会有太多的变化,所以把MetaspaceSize和MaxMetaspaceSize设置成一样。我们可以设定为 128M,节约内存

吞吐量 频繁的 GC 将会引起线程的上下文切换,增加系统的性能开销,从而影响每次处理的线程请求,最终导致系统的吞吐量下降。

-XX:ParallelGCThreads=8 线程数可以根据你的服务器资源情况来设定(要速度快的话可以设置大点,根据 CPU 的情况来定,一般设置成 CPU 的整 数倍

延时 JVM 的 GC 持续时间也会影响到每次请求的响应时间。

-XX:MaxTenuringThreshold=2 这个是分代年龄(年龄为 2 就可以进入老年代),因为我们基本上都使用的是 Spring 架构,Spring 中很多的 bean 是 长期要存活的,没有必要在 Survivor 区过渡太久,MaxTenuringThreshold默认是15,所以可以设定为 2,让大部分的 Spring 的内部的一些对象进入老年代。

-XX:+UseConcMarkSweepGC 如果是业务响应时间优先的,所以还是可以使用 CMS 垃圾回收器或者 G1 垃圾回收器。

推荐策略

  1. 新生代大小选择
  1. 老年代大小选择

GC 性能衡量指标

分析 GC 日志

通过 JVM 参数预先设置 GC 日志,几种 JVM 参数设置如下:

-XX:+PrintGC 输出 GC 日志

-XX:+PrintGCDetails 输出 GC 的详细日志

-XX:+PrintGCTimeStamps 输出 GC 的时间戳(以基准时间的形式)

-XX:+PrintGCDateStamps 输出 GC 的时间戳(以日期的形式,如 2013-05-04T21:53:59.234+0800)

-XX:+PrintHeapAtGC 在进行 GC 的前后打印出堆的信息

-Xloggc:../logs/gc.log 日志文件的输出路径

 

命令格式

java -jar -XX:+PrintGCDateStamps -XX:+PrintGCDetails -Xloggc:./gclogs jvm-1.0-SNAPSHOT.jar

日志查看工具gcViewer,Gceasy https://gceasy.io/

 

GC 调优策略

  • 降低 Minor GC 频率
  • 由于新生代空间较小,Eden 区很快被填满,就会导致频繁 Minor GC,因此我们可以通过增大新生代空间来降低 Minor GC 的频率。 单次 Minor GC 时间是由两部分组成:T1(扫描新生代)和 T2(复制存活对象)。
  • 降低 Full GC 的频率
  • 由于堆内存空间不足或老年代对象太多,会触发 Full GC,频繁的 Full GC 会带来上下文切换,增加系统的性能开销 。
  • 减少创建大对象:在平常的业务场景中,我们一次性从数据库中查询出一个大对象用于 web 端显示。比如,一次性查询出 60 个字段的业务操作,这种大对象如果超过年轻代最大对象阈值,会被直接创建在老年代;即使被创建在了年轻代,由于年轻代的内存空间有限,通过 Minor GC 之后也会进入到老 年代。这种大对象很容易产生较多的 Full GC。
  • 增大堆内存空间:在堆内存不足的情况下,增大堆内存空间,且设置初始化堆内存为最大堆内存,也可以降低 Full GC 的频率。
  • 选择合适的 GC 回收器: 如果要求每次操作的响应时间必须在 500ms 以内。这个时候我们一般会选择响应速度较快的 GC 回收器,堆内存比较小的情况下(<6G)选择 CMS(Concurrent Mark Sweep)回收器和堆内存比较大的情况下(>8G)G1 回收器。
  • GC调优小结 GC 调优是个很复杂、很细致的过程,要根据实际情况调整,不同的机器、不同的应用、不同的性能要求调优的手段都是不同的,一般调优的思路都是"测试 - 分析 - 调优",任何调优都需要结合场景,明确已知问题和性能目标,不能为了调优而调优,以免引入新的 Bug,带来风险和弊端。
posted on 2021-07-01 15:48  wolf12  阅读(191)  评论(0编辑  收藏  举报