Example of btrace method for locating production failures

preface

Many times we need to know the details of more, but it can't be in the development of the program running all of the details are printed to the log, usually can take is to modify the code at this time, relocation, and then observed, but this method is not very good for online applications, another if one side is not good to change the code, such as references to other external package of what, is very troublesome, BTrace is one can not change the code, do not restart the application, under the condition of dynamic view the details of the program runs tools, The following article introduces the method of btrace to locate the production fault for your reference.

The phenomenon of

Some requests are slow to pass through the data access layer and cause the processing thread to block, failing to check for exceptions from monitoring.

Write the btrace script

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

Determines execution of sql and stack information greater than 10 seconds.

Compile the script DBProxyTrace.Java and make sure the script is ok.

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

Execute the script DBProxyTrace.class

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

information

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)

positioning

Block on transaction rollback.

Use jstack to step 1 for positioning.

Print the JVM stack

"$_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)

conclusion

Blocking at the oracle driver rollback action, this is actually because the oracle driver in order to ensure the serial request response at the bottom of the lock, and this channel is blocked by slow statements, so rollback is blocked.

conclusion

The above is the whole content of this article, I hope the content of this article can bring 1 definite help to your study or work, if you have any questions, you can leave a message to communicate.