カスタムイベント

カスタムイベントとは？

JFRは2章で説明したようにJVM/OSの値やJava標準APIのいくつかの値はデフォルトで取得します。 しかし、実際にアプリケーションの診断を効果的にやろうとするとそれだけでは足らず、ミドルウェアや自分たちで書いているアプリケーションの値自身も取得したくなります。

それを実現するための仕組みがカスタムイベントです。JDK8までは非公式APIでしたが、JDK9から導入されたFlight Recorder APIにより現在は公式なAPIとして利用可能です。

カスタムイベントに関しては以下のドキュメントにまとまっています。 Flight Recorder APIプログラマーズ・ガイド: 第II部 イベントの作成

これによりWebのレスポンスやSQLの情報を記録したり、自作の共通ライブラリなどをフックして情報を詳細に取得することが可能になります。

簡単なイベントを作成してみる

とりあえずは書いてみるのが一番なので、まず簡単なイベントを作成してみましょう。 カスタムイベントはjdk.jfr.Eventを継承する事で簡単に作成できます。

import jdk.jfr.Event;
import jdk.jfr.Label;
import jdk.jfr.Name;

@Name("dev.nklab.myapp.Hello")
@Label("Hello World!")
public class Hello extends Event {

    @Label("Message")
    public String msg;
}

使う時は以下のようにイベントを初期化してbeginとcommitで計測したい間の処理を挟みます。

public class Main {
    public static void main(String[] arg) {
        var event = new HelloEvent();
        event.begin();
        System.out.println("Hello JFR");
        event.msg = "Hello world!";
        event.commit();
    }
}

では実行してみましょう。JFRを出力したいので-XX:StartFlightRecording:をつけます。ちなみにつけずに実行しても問題なく動作しますがJFRは生成されません。

$ java -XX:StartFlightRecording:filename=profile.jfr -cp . chapter06.Main
Started recording 1. No limit specified, using maxsize=250MB as default.

Use jcmd 8416 JFR.dump name=1 to copy recording data to file.
Hello JFR

profile.jfrという形でJFRファイルがダンプされているのでjfrコマンドで中身を確認してみます。すべてのイベントを出力すると量が多いのでHelloイベントでフィルタリングしています。

$ jfr print --events Hello profile.jfr
dev.nklab.myapp.Hello {
  startTime = 00:07:01.010
  duration = 0.414 ms
  msg = "Hello world!"
  eventThread = "main" (javaThreadId = 1)
  stackTrace = [
    chapter06.Main.main(String[]) line: 19
  ]
}

startTimeとdurationが自動で登録されました。これはbeginとcommitの部分を計測しています。msgはHelloイベントに定義したフィールドです。こちらをJFRのプロパティとして任意の値を格納することが出来ます。

また、ここで表示されているイベントタイプは実際のクラスの完全修飾クラス名ではなく@Nameで指定した値で上書きされます。 JFRの「イベントのネーミングおよびラベル付けのガイドライン」では、@Nameを本番では省略するべきではないとしています。

それはイベント名では意味が重複するので「event」「Event」のような名前を付けないという事が推奨されているのですが、パッケージ名や実際のクラス名には分類のためにそれが登場する可能性が高いためです。リファクタリング等でパッケージ名等が変わっても継続して既存の名前でJFR側では解析できるという点も重要です。

続いて同じJFRファイルをJCMで開いてみましょう。

EventBrowserから同じくHelloイベントが確認できます。

イベントタイプがdev.nklab.myapp.HelloではなくHello World!であること、カラム名がmsgではなくMessageな事に注目してください。これは@Labelによって実際の表示を上書きしているためです。

また、今回は特に指定していないのでカテゴリが「 Uncategorized 」になっています。これは見栄えの点でも検索性の点でも良くないので@Cateogryを使いカテゴリを指定します。

@Category("MyApp")
@Name("dev.nklab.myapp.Hello")
@Label("Hello World!")
public class HelloEvent extends Event {
    @Label("Message")
    public String msg;
}

MyAppでカテゴライズされていますね。これで任意のカテゴリに分類できます。以下のようにカテゴリを階層化する事も出来ます。

@Category({"My App", "Frontend", "Business Logic1"})
@Name("dev.nklab.myapp.Hello")
@Label("Hello World!")
public class HelloEvent extends Event {