[pgpool-general-jp: 1641] Re: pgpool-IIの処理性能について

北村由香 kitamura ＠ ryobi.co.jp
2020年 9月 16日 (水) 13:33:18 JST 

石井様

いつもお世話になっております。北村です。

検証中に以下のことがわかりましたのでご連絡いたします。
実際にjavaアプリが遅くなってたシステムは、以前メールに記載した
通りのpgpool.confの設定で、（health_check_period=0）であるため、
tcpdumpではスタンバイへアクセスが行われていないことが確認できました。

検証で使用していた別システムの方では、以前メールに記載した通りの設定
＋ヘルスチェック機能を有効（health_check_periodなど）にした状態でした。
この設定では、アプリ実行時にスタンバイへtcpdumpのアクセスが
行われているようです。

ヘルスチェックの有無で、スタンバイアクセスが変わるのかはわかりませんが、
今回のJavaが遅くなっている原因とは関係がないことがわかりました。
正しい情報をお伝えできておらず申し訳ございません。

> Tomcat側でコネクションプーリングしているということなので可能性からは除
> 外していたのですが、SQL実行の度にPgpool-IIにJava側から接続要求があり、
> その結果Pgpool-IIが毎回primary側とスタンバイ側のPostgreSQLに接続を張り
> に行っているような気がします(Pgpool-IIはload_balance_mode = offでもす
> べてのバックエンドに接続を張ります)。つまり、Tomcatのコネクションプー
> リングが効いていないのではないでしょうか？

javaアプリケーションは、最初にコネクトして複数のSQLを発行し、
最後にディスコネクトしているため、SQLごとに接続を張りに
行っているということはないのではないかと考えています。
また、ディスコネクトのログが出力されていませんでしたので、
おそらくjavaのコネクションプーリングは有効になっていると考えます。

