[Rails 4.0] 巨大なテーブルやserializeを使うときのActiveRecordオーバーヘッドを測定してみた

Railsは遅い!とよく言われますが、高速化ポイントのうち最有力候補の1つがDB/モデル周りです。
N+1問題を修正するだけでも、体感できるレベルの高速化が期待できます。

しかし、RubyKaigiでCookPadの方も言っていたように、RDBMSがSQLを実行する時間だけでなく、ActiveRecordオブジェクトの処理は非常に重いです。
モデル周りの最適化と聞いて、一生懸命SQLをEXPLAINするのも大事ですが、ログに出力される「Prefecture Load (0.5ms)」のような数値にはActiveRecordオブジェクト部分のオーバーヘッドが含まれていないため、全体でどの部分が遅いのかを理解しないと徒労に終わってしまう可能性があります。

よく言われる高速化のポイントとして

  • テーブルにカラムを増やしすぎると重いから、巨大なテーブルは分割すべし
  • serialize(や, ActiveRecord::Store)は遅いから使うな
  • pluckを使うと速い

などがありますが、実際に巨大なテーブルやserializeを使った場合、どの程度パフォーマンスに影響があるのか計測してみました。

もちろん、Rails 4で!

条件や環境

DBとモデル

今回使うモデルはこのようなものです。

Model1
nameだけのシンプルなモデル
Model2
256+1個のstringフィールドを持った巨大なモデル
Model3
Model2と同じテーブル構成で、すべてserializeしたもの
Model4
textカラムで長いserializeデータを入れられるもの
create_table :model1s do |t|
  t.string :name
end

create_table :model2s do |t|
  t.string :name
  (0..255).each do |i|
    t.string "name#{i}"
  end
end

create_table :model3s do |t|
  t.string :name
  (0..255).each do |i|
    t.string "name#{i}"
  end
end

create_table :model4s do |t|
  t.string :name
  t.text :data
end
class Model1 < ActiveRecord::Base
end

class Model2 < ActiveRecord::Base
end

class Model3 < ActiveRecord::Base
  (0..255).each do |i|
    serialize "data#{i}"
  end
end

class Model4 < ActiveRecord::Base
  serialize :data
end

測定方法

測定はすべて、rails consoleでBenchmark.measureしたものを掲載しています。
ばらつきを減らすため、3回ずつ測定しました。

環境は以下の通りです。

  • Ruby 2.0.0-p247
  • Ruby on Rails 4.0.0
  • SQLite3
  • Ubuntu 13.04 x86_x64
  • Core i7-4500U, RAM2GB (VM)

結果はBenchmark.measureのそのままなので、以下のようなフォーマットになります。

user system total (real)

rails consoleではログが標準出力に出てくるため、SQLを表示するとそこがオーバーヘッドになる可能性があります。今回は、development.rbでログレベルをinfoにし、SQLがログ出力されないようにしました。

config.log_level = :info

環境の違いについて

rails consoleはdevelopmentモードで起動していますが、同じ測定をproductionモードで実行しても、結果はほぼ同じでした。

DBをMySQLにする場合、InnoDBのmax row sizeに引っかかるので、カラム数を250位に減らしてencodingをlatin1にしてやる必要があります。
MySQLにすると、INSERT系の部分が1割ほど早くなることはありましたが、全体的な傾向は全く同じでした。

測定結果

new

まず、各モデルを1万回ずつnewしてみます。
DBには保存しません。

10000.times { Model1.new }
  0.600000   0.020000   0.620000 (  0.630955)
  0.520000   0.010000   0.530000 (  0.554211)
  0.610000   0.000000   0.610000 (  0.609702)

10000.times { Model2.new }
 21.030000   0.040000  21.070000 ( 21.312515)
 22.290000   0.100000  22.390000 ( 23.066587)
 23.690000   0.030000  23.720000 ( 23.846653)

10000.times { Model3.new }
 30.880000   0.010000  30.890000 ( 31.118914)
 30.920000   0.040000  30.960000 ( 31.395612)
 31.050000   0.120000  31.170000 ( 31.550993)

