Blog

spring boot で logging の設定のやり方まとめ

spring boot にはデフォルトでロギング機構が付いている。spring-boot-starter-web の依存に spring-boot-starter-logging 入ってるので、web 有効にしてたら自動でロギング機構も依存に入っている。デフォルトのバックエンドは logback である。

パッケージごとの loglevel の設定は application.yml で出来る。

logging.level.org.springframework.web.servlet.PageNotFound: ERROR

しかし、例えば logback の appender を追加したいなどの場合、もはや logback.xml を設定するしかない。XML で記述するのは苦行だが、耐え忍ぶしかない。(XML ではなく groovy でも設定できるが、groovy の方が情報量が少なく、辛い)。なお、設定ファイルは logback.xml ではなく logback-spring.xml という名前で置くのが spring 流。

logback-spring.xml を置かない場合、デフォルトだと以下の logback-spring.xml を設置されてるのと同じことである。

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
	<include resource="org/springframework/boot/logging/logback/defaults.xml" />
	<property name="LOG_FILE" value="${LOG_FILE:-${LOG_PATH:-${LOG_TEMP:-${java.io.tmpdir:-/tmp}}}/spring.log}"/>
	<include resource="org/springframework/boot/logging/logback/console-appender.xml" />
	<include resource="org/springframework/boot/logging/logback/file-appender.xml" />
	<root level="INFO">
		<appender-ref ref="CONSOLE" />
		<appender-ref ref="FILE" />
	</root>
</included>

最近の実装では、実際には org.springframework.boot.logging.logback.DefaultLogbackConfiguration で設定されている。 https://github.com/spring-projects/spring-boot/blob/master/spring-boot/src/main/java/org/springframework/boot/logging/logback/DefaultLogbackConfiguration.java

Java コードで記述することで 100msec ほど起動速度を削減できているとのこと。 https://github.com/spring-projects/spring-boot/issues/1796

springProfile

さて、spring boot では logback-spring.xml の中で springProfile というタグを記述することで、「特定の profile 下でのみ動作する」みたいな条件つけられるので、これを利用すると良い。

<springProfile name="staging">
    <!-- 'staging' のときに有効 -->
</springProfile>

<springProfile name="dev, staging">
    <!--'dev' または 'staging' のときに有効 -->
</springProfile>

<springProfile name="!production">
    <!--'production' じゃない時に有効 -->
</springProfile>

ファイルにログを出力する設定

src/main/resources/logback/appender/logback-file.xml とかに以下のようなファイルを設置する。

ファイルを出力するディレクトリは、logback の設定ファイルには記述しない。記述したとしてもデフォルト値を設定し、system property などで外から変更できるようにしておくのが望ましい。jar の外から変更できるのが本筋だと思う。logging.path というプロパティから、LOG_PATH という変数が spring.boot により設定されているので、これをベースのディレクトリとして利用している。

java 起動時に -Dlogging.path=/path/to/logs のように指定するのが良いと思う。

<included>
  <!-- ファイルに出力するロガー -->

  <!--
   LOG_PATH は spring boot が設定している。logging.path から取得される値。
   project 名は -Dproject= で java 起動時に指定。
   -->
  <property name="APP_LOG_FILENAME" value="${LOG_PATH}/application/${project}.log"/>

  <appender name="APPLICATION_LOG_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <file>${APP_LOG_FILENAME}</file>
    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
      <fileNamePattern>${APP_LOG_FILENAME}.%d{yyyyMMdd}.gz</fileNamePattern>
      <maxHistory>30</maxHistory>
    </rollingPolicy>
    <encoder>
      <charset>UTF-8</charset>
      <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %-5level [%t]%X{request_thread} %logger{45}:%L - %msg %n</pattern>
    </encoder>
  </appender>

  <appender name="ASYNC_APPLICATION_LOG_FILE" class="ch.qos.logback.classic.AsyncAppender">
    <appender-ref ref="APPLICATION_LOG_FILE"/>
  </appender>
</included>

jetty のアクセスログを取る

jetty のアクセスログをファイルに書いておく設定がこれです。

src/main/resources/logback/appender/logback-jetty_access_log.xml とかに置くと良いでしょう。

<included>
  <!-- jetty の access log を出力する -->

  <!--
   LOG_PATH は spring boot が設定している。logging.path から取得される値。
   project は -Dproject= で設定。supervisord.ini で設定している。
   -->
  <property name="JETTY_LOG_FILE" value="${LOG_PATH}/jetty/${project}-request.log"/>

  <appender name="REQUEST_LOG_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <file>${JETTY_LOG_FILE}</file>
    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
      <fileNamePattern>${JETTY_LOG_FILE}.%d{yyyyMMdd}.gz</fileNamePattern>
      <maxHistory>30</maxHistory>
    </rollingPolicy>
    <encoder>
      <pattern>%msg %X%n</pattern>
    </encoder>
  </appender>

</included>

最終的な logback-spring.xml の設定

最終的に logback-spring.xml を以下のように設定すると良い。

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
  <!-- http://docs.spring.io/spring-boot/docs/current/reference/html/boot-features-logging.html -->

  <!-- spring boot の設定を読む -->
  <include resource="org/springframework/boot/logging/logback/defaults.xml" />
  <include resource="org/springframework/boot/logging/logback/console-appender.xml" />

  <!--ローカル環境及びテスト環境では、INFO レベル以上を console に出力する -->
  <springProfile name="test,local">
    <root level="INFO">
      <appender-ref ref="CONSOLE"/>
    </root>
  </springProfile>

  <springProfile name="release, staging">
    <!-- release,staging 環境では、アプリケーションログはログファイルに書く。ログレベルは INFO -->
    <include resource="logback/appender/logback-file.xml"/>
    <root level="INFO">
      <appender-ref ref="ASYNC_APPLICATION_LOG_FILE"/>
    </root>

    <!-- release, staging 環境では、jetty のアクセスログをファイルに書いておく。fluentd とかでログ飛ばす用 -->
    <include resource="logback/appender/logback-jetty_access_log.xml"/>
    <logger name="org.eclipse.jetty.server.RequestLog" level="INFO" additivity="false">
      <appender-ref ref="REQUEST_LOG_FILE"/>
    </logger>
  </springProfile>

</configuration>

環境ごとの特定パッケージごとのログレベルの変更は、application-release.yml などの YAML ファイルに以下のように記述するようにし、logback-spring.xml には必要以上の設定は書かないほうが良いかと思う。

logging.level.org.springframework.web.servlet.PageNotFound: ERROR