[pgpool-general: 1280] Re: database detach and I don't understand why

Tatsuo Ishii ishii at postgresql.org
Fri Jan 4 08:00:29 JST 2013


> Thanks for looking into this!
> 
> 1) I search through the code and listed all functions for the jboss
> schema and there is no use of functions

Ok.

> 2) The same goes for triggers

Ok.

> 3) if the JBoss for some reason should disconnect shouldn't I be able
> to see that in the pgpool log or PostgreSQL log?
> 
> If you look through the PostgreSQL log you will actual see that all
> statement are executed in the same order until it degenerate node 1,
> and I did a diff on the PostgreSQL statement and there is no different
> until it degenerate.
> 
> I can't see anything that indicate why it "degenerate" in PostgreSQL log.

I see this line in the log:

2012-12-27 19:54:18 GMT 25803 20/357 0 LOG:  execute <unnamed>: COMMIT PREPARED '131075_MTkxLTdmMDAwMDAxOmUwMDY6NTBkYzllNzU6MjMwNQ==_N2YwMDAwMDE6ZTAwNjo1MGRjOWU3NToyMzBh'

This is a two phase commit command. Unfortunately I couldn't find any
corresponding "PREPARE TRANSACTION" and cannot guess what was actually
committed. Maybe the prepared transaction is related to the
difference?
--
Tatsuo Ishii
SRA OSS, Inc. Japan
English: http://www.sraoss.co.jp/index_en.php
Japanese: http://www.sraoss.co.jp

