Spring Boot でログイン画面 + 一覧画面 + 登録画面の Webアプリケーションを作る ( その２３ )( logback.xmlの設定 )

概要

Spring Boot でログイン画面 + 一覧画面 + 登録画面の Webアプリケーションを作る ( その２２ )( 気になった点を修正２ ) の続きです。

• 今回の手順で確認できるのは以下の内容です。
  • logback-develop.xml, logback-product.xml, logback-unittest.xml にログの出力方法を設定します。
• 「登録画面の surfaceArea と population の Bean Validation を修正して、保存できない値は入力チェックエラーになるようにする」は対応しないことにしました。小数点ありの数値をチェックするサンプルが無くなることに気づいたので。

ソフトウェア一覧

参考にしたサイト

1. Spring Boot Reference Guide - 66. Logging
   http://docs.spring.io/spring-boot/docs/current/reference/html/howto-logging.html

2. The logback manual - Chapter 6: Layouts
   http://logback.qos.ch/manual/layouts.html

3. java.io.tmpdirのOSによる値の差異について
   http://qiita.com/asadasan/items/e541abb6024996488580

4. IT忘備録・メモ書きと日記 - slf4j,logback~javaのロギングツール
   http://ameblo.jp/oregano-blog/entry-11586057084.html

5. clash_m45の開発ブログ - logbackで日次ログローテーションする
   http://clash-m45.hatenablog.com/entry/20110824/1314168361

6. TERASOLUNA Server Framework for Java (5.x) Development Guideline 5.0.0.RELEASE documentation - 5.6. ロギング
   http://terasolunaorg.github.io/guideline/5.0.0.RELEASE/ja/ArchitectureInDetail/Logging.html

7. intra-mart Accel Platform / ログ 仕様書
   http://www.intra-mart.jp/download/product/iap/im_core/im_log_specification/index.html#

手順

Spring Boot のログ出力のデフォルト設定はどうなっているのか？

1. Tomcat を起動するとそれなりのフォーマットのログが IntelliJ IDEA のコンソールに出力されますので、まずは Spring Boot のデフォルト設定がどうなっているのか調べてみます。

2. logback.xml に <include resource="org/springframework/boot/logging/logback/base.xml"/> と書いているので、このファイルを見てみます。以下の URL で base.xml とその関連ファイルが見られます。

   org/springframework/boot/logging/logback/
   https://github.com/spring-projects/spring-boot/tree/master/spring-boot/src/main/resources/org/springframework/boot/logging/logback

   • コンソールに出力する際のログフォーマットは defaults.xml の中に <property name="CONSOLE_LOG_PATTERN" value="%clr(%d{yyyy-MM-dd HH:mm:ss.SSS}){faint} %clr(%5p) %clr(${PID:- }){magenta} %clr(---){faint} %clr([%15.15t]){faint} %clr(%-40.40logger{39}){cyan} %clr(:){faint} %m%n%wex"/> と定義されていました。
   • root の level は base.xml に "INFO" で定義されており、コンソールだけでなくファイルにも出力されるよう設定されています。コンソールだけだと思っていました。
   • root は "INFO" で定義して、ライブラリ単位で level を調整したいものだけ個別に defaults.xml に定義しているようです。
   • ログファイルの出力場所を確認してみます。同じ defaults.xml の中に <property name="LOG_FILE" value="${LOG_FILE:-${LOG_PATH:-${LOG_TEMP:-${java.io.tmpdir:-/tmp}}/}spring.log}"/> と定義されており、今は LOG_FILE ã‚‚ LOG_PATH ã‚‚ LOG_TEMP も設定していないので、java.io.tmpdir に出力されていると思われます。
   • Web で java.io.tmpdir の場所を確認してから見てみると C:\Users\<ユーザ名>\AppData\Local\Temp の下に spring.log が出力されていました。しかも 10MB単位でローテーションされており、spring.log.7 まで出力されていました。知らない間に 70MB もログが出力されているとは。。。
   • 他の設定ファイルも見てみます。コンソール出力は console-appender.xml に、ファイル出力は file-appender.xml に定義されています。
   • console-appender.xml はシンプルに UTF-8 で出力するよう設定されているだけでした。
   • file-appender.xml にはログローテーションするよう RollingFileAppender で設定されていました。10MB 毎にローテーションするのはいいのですが、最大数が設定されていない。。。
   • Windows で Temp フォルダにあるファイルがどのようなタイミングで削除するのか調べてみたら、デフォルトでは削除されないようです。

設定方針

以下の方針で設定することにします。

