Re: Problem with committing in XA mode

Here is the log with the settings zou have suggested:

--
database_A SID:496f4f4d.454 16:12:09.578 LOG: duration: 0.000 ms bind
S_1: BEGIN
database_A SID:496f4f4d.454 16:12:09.578 LOG: execute S_1: BEGIN
database_A SID:496f4f4d.454 16:12:09.578 LOG: duration: 0.000 ms
database_A SID:496f4f4d.454 16:12:09.578 LOG: duration: 0.000 ms
parse <unnamed>: select count(*) from t0
database_A SID:496f4f4d.454 16:12:09.578 LOG: duration: 0.000 ms bind
<unnamed>: select count(*) from t0
database_A SID:496f4f4d.454 16:12:09.578 LOG: execute <unnamed>:
select count(*) from t0
database_A SID:496f4f4d.454 16:12:09.578 LOG: duration: 0.000 ms
database_A SID:496f4f4d.454 16:12:09.578 LOG: duration: 0.000 ms bind
S_2: COMMIT
database_A SID:496f4f4d.454 16:12:09.578 LOG: execute S_2: COMMIT
database_A SID:496f4f4d.454 16:12:09.578 LOG: duration: 0.000 ms
database_A SID:496f4f4d.454 16:12:09.593 LOG: duration: 0.000 ms bind
S_1: BEGIN
database_A SID:496f4f4d.454 16:12:09.593 LOG: execute S_1: BEGIN
database_A SID:496f4f4d.454 16:12:09.593 LOG: duration: 0.000 ms
database_A SID:496f4f4d.454 16:12:09.593 LOG: duration: 0.000 ms
parse <unnamed>: SELECT SOME_SEQ.nextval FROM dual
database_A SID:496f4f4d.454 16:12:09.593 LOG: duration: 0.000 ms bind
<unnamed>: SELECT SOME_SEQ.nextval FROM dual
database_A SID:496f4f4d.454 16:12:09.593 LOG: execute <unnamed>:
SELECT SOME_SEQ.nextval FROM dual
database_A SID:496f4f4d.454 16:12:09.593 LOG: duration: 0.000 ms
database_A SID:496f4f4d.454 16:12:09.609 LOG: duration: 0.000 ms bind
S_2: COMMIT
database_A SID:496f4f4d.454 16:12:09.609 LOG: execute S_2: COMMIT
database_A SID:496f4f4d.454 16:12:09.609 LOG: duration: 0.000 ms
database_A SID:496f4f4d.454 16:12:09.609 LOG: duration: 0.000 ms
parse <unnamed>: SHOW TRANSACTION ISOLATION LEVEL
database_A SID:496f4f4d.454 16:12:09.609 LOG: duration: 0.000 ms bind
<unnamed>: SHOW TRANSACTION ISOLATION LEVEL
database_A SID:496f4f4d.454 16:12:09.609 LOG: execute <unnamed>: SHOW
TRANSACTION ISOLATION LEVEL
database_A SID:496f4f4d.454 16:12:09.609 LOG: duration: 0.000 ms
database_A SID:496f4f4d.454 16:12:09.625 LOG: duration: 0.000 ms bind
S_1: BEGIN
database_A SID:496f4f4d.454 16:12:09.625 LOG: execute S_1: BEGIN
database_A SID:496f4f4d.454 16:12:09.625 LOG: duration: 0.000 ms
database_A SID:496f4f4d.454 16:12:09.625 LOG: duration: 0.000 ms
parse <unnamed>: SOME SELECT
database_A SID:496f4f4d.454 16:12:09.625 LOG: duration: 0.000 ms bind
<unnamed>: SOME SELECT
database_A SID:496f4f4d.454 16:12:09.625 LOG: execute <unnamed>: SOME
SELECT
database_A SID:496f4f4d.454 16:12:09.625 LOG: duration: 0.000 ms
database_A SID:496f4f4d.454 16:12:09.656 LOG: duration: 0.000 ms
parse <unnamed>: SOME SELECT
database_A SID:496f4f4d.454 16:12:09.656 LOG: duration: 0.000 ms bind
<unnamed>: SOME SELECT
database_A SID:496f4f4d.454 16:12:09.656 DETAIL: parameters: $1 = '1234'
database_A SID:496f4f4d.454 16:12:09.656 LOG: execute <unnamed>: SOME
SELECT
database_A SID:496f4f4d.454 16:12:09.656 DETAIL: parameters: $1 = '1234'
database_A SID:496f4f4d.454 16:12:09.656 LOG: duration: 0.000 ms
database_A SID:496f4f4d.454 16:12:09.671 LOG: duration: 0.000 ms bind
S_2: COMMIT
database_A SID:496f4f4d.454 16:12:09.671 LOG: execute S_2: COMMIT
database_A SID:496f4f4d.454 16:12:09.671 LOG: duration: 0.000 ms
database_A SID:496f4ed6.200 16:12:09.671 LOG: duration: 0.000 ms bind
S_1: BEGIN
database_A SID:496f4ed6.200 16:12:09.671 LOG: execute S_1: BEGIN
database_A SID:496f4ed6.200 16:12:09.671 LOG: duration: 0.000 ms
database_A SID:496f4ed6.200 16:12:09.671 LOG: duration: 0.000 ms
parse <unnamed>: select count(*) from t0
database_A SID:496f4ed6.200 16:12:09.671 LOG: duration: 0.000 ms bind
<unnamed>: select count(*) from t0
database_A SID:496f4ed6.200 16:12:09.671 LOG: execute <unnamed>:
select count(*) from t0
database_A SID:496f4ed6.200 16:12:09.671 LOG: duration: 0.000 ms
database_A SID:496f4ed6.200 16:12:09.671 LOG: duration: 0.000 ms bind
S_2: COMMIT
database_A SID:496f4ed6.200 16:12:09.671 LOG: execute S_2: COMMIT
database_A SID:496f4ed6.200 16:12:09.671 LOG: duration: 0.000 ms
database_A SID:496f4ed6.200 16:12:09.687 LOG: duration: 0.000 ms bind
S_1: BEGIN
database_A SID:496f4ed6.200 16:12:09.687 LOG: execute S_1: BEGIN
database_A SID:496f4ed6.200 16:12:09.687 LOG: duration: 0.000 ms
database_A SID:496f4ed6.200 16:12:09.687 LOG: duration: 0.000 ms
parse <unnamed>: SOME UPDATE
database_A SID:496f4ed6.200 16:12:09.687 LOG: duration: 0.000 ms bind
<unnamed>: SOME UPDATE
database_A SID:496f4ed6.200 16:12:09.687 DETAIL: parameters: $1 = 'a',
$2 = '1234', $3 = '2008-01-01 00:00:00'
database_A SID:496f4ed6.200 16:12:09.687 LOG: execute <unnamed>: SOME
UPDATE
database_A SID:496f4ed6.200 16:12:09.687 DETAIL: parameters: $1 = 'A',
$2 = '1234', $3 = '2008-01-01 00:00:00'
database_A SID:496f4ed6.200 16:12:09.687 LOG: duration: 0.000 ms
database_A SID:496f4ed6.200 16:12:09.687 LOG: duration: 0.000 ms bind
S_2: COMMIT
database_A SID:496f4ed6.200 16:12:09.687 LOG: execute S_2: COMMIT
database_A SID:496f4ed6.200 16:12:09.687 LOG: duration: 0.000 ms
database_A SID:496f4ed6.200 16:12:09.687 LOG: duration: 0.000 ms
parse <unnamed>: SHOW TRANSACTION ISOLATION LEVEL
database_A SID:496f4ed6.200 16:12:09.687 LOG: duration: 0.000 ms bind
<unnamed>: SHOW TRANSACTION ISOLATION LEVEL
database_A SID:496f4ed6.200 16:12:09.687 LOG: execute <unnamed>: SHOW
TRANSACTION ISOLATION LEVEL
database_A SID:496f4ed6.200 16:12:09.687 LOG: duration: 0.000 ms
database_A SID:496f4f4d.454 16:12:09.703 LOG: duration: 0.000 ms
parse <unnamed>: SHOW TRANSACTION ISOLATION LEVEL
database_A SID:496f4f4d.454 16:12:09.703 LOG: duration: 0.000 ms bind
<unnamed>: SHOW TRANSACTION ISOLATION LEVEL
database_A SID:496f4f4d.454 16:12:09.703 LOG: execute <unnamed>: SHOW
TRANSACTION ISOLATION LEVEL
database_A SID:496f4f4d.454 16:12:09.703 LOG: duration: 0.000 ms
database_A SID:496f4f4d.454 16:12:10.062 LOG: duration: 0.000 ms bind
S_1: BEGIN
database_A SID:496f4f4d.454 16:12:10.062 LOG: execute S_1: BEGIN
database_A SID:496f4f4d.454 16:12:10.062 LOG: duration: 0.000 ms
database_A SID:496f4f4d.454 16:12:10.062 LOG: duration: 0.000 ms
parse <unnamed>: SOME SELECT
database_A SID:496f4f4d.454 16:12:10.062 LOG: duration: 0.000 ms bind
<unnamed>: SOME SELECT
database_A SID:496f4f4d.454 16:12:10.062 LOG: execute <unnamed>: SOME
SELECT
database_A SID:496f4f4d.454 16:12:10.062 LOG: duration: 0.000 ms
database_A SID:496f4f4d.454 16:12:10.171 LOG: duration: 0.000 ms bind
S_2: COMMIT
database_A SID:496f4f4d.454 16:12:10.171 LOG: execute S_2: COMMIT
database_A SID:496f4f4d.454 16:12:10.171 LOG: duration: 0.000 ms
database_A SID:496f4f4d.454 16:12:10.171 LOG: duration: 0.000 ms
parse <unnamed>: SHOW TRANSACTION ISOLATION LEVEL
database_A SID:496f4f4d.454 16:12:10.171 LOG: duration: 0.000 ms bind
<unnamed>: SHOW TRANSACTION ISOLATION LEVEL
database_A SID:496f4f4d.454 16:12:10.171 LOG: execute <unnamed>: SHOW
TRANSACTION ISOLATION LEVEL
database_A SID:496f4f4d.454 16:12:10.171 LOG: duration: 0.000 ms
database_A SID:496f4f4d.454 16:12:27.531 LOG: duration: 0.000 ms bind
S_1: BEGIN
database_A SID:496f4f4d.454 16:12:27.531 LOG: execute S_1: BEGIN
database_A SID:496f4f4d.454 16:12:27.531 LOG: duration: 0.000 ms
database_A SID:496f4f4d.454 16:12:27.531 LOG: duration: 0.000 ms
parse <unnamed>: select count(*) from t0
database_A SID:496f4f4d.454 16:12:27.531 LOG: duration: 0.000 ms bind
<unnamed>: select count(*) from t0
database_A SID:496f4f4d.454 16:12:27.531 LOG: execute <unnamed>:
select count(*) from t0
database_A SID:496f4f4d.454 16:12:27.531 LOG: duration: 0.000 ms
database_A SID:496f4f4d.454 16:12:27.531 LOG: duration: 0.000 ms bind
S_2: COMMIT
database_A SID:496f4f4d.454 16:12:27.531 LOG: execute S_2: COMMIT
database_A SID:496f4f4d.454 16:12:27.531 LOG: duration: 0.000 ms
database_A SID:496f4f4d.454 16:12:27.546 LOG: duration: 0.000 ms bind
S_1: BEGIN
database_A SID:496f4f4d.454 16:12:27.546 LOG: execute S_1: BEGIN
database_A SID:496f4f4d.454 16:12:27.546 LOG: duration: 0.000 ms
database_A SID:496f4f4d.454 16:12:27.546 LOG: duration: 0.000 ms
parse <unnamed>: SOME SELECT
database_A SID:496f4f4d.454 16:12:27.546 LOG: duration: 0.000 ms bind
<unnamed>: SOME SELECT
database_A SID:496f4f4d.454 16:12:27.546 DETAIL: parameters: $1 =
'abcd', $2 = 'EFGH'
database_A SID:496f4f4d.454 16:12:27.546 LOG: execute <unnamed>: SOME
SELECT
database_A SID:496f4f4d.454 16:12:27.546 DETAIL: parameters: $1 =
'abcd', $2 = 'EFGH'
database_A SID:496f4f4d.454 16:12:27.546 LOG: duration: 0.000 ms
database_A SID:496f4f4d.454 16:12:27.578 LOG: duration: 0.000 ms bind
S_2: COMMIT
database_A SID:496f4f4d.454 16:12:27.578 LOG: execute S_2: COMMIT
database_A SID:496f4f4d.454 16:12:27.578 LOG: duration: 0.000 ms
database_A SID:496f4f4d.454 16:12:27.578 LOG: duration: 0.000 ms
parse <unnamed>: SHOW TRANSACTION ISOLATION LEVEL
database_A SID:496f4f4d.454 16:12:27.578 LOG: duration: 0.000 ms bind
<unnamed>: SHOW TRANSACTION ISOLATION LEVEL
database_A SID:496f4f4d.454 16:12:27.578 LOG: execute <unnamed>: SHOW
TRANSACTION ISOLATION LEVEL
database_A SID:496f4f4d.454 16:12:27.578 LOG: duration: 0.000 ms
database_A SID:496f4f4d.454 16:12:27.625 LOG: duration: 0.000 ms bind
S_1: BEGIN
database_A SID:496f4f4d.454 16:12:27.625 LOG: execute S_1: BEGIN
database_A SID:496f4f4d.454 16:12:27.625 LOG: duration: 0.000 ms
database_A SID:496f4f4d.454 16:12:27.625 LOG: duration: 0.000 ms
parse <unnamed>: SOME SELECT FOR UPDATE
database_A SID:496f4f4d.454 16:12:27.625 LOG: duration: 0.000 ms bind
<unnamed>: SOME SELECT FOR UPDATE
database_A SID:496f4f4d.454 16:12:27.625 DETAIL: parameters: $1 =
'abcd', $2 = 'EFGH'
database_A SID:496f4f4d.454 16:12:27.625 LOG: execute <unnamed>: SOME
SELECT FOR UPDATE
database_A SID:496f4f4d.454 16:12:27.625 DETAIL: parameters: $1 =
'abcd', $2 = 'EFGH'
database_A SID:496f4f4d.454 16:12:27.625 LOG: duration: 0.000 ms

