JDK Flight Recorder入門

Transcript

1. - Getting Started JDK Flight Recorder -
   JDK Flight Recorder入門
   JJUG CCC 2022 Spring
   2022年 6月19日
   1
   

   View Slide

2. 自己紹介
   伊藤ちひろ (Chihiro Ito) @Red Hat
   OpenJDK Committer
   Java Platform Advocate, Specialist Solution Architect
   Twitter : @chiroito
   2
   

   View Slide

3. アジェンダ
   3
   本日の内容 ▸ JDK Flight Recorderとは？
   ▸ JFRの起動停止
   ▸ 独自情報の記録
   ▸ 情報の使い方
   ▸ 実際の使い方
   

   View Slide

4. JDK Flight Recorder (JFR)
   Java用プロファイリングおよびイベント収集フレームワーク
   アプリケーションの動作に関する低レベルの情報を収集
   OpenJDKに組み込まれる
   OpenJDK 11+および8でデフォルトで利用可能
   カスタムイベント対応
   アプリケーション固有のイベントを登録・捕捉するための
   API
   JDK Mission Control (JMC)と組み合わせる
   JMCはJFRの記録を管理し、可視化できる
   4
   Source:
   https://docs.oracle.com/en/java/java-components/jdk-mission-control/8/user-guide/using-jdk-flight-recorder.html
   JDK Flight Recorder (JFR)
   JFRについて
   

   View Slide

5. JFRで何が分かるの？
   5
   各スレッドが何をしているか
   選択したイベントのスタックトレース
   時系列でスレッドが何をしているのかを表示
   （クラスロードや最適化など JVM内部の情報も表示される）
   スレッド一覧
   イベントを選択
   

   View Slide

6. JFRで何が分かるの？
   6
   JVMの状況 - ガベージコレクション -
   各種メモリの使用状況
   発生したGC一覧 選択したGCの詳細
   

   View Slide

7. JFRで何が分かるの？
   7
   JVMの状況 - コンパイル -
   コンパイルの対象や時間などの情報
   コンパイルにかかった時間の統計
   

   View Slide

8. JDK Flight Recorder (JFR)
   OpenJDK 11以降のメジャーバージョン
   OpenJDK 8 update 262以降（一部のベンダー）
   OpenJDK 8 update 272以降（全てのベンダー）
   8
   JDK Flight Recorder (JFR)
   使えるバージョン
   

   View Slide

9. JDK Flight Recorder (JFR)
   9
   JDK Flight Recorder (JFR)
   運用の流れ
   Java仮想マシン
   アプリ
   JFRファイル
   JDK Mission
   Control
   jfrコマンド
   JFR API
   可視化ツール
   CSV/JSON
   設定 構成ファイル
   

   View Slide

10. Java仮想マシン
    JDK Flight Recorder (JFR)
    10
    JDK Flight Recorder (JFR)
    アーキテクチャ概要
    Local Buffer
    Local Buffer
    Buffer
    Buffer
    Buffer
    Buffer
    Global Buffer
    Local Buffer
    JFR Periodic Tasks
    JFR リポジトリ
    ファイル
    Thread
    Thread
    

    View Slide

11. 11
    JFRの起動停止
    

    View Slide

12. JFRの起動停止
    ファイルの場所：$JAVA_HOME/lib/jfr
    default.jfc
    一般的な環境では負荷が1%未満になり、本番環境でも継続して使える構成ファイル
    profile.jfc
    一般的な環境では負荷が2%程度になり、分析をするときに使える構成ファイル
    上記の負荷は、”一般的な環境”なので必ずしもそうなるわけではない。記録量が多いと負荷は十分高くなる。
    12
    JDK Flight Recorder (JFR)
    JFRの構成ファイル
    

    View Slide

13. JFRの起動停止
    13
    JDK Flight Recorder (JFR)
    記録の状態
    NEW
    DELAYED
    RUNNING
    STOPPED
    CLOSED
    

    View Slide

14. JFRの起動停止
    JVM起動時に開始
    javaコマンドの実行時に-XX:StartFlightRecordingオプションを付与
    JFR API
    jdk.jfr.Recordingクラスを使用
    JCMD
    jcmdコマンドのJFRが接頭辞につくサブコマンドを実行
    MBean
    JMXで接続（ツールなどはこちら経由でアクセスしていますが、入門の範囲を超えるので説明は省略）
    14
    JDK Flight Recorder (JFR)
    JFRの操作方法
    

    View Slide

