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?
And the answer is yes, it’s 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:
You can’t create new objects you can’t create new arrays you can’t throw exceptions you can’t catch exceptions you can’t call instances or static methods – only methods declared from public static methods in BTraceUtils or in the current script can be called by BTrace you can’t have external, internal, Nested or local classes cannot have synchronized blocks or synchronized methods cannot have loops (for, while, do.. While you cannot inherit abstract classes (the parent must be java.lang.object) you cannot implement interfaces you cannot have assertion statements you cannot have class reserved words. The above restrictions can be circumvented through 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 ;
} BTrace script
/ * *
- Intercept the sample
*/ @BTrace public
class
PrintArgSimple
{
@OnMethod (
/ / the name of the class clazz
“com.techstar.monitordemo.controller.UserController” ,
// The method name is method
“arg1” ,
// Intercept time: entry location
@Location ( Kind . ENTRY ))
/** * Interceptor class name and method name */
public
static
void anyRead ( @ProbeClassName
String pcn ,
@ProbeMethodName
String pmn ,
AnyType [] args )
{
BTraceUtils . printArray ( args );
BTraceUtils . println ( pcn +
“,”
pmn );
BTraceUtils . println ();
}} Interception result:
192 : Btrace apple$ jps
l 369
5889
/ Users / apple / Downloads / performance / apache
jmeter
4.0 / bin/apacheJmeter.jar 25922 sun.tools.jps.jps 23011 org.jetBrains.idea.maven.server. RemoteMavenServer 25914 org . jetbrains . jps . cmdline . Launcher 25915 com . techstar . monitordemo . MonitordemoApplication 192 : Btrace apple$ btrace 25915
PrintArgSimple . java [ zuozewei ,
] com . techstar . monitordemo . controller . UserController , arg1 [ zee ,
[com.techstar.monitorDemo.controller.userController, arg1 intercepts constructor
The constructor
@Data public
class
User
{
private
int id ;
private
String name ; } the control method
@GetMapping ( value
“/arg2” )
public
User arg2 ( User user )
{
return user ;
} BTrace script
/ * *
- Intercepting constructor
*/ @BTrace public
class
PrintConstructor
{
@OnMethod ( clazz
“com.techstar.monitordemo.domain.User” , method
“”)
public
static
void anyRead ( @ProbeClassName
String pcn ,
@ProbeMethodName
String pmn ,
AnyType [] args )
{
BTraceUtils . println ( pcn +
“,”
pmn );
BTraceUtils . printArray ( args );
BTraceUtils . println ();
}} Interception result
192 : Btrace apple$ btrace 34119
PrintConstructor . java com . techstar . monitordemo . domain . User ,< init
[ 1 , zuozewei ,
] 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 ;
} BTrace script
/ * *
- Intercepts functions of the same name, distinguished by input arguments
*/ @BTrace public
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 ();
}} Interception result
192 : Btrace apple$ jps
l 369
5889
/ Users / apple / Downloads / performance / apache
jmeter
Jar 34281 sun.tools.jps.jps 34220 org.jetBrains.jps.cmdline. Launcher 34221 com . techstar . monitordemo . MonitordemoApplication 192 : Btrace apple$ btrace 34221
PrintSame . java com . techstar . monitordemo . controller . UserController , same , zuozewei com . techstar . monitordemo . controller . UserController , same , UserController, same, zuozewei Interception method return value
BTrace scripts
/ * *
- Intercept return value
*/ @BTrace public
class
PrintReturn
{
@OnMethod ( clazz
“com.techstar.monitordemo.controller.UserController” , method
“arg1” ,
// Time of interception: return value location
@Location ( Kind . RETURN ))
public
static
void anyRead ( @ProbeClassName
String pcn ,
@ProbeMethodName
String pmn ,
@Return
AnyType result )
{
BTraceUtils . println ( pcn +
“,”
pmn +
“,”
result );
BTraceUtils . println ();
}} Interception result
192 : Btrace apple$ jps
l 34528 org . jetbrains . jps . cmdline . Launcher 34529 com . techstar . monitordemo . MonitordemoApplication 369
5889
/ Users / apple / Downloads / performance / apache
jmeter
4.0 / bin/apacheJmeter.jar 34533 sun.tools.jps.jps 192: Btrace Apple $Btrace 34529
PrintReturn. Java com.techstar.monitorDemo.controller. UserController, arg1, 7DGroup, zuozewei Exception analysis
Sometimes the developer does not handle the exception properly, causing some important exceptions to be eaten artificially, and there is no log or the log is not detailed, resulting in difficult performance analysis to locate the problem. We can use BTrace to handle the control method
@GetMapping ( value
“/exception” )
public
String exception ()
{
try
{
System . out . println ( “start…” );
System . out . println ( 1
/
0);
// Simulate an exception
System . out . println ( “end…” );
}
catch
( Exception e )
{}
return
“successful…” ;
} BTrace script
/ * *
- This class can be used to locate problems when some 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.
*/ @BTrace public
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 ;
}
}} Interception result
192 : Btrace apple$ jps
l 369
5889
/ Users / apple / Downloads / performance / apache
jmeter
Jar 34727 sun.tools.jps.jps 34666 org.jetBrains.jps.cmdline. Launcher 34667 com . techstar . monitordemo . MonitordemoApplication 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 )
. Locate a function that exceeds a threshold
BTrace scripts
支那
A program that detects whether method execution time under a package path exceeds a 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 .*; @BTrace public
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 ( ” 耗时:” );
BTraceUtils . print ( duration );
Btraceutils.println (” nanosecond, stack as follows “); jstack ();
}
}} Interception result
192 : Btrace apple$ btrace 39644
Printdurationtracer.java com.techstar.monitorDemo.controller.adder. execute Time: 1715294657 nanosecond stack information com.techstar.monitorDemo.controller.adder.execute (adder.java: 13 ) com . techstar . monitordemo . controller . Main . main ( Main . java : 10) Com.techstar.monitorDemo.controller.adder.execute Time: 893795666 nanoseconds stack information com.techstar.monitorDemo.controller.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 as follows com.techstar.monitorDemo.controller.adder.execute (adder.java: 13) trace method execution time
BTrace scripts
/ * *
- Tracking the execution time of a method is implemented the same way AOP does.
*/ @BTrace public
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 )
{
Println (strcat (strcat (“Adder. Execute “), STR (timeMillis ())
beginTime )),
“ms” ));
Println (strcat (” return result :”, STR (result)));
}} Interception result
192 : Btrace apple$ btrace 40863
Printexecutetimetracer.java adder. execute Time: 803ms The result is 797 adder. execute time: 1266ms The result is as follows: 1261 adder. execute time: 788ms the result is 784 adder. execute time: 1524ms the result is 1521 adder. execute time: 1775ms
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
- Shortened syntax – 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
*/ @BTrace class
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 );
} Deadlock check
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.
*/ @BTrace public
class
PrintDeadlock
{
@OnTimer ( 4000 )
public
static
void print ()
{ deadlocks ();
}} 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 method parameters and properties 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.