2017-07-19

ActiveRecordのパフォーマンス・チューニング

ActiveRecord周りのパフォーマンス・チューニングの備忘録。

DBレベルのチューニングはしたものの、Railsアプリのレイヤーでパフォーマンスを上げたい、という人向けの記事です。 今回ベンチマークに使ったコードはこちらにあります。

先に結論

前提

計測対象アプリの環境

Ruby 2.4.1
Rails 5.1.1
DB MySQL
OS macOS Sierra

スキーマとデータ量

データ量↓

ContentType 10
Content 8,000(ContentTypeに対して800レコードずつ)
Comment 24,000(Contentに対して3レコードずつ)
Author 3

ベンチマークの方法

以下のRakeタスクで計測しました。

ActiveRecordが配列に展開されるまで(to_a)の時間を計測しています。

Benchmark.ips do |r|
  r.report "one join/all: eager_load" do
    ContentType.eager_load(:contents).to_a
  end

  r.report "one join/condition: eager_load" do
    ContentType.eager_load(:contents).where('contents.id < ?', 1000).to_a
  end
  ...
end

また、一部のケースにおいてはstackprofを使って、メソッドのプロファイリングをしました。

namespace :stackprof do
  desc 'Benchmark for ActiveRecord with stackprof'
  task active_record: :environment do
    StackProf.run(mode: :cpu, out: 'tmp/stackprof/active_record/cpu-full.dump') do
      ContentType.eager_load(contents: {comments: :author}).to_a
    end

    StackProf.run(mode: :cpu, out: 'tmp/stackprof/active_record/cpu-conditional.dump') do
      ContentType.eager_load(contents: {conditional_comments: :author}).where('contents.id < ?', 1000).to_a
    end
  end
end

測定結果

eager_load: one join/all
                          1.345  (± 0.0%) i/s -     47.000  in  35.499157s
eager_load: one join/conditional
                         10.872  (± 9.2%) i/s -    378.000  in  35.046556s
eager_load: full join/all
                          0.218  (± 0.0%) i/s -      8.000  in  36.837148s
eager_load: full join/conditional
                          0.400  (± 0.0%) i/s -     14.000  in  35.185927s
preload: one join/all
                          1.660  (± 0.0%) i/s -     58.000  in  35.373139s
preload: one join/conditional
                         26.632  (±11.3%) i/s -    896.000  in  35.004991s
preload: full join/all
                          0.294  (± 0.0%) i/s -     11.000  in  37.782031s
preload: full join/conditional
                          0.759  (± 0.0%) i/s -     27.000  in  35.798513s
select_all: full_join/all
                          1.130  (± 0.0%) i/s -     40.000  in  35.597281s
find_by_sql: full_join/all
                          0.917  (± 0.0%) i/s -     32.000  in  35.223277s
cache: full_join/all    124.408k (±15.0%) i/s -      4.042M in  35.001589s

preload vs eager_load

今回はpreloadの方がeager_loadよりも速い結果となりました。

どちらもN+1クエリを撲滅するためのメソッドですが、preloadは複数クエリに分割してアプリ内でJOINし、eager_loadはDB内でLEFT OUTER JOINをするという違いがあります。また、preloadをしたアソシエーションに対しては、そのインスタンスのwhereメソッドで絞込をすることができず、以下のような呼び出し方をするとエラーになります。

Hoge.preload(:fugas).where('fugas.id = 1')

これはpreloadで最初に発行されるクエリ(上記だとHogeを取得するクエリ)でwhere句が効いてしまうのが原因です。 preloadでwhere句による絞込をする場合は、アソシエーションのスコープに対して絞込条件を記述します。これによって、分割したクエリ内で絞り込み条件が効くようになります。

class ContentType < ApplicationRecord
  ...
  has_many :conditional_contents, -> {
    where('id < ?', 1000)
  }, class_name: 'Content'
  ...
end

分割されたクエリの中で条件(scope)が効いている様子↓

[89] pry(main)> ContentType.preload(:conditional_contents).to_a
  ContentType Load (0.9ms)  SELECT `content_types`.* FROM `content_types`
  Content Load (4.7ms)  SELECT `contents`.* FROM `contents` WHERE (id < 1000) AND `contents`.`content_type_id` IN (1, 2, 3, 4, 5, 6, 7, 8, 9, 10)

