[pgpool-general: 2389] Re: Error when use pgpool2 with JDBC

Denis Thomas dthomas at telecomdesign.fr
Thu Jan 9 23:51:59 JST 2014


Thanks for your help, Tatsuo.

Here the pgpool2 logs when I use protocol version 3 :
...
Jan  9 15:48:26 pool pgpool[4077]: connection received: host=192.168.1.11
port=35923
Jan  9 15:48:26 pool pgpool[4077]: DB node id: 0 backend pid: 1609
statement: Parse: SET extra_float_digits = 3
Jan  9 15:48:26 pool pgpool[4077]: DB node id: 1 backend pid: 1673
statement: Parse: SET extra_float_digits = 3
Jan  9 15:48:26 pool pgpool[4077]: DB node id: 0 backend pid: 1609
statement: B message
Jan  9 15:48:26 pool pgpool[4077]: DB node id: 1 backend pid: 1673
statement: B message
Jan  9 15:48:26 pool pgpool[4077]: DB node id: 0 backend pid: 1609
statement: Execute: SET extra_float_digits = 3
Jan  9 15:48:26 pool pgpool[4077]: pool_send_and_wait: Error or notice
message from backend: : DB node id: 0 backend pid: 1609 statement: SET
extra_float_digits = 3 message: execute <unnamed>: SET extra_float_digits =
3
Jan  9 15:48:26 pool pgpool[4077]: DB node id: 1 backend pid: 1673
statement: Execute: SET extra_float_digits = 3
Jan  9 15:48:26 pool pgpool[4077]: pool_send_and_wait: Error or notice
message from backend: : DB node id: 1 backend pid: 1673 statement: SET
extra_float_digits = 3 message: execute <unnamed>: SET extra_float_digits =
3
Jan  9 15:48:26 pool pgpool[4077]: statement:  DISCARD ALL
Jan  9 15:48:26 pool pgpool[4077]: DB node id: 0 backend pid: 1609
statement:  DISCARD ALL
Jan  9 15:48:26 pool pgpool[4077]: pool_send_and_wait: Error or notice
message from backend: : DB node id: 0 backend pid: 1609 statement:  DISCARD
ALL message: statement:  DISCARD ALL
Jan  9 15:48:26 pool pgpool[4077]: DB node id: 1 backend pid: 1673
statement:  DISCARD ALL
Jan  9 15:48:26 pool pgpool[4077]: pool_send_and_wait: Error or notice
message from backend: : DB node id: 1 backend pid: 1673 statement:  DISCARD
ALL message: statement:  DISCARD ALL
Jan  9 15:48:26 pool pgpool[4079]: connection received: host=192.168.1.11
port=35924
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: Parse: SET extra_float_digits = 3
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 1 backend pid: 1672
statement: Parse: SET extra_float_digits = 3
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: B message
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 1 backend pid: 1672
statement: B message
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: Execute: SET extra_float_digits = 3
Jan  9 15:48:26 pool pgpool[4079]: pool_send_and_wait: Error or notice
message from backend: : DB node id: 0 backend pid: 1608 statement: SET
extra_float_digits = 3 message: execute <unnamed>: SET extra_float_digits =
3
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 1 backend pid: 1672
statement: Execute: SET extra_float_digits = 3
Jan  9 15:48:26 pool pgpool[4079]: pool_send_and_wait: Error or notice
message from backend: : DB node id: 1 backend pid: 1672 statement: SET
extra_float_digits = 3 message: execute <unnamed>: SET extra_float_digits =
3
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: SELECT count(*) from (SELECT has_function_privilege('sensor',
'pgpool_regclass(cstring)', 'execute') WHERE EXISTS(SELECT * FROM
pg_catalog.pg_proc AS p WHERE p.proname = 'pgpool_regclass')) AS s
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: SELECT count(*) FROM pg_catalog.pg_attrdef AS d,
pg_catalog.pg_class AS c WHERE d.adrelid = c.oid AND d.adsrc ~ 'nextval'
AND c.relname = 'snsrprobe'
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: Parse: INSERT INTO snsrProbe (     id, probcolor, probcreated,
probglobal,     problevel, probname, probstrategy ) VALUES (     $1, $2,
now(), $3,     $4, $5, $6 )
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: BEGIN
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: B message
Jan  9 15:48:26 pool pgpool[4079]: pool_send_and_wait: Error or notice
message from backend: : DB node id: 0 backend pid: 1608 statement: INSERT
INTO snsrProbe (     id, probcolor, probcreated, probglobal,     problevel,
probname, probstrategy ) VALUES (     $1, $2, now(), $3,     $4, $5, $6 )
message: unnamed prepared statement does not exist
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: COMMIT
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: Parse: DELETE FROM snsrProbe WHERE id = $1
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: BEGIN
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: B message
Jan  9 15:48:26 pool pgpool[4079]: pool_send_and_wait: Error or notice
message from backend: : DB node id: 0 backend pid: 1608 statement: DELETE
FROM snsrProbe WHERE id = $1 message: unnamed prepared statement does not
exist
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: COMMIT
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: Parse: INSERT INTO snsrProbe (     id, probcolor, probcreated,
probglobal,     problevel, probname, probstrategy ) VALUES (     $1, $2,
now(), $3,     $4, $5, $6 )
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: BEGIN
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: B message
Jan  9 15:48:26 pool pgpool[4079]: pool_send_and_wait: Error or notice
message from backend: : DB node id: 0 backend pid: 1608 statement: INSERT
INTO snsrProbe (     id, probcolor, probcreated, probglobal,     problevel,
probname, probstrategy ) VALUES (     $1, $2, now(), $3,     $4, $5, $6 )
message: unnamed prepared statement does not exist
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: COMMIT
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: Parse: DELETE FROM snsrProbe WHERE id = $1
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: BEGIN
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: B message
Jan  9 15:48:26 pool pgpool[4079]: pool_send_and_wait: Error or notice
message from backend: : DB node id: 0 backend pid: 1608 statement: DELETE
FROM snsrProbe WHERE id = $1 message: unnamed prepared statement does not
exist
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: COMMIT
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: Parse: INSERT INTO snsrProbe (     id, probcolor, probcreated,
probglobal,     problevel, probname, probstrategy ) VALUES (     $1, $2,
now(), $3,     $4, $5, $6 )
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: BEGIN
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: B message
Jan  9 15:48:26 pool pgpool[4079]: pool_send_and_wait: Error or notice
message from backend: : DB node id: 0 backend pid: 1608 statement: INSERT
INTO snsrProbe (     id, probcolor, probcreated, probglobal,     problevel,
probname, probstrategy ) VALUES (     $1, $2, now(), $3,     $4, $5, $6 )
message: unnamed prepared statement does not exist
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: COMMIT
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: Parse: DELETE FROM snsrProbe WHERE id = $1
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: BEGIN
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: B message
Jan  9 15:48:26 pool pgpool[4079]: pool_send_and_wait: Error or notice
message from backend: : DB node id: 0 backend pid: 1608 statement: DELETE
FROM snsrProbe WHERE id = $1 message: unnamed prepared statement does not
exist
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: COMMIT
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: Parse: INSERT INTO snsrProbe (     id, probcolor, probcreated,
probglobal,     problevel, probname, probstrategy ) VALUES (     $1, $2,
now(), $3,     $4, $5, $6 )
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: BEGIN
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: B message
Jan  9 15:48:26 pool pgpool[4079]: pool_send_and_wait: Error or notice
message from backend: : DB node id: 0 backend pid: 1608 statement: INSERT
INTO snsrProbe (     id, probcolor, probcreated, probglobal,     problevel,
probname, probstrategy ) VALUES (     $1, $2, now(), $3,     $4, $5, $6 )
message: unnamed prepared statement does not exist
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: COMMIT
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: Parse: DELETE FROM snsrProbe WHERE id = $1
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: BEGIN
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: B message
Jan  9 15:48:26 pool pgpool[4079]: pool_send_and_wait: Error or notice
message from backend: : DB node id: 0 backend pid: 1608 statement: DELETE
FROM snsrProbe WHERE id = $1 message: unnamed prepared statement does not
exist
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement: COMMIT
Jan  9 15:48:26 pool pgpool[4079]: ProcessFrontendResponse: failed to read
kind from frontend. frontend abnormally exited
Jan  9 15:48:26 pool pgpool[4079]: statement:  DISCARD ALL
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 0 backend pid: 1608
statement:  DISCARD ALL
Jan  9 15:48:26 pool pgpool[4079]: pool_send_and_wait: Error or notice
message from backend: : DB node id: 0 backend pid: 1608 statement:  DISCARD
ALL message: statement:  DISCARD ALL
Jan  9 15:48:26 pool pgpool[4079]: DB node id: 1 backend pid: 1672
statement:  DISCARD ALL
Jan  9 15:48:26 pool pgpool[4079]: pool_send_and_wait: Error or notice
message from backend: : DB node id: 1 backend pid: 1672 statement:  DISCARD
ALL message: statement:  DISCARD ALL

