JVM 问题排查工具

更多内容,前往 IT-BLOG

Java 开发人员肯定都知道 JDK的 bin 目录中有 “java.exe”、“javac.exe” 这两个命令行工具。下面主要介绍一些监视虚拟机和故障处理的工具。

Jvm 入门工具

jpsJavaVirtual Machine Process Status Tooljps是 JDK提供的一个查看当前 Java进程的小工具。显示指定系统内所有的 HotSpot 虚拟机进程。

jps常用命令:格式为 jps [options] [hostid] ,jps 可以通过 RMI协议查询开启了 RMI服务的远程虚拟机进程状态,hostid 为 RMI 注册表中的主机名。如果不输则表示当前主机。打开命令行,敲一遍感受一下。

1 jps # 显示进程的ID 和 类的名称
2 jps –l # 输出输出完全的包名,应用主类名,jar的完全路径名 
3 jps –v # 输出jvm参数
4 jps –q # 只显示java进程号
5 jps -m # main 方法
6 jps -l xxx.xxx.xx.xx # 远程查看 

jps原理:Java程序在启动以后,会在 java.io.tmpdir指定的目录下,就是临时文件夹里,生成一个类似于 hsperfdata_User的文件夹,这个文件夹里(在 Linux中为 /tmp/hsperfdata_{userName}/),有几个文件,名字就是 java进程的pid,因此列出当前运行的 java进程,只是把这个目录里的文件名列一下而已。 至于系统的参数什么,就可以解析这几个文件获得。

jstack(Stack Trace for Java)JDK自带的线程堆栈分析工具,查看或导出 Java 应用程序中线程堆栈信息

jstack 常用命令:生成虚拟机当前时刻的线程快照。线程快照就是当前虚拟机内每一条线程正在执行的方法堆栈的集合,生成线程快照的主要目的是定位线程出现长时间停顿的原因,如线程间死锁死循环请求外部资源导致的长时间等待等都是导致线程长时间停顿的常见原因。线程出现停顿的时候通过 jstack 来查看各个线程的调用堆栈,就能知道没有响应线程在后台做些什么事情或者等待什么资源。命令格式为:jstack [option] pid

1 # 基本
2 jstack 2815
3 
4 # java和native c/c++框架的所有栈信息
5 jstack -m 2815
6 
7 # 额外的锁信息列表,查看是否死锁
8 jstack -l 2815

jstack参数:

选   项 作           用
-F

当 ’jstack [-l] pid’ 没有相应的时候强制打印栈信息

-l 除堆栈外,打印关于锁的附加信息,例如属于 java.util.concurrent 的 ownable synchronizers列表
-m 打印 java和 native c/c++框架的所有栈信息
-h -help 打印帮助信息

举个例子:jstack -l pid

 1 C:\Users\86156>jstack -l 18576
 2 "RMI Scheduler(0)" #17 daemon prio=5 os_prio=0 tid=0x000000002002a000 nid=0x3a64 waiting on condition [0x000000002184f000]
 3    java.lang.Thread.State: TIMED_WAITING (parking)
 4         at sun.misc.Unsafe.park(Native Method)
 5         - parking to wait for  <0x00000006c2c1e498> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
 6         at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
 7         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
 8         at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
 9         at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
10         at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
11         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
12         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
13         at java.lang.Thread.run(Thread.java:745)
14 
15    Locked ownable synchronizers:
16         - None

jinfo(Configuration Info for Java)jinfo 是 JDK 自带的命令,可以用来查看正在运行的 Java 应用程序的扩展参数,包括 Java System属性和 JVM命令行参数;也可以动态的修改正在运行的 JVM 一些参数。当系统崩溃时,jinfo可以从 core文件里面知道崩溃的 Java应用程序的配置信息。

jinfo常用命令:显示虚拟机配置信息

 1 # 输出当前 jvm 进程的全部参数和系统属性
 2 jinfo pid
 3 
 4 # 输出所有的参数
 5 jinfo -flags pid
 6 
 7 # 查看指定的 jvm 参数的值
 8 jinfo -flag PrintGC pid
 9 
10 # 开启/关闭指定的JVM参数
11 jinfo -flag +PrintGC pid
12 
13 # 设置flag的参数
14 jinfo -flag name=value pid
15 
16 # 输出当前 jvm 进行的全部的系统属性 System.getProperties()
17 jinfo -sysprops 2815