15. JFRの起動停止
    15
    JDK Flight Recorder (JFR)
    JVM起動時にJFRを開始
    オプション 説明
    name 記録の名前、数字だけではダメ
    settings 記録する構成名、デフォルトは default.jfc
    delay 起動から記録開始するまでの時間、指定する場合は 1秒以上を指定
    duration 記録を開始してから自動で終了するまでの時間、指定する場合は 1秒以上を指定
    disk 記録中にデータをディスクへ書き込むかどうか
    maxage ディスクに保存する最大時間、 s/m/hを指定可能
    maxsize ディスクに保存するデータの最大バイトサイズ、 m/M/g/Gを指定可能
    flush-interval メモリからディスクへ書き込む周期
    dumponexit JVM終了時に記録をダンプするかどうか
    filename ダンプさせるファイルパス名
    path-to-gc-roots GCのルートへのパスを収集するフラグ
    -XX:StartFlightRecording=オプション1=値1,オプション2=値2,...
    

    View Slide

16. JFRの起動停止
    Configuration c = Configuration.getConfiguration("default");
    Recording r = new Recording(c);
    r.start();
    // 処理
    r.stop();
    r.dump(Paths.get("my-recording.jfr"));
    16
    JDK Flight Recorder (JFR)
    JFR APIによる起動停止
    

    View Slide

17. JFRの起動停止
    jcmd JFR.start [オプション1=値1,オプション2=値2,...]
    jcmd JFR.stop name=名前 [filename=パス]
    jcmd JFR.dump [name=値] [maxage=値] [maxsize=値] [begin=値] [end=値] [filename=値]
    jcmd JFR.check [name=名前] [verbose=値]
    jcmd JFR.configure [オプション=値]
    17
    JDK Flight Recorder (JFR)
    JCMDによる起動停止
    

    View Slide

18. 18
    独自情報の記録
    

    View Slide

19. 独自情報の記録
    イベントの定義方法
    事前定義イベント（推奨）
    クラスとしてイベントの定義を作成する
    動的イベント
    イベントのクラスを作らずに、
    実行時にイベントの定義を作成する
    19
    JDK Flight Recorder (JFR)
    イベントの定義と記録方法
    イベントの記録方法
    期間イベント
    イベントとして記録したい処理の前後で記録
    周期的なイベント
    一定期間ごとにイベントを記録する
    

    View Slide

20. 独自情報の記録
    import jdk.jfr.*;
    @Label("Hello World")
    @Description("Helps programmer getting started")
    @Category({"Example", "Getting Started"})
    public class HelloWorldEvent extends Event {
    @Label("Message")
    String message;
    @Label("Number")
    int number;
    }
    20
    JDK Flight Recorder (JFR)
    事前定義イベント
    HelloWorldEvent event = new HelloWorldEvent();
    event.message = "hello, world!";
    event.number = 4711;
    event.begin();
    // 処理
    event.commit();
    ポイント：
    ● jdk.jfr.Eventを継承
    ● 記録したい情報をフィールドとして定義
    ● 必要に応じてアノテーションを付ける
    

    View Slide

21. 独自情報の記録
    import jdk.jfr.*;
    import java.util.*;
    import static java.util.Collections.*;
    List fields = new ArrayList<>();
    fields.add(new ValueDescriptor(String.class, "message", singletonList(new AnnotationElement(Label.class, "Message"))));
    fields.add(new ValueDescriptor(int.class, "number", singletonList(new AnnotationElement(Label.class, "Number"))));
    List eventAnnotations = new ArrayList<>();
    eventAnnotations.add(new AnnotationElement(Name.class, "com.example.HelloWorldEvent"));
    eventAnnotations.add(new AnnotationElement(Label.class, "Hello World"));
    eventAnnotations.add(new AnnotationElement(Description.class, "Helps programmer getting started"));
    eventAnnotations.add(new AnnotationElement(Category.class, new String[]{ "Example", "Getting Started" }));
    EventFactory f = EventFactory.create(eventAnnotations, fields);
    Event event = f.newEvent();
    event.set(0, "hello, world!");
    event.set(1, 4711);
    event.begin();
    // 処理
    event.commit();
    21
    JDK Flight Recorder (JFR)
    動的イベント
    

    View Slide

22. 独自情報の記録
    jdk.jfr.FlightRecorder.addPeriodicEvent(Class extends Event> eventClass, Runnable hook)を使用
    eventClassに指定したイベントが有効かなどを考慮して
    eventClassに指定されてる周期でhookを実行してくれる
    Runnableでイベントを書く処理を実装。
    22
    JDK Flight Recorder (JFR)
    周期的なイベント記録
    

    View Slide

23. 独自情報の記録
    @Period("1 s")
    public class PeriodicEvent extends Event {
    public int number;
    }
    23
    JDK Flight Recorder (JFR)
    周期的なイベント記録
    FlightRecorder.addPeriodicEvent(PeriodicEvent.class, () -> {
    PeriodicEvent event = new PeriodicEvent ();
    event.number = 4711;
    event.commit();
    });
    

    View Slide

