[pgsql-jp: 41476] Re: AutoCommitをfalseにするとレスポンスが遅くなる
kasaharatt ＠ nttdata.co.jp
kasaharatt ＠ nttdata.co.jp
2013年 7月 25日 (木) 20:26:04 JST
笠原です。
> 気になるのは、遅い方（AutoCommit=false）は、"execute S_2/C_3"
> のように、prepare文に名前がついていることです。
名前付準備文が使われていますね。
コネクションプーリングの影響か、あるいは同セッションで以前に作成された
PreparedStatementが再利用されている気がします。
> org.postgresql.PGStatement pgstmt = (org.postgresql.PGStatement)st;
> pgstmt.setPrepareThreshold(0);
上記の閾値セットですが、setObject()前に実施してください。
具体的には
PreparedStatement st = conn.prepareStatement(sql);
の直後です。
> -----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: Thursday, July 25, 2013 6:41 PM
> To: PostgreSQL Japanese Mailing List
> Subject: [pgsql-jp: 41475] Re: AutoCommitをfalseにするとレスポンスが遅くなる
>
> 笠原さん、MauMauさん
>
> 宮本です。
>
> 情報ありがとうございます。
>
> > そのため、9.2にアップグレードすることが解決方法の１つだと考えます。
>
> 何となくですが、これのような気がしますね。
> 少し時間がかかりますが、テストしてみます。
>
> > サーバ側にバインド変数を含むSQL文が送られているかどうか、つまり、
> > SQL文中に$1などが含まれるかどうかを見ます。
>
> ログを確認しましたが、
> バインド変数は早い方も遅い方もSQL文の中に出力されていました。
> （SQL文が長いので、ここでは省略していますが、実際のログには
> 出力されていました。）
> 気になるのは、遅い方（AutoCommit=false）は、"execute S_2/C_3"
> のように、prepare文に名前がついていることです。
>
> 早い方(AutoCommit=true)は、execute <unnamed> になっています。
>
> ■遅い方
>
> 2013-07-24 16:18:22 JST 11503 LOG: execute S_1: BEGIN
> 2013-07-24 16:18:22 JST 11503 LOG: execute S_2/C_3: SELECT COUNT(*) FROM ( SELECT ・・・
> 2013-07-24 16:18:22 JST 11503 DETAIL: parameters: $1 = '00060000', $2 = '00060000', $3 = '', $4 = '', $5 = '', $6 = '',
> $7 = '', $8 = '', $9 = '', $10 = '', $11 = '', $12 = '', $13 = '3', $14 = '3'
>
> ■早い方
>
> 2013-07-24 16:25:09 JST 14734 LOG: execute <unnamed>: SELECT COUNT(*) FROM ( SELECT ・・・
> 2013-07-24 16:25:09 JST 14734 DETAIL: parameters: $1 = '00060000', $2 = '00060000', $3 = '', $4 = '', $5 = '', $6 = '',
> $7 = '', $8 = '', $9 = '', $10 = '', $11 = '', $12 = '', $13 = '3', $14 = '3'
>
>
> プログラムソースは以下の通りです。setPrepareThresholdはテストで入れたものです。
>
> ----------------------------------------------------------------------import java.io.File;
> import java.sql.*;
> import java.util.Properties;
> import java.util.List;
> import org.postgresql.PGStatement.*;
>
>
> public class Test2online3ac {
>
> public static void main(String[] args) {
> try {
> Class.forName("org.postgresql.Driver");
> Connection conn = DriverManager.getConnection("jdbc:postgresql://localhost:xxxxx/xxxxx",
> "xxxxx", "xxxxx");
>
> conn.setAutoCommit(false);
>
> String sql = "SELECT COUNT(*) FROM ( SELECT ・・・省略
>
> PreparedStatement st = conn.prepareStatement(sql);
> st.setFetchSize(1000);
> st.setObject(1, "00060000");
> st.setObject(2, "00060000");
> st.setObject(3, "");
> st.setObject(4, "");
> st.setObject(5, "");
> st.setObject(6, "");
> st.setObject(7, "");
> st.setObject(8, "");
> st.setObject(9, "");
> st.setObject(10, "");
> st.setObject(11, "");
> st.setObject(12, "");
> st.setObject(13, "3");
> st.setObject(14, "3");
>
> System.out.println("AutoCommit is "+conn.getAutoCommit());
>
> org.postgresql.PGStatement pgstmt = (org.postgresql.PGStatement)st;
> pgstmt.setPrepareThreshold(0);
>
> long stime = System.currentTimeMillis();
> st.executeQuery();
> conn.commit();
> long etime = System.currentTimeMillis();
> System.out.println("経過時間：" + (etime - stime));
>
> st.close();
>
> conn.close();
>
> } catch (Throwable t) {
> t.printStackTrace();
> }
> }
>
> }
>
>
> 以上
>
> ---- MauMau <maumau307 ＠ gmail.com> さんは書きました:
> > MauMauです。
> >
> > > 遅い方の実行計画はプラン中に$1や$2などが見えますので、値がバインドされる前の
> > >
> > > 汎用的な実行計画に見えます。
> > > 早い方の実行計画は、実際にバインドされた値でもって作成された実行計画に見えます。
> >
> > PostgreSQL 9.1までは、問い合わせ計画の作成時にはバインド変数の値は使われません。
> >
> > 汎用的な問い合わせ計画が作成されます。
> > 今回の場合、それがnested loopだったのでしょう。
> >
> > PostgreSQL 9.2からは、次のように、バインド変数の値が使われるようになりました。
> >
> > そのため、9.2にアップグレードすることが解決方法の１つだと考えます。
> > 可能であれば、おためしいただいた結果を共有いただけると幸いです。
> >
> > http://www.postgresql.org/docs/current/static/release-9-2.html
> > Allow the planner to generate custom plans for specific parameter values
> > even when using prepared statements (Tom Lane)
> > In the past, a prepared statement always had a single "generic" plan that
> > was used for all parameter values, which was frequently much inferior to the
> > plans used for non-prepared statements containing explicit constant values.
> > Now, the planner attempts to generate custom plans for specific parameter
> > values. A generic plan will only be used after custom plans have repeatedly
> > proven to provide no benefit. This change should eliminate the performance
> > penalties formerly seen from use of prepared statements (including
> > non-dynamic statements in PL/pgSQL).
> >
> >
> > > なので、SQLの早い遅いは、実際のBIND値を考慮された実行計画かどうかの違いで、
> > >
> > > あとはそれがどこから来ているのか？ということか思います。
> >
> > たしかに、速かったときは、バインド変数が使われなかったものと思います。
> > バインド変数が使われなかった理由はわかりません。
> > アプリなのか、JDBCドライバなのか、それともサーバ側なのか。
> > もしこれを追求する場合は、次の情報を共有してください。
> >
> > ・サーバ側が原因かどうか
> > サーバ側にバインド変数を含むSQL文が送られているかどうか、つまり、
> > SQL文中に$1などが含まれるかどうかを見ます。
> > auto_explainの出力か、log_min_duraton_statement=0で出力される
> > サーバログ中のSQL文でよいと思います。
> >
> > ・アプリかJDBCドライバか
> > テストアプリのソースを見せてください。
> >
> >
> > 以上です。
> >
pgsql-jp メーリングリストの案内