Btrace 实践分析一次调用的耗时热点

1.1 下载BTrace

下载地址:目前需要JDK7+,最新版本为1.3.8.3download
设置环境变量:BTRACE_HOME

1.2 编写BTrace脚本HelloWorld.java

importcom.sun.btrace.annotations.*;
importstaticcom.sun.btrace.BTraceUtils.*;
@BTrace
publicclassHelloWorld {
@OnMethod(clazz="java.lang.Thread", method="start")
publicstaticvoidonThreadStart() {
println("thread start!");
}

1.3 运行

虽然btrace可以实时编译Java源文件,但如果你的脚本是要给运维同学执行的,线上运行时才发现写错了就尴尬了,可以预编译脚本:btracec HelloWorld.java,保证代码正确,这样也避免运行时的编译异常。

1.3.1 直接运行

btrace $pid HelloWorld.java

1.3.2 输出到指定文件运行

btrace -o btrace.log $pid HelloWorld.java

  • 当然如果想跟踪SOFALite应用的启动过程的话,可以将下载的压缩包中btrace-agent.jar-javaagent方式启动起来。

  • 例如,javaagent的设置方式

-javaagent:/home/admin/ccbin/lif_btrace/build/btrace-agent.jar=script=/home/admin/ccbin/lif_btrace/build/TrackDTDXSDLoad.class,scriptOutputFile=/home/admin/logs/lif_btrace.log

1.3.3 定义classpath

如果在HelloWorld.java里使用了JDK外的其他类,比如Netty的:
./btrace -cp .:netty-all-4.0.41.Final.jar $pid HelloWorld.java
但上面定义的classpath只在编译脚本时使用,而脚本里需要显式使用非JDK类的机会其实很少,而在运行时,因为已经绑到目标应用的JVM里,用的是目标JVM的classpath。

1.4 拦截方法定义

1.4.1 正则表达式定位

注意:所有样例工程在这里

@com.sun.btrace.annotations.OnMethod用来指定trace的目标类和方法以及具体位置,被注解的方法在匹配的方法执行到指定的位置会被调用。"clazz"属性用来指定目标类名,可以指定全限定类名,比如"java.awt.Component",也可以是正则表达式(表达式必须写在"/ /"中,比如"/java\.awt\..+/")。"method"属性用来指定被trace的方法。表达式可以参考自带的例子(NewComponent.java和Classload.java,关于方法的注解可以参考MultiClass.java)。有时候被trace的类和方法可能也使用了注解。用法参考自带例子WebServiceTracker.java。针对注解也是可以使用正则表达式,比如像这个"@/com\.acme\..+/ ",也可以通过指定超类来匹配多个类,比如"+java.lang.Runnable"可以匹配所有实现了java.lang.Runnable接口的类。具体参考自带例子SubtypeTracer.java。

  • 示例:
//下例打印所有用时超过300毫秒的方法调用
@OnMethod(clazz ="/com\\.alipay\\..+/", method ="/.+/", location = @Location(Kind.RETURN))
publicstaticvoidonDoFilter2(@ProbeClassName String pcn,@Durationlongduration) {
longcost = duration/(1000000*100);
if(cost >3) {
print(strcat(strcat(strcat(strcat(name(probeClass()),"."), probeMethod()),":"), str(probeLine())));
print("[");
print(strcat("Time cost (*100ms): ", str(cost)));
println("]");
}
}

1.5 初步结论

* 备注:第一个数字代码代码的行数,第二个代码的耗时,单位100ms
XXX.getIpMap:39[Time cost (*100ms):50]
  • 分析堆栈得知,业务测试代码中获取IP和域名等非常耗时(涉及文件IO);经过再一次调整打印规则,再次触发RPC调用,发现首次调用时,非常耗时,通过分析BTrace日志得知,另一个方法热点。
*备注:第一个数字代码代码的行数,第二个代码的耗时,单位100ms
XXX.getPID:192[Time cost (*100ms):50]

1.6 BTrace + JAVA VisualVM**

为了获得更好的展示体验,我们可以利用BTrace + JAVA VisualVM来分析应用中的热点耗时方法,做性能优化,具体如下:

1.6.1打开Java VisualVM并安装BTtrace Workbench

在控制台输入jvisualvm即可打开,然后安装BTrace

1.6.2指定分析的进程

  • 在Java VisualVM中选中想要监控的进程,右击选中Trace application

1.6.3编写脚本,启动BTrace

1.6.4 运行程序,其中的耗时热点将会打印出来

1.7 展望

  • 有了一次调用的耗时热点分析,可以举一反三,进行压测将所有耗时较高的点打印出来,并通过脚本解析的方式,就可以知道一次压测中所有耗时的热点了,并据此进行应用的性能优化😀。

  • 备注:使用阿里的Greys Java在线问题诊断工具也是非常不错的选择,使用上会更简单些。 github代码

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 203,937评论 6 478
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 85,503评论 2 381
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 150,712评论 0 337
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 54,668评论 1 276
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 63,677评论 5 366
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 48,601评论 1 281
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 37,975评论 3 396
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 36,637评论 0 258
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 40,881评论 1 298
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 35,621评论 2 321
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 37,710评论 1 329
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 33,387评论 4 319
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 38,971评论 3 307
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 29,947评论 0 19
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 31,189评论 1 260
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 44,805评论 2 349
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 42,449评论 2 342

推荐阅读更多精彩内容