JVM排查工具单

jstack是jdk自带的线程堆栈分析工具使用该命令可以查看或导出 Java 应用程序中线程堆栈信息。线程快照是当前虚拟机内每一条线程上在执行的方法堆栈的集合生成线程快照的主要目的是定位线程出现长时间停顿的原因如线程间死锁、死循环、 请求外部资源导致的长时间等待等问题注意Jstack 可以直接检测死锁Jstack并不能直接检测死循环但可以通过分析线程堆栈信息间接发现死循环的存在例如线程一直处于RUNNABLE状态。CPU 使用率异常高可以通过top或pidstat等工具查看。线程的堆栈信息中会反复出现相同的函数调用。jstack常用命令:java# 基本 jstack pid jstack 2815 # java和native c/c框架的所有栈信息 jstack -m 2815 # 额外的锁信息列表查看是否死锁 jstack -l 2815pid 是需要被打印配置信息的java进程id可以用jps查询jstack参数java-l 长列表. 打印关于锁的附加信息,例如属于java.util.concurrent 的 ownable synchronizers列表. -F 当’jstack [-l] pid’没有相应的时候强制打印栈信息 -m 打印java和native c/c框架的所有栈信息. -h | -help 打印帮助信息Jstack 使用通过使用 jps 命令获取需要监控的进程的pid然后使用 jstack pid 命令查看线程的堆栈信息。通过 jstack 命令可以获取当前进程的所有线程信息。每个线程堆的信息中都可以查看到 线程ID、线程的状态wait、sleep、running 等状态、是否持有锁信息等。死锁示例下面通过一个例子来演示 jstack 检查死锁的一个例子代码如下javapublic static void deathLock() { Thread t1 new Thread() { Override public void run() { try { lock1.lock(); TimeUnit.SECONDS.sleep(1); lock2.lock(); } catch (InterruptedException e) { e.printStackTrace(); } } }; Thread t2 new Thread() { Override public void run() { try { lock2.lock(); TimeUnit.SECONDS.sleep(1); lock1.lock(); } catch (InterruptedException e) { e.printStackTrace(); } } }; t1.setName(mythread1); t2.setName(mythread2); t1.start(); t2.start(); }使用 jstack -l pid 查看线程堆栈信息发现在堆栈信息最后面检查出了一个死锁。如下图可以清楚的看出 mythread2 等待 这个锁 “0x00000000d6eb82d0”这个锁是由于mythread1线程持有。mythread1线程等待这个锁“0x00000000d6eb8300”,这个锁是由mythread2线程持有。“mythread1”线程堆栈信息如下可以看出当前线程持有“0x00000000d6eb82d0”锁等待“0x00000000d6eb8300”的锁“mythread2”线程堆栈信息如下“mythread2”的堆栈信息中可以看出当前线程持有“0x00000000d6eb8300”锁等待“0x00000000d6eb82d0”的锁。jinfojinfo 是 JDK 自带的命令可以用来查看正在运行的 java 应用程序的扩展参数包括Java System属性和JVM命令行参数也可以动态的修改正在运行的 JVM 一些参数。当系统崩溃时jinfo可以从core文件里面知道崩溃的Java应用程序的配置信息Javacore也可以称为“threaddump”或是“javadump”它是 Java 提供的一种诊断特性能够提供一份可读的当前运行的 JVM 中线程使用情况的快照。即在某个特定时刻JVM 中有哪些线程在运行每个线程执行到哪一个类哪一个方法。应用程序如果出现不可恢复的错误或是内存泄露就会自动触发 Javacore 的生成。jinfo常用命令:java# 输出当前 jvm 进程的全部参数和系统属性 jinfo 2815 # 输出所有的参数 jinfo -flags 2815 # 查看指定的 jvm 参数的值 jinfo -flag PrintGC 2815 # 开启/关闭指定的JVM参数 jinfo -flag PrintGC 2815 # 设置flag的参数 jinfo -flag namevalue 2815 # 输出当前 jvm 进行的全部的系统属性 jinfo -sysprops 2815jinfo参数javano option 输出全部的参数和系统属性 -flag name 输出对应名称的参数 -flag [|-]name 开启或者关闭对应名称的参数 -flag namevalue 设定对应名称的参数 -flags 输出全部的参数 -sysprops 输出系统属性示例一 no option命令jinfo pid描述输出当前 jvm 进程的全部参数和系统属性示例二 -flag name命令jinfo -flag name pid描述输出对应名称的参数使用该命令可以查看指定的 jvm 参数的值。如查看当前 jvm 进程是否开启打印 GC 日志。示例三-flag [|-]name命令jinfo -flag [|-]name pid描述开启或者关闭对应名称的参数使用 jinfo 可以在不重启虚拟机的情况下可以动态的修改 jvm 的参数。尤其在线上的环境特别有用。使用如下示例四-flag namevalue命令jinfo -flag namevalue pid描述修改指定参数的值。同示例三但示例三主要是针对 boolean 值的参数设置的。如果是设置 value值则需要使用 namevalue 的形式。使用如下注意事项 jinfo虽然可以在java程序运行时动态地修改虚拟机参数但并不是所有的参数都支持动态修改示例五 -flags命令jinfo -flags pid描述输出全部的参数示例六-sysprops命令jinfo -sysprops pid描述输出当前 jvm 进行的全部的系统属性jmap命令jmap是一个多功能的命令。它可以生成 java 程序的 dump 文件 也可以查看堆内对象示例的统计信息、查看 ClassLoader 的信息以及 finalizer 队列。两个用途java# 查看堆的对象分配情况 jmap -heap 2815 # dump jmap -dump:live,formatb,file/tmp/heap2.bin 2815 jmap -dump:formatb,file/tmp/heap3.bin 2815 # 查看堆的占用 jmap -histo 2815 | head -10jmap参数javano option 查看进程的内存映像信息,类似 Solaris pmap 命令。 heap 显示Java堆详细信息 histo[:live] 显示堆中对象的统计信息 clstats打印类加载器信息 finalizerinfo 显示在F-Queue队列等待Finalizer线程执行finalizer方法的对象 dump:dump-options生成堆转储快照 F 当-dump没有响应时使用-dump或者-histo参数. 在这个模式下,live子参数无效. help打印帮助信息 Jflag指定传递给运行jmap的JVM的参数示例一no option命令jmap pid描述查看进程的内存映像信息,类似 Solaris pmap 命令。使用不带选项参数的jmap打印共享对象映射将会打印目标虚拟机中加载的每个共享对象的起始地址、映射大小以及共享对象文件的路径全称。这与Solaris的pmap工具比较相似。示例二heap命令jmap -heap pid描述显示Java堆详细信息打印一个堆的摘要信息包括使用的GC算法、堆配置信息和各内存区域内存使用信息textC:\Users\jjsjmap -heap 5932 Attaching to process ID 5932, please wait... Debugger attached successfully. Server compiler detected. JVM version is 25.91-b15 using thread-local object allocation. Parallel GC with 4 thread(s) Heap Configuration: MinHeapFreeRatio 0 MaxHeapFreeRatio 100 MaxHeapSize 1073741824 (1024.0MB) NewSize 42991616 (41.0MB) MaxNewSize 357564416 (341.0MB) OldSize 87031808 (83.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 60293120 (57.5MB) used 44166744 (42.120689392089844MB) free 16126376 (15.379310607910156MB) 73.25337285580842% used From Space: capacity 5242880 (5.0MB) used 0 (0.0MB) free 5242880 (5.0MB) 0.0% used To Space: capacity 14680064 (14.0MB) used 0 (0.0MB) free 14680064 (14.0MB) 0.0% used PS Old Generation capacity 120061952 (114.5MB) used 19805592 (18.888084411621094MB) free 100256360 (95.6119155883789MB) 16.496143590935453% used 20342 interned Strings occupying 1863208 bytes.示例三histo[:live]命令jmap -histo:live pid描述显示堆中对象的统计信息其中包括每个Java类、对象数量、内存大小(单位字节)、完全限定的类名。打印的虚拟机内部的类名称将会带有一个’*’前缀。如果指定了live子选项则只计算活动的对象。示例四clstats命令jmap -clstats pid描述打印类加载器信息-clstats是-permstat的替代方案在JDK8之前-permstat用来打印类加载器的数据打印Java堆内存的永久保存区域的类加载器的智能统计信息。对于每个类加载器而言它的名称、活跃度、地址、父类加载器、它所加载的类的数量和大小都会被打印。此外包含的字符串数量和大小也会被打印。示例五finalizerinfo命令jmap -finalizerinfo pid描述打印等待终结的对象信息Number of objects pending for finalization: 0 说明当前F-QUEUE队列中并没有等待Fializer线程执行final示例六dump:dump-options命令jmap -dump:formatb,fileheapdump.phrof pid描述生成堆转储快照dump文件。以hprof二进制格式转储Java堆到指定filename的文件中。live子选项是可选的。如果指定了live子选项堆中只有活动的对象会被转储。想要浏览heap dump你可以使用jhat(Java堆分析工具)读取生成的文件。这个命令执行JVM会将整个heap的信息dump写入到一个文件heap如果比较大的话就会导致这个过程比较耗时并且执行的过程中为了保证dump的信息是可靠的所以会暂停应用 线上系统慎用。更多请参考 jmap - Memory Map注意此命令会导致虚拟机暂停工作1~3秒因此在实际生产环境中基本不使用一般情况下在出现问题时会用以下方案服务已OOM或即将OOM依赖预设的JVM参数-XX:HeapDumpOnOutOfMemoryError。这样JVM会在崩溃时自动生成Dump无需手动干预避免二次伤害。服务可用但性能劣化Arthas用它进行在线、低侵入式分析。jstat它是 JDK 自带的工县用于监控JVM 各种运行时信息jstat参数众多但是使用一个就够了javajstat -gc pid 1000 10gc选项显示垃圾收集信息(也可以用 gcutilgcutil以百分比形式显示内存的使用情况gc显示的是内存占用的字节数以KB 的形式输出堆内存的使用情况)pidJava 进程的 PID。1000每 1000 毫秒采样一次。10采样 10 次。示例输出javaS0C S1C S0U S1U EC EU OC OU MC MU CCSC CCSU YGC YGCT FGC FGCT GCT 1536.0 1536.0 0.0 0.0 30720.0 1024.0 708608.0 2048.0 44800.0 43712.6 4864.0 4096.0 4 0.072 1 0.015 0.087 1536.0 1536.0 0.0 0.0 30720.0 2048.0 708608.0 2048.0 44800.0 43712.6 4864.0 4096.0 4 0.072 1 0.015 0.087 1536.0 1536.0 0.0 0.0 30720.0 3072.0 708608.0 2048.0 44800.0 43712.6 4864.0 4096.0 4 0.072 1 0.015 0.087字段含义S0C(Survivor Space 0 Capacity):第一个 Survivor 区域的容量(字节数).S1C(Survivor Space 1 Capacity):第二个 Survivor 区域的容量(字节数)。S0U(Survivor Space 0 Utilization):第一个 Survivor 区域的使用量(字节数)S1U(Survivor Space 1 Utilization):第二个 Survivor 区域的使用量(字节数)。EC(Eden Space Capacity): Eden 区域的容量(字节数)。EU(Eden Space Utilization): Eden 区域的使用量(字节数)OC(Old Generation Capacity): 老年代的容量(字节数)OU(Old Generation Utilization): 老年代的使用量(字节数)MC(Metaspace Capacity):方法区(Metaspace)的容量(字节数)MU (Metaspace Utilization):方法区的使用量(字节数)。CCSC(Compressed Class Space Capacity): 压缩类空间的容量(字节数)CCSU(Compressed Class Space Utilization): 压缩类空间的使用量(字节数)YGC (Young Generation GC Count):年轻代垃圾回收的次数YGCT (Young Generation GC Time):年轻代垃圾回收的总时间(秒)。FGC (Full GC Count): full gc 的次数。FGCT(Full GC Time): full gc 的总时间(秒)。GCT(Garbage Collection Time): 总的垃圾回收时间(秒)。注意:如果 FGC 变化频率很高则说明系统性能和吞吐量将下降或者可能出现内存溢出。jdbjdb可以用来预发debug,假设你预发的java_home是/opt/java/远程调试端口是8000.那么javajdb -attach 8000出现以上代表jdb启动成功。后续可以进行设置断点进行调试。具体参数可见oracle官方说明jdb - The Java DebuggerCHLSDBCHLSDB感觉很多情况下可以看到更好玩的东西不详细叙述了。 查询资料听说jstack和jmap等工具就是基于它的。javajava -classpath /opt/taobao/java/lib/sa-jdi.jar sun.jvm.hotspot.CLHSDB更详细的可见R大此贴Java 调试进阶工具btrace首当其冲的要说的是btrace。真是生产环境预发的排查问题大杀器。 简介什么的就不说了。直接上代码干l 查看当前谁调用了ArrayList的add方法同时只打印当前ArrayList的size大于500的线程调用栈javaOnMethod(clazz java.util.ArrayList, methodadd, location Location(value Kind.CALL, clazz /./, method /./)) public static void m(ProbeClassName String probeClass, ProbeMethodName String probeMethod, TargetInstance Object instance, TargetMethodOrField String method) { if(getInt(field(java.util.ArrayList, size), instance) 479){ println(check who ArrayList.add method: probeClass # probeMethod , method: method , size: getInt(field(java.util.ArrayList, size), instance)); jstack(); println(); println(); println(); } }监控当前服务方法被调用时返回的值以及请求的参数javaOnMethod(clazz com.taobao.sellerhome.transfer.biz.impl.C2CApplyerServiceImpl, methodnav, location Location(value Kind.RETURN)) public static void mt(long userId, int current, int relation, String check, String redirectUrl, Return AnyType result) { println(parameter# userId: userId , current: current , relation: relation , check: check , redirectUrl: redirectUrl , result: result); }btrace 具体可以参考这里https://github.com/btraceio/btrace注意:经过观察1.3.9的release输出不稳定要多触发几次才能看到正确的结果正则表达式匹配trace类时范围一定要控制否则极有可能出现跑满CPU导致应用卡死的情况由于是字节码注入的原理想要应用恢复到正常情况需要重启应用。GreysGreys是杜琨的大作吧。说几个挺棒的功能(部分功能和btrace重合):sc -df xxx: 输出当前类的详情,包括源码位置和classloader结构trace class method: 打印出当前方法调用的耗时情况细分到每个方法, 对排查方法性能时很有帮助。ArthasArthas是基于Greys。输入 dashboard 命令按回车 enter会展示当前进程的信息按 ctrlc 可以中断执行shell$ dashboard ID NAME GROUP PRIORI STATE %CPU TIME INTERRU DAEMON 17 pool-2-thread-1 system 5 WAITIN 67 0:0 false false 27 Timer-for-arthas-dashb system 10 RUNNAB 32 0:0 false true 11 AsyncAppender-Worker-a system 9 WAITIN 0 0:0 false true 9 Attach Listener system 9 RUNNAB 0 0:0 false true 3 Finalizer system 8 WAITIN 0 0:0 false true 2 Reference Handler system 10 WAITIN 0 0:0 false true 4 Signal Dispatcher system 9 RUNNAB 0 0:0 false true 26 as-command-execute-dae system 10 TIMED_ 0 0:0 false true 13 job-timeout system 9 TIMED_ 0 0:0 false true 1 main main 5 TIMED_ 0 0:0 false false 14 nioEventLoopGroup-2-1 system 10 RUNNAB 0 0:0 false false 18 nioEventLoopGroup-2-2 system 10 RUNNAB 0 0:0 false false 23 nioEventLoopGroup-2-3 system 10 RUNNAB 0 0:0 false false 15 nioEventLoopGroup-3-1 system 10 RUNNAB 0 0:0 false false Memory used total max usage GC heap 32M 155M 1820M 1.77% gc.ps_scavenge.count 4 ps_eden_space 14M 65M 672M 2.21% gc.ps_scavenge.time(m 166 ps_survivor_space 4M 5M 5M s) ps_old_gen 12M 85M 1365M 0.91% gc.ps_marksweep.count 0 nonheap 20M 23M -1 gc.ps_marksweep.time( 0 code_cache 3M 5M 240M 1.32% ms) Runtime os.name Mac OS X os.version 10.13.4 java.version 1.8.0_162 java.home /Library/Java/JavaVir tualMachines/jdk1.8.0 _162.jdk/Contents/Hom e/jre字段含义:heap: 堆内存的使用情况used 32M: 当前堆内存使用 32MBtotal 155M: 堆内存总量为 155MB.max1820M:堆内存最大量为1820MB.usage 1.77%: 堆内存使用百分比为 1.77%ps_eden_space: 年轻代 Eden 区域的使用情况used 14M: 当前 Eden 区域使用 14MBtotal 65M: Eden 区域总量为 65MB.max 672M: Eden 区域最大量为 672MB.usage 2.21%: Eden 区域使用百分比为 2.21%。ps_survivor_space: 年轻代 Survivor 区域的使用情况。used 4M: 当前 Survivor 区域使用 4MB.total 5M: Survivor 区域总量为 5MB。max 5M: Survivor 区域最大量为 5MB。ps_old_gen: 老年代的使用情况,used 12M: 当前老年代使用12MBtotal 85M: 老年代总量为 85MB。max 1365M: 老年代最大量为1365MB.usage 0.91%: 老年代使用百分比为 0.91%nonheap: 非堆内存的使用情况。used 20M: 当前非堆内存使用 20MB.total 23M: 非堆内存总量为 23MB。code cache: 代码缓存区的使用情况used 3M: 当前代码缓存区使用 3MB.total 5M: 代码缓存区总量为 5MB。max 240M: 代码缓存区最大量为 240MB。usage 1.32%: 代码缓存区使用百分比为 1.32%。javOSize就说一个功能:classes通过修改了字节码改变了类的内容即时生效。 所以可以做到快速的在某个地方打个日志看看输出缺点是对代码的侵入性太大。但是如果自己知道自己在干嘛的确是不错的玩意儿。其他功能Greys和btrace都能很轻易做的到不说了。更多请参考官网JProfiler之前判断许多问题要通过JProfiler但是现在Greys和btrace基本都能搞定了。再加上出问题的基本上都是生产环境(网络隔离)所以基本不怎么使用了但是还是要标记一下。更多请参考官网其它工具dmesg如果发现自己的java进程悄无声息的消失了几乎没有留下任何线索那么dmesg一发很有可能有你想要的。sudo dmesg|grep -i kill|less 去找关键字oom_killer。找到的结果类似如下:java[6710782.021013] java invoked oom-killer: gfp_mask0xd0, order0, oom_adj0, oom_scoe_adj0 [6710782.070639] [ffffffff81118898] ? oom_kill_process0x68/0x140 [6710782.257588] Task in /LXC011175068174 killed as a result of limit of /LXC011175068174 [6710784.698347] Memory cgroup out of memory: Kill process 215701 (java) score 854 or sacrifice child [6710784.707978] Killed process 215701, UID 679, (java) total-vm:11017300kB, anon-rss:7152432kB, file-rss:1232kB以上表明对应的java进程被系统的OOM Killer给干掉了得分为854. 解释一下OOM killerOut-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了。JVM可视化工具JConsoleJconsole Java Monitoring and Management ConsoleJDK自带的基于JMX的可视化监视、管理工具。 官方文档可以参考这里在新窗口打开找到jconsole工具javajaotc jcmd jinfo jshell rmid jar jconsole(这里) jjs jstack rmiregistry jarsigner jdb jlink jstat serialver java jdeprscan jmap jstatd unpack200 javac jdeps jmod keytool javadoc jhsdb jps pack200 javap jimage jrunscript rmic-l 打开jconsole选择查看概述、内存、线程、类、VM概要、MBean概述内存线程类VM概要MBeanVisual VMVisualVM 是一款免费的集成了多个 JDK 命令行工具的可视化工具它能为您提供强大的分析能力对 Java 应用程序做性能分析和调优。这些功能包括生成和分析海量数据、跟踪内存泄漏、监控垃圾回收器、执行内存和 CPU 分析同时它还支持在 MBeans 上进行浏览和操作。OverviewMonitor线程SamplerVisual GCvisual gc 是 visualvm 中的图形化查看 gc 状况的插件。官方文档可以参考这里比如我在IDEA中使用visual GC 插件来看GC状况。JProfileJProfiler 是一个商业的主要用于检查和跟踪系统限于Java开发的的性能的工具。JProfiler可以通过时时的监控系统的内存使用情况随时监视垃圾回收线程运行状况等手段从而很好的监视JVM运行情况及其性能。JProfiler 是一个全功能的Java剖析工具profiler专用于分析J2SE和J2EE应用程序。它把CPU、执行绪和内存的剖析组合在一个强大的应用中。 JProfiler可提供许多IDE整合和应用服务器整合用途。JProfiler直觉式的GUI让你可以找到效能瓶颈、抓出内存漏失(memory leaks)、并解决执行绪的问题。它让你得以对heap walker作资源回收器的root analysis可以轻易找出内存漏失heap快照snapshot模式让未被参照reference的对象、稍微被参照的对象、或在终结finalization队列的对象都会被移除整合精灵以便剖析浏览器的Java外挂功能。核心组件JProfiler 包含用于采集目标 JVM 分析数据的 JProfiler agent、用于可视化分析数据的 JProfiler UI、提供各种功能的命令行工具它们之间的关系如下图所示。JProfiler agentJProfiler agent 是一个本地库它可以在 JVM 启动时通过参数-agentpath:path to native library进行加载或者在程序运行时通过JVM Attach 机制进行加载。Agent 被成功加载后会设置 JVMTI 环境监听虚拟机产生的事件如类加载、线程创建等。例如当它监听到类加载事件后会给这些类注入用于执行度量操作的字节码。JProfiler UIJProfiler UI 是一个可独立部署的组件它通过 socket 和 agent 建立连接。这意味着不论目标 JVM 运行在本地还是远端JProfiler UI 和 agent 间的通信机制都是一样的。JProfiler UI 的主要功能是展示通过 agent 采集上来的分析数据此外还可以通过它控制 agent 的采集行为将快照保存至磁盘展示保存的快照。命令行工具JProfiler 提供了一系列命令行工具以实现不同的功能。jpcontroller - 用于控制 agent 的采集行为。它通过 agent 注册的 JProfiler MBean 向 agent 传递命令。jpenable - 用于将 agent 加载到一个正在运行的 JVM 上。jpdump - 用于获取正在运行的 JVM 的堆快照。jpexport jpcompare - 用于从保存的快照中提取数据并创建 HTML 报告。运行测试运行一个SpringBoot测试工程选择attach到JVM