jvm优化—监控工具:诊断内存泄露、cpu飙升、线程死锁、响应变慢

JVM调优 专栏收录该内容
8 篇文章 4 订阅

目录

一、jvm常见监控工具&指令

JVM常见参数

为什么要将永久代 (PermGen) 替换为元空间 (MetaSpace) 呢?

1、 jps:jvm进程状况工具

2、jstat: jvm统计信息监控工具

3、jinfo: java配置信息

4、jmap: java 内存映射工具

5、jhat:jvm堆快照分析工具

6、jstack:java堆栈跟踪工具

线程dump信息说明:

jstack线程dump输出状态解释

线程的状态分析

Runnable

Deadlock

Wait on condition

Waiting on monitor entry和Object.wait()

Blocked

关于concurrent的Lock

jstack解决CPU过高的问题

二、可视化工具

三、应用

1、cpu飙升

2、线程死锁

2.查看java进程的线程快照信息

3、OOM内存泄露

 


在常见的线上问题时候,我们多数会遇到以下问题:

  • 内存泄露
  • 某个进程突然cpu飙升
  • 线程死锁
  • 响应变慢...等等其他问题。

如果遇到了以上这种问题,在线下可以有各种本地工具支持查看,但到线上了,就没有这么多的本地调试工具支持,我们该如何基于监控工具来进行定位问题?

我们一般会基于数据收集来定位,而数据的收集离不开监控工具的处理,比如:运行日志、异常堆栈、GC日志、线程快照、堆快照等。经常使用恰当的分析和监控工具可以加快我们的分析数据、定位解决问题的速度。以下我们将会详细介绍。

一、jvm常见监控工具&指令

JVM常见参数

可通过JAVA_OPTS设置

参数说明:

-server:一定要作为第一个参数,在多个CPU时性能佳

-Xms:初始Heap大小,使用的最小内存,cpu性能高时此值应设的大一些

-Xmx:java heap最大值,使用的最大内存

-XX:PermSize:设定内存的永久保存区域

-XX:MaxPermSize:设定最大内存的永久保存区域

-XX:MaxNewSize:

+XX:AggressiveHeap 会使得 Xms没有意义。这个参数让jvm忽略Xmx参数,疯狂地吃完一个G物理内存,再吃尽一个G的swap。

-Xss:每个线程的Stack大小

-verbose:gc 现实垃圾收集信息

-Xloggc:gc.log 指定垃圾收集日志文件

-Xmn:young generation的heap大小,一般设置为Xmx的3、4分之一

-XX:+UseParNewGC :缩短minor收集的时间

-XX:+UseConcMarkSweepGC :缩短major收集的时间

提示:此选项在Heap Size 比较大而且Major收集时间较长的情况下使用更合适。

JDK 1.8 之前永久代还没被彻底移除的时候通常通过下面这些参数来调节方法区大小

-XX:PermSize=N //方法区 (永久代) 初始大小
-XX:MaxPermSize=N //方法区 (永久代) 最大大小,超过这个值将会抛出 OutOfMemoryError 异常:java.lang.OutOfMemoryError: PermGenCopy to clipboardErrorCopied

相对而言,垃圾收集行为在这个区域是比较少出现的,但并非数据进入方法区后就“永久存在”了。

JDK 1.8 的时候,方法区(HotSpot 的永久代)被彻底移除了(JDK1.7 就已经开始了),取而代之是元空间,元空间使用的是直接内存。

下面是一些常用参数:

-XX:MetaspaceSize=N //设置 Metaspace 的初始(和最小大小)
-XX:MaxMetaspaceSize=N //设置 Metaspace 的最大大小Copy to clipboardErrorCopied

与永久代很大的不同就是,如果不指定大小的话,随着更多类的创建,虚拟机会耗尽所有可用的系统内存。

为什么要将永久代 (PermGen) 替换为元空间 (MetaSpace) 呢?

  1. 整个永久代有一个 JVM 本身设置固定大小上限,无法进行调整,而元空间使用的是直接内存,受本机可用内存的限制,虽然元空间仍旧可能溢出,但是比原来出现的几率会更小。

    当你元空间溢出时会得到如下错误: java.lang.OutOfMemoryError: MetaSpace

你可以使用 -XX:MaxMetaspaceSize 标志设置最大元空间大小,默认值为 unlimited,这意味着它只受系统内存的限制。-XX:MetaspaceSize 调整标志定义元空间的初始大小如果未指定此标志,则 Metaspace 将根据运行时的应用程序需求动态地重新调整大小。

  1. 元空间里面存放的是类的元数据,这样加载多少类的元数据就不由 MaxPermSize 控制了, 而由系统的实际可用空间来控制,这样能加载的类就更多了。

  2. 在 JDK8,合并 HotSpot 和 JRockit 的代码时, JRockit 从来没有一个叫永久代的东西, 合并之后就没有必要额外的设置这么一个永久代的地方了。

1、 jps:jvm进程状况工具

jps [options] [hostid]

如果不指定hostid就默认为当前主机或服务器。

命令行参数选项说明如下:

-q 不输出类名、Jar名和传入main方法的参数

- l 输出main类或Jar的全限名

-m 输出传入main方法的参数

- v 输出传入JVM的参数

 

 

2、jstat: jvm统计信息监控工具

