跟踪/记录 ActiveRecord 回调函数

Question

有没有办法自动记录每次 ActiveRecord 回调发生的日志？当记录有多个回调时，这将有助于跟踪特定事情发生的原因。

我希望看到自动化日志消息，指示响应哪些回调而调用了哪些消息。例如：before_validation：calling update_capitalization

- mahemoff

Answer 1

我刚刚为此编写了一个宝石(gem)。

# Gemfile
gem "rails-callback_log", group: [:development, :test]

• https://github.com/jaredbeck/rails-callback_log
• https://rubygems.org/gems/rails-callback_log

- Jared Beck

---

太棒了！将是一个有用的开发插件。 - mahemoff

看起来这个 gem 已经不再维护了。在 Rails 7 上它对我来说无法工作。 - Aaron Breckenridge

回复：Rails 7，欢迎提交PR。 - Jared Beck

Answer 2

为了Google和后人（在Rails 3上）：

module CallbackTrace
  def self.included kls
    kls.send :alias_method_chain, :_compile_filter, :trace
  end

  def _compile_filter_with_trace filter
    generated_code = _compile_filter_without_trace(filter)
    return generated_code if filter.is_a?(Array)
    method_name = generated_code.to_s.split(%r{\(|\s}).first
    _klass = @klass
    prelogger = ->{
        Rails.logger.info("START [#{filter.class}](#{generated_code})")
        Rails.logger.info("#{_klass} #{Time.now}")
        if imethod=(_klass.instance_method(method_name) rescue nil)
          begin
            Rails.logger.info(imethod.source)
          rescue MethodSource::SourceNotFoundError
            Rails.logger.info("NO SOURCE FOR #{generated_code}")
          end
        else
          Rails.logger.info("NO METHOD: #{method_name} for #{@klass}")
        end
    }
    postlogger = ->{
      Rails.logger.info("ENDED #{generated_code} #{Time.now}")
    }
    @klass.send :define_method, "prelogger_#{method_name}", &prelogger
    @klass.send :define_method, "postlogger_#{method_name}", &postlogger
    "(prelogger_#{method_name}; retval = retval = #{generated_code}; " +
        "postlogger_#{method_name}; retval)"
  end
end
ActiveSupport::Callbacks::Callback.send :include, CallbackTrace

- xtoddx

---

我将这个放在初始化器中，并加入了一个配置选项来运行它或不运行。效果很好。非常冗长，因此即使在正常开发中也不会使用，但可以帮助您跟踪奇怪的回调问题。 - mahemoff

不幸的是，在Rails 4.1中无法工作，类'ActiveSupport :: Callbacks :: Callback'没有定义'_compile_filter'方法。 - mahemoff

Answer 3

更简单的方法是使用Rails本地记录器方法：

调试Rails应用程序

像这样使用它：

logger.debug "Person attributes hash: #{@person.attributes.inspect}"
logger.info "Processing the request..."
logger.fatal "Terminating application, raised unrecoverable error!!!"

编辑：

检查异常发生时调用了什么也是很有趣的用法。

logger.error("trace: #{ex.backtrace().join("\n")}")

- felipeclopes

---

谢谢，但我正在寻找一种自动化的方式，也许是一个外部 gem。我已经更新了问题。 - mahemoff

Answer 4

另一种方法是在所有模型上定义回调以进行日志记录。为了避免加载所有内容，您只需加载模型即可。为简单起见，这将尝试加载与app/models/*.rb中所有文件对应的类。我还将使用puts，但您可以使用Rails.logger.info或其他。对于临时调试，您可以将其放入初始化程序中，例如：config/initializers/001_log_callbacks.rb:

# Log all callbacks
Dir[Rails.root.join('app/models/*.rb').to_s].each do |filename|
  name = File.basename(filename, '.rb')
  begin
    model = name.camelize.constantize
    ActiveRecord::Callbacks::CALLBACKS.each do |callback|
      if callback.to_s.start_with?('around_')
        model.class_eval "#{callback} do |*args, &prc|; puts \"#{model}(\#{id}).#{callback} start\"; prc.call(*args) if prc; puts \"#{model}(\#{id}).#{callback} end\" end"
      else
        model.class_eval "#{callback} do; puts \"#{model}(\#{id}).#{callback}\" end"
      end
    end
  rescue
  end
end

- Gary S. Weaver