ククログ

株式会社クリアコード > ククログ > Groongaのクエリーチューニングの方法

Groongaのクエリーチューニングの方法

Groongaのサポートサービスでは、お客さんから高速化したいクエリーとデータを提供してもらい、より高速に結果を返すようにクエリーをチューニングするという作業もしています。必要であればインデックスの追加・変更やスキーマの変更、Groongaの改良なども実施して高速化します。

クエリーチューニングは長年のカンで実施しているのではなくチューニングを支援するための手法を整備しながら実施しています。この記事では私達がやっているクエリーチューニングの方法をまとめます。ツール類はGroonga本体同様に自由なソフトウェアとして広く公開しているのでサポートサービスを契約していないGroongaユーザーでも同じ方法を使えます。

そういう情報は秘密にしてもっとサポートサービスを利用するように促すほうがいいんじゃないの？と考える人もいるかとは思いますが、クリアコードは情報を独占することで稼ぐのではなく情報を広く共有しながら稼ぎたいのでいいのです。

チューニングに必要な情報

効率的にチューニングをするには次の情報が必要です。

クエリーがどのように実行されたか（PostgreSQLやMySQLでいうEXPLAIN）
各処理にどのくらい時間がかかったか（PostgreSQLやMySQL 8.0ではEXPLAIN ANALYZEのactualのところで確認できるやつ）

Groongaでこれらの情報を取得するにはクエリーログを出力するようにします。PostgreSQLやMySQL 8.0のEXPLAIN ANALYZEのように特定のクエリーの実行計画および実行時間を返すコマンドは存在しません。あると便利かもなぁと思うこともありますがクエリーログでも十分便利なことと実装することが面倒ということでGroongaには実装されていません¹。

EXPLAIN ANALYZEスタイルよりもクエリーログスタイルの方が便利なことがあります。それは、プロダクション環境で実行されたクエリーでもチューニングに必要な情報を集めることができることです。PostgreSQLやMySQLにはスロークエリーを記録する機能がありますが、そのままでは遅かったクエリーがわかるだけで詳細はわかりません²。クエリーログには詳細も記録されます。

ただし、クエリーログには遅いクエリーのみ記録するという機能はないのですべてのクエリーが記録されることになります。そのため、大量にリクエストをさばいているサーバーでは結構な量になってしまいます。

ボトルネックの特定

基本的にチューニングは次の手順になります。

ボトルネックを特定する
ボトルネックを解消する
十分高速になったら終了、まだ遅かったら1.に戻って次のボトルネックに取り組む

そのため、クエリーログを取得したら次にやることはボトルネックの特定です。このときに役立つパッケージがgroonga-query-logです。この中にあるgroonga-query-log-analyzeを使います。

Groongaで遅いクエリーを手軽に特定する方法ではgroonga-query-log-analyzeのインストール方法や結果の見方を説明していますが、この記事ではgroonga-query-log-analyzeを使ったチューニングの流れを実際にチューニングしながら説明します。

ここで例にするデータのスキーマは次の通りです。実際にお客さんからクエリーチューニングを依頼されたデータを簡略化したものです。Contentsテーブルに検索対象のデータが入っていて、検索するために各種インデックスが用意されているという感じです。

# 参照型
table_create ContentsType TABLE_HASH_KEY Int64
table_create SearchData TABLE_HASH_KEY ShortText


# 検索対象のテーブル
table_create Contents TABLE_HASH_KEY ShortText
# 出力
column_create Contents title COLUMN_SCALAR ShortText
# 検索対象
column_create Contents contents_type COLUMN_SCALAR ContentsType
column_create Contents search_data COLUMN_VECTOR SearchData
column_create Contents site_flag COLUMN_SCALAR Int64


# 各種インデックス
column_create ContentsType contents_index COLUMN_INDEX Contents Int64
column_create SearchData contents_search_data COLUMN_INDEX Contents search_data

チューニング対象のクエリーは次の通りです。

select \
  --table Contents \
  --sort_keys -_score \
  --output_pretty yes \
  --output_columns _score,title \
  --match_columns search_data \
  --query "編集部" \
  --filter "in_values(contents_type,3,4,5,6,7,8)||(contents_type==1&&(site_flag&1)!=0)"

