Using TracePoint to explore complex exception behavior in Ruby

Ever wanted to know which method caused an exception - even if the exception was swallowed before you could get your hands on it? You can do all this and more with the magic of TracePoint.

Sometimes it can be really difficult to understand what's happening with exceptions - especially in larger apps. Imagine that you're working on some code inside an existing project. You raise an exception, then something weird happens. Maybe the exception is swallowed. Maybe an environment variable is changed. Maybe your exception gets wrapped in another exception.

I'm going to show you a simple way to use TracePoints to get a little more information about exceptions in your app - even if those exceptions are swallowed.

A Convenient Example

The boundary between controllers and views in Rails is one spot where exceptions seem to defy logic. It's easy to see for yourself. Just raise an exception in a view and try to rescue it in a controller. You'll find that you CAN'T rescue the template error from the controller!

# pages_controller.rb

def index
  # this will never run
  logger.debug "someone raised the roof"
# index.haml

- raise "the roof"

Template errors can't be rescued inside of the controller WTF!?! I thought I rescued this!

It's obvious that there's something tricky going on. Let's see if we can figure out what it is.

Logging All Exceptions With TracePoint

TracePoints are a really powerful introspection tool that have been around since Ruby 2.0. They allow you to define callbacks for a wide variety of runtime events. For example, you can be notified whenever a class is defined, whenever a method is called or whenever an exception is raised. Check out the TracePoint documentation for even more events.

Let's start by adding a TracePoint that is called whenever an exception is raised and writes a summary of it to the log.

class PagesController < ApplicationController
  def index do |tp|
      # tp.raised_exeption contains the actual exception object that was raised!
      logger.debug "#{tp.raised_exception.object_id}: #{tp.raised_exception.class} #{tp.raised_exception.message} ".yellow + tp.raised_exception.backtrace[0].sub(Rails.root.to_s, "").blue
    end.enable do

If you're curious about the yellow and blue methods,  I'm using the colorize gem. It adds ANSI color codes to the output.

Now when I go and refresh my page, my logs look like the screenshot below. One interesting thing that you might notice is that there are two separate exceptions, and each of them is raised twice. That long number at the beginning of each line is the Exception's object id. That's how we know there are two exception objects, not four.

This log shows every use of `raise` in the rendering process This log shows every use of raise in the rendering process

Which Method Caused Which Raise?

Having a list of "raise" events is pretty useful. But it would be even better if we had some idea of which methods were causing each raise. Once again, TracePoint comes to the rescue.

TracePoint lets us add a handler that is called whenever a method returns. It's just as simple to use as the "raise" event was. In the example below we're logging every method return:

TracePoint.trace(:return) do |tp|
  logger.debug [tp.method_id, tp.lineno, tp.path.sub(Rails.root.to_s, "")].join(" : ").green 

There's one problem though. If you add this code to your rails app, you'll find that your app stops responding to requests. There are so many method calls in the simplest Rails request that the server times out before it can write them all to the log.

Since we're really only interested in method calls that caused exceptions, lets modify our code to output the first two "return" events that happen after each exception.

class PagesController < ApplicationController
  def index
    counter = 0
    return_trace = TracePoint.trace(:return) do |tp|
      logger.debug "\t" + [tp.method_id, tp.lineno, tp.path.sub(Rails.root.to_s, "")].join(" : ").green 
      if (counter += 1) > 3
        counter = 0
    return_trace.disable # disable the tracepoint by default do |tp|
      logger.debug "#{tp.raised_exception.object_id}: #{tp.raised_exception.class} #{tp.raised_exception.message} ".yellow + tp.raised_exception.backtrace[0].sub(Rails.root.to_s, "").blue
      # The "raise" enables the "return" tracepoint
    end.enable do


When I refresh my browser, I see the following lines have been added to the log:

Each "raise" event is shown above the method which caused it Each "raise" event is shown above the method which caused it

Because we only enable the "return" TracePoint when an exception is raised, the first "return" event is going to be from the method that raised the exception.

We can use this information to solve our mystery. Our original RuntimeError is being converted to an ActionView::Template::Error by the handle_render_error method on line 310 of template.rb.

The nice thing about this technique is that it doesn't have anything to do with Rails. You can use it any time you need to understand in greater detail which exceptions are being raise and caught under the hood.

What to do next:
  1. Try Honeybadger for FREE
    Honeybadger helps you find and fix errors before your users can even report them. Get set up in minutes and check monitoring off your to-do list.
    Start free trial
    Easy 5-minute setup — No credit card required
  2. Get the Honeybadger newsletter
    Each month we share news, best practices, and stories from the DevOps & monitoring community—exclusively for developers like you.
    author photo

    Starr Horne

    Starr Horne is a Rubyist and Chief JavaScripter at When she's not neck-deep in other people's bugs, she enjoys making furniture with traditional hand-tools, reading history and brewing beer in her garage in Seattle.

    More articles by Starr Horne
    Stop wasting time manually checking logs for errors!

    Try the only application health monitoring tool that allows you to track application errors, uptime, and cron jobs in one simple platform.

    • Know when critical errors occur, and which customers are affected.
    • Respond instantly when your systems go down.
    • Improve the health of your systems over time.
    • Fix problems before your customers can report them!

    As developers ourselves, we hated wasting time tracking down errors—so we built the system we always wanted.

    Honeybadger tracks everything you need and nothing you don't, creating one simple solution to keep your application running and error free so you can do what you do best—release new code. Try it free and see for yourself.

    Start free trial
    Simple 5-minute setup — No credit card required

    Learn more

    "We've looked at a lot of error management systems. Honeybadger is head and shoulders above the rest and somehow gets better with every new release."
    — Michael Smith, Cofounder & CTO of YvesBlue

    Honeybadger is trusted by top companies like:

    “Everyone is in love with Honeybadger ... the UI is spot on.”
    Molly Struve, Sr. Site Reliability Engineer, Netflix
    Start free trial