Customize logger messages in Rails2?


#1

In Rails2, what’s the best way to customize the format of logger output
in Rails?

In Rails1, due to Rails weird monkey-patching of Logger, you couldn’t
just subclass Logger and then set it as the logger to be used. Has this
been improved in Rails2, is there a cleaner way to do this now?

In Rails1, the only good way I found to customize the logger output was
to myself monkey-patch Logger at the end of environment.rb, over-riding
format_message:

class Logger
def format_message(severity, timestamp, progname, msg)
# stuff to output messages just the way I want.
end
end

However, oddly, in Rails2 this seems to have stopped having any effect
at all. The logger output is still uncustomized, Rails default.

Any advice? Thanks in advance to Frederick if he pays attention to this,
because so far he’s the only one who both understands what I’m talking
about and pays attention to me :slight_smile: I already owe you many beverages of
your choice, Frederick.


#2

On 11 Nov 2008, at 18:47, Jonathan R. wrote:

been improved in Rails2, is there a cleaner way to do this now?

In Rails1, the only good way I found to customize the logger output
was
to myself monkey-patch Logger at the end of environment.rb, over-
riding
format_message:

Well if you look at the source to BufferedLogger in rails 2, the add
method (which is what the rest of rails appears to be calling) just
appends the message to the buffer. (or in other words looks like you
should be overriding add on ActiveSupport::BufferedLogger or subclass
that and set config.logger to an instance of your subclass)

Fred


#3

Yeah, thanks. I found this patch, which adds formatter functionality to
BufferedLogger:

http://rails.lighthouseapp.com/projects/8994/tickets/1307-bufferedlogger-should-support-message-formatting

Using that as a guide, I have created a sub-class of BufferedLogger that
does what I want, until/unless that makes it into a future Rails
release.

But now I’m stuck figuring out how to tell Rails to use my new sub-class
(or an instantiation of it) of a BufferedLogger. Nothing I try to do
seems to work. Setting RAILS_DEFAULT_LOGGER myself to my instantiated
logger in environment.rb, no. Setting config.logger to my instantiated
logger in environment.rb, no.

Anyone figured out how to actually tell Rails2 to use a new logger
object?

(Odd that it’s taken so long to get logging right in Rails.)

Jonathan

Frederick C. wrote:

On 11 Nov 2008, at 18:47, Jonathan R. wrote:

been improved in Rails2, is there a cleaner way to do this now?

In Rails1, the only good way I found to customize the logger output
was
to myself monkey-patch Logger at the end of environment.rb, over-
riding
format_message:

Well if you look at the source to BufferedLogger in rails 2, the add
method (which is what the rest of rails appears to be calling) just
appends the message to the buffer. (or in other words looks like you
should be overriding add on ActiveSupport::BufferedLogger or subclass
that and set config.logger to an instance of your subclass)

Fred


#4

Okay, I finally figured out how to get this to work. Leave this here for
future list archive searchers, since I had to put together a bunch of
pieces.

My custom logger, based on this patch:
http://rails.lighthouseapp.com/projects/8994/tickets/1307-bufferedlogger-should-support-message-formatting

is in my lib/umlaut_logger.rb. So now that custom logger can take a
formatter, like standard ruby Logger can.

For some reason, inside the environmental config block, auto-loading
from constants doesn’t seem to work yet, I needed to require_dependency
it automatically. Then, I really wanted to take the existing log and
severity level fields from RAILS_DEFAULT_LOGGER, but
RAILS_DEFAULT_LOGGER isn’t set yet here. But if I wait until it IS set,
then it’s too late for re-setting it to easily have an effect. So I had
to reconstruct what it did from source, and other people’s suggetsions
in the listserv archives.

So, in the config block:

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)
# eg, my real one is more complicated:
our_logger.formatter = lambda {|severity_label, message| 

“#{severity_label}: #{message}”}

config.logger = our_logger

That was kind of a lot of work to get custom formatting. Phew.


#5

On 18 Nov 2008, at 00:18, Jonathan R. wrote:

release.

But now I’m stuck figuring out how to tell Rails to use my new sub-
class
(or an instantiation of it) of a BufferedLogger. Nothing I try to do
seems to work. Setting RAILS_DEFAULT_LOGGER myself to my instantiated
logger in environment.rb, no. Setting config.logger to my instantiated
logger in environment.rb, no.

Anyone figured out how to actually tell Rails2 to use a new logger
object?

I just set

config.logger = SyslogLogger.new ‘rails’
config.logger.level = Logger::INFO

from production.rb and that works fine.

Fred


#6

I needed to blot out hugh binary data in the log so here’s what I use
in 2.1. I have a hard time believing that there’s not a simpler way to
blot out huge binary data but I’ve been unable to find it. I recall
trying to use filter_parameter_logging from the controllers, but it
didn’t work for me at the time (likely my issue, not Rails). Anyhow
this code shows one way to muck with the logger, maybe it’ll help.
It’s in my environment.rb. Bananas not included.

module ActiveSupport
class BufferedLogger
def add(severity, message = nil, progname = nil, &block)
return if @level > severity
message = (message || (block && block.call) || progname).to_s
message.to_str.gsub!(/(\s|()x’([0-9a-fA-F]*)’(,|\s|))/,’\1x
‘BINARY_DATA’\3’)

  level = {
    0 => "D",
    1 => "I",
    2 => "W",
    3 => "E",
    4 => "F"
  }[severity] || "U"

  message = "[%s: %s #%d] %s" % [level,
                                 Time.now.strftime("%m%d %H:%M:

%S"),
$$,
message]

  message = "#{message}\n" unless message[-1] == ?\n
  buffer << message
  auto_flush
  message
end

end
end


#7

Argh, this still isn’t quite there yet. Now I can’t start my app with
script/console, which is convenient sometimes. Because in
script/console, somehow ActiveSupport hasn’t yet been loaded when it
loads the environment.

So I had to add a “require ‘active_support’” to my environment, and now
console is happy. I hope that won’t mess up anything else in the Rails
load order.

I had no idea I’d have to get so much into the guts of Rails just to set
a custom log format.

Jonathan R. wrote:

Okay, I finally figured out how to get this to work. Leave this here for
future list archive searchers, since I had to put together a bunch of
pieces.

My custom logger, based on this patch:
http://rails.lighthouseapp.com/projects/8994/tickets/1307-bufferedlogger-should-support-message-formatting

is in my lib/umlaut_logger.rb. So now that custom logger can take a
formatter, like standard ruby Logger can.

For some reason, inside the environmental config block, auto-loading
from constants doesn’t seem to work yet, I needed to require_dependency
it automatically. Then, I really wanted to take the existing log and
severity level fields from RAILS_DEFAULT_LOGGER, but
RAILS_DEFAULT_LOGGER isn’t set yet here. But if I wait until it IS set,
then it’s too late for re-setting it to easily have an effect. So I had
to reconstruct what it did from source, and other people’s suggetsions
in the listserv archives.

So, in the config block:

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)
# eg, my real one is more complicated:
our_logger.formatter = lambda {|severity_label, message| 

“#{severity_label}: #{message}”}

config.logger = our_logger

That was kind of a lot of work to get custom formatting. Phew.