疑問点
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. ...