Received: from maia.hub.org (unknown [200.46.208.211]) by mail.postgresql.org (Postfix) with ESMTP id 8E0A3632B31 for ; Wed, 3 Mar 2010 06:58:08 -0400 (AST) Received: from mail.postgresql.org ([200.46.204.86]) by maia.hub.org (mx1.hub.org [200.46.208.211]) (amavisd-maia, port 10024) with ESMTP id 68343-07 for ; Wed, 3 Mar 2010 10:57:52 +0000 (UTC) X-Greylist: from auto-whitelisted by SQLgrey-1.7.6 Received: from smadev.internal.net (host3.dynacom.ondsl.gr [62.103.35.211]) by mail.postgresql.org (Postfix) with ESMTP id 3A1C9634000 for ; Wed, 3 Mar 2010 06:57:56 -0400 (AST) Received: from smadev.internal.net (localhost [127.0.0.1]) by smadev.internal.net (8.14.2/8.14.2) with ESMTP id o23AviM5039856; Wed, 3 Mar 2010 12:57:44 +0200 (EET) (envelope-from achill@matrix.gatewaynet.com) Received: from localhost (localhost [[UNIX: localhost]]) by smadev.internal.net (8.14.2/8.14.2/Submit) id o23AvV4o039853; Wed, 3 Mar 2010 12:57:31 +0200 (EET) (envelope-from achill@matrix.gatewaynet.com) From: Achilleas Mantzios Organization: Dynacom Tankers Mgmt To: pgsql-jdbc@postgresql.org Subject: Re: Very Dangerous bug in XA connection pooling and SL EJBs with jboss-4.2.3 & latest postgresql-8.4-701.jdbc3.jar Date: Wed, 3 Mar 2010 12:57:31 +0200 User-Agent: KMail/1.9.7 Cc: Heikki Linnakangas , jboss-user@lists.jboss.org References: <201003011731.15724.achill@matrix.gatewaynet.com> <201003031209.41358.achill@matrix.gatewaynet.com> <4B8E3A4D.9000809@enterprisedb.com> In-Reply-To: <4B8E3A4D.9000809@enterprisedb.com> MIME-Version: 1.0 Content-Type: text/plain; charset="utf-8" Content-Transfer-Encoding: quoted-printable Content-Disposition: inline Message-Id: <201003031257.31670.achill@matrix.gatewaynet.com> X-Virus-Scanned: Maia Mailguard 1.0.1 X-Spam-Status: No, hits=-2.298 tagged_above=-10 required=5 tests=AWL=0.301, BAYES_00=-2.599 X-Spam-Level: X-Archive-Number: 201003/11 X-Sequence-Number: 20351 Thanx Here are the logs: call to the ejb =3D=3D=3D=3D=3D=3D=3D=3D=3D 2010-03-03 12:47:57,177 INFO [STDOUT] 12:47:57.177 (2) XAResource 1291479:= starting transaction xid =3D < 131075, 26, 24, 1-a09c8d8:d10e:4b8e3e06:32a= 09c8d8:d10e:4b8e3e06:34 > 2010-03-03 12:47:57,181 INFO [STDOUT] 12:47:57.180 (2) simple execute, han= dler=3Dorg.postgresql.jdbc2.AbstractJdbc2Statement$StatementResultHandler@d= d0f87, maxRows=3D0, fetchSize=3D0, flags=3D1 2010-03-03 12:47:57,184 INFO [STDOUT] 12:47:57.183 (2) FE=3D> Parse(stmt= =3DS_1,query=3D"BEGIN",oids=3D{}) 2010-03-03 12:47:57,185 INFO [STDOUT] 12:47:57.184 (2) FE=3D> Bind(stmt= =3DS_1,portal=3Dnull) 2010-03-03 12:47:57,185 INFO [STDOUT] 12:47:57.185 (2) FE=3D> Execute(por= tal=3Dnull,limit=3D0) 2010-03-03 12:47:57,186 INFO [STDOUT] 12:47:57.186 (2) FE=3D> Parse(stmt= =3Dnull,query=3D"select apptblidval,colname from status where assettable=3D= $1 and assetidval=3D$2 and appname=3D$3 and apptblname=3D$4 and status=3D$5= and isvalid order by apptblidval",oids=3D{1043,23,1043,1043,1043}) 2010-03-03 12:47:57,188 INFO [STDOUT] 12:47:57.187 (2) FE=3D> Bind(stmt= =3Dnull,portal=3Dnull,$1=3D<'mariner'>,$2=3D<'14173'>,$3=3D<'Crew'>,$4=3D<'= marinercourses'>,$5=3D<'warn'>) 2010-03-03 12:47:57,189 INFO [STDOUT] 12:47:57.189 (2) FE=3D> Describe(po= rtal=3Dnull) 2010-03-03 12:47:57,190 INFO [STDOUT] 12:47:57.190 (2) FE=3D> Execute(por= tal=3Dnull,limit=3D0) 2010-03-03 12:47:57,192 INFO [STDOUT] 12:47:57.192 (2) FE=3D> Sync 2010-03-03 12:47:57,199 INFO [STDOUT] 12:47:57.199 (2) <=3DBE ParseComple= te [S_1] 2010-03-03 12:47:57,200 INFO [STDOUT] 12:47:57.200 (2) <=3DBE BindComplet= e [null] 2010-03-03 12:47:57,200 INFO [STDOUT] 12:47:57.200 (2) <=3DBE CommandStat= us(BEGIN) 2010-03-03 12:47:57,201 INFO [STDOUT] 12:47:57.201 (2) <=3DBE ParseComple= te [null] 2010-03-03 12:47:57,202 INFO [STDOUT] 12:47:57.201 (2) <=3DBE BindComplet= e [null] 2010-03-03 12:47:57,202 INFO [STDOUT] 12:47:57.202 (2) <=3DBE RowDescript= ion(2) 2010-03-03 12:47:57,203 INFO [STDOUT] 12:47:57.203 (2) <=3DBE CommandStat= us(SELECT) 2010-03-03 12:47:57,203 INFO [STDOUT] 12:47:57.203 (2) <=3DBE ReadyForQue= ry(T) 2010-03-03 12:47:57,206 INFO [STDOUT] 12:47:57.204 (2) XAResource 1291479:= ending transaction xid =3D < 131075, 26, 24, 1-a09c8d8:d10e:4b8e3e06:32a09= c8d8:d10e:4b8e3e06:34 > 2010-03-03 12:47:57,211 INFO [STDOUT] 12:47:57.211 (2) XAResource 1291479:= committing xid =3D < 131075, 26, 24, 1-a09c8d8:d10e:4b8e3e06:32a09c8d8:d10= e:4b8e3e06:34 > (one phase) 2010-03-03 12:47:57,217 INFO [STDOUT] 12:47:57.217 (2) simple execute, han= dler=3Dorg.postgresql.jdbc2.AbstractJdbc2Connection$TransactionCommandHandl= er@1a9b034, maxRows=3D0, fetchSize=3D0, flags=3D22 2010-03-03 12:47:57,225 INFO [STDOUT] 12:47:57.225 (2) FE=3D> Parse(stmt= =3DS_2,query=3D"COMMIT",oids=3D{}) 2010-03-03 12:47:57,227 INFO [STDOUT] 12:47:57.227 (2) FE=3D> Bind(stmt= =3DS_2,portal=3Dnull) 2010-03-03 12:47:57,229 INFO [STDOUT] 12:47:57.228 (2) FE=3D> Execute(por= tal=3Dnull,limit=3D1) 2010-03-03 12:47:57,237 INFO [STDOUT] 12:47:57.237 (2) FE=3D> Sync 2010-03-03 12:47:57,246 INFO [STDOUT] 12:47:57.246 (2) <=3DBE ParseComple= te [S_2] 2010-03-03 12:47:57,248 INFO [STDOUT] 12:47:57.248 (2) <=3DBE BindComplet= e [null] 2010-03-03 12:47:57,250 INFO [STDOUT] 12:47:57.250 (2) <=3DBE CommandStat= us(COMMIT) 2010-03-03 12:47:57,251 INFO [STDOUT] 12:47:57.251 (2) <=3DBE ReadyForQue= ry(I) call to the java block - the one with con.setAutocommit(false) - (as we see= below its fine the very first time) =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D 2010-03-03 12:49:31,892 INFO [STDOUT] 12:49:31.892 (2) simple execute, han= dler=3Dorg.postgresql.jdbc2.AbstractJdbc2Statement$StatementResultHandler@1= 9331eb, maxRows=3D0, fetchSize=3D0, flags=3D1 2010-03-03 12:49:31,893 INFO [STDOUT] 12:49:31.893 (2) FE=3D> Bind(stmt= =3DS_1,portal=3Dnull) 2010-03-03 12:49:31,895 INFO [STDOUT] 12:49:31.895 (2) FE=3D> Execute(por= tal=3Dnull,limit=3D0) 2010-03-03 12:49:31,896 INFO [STDOUT] 12:49:31.895 (2) FE=3D> Parse(stmt= =3Dnull,query=3D"select now()",oids=3D{}) 2010-03-03 12:49:31,897 INFO [STDOUT] 12:49:31.897 (2) FE=3D> Bind(stmt= =3Dnull,portal=3Dnull) 2010-03-03 12:49:31,898 INFO [STDOUT] 12:49:31.898 (2) FE=3D> Describe(po= rtal=3Dnull) 2010-03-03 12:49:31,899 INFO [STDOUT] 12:49:31.899 (2) FE=3D> Execute(por= tal=3Dnull,limit=3D0) 2010-03-03 12:49:31,901 INFO [STDOUT] 12:49:31.901 (2) FE=3D> Sync 2010-03-03 12:49:31,903 INFO [STDOUT] 12:49:31.902 (2) <=3DBE BindComplet= e [null] 2010-03-03 12:49:31,904 INFO [STDOUT] 12:49:31.904 (2) <=3DBE CommandStat= us(BEGIN) 2010-03-03 12:49:31,904 INFO [STDOUT] 12:49:31.904 (2) <=3DBE ParseComple= te [null] 2010-03-03 12:49:31,905 INFO [STDOUT] 12:49:31.905 (2) <=3DBE BindComplet= e [null] 2010-03-03 12:49:31,905 INFO [STDOUT] 12:49:31.905 (2) <=3DBE RowDescript= ion(1) 2010-03-03 12:49:31,906 INFO [STDOUT] 12:49:31.906 (2) <=3DBE DataRow 2010-03-03 12:49:31,907 INFO [STDOUT] 12:49:31.907 (2) <=3DBE CommandStat= us(SELECT) 2010-03-03 12:49:31,908 INFO [STDOUT] 12:49:31.908 (2) <=3DBE ReadyForQue= ry(T) 2010-03-03 12:49:31,909 INFO [STDOUT] 12:49:31.909 (2) simple execute, han= dler=3Dorg.postgresql.jdbc2.AbstractJdbc2Connection$TransactionCommandHandl= er@1d7ce63, maxRows=3D0, fetchSize=3D0, flags=3D22 2010-03-03 12:49:31,910 INFO [STDOUT] 12:49:31.910 (2) FE=3D> Bind(stmt= =3DS_2,portal=3Dnull) 2010-03-03 12:49:31,911 INFO [STDOUT] 12:49:31.911 (2) FE=3D> Execute(por= tal=3Dnull,limit=3D1) 2010-03-03 12:49:31,913 INFO [STDOUT] 12:49:31.912 (2) FE=3D> Sync 2010-03-03 12:49:31,915 INFO [STDOUT] 12:49:31.915 (2) <=3DBE BindComplet= e [null] 2010-03-03 12:49:31,916 INFO [STDOUT] 12:49:31.916 (2) <=3DBE CommandStat= us(COMMIT) 2010-03-03 12:49:31,917 INFO [STDOUT] 12:49:31.917 (2) <=3DBE ReadyForQue= ry(I) call to the ejb (again - 2nd time) =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D 2010-03-03 12:50:24,246 INFO [STDOUT] 12:50:24.245 (2) XAResource 1291479:= starting transaction xid =3D < 131075, 26, 24, 1-a09c8d8:d10e:4b8e3e06:3ca= 09c8d8:d10e:4b8e3e06:3e > 2010-03-03 12:50:24,248 INFO [STDOUT] 12:50:24.247 (2) simple execute, han= dler=3Dorg.postgresql.jdbc2.AbstractJdbc2Statement$StatementResultHandler@a= 06e8d, maxRows=3D0, fetchSize=3D0, flags=3D1 2010-03-03 12:50:24,248 INFO [STDOUT] 12:50:24.248 (2) FE=3D> Bind(stmt= =3DS_1,portal=3Dnull) 2010-03-03 12:50:24,249 INFO [STDOUT] 12:50:24.249 (2) FE=3D> Execute(por= tal=3Dnull,limit=3D0) 2010-03-03 12:50:24,249 INFO [STDOUT] 12:50:24.249 (2) FE=3D> Parse(stmt= =3Dnull,query=3D"select apptblidval,colname from status where assettable=3D= $1 and assetidval=3D$2 and appname=3D$3 and apptblname=3D$4 and status=3D$5= and isvalid order by apptblidval",oids=3D{1043,23,1043,1043,1043}) 2010-03-03 12:50:24,250 INFO [STDOUT] 12:50:24.250 (2) FE=3D> Bind(stmt= =3Dnull,portal=3Dnull,$1=3D<'mariner'>,$2=3D<'14173'>,$3=3D<'Crew'>,$4=3D<'= marinercourses'>,$5=3D<'warn'>) 2010-03-03 12:50:24,251 INFO [STDOUT] 12:50:24.251 (2) FE=3D> Describe(po= rtal=3Dnull) 2010-03-03 12:50:24,252 INFO [STDOUT] 12:50:24.252 (2) FE=3D> Execute(por= tal=3Dnull,limit=3D0) 2010-03-03 12:50:24,253 INFO [STDOUT] 12:50:24.252 (2) FE=3D> Sync 2010-03-03 12:50:24,255 INFO [STDOUT] 12:50:24.255 (2) <=3DBE BindComplet= e [null] 2010-03-03 12:50:24,256 INFO [STDOUT] 12:50:24.256 (2) <=3DBE CommandStat= us(BEGIN) 2010-03-03 12:50:24,257 INFO [STDOUT] 12:50:24.257 (2) <=3DBE ParseComple= te [null] 2010-03-03 12:50:24,258 INFO [STDOUT] 12:50:24.258 (2) <=3DBE BindComplet= e [null] 2010-03-03 12:50:24,260 INFO [STDOUT] 12:50:24.260 (2) <=3DBE RowDescript= ion(2) 2010-03-03 12:50:24,261 INFO [STDOUT] 12:50:24.261 (2) <=3DBE CommandStat= us(SELECT) 2010-03-03 12:50:24,262 INFO [STDOUT] 12:50:24.262 (2) <=3DBE ReadyForQue= ry(T) 2010-03-03 12:50:24,263 INFO [STDOUT] 12:50:24.262 (2) XAResource 1291479:= ending transaction xid =3D < 131075, 26, 24, 1-a09c8d8:d10e:4b8e3e06:3ca09= c8d8:d10e:4b8e3e06:3e > 2010-03-03 12:50:24,264 INFO [STDOUT] 12:50:24.263 (2) XAResource 1291479:= committing xid =3D < 131075, 26, 24, 1-a09c8d8:d10e:4b8e3e06:3ca09c8d8:d10= e:4b8e3e06:3e > (one phase) 2010-03-03 12:50:24,265 INFO [STDOUT] 12:50:24.265 (2) simple execute, han= dler=3Dorg.postgresql.jdbc2.AbstractJdbc2Connection$TransactionCommandHandl= er@1217fef, maxRows=3D0, fetchSize=3D0, flags=3D22 2010-03-03 12:50:24,266 INFO [STDOUT] 12:50:24.266 (2) FE=3D> Bind(stmt= =3DS_2,portal=3Dnull) 2010-03-03 12:50:24,267 INFO [STDOUT] 12:50:24.267 (2) FE=3D> Execute(por= tal=3Dnull,limit=3D1) 2010-03-03 12:50:24,269 INFO [STDOUT] 12:50:24.269 (2) FE=3D> Sync 2010-03-03 12:50:24,272 INFO [STDOUT] 12:50:24.272 (2) <=3DBE BindComplet= e [null] 2010-03-03 12:50:24,273 INFO [STDOUT] 12:50:24.273 (2) <=3DBE CommandStat= us(COMMIT) 2010-03-03 12:50:24,274 INFO [STDOUT] 12:50:24.274 (2) <=3DBE ReadyForQue= ry(I) call to the java block - the one with con.setAutocommit(false) - again - 2n= d time - this time we have a problem =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D 2010-03-03 12:51:30,426 INFO [STDOUT] 12:51:30.426 (2) simple execute, han= dler=3Dorg.postgresql.jdbc2.AbstractJdbc2Statement$StatementResultHandler@1= 3b64eb, maxRows=3D0, fetchSize=3D0, flags=3D17 2010-03-03 12:51:30,427 INFO [STDOUT] 12:51:30.427 (2) FE=3D> Parse(stmt= =3Dnull,query=3D"select now()",oids=3D{}) 2010-03-03 12:51:30,428 INFO [STDOUT] 12:51:30.428 (2) FE=3D> Bind(stmt= =3Dnull,portal=3Dnull) 2010-03-03 12:51:30,429 INFO [STDOUT] 12:51:30.429 (2) FE=3D> Describe(po= rtal=3Dnull) 2010-03-03 12:51:30,429 INFO [STDOUT] 12:51:30.429 (2) FE=3D> Execute(por= tal=3Dnull,limit=3D0) 2010-03-03 12:51:30,430 INFO [STDOUT] 12:51:30.430 (2) FE=3D> Sync 2010-03-03 12:51:30,433 INFO [STDOUT] 12:51:30.433 (2) <=3DBE ParseComple= te [null] 2010-03-03 12:51:30,434 INFO [STDOUT] 12:51:30.434 (2) <=3DBE BindComplet= e [null] 2010-03-03 12:51:30,435 INFO [STDOUT] 12:51:30.435 (2) <=3DBE RowDescript= ion(1) 2010-03-03 12:51:30,436 INFO [STDOUT] 12:51:30.436 (2) <=3DBE DataRow 2010-03-03 12:51:30,437 INFO [STDOUT] 12:51:30.437 (2) <=3DBE CommandStat= us(SELECT) 2010-03-03 12:51:30,440 INFO [STDOUT] 12:51:30.440 (2) <=3DBE ReadyForQue= ry(I) call to a java block with con.setAutocommit(true) =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D 2010-03-03 12:55:42,028 INFO [STDOUT] 12:55:42.028 (2) simple execute, han= dler=3Dorg.postgresql.jdbc2.AbstractJdbc2Statement$StatementResultHandler@1= 8526aa, maxRows=3D0, fetchSize=3D0, flags=3D17 2010-03-03 12:55:42,029 INFO [STDOUT] 12:55:42.028 (2) FE=3D> Parse(stmt= =3Dnull,query=3D"select now()",oids=3D{}) 2010-03-03 12:55:42,029 INFO [STDOUT] 12:55:42.029 (2) FE=3D> Bind(stmt= =3Dnull,portal=3Dnull) 2010-03-03 12:55:42,030 INFO [STDOUT] 12:55:42.030 (2) FE=3D> Describe(po= rtal=3Dnull) 2010-03-03 12:55:42,030 INFO [STDOUT] 12:55:42.030 (2) FE=3D> Execute(por= tal=3Dnull,limit=3D0) 2010-03-03 12:55:42,030 INFO [STDOUT] 12:55:42.030 (2) FE=3D> Sync 2010-03-03 12:55:42,032 INFO [STDOUT] 12:55:42.032 (2) <=3DBE ParseComple= te [null] 2010-03-03 12:55:42,033 INFO [STDOUT] 12:55:42.033 (2) <=3DBE BindComplet= e [null] 2010-03-03 12:55:42,034 INFO [STDOUT] 12:55:42.034 (2) <=3DBE RowDescript= ion(1) 2010-03-03 12:55:42,035 INFO [STDOUT] 12:55:42.035 (2) <=3DBE DataRow 2010-03-03 12:55:42,036 INFO [STDOUT] 12:55:42.035 (2) <=3DBE CommandStat= us(SELECT) 2010-03-03 12:55:42,036 INFO [STDOUT] 12:55:42.036 (2) <=3DBE ReadyForQue= ry(I) call to the java block - the one with con.setAutocommit(false) - again - 3r= d time - this time its ok again =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D 2010-03-03 12:56:51,374 INFO [STDOUT] 12:56:51.374 (2) simple execute, han= dler=3Dorg.postgresql.jdbc2.AbstractJdbc2Statement$StatementResultHandler@1= 4a5594, maxRows=3D0, fetchSize=3D0, flags=3D1 2010-03-03 12:56:51,378 INFO [STDOUT] 12:56:51.378 (2) FE=3D> Bind(stmt= =3DS_1,portal=3Dnull) 2010-03-03 12:56:51,380 INFO [STDOUT] 12:56:51.380 (2) FE=3D> Execute(por= tal=3Dnull,limit=3D0) 2010-03-03 12:56:51,385 INFO [STDOUT] 12:56:51.385 (2) FE=3D> Parse(stmt= =3Dnull,query=3D"select now()",oids=3D{}) 2010-03-03 12:56:51,387 INFO [STDOUT] 12:56:51.387 (2) FE=3D> Bind(stmt= =3Dnull,portal=3Dnull) 2010-03-03 12:56:51,388 INFO [STDOUT] 12:56:51.388 (2) FE=3D> Describe(po= rtal=3Dnull) 2010-03-03 12:56:51,390 INFO [STDOUT] 12:56:51.390 (2) FE=3D> Execute(por= tal=3Dnull,limit=3D0) 2010-03-03 12:56:51,391 INFO [STDOUT] 12:56:51.391 (2) FE=3D> Sync 2010-03-03 12:56:51,393 INFO [STDOUT] 12:56:51.393 (2) <=3DBE BindComplet= e [null] 2010-03-03 12:56:51,395 INFO [STDOUT] 12:56:51.395 (2) <=3DBE CommandStat= us(BEGIN) 2010-03-03 12:56:51,397 INFO [STDOUT] 12:56:51.397 (2) <=3DBE ParseComple= te [null] 2010-03-03 12:56:51,398 INFO [STDOUT] 12:56:51.398 (2) <=3DBE BindComplet= e [null] 2010-03-03 12:56:51,399 INFO [STDOUT] 12:56:51.399 (2) <=3DBE RowDescript= ion(1) 2010-03-03 12:56:51,400 INFO [STDOUT] 12:56:51.400 (2) <=3DBE DataRow 2010-03-03 12:56:51,402 INFO [STDOUT] 12:56:51.402 (2) <=3DBE CommandStat= us(SELECT) 2010-03-03 12:56:51,404 INFO [STDOUT] 12:56:51.404 (2) <=3DBE ReadyForQue= ry(T) 2010-03-03 12:56:51,406 INFO [STDOUT] 12:56:51.406 (2) simple execute, han= dler=3Dorg.postgresql.jdbc2.AbstractJdbc2Connection$TransactionCommandHandl= er@13d3f62, maxRows=3D0, fetchSize=3D0, flags=3D22 2010-03-03 12:56:51,409 INFO [STDOUT] 12:56:51.409 (2) FE=3D> Bind(stmt= =3DS_2,portal=3Dnull) 2010-03-03 12:56:51,411 INFO [STDOUT] 12:56:51.411 (2) FE=3D> Execute(por= tal=3Dnull,limit=3D1) 2010-03-03 12:56:51,413 INFO [STDOUT] 12:56:51.413 (2) FE=3D> Sync 2010-03-03 12:56:51,417 INFO [STDOUT] 12:56:51.417 (2) <=3DBE BindComplet= e [null] 2010-03-03 12:56:51,419 INFO [STDOUT] 12:56:51.418 (2) <=3DBE CommandStat= us(COMMIT) 2010-03-03 12:56:51,421 INFO [STDOUT] 12:56:51.421 (2) <=3DBE ReadyForQue= ry(I) =CE=A3=CF=84=CE=B9=CF=82 Wednesday 03 March 2010 12:30:37 =CE=BF/=CE=B7 Hei= kki Linnakangas =CE=AD=CE=B3=CF=81=CE=B1=CF=88=CE=B5: > Achilleas Mantzios wrote: > > =CE=A3=CF=84=CE=B9=CF=82 Wednesday 03 March 2010 10:54:53 =CE=BF/=CE=B7= Heikki Linnakangas =CE=AD=CE=B3=CF=81=CE=B1=CF=88=CE=B5: > >> Achilleas Mantzios wrote: > >>> i'll try to make a test case, but i think now there is enuf material = for anyone to make his own case, > >>> please ask whatever i may have missed, and thank you for your attenti= on. > >> If you can set logLevel to DEBUG (ie. loglevel=3D2 in connection strin= g), > >> run the code, and send over the logs, that would help a lot. From that > >> we should see what exactly is the sequence of XA commands the JDBC > >> driver is receiving from JBoss. > >=20 > > As loglevel configuration property to org.postgresql.ds.common.BaseData= Source is not supported in the lastest driver,=20 > > i made this patch (i attach it) against postgresql-jdbc-8.4-701.src, al= so i set in jboss=20 > >=20 > > > > > > pgsql > > true > > org.postgresql.xa.PGXADataSource > > localhost > > 5432 > > dynacom > > postgres > > xxxx > > 8.2 > > 2 > > > > 1 > > 2 > > > > PostgreSQL 8.0 > > > > > > > >=20 > > But i dont see anything spectacular comming out of PostgreSQL logs.=20 > > in postgresql.conf I have set=20 > > client_min_messages =3D debug5 > > log_min_messages =3D debug5 >=20 > The extra logs should go somewhere in the client side, in one of the > jboss log files. If you can't find it, you can do something like this in > the application to redirect it to a file: >=20 > java.io.Writer output =3D new > java.io.FileWriter("/tmp/postgresql-jdbc.debug.txt", true); > java.sql.DriverManager.setLogWriter(new > java.io.PrintWriter(output,true)); >=20 >=20 > > however playing with does not seem to change a thing. > > Am i missing something? >=20 > Not sure why that's not working, but here's one way of setting loglevel: >=20 > 1. Create file "org/postgresql/driverconfig.properties" with line > "loglevel=3D2" in it: > echo "loglevel=3D2" > org/postgresql/driverconfig.properties > 2. Add file to the driver jar: > jar uvf postgresql.jar org/postgresql/driverconfig.properties >=20 > --=20 > Heikki Linnakangas > EnterpriseDB http://www.enterprisedb.com >=20 =2D-=20 Achilleas Mantzios