早速すごい差が出ました。
カラムが1個のModel1に比べ、257個のModel2では40倍近く遅くなっています。
serializeしたModel3は、データを何も入れなくても、さらに1.5倍ほど遅くなりました。

create

次に、各モデルを1000回ずつcreateしてみます。
newに加えて、validationやDBへの書き込みなどが発生します。

1000.times { Model1.create! name: 'HOGE' }
  3.420000   2.280000   5.700000 ( 13.391079)
  3.210000   2.380000   5.590000 ( 12.526155)
  2.970000   2.420000   5.390000 ( 11.630498)

1000.times { Model2.create! name: 'HOGE' }
 10.130000   2.400000  12.530000 ( 20.504972)
  8.270000   2.400000  10.670000 ( 16.984780)
  8.420000   2.520000  10.940000 ( 17.850486)

1000.times { Model3.create! name: 'HOGE' }
 26.470000   2.540000  29.010000 ( 37.193132)
 24.730000   2.520000  27.250000 ( 35.113511)
 24.850000   2.580000  27.430000 ( 34.312424)

おおざっぱに(real – total)がDB待ち時間と考えると、どのパターンでも大差なく8秒ほどがDB待ちになっています。
user時間では、Model2とModel3の差が大きくなっています。serializeカラムは、実際にはそのカラムがnilだとしても、保存時に大きな負荷になることがわかります。

params = { name: 'HOGE' }
(0..255).each { |i| params["data#{i}"] = i }

1000.times { Model2.create! params }
 32.010000   3.020000  35.030000 ( 42.856594)
 30.020000   2.800000  32.820000 ( 40.544360)
 34.010000   2.760000  36.770000 ( 44.144898)

1000.times { Model3.create! params }
139.150000   5.830000 144.980000 (153.915362)
136.440000   5.070000 141.510000 (150.696718)
136.450000   5.300000 141.750000 (151.109004)

今度はすべてのカラムに値を入れてみました。
どちらもデータが少ない場合に比べて遅くなっていますが、特にModel3の遅さが顕著です。serializeしたカラムは、値が入るとさらに大きな負荷がかかることがわかります。

find

次は、DBからデータを1件取得してみます。ID指定なので、DB側の負荷は少ないはずです。

# 事前にテーブルにはデータを1件だけ入れておく
# rake db:migrate:reset
Model1.create! name: 'HOGE'
Model2.create! name: 'HOGE'
Model3.create! name: 'HOGE'

10000.times { Model1.find(1) }
 10.590000   0.460000  11.050000 ( 11.103972)
 10.640000   0.460000  11.100000 ( 11.276034)
 10.470000   0.390000  10.860000 ( 10.997969)

10000.times { Model2.find(1) }
 28.690000   0.520000  29.210000 ( 29.436953)
 27.570000   0.540000  28.110000 ( 28.403855)
 28.990000   0.490000  29.480000 ( 29.817771)

10000.times { Model3.find(1) }
 41.590000   0.530000  42.120000 ( 42.496996)
 41.560000   0.540000  42.100000 ( 42.508387)
 42.140000   0.560000  42.700000 ( 43.247696)

Model1とModel2でまた大きな差が出ました。カラム数が増えればSELECT *で取得する件数も増えるので、単純に遅くなるのは理解できます。

そこで、SELECTするカラムを絞り込んでみましょう。

10000.times { Model1.select(:name).find(1) }
 10.200000   0.340000  10.540000 ( 10.632150)
 10.790000   0.450000  11.240000 ( 11.334411)
 11.070000   0.450000  11.520000 ( 11.797071)

10000.times { Model2.select(:name).find(1) }
 18.090000   0.360000  18.450000 ( 18.537357)
 19.590000   0.550000  20.140000 ( 20.405800)
 19.340000   0.390000  19.730000 ( 19.957142)

10000.times { Model3.select(:name).find(1) }
 21.910000   0.440000  22.350000 ( 22.616035)
 21.920000   0.410000  22.330000 ( 22.525840)
 21.540000   0.440000  21.980000 ( 22.149922)