database_B SID:496f4ed7.e04 16:12:27.859 LOG: duration: 0.000 ms bind
S_1: BEGIN
database_B SID:496f4ed7.e04 16:12:27.859 LOG: execute S_1: BEGIN
database_B SID:496f4ed7.e04 16:12:27.859 LOG: duration: 0.000 ms
database_B SID:496f4ed7.e04 16:12:27.859 LOG: duration: 0.000 ms
parse <unnamed>: select count(*) from t0
database_B SID:496f4ed7.e04 16:12:27.859 LOG: duration: 0.000 ms bind
<unnamed>: select count(*) from t0
database_B SID:496f4ed7.e04 16:12:27.859 LOG: execute <unnamed>:
select count(*) from t0
database_B SID:496f4ed7.e04 16:12:27.875 LOG: duration: 15.999 ms
database_B SID:496f4ed7.e04 16:12:27.875 LOG: duration: 0.000 ms bind
S_2: COMMIT
database_B SID:496f4ed7.e04 16:12:27.875 LOG: execute S_2: COMMIT
database_B SID:496f4ed7.e04 16:12:27.875 LOG: duration: 0.000 ms
database_B SID:496f4ed7.e04 16:12:27.875 LOG: duration: 0.000 ms bind
S_1: BEGIN
database_B SID:496f4ed7.e04 16:12:27.875 LOG: execute S_1: BEGIN
database_B SID:496f4ed7.e04 16:12:27.875 LOG: duration: 0.000 ms
database_B SID:496f4ed7.e04 16:12:27.875 LOG: duration: 0.000 ms
parse <unnamed>: SOME SELECT
database_B SID:496f4ed7.e04 16:12:27.890 LOG: duration: 14.999 ms
bind <unnamed>: SOME SELECT
database_B SID:496f4ed7.e04 16:12:27.890 DETAIL: parameters: $1 =
'abcd', $2 = 'EFGH'
database_B SID:496f4ed7.e04 16:12:27.890 LOG: execute <unnamed>: SOME
SELECT FOR UPDATE
database_B SID:496f4ed7.e04 16:12:27.890 DETAIL: parameters: $1 =
'abcd', $2 = 'EFGH'
database_B SID:496f4ed7.e04 16:12:27.890 LOG: duration: 0.000 ms

