产上我 们经常会碰到一些不好排查的问题,例如线程安全问题,用最简单的threaddump或者heapdump不好查到问题原因。为了排查这些问题,有时我们会临时加一些日志,比如在一些关键的函数里打印出入参,然后重新打包发布,如果打了日志还是没找到问题,继续加日志,重新打包发布。对于上线流程复杂而且审核比较严的公司,从改代码到上线需要层层的流转,会大大影响问题排查的进度。
这个时候我们可以使用能够在线调试的工具帮助我们查找问题,例如btrace,可以动态的插入代码,极大提高我们查找问题的效率。 本文通过生产案例介绍如何用这一类工具快速定位传统方法不好定位的问题。
问题描述
服务器在高并发的情况下cpu消耗很高,响应速度变慢,打threaddump,发现创建了大量的Timer-xxx线程,状态都是runnable,但是没有函数堆栈,也就是刚创建了还没执行。打heapdump看,还是不好发现问题,也只能看到一堆没有堆栈的线程。
查了代码,发现近期改的地方没有主动创建Timer的地方,所以大概率是第三方jar包创建的,怎么才能找到是谁创建的线程。用这种静态的分析方法已经不太好用了,因为不管是ThreadDump还是HeapDump,抓住的都是一个快照,ThreadDump主要用来看线程的状态,HeapDump主要是看内存里的东西,还可以看线程里调用链上的栈的内容(仅限于对象,基本类型看不到)。
我们要知道谁创建的线程,只要知道谁调用了Thread类的start方法即可。假如我们在ThreadDump里看到如下的stacktrace:
java.lang.Thread.start() com.xxx.SomeClass.startNewThread(); …
那我们就知道是谁创建了新线程,但是遗憾的是start方法太快,而ThreadDump很难抓到,start调用结束后就有一个新的stacktrace了。大部分情况下ThreadDump只会抓到比较慢的函数,最常见的是socket.read()这样的,还有一些需要多次循环的。
必须借助功能更强大的工具进行分析,比如Btrace,可以动态的插入字节码,可以使我们动态的在线查找问题。Btrace是比较基础的工具,需要自己写代码插入,原理就是字节码增强,或者叫Instrumentation,类似于AOP,通过插入一些代码进行调试分析,包括很多性能监控工具,也是通过这个原理进行无侵入的埋点。
Btrace和Arthas简介及使用示例
BTrace是Java的安全可靠的动态跟踪工具。它的工作原理是通过 instrument + asm 来对正在运行的java程序中的class类进行动态增强。使用Btrace时需要写btrace脚本,也就是Java代码,这些代码会被植入运行的JVM中,如果写的不好,可能会把JVM搞崩溃。
Arthas是阿里开源的一款工具,跟Btrace的原理一样,它用起来更简单,把最常用的功能都做了封装,不需要自己写代码了,使用起来比较简单,但是灵活性不如BTrace。
用Btrace举两个例子,没法用threaddump和heapdump快速定位问题的情况。
1.用btrace查看stacktrace
假如我们有以下代码,f函数会一直不停的创建Timer,而Timer会启动新线程,大量的线程导致OOM,我们需要查到是谁创建的线程。
public class Test { public static void main(String[] args) throws InterruptedException { f(); } public static void f() throws InterruptedException { for(int i = 0; i < 10000; i++) { new Timer(true); Thread.sleep(1000); } } }
打一个threaddump,没法发现f与新线程的关系。
"Timer-31" daemon prio=5 tid=0x00007fc74a894800 nid=0x6407 in Object.wait() [0x00007000017db000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000007d596be10> (a java.util.TaskQueue) at java.lang.Object.wait(Object.java:503) at java.util.TimerThread.mainLoop(Timer.java:526) - locked <0x00000007d596be10> (a java.util.TaskQueue) at java.util.TimerThread.run(Timer.java:505) Locked ownable synchronizers: - None "main" prio=5 tid=0x00007fc74a80b000 nid=0x1703 waiting on condition [0x0000700000219000] java.lang.Thread.State: TIMED_WAITING (sleeping) at java.lang.Thread.sleep(Native Method) at test.Test.f(Test.java:13) at test.Test.main(Test.java:8) Locked ownable synchronizers: - None
可以用Btrace查找是谁创建的。用Btrace需要写脚本,以下脚本就是在java.lang.Thread类的start方法被调用的时候执行onnewThread方法,打印5行堆栈。
import com.sun.btrace.annotations.*; import static com.sun.btrace.BTraceUtils.*; @BTrace public class ThreadStart { @OnMethod( clazz="java.lang.Thread", method="start" ) public static void onnewThread(@Self Thread