groonga-query-log-analyzeの結果は次の通りです³。見やすさのために一部重要でない部分は省略しています。

$ groonga-query-log-analyze --stream-all query.log
1) [2021-06-... (20.50484373)](0): select ...
  name: <select>
  parameters:
    <table>: <Contents>
    <sort_keys>: <-_score>
    <output_pretty>: <yes>
    <output_columns>: <_score,title>
    <match_columns>: <search_data>
    <query>: <編集部>
    <filter>: <in_values(contents_type,3,4,5,6,7,8)||(contents_type==1&&(site_flag&1)!=0)>
  1) 20.49961860:     select( 52396)
  2) 0.00473287:       sort(    10) -_score
  3) 0.00014068:     output(    10) _score,title
  4) 0.00034654:       send(  1847)

最初の行の(20.50...)の部分で20秒ほどかかっていることがわかります。具体的にどの処理がボトルネックかは最後の次の部分を見るとわかります。

  1) 20.49961860:     select( 52396)
  2) 0.00473287:       sort(    10) -_score
  3) 0.00014068:     output(    10) _score,title
  4) 0.00034654:       send(  1847)

selectの部分が20秒ほどかかっています。selectは検索処理の部分なので検索が遅いということです。

遅い処理がわかったらその中でも特になにが遅いかを絞り込みます。どうするかというと少しずつ処理を減らしていき速くなるかどうかをみます。処理を抜いて速くなったらそれがボトルネックだったということです。今回は検索処理が遅かったので検索処理から条件を抜いていきます。

今回の場合は条件は以下の4つです。

--query "編集部"
in_values(contents_type,3,4,5,6,7,8)
contents_type==1
(site_flag&1)!=0

条件が多い場合は条件を半分ずつ減らしながら確認します。端的に言うと2分探索で探します。文章で書くとわかりにくいのですが、たとえば、今回のように4つあるなら次のようにします。

まず前半の条件2つを除く（queryとin_valuesを除く）
1. 速くなった場合：除いた前半の条件の中にボトルネックがあるはず
2. 遅くなった場合：残した後半の条件の中にボトルネックがあるはず
1. 速くなった場合：除いた前半の条件の中のさらに前半半分（つまり1つ）を除く（queryを除く）
2. 遅くなった場合：残した後半の条件の中のさらに前半半分（つまり1つ）を除く（contents_typeを除く）
...（対象の条件が半分ずつになっていき、いずれどの条件がボトルネックかがわかる）...

ただ、今回のように条件が4つなら十分少ないので2分探索とかしないで1つずつ確認します。そっちのほうがすぐに終わるからです。

それでは先頭の条件から順番に除いて結果を見ていきましょう。まずは、queryを除きます。

select \
  --table Contents \
  --sort_keys -_score \
  --output_pretty yes \
  --output_columns _score,title \
  --filter "in_values(contents_type,3,4,5,6,7,8)||(contents_type==1&&(site_flag&1)!=0)"

$ groonga-query-log-analyze --stream-all query.log
...
  1) 9.62548430:     select(4162703)
  2) 0.37052584:       sort(    10) -_score
  3) 0.00020546:     output(    10) _score,title
  4) 0.00274467:       send(  1452)

10秒弱になりました。遅いですが、それでも2倍ほど速くなっています。

次はin_valuesを除いてみましょう。

select \
  --table Contents \
  --sort_keys -_score \
  --output_pretty yes \
  --output_columns _score,title \
  --match_columns search_data \
  --query "編集部" \
  --filter "(contents_type==1&&(site_flag&1)!=0)"

$ groonga-query-log-analyze --stream-all query.log
...
  1) 14.42021626:     select( 52396)
  2) 0.00482914:       sort(    10) -_score
  3) 0.00014181:     output(    10) _score,title
  4) 0.00040697:       send(  1847)

これだと15秒弱なので5秒速くなりました。

次はcontents_typeを除いてみましょう。

select \
  --table Contents \
  --sort_keys -_score \
  --output_pretty yes \
  --output_columns _score,title \
  --match_columns search_data \
  --query "編集部" \
  --filter "in_values(contents_type,3,4,5,6,7,8)||((site_flag&1)!=0)"