database_A SID:496f4f4d.454 16:12:27.937 LOG: duration: 0.000 ms bind
S_2: COMMIT
database_A SID:496f4f4d.454 16:12:27.937 LOG: execute S_2: COMMIT
database_A SID:496f4f4d.454 16:12:27.937 LOG: duration: 0.000 ms

database_B SID:496f4ed7.e04 16:12:27.953 LOG: duration: 0.000 ms
parse <unnamed>: PREPARE TRANSACTION
'48801_AOiMyUwnZ6MjBA==_Q3ZoYXZyYW5la2pkYmNEU1BhcmFt'

database_A SID:496f4f4d.454 16:12:27.953 LOG: duration: 0.000 ms
parse <unnamed>: PREPARE TRANSACTION
'48801_AOiMyUwnZ6MjBA==_Q3ZoYXZyYW5la2pkYmNEU0xpdmU='
database_A SID:496f4f4d.454 16:12:27.953 LOG: duration: 0.000 ms bind
<unnamed>: PREPARE TRANSACTION
'48801_AOiMyUwnZ6MjBA==_Q3ZoYXZyYW5la2pkYmNEU0xpdmU='

database_B SID:496f4ed7.e04 16:12:27.953 LOG: duration: 0.000 ms bind
<unnamed>: PREPARE TRANSACTION
'48801_AOiMyUwnZ6MjBA==_Q3ZoYXZyYW5la2pkYmNEU1BhcmFt'

