The inspect method on Active Record models returns a string including the model’s class and a list of all its attributes and their values. In Rails 7.2, you can configure which attributes are included in the output of inspect. In this post, I’ll discuss the performance issue that led me to implement this feature. I’ll also talk about how this feature can be used to improve developer experience.

to_s vs. inspect

Objects in Ruby define both to_s and inspect methods. Conventionally, to_s returns a string representation of the object, while inspect returns information about the object that can be used for debugging purposes.

Let’s take a look at how to_s and inspect work for Active Record models:

Book.first.to_s #=> "#<Book:0x000000017765e6b8>"

Book.first.inspect #=> "#<Book id: 1, title: “The Rings of Saturn”, created_at: \"2024-03-19 10:16:20.229686000 -0400\”, updated_at: \"2024-03-19 10:16:20.229686000 -0400\”>”

As you can see, to_s returns a short string representation of the model, containing just the name of the model’s class. On the other hand, inspect returns all the model’s attributes and their values.

However, that means calling inspect can be much slower than calling to_s. When we call inspect, we need to iterate over all the model’s attributes and get their values. We also check each of these against a list of filters defined by the ActiveRecord::ParameterFilter which are used to redact things like Personal Identifiable Information (PII) from the output. So, the cost of calling inspect increases based on the number of attributes on the model and the number of filters in the parameter filter. On the other hand, the cost of calling to_s is constant.

Since inspect is generally intended for debugging purposes, and its performance can vary depending on the model it’s called on, we should be careful about when it gets called in production. But as we’ll see, it can be surprisingly easy to inadvertently call inspect and cause problems.

The footgun

Developers at Shopify regularly profile their code to identify performance bottlenecks in our applications. Last year, a team discovered that we were spending almost 8 seconds in Active Record’s inspect method on certain requests. That’s a really long time!

Profile showing >7s spent in ActiveRecord::Core#inspect

The image above is a section of a profile that shows >7s being spent in Active Record’s inspect method. This is a left heavy view, so that means 7 seconds were spent in that method in total during this request, not necessarily consecutively. (Checkout speedscope to learn more about this profile.)

On further investigation it turned out that this code was calling to_s on an Array containing hundreds of Active Record models. For enumerables like arrays and hashes, to_s is simply an alias for inspect. The method works by iterating over the elements of the enumerable and calling inspect on each of them. to_s can be called in many ways, like implicitly during string interpolation, meaning it’s not always obvious in the code that inspect might be called on a model, or hundreds of models.

Developers sometimes refer to this type of issue as a “footgun”. The model’s inspect method is a useful feature for debugging, but misusing it is also an easy way to inadvertently shoot yourself in the foot and create performance issues in production. Calling to_s on a gigantic array full of Active Record models is most likely a mistake, but mistakes happen, and it shouldn’t lead to such a catastrophic performance issue.

Disarming the footgun

This kind of performance regression can be fixed by refactoring the application’s code to avoid the massive amount of calls to inspect. However, we would also like Rails to do something a little more reasonable in production to help avoid such a dire situation.

When considering possible solutions, it’s important to remember inspect does have use cases in production, like when we want to emit logs during error cases. So our solution can’t simply be to redefine or remove the inspect method in production. Ideally, our solution should maintain the power of the inspect method, while providing safety against unintentional misuse.

After some consideration we landed on a solution with two parts:

  1. Allow developers to configure which attributes are output by inspect
  2. In production, configure models to only output their id by default

Let’s get into a little bit more detail about how this solution is implemented (you can also check out the Pull Request).

First, we created a new class attribute on ActiveRecord::Base called attributes_for_inspect. When calling inspect on a model instance, only the attributes listed in attributes_for_inspect will be included.

Book.first.inspect #=> "#<Book id: 1, title: \“The Rings of Saturn\”, created_at: \"2024-03-19 10:16:20.229686000 -0400\”, updated_at: \"2024-03-19 10:16:20.229686000 -0400\”>”


Book.attributes_for_inspect = [:id, :title]


Book.first.inspect #=> "#<Book id: 1, title: \“The Rings of Saturn\”>”

