btrace定位生产故障的方法示例

前言

很多时候我们需要知道更多的程序的运行细节，但又不可能在开发的时候就把程序中所有的运行细节都打印到日志上，通常这个时候能采取的就是修改代码，重新部署，然后再观察，但这种方法对于online应用来说不是很好，另外一方面如果碰到不好改的代码，例如引用的其他的外部的包什么的，就很麻烦了，btrace就是一个可以在不改代码、不重启应用的情况下，动态的查看程序运行细节的工具，下面这篇文章就介绍了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塞了。

总结

以上就是这篇文章的全部内容了，希望本文的内容对大家的学习或者工作能带来一定的帮助，如果有疑问大家可以留言交流。