手把手教你使用 Btrace 定位应用热点

96
泡面办公室
2017.09.29 19:14* 字数 2625

前言

前段时间笔者对一个 Java 类型的项目做性能测试,发现应用 CPU 使用率很高,TPS 无法满足需求,只能通过使用性能问题定位的利器—— Btrace 来获取方法调用的平均耗时与单笔交易执行次数,从而定位热点方法,快速定位问题。下面就为大家介绍一下笔者在实际中使用 Btrace 的一些方法和注意事项,希望能为你带来一些有价值的参考。

当然,在使用 Btrace 之前要先安装,具体方法请参考相关说明,就不在此赘述了。由于 Btrace 并非可视化的监控工具,采集结果是以文本信息的方式输出来的,故需要我们对结果进行必要的统计分析才能找出应用的热点方法。在实际使用中,笔者通常按照以下步骤进行热点方法的抓取:

① 编写采集脚本;

② 运行采集脚本;

③ 执行场景;

④ 停止场景;

⑤ 停止采集脚本;

⑥ 获取方法列表;

⑦ 分析结果,获得方法的平均耗时与执行次数。

下面具体介绍一下每一步的操作要点。

编写采集脚本

首先要编写一个脚本,用于定义要抓取的热点方法。脚本的大概结构如图 1 所示,下面对脚本做一个简单的介绍。

图1  监控脚本

首先导入 Btrace 自带的两个包,然后像正常编写 Java 类一样编写一个简单的类,类名的命名只要符合 Java 规范即可。

@OnMethod 注解里的内容是定义触发的条件,当程序执行时满足了注解内的条件就会执行下面的 test-trace(这个方法可以自由命名)方法。

变量 clazz 是要抓取方法的范围,即 class,这个变量指定的路径越详细抓取的方法就会越少,输出结果也越少,通常我们只抓取项目本身定义的类中的所有方法即可,调用的第三方及使用的框架的类可以过滤掉。

method 的作用是定义需要监控的方法,可以使用正则表达式的方式进行匹配。

location 变量的作用是定义方法的拦截位置,我们要获取方法的执行耗时需要使用 Kind.RETURN,这样在方法执行完成后我们就可以获取返执行时间 @Duration。

脚本中的 test-trace 方法是我们要输出的抓取结果的一些代码,当 @OnMethod 触发条件满足时就会被执行。

再看一下几个参数,

@ProbeClassName 是当前执行到的包含完整包路径的类名称;

@ProbeMethodName 是当前被执行到的方法名称;

@Duration 是当前方法执行消耗的时间,单位为纳秒,所以在输出这个耗时的时候,我们要把纳秒转化成毫秒,以增加可读性。

最后,我们只需使用一个 print 方法将这几个参数输出即可,输出的格式是类似于 “com.yeepay.*.* . queryList:100”。

整个脚本的结构非常简洁,很容易学习与掌握。当然 Btrace 不只提供这么简单的功能,如果你有更复杂的需求请参阅相关资料。这里需要说明的是,尽量对过滤的范围进行压缩,以排除其他无关类的影响。如果抓取的结果中没有热点方法,我们可以再尝试改变抓取的类的范围。

执行采集脚本

脚本编写完成之后,无需特别的编译即可执行了。如果在执行时报错,那么我们再回去修改脚本即可。执行前我们需要先获取被测应用的 PID,并且把抓取结果保存到文件中。命令格式如下:

btrace PID ./Test.java >> trace-res.txt

命令运行之后,如果没有报错,就说明 Btrace 已经开始工作了,只要程序相关的方法被执行到,并且符合采集的条件,那么采集结果就会输出到 trace-res.txt 文件中。

执行测试场景

采集脚本启动后就要进行测试场景的执行了。根据笔者的经验,建议发压的压力不要太大或者时间不要太长,否则收集的结果文件会很大,后续分析起来会比较费劲。发压一定时间后,采集的数据足够我们分析了,这时就要停止压力,然后把 Btrace 的进程 kill 掉。

获取应用的方法列表

