[pgpool-general-jp: 1025] Re: 【質問】pgpoolに対しJDBCからアクセスする際の手法について

tsujihra @ nttdata.co.jp tsujihra @ nttdata.co.jp
2011年 12月 12日 (月) 22:15:21 JST


質問者の辻です。

下記の件、素早いご返事を頂いたにもかかわらず、当方の都合により反応
が遅れてしまい、申し訳ありませんでした。

> というデバッグ行がありますが、バックエンドから返って来るパケットに"P"と
> いうのは無いので、どうも動作が混乱しているように思えます。そしてその後、

とご回答いただいた件ですが、確かにこちらでもWEBリソースなどで調べて
みる限り、バックエンドが「P」を返すことはないと思っておりました。

ただ、実際のパケットを見たところ、やはり「P」が返ってきているように
思います。

下記にそのパケットを記載します。
(パケットはwiresharkにて取得いたしました。)
(前回メールに記載したJavaAPとは、アクセスするテーブル名・カラム名が
 異なっておりますが、同じく単純なSELECT文です。)

上記のパケットの中身を表示しております。
(ログで言うところのエラーが起こる直前のパケット)

0040行の3バイト目の「P」がそれにあたると考えております。

---
0000   52 54 00 89 eb 2f 52 54 00 89 eb 39 08 00 45 00  RT.../RT...9..E.
0010   01 3c a6 bc 40 00 40 06 fd 67 c0 a8 0a 32 c0 a8  .<.. @ .@..g...2..
0020   0a 15 15 38 d3 ba 72 ef 9e ad 14 5d f0 5f 80 18  ...8..r....]._..
0030   00 3e da b6 00 00 01 01 08 0a 43 39 3b e2 54 2b  .>........C9;.T+
0040   4f 5f 50 62 6c 61 6e 6b 00 54 00 03 69 64 00 00  O_Pblank.T..id..
0050   00 00 17 00 04 ff ff ff ff 64 61 74 61 31 00 00  .........data1..
0060   00 00 17 00 04 ff ff ff ff 64 61 74 61 32 00 00  .........data2..
0070   00 04 12 ff ff 00 00 00 58 44 e0 00 00 00 05 31  ........XD.....1
0080   00 00 00 05 31 00 00 00 58 74 65 73 74 20 20 20  ....1...Xtest   
0090   20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20                  
00a0   20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20                  
00b0   20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20                  
00c0   20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20                  
00d0   20 20 20 20 20 20 20 20 20 20 20 20 20 44 e0 00               D..
00e0   00 00 05 34 00 00 00 05 33 00 00 00 58 61 61 61  ...4....3...Xaaa
00f0   20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20                  
0100   20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20                  
0110   20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20                  
0120   20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20                  
0130   20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20                  
0140   20 43 53 45 4c 45 43 54 00 5a                     CSELECT.Z
---

また、参考として別のパケットも記載します。前回の本文にも書いた
JavaAP(+JDBCv2)→PostgreSQLというようにpgpoolを挟まず直接SQLを投げたとき、
上記の例と同様にPostgreSQL自体が処理を終えて「CSELECT」「Z」を送ってきたの
パケットです。
こちらについても同様の箇所に「P」が返ってきているように見受けられます。

