This howto shows how to modify some of the defaults in rails’ logging configuration. For background about what the logger is and how to use it, see logger.
Basics
You can control some aspects of the logger through the config object in config/environment.rb for a change in all environments
Log Level
The available log levels are: :debug, :info, :warn, :error, :fatal. The ruby Logger class normally also accepts :any, but that doesn’t seem to work with rails.
config.log_level = :debug
Log Path
The log file path is relative to the RAILS_ROOT directory. Make sure that the file exists and has permissions that allow writing for the user that rails will run under.
config.log_path = 'log/debug.log'
Per-environment logging configs
If you want log warnings when your application is running in production mode add the following line to the end of your #{RAILS_ROOT}/config/production.rb file:
config.log_level = :warn
However, if you use Ruby standard logger (for example config.logger = Logger.new(File.dirname(__FILE__) + "/../log/#{RAILS_ENV}.log") in config/environment.rb), not Rails’ default one, use this instead:
config.logger.level = Logger::WARN
Using different loggers for different parts of rails
Since Rails 2.0, something similar is done in "Rails::Initializer#initializelogger":http://github.com/github/rails/tree/c8da518bbfedc2a06b1d96912ddae00e57f21748/railties/lib/initializer.rb#L238-266 and initialize_framework_logging instead of in environment.rb as stated below._
environment.rb defines the loggers used by the components of rails. First it defines the default logger for the application :
begin
RAILS_DEFAULT_LOGGER = Logger.new(“#{RAILS_ROOT}/log/#{RAILS_ENV}.log”)
rescue StandardError
RAILS_DEFAULT_LOGGER = Logger.new(STDERR)
RAILS_DEFAULT_LOGGER.level = Logger::WARN
RAILS_DEFAULT_LOGGER.warn(
“Rails Error: Unable to access log file. Please ensure that log/#{RAILS_ENV}.log exists and is chmod 0666. " +
"The log level has been raised to WARN and the output directed to STDERR until the problem is fixed.”
)
end
Then it assigns this logger to its friends :
[ActiveRecord, ActionController, ActionMailer].each { |mod| mod::Base.logger ||= RAILS_DEFAULT_LOGGER }
Say you want Active record to log in database.log instead of the default #{RAILS_ENV}.log file. You can add the following to the end of your #{RAILS_ROOT}/config/#{RAILS_ENV}.rb file (for example to developement.rb):
ActiveRecord::Base.logger = Logger.new("#{RAILS_ROOT}/log/#{RAILS_ENV}_database.log")
Beware when using “script/server mongrel”
The file /railties/lib/commands/servers/mongrel.rb (such as used in RadRails when running Mongrel) includes the following two lines:
require 'initializer' Rails::Initializer.run(:initialize_logger)
This breaks the option to set another logger using config.logger
You can still force RAILS_DEFAULT_LOGGER to whatever logger you want, though that will get you “warning: already initialized constant RAILS_DEFAULT_LOGGER”.
See ticket 8665
Getting monochrome log messages
Removing the colour escape sequences that are used by default is quite simple. Simply set colorize_logging to false:
ActiveRecord::Base.colorize_logging = false
Note that the colorize_logging method doesn’t appear in ActionController (why?[because the only module in rails that adds color to the logs is ActiveRecord -jean]).
Changing the log format
As said in the logger.rb source file:
> There is currently no supported way to change the overall format,
> but you may have some luck hacking the Format constant.
This, when added to the end of environment.rb, puts the timestamp and PID in the log.
class Logger
def format_message(severity, timestamp, progname, msg)
"#{timestamp} (#{$$}) #{msg}\n"
end
end
Why doesn’t Logger behave the way the Ruby library docs say it should under rails?
(Note that the Rails 2.0 default logger has been changed from Ruby’s own logger with the clean_logger extensions described below to ActiveSupport::BufferedLogger. From the CHANGELOG: “You can change it back with config.logger = Logger.new(”/path/to/log", level)". Rails::Initializer.initialize_logger() documentation also indicates you can set RAILS_DEFAULT_LOGGER.)
Look at the source to what Rails 1.2 does to mung the standard Logger object to do what it wants. Can you see anything wrong with this picture? If Rails wants a Logger object that behaves this way, it should subclass Logger, or inject its own Logger::Formatter into the picture rather than this mess.
What this accomplishes is utterly evil. If you’re adding things to a rails app that expect Logger to behave as documented, you’ll configure your logging date formats all day long and never have any impact. Worse, the code is flagged :nodoc:, so after screwing around with expected behavior, we’re left with no indication as to why a Logger instance created from the Rails console will behave different than a Logger created from IRB.
Mixins are a great feature of Ruby, but a mixin that irrevocably alters a core library class just to avoid the minor pain of creating a proper subclass where it it obviously necessary is just plain wrong, no matter how $!#^$% pragmatic you’re claiming to be.
This code added to environment.rb will restore the default logger behavior under 1.8.4, Rails 1.2:
class Logger
def format_message(severity, timestamp, progname, msg)
if <a href="mailto:!@formatter.nil">!@formatter.nil</a>?
@formatter.call(severity, timestamp, progname, msg)
else
@default_formatter.call(severity, timestamp, progname, msg)
end
end
end
class RailsFormatter < Logger::Formatter
def call(severity, timestamp, progname, msg)
"#{msg}\n"
end
end
RAILS_DEFAULT_LOGGER.formatter = RailsFormatter.new
Need Advanced Logging? Like rolling files, email, …?
In the old days, when you needed something similar to log4j , then you would be told to take a look at the log4r project It allows more advanced logging than the standard logger. However, log4r doesn’t work with the current version of Rails because of incompatibilities between the benchmarking module and log4r. See ticket 3512 for more information.
“Logging” to replace log4r
On 5/31/08, log4r has been idle since March 2004. It looks like no-one has been able to contact the original developer for some time, and a replacement project, http://logging.rubyforge.org has been created that solves the above mentioned problem.
For example, in config/environment.rb:
require 'logging'
# Bootstrap the Rails environment, frameworks, and default configuration
require File.join(File.dirname(__FILE__), 'boot')
# Logging.init is required to avoid
# unknown level was given 'info' (ArgumentError)
# or
# uninitialized constant Logging::MAX_LEVEL_LENGTH (NameError)
# when an Appender or Layout is created BEFORE any Logger is instantiated:
Logging.init :debug, :info, :warn, :error, :fatal
layout = Logging::Layouts::Pattern.new :pattern => "[%d] [%-5l] %m\n"
# Default logfile, history kept for 10 days
default_appender = Logging::Appenders::RollingFile.new 'default', \
:filename => ...., :age => 'daily', :keep => 10, :safe => true, :layout => layout
# Audit logfile, history kept forever
audit_appender = Logging::Appenders::RollingFile.new 'audit', \
:filename => ...., :age => 'daily', :safe => true, :layout => layout
DEFAULT_LOGGER = returning Logging::Logger['server'] do |l|
l.add_appenders default_appender
end
# A logger logging to two files, the audit trail being kept forever
AUDIT_LOGGER = returning Logging::Logger['audit'] do |l|
l.add_appenders [audit_appender, default_appender]
end
Rails::Initializer.run do |config|
:
# When using "script/server mongrel", use
# RAILS_DEFAULT_LOGGER = DEFAULT_LOGGER
# instead
config.logger = DEFAULT_LOGGER
:
end
and in the per-environment config, like environments/development.rb:
DEFAULT_LOGGER.level = :debug
AUDIT_LOGGER.level = :debug
Logging::Appender::Email (in June 2008) does not automatically flush after some inactivity. So, to get important alerts right away, be sure to either set :immediate_at => 'error,fatal' or use :buffsize => 1. Also note that the values for :from and :to should be a plain email addresses, not something like Me myself <me at example.org>.
email_layout = Logging::Layouts::Pattern.new :pattern => '[%d] [%-5l] [%c] %m\n'
email_appender = Logging::Appenders::Email.new 'email',
:from => 'webmaster at example.org',
:to => 'webmaster at example.org',
:server => 'smtp.example.org',
:domain => 'example.org',
:level => :warn,
:buffsize => 1, # so we don't need to flush
# or:
# :immediate_at => 'warn,error',
:subject => "Alert from rails.example.org (#{RAILS_ENV})",
:layout => email_layout
DEFAULT_LOGGER = returning Logging::Logger['server'] do |l|
l.add_appenders [default_appender, email_appender]
end
and, for example, at the end of environment.rb:
if $0 !~ /rake/
DEFAULT_LOGGER.warn "My Application started"
at_exit do
DEFAULT_LOGGER.warn "My Application stopped"
end
end
Rotating log files
When all you need is log rotation, then instead of using “Logging” you can also have the operating system execute the file rollovers. See DeploymentTips.
Logging Permission Errors
I ran into problems with logging on Apache 2 with Fcgi resulting in a “could not access {RAILS_ENV}/log/development.log” message in the Apache Error log and suggesting I made sure the log file existed and was chmodded 0666. Changine permissions on the files had no effect but setting a 777 permission on the /log directory fixed it.
Question:
Thank you for these useful informations. However I’d like to know if it’s possible to display the logs in the console rather than using the “debug.log” file .
Answer #1:
You can tail the log in the console. For example:
cd /railsapp/log
tail -f development.log
Adding Color to your own logs
The ActiveRecord #format_log_entry method looks like this:
def format_log_entry(message, dump = nil)
if ActiveRecord::Base.colorize_logging
if@row_even @row_even = false
message_color, dump_color = “4;36;1”, “0;1”
else
@@row_even = true
message_color, dump_color = “4;35;1”, “0”
end log_entry = " \e[#{message_color}m#{message}\e[0m " log_entry << “\e[#{dump_color}m%#{String === dump ? ‘s’ : ’p’}\e[0m” % dump if dump log_entry else “%s %s” % [message, dump] end end
it’s actually found in activerecord/connection_adapters/abstract_adapter.rb_
Question: I am running Rails 1.2.3 with Mongrel and Ruby 1.8.6 on Windows. No matter what I set the value of log_level in environment.rb or environments/development.rb, my logfile always contains the same output. How do I begin to track down why its doing so?
Answer: config.log_level = :info will not work if you are setting config.logger. In that case, you will want to set config.logger.log_level = (Logger::INFO or whatever). I have also seen cases where ./script/server will setup one logger and RAILS_DEFAULT_LOGGER will not get reset. You can assert this by keeping a global reference to the logger you setup in environment.rb, and later on doing a `throw “Lame” unless $my_logger == RAILS_DEFAULT_LOGGER`
Pretty logs for rails 1.2.x and 2.0
I use for creating pretty logs on rails
next patches
config/environment.rb
require ‘logger_core_ext’
file app/lib/logger_core_ext.rb
class Logger
# Used for rails 1.2.x
alias format_message old_format_message
class Formatter
def call(severity, time, progname, msg)
“s|#5d|%s] %s: %s\n” % [severity[0..3], $$, time.to_s(:db), progname, msg2str(msg)]
end
end
endmodule ActiveSupport
# Used for rails 2.0
class BufferedLogger
module Severity
def level_to_s(level)
case level
when 0
‘DEBUG’
when 1
‘INFO’
when 2
‘WARN’
when 3
‘ERROR’
when 4
‘FATAL’
when 5
‘UNKNOWN’
end
end
end
def add(severity, message = nil, progname = nil, &block)
return if @level > severity
# message = (message || (block && block.call) || progname).to_s
message = (message || (block && block.call) || progname).to_s
# If a newline is necessary then create a new message ending with a newline.
# Ensures that the original message is not mutated.
message = “#{message}\n” unless message[-1] == ?\n
message = “s|#5d|%s] %s: %s” % [level_to_s(severity)[0..3], $$, Time.now.to_s(:db), progname, message]
@buffer << message
auto_flush
message
end
end
end
This howto shows how to modify some of the defaults in rails’ logging configuration. For background about what the logger is and how to use it, see logger.
Basics
You can control some aspects of the logger through the config object in config/environment.rb for a change in all environments
Log Level
The available log levels are: :debug, :info, :warn, :error, :fatal. The ruby Logger class normally also accepts :any, but that doesn’t seem to work with rails.
config.log_level = :debug
Log Path
The log file path is relative to the RAILS_ROOT directory. Make sure that the file exists and has permissions that allow writing for the user that rails will run under.
config.log_path = 'log/debug.log'
Per-environment logging configs
If you want log warnings when your application is running in production mode add the following line to the end of your #{RAILS_ROOT}/config/production.rb file:
config.log_level = :warn
However, if you use Ruby standard logger (for example config.logger = Logger.new(File.dirname(__FILE__) + "/../log/#{RAILS_ENV}.log") in config/environment.rb), not Rails’ default one, use this instead:
config.logger.level = Logger::WARN
Using different loggers for different parts of rails
Since Rails 2.0, something similar is done in "Rails::Initializer#initializelogger":http://github.com/github/rails/tree/c8da518bbfedc2a06b1d96912ddae00e57f21748/railties/lib/initializer.rb#L238-266 and initialize_framework_logging instead of in environment.rb as stated below._
environment.rb defines the loggers used by the components of rails. First it defines the default logger for the application :
begin
RAILS_DEFAULT_LOGGER = Logger.new(“#{RAILS_ROOT}/log/#{RAILS_ENV}.log”)
rescue StandardError
RAILS_DEFAULT_LOGGER = Logger.new(STDERR)
RAILS_DEFAULT_LOGGER.level = Logger::WARN
RAILS_DEFAULT_LOGGER.warn(
“Rails Error: Unable to access log file. Please ensure that log/#{RAILS_ENV}.log exists and is chmod 0666. " +
"The log level has been raised to WARN and the output directed to STDERR until the problem is fixed.”
)
end
Then it assigns this logger to its friends :
[ActiveRecord, ActionController, ActionMailer].each { |mod| mod::Base.logger ||= RAILS_DEFAULT_LOGGER }
Say you want Active record to log in database.log instead of the default #{RAILS_ENV}.log file. You can add the following to the end of your #{RAILS_ROOT}/config/#{RAILS_ENV}.rb file (for example to developement.rb):
ActiveRecord::Base.logger = Logger.new("#{RAILS_ROOT}/log/#{RAILS_ENV}_database.log")
Beware when using “script/server mongrel”
The file /railties/lib/commands/servers/mongrel.rb (such as used in RadRails when running Mongrel) includes the following two lines:
require 'initializer' Rails::Initializer.run(:initialize_logger)
This breaks the option to set another logger using config.logger
You can still force RAILS_DEFAULT_LOGGER to whatever logger you want, though that will get you “warning: already initialized constant RAILS_DEFAULT_LOGGER”.
See ticket 8665
Getting monochrome log messages
Removing the colour escape sequences that are used by default is quite simple. Simply set colorize_logging to false:
ActiveRecord::Base.colorize_logging = false
Note that the colorize_logging method doesn’t appear in ActionController (why?[because the only module in rails that adds color to the logs is ActiveRecord -jean]).
Changing the log format
As said in the logger.rb source file:
> There is currently no supported way to change the overall format,
> but you may have some luck hacking the Format constant.
This, when added to the end of environment.rb, puts the timestamp and PID in the log.
class Logger
def format_message(severity, timestamp, progname, msg)
"#{timestamp} (#{$$}) #{msg}\n"
end
end
Why doesn’t Logger behave the way the Ruby library docs say it should under rails?
(Note that the Rails 2.0 default logger has been changed from Ruby’s own logger with the clean_logger extensions described below to ActiveSupport::BufferedLogger. From the CHANGELOG: “You can change it back with config.logger = Logger.new(”/path/to/log", level)". Rails::Initializer.initialize_logger() documentation also indicates you can set RAILS_DEFAULT_LOGGER.)
Look at the source to what Rails 1.2 does to mung the standard Logger object to do what it wants. Can you see anything wrong with this picture? If Rails wants a Logger object that behaves this way, it should subclass Logger, or inject its own Logger::Formatter into the picture rather than this mess.
What this accomplishes is utterly evil. If you’re adding things to a rails app that expect Logger to behave as documented, you’ll configure your logging date formats all day long and never have any impact. Worse, the code is flagged :nodoc:, so after screwing around with expected behavior, we’re left with no indication as to why a Logger instance created from the Rails console will behave different than a Logger created from IRB.
Mixins are a great feature of Ruby, but a mixin that irrevocably alters a core library class just to avoid the minor pain of creating a proper subclass where it it obviously necessary is just plain wrong, no matter how $!#^$% pragmatic you’re claiming to be.
This code added to environment.rb will restore the default logger behavior under 1.8.4, Rails 1.2:
class Logger
def format_message(severity, timestamp, progname, msg)
if <a href="mailto:!@formatter.nil">!@formatter.nil</a>?
@formatter.call(severity, timestamp, progname, msg)
else
@default_formatter.call(severity, timestamp, progname, msg)
end
end
end
class RailsFormatter < Logger::Formatter
def call(severity, timestamp, progname, msg)
"#{msg}\n"
end
end
RAILS_DEFAULT_LOGGER.formatter = RailsFormatter.new
Need Advanced Logging? Like rolling files, email, …?
In the old days, when you needed something similar to log4j , then you would be told to take a look at the log4r project It allows more advanced logging than the standard logger. However, log4r doesn’t work with the current version of Rails because of incompatibilities between the benchmarking module and log4r. See ticket 3512 for more information.
“Logging” to replace log4r
On 5/31/08, log4r has been idle since March 2004. It looks like no-one has been able to contact the original developer for some time, and a replacement project, http://logging.rubyforge.org has been created that solves the above mentioned problem.
For example, in config/environment.rb:
require 'logging'
# Bootstrap the Rails environment, frameworks, and default configuration
require File.join(File.dirname(__FILE__), 'boot')
# Logging.init is required to avoid
# unknown level was given 'info' (ArgumentError)
# or
# uninitialized constant Logging::MAX_LEVEL_LENGTH (NameError)
# when an Appender or Layout is created BEFORE any Logger is instantiated:
Logging.init :debug, :info, :warn, :error, :fatal
layout = Logging::Layouts::Pattern.new :pattern => "[%d] [%-5l] %m\n"
# Default logfile, history kept for 10 days
default_appender = Logging::Appenders::RollingFile.new 'default', \
:filename => ...., :age => 'daily', :keep => 10, :safe => true, :layout => layout
# Audit logfile, history kept forever
audit_appender = Logging::Appenders::RollingFile.new 'audit', \
:filename => ...., :age => 'daily', :safe => true, :layout => layout
DEFAULT_LOGGER = returning Logging::Logger['server'] do |l|
l.add_appenders default_appender
end
# A logger logging to two files, the audit trail being kept forever
AUDIT_LOGGER = returning Logging::Logger['audit'] do |l|
l.add_appenders [audit_appender, default_appender]
end
Rails::Initializer.run do |config|
:
# When using "script/server mongrel", use
# RAILS_DEFAULT_LOGGER = DEFAULT_LOGGER
# instead
config.logger = DEFAULT_LOGGER
:
end
and in the per-environment config, like environments/development.rb:
DEFAULT_LOGGER.level = :debug
AUDIT_LOGGER.level = :debug
Logging::Appender::Email (in June 2008) does not automatically flush after some inactivity. So, to get important alerts right away, be sure to either set :immediate_at => 'error,fatal' or use :buffsize => 1. Also note that the values for :from and :to should be a plain email addresses, not something like Me myself <me at example.org>.
email_layout = Logging::Layouts::Pattern.new :pattern => '[%d] [%-5l] [%c] %m\n'
email_appender = Logging::Appenders::Email.new 'email',
:from => 'webmaster at example.org',
:to => 'webmaster at example.org',
:server => 'smtp.example.org',
:domain => 'example.org',
:level => :warn,
:buffsize => 1, # so we don't need to flush
# or:
# :immediate_at => 'warn,error',
:subject => "Alert from rails.example.org (#{RAILS_ENV})",
:layout => email_layout
DEFAULT_LOGGER = returning Logging::Logger['server'] do |l|
l.add_appenders [default_appender, email_appender]
end
and, for example, at the end of environment.rb:
if $0 !~ /rake/
DEFAULT_LOGGER.warn "My Application started"
at_exit do
DEFAULT_LOGGER.warn "My Application stopped"
end
end
Rotating log files
When all you need is log rotation, then instead of using “Logging” you can also have the operating system execute the file rollovers. See DeploymentTips.
Logging Permission Errors
I ran into problems with logging on Apache 2 with Fcgi resulting in a “could not access {RAILS_ENV}/log/development.log” message in the Apache Error log and suggesting I made sure the log file existed and was chmodded 0666. Changine permissions on the files had no effect but setting a 777 permission on the /log directory fixed it.
Question:
Thank you for these useful informations. However I’d like to know if it’s possible to display the logs in the console rather than using the “debug.log” file .
Answer #1:
You can tail the log in the console. For example:
cd /railsapp/log
tail -f development.log
Adding Color to your own logs
The ActiveRecord #format_log_entry method looks like this:
def format_log_entry(message, dump = nil)
if ActiveRecord::Base.colorize_logging
if@row_even @row_even = false
message_color, dump_color = “4;36;1”, “0;1”
else
@@row_even = true
message_color, dump_color = “4;35;1”, “0”
end log_entry = " \e[#{message_color}m#{message}\e[0m " log_entry << “\e[#{dump_color}m%#{String === dump ? ‘s’ : ’p’}\e[0m” % dump if dump log_entry else “%s %s” % [message, dump] end end
it’s actually found in activerecord/connection_adapters/abstract_adapter.rb_
Question: I am running Rails 1.2.3 with Mongrel and Ruby 1.8.6 on Windows. No matter what I set the value of log_level in environment.rb or environments/development.rb, my logfile always contains the same output. How do I begin to track down why its doing so?
Answer: config.log_level = :info will not work if you are setting config.logger. In that case, you will want to set config.logger.log_level = (Logger::INFO or whatever). I have also seen cases where ./script/server will setup one logger and RAILS_DEFAULT_LOGGER will not get reset. You can assert this by keeping a global reference to the logger you setup in environment.rb, and later on doing a `throw “Lame” unless $my_logger == RAILS_DEFAULT_LOGGER`
Pretty logs for rails 1.2.x and 2.0
I use for creating pretty logs on rails
next patches
config/environment.rb
require ‘logger_core_ext’
file app/lib/logger_core_ext.rb
class Logger
# Used for rails 1.2.x
alias format_message old_format_message
class Formatter
def call(severity, time, progname, msg)
“s|#5d|%s] %s: %s\n” % [severity[0..3], $$, time.to_s(:db), progname, msg2str(msg)]
end
end
endmodule ActiveSupport
# Used for rails 2.0
class BufferedLogger
module Severity
def level_to_s(level)
case level
when 0
‘DEBUG’
when 1
‘INFO’
when 2
‘WARN’
when 3
‘ERROR’
when 4
‘FATAL’
when 5
‘UNKNOWN’
end
end
end
def add(severity, message = nil, progname = nil, &block)
return if @level > severity
# message = (message || (block && block.call) || progname).to_s
message = (message || (block && block.call) || progname).to_s
# If a newline is necessary then create a new message ending with a newline.
# Ensures that the original message is not mutated.
message = “#{message}\n” unless message[-1] == ?\n
message = “s|#5d|%s] %s: %s” % [level_to_s(severity)[0..3], $$, Time.now.to_s(:db), progname, message]
@buffer << message
auto_flush
message
end
end
end