ActiveRecord changes Logger formatting

rubyonrails-talk
1

Why does my Logger formatting change after I "require 'active_record'"?

irb(main):001:0> require 'logger' => true irb(main):002:0> $logger = Logger::new STDOUT => #<Logger:0xb7dd0a38 @formatter=nil, @default_formatter=#<Logger::Formatter:0xb7dd0a10 @datetime_format=nil>, @level=0, @progname=nil, @logdev=#<Logger::LogDevice:0xb7dd09e8 @shift_age=nil, @filename=nil, @mutex=#<Logger::LogDevice::LogDeviceMutex:0xb7dd09c0 @mon_waiting_queue=, @mon_entering_queue=, @mon_count=0, @mon_owner=nil>, @dev=#<IO:0xb7f10574>, @shift_size=nil>> irb(main):003:0> irb(main):004:0* $logger.info{ "Expected log line style" } I, [2009-05-24T06:58:44.599720 #22050] INFO -- : Expected log line style => true irb(main):005:0> irb(main):006:0* require 'active_record' => true irb(main):007:0> $logger.info{ "Why did AR change my log line style?" } Why did AR change my log line style? => true irb(main):008:0>

Furthermore, how does one specify a user defined Logger format style? I need to provide my Log lines in a format consistent with our other applications.

2

Does anyone have any ideas here??? I no longer have useful Logger messages. That's very frustrating.

R

3

Does anyone have any ideas here??? I no longer have useful Logger messages. That's very frustrating.

probably because activerecord requires activesupport and activesupport does

(note that it defaults you to Logger::SimpleFormatter)

Fred

4

Frederick Cheung wrote:

probably because activerecord requires activesupport and activesupport does

http://github.com/rails/rails/blob/669fd84910586d4c791b6f5bf4320f68ac7845aa/activesupport/lib/active_support/core_ext/logger.rb

For what it's worth, I share the original questioners general unhappiness with Rails default logging format.

It's possible to customize that without too much code, although somewhat more confusing and under-documented than one might wish, and also seems to change slightly from one Rails version to the next, for whatever reasons the precise hooks into Rails logging mechanisms seem to be somewhat unstable.

Here's how I customize logging in a Rails 2.1.2 app, choosing to use the Rails2 default "BuferredLogger" for what (I assume) is better efficiency in disk writes, but with my own output formats. Anyone feel free to let me know if there's a better way, or if this is easier in subsequent Rails versions. But it's not too hard (once you figure it out, which took me a bit of playing around).

In my lib directory, a sub-class of the BufferedLogger that actually accepts a formatter, as the standard BufferedLogger (at least in 2.1.1) oddly does not:

http://umlaut.rubyforge.org/svn/trunk/lib/umlaut_logger.rb

Then in environment.rb, set the logger and it's formatter:

    require_dependency 'umlaut_logger'     severity_level = ActiveSupport::BufferedLogger.const_get(config.log_level.to_s.upcase)     log_file = File.join(RAILS_ROOT, "log", "#{RAILS_ENV}.log")

    our_logger = UmlautLogger.new(log_file, severity_level)     our_logger.formatter = lambda do |severity_label, msg|       time_fmtd = Time.now.strftime("%d %b %H:%M:%S")       preface = "[#{time_fmtd}] (pid:#{$$}) #{severity_label}: "       # stick our preface AFTER any initial newlines       msg =~ /^(\n+)[^\n]/       index = $1 ? $1.length : 0       return msg.insert(index, preface)     end     config.logger = our_logger