$ groonga-query-log-analyze --stream-all query.log
...
  1) 19.84345332:     select( 52396)
  2) 0.00493025:       sort(    10) -_score
  3) 0.00014939:     output(    10) _score,title
  4) 0.00041254:       send(  1847)

20秒弱なのでほぼ誤差です。

最後はsite_flagです。

select \
  --table Contents \
  --sort_keys -_score \
  --output_pretty yes \
  --output_columns _score,title \
  --match_columns search_data \
  --query "編集部" \
  --filter "in_values(contents_type,3,4,5,6,7,8)||(contents_type==1)"

$ groonga-query-log-analyze --stream-all query.log
...
  1) 0.06171758:     filter(202678) in_values(Contents.contents_type, 3, 4, 5, 6, 7, 8)
  2) 0.38215707:     filter(4162703) Contents.contents_type equal #<record:hash:ContentsType id:1 key:1>
  3) 0.34524652:     filter( 52396) (match columns) match "編集部"
  4) 0.00003017:     select( 52396)
  5) 0.07122897:       sort(    10) -_score
  6) 0.00020544:     output(    10) _score,title
  7) 0.00214134:       send(  1848)

1秒を切りました。site_flagがボトルネックということです。

また、当初は処理の詳細としてselectしか出ていなかったですが、今は各条件ごとにfilterも出ています。filterはその条件だけを使って絞り込んだときにでます。つまり、これまではすべての条件を一気に絞り込んでいて、今は各条件を個別に絞り込んでいるということです。

なお、絞り込み方には2種類あります。インデックスを使った絞り込みかインデックスを使わないシーケンシャルサーチでの絞り込みかです。どちらを使ったかはクエリーログからはわかりません。プロセスログにINFOレベルで記録されているので必要であればプロセスログを参照することになります。ただ、今の段階では確認する必要はありません。ボトルネックの特定作業でのポイントは絞り込みに注力することです。これはデバッグ力: よく知らないプログラムの直し方の進め方と同じです。詳細よりも注目すべきポイントを減らすことが大事です。

ボトルネックを特定したので次は特定したボトルネックを解消します。

ボトルネックの解消

ボトルネックの解消方法はボトルネックの種類によって変わります。たとえば、インデックスが使われておらずシーケンシャルサーチになっていて遅い場合はインデックスを使えるようにクエリーを変えたり必要なインデックスを追加したりします。そのため、ある程度Groongaの知識が必要になります。ただ、多くの場合はインデックスが足りないことが原因のことが多いでしょう。

今回はインデックスが足りないケースではありません。filterが出ていないことからGroongaのオプティマイザーが(site_flag&1)!=0をうまく処理できていない（個別の条件に分けられていない）ことが原因と考えられます。が、これはGroongaの開発に関わっている人でないと気づけないでしょう。。。こういう場合はサポートサービスやコミュニティーで相談することになります。その際、クエリーログを使って絞り込んだ結果およびその経緯を説明すると助けてもらいやすくなるのでボトルネックの特定作業はムダではありません！

実は、今のGroongaは(${カラム} ${演算子} ${値}) ${論理演算子} (${カラム} ${演算子} ${値} ${論理演算子} ...)というような条件式以外はうまく扱えないことが多いです。たとえば(site_flag&1)!=0というような(${カラム} ${演算子} ${値}) ${演算子} ${値}という形はうまく扱えません。そのため、${カラム} ${演算子} ${値}という形に変形する必要があります。

他にはGroongaを改良して(${カラム} ${演算子} ${値}) ${演算子} ${値}という形もうまく扱えるようにするというアプローチもあります。数値の各ビットをトークンに分解するトークナイザーを作ってビット位置をインデックスカラムのセクションに対応させてsite_flag @ 1とか書けるようにすればいける気がします⁴。

今回は条件式を${カラム} ${演算子} ${値}という形にするアプローチで対応します。お客さんに確認したところ、フラグは現時点で3つで今後増える可能性はあるが現時点で予定はないということでした。そのため、そんなに大量のフラグにはならなそうです。よって、各フラグごとに専用のBoolのカラムを作ってそれを使う形にします。GroongaはPostgreSQLやMySQLと違ってカラムナーなのでカラムの追加削除コストは低いです。そのため、フラグをカラムに分割する方法は現実的なアプローチの1つです。