jstat 是用于见识虚拟机各种运行状态信息的命令行工具。

它可以显示本地或者远程虚拟机进程中的类装载、内存、垃圾收集、jit编译等运行数据,它是线上定位jvm性能的首选工具。

命令格式:

jstat [ generalOption | outputOptions vmid [interval[s|ms] [count]] ]

generalOption - 单个的常用的命令行选项,如-help, -options, 或 -version。

outputOptions -一个或多个输出选项,由单个的statOption选项组成,可以和-t, -h, and -J等选项配合使用。

Usage: jstat -help|-options
       jstat -<option> [-t] [-h<lines>] <vmid> [<interval> [<count>]]

参数选项:

Option

Displays

Ex

class

用于查看类加载情况的统计

jstat -class pid:显示加载class的数量,及所占空间等信息。

compiler

查看HotSpot中即时编译器编译情况的统计

jstat -compiler pid:显示VM实时编译的数量等信息。

gc

查看JVM中堆的垃圾收集情况的统计

jstat -gc pid:可以显示gc的信息,查看gc的次数,及时间。其中最后五项,分别是young gc的次数,young gc的时间,full gc的次数,full gc的时间,gc的总时间。

gccapacity

查看新生代、老生代及持久代的存储容量情况

jstat -gccapacity:可以显示,VM内存中三代(young,old,perm)对象的使用和占用大小

gccause

查看垃圾收集的统计情况(这个和-gcutil选项一样),如果有发生垃圾收集,它还会显示最后一次及当前正在发生垃圾收集的原因。

jstat -gccause:显示gc原因

gcnew

查看新生代垃圾收集的情况

jstat -gcnew pid:new对象的信息

gcnewcapacity

用于查看新生代的存储容量情况

jstat -gcnewcapacity pid:new对象的信息及其占用量

gcold

用于查看老生代及持久代发生GC的情况

jstat -gcold pid:old对象的信息

gcoldcapacity

用于查看老生代的容量

jstat -gcoldcapacity pid:old对象的信息及其占用量

gcpermcapacity

用于查看持久代的容量

jstat -gcpermcapacity pid: perm对象的信息及其占用量

gcutil

查看新生代、老生代及持代垃圾收集的情况

jstat -gcutil pid:统计gc信息统计

printcompilation

HotSpot编译方法的统计

jstat -printcompilation pid:当前VM执行的信息

 

3、jinfo: java配置信息

命令格式:

jinfo[option] pid

比如:获取一些当前进程的jvm运行和启动信息。

[root@newolpay-01 ~]# jinfo 16361
Attaching to process ID 16361, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.121-b13
Java System Properties:

jboss.i18n.generate-proxies = true
java.runtime.name = Java(TM) SE Runtime Environment
java.vm.version = 25.121-b13
sun.boot.library.path = /usr/local/jdk1.8.0_121/jre/lib/amd64
shared.loader = 
java.vendor.url = http://java.oracle.com/
java.vm.vendor = Oracle Corporation
path.separator = :
file.encoding.pkg = sun.io
java.vm.name = Java HotSpot(TM) 64-Bit Server VM
java.util.logging.config.file = /usr/local/java/apache-tomcat-8.0.39-PayService-80/conf/logging.properties
tomcat.util.buf.StringCache.byte.enabled = true
sun.os.patch.level = unknown
sun.java.launcher = SUN_STANDARD
user.country = US
tomcat.util.scan.StandardJarScanFilter.jarsToScan = log4j-web*.jar,log4j-taglib*.jar,log4javascript*.jar,slf4j-taglib*.jar
user.dir = /usr/local/java/apache-tomcat-8.0.39-PayService-80/bin
java.vm.specification.name = Java Virtual Machine Specification
java.runtime.version = 1.8.0_121-b13
java.awt.graphicsenv = sun.awt.X11GraphicsEnvironment
os.arch = amd64
java.endorsed.dirs = /usr/local/java/apache-tomcat-8.0.39-PayService-80/endorsed
line.separator = 