一番遅いケース(eager_loadの複数JOIN)でも、SQL自体の速度はそこまで遅くないことにも注意が必要です。4〜5秒程度かかっていたケースでもSQL自体は200msで取得できていて、ActiveRecord::Baseにインスタンス生成する過程が遅いことがわかります。

SQL (200.7ms)  SELECT `content_types`.`id` AS t0_r0, `content_types`.`name` AS t0_r1, `content_types`.`created_at` AS t0_r2, `content_types`.`updated_at` AS t0_r3, `contents`.`id` AS t1_r0, `contents`.`title` AS t1_r1, `contents`.`body` AS t1_r2, `contents`.`content_type_id` AS t1_r3, `contents`.`author_id` AS t1_r4, `contents`.`created_at` AS t1_r5, `contents`.`updated_at` AS t1_r6, `comments`.`id` AS t2_r0, `comments`.`body` AS t2_r1, `comments`.`content_id` AS t2_r2, `comments`.`author_id` AS t2_r3, `comments`.`created_at` AS t2_r4, `comments`.`updated_at` AS t2_r5, `authors`.`id` AS t3_r0, `authors`.`name` AS t3_r1, `authors`.`created_at` AS t3_r2, `authors`.`updated_at` AS t3_r3 FROM `content_types` LEFT OUTER JOIN `contents` ON `contents`.`content_type_id` = `content_types`.`id` LEFT OUTER JOIN `comments` ON `comments`.`content_id` = `contents`.`id` LEFT OUTER JOIN `authors` ON `authors`.`id` = `comments`.<code>author_id</code>

絞込有り無し

絞込有り/無しを比較した場合、明らかに絞込有りの方が速いです。

絞込に関しては、stackprofによるプロファイリングをかけて調査してみました。絞込なしのケースだと以下のような結果になりました。

$ stackprof cpu-full.dump
==================================
  Mode: cpu(1000)
  Samples: 4294 (1.24% miss rate)
  GC: 497 (11.57%)
==================================
     TOTAL    (pct)     SAMPLES    (pct)     FRAME
      1704  (39.7%)        1685  (39.2%)     ActiveSupport::Inflector#underscore
       535  (12.5%)         534  (12.4%)     Mysql2::Result#each
       178   (4.1%)         176   (4.1%)     Listen::Record::Entry#meta
       170   (4.0%)         170   (4.0%)     Listen::Record::Entry#_entries
       166   (3.9%)         166   (3.9%)     ActiveRecord::Associations::JoinDependency::JoinPart#extract_record
      1016  (23.7%)         132   (3.1%)     ActiveSupport::Dependencies::Loadable#require
       222   (5.2%)         111   (2.6%)     ActiveRecord::Result#hash_rows
        77   (1.8%)          77   (1.8%)     Listen::Record::Entry#real_path
      7765 (180.8%)          71   (1.7%)     ActiveRecord::Associations::JoinDependency#instantiate
      8892 (207.1%)          50   (1.2%)     ActiveRecord::Associations::JoinDependency#construct
      4099  (95.5%)          48   (1.1%)     ActiveRecord::Associations::JoinDependency#construct_model
        57   (1.3%)          36   (0.8%)     ActiveRecord::LazyAttributeHash#assign_default_value
        32   (0.7%)          32   (0.7%)     ActiveRecord::Core#init_internals
        23   (0.5%)          23   (0.5%)     ActiveRecord::Reflection::AssociationReflection#foreign_key
        22   (0.5%)          22   (0.5%)     ActiveRecord::Relation#initialize
        21   (0.5%)          21   (0.5%)     ActiveRecord::Attribute#initialize
        21   (0.5%)          21   (0.5%)     block (4 levels) in class_attribute
....

MySQL2::Result#eachのSAMPLES(コールスタック内のトップでサンプリングされた回数)が多く、SQLで取得したレコードをインスタンス生成する処理に時間がかかっていることが予想されます。ActiveRecord::Associations::JoinDependencyのメソッド呼び出しのTOTAL(コールスタック内でサンプリングされた回数)も大きく、JOIN関連の処理が重いことがわかります。

絞込有りのケースだと以下のようになりました

$ stackprof cpu-conditional.dump
==================================
  Mode: cpu(1000)
  Samples: 271 (0.73% miss rate)
  GC: 71 (26.20%)
