Rails Logger
Best Practices

Using puts doesn’t count

When faced with a time crunch, it’s easy to defer logging and testing to the backburner. If you’re lucky, you’ll make it to the backburner…eventually. If you’re not, you’ll ship your app without any logging.

Woe betide you though if you don’t include logging, because you’re going to have a very difficult time trying to figure out what went wrong when something does go wrong. So, with that said, this post will show you how to implement logging for your Ruby on Rails app and how to do it well.

Onward!

First things first…what is Rails?

In 1995, Yukihiro “Matz” Matsumoto released a programming language called Ruby. Designed to make developers happy, Ruby syntax was clean, intuitive, and easy-to-use. However, Ruby was not designed for use on the web.

rails logo

Enter Rails.

David Heinemeier Hansson extracted what would come to be known as Rails from the work he’d done for the project management software Basecamp. To make a long story short, Rails makes it possible for developers to use Ruby to build web apps. As far as Ruby frameworks go, Rails is the most popular.

Why log?

The obvious answer is that logging tells you what went wrong in the event that something does go wrong. However, we can dig deeper and tell stories about the following areas of our apps using logs:

  • Development and Quality: Typically, these are the first reasons that come to mind when you mention logging. In addition to providing useful information during the development process, logging makes it easier to ensure that you release a quality product. By formally implementing a logging solution (instead of having your developers sprinkle puts statements all over your code), you are setting the stage for creating a better, cleaner product.
  • Performance and Metrics: Once you’ve finished building your product, you’ll want to know how it behaves in the real world. The only way to do that is to measure its performance with real users. How does your app handle heavy use? How long does it take for your server to respond to a request? Does your server even respond at all?
  • Security and Compliance: If you’re in a highly regulated industry, you’ll need to know if you’re meeting security requirements and complying with any laws that may be applicable. For example, you might be an eCommerce site that handles credit card transactions or a medical firm that’s required to following HIPAA regulations. You’ll want to know if there are any issues, such as data breaches, before they affect your users.
  • User Behavior: Without a user base, there is no point to having a website. Given this, how well do you cater to the needs and wants of your users? By logging user actions and analyzing them, you’ll be able to make better decisions and provide a better experience for those using your app.

Okay, so how do I do this logging thing?

Ruby, whose stated goal is to make developers happy, has built-in logging. It is also used by default in Rails. Cool! So how do you use it? Well, you can include the following in environment.rb (or, really, any environment file):

Rails.logger = Logger.new(STDOUT)

Or, you can include this in the initializer section:

config.logger = Logger.new(STDOUT)

That’s it!

Okay, well, that’s not completely true. This isn’t the best way to implement logging, but it’s still better than nothing. Remember, the default is to log everything, so you’re probably going to want to tinker with the Logger defaults, if not replace it altogether (unless you enjoy wading through lots of noise to get to the signal).

If I use Rails, what other logging options are available to me?

configuration

Using the default logging library, Logger, will get you far, but you can improve the logs you get. There are tons of packages (called Gems in the Ruby world) available to you, but here are some of the most popular options:

  • Log4r: An easy-to-configure logging library, Log4r’s philosophy is based on the act of using simple puts statements. However, the library adds the following features (among many others) aimed at allowing you to control the information logged:
    • Hierarchical logging system (with the ability to assign each level a custom name)
    • Logger inheritance
    • Ability to output to multiple destinations
    • Execution tracing
    • Custom Formatting

  • Logging: Very similar to Log4r, but based on the design used for Java’s log4j library.
  • Lograge: Rails, by default, logs pretty much everything. Lograge aims to increase the usefulness and readability of Rails messages by reducing them to single lines.

How do I build a better log?

As we previously stated, Rails logs everything by default. This can render your logs useless, which is not what we want. Using Logger, we’ll walk through how to improve what you get from your apps.

Set your logging levels appropriately

The Logger class outputs messages that meet the log level that you set, and in Logger, there are six levels:

Unknown > Fatal > Error > Warn > Info > Debug

Like other logging tools, Logger outputs anything at or more severe than the level you’ve set. For example, if you’ve set Logger to Error, you’ll get messages tagged as Error, Fatal, and Unknown.

You can set the log level setting logger.level = Logger::LOG_LEVEL

As usual, you’ll want to log more in Development and Test and less in Production.

