Adding Logging to Your Application

Problem

You want to make your application log events or diagnostic data to a file or stream. You want verbose logging when your application is in development, and more taciturn logging when in production.

Solution

Use the logger library in the Ruby standard library. Use its Logger class to send logging data to a file or other output stream.

In most cases, youll share a single Logger object throughout your application, as a global variable or module constant:

	require  
logger
	$LOG = Logger.new($stderr)

You can then call the instance methods of Logger to send messages to the log at various levels of severity. From least to most severe, the instance methods are Logger#debug, Logger#info, Logger#warn, Logger#error, and Logger#fatal.

This code uses the applications logger to print a debugging message, and (at a higher severity) as part of error-handling code.

	def divide(numerator, denominator)
	 $LOG.debug("Numerator: #{numerator}, denominator #{denominator}")
	 begin
	 result = numerator / denominator
	 rescue Exception => e
	 $LOG.error "Error in division!: #{e}"
	 result = nil
	 end
	 return result
	end

	divide(10, 2)
	# D, [2006-03-31T19:35:01.043938 #18088] DEBUG -- : Numerator: 10, denominator 2
	# => 5

	divide(10, 0)
	# D, [2006-03-31T19:35:01.045230 #18088] DEBUG -- : Numerator: 10, denominator 0
	# E, [2006-03-31T19:35:01.045495 #18088] ERROR -- : Error in division!: divided by 0
	# => nil

To change the log level, simply assign the appropriate constant to level:

	$LOG.level = Logger::ERROR

Now our logger will ignore all log messages except those with severity ERROR or FATAL:

	divide(10, 2)
	# => 5

	divide(10, 0)
	# E, [2006-03-31T19:35:01.047861 #18088] ERROR -- : Error in division!: divided by 0
	# => nil

Discussion

Rubys standard logging system works like Javas oft-imitated Log4J. The Logger object centralizes all the decisions about whether a particular message is important enough to be written to the log. When you write code, you simply assume that all the messages will be logged. At runtime, you can get a more or a less verbose log by changing the log level. A production application usually has a log level of Logger::INFO or Logger::WARN.

The DEBUG log level is useful for step-by-step diagnostics of a complex task. The ERROR level is often used when handling exceptions: if the program can solve a problem, it logs the exception rather than crash and expects a human administrator to deal with it. The FATAL level should only be used when the program cannot recover from a problem, and is about to crash or exit.

If your log is being stored in a file, you can have Logger rotate or replace the log file when it get too big, or once a certain amount of time has elapsed:

	# Keep data for the current month only
	Logger.new(	his_month.log, monthly)

	# Keep data for today and the past 20 days.
	Logger.new(application.log, 20, daily)

	# Start the log over whenever the log exceeds 100 megabytes in size.
	Logger.new(application.log, 0, 100 * 1024 * 1024)

If the default log entries are too verbose for you, you have a couple of options. The simplest is to set datetime_format to a more concise date format. This code gets rid of the milliseconds:

	$LOG.datetime_format = \%Y-%m-%d %H:%M:%S
	$LOG.error(This is a little shorter.)
	# E, [2006-03-31T19:35:01#17339] ERROR -- : This is a little shorter.

If thats not enough for you, you can replace the call method that formats a message for the log:

	class Logger
	 class Formatter
	 Format = "%s [%s] %s %s
"
	 def call(severity, time, progname, msg)
	 Format % [severity, format_datetime(time), progname, msg]
	 end
	 end
	end

	$LOG.error(This is much shorter.)
	# ERROR [2006-03-31T19:35:01.058646 ] This is much shorter.

See Also

• The standard library documentation for the logger library