Skip to content

🔍 Rails N+1 queries auto-detection with zero false positives / false negatives

License

Notifications You must be signed in to change notification settings

charkost/prosopite

Folders and files

NameName
Last commit message
Last commit date

Latest commit

 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 

Repository files navigation

Prosopite CI Gem Version

Prosopite is able to auto-detect Rails N+1 queries with zero false positives / false negatives.

N+1 queries detected:
  SELECT `users`.* FROM `users` WHERE `users`.`id` = 20 LIMIT 1
  SELECT `users`.* FROM `users` WHERE `users`.`id` = 21 LIMIT 1
  SELECT `users`.* FROM `users` WHERE `users`.`id` = 22 LIMIT 1
  SELECT `users`.* FROM `users` WHERE `users`.`id` = 23 LIMIT 1
  SELECT `users`.* FROM `users` WHERE `users`.`id` = 24 LIMIT 1
Call stack:
  app/controllers/thank_you_controller.rb:4:in `block in index'
  app/controllers/thank_you_controller.rb:3:in `each'
  app/controllers/thank_you_controller.rb:3:in `index':
  app/controllers/application_controller.rb:8:in `block in <class:ApplicationController>'

The need for prosopite emerged after dealing with various false positives / negatives using the bullet gem.

Compared to Bullet

Prosopite can auto-detect the following extra cases of N+1 queries:

N+1 queries after record creations (usually in tests)

FactoryBot.create_list(:leg, 10)

Leg.last(10).each do |l|
  l.chair
end

Not triggered by ActiveRecord associations

Leg.last(4).each do |l|
  Chair.find(l.chair_id)
end

First/last/pluck of collection associations

Chair.last(20).each do |c|
  c.legs.first
  c.legs.last
  c.legs.pluck(:id)
end

Changing the ActiveRecord class with #becomes

Chair.last(20).map{ |c| c.becomes(ArmChair) }.each do |ac|
  ac.legs.map(&:id)
end

Mongoid models calling ActiveRecord

class Leg::Design
  include Mongoid::Document
  ...
  field :cid, as: :chair_id, type: Integer
  ...
  def chair
    @chair ||= Chair.where(id: chair_id).first!
  end
end

Leg::Design.last(20) do |l|
  l.chair
end

Why a new gem

Creating a new gem makes more sense since bullet's core mechanism is completely different from prosopite's.

How it works

Prosopite monitors all SQL queries using the Active Support instrumentation and looks for the following pattern which is present in all N+1 query cases:

More than one queries have the same call stack and the same query fingerprint.

Installation

Add this line to your application's Gemfile:

gem 'prosopite'

If you're not using MySQL/MariaDB, you should also add:

gem 'pg_query'

And then execute:

$ bundle install

Or install it yourself as:

$ gem install prosopite

Configuration

The preferred type of notifications can be configured with:

  • Prosopite.min_n_queries: Minimum number of N queries to report per N+1 case. Defaults to 2.
  • Prosopite.raise = true: Raise warnings as exceptions. Defaults to false.
  • Prosopite.rails_logger = true: Send warnings to the Rails log. Defaults to false.
  • Prosopite.prosopite_logger = true: Send warnings to log/prosopite.log. Defaults to false.
  • Prosopite.stderr_logger = true: Send warnings to STDERR. Defaults to false.
  • Prosopite.backtrace_cleaner = my_custom_backtrace_cleaner: use a different ActiveSupport::BacktraceCleaner. Defaults to Rails.backtrace_cleaner.
  • Prosopite.custom_logger = my_custom_logger: Set a custom logger. See the following section for the details. Defaults to false.
  • Prosopite.enabled = true: Enables or disables the gem. Defaults to true.

Custom Logging Configuration

You can supply a custom logger with the Prosopite.custom_logger setting.

This is useful for circumstances where you don't want your logs to be highlighted with red, or you want logs sent to a custom location.

