疑問点
Tomcatにwarをデプロイする方式では、Tomcatのログはconf/logging.properties で設定し、アプリケーションからはTomcatのログ設定を変更することができない。
参考 tomcat ロギング リファレンス
しかし組み込みTomcatを利用する方式では、アプリケーションからTomcatに関するログの設定を変更することができ、アプリケーションのログと同じようにTomcatのログが出力される。
例えば以下のログでは、Spring Frameworkに混じってTomcatのログも出力されている。
. ____ _ __ _ _
/\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
\\/ ___)| |_)| | | | | || (_| | ) ) ) )
' |____| .__|_| |_|_| |_\__, | / / / /
=========|_|==============|___/=/_/_/_/
:: Spring Boot :: (v2.0.2.RELEASE)
2018-05-31 20:14:14.158 INFO 7188 --- [ main] com.example.demo.DemoApplication : Starting DemoApplication on kimura-pc with PID 7188 (C:\Users\pbreh_000\Desktop\study\demo\target\classes started by pbreh_000 in C:\Users\pbreh_000\Desktop\study\demo)
2018-05-31 20:14:14.158 INFO 7188 --- [ main] com.example.demo.DemoApplication : No active profile set, falling back to default profiles: default
2018-05-31 20:14:14.205 INFO 7188 --- [ main] ConfigServletWebServerApplicationContext : Refreshing org.springframework.boot.web.servlet.context.AnnotationConfigServletWebServerApplicationContext@6b419da: startup date [Thu May 31 20:14:14 JST 2018]; root of context hierarchy
2018-05-31 20:14:15.360 INFO 7188 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 8080 (http)
2018-05-31 20:14:15.375 INFO 7188 --- [ main] o.apache.catalina.core.StandardService : Starting service [Tomcat]
2018-05-31 20:14:15.391 INFO 7188 --- [ main] org.apache.catalina.core.StandardEngine : Starting Servlet Engine: Apache Tomcat/8.5.31
warをデプロイするときと、組み込みTomcatで、どういう違いがあるのか？
結論
- warをデプロイするときは、アプリケーションからTomcatのログを制御できない
- 組み込みTomcatのときは、アプリケーションからTomcatのログを制御できる
理由
以下の話を読む前の前提知識。ライブラリで実装しているログをアプリケーションから設定したいときは、アダプタ用のjar(log4j-over-slf4j や jul-to-slf4j )に、実行時に差し替える必要がある。
参考 Java ログ出力パターン
Tomcatの内部ロガー
リファレンスによると
- Tomcatは JULI という独自ロガーの実装を持っている
- JULI は Apache Commons Logging をforkしてパッケージ名を変えている
- JULI は 実装クラスにjava.util.loggingを使うようにハードコードされている
- なぜ上記のようになっているかというと、java.util.logging はデフォルトだと VMごとにしか設定が切り替えられないため、独自のLogManager(ClassLoaderLogManager)によってクラスローダごとに設定を読み込めるようにしたいから
Tomcatにwarをデプロイするとき
catalina.shを利用したときの起動クラスは org.apache.catalina.startup.Bootstrap
Tomcatのクラスローダはwarごとにライブラリを管理できるように階層化されている。
参考 Class Loader HOW-TO
Bootstrap
|
System
|
Common
/ \
Webapp1 Webapp2 ...
親のクラスローダ(複数の場合あり)が要求されたクラスやリソースを見つけられなかった場合だけ、自分のリポジトリを見にいくことになる。
例えば、Tomcatのログをアプリケーションからコントロールするためにアダプタを設定しようとしてwarに jul-to-slf4j.jar を含めた場合でも、Tomcatのクラスを読み込んでいるクラスローダ(Common)から、WEBアプリケーションのクラスは参照できない。そのため、ログ実装をアプリケーションから差し替えることができない。
組み込みTomcatとして使うとき
組み込みTomcatの起動クラスは org.apache.catalina.startup.Tomcat
org.apache.catalina.startup.Bootstrap で起動したときとは違い、Catalina系のクラスとWEBアプリケーションのクラスが同一クラスローダに読み込まれる。
そのため jul-to-slf4j.jar をクラスパスに通せば、ロガーの差し替えができる。
検証する
pom.xmlを用意する。
<?xml version="1.0" encoding="UTF-8"?>
<project xmlns="http://maven.apache.org/POM/4.0.0"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
<modelVersion>4.0.0</modelVersion>
<packaging>jar</packaging>
<groupId>example.com</groupId>
<artifactId>embedded-tomcat-logging</artifactId>
<version>1.0-SNAPSHOT</version>
<dependencies>
<dependency>
<groupId>org.apache.tomcat.embed</groupId>
<artifactId>tomcat-embed-core</artifactId>
<version>8.5.23</version>
</dependency>
<dependency>
<groupId>ch.qos.logback</groupId>
<artifactId>logback-core</artifactId>
<version>1.2.3</version>
</dependency>
<dependency>
<groupId>ch.qos.logback</groupId>
<artifactId>logback-classic</artifactId>
<version>1.2.3</version>
</dependency>
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>jul-to-slf4j</artifactId>
<version>1.7.25</version>
</dependency>
</dependencies>
<properties>
<java.version>1.8</java.version>
<maven.compiler.target>${java.version}</maven.compiler.target>
<maven.compiler.source>${java.version}</maven.compiler.source>
</properties>
</project>
logback.xmlを用意する。
<configuration>
<contextListener class="ch.qos.logback.classic.jul.LevelChangePropagator">
<resetJUL>true</resetJUL>
</contextListener>
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>%c %d [%thread] %-5level - %msg%n</pattern>
</encoder>
</appender>
<root level="info">
<appender-ref ref="STDOUT"/>
</root>
</configuration>
組み込みTomcatを起動する。
public class Main {
public static void main(String[] args) throws LifecycleException, InterruptedException {
SLF4JBridgeHandler.removeHandlersForRootLogger();
SLF4JBridgeHandler.install();
Tomcat tomcat = new Tomcat();
tomcat.setPort(8080);
Context ctx = tomcat.addContext("/sample", new File(".").getAbsolutePath());
Logger logger = LoggerFactory.getLogger(Main.class);
logger.info("start...");
Tomcat.addServlet(ctx, "hello", new HttpServlet() {
protected void service(HttpServletRequest req, HttpServletResponse resp)
throws ServletException, IOException {
Writer w = resp.getWriter();
w.write("Hello, World!");
w.flush();
}
});
ctx.addServletMappingDecoded("/*", "hello");
tomcat.start();
tomcat.getServer().await();
}
}
コンソール出力を見ると、Logbackに実装が切り替えられている。
org.apache.coyote.http11.Http11NioProtocol 2018-05-31 20:37:47,682 [main] INFO ---- Initializing ProtocolHandler ["http-nio-8080"]
org.apache.tomcat.util.net.NioSelectorPool 2018-05-31 20:37:47,745 [main] INFO ---- Using a shared selector for servlet write/read
org.apache.catalina.core.StandardService 2018-05-31 20:37:47,747 [main] INFO ---- Starting service [Tomcat]
org.apache.catalina.core.StandardEngine 2018-05-31 20:37:47,748 [main] INFO ---- Starting Servlet Engine: Apache Tomcat/8.5.23
org.apache.coyote.http11.Http11NioProtocol 2018-05-31 20:37:47,889 [main] INFO ---- Starting ProtocolHandler ["http-nio-8080"]
実際にクラスローダを確認してみると、Tomcat関連のクラスとWEBアプリケーションのクラスが同一のクラスローダに読み込まれている。
Spring Bootの場合
動作確認バージョンは以下。
<parent>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-parent</artifactId>
<version>2.0.2.RELEASE</version>
<relativePath/> <!-- lookup parent from repository -->
</parent>
Spring Bootはもう少し複雑なことをしていて、Java標準のクラスローダで spring boot loader classes を読み込み、そこから依存する各jarをロードしている。
example.jar
|
+-META-INF
| +-MANIFEST.MF
+-org
| +-springframework
| +-boot
| +-loader
| +-<spring boot loader classes>
+-BOOT-INF
+-classes
| +-mycompany
| +-project
| +-YourClasses.class
+-lib
+-dependency1.jar
+-dependency2.jar
参考 E.1.1 The Executable Jar File Structure
まあどっちにしろ、Tomcat関連のクラスからWEBアプリケーションのクラスが参照できているので同じことかなと。
SpringBootの組み込みTomcatの注意点
「Tomcat関連のログはアプリケーションのログ設定で一元管理できる」といきたいところだが、Tomcatのアクセスログは上記のログでは出力されない。Tomcatのアクセスログは独自のValveで実装されているため、ログ部分をアダプタで差し替えできないから。
Access logging is a related but different feature, which is implemented as a Valve. It uses self-contained logic to write its log files. 参考 Logging in Tomcat
ただし、Spring Boot だとプロパティで設定できる。
参考 Appendix A. Common application properties
server.tomcat.accesslog.buffered=true # Whether to buffer output such that it is flushed only periodically.
server.tomcat.accesslog.directory=logs # Directory in which log files are created. Can be absolute or relative to the Tomcat base dir.
server.tomcat.accesslog.enabled=false # Enable access log.
server.tomcat.accesslog.file-date-format=.yyyy-MM-dd # Date format to place in the log file name.
server.tomcat.accesslog.pattern=common # Format pattern for access logs.
server.tomcat.accesslog.prefix=access_log # Log file name prefix.
server.tomcat.accesslog.rename-on-rotate=false # Whether to defer inclusion of the date stamp in the file name until rotate time.
server.tomcat.accesslog.request-attributes-enabled=false # Set request attributes for the IP address, Hostname, protocol, and port used for the request.
server.tomcat.accesslog.rotate=true # Whether to enable access log rotation.
server.tomcat.accesslog.suffix=.log # Log file name suffix.
...