PostgreSQL master logs :
...
2014-01-09 15:48:26.558 CET pool LOG:  execute <unnamed>: SET
extra_float_digits = 3
2014-01-09 15:48:26.569 CET pool LOG:  statement:  DISCARD ALL
2014-01-09 15:48:26.618 CET pool LOG:  execute <unnamed>: SET
extra_float_digits = 3
2014-01-09 15:48:26.644 CET pool LOG:  execute pgpool4079/pgpool4079:
SELECT count(*) from (SELECT has_function_privilege('sensor',
'pgpool_regclass(cstring)', 'execute') WHERE EXISTS(SELECT * FROM
pg_catalog.pg_proc AS p WHERE p.proname = 'pgpool_regclass')) AS s
2014-01-09 15:48:26.649 CET pool LOG:  execute pgpool4079/pgpool4079:
SELECT count(*) FROM pg_catalog.pg_attrdef AS d, pg_catalog.pg_class AS c
WHERE d.adrelid = c.oid AND d.adsrc ~ 'nextval' AND c.relname = 'snsrprobe'
2014-01-09 15:48:26.651 CET pool LOG:  statement: BEGIN
2014-01-09 15:48:26.652 CET pool ERROR:  unnamed prepared statement does
not exist
2014-01-09 15:48:26.653 CET pool LOG:  statement: COMMIT
2014-01-09 15:48:26.731 CET pool LOG:  statement: BEGIN
2014-01-09 15:48:26.732 CET pool ERROR:  unnamed prepared statement does
not exist
2014-01-09 15:48:26.735 CET pool LOG:  statement: COMMIT
2014-01-09 15:48:26.743 CET pool LOG:  statement: BEGIN
2014-01-09 15:48:26.744 CET pool ERROR:  unnamed prepared statement does
not exist
2014-01-09 15:48:26.745 CET pool LOG:  statement: COMMIT
2014-01-09 15:48:26.747 CET pool LOG:  statement: BEGIN
2014-01-09 15:48:26.748 CET pool ERROR:  unnamed prepared statement does
not exist
2014-01-09 15:48:26.749 CET pool LOG:  statement: COMMIT
2014-01-09 15:48:26.753 CET pool LOG:  statement: BEGIN
2014-01-09 15:48:26.754 CET pool ERROR:  unnamed prepared statement does
not exist
2014-01-09 15:48:26.755 CET pool LOG:  statement: COMMIT
2014-01-09 15:48:26.757 CET pool LOG:  statement: BEGIN
2014-01-09 15:48:26.758 CET pool ERROR:  unnamed prepared statement does
not exist
2014-01-09 15:48:26.758 CET pool LOG:  statement: COMMIT
2014-01-09 15:48:26.763 CET pool LOG:  statement: BEGIN
2014-01-09 15:48:26.763 CET pool ERROR:  unnamed prepared statement does
not exist
2014-01-09 15:48:26.764 CET pool LOG:  statement: COMMIT
2014-01-09 15:48:26.766 CET pool LOG:  statement: BEGIN
2014-01-09 15:48:26.767 CET pool ERROR:  unnamed prepared statement does
not exist
2014-01-09 15:48:26.768 CET pool LOG:  statement: COMMIT
2014-01-09 15:48:26.779 CET pool LOG:  statement:  DISCARD ALL
2014-01-09 15:48:28.625 CET  LOG:  connection received: host=pool port=35731
2014-01-09 15:48:28.627 CET pool LOG:  connection authorized: user=sensor
database=postgres
2014-01-09 15:48:28.630 CET pool LOG:  disconnection: session time:
0:00:00.005 user=sensor database=postgres host=pool port=35731
2014-01-09 15:48:38.645 CET  LOG:  connection received: host=pool port=35733
2014-01-09 15:48:38.646 CET pool LOG:  connection authorized: user=sensor
database=postgres
2014-01-09 15:48:38.649 CET pool LOG:  disconnection: session time:
0:00:00.005 user=sensor database=postgres host=pool port=35733
2014-01-09 15:48:48.665 CET  LOG:  connection received: host=pool port=35735
2014-01-09 15:48:48.666 CET pool LOG:  connection authorized: user=sensor
database=postgres
2014-01-09 15:48:48.669 CET pool LOG:  disconnection: session time:
0:00:00.004 user=sensor database=postgres host=pool port=35735
2014-01-09 15:48:58.688 CET  LOG:  connection received: host=pool port=35737

