2018-12-19

Bulletコードリーディング

N+1クエリの検出ツールとして有名なBulletのコードリーディングをしました。バージョンは5.9.0です。

コードリーディングの過程で、False Negative, False Positiveなケースを発見したのでそれも併せて紹介します。

※この記事はRuby on Rails Advent Calendar 2018の19日目の記事です。

処理の概要

使い方ざっくり

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_sqlload_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的にも非効率でメモリも食いそうなコードは書かないと思いますがw

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のログをちゃんと読むことだなーと改めて思いました…w

このエントリーをはてなブックマークに追加