==================================
     TOTAL    (pct)     SAMPLES    (pct)     FRAME
        54  (19.9%)          53  (19.6%)     ActiveSupport::Inflector#underscore
        32  (11.8%)          29  (10.7%)     ActiveRecord::Relation#initialize_copy
        24   (8.9%)          24   (8.9%)     Mysql2::Result#each
        17   (6.3%)          17   (6.3%)     ActiveRecord::Associations::JoinDependency::JoinPart#extract_record
       531 (195.9%)          13   (4.8%)     ActiveRecord::Associations::JoinDependency#instantiate
         5   (1.8%)           5   (1.8%)     ActiveRecord::QueryMethods#default_value_for
       568 (209.6%)           5   (1.8%)     ActiveRecord::Associations::JoinDependency#construct
...
 147 (54.2%) 1 (0.4%) ActiveRecord::Associations::JoinDependency#construct_model
...

全体的にTOTAL/SAMPLESの数が圧倒的に減っています。また、ActiveRecord::Associations::JoinDependency#construct_modelはTOTAL/SAMPLESともに減っています。このことから、絞込んだことによってJOINのコストが大幅に減少し、速度が改善されたということが言えそうです。

select_all/find_by_sql

こちらはインスタンス生成やアプリ内でJOINの処理をしないので高速です。

プロファイリングの結果は以下の通り。

$ stackprof cpu-full-select_all.dump
==================================
  Mode: cpu(1000)
  Samples: 656 (4.65% miss rate)
  GC: 33 (5.03%)
==================================
     TOTAL    (pct)     SAMPLES    (pct)     FRAME
       506  (77.1%)         506  (77.1%)     Mysql2::Result#each
       226  (34.5%)         113  (17.2%)     ActiveRecord::Result#hash_rows
         2   (0.3%)           1   (0.2%)     Logger::LogDevice#write
         2   (0.3%)           1   (0.2%)     Mysql2::Client#query
         2   (0.3%)           1   (0.2%)     FSEvent#run
       115  (17.5%)           1   (0.2%)     ActiveRecord::Result#each
...

$ stackprof cpu-full-find_by_sql.dump
==================================
  Mode: cpu(1000)
  Samples: 1512 (3.08% miss rate)
  GC: 102 (6.75%)
==================================
     TOTAL    (pct)     SAMPLES    (pct)     FRAME
       513  (33.9%)         512  (33.9%)     Mysql2::Result#each
       201  (13.3%)         199  (13.2%)     Listen::Record::Entry#meta
       183  (12.1%)         183  (12.1%)     Listen::Record::Entry#_entries
      1030  (68.1%)         116   (7.7%)     ActiveSupport::Dependencies::Loadable#require
       108   (7.1%)         108   (7.1%)     ActiveRecord::Core#init_internals
       174  (11.5%)          87   (5.8%)     ActiveRecord::Result#hash_rows
        74   (4.9%)          74   (4.9%)     Listen::Record::Entry#real_path
        26   (1.7%)          26   (1.7%)     #<Module:0x007fc90cf7d5a0>.convert
        41   (2.7%)          14   (0.9%)     Module#delegate
        14   (0.9%)          14   (0.9%)     #<Module:0x007fc907427110>.mechanism
        11   (0.7%)          11   (0.7%)     ActiveRecord::LazyAttributeHash#initialize
       680  (45.0%)          10   (0.7%)     Listen::Record#_fast_build_dir
         7   (0.5%)           5   (0.3%)     ActiveRecord::Core::ClassMethods#allocate
         4   (0.3%)           4   (0.3%)     ActiveRecord::AttributeSet#initialize
        14   (0.9%)           4   (0.3%)     ActiveSupport::Dependencies::WatchStack#new_constants
       415  (27.4%)           3   (0.2%)     ActiveRecord::Result#each
...

select_allはインスタンス生成が走っておらず、find_by_sqlはインスタンス生成は走っているもののJOINの処理が無いことがわかります。SQLを直接書くということは可搬性も損ねかねないのと、可読性も悪くなるため導入する際は注意が必要です。

キャッシュ

言わずもがなだと思いますが、今回のベンチマークで一番高速でした。

ActiveRecordをキャッシュする場合はfind系以外の場合、遅延評価でクエリを実行するActiveRecord::Relationが返ってくるためto_aメソッドで配列化する必要があります。もしto_aなどで配列展開しない場合は実行クエリがキャッシュされるだけで、レコード自体はキャッシュされません。具体的には以下のようにしてキャッシュする必要があります。

content_types = Rails.cache.fetch("records") do
  ContentType.eager_load(contents: {comments: :author}).to_a
end

参考URL

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