バイトコード操作でロギング処理を追加する

はじめに

前回はただフィールドを追加するだけのコードを書きました。 なんのひねりもありません。 progret.hatenadiary.com

そして今回はメソッドの最初と最後にロギング処理を追加します。 今回は簡単化のため、標準出力に出力します。

今回の記事ではJavassistとByte Buddyを使ってロギング処理を追加してみたいと思います。 (cglibは心が折れた内部APIがすごい見えるので今回は取り扱いません)

今回は以下のクラスに対してメソッドの最初と最後にロギング処理を追加します。

  public class Some {
    public void someMethod() {
      System.out.println("some implementation");
    }
  }

まずはJavassistから

まずはJavassistで追加してみたいと思います。

  @Test
  public void testAddLogMethodWithJavassist() throws CannotCompileException, IOException, NotFoundException {
    ClassPool pool = ClassPool.getDefault();
    CtClass clazz = pool.get(Some.class.getName());
    for (CtMethod method : clazz.getMethods()) {
      if (method.getDeclaringClass()
        .equals(clazz) && !Modifier.isNative(method.getModifiers()) && !Modifier.isAbstract(method.getModifiers())) {
        method.insertBefore("System.out.println(\"" + method.getName() + ":start\");");
        method.insertAfter("System.out.println(\"" + method.getName() + ":end\");");
      }
    }
    byte[] bytes = clazz.toBytecode();
  }

JavassitのAPIでは、Javaのソース文字列ベースで操作が可能です。 今回はCtMethodのinsertBeforeとinsertAfterというメソッドを使って メソッドの前後に処理を追加しています。

ダブルクォートのエスケープが必要で辛い感じが少しありますが 大した点ではないので置いておきます。

Javassistにはいくつかの制約がありますが $から始まる特殊な変数名により、あらかじめ定められた値の参照をすることができます。(参考URL) ローカル変数は参照できません。

ところで、javassistや標準のリフレクションAPIにあるModifierクラスにisSyntheticがないのはなんででしょう・・・ 欲しいですね。

Byte Buddyで書いてみる

今度はByte Buddyで書いてみます。

  @Test
  public void testAddLogMethodWithByteBuddy() throws IOException {
    byte[] bytes = new ByteBuddy().rebase(Some.class)
      .visit(Advice.to(ExampleAdvice.class)
        .on(ElementMatchers.isMethod()
          .and(isDeclaredBy(Some.class))
          .and(not(isAbstract()))
          .and(not(isNative()))))
      .make()
      .getBytes();
  }

  public static class ExampleAdvice {
    @OnMethodEnter
    public static void enter(@Origin Method method) {
      System.out.println(method.getName() + ":start");
    }

    @OnMethodExit
    public static void exit(@Origin Method method) {
      System.out.println(method.getName() + ":end");
    }
  }

Byte BuddyはJavassistと違い、アノテーションを使った独自のAPIによって バイトコードの操作が可能です。

今回の例ではOnMethodEnterとOnMethodExitアノテーションを使ってメソッドの前後に処理を追加しています。 ちなみに、この例ではExampleAdviceクラスのstaticメソッドが実際に呼ばれるわけではなく インライン化されて呼ばれます。

また、アノテーションのOnMethodEnter/Exitのinlineプロパティをfalseにすることでインライン化しないことも可能です。

では、これで生成したバイトコードはどうなるでしょうか?

public class Some {
  public void someMethod() {
    System.out.println(Some.class.getDeclaredMethod("someMethod", new Class[0]).getName() + ":start");
    System.out.println("some implementation");
    System.out.println(Some.class.getDeclaredMethod("someMethod", new Class[0]).getName() + ":end");
  }
}

こんな感じになります。(一部簡略化しています。) methodを毎回取得する形になってしまいます。 これではいけません。余計な処理が走ってしまいます。 インライン化しなければ、解決することも可能かもしれませんが置いておきます。

では、これをRewriteしてみます。

Byte BuddyにはCustom Mapping APIというものがあり 自分で定義したアノテーションが付けられたadviceの引数に対して、独自のマッピング処理を追加することが可能です。 今回はメソッド名の取得がしたいだけなので 動的ではなく静的に実行が可能なはずです。

というわけで、MethodNameアノテーションを用意してみます。

  @Retention(RetentionPolicy.RUNTIME)
  @Target(ElementType.PARAMETER)
  public static @interface MethodName {
  }

ここで、@Retention(RetentionPolicy.RUNTIME)を付与していることに注意してください。 筆者はここでハマりました。

デフォルトでは、メソッドの引数をマッピングしようとするので 例外が発生してしまいます。

では、MethodNameアノテーションを解決する、DynamicValueというインターフェースを実装したクラスを用意します。

  class MethodNameBinder implements DynamicValue<MethodName> {
    @Override
    public StackManipulation resolve(TypeDescription instrumentedType, MethodDescription instrumentedMethod, InDefinedShape target,
      Loadable<MethodName> annotation, Assigner assigner, boolean initialized) {
      if (target.getType()
        .asErasure()
        .isAssignableFrom(String.class)) {
        String name = instrumentedMethod.getName();
        return new TextConstant(name);
      }
      throw new IllegalStateException("not assignable type");
    }
  }

アノテーションが付与された引数の型がStringをAssignできるなら バイトコード上の定数としてメソッド名を返却します。

では、今回のCustom Mappingに合わせてExampleAdviceのクラスとテストコードに変更を加えます。

  @Test
  public void testAddLogMethodWithByteBuddy() throws IOException {
    byte[] bytes = new ByteBuddy().rebase(Some.class)
      .visit(Advice.withCustomMapping()
        .bind(MethodName.class, new MethodNameBinder())
        .to(ExampleAdvice.class)
        .on(ElementMatchers.isMethod()
          .and(isDeclaredBy(Some.class))
          .and(not(isAbstract()))
          .and(not(isNative()))))
      .make()
      .getBytes();
  }

  public static class ExampleAdvice {
    @OnMethodEnter
    public static void enter(@MethodName String methodName) {
      System.out.println(methodName + ":start");
    }

    @OnMethodExit
    public static void exit(@MethodName String methodName) {
      System.out.println(methodName + ":end");
    }
  }

こんな感じになりました。

実行してみると、Javassistと似たような形でバイトコードが出力されるでしょう。

まとめ

今回はバイトコード操作でロギング処理を追加してみました。

JavassitではJavaのソース文字列ベースでバイトコード操作が可能なのが特徴です。 これはASMで書く時よりもバイトコードに関する知識をあまりなくても非常に楽に取り扱うことができます。 (時と場合によりますが。)

一方、Byte Buddyでは、実際にソースからコンパイルしたバイトコードをベースにバイトコード操作が可能なのが特徴です。 これはJavassistに比べて優秀かというと、コンパイルの検証がコンパイル時になる、という点ではないでしょうか? 実行時に例外が減るのはいいことです。 (Advice次第ではありますが。)

しかし、Byte Buddyでは動的に解決した値に関してインライン化の制限が出てしまいます。 これに対しては、本来静的に解決可能な値であるなら、自分でカスタムした解決処理を追加することで回避できます。 非常に面白いライブラリですね。

どちらも面白いライブラリではありますが Javassistではバイトコードに近い内容の解析も可能なので 使う場面によってライブラリを選ぶべきかとは思います。

次は何書こうかなぁ。