database_A SID:496f4f4d.454 16:12:27.953 LOG: execute <unnamed>:
PREPARE TRANSACTION '48801_AOiMyUwnZ6MjBA==_Q3ZoYXZyYW5la2pkYmNEU0xpdmU='
database_B SID:496f4ed7.e04 16:12:27.953 LOG: execute <unnamed>:
PREPARE TRANSACTION '48801_AOiMyUwnZ6MjBA==_Q3ZoYXZyYW5la2pkYmNEU1BhcmFt'
database_A SID:496f4f4d.454 16:12:27.953 LOG: duration: 0.000 ms

database_B SID:496f4ed7.e04 16:12:27.968 LOG: duration: 14.999 ms

database_A SID:496f4f4d.454 16:12:28.000 LOG: duration: 0.000 ms
parse <unnamed>: COMMIT PREPARED
'48801_AOiMyUwnZ6MjBA==_Q3ZoYXZyYW5la2pkYmNEU0xpdmU='
database_A SID:496f4f4d.454 16:12:28.000 LOG: duration: 0.000 ms bind
<unnamed>: COMMIT PREPARED
'48801_AOiMyUwnZ6MjBA==_Q3ZoYXZyYW5la2pkYmNEU0xpdmU='

database_B SID:496f4ed7.e04 16:12:28.000 LOG: duration: 0.000 ms
parse <unnamed>: COMMIT PREPARED
'48801_AOiMyUwnZ6MjBA==_Q3ZoYXZyYW5la2pkYmNEU1BhcmFt'