Make Logger work for you

Ideally, your logs should be so good that someone can understand the issue using no other information. We might not get to that level, but we’re going to try!

Avoid puts; use Logger

When outputting messages to debug your code, use

logger.{unknown|fatal|error|warn|info|debug} instead of puts. While this requires a bit more typing, you get output that:

  • Fits into the standard log format
  • Comes with timestamps
  • Is logged with levels so that you can determine which messages appear in a given environment

Format your Logger messages

Take some time to format the messages that Logger outputs. For example, you could sanitize the output and provide a value for progname, which is helpful when you have various systems you’re monitoring.

logger = Logger.new logfile.log
Logger.level = Logger::WARN

# logs for program called MainProgram
logger.progname = 'MainProgram'

# a simple formatter
logger.formatter = proc do |severity, time, progname, msg|
	"#{datetime}: #{msg} from #{progname} \n"
end

logger.info("Some error.")

This takes changes the format of the message from the default

I, [1999-03-03T02:34:24.895701 #19074]  INFO -- Main: Some error.

to

1999-03-03 02:34:24 +0900: Some error from MainProgram

See? Not much work, and much cleaner messages. Alternatively, you can define the above in a class:

class CustomFormater < Logger::Formater
  def call(severity, time, progname, msg)
    "#{datetime}: #{msg} from #{progname} \n"
  end
end

Yes, this is a lot of typing, but you only have to do it once.

Remember, you can also use the lograge gem to consolidate multi-line requests into a single line.

Make your logs machine-friendly

Now that you’ve made your logs human-readable, let’s make them machine-friendly. This is especially useful if you’re gathering a lot of data for data analyses.

One way to do this is to log in JSON. By extending the above class example, we can create a custom formatter that outputs our logs in JSON format:

logger = Logger.new logfile.log
Logger.level = Logger::WARN

# logs for program called MainProgram
logger.progname = 'MainProgram'

# a simple formatter
logger.formatter = proc do |severity, time, progname, msg|
	%Q|{time: "#{datetime}\n", message: "#{msg} from #{progname}"}\n|
end

logger.info("Some error.")

This yields

{
"time": "1999-03-03 02:34:24 +0900",
"message": "Some error from MainProgram"
}

If you’d like to class-ify this, you can use the following:

class CustomFormater < Logger::Formater
  def call(severity, time, progname, msg)
    %Q|{time: "#{datetime}\n", message: "#{msg} from #{progname}"}\n|
  end
end

Now, it’s easy for you to stream your data to your preferred analytics tools.

Between logging nothing and logging everything,
where should I land on this spectrum?

Obviously, what you should log depends on the specifics of your app. Here are some ideas to help you get started when deciding what you want to log.

troubleshooting

Troubleshooting/Performance

Ideally, your logs should contain enough information that you can quickly identify the issue, as well as the source of the issue. Context matters, and while it’s a fine balance between too much and too little information, you’ll want to err on the side of more in cases of uncertainty. At the very least, you’ll want to capture the following data points:

  • Log level
  • Date/time of request
  • HTTP method
  • HTTP response code
  • Requestor’s IP address
  • URL used
  • Request parameters

For example, Lograge gives you lines like this (remember, the library assumes you are using a log formatter as well, so it doesn’t include the date/timestamp):

method=GET path=/jobs/833552.json format=json controller=JobsController  action=show status=200 duration=58.33 view=40.43 db=15.26

A note on performance

By making note of the Warn flags that show up in your logs, you can prevent issues from escalating to Error. This is particularly applicable when it comes to things like server storage discs and requests (are you seeing a spike in traffic due to your newly-implemented marketing campaign?).

Operational Intelligence

When logging on user behavior, you’ll want to include the appropriate context, including:

  • User ID
  • Time spent on your site
  • Search queries
  • Referrer/referrals

This can help you identify strengths and weaknesses of your site/app.

Takeaways

It’s easy to put logging on your development backburner, but implementing even rudimentary logging is better than nothing. Hopefully, this article showed you some tricks you can use right away to improve your app logging. Doing so can make a big difference when it comes to debugging, as well as planning and executing business decisions regarding your app.

Happy logging!

Love this? Share it!
Want to share your experience in articles like this one? Contact us @logmatic.

Related Posts

Get notified when new content is published