概要

記事一覧はこちらです。

Spring Boot 2.2.x の Web アプリを 2.3.x へバージョンアップする ( その３ )( Spring Boot を 2.2.9 → 2.3.2 へバージョンアップする ) の続きです。

今回の手順で確認できるのは以下の内容です。
- 以下のドキュメントを見て必要な箇所を変更します。
  - Spring Boot 2.3 Release Notes

参照したサイト・書籍

Spring BootのGraceful shutdownって内部でどうやって実現されているの？
https://speakerdeck.com/kawakawaryuryu/spring-bootfalsegraceful-shutdowntutenei-bu-dedouyatuteshi-xian-sareteirufalse
Spring BootのGraceful shutdown処理が内部でどう呼ばれているかソースコードリーディングしてみた結果
https://qiita.com/kawakawaryuryu/items/bc92453f9c43d98c1a26
Spring Boot 2.3 の Liveness & Readiness Probes 対応について調べてみた
https://speakerdeck.com/otty375/spring-boot-2-dot-3-liveness-and-readiness-probes
Kubernetes Probes
https://docs.spring.io/spring-boot/docs/current/reference/html/production-ready-features.html#production-ready-kubernetes-probes
Liveness and Readiness Probes with Spring Boot
https://spring.io/blog/2020/03/25/liveness-and-readiness-probes-with-spring-boot
Liveness and Readiness Probes in Spring Boot
https://www.baeldung.com/spring-liveness-readiness-probes
Kubernetes のヘルスチェック(Liveness Probe,Readiness Probe)を検証する
https://qiita.com/toshihirock/items/c7e94e70c1c9650488df

手順

`server.shutdown=graceful` を設定する

Graceful shutdown によると設定ファイルに server.shutdown=graceful を記述すれば Graceful shutdown をしてくれるようになったので、src/main/resources/application.properties に設定します。

..........
management.endpoint.health.show-details=always

server.shutdown=graceful

#spring.autoconfigure.exclude=com.integralblue.log4jdbc.spring.Log4jdbcAutoConfiguration
spring.datasource.hikari.jdbc-url=jdbc:postgresql://localhost/ksbylending
..........

動作を確認するために src/main/java/ksbysample/webapp/lending/web/GracefulShutdownTestController.java を新規作成して以下の内容を記述します。http://localhost:8080/gracefulShutdownTest にアクセスすると 5分間 sleep してからレスポンスを返す Controller クラスです。Graceful shutdown が有効になっていれば、この URL にアクセスしてから Tomcat を停止しようとすると 30秒（spring.lifecycle.timeout-per-shutdown-phase のデフォルト値）待ってから停止するはず。

package ksbysample.webapp.lending.web;

import org.springframework.stereotype.Controller;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.ResponseBody;

/**
 * Spring Boot 2.3 から追加された Graceful shutdown の機能をテストするための Controller
 */
@Controller
public class GracefulShutdownTestController {

    /**
     * アクセス後 5分 sleep してからレスポンスを返す
     *
     * @return "OK"の文字列
     * @throws InterruptedException
     */
    @GetMapping("/gracefulShutdownTest")
    @ResponseBody
    public String index() throws InterruptedException {
        Thread.sleep(60_000 * 5);
        return "OK";
    }

}