> SQL for node 1 :(I have truncated the long lines )
> 2012-12-27 19:54:18 GMT 26538 23/167 0 LOG:  execute S_1: BEGIN
> 2012-12-27 19:54:18 GMT 26538 23/167 0 LOG:  execute <unnamed>: INSERT
> INTO JBM_TX (NODE_ID, TRANSACTION_ID, BRANCH_QUAL, FORMAT_ID,
> GLOBAL_TXID) VALUES($1, $2, $3, $4, $5)
> 2012-12-27 19:54:18 GMT 26538 23/167 0 DETAIL:  parameters: $1 =
> '191', $2 = '3446306904799576068', $3 = '7f000001:e006:50dc9e75:2317',
> $4 = '131075', $5 = '191-7f000001:e006:50dc9e75:2305'
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 LOG:  execute <unnamed>:
> INSERT INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID,
> STATE, ORD, PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2,
> $3, $4, $5, $6, $7, $8)
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 DETAIL:  parameters: $1 =
> '2872', $2 = '3446306904799576396', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799576403', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 LOG:  execute <unnamed>:
> INSERT INTO JBM_MSG (MESSAGE_ID, RELIABLE, EXPIRATION, TIMESTAMP,
> PRIORITY, TYPE, HEADERS, PAYLOAD) VALUES ($1, $2, $3, $4, $5, $6, $7,
> $8)
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 DETAIL:  parameters: $1 =
> '3446306904799576396', $2 = 'Y', $3 = '0', $4 = '1356638058062', $5 =
> '4', $6 = '2', $7 = '....' , $8 = '....'
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 LOG:  execute <unnamed>:
> INSERT INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID,
> STATE, ORD, PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2,
> $3, $4, $5, $6, $7, $8)
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 DETAIL:  parameters: $1 =
> '2875', $2 = '3446306904799576397', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799609172', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 LOG:  execute <unnamed>:
> INSERT INTO JBM_MSG (MESSAGE_ID, RELIABLE, EXPIRATION, TIMESTAMP,
> PRIORITY, TYPE, HEADERS, PAYLOAD) VALUES ($1, $2, $3, $4, $5, $6, $7,
> $8)
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 DETAIL:  parameters: $1 =
> '3446306904799576397', $2 = 'Y', $3 = '0', $4 = '1356638058393', $5 =
> '4', $6 = '2', $7 = '....' , $8 = '....'
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 LOG:  execute <unnamed>:
> INSERT INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID,
> STATE, ORD, PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2,
> $3, $4, $5, $6, $7, $8)
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 DETAIL:  parameters: $1 =
> '2876', $2 = '3446306904799576397', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799641941', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 LOG:  execute <unnamed>:
> INSERT INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID,
> STATE, ORD, PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2,
> $3, $4, $5, $6, $7, $8)
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 DETAIL:  parameters: $1 =
> '2875', $2 = '3446306904799576398', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799641942', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 LOG:  execute <unnamed>:
> INSERT INTO JBM_MSG (MESSAGE_ID, RELIABLE, EXPIRATION, TIMESTAMP,
> PRIORITY, TYPE, HEADERS, PAYLOAD) VALUES ($1, $2, $3, $4, $5, $6, $7,
> $8)
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 DETAIL:  parameters: $1 =
> '3446306904799576398', $2 = 'Y', $3 = '0', $4 = '1356638058412', $5 =
> '4', $6 = '2', $7 = '....' , $8 = '....'
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 LOG:  execute S_5: INSERT
> INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID, STATE, ORD,
> PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2, $3, $4, $5,
> $6, $7, $8)
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 DETAIL:  parameters: $1 =
> '2876', $2 = '3446306904799576398', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799641943', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 LOG:  execute S_5: INSERT
> INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID, STATE, ORD,
> PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2, $3, $4, $5,
> $6, $7, $8)
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 DETAIL:  parameters: $1 =
> '2875', $2 = '3446306904799576399', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799674712', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 LOG:  execute <unnamed>:
> INSERT INTO JBM_MSG (MESSAGE_ID, RELIABLE, EXPIRATION, TIMESTAMP,
> PRIORITY, TYPE, HEADERS, PAYLOAD) VALUES ($1, $2, $3, $4, $5, $6, $7,
> $8)
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 DETAIL:  parameters: $1 =
> '3446306904799576399', $2 = 'Y', $3 = '0', $4 = '1356638058425', $5 =
> '4', $6 = '2', $7 = '....' , $8 = '....'
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 LOG:  execute S_5: INSERT
> INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID, STATE, ORD,
> PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2, $3, $4, $5,
> $6, $7, $8)
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 DETAIL:  parameters: $1 =
> '2876', $2 = '3446306904799576399', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799674713', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 LOG:  execute S_5: INSERT
> INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID, STATE, ORD,
> PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2, $3, $4, $5,
> $6, $7, $8)
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 DETAIL:  parameters: $1 =
> '2875', $2 = '3446306904799576400', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799674714', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 LOG:  execute S_6: INSERT
> INTO JBM_MSG (MESSAGE_ID, RELIABLE, EXPIRATION, TIMESTAMP, PRIORITY,
> TYPE, HEADERS, PAYLOAD) VALUES ($1, $2, $3, $4, $5, $6, $7, $8)
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 DETAIL:  parameters: $1 =
> '3446306904799576400', $2 = 'Y', $3 = '0', $4 = '1356638058434', $5 =
> '4', $6 = '2', $7 = '....' , $8 = '....'
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 LOG:  execute S_5: INSERT
> INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID, STATE, ORD,
> PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2, $3, $4, $5,
> $6, $7, $8)
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 DETAIL:  parameters: $1 =
> '2876', $2 = '3446306904799576400', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799674715', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 LOG:  execute S_5: INSERT
> INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID, STATE, ORD,
> PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2, $3, $4, $5,
> $6, $7, $8)
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 DETAIL:  parameters: $1 =
> '2875', $2 = '3446306904799576401', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799674716', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 LOG:  execute S_6: INSERT
> INTO JBM_MSG (MESSAGE_ID, RELIABLE, EXPIRATION, TIMESTAMP, PRIORITY,
> TYPE, HEADERS, PAYLOAD) VALUES ($1, $2, $3, $4, $5, $6, $7, $8)
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 DETAIL:  parameters: $1 =
> '3446306904799576401', $2 = 'Y', $3 = '0', $4 = '1356638058444', $5 =
> '4', $6 = '2', $7 = '....' , $8 = '....'
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 LOG:  execute S_5: INSERT
> INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID, STATE, ORD,
> PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2, $3, $4, $5,
> $6, $7, $8)
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 DETAIL:  parameters: $1 =
> '2876', $2 = '3446306904799576401', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799707485', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 LOG:  execute S_5: INSERT
> INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID, STATE, ORD,
> PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2, $3, $4, $5,
> $6, $7, $8)
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 DETAIL:  parameters: $1 =
> '2875', $2 = '3446306904799576402', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799707486', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 LOG:  execute S_6: INSERT
> INTO JBM_MSG (MESSAGE_ID, RELIABLE, EXPIRATION, TIMESTAMP, PRIORITY,
> TYPE, HEADERS, PAYLOAD) VALUES ($1, $2, $3, $4, $5, $6, $7, $8)
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 DETAIL:  parameters: $1 =
> '3446306904799576402', $2 = 'Y', $3 = '0', $4 = '1356638058453', $5 =
> '4', $6 = '2', $7 = '....' , $8 = '....'
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 LOG:  execute S_5: INSERT
> INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID, STATE, ORD,
> PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2, $3, $4, $5,
> $6, $7, $8)
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 DETAIL:  parameters: $1 =
> '2876', $2 = '3446306904799576402', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799707487', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 LOG:  execute S_5: INSERT
> INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID, STATE, ORD,
> PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2, $3, $4, $5,
> $6, $7, $8)
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 DETAIL:  parameters: $1 =
> '2875', $2 = '3446306904799576403', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799707488', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 LOG:  execute S_6: INSERT
> INTO JBM_MSG (MESSAGE_ID, RELIABLE, EXPIRATION, TIMESTAMP, PRIORITY,
> TYPE, HEADERS, PAYLOAD) VALUES ($1, $2, $3, $4, $5, $6, $7, $8)
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 DETAIL:  parameters: $1 =
> '3446306904799576403', $2 = 'Y', $3 = '0', $4 = '1356638058463', $5 =
> '4', $6 = '2', $7 = '....' , $8 = '....'
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 LOG:  execute S_5: INSERT
> INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID, STATE, ORD,
> PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2, $3, $4, $5,
> $6, $7, $8)
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 DETAIL:  parameters: $1 =
> '2876', $2 = '3446306904799576403', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799707489', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 LOG:  execute S_5: INSERT
> INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID, STATE, ORD,
> PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2, $3, $4, $5,
> $6, $7, $8)
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 DETAIL:  parameters: $1 =
> '2875', $2 = '3446306904799576404', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799740258', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 LOG:  execute S_6: INSERT
> INTO JBM_MSG (MESSAGE_ID, RELIABLE, EXPIRATION, TIMESTAMP, PRIORITY,
> TYPE, HEADERS, PAYLOAD) VALUES ($1, $2, $3, $4, $5, $6, $7, $8)
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 DETAIL:  parameters: $1 =
> '3446306904799576404', $2 = 'Y', $3 = '0', $4 = '1356638058532', $5 =
> '4', $6 = '2', $7 = '....' , $8 = '....'
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 LOG:  execute S_5: INSERT
> INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID, STATE, ORD,
> PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2, $3, $4, $5,
> $6, $7, $8)
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 DETAIL:  parameters: $1 =
> '2876', $2 = '3446306904799576404', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799740259', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 26538 23/167 249453 LOG:  execute S_2: COMMIT
> 2012-12-27 19:54:18 GMT 25803 20/357 0 LOG:  execute <unnamed>: COMMIT
> PREPARED '131075_MTkxLTdmMDAwMDAxOmUwMDY6NTBkYzllNzU6MjMwNQ==_N2YwMDAwMDE6ZTAwNjo1MGRjOWU3NToyMzBh'
> 2012-12-27 19:54:18 GMT 26538 23/168 0 LOG:  execute S_1: BEGIN
> 2012-12-27 19:54:18 GMT 26538 23/168 0 LOG:  execute <unnamed>: UPDATE
> JBM_MSG_REF SET STATE='C', TRANSACTION_ID = NULL WHERE
> TRANSACTION_ID=$1 AND STATE='+'
> 2012-12-27 19:54:18 GMT 26538 23/168 0 DETAIL:  parameters: $1 =
> '3446306904799576068'
> 2012-12-27 19:54:18 GMT 26538 23/168 249455 LOG:  execute <unnamed>:
> DELETE FROM JBM_MSG_REF WHERE TRANSACTION_ID=$1 AND STATE='-'
> 2012-12-27 19:54:18 GMT 26538 23/168 249455 DETAIL:  parameters: $1 =
> '3446306904799576068'
> 2012-12-27 19:54:18 GMT 26538 23/168 249455 LOG:  execute <unnamed>:
> DELETE FROM JBM_TX WHERE NODE_ID = $1 AND TRANSACTION_ID = $2
> 2012-12-27 19:54:18 GMT 26538 23/168 249455 DETAIL:  parameters: $1 =
> '191', $2 = '3446306904799576068'
> 2012-12-27 19:54:18 GMT 26538 23/168 249455 LOG:  execute S_2: COMMIT
> 2012-12-27 19:54:18 GMT 26538 23/169 0 LOG:  execute S_1: BEGIN
> 2012-12-27 19:54:18 GMT 26538 23/169 0 LOG:  execute S_2: COMMIT
> 2012-12-27 19:54:18 GMT 26538 23/170 0 LOG:  execute S_1: BEGIN
> 2012-12-27 19:54:18 GMT 25803 20/358 0 LOG:  statement: BEGIN
> 2012-12-27 19:54:18 GMT 26538 23/170 0 LOG:  execute <unnamed>: DELETE
> FROM JBM_MSG_REF WHERE MESSAGE_ID=$1 AND CHANNEL_ID=$2 AND STATE='C'
> 2012-12-27 19:54:18 GMT 26538 23/170 0 DETAIL:  parameters: $1 =
> '3446306904799576397', $2 = '2876'
> 2012-12-27 19:54:18 GMT 26538 23/170 249456 LOG:  execute S_2: COMMIT
> 2012-12-27 19:54:18 GMT 25803 20/358 0 LOG:  statement: COMMIT
> 2012-12-27 19:54:18 GMT 25803 20/359 0 LOG:  execute S_1: BEGIN
> 2012-12-27 19:54:18 GMT 25803 20/359 0 LOG:  execute <unnamed>: select
> next_id from sequence_log_msg_attribs for update
> 2012-12-27 19:54:18 GMT 25803 20/359 249457 LOG:  execute <unnamed>:
> update sequence_log_msg_attribs set next_id = $1 where next_id = $2
> 2012-12-27 19:54:18 GMT 25803 20/359 249457 DETAIL:  parameters: $1 =
> '61691', $2 = '61690'
> 2012-12-27 19:54:18 GMT 25803 20/359 249457 LOG:  execute S_2: COMMIT
> 2012-12-27 19:54:18 GMT 26537 22/120 0 LOG:  execute S_1: BEGIN
> 2012-12-27 19:54:18 GMT 26537 22/120 0 LOG:  execute <unnamed>: DELETE
> FROM JBM_MSG_REF WHERE MESSAGE_ID=$1 AND CHANNEL_ID=$2 AND STATE='C'
> 2012-12-27 19:54:18 GMT 26537 22/120 0 DETAIL:  parameters: $1 =
> '3446306904799576397', $2 = '2875'
> 2012-12-27 19:54:18 GMT 26537 22/120 249458 LOG:  execute S_2: COMMIT
> 2012-12-27 19:54:18 GMT 26538 23/171 0 LOG:  execute S_1: BEGIN
> 2012-12-27 19:54:18 GMT 26538 23/171 0 LOG:  execute <unnamed>: DELETE
> FROM JBM_MSG WHERE MESSAGE_ID = $1 AND NOT EXISTS (SELECT
> JBM_MSG_REF.MESSAGE_ID FROM JBM_MSG_REF WHERE JBM_MSG_REF.MESSAGE_ID =
> $2)
> 2012-12-27 19:54:18 GMT 26538 23/171 0 DETAIL:  parameters: $1 =
> '3446306904799576397', $2 = '3446306904799576397'
> 2012-12-27 19:54:18 GMT 26538 23/171 0 DETAIL:  parameters: $1 =
> '3446306904799576397', $2 = '3446306904799576397'
> 2012-12-27 19:54:18 GMT 25657 2/0 0 LOG:  unexpected EOF on client connection
> 2012-12-27 19:54:18 GMT 25658 3/0 0 LOG:  unexpected EOF on client connection
> 2012-12-27 19:54:18 GMT 28045 25/0 0 LOG:  unexpected EOF on client connection
> 2012-12-27 19:54:18 GMT 26537 22/0 0 LOG:  could not receive data from
> client: Connection reset by peer
> 
> SQL for node 0: (I have truncated the long lines )
> 
> 2012-12-27 19:54:18 GMT 19308 23/35 0LOG:  execute S_1: BEGIN
> 2012-12-27 19:54:18 GMT 19308 23/35 0LOG:  execute <unnamed>: INSERT
> INTO JBM_TX (NODE_ID, TRANSACTION_ID, BRANCH_QUAL, FORMAT_ID,
> GLOBAL_TXID) VALUES($1, $2, $3, $4, $5)
> 2012-12-27 19:54:18 GMT 19308 23/35 0DETAIL:  parameters: $1 = '191',
> $2 = '3446306904799576068', $3 = '7f000001:e006:50dc9e75:2317', $4 =
> '131075', $5 = '191-7f000001:e006:50dc9e75:2305'
> 2012-12-27 19:54:18 GMT 19308 23/35 249453LOG:  execute <unnamed>:
> INSERT INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID,
> STATE, ORD, PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2,
> $3, $4, $5, $6, $7, $8)
> 2012-12-27 19:54:18 GMT 19308 23/35 249453DETAIL:  parameters: $1 =
> '2872', $2 = '3446306904799576396', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799576403', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 19308 23/35 249453LOG:  execute <unnamed>:
> INSERT INTO JBM_MSG (MESSAGE_ID, RELIABLE, EXPIRATION, TIMESTAMP,
> PRIORITY, TYPE, HEADERS, PAYLOAD) VALUES ($1, $2, $3, $4, $5, $6, $7,
> $8)
> 2012-12-27 19:54:18 GMT 19308 23/35 249453DETAIL:  parameters: $1 =
> '3446306904799576396', $2 = 'Y', $3 = '0', $4 = '1356638058062', $5 =
> '4', $6 = '2', $7 = '....' , $8 = '....'
> 2012-12-27 19:54:18 GMT 19308 23/35 249453LOG:  execute <unnamed>:
> INSERT INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID,
> STATE, ORD, PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2,
> $3, $4, $5, $6, $7, $8)
> 2012-12-27 19:54:18 GMT 19308 23/35 249453DETAIL:  parameters: $1 =
> '2875', $2 = '3446306904799576397', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799609172', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 19308 23/35 249453LOG:  execute <unnamed>:
> INSERT INTO JBM_MSG (MESSAGE_ID, RELIABLE, EXPIRATION, TIMESTAMP,
> PRIORITY, TYPE, HEADERS, PAYLOAD) VALUES ($1, $2, $3, $4, $5, $6, $7,
> $8)
> 2012-12-27 19:54:18 GMT 19308 23/35 249453DETAIL:  parameters: $1 =
> '3446306904799576397', $2 = 'Y', $3 = '0', $4 = '1356638058393', $5 =
> '4', $6 = '2', $7 = '....' , $8 = '....'
> 2012-12-27 19:54:18 GMT 19308 23/35 249453LOG:  execute <unnamed>:
> INSERT INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID,
> STATE, ORD, PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2,
> $3, $4, $5, $6, $7, $8)
> 2012-12-27 19:54:18 GMT 19308 23/35 249453DETAIL:  parameters: $1 =
> '2876', $2 = '3446306904799576397', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799641941', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 19308 23/35 249453LOG:  execute <unnamed>:
> INSERT INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID,
> STATE, ORD, PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2,
> $3, $4, $5, $6, $7, $8)
> 2012-12-27 19:54:18 GMT 19308 23/35 249453DETAIL:  parameters: $1 =
> '2875', $2 = '3446306904799576398', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799641942', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 19308 23/35 249453LOG:  execute <unnamed>:
> INSERT INTO JBM_MSG (MESSAGE_ID, RELIABLE, EXPIRATION, TIMESTAMP,
> PRIORITY, TYPE, HEADERS, PAYLOAD) VALUES ($1, $2, $3, $4, $5, $6, $7,
> $8)
> 2012-12-27 19:54:18 GMT 19308 23/35 249453DETAIL:  parameters: $1 =
> '3446306904799576398', $2 = 'Y', $3 = '0', $4 = '1356638058412', $5 =
> '4', $6 = '2', $7 = '....' , $8 = '....'
> 2012-12-27 19:54:18 GMT 19308 23/35 249453LOG:  execute S_5: INSERT
> INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID, STATE, ORD,
> PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2, $3, $4, $5,
> $6, $7, $8)
> 2012-12-27 19:54:18 GMT 19308 23/35 249453DETAIL:  parameters: $1 =
> '2876', $2 = '3446306904799576398', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799641943', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 19308 23/35 249453LOG:  execute S_5: INSERT
> INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID, STATE, ORD,
> PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2, $3, $4, $5,
> $6, $7, $8)
> 2012-12-27 19:54:18 GMT 19308 23/35 249453DETAIL:  parameters: $1 =
> '2875', $2 = '3446306904799576399', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799674712', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 19308 23/35 249453LOG:  execute <unnamed>:
> INSERT INTO JBM_MSG (MESSAGE_ID, RELIABLE, EXPIRATION, TIMESTAMP,
> PRIORITY, TYPE, HEADERS, PAYLOAD) VALUES ($1, $2, $3, $4, $5, $6, $7,
> $8)
> 2012-12-27 19:54:18 GMT 19308 23/35 249453DETAIL:  parameters: $1 =
> '3446306904799576399', $2 = 'Y', $3 = '0', $4 = '1356638058425', $5 =
> '4', $6 = '2', $7 = '....' , $8 = '....'
> 2012-12-27 19:54:18 GMT 19308 23/35 249453LOG:  execute S_5: INSERT
> INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID, STATE, ORD,
> PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2, $3, $4, $5,
> $6, $7, $8)
> 2012-12-27 19:54:18 GMT 19308 23/35 249453DETAIL:  parameters: $1 =
> '2876', $2 = '3446306904799576399', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799674713', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 19308 23/35 249453LOG:  execute S_5: INSERT
> INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID, STATE, ORD,
> PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2, $3, $4, $5,
> $6, $7, $8)
> 2012-12-27 19:54:18 GMT 19308 23/35 249453DETAIL:  parameters: $1 =
> '2875', $2 = '3446306904799576400', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799674714', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 19308 23/35 249453LOG:  execute S_6: INSERT
> INTO JBM_MSG (MESSAGE_ID, RELIABLE, EXPIRATION, TIMESTAMP, PRIORITY,
> TYPE, HEADERS, PAYLOAD) VALUES ($1, $2, $3, $4, $5, $6, $7, $8)
> 2012-12-27 19:54:18 GMT 19308 23/35 249453DETAIL:  parameters: $1 =
> '3446306904799576400', $2 = 'Y', $3 = '0', $4 = '1356638058434', $5 =
> '4', $6 = '2', $7 = '....' , $8 = '....'
> 2012-12-27 19:54:18 GMT 19308 23/35 249453LOG:  execute S_5: INSERT
> INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID, STATE, ORD,
> PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2, $3, $4, $5,
> $6, $7, $8)
> 2012-12-27 19:54:18 GMT 19308 23/35 249453DETAIL:  parameters: $1 =
> '2876', $2 = '3446306904799576400', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799674715', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 19308 23/35 249453LOG:  execute S_5: INSERT
> INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID, STATE, ORD,
> PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2, $3, $4, $5,
> $6, $7, $8)
> 2012-12-27 19:54:18 GMT 19308 23/35 249453DETAIL:  parameters: $1 =
> '2875', $2 = '3446306904799576401', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799674716', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 19308 23/35 249453LOG:  execute S_6: INSERT
> INTO JBM_MSG (MESSAGE_ID, RELIABLE, EXPIRATION, TIMESTAMP, PRIORITY,
> TYPE, HEADERS, PAYLOAD) VALUES ($1, $2, $3, $4, $5, $6, $7, $8)
> 2012-12-27 19:54:18 GMT 19308 23/35 249453DETAIL:  parameters: $1 =
> '3446306904799576401', $2 = 'Y', $3 = '0', $4 = '1356638058444', $5 =
> '4', $6 = '2', $7 = '....' , $8 = '....'
> 2012-12-27 19:54:18 GMT 19308 23/35 249453LOG:  execute S_5: INSERT
> INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID, STATE, ORD,
> PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2, $3, $4, $5,
> $6, $7, $8)
> 2012-12-27 19:54:18 GMT 19308 23/35 249453DETAIL:  parameters: $1 =
> '2876', $2 = '3446306904799576401', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799707485', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 19308 23/35 249453LOG:  execute S_5: INSERT
> INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID, STATE, ORD,
> PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2, $3, $4, $5,
> $6, $7, $8)
> 2012-12-27 19:54:18 GMT 19308 23/35 249453DETAIL:  parameters: $1 =
> '2875', $2 = '3446306904799576402', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799707486', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 19308 23/35 249453LOG:  execute S_6: INSERT
> INTO JBM_MSG (MESSAGE_ID, RELIABLE, EXPIRATION, TIMESTAMP, PRIORITY,
> TYPE, HEADERS, PAYLOAD) VALUES ($1, $2, $3, $4, $5, $6, $7, $8)
> 2012-12-27 19:54:18 GMT 19308 23/35 249453DETAIL:  parameters: $1 =
> '3446306904799576402', $2 = 'Y', $3 = '0', $4 = '1356638058453', $5 =
> '4', $6 = '2', $7 = '....' , $8 = '....'
> 2012-12-27 19:54:18 GMT 19308 23/35 249453LOG:  execute S_5: INSERT
> INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID, STATE, ORD,
> PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2, $3, $4, $5,
> $6, $7, $8)
> 2012-12-27 19:54:18 GMT 19308 23/35 249453DETAIL:  parameters: $1 =
> '2876', $2 = '3446306904799576402', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799707487', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 19308 23/35 249453LOG:  execute S_5: INSERT
> INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID, STATE, ORD,
> PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2, $3, $4, $5,
> $6, $7, $8)
> 2012-12-27 19:54:18 GMT 19308 23/35 249453DETAIL:  parameters: $1 =
> '2875', $2 = '3446306904799576403', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799707488', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 19308 23/35 249453LOG:  execute S_6: INSERT
> INTO JBM_MSG (MESSAGE_ID, RELIABLE, EXPIRATION, TIMESTAMP, PRIORITY,
> TYPE, HEADERS, PAYLOAD) VALUES ($1, $2, $3, $4, $5, $6, $7, $8)
> 2012-12-27 19:54:18 GMT 19308 23/35 249453DETAIL:  parameters: $1 =
> '3446306904799576403', $2 = 'Y', $3 = '0', $4 = '1356638058463', $5 =
> '4', $6 = '2', $7 = '....' , $8 = '....'
> 2012-12-27 19:54:18 GMT 19308 23/35 249453LOG:  execute S_5: INSERT
> INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID, STATE, ORD,
> PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2, $3, $4, $5,
> $6, $7, $8)
> 2012-12-27 19:54:18 GMT 19308 23/35 249453DETAIL:  parameters: $1 =
> '2876', $2 = '3446306904799576403', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799707489', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 19308 23/35 249453LOG:  execute S_5: INSERT
> INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID, STATE, ORD,
> PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2, $3, $4, $5,
> $6, $7, $8)
> 2012-12-27 19:54:18 GMT 19308 23/35 249453DETAIL:  parameters: $1 =
> '2875', $2 = '3446306904799576404', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799740258', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 19308 23/35 249453LOG:  execute S_6: INSERT
> INTO JBM_MSG (MESSAGE_ID, RELIABLE, EXPIRATION, TIMESTAMP, PRIORITY,
> TYPE, HEADERS, PAYLOAD) VALUES ($1, $2, $3, $4, $5, $6, $7, $8)
> 2012-12-27 19:54:18 GMT 19308 23/35 249453DETAIL:  parameters: $1 =
> '3446306904799576404', $2 = 'Y', $3 = '0', $4 = '1356638058532', $5 =
> '4', $6 = '2', $7 = '....' , $8 = '....'
> 2012-12-27 19:54:18 GMT 19308 23/35 249453LOG:  execute S_5: INSERT
> INTO JBM_MSG_REF (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID, STATE, ORD,
> PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES ($1, $2, $3, $4, $5,
> $6, $7, $8)
> 2012-12-27 19:54:18 GMT 19308 23/35 249453DETAIL:  parameters: $1 =
> '2876', $2 = '3446306904799576404', $3 = '3446306904799576068', $4 =
> '+', $5 = '3446306904799740259', $6 = NULL, $7 = '0', $8 = '0'
> 2012-12-27 19:54:18 GMT 19308 23/35 249453LOG:  execute S_2: COMMIT
> 2012-12-27 19:54:18 GMT 18558 20/80 0LOG:  execute <unnamed>: COMMIT
> PREPARED '131075_MTkxLTdmMDAwMDAxOmUwMDY6NTBkYzllNzU6MjMwNQ==_N2YwMDAwMDE6ZTAwNjo1MGRjOWU3NToyMzBh'
> 2012-12-27 19:54:18 GMT 19308 23/36 0LOG:  execute S_1: BEGIN
> 2012-12-27 19:54:18 GMT 19308 23/36 0LOG:  execute <unnamed>: UPDATE
> JBM_MSG_REF SET STATE='C', TRANSACTION_ID = NULL WHERE
> TRANSACTION_ID=$1 AND STATE='+'
> 2012-12-27 19:54:18 GMT 19308 23/36 0DETAIL:  parameters: $1 =
> '3446306904799576068'
> 2012-12-27 19:54:18 GMT 19308 23/36 249455LOG:  execute <unnamed>:
> DELETE FROM JBM_MSG_REF WHERE TRANSACTION_ID=$1 AND STATE='-'
> 2012-12-27 19:54:18 GMT 19308 23/36 249455DETAIL:  parameters: $1 =
> '3446306904799576068'
> 2012-12-27 19:54:18 GMT 19308 23/36 249455LOG:  execute <unnamed>:
> DELETE FROM JBM_TX WHERE NODE_ID = $1 AND TRANSACTION_ID = $2
> 2012-12-27 19:54:18 GMT 19308 23/36 249455DETAIL:  parameters: $1 =
> '191', $2 = '3446306904799576068'
> 2012-12-27 19:54:18 GMT 19308 23/36 249455LOG:  execute S_2: COMMIT
> 2012-12-27 19:54:18 GMT 19308 23/37 0LOG:  execute S_1: BEGIN
> 2012-12-27 19:54:18 GMT 19308 23/37 0LOG:  execute S_2: COMMIT
> 2012-12-27 19:54:18 GMT 19308 23/38 0LOG:  execute S_1: BEGIN
> 2012-12-27 19:54:18 GMT 18558 20/81 0LOG:  statement: BEGIN
> 2012-12-27 19:54:18 GMT 19308 23/38 0LOG:  execute <unnamed>: DELETE
> FROM JBM_MSG_REF WHERE MESSAGE_ID=$1 AND CHANNEL_ID=$2 AND STATE='C'
> 2012-12-27 19:54:18 GMT 19308 23/38 0DETAIL:  parameters: $1 =
> '3446306904799576397', $2 = '2876'
> 2012-12-27 19:54:18 GMT 19308 23/38 249456LOG:  execute S_2: COMMIT
> 2012-12-27 19:54:18 GMT 18558 20/81 0LOG:  statement: COMMIT
> 2012-12-27 19:54:18 GMT 18558 20/82 0LOG:  execute S_1: BEGIN
> 2012-12-27 19:54:18 GMT 18558 20/82 0LOG:  execute <unnamed>: select
> next_id from sequence_log_msg_attribs for update
> 2012-12-27 19:54:18 GMT 18558 20/82 249457LOG:  execute <unnamed>:
> update sequence_log_msg_attribs set next_id = $1 where next_id = $2
> 2012-12-27 19:54:18 GMT 18558 20/82 249457DETAIL:  parameters: $1 =
> '61691', $2 = '61690'
> 2012-12-27 19:54:18 GMT 18558 20/82 249457LOG:  execute S_2: COMMIT
> 2012-12-27 19:54:18 GMT 19307 22/70 0LOG:  execute S_1: BEGIN
> 2012-12-27 19:54:18 GMT 19307 22/70 0LOG:  execute <unnamed>: DELETE
> FROM JBM_MSG_REF WHERE MESSAGE_ID=$1 AND CHANNEL_ID=$2 AND STATE='C'
> 2012-12-27 19:54:18 GMT 19307 22/70 0DETAIL:  parameters: $1 =
> '3446306904799576397', $2 = '2875'
> 2012-12-27 19:54:18 GMT 19307 22/70 249458LOG:  execute S_2: COMMIT
> 2012-12-27 19:54:18 GMT 19308 23/39 0LOG:  execute S_1: BEGIN
> 2012-12-27 19:54:18 GMT 19308 23/39 0LOG:  execute <unnamed>: DELETE
> FROM JBM_MSG WHERE MESSAGE_ID = $1 AND NOT EXISTS (SELECT
> JBM_MSG_REF.MESSAGE_ID FROM JBM_MSG_REF WHERE JBM_MSG_REF.MESSAGE_ID =
> $2)
> 2012-12-27 19:54:18 GMT 19308 23/39 0DETAIL:  parameters: $1 =
> '3446306904799576397', $2 = '3446306904799576397'
> 2012-12-27 19:54:18 GMT 22442 1/124 0LOG:  execute <unnamed>: SET
> SESSION CHARACTERISTICS AS TRANSACTION ISOLATION LEVEL READ COMMITTED
> 2012-12-27 19:54:18 GMT 22442 1/125 0LOG:  execute <unnamed>: select 1
> 2012-12-27 19:54:18 GMT 22442 1/126 0LOG:  execute S_1: BEGIN
> 2012-12-27 19:54:18 GMT 22442 1/126 0LOG:  execute <unnamed>: select
> iteminfopa0_.infopanel_item_uuid as infopanel1_99_0_, iteminfopa0_.x
> as x0_, iteminfopa0_.y as y0_, iteminfopa0_.item_uuid as item4_0_ from
> itemInfoPanelToPoint iteminfopa0_ where
> iteminfopa0_.infopanel_item_uuid=$1
> 2012-12-27 19:54:18 GMT 22442 1/126 0DETAIL:  parameters: $1 =
> 'e0005ae7-7285-45a1-88a1-e73e54149485'
> 2012-12-27 19:54:18 GMT 22442 1/126 0LOG:  execute <unnamed>: select
> itempintop0_.pin_item_uuid as pin1_99_0_, itempintop0_.x as x0_,
> itempintop0_.y as y0_, itempintop0_.item_uuid as item4_0_ from
> itemPinToPoint itempintop0_ where itempintop0_.pin_item_uuid=$1
> 2012-12-27 19:54:18 GMT 22442 1/126 0DETAIL:  parameters: $1 =
> 'e0005ae7-7285-45a1-88a1-e73e54149485'
> 2012-12-27 19:54:18 GMT 22442 1/126 0LOG:  execute <unnamed>: select
> this_.uuid as uuid100_0_ from placement_service this_
> 2012-12-27 19:54:18 GMT 22442 1/126 0LOG:  execute <unnamed>: select
> this_.uuid as uuid125_0_ from keyword_administration this_
> 2012-12-27 19:54:18 GMT 22444 2/134 0LOG:  execute <unnamed>: SET
> SESSION CHARACTERISTICS AS TRANSACTION ISOLATION LEVEL READ COMMITTED
> 2012-12-27 19:54:18 GMT 22442 1/126 0LOG:  execute <unnamed>: select
> this_.uuid as uuid501_0_, this_.profile_name as profile2_501_0_ from
> impact_config_profile this_
> 2012-12-27 19:54:18 GMT 22444 2/135 0LOG:  execute <unnamed>: select 1
> 2012-12-27 19:54:18 GMT 22444 2/136 0LOG:  execute S_1: BEGIN
> 2012-12-27 19:54:18 GMT 22442 1/126 0LOG:  execute <unnamed>: select
> impactprof0_.impact_profile_id as impact3_501_1_, impactprof0_.uuid as
> uuid1_, impactprof0_.uuid as uuid500_0_, impactprof0_1_.filter_type as
> filter2_503_0_, impactprof0_2_.dangerous_temperature as
> dangerous2_504_0_, impactprof0_2_.critical_temperature as
> critical3_504_0_, impactprof0_2_.check_redundancy as check4_504_0_,
> impactprof0_.identifiable_type as identifi2_500_0_ from
> impact_config_profile_part impactprof0_ left outer join
> impact_config_alarm_profile_part impactprof0_1_ on
> impactprof0_.uuid=impactprof0_1_.uuid left outer join
> impact_config_cooling_profile_part impactprof0_2_ on
> impactprof0_.uuid=impactprof0_2_.uuid where
> impactprof0_.impact_profile_id=$1
> 2012-12-27 19:54:18 GMT 22442 1/126 0DETAIL:  parameters: $1 =
> '6aeba475-aba0-4b9b-8fff-6ff264da605f'
> 2012-12-27 19:54:18 GMT 22444 2/136 0LOG:  execute <unnamed>: DELETE
> FROM JBM_MSG_REF WHERE MESSAGE_ID=$1 AND CHANNEL_ID=$2 AND STATE='C'
> 2012-12-27 19:54:18 GMT 22444 2/136 0DETAIL:  parameters: $1 =
> '3446306904799576396', $2 = '2872'
> 2012-12-27 19:54:18 GMT 22442 1/126 0LOG:  execute <unnamed>: select
> alarmfilte0_.alarm_impact_profile_id as alarm3_500_1_,
> alarmfilte0_.uuid as uuid1_, alarmfilte0_.uuid as uuid502_0_,
> alarmfilte0_.description_pattern as descript2_502_0_ from
> impact_config_alarm_filter_entry alarmfilte0_ where
> alarmfilte0_.alarm_impact_profile_id=$1
> 2012-12-27 19:54:18 GMT 22442 1/126 0DETAIL:  parameters: $1 =
> 'e26f45e2-715e-4465-80bb-ac492c88f880'
> 2012-12-27 19:54:18 GMT 22444 2/136 249459LOG:  execute S_2: COMMIT
> 2012-12-27 19:54:18 GMT 22444 2/137 0LOG:  execute S_1: BEGIN
> 2012-12-27 19:54:18 GMT 22444 2/137 0LOG:  execute <unnamed>: DELETE
> FROM JBM_MSG WHERE MESSAGE_ID = $1 AND NOT EXISTS (SELECT
> JBM_MSG_REF.MESSAGE_ID FROM JBM_MSG_REF WHERE JBM_MSG_REF.MESSAGE_ID =
> $2)
> 2012-12-27 19:54:18 GMT 22444 2/137 0DETAIL:  parameters: $1 =
> '3446306904799576396', $2 = '3446306904799576396'
> 2012-12-27 19:54:18 GMT 22444 2/137 249460LOG:  execute S_2: COMMIT
> 
> 2013/1/2 Tatsuo Ishii <ishii at postgresql.org>:
>> Well there some possibilities:
>>
>> 1) JBoss uses functions which has side effect(updating tables).
>>
>> 2) JBoss uses triggers which updates the table in question.
>>
>> 3) the transaction updating the table in question committed on node 1
>>    but not committed on node 0 for some reason. Maybe the connection
>>    between JBoss and pgpool between those two commit commands were
>>    disconnected?
>>
>> Anyway, if you carefully look into the PostgreSQL log (I assume
>> log_statement is on), you may be able find the cause.
>> --
>> Tatsuo Ishii
>> SRA OSS, Inc. Japan
>> English: http://www.sraoss.co.jp/index_en.php
>> Japanese: http://www.sraoss.co.jp
>>
>>> the different is that node 1 the message in jbm_msg still exist, but
>>> on node 0 it's deleted. the jbm_msg_ref on both servers are empty.
>>>
>>> but I don't understand how that's possible when the jms process
>>> communicate through the pgpool? and if I read the postgresql logs
>>> correct for both nodes all SQL statement are executed in the same
>>> order until it detach.
>>>
>>> /Flemming
>>>
>>> 2012/12/31 Tatsuo Ishii <ishii at postgresql.org>:
>>>>> Hello,
>>>>>
>>>>> We have been using pgpool2 for sometime now and been happy with it,
>>>>> but lately it suddenly start to detach the database on one of the
>>>>> nodes on 2 node cluster. I have been investigated this for a while and
>>>>> I can't understand why pgpool2 thinks is should detach.
>>>>>
>>>>> We are using pgpool version 3.0.4-1 with postgresql version
>>>>> 8.4.8-0squeeze2 our application server is JBossAS 5 including (jboss
>>>>> messaging 1.4.8-SP2). The application server only communicate through
>>>>> pgpool so we are sure that no other processes are working around
>>>>> pgpool
>>>>>
>>>>> We are pretty sure the databases are not different from the beginning
>>>>> and it's new records that are created. We post 3 messages on 2
>>>>> different jms queues and 3 clients that consumes the messages. When
>>>>> jboss messaging component want to remove the messages because it
>>>>> delivered to all the clients, pgpool detach the database because it
>>>>> get a different response from node 1 when it want to delete the
>>>>> message.... which I don't understand how that's possible
>>>>>
>>>>> I really will appreciate some help to understand what is going on and
>>>>> why it detach the database
>>>>>
>>>>> Thanks!
>>>>>
>>>>> br,
>>>>> Flemming
>>>>>
>>>>> the log_line_prefix = '%t %p %v %x' for the postgresql
>>>>>
>>>>> You can find the log files by following the links below for pgpool2
>>>>> debug log and postgresql log from both servers
>>>>>
>>>>> jboss-detach-190.sql(postgresql log) >
>>>>> http://ubuntuone.com/6Ku56EoHI7FAXAyC1p1prQ
>>>>> jboss-detach-191.sql(postgresql log) >
>>>>> http://ubuntuone.com/0ICbQCiowqDgKe7LglMxSV
>>>>> pgpool.conf > http://ubuntuone.com/3BhoRnr3ACifYhi2QqSbat
>>>>> pgppool-191-log  > http://ubuntuone.com/1g8ExrevBeRUj92XS5WjyZ7
>>>>
>>>> From the log, the cause of the detach was this:
>>>>
>>>> Dec 27 19:54:18 SWDEV035 pgpool: 2012-12-27 19:54:18 ERROR: pid 18412: pgpool detected difference of the number of inserted, updated or deleted tuples. Possible last query was: "DELETE FROM JBM_MSG WHERE MESSAGE_ID = $1 AND NOT EXISTS (SELECT JBM_MSG_REF.MESSAGE_ID FROM JBM_MSG_REF WHERE JBM_MSG_REF.MESSAGE_ID = $2)"
>>>> Dec 27 19:54:18 SWDEV035 pgpool: 2012-12-27 19:54:18 LOG:   pid 18412: CommandComplete: Number of affected tuples are: 0 1
>>>>
>>>> As you said, it seems your node 0 DB did not have a raw satisfied the
>>>> WHERE clause, while your node 1 had one row which satisfied it at that
>>>> time. I suggest to check tables used by JBoss right after failover to
>>>> see there's difference in table's data.
>>>> --
>>>> Tatsuo Ishii
>>>> SRA OSS, Inc. Japan
>>>> English: http://www.sraoss.co.jp/index_en.php
>>>> Japanese: http://www.sraoss.co.jp
>>> _______________________________________________
>>> pgpool-general mailing list
>>> pgpool-general at pgpool.net
>>> http://www.pgpool.net/mailman/listinfo/pgpool-general


More information about the pgpool-general mailing list