The introduction
When we do problem analysis on Java applications, we often use log to locate and analyze problems. But what if our log lacks relevant information? Remote debugging will affect the normal operation of the application, modify the code to redeploy the application, real-time and flexibility is difficult to ensure, is there a flexible and non-invasive method without affecting the normal operation of the application?
The answer is yes, it is a Java artifact -BTrace
What is BTrace?
BTrace uses Java Attach technology, which allows us to seamlessly Attach our BTrace script to the JVM. You can retrieve any data you want from the script, which is very secure and invasive, especially for locating online problems.
BTrace principle
BTrace is based on dynamic bytecode modification technology (Hotswap) to inject trace code into the bytecode of the target program.
Install the configuration
For the installation, configuration and use of BTrace, I will not repeat the wheel here, there are too many tutorials online.
Official website: github.com/btraceio/bt…
Matters needing attention
Production environment can be used, but the bytecode modification will not be restored, using Btrace, need to make sure tracking action is read-only (i.e., the tracking can not change the state of an object program) and limited behavior (i.e., the tracking needs for a limited time to terminate), a tracking behavior need to meet the following limits:
Cannot create a new object
Cannot create a new array
Cannot throw an exception
Unable to catch exceptions
No instance or static method calls – only methods declared from public static methods in BTraceUtils or in the current script can be called by BTrace
There can be no external, internal, nested, or native classes
There cannot be synchronized blocks or synchronized methods
No loops (for, while, do.. While)
Cannot inherit abstract classes (parent must be java.lang.object)
Unable to implement interface
There can be no assertion statements
There can be no class reserved word
These restrictions can be bypassed by using the Unsafe mode. Both tracing scripts and engines must be set to unsafe mode. The script needs to use the annotation @btrace (unsafe=true), The BTrace script in the bin directory of the BTrace installation directory needs to be modified to change -dcom.sun.btrace. unsafe=false to -dcom.sun.
Note: With unsafe, if your application has been traced by BTrace, the unsafe setting will remain relevant for the entire life of the process. If you change the Unsafe setting, you will need to restart the target process to get the desired result. If your application cannot be restarted at will, decide which mode to use to start the engine before using the bTrace final process for the first time.
Use the sample
Intercepting a normal method
The control method
@GetMapping(value = “/arg1”) public String arg1(@RequestParam(“name”) String name) throws InterruptedException { Thread.sleep(2000); return “7DGroup,” + name; } 1. 2. 3.
BTrace scripts
/ @btracePublic class PrintArgSimple {@onMethod (// class name clazz = “Com. Techstar. Monitordemo. Controller. UserController”, / / the method name method = “arg1, / / intercept moments: Public static void anyRead(@probeclassName String PCN, @probeclassName String PCN, @ProbeMethodName String pmn, AnyType[] args) { BTraceUtils.printArray(args); BTraceUtils.println(pcn + “,” + pmn); BTraceUtils.println(); 1. 2. 3. 5. 6. 7. 8.
Interception result:
192:Btrace apple The JPS – l3695889 / Users/apple/Downloads/performance/apache – jmeter – 4.0 / bin/ApacheJMeter jar25922sun. View the JPS. Jps23011org jetb rains.idea.maven.server.RemoteMavenServer25914org.jetbrains.jps.cmdline.Launcher25915com.techstar.monitordemo.Monitordem oApplication192:Btraceapple jps -l369 5889 / Users/apple/Downloads/performance/apache – jmeter – 4.0 / bin/ApacheJMeter jar25922 sun. View the JPS. Jps23011 org.jetbrains.idea.maven.server.RemoteMavenServer25914 org.jetbrains.jps.cmdline.Launcher25915 com.techstar.monitordemo.MonitordemoApplication192:Btrace Applejps – l3695889 / Users/apple/Downloads/performance/apache – jmeter – 4.0 / bin/ApacheJMeter jar25922sun. View the JPS. Jps23011org .jetbrains.idea.maven.server.RemoteMavenServer25914org.jetbrains.jps.cmdline.Launcher25915com.techstar.monitordemo.Monit ordemoApplication192:Btraceapple btrace 25915 PrintArgSimple.java [zuozewei, ]com.techstar.monitordemo.controller.UserController,arg1[zee, ]com.techstar.monitordemo.controller.UserController,arg1 1.
Intercepting constructor
The constructor
@Datapublic class User { private int id; private String name;} 1.
The control method
@GetMapping(value = “/arg2”) public User arg2(User user) { return user; 1}.
BTrace scripts
/ * * * to intercept the constructor * / @ BTracepublic class PrintConstructor {@ OnMethod (clazz = “com. Techstar. Monitordemo. Domain. The User”. method = “”) public static void anyRead(@ProbeClassName String pcn, @ProbeMethodName String pmn, AnyType[] args) { BTraceUtils.println(pcn + “,” + pmn); BTraceUtils.printArray(args); BTraceUtils.println(); 1}}.
Intercept the results
192:Btrace apple$ btrace 34119 PrintConstructor.java com.techstar.monitordemo.domain.User,[1, zuozewei, ] 1.
Intercepts functions with the same name as arguments
The control method
@GetMapping(value = “/same1”) public String same(@RequestParam(“name”) String name) { return “7DGroup,” + name; } @GetMapping(value = “/same2”) public String same(@RequestParam(“id”) int id, @RequestParam(“name”) String name) { return “7DGroup,” + name + “,” + id; 1}.
BTrace scripts
/** * intercepts the function of the same name, Through the input parameters to distinguish * / @ BTracepublic class PrintSame {@ OnMethod (clazz = “com. Techstar. Monitordemo. Controller. UserController”, method = “same”) public static void anyRead(@ProbeClassName String pcn, @ProbeMethodName String pmn, String name) { BTraceUtils.println(pcn + “,” + pmn + “,” + name); BTraceUtils.println(); 1}}.
Intercept the results
192:Btrace apple The JPS – l3695889 / Users/apple/Downloads/performance/apache – jmeter – 4.0 / bin/ApacheJMeter jar34281sun. View the JPS. Jps34220org jetb rains.jps.cmdline.Launcher34221com.techstar.monitordemo.MonitordemoApplication192:Btraceapple jps -l369 5889 / Users/apple/Downloads/performance/apache – jmeter – 4.0 / bin/ApacheJMeter jar34281 sun. View the JPS. Jps34220 org.jetbrains.jps.cmdline.Launcher34221 com.techstar.monitordemo.MonitordemoApplication192:Btrace Applejps – l3695889 / Users/apple/Downloads/performance/apache – jmeter – 4.0 / bin/ApacheJMeter jar34281sun. View the JPS. Jps34220org .jetbrains.jps.cmdline.Launcher34221com.techstar.monitordemo.MonitordemoApplication192:Btraceapple btrace 34221 PrintSame.java com.techstar.monitordemo.controller.UserController,same,zuozeweicom.techstar.monitordemo.controller.UserController,same, zuozeweicom.techstar.monitordemo.controller.UserController,same,zuozewei 1.
Intercepting method return value
BTrace scripts
/ interception return value * * * * / @ BTracepublic class PrintReturn {@ OnMethod (clazz = “com. Techstar. Monitordemo. Controller. UserController”, Method = “arg1”, // intercept time: Location = @location (kind. RETURN)) public static void anyRead(@probeclassName String PCN, @ProbeMethodName String pmn, @Return AnyType result) { BTraceUtils.println(pcn + “,” + pmn + “,” + result); BTraceUtils.println(); 1}}.
Intercept the results
192:Btrace apple The JPS – l34528org. Jetbrains. The JPS. Cmdline. Launcher34529com. Techstar. Monitordemo. MonitordemoApplication3695889 / Users/apple/Down Loads/performance/apache – jmeter – 4.0 / bin/ApacheJMeter jar34533sun. View the JPS. Jps192: Btraceapple JPS – l34528 org.jetbrains.jps.cmdline.Launcher34529 com.techstar.monitordemo.MonitordemoApplication369 5889 / Users/apple/Downloads/performance/apache – jmeter – 4.0 / bin/ApacheJMeter jar34533 sun. View the JPS. Jps192: Btrace Applejps – l34528org. Jetbrains. The JPS. Cmdline. Launcher34529com. Techstar. Monitordemo. MonitordemoApplication3695889 / Users/apple / Downloads/performance/apache – jmeter – 4.0 / bin/ApacheJMeter jar34533sun. View the JPS. Jps192: Btraceapple btrace 34529 PrintReturn. Java com. Techstar. Monitordemo. Controller. UserController, arg1, 7 dgroup zuozewei 1.
Abnormal analysis
Sometimes, some important exceptions are eaten by the developer because of unreasonable exception processing. In addition, there is no log or the log is not detailed, which makes it difficult for performance analysis to locate the problem. We can use BTrace to solve the problem
The control method
@GetMapping(value = “/exception”) public String exception() { try { System.out.println(“start…” ); System.out.println(1 / 0); System.out.println(“end…”) ); } catch (Exception e) {} return “successful…” ; 1}.
BTrace scripts
/** * Sometimes exceptions are eaten and the log is not printed. This example demonstrates printing stack trace * of an exception and thread local variables. This * trace script prints exception stack trace whenever * java.lang.Throwable’s constructor returns. This way * you can trace all exceptions that may be caught and * “eaten” silently by the traced program. Note that the * assumption is that the exceptions are thrown soon after * creation [like in “throw new FooException();”] rather * that be stored and thrown later. */@BTracepublic class PrintOnThrow { // store current exception in a thread local // variable (@TLS annotation). Note that we can’t // store it in a global variable! @TLS static Throwable currentException; // introduce probe into every constructor of java.lang.Throwable // class and store “this” in the thread local variable. @OnMethod(clazz = “java.lang.Throwable”, method = “”) public static void onthrow(@Self Throwable self) { currentException = self; } @OnMethod(clazz = “java.lang.Throwable”, method = “”) public static void onthrow1(@Self Throwable self, String s) { currentException = self; } @OnMethod(clazz = “java.lang.Throwable”, method = “”) public static void onthrow1(@Self Throwable self, String s, Throwable cause) { currentException = self; } @OnMethod(clazz = “java.lang.Throwable”, method = “”) public static void onthrow2(@Self Throwable self, Throwable cause) { currentException = self; } // when any constructor of java.lang.Throwable returns // print the currentException’s stack trace. @OnMethod(clazz = “java.lang.Throwable”, method = “”, location = @Location(Kind.RETURN)) public static void onthrowreturn() { if (currentException ! = null) { Threads.jstack(currentException); BTraceUtils.println(“=====================”); currentException = null; 1}}}.
Intercept the results
192:Btrace apple
btrace 34667 PrintOnThrow.java java.lang.ClassNotFoundException: org.apache.catalina.webresources.WarResourceSet java.net.URLClassLoader.findClass(URLClassLoader.java:381) java.lang.ClassLoader.loadClass(ClassLoader.java:424) java.lang.ClassLoader.loadClass(ClassLoader.java:411) sun.misc.Launcher
ConnectionHandler.process(AbstractProtocol.java:800) org.apache.tomcat.util.net.NioEndpoint
Worker.run(ThreadPoolExecutor.java:624) org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) java.lang.Thread.run(Thread.java:748)=====================… 1.
Locate a function that exceeds a threshold
BTrace scripts
** * A program that detects whether the execution time of a method under a package path exceeds a certain threshold, and prints stack information for the current thread if the threshold is exceeded. /import com.sun.btrace.BTraceUtils; import com.sun.btrace.annotations.; import static com.sun.btrace.BTraceUtils.; @BTracepublic class PrintDurationTracer { @OnMethod(clazz = “/com\.techstar\.monitordemo\.. /”, method = “/.*/”, location = @Location(Kind.RETURN)) public static void trace(@ProbeClassName String pcn, @ProbeMethodName String pmn, @duration long Duration) {// Duration is in nanoseconds if (Duration > 1000 * 1000 * 2) { BTraceUtils.println(Strings.strcat(Strings.strcat(pcn, “.”), pmn)); BTraceUtils. Print (” time: “); BTraceUtils.print(duration); Btraceutils.println (” nanosecond, stack as follows “); jstack(); 1}}}.
Intercept the results
192:Btrace apple$ btrace 39644 PrintDurationTracer.java com.techstar.monitordemo.controller.Adder.execute Time: 1715294657 nanoseconds, stack information below com. Techstar. Monitordemo. Controller. The Adder. Execute (Adder. Java: 13) com. Techstar. Monitordemo. Controlle r.Main.main(Main.java:10)com.techstar.monitordemo.controller.Adder.execute Time: 893795666 nanoseconds, stack information below com. Techstar. Monitordemo. Controller. The Adder. Execute (Adder. Java: 13) com. Techstar. Monitordemo. Controller .Main.main(Main.java:10)com.techstar.monitordemo.controller.Adder.execute Time: 1331363658 nanoseconds, stack information below com. Techstar. Monitordemo. Controller. The Adder. Execute (Adder. Java: 13) 1.
Trace method execution time
BTrace scripts
/** * Tracks the execution time of a method, just like AOP. */@BTracepublic class PrintExecuteTimeTracer { @TLS static long beginTime; @OnMethod(clazz = “com.techstar.monitordemo.controller.Adder”, method = “execute”) public static void traceExecuteBegin() { beginTime = timeMillis(); } @OnMethod(clazz = “com.techstar.monitordemo.controller.Adder”, method = “execute”, location = @Location(Kind.RETURN)) public static void traceExecute(int arg1, int arg2, @return int result {btraceutils. println(strcat(strcat(” adder.execute time :”, STR (timeMillis() -begintime)), “ms”)); Println (strcat(” return result :”, STR (result))); 1}}.
Intercept the results
192: Btrace apple $40863 PrintExecuteTimeTracer Btrace. Java Adder. Execute time: 803 ms to return the result as follows: 797 Adder. Execute Execute time :788ms the result is 784 adder. execute time :1524ms the result is 1521 adder. execute time :1775ms 1.
Performance analysis
It is often found that a service is slow during pressure testing, but because the service has a lot of business logic and method composition, it is difficult to determine exactly where the slowness is. BTrace can solve this problem by roughly locating where the problem might exist, using packet path fuzzy matching to find the problem.
BTrace scripts
/** * * Description: * This script demonstrates new capabilities built into BTrace 1.2 * When omitting “public” identifier in the class * definition one can safely omit all other modifiers when declaring methods * and variables * Extended syntax for @ProbeMethodName annotation – you can use * parameter to request a fully qualified method name instead of * the short one * Profiling support – you can use {@linkplain Profiler} instance to gather * performance data with the smallest overhead possible /@BTraceclass Profiling { @Property Profiler profiler = BTraceUtils.Profiling.newProfiler(); @OnMethod(clazz = “/com\.techstar\.. / “, method = “/./”) void entry(@ProbeMethodName(fqn = true) String probeMethod) { BTraceUtils.Profiling.recordEntry(profiler, probeMethod); } @OnMethod(clazz = “/com\.techstar\.. /”, method = “/.*/”, location = @Location(value = Kind.RETURN)) void exit(@ProbeMethodName(fqn = true) String probeMethod, @Duration long duration) { BTraceUtils.Profiling.recordExit(profiler, probeMethod, duration); } @OnTimer(5000) void timer() { BTraceUtils.Profiling.printSnapshot(“Performance profile”, profiler); 1}.
Deadlock screening
We doubt whether the program has a deadlock, can be traced through the following script scan, very simple and convenient.
/** * This BTrace program demonstrates deadlocks * built-in function. This example prints * deadlocks (if any) once every 4 seconds. */@BTracepublic class PrintDeadlock { @OnTimer(4000) public static void print() { deadlocks(); 1}}.
summary
BTrace is an after-the-fact tool. The so-called after-the-fact tool is to use BTrace to dynamically trace the analysis after the service has been live or tested, but there is a problem.
For example, which methods execute too slowly, such as monitoring methods that take more than 1 second to execute;
See which methods call system.gc() and what the call stack looks like;
View the parameters and properties of the method
Which methods are abnormal
.
In a word, here are only some frequently used examples to draw inspiration from others, and there are many others that are not listed. You can refer to other official samples to play.