JDK Flight Recorder入門

Transcript

1. - Getting Started JDK Flight Recorder - JDK Flight Recorder入門 JJUG CCC 2022 Spring 2022年 6月19日 1
2. 自己紹介 伊藤ちひろ (Chihiro Ito) @Red Hat OpenJDK Committer Java Platform Advocate, Specialist Solution Architect Twitter : @chiroito 2
3. アジェンダ 3 本日の内容 ▸ JDK Flight Recorderとは？ ▸ JFRの起動停止 ▸ 独自情報の記録 ▸ 情報の使い方 ▸ 実際の使い方
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について
5. JFRで何が分かるの？ 5 各スレッドが何をしているか 選択したイベントのスタックトレース 時系列でスレッドが何をしているのかを表示 （クラスロードや最適化など JVM内部の情報も表示される） スレッド一覧 イベントを選択
6. JFRで何が分かるの？ 6 JVMの状況 - ガベージコレクション - 各種メモリの使用状況 発生したGC一覧 選択したGCの詳細
7. JFRで何が分かるの？ 7 JVMの状況 - コンパイル - コンパイルの対象や時間などの情報 コンパイルにかかった時間の統計
8. JDK Flight Recorder (JFR) OpenJDK 11以降のメジャーバージョン OpenJDK 8 update 262以降（一部のベンダー） OpenJDK 8 update 272以降（全てのベンダー） 8 JDK Flight Recorder (JFR) 使えるバージョン
9. JDK Flight Recorder (JFR) 9 JDK Flight Recorder (JFR) 運用の流れ Java仮想マシン アプリ JFRファイル JDK Mission Control jfrコマンド JFR API 可視化ツール CSV/JSON 設定 構成ファイル
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
11. 11 JFRの起動停止
12. JFRの起動停止 ファイルの場所：$JAVA_HOME/lib/jfr default.jfc 一般的な環境では負荷が1%未満になり、本番環境でも継続して使える構成ファイル profile.jfc 一般的な環境では負荷が2%程度になり、分析をするときに使える構成ファイル 上記の負荷は、”一般的な環境”なので必ずしもそうなるわけではない。記録量が多いと負荷は十分高くなる。 12 JDK Flight Recorder (JFR) JFRの構成ファイル
13. JFRの起動停止 13 JDK Flight Recorder (JFR) 記録の状態 NEW DELAYED RUNNING STOPPED CLOSED
14. JFRの起動停止 JVM起動時に開始 javaコマンドの実行時に-XX:StartFlightRecordingオプションを付与 JFR API jdk.jfr.Recordingクラスを使用 JCMD jcmdコマンドのJFRが接頭辞につくサブコマンドを実行 MBean JMXで接続（ツールなどはこちら経由でアクセスしていますが、入門の範囲を超えるので説明は省略） 14 JDK Flight Recorder (JFR) JFRの操作方法
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,...
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による起動停止
17. JFRの起動停止 jcmd <PID> JFR.start [オプション1=値1,オプション2=値2,...] jcmd <PID> JFR.stop name=名前 [filename=パス] jcmd <PID> JFR.dump [name=値] [maxage=値] [maxsize=値] [begin=値] [end=値] [filename=値] jcmd <PID> JFR.check [name=名前] [verbose=値] jcmd <PID> JFR.configure [オプション=値] 17 JDK Flight Recorder (JFR) JCMDによる起動停止
18. 18 独自情報の記録
19. 独自情報の記録 イベントの定義方法 事前定義イベント（推奨） クラスとしてイベントの定義を作成する 動的イベント イベントのクラスを作らずに、 実行時にイベントの定義を作成する 19 JDK Flight Recorder (JFR) イベントの定義と記録方法 イベントの記録方法 期間イベント イベントとして記録したい処理の前後で記録 周期的なイベント 一定期間ごとにイベントを記録する
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を継承 • 記録したい情報をフィールドとして定義 • 必要に応じてアノテーションを付ける
21. 独自情報の記録 import jdk.jfr.*; import java.util.*; import static java.util.Collections.*; List<ValueDescriptor> 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<AnnotationElement> 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) 動的イベント
22. 独自情報の記録 jdk.jfr.FlightRecorder.addPeriodicEvent(Class<? extends Event> eventClass, Runnable hook)を使用 eventClassに指定したイベントが有効かなどを考慮して eventClassに指定されてる周期でhookを実行してくれる Runnableでイベントを書く処理を実装。 22 JDK Flight Recorder (JFR) 周期的なイベント記録
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(); });
24. 24 情報の使い方
25. 情報の使い方 JDK Mission Control jfr コマンド JFR Consumer API JFR Event Streaming API 25 JDK Flight Recorder (JFR) 活用方法
26. 情報の使い方 JFRファイルに記録されている情報を見るためのアプリケーション OpenJDKプロジェクトの一部 ベンダーによってJDKに同梱されていたり、いなかったりする ベンダーによって個別にダウンロードできる 26 JDK Flight Recorder (JFR) JDK Mission Control
27. 情報の使い方 JFRのコマンドラインインターフェース（ CLI）ツール JFRファイルのメタデータやイベントをテキスト（ XML, JSONなど）で出力 リポジトリに残ったファイルからJFRファイルを作成 JFRファイルを分割 27 JDK Flight Recorder (JFR) jfrコマンド
28. 情報の使い方 JFRファイルに含まれる情報の一覧を取得 jfr metadata <JFR file> | grep @Name 情報をCSVへ変換 jfr print --json --events <イベント名> <JFR file> | jq -r ".recording.events[].values | [<出力したい要素を羅列>] | @csv" 抽出例 jfr print --json --events jdk.CPULoad <JFR file> | jq -r ".recording.events[].values | [.startTime, .jvmUser, .jvmSystem, .machineTotal] | @csv" 28 JDK Flight Recorder (JFR) jfrコマンドの使用例
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")); } } }
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(); // 処理 }
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() }
32. 32 実際の使い方
33. 実際の使い方 問題を事前に予期できるようにする • リクエストの処理時間が伸びてないかなどを確認できるようにする 対象のプロセスの中で問題が起きているのか、外で起きているのかを判断できるようにする • 通信などのI/Oで問題が起きていれば外の可能性が高い プロセスの中で問題が起きているならその原因を特定できるようにする • JVMの情報は標準で十分取れるので、アプリケーションのどこで問題が起きているかを特定できるようにする 33 JDK Flight Recorder (JFR) 情報を使う目的
34. 実際の使い方 34 JDK Flight Recorder (JFR) RESTアプリケーションのシーケンス クライアント アプリケーション JDKの通信ライブラリ サービスやRDB アプリケーションの処理時間 HTTPリクエスト HTTレスポンス APIとして実装したの処理時間 REST API/SQL など サービスやRDBの処理時間 フレームワークの処理時間 クライアントから見た 処理時間 Javaが通信と認識する時間 JDBCやREST Clientライブラリ を使って通信する時間 （RetryやTimeoutを考慮） 外部から情報を読み書きする処 理にかかる時間 JFRで取られる情報
35. 実際の使い方 JVMという低レイヤの情報しかない • 通信の情報　　：通信期間、通信相手、データ量 • ファイルの情報：アクセス期間、アクセス先、データ量 • スレッド　　　：期間、状態 どの業務で何の処理をしているときに問題が発生しているか分からない 35 JDK Flight Recorder (JFR) 標準イベントだけの課題
36. 実際の使い方 • どの業務のどの処理を実行しているのか（最も広い範囲の情報） • どの外部呼び出しを実行しているのか（ SQL、REST APIの呼び出しなど） • アプリケーションとフレームワークのどこで問題が起きているか • 問題時に切り分けられる情報を含める ◦ ユーザ情報や商品情報など 36 JDK Flight Recorder (JFR) 足した方が良い情報
37. 実際の使い方 37 JDK Flight Recorder (JFR) RESTアプリケーションのシーケンス クライアント アプリケーション JDKの通信ライブラリ サービスやRDB アプリケーションの処理時間 HTTPリクエスト HTTレスポンス APIとして実装したの処理時間 REST API/SQL など サービスやRDBの処理時間 フレームワークの処理時間 クライアントから見た 処理時間 Javaが通信と認識する時間 JDBCやREST Clientライブラリ を使って通信する時間 （RetryやTimeoutを考慮） 外部から情報を読み書きする処 理にかかる時間 JFRで取られる情報 処理時間の全体の変化が分か るようになる 何をリクエストしているのかが わかる リトライを考慮した情報が取れ る 処理全体の時間
38. 実際の使い方 まずは包括的に取るためにServletFilterやInterceptor、Listenerなどを活用する • アプリの実装者はJFRを使った実装について意識しなくて良くなる。 • 優先度は最高と最低の両方で実装する（その間で実行される処理の問題を検出するため） 何かしらの方法でグループを作ってイベントを分ける • １つ１つのイベントを作ると、情報が増えすぎて見るのが大変 • １つのイベントで汎用的に収集すると、取得した情報の活用が難しい。 • URLのパスやデプロイ単位が良い感じに分割されているとグループ化しやすい Tracingを利用しているならその識別子を含める • 異なるプロセス間での情報の連携が容易になる 38 JDK Flight Recorder (JFR) 実装のポイント
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(); } } }
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();
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
42. JDK Flight Recorder • みなさんが使っているJavaでもJFRが使えるはずなので、機能を有効にしましょう • まずはデフォルトの構成で情報を取ってみましょう • JMCで確認するところから初めて、jfrコマンドを使って既存の監視ツールに統合してみましょう • アプリケーションに独自イベントを導入して、より有益な情報を取れるようにしてみましょう 42 JDK Flight Recorder (JFR) まとめ
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