JVM故障分析系列

JVM故障分析系列文章

JVM故障分析系列之一:使用jstack定位线程堆栈信息
JVM故障分析系列之二:jstack生成的Thread Dump日志结构解析
JVM故障分析系列之三:jstat命令的使用及VM Thread分析
JVM故障分析系列之四:jstack生成的Thread Dump日志线程状态
JVM故障分析系列之五:常见的Thread Dump日志案例分析
JVM故障分析系列之六:JVM Heap Dump(堆转储文件)的生成和MAT的使用
JVM故障分析系列之七:使用MAT的Histogram和Dominator Tree定位溢出源

前一段时间上线的系统升级之后,出现了严重的高CPU的问题,于是开始了一系列的优化处理之中,现在将这个过程做成一个系列的文章。

1 基本概念
2 使用jstack生成thread dump
3 生成shell文件
基本概念
在对Java内存泄漏进行分析的时候,需要对jvm运行期间的内存占用、线程执行等情况进行记录的dump文件,常用的主要有thread dump和heap dump。

thread dump 主要记录JVM在某一时刻各个线程执行的情况,以栈的形式显示,是一个文本文件。通过对thread dump文件可以分析出程序的问题出现在什么地方,从而定位具体的代码然后进行修正。thread dump需要结合占用系统资源的线程id进行分析才有意义。
heap dump 主要记录了在某一时刻JVM堆中对象使用的情况,即某个时刻JVM堆的快照,是一个二进制文件,主要用于分析哪些对象占用了太对的堆空间,从而发现导致内存泄漏的对象。
上面两种dump文件都具有实时性,因此需要在服务器出现问题的时候生成,并且多生成几个文件,方便进行对比分析。下面我们先来说一下如何生成 thread dump。

使用jstack生成thread dump
当服务器出现高CPU的时候,首先执行 top -c 命令动态显示进程及占用资源的排行,如下图:
在这里插入图片描述

top后面的参数-c可以显示进程详细的信息。top命令执行的时候还可以执行一些快捷键:

1 对于多核服务器,可以显示各个CPU占用资源的情况
shift+h 显示所有的线程信息
shift+w 将当前 top 命令的设置保存到 ~/.toprc 文件中,这样不用每次都执行快捷键了
以上图为例,pid为1503的进程占用了大量的CPU资源,接下来需要将占用CPU最高进程中的线程打印出来,可以用 top -bn1 -H -p 命令,执行结果如下:
在这里插入图片描述

上面 -bn1 参数的含义是只输出一次结果,而不是显示一个动态的结果。

我个人请喜欢用 ps -mp -o THREAD,tid,time | sort -k2r 命令查看,后面的sort参数根据线程占用的cpu比例进行排序,结果如下:
在这里插入图片描述

接下来我们清楚今天的主角 jstack,这是一个在JDK5开始提供的内置工具,可以打印指定进程中线程运行的状态,包括线程数量、是否存在死锁、资源竞争情况和线程的状态等等。有下面的几个常用的参数:

-l 长列表,打印关于锁的附加信息
-m 打印java和jni框架的所有栈信息
因为thread id在栈信息中是以十六进制的形式显示的,因此需要使用 printf “%x \n” 命令将现场id转成十六进制的值,然后执行 jstack -l | grep -A 10 命令显示出错的堆栈信息,如下图:
在这里插入图片描述

上面命令中 -A 10 参数用来指定显示行数,否则只会显示一行信息。

这样通过上图,可以很快地定位到程序问题的代码,然后对代码进行分析和改进即可。注意:需要在多个时间段提出多个 Thread Dump信息,然后综合进行对比分析,单独分析一个文件是没有意义的。

生成shell文件
上面讲述了整个的分析过程,不过所有的命令就是实时的,所以最好创建一个shell脚本瞬间执行完成,下面对 当CPU飙高时,它在做什么 这篇文章中所提供的shell进行了改进如下:

