N+1クエリの検出ツールとして有名なBulletのコードリーディングをしました。バージョンは5.9.0です。
コードリーディングの過程で、False Negative, False Positiveなケースを発見したのでそれも併せて紹介します。
※この記事はRuby on Rails Advent Calendar 2018の19日目の記事です。
処理の概要
- BulletのRackミドルウェアを差し込む
- 使っているORMに対してモジュールをprependやらextendやらで拡張。
- これによってORMのメソッド呼び出しをフックしてBulletの処理をすることができる
- モジュールのメソッドでN+1クエリの集計をして、Rackミドルウェアを使って結果を表示する
使い方ざっくり
config/environments/development.rb とかに以下のような記述を入れればOK
Bullet.enable = true
Bullet.bullet_logger = true
Bullet.console = true
Bullet.rails_logger = true
Bullet.add_footer = true
RailsだとRailtieで自動的にRackミドルウェアが読み込まれます
コードリーディング
Railsのコントローラで以下のようなN+1クエリを検知したときのパターンを追っていきます。
User.all.each do |user|
user.posts.to_a
end
# class User < ApplicationRecord
# has_many :posts
# end
#
# class Post < ApplicationRecord
# belongs_to :user
# end
lib/bullet.rbでRails::Railtieが定義されている場合はBullet::BulletRailtieが定義されます。
module Bullet
if defined? Rails::Railtie
class BulletRailtie < Rails::Railtie
initializer 'bullet.configure_rails_initialization' do |app|
app.middleware.use Bullet::Rack
end
end
end
BulletRailtieはイニシャライザでBullet::RackのRackミドルウェアをアプリケーションのミドルウェアに差し込みます。
Bullet::Rackは以下のように定義されています。
module Bullet
class Rack
# ...
def call(env)
return @app.call(env) unless Bullet.enable?
Bullet.start_request
status, headers, response = @app.call(env)
response_body = nil
if Bullet.notification?
if !file?(headers) && !sse?(headers) && !empty?(response) &&
status == 200 && html_request?(headers, response)
response_body = response_body(response)
response_body = append_to_html_body(response_body, footer_note) if Bullet.add_footer
response_body = append_to_html_body(response_body, Bullet.gather_inline_notifications)
headers['Content-Length'] = response_body.bytesize.to_s
end
Bullet.perform_out_of_channel_notifications(env)
end
[status, headers, response_body ? [response_body] : response]
ensure
Bullet.end_request
end
Bullet.enable?がtrueの場合はBullet.start_requestした上でapp.callします。Bullet.notification?がtrueの場合にレスポンスBodyにBulletの通知を入れてRackレスポンスを返します。
Bullet.start_requestはThread.currentに値を設定しています。Bullet::RackのensureでBullet.end_requestを呼び出していますが、このメソッドで設定したThread.currentの値をnilでリセットしています。
module Bullet
class << self
def start_request
Thread.current[:bullet_start] = true
Thread.current[:bullet_notification_collector] = Bullet::NotificationCollector.new
Thread.current[:bullet_object_associations] = Bullet::Registry::Base.new
Thread.current[:bullet_call_object_associations] = Bullet::Registry::Base.new
Thread.current[:bullet_possible_objects] = Bullet::Registry::Object.new
Thread.current[:bullet_impossible_objects] = Bullet::Registry::Object.new
Thread.current[:bullet_inversed_objects] = Bullet::Registry::Base.new
Thread.current[:bullet_eager_loadings] = Bullet::Registry::Association.new
Thread.current[:bullet_counter_possible_objects] ||= Bullet::Registry::Object.new
Thread.current[:bullet_counter_impossible_objects] ||= Bullet::Registry::Object.new
end
lib/bullet.rbの読み込みで、::ActiveRecordが定義されている場合はActiveRecordのautoloadが設定されます。
autoload :ActiveRecord, "bullet/#{active_record_version}" if active_record?
module Bullet
module Dependency
# ...
def active_record?
@active_record ||= defined? ::ActiveRecord
end
configで書いた Bullet.enable = trueは以下のようなセッターメソッドになっています。
def enable=(enable)
@enable = @n_plus_one_query_enable = @unused_eager_loading_enable = @counter_cache_enable = enable
if enable?
reset_whitelist
unless orm_pathches_applied
self.orm_pathches_applied = true
Bullet::Mongoid.enable if mongoid?
Bullet::ActiveRecord.enable if active_record?
end
end
end
ActiveRecordを使っている場合はBullet::ActiveRecord.enableが呼ばれます。ActiveRecordのバージョンによってパッチの当て方が変わるため、バージョンによって読み込むファイルが変わります。以下、ActiveRecordのバージョン5.2のパターンを追っていきます。
Bullet::ActiveRecord.enableは以下のように定義されており、ActiveRecord::BaseやActiveRecord::Relationに対してprependやextendでパッチを当てまくってます。
module Bullet
module ActiveRecord
def self.enable
require 'active_record'
::ActiveRecord::Base.extend(Module.new do
# ...
::ActiveRecord::Base.prepend(SaveWithBulletSupport)
::ActiveRecord::Relation.prepend(Module.new do
まず User.all とクエリメソッドが呼ばれると .records => .find_by_sql が呼ばれます。
::ActiveRecord::Base.extend(Module.new do
def find_by_sql(sql, binds = [], preparable: nil, &block)
result = super
if Bullet.start?
if result.is_a? Array
if result.size > 1
Bullet::Detector::NPlusOneQuery.add_possible_objects(result)
Bullet::Detector::CounterCache.add_possible_objects(result)
elsif result.size == 1
Bullet::Detector::NPlusOneQuery.add_impossible_object(result.first)
Bullet::Detector::CounterCache.add_impossible_object(result.first)
end
elsif result.is_a? ::ActiveRecord::Base
Bullet::Detector::NPlusOneQuery.add_impossible_object(result)
Bullet::Detector::CounterCache.add_impossible_object(result)
end
end
result
end
end)
User.allが複数件の場合はresult.size > 1なのでadd_possible_objectsでpossible_objectsとしてマーキングされます。
キーは”#{モデル名}:#{主キーの値}”でセットされます。Userでid: 1なら”User:1” という感じです。
user.posts.to_aのアソシエーションのメソッド呼び出しではfind_by_sqlとload_targetが呼ばれます。load_targetではBullet::Detector::NPlusOneQuery.call_associationが呼ばれます。
::ActiveRecord::Associations::CollectionAssociation.prepend(Module.new do
def load_target
records = super
if Bullet.start?
if is_a? ::ActiveRecord::Associations::ThroughAssociation
# ...
end
Bullet::Detector::NPlusOneQuery.call_association(owner, reflection.name) unless @inversed
if records.first.class.name !~ /^HABTM_/
# ...
end
end
records
end
conditions_met?がtrueの場合 create_notificationで通知が生成されます。
module Bullet
module Detector
class NPlusOneQuery < Association
class <<self
# executed when object.assocations is called.
# first, it keeps this method call for object.association.
# then, it checks if this associations call is unpreload.
# if it is, keeps this unpreload associations and caller.
def call_association(object, associations)
return unless Bullet.start?
return unless Bullet.n_plus_one_query_enable?
return unless object.primary_key_value
return if inversed_objects.include?(object.bullet_key, associations)
add_call_object_associations(object, associations)
Bullet.debug('Detector::NPlusOneQuery#call_association', "object: #{object.bullet_key}, associations: #{associations}")
if !excluded_stacktrace_path? && conditions_met?(object, associations)
Bullet.debug('detect n + 1 query', "object: #{object.bullet_key}, associations: #{associations}")
create_notification caller_in_project, object.class.to_s, associations
end
end
conditions_met?は以下のように定義されています。
def conditions_met?(object, associations)
possible?(object) && !impossible?(object) && !association?(object, associations)
end
User.allで各ユーザレコードはpossible_objectsとしてマーキングされていて、かつ impossible_objectsとしてマーキングされていないためconditions_met?はtrueになります。
create_notificationはBullet.notification_collector（Thread.currentに設定されているBullet::NotificationCollectorオブジェクト）のaddメソッドで通知としてセットされます。
def create_notification(callers, klazz, associations)
notify_associations = Array(associations) - Bullet.get_whitelist_associations(:n_plus_one_query, klazz)
if notify_associations.present?
notice = Bullet::Notification::NPlusOneQuery.new(callers, klazz, notify_associations)
Bullet.notification_collector.add(notice)
end
end
あとはここでセットされた通知がBullet::RackでHTMLとしてセットされることでポップアップなどが表示されることになります。
BulletのFalse Positive, False Negative
impossible, possibleで判別しているためいくつかのケースで誤検知が発生します。
False Positiveの例だと以下のようなケースで誤検知されます。
class HogeController < ApplicationController
def index
User.all.to_a.first.posts.to_a
end
end
これはUser.all.to_aが複数件のときにpossible_objects扱いになってしまうため、Array#firstで絞り込んだとしてもconditions_met?がtrueになってしまうことに起因します。もちろんこんなSQL的にも非効率でメモリも食いそうなコードは書かないと思いますがｗ
False Negativeの例だと以下のようなケースで誤検知されます。
class UserController < ApplicationController
def index
User.find(1)
User.find(2)
User.where('id < 3').each do |user|
user.posts.to_a
end
end
end
これはUser.find(XX)でimpossible_objects扱いになってしまうため、conditions_met?がfalseになってしまうことに起因します。
いずれの例も、こんな書き方はしないと思うので問題ないと思いますが、万能ではないことは覚えておいて良いかもしれません。
ということで、N+1クエリを回避する一番良い方法はRailsのログをちゃんと読むことだなーと改めて思いました…ｗ