java.io.tmpdir = /usr/local/java/apache-tomcat-8.0.39-PayService-80/temp
java.vm.specification.vendor = Oracle Corporation
java.util.logging.manager = org.apache.juli.ClassLoaderLogManager
java.naming.factory.url.pkgs = org.apache.naming
os.name = Linux
sun.jnu.encoding = UTF-8
java.library.path = /usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
java.class.version = 52.0
java.specification.name = Java Platform API Specification
sun.management.compiler = HotSpot 64-Bit Tiered Compilers
os.version = 3.10.0-514.6.2.el7.x86_64
user.home = /root
user.timezone = Asia/Shanghai
catalina.useNaming = true
java.awt.printerjob = sun.print.PSPrinterJob
file.encoding = UTF-8
java.specification.version = 1.8
tomcat.util.scan.StandardJarScanFilter.jarsToSkip = bootstrap.jar,commons-daemon.jar,tomcat-juli.jar,annotations-api.jar,el-api.jar,j
sp-api.jar,servlet-api.jar,websocket-api.jar,catalina.jar,catalina-ant.jar,catalina-ha.jar,catalina-storeconfig.jar,catalina-tribes.jar,jasper.jar,jasper-el.jar,ecj-*.jar,tomcat-api.jar,tomcat-util.jar,tomcat-util-scan.jar,tomcat-coyote.jar,tomcat-dbcp.jar,tomcat-jni.jar,tomcat-websocket.jar,tomcat-i18n-en.jar,tomcat-i18n-es.jar,tomcat-i18n-fr.jar,tomcat-i18n-ja.jar,tomcat-juli-adapters.jar,catalina-jmx-remote.jar,catalina-ws.jar,tomcat-jdbc.jar,tools.jar,commons-beanutils*.jar,commons-codec*.jar,commons-collections*.jar,commons-dbcp*.jar,commons-digester*.jar,commons-fileupload*.jar,commons-httpclient*.jar,commons-io*.jar,commons-lang*.jar,commons-logging*.jar,commons-math*.jar,commons-pool*.jar,jstl.jar,taglibs-standard-spec-*.jar,geronimo-spec-jaxrpc*.jar,wsdl4j*.jar,ant.jar,ant-junit*.jar,aspectj*.jar,jmx.jar,h2*.jar,hibernate*.jar,httpclient*.jar,jmx-tools.jar,jta*.jar,log4j*.jar,mail*.jar,slf4j*.jar,xercesImpl.jar,xmlParserAPIs.jar,xml-apis.jar,junit.jar,junit-*.jar,ant-launcher.jar,cobertura-*.jar,asm-*.jar,dom4j-*.jar,icu4j-*.jar,jaxen-*.jar,jdom-*.jar,jetty-*.jar,oro-*.jar,servlet-api-*.jar,tagsoup-*.jar,xmlParserAPIs-*.jar,xom-*.jarcatalina.home = /usr/local/java/apache-tomcat-8.0.39-PayService-80
user.name = root
java.class.path = /usr/local/java/apache-tomcat-8.0.39-PayService-80/bin/bootstrap.jar:/usr/local/java/apache-tomcat-8.0.39-PayServic
e-80/bin/tomcat-juli.jarjava.naming.factory.initial = org.apache.naming.java.javaURLContextFactory
package.definition = sun.,java.,org.apache.catalina.,org.apache.coyote.,org.apache.jasper.,org.apache.naming.,org.apache.tomcat.
java.vm.specification.version = 1.8
sun.arch.data.model = 64
sun.java.command = org.apache.catalina.startup.Bootstrap start
java.home = /usr/local/jdk1.8.0_121/jre
user.language = en
java.specification.vendor = Oracle Corporation
awt.toolkit = sun.awt.X11.XToolkit
java.vm.info = mixed mode
java.version = 1.8.0_121
java.ext.dirs = /usr/local/jdk1.8.0_121/jre/lib/ext:/usr/java/packages/lib/ext
sun.boot.class.path = /usr/local/jdk1.8.0_121/jre/lib/resources.jar:/usr/local/jdk1.8.0_121/jre/lib/rt.jar:/usr/local/jdk1.8.0_121/jr
e/lib/sunrsasign.jar:/usr/local/jdk1.8.0_121/jre/lib/jsse.jar:/usr/local/jdk1.8.0_121/jre/lib/jce.jar:/usr/local/jdk1.8.0_121/jre/lib/charsets.jar:/usr/local/jdk1.8.0_121/jre/lib/jfr.jar:/usr/local/jdk1.8.0_121/jre/classesserver.loader = 
java.vendor = Oracle Corporation
catalina.base = /usr/local/java/apache-tomcat-8.0.39-PayService-80
file.separator = /
java.vendor.url.bug = http://bugreport.sun.com/bugreport/
common.loader = "${catalina.base}/lib","${catalina.base}/lib/*.jar","${catalina.home}/lib","${catalina.home}/lib/*.jar"
sun.io.unicode.encoding = UnicodeLittle
sun.font.fontmanager = sun.awt.X11FontManager
sun.cpu.endian = little
package.access = sun.,org.apache.catalina.,org.apache.coyote.,org.apache.jasper.,org.apache.tomcat.
sun.cpu.isalist = 

VM Flags:
Non-default VM flags: -XX:CICompilerCount=12 -XX:+DisableExplicitGC -XX:InitialHeapSize=2147483648 -XX:MaxHeapSize=2147483648 -XX:Max
NewSize=1073741824 -XX:MaxTenuringThreshold=10 -XX:MinHeapDeltaBytes=524288 -XX:NewRatio=2 -XX:NewSize=1073741824 -XX:OldSize=1073741824 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseParallelGC Command line:  -Djava.util.logging.config.file=/usr/local/java/apache-tomcat-8.0.39-PayService-80/conf/logging.properties -Djava.util
.logging.manager=org.apache.juli.ClassLoaderLogManager -Dfile.encoding=UTF-8 -Xms2048m -Xmx2048m -XX:NewSize=512m -XX:MaxNewSize=1024m -XX:MaxTenuringThreshold=10 -XX:NewRatio=2 -XX:+DisableExplicitGC -Djava.endorsed.dirs=/usr/local/java/apache-tomcat-8.0.39-PayService-80/endorsed -Dcatalina.base=/usr/local/java/apache-tomcat-8.0.39-PayService-80 -Dcatalina.home=/usr/local/java/apache-tomcat-8.0.39-PayService-80 -Djava.io.tmpdir=/usr/local/java/apache-tomcat-8.0.39-PayService-80/temp

 

4、jmap: java 内存映射工具