database_A SID:496f4f4d.454 16:12:28.000 LOG: execute <unnamed>:
COMMIT PREPARED '48801_AOiMyUwnZ6MjBA==_Q3ZoYXZyYW5la2pkYmNEU0xpdmU='

database_B SID:496f4ed7.e04 16:12:28.000 LOG: duration: 0.000 ms bind
<unnamed>: COMMIT PREPARED
'48801_AOiMyUwnZ6MjBA==_Q3ZoYXZyYW5la2pkYmNEU1BhcmFt'

database_A SID:496f4f4d.454 16:12:28.000 ERROR: prepared transaction
with identifier "48801_AOiMyUwnZ6MjBA==_Q3ZoYXZyYW5la2pkYmNEU0xpdmU="
does not exist
database_A SID:496f4f4d.454 16:12:28.000 STATEMENT: COMMIT PREPARED
'48801_AOiMyUwnZ6MjBA==_Q3ZoYXZyYW5la2pkYmNEU0xpdmU='

database_B SID:496f4ed7.e04 16:12:28.000 LOG: execute <unnamed>:
COMMIT PREPARED '48801_AOiMyUwnZ6MjBA==_Q3ZoYXZyYW5la2pkYmNEU1BhcmFt'

database_A SID:496f4f4d.454 16:12:28.015 LOG: duration: 0.000 ms
parse <unnamed>: SHOW TRANSACTION ISOLATION LEVEL
database_A SID:496f4f4d.454 16:12:28.015 LOG: duration: 0.000 ms bind
<unnamed>: SHOW TRANSACTION ISOLATION LEVEL
database_A SID:496f4f4d.454 16:12:28.015 LOG: execute <unnamed>: SHOW
TRANSACTION ISOLATION LEVEL
database_A SID:496f4f4d.454 16:12:28.015 LOG: duration: 0.000 ms

