All Rubyists Love Logging

David Lyons
David Lyons
Share
3d illustration of a wood log

If you’re an old hand at Rails, you likely take logging for granted. However, if you’re one of the unicorns that write apps in Ruby and don’t use Rails, you’ve probably done little-to-no logging. Apps that don’t use a database on the backend or local command line style apps with no datastore may actually have no logging at all. Is this a problem? Should you be worried? What even is logging?

What is Logging?

Logging generally refers to an application writing various kinds of activity to a file (or database, or the console) as it happens in the application. So, right away, we have a rather fuzzy definition.

  • What exactly should you be logging? Errors? Transactions? Status?
  • What will your logs be used for? Audit trail? Error tracking? Debugging?
  • Who will be looking at these logs? Developers? Managers? Support?

If I haven’t made it clear by now, logging is a very business process heavy construct. While I can’t tell you what to log, I can show you an easy way to add logging to your application, whether it’s a script, command line app, Sinatra web app, or whatever!

Class: Logger

As Ruby developers, we’re lucky to have the Ruby Standard Library, which once again has us covered. The Logger class has everything we need for most of our logging needs. You can have one logger object for each type of log, or one for each class, or any other combination you can imagine. For a beginner, and for most simple-to-moderate needs, I’ve found that one log to rule them all works well.

One Log to Rule Them All

How do you add this to your app?

require 'logger'

class MyLog
  def self.log
    if @logger.nil?
      @logger = Logger.new STDOUT
      @logger.level = Logger::DEBUG
      @logger.datetime_format = '%Y-%m-%d %H:%M:%S '
    end
    @logger
  end
end

That’s it. Your entire application can now write to the log with a line like this:

MyLog.log.info "Look, ma! I'm loggin'!"

Since it’s writing to STDOUT, you’d see this in your terminal:

