JFR Event Streaming with Java 14

原文はこちら。
The original was written by Michael Bien.
https://mbien.dev/blog/entry/jfr-event-streaming-with-java

Java Flight Recorder (以後JFR) には長い歴史があります。以前はBEA JRockit JVMに含まれていましたが、その後BEAとSunがOracleに買収されたことでOracle JDK (7以後) の商用機能になりました。その後最終的にOpenJDK 11で完全にオープンソース化 (JEP 328) されました(OpenJDK 8へのバックポートがあります)。来年リリース予定のOpenJDK 14でJFRに新機能が追加されます。

JEP 328: Flight Recorder
https://openjdk.java.net/jeps/328

JEP 349でJFRのイベントを同じJVM内からメモリ内で継続的に消費したり、JFRリポジトリファイルを使って別のJVMから取得したりできます。

JEP 349: JFR Event Streaming
https://openjdk.java.net/jeps/349

JEP 349はすでに早期ビルドに取り込まれているので、OpenJDK 14 build 22以後で試すことができます(訳注:2019/12/12現在ではbuild 26)。

JDK 14 Early-Access Builds
https://jdk.java.net/14/

In-Process Streaming

JFRの基本構成ファイル(XML)は、JDK_HOME/lib/jfrにあります。 デフォルト設定(default.jfc)は比較的低いオーバーヘッドですが、profile.jfcの場合、より多くのデータを取得します。Java Mission Control (以後JMC) では、必要に応じてテンプレートに基づいてカスタム設定を作成できます。この例ではデフォルトの設定を使用しています。

JDK Mission Control (AdoptOpenJDK)
https://adoptopenjdk.net/jmc.html

最初の例では、デフォルトのJFR設定を使ってJFRをローカルJVMで開始し、動作確認のためのイベントハンドラを登録しています。

import java.io.IOException;
import java.text.ParseException;
import jdk.jfr.Configuration;
import jdk.jfr.consumer.EventStream;
import jdk.jfr.consumer.RecordingStream;
public class JFRStreamTest {
    
    public static void main(String[] args) throws IOException, ParseException  {
        
        Configuration config = Configuration.getConfiguration("default");
        System.out.println(config.getDescription());
        System.out.println("settings:");
        config.getSettings().forEach((key, value) -> System.out.println(key+": "+value));
        
        // open a stream and start local recording
        try (EventStream es = new RecordingStream(config)) {
            
            // register event handlers
            es.onEvent("jdk.GarbageCollection", System.out::println);
            es.onEvent("jdk.CPULoad", System.out::println);
            es.onEvent("jdk.JVMInformation", System.out::println);
            
            // start and block
            es.start();
        }
    }
}

この例は、実行中のJVMの情報を1回、CPU負荷は定期的に、そしてGCイベントは発生時に出力します。

Out-of-Process Streaming

起動時にjcmd JFR.startまたはJVMのフラグ -XX:+FlightRecorder を使用して、通常どおりJFRを起動します。 リポジトリの場所は、JFRが実行されるとすぐにjdk.jfr.repositoryシステムプロパティに格納されます(Java 14での新機能)。起動時に、JFRのオプションのカンマ区切りリストを使って設定することもできます。

-XX:FlightRecorderOptions=repository=./blackbox

OracleのErikからコメントをもらい、リポジトリの場所はjcmdからも以下のように設定できます。

jcmd <PID> JFR.configure repositorypath=<directory>

記録開始後に設定すると、新規データは新しく設定した場所に記録されます。

$ jcmd -l | grep netbeans
8492 org.netbeans.Main ... --branding nb
 
$ jcmd 8492 JFR.start name=streamtest
Started recording 1. No limit specified, using maxsize=250MB as default.
Use jcmd 8492 JFR.dump name=streamtest filename=FILEPATH to copy recording data to file.
 
$ jinfo -sysprops 8492 | grep jfr
jdk.jfr.repository=/tmp/2019_11_18_02_19_59_8492

上記の例で、記録されていてリポジトリの場所が分かっている状態なので、2個目のJVMはライブのJFRリポジトリへのストリームを開き、アプリケーションを監視できます。JFRの記録をファイルに出力せず、ライブリポジトリに直接接続している点にご注意ください。

import java.io.IOException;
import java.nio.file.Path;
import jdk.jfr.consumer.EventStream;
public class JFRStreamTest {
    
    public static void main(String[] args) throws IOException  {
        // connect to JFR repository
        try (EventStream es = EventStream.openRepository(Path.of("/tmp/2019_11_18_02_19_59_8492"))) {
            
            // register some event handlers
            //es.onEvent("jdk.CPULoad", System.out::println);
            es.onEvent("jdk.SocketRead", System.out::println);
            es.onEvent("jdk.SocketWrite", System.out::println);
            
            // start and block
            es.start();
        }
    }
}

簡単なテストとして、Java 14で動作するNetBeansインスタンスを上記の例を使って監視し、IDEが更新を確認できるようにしました。SocketReadとSocketWriteの両イベントを監視していたので、以下のような出力が出てきました。

jdk.SocketRead {
   startTime = 04:34:09.571
   duration = 117.764 ms
   host = "netbeans.apache.org"
   address = "40.79.78.1"
   port = 443
   timeout = 30.000 s
   bytesRead = 5 bytes
   endOfStream = false
   eventThread = "pool-5-thread-1" (javaThreadId = 163)
   stackTrace = [
     java.net.Socket$SocketInputStream.read(byte[], int, int) line: 68
     sun.security.ssl.SSLSocketInputRecord.read(InputStream, byte[], int, int) line: 457
     sun.security.ssl.SSLSocketInputRecord.decode(ByteBuffer[], int, int) line: 165
     sun.security.ssl.SSLTransport.decode(TransportContext, ByteBuffer[], int, int, …
     sun.security.ssl.SSLSocketImpl.decode(ByteBuffer) line: 1460
     …
   ]
 }
 …

Streaming Dumped Records

もちろん、JFR記録のダンプ (jcmd JFR.dump filename=foo.jfr) へのストリームを開く (EventStream.openFile(path)) こともでき、期待通りに動作します。

Conclusion

かなりクールな新機能です。現時点では、インメモリではなくアウトプロセスでのストリーミングのためには、リポジトリファイルで同期する必要がありますが、RAMディスクでこの問題を簡単に回避できそうです(もちろんリポジトリファイルに永続化することで、原因が分かりづらいクラッシュにおいてもイベントが記録されるので、これはこれで意味があります)。

コメントを残す

以下に詳細を記入するか、アイコンをクリックしてログインしてください。

WordPress.com ロゴ

WordPress.com アカウントを使ってコメントしています。 ログアウト /  変更 )

Google フォト

Google アカウントを使ってコメントしています。 ログアウト /  変更 )

Twitter 画像

Twitter アカウントを使ってコメントしています。 ログアウト /  変更 )

Facebook の写真

Facebook アカウントを使ってコメントしています。 ログアウト /  変更 )

%s と連携中