And slave logs :
2014-01-09 15:48:26.556 CET pool LOG:  execute <unnamed>: SET
extra_float_digits = 3
2014-01-09 15:48:26.568 CET pool LOG:  statement:  DISCARD ALL
2014-01-09 15:48:26.617 CET pool LOG:  execute <unnamed>: SET
extra_float_digits = 3
2014-01-09 15:48:26.778 CET pool LOG:  statement:  DISCARD ALL
2014-01-09 15:48:28.628 CET  LOG:  connection received: host=pool port=51328
2014-01-09 15:48:28.629 CET pool LOG:  connection authorized: user=sensor
database=postgres
2014-01-09 15:48:28.630 CET pool LOG:  disconnection: session time:
0:00:00.002 user=sensor database=postgres host=pool port=51328
2014-01-09 15:48:38.648 CET  LOG:  connection received: host=pool port=51330
2014-01-09 15:48:38.649 CET pool LOG:  connection authorized: user=sensor
database=postgres
2014-01-09 15:48:38.652 CET pool LOG:  disconnection: session time:
0:00:00.004 user=sensor database=postgres host=pool port=51330
2014-01-09 15:48:48.667 CET  LOG:  connection received: host=pool port=51332
2014-01-09 15:48:48.670 CET pool LOG:  connection authorized: user=sensor
database=postgres
2014-01-09 15:48:48.672 CET pool LOG:  disconnection: session time:
0:00:00.005 user=sensor database=postgres host=pool port=51332
2014-01-09 15:48:58.689 CET  LOG:  connection received: host=pool port=51334
2014-01-09 15:48:58.690 CET pool LOG:  connection authorized: user=sensor
database=postgres
2014-01-09 15:48:58.693 CET pool LOG:  disconnection: session time:
0:00:00.004 user=sensor database=postgres host=pool port=51334
2014-01-09 15:49:08.709 CET  LOG:  connection received: host=pool port=51336
2014-01-09 15:49:08.709 CET pool LOG:  connection authorized: user=sensor
database=postgres
2014-01-09 15:49:08.711 CET pool LOG:  disconnection: session time:
0:00:00.002 user=sensor database=postgres host=pool port=51336
2014-01-09 15:49:18.731 CET  LOG:  connection received: host=pool port=51338
2014-01-09 15:49:18.733 CET pool LOG:  connection authorized: user=sensor
database=postgres
2014-01-09 15:49:18.736 CET pool LOG:  disconnection: session time:
0:00:00.005 user=sensor database=postgres host=pool port=51338



2014/1/9 Tatsuo Ishii <ishii at postgresql.org>

> Denis,
>
> >>   I currently have no test-bed with a running pgpool, but maybe you
> >> could create a simple test case: open a JDBC connection (no polling,
> >> no protocol specified, straight JDBC) to the pgpool, and observe the
> >> log files on both back-ends. Tatsuo Ishii noted, that the pgpool
> >> status shows that both back-ends behave differently when the SET is
> >> executed. There might be something there.
> >>
> >
> > The two servers are configured with the same parameters, except fot
> > replication of course, and wal archiving, not activated on slave. Is it
> > possible that the problem come from ?
>
> I don't think so.
>
> Can you show me PostgreSQL log when you face the problem? There must
> be a notice message in the log because pgpool-II detects notice
> ("N"). I think the key to solve the problem is the content of the
> message.
> --
> Tatsuo Ishii
> SRA OSS, Inc. Japan
> English: http://www.sraoss.co.jp/index_en.php
> Japanese: http://www.sraoss.co.jp
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.sraoss.jp/pipermail/pgpool-general/attachments/20140109/33994d39/attachment-0001.html>


More information about the pgpool-general mailing list