24. 24
    情報の使い方
    

    View Slide

25. 情報の使い方
    JDK Mission Control
    jfr コマンド
    JFR Consumer API
    JFR Event Streaming API
    25
    JDK Flight Recorder (JFR)
    活用方法
    

    View Slide

26. 情報の使い方
    JFRファイルに記録されている情報を見るためのアプリケーション
    OpenJDKプロジェクトの一部
    ベンダーによってJDKに同梱されていたり、いなかったりする
    ベンダーによって個別にダウンロードできる
    26
    JDK Flight Recorder (JFR)
    JDK Mission Control
    

    View Slide

27. 情報の使い方
    JFRのコマンドラインインターフェース（
    CLI）ツール
    JFRファイルのメタデータやイベントをテキスト（
    XML, JSONなど）で出力
    リポジトリに残ったファイルからJFRファイルを作成
    JFRファイルを分割
    27
    JDK Flight Recorder (JFR)
    jfrコマンド
    

    View Slide

28. 情報の使い方
    JFRファイルに含まれる情報の一覧を取得
    jfr metadata | grep @Name
    情報をCSVへ変換
    jfr print --json --events <イベント名> |
    jq -r ".recording.events[].values | [<出力したい要素を羅列>] | @csv"
    抽出例
    jfr print --json --events jdk.CPULoad |
    jq -r ".recording.events[].values | [.startTime, .jvmUser, .jvmSystem, .machineTotal] | @csv"
    28
    JDK Flight Recorder (JFR)
    jfrコマンドの使用例
    

    View Slide

29. 情報の使い方
    29
    JDK Flight Recorder (JFR)
    JFR Consumer API
    import jdk.jfr.consumer.*;
    import java.nio.file.paths;
    try (RecordingFile recordingFile = new RecordingFile(Paths.get("dump.jfr"))) {
    while (recordingFile.hasMoreEvents()) {
    RecordedEvent event = recordingFile.readEvent();
    if(event.getEventType().getLabel().equals("Hello World")) {
    System.out.println(event.getString("message"));
    }
    }
    }
    

    View Slide

30. 情報の使い方
    30
    JDK Flight Recorder (JFR)
    JFR Event Streaming API
    import jdk.jfr.consumer.*;
    try (EventStream es = EventStream.openRepository()) {
    es.onEvent("HelloWorld", event -> {
    System.out.println(event.getString("message"));
    });
    es.startAsync();
    // 処理
    }
    

    View Slide

31. 情報の使い方
    31
    JDK Flight Recorder (JFR)
    JFR Event Streaming API with Framework
    import jdk.jfr.consumer.*;
    private EventStream es;
    public void start(){
    es = EventStream.openRepository();
    es.onEvent("HelloWorld", event -> {
    System.out.println(event.getString("message"));
    });
    es.startAsync();
    }
    public void stop(){
    es.close()
    }
    

    View Slide

32. 32
    実際の使い方
    

    View Slide

33. 実際の使い方
    問題を事前に予期できるようにする
    ● リクエストの処理時間が伸びてないかなどを確認できるようにする
    対象のプロセスの中で問題が起きているのか、外で起きているのかを判断できるようにする
    ● 通信などのI/Oで問題が起きていれば外の可能性が高い
    プロセスの中で問題が起きているならその原因を特定できるようにする
    ● JVMの情報は標準で十分取れるので、アプリケーションのどこで問題が起きているかを特定できるようにする
    33
    JDK Flight Recorder (JFR)
    情報を使う目的
    

    View Slide

34. 実際の使い方
    34
    JDK Flight Recorder (JFR)
    RESTアプリケーションのシーケンス
    クライアント アプリケーション JDKの通信ライブラリ サービスやRDB
    アプリケーションの処理時間
    HTTPリクエスト
    HTTレスポンス
    APIとして実装したの処理時間
    REST API/SQL など サービスやRDBの処理時間
    フレームワークの処理時間
    クライアントから見た
    処理時間
    Javaが通信と認識する時間
    JDBCやREST Clientライブラリ
    を使って通信する時間
    （RetryやTimeoutを考慮）
    外部から情報を読み書きする処
    理にかかる時間
    JFRで取られる情報
    

    View Slide

35. 実際の使い方
    JVMという低レイヤの情報しかない
    ● 通信の情報　　：通信期間、通信相手、データ量
    ● ファイルの情報：アクセス期間、アクセス先、データ量
    ● スレッド　　　：期間、状態
    どの業務で何の処理をしているときに問題が発生しているか分からない
    35
    JDK Flight Recorder (JFR)
    標準イベントだけの課題
    

    View Slide