うわあ微妙…
SELECTするカラムを絞っても、Model1と同じになるというわけではないみたいです。
ただ、serializeカラムを含まない状態でのfindだとModel2とModel3がほぼ同じになるのは興味深いですね。

それでは、速いと評判のpluckを使ってみましょう。

10000.times { Model1.pluck(:name) }
  8.410000   0.360000   8.770000 (  8.800651)
  8.540000   0.430000   8.970000 (  9.081969)
  8.400000   0.470000   8.870000 (  9.099462)

10000.times { Model2.pluck(:name) }
  8.150000   0.390000   8.540000 (  8.639425)
  8.460000   0.430000   8.890000 (  9.159416)
  8.360000   0.390000   8.750000 (  8.922662)

10000.times { Model3.pluck(:name) }
 12.090000   0.460000  12.550000 ( 12.801018)
 12.030000   0.490000  12.520000 ( 12.750606)
 12.070000   0.490000  12.560000 ( 12.808199)

そんな10倍も速くなるというほどではないですが、確かに高速化されています。
Model1とModel2が、同じ速度になりました。Modelオブジェクトをnewせず、SELECTも必要なカラムだけ実行するので、テーブルにいくつカラムがあっても影響ないようです。
ただModel3を見る限り、取得するカラムがserializeされていなくても、そのモデルにserializeカラムがあるだけで遅くなるみたいです。

pluckについて追記

08/13追記
比較対象のfindがnameにアクセスしていなくて不公平だったので、nameを評価したバージョンを追記しておきます。

10000.times { Model1.find(1).name }
 11.090000   0.420000  11.510000 ( 11.583137)
  9.730000   0.390000  10.120000 ( 10.191548)
 10.000000   0.290000  10.290000 ( 10.393030)

10000.times { Model2.find(1).name }
 29.110000   0.450000  29.560000 ( 29.826637)
 28.070000   0.370000  28.440000 ( 28.632295)
 28.380000   0.370000  28.750000 ( 29.052701)

10000.times { Model3.find(1).name }
 41.340000   0.420000  41.760000 ( 42.036065)
 42.110000   0.530000  42.640000 ( 43.228848)
 43.630000   0.530000  44.160000 ( 44.654895)

10000.times { Model1.select(:name).find(1).name }
 11.070000   0.400000  11.470000 ( 11.551049)
 11.620000   0.430000  12.050000 ( 12.187623)
 10.800000   0.410000  11.210000 ( 11.448768)

10000.times { Model2.select(:name).find(1).name }
 18.330000   0.400000  18.730000 ( 18.914217)
 18.140000   0.430000  18.570000 ( 18.680057)
 19.250000   0.440000  19.690000 ( 20.046789)

10000.times { Model3.select(:name).find(1).name }
 21.290000   0.380000  21.670000 ( 22.053869)
 20.440000   0.540000  20.980000 ( 21.202539)
 21.150000   0.470000  21.620000 ( 21.825256)

はい、完全に誤差の範囲内でした。

ついでなので、pluckが真価を発揮する(というか単に正しい使用方法)、大量データから特定カラムを取得する速度を見てみましょう。

# rake db:migrate:reset
# まずは100件のデータで小手調べ
100.times { Model1.create! name: 'HOGE' }

100.times { Model1.all.map(&:name) }
  0.830000   0.010000   0.840000 (  0.857858)
  0.820000   0.000000   0.820000 (  0.837119)
  0.810000   0.010000   0.820000 (  0.829982)

100.times { Model1.pluck(:name) }
  0.170000   0.000000   0.170000 (  0.167697)
  0.230000   0.000000   0.230000 (  0.230604)
  0.250000   0.000000   0.250000 (  0.258802)

# データ1000件で同じことをする
900.times { Model1.create! name: 'HOGE' }

100.times { Model1.all.map(&:name) }
 10.470000   0.020000  10.490000 ( 10.609048)
 10.570000   0.020000  10.590000 ( 10.670045)
 11.100000   0.040000  11.140000 ( 11.354826)

100.times { Model1.pluck(:name) }
  2.080000   0.030000   2.110000 (  2.188038)
  2.150000   0.010000   2.160000 (  2.178590)
  2.160000   0.010000   2.170000 (  2.193926)

