java

使用jdk常用工具排查故障流程

2021-01-27  本文已影响0人  修行者12138

基本流程

jps定位进程
jstat统计堆信息
jstack定位问题线程
jmap定位问题对象

jps

jps用于查看服务器当前有哪些java进程,排查问题时,一般先使用jps定位到pid
-l参数可以打印完整类路径或jar包路径,-v参数可以打印启动参数
备注: ps -ef | grep java 可以打印启动参数和jar路径,但打印不了类路径

sh-4.2
# jps -l
1 /home/adms_app.jar
2098 sun.tools.jps.Jps

jstat

jstat用于统计堆各区域的使用情况等信息

下图中,jstat -gc 1 1000 5命令表示每1000ms打印一次pid为1的进程的堆的信息,共打印5次。
S0C表示S0的capacity,即总容量,S0U表示S0的used,即已使用空间,单位为kb,U/C可以得到使用率,如MU/MC = 元空间使用率。
E、O、M分别表示Eden区、老年代、元空间,YGC/YGCT表示YGC的GC次数/GC时间,FGC/FGCT表示FGC的GC次数/GC时间。

sh-4.2# jstat -gc 1 1000 5
 S0C    S1C      S0U    S1U      EC       EU        OC         OU       MC       MU      CCSC     CCSU     YGC     YGCT    FGC    FGCT     GCT
68096.0 68096.0  0.0   17619.1 545344.0 31013.4  5609920.0  1641632.2  108988.0 106255.3 12508.0 11906.6     67    9.386   6      0.228    9.615
68096.0 68096.0  0.0   17619.1 545344.0 31015.5  5609920.0  1641632.2  108988.0 106255.3 12508.0 11906.6     67    9.386   6      0.228    9.615
68096.0 68096.0  0.0   17619.1 545344.0 31153.6  5609920.0  1641632.2  108988.0 106255.3 12508.0 11906.6     67    9.386   6      0.228    9.615
68096.0 68096.0  0.0   17619.1 545344.0 31181.7  5609920.0  1641632.2  108988.0 106255.3 12508.0 11906.6     67    9.386   6      0.228    9.615
68096.0 68096.0  0.0   17619.1 545344.0 31181.7  5609920.0  1641632.2  108988.0 106255.3 12508.0 11906.6     67    9.386   6      0.228    9.615
sh-4.2# jstat -gcutil 1 1000 5
 S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT
 0.00  25.87  11.57  29.26  97.49  95.19     67    9.386     6    0.228    9.615
 0.00  25.87  11.57  29.26  97.49  95.19     67    9.386     6    0.228    9.615
 0.00  25.87  11.57  29.26  97.49  95.19     67    9.386     6    0.228    9.615
 0.00  25.87  11.69  29.26  97.49  95.19     67    9.386     6    0.228    9.615
 0.00  25.87  11.69  29.26  97.49  95.19     67    9.386     6    0.228    9.615

-gc参数显示具体数值,-gcutil展示比例

jstack

jstack用于查看某个进程内的线程信息,常用于排查cpu问题

使用jstack时,一般步骤如下
步骤1,用top -Hp pid查看pid进程内的线程的cpu占比,按cpu使用率从大到小排序。
本步骤需要着重观察的是: cpu占比较高的线程,以及cpu运行时间(即TIME+列)较长的线程

topHp.png

这里有一个问题,cpu多高算高?
假设有一个4核的cpu,一个核跑满是100%,整个cpu最高跑到400%。
如果有一个线程死循环(while true),cpu一般能到90%+,到不了100%是因为即使是while true,还是会有时间片轮转。

另外,cpu运行时间也是一个很重要的指标,上图中,pid为71的线程,跑了2小时18分钟,肯定有问题。

步骤2,把当前线程信息导出thread dump文件

sh-4.2# jstack -l 1 > 1.tdump

步骤3,根据上一步找到的问题线程的pid,把pid转成16进制,因为thread dump文件中,线程pid是用16进制表示的

sh-4.2# printf "%x\n" 71
47

步骤4,在thread dump文件中检索上一步算出的线程pid的16进制,一般看后20行,能看到完整调用栈即可

