JVM 終了時の ShutdownHook が動きません

tl;dr
ことの経緯
そもそもシャットダウン・フック何？

tl;dr

Windows 環境で Java のシャットダウン・フックが動作しない事象があったのでその経緯をログとして残します。

結論としては jdk-21.0.2 前後でシャットダウン・フックの挙動が異なるようだ。

JDK	OK/NG
jdk-21.0.8+9	NG
jdk-21.0.7+6	NG
jdk-21.0.6+7	NG
jdk-21.0.5+11	NG
jdk-21.0.4+7	NG
jdk-21.0.3+9	NG
jdk-21.0.2+13	NG
jdk-21.0.1+12	OK
jdk-21+35	OK

jdk-21+35 と jdk-21.0.1+12 ではシャットダウン・フックが動作するが、それより新しいJDKではシャットダウン・フックが動作しないように見える(動作しているようだが、処理の途中で強制終了して、シャットダウン・フックの処理が完了しない)。

ことの経緯

Windows Server 上で、サービスとして起動しているアプリケーションの終了時に、JFR のダンプファイルが生成されない事象があった。

以下のようなオプションを指定しており、

-XX:StartFlightRecording=name=xxx,dumponexit=true,filename=myrecording.jfr

dumponexit=true としているため、JVM 終了時に myrecording.jfr にダンプデータが書き出されるハズだが、これが書き出されない(起動時に生成された0バイトファイルのまま)(JFR のリポジトリにはチャンクファイルの残骸がJVM終了後も残り続ける)。

dumponexit によるダンプファイル生成はシャットダウン・フックにより行われるので、シャットダウン・フックが動いていなさそうだ。

Windows のサービスは、WinSW で起動しているため、WinSW がプロセスを kill している可能性がある？

WinSW のサービス停止処理は以下のようになっており、

    private static void StopProcess(Process process, TimeSpan stopTimeout)
    {
        Logger.Debug($"Stopping process {process.Id}...");

        if (process.HasExited)
        {
            goto Exited;
        }

        if (SendCtrlC(process) is not bool sent)
        {
            goto Exited;
        }

        if (!sent)
        {
            try
            {
                sent = process.CloseMainWindow();
            }
            catch (InvalidOperationException)
            {
                goto Exited;
            }
        }

        if (sent)
        {
            if (process.WaitForExit((int)stopTimeout.TotalMilliseconds))
            {
                Logger.Debug($"Process {process.Id} canceled with code {process.ExitCode}.");
                return;
            }
        }

#if NET
        process.Kill();
#else
        try
        {
            process.Kill();
        }
        catch when (process.HasExited)
        {
        }
#endif

        Logger.Debug($"Process {process.Id} terminated.");
        return;

    Exited:
        Logger.Debug($"Process {process.Id} has already exited.");
    }

WinSW のログには以下のように出力されている。

Process 999 canceled with code -1073741510.

終了コードの -1073741510 はつまり 0xC000013A で、これは Ctrl+C で終了したことを示すため、WinSW が要因ではない。

Windows サービスからでなく、コマンドプロンプトから実行して Ctrl+C で終了しても JFR のダンプファイルは生成されない。

アプリケーションを Ctrl+C ではなく、System.exit() で終了した場合は JFR のダンプファイルは生成される。なので、書き込み権限などの環境要因ではない。

JFR とは別で、アプリケーション側のシャットダウンフックで System.out すると、

Runtime.getRuntime().addShutdownHook(new Thread("My Shutdown Hook") {
    public void run() {
        System.out.println("ShutdownHook started");
        // ...
        System.out.println("ShutdownHook finished");
    }
});

started のログは出力されたりされなかったりする。一方 finished のログは常に表示されない。

なので JFR ではなく、JVM のシャットダウン・シーケンス自体の問題のようだ。 (シャットダウン・フック内でロガー経由でログ出力しており、先にロガー側がシャットダウンされていてログがでないことを、シャットダウン・フックが実行されていないと勘違いするのはよくある話)。

