Finding the Slow Query Killing Your Rails App

andreigaspar1 pts0 comments

Finding the Slow Query Killing Your Rails App | AppSignal BlogPerformance problems in Rails applications are sneaky. Generally speaking, nobody opens tickets that say “my application is slower than it was last month (about 20%)”. What you do get instead are vague complaints from team members about a p95 latency that is climbing every week or a background job that used to take 2 seconds now taking 40 seconds to finish.

Nine times out of ten, the problem is going to be a query that used to be fast, and now it’s not. When that query was first written, it had 500 records in the table. Now, it’s got 500K records, and it’s running a full table scan on every page load. Each new row means slightly more scan time and latency. This increase in time continues until it reaches a point when it can no longer be ignored. And by then, it’s usually been around for a few weeks.

This article walks you through a repeatable debugging loop: identifying the bottleneck, understanding why it’s slow, fixing it, and verifying that the fix has actually worked.

It’s not a comprehensive guide to every ActiveRecord optimization (the linked articles at the bottom cover those in depth). It’s just the workflow you can reach for when something is clearly wrong and you need to locate the issue fast.

Finding Where the Time Goes

Before digging through logs or adding logger.debug statements everywhere, you should open AppSignal’s Performance > Charts and look at the Event Groups (Relative) chart. It gives you a quick breakdown of where request time is actually being spent, whether that is active_record, view, process_action, external HTTP calls, or something else entirely.

If active_record is taking up a large chunk of the total response time (around 55% in our case), there is a good chance the database is where the slowdown is coming from.

The event groups chart showing active_record dominating meaning start with database before touching anything else<br>This easy check helps you avoid unnecessary guesswork. For instance, if your database is consuming the majority of your response time, there’s no need to optimize template rendering or get into your view partials.

From there, go to Performance > Slow Queries in AppSignal. AppSignal ranks each query based on both duration and frequency, and this ranking matters more than you may think. For example, a query taking 900 ms that executes only once a day will not be that noticeable to your users. A 150 ms query that executes on every request when someone looks at a product listing will take away a lot of response time at scale. The high-frequency offenders will show up first in the impact ranking created by AppSignal, and that’s almost always the best place to start.

Click any query, and a detail panel will open, showing the mean duration , throughput over the selected time window, and the actions that trigger it. Be sure to check that last piece to have the full context before you write your solution. A slow query firing only on an admin CSV export is a lower priority than one firing on your main product index.

Always make sure you understand the reach of the problem before you write any fix.

Slow queries ranked by impact<br>Understanding Why It's Slow

Clicking into a slow query reveals that specific request’s performance sample, including a full timeline of all events related to it. This is where patterns start to emerge, and these are the two that cause most production query issues within Rails:

The first one is a single long sql.active_record bar: that is, one query that takes between 300 and 500 milliseconds on a table that should typically respond within milliseconds. If a table has 200,000 rows, then the database must sequentially scan each of them to find the ones that match your WHERE clause. This is usually fine when the table is small, though.

The second pattern looks very different, as there are many short bars that are stacked up. If you’ve got 15 to 20 queries, each taking 15 ms, then you’re likely looking at an N+1 problem. This typically happens when you’ve performed a collection load without preloading associations, and ActiveRecord has executed a query one time per record while looping through the collection. Individually, those queries are not an issue, but if you perform 1,000 queries, this will create an N+1 problem, and AppSignal will highlight this with an N+1 warning banner in the sample view.

N+1 warning banner in AppSignal

Stacked `sql.active_record` timeline rows caused by N+1 queries<br>Each of these patterns will be differently displayed on the timeline, and checking it prior to reading any code will save you time. Once you have formed a hypothesis, copy the SQL from the Slow Queries panel and run EXPLAIN ANALYZE against your database directly:

SQL

EXPLAIN ANALYZE SELECT * FROM orders WHERE user_id = 42;

text

Seq Scan on orders (cost=0.00..4821.00 rows=1 width=256)<br>(actual time=0.042..38.214 rows=1 loops=1)<br>Filter: (user_id = 42)<br>Rows Removed by Filter:...

query time slow appsignal queries from

Related Articles