X

A blog about Oracle Technology Network Japan

Java 14でのJava Flight RecorderとJFR Event Streaming

Guest Author

※本記事は、Ben Evansによる"Java Flight Recorder and JFR Event Streaming in Java 14"を翻訳したものです。


実行中のアプリに関する大量のデータ・ポイントからなるストリームを取得する

 

著者:Ben Evans

2020年2月27日

 

本記事では、Java 14に導入される新機能について説明します。この機能はJFR Event Streaming(JEP 349)と呼ばれており、長い歴史を持つ成熟したプロファイリングおよび監視テクノロジー群の最新版です。

元々のJava Flight Recorder(JFR)ツールとJava Mission Control(JMC)ツールは、2008年にオラクルがBEA Systemsを買収したときに、その一環として獲得したものでした。この2つのコンポーネントは連携して動作します。JFRは低オーバーヘッドのイベントベース・プロファイリング・エンジンで、バイナリ形式でイベントを書き込む高パフォーマンス・バックエンドが搭載されています。一方のJMCは、JVMの遠隔測定機能を使ってJFRが作成したデータファイルを調査するGUIツールです。

元々、これらのツールはBEAのJRockit JVM向けツール製品の一部でしたが、JRockitがJava HotSpot VMに統合される過程で、Oracle JDKの商用バージョンに含まれることになりました。JDK 9のリリース後、オラクルはJavaのリリース・モデルを変更し、JFRとJMCがオープンソース・ツールになることを発表しました。

JFRはOpenJDKに寄贈され、JEP 328としてJDK 11で提供されました。JMCは独立したオープンソース・プロジェクトとなり、現在は別個のダウンロードとして存在しています。

Java 14の到来とともにJFRに新機能が導入され、連続したイベント・ストリームを生成できるようになっています。この変更により、事後にファイルを解析するのではなく、イベントを即時処理するAPIも提供されるようになっています。また、この変更によって、JFR Event Streamingは監視ツールや観測ツールを構築するまたとない土台となります。

ただし、1つ問題があります。JFRとJMCがオープンソース・ツールになったのはごく最近であるため、多くのJava開発者はその高機能さを知らないということです。そこで、Java 14での新機能の紹介に入る前に、JMCとJFRについて最初から説明することにします。


JFRの概要

JFRが初めてオープンソースとして利用できるようになったのは、OpenJDK 11でのことです。そのため、OpenJDK 11(以降)を実行しているか、またはオラクルの顧客として商用JDKを実行している必要があります。

JFRの記録はさまざまな方法で作成できますが、ここでは、JVMの起動時にコマンドライン引数を使用する方法と、jcmdを使用する方法の2つの方法を取り上げます。

まずは、JFRを起動するために必要なコマンドライン・スイッチを確認します。次に示すのは、重要なスイッチです。

-XX:StartFlightRecording:<options>

このスイッチを指定することで、プロセス開始時にJFRの記録が有効になります。Java 14より前のJFRでは、プロファイリング・データのファイルを生成していました。このデータは、1つのダンプ・ファイルにすることも、連続したリング・バッファにすることも可能でした。データをどのようにキャプチャするかは、多数のコマンドライン・オプションで制御します。

また、JFRでは100を超えるメトリックをキャプチャすることができます。ほとんどのメトリックは非常に軽微な影響しか与えませんが、一部には顕著なオーバーヘッドを招くものもあります。それらのメトリックの構成を個々に管理した場合、膨大な作業になってしまいます。そこで、この作業を簡単に行うために、JFRではプロファイリング構成ファイルを使用するようになっています。この構成ファイルは、各メトリックの構成を含む単純なXMLファイルで、それぞれのメトリックをキャプチャするかどうかを指定します。標準のJDKダウンロードには、default.jfcおよびprofile.jfcという2つの基本的なファイルが含まれています。

