【Rails】バッチの実行ログを専用のログファイルと標準出力の両方に出す

目的

以下のようなことがやりたかったので、その実現方法のメモです。

cronで実行されるrakeタスクの実行ログを、そのバッチ専用のログファイルに出力
手動でバッチ実行したときのために、標準出力にも同じ内容を出力
予期せぬ例外が発生したときのエラー内容もログファイルに記録

1. バッチ専用のログファイルに出力

単純にRails.loggerを使うと、Controllerなどが出力するアプリケーションログもバッチのログもすべて同じファイルに出力されてしまいます（log/production.logなど）。それらを区別してバッチの実行ログを確認しやすいようにするため、個別のログファイルに出力します。

ファイル名の指定

以下でlog/batch.logに出力されます。

logger = ActiveSupport::Logger.new(Rails.root.join("log/batch.log"))
logger.info "バッチのログだよーん" # => log/batch.logに書き込まれる

ローテートの設定

さらに、Logger.newの第2,3引数を指定すると、ログローテートの設定ができます。ファイルサイズが膨大になる前に、ファイルを自動的に分割してくれます。

サイズ指定で分割

以下は、10MBを超えたらファイルを分割し、5ファイルを超えたら古いファイルを削除する、という設定。 batch.log.0、batch.log.1、というファイル名になります。

ActiveSupport::Logger.new("log/batch.log", 5, 10.megabytes)

日数で分割

'daily', 'weekly', 'monthly'を指定すると、1日 or 1週間 or 1ヶ月の間隔でファイルを更新します。 batch.log.20141101、とか、batch.log.201411、などのファイル名になります。

# 1日で分割
ActiveSupport::Logger.new("log/batch.log", "daily")
# 1週間で分割
ActiveSupport::Logger.new("log/batch.log", "weekly")
# 1ヶ月で分割
ActiveSupport::Logger.new("log/batch.log", "monthly")

フォーマットの指定

Logger.newしたログはメッセージのみを出力する味気ないものになってます。以下でフォーマットをつけましょう。

logger.formatter = ::Logger::Formatter.new
logger.info "バッチのログだよーん"

Formatterのデフォルトの形式に則って、以下のようなログが出ます。

I, [2014-11-15T18:48:18.763841 #21583]  INFO -- : バッチのログだよーん

2. 標準出力にも同じ内容を出力する

開発中などは、バッチ実行したときにログファイルだけに出力されるだとけっこう不便です。なので、同時に標準出力にも出力されるようにします。

標準出力にログを出す場合は、Logger.newにファイル名ではなくSTDOUTを指定します。標準エラー出力の場合はSTDERRですね。

2つのLoggerに同時に出力させるには、ActiveSupport::Logger.broadcastメソッドを利用します。

logger = ActiveSupport::Logger.new("log/batch.log")
console = ActiveSupport::Logger.new(STDOUT)

logger.extend ActiveSupport::Logger.broadcast(console)

logger.info "バッチのログだよーん" # => batch.log と 標準出力の両方に出力

broadcastの実装は以下を参照。 2つのLoggerに同じメソッド呼び出しをするModuleを生成していますね。

rails/logger.rb at master · rails/rails

これを、バッチの先頭でRails.loggerに上書いてしまえば、バッチ実行中に呼び出されるRails.loggerはすべて指定したログファイルと標準出力に出るので、便利です。

# ログレベルはアプリケーションのものを継承するとよいかも
logger.level = Rails.logger.level

Rails.logger = logger

3. エラー内容をログファイルに出力

本筋とは少しずれておまけみたいになります。バッチ実行中に予期せぬ例外が発生した場合は、そのエラー内容がログファイルに書きだされていると便利です。これに関してはうまいやり方がわからなかったので、とりあえずcron実行のときには標準エラー出力の内容をログファイルに追記するようにします。

crontabに2>>log/cron.logをつければいいのですが、cronの登録にはwheneverを使うので、wheneverでのこれの付け方。

schedule.rbで以下のように記述します。

every 1.hour do
  rake "batch", output: { error: "log/cron.log" }
end

ちなみに、output: { standard: "log/cron.log" } で 1>>log/cron.logがつきます。

参考： Output redirection aka logging your cron jobs · javan/whenever Wiki

おどるダメ人間

Web系の技術のこととか、そうじゃないこととか、思いついたことをメモする。