Ruby on Rails books and screencasts

How to Write Good Error Messages

by Brad Bollenbach

Getting woken up at 2AM because your application is failing sucks. Even worse is having to dig through the logs and find only this:

Error updating captured_at for purchase 1244

captured_at who? What was captured? What impact is this having on customers? And was this really important enough to get woken up in the middle of the night?

In the world of professional software development, the way your application fails is exactly as important as the way it succeeds. It doesn't matter if your application has 99% test coverage, an AngularJS front-end, Clojure under the hood, and juggles data between three different NoSQL databases with one hand tied behind its back — if your purchase process is broken, and you can't decrypt the java.lang.ClassCastException staring you in the face, then you're in trouble.

When it comes to debugging, the error message is God. Taking the time to write good error messages will dramatically improve your ability to understand what the system is telling you when things break.

Here are some things to consider when writing error messages to ensure that, when things do go wrong, you'll be able to quickly track down the problem.

For our purposes, we'll assume we're looking at some code that updates records from a periodically run rake task, as these error messages are particularly prone to disappearing into the ether. The purpose of this rake task is to update the captured_at field on a purchase, which then allows another task somewhere else to fulfill the customer's order.

Be Descriptive

When writing code on a deadline, it's easy get lazy with error messages:

begin
  update_purchase_captured_at!(purchase, captured_at)
rescue Exception => e
  Rails.logger.error("Error updating captured_at for purchase #{purchase.id}")
end

If the developer who sees this error message actually is a violent psychopath who knows where you live then now is the right time to consider going into hiding. A good error message should answer as many of the five W's as it can:

begin
  update_purchase_captured_at!(purchase, captured_at)
rescue Exception => e
  Rails.logger.error(
    "[#{Time.zone.now}][rake purchases:update_captured_at] Error updating captured_at " +
    "for purchase #{purchase.id}: #{e.class}: #{e.message}")
end

Now I can see who was trying to update captured_at (the rake task), and when and why it failed.

Always Log Backtraces

One thing still missing from the above though is where the error happened. The backtrace is a vital piece of debugging information, so log it:

begin
  update_purchase_captured_at!(purchase, captured_at)
rescue Exception => e
  Rails.logger.error(
    "[#{Time.zone.now}][rake purchases:update_captured_at] Error updating captured_at " +
    "for purchase #{purchase.id}: #{e.class}: #{e.message}\n#{e.backtrace}")
end

When Possible, Describe System Impact

In a team of 4-5 developers or more, it's impossible to keep up with all the features being added to the product. If you're the one who gets woken in the middle of the night by the above error message, unless you're the one who wrote it, you probably won't fully understand its impact on the system.

Does it mean customers are seeing error pages? Are funds actually getting captured here, but orders not being fulfilled? Is it something that can wait until tomorrow morning?

Be generous to the person staring bleary-eyed at this message at 2AM trying to figure it out. When possible, describe the impact of the error in the message itself:

begin
  update_purchase_captured_at!(purchase, captured_at)
rescue Exception => e
  Rails.logger.error(%Q{\
[#{Time.zone.now}][rake purchases:update_captured_at] Error updating \
captured_at for purchase #{purchase.id}: #{e.class}: #{e.message}

This means the funds got captured, but the order will *not* be fulfilled!

#{e.backtrace}})
end

This is truly going the extra mile, and will be greatly appreciated by anyone who has to debug this error.

Offer Pointers for Debugging

We've all seen this warning from Rails at some point:

Called id for nil, which would mistakenly be 4 — if you really
wanted the id of nil, use object_id

Calling id on nil could otherwise be a source of extraordinarily frustrating bugs, if not for the helping hand of (the now deprecated) whiny_nil. The same holds for error messages that you write. When possible, give the person debugging your error message a head start:

begin
  update_purchase_captured_at!(purchase, captured_at)
rescue Exception => e
  Rails.logger.error(%Q{\
[#{Time.zone.now}][rake purchases:update_captured_at] Error updating \
captured_at for purchase #{purchase.id}: #{e.class}: #{e.message}

This means the funds got captured, but the order will *not* be fulfilled!

Visit http://paymentbackend.com/admin and search for transaction ID
#{purchase.transaction_id} for more details on this purchase.

#{e.backtrace}})
end

Make Errors Visible

After those few tweaks, you've now got something that is seriously helpful. There's just one last problem with your error message: developers won't see it. If you want to get a developer's attention, you'll need more than just Rails.logger. You'll also want to notify an error monitoring service like Honeybadger or Airbrake so that you get emailed (or SMS'd, IM'd, etc.) as soon as the error occurs.

Setting up Honeybadger, for example, is dead simple. And once you do, it will automatically get notified of all exceptions that you don't explicitly handle in your Rails application code.

For exceptions that you do handle, like our earlier example, it's easy to send those to Honeybadger too:

begin
  update_purchase_captured_at!(purchase, captured_at)
rescue Exception => e
  Honeybadger.notify(e)

  Rails.logger.error(%Q{\
[#{Time.zone.now}][rake purchases:update_captured_at] Error updating \
captured_at for purchase #{purchase.id}: #{e.class}: #{e.message}

This means the funds got captured, but the order will *not* be fulfilled!

Visit http://thepaymentprocess.com/admin and search for transaction ID
#{purchase.transaction_id} for more details on this purchase.

#{e.backtrace}})
end

Now you're covered on both fronts: Honeybadger will notify you of the "raw" exception, but your logs will contain more detailed information, which allow a developer to hit the ground running when things to go wrong.

Summary

This may seem like a lot of effort to go through for an error message, and it some cases it is overkill. But for the critical path of your application (e.g. purchase capture and fulfillment if you're an e-commerce site) investing a little extra care in the not-happy path will pay for itself many times over.

Write error messages as though they'll be read by someone who's tired, pissed off, and has no idea how the code in question works. Because eventually, the person reading that error message will be you.

Want more programming tips and techniques?

I'm writing a book called Rock Solid Rails Development: A No-Nonsense Guide to Building High-Quality Rails Apps. Enter your email to get more exclusive articles by email, and find out as soon as the book's released!