• ログフォーマットは今のままで特に不満はないので、そのまま利用することにします。
• logback-develop.xml はコンソール出力のみにします。
• logback-unittest.xml は root の level の OFF 設定だけ残して、それ以外の設定を削除します。
• logback-product.xml はファイル出力のみにします ( Windows でサービスで動かすつもりなのでコンソールには出力しません ) 。日単位でローテーションさせて、最大30日分保存されるようにします。

logback.xml を設定する

1. IntelliJ IDEA 上で 1.0.x-logbackxml ブランチを作成します。

2. src/main/resources の下の logback.xml を リンク先の内容 に変更します。

3. ログファイルの出力先に設定した C:\webapps\ksbysample-webapp-basic\logs ディレクトリを作成します。

logback-develop.xml を設定する

1. src/main/resources の下の logback-develop.xml を リンク先の内容 に変更します。

2. 動作確認します。bootRun タスクを実行します。

   • IntelliJ IDEA のコンソールには以前と同様のログが出力されました。
   • C:\Users\<ユーザ名>\AppData\Local\Temp の下には spring.log が出力されなくなりました。ただし、native-platform2794970538314105909dir とか、gradle139425685678566444.bin とか、tomcat.7446016434940347344.8080とかが出力されていました。この後、logback-product.xml を修正して jar から起動して動作確認した時にも出力されるようであれば、出力されない方法がないか調査したいと思います。

3. Run View で Ctrl+F2 を押して Tomcat を停止します。

logback-unittest.xml を設定する

1. src/main/resources の下の logback-unittest.xml を リンク先の内容 に変更します。

