引言
在我们对Java应用做问题分析的时候，往往采用log进行问题定位和分析，但是如果我们的log缺乏相关的信息呢？远程调试会影响应用的正常工作，修改代码重新部署应用，实时性和灵活性难以保证，有没有不影响正常应用运行，又灵活并无侵入性的方法呢？
答案是有，它就是Java中的神器-BTrace BTrace是什么？
BTrace使用Java的Attach技术，可以让我们无缝的将我们BTrace脚本挂到JVM上，通过脚本你可以获取到任何你想拿到的数据，在侵入性和安全性都非常可靠，特别是定位线上问题的神器。
BTrace原理
BTrace是基于动态字节码修改技术（Hotswap）向目标程序的字节码注入追踪代码。
安装配置
关于BTrace的安装配置使用，此处就不再重复造轮子，网上有太多的教程。
官网地址：github.com/btraceio/bt… 注意事项
生产环境可以使用，但修改的字节码不会被还原，使用Btrace时，需要确保追踪的动作是只读的（即：追踪行为不能修改目标程序的状态）和有限的行为（即：追踪行为需要在有限的时间内终止），一个追踪行为需要满足以下的限制：
不能创建新的对象 不能创建新的数组 不能抛出异常 不能捕获异常 不能对实例或静态方法调用-只有从BTraceUtils中的public static方法中或在当前脚本中声明的方法，可以被BTrace调用 不能有外部，内部，嵌套或本地类 不能有同步块或同步方法 不能有循环（for，while，do..while） 不能继承抽象类（父类必须是java.lang.Object） 不能实现接口 不能有断言语句 不能有class保留字 以上的限制可以通过通过unsafe模式绕过。追踪脚本和引擎都必须设置为unsafe模式。脚本需要使用注解为 @BTrace(unsafe=true)，需要修改BTrace安装目录下bin中btrace脚本将 -Dcom.sun.btrace.unsafe=false改为 -Dcom.sun.btrace.unsafe=true。
注：关于unsafe的使用，如果你的程序一旦被btrace追踪过，那么unsafe的设置会一直伴随该进程的整个生命周期。如果你修改了unsafe的设置，只有通过重启目标进程，才能获得想要的结果。所以该用法不是很好使用，如果你的应用不能随便重启，那么你在第一次使用btrace最终目标进程之前，先想好到底使用那种模式来启动引擎。 使用示例
拦截一个普通方法
control方法
@GetMapping ( value
"/arg1" )
public
String arg1 ( @RequestParam ( "name" )
String name )
throws
InterruptedException
{
Thread . sleep ( 2000 );
return
"7DGroup,"
name ;
} BTrace脚本
/**
- 拦截示例 */ @BTrace public
class
PrintArgSimple
{
@OnMethod (
//类名 clazz
"com.techstar.monitordemo.controller.UserController" ,
//方法名 method
"arg1" ,
//拦截时刻：入口 location
@Location ( Kind . ENTRY ))
/** * 拦截类名和方法名 */
public
static
void anyRead ( @ProbeClassName
String pcn ,
@ProbeMethodName
String pmn ,
AnyType [] args )
{
BTraceUtils . printArray ( args );
BTraceUtils . println ( pcn +
","
pmn );
BTraceUtils . println ();
} } 拦截结果：
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 拦截构造函数
构造函数
@Data public
class
User
{
private
int id ;
private
String name ; } control方法
@GetMapping ( value
"/arg2" )
public
User arg2 ( User user )
{
return user ;
} BTrace脚本
/**
- 拦截构造函数 */ @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 ();
} } 拦截结果
192 : Btrace apple$ btrace 34119
PrintConstructor . java com . techstar . monitordemo . domain . User ,< init
[ 1 , zuozewei ,
] 拦截同名函数，以参数区分
control方法
@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脚本
/**
- 拦截同名函数，通过输入的参数区分 */ @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 ();
} } 拦截结果
192 : Btrace apple$ jps
l 369
5889
/ Users / apple / Downloads / performance / apache
jmeter
4.0 / bin / ApacheJMeter . 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 , zuozewei com . techstar . monitordemo . controller . UserController , same , zuozewei 拦截方法返回值
BTrace脚本
/**
- 拦截返回值 */ @BTrace public
class
PrintReturn
{
@OnMethod ( clazz
"com.techstar.monitordemo.controller.UserController" , method
"arg1" ,
//拦截时刻：返回值 location
@Location ( Kind . RETURN ))
public
static
void anyRead ( @ProbeClassName
String pcn ,
@ProbeMethodName
String pmn ,
@Return
AnyType result )
{
BTraceUtils . println ( pcn +
","
pmn +
","
result );
BTraceUtils . println ();
} } 拦截结果
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 异常分析
有时候开发人员对异常处理不合理，导致某些重要异常人为被吃掉，并且没有日志或者日志不详细，导致性能分析定位问题困难，我们可以使用BTrace来处理 control方法
@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..." ;
} BTrace脚本
/**
- 有时候，有些异常被人为吃掉，日志又没有打印，这个时候可以用该类定位问题
- 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 ;
}
} } 拦截结果
192 : Btrace apple$ jps
l 369
5889
/ Users / apple / Downloads / performance / apache
jmeter
4.0 / bin / ApacheJMeter . 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 . LauncherConnectionHandler . process ( AbstractProtocol . java : 800 ) org . apache . tomcat . util . net . NioEndpointWorker . run ( ThreadPoolExecutor . java : 624 ) org . apache . tomcat . util . threads . TaskThread$WrappingRunnable . run ( TaskThread . java : 61 ) java . lang . Thread . run ( Thread . java : 748 )
... 定位某个超过阈值的函数
BTrace脚本
**
探测某个包路径下的方法执行时间是否超过某个阈值的程序，如果超过了该阀值，则打印当前线程的栈信息。
/ 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的单位是纳秒
if
( duration
1000
1000
2 )
{
BTraceUtils . println ( Strings . strcat ( Strings . strcat ( pcn ,
"." ), pmn ));
BTraceUtils . print ( " 耗时:" );
BTraceUtils . print ( duration );
BTraceUtils . println ( "纳秒,堆栈信息如下" ); jstack ();
}
} } 拦截结果
192 : Btrace apple$ btrace 39644
PrintDurationTracer . java com . techstar . monitordemo . controller . Adder . execute 耗时: 1715294657 纳秒,堆栈信息如下 com . techstar . monitordemo . controller . Adder . execute ( Adder . java : 13 ) com . techstar . monitordemo . controller . Main . main ( Main . java : 10 ) com . techstar . monitordemo . controller . Adder . execute 耗时: 893795666 纳秒,堆栈信息如下 com . techstar . monitordemo . controller . Adder . execute ( Adder . java : 13 ) com . techstar . monitordemo . controller . Main . main ( Main . java : 10 ) com . techstar . monitordemo . controller . Adder . execute 耗时: 1331363658 纳秒,堆栈信息如下 com . techstar . monitordemo . controller . Adder . execute ( Adder . java : 13 ) 追踪方法执行时间
BTrace脚本
/**
- 追踪某个方法的执行时间，实现原理同AOP一样。 */ @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 )
{
BTraceUtils . println ( strcat ( strcat ( "Adder.execute 耗时:" , str ( timeMillis ()
beginTime )),
"ms" ));
BTraceUtils . println ( strcat ( "返回结果为:" , str ( result )));
} } 拦截结果
192 : Btrace apple$ btrace 40863
PrintExecuteTimeTracer . java Adder . execute 耗时: 803ms 返回结果为: 797 Adder . execute 耗时: 1266ms 返回结果为: 1261 Adder . execute 耗时: 788ms 返回结果为: 784 Adder . execute 耗时: 1524ms 返回结果为: 1521 Adder . execute 耗时: 1775ms 性能分析
压测的时候经常发现某一个服务变慢了，但是由于这个服务有很多的业务逻辑和方法构成，这个时候就不好定位到底慢在哪个地方。BTrace可以解决这个问题，只需要大概定位问题可能存在的地方，通过包路径模糊匹配，就可以找到问题。
BTrace脚本
/** *
- 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 );
} 死锁排查
我们怀疑程序是否有死锁，可以通过以下的脚本扫描追踪，非常简单方便。 /**
- 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 ();
} } 小结
BTrace是一个事后工具，所谓的事后工具就是在服务已经上线或者压测后，但是发现有问题的时候，可以使用BTrace动态跟踪分析。
比如哪些方法执行太慢，例如监控方法执行时间超过1秒的方法； 查看哪些方法调用了system.gc( )，调用栈是怎样的； 查看方法的参数和属性 哪些方法发生了异常 ..... 总之，这里只是将部分经常用的列举了下抛砖引玉，还有很多没有列举，大家可以参考官方的其他Sample去玩下。