Next, in production, we set the value of attributes_for_inspect to [:id] for all models. So, opening a Rails console in the production environment, we will see:

Book.first.inspect #=> "#<Book id: 1>”

Now, the potential performance problem has been greatly reduced. By default in production, calling inspect on a model will only iterate through a single attribute, :id. We still check that attribute against any parameter filters, so it’s slower than calling to_s. But importantly, the cost of calling inspect no longer grows with the number of attributes on the model.

There are two “escape hatches” that allow you to easily get back the full power of the inspect method. First, you can pass the symbol :all to attributes_for_inspect. This will revert to the behaviour of outputting all the attributes. That’s what happens by default in development and test modes, so we can still have the power of inspect for debugging purposes.

Book.attributes_for_inspect = :all

Book.first.inspect #=> "#<Book id: 1, title: \“The Rings of Saturn\”, created_at: \"2024-03-19 10:16:20.229686000 -0400\”, updated_at: \"2024-03-19 10:16:20.229686000 -0400\”>”

Alternatively, if you need the full output in a specific case, you can call the new full_inspect method.

Book.attributes_for_inspect = [:id]
Book.first.inspect #=> "#<Book id: 1>
Book.first.full_inspect #=> "#<Book id: 1, title: “The Rings of Saturn”, created_at: \"2024-03-19 10:16:20.229686000 -0400\”, updated_at: \"2024-03-19 10:16:20.229686000 -0400\”>”

Bonus: wins for developer experience

The motivation for introducing attributes_for_inspect was to dampen potential performance issues related to the use of inspect in production. However, it can also be used to improve the experience for developers working on the application.

In large Rails applications, it’s not uncommon for Active Record models to have dozens of attributes, sometimes with quite long values. It can be a pain because we don’t always manually call inspect, for example, inspect is called whenever an object is returned in the console.

myapp(dev)> Book.first
=>
  #<Book:0x000000017f9a9d88 id: 1,
  title: “The Rings of Saturn”,
  author: “W.G. Sebald”,
  published: 1998,
  pages: 306,
  language: “English”,
  type: “fiction”,
  format: “hardcover”,
  translated: true,
  original_language: “German”,
  original_name: "Die Ringe des Saturn”,
  translator: “Michael Hulse”,
  isbn-13: 9780811213783,
  isbn-10: “0811213781”,
  publisher: “New Directions”,
  created_at: "2024-03-19 10:16:20.229686000 -0400”,
  updated_at: "2024-03-19 10:16:20.229686000 -0400”>

At a certain point, the output is broken into multiple lines. When long enough, or if your window is small enough, you might even find your terminal has been hijacked to allow you to scroll through the output, requiring you to enter a command to exit before continuing with your debugging session. Long output from inspect can also clutter the results of failed test runs.

If you are like me, you might find that these long outputs are very hard to parse and slow you down while debugging as you try to make sense of the wall of characters printed on the screen. Rarely do I need to know the value of all the model’s attributes. Rather, I’m just interested in one or two things that identify the model for me before deciding what to do next.

So we can use attributes_for_inspect to only include attributes that are most useful for developers when debugging. This is especially noticeable when we are working with arrays of models, where we can reduce the size of the output from hundreds of lines to just a few.

By default, Rails 7.2 will set attributes_for_inspect to :all for all models in development and test, to maintain the existing behaviour. But I encourage you to try using attributes_for_inspect to improve your experience in the Rails console. And remember, you can always call full_inspect to get the values of all the model’s attributes.

Conclusion

As the saying goes, Rails provides sharp knives. But sometimes a powerful feature can cause unintended problems. In this post we saw that developers could accidentally create a situation where the inspect method is called on many Active Record models, leading to a performance issue. For Rails 7.2, we made the attributes included in the output of inspect configurable. In product environments only a model’s id will be included in the output of inspect, which helps guard against potential performance issues caused by mistakenly calling inspect. As a nice additional win, we also saw that this feature can be used to improve developer experience. Give attributes_for_inspect a try for yourself when you upgrade your application to Rails 7.2.