2. 動作確認します。「Run 'Tests in 'ksbysample...' with Coverage」を実行します。

   • IntelliJ IDEA のコンソールには何も出力されませんでした。
   • C:\Users\<ユーザ名>\AppData\Local\Temp の下にも spring.log は出力されていませんでした。ただし coverage0args、idea_working_dirs_junit0.tmp、idea_test_0.out というファイルが出力されていました ( 「Run 'Tests in 'ksbysample...' with Coverage」終了後も削除されずに残っていました ) 。これらは Coverage , JUnit, test 関連のファイルと思われるので特に何もしません。

logback-product.xml を設定する

1. src/main/resources の下の logback-product.xml を リンク先の内容 に変更します。

2. 動作確認します。まずは build タスクを実行して jar ファイルを作成します。

3. Terminal View を開いた後、以下の画像のコマンドを実行します。

   

   • IntelliJ IDEA の Terminal には何も出力されませんでした。
   • C:\webapps\ksbysample-webapp-basic\logs\ksbysample-webapp-basic.log が作成されました。
   • C:\Users\<ユーザ名>\AppData\Local\Temp の下に spring.log は出力されていませんでした。ただし tomcat.2747162588485574445.8080 が作成されていました。

   • tomcat.2747162588485574445.8080 の中を見るとファイルは１つも出力されていませんが、以下のサブディレクトリが作成されています。

     tomcat.2747162588485574445.8080\work\Tomcat\localhost\ROOT

   • ディレクトリ構成を見た感じでは Tomcat の WORK ディレクトリのようです。ディレクトリをあらかじめ指定して Temp ディレクトリに毎回出力されないようにしたいと思います。

4. Terminal View で Ctrl+C を押して Tomcat を終了します。

5. Spring Boot Reference Guide - Appendix A. Common application properties に設定がないか見てみると、server.tomcat.basedir という設定項目がありました。たぶんこれだと思われます。

6. src/main/resources の下の application-product.properties を リンク先の内容 に変更します。

7. C:\webapps\ksbysample-webapp-basic\work ディレクトリを作成します。

8. clean タスク、build タスクを実行して jar ファイルを作成し直します。今回は設定ファイルしか変更していませんので clean タスクを実行しないと jar ファイルを作成し直してくれませんでした。

9. Terminal View から再度 jar ファイルを実行します。

   • C:\Users\<ユーザ名>\AppData\Local\Temp の下に tomcat.2747162588485574445.8080 のようなディレクトリは作成されませんでした。
   • server.tomcat.basedir で設定したディレクトリの下に C:\webapps\ksbysample-webapp-basic\work\Tomcat\localhost\ROOT が作成されていました。

10. Terminal View で Ctrl+C を押して Tomcat を終了します。

commit、GitHub へ Push、1.0.x-logbackxml -> 1.0.x へ Pull Request、1.0.x でマージ、1.0.x-logbackxml ブランチを削除

1. commit、GitHub へ Push、1.0.x-logbackxml -> 1.0.x へ Pull Request、1.0.x でマージ、1.0.x-logbackxml ブランチを削除、をします。

ソースコード

logback.xml

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <include resource="org/springframework/boot/logging/logback/defaults.xml"/>

    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>${CONSOLE_LOG_PATTERN}</pattern>
            <charset>MS932</charset>
        </encoder>
    </appender>

    <property name="LOG_FILE" value="C:/webapps/ksbysample-webapp-basic/logs/ksbysample-webapp-basic.log"/>
    <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <encoder>
            <pattern>${FILE_LOG_PATTERN}</pattern>
        </encoder>
        <file>${LOG_FILE}</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${LOG_FILE}.%d{yyyy-MM-dd}</fileNamePattern>
            <maxHistory>30</maxHistory>
        </rollingPolicy>
    </appender>

    <if condition='"${spring.profiles.active}" == "develop"'>
        <then>
            <include resource="logback-develop.xml"/>
        </then>
    </if>
    <if condition='"${spring.profiles.active}" == "unittest"'>
        <then>
            <include resource="logback-unittest.xml"/>
        </then>
    </if>
    <if condition='"${spring.profiles.active}" == "product"'>
        <then>
            <include resource="logback-product.xml"/>
        </then>
    </if>
</configuration>

• <include resource="org/springframework/boot/logging/logback/base.xml"/> → <include resource="org/springframework/boot/logging/logback/defaults.xml"/> に変更します。base.xml でログ出力先に <appender-ref ref="FILE" /> が指定されていますが、include 後にこの設定を取り除く方法が分かりませんでしたので、include して設定されないようにしました。
• <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender"> ... </appender> を追加しました。charset の設定は utf8 にすると IntelliJ IDEA の Run View で文字化けするため、MS932 にしています。
• <property name="LOG_FILE" value="C:/webapps/ksbysample-webapp-basic/logs/ksbysample-webapp-basic.log"/> を追加してログファイルの出力先を定義しました。
• <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender"> ... </appender> を追加しました。
  • ログフォーマットは defaults.xml で定義されている FILE_LOG_PATTERN をそのまま使用しています。
  • ファイルの出力先は上で定義し直した LOG_FILE を設定しています。
  • ローテーションは TimeBasedRollingPolicy で日時ベースでローテーションされるように設定しています。
  • ローテーションのタイミングは .%d{yyyy-MM-dd} で日単位で設定しました。また最大 30日分保存されるようにしています。fileNamePattern と maxHistory を以下のように設定すると分単位でローテーションする動作を確認することが出来ます ( 本当に設定通りローテーションするのかこの設定で確認しました ) 。

        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${LOG_FILE}.%d{yyyy-MM-dd_HH-mm}</fileNamePattern>
            <maxHistory>5</maxHistory>
        </rollingPolicy>

logback-develop.xml

<?xml version="1.0" encoding="UTF-8"?>
<included>
    <root level="INFO">
        <appender-ref ref="CONSOLE"/>
    </root>

    <!-- Spring MVC -->
    <logger name="org.springframework.web" level="DEBUG"/>

    <!-- log4jdbc-log4j2 -->
    <logger name="jdbc.sqlonly" level="DEBUG"/>
    <logger name="jdbc.sqltiming" level="INFO"/>
    <logger name="jdbc.audit" level="INFO"/>
    <logger name="jdbc.resultset" level="ERROR"/>
    <logger name="jdbc.resultsettable" level="ERROR"/>
    <logger name="jdbc.connection" level="DEBUG"/>
</included>

• <root level="INFO"> ... </root> を追加し、出力先は CONSOLE のみに設定します。

logback-unittest.xml

<?xml version="1.0" encoding="UTF-8"?>
<included>
    <logger name="root" level="OFF"/>
</included>

• <logger name="root" level="OFF"/> だけにします。

logback-product.xml

<?xml version="1.0" encoding="UTF-8"?>
<included>
    <root level="INFO">
        <appender-ref ref="FILE"/>
    </root>
</included>

• <root level="INFO"> ... </root> を追加します。
• <logger name="org.springframework.web" level="INFO"/> を削除します。

application-product.properties

server.tomcat.basedir = C:/webapps/ksbysample-webapp-basic

spring.datasource.url = jdbc:mysql://localhost/world
spring.datasource.username = root
spring.datasource.password = xxxxxxxx
spring.datasource.driverClassName = com.mysql.jdbc.Driver

spring.thymeleaf.cache = true

• server.tomcat.basedir = C:/webapps/ksbysample-webapp-basic を追加します。

履歴

2015/03/29
初版発行。