default.jfcによるデフォルト・レベルの記録は、オーバーヘッドが非常に小さくなるように設計されており、基本的にすべての本番環境のJavaプロセスで使用できるようになっています。profile.jfc構成を使うことで、さらに詳しい情報を取得できますが、当然ながらランタイム・コストは高くなります。

提供されている2つのファイルを使用する以外に、必要なデータ・ポイントだけを含むカスタム構成ファイルを作成することも可能です。JMCツール(次のセクションで説明します)には、このファイルを簡単に作成できるテンプレート・マネージャが搭載されています。

コマンドラインで渡すことができる他のオプションとして、記録されたデータを格納するファイルの名前や、保持するデータの量(データ・ポイント取得からの経過時間で指定します)などがあります。次に示すのは、JFRのコマンドライン全体の例です。

-XX:StartFlightRecording:disk=true,filename=/sandbox/service.jfr,maxage=12h,settings=profile

これにより、詳細なプロファイリング情報を含む、12時間のローリング・バッファが作成されます。このファイルがどこまで大きくなれるかについては、何の指定もしていません。

注:JFRが商用ビルドの一部だったときは、-XX:+UnlockCommercialFeaturesスイッチでアンロックされました。しかし、Oracle JDK 11以降のバージョンでこのオプションを使った場合は、警告が発生します。警告が表示されるのは、商用機能のすべてがオープンソース化されているからです。また、このフラグはOpenJDKには当初から存在しないため、使い続ける意味はありません。OpenJDKビルドでこの商用機能フラグを使った場合は、エラーになります。

JFRの優れた機能の1つとして、JVMの起動時に構成する必要がないという点が挙げられます。JFRは、jcmdプログラムを使ってコマンドラインから起動し、実行中のJVMをUNIXコマンドラインから制御することもできます。次に例を示します。
 

$ jcmd <pid> JFR.start name=Recording1 settings=default
$ jcmd <pid> JFR.dump filename=recording.jfr
$ jcmd <pid> JFR.stop

それだけでなく、アプリケーションの起動後にJFRにアタッチすることもできます。JMC(次のセクションを参照)には、ローカル・マシンで実行されているJVM内のJFRを動的に制御する機能があります。

JFRをどのように起動しても結果は同じで、1つのJVMに対する1回のプロファイリング実行につき、1つのファイルになります。このファイルには大量のバイナリ・データが含まれており、人間が読むことはできません。そのため、データを抽出して視覚化する何らかのツールが必要になります。その1つがJMCです。

 

JMC 7の概要

JMCのグラフィカル・ツールを使って、JFR出力ファイルに含まれるデータを表示してみます。このツールは、jmcコマンドで起動します。以前のJMCはOracle JDKダウンロードにバンドルされていましたが、現在は別個に公開されています。

図1にJMCの起動画面を示します。ファイルをロードすると、JMCは自動分析を行い、実行記録に含まれる明らかな問題を特定します。
 

The JMC startup screen

図1:JMCの起動画面

注:プロファイリングを行うためには、対象のアプリケーションでJFRが有効化されていなければなりません。JMCでは、以前に作成したファイルを使うことに加え、左上のパネルの左側にあるJVM Browserというタブからローカル・アプリケーションに動的にアタッチすることもできます。

JMCで最初に見かける画面の1つに、遠隔測定の概要を示した画面(図2)があります。ここには、JVMの全体的な健全性を示す、概要レベルのダッシュボードが表示されます。
 

Initial telemetry dashboard

図2:最初の遠隔測定ダッシュボード

主要なJVMサブシステムには、すべて専用の画面が割り当てられており、詳しい分析を行うことができます。たとえば、ガベージ・コレクションの概要画面(図3)には、JFRファイルの対象期間全体のガベージ・コレクション・イベントが表示されます。タイムラインで異常に長いガベージ・コレクション・イベントが発生している場合、「Longest Pause」という表示からその場所を確認できます。
 

Garbage collection overview