なお、この場合、JavaAPの処理は正常に終了しております。
---
0000   52 54 00 89 eb 2f 52 54 00 89 eb 39 08 00 45 00  RT.../RT...9..E.
0010   01 3c fd c4 40 00 40 06 a6 5f c0 a8 0a 32 c0 a8  .<.. @ .@.._...2..
0020   0a 15 15 38 e2 3d 74 e9 2e cf 17 d1 d4 25 80 18  ...8.=t......%..
0030   00 3e ef ce 00 00 01 01 08 0a 43 77 d0 62 54 6a  .>........Cw.bTj
0040   1d 71 50 62 6c 61 6e 6b 00 54 00 03 69 64 00 00  .qPblank.T..id..
0050   00 00 17 00 04 ff ff ff ff 64 61 74 61 31 00 00  .........data1..
0060   00 00 17 00 04 ff ff ff ff 64 61 74 61 32 00 00  .........data2..
0070   00 04 12 ff ff 00 00 00 58 44 e0 00 00 00 05 31  ........XD.....1
0080   00 00 00 05 31 00 00 00 58 74 65 73 74 20 20 20  ....1...Xtest   
0090   20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20                  
00a0   20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20                  
00b0   20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20                  
00c0   20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20                  
00d0   20 20 20 20 20 20 20 20 20 20 20 20 20 44 e0 00               D..
00e0   00 00 05 34 00 00 00 05 33 00 00 00 58 61 61 61  ...4....3...Xaaa
00f0   20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20                  
0100   20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20                  
0110   20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20                  
0120   20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20                  
0130   20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20                  
0140   20 43 53 45 4c 45 43 54 00 5a                     CSELECT.Z
---



さらに(あまり意味は無いと思いますが)PostgreSQLに直接psqlを投げた
とき、PostgreSQL自体は正常に処理が終了したということで返してきてい
るパケットも併せて記載します。
こちらは、全く異なっているようです。

---
0000   52 54 00 89 eb 2f 52 54 00 89 eb 39 08 00 45 00  RT.../RT...9..E.
0010   01 64 08 10 40 00 40 06 9b ec c0 a8 0a 32 c0 a8  .d.. @ .@......2..
0020   0a 15 15 38 dd 6c c8 f6 1f a7 6b f7 ff 19 80 18  ...8.l....k.....
0030   00 2e 25 c4 00 00 01 01 08 0a 43 8c 8a 73 54 7e  ..%.......C..sT~
0040   d3 84 54 00 00 00 4b 00 03 69 64 00 00 00 40 01  ..T...K..id... @ .
0050   00 01 00 00 00 17 00 04 ff ff ff ff 00 00 64 61  ..............da
0060   74 61 31 00 00 00 40 01 00 02 00 00 00 17 00 04  ta1... @ .........
0070   ff ff ff ff 00 00 64 61 74 61 32 00 00 00 40 01  ......data2... @ .
0080   00 03 00 00 04 12 ff ff 00 00 00 58 00 00 44 00  ...........X..D.
0090   00 00 68 00 03 00 00 00 01 31 00 00 00 01 31 00  ..h......1....1.
00a0   00 00 54 74 65 73 74 20 20 20 20 20 20 20 20 20  ..Ttest         
00b0   20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20                  
00c0   20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20                  
00d0   20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20                  
00e0   20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20                  
00f0   20 20 20 20 20 20 20 44 00 00 00 68 00 03 00 00         D...h....
0100   00 01 34 00 00 00 01 33 00 00 00 54 61 61 61 20  ..4....3...Taaa 
0110   20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20                  
0120   20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20                  
0130   20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20                  
0140   20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20                  
0150   20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20                  
0160   43 00 00 00 0b 53 45 4c 45 43 54 00 5a 00 00 00  C....SELECT.Z...
0170   05 49                                            .I
---



もう少し前後のパケットに関する情報をお送りしたほうがよろしいでしょうか。

ご回答よろしくお願いします。

-----Original Message-----
From: Tatsuo Ishii [mailto:ishii @ sraoss.co.jp] 
Sent: Saturday, December 03, 2011 8:14 PM
To: pgpool-general-jp @ sraoss.jp; tsujihra @ nttdata.co.jp
Cc: yamanekik @ nttdata.co.jp; iinok @ nttdata.co.jp
Subject: Re: [pgpool-general-jp: 1021] 【質問】pgpoolに対しJDBCからアクセスする際の手法について

こんばんは。

psqlではOKで、Javaはダメ、ということは、JDBC+v2プロトコルでは。単純な
V2プロトコルとは違うパケットが返ってきているのではないかと思います。実際、

> 2011-11-30 06:28:39 DEBUG: pid 7701: read_kind_from_one_backend: read kind from 0 th backend P

