Re: Very Dangerous bug in XA connection pooling and SL EJBs with jboss-4.2.3 & latest postgresql-8.4-701.jdbc3.jar

Achilleas Mantzios wrote:
> Introduction
> ========
> This bug has the potential effect of xactions which under certain condition should rollback, to behave
> as if autocommit is true.
> The workaround is to use local-tx-datasource with the standard driver org.postgresql.Driver instead of
> xa-datasource with org.postgresql.xa.PGXADataSource.
>
> The description below is with FreeBSD diablo-1.5 , but its exactly the same with SLES 10 SP1 and 1.5.0_15.
>
> configuration
> ==============
> server/default/deploy/postgres-xa-ds.xml
> -------------------------------------------------------------------
> <datasources>
> <xa-datasource>
> <jndi-name>pgsql</jndi-name>
>
> <use-java-context>true</use-java-context>
>
> <xa-datasource-class>org.postgresql.xa.PGXADataSource</xa-datasource-class>
> <xa-datasource-property name="ServerName">localhost</xa-datasource-property>
> <xa-datasource-property name="PortNumber">5432</xa-datasource-property>
> <xa-datasource-property name="DatabaseName">dynacom</xa-datasource-property>
>
> <xa-datasource-property name="User">postgres</xa-datasource-property>
> <xa-datasource-property name="Password">xxxxx</xa-datasource-property>
> <xa-datasource-property name="Compatible">8.2</xa-datasource-property>
>
> <track-connection-by-tx/>
> <min-pool-size>1</min-pool-size>
> <max-pool-size>2</max-pool-size>
>
> <metadata>
> <type-mapping>PostgreSQL 8.0</type-mapping>
> </metadata>
> </xa-datasource>
> </datasources>
>
> Description
> ========
> Consider the following test case:
> This code is executed:
> StatusHome sthome = (StatusHome) ic.lookup("java:comp/env/ejb/Status");
> Status stat = sthome.create();
>
> "Status" is a SL Session EJB, which is defined to run with @ejb.transaction type = "Required"
> Whenever the above is executed, i see in pgsql log:
>
> postgres [23247] 2010-03-02 16:04:09.377 EET line:8 LOG: execute S_1: BEGIN
> postgres [23247] 2010-03-02 16:04:09.378 EET line:9 LOG: execute <unnamed>: select ....
> postgres [23247] 2010-03-02 16:04:09.380 EET line:11 LOG: execute S_2: COMMIT
>
> which is correct behaviour. Then the following code (lets name it sql_xact) is executed:
> sql_xact:
> try {
> DataSource ds = (javax.sql.DataSource) ic.lookup("java:comp/env/jdbc/DynacomDB");
> con = ds.getConnection();
> con.setAutoCommit(false);
> st = con.prepareStatement("select now();");
> rs = st.executeQuery();
> rs.close();
> st.close();
> con.commit();
> }
> catch (Exception e) {
> out.println("<BR>\n");
> out.println("Error: " + e.getMessage());
> con.rollback();
> e.printStackTrace();
> }
> finally {
> if (con != null) con.close();
> }
>
> If the above is executed on the same postgresql backend and immediately after the previous (EJB call) block of code, i see in pgsql log:
>
> postgres [23247] 2010-03-02 16:07:24.088 EET line:24 LOG: execute <unnamed>: select now()
>
> which means no begin-commit/rollback block. at this point a xaction supposed to rollback, is semi-commited.
> Now, If however, i execute this block of code:
>
> try {
> DataSource ds = (javax.sql.DataSource) ic.lookup("java:comp/env/jdbc/DynacomDB");
> con = ds.getConnection();
> con.setAutoCommit(true);
>
> st = con.prepareStatement("select now();");
> rs = st.executeQuery();
> rs.close();
> st.close();
>
> }
> catch (Exception e) {
> out.println("<BR>\n");
> out.println("Error: " + e.getMessage());
> e.printStackTrace();
> }
> finally {
> if (con != null) con.close();
> }
>
> and then sql_xact code again, then the connection gets back to normal, pgsql log looking like:
> postgres [23247] 2010-03-02 16:11:57.729 EET line:39 LOG: execute S_1: BEGIN
> postgres [23247] 2010-03-02 16:11:57.729 EET line:40 LOG: execute <unnamed>: select now()
> postgres [23247] 2010-03-02 16:11:57.730 EET line:41 LOG: execute S_2: COMMIT

> Any thoughts as to where the problem might reside? The jboss camp or the pgsql-jdbc camp?

Hard to tell. Can you make a complete reproducable test case and send
that over? It's a bit hard to see what exactly is going on without that.

And/or if you could set logLevel property to DEBUG, and send the full
log produced when you run the test test case with that, that might help.

--
Heikki Linnakangas
EnterpriseDB http://www.enterprisedb.com