Obvious N+1 query not detected in RSpec (when setup code is run before it) #653
Description
Hey 👋
I'm attempting to set-up Bullet to run in my RSpec tests to detect N+1 queries and whatnot. I've followed the setup outlined in the README (here), and set a fairly obvious N+1 example that does trigger a Bullet notification when run in a controller.
I can't quite explain why, but Bullet seems to NOT detect N+1 queries when some other database interactions happen. To show what I mean consider the following two variations of the same RSpec test.
I've moved all the Bullet related code out of the general RSpec config and into the example. I've also moved the DB setup code out of a before hook into the example. This to show the timings off.
This does NOT trigger a Bullet warning
Note Bullet.start_request is invoked at the start of the example, before any DB interaction.
RSpec.describe User do
specify "test bullet detects N+1 query" do
Bullet.start_request
user = create(:user)
user.comments.create(content: "Comment 1")
user.comments.create(content: "Comment 2")
user.comments.create(content: "Comment 3")
user2 = create(:user, name: "User 2")
user2.comments.create(content: "User 2 Comment 1")
user2.comments.create(content: "User 2 Comment 2")
user2.comments.create(content: "User 2 Comment 3")
comments = []
described_class.all.each do |user|
user.comments.each do |comment|
comments << comment.content
end
end
expect(comments).to eq(["Comment 1", "Comment 2", "Comment 3", "User 2 Comment 1", "User 2 Comment 2", "User 2 Comment 3"])
Bullet.perform_out_of_channel_notifications if Bullet.notification?
Bullet.end_request
end
end1 example, 0 failures
This does trigger a Bullet warning
Note Bullet.start_request is run just before the actual querying code.
RSpec.describe User do
specify "test bullet detects N+1 query" do
user = create(:user)
user.comments.create(content: "Comment 1")
user.comments.create(content: "Comment 2")
user.comments.create(content: "Comment 3")
user2 = create(:user, name: "User 2")
user2.comments.create(content: "User 2 Comment 1")
user2.comments.create(content: "User 2 Comment 2")
user2.comments.create(content: "User 2 Comment 3")
# Invoking Bullet after the DB setup code works
Bullet.start_request
comments = []
described_class.all.each do |user|
user.comments.each do |comment|
comments << comment.content
end
end
expect(comments).to eq(["Comment 1", "Comment 2", "Comment 3", "User 2 Comment 1", "User 2 Comment 2", "User 2 Comment 3"])
Bullet.perform_out_of_channel_notifications if Bullet.notification?
Bullet.end_request
end
end1) User test bullet detects N+1 query
Failure/Error: Bullet.perform_out_of_channel_notifications if Bullet.notification?
Bullet::Notification::UnoptimizedQueryError:
user: jessevanderpluijm
USE eager loading detected
User => [:comments]
Add to your query: .includes([:comments])
My environment
I run a fairly standard RSpec setup, the only other plugin I have setup is DatabaseCleaner, which should run entirely around the example. (To ensure this wasn't messing with things I moved all the Bullet code into the example.
Related issues
This might to be related to: #427. But I wanted to report this anyway since (1) that issue doesn't really have a fix, and (2) I have a more simplified version of the problem that does not have anything to do with RSpec hook execution order.