database_B SID:496f4ed7.e04 16:12:28.015 LOG: duration: 14.999 ms
database_B SID:496f4ed7.e04 16:12:28.015 LOG: duration: 0.000 ms
parse <unnamed>: SHOW TRANSACTION ISOLATION LEVEL
database_B SID:496f4ed7.e04 16:12:28.015 LOG: duration: 0.000 ms bind
<unnamed>: SHOW TRANSACTION ISOLATION LEVEL
database_B SID:496f4ed7.e04 16:12:28.015 LOG: execute <unnamed>: SHOW
TRANSACTION ISOLATION LEVEL
database_B SID:496f4ed7.e04 16:12:28.015 LOG: duration: 0.000 ms

database_A SID:496f4f4d.454 16:12:29.421 LOG: duration: 0.000 ms
parse <unnamed>: COMMIT PREPARED
'48801_AF7jVNS8Z6MjBA==_Q3ZoYXZyYW5la2pkYmNEU0xpdmU='

database_B SID:496f4ed7.e04 16:12:29.421 LOG: duration: 0.000 ms
parse <unnamed>: COMMIT PREPARED
'48801_AF7jVNS8Z6MjBA==_Q3ZoYXZyYW5la2pkYmNEU1BhcmFt'

database_A SID:496f4f4d.454 16:12:29.421 LOG: duration: 0.000 ms bind
<unnamed>: COMMIT PREPARED
'48801_AF7jVNS8Z6MjBA==_Q3ZoYXZyYW5la2pkYmNEU0xpdmU='

database_B SID:496f4ed7.e04 16:12:29.421 LOG: duration: 0.000 ms bind
<unnamed>: COMMIT PREPARED
'48801_AF7jVNS8Z6MjBA==_Q3ZoYXZyYW5la2pkYmNEU1BhcmFt'