jmap命令用于生产堆转存快照。打印出某个java进程(使用pid)内存内的所有‘对象’的情况(如:产生那些对象,及其数量)。

命令格式:

jmap [ option ] pid

jmap [ option ] executable core

jmap [ option ] [server-id@]remote-hostname-or-IP

 

参数选项:

-dump:[live,]format=b,file=<filename> 使用hprof二进制形式,输出jvm的heap内容到文件=. live子选项是可选的,假如指定live选项,那么只输出活的对象到文件. 

-finalizerinfo 打印正等候回收的对象的信息.

-heap 打印heap的概要信息,GC使用的算法,heap的配置及wise heap的使用情况.

-histo[:live] 打印每个class的实例数目,内存占用,类全名信息. VM的内部类名字开头会加上前缀”*”. 如果live子参数加上后,只统计活的对象数量. 

-permstat 打印classload和jvm heap长久层的信息. 包含每个classloader的名字,活泼性,地址,父classloader和加载的class数量. 另外,内部String的数量和占用内存数也会打印出来. 

-F 强迫.在pid没有相应的时候使用-dump或者-histo参数. 在这个模式下,live子参数无效. 

-h | -help 打印辅助信息 

-J 传递参数给jmap启动的jvm. 

例如:

使用jmap -heap pid查看进程堆内存使用情况,包括使用的GC算法、堆配置参数和各代中堆内存使用情况:

[root@newolpay-01 ~]# jmap -heap 16361
Attaching to process ID 16361, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.121-b13

using thread-local object allocation.
Parallel GC with 13 thread(s)

Heap Configuration:
   MinHeapFreeRatio         = 0
   MaxHeapFreeRatio         = 100
   MaxHeapSize              = 2147483648 (2048.0MB)
   NewSize                  = 1073741824 (1024.0MB)
   MaxNewSize               = 1073741824 (1024.0MB)
   OldSize                  = 1073741824 (1024.0MB)
   NewRatio                 = 2
   SurvivorRatio            = 8
   MetaspaceSize            = 21807104 (20.796875MB)
   CompressedClassSpaceSize = 1073741824 (1024.0MB)
   MaxMetaspaceSize         = 17592186044415 MB
   G1HeapRegionSize         = 0 (0.0MB)

Heap Usage:
PS Young Generation
Eden Space:
   capacity = 1016070144 (969.0MB)
   used     = 181957384 (173.52808380126953MB)
   free     = 834112760 (795.4719161987305MB)
   17.907954984651138% used
From Space:
   capacity = 28835840 (27.5MB)
   used     = 23842800 (22.738265991210938MB)
   free     = 4993040 (4.7617340087890625MB)
   82.6846036044034% used
To Space:
   capacity = 28311552 (27.0MB)
   used     = 0 (0.0MB)
   free     = 28311552 (27.0MB)
   0.0% used
PS Old Generation
   capacity = 1073741824 (1024.0MB)
   used     = 435791616 (415.603271484375MB)
   free     = 637950208 (608.396728515625MB)
   40.586256980895996% used

46929 interned Strings occupying 4929168 bytes.

使用jmap -histo[:live] pid查看堆内存中的对象数目、大小统计直方图

 

5、jhat:jvm堆快照分析工具

jhat 命令与jamp搭配使用,用来分析map生产的堆快存储快照。jhat内置了一个微型http/Html服务器,可以在浏览器找那个查看。不过建议尽量不用,既然有dumpt文件,可以从生产环境拉取下来,然后通过本地可视化工具来分析,这样既减轻了线上服务器压力,有可以分析的足够详尽(比如 MAT/jprofile/visualVm)等。

 

6、jstack:java堆栈跟踪工具

jstack用于生成java虚拟机当前时刻的线程快照。

线程快照是当前java虚拟机内每一条线程正在执行的方法堆栈的集合,生成线程快照的主要目的是定位线程出现长时间停顿的原因,如线程间死锁、死循环、请求外部资源导致的长时间等待等。

命令格式:

jstack [ option ] pid

jstack [ option ] executable core

jstack [ option ] [server-id@]remote-hostname-or-IP

参数:

  • -F当’jstack [-l] pid’没有相应的时候强制打印栈信息
  • -l长列表. 打印关于锁的附加信息,例如属于java.util.concurrent的ownable synchronizers列表.
  • -m打印java和native c/c++框架的所有栈信息.
  • -h | -help打印帮助信息
  • pid 需要被打印配置信息的java进程id,可以用jps查询.

后续的查找耗费最高cpu例子会用到。

"C2 CompilerThread6" #11 daemon prio=9 os_prio=0 tid=0x00007f9a080e1000 nid=0x4002 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread5" #10 daemon prio=9 os_prio=0 tid=0x00007f9a080de800 nid=0x4001 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread4" #9 daemon prio=9 os_prio=0 tid=0x00007f9a080d4800 nid=0x4000 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread3" #8 daemon prio=9 os_prio=0 tid=0x00007f9a080d2000 nid=0x3fff waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread2" #7 daemon prio=9 os_prio=0 tid=0x00007f9a080d0000 nid=0x3ffe waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" #6 daemon prio=9 os_prio=0 tid=0x00007f9a080ce000 nid=0x3ffd waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" #5 daemon prio=9 os_prio=0 tid=0x00007f9a080cb000 nid=0x3ffc waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" #4 daemon prio=9 os_prio=0 tid=0x00007f9a080c9800 nid=0x3ffb runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" #3 daemon prio=8 os_prio=0 tid=0x00007f9a08096800 nid=0x3ffa in Object.wait() [0x00007f99b3ffe000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)
	- locked <0x00000000800452d0> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164)
	at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)

