Although there are tools that can help you detect n+1 queries before they hit production, I think that is good to be able to identify n+1 queries directly by watching your logs…

Not all the tools will tell you exactly that you have n+1 queries, and sometimes the ones that will tell you, can give you false negatives.

Also I think that, although there is hardly no training anywhere for this ability, is always an expected ability for an experienced rails developer.

Look for repeated queries

As you may know, an n+1 queries problem means that a query is executed for every result of a previous query.

For example, given a Post that has many comments, If you execute the next code…

Post.map(&:comments).map(&:to_a)

You will execute…

• 1 query to fetch the posts (Post.all)
• And n queries to fetch the comments of each post(post.comments)

So, if you go to the console and test this code…

If there are 2 posts, it will execute 3 queries (2 + 1), and you will see in your logs, something like…

> Post.first(2).map(&:comments).map(&:to_a)
Post Load (0.8ms)  SELECT "posts".* FROM "posts" ORDER BY "posts"."id" ASC LIMIT $1  [["LIMIT", 2]]
Comment Load (0.4ms)  SELECT "comments".* FROM "comments" WHERE "comments"."post_id" = $1 ORDER BY "comments"."id" ASC  [["post_id", 1]]
Comment Load (0.3ms)  SELECT "comments".* FROM "comments" WHERE "comments"."post_id" = $1 ORDER BY "comments"."id" ASC  [["post_id", 2]]

And if there are 5 posts, it will execute 6 queries (5 + 1), and you will see in your logs, something like…

> Post.first(5).map(&:comments).map(&:to_a)
Post Load (0.8ms)  SELECT "posts".* FROM "posts" ORDER BY "posts"."id" ASC LIMIT $1  [["LIMIT", 5]]
Comment Load (0.4ms)  SELECT "comments".* FROM "comments" WHERE "comments"."post_id" = $1 ORDER BY "comments"."id" ASC  [["post_id", 1]]
Comment Load (0.3ms)  SELECT "comments".* FROM "comments" WHERE "comments"."post_id" = $1 ORDER BY "comments"."id" ASC  [["post_id", 2]]
Comment Load (0.3ms)  SELECT "comments".* FROM "comments" WHERE "comments"."post_id" = $1 ORDER BY "comments"."id" ASC  [["post_id", 3]]
Comment Load (0.2ms)  SELECT "comments".* FROM "comments" WHERE "comments"."post_id" = $1 ORDER BY "comments"."id" ASC  [["post_id", 4]]
Comment Load (0.3ms)  SELECT "comments".* FROM "comments" WHERE "comments"."post_id" = $1 ORDER BY "comments"."id" ASC  [["post_id", 5]]

And if there are 1000 posts, it will execute 1001 queries (1000 + 1), and in the same way you will see in your logs…

> Post.first(1000).map(&:comments).map(&:to_a)
Post Load (0.8ms)  SELECT "posts".* FROM "posts" ORDER BY "posts"."id" ASC LIMIT $1  [["LIMIT", 1000]]
Comment Load (0.4ms)  SELECT "comments".* FROM "comments" WHERE "comments"."post_id" = $1 ORDER BY "comments"."id" ASC  [["post_id", 1]]
Comment Load (0.3ms)  SELECT "comments".* FROM "comments" WHERE "comments"."post_id" = $1 ORDER BY "comments"."id" ASC  [["post_id", 2]]
Comment Load (0.3ms)  SELECT "comments".* FROM "comments" WHERE "comments"."post_id" = $1 ORDER BY "comments"."id" ASC  [["post_id", 3]]
Comment Load (0.2ms)  SELECT "comments".* FROM "comments" WHERE "comments"."post_id" = $1 ORDER BY "comments"."id" ASC  [["post_id", 4]]
Comment Load (0.3ms)  SELECT "comments".* FROM "comments" WHERE "comments"."post_id" = $1 ORDER BY "comments"."id" ASC  [["post_id", 5]]
#...
Comment Load (0.3ms)  SELECT "comments".* FROM "comments" WHERE "comments"."post_id" = $1 ORDER BY "comments"."id" ASC  [["post_id", 1000]]

Look for repeated queries executed in the same place

The previous examples show examples taken from the rails console, but as you can see in the next example…

When you start the server, on your logs, after each query, rails will show you where is the code that executes that query.

Started GET "/posts" for ::1 at 2021-11-10 06:47:40 -0600
Processing by PostsController#index as HTML
  Rendering layout layouts/application.html.erb
  Rendering posts/index.html.erb within layouts/application
  Rendered posts/_filters.html.erb (Duration: 6.5ms | Allocations: 2354)
  Post Load (1.2ms)  SELECT "posts".* FROM "posts" WHERE "posts"."comments_count" = $1  [["comments_count", 5]]
  ↳ app/views/posts/index.html.erb:5
  Comment Load (3.4ms)  SELECT "comments".* FROM "comments" WHERE "comments"."post_id" = $1 ORDER BY "comments"."id" DESC LIMIT $2  [["post_id", 1], ["LIMIT", 1]]
  ↳ app/views/posts/_post.html.erb:6
  Comment Load (1.0ms)  SELECT "comments".* FROM "comments" WHERE "comments"."post_id" = $1 ORDER BY "comments"."id" DESC LIMIT $2  [["post_id", 2], ["LIMIT", 1]]
  ↳ app/views/posts/_post.html.erb:6
  Comment Load (1.0ms)  SELECT "comments".* FROM "comments" WHERE "comments"."post_id" = $1 ORDER BY "comments"."id" DESC LIMIT $2  [["post_id", 3], ["LIMIT", 1]]
  ↳ app/views/posts/_post.html.erb:6
  Comment Load (1.0ms)  SELECT "comments".* FROM "comments" WHERE "comments"."post_id" = $1 ORDER BY "comments"."id" DESC LIMIT $2  [["post_id", 4], ["LIMIT", 1]]
  ↳ app/views/posts/_post.html.erb:6
  Comment Load (1.0ms)  SELECT "comments".* FROM "comments" WHERE "comments"."post_id" = $1 ORDER BY "comments"."id" DESC LIMIT $2  [["post_id", 5], ["LIMIT", 1]]
  ↳ app/views/posts/_post.html.erb:6
  #...
  Rendered collection of posts/_post.html.erb [20 times] (Duration: 84.5ms | Allocations: 34947)
  Rendered posts/index.html.erb within layouts/application (Duration: 107.3ms | Allocations: 45186)
  Rendered layout layouts/application.html.erb (Duration: 175.0ms | Allocations: 77162)
Completed 200 OK in 204ms (Views: 147.6ms | ActiveRecord: 34.7ms | Allocations: 86545)

So, if you look out for this two things, repeated queries that are executed from the sample place … you can be almost sure that you have an n+1 queries problem in that place.

Related articles

• Building a DateTime range to query for the records created a "week before"
• Fetching the top n per group with window functions
• Use after_touch to avoid to handle race conditions saving computed values
• Tool to run the examples for the 5 ways to fetch the latest-n-of-each record