はじめに

性能測定でメソッド毎の処理時間が知りたい！というような場合にメソッドの前後にいちいち下記のようなコードを書いていくのは少し面倒です。。。

public void hoge() {
    // 処理時間を測りたいメソッドの直前で時間を取得
    long methodStartTime = System.currentTimeMillis();

    // 処理時間を測りたいメソッド
    target();

    // メソッドの実行前に取得した時間との差分でメソッドの処理時間を計算
    long execTime = System.currentTimeMillis() - methodStartTime;

    System.out.println(execTime);

}

プロファイラを使うという事も考えられますが、その分メモリを使うので性能測定という目的の場合はちょっと不向きかなと思っています。

そんな折、生Strutsなアプリの性能測定をすることになり、いい機会だったのでAspectJを使って元のコードに手を入れず簡単にメソッドの処理時間が取得できないか試してみました。

ちなみに、やっているプロジェクトがビルドにAnt使っているのでAntでのやり方を書きます。

まずは、AspectJのjarを手に入れよう

Antで！と言った直後ですが、jarは面倒なのでMavenで取得しちゃいました・・・
2015/5時点での最新ver.は、1.8.6です

pom.xml

<!-- AspectJのライブラリ -->
<dependency>
    <groupId>org.aspectj</groupId>
    <artifactId>aspectjrt</artifactId>
    <version>1.8.6</version>
</dependency>
<!-- AspectJの動的ウィービング用のライブラリ -->
<dependency>
    <groupId>org.aspectj</groupId>
    <artifactId>aspectjweaver</artifactId>
    <version>1.8.6</version>
</dependency>
<!-- AspectJのコンパイラとラッパーが入っているライブラリ -->
<dependency>
    <groupId>org.aspectj</groupId>
    <artifactId>aspectjtools</artifactId>
    <version>1.8.6</version>
</dependency>

ネットからだと
https://eclipse.org/aspectj/
からダウンロードできます。

Aspectを書いてみよう

今回は上に書いてあるのと同じ方法でメソッドの処理時間を測ります。なのでアドバイスはAroundでポイントカットは全パッケージ、全クラス、全メソッド(引数による制限なし)としています。

Example.java

@Aspect
public class MethodExecTimeLogger {

    @Around("execution(* *.*(..))")
    public Object getMethodExecTime(ProceedingJoinPoint point) throws Throwable {
        long methodStartTime = System.currentTimeMillis();

        // 織り込み先(ジョインポイント)のメソッドを呼ぶ
        Object result = point.proceed();

        long execTime = System.currentTimeMillis() - methodStartTime;

        System.out.println(execTime);

        // 織り込み先(ジョインポイント)のメソッドの戻り値を返却
        return result;
    }

}

Antでビルドしてみよう

build.xmlを変更しないでビルドする場合

antのlib配下に、aspectjtools-$ver.jarを置く
Eclipseの場合は、設定＞Ant＞ランタイム＞グローバル項目に追加する
Ant実行時の引数に以下を追加する
java:args -Dbuild.compilier=org.aspectj.tools.ant.taskdefs.Ajc11CompilerAdapter
上記のようにしておくと、javacタスクがiajcタスク(AspectJのコンパイラ)に自動で置き換わりコンパイルしてくれるようになります。
便利！
Ant実行！

これだけで、作ったAspectが全メソッドに埋め込まれます。デコンパイラで普通にコンパイルしたクラスファイルと中身を比べると一目瞭然です。

<注意>
https://eclipse.org/aspectj/doc/next/devguide/antTasks-adapter.html
にも書いてありますが、上記のやり方だとコンパイルが正常に行われないことがあるそうです。出会ったことがないので、どういう風に上手くコンパイルされないのかわかりませんが、「なんか変だな、、、」という場合は下記のようにしてみてください。

iajcタスクを使いコンパイルする場合

上記「build.xmlを変更しないでビルドする場合」の1.と同様
iajcタスクを定義する

buil.xml

<taskdef resource="org/aspectj/tools/ant/taskdefs/aspectjTaskdefs.properties"></taskdef>
<property name="aspect.compile.classpath" refid="compile.classpath" />
<target name="compile">
    <!-- javacで下みたいに作っていたら -->
    <javac destdir="${classes.dir}" srcdir="${src.dir}" encoding="UTF-8" source="1.6" target="1.6">
        <classpath refid="compile.classpath" />
    </javac>

    <!-- iajcでは、こうなります -->
    <iajc sourceroots="${src.dir}" destDir="${classes.dir}" classpath="${aspect.compile.classpath}" encoding="UTF-8" source="1.6" target="1.6" />
</target>

iajcタスクのclasspathには、aspectjrt.jarが含まれるようにして下さい。

おわりに

最近の気の利いたフレームワークだとAOP機能が最初からあるので、素のままAspectJを使うことはあんまりないとは思いますが、静的ウィービングができるのでフレームワークに依存せず使えるのがいいなぁと思いました。

今回はAntを使ってビルドしてみましたが、機会があったらMavenでもやって追記しようと思います。

追記

pomにもコメントを付けましたが、取得する3つのjarはそれぞれ
* aspectjrt: AspectJのライブラリ本体
* aspectjweaver: 動的ウィービングするときに使うライブラリ
* aspectjtools: コンパイラとそのラッパーが入っているライブラリ
みたいです。なので、静的ウィービングだけならweaverはいらないです。

今更、AspectJを使ってみた