#!/bin/bash
if [ $# -le 0 ]; then
    echo "usage: $0 <pid> [line-number]"
    exit 1
fi

# java home
if test -z $JAVA_HOME 
then
    JAVA_HOME='/usr/local/jdk'
fi

#pid
pid=$1
# checking pid
if test -z "$($JAVA_HOME/bin/jps -l | cut -d '' -f 1 | grep $pid)"
then
    echo "process of $pid is not exists"
    exit
fi

#line number
linenum=$2
if test -z $linenum
then
    linenum=10
fi

stackfile=stack$pid.dump
threadsfile=threads$pid.dump

# generate java stack
$JAVA_HOME/bin/jstack -l $pid >> $stackfile
ps -mp $pid -o THREAD,tid,time | sort -k2r | awk '{if ($1 !="USER" && $2 != "0.0" && $8 !="-") print $8;}' | xargs printf "%x\n" >> $threadsfile
tids="$(cat $threadsfile)"
for tid in $tids
do
    echo "------------------------------ ThreadId ($tid) ------------------------------"
    cat $stackfile | grep 0x$tid -A $linenum
done

rm -f $stackfile $threadsfile

JVM故障分析系列之二:jstack生成的Thread Dump日志结构解析

一个典型的thread dump文件主要由一下几个部分组成:
在这里插入图片描述

上图将JVM上的线程堆栈信息和线程信息做了详细的拆解。

第一部分:Full thread dump identifier

这一部分是内容最开始的部分,展示了快照文件的生成时间和JVM的版本信息。

2017-10-19 10:46:44
Full thread dump Java HotSpot(TM) 64-Bit Server VM (24.79-b02 mixed mode):

第二部分:Java EE middleware, third party & custom application Threads

这是整个文件的核心部分,里面展示了JavaEE容器(如tomcat、resin等)、自己的程序中所使用的线程信息。这一部分详细的含义见 Java内存泄漏分析系列之四:jstack生成的Thread Dump日志线程状态分析。

"resin-22129" daemon prio=10 tid=0x00007fbe5c34e000 nid=0x4cb1 waiting on condition [0x00007fbe4ff7c000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:315)
    at com.caucho.env.thread2.ResinThread2.park(ResinThread2.java:196)
    at com.caucho.env.thread2.ResinThread2.runTasks(ResinThread2.java:147)
    at com.caucho.env.thread2.ResinThread2.run(ResinThread2.java:118)

第三部分:HotSpot VM Thread

这一部分展示了JVM内部线程的信息,用于执行内部的原生操作。下面常见的集中内置线程:

“Attach Listener”

该线程负责接收外部命令,执行该命令并把结果返回给调用者,此种类型的线程通常在桌面程序中出现。

"Attach Listener" daemon prio=5 tid=0x00007fc6b6800800 nid=0x3b07 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
“DestroyJavaVM”

执行main()的线程在执行完之后调用JNI中的 jni_DestroyJavaVM() 方法会唤起DestroyJavaVM 线程。在JBoss启动之后,也会唤起DestroyJavaVM线程,处于等待状态,等待其它线程(java线程和native线程)退出时通知它卸载JVM。

"DestroyJavaVM" prio=5 tid=0x00007fc6b3001000 nid=0x1903 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
“Service Thread”

用于启动服务的线程

"Service Thread" daemon prio=10 tid=0x00007fbea81b3000 nid=0x5f2 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
“CompilerThread”

用来调用JITing,实时编译装卸CLASS。通常JVM会启动多个线程来处理这部分工作,线程名称后面的数字也会累加,比如CompilerThread1。

"C2 CompilerThread1" daemon prio=10 tid=0x00007fbea814b000 nid=0x5f1 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" daemon prio=10 tid=0x00007fbea8142000 nid=0x5f0 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
“Signal Dispatcher”

Attach Listener线程的职责是接收外部jvm命令,当命令接收成功后,会交给signal dispather 线程去进行分发到各个不同的模块处理命令,并且返回处理结果。
signal dispather线程也是在第一次接收外部jvm命令时,进行初始化工作。

"Signal Dispatcher" daemon prio=10 tid=0x00007fbea81bf800 nid=0x5ef runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
“Finalizer”

这个线程也是在main线程之后创建的,其优先级为10,主要用于在垃圾收集前,调用对象的finalize()方法;关于Finalizer线程的几点:
(1)只有当开始一轮垃圾收集时,才会开始调用finalize()方法;因此并不是所有对象的finalize()方法都会被执行;
(2)该线程也是daemon线程,因此如果虚拟机中没有其他非daemon线程,不管该线程有没有执行完finalize()方法,JVM也会退出;
(3)JVM在垃圾收集时会将失去引用的对象包装成Finalizer对象(Reference的实现),并放入ReferenceQueue,由Finalizer线程来处理;最后将该Finalizer对象的引用置为null,由垃圾收集器来回收;
(4)JVM为什么要单独用一个线程来执行finalize()方法呢?
如果JVM的垃圾收集线程自己来做,很有可能由于在finalize()方法中误操作导致GC线程停止或不可控,这对GC线程来说是一种灾难。

"Finalizer" daemon prio=10 tid=0x00007fbea80da000 nid=0x5eb in Object.wait() [0x00007fbeac044000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
    - locked <0x00000006d173c1a8> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
    at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)
“Reference Handler”

JVM在创建main线程后就创建Reference Handler线程,其优先级最高,为10,它主要用于处理引用对象本身(软引用、弱引用、虚引用)的垃圾回收问题 。

"Reference Handler" daemon prio=10 tid=0x00007fbea80d8000 nid=0x5ea in Object.wait() [0x00007fbeac085000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    at java.lang.Object.wait(Object.java:503)
    at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133)
    - locked <0x00000006d173c1f0> (a java.lang.ref.Reference$Lock)
“VM Thread”

JVM中线程的母体,根据HotSpot源码中关于vmThread.hpp里面的注释,它是一个单例的对象(最原始的线程)会产生或触发所有其他的线程,这个单例的VM线程是会被其他线程所使用来做一些VM操作(如清扫垃圾等)。
在 VM Thread 的结构体里有一个VMOperationQueue列队,所有的VM线程操作(vm_operation)都会被保存到这个列队当中,VMThread 本身就是一个线程,它的线程负责执行一个自轮询的loop函数(具体可以参考:VMThread.cpp里面的void VMThread::loop()) ,该loop函数从VMOperationQueue列队中按照优先级取出当前需要执行的操作对象(VM_Operation),并且调用VM_Operation->evaluate函数去执行该操作类型本身的业务逻辑。
VM操作类型被定义在vm_operations.hpp文件内,列举几个:ThreadStop、ThreadDump、PrintThreads、GenCollectFull、GenCollectFullConcurrent、CMS_Initial_Mark、CMS_Final_Remark…… 有兴趣的同学,可以自己去查看源文件。

"VM Thread" prio=10 tid=0x00007fbea80d3800 nid=0x5e9 runnable

第四部分:HotSpot GC Thread

JVM中用于进行资源回收的线程,包括以下几种类型的线程:

“VM Periodic Task Thread”

该线程是JVM周期性任务调度的线程,它由WatcherThread创建,是一个单例对象。该线程在JVM内使用得比较频繁,比如:定期的内存监控、JVM运行状况监控。

"VM Periodic Task Thread" prio=10 tid=0x00007fbea82ae800 nid=0x5fa waiting on condition

可以使用jstat 命令查看GC的情况,比如查看某个进程没有存活必要的引用可以使用命令 jstat -gcutil 250 7 参数中pid是进程id,后面的250和7表示每250毫秒打印一次,总共打印7次。
这对于防止因为应用代码中直接使用native库或者第三方的一些监控工具的内存泄漏有非常大的帮助。

“GC task thread#0 (ParallelGC)”

垃圾回收线程,该线程会负责进行垃圾回收。通常JVM会启动多个线程来处理这个工作,线程名称中#后面的数字也会累加。

"GC task thread#0 (ParallelGC)" prio=5 tid=0x00007fc6b480d000 nid=0x2503 runnable

"GC task thread#1 (ParallelGC)" prio=5 tid=0x00007fc6b2812000 nid=0x2703 runnable

"GC task thread#2 (ParallelGC)" prio=5 tid=0x00007fc6b2812800 nid=0x2903 runnable

"GC task thread#3 (ParallelGC)" prio=5 tid=0x00007fc6b2813000 nid=0x2b03 runnable

如果在JVM中增加了 -XX:+UseConcMarkSweepGC 参数将会启用CMS (Concurrent Mark-Sweep)GC Thread方式,以下是该模式下的线程类型:
“Gang worker#0 (Parallel GC Threads)”
原来垃圾回收线程GC task thread#0 (ParallelGC) 被替换为 Gang worker#0 (Parallel GC Threads)。Gang worker 是JVM用于年轻代垃圾回收(minor gc)的线程。

"Gang worker#0 (Parallel GC Threads)" prio=10 tid=0x00007fbea801b800 nid=0x5e4 runnable 

"Gang worker#1 (Parallel GC Threads)" prio=10 tid=0x00007fbea801d800 nid=0x5e7 runnable 
“Concurrent Mark-Sweep GC Thread”

并发标记清除垃圾回收器(就是通常所说的CMS GC)线程, 该线程主要针对于年老代垃圾回收。

"Concurrent Mark-Sweep GC Thread" prio=10 tid=0x00007fbea8073800 nid=0x5e8 runnable 
“Surrogate Locker Thread (Concurrent GC)”

此线程主要配合CMS垃圾回收器来使用,是一个守护线程,主要负责处理GC过程中Java层的Reference(指软引用、弱引用等等)与jvm 内部层面的对象状态同步。

“Surrogate Locker Thread (Concurrent GC)” daemon prio=10 tid=0x00007fbea8158800 nid=0x5ee waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
这里以 WeakHashMap 为例进行说明,首先是一个关键点:

WeakHashMap和HashMap一样,内部有一个Entry[]数组;
WeakHashMap的Entry比较特殊,它的继承体系结构为Entry->WeakReference->Reference;
Reference 里面有一个全局锁对象:Lock,它也被称为pending_lock,注意:它是静态对象;
Reference 里面有一个静态变量:pending;
Reference 里面有一个静态内部类:ReferenceHandler的线程,它在static块里面被初始化并且启动,启动完成后处于wait状态,它在一个Lock同步锁模块中等待;
WeakHashMap里面还实例化了一个ReferenceQueue列队
假设,WeakHashMap对象里面已经保存了很多对象的引用,JVM 在进行CMS GC的时候会创建一个ConcurrentMarkSweepThread(简称CMST)线程去进行GC。ConcurrentMarkSweepThread线程被创建的同时会创建一个SurrogateLockerThread(简称SLT)线程并且启动它,SLT启动之后,处于等待阶段。
CMST开始GC时,会发一个消息给SLT让它去获取Java层Reference对象的全局锁:Lock。直到CMS GC完毕之后,JVM 会将WeakHashMap中所有被回收的对象所属的WeakReference容器对象放入到Reference 的pending属性当中(每次GC完毕之后,pending属性基本上都不会为null了),然后通知SLT释放并且notify全局锁:Lock。此时激活了ReferenceHandler线程的run方法,使其脱离wait状态,开始工作了。
ReferenceHandler这个线程会将pending中的所有WeakReference对象都移动到它们各自的列队当中,比如当前这个WeakReference属于某个WeakHashMap对象,那么它就会被放入相应的ReferenceQueue列队里面(该列队是链表结构)。 当我们下次从WeakHashMap对象里面get、put数据或者调用size方法的时候,WeakHashMap就会将ReferenceQueue列队中的WeakReference依依poll出来去和Entry[]数据做比较,如果发现相同的,则说明这个Entry所保存的对象已经被GC掉了,那么将Entry[]内的Entry对象剔除掉。

第五部分:JNI global references count

这一部分主要回收那些在native代码上被引用,但在java代码中却没有存活必要的引用,对于防止因为应用代码中直接使用native库或第三方的一些监控工具的内存泄漏有非常大的帮助。

JNI global references: 830

JVM故障分析系列之三:jstat命令的使用及VM Thread分析

使用jstat命令
当服务器CPU100%的时候,通过定位占用资源最大的线程定位到 VM Thread:

“VM Thread” prio=10 tid=0x00007fbea80d3800 nid=0x5e9 runnable
这个时候需要使用 jstat -gc 命令查看gc的信息,显示结果如下:
在这里插入图片描述

S0C    S1C    S0U    S1U      EC       EU      OC         OU       PC        PU       YGC     YGCT    FGC   FGCT       GCT
64.0   64.0   0.0    0.0   332992.0   0.0    666304.0   73192.5   83968.0   83967.9   6893   17.576  6882   2705.923  2723.499

结果中每个项目的含义可以参考官方对jstat的文档,简单翻译如下:

  • S0C: Young Generation第一个survivor space的内存大小 (kB).
  • S1C: Young Generation第二个survivor space的内存大小 (kB).
  • S0U: Young Generation第一个Survivor space当前已使用的内存大小 (kB).
  • S1U: Young Generation第二个Survivor space当前已经使用的内存大小 (kB).
  • EC: Young Generation中eden space的内存大小 (kB).
  • EU: Young Generation中Eden space当前已使用的内存大小 (kB).
  • OC: Old Generation的内存大小 (kB).
  • OU: Old Generation当前已使用的内存大小 (kB).
  • PC: Permanent Generation的内存大小 (kB)
  • PU: Permanent Generation当前已使用的内存大小 (kB).
  • YGC: 从启动到采样时Young Generation GC的次数
  • YGCT: 从启动到采样时Young Generation GC所用的时间 (s).
  • FGC: 从启动到采样时Old Generation GC的次数.
  • FGCT: 从启动到采样时Old Generation GC所用的时间 (s).
  • GCT: 从启动到采样时GC所用的总时间 (s).

JDK8的结果稍微有所不同,结果含义可以参考:http://docs.oracle.com/javase/8/docs/technotes/tools/unix/jstat.html。

JVM内存模型
上面中的Young Generation、Permanent Generation和Old Generation等概念有一些混乱,这里简要的进行说明。简单来说,JVM内存由堆(Heap)和非堆(Non-heap)内存组成,前者共运行在JVM之上的程序使用,后者供JVM自己使用。
在这里插入图片描述

堆内存的组成如下:
在这里插入图片描述

非堆内存由 Permanent Generation 和 Code Cache 两部分组成:

Permanent Generation(持久代): 保存虚拟机自己的静态(refective)数据,主要存放加载的Class类级别静态对象如class本身,method,field等等。permanent generation空间不足会引发full GC;
Code Cache: 用于编译和保存本地代码(native code)的内存,JVM内部处理或优化。

JVM内存参数设置

堆内存设置

堆内存(总的)由 -Xms 和 -Xmx 分别设置最小和最大堆内存
New Generation 由 -Xmn 设置,-XX:SurvivorRatio=m 设置 Eden和 两个Survivor区的大小比值;-XX:NewRatio=n 设置 New Generation 和 Old Generation 的大小比值。
每个线程的堆栈大小由 ·-Xss· 设置,JDK5.0以后每个线程堆栈大小为1M,以前每个线程堆栈大小为256K。在相同物理内存下,减小这个值能生成更多的线程。但是操作系统对一个进程内的线程数还是有限制的,不能无限生成,经验值在3000~5000左右。

非堆内存设置

非堆内存由 -XX:PermSize=n 和 -XX:MaxPermSize=n 分别设置最小和最大非堆内存大小

日志分析

介绍完上面的概念之后,我们再来看最上面的日志信息,有两个地方有问题:
一是FGC(完全GC)的数量太大了,正常来说FGC应该占整个GC(YGC+FGC)的1%到5%才正常,上面日志上完全GC的次数太多了;二是日志中PU的值太大了,基本上已经达到设置的PC了,因此需要增大MaxPermSize的值。
不过这只是权宜之计,出现这么大的非堆内存,肯定什么地方出现了问题,还需要进一步找到占用内存的原因,这也是后面文章所要说的。

参考资料:
100% CPU diagnosis
JVM调优总结 + jstat 分析
JVM调优总结(这个总结得比较全面)
JVM调优总结系列文章
JVM系列一:JVM内存组成及分配

JVM故障分析 内存泄漏
One thought to “JVM故障分析系列之三:jstat命令的使用及VM Thread分析”

LOUPIPALIEN 2018年12月21日 10:59 上午
-Xmssize
Sets the initial size (in bytes) of the heap. This value must be a multiple of 1024 and greater than 1 MB. Append the letter k or K
to indicate kilobytes, m or M to indicate megabytes, g or G to
indicate gigabytes.

The following examples show how to set the size of allocated memory to
6 MB using various units:

-Xms6291456
-Xms6144k
-Xms6m
If you do not set this option, then the initial size will be set as the sum of the sizes allocated for the old generation and the
young generation. The initial size of the heap for the young
generation can be set using the -Xmn option or t

he -XX:NewSize option.

From https://docs.oracle.com/javase/8/docs/technotes/tools/unix/java.html

  • 0
    点赞
  • 1
    收藏
    觉得还不错? 一键收藏
  • 0
    评论
评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值