使用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发布了我的答案之后(参见下面的“编辑”)，我想我应该尝试使用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。