Rails 中的日志解析

1. 介绍

一般来说，为了调试，几乎每个应用框架都可以看到日志输出，rails 也不例外，且会经常查看日志来排错。而在 rails 中使用日志断点也很简单。

# 点击菜单跳转链接时的事件推送
def handle_view_event
  Rails.logger.info("你点击了: #{@keyword}")
end

就是使用Rails.logger.info这个指令，只要在需要断点输出的地方，都可以使用，包括你的 controller、mdoel 等。

在开发环境和生产环境，总是有一些区别，比如在生产环境有时候会因为一些 nil 值，报 500 错误，这个时候我们就要根据生产环境的日志来排错，但生产环境的日志不够详细，难以看出什么错误。而日志是有等级之分的，只要把生产环境的日志等级设置成 debug 就可以看到更为详细的信息。

# config/environments/production.rb
config.log_level = :debug

但这样也是有弊端的，因为输出的内容多了，会导致日志文件很大的，需要权衡。

刚才说过日志是有等级，rails 的日志分成五个等级，按照事件的轻重程序从低到高分别是: debug、info、warn、error、fatal。

也就是说上面的Rails.logger.info可以换成Rails.logger.debug等。

默认情况下，我们的日志是存放在log/development.log上的，如果想更改位置那也很简单。

# config/application.rb
config.logger = Logger.new('foo.log', 'daily')

上面的例子就是把日志文件换成'foo.log'，并且还可以保留一天的日志信息，就是会自动切割日志，这样可以僻免日志文件越来越臃肿的问题。

除了按照时间来切割日志之外，还可以按照日志文件的大小来切割。

除此之外，还可以对日志的格式进行自定义，比如时间格式等。

2. 源码解析

ruby 有个标准库叫logger，而 rails 中的日志功能就是基于它实现的，这个库定义了日志的等级，以及如何输出日志等内容。

当访问一个 action 的时候，经常可以在日志中看到类似下面这样的信息。

Started GET "/articles/redis-de-tu-xing-hua-gong-ju-si" for 127.0.0.1 at 2015-12-02 15:00:21 +0800
Processing by ArticlesController#show as HTML
  Parameters: {"id"=>"redis-de-tu-xing-hua-gong-ju-si"}

通过搜索 rails 的源码，可以找到对应上面表现效果的代码：

# https://github.com/rails/rails/blob/7f18ea14c893cb5c9f04d4fda9661126758332b5/actionpack/lib/action_controller/log_subscriber.rb#L5
module ActionController
  class LogSubscriber < ActiveSupport::LogSubscriber

    def start_processing(event)
      return unless logger.info?

      payload = event.payload
      params  = payload[:params].except(*INTERNAL_PARAMS)
      format  = payload[:format]
      format  = format.to_s.upcase if format.is_a?(Symbol)

      info "Processing by #{payload[:controller]}##{payload[:action]} as #{format}"
      info "  Parameters: #{params.inspect}" unless params.empty?
    end

  end
end

那在源码中是如何调用这个方法的呢？

# https://github.com/rails/rails/blob/7f18ea14c893cb5c9f04d4fda9661126758332b5/actionpack/lib/action_controller/metal/instrumentation.rb#L27
module ActionController
  module Instrumentation
    extend ActiveSupport::Concern

    include AbstractController::Logger

    def process_action(*args)
      ...
      ActiveSupport::Notifications.instrument("start_processing.action_controller", raw_payload.dup)
      ...
    end

  end
end

3. lograge

lograge这个 gem 可以让你改变 ruby 默认的日志记录的格式和方式，比如它可以忽略更无用的日志信息，集中在重要的信息上。

添加下面那行到Gemfile文件：

gem "lograge"

开启这个功能：

# config/application.rb
config.lograge.enabled = true

重启 rails 应用即可。

其他的功能可以查看官方的 readme 文档。

完结。