# データ1万件で同じことをする
9000.times { Model1.create! name: 'HOGE' }

100.times { Model1.all.map(&:name) }
 90.960000   0.080000  91.040000 ( 91.983647)
 85.910000   0.060000  85.970000 ( 86.698406)
102.590000   0.230000 102.820000 (103.998012)

100.times { Model1.pluck(:name) }
 10.160000   0.100000  10.260000 ( 10.390672)
 14.050000   0.120000  14.170000 ( 14.542783)
 13.250000   0.010000  13.260000 ( 13.390256)

やはりこのケースでは、pluckの優位性が目立ちます。1万件では10倍近くの差が出ました。
先ほどの結果と合わせてみると、Model2やModel3ではより大きな差になることがわかります。

serializeのデータ量による差

最後に、serializeに大きいデータを入れるとどの程度変わるのか見てみましょう。

params = { name: 'HOGE' }

params[:data] = 'a'
1000.times { Model4.create! params }
  4.330000   2.380000   6.710000 ( 13.019374)
  4.620000   2.490000   7.110000 ( 13.991936)
  4.590000   2.410000   7.000000 ( 13.777286)

params[:data] = [1]
1000.times { Model4.create! params }
  4.400000   2.580000   6.980000 ( 14.922659)
  4.400000   2.350000   6.750000 ( 13.414692)
  4.310000   2.380000   6.690000 ( 13.555350)

params[:data] = (1..100).to_a
1000.times { Model4.create! params }
 10.580000   3.070000  13.650000 ( 21.245134)
 10.860000   2.990000  13.850000 ( 21.383432)
 11.020000   3.210000  14.230000 ( 21.944009)

params[:data] = (1..1000).to_a
1000.times { Model4.create! params }
 67.160000   3.040000  70.200000 ( 78.202392)
 67.920000   2.900000  70.820000 ( 78.956099)
 70.520000   3.080000  73.600000 ( 81.448431)

セットするデータが大きくなると、急激に遅くなっています。
長いとはいえ2カラムしかないテーブルで、1件挿入するのに80msもかかるのは軽くショックですね。

次に、findの速度を見てみます。

# rake db:migrate:reset

Model4.create!
10000.times { Model4.find(1) }
  9.890000   0.350000  10.240000 ( 10.310732)
 10.590000   0.370000  10.960000 ( 11.154107)
  9.950000   0.480000  10.430000 ( 10.588264)

Model4.find(1).update_attribute :data, [1]
10000.times { Model4.find(1) }
 10.220000   0.290000  10.510000 ( 10.573952)
 10.220000   0.420000  10.640000 ( 10.917978)
 10.400000   0.420000  10.820000 ( 11.114668)

Model4.find(1).update_attribute :data, (1..100).to_a
10000.times { Model4.find(1) }
 10.090000   0.400000  10.490000 ( 10.532497)
 10.260000   0.440000  10.700000 ( 10.952060)
 10.240000   0.430000  10.670000 ( 10.808926)

Model4.find(1).update_attribute :data, (1..1000).to_a
10000.times { Model4.find(1) }
 10.470000   0.330000  10.800000 ( 10.858970)
 10.400000   0.380000  10.780000 ( 11.011753)
 10.710000   0.460000  11.170000 ( 11.597594)

Model4.find(1).update_attribute :data, (1..10000).to_a
10000.times { Model4.find(1) }
 15.890000   0.430000  16.320000 ( 16.446115)
 15.990000   0.310000  16.300000 ( 16.413631)
 16.080000   0.520000  16.600000 ( 16.799734)

あれ、全然速度が変わりません。deserializeは超高速?

もちろんそんなことはなくて、findしても実際にそのカラムにアクセスするまではdeserializeが行われないのですね。
改めて、ちゃんと評価してみましょう。

# rake db:migrate:reset

Model4.create!
10000.times { Model4.find(1).data }
 10.550000   0.360000  10.910000 ( 11.168614)
 10.280000   0.390000  10.670000 ( 10.782972)
  9.970000   0.400000  10.370000 ( 10.448021)

