[pgsql-jp: 41926] Re: 【質問】サブクエリを使った検索文の実行時間短縮について

[TAKATSUKA Haruka]

こんにちは。JPUG の高塚です。

ヒット件数が 1. は 177件、 2. は 4321件なのですよね。
検索時間の差異はヒット件数に由来するように見えます。
2. では、1回平均 6.168ms を要する検索を 1904回ループ繰り返しする処理に
なっていることで時間を要しています。

SQLやプランを改善するアイデアは何かありそうですが、少なくとも
pgbigmによるインデックスキーワード検索自体の問題ということでは
なさそうです。


On Wed, 29 Mar 2017 02:51:08 +0900
<toshio_uchiyama ＠ mirror.ocn.ne.jp> wrote:

> 　PostgreSQL 9.4.4 とpg-bigm 1.1 を用いた
> 全文検索エンジンで、条件語
> 
> 1. スポーツ　と　テニス　の両方を含む
> 2. ありがとう　と　感謝　の両方を含む
> 
> を変更しただけの同一検索文
> （サブクエリを用いている）で実行時間に差が
> でています。1 の条件語での検索が 1 秒程度で
> 2 の検索語での検索が11秒程度です。
> どちらも 1 秒程度だと助かります。
> 　テーブルは、変な名前ですが manual という名前で
> ビデオの字幕を登録したものです。
> 
> カラム	データ型
> id	bigint
> theme	text
> video	text
> starttime	numeric(10,3)
> endtime	numeric(10,3)
> content	text
> track	bigint
> userid	text
> eng_conv	integer
> time	timestamp without time zone
> 
> の10列です。theme がビデオ名です。video が
> ビデオの id です。starttimeとendtime が字幕の
> 開始時間と終了時間です。content が字幕です。
> track は字幕番号です。userid が登録者の
> ユーザーID です。eng_conv は英会話動画の
> フラグです。time が登録時刻です。複数の字幕に
> 同じ video ID とトラック番号がついています。
> 　インデックスは、
> 
> manual_pkey
> CREATE UNIQUE INDEX manual_pkey ON manual USING btree (id)
> manual_eng_conv_idx
> CREATE INDEX manual_eng_conv_idx ON manual USING btree (eng_conv)
> manual_lower_gin_content_idx
> CREATE INDEX manual_lower_gin_content_idx ON manual USING gin
> (lower(content) gin_bigm_ops)
> manual_lower_gin_theme_idx
> CREATE INDEX manual_lower_gin_theme_idx ON manual USING gin (lower(theme)
> gin_bigm_ops)
> manual_track_idx
> CREATE INDEX manual_track_idx ON manual USING btree (track)
> manual_video_idx
> CREATE INDEX manual_video_idx ON manual USING btree (video)
> 
> の6つを付けています。
> 
> 1　の検索語の場合の explain analyze が
> moovle=# explain analyze select * from manual where lower( content ) like
> lower( '%スポーツ%') and video in ( select distinct video from manual where
> lower( content ) like lower( '%テニス%' ));
> 
> QUERY PLAN
> ----------------------------------------------------------------------------
> ----------------------------------------------------------------------------
> --
> Nested Loop  (cost=8749.96..8936.05 rows=1 width=185) (actual
> time=4.825..202.034 rows=177 loops=1)
>    ->  HashAggregate  (cost=8660.73..8660.76 rows=3 width=12) (actual
> time=0.712..0.764 rows=193 loops=1)
>          Group Key: manual_1.video
>          ->  Bitmap Heap Scan on manual manual_1  (cost=52.50..8651.86
> rows=3549 width=12) (actual time=0.131..0.615 rows=327 loops=1)
>                Recheck Cond: (lower(content) ~~ '%テニス%'::text)
>                Heap Blocks: exact=233
>                ->  Bitmap Index Scan on manual_lower_gin_content_idx
> (cost=0.00..51.62 rows=3549 width=0) (actual time=0.104..0.104 rows=327
> loops=1)
>                      Index Cond: (lower(content) ~~ '%テニス%'::text)
>    ->  Bitmap Heap Scan on manual  (cost=89.23..91.74 rows=1 width=185)
> (actual time=1.040..1.041 rows=1 loops=193)
>          Recheck Cond: ((video = manual_1.video) AND (lower(content) ~~ '%ス
> ポーツ%'::text))
>          Heap Blocks: exact=113
>          ->  BitmapAnd  (cost=89.23..89.23 rows=1 width=0) (actual
> time=1.038..1.038 rows=0 loops=193)
>                ->  Bitmap Index Scan on manual_video_idx  (cost=0.00..26.47
> rows=1454 width=0) (actual time=0.119..0.119 rows=846 loops=193)
>                      Index Cond: (video = manual_1.video)
>                ->  Bitmap Index Scan on manual_lower_gin_content_idx
> (cost=0.00..61.62 rows=3549 width=0) (actual time=0.913..0.913 rows=1606
> loops=193)
>                      Index Cond: (lower(content) ~~ '%スポーツ%'::text)
>  Planning time: 0.305 ms
>  Execution time: 202.111 ms
> (18 行)
> 
> 2 の検索語の explain analyze が
> moovle=# explain analyze select content from manual where lower( content )
> like lower( '%ありがとう%' ) and video in ( select video from manual where
> lower( content ) like lower( '%感謝%' ));
> 
> QUERY PLAN
> ----------------------------------------------------------------------------
> ----------------------------------------------------------------------------
> ----
> Nested Loop  (cost=8748.89..8952.81 rows=596 width=48) (actual time=69.371..
> 11769.517 rows=4321 loops=1)
>    ->  HashAggregate  (cost=8650.73..8650.76 rows=3 width=12) (actual
> time=20.822..21.578 rows=1904 loops=1)
>          Group Key: manual_1.video
>          ->  Bitmap Heap Scan on manual manual_1  (cost=42.50..8641.86
> rows=3549 width=12) (actual time=4.855..16.387 rows=4541 loops=1)
>                Recheck Cond: (lower(content) ~~ '%感謝%'::text)
>                Heap Blocks: exact=3647
>                ->  Bitmap Index Scan on manual_lower_gin_content_idx
> (cost=0.00..41.62 rows=3549 width=0) (actual time=3.041..3.041 rows=4541
> loops=1)
>                      Index Cond: (lower(content) ~~ '%感謝%'::text)
>    ->  Bitmap Heap Scan on manual  (cost=98.16..100.67 rows=1 width=60)
> (actual time=6.165..6.168 rows=2 loops=1904)
>          Recheck Cond: ((video = manual_1.video) AND (lower(content) ~~ '%あ
> りがとう%'::text))
>          Rows Removed by Index Recheck: 0
>          Heap Blocks: exact=2986
>          ->  BitmapAnd  (cost=98.16..98.16 rows=1 width=0) (actual
> time=6.158..6.158 rows=0 loops=1904)
>                ->  Bitmap Index Scan on manual_video_idx  (cost=0.00..25.40
> rows=1454 width=0) (actual time=0.115..0.115 rows=797 loops=1904)
>                      Index Cond: (video = manual_1.video)
>                ->  Bitmap Index Scan on manual_lower_gin_content_idx
> (cost=0.00..71.62 rows=3549 width=0) (actual time=6.005..6.005 rows=16570
> loops=1904)
>                      Index Cond: (lower(content) ~~ '%ありがとう%'::text)
>  Planning time: 1.660 ms
>  Execution time: 11769.988 ms
> (19 行)
> 
> です。explain analyze で見たときの両者の違いは、
> Rows Removed by Index Recheck: 0
> です。これによって、実行時間にこんなに差が出るでしょうか。