sh-4.2# grep 0x47 1.tdump -A20
"KafkaConsumerExample" #51 prio=5 os_prio=0 tid=0x00007f87d4539800 nid=0x47 runnable [0x00007f86cfcfd000]
   java.lang.Thread.State: RUNNABLE
        at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
        at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
        at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79)
        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
        - locked <0x00000000c29af7f0> (a sun.nio.ch.Util$2)
        - locked <0x00000000c29af808> (a java.util.Collections$UnmodifiableSet)
        - locked <0x00000000c297fbe8> (a sun.nio.ch.EPollSelectorImpl)
        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
        at org.apache.kafka.common.network.Selector.select(Selector.java:700)
        at org.apache.kafka.common.network.Selector.poll(Selector.java:422)
        at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:460)
        at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:261)
        at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:233)
        at org.apache.kafka.clients.consumer.KafkaConsumer.pollOnce(KafkaConsumer.java:1172)
        at org.apache.kafka.clients.consumer.KafkaConsumer.poll(KafkaConsumer.java:1116)
        at com.xxx.service.HkKafkaConsumer.doWork(HkKafkaConsumer.java:107)
        at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:82)

可以看到,该线程是kafka消费者线程

注意: 开发时,线程名一定要定好,能对应具体业务,这样用jstack的时候,可以根据线程名马上定位到具体业务。

另外,Thread类的getAllStackTraces方法可以获取当前虚拟机所有线程的调用栈,如果开发人员不方便上生产,可以用该api暴露接口。

jmap

jmap用于查看某个进程的对象信息,常用于排查内存问题

jmap -dump:live,format=b,file=/root/1.hprof 1把堆的内容打印到文件,live参数表示只输出活的对象。
备注:
heap dump文件的大小与当前堆使用量的大小一致,假如堆使用量为2G,heap dump文件就有2G,导出heap dump文件需要很长的时间,导出过程可能会影响对外服务。
另外,heap dump文件只有用专业的工具(如jhat、jvisualvm、mat)才能看,无法用grep等命令检索。
综上,一般很少在生产环境使用该命令。

sh-4.2# jmap -dump:live,format=b,file=/root/1.hprof 1
Dumping heap to /root/1.hprof ...
Heap dump file created

jmap -histo:live pid统计类实例数以及字节数。
一般用jmap -histo:live pid | grep packge检查是否内存泄漏,page为java项目的包名

sh-4.2# jmap -histo:live 1 | head -n 10

 num     #instances         #bytes  class name
----------------------------------------------
   1:        285471       28159520  [C
   2:        109772        9659936  java.lang.reflect.Method
   3:          9392        8411512  [B
   4:        283248        6797952  java.lang.String
   5:         78183        5158160  [Ljava.lang.Object;
   6:        145353        4651296  java.util.concurrent.ConcurrentHashMap$Node
   7:         93898        3755920  java.util.LinkedHashMap$Entry

jmap -J-D64 -heap 1打印heap的概要信息

sh-4.2#  jmap -J-D64 -heap 1
Attaching to process ID 1, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.73-b02

using parallel threads in the new generation.
using thread-local object allocation.
Concurrent Mark-Sweep GC

Heap Configuration:
   MinHeapFreeRatio         = 40
   MaxHeapFreeRatio         = 70
   MaxHeapSize              = 6442450944 (6144.0MB)
   NewSize                  = 697892864 (665.5625MB)
   MaxNewSize               = 697892864 (665.5625MB)
   OldSize                  = 5744558080 (5478.4375MB)
   NewRatio                 = 2
   SurvivorRatio            = 8
   MetaspaceSize            = 21807104 (20.796875MB)
   CompressedClassSpaceSize = 1073741824 (1024.0MB)
   MaxMetaspaceSize         = 17592186044415 MB
   G1HeapRegionSize         = 0 (0.0MB)

Heap Usage:
New Generation (Eden + 1 Survivor Space):
   capacity = 628162560 (599.0625MB)
   used     = 292043832 (278.5147018432617MB)
   free     = 336118728 (320.5477981567383MB)
   46.491760349422925% used
Eden Space:
   capacity = 558432256 (532.5625MB)
   used     = 272566632 (259.9397964477539MB)
   free     = 285865624 (272.6227035522461MB)
   48.80925646243472% used
From Space:
   capacity = 69730304 (66.5MB)
   used     = 19477200 (18.574905395507812MB)
   free     = 50253104 (47.92509460449219MB)
   27.932188564673403% used
To Space:
   capacity = 69730304 (66.5MB)
   used     = 0 (0.0MB)
   free     = 69730304 (66.5MB)
   0.0% used
concurrent mark-sweep generation:
   capacity = 5744558080 (5478.4375MB)
   used     = 1681031336 (1603.1564102172852MB)
   free     = 4063526744 (3875.281089782715MB)
   29.263022718015588% used

51598 interned Strings occupying 5488888 bytes.

总结

按上面的步骤,一般可以定位到问题,但是比较困难,需要在短时间内做大量操作,因此,推荐使用阿里的arthas

上一篇下一篇

猜你喜欢

热点阅读