これは、なにをしたくて書いたもの?
Apache Tomcatが提供しているValveに、StuckThreadDetectionValve
というものがあります。
こちらを使うと、リクエストを受け取ってからStuckThreadDetectionValve
に指定した時間(秒数)が経過した際に、スレッドが
スタックしている可能性があるとしてApache TomcatがWARNログを出力してくれるようになります。
StuckThreadDetectionValve
自体については、かなり前にこのブログでも扱ったことがあります。
Tomcat 7から追加された、StuckThreadDetectionValveを使う - CLOVER🍀
これをSpring Bootで使うにはどうしたらいいのかな?ということで試してみました。
Apache TomcatのStuckThreadDetectionValve
Apache TomcatのStuckThreadDetectionValve
のドキュメントは、こちら。
The Valve Component / Stuck Thread Detection Valve
設定としては、スレッドがスタックしているとみなされるまでの秒数(デフォルトでは600秒=10分)、そしてスタックしたとみなされた
場合にスレッドにinterruptするまでの秒数を指定することができます。
指定するプロパティは、それぞれthreshold
(スレッドがスタックしているとみなされるまでの秒数)と
interruptThreadThreshold
(スタックしたとみなされた 場合にスレッドにinterruptするまでの秒数)です。
interruptThreadThreshold
はデフォルトでは-1
で無効ですが、使用する場合はthreshold
以上の値を指定する必要があります。
Spring BootでApache Tomcatをカスタマイズする
Spring BootでApache Tomcatを使う場合は、基本的には組み込み版になります。
この設定を行うには、まずはapplication.properties
(またはapplication.yaml
)での設定ですが、ここで設定できる項目には
Valveに関するものはアクセスログくらいしかなさそうです。
Common Application Properties / Server Properties
となると、プログラムでApache Tomcatをカスタマイズすることになります。
ドキュメントとしては、このあたりですね。
WebServerFactoryCustomizer
を使い、SpringのBeanを定義します。
WebServerFactoryCustomizer
には型パラメーターを指定しますが、汎用的にはConfigurableServletWebServerFactory
を、
特定のサーブレットコンテナ向けにはTomcatServletWebServerFactory
、JettyServletWebServerFactory
、
UndertowServletWebServerFactory
などを指定します。
Valveの設定はApache Tomcat向けになるので、今回はTomcatServletWebServerFactory
を使用します。
ということで、試してみましょう。
環境
今回の環境は、こちら。
$ java --version openjdk 17.0.8.1 2023-08-24 OpenJDK Runtime Environment (build 17.0.8.1+1-Ubuntu-0ubuntu122.04) OpenJDK 64-Bit Server VM (build 17.0.8.1+1-Ubuntu-0ubuntu122.04, mixed mode, sharing) $ mvn --version Apache Maven 3.9.5 (57804ffe001d7215b5e7bcb531cf83df38f93546) Maven home: $HOME/.sdkman/candidates/maven/current Java version: 17.0.8.1, vendor: Private Build, runtime: /usr/lib/jvm/java-17-openjdk-amd64 Default locale: ja_JP, platform encoding: UTF-8 OS name: "linux", version: "5.15.0-87-generic", arch: "amd64", family: "unix"
Spring Bootプロジェクトを作成する
それでは、Spring Bootプロジェクトを作成していきます。依存関係にweb
を指定して作成。
$ curl -s https://start.spring.io/starter.tgz \ -d bootVersion=3.1.5 \ -d javaVersion=17 \ -d type=maven-project \ -d name=add-tomcat-stuck-thread-detection-valve \ -d groupId=org.littlewings \ -d artifactId=add-tomcat-stuck-thread-detection-valve \ -d version=0.0.1-SNAPSHOT \ -d packageName=org.littlewings.spring.web \ -d dependencies=web \ -d baseDir=add-tomcat-stuck-thread-detection-valve | tar zxvf -
作成されたプロジェクト内へ移動。
$ cd add-tomcat-stuck-thread-detection-valve
Maven依存関係など。
<properties> <java.version>17</java.version> </properties> <dependencies> <dependency> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-starter-web</artifactId> </dependency> <dependency> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-starter-test</artifactId> <scope>test</scope> </dependency> </dependencies> <build> <plugins> <plugin> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-maven-plugin</artifactId> </plugin> </plugins> </build>
生成されたソースコードは削除しておきます。
$ rm src/main/java/org/littlewings/spring/web/AddTomcatStuckThreadDetectionValveApplication.java src/test/java/org/littlewings/spring/web/AddTomcatStuckThreadDetectionValveApplicationTests.java
アプリケーションを作成し、StuckThreadDetectionValveを組み込む
まずは簡単なRestControllerを作成しましょう。
src/main/java/org/littlewings/spring/web/SampleController.java
package org.littlewings.spring.web; import org.springframework.http.MediaType; import org.springframework.web.bind.annotation.GetMapping; import org.springframework.web.bind.annotation.RequestMapping; import org.springframework.web.bind.annotation.RestController; import java.util.concurrent.TimeUnit; @RestController @RequestMapping("sample") public class SampleController { @GetMapping(value = "simple", produces = {MediaType.TEXT_PLAIN_VALUE}) public String simple() { return "Hello World"; } @GetMapping(value = "slow", produces = {MediaType.TEXT_PLAIN_VALUE}) public String slow() throws InterruptedException { long sleepSeconds = 10L; TimeUnit.SECONDS.sleep(sleepSeconds); return String.format("Slow Response, sleep %ds", sleepSeconds); } }
2つのエンドポイントを定義して、ひとつは10秒スリープしてからレスポンスを返すようにしています。
main
メソッドを持ったクラスはこちら。
src/main/java/org/littlewings/spring/web/App.java
package org.littlewings.spring.web; import org.springframework.boot.SpringApplication; import org.springframework.boot.autoconfigure.SpringBootApplication; @SpringBootApplication public class App { public static void main(String... args) { SpringApplication.run(App.class, args); } }
これでサンプルアプリケーションとしては完成ですが、ここにStuckThreadDetectionValve
を組み込みます。
こちらです。
src/main/java/org/littlewings/spring/web/WebConfiguration.java
package org.littlewings.spring.web; import org.apache.catalina.valves.StuckThreadDetectionValve; import org.springframework.boot.web.embedded.tomcat.TomcatServletWebServerFactory; import org.springframework.boot.web.server.WebServerFactoryCustomizer; import org.springframework.context.annotation.Bean; import org.springframework.context.annotation.Configuration; @Configuration public class WebConfiguration { @Bean public WebServerFactoryCustomizer<TomcatServletWebServerFactory> tomcatWebServerFactoryWebServerFactoryCustomizer() { return server -> { StuckThreadDetectionValve stuckThreadDetectionValve = new StuckThreadDetectionValve(); stuckThreadDetectionValve.setThreshold(5); server.addEngineValves(stuckThreadDetectionValve); }; } }
今回は、EngineにStuckThreadDetectionValve
を組み込むことにしました。
動作確認
動作確認してみます。ビルドして起動。
$ mvn package $ java -jar target/add-tomcat-stuck-thread-detection-valve-0.0.1-SNAPSHOT.jar
確認。まずはふつうに動く方。
$ curl localhost:8080/sample/simple Hello World
続いて、スリープを入れている方。
$ curl localhost:8080/sample/slow Slow Response, sleep 10s
この時、アプリケーション側ではこんなログが出力されます。
2023-10-28T19:09:34.917+09:00 WARN 29375 --- [alina-utility-2] o.a.c.valves.StuckThreadDetectionValve : Thread [http-nio-8080-exec-1] (id=[21]) has been active for [8,716] milliseconds (since [10/28/23, 7:09 PM]) to serve the same request for [http://localhost:8080/sample/slow] and may be stuck (configured threshold for this StuckThreadDetectionValve is [5] seconds). There is/are [1] thread(s) in total that are monitored by this Valve and may be stuck. java.lang.Throwable: null at java.base@17.0.8.1/java.lang.Thread.sleep(Native Method) ~[na:na] at java.base@17.0.8.1/java.lang.Thread.sleep(Thread.java:337) ~[na:na] at java.base@17.0.8.1/java.util.concurrent.TimeUnit.sleep(TimeUnit.java:446) ~[na:na] at org.littlewings.spring.web.SampleController.slow(SampleController.java:22) ~[classes!/:0.0.1-SNAPSHOT] at java.base@17.0.8.1/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:na] at java.base@17.0.8.1/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) ~[na:na] at java.base@17.0.8.1/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na] at java.base@17.0.8.1/java.lang.reflect.Method.invoke(Method.java:568) ~[na:na] at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:205) ~[spring-web-6.0.13.jar!/:6.0.13] at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:150) ~[spring-web-6.0.13.jar!/:6.0.13] at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:118) ~[spring-webmvc-6.0.13.jar!/:6.0.13] at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:884) ~[spring-webmvc-6.0.13.jar!/:6.0.13] at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:797) ~[spring-webmvc-6.0.13.jar!/:6.0.13] at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) ~[spring-webmvc-6.0.13.jar!/:6.0.13] at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1081) ~[spring-webmvc-6.0.13.jar!/:6.0.13] at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:974) ~[spring-webmvc-6.0.13.jar!/:6.0.13] at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1011) ~[spring-webmvc-6.0.13.jar!/:6.0.13] at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:903) ~[spring-webmvc-6.0.13.jar!/:6.0.13] at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:564) ~[tomcat-embed-core-10.1.15.jar!/:na] at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:885) ~[spring-webmvc-6.0.13.jar!/:6.0.13] at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:658) ~[tomcat-embed-core-10.1.15.jar!/:na] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:205) ~[tomcat-embed-core-10.1.15.jar!/:na] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149) ~[tomcat-embed-core-10.1.15.jar!/:na] at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:51) ~[tomcat-embed-websocket-10.1.15.jar!/:na] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174) ~[tomcat-embed-core-10.1.15.jar!/:na] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149) ~[tomcat-embed-core-10.1.15.jar!/:na] at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100) ~[spring-web-6.0.13.jar!/:6.0.13] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116) ~[spring-web-6.0.13.jar!/:6.0.13] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174) ~[tomcat-embed-core-10.1.15.jar!/:na] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149) ~[tomcat-embed-core-10.1.15.jar!/:na] at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93) ~[spring-web-6.0.13.jar!/:6.0.13] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116) ~[spring-web-6.0.13.jar!/:6.0.13] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174) ~[tomcat-embed-core-10.1.15.jar!/:na] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149) ~[tomcat-embed-core-10.1.15.jar!/:na] at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201) ~[spring-web-6.0.13.jar!/:6.0.13] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116) ~[spring-web-6.0.13.jar!/:6.0.13] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174) ~[tomcat-embed-core-10.1.15.jar!/:na] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149) ~[tomcat-embed-core-10.1.15.jar!/:na] at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:167) ~[tomcat-embed-core-10.1.15.jar!/:na] at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:90) ~[tomcat-embed-core-10.1.15.jar!/:na] at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:482) ~[tomcat-embed-core-10.1.15.jar!/:na] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:115) ~[tomcat-embed-core-10.1.15.jar!/:na] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:93) ~[tomcat-embed-core-10.1.15.jar!/:na] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74) ~[tomcat-embed-core-10.1.15.jar!/:na] at org.apache.catalina.valves.StuckThreadDetectionValve.invoke(StuckThreadDetectionValve.java:185) ~[tomcat-embed-core-10.1.15.jar!/:na] at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:340) ~[tomcat-embed-core-10.1.15.jar!/:na] at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:391) ~[tomcat-embed-core-10.1.15.jar!/:na] at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:63) ~[tomcat-embed-core-10.1.15.jar!/:na] at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:896) ~[tomcat-embed-core-10.1.15.jar!/:na] at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1744) ~[tomcat-embed-core-10.1.15.jar!/:na] at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:52) ~[tomcat-embed-core-10.1.15.jar!/:na] at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191) ~[tomcat-embed-core-10.1.15.jar!/:na] at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659) ~[tomcat-embed-core-10.1.15.jar!/:na] at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) ~[tomcat-embed-core-10.1.15.jar!/:na] at java.base@17.0.8.1/java.lang.Thread.run(Thread.java:833) ~[na:na] 2023-10-28T19:09:44.924+09:00 WARN 29375 --- [alina-utility-2] o.a.c.valves.StuckThreadDetectionValve : Thread [http-nio-8080-exec-1] (id=[21]) was previously reported to be stuck but has completed. It was active for approximately [10,049] milliseconds.
OKですね。
テストを書く
最後に、テストも書いておきましょう。
src/test/java/org/littlewings/spring/web/SampleControllerTest.java
package org.littlewings.spring.web; import org.junit.jupiter.api.Test; import org.junit.jupiter.api.extension.ExtendWith; import org.springframework.beans.factory.annotation.Autowired; import org.springframework.boot.test.context.SpringBootTest; import org.springframework.boot.test.system.CapturedOutput; import org.springframework.boot.test.system.OutputCaptureExtension; import org.springframework.boot.test.web.client.TestRestTemplate; import static org.assertj.core.api.Assertions.assertThat; @SpringBootTest(webEnvironment = SpringBootTest.WebEnvironment.RANDOM_PORT) @ExtendWith(OutputCaptureExtension.class) class SampleControllerTest { @Autowired private TestRestTemplate restTemplate; @Test void sampleAccess() { String response = restTemplate.getForObject("/sample/simple", String.class); assertThat(response).isEqualTo("Hello World"); } @Test void slowAccess(CapturedOutput output) { String response = restTemplate.getForObject("/sample/slow", String.class); assertThat(response).containsPattern("Slow Response, sleep \\d+s"); assertThat(output) .contains("StuckThreadDetectionValve") .contains("may be stuck (configured threshold for this StuckThreadDetectionValve"); } }
おわりに
Spring Bootで、Apache TomcatのStuckThreadDetectionValve
を使ってみました。
たぶんCustomizerでカスタマイズすることになるのかなと思っていましたが、やっぱりそうでしたね。
最近あまり使っていないのですが、もしも組み込む時は…ということで。