有了采集结果,接下来我们就要对结果进行统计分析。首先,我们要获取方法列表,当然这一步在整个测试过程中只需进行一次,除非应用增加了新的方法或修改了某些方法的名称。方法列表是我们对采集结果进行分析的基础,后续我们要根据方法列表里的方法名称,进行逐个方法的采集结果的统计计算。下面这个命令是笔者对采集结果进行方法列表的提取操作:

cat trace-res.txt | awk -F ':' '{print $1}' | awk ‘!a[$0]++’ >> fuction-list.txt

执行完成后把 fuction-list.txt 文件中的方法列表拷贝到一个 Excel 表格中,作为分析的第一列。笔者 Excel 统计分析的格式如图 2 所示。

图2  热点方法采集结果分析表

输出采集结果

接下来还需要根据方法列表来获取每个方法的平均执行耗时与采集次数。同样,我们也使用 shell 命令来实现,具体的命令类似这样:

cat trace.txt | grep -a “com.yeepay.g3.utils.*” | awk -F ':' '{print $2}’ | awk ‘{sum+=$1} END {if (NR==0) print "0 0";else if (NR>0) print sum/NR,NR}’

这个命令的最后一个管道对输出结果进行了一次判断,避免变量 NR(行数)出现 0 的时导致命令报错。

一般情况下应用的方法会比较多,如果每次都手工写命令并执行那也是一件体力活。这时我们把这个命令统一写到一个脚本中,分析的时候执行脚本即可。笔者写好后的整体效果如图3所示,有密集恐惧症的读者请忽略此图。

图3 自动解析输出方法平均耗时与执行次数的 shell 脚本

执行完这个脚本后,输出的结果包含两列,第一列是“平均耗时”,第二列是“采集次数”,把这两列结果直接复制到 Excel 中,即可对结果进行分析。我们可以对“平均耗时”和“每笔交易执行次数”进行排序,以发现耗时最高和平均执行次数最高的方法。

笔者的分析结果如图 2 所示。其中“原子方法”列的状态是与开发沟通后确定的。所谓的原子方法是指这个方法是否还调用别的方法,如果没有调用别的方法,那么我们就认为是原子方法。如果一个方法是原子方法且平均耗时较长,那肯定就是热点方法,也是要重点进行优化的地方。

另外一列“每笔交易执行次数”需要大家注意,这一列的值是笔者在另外的一个场景中把响应时间阈值设置为0时获取的结果,并不是图 2 中“采集次数”直接除于请求次数所得的结果。

通过图 2 中的表可以清晰地找出当前的热点方法,然后研发人员就可以重点对这些方法进行优化。通过使用 Btrace 工具可以大大缩短定位热点方法的时间,快速而有效。笔者根据图 2 的结果,对应用进行优化,发现应用的同步处理能力可以提升 3 倍,异步处理能力可以提升 10 倍。

影响性分析

最后需要大家注意的是使用 Btrace 时会对应用产生影响。经笔者实践,如果监控阈值为 0(采集脚本中的 if 语句 if duration >= 0 ),对应用的影响是致命的,可能会造成 TPS 严重下降,因为会有大量的监控结果输出导致磁盘 IO 被打满。在笔者做的项目中实测 200 笔交易共输出 2.5GB 的采集信息,实在惊人!而采集阈值为 10 毫秒时,对应用的性能影响为 25% 左右。因此,采集的阈值越大,影响越小;过滤的方法越多对应用的影响越小。所以在使用 Btrace 时建议大家设置合理的阈值,减少输出量

另外,建议大家单独执行一个场景用于获取方法的列表及单笔交易执行次数,比如将阈值设置为 0,连续发起 10 笔请求,然后对结果进行分析,获取方法列表及单笔交易执行次数,这样的动作我们只进行一次就可以了。

好消息

易宝 CTO 陈斌翻译的新书《架构真经》正在京东和亚马逊热卖!

《架构真经》:《架构即未来》姊妹篇,硅谷大咖的干货呈现,互联网架构的50条军规。唐彬、向江旭、叶亚明、段念、吴华鹏、张瑞海、韩军、程炳皓、张云泉、余晨、李大学、霍泰稳联袂力荐。

技术
Web note ad 1