"Reference Handler" #2 daemon prio=10 os_prio=0 tid=0x00007f9a08092000 nid=0x3ff9 in Object.wait() [0x00007f99f4131000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	at java.lang.Object.wait(Object.java:502)
	at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
	- locked <0x0000000080065948> (a java.lang.ref.Reference$Lock)
	at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)

"main" #1 prio=5 os_prio=0 tid=0x00007f9a08009000 nid=0x3fea runnable [0x00007f9a0ed03000]
   java.lang.Thread.State: RUNNABLE
	at java.net.PlainSocketImpl.socketAccept(Native Method)
	at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:409)
	at java.net.ServerSocket.implAccept(ServerSocket.java:545)
	at java.net.ServerSocket.accept(ServerSocket.java:513)
	at org.apache.catalina.core.StandardServer.await(StandardServer.java:464)
	at org.apache.catalina.startup.Catalina.await(Catalina.java:717)
	at org.apache.catalina.startup.Catalina.start(Catalina.java:663)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:351)
	at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:485)

"VM Thread" os_prio=0 tid=0x00007f9a0808a000 nid=0x3ff8 runnable 

"GC task thread#0 (ParallelGC)" os_prio=0 tid=0x00007f9a0801e800 nid=0x3feb runnable 

"GC task thread#1 (ParallelGC)" os_prio=0 tid=0x00007f9a08020000 nid=0x3fec runnable 

"GC task thread#2 (ParallelGC)" os_prio=0 tid=0x00007f9a08022000 nid=0x3fed runnable 

"GC task thread#3 (ParallelGC)" os_prio=0 tid=0x00007f9a08024000 nid=0x3fee runnable 

"GC task thread#4 (ParallelGC)" os_prio=0 tid=0x00007f9a08025800 nid=0x3fef runnable 

"GC task thread#5 (ParallelGC)" os_prio=0 tid=0x00007f9a08027800 nid=0x3ff0 runnable 

"GC task thread#6 (ParallelGC)" os_prio=0 tid=0x00007f9a08029800 nid=0x3ff1 runnable 

"GC task thread#7 (ParallelGC)" os_prio=0 tid=0x00007f9a0802b000 nid=0x3ff2 runnable 

"GC task thread#8 (ParallelGC)" os_prio=0 tid=0x00007f9a0802d000 nid=0x3ff3 runnable 

"GC task thread#9 (ParallelGC)" os_prio=0 tid=0x00007f9a0802e800 nid=0x3ff4 runnable 

"GC task thread#10 (ParallelGC)" os_prio=0 tid=0x00007f9a08030800 nid=0x3ff5 runnable 

"GC task thread#11 (ParallelGC)" os_prio=0 tid=0x00007f9a08032800 nid=0x3ff6 runnable 

"GC task thread#12 (ParallelGC)" os_prio=0 tid=0x00007f9a08034000 nid=0x3ff7 runnable 

"VM Periodic Task Thread" os_prio=0 tid=0x00007f9a080f1000 nid=0x4009 waiting on condition 

JNI global references: 360

