前言
很多時候我們需要知道更多的程序的運行細節，但又不可能在開發的時候就把程序中所有的運行細節都打印到日志上，通常這個時候能采取的就是修改代碼，重新部署，然后再觀察，但這種方法對于online應用來說不是很好，另外一方面如果碰到不好改的代碼，例如引用的其他的外部的包什么的，就很麻煩了，BTrace就是一個可以在不改代碼、不重啟應用的情況下，動態的查看程序運行細節的工具，下面這篇文章就介紹了btrace定位生產故障的方法，需要的朋友們可以參考借鑒。
現象
某些請求通過數據訪問層很慢并導致處理線程阻塞，從監控中未能檢查到異常。
編寫btrace腳本
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
|
@BTracepublic 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，確認腳本沒有問題。
|
1
|
./bin/btracec -cp build/ java/DBProxyTrace.java |
執行腳本DBProxyTrace.class
|
1
|
./bin/btrace -cp build/ 17342 DBProxyTrace.class |
信息
|
1
2
3
4
5
6
7
|
10468msthis task executes more than 10s. the sql is : rollbackjstack 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堆棧
|
1
2
3
4
|
"$_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塞了。
總結
以上就是這篇文章的全部內容了，希望本文的內容對大家的學習或者工作能帶來一定的幫助，如果有疑問大家可以留言交流。