jinfo参数:

1 no option 输出全部的参数和系统属性
2 -flag name 输出对应名称的参数
3 -flag [+|-]name 开启或者关闭对应名称的参数
4 -flag name=value 设定对应名称的参数
5 -flags 输出全部的参数
6 -sysprops 输出系统属性

更多请参考:jvm 性能调优工具之 jinfo

jmap(Memory Map for Java)生成虚拟机内存堆转储快照 dump文件, 也可以查看堆内对象示例的统计信息、查看 ClassLoader 的信息以及 finalizer 队列

jmap常用命令:格式为 jmap [option] pid

1 # 查看堆的情况
2 jmap -heap 2815
3 
4 # dump
5 jmap -dump:live,format=b,file=/tmp/heap2.bin 2815
6 jmap -dump:format=b,file=/tmp/heap3.bin 2815
7 
8 # 查看堆的占用
9 jmap -histo 2815 | head -10

jmap参数:

1 no option: 查看进程的内存映像信息,类似 Solaris pmap 命令。
2 heap: 显示Java堆详细信息
3 histo[:live]: 显示堆中对象的统计信息
4 clstats:打印类加载器信息
5 finalizerinfo: 显示在F-Queue队列等待Finalizer线程执行finalizer方法的对象
6 dump:<dump-options>:生成堆转储快照
7 F: 当-dump没有响应时,使用-dump或者-histo参数. 在这个模式下,live子参数无效.
8 help:打印帮助信息
9 J<flag>:指定传递给运行jmap的JVM的参数

更多请参考:jvm 性能调优工具之 jmapjmap - Memory Map

jstat(JVM Statistics Monitoring Tool)用于收集 HtoSpot 虚拟机各方面的运行状态信息,可以显示类装载内存垃圾收集JIT编译等运行数据。

jstat常用命令:格式为 jstat [option vmid [interval[s | ms] [count]] ]  参数 interval 和 count 代表查询间隔和次数。如果省略说明只查询一次。假设需要没 1000毫秒查询一次进程 2815 垃圾收集等状况,一共查询 20次,命令如下:

jstat -gc 7672 1000 20

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

 举一个使用率比较高的例子:jstat -gcutil 7672

这台服务器的新生代 Eden区(E,表示 Eden)使用了 24.01%的空间,两个 Survivor 区(S0、S1,表示 Survivor0、Survivor1 )S0是空的,S1 使用了 25%的空间。老年代(O,表示Old)和元空间(M,表示 Metaspace)分别使用了 27.38% 和 94.81% 的空间。程序运行以来共发生 MinorGC(YGC,表示 Young GC)4221次,YGCT 总耗时 10.147秒,发送 Full GC(FGC)3次,FGCT总耗时 0.217秒,GGC 表示所有 GC总耗时 10.365秒。

使用 jstat 工具在纯文本状态下监视虚拟机状态的变化,确实不如 VisualVM等可视化的监视工具直接以图表展现那样直观。但许多服务器管理员都习惯在文本控制台中工作,直接在控制台使用 jstat命令依然是一种常见的监控方式。

jhat(JVM Heap Anaysis Tool):虚拟机推转储快照分析工具

jhat 命令与 jmap搭配使用,来分析 jmap生成的转储快照。但我们一般不会使用该工具。第一是一般不会在部署应用程序的服务器上直接分析 dump文件,即使可以这样做,也尽量将 dump文件复制到其他机器上进行分析,因为分析工作是一个耗时而且消耗硬件资源的过程,既然在其他机器上运行,那就没有必要受命令行工具的限制了;另一个原因是 jhat工具相对比较简陋,建议使用 VsualVM,以及专业用于分析 dump文件的工具。

Java 调试进阶工具