线程dump信息说明:

  • [T#1] 线程名字
  • daemon 表示线程是否是守护线程
  • prio 表示我们为线程设置的优先级
  • os_prio 表示的对应的操作系统线程的优先级,由于并不是所有的操作系统都支持线程优先级,所以可能会出现都置为0的情况
  • tid 是java中为这个线程的id
  • nid 是这个线程对应的操作系统本地线程id,每一个java线程都有一个对应的操作系统线程
  • wait on condition表示当前线程处于等待状态,但是并没列出具体原因
  • java.lang.Thread.State: WAITING (parking) 也是表示的处于等待状态,括号中的内容说明了导致等待的原因,例如这里的parking说明是因为调用了 LockSupport.park方法导致等待
  • java.lang.Thread.State说明:

一个Thread对象可以有多个状态,在java.lang.Thread.State中,总共定义六种状态:

1、NEW

线程刚刚被创建,也就是已经new过了,但是还没有调用start()方法,jstack命令不会列出处于此状态的线程信息

2、RUNNABLE #java.lang.Thread.State: RUNNABLE

RUNNABLE这个名字很具有欺骗性,很容易让人误以为处于这个状态的线程正在运行。事实上,这个状态只是表示,线程是可运行的。我们已经无数次提到过,一个单核CPU在同一时刻,只能运行一个线程。

3、BLOCKED # java.lang.Thread.State: BLOCKED (on object monitor)

线程处于阻塞状态,正在等待一个monitor lock。通常情况下,是因为本线程与其他线程公用了一个锁。其他在线程正在使用这个锁进入某个synchronized同步方法块或者方法,而本线程进入这个同步代码块也需要这个锁,最终导致本线程处于阻塞状态。

4、WAITING

等待状态,调用以下方法可能会导致一个线程处于等待状态:

  • Object.wait 不指定超时时间 # java.lang.Thread.State: WAITING (on object monitor)

  • Thread.join with no timeout

  • LockSupport.park #java.lang.Thread.State: WAITING (parking)

例如:对于wait()方法,一个线程处于等待状态,通常是在等待其他线程完成某个操作。本线程调用某个对象的wait()方法,其他线程处于完成之后,调用同一个对象的notify或者notifyAll()方法。Object.wait()方法只能够在同步代码块中调用。调用了wait()方法后,会释放锁。

5、TIMED_WAITING

线程等待指定的时间,对于以下方法的调用,可能会导致线程处于这个状态:

  • Thread.sleep #java.lang.Thread.State: TIMED_WAITING (sleeping)

  • Object.wait 指定超时时间 #java.lang.Thread.State: TIMED_WAITING (on object monitor)

  • Thread.join with timeout

  • LockSupport.parkNanos #java.lang.Thread.State: TIMED_WAITING (parking)

  • LockSupport.parkUntil #java.lang.Thread.State: TIMED_WAITING (parking)

6、TERMINATED

线程终止。

jstack线程dump输出状态解释

1. 线程的状态分析

2. Runnable

3. Deadlock

4. Wait on condition

5. Waiting on monitor entry和Object.wait()

6. Blocked

7. 关于concurrent的Lock

8. jstack解决CPU过高的问题

 

  • 执行jstack命令,将得到进程的堆栈信息。我一般使用jstack -l pid来得到长列表,显示其详细信息
  • 有时线程挂起的时候,需要执行jstack -F pid获取。
  • 在实际运行中,往往一次 dump的信息,还不足以确认问题。建议产生三次 dump信息,如果每次 dump都指向同一个问题,我们才确定问题的典型性。
  • 堆栈信息只是一种参考,一些正常RUNNING的线程,由于复杂网络环境和IO的影响,也是有问题的,用jstack就无法定位,需要结合对业务代码的理解。

线程的状态分析

线程的定义里,有状态:

public enum State {
        NEW,
        RUNNABLE,
        BLOCKED,
        WAITING,
        TIMED_WAITING,
        TERMINATED;
}

 

在dump 文件里,写法可能不太一样:

  • 死锁,Deadlock(重点关注)
  • 执行中,Runnable
  • 等待资源,Waiting on condition(重点关注)
  • 等待获取监视器,Waiting on monitor entry(重点关注)
  • 对象等待中,Object.wait() 或 TIMED_WAITING
  • 暂停,Suspended
  • 阻塞,Blocked(重点关注)
  • 停止,Parked

Runnable

线程正在运行中。

一般指该线程正在执行状态中,该线程占用了资源,正在处理某个请求,有可能正在传递SQL到数据库执行,有可能在对某个文件操作,有可能进行数据类型等转换。

Deadlock

"t2" prio=6 tid=0x02bcf000 nid=0xc70 waiting for monitor entry [0x02f6f000]  
   java.lang.Thread.State: BLOCKED (on object monitor)  
    at com.demo.DeadLock$2.run(DeadLock.java:40)  
    - waiting to lock <0x22a297a8> (a java.lang.Object)  
    - locked <0x22a297b0> (a java.lang.Object)  
   Locked ownable synchronizers:  
    - None    
"t1" prio=6 tid=0x02bce400 nid=0xba0 waiting for monitor entry [0x02f1f000]  
   java.lang.Thread.State: BLOCKED (on object monitor)  
    at com.demo.DeadLock$1.run(DeadLock.java:25)  
    - waiting to lock <0x22a297b0> (a java.lang.Object)  
    - locked <0x22a297a8> (a java.lang.Object)  
   Locked ownable synchronizers:  
    - None

 

上面是一个典型的死锁堆栈,t1线程lock在地址0x22a297a8,同时t2线程在waiting to lock这个地址。

更有意思的是,堆栈也记录了发生死锁的代码行数,这对我们定位问题起到很大的帮助。

Wait on condition

等待资源,或等待某个条件的发生。具体原因需结合 stacktrace来分析。

常见情况是该线程在 sleep,等待 sleep的时间到了时候,将被唤醒。

关键字:TIMED_WAITING,sleeping,parking。TIMED_WAITING可能是调用了有超时参数的wait所引起的。

parking指线程处于挂起中。


下面是一个典型的sleep引起的Wait on condition

 

"thread-1" prio=10 tid=0x00007fbe985cd000 nid=0x7bc6 waiting on condition [0x00007fbe65848000]
  java.lang.Thread.State: TIMED_WAITING (sleeping)
       at java.lang.Thread.sleep(Native Method)
       at com.xxx.MonitorManager$2.run(MonitorManager.java:124)
       at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:895)
       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:918)
       at java.lang.Thread.run(Thread.java:662)
  • 如果发现有大量的线程都在处在 Wait on condition,从线程 stack看,正等待网络读写,这可能是一个网络瓶颈的征兆。因为网络阻塞导致线程无法执行。一种情况是网络非常忙,几乎消耗了所有的带宽,仍然有大量数据等待网络读 写;另一种情况也可能是网络空闲,但由于路由等问题,导致包无法正常的到达。可以结合其他网络分析工具定位问题。如下面的堆栈,线程等待在LinkedBlockingQueue上等待数据的生成。

  • 如果堆栈信息明确是应用代码,则证明该线程正在等待资源。一般是大量读取某资源,且该资源采用了资源锁的情况下,线程进入等待状态,等待资源的读取。
