使用 Log4r 进行上下文日志记录

Question

以下是我使用 Log4r 的一些现有日志记录代码的工作方式。正如您在 WorkerX::a_method 中看到的那样，每当我记录一条消息时，我都希望包含类名和调用方法（我不希望所有调用者历史记录或任何其他噪音，这是我背后的目的LgrHelper）。

class WorkerX

  include LgrHelper

  def initialize(args = {})
    @logger = Lgr.new({:debug => args[:debug], :logger_type => 'WorkerX'})
  end

  def a_method
    error_msg("some error went down here")
    # This prints out: "WorkerX::a_method - some error went down here"
  end

end


class Lgr
  require 'log4r'
  include Log4r

  def initialize(args = {}) # args: debug boolean, logger type
    @debug = args[:debug] 
    @logger_type = args[:logger_type]

    @logger = Log4r::Logger.new(@logger_type)
    format = Log4r::PatternFormatter.new(:pattern => "%l:\t%d - %m")
    outputter = Log4r::StdoutOutputter.new('console', :formatter => format)
    @logger.outputters = outputter

    if @debug then
      @logger.level = DEBUG
    else
      @logger.level = INFO
    end
  end

  def debug(msg)
    @logger.debug(msg)
  end

  def info(msg)
    @logger.info(msg)
  end

  def warn(msg)
    @logger.warn(msg)
  end

  def error(msg)
    @logger.error(msg)
  end

  def level
    @logger.level
  end

end


module LgrHelper

  # This module should only be included in a class that has a @logger instance variable, obviously.

  protected

  def info_msg(msg)
    @logger.info(log_intro_msg(self.method_caller_name) + msg)
  end

  def debug_msg(msg)
    @logger.debug(log_intro_msg(self.method_caller_name) + msg)
  end

  def warn_msg(msg)
    @logger.warn(log_intro_msg(self.method_caller_name) + msg)
  end

  def error_msg(msg)
    @logger.error(log_intro_msg(self.method_caller_name) + msg)
  end

  def log_intro_msg(method)
    msg = class_name
    msg += '::'
    msg += method
    msg += ' - '

    msg
  end

  def class_name
    self.class.name
  end

  def method_caller_name
    if  /`(.*)'/.match(caller[1]) then # caller.first
      $1
    else
      nil
    end
  end

end

我真的不喜欢这种方法。我宁愿只使用现有的@logger 实例变量来打印消息并足够聪明地了解上下文。如何做到这一点，或类似的更简单的方法？

我的环境是 Rails 2.3.11（现在！）。

Answer 1

在使用extend 发布我的答案后，（请参阅下面的“EDIT”），我想我会尝试使用set_trace_func 来保持某种堆栈跟踪，就像我在讨论中一样发布到。这是我的最终解决方案； set_trace_proc 调用将被放入初始化程序或类似函数中。

#!/usr/bin/env ruby

# Keep track of the classes that invoke each "call" event
# and the method they called as an array of arrays.
# The array is in the format: [calling_class, called_method]
set_trace_func proc { |event, file, line, id, bind, klass|
  if event == "call"
    Thread.current[:callstack] ||= []
    Thread.current[:callstack].push [klass, id]
  elsif event == "return"
    Thread.current[:callstack].pop
  end
}

class Lgr
  require 'log4r'
  include Log4r

  def initialize(args = {}) # args: debug boolean, logger type
    @debug = args[:debug]
    @logger_type = args[:logger_type]

    @logger = Log4r::Logger.new(@logger_type)
    format = Log4r::PatternFormatter.new(:pattern => "%l:\t%d - %m")
    outputter = Log4r::StdoutOutputter.new('console', :formatter => format)
    @logger.outputters = outputter

    if @debug then
      @logger.level = DEBUG
    else
      @logger.level = INFO
    end
  end

  def debug(msg)
    @logger.debug(msg)
  end

  def info(msg)
    @logger.info(msg)
  end

  def warn(msg)
    @logger.warn(msg)
  end

  def error(msg)
    @logger.error(msg)
  end

  def level
    @logger.level
  end

  def invoker
    Thread.current[:callstack] ||= []
    ( Thread.current[:callstack][-2] || ['Kernel', 'main'] )
  end
end

class CallingMethodLogger < Lgr
  [:info, :debug, :warn, :error].each do |meth|
    define_method(meth) { |msg| super("#{invoker[0]}::#{invoker[1]} - #{msg}") }
  end
end

class WorkerX
  def initialize(args = {})
    @logger = CallingMethodLogger.new({:debug => args[:debug], :logger_type => 'WorkerX'})
  end

  def a_method
    @logger.error("some error went down here")
    # This prints out: "WorkerX::a_method - some error went down here"
  end
end

w = WorkerX.new
w.a_method

我不知道对 proc 的调用会在多大程度上影响应用程序的性能；如果有的话；如果它最终成为一个问题，也许调用类的一些不那么聪明的东西（就像我的旧答案，下面）会更好。

[编辑：下面是我的旧答案，上面引用了。]

使用extend怎么样？这是我从你的代码中拼凑起来的一个快速而肮脏的脚本来测试它；我不得不重新排序以避免错误，但除了LgrHelper（我将其重命名为CallingMethodLogger）和WorkerX的初始化程序的第二行之外，代码是相同的：

#!/usr/bin/env ruby

module CallingMethodLogger
  def info(msg)
    super("#{@logger_type}::#{method_caller_name} - " + msg)
  end

  def debug(msg)
    super("#{@logger_type}::#{method_caller_name} - " + msg)
  end

  def warn(msg)
    super("#{@logger_type}::#{method_caller_name} - " + msg)
  end

  def error(msg)
    super("#{@logger_type}::#{method_caller_name} - " + msg)
  end

  def method_caller_name
    if  /`(.*)'/.match(caller[1]) then # caller.first
      $1
    else
      nil
    end
  end
end

class Lgr
  require 'log4r'
  include Log4r

  def initialize(args = {}) # args: debug boolean, logger type
    @debug = args[:debug]
    @logger_type = args[:logger_type]

    @logger = Log4r::Logger.new(@logger_type)
    format = Log4r::PatternFormatter.new(:pattern => "%l:\t%d - %m")
    outputter = Log4r::StdoutOutputter.new('console', :formatter => format)
    @logger.outputters = outputter

    if @debug then
      @logger.level = DEBUG
    else
      @logger.level = INFO
    end
  end

  def debug(msg)
    @logger.debug(msg)
  end

  def info(msg)
    @logger.info(msg)
  end

  def warn(msg)
    @logger.warn(msg)
  end

  def error(msg)
    @logger.error(msg)
  end

  def level
    @logger.level
  end
end

class WorkerX
  def initialize(args = {})
    @logger = Lgr.new({:debug => args[:debug], :logger_type => 'WorkerX'})
    @logger.extend CallingMethodLogger
  end

  def a_method
    @logger.error("some error went down here")
    # This prints out: "WorkerX::a_method - some error went down here"
  end
end

w = WorkerX.new
w.a_method

输出是：

ERROR:  2011-07-24 20:01:40 - WorkerX::a_method - some error went down here

缺点是，通过这种方法，调用者的类名不会被自动计算出来；它基于传递给Lgr 实例的@logger_type 是显式的。但是，您可以使用另一种方法来获取类的实际名称——可能类似于call_stack gem 或使用Kernel#set_trace_func——参见this thread。