現時点では1, 2, 4のみ利用しているということなので--load_tableを使って個別のカラムにわけます。

# フラグ1用
column_create Contents is_a COLUMN_SCALAR Bool
# フラグ2用
column_create Contents is_b COLUMN_SCALAR Bool
# フラグ3用
column_create Contents is_c COLUMN_SCALAR Bool

# site_flagカラムの値をis_a, is_b, is_cカラムに分割
select \
  --table Contents \
  --limit 0 \
  --load_table Contents \
  --load_columns "_key, is_a, is_b, is_c" \
  --load_values "_key, ((site_flag&1)!=0), ((site_flag&2)!=0), ((site_flag&4)!=0)"

Bool型はtrueかfalseしかとらないためインデックスを作っても速くならないことがあります。そのため、ここではインデックスを作らずに進めてみます。

(site_flag&1)!=0はis_a==trueに書き換えます。

select \
  --table Contents \
  --sort_keys -_score \
  --output_pretty yes \
  --output_columns _score,title \
  --match_columns search_data \
  --query "編集部" \
  --filter "in_values(contents_type,3,4,5,6,7,8)||(contents_type==1&&is_a==true)"

$ groonga-query-log-analyze --stream-all query.log
... (1.21...)...
...
  1) 0.39698719:     filter(3960025) Contents.contents_type equal #<record:hash:ContentsType id:1 key:1>
  2) 0.39545914:     filter(3960025) Contents.is_a equal true
  3) 0.02525579:     filter(4162703) in_values(Contents.contents_type, 3, 4, 5, 6, 7, 8)
  4) 0.32966184:     filter( 52396) (match columns) match "編集部"
  5) 0.00002792:     select( 52396)
  6) 0.06403390:       sort(    10) -_score
  7) 0.00017637:     output(    10) _score,title
  8) 0.00235876:       send(  1847)

各絞り込み処理は0.4秒以下、全体としては1.21秒になりました。まだ遅いですが、最初のボトルネックは解消できました。十分に速くなるまで次のボトルネックの特定→解消を続けていくことになります。

なお、↑まではデバッグビルドのGroongaで動かしていましたが、リリースビルドのGroongaで動かしたところ次のように0.5秒強になりました。

$ groonga-query-log-analyze --stream-all query.log
... (0.51...)...
...
  1) 0.14832385:     filter(3960025) Contents.contents_type equal #<record:hash:ContentsType id:1 key:1>
  2) 0.23101660:     filter(3960025) Contents.is_a equal true
  3) 0.01123953:     filter(4162703) in_values(Contents.contents_type, 3, 4, 5, 6, 7, 8)
  4) 0.10631706:     filter( 52396) (match columns) match "編集部"
  5) 0.00002999:     select( 52396)
  6) 0.02041890:       sort(    10) -_score
  7) 0.00014432:     output(    10) _score,title
  8) 0.00243412:       send(  1848)

まとめ

Groongaのサポートサービスでも使っているGroongaのクエリーチューニングの方法をまとめました。ざっくり言うと次の通りです。

再現環境を用意する
クエリーログとgroonga-query-log-analyzeを使ってボトルネックを特定する
特定したボトルネックを解消する
十分に高速になるまで2.と3.を繰り返す

Groongaを使っている人はこの方法を活用しつつGroonga本来の力を活用しきってください！

サポートサービスでは機能追加の要望に応えるということもしているのでEXPLAIN ANALYZEのようなコマンドが欲しいというお客さんがいたら実装すると思います。 ↩
PostgreSQLにはスロークエリーのEXPLAINを自動で取得するauto_explainというモジュールがあります。 ↩
実際はtail -F query.log | groonga-query-log-analyze --stream-allのようにクエリーログが追記されたらすぐに解析結果がでるようにして作業します。 ↩
Groongaの実装に詳しくないと何を言っているかわからないと思います。 ↩

ククログ

Groongaのクエリーチューニングの方法

チューニングに必要な情報

ボトルネックの特定

ボトルネックの解消

まとめ

関連情報