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

更新時間：2017年02月13日 14:09:41 投稿：daisy

這篇文章主要介紹了btrace定位生產故障的方法示例，文中通過示例代碼介紹的很詳細，相信對大家具有一定的參考價值，需要的朋友們下面來一起看看吧。

前言

很多時候我們需要知道更多的程序的運行細節(jié)，但又不可能在開發(fā)的時候就把程序中所有的運行細節(jié)都打印到日志上，通常這個時候能采取的就是修改代碼，重新部署，然后再觀察，但這種方法對于online應用來說不是很好，另外一方面如果碰到不好改的代碼，例如引用的其他的外部的包什么的，就很麻煩了，BTrace就是一個可以在不改代碼、不重啟應用的情況下，動態(tài)的查看程序運行細節(jié)的工具，下面這篇文章就介紹了btrace定位生產故障的方法，需要的朋友們可以參考借鑒。

現象

某些請求通過數據訪問層很慢并導致處理線程阻塞，從監(jiān)控中未能檢查到異常。

編寫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();
 }
 }
}

判斷執(zhí)行大于10秒的sql和堆棧信息。

編譯腳本DBProxyTrace.Java，確認腳本沒有問題。

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

執(zhí)行腳本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塞了。

總結

以上就是這篇文章的全部內容了，希望本文的內容對大家的學習或者工作能帶來一定的幫助，如果有疑問大家可以留言交流。