初探BTrace脚本 - 看看持续集成哪个环节比较慢

需求

    这几天发现持续集成环境的执行效率比较低，所以想到用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报告，而后对它进行分析，找出执行效率低下的单元测试了。

 

== 全文完 ==