[pgsql-jp: 41473] Re: AutoCommitをfalseにするとレスポンスが遅くなる
kasaharatt ＠ nttdata.co.jp
kasaharatt ＠ nttdata.co.jp
2013年 7月 25日 (木) 14:31:56 JST
笠原です。
遅い方の実行計画はプラン中に$1や$2などが見えますので、値がバインドされる前の
汎用的な実行計画に見えます。
早い方の実行計画は、実際にバインドされた値でもって作成された実行計画に見えます。
Estimate cost を見る限り、双方で結構差があるので、実行時にブレやすい計画では
なさそうです。同じテーブル/条件句/条件値 ということであればGEQOの影響も考えにくいですね。
ちなみに、rowsやestimationを見ると、検索している対象のテーブルの状態(件数など)は、
確証はありませんが同じ様に見えます。
なので、SQLの早い遅いは、実際のBIND値を考慮された実行計画かどうかの違いで、
あとはそれがどこから来ているのか？ということか思います。
Autocommitのtrue/falseの違いで、バインドされるかどうかが変わるのでは？ということでしたが・・
一応手元の環境で、autocommitのtrue/false別にバインドの振る舞いが変わるかどうかを
PostgreSQL 9.1.9 & JDBC 9.2 でテストしてみましたが、特に変わりませんでした。
やはり、テストの方法やテストプログラム、環境を見直した方が良い気がします。
# コネクションプーリングの影響や、設定パラメータ、バインドする値やバインド時に
使用しているメソッド(setXXX)などです。
あまり有益な応答ができなくてすいません・・・
> -----Original Message-----
> From: pgsql-jp-bounces ＠ ml.postgresql.jp [mailto:pgsql-jp-bounces ＠ ml.postgresql.jp] On Behalf Of
> pascalpascal ＠ snow.plala.or.jp
> Sent: Wednesday, July 24, 2013 8:05 PM
> To: PostgreSQL Japanese Mailing List
> Subject: [pgsql-jp: 41470] Re: AutoCommitをfalseにするとレスポンスが遅くなる
>
> 宮本です。
>
> > 再度で申し訳ないのですがst.setPrepareThreshold(0)で試行すると、
> > もしかして良い実行計画になったりしませんか？
>
> st.setPrepareThreshold(0)でテストしてみましたが、
> 実行計画、レスポンスは変わりませんでした。
> （Nested Loopのままです。）
>
> 実行計画の内容は以下の通りです。
> SQLが長いので実行計画もかなり長いです。
> すみません。
>
> (1) 遅い方の実行計画
>
> Aggregate (cost=82031.28..82031.29 rows=1 width=0) (actual time=181560.059..181560.059 rows=1 loops=1)
> Buffers: shared hit=21159574
> -> Sort (cost=82031.26..82031.27 rows=1 width=879) (actual time=181559.897..181559.965 rows=920 loops=1)
> Sort Key: tablek.col1, tablek.col2
> Sort Method: quicksort Memory: 959kB
> Buffers: shared hit=21159574
> -> Nested Loop Left Join (cost=2.94..82031.25 rows=1 width=879) (actual time=576.622..181554.559
> rows=920 loops=1)
> Buffers: shared hit=21159572
> -> Nested Loop Left Join (cost=2.94..82022.94 rows=1 width=818) (actual time=576.607..181549.912
> rows=920 loops=1)
> Buffers: shared hit=21159572
> -> Nested Loop Left Join (cost=2.94..82014.65 rows=1 width=757) (actual
> time=576.604..181548.371 rows=920 loops=1)
> Buffers: shared hit=21159521
> -> Nested Loop Left Join (cost=2.94..82006.37 rows=1 width=696) (actual
> time=576.588..181543.650 rows=920 loops=1)
> Buffers: shared hit=21156761
> -> Nested Loop Left Join (cost=2.94..81998.08 rows=1 width=639) (actual
> time=576.568..181539.109 rows=920 loops=1)
> Buffers: shared hit=21154001
> -> Nested Loop Left Join (cost=2.94..81989.80 rows=1 width=578) (actual
> time=576.530..181533.225 rows=920 loops=1)
> Buffers: shared hit=21151240
> -> Nested Loop Left Join (cost=2.94..81981.44 rows=1 width=529)
> (actual time=576.491..181521.983 rows=920 loops=1)
> Buffers: shared hit=21147549
> -> Nested Loop Left Join (cost=2.94..81973.13 rows=1
> width=499) (actual time=576.429..181514.046 rows=920 loops=1)
> Join Filter: ((AA.colZ)::text = (tbl5.col3)::text)
> Buffers: shared hit=21143868
> -> Nested Loop (cost=2.94..81964.75 rows=1
> width=442) (actual time=576.390..181505.423 rows=920 loops=1)
> Join Filter: (((tablek.col2)::text =
> (table11.col2)::text) AND ((tablek.colP)::text = (max((table11.colP)::text))))
> Buffers: shared hit=21140187
> -> Nested Loop (cost=0.00..81961.67 rows=1
> width=417) (actual time=510.376..181495.747 rows=1766 loops=1)
> Buffers: shared hit=21140185
> -> Index Scan using index51 on table5 tbl5
> (cost=0.00..1433.91 rows=1 width=196) (actual time=0.045..22.643 rows=1318 loops=1)
> Index Cond: ((col3)::text =
> '6'::text)
> Filter: (((($1)::text = ''::text) OR
> ((col3)::text = ($2)::text)) AND ((($3)::text = ''::text) OR ((col5)::text = ($4)::text)) AND ((($5)::text = ''::text)
> OR ((col6)::text = ($6)::text)) AND ((($7)::text = ''::text) OR ((col7)::text = ($8)::text)) AND ((($9)::text = ''::text)
> OR ((colA)::text = ($10)::text)) AND ((($11)::text = ''::text) OR ((kd_kb)::text = ($12)::text)))
> Buffers: shared hit=1015
> -> Index Scan using index12 on table12
> tablek (cost=0.00..80527.74 rows=1 width=235) (actual time=128.886..137.679 rows=1 loops=1318)
> Index Cond: ((col1)::text =
> (tbl5.col1)::text)
> Filter: ((($13)::text = ''::text) OR
> ((col2)::text = ($14)::text))
> Buffers: shared hit=21139170
> -> HashAggregate (cost=2.94..2.98 rows=4
> width=11) (actual time=0.001..0.003 rows=8 loops=1766)
> Buffers: shared hit=2
> -> Seq Scan on table11 (cost=0.00..2.81
> rows=25 width=11) (actual time=0.038..0.053 rows=25 loops=1)
> Filter: ((col9)::text = '2'::text)
> Buffers: shared hit=2
> -> Index Scan using index3 on table3 AA
> (cost=0.00..8.36 rows=1 width=66) (actual time=0.007..0.007 rows=1 loops=920)
> Index Cond: ((colZ)::text = '6'::text)
> Buffers: shared hit=3681
> -> Index Scan using index2 on table2 BB (cost=0.00..8.30
> rows=1 width=45) (actual time=0.006..0.006 rows=1 loops=920)
> Index Cond: (((colS)::text = '6'::text) AND
> ((colS)::text = (tbl5.col3)::text) AND ((colB)::text = (tbl5.col5)::text))
> Buffers: shared hit=3681
> -> Index Scan using index6 on table6 KK (cost=0.00..8.34 rows=1
> width=65) (actual time=0.010..0.010 rows=1 loops=920)
> Index Cond: ((colG)::text = (tbl5.col6)::text)
> Buffers: shared hit=3691
> -> Index Scan using index9 on table9 k1 (cost=0.00..8.27 rows=1 width=68)
> (actual time=0.004..0.005 rows=1 loops=920)
> Index Cond: (((col4)::text = 'xxx'::text) AND ((colK)::text =
> (table11.col2)::text))
> Buffers: shared hit=2761
> -> Index Scan using index9 on table9 k2 (cost=0.00..8.27 rows=1 width=68)
> (actual time=0.003..0.003 rows=1 loops=920)
> Index Cond: (((col4)::text = 'aaa'::text) AND ((colK)::text =
> (tbl5.colA)::text))
> Buffers: shared hit=2760
> -> Index Scan using index9 on table9 k3 (cost=0.00..8.27 rows=1 width=68) (actual
> time=0.003..0.004 rows=1 loops=920)
> Index Cond: (((col4)::text = 'bbb'::text) AND ((colK)::text =
> (tbl5.kd_kb)::text))
> Buffers: shared hit=2760
> -> Index Scan using index9 on table9 k4 (cost=0.00..8.27 rows=1 width=68) (actual
> time=0.000..0.000 rows=0 loops=920)
> Index Cond: (((col4)::text = 'ccc'::text) AND ((colK)::text = (tbl5.colY)::text))
> Buffers: shared hit=51
> -> Index Scan using index9 on table9 k5 (cost=0.00..8.27 rows=1 width=68) (actual
> time=0.000..0.000 rows=0 loops=920)
> Index Cond: (((col4)::text = 'ddd'::text) AND ((colK)::text = (tbl5.col8)::text))
>
> ---------------------------------
> (2) 早い方の実行計画
>
> Aggregate (cost=113545.21..113545.22 rows=1 width=0) (actual time=576.520..576.521 rows=1 loops=1)
> Buffers: shared hit=31682
> -> Sort (cost=113543.34..113543.65 rows=125 width=879) (actual time=576.356..576.421 rows=920 loops=1)
> Sort Key: tablek.col1
> Sort Method: quicksort Memory: 959kB
> Buffers: shared hit=31682
> -> Hash Left Join (cost=5870.68..113538.99 rows=125 width=879) (actual time=229.277..573.663 rows=920
> loops=1)
> Hash Cond: ((tbl5.col8)::text = (k5.colK)::text)
> Buffers: shared hit=31680
> -> Hash Left Join (cost=5859.21..113523.43 rows=125 width=818) (actual time=229.246..572.006
> rows=920 loops=1)
> Hash Cond: ((tbl5.colY)::text = (k4.colK)::text)
> Buffers: shared hit=31677
> -> Hash Left Join (cost=5844.43..113507.86 rows=125 width=757) (actual
> time=229.228..571.575 rows=920 loops=1)
> Hash Cond: ((tbl5.kd_kb)::text = (k3.colK)::text)
> Buffers: shared hit=31674
> -> Nested Loop Left Join (cost=5826.46..113488.76 rows=125 width=696) (actual
> time=229.199..570.922 rows=920 loops=1)
> Buffers: shared hit=31671
> -> Nested Loop Left Join (cost=5826.46..113280.74 rows=125 width=639) (actual
> time=229.179..567.257 rows=920 loops=1)
> Buffers: shared hit=28911
> -> Nested Loop Left Join (cost=5826.46..112282.41 rows=125 width=590)
> (actual time=229.140..560.829 rows=920 loops=1)
> Join Filter: (((BB.colS)::text = (tbl5.col3)::text) AND
> ((BB.colB)::text = (tbl5.col5)::text))
> Buffers: shared hit=25220
> -> Hash Left Join (cost=5826.46..111503.33 rows=125 width=560)
> (actual time=228.844..518.031 rows=920 loops=1)
> Hash Cond: ((tbl5.col3)::text = (AA.colZ)::text)
> Buffers: shared hit=25146
> -> Hash Join (cost=5818.08..111493.23 rows=125 width=503)
> (actual time=228.766..517.403 rows=920 loops=1)
> Hash Cond: ((tablek.col1)::text = (tbl5.col1)::text)
> Buffers: shared hit=25141
> -> Nested Loop (cost=4500.17..109593.27 rows=154880
> width=321) (actual time=117.443..441.186 rows=502642 loops=1)
> Buffers: shared hit=24781
> -> Nested Loop Left Join (cost=0.00..11.29
> rows=1 width=97) (actual time=0.077..0.081 rows=1 loops=1)
> Join Filter: ((k1.colK)::text =
> (table11.col2)::text)
> Buffers: shared hit=6
> -> GroupAggregate (cost=0.00..3.00
> rows=1 width=11) (actual time=0.046..0.046 rows=1 loops=1)
> Buffers: shared hit=2
> -> Seq Scan on table11
> (cost=0.00..2.98 rows=3 width=11) (actual time=0.020..0.033 rows=3 loops=1)
> Filter: (((col2)::text =
> '3'::text) AND ((col9)::text = '2'::text))
> Buffers: shared hit=2
> -> Index Scan using index9 on table9 k1
> (cost=0.00..8.27 rows=1 width=68) (actual time=0.028..0.031 rows=1 loops=1)
> Index Cond: (((col4)::text =
> 'K0870'::text) AND ((colK)::text = '3'::text))
> Buffers: shared hit=4
> -> Bitmap Heap Scan on table12 tablek
> (cost=4500.17..107645.98 rows=154880 width=235) (actual time=117.358..286.140 rows=502642 loops=1)
> Recheck Cond: (((colP)::text =
> (max((table11.colP)::text))) AND ((col2)::text = '3'::text))
> Buffers: shared hit=24775
> -> Bitmap Index Scan on index12
> (cost=0.00..4461.45 rows=154880 width=0) (actual time=112.823..112.823 rows=502642 loops=1)
> Index Cond: (((colP)::text =
> (max((table11.colP)::text))) AND ((col2)::text = '3'::text))
> Buffers: shared hit=2337
> -> Hash (cost=1313.45..1313.45 rows=357 width=196)
> (actual time=5.184..5.184 rows=1318 loops=1)
> Buckets: 1024 Batches: 1 Memory Usage: 261kB
> Buffers: shared hit=360
> -> Bitmap Heap Scan on table5 tbl5
> (cost=11.11..1313.45 rows=357 width=196) (actual time=0.406..4.076 rows=1318 loops=1)
> Recheck Cond: ((col3)::text = '6'::text)
> Buffers: shared hit=360
> -> Bitmap Index Scan on index51
> (cost=0.00..11.02 rows=357 width=0) (actual time=0.347..0.347 rows=1318 loops=1)
> Index Cond: ((col3)::text =
> '6'::text)
> Buffers: shared hit=10
> -> Hash (cost=8.36..8.36 rows=1 width=66) (actual
> time=0.046..0.046 rows=1 loops=1)
> Buckets: 1024 Batches: 1 Memory Usage: 1kB
> Buffers: shared hit=5
> -> Index Scan using index3 on table3 AA
> (cost=0.00..8.36 rows=1 width=66) (actual time=0.042..0.042 rows=1 loops=1)
> Index Cond: ((colZ)::text = '6'::text)
> Buffers: shared hit=5
> -> Materialize (cost=0.00..473.18 rows=140 width=45) (actual
> time=0.000..0.011 rows=140 loops=920)
> Buffers: shared hit=74
> -> Index Scan using index2 on table2 BB (cost=0.00..472.48
> rows=140 width=45) (actual time=0.047..0.254 rows=140 loops=1)
> Index Cond: ((colS)::text = '6'::text)
> Buffers: shared hit=74
> -> Index Scan using index6 on table6 KK (cost=0.00..7.97 rows=1 width=65)
> (actual time=0.006..0.006 rows=1 loops=920)
> Index Cond: ((colG)::text = (tbl5.col6)::text)
> Buffers: shared hit=3691
> -> Index Scan using index9 on table9 k2 (cost=0.00..1.65 rows=1 width=68)
> (actual time=0.003..0.003 rows=1 loops=920)
> Index Cond: (((col4)::text = 'aaa'::text) AND ((colK)::text =
> (tbl5.colAb)::text))
> Buffers: shared hit=2760
> -> Hash (cost=17.92..17.92 rows=4 width=68) (actual time=0.018..0.018 rows=4
> loops=1)
> Buckets: 1024 Batches: 1 Memory Usage: 1kB
> Buffers: shared hit=3
> -> Bitmap Heap Scan on table9 k3 (cost=4.28..17.92 rows=4 width=68) (actual
> time=0.014..0.015 rows=4 loops=1)
> Recheck Cond: ((col4)::text = 'bbb'::text)
> Buffers: shared hit=3
> -> Bitmap Index Scan on index9 (cost=0.00..4.28 rows=4 width=0) (actual
> time=0.010..0.010 rows=4 loops=1)
> Index Cond: ((col4)::text = 'bbb'::text)
> Buffers: shared hit=2
> -> Hash (cost=14.75..14.75 rows=3 width=68) (actual time=0.008..0.008 rows=3 loops=1)
> Buckets: 1024 Batches: 1 Memory Usage: 1kB
> Buffers: shared hit=3
> -> Bitmap Heap Scan on table9 k4 (cost=4.27..14.75 rows=3 width=68) (actual
> time=0.004..0.004 rows=3 loops=1)
> Recheck Cond: ((col4)::text = 'ccc'::text)
> Buffers: shared hit=3
> -> Bitmap Index Scan on index9 (cost=0.00..4.27 rows=3 width=0) (actual
> time=0.003..0.003 rows=3 loops=1)
> Index Cond: ((col4)::text = 'ccc'::text)
> Buffers: shared hit=2
> -> Hash (cost=11.44..11.44 rows=2 width=68) (actual time=0.011..0.011 rows=2 loops=1)
> Buckets: 1024 Batches: 1 Memory Usage: 1kB
> Buffers: shared hit=3
> -> Bitmap Heap Scan on table9 k5 (cost=4.27..11.44 rows=2 width=68) (actual
> time=0.007..0.007 rows=2 loops=1)
> Recheck Cond: ((col4)::text = 'ddd'::text)
> Buffers: shared hit=3
> -> Bitmap Index Scan on index9 (cost=0.00..4.27 rows=2 width=0) (actual
> time=0.003..0.003 rows=2 loops=1)
> Index Cond: ((col4)::text = 'ddd'::text)
> Buffers: shared hit=2
>
> -------------------------------
> よろしくお願いします。
>
>
>
>
>
> ---- kasaharatt ＠ nttdata.co.jp さんは書きました:
> > 笠原です。
> >
> > > 試しに、同じJavaプログラムで、バインド変数を使わずに、
> > > where句の条件にすべて値を直接指定して、SQLを実行すると、
> > > 実行計画にhash joinが採用され、早くなることがわかりました。
> > これを見ると PrepareThreshold が影響しているように見えます・・
> >
> > 再度で申し訳ないのですがst.setPrepareThreshold(0)で試行すると、
> > もしかして良い実行計画になったりしませんか？
> >
> > PostgreSQL のJDBCは、PrepareThreshold の設定値(デフォルト 5)を以上の
> > 処理を同じPrepararedStatementに対して行うと、DB側で実行計画を
> > キャッシュして、以降はその実行計画で処理が行われます。
> >
> > つまり、PrepareThreshold の値未満の実行時は、毎回BIND値を考慮した
> > 実行計画でSQLが処理されます。毎回プランニングされます。
> > それ以降はどんなBIND値が来ても正しい結果が返るように、やや汎用的な
> > 実行計画が作成され、それを使いまわします。プランニングはスキップします。
> >
> > バインド変数を使わずに値を直接指定したSQLで良い実行計画になるということは、
> > おそらく上記の振る舞いが影響しているように思えます。
> >
> > > 推測ですが、autocommitをfalseにすると、実行計画でバインド変数の
> > > 中身が考慮されないと思われます。
> > Autocommitは特にバインド変数の考慮の有無には影響しないと思います。
> > コードも見てみましたが、特にバインド変数や実行計画に影響を及ぼしそうな
> > 処理はやってなさげです・・
> >
> > > -----Original Message-----
> > > From: pgsql-jp-bounces ＠ ml.postgresql.jp [mailto:pgsql-jp-bounces ＠ ml.postgresql.jp] On Behalf Of
> > > pascalpascal ＠ snow.plala.or.jp
> > > Sent: Wednesday, July 24, 2013 5:30 PM
> > > To: PostgreSQL Japanese Mailing List
> > > Subject: [pgsql-jp: 41468] Re: AutoCommitをfalseにするとレスポンスが遅くなる
> > >
> > > 宮本です。
> > >
> > > 実行計画の内容は今、準備中ですが、ひとつ情報があります。
> > >
> > > 試しに、同じJavaプログラムで、バインド変数を使わずに、
> > > where句の条件にすべて値を直接指定して、SQLを実行すると、
> > > 実行計画にhash joinが採用され、早くなることがわかりました。
> > > 推測ですが、autocommitをfalseにすると、実行計画でバインド変数の
> > > 中身が考慮されないと思われます。
> > >
> > > これはそういうものなんでしょうか？
> > > autocommitをfalseにして、SQLでバインド変数を
> > > 使用するのはよくありそうですが。。
> > >
> > > 実行計画の内容は少々お待ちください。。
> > >
> > > ---- kasaharatt ＠ nttdata.co.jp さんは書きました:
> > > > 笠原です。
> > > >
> > > > うーん、何でしょうね・・
> > > >
> > > > ちなみに、早い(hash joinが使われる)実行計画と遅い(nested loop joinが使われる)実行計画の
> > > > プランそのものを見せていただけたりしますか？
> > > > # できればEXPLAIN ANALYZEの結果があると嬉しいです。
> > > > テーブル名や列名、コンディションはマスクされてても良いかと・・
> > > >
> > > > > -----Original Message-----
> > > > > From: pgsql-jp-bounces ＠ ml.postgresql.jp [mailto:pgsql-jp-bounces ＠ ml.postgresql.jp] On Behalf Of
> > > > > pascalpascal ＠ snow.plala.or.jp
> > > > > Sent: Wednesday, July 24, 2013 1:30 PM
> > > > > To: PostgreSQL Japanese Mailing List
> > > > > Subject: [pgsql-jp: 41466] Re: AutoCommitをfalseにするとレスポンスが遅くなる
> > > > >
> > > > > mlusさん、笠原さん
> > > > >
> > > > > 宮本です。
> > > > > ご連絡ありがとうございます。
> > > > >
> > > > > > Connection.setReadOnly(true) とか
> > > > > > createStatement(ResultSet.TYPE_FORWARD_ONLY,
> > > > > > ResultSet.CONCUR_READ_ONLY ,
> > > > > > ResultSet.HOLD_CURSORS_OVER_COMMIT)
> > > > > >
> > > > > > みたいな感じで、Statementの調整とかもありますが、関係ないですかね。
> > > > >
> > > > > Connection.setReadOnly(true)をしたり、Commitしてみましたが、結果は
> > > > > 変わりませんでした。（遅い）
> > > > >
> > > > > > もしそうであれば、ExecuteQuery前に
> > > > > > st.setPrepareThreshold(1)
> > > > > > を実行して、プランを比較してみていただけませんか？
> > > > >
> > > > > PrepareThresholdはデフォルト値のままでしたので、
> > > > > st.setPrepareThreshold(1)を実行し、SQLを３回実行して
> > > > > 比較してみました。
> > > > > が、残念ながら、３回ともレスポンス、実行計画は
> > > > > 変わりませんでした。（遅いまま）
> > > > >
> > > > > 1回目：182080 msec
> > > > > 2回目：182218 msec
> > > > > 3回目：182006 msec
> > > > >
> > > > > 追加情報なのですが、以下のように、Javaで実行するSQLに
> > > > > "explain analyze"をつけて実行すると、レスポンスは早くなり、
> > > > > explainの結果で出力される実行計画も"hash join"が使用されます。
> > > > > （期待通りの実行計画になります。）
> > > > >
> > > > > String sql = "explain analyze SELECT COUNT(*) FROM (SELECT A,B・・・ （省略）"
> > > > >
> > > > > よろしくお願いします。
> > > > >
> > > > > 以上
> > > > >
> > > > > ---- kasaharatt ＠ nttdata.co.jp さんは書きました:
> > > > > > 笠原と申します。
> > > > > >
> > > > > > >> Q1 SQL分の実行には、StatementとPreparedStatementのどちらを使ったでしょうか。
> > > > > > >
> > > > > > > PreparedStatementを使用しています。
> > > > > > > String sql = "SELECT COUNT(*) FROM (SELECT A,B・・・ （省略）"
> > > > > > > PreparedStatement st = conn.prepareStatement(sql);
> > > > > > PrepareThreshold はデフォルト値でしょうか？
> > > > > >
> > > > > > もしそうであれば、ExecuteQuery前に
> > > > > > st.setPrepareThreshold(1)
> > > > > > を実行して、プランを比較してみていただけませんか？
> > > > > > # できればst.setPrepareThreshold(1)設定後に3回程度連続でSQLを実行してみて欲しいです。
> > > > > >
> > > > > > もしかしたら PrepareThreshold が影響しているかもしれません・・
> > > > > > http://jdbc.postgresql.org/documentation/head/server-prepare.html
> > > > > >
> > > > > >
> > > > > > > -----Original Message-----
> > > > > > > From: pgsql-jp-bounces ＠ ml.postgresql.jp [mailto:pgsql-jp-bounces ＠ ml.postgresql.jp] On Behalf Of
> > > > > > > pascalpascal ＠ snow.plala.or.jp
> > > > > > > Sent: Wednesday, July 24, 2013 10:33 AM
> > > > > > > To: PostgreSQL Japanese Mailing List
> > > > > > > Subject: [pgsql-jp: 41463] Re: AutoCommitをfalseにするとレスポンスが遅くなる
> > > > > > >
> > > > > > > MauMauさん
> > > > > > >
> > > > > > > ご連絡ありがとうございます。
> > > > > > >
> > > > > > > > 問い合わせ計画は自動コミットが有効かどうかによって変わらないように思うのですが、次のことを教えてくださ
> い。
> > > > > > >
> > > > > > > 私も変わらないと思っていましたので、今回の現象は驚いています。
> > > > > > >
> > > > > > > > Q1 SQL分の実行には、StatementとPreparedStatementのどちらを使ったでしょうか。
> > > > > > >
> > > > > > > PreparedStatementを使用しています。
> > > > > > >
> > > > > > > String sql = "SELECT COUNT(*) FROM (SELECT A,B・・・ （省略）"
> > > > > > > PreparedStatement st = conn.prepareStatement(sql);
> > > > > > >
> > > > > > > > Q2 setAutoCommit()で自動コミットを有効/無効にしたそれぞれの場合で、まったく同じSQL分を実行されているで
> しょ
> > > うか。
> > > > > > >
> > > > > > > SQL、where句の定数、バインド変数の値もまったく同じです。
> > > > > > >
> > > > > > > バインド変数は、例えば、
> > > > > > > st.setObject(1, "00060000");
> > > > > > > のような感じで指定しています。
> > > > > > >
> > > > > > > 簡単にいうと、同じプログラムで、
> > > > > > > conn.setAutoCommit(false) を入れるか、入れないかで、
> > > > > > > レスポンス、実行計画が違います。
> > > > > > >
> > > > > > > > Q3 それぞれの場合において、テーブル内のデータや統計情報に違いはなかったでしょうか。
> > > > > > >
> > > > > > > AutoCommit(false)ありのプログラムを実行したすぐ後に
> > > > > > > AutoCommit(false)なしのプログラムを実行しても、
> > > > > > > レスポンスや実行計画が違います。getAutoCommit()して
> > > > > > > 確認していますが、AutoCommit(false)なしの場合はtrueになっています。
> > > > > > > 実行計画はauto_explain.log_min_durationを設定して、Postgresqlログで
> > > > > > > 確認しています。
> > > > > > >
> > > > > > > アプリの仕様上、AutoCommitはfalseにしないといけないので、
> > > > > > > AutoCommitはfalseにしたままで、この問題を解決できるような
> > > > > > > 回避策がないかと思っています。
> > > > > > >
> > > > > > > よろしくお願いします。
> > > > > > >
> > > > > > > ---- MauMau <maumau307 ＠ gmail.com> さんは書きました:
> > > > > > > > MauMauといいます。
> > > > > > > >
> > > > > > > > 問い合わせ計画は自動コミットが有効かどうかによって変わらないように思うのですが、次のことを教えてくださ
> い。
> > > > > > > >
> > > > > > > > Q1 SQL分の実行には、StatementとPreparedStatementのどちらを使ったでしょうか。
> > > > > > > >
> > > > > > > > Q2 setAutoCommit()で自動コミットを有効/無効にしたそれぞれの場合で、まったく同じSQL分を実行されているで
> しょ
> > > うか。
> > > > > > > > 同じとは、WHERE句などで指定する定数や、PreparedStatement#setXXX()で
> > > > > > > > 設定する値も完全に一致する、ということです。
> > > > > > > >
> > > > > > > > Q3 それぞれの場合において、テーブル内のデータや統計情報に違いはなかったでしょうか。
> > > > > > > >
> > > > > > > >
> > > > > > > > 以上です。
> > > > > > > >
> > > > > > > > ----- Original Message -----
> > > > > > > > From: <pascalpascal ＠ snow.plala.or.jp>
> > > > > > > > To: <pgsql-jp ＠ ml.postgresql.jp>
> > > > > > > > Sent: Tuesday, July 23, 2013 5:29 PM
> > > > > > > > Subject: [pgsql-jp: 41453] AutoCommitをfalseにするとレスポンスが遅くなる
> > > > > > > >
> > > > > > > >
> > > > > > > > > 宮本と申します。
> > > > > > > > >
> > > > > > > > > 現在、PostgreSQL(9.1.6)を運用しております。
> > > > > > > > >
> > > > > > > > > jdbc経由でPostgresqlに接続して、selectを実行するJavaのプログラムで
> > > > > > > > > レスポンスが遅いという現象があり、調査したところ、
> > > > > > > > > AutoCommitをfalseにすると、遅いということがわかりました。
> > > > > > > > >
> > > > > > > > > AutoCommitをfalseにすると実行計画も違います。長いSQL文で結合が多く、
> > > > > > > > > データ件数も多いため、Hash joinを使った方が早いのですが、
> > > > > > > > > AutoCommitをfalseにすると、なぜか、Nested Loopが使われてしまいます。
> > > > > > > > >
> > > > > > > > > AutoCommit レスポンス 実行計画
> > > > > > > > > ---------------------------------------------
> > > > > > > > > false 遅い（約3分） Nested loop
> > > > > > > > > true 早い（約6秒） Hash join
> > > > > > > > >
> > > > > > > > > 環境
> > > > > > > > > OS: Redhat Enterprise Linux 5.7
> > > > > > > > > PostgreSQL: 9.1.6
> > > > > > > > > jdbc: postgresql-9.1-901.jdbc3.jar
> > > > > > > > > （jdbcをpostgresql-9.1-903.jdbc3.jarやpostgresql-9.2-1003.jdbc3.jarにしても同じでした。）
> > > > > > > > >
> > > > > > > > > これは仕様なのでしょうか。
> > > > > > > > > それともバグなのでしょうか。
> > > > > > > > > ネット上でいろいろ調べましたが、わかりませんでした。
> > > > > > > > > どなたか情報をお持ちの方は教えていただけないでしょうか。
> > > > > > > > > よろしくお願いします。
> > > > > > > > >
> > > > > > > >
> > > > > >
> > > >
> >
pgsql-jp メーリングリストの案内