Tomcat EmbeddedでAccessLogValveを適用してアクセスログを出力する

Tomcat EmbeddedでTomcatのアクセスログを出力する方法

META-INF/context.xmlを作成してAccessLogValveを適用する

context.xmlを用いて、下のようにAccessLogValveを適用する

<?xml version="1.0" encoding="UTF-8"?>
<Context>
  <Valve className="org.apache.catalina.valves.AccessLogValve" directory="logs"
      prefix="access" suffix=".log" pattern="%h %l %u %t &quot;%r&quot; %s %b" />

</Context>

Tomcat Embeddedを使ってTomcatを起動する

final Tomcat tomcat = new Tomcat();
tomcat.setPort(8080);

final String docBase = new File("src/main/webapp").getAbsolutePath();
final StandardContext context = (StandardContext) tomcat.addWebapp("/", docBase);

final File additionWebInfClasses = new File("build/classes/main");
final StandardRoot resources = new StandardRoot(context);
resources.addPreResources(
        new DirResourceSet(resources, "/WEB-INF/classes",
                additionWebInfClasses.getAbsolutePath(), "/"));
context.setResources(resources);

tomcat.start();
tomcat.getServer().await();

結果

カレントディレクトリ配下のtomcat.8080/logs配下にアクセスログが出力されるようになる。

➜  tomcat-embedded-example cat tomcat.8080/logs/access.2017-07-15.log 
127.0.0.1 - - [15/Jul/2017:15:36:39 +0900] "GET / HTTP/1.1" 200 89
127.0.0.1 - - [15/Jul/2017:15:36:43 +0900] "GET /hoge HTTP/1.1" 404 1002

[Tomcat]StuckThreadDetectionValveを使って遅延した処理の情報をログに出力する

StuckThreadDetectionValveを使うことで、処理遅延が発生したスレッドを検知することができる。

使い方は下の通り

設定を追加する

conf/server.xmlにStuckThreadDetectionValveを使用するように設定をする。

thresholdを使って、どれぐらい遅延したら検知するかを設定する。
デフォルトは600秒となっている。下のように60と設定すると60秒となる。

ログの結果

単純に一定時間スリープするServletで試すと下のようなログが出力される。

16-Jun-2017 21:14:37.445 警告 [ContainerBackgroundProcessor[StandardEngine[Catalina]]] org.apache.catalina.valves.StuckThreadDetectionValve.notifyStuckThreadDetected Thread [http-nio-8080-exec-6] (id=[29]) has been active for [62,731] milliseconds (since [17/06/16 21:13]) to serve the same request for [http://localhost:8080/hoge] and may be stuck (configured threshold for this StuckThreadDetectionValve is [60] seconds). There is/are [1] thread(s) in total that are monitored by this Valve and may be stuck.
java.lang.Throwable
at java.lang.Thread.sleep(Native Method)
at java.lang.Thread.sleep(Thread.java:340)
at java.util.concurrent.TimeUnit.sleep(TimeUnit.java:386)
at hoge.HogeServlet.doGet(HogeServlet.kt:11)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:635)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:742)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)

その後処理が完了すると、下のようなログも出力される

16-Jun-2017 21:15:37.465 警告 [ContainerBackgroundProcessor[StandardEngine[Catalina]]] org.apache.catalina.valves.StuckThreadDetectionValve.notifyStuckThreadCompleted Thread [http-nio-8080-exec-6] (id=[29]) was previously reported to be stuck but has completed. It was active for approximately [120,031] milliseconds.

これで、処理遅延などが発生した場合に自動的にスレッドダンプが取得できる。
障害時にスレッドダンプとってません問題も回避できそうな気もする。