调试排错 - 排查工具单

Java 调试进阶工具

btrace

首当其冲的要说的是btrace。真是生产环境&预发的排查问题大杀器。简介什么的就不说了。直接上代码干

l 查看当前谁调用了ArrayList的add方法，同时只打印当前ArrayList的size大于500的线程调用栈

@OnMethod(clazz = "java.util.ArrayList", method="add", 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();
    }
}

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

@OnMethod(clazz = "com.taobao.sellerhome.transfer.biz.impl.C2CApplyerServiceImpl", method="nav", 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导致应用卡死的情况
由于是字节码注入的原理，想要应用恢复到正常情况，需要重启应用。

Greys

Greys是@杜琨的大作吧。说几个挺棒的功能(部分功能和btrace重合):

sc -df xxx: 输出当前类的详情,包括源码位置和classloader结构
trace class method: 打印出当前方法调用的耗时情况，细分到每个方法, 对排查方法性能时很有帮助。

Arthas

Arthas是基于Greys。

输入 dashboard 命令，按回车 enter，会展示当前进程的信息，按 ctrl+c 可以中断执行

$ 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: 当前堆内存使用 32MB
otal 155M: 堆内存总量为 155MB.
max1820M:堆内存最大量为1820MB.
usage 1.77%: 堆内存使用百分比为 1.77%

ps_eden_space: 年轻代 Eden 区域的使用情况

used 14M: 当前 Eden 区域使用 14MB
total 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: 当前老年代使用12MB
total 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。找到的结果类似如下:

[6710782.021013] java invoked oom-killer: gfp_mask=0xd0, order=0, oom_adj=0, oom_scoe_adj=0
[6710782.070639] [<ffffffff81118898>] ? oom_kill_process+0x68/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 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了。

JVM可视化工具

JConsole

Jconsole （Java Monitoring and Management Console），JDK自带的基于JMX的可视化监视、管理工具。官方文档可以参考这里在新窗口打开

找到jconsole工具

jaotc        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概要

MBean

Visual VM

VisualVM 是一款免费的，集成了多个 JDK 命令行工具的可视化工具，它能为您提供强大的分析能力，对 Java 应用程序做性能分析和调优。这些功能包括生成和分析海量数据、跟踪内存泄漏、监控垃圾回收器、执行内存和 CPU 分析，同时它还支持在 MBeans 上进行浏览和操作。

Overview

Monitor

线程

Sampler

Visual GC

visual gc 是 visualvm 中的图形化查看 gc 状况的插件。官方文档可以参考这里

比如我在IDEA中使用visual GC 插件来看GC状况。

JProfile

JProfiler 是一个商业的主要用于检查和跟踪系统（限于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 agent：

JProfiler agent 是一个本地库，它可以在 JVM 启动时通过参数-agentpath:<path to native library>进行加载或者在程序运行时通过JVM Attach 机制进行加载。Agent 被成功加载后，会设置 JVMTI 环境，监听虚拟机产生的事件，如类加载、线程创建等。例如，当它监听到类加载事件后，会给这些类注入用于执行度量操作的字节码。