読者です 読者をやめる 読者になる 読者になる

shimada-kの日記

ソフトウェア・エンジニアのブログです

MySQLでインデックスが効いてないとつまりどうなるのか

Linuxカーネル バックエンド

MySQLでインデックスを使用しないクエリを投げると実際遅いことは分かるんですけど、マジックワード感があるのでなぜ遅くなるのか考えてみました。

すごく大きなテーブルを作ってインデックスを使用したSELECTとそうでないSELECTを投げてperfで調査しました。

環境

  • OS:Debian Squeeze (Kernel 2.6.32-5-amd64)
  • H/W:Corei5-3470T, Memory 16GB, SSD 120GB
  • perf:0.0.2.PERF

perfをインストールします

apt-get install google-perftools linux-tools-2.6.32

これでperfが動く環境になりました。次に実験用のテーブルを作りガツっとデータをINSERTします。今回使用するテーブルは下記のような構造にしました。1ユーザごとに100件のレコードを保持していることを想定して、100万ユーザ分のデータをINSERTすることにします。

mysql> DESC owning_muffins;
+------------+---------------------+------+-----+---------+----------------+
| Field      | Type                | Null | Key | Default | Extra          |
+------------+---------------------+------+-----+---------+----------------+
| id         | bigint(20) unsigned | NO   | PRI | NULL    | auto_increment |
| user_id    | bigint(20) unsigned | NO   |     | NULL    |                |
| flavor_id  | int(11)             | NO   |     | NULL    |                |
| blueberry  | tinyint(4)          | YES  |     | NULL    |                |
| strawberry | tinyint(4)          | YES  |     | NULL    |                |
| chocochip  | tinyint(4)          | YES  |     | NULL    |                |
| nuts       | tinyint(4)          | YES  |     | NULL    |                |
| created_at | datetime            | YES  |     | NULL    |                |
+------------+---------------------+------+-----+---------+----------------+
8 rows in set (0.00 sec)

INSERTするバッチ

require 'rubygems'
require 'mysql'

# insertData.rb
# データを大量にinsertするコード
# テーブルはユーザごとに100のデータを持っていることを想定
# ユーザは100万人とする
# insertするデータ数は100万×100で100000000

def insertData
    con = Mysql::connect('host', 'user', 'password', 'db_name')
    sql = 'SET NAMES utf8'
    con.query sql

    for user_id in 1..1000000 do
        for has_muffin in 1..100 do
            query_string = 'INSERT INTO owning_muffins (user_id, flavor_id, blueberry, strawberry, chocochip, nuts, created_at) values(' << user_id.to_s  << ',' << rand(10).to_s << ',' << rand(2).to_s << ',' << rand(2).to_s << ',' << rand(2).to_s << ',' << rand(2).to_s << ',\'' << Time.now.strftime("%Y-%m-%d %H:%M:%S") << '\');'
            # puts query_string
            con.query query_string
        end
    end
end

insertData()

バッチ終了後には100×100万で1億レコードのテーブルになります。

#ちなみにこのINSERTバッチ、実行完了まで丸2日かかりましたw

これでデータが入ったのでSELECTするバッチを実行してperfで計測します。

require 'rubygems'
require 'mysql'

# fetchData.rb
# データをselectするコード
# インデックスを効かせたselectか効かないselectか選択する
# 引数付きで実行するとインデックスを使用しない検索を行う

def fetchData(has_index = true)
    con = Mysql::connect('host', 'user', 'password', 'db_name')
    sql = 'SET NAMES utf8'
    con.query sql

    id = rand(100000000)
    user_id = rand(1000000)

    if has_index then
        ids = ''
        for id in 1..100 do
            if id == 100 then
                ids <<  (user_id * 100 + id).to_s
            else
                ids <<  (user_id * 100 + id).to_s << ','
            end
        end
        # puts ids
        query_string = 'SELECT * FROM owning_muffins WHERE id in (' << ids << ')'
    else
        query_string = 'SELECT * FROM owning_muffins WHERE user_id = ' << user_id.to_s
    end

    #puts query_string
    data = con.query query_string

    ret_array = Array.new

    while(record = data.fetch_hash())
        ret_array.push(record)
    end 

    # 標準出力に表示する
    # for i in 0..ret_array.length - 1 do
    #  puts ret_array[i]['id']
    # end