以上、よろしくお願いいたします。
-----
> 
> 石井です。
> 
> > 別システムの方での確認結果にはなりますが、
> > log_per_node_statement = onでPgpool-IIのログを確認したところ、
> > 全てDB node id: 0で出力されておりましたので、Pgpool-IIは
> > スタンバイ側には処理を行っていないように思われます。（ノード0はDBプライマリ）
> > また、log_statement = 'all'の状態で、スタンバイ側のPostgreSQLのログも
> > 確認しましたが、SQL文の出力はありませんでした。
> > ですので、SQLがスタンバイに流れているということはなさそうなのですが、
> > Tcpdumpで通信を監視すると、スタンバイでSQLごとにPgpool-IIサーバからの
> > 通信が見受けられるという状態です。
> >
> > 4.0.2固有のバグの切り分けとして、4.0.10のPgpoo-IIでも同様の検証を
> > 行いましたが、やはりtcpdumpで同様にスタンバイサーバへのアクセスは確認できました。
> > （4.1.3でも同様でした。）
> 
> Tomcat側でコネクションプーリングしているということなので可能性からは除
> 外していたのですが、SQL実行の度にPgpool-IIにJava側から接続要求があり、
> その結果Pgpool-IIが毎回primary側とスタンバイ側のPostgreSQLに接続を張り
> に行っているような気がします(Pgpool-IIはload_balance_mode = offでもす
> べてのバックエンドに接続を張ります)。つまり、Tomcatのコネクションプー
> リングが効いていないのではないでしょうか？
> (Tomcatよく知らないので、違っていたらごめんなさい。)
> 
> それならば、tcpdumpがスタンバイへの通信を検出した理由も説明が付きます。
> tcpdumpのキャプチャした通信内容を-Xで表示してみれば接続要求のパケット
> であることがわかるでしょう。
> 
> あるいはスタンバイのpostgresql.confでlog_connections = onにしてログを
> 観察してもわかると思います。
> 
> > これらの結果から、この現象（スタンバイサーバにアクセスがされている）は
> > 障害ではなく、仕様ということが濃厚になりますでしょうか？
> > もし何か回避策など思い当たりましたらご教示いただければ幸いです。
> 
> - Tomcatのコネクションプーリングを有効にする
> - Pgpool-IIのconnection_cacheを有効にする
> 
> あたりでしょうか。
> 
> > JAVAアプリがPgpool経由接続で遅くなっている原因は
> > このスタンバイへのアクセスがあることとは別の原因である可能性も
> > ありますので、他の可能性を調査してい行きたいと思います。
> >
> > 以上、よろしくお願いいたします。
> > -----
> >
> >>
> >> > 石井様
> >> >
> >> > お世話になっております。北村です。
> >> > 早々にご確認いただきありがとうございます。
> >> > 考えられる問題パターンもあげていただきありがとうございます。
> >> >
> >> >> 1) Javaアプリ<-->Pgpool-II<-->PostgreSQLのどこかでネットワークが遅い
> >> >
> >> > 今回はJavaアプリとPgpool-IIが同一サーバに存在している環境になりますので、
> >> > 1)の可能性は薄いと考えております。
> >> >
> >> >> 2) Pgpool-IIが走っているマシンのCPUリソース and/or メモリが足りない
> >> >
> >> > こちらについては詳しく確認できておりませんので、可能性があるかもしれません。
> >> >
> >> >> 3) テストに使用したINSERT文やUPDATE文が長大で、Pgpool-IIがパースするの
> >> >>    に時間がかかっている(これは4.1で改善されています)
> >> >
> >> > テストに使用したSELECT文やINSERT文はさほど長大ではないので、
> >> > 3)の可能性も薄いのではないかと考えております。
> >> > （INSERT文は単純なINSERT VALUESで、カラム数は50個ほどです。）
> >> >
> >> >> 4) 一部の問い合わせが遠隔地のスタンバイにも送られていてその応答待ちで
> >> >>    時間がかかっている(お伺いした設定ではその可能性はないはずですが、一応。)
> >> >
> >> > もしかすると4)の可能性があるのではないかと考えております。
> >> > Pgpool-IIサーバからDBサーバへPingの応答時間を確認したところ、
> >> > DBプライマリは0.1ミリ秒、DBスタンバイは19ミリ秒ほどで、
> >> > ちょうど1SQLあたりに生じている差と同じくらいでした。
> >> >
> >> > 別システムでの調査結果にはなるのですが、ご相談している環境と同じような
> >> > 設定の環境で、アプリケーション実行時にtcpdumpを使用して通信を
> >> > 監視したところ、Pgpool-IIサーバとDBスタンバイサーバ間の通信が、
> >> > 1トラン内のSQLの実行回数分行われているようでした。
> >> >
> >> > load_balance_mode = offを設定しているため負荷分散機能が無効となり
> >> > DBスタンバイへSQLは送られない認識なのですが、その設定であっても
> >> > SQL文ごとにDBスタンバイへの通信は行われるものなのでしょうか？
> >>
> >> 行われないはずですが、何か特殊な条件や、4.0.2固有のバグのせいでスタン
> >> バイと通信しているのかも知れません。Pgpool-IIのログ
> >> (log_per_node_statement = on)か、スタンバイ側のPostgreSQLのクエリログ
> >> があればなにかわかるかも知れません。
> >>
> >> > 現在のPgpool-IIの設定パラメータは下記の通りです。
> >> > 何かお気づきの点などございましたら、ご教示いただければ幸いです。
> >> > よろしくお願いいたします。
> >>
> >> 特に気になったところはありません。
> >>
> >> > ■pgpool.confに設定されている内容（pgpool.conf.sample-streamを元に作成）
> >> > listen_addresses = '*'
> >> > port = 9999
> >> > socket_dir = '/tmp'
> >> > pcp_listen_addresses = '*'
> >> > pcp_port = 9898
> >> > pcp_socket_dir = '/tmp'
> >> > listen_backlog_multiplier = 2
> >> > serialize_accept = off
> >> > backend_hostname0 = (PostgreSQLプライマリのホスト名)
> >> > backend_port0 = (PostgreSQLプライマリのポート番号)
> >> > backend_data_directory0 = (PostgreSQLプライマリのインスタンス)
> >> > backend_flag0 = 'ALLOW_TO_FAILOVER'
> >> > backend_hostname1 = (PostgreSQLスタンバイのホスト名)
> >> > backend_port1 = (PostgreSQLスタンバイのポート番号)
> >> > backend_data_directory1 = (PostgreSQLスタンバイのインスタンス)
> >> > enable_pool_hba = on
> >> > pool_passwd = 'pool_passwd'
> >> > authentication_timeout = 60
> >> > allow_clear_text_frontend_auth = off ssl = off ssl_ciphers =
> >> > 'HIGH:MEDIUM:+3DES:!aNULL'
> >> > ssl_prefer_server_ciphers = off
> >> > num_init_children = 600
> >> > max_pool = 4
> >> > child_life_time = 300
> >> > child_max_connections = 0
> >> > connection_life_time = 0
> >> > client_idle_limit = 0
> >> > log_destination = 'syslog'
> >> > log_line_prefix = '[%l] user=%u, db=%d, proc=%P, pid=%p, app=%a '
> >> > log_connections = on
> >> > log_hostname = off
> >> > log_statement = on
> >> > log_per_node_statement = on
> >> > log_client_messages = off
> >> > log_standby_delay = 'if_over_threshold'
> >> > syslog_facility = 'LOCAL0'
> >> > syslog_ident = 'pgpool'
> >> > pid_file_name = （Pgpool-IIのpidファイルのパス）
> >> > logdir = '/tmp'
> >> > connection_cache = off
> >> > reset_query_list = 'ABORT; DISCARD ALL'
> >> > replication_mode = off
> >> > replicate_select = off
> >> > insert_lock = off
> >> > lobj_lock_table = ''
> >> > replication_stop_on_mismatch = off
> >> > failover_if_affected_tuples_mismatch = off load_balance_mode = off
> >> > ignore_leading_white_space = on white_function_list = ''
> >> > black_function_list = 'currval,lastval,nextval,setval'
> >> > black_query_pattern_list = ''
> >> > database_redirect_preference_list = ''
> >> > app_name_redirect_preference_list = ''
> >> > allow_sql_comments = off
> >> > disable_load_balance_on_write = 'transaction'
> >> > master_slave_mode = on
> >> > master_slave_sub_mode = 'stream'
> >> > sr_check_period = 0
> >> > sr_check_user = （PostgreSQLユーザ名）
> >> > sr_check_password = （PostgreSQLユーザのパスワード）
> >> > sr_check_database = 'postgres'
> >> > delay_threshold = 10000000
> >> > follow_master_command = ''
> >> > health_check_period = 0
> >> > health_check_timeout = 20
> >> > health_check_user = 'nobody'
> >> > health_check_password = ''
> >> > health_check_database = ''
> >> > health_check_max_retries = 0
> >> > health_check_retry_delay = 1
> >> > connect_timeout = 10000
> >> > failover_command = ''
> >> > failback_command = ''
> >> > failover_on_backend_error = on
> >> > detach_false_primary = off
> >> > search_primary_node_timeout = 300
> >> > recovery_user = 'nobody'
> >> > recovery_password = ''
> >> > recovery_1st_stage_command = ''
> >> > recovery_2nd_stage_command = ''
> >> > recovery_timeout = 90
> >> > client_idle_limit_in_recovery = 0
> >> > use_watchdog = off
> >> > trusted_servers = ''
> >> > ping_path = '/bin'
> >> > wd_hostname = ''
> >> > wd_port = 9000
> >> > wd_priority = 1
> >> > wd_authkey = ''
> >> > wd_ipc_socket_dir = '/tmp'
> >> > delegate_IP = ''
> >> > if_cmd_path = '/sbin'
> >> > if_up_cmd = 'ip addr add $_IP_$/24 dev eth0 label eth0:0'
> >> > if_down_cmd = 'ip addr del $_IP_$/24 dev eth0'
> >> > arping_path = '/usr/sbin'
> >> > arping_cmd = 'arping -U $_IP_$ -w 1 -I eth0'
> >> > clear_memqcache_on_escalation = on
> >> > wd_escalation_command = ''
> >> > wd_de_escalation_command = ''
> >> > failover_when_quorum_exists = on
> >> > failover_require_consensus = on
> >> > allow_multiple_failover_requests_from_node = off
> >> > wd_monitoring_interfaces_list = ''
> >> > wd_lifecheck_method = 'heartbeat'
> >> > wd_interval = 10
> >> > wd_heartbeat_port = 9694
> >> > wd_heartbeat_keepalive = 2
> >> > wd_heartbeat_deadtime = 30
> >> > heartbeat_destination0 = 'host0_ip1'
> >> > heartbeat_destination_port0 = 9694
> >> > heartbeat_device0 = ''
> >> > wd_life_point = 3
> >> > wd_lifecheck_query = 'SELECT 1'
> >> > wd_lifecheck_dbname = 'template1'
> >> > wd_lifecheck_user = 'nobody'
> >> > wd_lifecheck_password = ''
> >> > relcache_expire = 0
> >> > relcache_size = 256
> >> > check_temp_table = on
> >> > check_unlogged_table = on
> >> > memory_cache_enabled = off
> >> > memqcache_method = 'shmem'
> >> > memqcache_memcached_host = 'localhost'
> >> > memqcache_memcached_port = 11211
> >> > memqcache_total_size = 67108864
> >> > memqcache_max_num_cache = 1000000
> >> > memqcache_expire = 0
> >> > memqcache_auto_cache_invalidation = on memqcache_maxcache = 409600
> >> > memqcache_cache_block_size = 1048576 memqcache_oiddir =
> >> > '/var/log/pgpool/oiddir'
> >> > white_memqcache_table_list = ''
> >> > black_memqcache_table_list = ''
> >> >
> >> > 以上、よろしくお願いいたします。
> >> > -----
> >> >
> >> >> 石井です。
> >> >>
> >> >> Pgpool-II経由のときに、1 SQLあたり19ミリ秒余計にかかるのはちょっとオー
> >> >> バヘッドが大きすぎるように思います。
> >> >>
> >> >> 手元の環境で(pgbench, Pgpool-II, PostgreSQL, すべて同じマシン上に環境
> >> >> 構築)pgbenchを使ってテストすると[1]、
> >> >>
> >> >> Pgpool-II経由:latency average = 27.318 ms
> >> >> PostgreSQL直接: latency average = 25.578 ms
> >> >>
> >> >> その差は1.7ミリ秒ほどです(ただし、1 SQLあたりではなく、1トランザクショ
> >> >> ンあたり。1 SQLあたりなら差はもっと小さいはず)。北村さんの環境でオーバ
> >> >> ヘッドが大きい理由として考えられるのは、
> >> >>
> >> >> 1) Javaアプリ<-->Pgpool-II<-->PostgreSQLのどこかでネットワークが遅い
> >> >>
> >> >> 2) Pgpool-IIが走っているマシンのCPUリソース and/or メモリが足りない
> >> >>
> >> >> 3) テストに使用したINSERT文やUPDATE文が長大で、Pgpool-IIがパースするの
> >> >>    に時間がかかっている(これは4.1で改善されています)
> >> >>
> >> >> 4) 一部の問い合わせが遠隔地のスタンバイにも送られていてその応答待ちで
> >> >>    時間がかかっている(お伺いした設定ではその可能性はないはずですが、一応。)
> >> >>
> >> >> などです。まずは問題の切り分けを行ってみてはいかがでしょう？
> >> >>
> >> >> あと、4.0.2は2年前にリリースされただいぶ古いバージョンで、その後性能改
> >> >> 善も行われているので、同じ4.0系の最新版を試してみるのも良いと思います。
> >> >>
> >> >> [1]実際に使ったコマンドは、
> >> >> pgbench -M extended -n -p 11000 -T 10 -c 10 test
> >> >>
> >> >> > はじめまして、お世話になります。
> >> >> > 北村と申します。
> >> >> >
> >> >> > 現在Pgpool-IIの検証を行っているのですが、アプリケーションを
> >> >> > postgreSQLに直接接続した場合とPgpool-IIに接続した場合で
> >> >> > 性能差が出ており、Pgpool-II経由の方が約6倍処理時間がかかっています。
> >> >> >
> >> >> > この差が妥当な値なのか、チューニングにより性能改善が見込める
> >> >> > 可能性があるのか、ご教示いただきたくメールさせていただきました。
> >> >> >
> >> >> > 【検証環境】
> >> >> > 　○PostgreSQL 11
> >> >> > 　　- RHEL 7に構築
> >> >> > 　　- 2台構成で非同期ストリーミングレプリケーションを構築
> >> >> > 　　- スタンバイサーバは遠隔地に配置している
> >> >> > 　○Pgpool-II 4.0.2
> >> >> > 　　- RHEL 7に構築（DBサーバとは別サーバ）
> >> >> > 　　- コネクションプーリングは使用しない（connection_cache = off）
> >> >> > 　　　（javaのコネクションプーリングを使用しているため）
> >> >> > 　　- DBプライマリにアクセスしたいため、
> >> >> > 　　　負荷分散は行わない（load_balance_mode = off）
> >> >> >
> >> >> > 【検証内容】
> >> >> > 　1トランザクション内で大量SQL（SELECT文やINSERT文）を実行する
> >> >> > 　アプリケーション(java)について、DB直接接続の場合と
> >> >> > 　Pgpool接続の場合で、処理時間を測定。
> >> >> >
> >> >> > 　DB直接接続：全体処理時間00:00:30秒（1SQLあたり約3ミリ秒）
> >> >> > 　Pgpool接続：全体処理時間00:02:58秒（1SQLあたり約19ミリ秒）
> >> >> > 　　　⇒pgpool接続の方が1SQLあたり約16ミリ秒遅い
> >> >> >
> >> >> > 【ご相談事項】
> >> >> > 　・pgpoolを経由すると、1SQLあたりの処理時間が多く（約6倍）
> >> >> > 　　かかっているのですが、これは妥当なものなのでしょうか？
> >> >> > 　・Pgpoolで負荷分散とコネクションプールを行わない前提で、
> >> >> > 　　Pgpoolのチューニングにより性能改善策などは考えられますでしょうか？
> >> >> >
> >> >> > 何かお気づきの点や設定の勘所等をご教示いただければ幸いです。
> >> >> > よろしくお願いいたします。
> >> >> >
> >> >> >
> >> >> > _______________________________________________
> >> >> > pgpool-general-jp mailing list
> >> >> > pgpool-general-jp ＠ sraoss.jp
> >> >> > http://www.sraoss.jp/mailman/listinfo/pgpool-general-jp
> >> >

pgpool-general-jp メーリングリストの案内