database_A SID:496f4f4d.454 16:12:29.421 LOG: execute <unnamed>:
COMMIT PREPARED '48801_AF7jVNS8Z6MjBA==_Q3ZoYXZyYW5la2pkYmNEU0xpdmU='

database_B SID:496f4ed7.e04 16:12:29.421 LOG: execute <unnamed>:
COMMIT PREPARED '48801_AF7jVNS8Z6MjBA==_Q3ZoYXZyYW5la2pkYmNEU1BhcmFt'

database_A SID:496f4f4d.454 16:12:29.421 ERROR: prepared transaction
with identifier "48801_AF7jVNS8Z6MjBA==_Q3ZoYXZyYW5la2pkYmNEU0xpdmU="
does not exist
database_A SID:496f4f4d.454 16:12:29.421 STATEMENT: COMMIT PREPARED
'48801_AF7jVNS8Z6MjBA==_Q3ZoYXZyYW5la2pkYmNEU0xpdmU='

database_B SID:496f4ed7.e04 16:12:29.421 ERROR: prepared transaction
with identifier "48801_AF7jVNS8Z6MjBA==_Q3ZoYXZyYW5la2pkYmNEU1BhcmFt"
does not exist
database_B SID:496f4ed7.e04 16:12:29.421 STATEMENT: COMMIT PREPARED
'48801_AF7jVNS8Z6MjBA==_Q3ZoYXZyYW5la2pkYmNEU1BhcmFt'
database_B SID:496f4ed7.e04 16:12:29.421 LOG: duration: 0.000 ms
parse <unnamed>: SHOW TRANSACTION ISOLATION LEVEL
database_B SID:496f4ed7.e04 16:12:29.421 LOG: duration: 0.000 ms bind
<unnamed>: SHOW TRANSACTION ISOLATION LEVEL
database_B SID:496f4ed7.e04 16:12:29.421 LOG: execute <unnamed>: SHOW
TRANSACTION ISOLATION LEVEL

database_A SID:496f4f4d.454 16:12:29.421 LOG: duration: 0.000 ms
parse <unnamed>: SHOW TRANSACTION ISOLATION LEVEL

database_B SID:496f4ed7.e04 16:12:29.421 LOG: duration: 0.000 ms

database_A SID:496f4f4d.454 16:12:29.421 LOG: duration: 0.000 ms bind
<unnamed>: SHOW TRANSACTION ISOLATION LEVEL
database_A SID:496f4f4d.454 16:12:29.421 LOG: execute <unnamed>: SHOW
TRANSACTION ISOLATION LEVEL
database_A SID:496f4f4d.454 16:12:29.421 LOG: duration: 0.000 ms
--

Thx in advance,

Regards

VH