36. 実際の使い方
    ● どの業務のどの処理を実行しているのか（最も広い範囲の情報）
    ● どの外部呼び出しを実行しているのか（
    SQL、REST APIの呼び出しなど）
    ● アプリケーションとフレームワークのどこで問題が起きているか
    ● 問題時に切り分けられる情報を含める
    ○ ユーザ情報や商品情報など
    36
    JDK Flight Recorder (JFR)
    足した方が良い情報
    

    View Slide

37. 実際の使い方
    37
    JDK Flight Recorder (JFR)
    RESTアプリケーションのシーケンス
    クライアント アプリケーション JDKの通信ライブラリ サービスやRDB
    アプリケーションの処理時間
    HTTPリクエスト
    HTTレスポンス
    APIとして実装したの処理時間
    REST API/SQL など サービスやRDBの処理時間
    フレームワークの処理時間
    クライアントから見た
    処理時間
    Javaが通信と認識する時間
    JDBCやREST Clientライブラリ
    を使って通信する時間
    （RetryやTimeoutを考慮）
    外部から情報を読み書きする処
    理にかかる時間
    JFRで取られる情報
    処理時間の全体の変化が分か
    るようになる
    何をリクエストしているのかが
    わかる
    リトライを考慮した情報が取れ
    る
    処理全体の時間
    

    View Slide

38. 実際の使い方
    まずは包括的に取るためにServletFilterやInterceptor、Listenerなどを活用する
    ● アプリの実装者はJFRを使った実装について意識しなくて良くなる。
    ● 優先度は最高と最低の両方で実装する（その間で実行される処理の問題を検出するため）
    何かしらの方法でグループを作ってイベントを分ける
    ● １つ１つのイベントを作ると、情報が増えすぎて見るのが大変
    ● １つのイベントで汎用的に収集すると、取得した情報の活用が難しい。
    ● URLのパスやデプロイ単位が良い感じに分割されているとグループ化しやすい
    Tracingを利用しているならその識別子を含める
    ● 異なるプロセス間での情報の連携が容易になる
    38
    JDK Flight Recorder (JFR)
    実装のポイント
    

    View Slide

39. 実際の使い方
    39
    JDK Flight Recorder (JFR)
    インターセプターの例
    @Priority(1)
    @Interceptor
    public class PaymentRepositoryInterceptor {
    @AroundInvoke
    Object repositoryInvocation(InvocationContext context) throws Exception {
    String traceId = ...;
    String paymentId = ...;
    String methodName = context.getMethod().getName();
    Event event = new CustomerRepositoryEvent(traceId, paymentId, methodName);
    event.begin();
    try {
    return context.proceed();
    } finally {
    event.commit();
    }
    }
    }
    

    View Slide

40. 実際の使い方
    40
    JDK Flight Recorder (JFR)
    リトライする処理の例
    public class ServiceXClient{
    @Retry
    Response xxx(String var1){
    // 個別実行の情報
    Event event = new ServiceXEvent(var1);
    event.begin();
    // 処理
    event.commit();
    }
    }
    ServiceXClient serviceX = ..;
    // リトライも含めた情報
    Event event = new ServiceXWholeEvent(var1);
    event.begin();
    // リトライされる可能性がある処理
    serviceX.xxx(var1);
    event.commit();
    

    View Slide

41. 実際の使い方
    41
    JDK Flight Recorder (JFR)
    JDBCの例
    Statement jdbcStatement = …;
    Event StatementEvent event = new StatementEvent(sql);
    event.begin();
    ResultSet rs = jdbcStatement.executeQuery(sql);
    event.commit();
    DBアクセスはライブラリによって隠ぺいされることが多く手を入れづらい。
    Jfr4JDBCというライブラリを利用して情報を取ることをお奨めします。
    https://github.com/chiroito/Jfr4Jdbc/blob/master/README.ja.md
    

    View Slide

42. JDK Flight Recorder
    ● みなさんが使っているJavaでもJFRが使えるはずなので、機能を有効にしましょう
    ● まずはデフォルトの構成で情報を取ってみましょう
    ● JMCで確認するところから初めて、jfrコマンドを使って既存の監視ツールに統合してみましょう
    ● アプリケーションに独自イベントを導入して、より有益な情報を取れるようにしてみましょう
    42
    JDK Flight Recorder (JFR)
    まとめ
    

    View Slide

43. 43
    Red Hat is the world’s leading provider of enterprise
    open source software solutions. Award-winning
    support, training, and consulting services make
    Red Hat a trusted adviser to the Fortune 500.
    Thank you
    

    View Slide