【1】btrace:首当其冲的要说的是btrace。真实生产环境&预发的排查问题大杀器。 查看当前谁调用了 ArrayList的 add方法,同时只打印当前 ArrayList的 size大于500的线程调用栈

 1 @OnMethod(clazz = "java.util.ArrayList", method="add", location = @Location(value = Kind.CALL, clazz = "/./", method = "/./"))
 2 public static void m(@ProbeClassName String probeClass, @ProbeMethodName String probeMethod, @TargetInstance Object instance, @TargetMethodOrField String method) {
 3 
 4     if(getInt(field("java.util.ArrayList", "size"), instance) > 479){
 5         println("check who ArrayList.add method:" + probeClass + "#" + probeMethod  + ", method:" + method + ", size:" + getInt(field("java.util.ArrayList", "size"), instance));
 6         jstack();
 7         println();
 8         println("===========================");
 9         println();
10     }
11 }

【2】监控当前服务方法被调用时返回的值以及请求的参数

1 @OnMethod(clazz = "com.taobao.sellerhome.transfer.biz.impl.C2CApplyerServiceImpl", method="nav", location = @Location(value = Kind.RETURN))
2 public static void mt(long userId, int current, int relation, String check, String redirectUrl, @Return AnyType result) {
3 
4     println("parameter# userId:" + userId + ", current:" + current + ", relation:" + relation + ", check:" + check + ", redirectUrl:" + redirectUrl + ", result:" + result);
5 }

btrace 具体可以参考这里:https://github.com/btraceio/btrace

注意:①、经过观察,1.3.9的release输出不稳定,要多触发几次才能看到正确的结果;
②、正则表达式匹配trace类时范围一定要控制,否则极有可能出现跑满CPU导致应用卡死的情况;
③、由于是字节码注入的原理,想要应用恢复到正常情况,需要重启应用。

【3】Greys:Greys是@杜琨的大作吧。说几个挺棒的功能(部分功能和btrace重合):sc -df xxx:输出当前类的详情,包括源码位置和classloader结构;trace class method: 打印出当前方法调用的耗时情况,细分到每个方法, 对排查方法性能时很有帮助。
【4】Arthas:Arthas是基于Greys。具体请参考:调试排错 - Java应用在线调试Arthas
【5】javOSize:就说一个功能:classes:通过修改了字节码,改变了类的内容,即时生效。 所以可以做到快速的在某个地方打个日志看看输出,缺点是对代码的侵入性太大。但是如果自己知道自己在干嘛,的确是不错的玩意儿。其他功能 Greys和 btrace都能很轻易做的到,不说了。更多请参考:官网
【6】JProfiler:之前判断许多问题要通过JProfiler,但是现在Greys和btrace基本都能搞定了。再加上出问题的基本上都是生产环境(网络隔离),所以基本不怎么使用了,但是还是要标记一下。更多请参考:官网

其它工具


dmesg:如果发现自己的 java进程悄无声息的消失了,几乎没有留下任何线索,那么dmesg一发,很有可能有你想要的。sudo dmesg|grep -i kill|less 去找关键字oom_killer。找到的结果类似如下:

1 [6710782.021013] java invoked oom-killer: gfp_mask=0xd0, order=0, oom_adj=0, oom_scoe_adj=0
2 [6710782.070639] [<ffffffff81118898>] ? oom_kill_process+0x68/0x140 
3 [6710782.257588] Task in /LXC011175068174 killed as a result of limit of /LXC011175068174 
4 [6710784.698347] Memory cgroup out of memory: Kill process 215701 (java) score 854 or sacrifice child 
5 [6710784.707978] Killed process 215701, UID 679, (java) total-vm:11017300kB, anon-rss:7152432kB, file-rss:1232kB

以上表明,对应的 java进程被系统的 OOM Killer给干掉了,得分为854. 解释一下 OOM killer(Out-Of-Memory killer),该机制会监控机器的内存资源消耗。当机器内存耗尽前,该机制会扫描所有的进程(按照一定规则计算,内存占用,时间等),挑选出得分最高的进程,然后杀死,从而保护机器。
dmesg日志时间转换公式:log实际时间=格林威治1970-01-01+(当前时间秒数-系统启动至今的秒数+dmesg打印的 log时间)秒数:date -d "1970-01-01 UTC echo "$(date +%s)-$(cat /proc/uptime|cut -f 1 -d' ')+12288812.926194"|bc seconds" 剩下的,就是看看为什么内存这么大,触发了 OOM-Killer了。

posted @ 2020-11-14 17:39  Java程序员进阶  阅读(31)  评论(0编辑  收藏  举报