というデバッグ行がありますが、バックエンドから返って来るパケットに"P"と
いうのは無いので、どうも動作が混乱しているように思えます。そしてその後、

> 2011-11-30 06:28:39 ERROR: pid 7701: pool_read2: failed to realloc

というエラーになっているのではないかと思います。PostgreSQLとpgpoolとの
間のパケットレベルでやり取りが分かれば良いのですが...
--
Tatsuo Ishii
SRA OSS, Inc. Japan
English: http://www.sraoss.co.jp/index_en.php
Japanese: http://www.sraoss.co.jp

> はじめまして。辻と申します。
> 
> pgpool-IIに対するJDBCアクセスに関して質問させてください。
> 
> 現在、OSSによる大量データINSERTの実証を行っており、PostgreSQLならびに
> pgpool-IIの利用を考えております。
> 
> 実装したいアーキテクチャとしては、
> ・PostgreSQLをシェアードナッシングで並列に並べ、APからは透過的に1つの
>  大きなDBに見せるべく、APとDBの間に振り分けのモジュールを挟む
> ということを考えており、pgpoolが備えているパラレルクエリの機能が利用で
> きるのではないかという考えに至りました。
> 
> 
> 質問したい事柄を初めに端的に述べますと、JavaのAPからJDBC経由(V2プロト
> コル)でpgpoolにアクセスしたときに、後ろのPostgreSQLまでは正常に処理が
> 行われているのですが、PostgreSQLからpgpoolに返ってきた通信を受け取った
> 際にpgpoolがエラーになる(環境によってはハングする)という状況が起こっ
> ており、それの対策をお伺いしたく思います。
> 
> 
> 現在、検証を行っている環境の構成を簡単にご説明します。
> 
> ■APサーバ(CentOS(5.4))
>  【AP】Java(OpenJDK1.6.0)
>  【JDBC】postgresql-8.4-701.jdbc4.jar
>  【振り分け】pgpool-II(3.1)
> 
> ■DBサーバ(CentOS(5.4))
>  【DB】PostgresSQL8.4.2
>  【HA】Heartbeat(2.1.4)
>   ※DBサーバは2台によるHA構成を3セット
> 
> ※構成補足
>  ・pgpoolはパラレルモードのみを使用。(レプリケーションモードは使用し
>   ていない)
>  ・パラレルモードを利用するにあたり、「pgpool-II チュートリアル」によ
>   ると「JDBCなどのような拡張問い合わせプロトコルには対応していません」
>   とあったため、簡易問い合わせプロトコルを利用すべく、JDBCのオプショ
>   ンとして「protocolVersion=2」を付けて実行。
> 
> 
> エラーの経緯を詳細に説明します。
> 1.JavaアプリケーションからJDBC経由でSQL(単純なSELECT文)を発行
> 2.pgpoolはそれを受け取り、3台のPostgreSQLと認証などの交渉を行う
> 3.PostgreSQLからReadyForQueryが返ってくる
> 4.pgpoolはまず1台のPostgreSQLにSQLを投げる
> 5.PostgreSQLから返ってきたメッセージを受け取る際に、以下のような
>   エラーが発生
> 
> ERROR: pid 7701: pool_read2: failed to realloc
> 
> 
> 
> このような事象が発生する場合、何か良い対策はありますでしょうか。
> (ちなみにプロトコルv2にこだわっているわけではないので、そのような根本
> から変更するようなアプローチでも構いません。)
> 
> 
> 
> ちなみに、同じ状況でJavaAP→PostgreSQLという形で直接SQLを投げた場合、
> PostgreSQLは上記と同じ内容のパケットを返してくるのですが、javaAPは正常
> 終了します。
> 
> また、psqlで同じSQLをpgpoolに向かって発行した場合、こちらの想定通りの
> 動作(3つのPostgreSQL全てからデータを集めてくる、つまりパラレルクエリ
> モードの正常な動き)をします。ただし、この場合、PostgreSQLから返ってく
> るパケットは上記とは異なっています。
> 
> また、「SELECT AID FROM PGBENCH_ACCOUNTS WHERE AID = 1」のように、
> Where句で振り分けのキーになっているカラムを限定するなどした際も同じく
> エラーになります。
> 
> また、「SELECT 1」のようなSQLの場合はJavaAP含めて全て正常に終了します。
> 
> 
> 以下に、Javaのアプリケーションの抜粋とログの抜粋を貼ります。
> 
> Java AP
> ---
> package Test;
> 
> import java.sql.*;
> import java.util.Properties;
> 
> public class PostgresTestSelect {
> 
> 	/**
> 	 * @param args
> 	 */
> 	final private static String PostgresJDBCDriver = "org.postgresql.Driver";
> 	
> 	// DBNAME, DBDIR, USER, PASS, JDBCDriver, DBURL
> 	final private static String DBNAME = "bench_parallel";
> 	final private static String USER = "postgres";
> 	final private static String PASS = "postgres";
> 	final private static String JDBCDriver = PostgresJDBCDriver;
> 	final private static String DBURL = "jdbc:postgresql://192.168.198.31:9999/" + DBNAME;
> 
> 	public static void main(String[] args) throws SQLException{
> 		try{
> 			System.out.println("SELECT:");
> 			connect(USER, PASS);
> 			
> 			ResultSet rs;
> 			int count;
> 			
> 			// SELECT
> 			Statement stmt = conn.createStatement();
> 			rs = stmt.executeQuery("select * from pgbench_accounts;");
> //			rs = stmt.executeQuery("select aid from pgbench_accounts where aid = 1;");
> //			rs = stmt.executeQuery("select 1;");
> 			count = 0;
> 			while(rs.next())
> 			{
> 				int n = rs.getInt("aid");
> 				int a = rs.getInt("bid");
> 				int b = rs.getInt("abalance");
> 				String c = rs.getString("filler");
> 				System.out.println(n + ", " + a+ ", " + b+ ", " + c);
> 				count++;
> 			}
> 			System.out.println(count+"件取得しました。");
> 			rs.close();
> 			stmt.close();
> 			disconnect();
> 
> 		}catch(Exception e){
> 
> (中略)
> 
> 
> 	static Connection conn = null;
> 	//
> 	// database open
> 	//
> 	public static void connect(String user, String pass) 
> 	throws SQLException, ClassNotFoundException
> 	{
> 		try{
> 			Class.forName(JDBCDriver).newInstance();
> 			System.setProperty("jdbc.driver", JDBCDriver);
> 			
> 		}
> 		catch(Exception e){
> 			System.out.print(e.toString());
> 			if (e instanceof SQLException)
> 			{
> 				System.out.println("Error Code:"+((SQLException)e).getErrorCode());				
> 			}
> 			e.printStackTrace();
> 		}
> 		try{
> 			if (user.isEmpty() && pass.isEmpty())
> 			{
> 				conn = DriverManager.getConnection(DBURL);
> 			}
> 			else
> 			{
> 				Properties prop = new Properties();
> 				prop.put("user", user);
> 				prop.put("password", pass);
> 				prop.put("protocolVersion", "2");
> (以下略)
> ---
> 
> 
> pgpoolログ
> ---
> 2011-11-30 06:28:39 LOG:   pid 7701: connection received: host=192.168.198.11 port=35270
> 2011-11-30 06:28:39 DEBUG: pid 7701: Protocol Major: 2 Minor: 0 database: bench_parallel user: postgres
> 2011-11-30 06:28:39 DEBUG: pid 7701: new_connection: connecting 0 backend
> 2011-11-30 06:28:39 DEBUG: pid 7701: new_connection: connecting 1 backend
> 2011-11-30 06:28:39 DEBUG: pid 7701: new_connection: connecting 2 backend
> 
> (中略)
> 
> 2011-11-30 06:28:39 DEBUG: pid 7701: ProcessFrontendResponse: kind from frontend Q(51)
> 2011-11-30 06:28:39 DEBUG: pid 7701: pool_read_string: read all from pending data. po:0 len:0
> 2011-11-30 06:28:39 DEBUG: pid 7701: pool_unset_doing_extended_query_message: done
> 2011-11-30 06:28:39 LOG:   pid 7701: statement: select * from pgbench_accounts;
> 2011-11-30 06:28:39 DEBUG: pid 7701: pool_set_query_in_progress: done
> 2011-11-30 06:28:39 DEBUG: pid 7701: initSelectStmt: ANALYZE now(0)
> 2011-11-30 06:28:39 DEBUG: pid 7701: inside build_range_info num= 1 current_select=0
> 2011-11-30 06:28:39 DEBUG: pid 7701: inside build_range_info dist 0
> 2011-11-30 06:28:39 DEBUG: pid 7701: inside build_virtual_info dist state=P  pgbench_accounts
> 2011-11-30 06:28:39 DEBUG: pid 7701: append_virtual_table select=0, no=0,col=aid,type=integer,table=pgbench_accounts,state=P,valid=-1
> 2011-11-30 06:28:39 DEBUG: pid 7701: append_virtual_table select=0, no=1,col=bid,type=integer,table=pgbench_accounts,state=P,valid=-1
> 2011-11-30 06:28:39 DEBUG: pid 7701: append_virtual_table select=0, no=2,col=abalance,type=integer,table=pgbench_accounts,state=P,valid=-1
> 2011-11-30 06:28:39 DEBUG: pid 7701: append_virtual_table select=0, no=3,col=filler,type=character(84),table=pgbench_accounts,state=P,valid=-1
> 2011-11-30 06:28:39 DEBUG: pid 7701: AnalyzeReturnRecord: current_select=0
> 2011-11-30 06:28:39 DEBUG: pid 7701: append_all_virtual: analyze[0] col=aid,type=integer
> 2011-11-30 06:28:39 DEBUG: pid 7701: append_all_virtual: analyze[0] col=bid,type=integer
> 2011-11-30 06:28:39 DEBUG: pid 7701: append_all_virtual: analyze[0] col=abalance,type=integer
> 2011-11-30 06:28:39 DEBUG: pid 7701: append_all_virtual: analyze[0] col=filler,type=character(84)
> 2011-11-30 06:28:39 DEBUG: pid 7701: _rewriteSelectStmt select_no=0 state=PPPPPPPP
> 2011-11-30 06:28:39 DEBUG: pid 7701: analyze_debug :select no(0), last select(-1), last_part(-1), state(P)
> 2011-11-30 06:28:39 DEBUG: pid 7701: can pool_parallel_exec  SELECT * FROM "pgbench_accounts"
> 2011-11-30 06:28:39 DEBUG: pid 7701: pool_parallel_query:  0 th FD_SET: 11
> 2011-11-30 06:28:39 DEBUG: pid 7701: pool_parallel_query:  1 th FD_SET: 12
> 2011-11-30 06:28:39 DEBUG: pid 7701: pool_parallel_query:  2 th FD_SET: 13
> 2011-11-30 06:28:39 DEBUG: pid 7701: pool_parallel_query: num_fds: 14
> 2011-11-30 06:28:39 DEBUG: pid 7701: read_kind_from_one_backend: read kind from 0 th backend P
> 2011-11-30 06:28:39 ERROR: pid 7701: pool_read2: failed to realloc
> 2011-11-30 06:28:39 DEBUG: pid 7572: reap_handler called
> 2011-11-30 06:28:39 DEBUG: pid 7572: reap_handler: call wait3
> 2011-11-30 06:28:39 DEBUG: pid 7572: child 7701 exits with status 256
> 
> (以下略)
> ---
> 
> 
> 以上です。
> よろしくお願いします。
> _______________________________________________
> pgpool-general-jp mailing list
> pgpool-general-jp @ sraoss.jp
> http://www.sraoss.jp/mailman/listinfo/pgpool-general-jp


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