The Ideal Rails Production Environment Log Level

I am learning all about Rails logs today. My objective is to determine the ideal log level to run a Rails Application in when it is in the Production Environment. The app currently runs in :info but this generates pretty hefty log files. We have a cron job setup to email the production.log contents every day. I've found that I tend to tune out repetitive emails--which is dangerous when it comes to server logs because it makes it easy to miss important messages when they come.

My first find in my quest was this article: Rails Logging Tips. It provided foundational knowledge of logging options as well some advanced logging pointers. I learned that the Rails log levels available to me are: debug, info, warn, error, and fatal. I also learned that Rails defaults to the "info" level when in the Production Environment. The section on Reducing Log File Size drew my attention. I decided to edit my config/environments/production.rb file to config.log_level = :warn. At first it looks like its going to do the trick, the log will only have warnings and errors in it from here out! But when I purposefully generate an application error I notice that the information logged about it is really not all that helpful. It does give me a backtrace. But I want to know what user actions caused the error so I can duplicate it (maybe this is possible with backtraces and I don't know it yet). The information I want is a timestamp and the url or request that was made resulting in the error. This information was available in the :info log level.

Next order of business, trying out all of the log levels to see if a different one will suit me better. Note: When changing log levels in your production.rb file you have to restart you application for the change to take effect. I couldn't remember how to restart my application. Our server is running Passenger. This wiki article: Restarting a Rails Application Using Passenger gave me the magic command I was looking for (touch /tmp/restart.txt).

Wow! :debug gives some pretty handy info. Including SQL statements. After poking around a bit more I decide none of the log levels do what I want. I'd like to get the information displayed in the :debug or :info log levels but only when the message is :warn or higher. I remember that the Rails Logging Tips article mentioned something about filtering log messages. Maybe I could set the log level to :info and apply some sort of filter. My Google searches on this don't turn up any promising leads. But I do happen upon a few blog posts about adding timestamps to the Rails logger. There are two different ways to do it. One way is to extend the logger class the other way is to initiate your own logger class. Apparently Rails changed up the logger in version 2.x.

How to modify the logger class in Rails 1.2.x:

http://www.zetetic.net/blog/2007/11/08/making-rails-logs-more-useful/

How to modify the logger class in in Rails 2.x:

http://stackoverflow.com/questions/462651/rails-logger-format-string-configuration

How to create your own custom logger in Rails 2.x

Rails 2.x: http://www.ubuntusolutions.org/2009/08/custom-logger-in-rails.html

I add the lines of code to the end of my environment.rb file and voila I have timestamps. :)

I am not quite ready to jump into creating a custom logger. I am still interested in possibly filtering the :info log messages. Maybe I could get it to disregard logs for requests that return an status 200 ok.

Two more parting nuggets I dug up while researching this. How to rotate your rails logs and how to log to STDOUT when using the console.