[pgsql-jp: 36577] Re: JDBC+pgpool利用時の不具合(!?)について

Tatsuo Ishii ishii @ sraoss.co.jp
2005年 12月 19日 (月) 12:21:52 JST


石井です。

> > 山田です。
> > 
> > 石井様>
> > たびたびのご対応と修正版のご提供、感謝しております。
> 
> こちらこそおつきあいいただき、ありがとうございます。
> 
> > > 本日本家MLでちょっとやり取りしてみたのですが、結果 Execute したあとに、
> > > pgpoolの中から"Flush"というメッセージを送ってあげればよさそうだ、とい
> > > うことが分かりました。Flushは、バックエンドに対して、バッファリングさ
> > > れているメッセージをすべてフロントエンドに送るように指示します。これで
> > > Executeの完了が間接的に分かるので、うまくいくと思います。
> > 
> > ふむ、ふむ、syncの前にflushというのは、なんとなく感覚で
> > 理解できますです。
> > 
> > それで、修正版のほうで試させていただきました。
> > 結果ですが、5回ほど実行しまして、うち2回が2サーバーから
> > 10000行の挿入に成功して、他3回が最初のメールと同じように
> > デッドロック(!?)と思われる現象が発生しました。
> > 最初の時点よりは格段に発生率が下がりましたが、
> > なんともすっきりとしない結果になってしまいました。
> 
> うーん、そうですか。ということは、Executeの時点で同期をしたのでは足り
> なくて、PREPARE, BINDの時点でなんらかのロックが取られているのかもしれ
> ませんね。調べてみます。
> 
> > 上記のflushとは別の要素や、私どものシステム環境(OSとかH/W)の
> > 話になってくるんでしょうか?
> 
> 関係ないと思います。
> 
> > 気になると言えば、PostgreSQLが受け取るコマンドを見ると、
> > 通常は理路整然と PREPARE->BIND->EXECUTE と順番に繰り返し
> > ているのですが、やはり、停止時にはLOCKコマンドが
> > PREPARE, PREPARE, EXECUTE, EXECUTE
> > と交差した状態になっています。
> > #…というか、これは結局"結果"で、こういう現象が発生する
> > #ときにデッドロック(!?)と思しき状態になるのですかね?
> 
> これ自体は問題ありません。ただ気になるのは、
> 
> db1で、
> > 2005-12-16 13:26:20 JST[12444 LOG:  statement: EXECUTE <unnamed>  [PREPARE:  /*STRICT*/ /*1*/ LOCK t1]
> > 2005-12-16 13:26:20 JST[12445 LOG:  statement: <BIND>
> > 2005-12-16 13:26:20 JST[12445 LOG:  statement: EXECUTE <unnamed>  [PREPARE:  /*STRICT*/ /*2*/ LOCK t1]
> 
> と1->2の順にLOCKしているのにたいし、db2では
> 
> > 2005-12-16 13:26:20 JST[11821 LOG:  statement: EXECUTE <unnamed>  [PREPARE:  /*STRICT*/ /*2*/ LOCK t1]
> > 2005-12-16 13:26:20 JST[11820 LOG:  statement: EXECUTE <unnamed>  [PREPARE:  /*STRICT*/ /*1*/ LOCK t1]
> 
> と逆の順序で実行していることです。これだとデッドロックしちゃいますね。
> 
> > 上記以外でなにか気になる点(設定や環境)等ございましたら、
> > お知らせいただけると幸いです。
> > 
> > 長くなってしまい恐縮ですが、念のためログを追記いたします。
> > それでは、よろしくお願いいたします。
> 
> ありがとうございます。更に調べてみます。

あれから調べてみて分かったこと:

1) libpqで山田さんのテストプログラムと似たようなことをするプログラムを
   書いてみましたが、現象が再現しませんでした。
   # マシン1台だと再現しない、もしくはC/JDBCの違い?

2) 山田さんのログでは、

2005-12-16 13:26:20 DEBUG: pid 27023: read kind from frontend P(50)
2005-12-16 13:26:20 DEBUG: pid 27023: read kind from frontend B(42)
2005-12-16 13:26:20 DEBUG: pid 27023: read kind from frontend D(44)
2005-12-16 13:26:20 DEBUG: pid 27023: read kind from frontend E(45)
2005-12-16 13:26:20 DEBUG: pid 27023: Execute: portal name <>
2005-12-16 13:26:20 DEBUG: pid 27023: waiting for backend[0] completing the query
2005-12-16 13:26:20 DEBUG: pid 27023: waiting for backend[1] completing the query
2005-12-16 13:26:20 DEBUG: pid 27023: read kind from frontend S(53)
2005-12-16 13:26:20 DEBUG: pid 27023: read kind from backend 2

のように、Parse, Bind, Describe, Execute, Syncと来ていきなり2(Bind
complete)が返ってきています。これは本来1が来てから2が返らなければなら
ないはずなのですが。

そこで山田さんにお願いですが、

1) 添付のlibpqプログラムをJavaと同じような条件で実行して問題が起きない
   かどうか

2) 山田さんのプログラムでの正常ケースでのpgpoolのログ取得

を実行していただけないでしょうか?お手数ですがよろしくお願いします。

テストプログラム:a.out "dbname=test host=host1 port=9999" のように実
行します。
---------------------------------------------------------------------
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <sys/types.h>
#include "libpq-fe.h"

/* for ntohl/htonl */
#include <netinet/in.h>
#include <arpa/inet.h>


static void
exit_nicely(PGconn *conn)
{
	PQfinish(conn);
	exit(1);
}

int
main(int argc, char **argv)
{
	const char *conninfo;
	PGconn	   *conn;
	PGresult   *res;
	const char *paramValues[1];
	int			paramLengths[1];
	int			paramFormats[1];
	uint32_t	binaryIntVal;
	int i;
	int id;
	char idstr[32];

	/*
	 * If the user supplies a parameter on the command line, use it as the
	 * conninfo string; otherwise default to setting dbname=postgres and using
	 * environment variables or defaults for all other connection parameters.
	 */
	if (argc > 1)
		conninfo = argv[1];
	else
		conninfo = "dbname = postgres";

	for (i=0;i<10000;i++) {

		/* Make a connection to the database */
		conn = PQconnectdb(conninfo);

		/* Check to see that the backend connection was successfully made */
		if (PQstatus(conn) != CONNECTION_OK)
		{
			fprintf(stderr, "Connection to database failed: %s",
					PQerrorMessage(conn));
			exit_nicely(conn);
		}

		/*
		 * BEGIN;
		 * LOCK t1;
		 * SELECT MAX(id) AS max_id FROM t1;
		 * INSERT INTO t1(id, .....);
		 * COMMIT;
		 */

		res = PQexecParams(conn, "BEGIN",
						   0, NULL, NULL, NULL,	NULL, 0);
		if (PQresultStatus(res) != PGRES_COMMAND_OK)
		{
			fprintf(stderr, "query failed: %s", PQerrorMessage(conn));
			PQclear(res);
			exit_nicely(conn);
		}
		PQclear(res);

		res = PQexecParams(conn, "LOCK t1",
						   0, NULL, NULL, NULL,	NULL, 0);
		if (PQresultStatus(res) != PGRES_COMMAND_OK)
		{
			fprintf(stderr, "query failed: %s", PQerrorMessage(conn));
			PQclear(res);
			exit_nicely(conn);
		}
		PQclear(res);

		res = PQexecParams(conn, "SELECT max(id) FROM t1",
						   0, NULL, NULL, NULL,	NULL, 0);
		if (PQresultStatus(res) != PGRES_TUPLES_OK)
		{
			fprintf(stderr, "query failed: %s", PQerrorMessage(conn));
			PQclear(res);
			exit_nicely(conn);
		}
		id = atoi(PQgetvalue(res, 0, 0));
		id++;
		snprintf(idstr, sizeof(idstr), "%d", id);
		paramValues[0] = idstr;
		PQclear(res);

		res = PQexecParams(conn, "INSERT INTO t1 VALUES($1)",
						   1, NULL, paramValues, NULL,	NULL, 0);
		if (PQresultStatus(res) != PGRES_COMMAND_OK)
		{
			fprintf(stderr, "query failed: %s", PQerrorMessage(conn));
			PQclear(res);
			exit_nicely(conn);
		}

		res = PQexecParams(conn, "COMMIT",
						   0, NULL, NULL, NULL,	NULL, 0);
		if (PQresultStatus(res) != PGRES_COMMAND_OK)
		{
			fprintf(stderr, "query failed: %s", PQerrorMessage(conn));
			PQclear(res);
			exit_nicely(conn);
		}
		PQclear(res);

		PQfinish(conn);
	}

	return 0;
}



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