btrace定位生产故障

Posted 超人汪小建(seaboat)

tags:

篇首语:本文由小常识网(cha138.com)小编为大家整理,主要介绍了btrace定位生产故障相关的知识,希望对你有一定的参考价值。

现象

某些请求通过数据访问层很慢并导致处理线程阻塞,从监控中未能检查到异常。

编写btrace脚本

@BTrace
public class DBProxyTrace {

    @OnMethod(clazz = "xxx.xxx.QueryHandler", method = "query",
            location = @Location(Kind.RETURN))
    public static void trace2(String sql, @Duration long duration) {
        if (duration/1000000 > 10 * 1000) {
            com.sun.btrace.BTraceUtils.println(duration/1000000 + "ms");
            com.sun.btrace.BTraceUtils.println("this task executes more than 10s. the sql is : "
                    + sql);
            com.sun.btrace.BTraceUtils.println("jstack is : ");
            com.sun.btrace.BTraceUtils.jstack();
        }
    }
}

判断执行大于10秒的sql和堆栈信息。

编译脚本DBProxyTrace.java,确认脚本没有问题。

./bin/btracec  -cp build/ java/DBProxyTrace.java

执行脚本DBProxyTrace.class

./bin/btrace -cp build/ 17342  DBProxyTrace.class

信息

10468ms
this task executes more than 10s. the sql is : rollback
jstack is :
xxx.QueryHandler.query(QueryHandler.java:106)
xxx.net.AbstractConnection.onReadData(AbstractConnection.java:245)
xxx.net.NIOReactor$RW.run(NIOReactor.java:77)
java.lang.Thread.run(Thread.java:745)

定位

阻塞在事务回滚。

使用jstack进一步定位。

打印JVM堆栈

"$_NIOREACTOR-7-RW" prio=10 tid=0x00007f069856f000 nid=0xde1 waiting for monitor entry [0x00007f0677011000]
   java.lang.Thread.State: BLOCKED (on object monitor)
    at oracle.jdbc.driver.PhysicalConnection.rollback(PhysicalConnection.java:1167)
    - waiting to lock <0x000000068086fbc0> (a oracle.jdbc.driver.T4CConnection)

结论

阻塞在了oracle驱动rollback动作,这里其实是因为oracle驱动为了保证串行请求响应而在底层加了锁,而这个通道被慢语句塞住了,所以rollback塞了。

以上是关于btrace定位生产故障的主要内容,如果未能解决你的问题,请参考以下文章

利用jvisualvm使用btrace进行线上调试案例

Btrace入门到熟练小工完全指南

性能工具之Java调试工具BTrace入门

快速定位自动化脚本故障?只需学会这个!

生产环境CPU过高问题定位

[转]生产环境中程序占用cpu过高的程序的排查办法