btrace method to locate production faults

Preface

Many times we need to know more details about the running of the program, but it is impossible to print all the running details in the program during development. Go to the log. Usually what you can do at this time is to modify the code, redeploy, and then observe again. However, this method is not very good for online applications. On the other hand, if you encounter code that is difficult to change, such as other referenced External packages and so on are very troublesome. BTrace is a tool that can dynamically view program running details without changing the code or restarting the application. The following article introduces the method of btrace to locate production faults. , friends in need can refer to it.

Phenomena

Some requests are very slow through the data access layer and cause the processing thread to be blocked, and the exception cannot be detected from the monitoring.

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

Judge the SQL and stack information that is executed for more than 10 seconds.

Compile the script DBProxyTrace.Java and confirm that there is no problem with the script.

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

Execute 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)

Location

Blocked in transaction rollback.

Use jstack for further positioning.

Print 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

Blocked The oracle driver rollback action is actually because the oracle driver adds a lock on the bottom layer to ensure the serial request response, and this channel is blocked by slow statements, so the rollback is blocked.

For more articles related to btrace’s method of locating production faults, please pay attention to the PHP Chinese website!