初めてのRailsアプリ（その５）

ruby rails

railsubject_05

初めてのRailsアプリ（その５）

When on Rails, do as the Railsist do.

6. ログを整える

ログ仕様なるものが出来上がったようなので、それをなるべく容易に実現すべく奮闘。楽をしたいがために、勤勉に勉強する、なんという矛盾。

仕様

  • フォーマット
    • YYYY/MM/DD hh:mm:ss.SSS LogLevel (UserId) (Calller) MessgeId Message ExceptionInfo
    • ExceptionInfo（例外情報）は省略可能
  • Actionの開始前／終了後にログを出力

実装

CustomLogger

標準のloggerをラップしてカスタマイズ。

# Rails.loggerをカスタマイズしたモジュール 
# ログの書式は以下
# (ユーザID)　（呼び出し元） メッセージ エラーメッセージ スタックトレース
module CustomLogger
    # Rails.logger.debugのカスタマイズ
    # == Parameters:
    # ユーザID（セッション等から取得する）
    # メッセージID（MSG_MSG_000）
    # メッセージ
    # 例外（省略可能）
    def debug(user_id, message_id, message, error=nil)
        log = format(user_id, message_id, message, error)
        Rails.logger.debug(log)
    end

    # Rails.logger.infoのカスタマイズ
    # == Parameters:
    # ユーザID（セッション等から取得する）
    # メッセージID（MSG_MSG_000）
    # メッセージ
    # 例外（省略可能）
    def info(user_id, message_id, message, error=nil)
        log = format(user_id, message_id, message, error)
        Rails.logger.info(log)
    end

    # Rails.logger.warnのカスタマイズ
    # == Parameters:
    # ユーザID（セッション等から取得する）
    # メッセージID（MSG_MSG_000）
    # メッセージ
    # 例外（省略可能）
    def warn(user_id, message_id, message, error=nil)
        log = format(user_id, message_id, message, error)
        Rails.logger.warn(log)
    end

    # Rails.logger.errorのカスタマイズ
    # == Parameters:
    # ユーザID（セッション等から取得する）
    # メッセージID（MSG_MSG_000）
    # メッセージ
    # 例外（省略可能）
    def error(user_id, message_id, message, error=nil)
        log = format(user_id, message_id, message, error)
        Rails.logger.error(log)
    end

    module_function :debug
    module_function :info
    module_function :warn
    module_function :error

    private
    def format(user_id, message_id, message, error)
        caller = caller(2).first.split("/").last
        if(!error.nil?) then
            error_message = "#{error.message} #{error.backtrace}"
        else
            error_message = ""
        end
        return "(#{user_id}) (#{caller}) #{message} #{error_message}"
    end

    module_function :format
end

application.rb

ログのフォーマットをデフォルトから変更する。また、ログのカラー情報を除去する。

f:id:naotooncajon:20130723002919p:image

environment.rb

ログのフォーマットを指定。こんなトコロでオーバーライド可能、なんかもう自由すぎだよ、Ruby。

f:id:naotooncajon:20130723002915p:image

application_controller.rb

基底コントローラにフィルタを設定

f:id:naotooncajon:20130723002912p:image

完成形

使い方

適当なところでログを出力します。

f:id:naotooncajon:20130723002909p:image

ログ

そんで出力結果はこちら。

2013/07/22 21:49:41.687855 #57291  INFO Started GET "/subjects/" for 127.0.0.1 at Mon Jul 22 21:49:41 +0900 2013
2013/07/22 21:49:41.699202 #57291  INFO Processing by SubjectsController#index as HTML
2013/07/22 21:49:41.699824 #57291  INFO (7010onCajon) (application_controller.rb:9:in `start_logger') Action開始 
2013/07/22 21:49:41.701322 #57291 DEBUG   Subject Load (0.3ms)  SELECT "subjects".* FROM "subjects" 
2013/07/22 21:49:41.701764 #57291 DEBUG (7010onCajon) (subjects_controller.rb:7:in `index') デバッグです。 
2013/07/22 21:49:41.702252 #57291 DEBUG (7010onCajon) (subjects_controller.rb:11:in `index') エラーです。 エラー /Users/7010oncajon/Documents/workspace/railsubject/app/controllers/subjects_controller.rb:9:in `index'/Library/Ruby/Gems/1.8/gems/actionpack-3.2.13/lib/action_controller/metal/implicit_render.rb:4:in `send_action'/Library/Ruby/Gems/1.8/gems/actionpack-3.2.13/lib/action_controller/metal/implicit_render.rb:4:in

...

2013/07/22 21:49:41.708029 #57291  INFO   Rendered subjects/index.html.erb within layouts/application (0.9ms)
2013/07/22 21:49:41.710125 #57291  INFO (7010onCajon) (application_controller.rb:13:in `end_logger') Action終了 
2013/07/22 21:49:41.710546 #57291  INFO Completed 200 OK in 11ms (Views: 6.5ms | ActiveRecord: 0.3ms)

スタックトレースが長すぎるorz

終わりに

困ったこと

  • ミリ秒が三桁(.SSS)で表示できない。六桁になってしまうが、どうするんだ。
  • SQLはDEBUGレベルなようだ。リリース版でもSQLログがいるとかいらないとか、どうしよう。
  • 勢いでPIDを入れちゃったけど、要るかな。

今後やりたいこと

  • groupでsubjectを選択する際のUI高度化
  • mailでメールを送る
  • activerecordについてのお勉強