I, [2014-08-13 15:18:50-0600 #65630]  INFO -- : Look, ma! I'm loggin'!

How It Works

Let’s break down what our code is actually doing. First, there’s something we’re not doing.

We’re not instantiating a logger object directly into our application and passing that object around, all OOP style. Instead, we create a small class called MyLog with a single class method called log. This single method checks to see if a logger object exists, creates it if it doesn’t, and returns it. Ruby developers generally don’t write a lot of class methods, but this is a clever way to create a globally accessible object.

You could just, you know, create a global variable:

$log = Logger.new STDOUT
$log.level = Logger::DEBUG
$log.datetime_format = '%Y-%m-%d %H:%M:%S%z '

But, since globals are mutable, it’s less stable than a class with class method.

In the faux-initialize block, we instantiate the Logger object, set where the output goes, set the log level, and set the datetime format.

if @logger.nil?
  @logger = Logger.new STDOUT
  @logger.level = Logger::DEBUG
  @logger.datetime_format = '%Y-%m-%d %H:%M:%S%z '
end

The log entries are set to go to STDOUT, but you can just as easily direct them into a file with something like:

@logger = Logger.new 'path/to/log/files/log.txt'

The level of the log is a little tricky to understand at first, but it basically controls what information is written to the log. When telling the logger to write, the “level” of the message can be specified. This is useful because you can set the level to Logger::WARN for production, meaning WARN, FATAL, ERROR, and UNKNOWN are written. That way, the debug lines in your code won’t clutter up the production logs. When you’re writing new features or fixing bugs in development, turn the level up to Logger::Debug and all the debug and info logs start showing up too. The available levels are (in “most serious” to “least serious” order):

  • UNKNOWN – I can’t even. Always written to log.
  • FATAL – Fatal errors and other serious unhappiness.
  • ERROR – An error occurred. Someone should fix this.
  • WARN – A possible error occurred. Someone maybe should fix this.
  • INFO – In case you were wondering…
  • DEBUG – The more sophisticated version of puts style debugging.

There is a corresponding method for each of the levels. For example, @logger.fatal("App is dying!!") will write the message at the FATAL level. The Logger class also has query methods for each level (i.e. fatal?), allowing you to ask the @logger if it currently supports that level of logging.

It’ll be up to you to decide what level each log entry should be, but it’s pretty obvious once you start adding logs to your app the difference between a fatal error, general info, and debug data.

The datetime that will be shown in the log is being set to the ISO 8601 standard and I don’t see any reason to do it any other way. These datetimes are universally readable, searchable, and parseable. Change it if you must, but do so with caution and for a good reason.

Go Forth and Log

Since I’ve started playing with the Logger I’ve been using DEBUG and INFO the most.

DEBUG is great for checking the contents of a variable, seeing if a certain method is ever called, watching the progress of a loop, or anything else you want to keep an eye on in your application. Unlike puts style debugging, you can just leave these log calls in place, turn down the level on your logger, and no longer see this data in your logs or in the console. Want to check if an array is the size you expect? Drop in a call to your logger and see this in your log:

D [2014-08-13 15:23:42-0600 #65631]  DEBUG -- : Array length: 42

42 items in my Life, The Universe, and Everything array…that seems right!

INFO is nice for simple transaction logging. Databases usually give you this kind of thing for free, but scripts, command line apps, or web apps with no datastore can benefit from keeping a general audit trail. For example, you might log the completion of a certain task:

I, [2014-08-13 15:25:21-0600 #65632]  INFO -- : David published an article.

Later, if you want to know when David published an article, BAM! it’s in your logs.

MyLog.log.info “Wrapping up”

Do you use the Ruby Logger? Maybe you have a favorite gem to handle all your logging needs? If you’ve been around the logging block a few times, what practices and designs have worked for you? Log your info in the comments!

Frequently Asked Questions (FAQs) about Ruby Logging

What is Ruby Logging and why is it important?

Ruby Logging is a powerful tool that developers use to track the activities and performance of their applications. It provides a systematic way to collect and store information about the application’s operation, which can be used for debugging, performance tuning, and auditing purposes. Logging is crucial because it helps developers identify and fix issues quickly, understand how the application is being used, and make informed decisions about future development.

How do I get started with Ruby Logging?

To get started with Ruby Logging, you need to require the ‘logger’ library in your Ruby script. Once you’ve done that, you can create a new logger instance and start logging messages. The logger provides different severity levels (DEBUG, INFO, WARN, ERROR, FATAL, and UNKNOWN) that you can use to categorize your log messages.

How can I customize the format of my log messages in Ruby?

Ruby Logger allows you to customize the format of your log messages by setting the ‘formatter’ attribute of your logger instance. You can define a proc that takes the severity, time, program name, and message as arguments and returns the formatted message as a string.

How can I manage the size of my log files in Ruby?

Ruby Logger provides a built-in mechanism for rotating log files when they reach a certain size. You can specify the maximum size of a log file and the number of old log files to keep when you create your logger instance.

Can I log messages to multiple destinations in Ruby?

Yes, you can log messages to multiple destinations by creating multiple logger instances. Each logger instance can be configured to log messages to a different destination, such as a file, the console, or a network socket.

How can I filter log messages based on their severity level in Ruby?

You can filter log messages based on their severity level by setting the ‘level’ attribute of your logger instance. Only messages with a severity level equal to or higher than the specified level will be logged.

How can I add context information to my log messages in Ruby?

You can add context information to your log messages by using the ‘progname’ attribute of your logger instance. The ‘progname’ will be included in every log message, providing additional context about where the message came from.

Can I use Ruby Logging in a multi-threaded environment?

Yes, Ruby Logger is thread-safe, which means you can use it in a multi-threaded environment without worrying about race conditions. Each logger instance has its own internal lock that ensures only one thread can write to the log at a time.

How can I handle exceptions in my log messages in Ruby?

Ruby Logger provides a convenient way to log exceptions. You can pass an exception object to the ‘error’ or ‘fatal’ methods, and the logger will automatically include the exception’s message and backtrace in the log message.

Can I use Ruby Logging with other logging libraries or frameworks?

Yes, Ruby Logger is designed to be a standalone library, but it can also be used with other logging libraries or frameworks. Many popular Ruby frameworks, such as Rails and Sinatra, provide their own logging facilities that are built on top of Ruby Logger.