Model4.find(1).update_attribute :data, [1]
10000.times { Model4.find(1).data }
 13.890000   0.480000  14.370000 ( 14.503605)
 13.630000   0.460000  14.090000 ( 14.238907)
 13.580000   0.390000  13.970000 ( 14.228241)

Model4.find(1).update_attribute :data, (1..100).to_a
10000.times { Model4.find(1).data }
 45.780000   0.490000  46.270000 ( 46.694700)
 45.350000   0.540000  45.890000 ( 46.240731)
 44.940000   0.540000  45.480000 ( 45.923395)

Model4.find(1).update_attribute :data, (1..1000).to_a
10000.times { Model4.find(1).data }
330.520000   0.810000 331.330000 (333.764699)
327.170000   0.670000 327.840000 (330.223176)
328.680000   0.910000 329.590000 (332.435454)

遅い、遅すぎる…
serializeカラムに長いデータが入っている場合、それをたくさんfindするのは現実的ではないようです。

「とりあえず便利そうだからserializeしたけど、WHEREで検索できなくて困った。全件取得してループで回してRuby側で検索しよう」という小学生メソッドでは、遅いどころかGateway Timeoutで死亡してしまいますね。

SQLを直接実行した場合

おまけとして、これらの検証結果と同じようなことを生SQLで実行してみました。

10000.times {
  ActiveRecord::Base.connection.execute(
    'SELECT name FROM model1s WHERE id = 1')
}
  2.930000   0.300000   3.230000 (  4.053164)
  3.060000   0.270000   3.330000 (  3.933746)
  3.070000   0.280000   3.350000 (  3.958062)

1000.times{
  ActiveRecord::Base.connection.execute(
    'INSERT INTO model1s SET name = "Hoge"')
}
  0.340000   0.110000   0.450000 (  3.312933)
  0.370000   0.030000   0.400000 (  2.651639)
  0.350000   0.140000   0.490000 (  3.199039)

比較するまでもありませんでした。
ちなみに、model2s, model3s, model4sのどのテーブルで実行しても速度はほぼ同じです。

まとめ

世間で言われる評判は正しかったです。

テーブルのカラム数が大きくなると、createやfindは非常に遅くなります。特にserializeなんかしていると目も当てられません。Userなど頻繁に使うのに肥大化しがちなテーブルでは注意が必要です。

今回は測定していませんが、scopeやassociationなどほかの要因でもモデルは複雑化していくので、pluckの優秀さが際立ちます。
たくさんのモデルオブジェクトをnewしないようにする注意が必要そうです。

カラムがとても多いテーブルでは、SELECTで絞るのもそれなりに有効です。ただ、257個を1個に絞ったところで2倍程度の速度向上だし、テーブルの肥大化で低下した速度を取り戻すほどではありません。
コーディングの複雑化を考えると、それよりはnewされる回数を減らす工夫をした方が効率が良い気がします。

SQLを生で実行すると、桁が違う速度が得られます。ただ、それを改めてモデルに入れていたら意味がないし、配列のまま扱うと何のためにRailsを使っているのかわからなくなってきます。

結局高速化は、効果のオーダーと手間や複雑さと増大といったコストのバランスを考慮し、費用対効果で判断するしかないですね。

Ruby on RailsによるWEBシステム開発、Android/iPhoneアプリ開発、電子書籍配信のことならお任せください この記事を書いた人と働こう! Ruby on Rails の開発なら実績豊富なBPS

この記事の著者

baba

ゆとりプログラマー。 高校時代から趣味でプログラミングを初め、そのままコードを書き続けて現在に至る。慶應義塾大学環境情報学部(SFC)卒業。BPS設立初期に在学中から参加している最古参メンバーの一人。得意分野はWeb全般、Ruby on Rails、Androidアプリケーションなど。最近はBlinkと格闘中。軽度の資格マニアで、情報処理技術者試験(高度10区分)などを保有。

babaの書いた記事

週刊Railsウォッチ

インフラ

BigBinary記事より

ActiveSupport探訪シリーズ