図3:ガベージ・コレクションの概要

詳細プロファイリング構成では、新しい割当てバッファ(TLAB)がアプリケーション・スレッドに渡されたことを示す個々のイベントを確認することもできます(図4)。これにより、プロセス内のリソースをはるかに正確に確認できるようになります。
 

TLAB allocations

図4:TLAB割当て

TLAB割当てからは、どのスレッドに一番多くメモリを割り当てているかを簡単に確認できます。図4では、Apache Kafkaトピックのデータを使用しているスレッドです。

他の主要なJVMサブシステムに、JITコンパイラがあります。図5からわかるように、JMCを使ってコンパイラの詳細な動作を確認することができます。
 

Watching the compiler

図5:コンパイラの観測

JITコンパイラのコード・キャッシュの利用可能メモリは重要なリソースです。ここには、コンパイルされたメソッドが格納されます。コンパイルされたメソッドが大量に含まれるプロセスでは、このメモリ領域が枯渇し、プロセスがピーク・パフォーマンスに到達しない可能性があります。図6に、このキャッシュに関連するデータを示します。
 

Monitoring the code cache

図6:コード・キャッシュの監視

JMCには、メソッドレベルのプロファイラ(図7)も含まれています。このプロファイラの動作は、VisualVMのプロファイラや、商用ツール(JProfilerやYourKitなど)とよく似ています。
 

Profiling pane

図7:プロファイリング・ペイン

JMCの高度な画面の1つに、VM Operationsビュー(図8)があります。ここには、JVMが実行する内部オペレーションの一部と、それらのオペレーションにかかる時間が表示されます。すべての分析に必要になると考えられるビューではありませんが、特定の種類の問題を検出する際にはとても有効です。
 

Viewing JVM operations

図8:JVMオペレーションの表示

たとえば、ここで視覚化されている重要なデータ・ポイントの1つが、バイアス・ロックの取り消し時間です。ほとんどのプログラムには、JVMのバイアス・ロック・テクノロジー(大まかに言えば、オブジェクトをロックした最初のスレッドが、そのオブジェクトをロックする唯一のスレッドとなる可能性が高いという考え方)が有効です。しかし、一部のワークロード(Apache Cassandraなど)は、バイアス・ロックが悪影響を与えるような設計になっています。VM Operationsビューでは、そのようなケースをとても簡単に見つけることができるでしょう。


プログラムでJFRファイルを解析する

JMCの重要なユースケースは、1つのJVMから作成されたファイルをアプリケーションのプロファイリングや開発のために調べることです。しかし、サービスベースの環境やエンタープライズ環境では、GUIを使ってファイルを1つずつ調査するというモデルがもっとも便利なアプローチであるとは限りません。

それよりも、JFRでキャプチャした生データを解析できるツールを作成し、もっと便利な方法でデータにアクセスして視覚化できるようにしたいと思う方もいるでしょう。ありがたいことに、プログラムからJFRイベントにアクセスできるAPIは、とても簡単に使い始めることができます。

重要なクラスは、jdk.jfr.consumer.RecordingFileとjdk.jfr.consumer.RecordedEventです。RecordingFileクラスにはRecordedEventクラスのインスタンスが含まれています。イベントをただ順番に調べるのは簡単で、次のような単純なJavaコードで実現できます。

var recordingFile = new RecordingFile(Paths.get(fileName));
while (recordingFile.hasMoreEvents()) {
    var event = recordingFile.readEvent();
    if (event != null) {
        var details = decodeEvent(event);
        if (details == null) {
            // Log a failure to recognize details
        } else {
            // Process details
            System.out.println(details);
        }
    }
}

各イベントには、微妙に異なるデータが含まれている可能性があります。そのため、どのような型のデータが記録されているかを考慮したデコード処理が必要になります。この例では、簡略化するため、受け取ったRecordedEventを単純な、文字列のマップに変換しています。

