読者です 読者をやめる 読者になる 読者になる

tumblr

tumblr(タンブラー)は、メディアミックスブログサービス。ブログとミニブログ、そしてソーシャルブックマークを統合したマイクロブログサービスである。アメリカのDavidville.inc(現: Tumblr, Inc.)により2007年3月1日にサービスが開始された。

railsのログフォーマットを変更する

Ruby on Rails

railsのloggerが良く言えばミニマル、悪く言うとログとしての機能を満たしてないんじゃないのってくらい貧弱なので、ログのフォーマットを変えようとおもった。
環境はruby2.0.0-p247, rails4.0.0

Rails.loggerの継承元

デフォルトのrailsのloggerは以下のように使うことが出来る。

Rails.logger.debug("This is debug log")
# => This is debug log

ログメッセージのみの出力しか無い。せめてログを吐いた時刻とかログレベルくらいは出力して欲しい。
そもそもこのRails.loggerはなにものなのか

klass = Rails.logger.class # => ActiveSupport::Logger
p klass.ancestors
#  [ActiveSupport::Logger,
#  LoggerSilence,
#  Logger,
#  Logger::Severity,
#  Object,
#  ActiveSupport::Dependencies::Loadable,
#  PP::ObjectMixin,
#  V8::Conversion::Object,
#  JSON::Ext::Generator::GeneratorMethods::Object,
#  Kernel,
#  BasicObject]

Rails.logger自体はActiveSupport::Loggerクラスのインスタンス、そしてそのクラスはLoggerクラスを継承している

ActiveSupport::Loggerの中身

ActiveSupport::Loggerのソースを見てみるとかなりシンプル。
標準添付ライブラリのLoggerを継承してLoggerSilenceというモジュールをincludeしてbroadcastというクラスメソッドを定義している。どうやらこのクラスの使用感はLoggerとそれほど変わらないっぽい。
LoggerSilenceを見てみてもLoggerのメソッドをオーバーライドしている感じも見当たらない。


ActiveSupport::Loggerの最後のほうに何やら怪しげなクラスが定義されている。というかコメントにも思いっきり" which only displays the message. "って書いてあるので、どうやらここをどうにかすればrailsのログフォーマットも変えられそうだ。

    # Simple formatter which only displays the message.
    class SimpleFormatter < ::Logger::Formatter
      # This method is invoked when a log event occurs
      def call(severity, timestamp, progname, msg)
        "#{String === msg ? msg : msg.inspect}\n"
      end
    end

https://github.com/rails/rails/blob/v4.0.0/activesupport/lib/active_support/logger.rb
https://github.com/rails/rails/blob/v4.0.0/activesupport/lib/active_support/logger_silence.rb

標準添付ライブラリのLogger

Rails.loggerの継承元であるLoggerはrubyの標準添付ライブラリのものらしい。
このLoggerの使い方というかログフォーマッタの変更方法が分かればrailsのログフォーマットの変更も出来そうだ。


ドキュメントを見ると見慣れたinfoとかerrorなどのログレベルをそのままインスタンスメソッドにしたものが書かれているのに加えてformatterというわかりやすいインスタンスメソッドを発見。

formatter -> String
ログを出力する際に使用するフォーマッターを取得します。
このメソッドの返り値が持つ call メソッドは 4 つの引数 (severity, time, program name, message) を受けとります。


formatter=(formatter)
ログを出力する際に使用するフォーマッターをセットします。
[PARAM] formatter:
4 つの引数 (severity, time, program name, message) を受け取る call メソッドを 持つオブジェクトを指定します。call メソッドの返り値は文字列にしてください。

http://docs.ruby-lang.org/ja/1.9.2/class/Logger.html


ドキュメントにあるようにLoggerのインスタンスメソッドformatterにフォーマッターオブジェクトを渡せばログフォーマットを変えられるようだ。フォーマッターはcallメソッドを持てばいいのでProcオブジェクトを渡してもいいみたい。

ここで再度ActiveSupport::Loggerの中で定義していたSimpleFormatterを見てみる。これも指定通りcallメソッドを持っているが、msgという引数以外は無視しているがためにseverity(ログレベル), time(ログの出力時刻), prog name(アプリ名など)のログに欲しい情報が全く出ていなかったのだと分かる。

ログフォーマットの変更

そうと分かればあとは適当なフォーマッターを作ってそれをconfig/initializerの中とかで適当に読みこませればいい。
(こういうものってconfig/initializerに入れるべきなのかどうすべきなのかはよく分からない…)

[追記] 2014/1/05 21:54
修正前のコードをconfig/initializersの中にいれてrails sでwebrickサーバを起動すると
undefined method `tagged' for #
というエラーが出てた。
tagged logging用のメソッドがないとかなんとか言ってるのでとりあえずActiveSupport::TaggedLogging::Formatterをインクルードしてみたら直った
以下は修正済みのコード

class LoggerFormatWithTime

  def call(severity, timestamp, progname, msg)
    "[#{timestamp.strftime("%Y/%m/%d %H:%M:%S" )}.#{'%06d' % timestamp.usec.to_s}] (pid=#{$$}) [#{severity}] -- [#{progname}]: #{String === msg ? msg : msg.inspect}\n"
  end
end

Rails.logger.formatter = LoggerFormatWithTime.new
Rails.logger.progname = "SugoiApp"
Rails.logger.error "yabai error"
# => [2014/01/04 21:15:39.454915] (pid=41290) [ERROR] -- [SugoiApp]: yabai error