Javaアプリケーションログ出力パターン

はじめに

Javaでアプリケーションを構築する時に考慮すべきログは、3つに分類できると考えている。

アプリケーションレベルのログ
- Commons Logging,Log4J,Logback,SLF4Jなど
ミドルウェアレベルのログ
- Apache Tomcat の JULI など
- アプリケーションレイヤからログに関する設定をいじれないことが多い
起動スクリプトや終了スクリプトのログ
- Apache Tomcatの catalina.out など

アプリケーションレベルのログ

ログの実装ライブラリ（java.util.logging, Log4J 等）と、それを抽象化するライブラリ（SLF4J, Commons Logging 等）がある。
参考 javaのロガーが多すぎて訳が解らないので整理してみました

実現方法

例えばSLF4J + Logback を利用した場合、以下のように書ける。

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
  ...
  // SLF4J + Logback
  Logger logger = LoggerFactory.getLogger(Main.class.getName());
  logger.info("Logback logging");

SLF4Jのインタフェースしか利用していないのに、ログ実装にLobackを利用することができる。また、ログ実装を変更すればソースコードの修正なしでログ実装を切り替えることができる。
参考よく使うJavaライブラリで味わうデザインパターン - Adapterパターン

同様に、依存ライブラリのログも Logbackで出力できる。外部ライブラリで java.util.logging や Log4J を利用したコードが書かれているにも関わらず、以下のようにLogbackの設定でログ出力ができる。なぜか？

Javaではコンパイル時に依存するクラスファイルをクラスパスに通すが、一度クラスファイルが生成されたら実行時まで依存するクラスファイルは必要ない。コンパイル時に利用したクラスファイルとパッケージやメソッドは同一だが、SLF4Jを利用した実装をしたクラスファイルに差し替えることで、ログ実装を強制的に上書きしている。

log4j-over-slf4j や jul-to-slf4j というアダプタ関連のクラスがこれに該当する。

ライブラリの中を見てみると、log4jのクラスをラップしていることがわかる。
参考 Github slf4j

注意点

java.util.logging だけはログが差し替えられない。java.util.logging は標準APIのため、クラスファイルがrt.jarに入ってしまっているため、実行時にclassファイルを差し替えることができないから。アプリへのslf4j + logback 導入時の java.util.logging 向け対処

ミドルウェアレベルのログ

Apache Tomcat の内部ロガーの JULI などが該当する。アクセスログなど、大抵はミドルウェア（APサーバ）ごとにログ出力の設定が必要なことが多い。(アプリケーションログとは分離したレベルでログ出力したいことが多いため)
参考 Logging in Tomcat

The internal logging for Apache Tomcat uses JULI, a packaged renamed fork of Apache Commons Logging that is hard-coded to use the java.util.logging framework. This ensures that Tomcat’s internal logging and any web application logging will remain independent, even if a web application uses Apache Commons Logging.

起動スクリプトや終了スクリプトのログ

起動・停止のためのbashスクリプトでログを出力するために、標準出力/標準エラー出力をファイルにリダイレクトすることがある。例えば、Apache Tomcatの起動スクリプトの catalina.sh は catalina.out にログを出す。

26-Sep-2017 22:09:52.430 情報 [main] org.apache.catalina.core.StandardService.startInternal サービス [Catalina] を起 動します
26-Sep-2017 22:09:52.430 情報 [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine: Apache Tomcat/8.5.23
26-Sep-2017 22:09:52.450 情報 [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Webアプ リケーションディレクトリ [/home/kimura/apache-tomcat-8.5.23/webapps/ROOT] を配備します
26-Sep-2017 22:09:52.887 情報 [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/home/kimura/apache-tomcat-8.5.23/webapps/ROOT] has finished in [436] ms
26-Sep-2017 22:09:52.887 情報 [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Webアプ リケーションディレクトリ [/home/kimura/apache-tomcat-8.5.23/webapps/docs] を配備します
26-Sep-2017 22:09:52.909 情報 [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/home/kimura/apache-tomcat-8.5.23/webapps/docs] has finished in [22] ms
26-Sep-2017 22:09:52.910 情報 [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Webアプ リケーションディレクトリ [/home/kimura/apache-tomcat-8.5.23/webapps/examples] を配備します
26-Sep-2017 22:09:53.208 情報 [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/home/kimura/apache-tomcat-8.5.23/webapps/examples] has finished in [299] ms
26-Sep-2017 22:09:53.208 情報 [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Webアプ リケーションディレクトリ [/home/kimura/apache-tomcat-8.5.23/webapps/host-manager] を配備します
26-Sep-2017 22:09:53.258 情報 [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/home/kimura/apache-tomcat-8.5.23/webapps/host-manager] has finished in [50] ms
26-Sep-2017 22:09:53.259 情報 [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Webアプ リケーションディレクトリ [/home/kimura/apache-tomcat-8.5.23/webapps/manager] を配備します
26-Sep-2017 22:09:53.287 情報 [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/home/kimura/apache-tomcat-8.5.23/webapps/manager] has finished in [28] ms
26-Sep-2017 22:09:53.303 情報 [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
26-Sep-2017 22:09:53.392 情報 [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["ajp-nio-8009"]
26-Sep-2017 22:09:53.394 情報 [main] org.apache.catalina.startup.Catalina.start Server startup in 995 ms

また大抵のログ実装では、設定すれば標準出力に出すことができる。

またハンドリングされない例外(OutOfMemoryErrorなど)は、標準エラー出力に出る。

public static void main(String[] args) {
    throw new OutOfMemoryError("oome");
}

Javaアプリケーション ログ出力パターン