public Map<String, String> decodeEvent(final RecordedEvent e) {
        for (var ent : mappers.entrySet()) {
            if (ent.getKey().test(e)) {
                return ent.getValue().apply(e);
            }
        }
        return null;
    }


    
鍵となるのはデコーダの処理です。このシグネチャは少しばかり複雑です。

private static Predicate<RecordedEvent> testMaker(String s) {
        return e -> e.getEventType().getName().startsWith(s);
    }
    private static final Map<Predicate<RecordedEvent>,
            Function<RecordedEvent, Map<String, String>>> mappers =
                Map.of(testMaker("jdk.ObjectAllocationInNewTLAB"),
                ev -> Map.of("start", ""+ ev.getStartTime(), "end",
                             ""+ ev.getEndTime(),
                             "thread",
                             ev.getThread("eventThread").getJavaName(),
                             "class", ev.getClass("objectClass").getName(),
                             "size", ""+ ev.getLong("allocationSize"),
                             "tlab", ""+ ev.getLong("tlabSize")
               ));

mapperは、ペアのコレクションです。各ペアは、条件と関数で構成されています。条件は、入力イベントの評価に使われます。条件がTRUEを返した場合、関連付けられた関数がイベントに適用され、イベントが文字列のマップに変換されます。

つまり、decodeEvent()メソッドはmapperをループし、入力イベントに一致する条件を探そうとします。一致する条件が見つかった場合、対応する関数が呼び出され、イベントがデコードされます。

JFRが提供する一連のイベントは、Javaのバージョンによって微妙に異なります。Java 11では、120種類を超えるイベントが存在する可能性があります。イベントの種類ごとに微妙に異なるデコーダが必要であるため、すべての種類のイベントをサポートすることは至難の業です。しかし、興味のあるメトリックのサブセットをサポートすることは、容易に実現できます。


Java 14のJFR Event Streaming

Java 14では、JFRを新しいモードで使用できるようになりました。それがJFR Event Streamingです。このAPIを使うことで、JFRイベントが発生したときにコールバックを受け取り、そのコールバックに即座に応答するプログラムを作れるようになります。

開発者がこのAPIを使うと考えられる方法のうち、明らかであり重要なのは、Javaエージェントを用いる方法です。Javaエージェントは、Instrumentation APIを使用する特別なJARファイルです。このAPIでは、クラスで特別な静的メソッドpremain()を宣言し、クラス自体をインスツルメント・ツールとして登録します。次に、Javaエージェントの一例を示します。

public class AgentMain implements Runnable {
    public static void premain(String agentArgs, Instrumentation inst) {
        try {
            Logger.getLogger("AgentMain").log(
                Level.INFO, "Attaching JFR Monitor");
            new Thread(new AgentMain()).start();
        } catch (Throwable t) {
            Logger.getLogger("AgentMain").log(
                Level.SEVERE,"Unable to attach JFR Monitor", t);
        }
    }
    public void run() {
        var sender = new JfrStreamEventSender();
        try (var rs = new RecordingStream()) {
            rs.enable("jdk.CPULoad")
                .withPeriod(Duration.ofSeconds(1));
            rs.enable("jdk.JavaMonitorEnter")
                .withThreshold(Duration.ofMillis(10));
            rs.onEvent("jdk.CPULoad", sender);
            rs.onEvent("jdk.JavaMonitorEnter", sender);
            rs.start();
        }
    }
}

premain()メソッドが呼び出されると、AgentMainの新しいインスタンスが作成され、新しいスレッドで実行されます。構成された記録ストリームは、一度起動すると終了することはありません(そのため、別個のインスツルメント・スレッドで作成されます)。

記録ストリームでは、大量のイベントが生成される可能性があります。ありがたいことに、JFR APIでは、コールバックでの処理が見込まれるイベントの数を減らすための基本的なフィルタリングがいくつか提供されています。
    

  • Enabled:イベントの記録自体を行うかどうかを指定する
  • Threshold:記録されるイベントの最短時間を指定する
  • Stack trace:Event.commit()メソッドでスタック・トレースを記録するかどうかを指定する
  • Period:イベントが定期的に送信される場合、その間隔を指定する