One common scenario is that you may be generating json logs and sending them to Datadog, ELK stack, or similar, and don't want to have to remove the default red escaping data from messages sent to the Rails logger, or want to tag them differently with your own custom logger.

# Turns off logging with red highlights, but still sends them to the Rails logger
Prosopite.custom_logger = Rails.logger
# Use a completely custom logging instance
Prosopite.custom_logger = MyLoggerClass.new

Development Environment Usage

Prosopite auto-detection can be enabled on all controllers:

class ApplicationController < ActionController::Base
  unless Rails.env.production?
    around_action :n_plus_one_detection

    def n_plus_one_detection
      Prosopite.scan
      yield
    ensure
      Prosopite.finish
    end
  end
end

And the preferred notification channel should be configured:

# config/environments/development.rb

config.after_initialize do
  Prosopite.rails_logger = true
end

Test Environment Usage

Tests with N+1 queries can be configured to fail with:

# config/environments/test.rb

config.after_initialize do
  Prosopite.rails_logger = true
  Prosopite.raise = true
end

And each test can be scanned with:

# spec/spec_helper.rb

config.before(:each) do
  Prosopite.scan
end

config.after(:each) do
  Prosopite.finish
end

WARNING: scan/finish should run before/after each test and NOT before/after the whole suite.

Middleware

Rack

Instead of using an around_action hook in a Rails Controller, you can also use the rack middleware instead implementing auto detect for all controllers.

Add the following line into your config/initializers/prosopite.rb file.

unless Rails.env.production?
  require 'prosopite/middleware/rack'
  Rails.configuration.middleware.use(Prosopite::Middleware::Rack)
end

Sidekiq

We also provide a middleware for sidekiq 6.5.0+ so that you can auto detect n+1 queries that may occur in a sidekiq job. You just need to add the following to your sidekiq initializer.

Sidekiq.configure_server do |config|
  unless Rails.env.production?
    config.server_middleware do |chain|
      require 'prosopite/middleware/sidekiq'
      chain.add(Prosopite::Middleware::Sidekiq)
    end
  end
end

For applications running sidekiq < 6.5.0 but want to add the snippet, you can guard the snippet with something like this and remove it once you upgrade sidekiq:

 if Sidekiq::VERSION >= '6.5.0' && (Rails.env.development? || Rails.env.test?)
.....
end

Allow list

Ignore notifications for call stacks containing one or more substrings / regex:

Prosopite.allow_stack_paths = ['substring_in_call_stack', /regex/]

Ignore notifications matching a specific SQL query:

Prosopite.ignore_queries = [/regex_match/, "SELECT * from EXACT_STRING_MATCH"]

Scanning code outside controllers or tests

All you have to do is to wrap the code with:

Prosopite.scan
<code to scan>
Prosopite.finish

In block form the Prosopite.finish is called automatically for you at the end of the block:

Prosopite.scan do
  <code to scan>
end

The result of the code block is also returned by Prosopite.scan, so you can wrap calls as follows:

my_object = Prosopite.scan do
  MyObjectFactory.create(params)
end

Pausing and resuming scans

Scans can be paused:

Prosopite.scan
# <code to scan>
Prosopite.pause
# <code that has n+1s>
Prosopite.resume
# <code to scan>
Prosopite.finish

You can also pause items in a block, and the Prosopite.resume will be done for you automatically:

Prosopite.scan
# <code to scan>

result = Prosopite.pause do
  # <code that has n+1s>
end

Prosopite.finish

Pauses can be ignored with Prosopite.ignore_pauses = true in case you want to remember their N+1 queries.

An example of when you might use this is if you are testing Active Jobs inline, and don't want to run Prosopite on background job code, just foreground app code. In that case you could write an Active Job callback that pauses the scan while the job is running.

Contributing

Bug reports and pull requests are welcome on GitHub at https://github.com/charkost/prosopite.

License

Prosopite is licensed under the Apache License, Version 2.0. See LICENSE.txt for the full license text.