以下のようにファイル作成すると、

Runtime.getRuntime().addShutdownHook(new Thread("GlassFish Shutdown Hook") {
    public void run() {
        try {
            Files.write(Path.of("shutdown_hook_test.txt"), "Shutdown hook was called.".getBytes());
        } catch (Exception e) {
            e.printStackTrace();
        }
        // ...
    }
});

正常に生成される場合もあれば、ゼロバイトのファイルが生成される場合もあれば、全く生成されない場合もあり、タイミング次第のようだ。

なので、シャットダウン・フックの途中で JVM が終了している模様。

不思議なのが、Windows 11 のローカル環境では再現せず、シャットダウン・フックは正常に動作する点。

環境差異かなぁと、JVM のシステムプロパティを眺めていたら、なにやら JMV のバージョンが異なるではありませんか。

ローカル環境は java.vm.version=jdk-21+35-LTS、シャットダウン・フックが動かないサーバ側の環境のものは java.vm.version=21.0.8+9-LTS と微妙な違いが。Gradle のツールチェーンで JDK 21 と指定しているだけなので違いが出るのは仕方ない。

ためしにローカルでビルドしたアプリ(jpackageでパッケージ化しているのでランタイム含む)をサーバに持って行って実行すると。

問題発生せず。

パッチバージョンの違いでそんなに変わる？と思いつつ、どこから問題が発生するかを調べていくと、以下のような結果に。

JDK	OK/NG
jdk-21.0.8+9	NG
jdk-21.0.7+6	NG
jdk-21.0.6+7	NG
jdk-21.0.5+11	NG
jdk-21.0.4+7	NG
jdk-21.0.3+9	NG
jdk-21.0.2+13	NG
jdk-21.0.1+12	OK
jdk-21+35	OK

21.0.2からは、シャットダウン・フックの処理が最後まで実行されずに JVM が終了する。

21.0.2 で何が変わったかをリリースノートで確認。

ソースの差分はgithub

ん～多すぎて良くわからん。

JDK 22 や JDK 23 も同じ状況っぽい。

急ぎ jdk-21.0.1+12 を使うようにして暫定対処することにして、深堀りは後日にしよ。

blog1.mammb.com

そもそもシャットダウン・フック何？

シャットダウン・フックは以下のように Runtime に登録しておくと、JVM 終了時にリソースのクリーンアップ処理などをフックできる仕組み。

Runtime.getRuntime().addShutdownHook(new Thread("My Shutdown Hook") {
    public void run() {
        // ...
    }
});

シャットダウン・フックは初期化されただけで起動していないスレッドで、シャットダウン・シーケンスの中で実行される。

シャットダウン・シーケンスは以下のいずれかの条件で開始する。

非デーモンスレッドの数が最初にゼロになった時
Runtime.exit または System.exit メソッドが呼ばれた時
OS から割り込みシグナル(Ctrl+C)(SIGINT)を受信した時

JVM がシャットダウンシーケンスを開始すると、登録されたシャットダウン・フックスレッドが開始する。

シャットダウン・フックスレッドは並行して実行され、その実行順序は保証されず、シャットダウン・シーケンス開始時に生きていた他のスレッド(デーモンまたは非デーモン)と同時に実行される(なのでデッドロックなどの競合に注意が必要)。

シャットダウン・フックがすべて終了すると、(終了時のファイナライズが有効である場合)ファイナライザの実行後に JVM は停止する。

以下のケースではシャットダウン・フックは実行されない

Runtime.halt() で終了した場合
プロセスをkillした場合(SIGKILLシグナル、Windowsの場合はTerminateProcess)
javaw で起動した場合
ネイティブ・コードのエラーが原因でVMがクラッシュした場合
JVMの起動引数 -Xrs を指定した場合 SIGINTシグナルを無視するようになり JVM の正常なシャットダウンシーケンスが開始されなくなる

tl;dr

ことの経緯

そもそも シャットダウン・フック 何？

そもそもシャットダウン・フック何？