Heikki Linnakangas wrote:
> Vlastimil Havranek wrote:
>> Thx a lot for prompt answer, here is a slightly more detailed log:
>>
>> --
>> 2009-01-15 14:59:56 LOG: duration: 0.000 ms parse <unnamed>:
>> PREPARE TRANSACTION
>> '48801_AF7jVNS8Z6MjBA==_Q3ZoYXZyYW5la2pkYmNEU1BhcmFt'
>> 2009-01-15 14:59:56 LOG: duration: 0.000 ms bind <unnamed>: PREPARE
>> TRANSACTION '48801_AF7jVNS8Z6MjBA==_Q3ZoYXZyYW5la2pkYmNEU1BhcmFt'
>> 2009-01-15 14:59:56 LOG: execute <unnamed>: PREPARE TRANSACTION
>> '48801_AF7jVNS8Z6MjBA==_Q3ZoYXZyYW5la2pkYmNEU1BhcmFt'
>> 2009-01-15 14:59:56 LOG: duration: 0.000 ms parse <unnamed>:
>> PREPARE TRANSACTION
>> '48801_AF7jVNS8Z6MjBA==_Q3ZoYXZyYW5la2pkYmNEU0xpdmU='
>> 2009-01-15 14:59:56 LOG: duration: 0.000 ms bind <unnamed>: PREPARE
>> TRANSACTION '48801_AF7jVNS8Z6MjBA==_Q3ZoYXZyYW5la2pkYmNEU0xpdmU='
>> 2009-01-15 14:59:56 LOG: execute <unnamed>: PREPARE TRANSACTION
>> '48801_AF7jVNS8Z6MjBA==_Q3ZoYXZyYW5la2pkYmNEU0xpdmU='
>> 2009-01-15 14:59:56 LOG: duration: 0.000 ms
>> 2009-01-15 14:59:56 LOG: duration: 0.000 ms
>> 2009-01-15 14:59:56 LOG: duration: 0.000 ms parse <unnamed>: COMMIT
>> PREPARED '48801_AF7jVNS8Z6MjBA==_Q3ZoYXZyYW5la2pkYmNEU1BhcmFt'
>> 2009-01-15 14:59:56 LOG: duration: 0.000 ms bind <unnamed>: COMMIT
>> PREPARED '48801_AF7jVNS8Z6MjBA==_Q3ZoYXZyYW5la2pkYmNEU1BhcmFt'
>> 2009-01-15 14:59:56 LOG: execute <unnamed>: COMMIT PREPARED
>> '48801_AF7jVNS8Z6MjBA==_Q3ZoYXZyYW5la2pkYmNEU1BhcmFt'
>> 2009-01-15 14:59:56 LOG: duration: 0.000 ms parse <unnamed>: COMMIT
>> PREPARED '48801_AF7jVNS8Z6MjBA==_Q3ZoYXZyYW5la2pkYmNEU0xpdmU='
>> 2009-01-15 14:59:56 LOG: duration: 0.000 ms bind <unnamed>: COMMIT
>> PREPARED '48801_AF7jVNS8Z6MjBA==_Q3ZoYXZyYW5la2pkYmNEU0xpdmU='
>> 2009-01-15 14:59:56 LOG: execute <unnamed>: COMMIT PREPARED
>> '48801_AF7jVNS8Z6MjBA==_Q3ZoYXZyYW5la2pkYmNEU0xpdmU='
>> 2009-01-15 14:59:56 ERROR: prepared transaction with identifier
>> "48801_AF7jVNS8Z6MjBA==_Q3ZoYXZyYW5la2pkYmNEU0xpdmU=" does not exist
>> 2009-01-15 14:59:56 STATEMENT: COMMIT PREPARED
>> '48801_AF7jVNS8Z6MjBA==_Q3ZoYXZyYW5la2pkYmNEU0xpdmU='
>
> Hmm, it looks like the server is getting a COMMIT, followed by two
> PREPARE TRANSACTION commands in a row:
>
> BEGIN
> ...
> COMMIT
> PREPARE TRANSACTION '48801_AF7jVNS8Z6MjBA==_Q3ZoYXZyYW5la2pkYmNEU0xpdmU='
> PREPARE TRANSACTION '48801_AF7jVNS8Z6MjBA==_Q3ZoYXZyYW5la2pkYmNEU0xpdmU='
>
> I presume there's multiple backends issuing these commands
> concurrently, otherwise both PREPARE TRANSACTION commands should fail
> with "there is no transaction in progress" warning.
>
> One theory is that the 2nd PREPARE TRANSACTION *is* failing, and gives
> a WARNING, but we're not seeing that in any of the logs. I don't know
> why that might happen, but I notice that we don't have a check for
> that case in the JDBC driver's prepare() method, so the application
> server would think that the transaction prepare succeeded.
>
> Please make sure you have log_min_messages set to "warning" (or lower,
> e.g "notice") and try again. Also, %c would be very helpful in
> log_line_prefix, so that we could tell apart actions of different
> backends in the log.
>

--
-------------------------------------------------------------
Vlastimil Havránek
Software Developer
xitee k.s. || www.xitee.com || vlastimil(dot)havranek(at)xitee(dot)com
Phone: office +420 234262342, mobile +420 775366990
-------------------------------------------------------------