I was going through the Web of Metal app logs and thought that it would be helpful if the log statements also printed the method name and line number along with the message being logged. I wrote this little helper module that I thought you might find helpful.

Your can download the source from Git hub

The module adds 5 helper methods to your class: log_debug, log_info, log_warn, log_error, and log_fatal

Whenever you call one of the methods it will log the message in the following format:

classname:method_name:(line_number):your_message


This is what the code would look like in your method:

def do_something
  log_debug(“entering method”)
end

Here is an example of the log:
LogHelperExample:do_something:(14):entering method

The module will also print out the log statements to the screen if the RAILS_ENV is ‘test’ or ‘development’. I found that useful for my app but you may want to remove it.

The module creates the helper methods using the following code:

def self.define_log_helper(base, level)
  base.class_eval <<-end_eval
    def log_#{level}(string, &block)
      log_string = "\#{get_caller(caller)}:\#{string}"
      puts log_string if defined?(RAILS_ENV) && (RAILS_ENV == 'test' || RAILS_ENV == 'development')
      get_logger.#{level}(log_string, &block)
    end
  end_eval
end

Getting the name of the method and line number was relatively easy. The key is to use the private method caller from Kernel

The caller method places the execution stack into an array object. The line number and method name are retrieved from the LogHelper.get_caller method.

def get_caller(ca)
  "#{self.class.name}:#{$2}:(#{$1})" if /:(\d*):in `([^']*)'/.match( ca[0])
 end

The code above pulls the first element of the array, which contains the value that we want to parse. It will look like the following:


['/Users/gulicss/source/blog/log_helper/test/log_helper_example.rb:5:in `do_something'', '/Users/gulicss/source/blog/log_helper/test/log_helper_test.rb:16:in `test_should_pass_in_callers_classname_method_name_and_line_number'', '/Library/Ruby/Gems/1.8/gems/mocha-0.9.3/lib/mocha/test_case_adapter.rb:69:in `__send__'', '/Library/Ruby/Gems/1.8/gems/mocha-0.9.3/lib/mocha/test_case_adapter.rb:69:in `run'', '/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/test/unit/testsuite.rb:34:in `run'',.....


A downside to this implementation is that it really only works in classes that include the LogHelper module and use the helper methods. Any class that uses logger.<log level> directly will not have the extra information

In Rails 2.2.2 there is no way to change the format of the Logger output . If you want to add this functionality so that the format of all logged message displays the method name and line number you would have to modify BufferedLogger directly like in the following:

for severity in Severity.constants
  class_eval <<-EOT, __FILE__, __LINE__
    def #{severity.downcase}(message = nil, progname = nil, &block)
      if /(\\w*)\\.rb:(\\d*):in `([^']*)'/.match( caller[0])
        message = "\#{$1.camelize}:\#{$3}:(\#{$2}):\#{message}"
      end
      add(#{severity}, message, progname, &block)
    end
    def #{severity.downcase}?
      #{severity} >= @level
    end
  EOT
end

Notice in the above I parse out the class name from caller[0]. This is required because the value of self.class.name will now be ActiveSupport::BufferedLogger.

Well that is about it. Hope you find something useful in this post.