zerosum dirt(nap)

evolution through a series of accidents

zerosum dirt(nap)

Tweaking The Rails Logger

March 05, 2007 by nap · Comments

The Ruby Logger is a simple but pretty flexible tool — hopefully you’re already using it. If not, you should be. The default logger message format is pretty barebones though, so I thought I’d take a few minutes to talk about how to make it more useful by monkey patching format_message.

First, make sure to check out TopFunky’s ‘Hodel 3000 compliant logger’ article, posted a couple months ago. Geoffrey’s syslog-friendly modification works great when running in production mode. Customized log messages are just as important in the development environment, where we’ve made our own simple modifications to include the name and line number of the file:

class Logger
  def format_message(severity, timestamp, msg, progname)
    "#{Kernel.caller[2]}: #{severity.upcase}: #{progname.gsub(/\n/, '').lstrip}\n"

This little snippet is especially handy if you’re using an IDE like IntelliJ that’s smart enough to hyperlink the file path. Got an error being logged in users_controller.rb on line 91? Click on the hyperlink and you’re there.

It works by accessing the execution stack Array returned by Kernel.caller. caller0 will refer to the line in Logger#add where format_message is called. caller1 is most likely going to point to one of the Logger# methods, one of [ debug, info, warn, error, fatal ]. This is the next level down in the stack, where the add method was called from. In most “application-level” code (code we actually write in our application, exterior to the benchmarking messages and such that Rails gives us for free), caller2 is going to be something in our application code itself, some place that we called, or logger.error, or whatever, from.

To get this installed in our environment we create a file development_logger.rb, containing the source above. Then, in development.rb (or the initializer block of environment.rb):

require 'development_logger.rb'

This will “monkey patch” the Rails Logger, effectively overriding it’s format_message method with our own mojo. Sure, it’s not perfect. But it works great for development purposes. A more elegant way to do the same thing would be to subclass Logger and then do something like:

config.logger =

However, this just doesn’t seem to have any effect when running script/server, which proceeds as if config.logger is set to the standard (unmodified) Rails Logger. I’m at a bit of a loss as to why. If anyone can explain why setting config.logger seems to have no effect, please (please!) let me know.

blog comments powered by Disqus