ども、知らないことばかりの cloudpack の かっぱ (@inokara) です。

はじめに

アプリケーションのエラーログも見逃したくない

PlayFramework では特に設定を行わない限りは ${application.home}/logs/application.log にログを書き込むが、放っておくとローテーションも行われない…orz。後々泣かない為にもローテーションを行いつつ、ログの監視を行うにあたり監視対象のログファイル名は固定したい場合にどうすっかなーと思って試したメモ。

キモは LogBack

初耳の LogBack だが、PlayFramework ではデフォルトのロガーとして利用されている。

log4j の後継という位置付けで log4j よりも柔軟な設定が出来るとのこと。今回は Logback の設定を修正した上で…冒頭と繰り返しになるが、

  • ログの定期的なローテーション
  • 最新のログファイル名は固定

を試してみたい。

参考

Logback Project
Logback Document / Chapter 4: Appenders / FileAppender
Logback Document / Chapter 4: Appenders / RollingFileAppender

logger.xml

logger.xml を全文掲載

とりあえず Logback の設定は以下のような logger.xml に記述して ${application.home}/conf/ 以下に置くことでやりたいことを実現してみる。



  

  
    ${application.home}/logs/application.log
    
      ${application.home}/logs/application.%i.log
      1
      3
    

    
      10
    

     
       %date - [%level] - from %logger in %thread %n%message%n%xException%n
     
   

  
    
      %coloredLevel %logger{15} - %message%n%xException{5}

ローテーション内容の詳細

  • 最新のログは ${application.home}/logs/application.log に書き込む
  • 一定容量を超えたら ${application.home}/logs/application.1.log のようにローテーション
  • 容量の制限は 1000 バイト/1 ファイル（テストの為）
  • 過去 3 ファイルまで保存

ポイント

今回のポイントとなる部分は以下の通り。

  
    ${application.home}/logs/application.log
    
      ${application.home}/logs/application.%i.log
      1
      3
    

    
      1000
    

    
      %date - [%level] - from %logger in %thread %n%message%n%xException%n

ch.qos.logback.core.rolling.RollingFileAppender というクラスを利用することで…

RollingFileAppender extends FileAppender with the capability to rollover log files. For example, RollingFileAppender can log to a file named log.txt file and, once a certain condition is met, change its logging target to another file.

とあるように従来の FileAppender を拡張することが出来る。例えば、ファイル名を log.txt に変更したり、一定条件を満たされるとローテーションさせたりすることが出来るようになる。

以下は各種プロパティを整理したもの。（ドキュメントより抜粋）

プロパティ名 タイプ 詳細
file string ファイル名を指定
apend boolean デフォルトは有効で有効な場合には既存ファイルにログイベントが追記される
encoder Encoder ※ちょい特殊
rollingPolicy RollingPolicy ログのローテーションポリシーで TimeBasedRollingPolicy / FixedWindowRollingPolicy から選択
triggeringPolicy triggeringPolicy ローテーションを行う際のトリガーを指定で SizeBasedTriggeringPolicy を指定する
prudent boolean FixedWindowRollingPolicy では利用しない

なるほど、なるほど。

上記の設定例を見ると…

  • ファイル名は ${application.home}/logs/application.log
  • ローテーションされるファイル名は ${application.home}/logs/application.%i.log
  • ローテーションは三世代（1 〜 3）
  • ファイルサイズが 1000 bytes を超えたらローテーションされる（デフォルトは 10MB となる）

ファイルサイズの指定については以下のように書かれている。

SizeBasedTriggeringPolicy accepts only one parameter, namely maxFileSize, with a default value of 10 MB.

The maxFileSize option can be specified in bytes, kilobytes, megabytes or gigabytes by suffixing a numeric value with KB, MB and respectively GB. For example, 5000000, 5000KB, 5MB and 2GB are all valid values, with the first three being equivalent.

KB や MB や GB で指定することが出来る。

デモ

アプリケーションの用意

import org.fluentd.logger.FluentLogger;
import play.Logger;

public class Application extends Controller {
  private static final FluentLogger LOG = FluentLogger.getLogger("app","127.0.0.1", 24224);

  public static Result index() {
      Logger.debug("--------------------------------------------------------------");
      return ok(index.render("Your new application is ready."));

(snip)

上記のようなアプリケーションを用意。ちなみに fluent-logger-java との同居も可能。とりあえず Logger に仕事をさせたいのでアプリケーションのルート（/）にアクセスさせる度に Logger がデバッグログを吐く。

アプリケーションの起動

アプリケーションを play dist 状態で、冒頭に貼った logger.xml を以下のように指定してアプリケーションを起動する。

${application.home}/bin/play-test-app -Dhttp.port=9002 -Dlogger.file=${application.home}/conf/logger.xml &

起動後の application.log は以下のような状態。

$ pwd
${application.home}/logs
$ ls -l
合計 4
-rw-rw-r-- 1 pool pool 181  2月 19 07:37 application.log

とりあえずローテーションさせてみる

ひたすら curl -s localhost:9000/ip を実行することで application.log には以下のようなログが吐かれ続ける。

2015-02-19 07:40:32,777 - [DEBUG] - from application in play-akka.actor.default-dispatcher-4
--------------------------------------------------------------

以下のようにログが分割されている。

$ ls -ltr
合計 12
-rw-rw-r-- 1 pool pool 2393  2月 19 07:40 application.2.log
-rw-rw-r-- 1 pool pool 1106  2月 19 07:42 application.1.log
-rw-rw-r-- 1 pool pool  158  2月 19 07:42 application.log

おお。ちゃんと最新のファイルは application.log になってるし 1000 bytes で（チョッキリではないけど）ローテーションされている！

ということで…

今日の知見

  • Play Framework では標準で Logback というログフレームワークが利用されている
  • 特に指定しなければ ${application.home}/logs/application.log にログが吐かれ続ける
  • ローテーションを行う場合には ch.qos.logback.core.rolling.RollingFileAppender クラスを利用する
  • RollingFileAppender クラスではファイルサイズ、時間でのローテーションを行うことが出来る

今回は…

駆け足でサイズベースのローテーションを試してみたが TimeBasedRollingPolicy を利用することで時間でのローテーションも出来るので別途試したいみたい。

元記事はこちらです。
「PlayFramework の application.log をよしなにローテーションする方法」