end

# 引数があればインデックスを無効にする
if ARGV[0] then
    has_index = false
else
    has_index = true
end

fetchData(has_index)

インデックスを使用したクエリをたたくものとインデックスをしないクエリをたたく2種類の計測を行いました。

MySQLがどんな風に子プロセスor子スレッドを作ってるか分からないのでシステム全体でイベントを計測します(-aオプションを使用する場合はrootにならないとダメです)。さらに誤差を考えてそれぞれ10回ずつ実行した平均をとります。計測コマンドは下記の通り。

# インデックスを使用した場合
perf stat -a -r 10 -e cpu-clock,task-clock,page-faults,cpu-migrations,L1-dcache-load-misses,L1-dcache-store-misses,L1-dcache-prefetch-misses,L1-icache-load-misses,L1-icache-prefetch-misses,LLC-load-misses,LLC-store-misses,LLC-prefetch-misses ruby fetchData.rb

# インデックスを使用しない場合
perf stat -a -r 10 -e cpu-clock,task-clock,page-faults,cpu-migrations,L1-dcache-load-misses,L1-dcache-store-misses,L1-dcache-prefetch-misses,L1-icache-load-misses,L1-icache-prefetch-misses,LLC-load-misses,LLC-store-misses,LLC-prefetch-misses ruby fetchData.rb hoge

計測結果です。まずはインデックスが効いている場合

score event
229.827713 cpu-clock-msecs
229.937963 task-clock-msecs
2676 page-faults
3 CPU-migrations
34293 L1-dcache-load-misses
1799415 L1-dcache-store-misses
559063 L1-dcache-prefetch-misses
1103446 L1-icache-load-misses
not counted L1-icache-prefetch-misses
1074416 LLC-load-misses
123611 LLC-store-misses
444980 LLC-prefetch-misses

実行にかかった時間は0.057323544秒でした(10回の平均値)

次はインデックスが効いていない場合

score event
115113.325665 cpu-clock-msecs
115114.371156 task-clock-msecs
4654 page-faults
40 CPU-migrations
11365832 L1-dcache-load-misses
1050214193 L1-dcache-store-misses
211685824 L1-dcache-prefetch-misses
53432908 L1-icache-load-misses
not counted L1-icache-prefetch-misses
164818024 LLC-load-misses
171005281 LLC-store-misses
119857977 LLC-prefetch-misses

実行にかかった時間は28.792978184秒でした(10回の平均値)

実行時間はおおよそ502倍になっています。最初io-waitが頻発してるのかと思っていましたがそうではなさそうです。cpu-clockと総実行時間から逆算したio-waitの時間が0に近いので他の要因であると考えます。

実行時間が502倍なのでインデックスが効いている場合の各値を502倍してインデックスが効いていない場合の数値と比較してみました。

#各数値が実行時間と正比例する前提の方法論なので乱暴ですが俯瞰して比較する際の指針にはなりえるかも、と考えました。

index_not_use / (502 * index_use) event
0.9971710235 cpu-clock-msecs
0.996701955 task-clock-msecs
0.003462475541 page-faults
0.02654514983 CPU-migrations
0.6598454059 L1-dcache-load-misses
1.161964851 L1-dcache-store-misses
0.7538370338 L1-dcache-prefetch-misses
0.09640602364 L1-icache-load-misses
not counted L1-icache-prefetch-misses
0.3054067844 LLC-load-misses
2.754221392 LLC-store-misses
0.5362569033 LLC-prefetch-misses

L1とLLC(ラスト・レベル・キャッシュ。今回使用したマシンは3次までCPUキャッシュがあるのでL3キャッシュのこと)のSTOREキャッシュミスが比較的多いことが分かります。なのでデータをキャッシングしておく際のオーバーヘッドが大きいようです。

  1. キャッシュを参照
  2. キャッシュに無い
  3. メモリか他のキャッシュからデータを取ってきて自分の所に保存

これを都度繰り返しているということになります。フルスキャンなのでそのようになるのでしょう。

#なぜL1キャッシュよりL3キャッシュのミスの方が割合が多いのかというのはプロセスマイグレーションの話とかCPUキャッシュのウェイ数とかが関係してきそうなのでこれ以上深追いはしたくない。