Using Kernel#caller to Log Method Name and Line Number
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.