"IoWaitThread" prio=6 tid=0x0000000007334800 nid=0x2b3c waiting on condition [0x000000000893f000]
   java.lang.Thread.State: WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000007d5c45850> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)
        at java.util.concurrent.LinkedBlockingDeque.takeFirst(LinkedBlockingDeque.java:440)
        at java.util.concurrent.LinkedBlockingDeque.take(LinkedBlockingDeque.java:629)
        at com.xxx.ThreadIoWaitState$IoWaitHandler2.run(ThreadIoWaitState.java:89)
        at java.lang.Thread.run(Thread.java:662)

Waiting on monitor entry和Object.wait()

意味着线程在等待进入一个临界区
Monitor是 Java中用以实现线程之间的互斥与协作的主要手段,它可以看成是对象或者 Class的锁。

每一个对象都有,也仅有一个 monitor。

  • 所有期待获得锁的线程,在锁已经被其它线程拥有的时候,这些期待获得锁的线程就进入了Object Lockentry set区域。
  • 所有曾经获得过锁,但是由于其它必要条件不满足而需要wait的时候,线程就进入了Object Lockwait set区域 。
  • wait set区域的线程获得notify/notifyAll通知的时候,随机的一个Thread(notify)或者是全部的Thread(notifyALL)从Object Lock的wait set区域进入了entry set中。
  • 在当前拥有锁的线程释放掉锁的时候,处于该Object Lockentryset区域的线程都会抢占该锁,但是只能有任意的一个Thread能取得该锁,而其他线程依然在entry set中等待下次来抢占到锁之后再执行。

看下面的堆栈,线程在等待数据库连接池返回一个可用的链接

" DB-Processor-13" daemon prio=5 tid=0x003edf98 nid=0xca waiting for monitor entry [0x000000000825f000]
java.lang.Thread.State: BLOCKED (on object monitor)
       at beans.ConnectionPool.getConnection(ConnectionPool.java:102)
       - waiting to lock <0xe0375410> (a beans.ConnectionPool)
       at xxx.getTodayCount(ServiceCnt.java:111)
       at xxx.ServiceCnt.insertCount(ServiceCnt.java:43)
"DB-Processor-14" daemon prio=5 tid=0x003edf98 nid=0xca waiting for monitor entry [0x000000000825f020]
java.lang.Thread.State: BLOCKED (on object monitor)
       at beans.ConnectionPool.getConnection(ConnectionPool.java:102)
       - waiting to lock <0xe0375410> (a beans.ConnectionPool)
       at xxx.ServiceCnt.getTodayCount(ServiceCnt.java:111)
       at xxx.ServiceCnt.insertCount(ServiceCnt.java:43)
" DB-Processor-3" daemon prio=5 tid=0x00928248 nid=0x8b waiting for monitor entry [0x000000000825d080]
java.lang.Thread.State: RUNNABLE
       at oracle.jdbc.driver.OracleConnection.isClosed(OracleConnection.java:570)
       - waiting to lock <0xe03ba2e0> (a oracle.jdbc.driver.OracleConnection)
       at beans.ConnectionPool.getConnection(ConnectionPool.java:112)
       - locked <0xe0386580> (a java.util.Vector)
       - locked <0xe0375410> (a beans.ConnectionPool)
       at xxx.Cue_1700c.GetNationList(Cue_1700c.java:66)
       at org.apache.jsp.cue_1700c_jsp._jspService(cue_1700c_jsp.java:120)

 

Blocked

线程阻塞,是指当前线程执行过程中,所需要的资源长时间等待却一直未能获取到,被容器的线程管理器标识为阻塞状态,可以理解为等待资源超时的线程。
如果线程处于Blocked状态,但是原因不清楚。可以使用jstack -m pid得到线程的mixed信息

----------------- t@13 -----------------
0xff31e8b8      ___lwp_cond_wait + 0x4
0xfea8c810      void ObjectMonitor::EnterI(Thread*) + 0x2b8
0xfeac86b8      void ObjectMonitor::enter2(Thread*) + 0x250

 

例如,以上信息表明,线程在尝试进入同步块时阻塞了。

关于concurrent的Lock

在JDK 5.0中,引入了Lock机制,从而使开发者能更灵活的开发高性能的并发多线程程序,可以替代以往JDK中的synchronizedMonitor的机制。但是,要注意的是,因为Lock类只是一个普通类,JVM无从得知Lock对象的占用情况,所以在线程DUMP中,也不会包含关于 Lock的信息,关于死锁等问题,就不如用 synchronized的编程方式容易识别。

jstack解决CPU过高的问题

第一步,找到占用cpu最高的一个线程
方法一:top -p [pid]
方法二:ps -mo spid,lwp,stime,time,%cpu -p [pid]
方法三:直接top,然后shift+h


第二步,将其转化成16进制。假使我们得到的线程号为n,接下来将它转成16进制,记为spid
方法一:echo "obase=64;n"|bc
方法二:printf 0x%x n


第三步

执行jstack -l pid| grep spid -A 100 打印后面100行分析问题

下面便是一个查找的结果