上記以外のフィルタ機能は、アプリケーション・プログラマーが実装しなければならない点に注意してください。たとえば、毎秒数GBを割り当てるJavaプログラム(かなりの割当て量ですが、大規模なアプリケーションでは十分考えられます)では、何十万というイベントがおそらく生成されるでしょう。

先ほどのサンプルJavaエージェントは、記録ストリームを開始し、それぞれのイベントをJfrStreamEventSenderと呼ばれるオブジェクトに送ります。このオブジェクトは、次のようになっています。

public final class JfrStreamEventSender implements Consumer<RecordedEvent> {
    private static final String SERVER_URL = "http://127.0.0.1:8080/events";
    @Override
    public void accept(RecordedEvent event) {
        try {
            var payload = JFRFileProcessor.decodeEvent(event);
            String json = new ObjectMapper().writeValueAsString(payload);
            var client = HttpClient.newHttpClient();
            var request = HttpRequest.newBuilder()
                    .uri(URI.create(SERVER_URL))
                    .timeout(Duration.ofSeconds(30))
                    .header("Content-Type", "application/json")
                    .POST(HttpRequest.BodyPublishers.ofString(json))
                    .build();
            HttpResponse<String> response = 
                client.send(request, HttpResponse.BodyHandlers.ofString());
            Logger.getLogger("JfrStreamEventSender").log(
                Level.INFO, 
                "Server response code: " + response.statusCode() + 
                ", body: " + response.body());
        } catch (IOException | InterruptedException e) {
            Logger.getLogger("JfrStreamEventSender").log(
                Level.SEVERE, "Unable to send JFR event to server", e);
        }
    }
}

このステートレス・クラスでは、イベントをそのまま受け取り、ファイルを処理する場合で示したのと同じようにデコードを行ってから、Jacksonライブラリを使ってJSONにエンコードしています。その後、Java 11 HTTPクライアントを使い、メトリックのペイロードを、その処理が可能なサービスに送信しています。この例で使っているサービスは、localhostのポート8080です。

もちろん、この単純なサンプル・コードから本番グレードのモニタリング・ツールを作るためには、さまざまなことが必要になります。大規模なツールを構築するためには、大量の入力データ・ポイント処理が可能なHTTPエンドポイントの作成が必要です。JVMを一意に特定することや、入力データが正しく分類されていることを保証するといった問題にも対処しなければなりません。

データ分析パイプラインや中期的ストレージ・システム、そしてフロントエンドでの視覚化やページ表示の導入も必要です。本番システムを監視していることから、こういった仕組みのすべてが最大限の信頼性レベルで動作することが不可欠です。

このような難題はありますが、JFR Event Streamingは、アプリケーションを実行しているJVMの監視および観測に使用可能なテクノロジーにおける大きな一歩を表しています。この新しいAPIは大きな注目を集めています。そしておそらく、Java 14のリリース後まもなく、オープンソースのトレーシングおよび監視ライブラリにイベント・ストリーミングのサポートが追加されることになるでしょう。監視やプロファイリングにおけるJFRのアプローチにはメリットがあります。そのメリットが皆さんのJVMのもとにやってくるのは、まもなくです。


Ben Evans

Ben Evans(@kittylyst):Java Champion。New Relicのプリンシパル・エンジニア。『Optimizing Java』(O'Reilly)を含め、プログラミングに関する5冊の書籍を執筆している。jClarity(Microsoftにより買収)の創業者の1人であり、Java SE/EE Executive Committeeの元メンバーである。

Be the first to comment

Comments ( 0 )
Please enter your name.Please provide a valid email address.Please enter a comment.CAPTCHA challenge response provided was incorrect. Please try again.