src/main/java/ksbysample/webapp/lending/config/WebSecurityConfig.java に .antMatchers("/gracefulShutdownTest/**").permitAll() の記述を追加して、認証不要にします。

    @Configuration
    public static class FormLoginWebSecurityConfigurationAdapter extends WebSecurityConfigurerAdapter {

        @Override
        protected void configure(HttpSecurity http) throws Exception {
            http.authorizeRequests()
                    // 認証の対象外にしたいURLがある場合には、以下のような記述を追加します
                    // 複数URLがある場合はantMatchersメソッドにカンマ区切りで対象URLを複数列挙します
                    // .antMatchers("/country/**").permitAll()
                    ..........
                    .antMatchers("/sample/**").permitAll()
                    .antMatchers("/gracefulShutdownTest/**").permitAll()
                    .anyRequest().hasAnyRole("USER", "ADMIN", "APPROVER");
            ..........

Tomcat を起動して Graceful shutdown の機能を試してみると、

IntelliJ IDEA から起動した時は機能しません。すぐに Tomcat が停止します（停止は Navigation bar や Services Tool Window の Stop ボタンで行いました）。
jar ファイルを作成してコマンドラインすると、/gracefulShutdownTest にアクセスして 5秒後に Ctrl+C を押す → 30秒何も起こらない → バッチジョブを終了しますか (Y/N)? が表示される、という動きになりました。Graceful shutdown が機能しています。

2020-08-09 20:50:50.080  INFO 23156 --- [SpringContextShutdownHook] o.s.a.r.l.SimpleMessageListenerContainer : Waiting for workers to finish.
2020-08-09 20:50:50.709  INFO 23156 --- [SpringContextShutdownHook] o.s.a.r.l.SimpleMessageListenerContainer : Successfully waited for workers to finish.
2020-08-09 20:50:50.714  INFO 23156 --- [SpringContextShutdownHook] o.s.b.w.e.tomcat.GracefulShutdown        : Commencing graceful shutdown. Waiting for active requests to complete
2020-08-09 20:51:20.717  INFO 23156 --- [SpringContextShutdownHook] o.s.c.support.DefaultLifecycleProcessor  : Failed to shut down 1 bean with phase value 2147483647 within timeout of 30000ms: [webServerGracefulShutdown]
2020-08-09 20:51:20.740  INFO 23156 --- [tomcat-shutdown] o.s.b.w.e.tomcat.GracefulShutdown        : Graceful shutdown aborted with one or more requests still active
..........
2020-08-09 20:51:22.954  INFO 23156 --- [SpringContextShutdownHook] o.s.a.r.l.SimpleMessageListenerContainer : Shutdown ignored - container is not active already
2020-08-09 20:51:22.955  INFO 23156 --- [SpringContextShutdownHook] o.s.s.concurrent.ThreadPoolTaskExecutor  : Shutting down ExecutorService 'applicationTaskExecutor'
2020-08-09 20:51:22.963  INFO 23156 --- [SpringContextShutdownHook] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown initiated...
2020-08-09 20:51:22.977  INFO 23156 --- [SpringContextShutdownHook] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown completed.
2020-08-09 20:51:23.018  WARN 23156 --- [SpringContextShutdownHook] io.lettuce.core.RedisChannelHandler      : Connection is already closed
2020-08-09 20:51:23.018  WARN 23156 --- [SpringContextShutdownHook] io.lettuce.core.RedisChannelHandler      : Connection is already closed
2020-08-09 20:51:23.018  WARN 23156 --- [SpringContextShutdownHook] io.lettuce.core.RedisChannelHandler      : Connection is already closed
2020-08-09 20:51:23.048  INFO 23156 --- [SpringContextShutdownHook] o.s.s.concurrent.ThreadPoolTaskExecutor  : Shutting down ExecutorService
2020-08-09 20:51:23.049  WARN 23156 --- [SpringContextShutdownHook] io.lettuce.core.RedisChannelHandler      : Connection is already closed

nssm.exe でサービスに登録して起動した時に Graceful shutdown したい場合、登録時に「Shutdown」タブで「Generate Control-C」だけをチェックして「Timeout」に spring.lifecycle.timeout-per-shutdown-phase に設定した時間より長い時間をセットする必要があります（デフォルトでは全てチェックされていて「Timeout」に 1500 がセットされている）。

この設定にすると、サービス起動 → /gracefulShutdownTest にアクセスして 5秒後に「サービスの停止」リンククリック → 60秒何も起こらない（spring.lifecycle.timeout-per-shutdown-phase に設定された秒数ではなく nssm.exe で設定した Timeout の秒数） → サービスが停止する、という動きになりました。ログファイルを見ると Graceful shutdown が機能して Tomcat は 30秒後に停止していますが、サービスが停止するまでには nssm.exe で設定した Timeout の秒数を待つ必要があります（処理中のリクエストがなくてもnssm.exe で設定した Timeout の秒数を必ず待つようになります）。

2020-08-10 23:50:46.445  INFO 3384 --- [SpringContextShutdownHook] o.s.a.r.l.SimpleMessageListenerContainer : Waiting for workers to finish.
2020-08-10 23:50:46.979  INFO 3384 --- [SpringContextShutdownHook] o.s.a.r.l.SimpleMessageListenerContainer : Successfully waited for workers to finish.
2020-08-10 23:50:46.983  INFO 3384 --- [SpringContextShutdownHook] o.s.b.w.e.tomcat.GracefulShutdown        : Commencing graceful shutdown. Waiting for active requests to complete
2020-08-10 23:51:16.987  INFO 3384 --- [SpringContextShutdownHook] o.s.c.support.DefaultLifecycleProcessor  : Failed to shut down 1 bean with phase value 2147483647 within timeout of 30000ms: [webServerGracefulShutdown]
2020-08-10 23:51:16.989  INFO 3384 --- [tomcat-shutdown] o.s.b.w.e.tomcat.GracefulShutdown        : Graceful shutdown aborted with one or more requests still active
..........
2020-08-10 23:51:19.272  INFO 3384 --- [SpringContextShutdownHook] o.s.a.r.l.SimpleMessageListenerContainer : Shutdown ignored - container is not active already
2020-08-10 23:51:19.273  INFO 3384 --- [SpringContextShutdownHook] o.s.s.concurrent.ThreadPoolTaskExecutor  : Shutting down ExecutorService 'applicationTaskExecutor'
2020-08-10 23:51:19.283  INFO 3384 --- [SpringContextShutdownHook] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown initiated...
2020-08-10 23:51:19.297  INFO 3384 --- [SpringContextShutdownHook] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown completed.
2020-08-10 23:51:19.357  INFO 3384 --- [SpringContextShutdownHook] o.s.s.concurrent.ThreadPoolTaskExecutor  : Shutting down ExecutorService
2020-08-10 23:51:19.358  WARN 3384 --- [SpringContextShutdownHook] io.lettuce.core.RedisChannelHandler      : Connection is already closed

ローカルで Docker で Tomcat を起動した場合、Commencing graceful shutdown. のログが出力されましたので Graceful shutdown が機能しています。

2020-08-11 00:15:11.433  INFO 1 --- [extShutdownHook] o.s.a.r.l.SimpleMessageListenerContainer : Waiting for workers to finish.
2020-08-11 00:15:12.174  INFO 1 --- [extShutdownHook] o.s.a.r.l.SimpleMessageListenerContainer : Successfully waited for workers to finish.
2020-08-11 00:15:12.180  INFO 1 --- [extShutdownHook] o.s.b.w.e.tomcat.GracefulShutdown        : Commencing graceful shutdown. Waiting for active requests to complete

`management.endpoint.health.probes.enabled=true` を設定する

Liveness and Readiness probes によると、アプリが実行中かどうか（liveness）、リクエストに応答できる準備が出来ているかどうか（readiness）を Actuator で取得できる機能が提供されたとのこと。Kubernetes 環境向けの機能なので、Kubernetes の Container probes の説明が分かりやすいです。

Kubernetes の環境で実行しないとあまり意味はなさそうですが（Kubernetes 環境だと自動で設定されるらしい）、面白そうなので設定してみます。

src/main/resources/application.properties を以下のように変更します。

..........
management.endpoint.health.show-details=always
management.endpoint.health.probes.enabled=true
management.endpoint.health.group.liveness.include=livenessStateProbeIndicator,cacheCheck
management.endpoint.health.group.readiness.include=readinessStateProbeIndicator,cacheCheck

server.shutdown=graceful

..........

以下の３行を追加します。
- management.endpoint.health.probes.enabled=true
- management.endpoint.health.group.liveness.include=livenessStateProbeIndicator,cacheCheck
- management.endpoint.health.group.readiness.include=readinessStateProbeIndicator,cacheCheck
Liveness and Readiness probes には management.endpoint.health.probes.enabled=true の記述しかないのですが、他の２つも設定しないと /actuator/health/liveness、/actuator/health/readiness にアクセスした時に 404 Not Found が返ってきました。

Tomcat を起動してから http://localhost:8080/actuator/health/liveness にアクセスすると 200 OK と以下の画像のレスポンスが返ってきました。

f:id:ksby:20200812000549p:plain