"http-8081-11" daemon prio=10 tid=0x00002aab049a1800 nid=0x52f1 in Object.wait() [0x0000000042c75000]  
   java.lang.Thread.State: WAITING (on object monitor)  
     at java.lang.Object.wait(Native Method)  
     at java.lang.Object.wait(Object.java:485)  
     at org.apache.tomcat.util.net.JIoEndpoint$Worker.await(JIoEndpoint.java:416)

 

二、可视化工具

对jvm监控的常见可视化工具,除了jdk本身提供的Jconsole和visualVm以外,还有第三方提供的jprofilter,perfino,Yourkit,Perf4j,JProbe,MAT等。这些工具都极大的丰富了我们定位以及优化jvm方式。

这些工具的使用,网上有很多教程提供,这里就不再过多介绍了。对于VisualVm来说,比较推荐使用,它除了对jvm的侵入性比较低以外,还是jdk团队自己开发的,相信以后功能会更加丰富和完善。jprofilter对于第三方监控工具,提供的功能和可视化最为完善,目前多数ide都支持其插件,对于上线前的调试以及性能调优可以配合使用。

另外对于线上dump的heap信息,应该尽量拉去到线下用于可视化工具来分析,这样分析更详细。如果对于一些紧急的问题,必须需要通过线上监控,可以采用 VisualVm的远程功能来进行,这需要使用tool.jar下的MAT功能。

 

三、应用

1、cpu飙升

在线上有时候某个时刻,可能会出现应用某个时刻突然cpu飙升的问题。对此我们应该熟悉一些指令,快速排查对应代码。

 

1.找到最耗CPU的进程

指令:top

2.找到该进程下最耗费cpu的线程

指令:top -Hp pid

3.转换进制

printf "0x%x\n" 15332

// 转换16进制(转换后为0x3be4) 

[root@newolpay-11 /]# printf "0x%x\n" 15332
0x3be4

4.过滤指定线程,打印堆栈信息

指令:
jstack pid |grep 'threadPid'  -C5 --color 

jstack 13525 |grep '0x3be4'  -C5 --color  //  打印进程堆栈 并通过线程id,过滤得到线程堆栈信息。

jstack -l 13525 | grep '0x3be4' -A 100 // 打印后面100行分析问题

 

可以看到是一个上报程序,占用过多cpu了(以上例子只为示例,本身耗费cpu并不高)

 

2、线程死锁

有时候部署场景会有线程死锁的问题发生,但又不常见。此时我们采用jstack查看下一下。

比如说我们现在已经有一个线程死锁的程序,导致某些操作waiting中

 

1.查找java进程id

指令:top 或者 jps 

 

2.查看java进程的线程快照信息

指令:jstack -l pid

从输出信息可以看到,有一个线程死锁发生,并且指出了那行代码出现的。如此可以快速排查问题。

 

3、OOM内存泄露

java堆内的OOM异常是实际应用中常见的内存溢出异常。一般我们都是先通过内存映射分析工具(比如MAT)对dump出来的堆转存快照进行分析,确认内存中对象是否出现问题。

  • 当然了出现OOM的原因有很多,并非是堆中申请资源不足一种情况。
  • 还有可能是申请太多资源没有释放,
  • 或者是频繁频繁申请,系统资源耗尽。针对这三种情况我需要一一排查。

 

OOM的三种情况:

1.申请资源(内存)过小,不够用。

2.申请资源太多,没有释放。

3.申请资源过多,资源耗尽。比如:线程过多,线程内存过大等。

 

 

1.排查申请申请资源问题。

指令:jmap -heap 11869 

查看新生代,老生代堆内存的分配大小以及使用情况,看是否本身分配过小。

从上述排查,发现程序申请的内存没有问题。

 

2.排查gc

特别是fgc情况下,各个分代内存情况。

指令:jstat -gcutil 11938 1000 每秒输出一次gc的分代内存分配情况,以及gc时间

 

3.查找最费内存的对象

指令: jmap -histo:live 11869 | more

上述输出信息中,最大内存对象才161kb,属于正常范围。如果某个对象占用空间很大,比如超过了100Mb,应该着重分析,为何没有释放。

 

注意,上述指令:

jmap -histo:live 11869 | more

执行之后,会造成jvm强制执行一次fgc,在线上不推荐使用,可以采取dump内存快照,线下采用可视化工具进行分析,更加详尽。

jmap -dump:format=b,file=/tmp/dump.dat 11869 

或者采用线上运维工具,自动化处理,方便快速定位,遗失出错时间。

4.确认资源是否耗尽

  • pstree 查看进程线程数量
  • netstat 查看网络连接数量

或者采用:

  • ll /proc/${PID}/fd | wc -l // 打开的句柄数
  • ll /proc/${PID}/task | wc -l (效果等同pstree -p | wc -l) //打开的线程数

 

以上就是一些常见的jvm命令应用。

一种工具的应用并非是万能钥匙,包治百病,问题的解决往往是需要多种工具的结合才能更好的定位问题,无论使用何种分析工具,最重要的是熟悉每种工具的优势和劣势。这样才能取长补短,配合使用。

原文链接:https://juejin.im/post/59e6c1f26fb9a0451c397a8c
 

  • 3
    点赞
  • 0
    评论
  • 12
    收藏
  • 一键三连
    一键三连
  • 扫一扫,分享海报

相关推荐
©️2020 CSDN 皮肤主题: 博客之星2020 设计师:CY__ 返回首页
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

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

余额充值