需求
这几天发现持续集成环境的执行效率比较低,所以想到用BTrace来看看是什么原因造成的,哪些环节比较慢。
持续集成环境的服务端是hudson,里面跑的主要是各个应用的单元测试,由maven管理执行。
获取资源
从BTrace官方下载它的工具包 http://kenai.com/projects/btrace/downloads/directory/releases
我这边下载的是 release-1.2 目录下的1.2版本。
简单的使用说明,可以参考用户手册:http://kenai.com/projects/btrace/pages/UserGuide
hudson中运行的是
hudson中跑的是单元测试代码内容类似如下:
package com.hugehard......test;
......
public class SomeBizServiceTest extends JTester {
......
@Test
public void testXX() {
...
}
@Test
public void testOO() {
...
}
...
}
所以我们需要监控的是单元测试类,这些类处于名称包含hugehard的包路径中。
我们希望知道testXX, testOO这样的方法的执行时间。
编写监控脚本
package hudson;
import static com.sun.btrace.BTraceUtils.print;
import static com.sun.btrace.BTraceUtils.println;
import com.sun.btrace.BTraceUtils.Time;
import com.sun.btrace.annotations.BTrace;
import com.sun.btrace.annotations.Kind;
import com.sun.btrace.annotations.Location;
import com.sun.btrace.annotations.OnMethod;
import com.sun.btrace.annotations.ProbeClassName;
import com.sun.btrace.annotations.ProbeMethodName;
import com.sun.btrace.annotations.TLS;
/**
* BtraceHudson.java
*
* @author caesar 2011-7-30 AM11:23:17
*/
@BTrace
public class BtraceHudson {
@TLS
static long starttime = 0;
@OnMethod(clazz = "/.*hugehard.*/", method = "/test.*/")
public static void startMethod(@ProbeClassName String probeClass,
@ProbeMethodName String probeMethodName) {
print("probeClass: ");
print(probeClass);
print(" ");
print("probeMethodName: ");
print(probeMethodName);
print(" start time: ");
starttime = Time.nanos();
println(starttime);
}
@OnMethod(clazz = "/.*hugehard.*/", method = "/test.*/",
location = @Location(Kind.RETURN))
public static void collectTestMethodExecutionEnd(@ProbeClassName String probeClass,
@ProbeMethodName String probeMethodName) {
print("probeClass: ");
print(probeClass);
print(" ");
print("probeMethodName: ");
print(probeMethodName);
print(" execute time: ");
long executeTime = Time.nanos() - starttime;
println(executeTime);
}
}
上面这段代码是参考博文 http://jarit.iteye.com/blog/1010908 中的内容,所以这里就不赘述它的原理了。
maven不能btrace?
我在自己的工程根目录下,执行“mvn clean test”。
通过“jps -l”拿到maven的PID。
而后通过“btrace <PID> BtraceHudson.java”,期望能够获得每个测试方法的执行时间。
但是没有获得任何的信息。
后来把标注 @OnMethod 中的clazz和method限定都放到最宽泛的程度,才发现,里面拿到的方法执行信息,根本与单元测试类毫无关联,而都是来自maven的代码类。
这时候想起来,maven在执行每个工程的单元测试的时候,它会创建独立的线程去执行它们pom.xml中定义的内容。
所以我这里拿到PID,仅仅是maven自身的线程信息,根本拿不到具体工程的线程中的方法执行信息。
javaagent模式
根目录的pom.xml中我们定义了jmockit的javaagent,用于执行test阶段的单元测试mock代码之用。配置如下:
<project> <dependencies> ...... </dependencies> <build> <plugins> <plugin> <groupId>org.apache.maven.plugins</groupId> <artifactId>maven-surefire-plugin</artifactId> <version>2.4.2</version> <configuration> <argLine>-javaagent:"${settings.localRepository}/com/hugehard/external/test.jmockit/0.997/test.jmockit-0.997.jar"</argLine> <junitArtifactName>com.alibaba.external:test.junit</junitArtifactName> <testNGArtifactName>com.alibaba.external:test.testng.jdk15</testNGArtifactName> </configuration> <executions> <execution> <goals> <goal>test</goal> </goals> </execution> </executions> </plugin> </plugins> </build> </project>
这让我想起来,btrace也是有agent模式的,可以让它和应用一起启动。
这样每次maven创建新线程来执行单元测试的时候,会否也让btrace一起启动了呢?
参考官方文档,修改argLine配置如下:
<argLine>-javaagent:"${settings.localRepository}/com/hugehard/external/test.jmockit/0.997/test.jmockit-0.997.jar" -javaagent:/tmp/hudson-optimize/credit-shared-1/btrace-agent.jar=script=/tmp/hudson-optimize/BtraceHudson.class,scriptOutputFile=/tmp/hudson-optimize/btrace.${pom.artifactId}</argLine>
这里需要说明一下:
1、javaagent模式下,需要预编译btrace类
(详细请参考 http://kenai.com/projects/btrace/pages/UserGuide#precompile)
所以我们需要用如下指令先编译咱们的BtraceHudson.java
/work/ide/btrace/btrace-bin/bin/btracec -cp . BtraceHudson.java
而后会得到编译好的类 BtraceHudson.class。
2、javaagent中,请确保给出的btrace-agent.jar所在的目录中也包括了btrace-boot.jar, btrace-client.jar这两个包。
3、我们可以在scriptOutputFile中指定btrace的输出结果重定向到我们希望拿到报告的位置。
4、另外,这里使用的${pom.artifactId} 是为了每个pom.xml对应的工程在执行单元测试的时候,它们所生成的btrace报告不会互相覆盖。
接着像我们往常一样,执行“mvn clean test”指令,就能在咱们指定的目录中查看btrace报告,而后对它进行分析,找出执行效率低下的单元测试了。
== 全文完 ==