Uploaded image for project: 'JBoss Transaction Manager'
  1. JBoss Transaction Manager
  2. JBTM-3004

"Connection is already associated with a different transaction" with Tomcat JDBC pool, XA

    Details

    • Type: Bug
    • Status: Closed (View Workflow)
    • Priority: Critical
    • Resolution: Won't Fix
    • Affects Version/s: 5.8.1.Final
    • Fix Version/s: None
    • Component/s: JTA
    • Labels:
    • Environment:

      Tomcat 9.0.4, Tomcat JDBC Pool, PostgreSQL 10, Oracle JDK 8, Centos 7 x86_64

    • Steps to Reproduce:
      Hide

      In the description, also see setup.sh.

      Show
      In the description, also see setup.sh .

      Description

      Goal

      To have a transaction manager taking care of XA capable data source with pooled connection to the database.

      Means

      There are two pools in the Tomcat distribution, Tomcat DBCP2 and Tomcat JDBC. We choose Tomcat JDBC, because Tomcat DBCP2 does not contain XA capability. XA classes, the whole managed package from Apache Commons DBCP2 is removed in the Tomcat distribution.

      Configuration

      With this simple recovery test application, the following is our configuration (PostgreSQL flavored): context.xml. Note the disabled Arjuna connection pooling on line 37 and Tomcat JDBC Pool DataSourceFactory on line 41.

      Test

      The test as it is written right now works just fine except for an IllegalStateException thrown while Tomcat is being shut down, see line 494. If you run it with PostgreSQL Docker container as described in the doc the test passes, i.e. the recovery works just fine. See the log including database trace.

      Failure

      You can either run the test suite or you can do it manually according to what I prepared here for you. The only expected thing is a modern Linux kernel, docker installed and this rather
      insecure setup in your /etc/sysconfig/docker, add: -H tcp://127.0.0.1:2375 -H unix:///var/run/docker.sock to OPTIONS.

      The setup script looks like this: setup.sh

      Download the attached built test.war to the same dir as the script.

      When you run the script yo should have PostgreSQL in container running and also Tomcat 9.0.4 configured and running.

      The first "test" is JNDI lookup and it is fine:

      karm@local:~$ curl localhost:8080/test/executor/jndi -i
      HTTP/1.1 204 
      Date: Wed, 28 Mar 2018 12:35:55 GMT
      

      Then the recovery test, when executed once and for the first time also passes:

      karm@local:~$ curl localhost:8080/test/executor/recovery -i
      HTTP/1.1 204 
      Date: Wed, 28 Mar 2018 12:36:13 GMT
      

      You can observe trace log on Tomcat's log and also take a look into the database trace. For the purpose of convenience in the test suite, the container as it is started right now does not log to std out, it logs into a file inside itself, see:

      karm@local:~/workspaceRH/narayana-play$ docker -H=tcp://127.0.0.1:2375 exec -it narayana_db bash
      root@fb6e220cded5:/# tail -f /tmp/db.log
      2018-03-28 12:27:23.730 UTC transaction_id:0LOG:  database system was shut down at 2018-03-28 12:27:23 UTC
      2018-03-28 12:27:23.742 UTC transaction_id:0LOG:  database system is ready to accept connections
      

      Connection is already associated with a different transaction!

      When you call the app second time, it fails:

      karm@local:~$ curl localhost:8080/test/executor/recovery -i
      HTTP/1.1 500 
      Content-Type: text/html;charset=utf-8
      Content-Language: en
      Content-Length: 5725
      Date: Wed, 28 Mar 2018 12:36:24 GMT
      Connection: close
      
      java.sql.SQLException: ARJUNA017003: Checking transaction and found that this connection is already associated with a different transaction! Obtain a new connection for this transaction.
          org.jboss.resteasy.core.ExceptionHandler.handleApplicationException(ExceptionHandler.java:77)
          org.jboss.resteasy.core.ExceptionHandler.handleException(ExceptionHandler.java:220)
          org.jboss.resteasy.core.SynchronousDispatcher.writeException(SynchronousDispatcher.java:175)
          org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:418)
          org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:209)
          org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:221)
          org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:56)
          org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:51)
          javax.servlet.http.HttpServlet.service(HttpServlet.java:741)
          org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
      </pre><p><b>Root Cause</b></p><pre>java.sql.SQLException: ARJUNA017003: Checking transaction and found that this connection is already associated with a different transaction! Obtain a new connection for this transaction.
          com.arjuna.ats.internal.jdbc.ConnectionImple.checkTransaction(ConnectionImple.java:1041)
          com.arjuna.ats.internal.jdbc.ConnectionImple.createStatement(ConnectionImple.java:153)
          jdk.internal.reflect.GeneratedMethodAccessor44.invoke(Unknown Source)
          java.base&#47;jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
          java.base&#47;java.lang.reflect.Method.invoke(Method.java:564)
          org.apache.tomcat.jdbc.pool.ProxyConnection.invoke(ProxyConnection.java:126)
          org.apache.tomcat.jdbc.pool.JdbcInterceptor.invoke(JdbcInterceptor.java:108)
          org.apache.tomcat.jdbc.pool.interceptor.AbstractCreateStatementInterceptor.invoke(AbstractCreateStatementInterceptor.java:75)
          org.apache.tomcat.jdbc.pool.JdbcInterceptor.invoke(JdbcInterceptor.java:108)
          org.apache.tomcat.jdbc.pool.interceptor.ConnectionState.invoke(ConnectionState.java:152)
          org.apache.tomcat.jdbc.pool.JdbcInterceptor.invoke(JdbcInterceptor.java:108)
          org.apache.tomcat.jdbc.pool.TrapException.invoke(TrapException.java:40)
          org.apache.tomcat.jdbc.pool.JdbcInterceptor.invoke(JdbcInterceptor.java:108)
          org.apache.tomcat.jdbc.pool.interceptor.AbstractCreateStatementInterceptor.invoke(AbstractCreateStatementInterceptor.java:75)
          org.apache.tomcat.jdbc.pool.JdbcInterceptor.invoke(JdbcInterceptor.java:108)
          org.apache.tomcat.jdbc.pool.DisposableConnectionFacade.invoke(DisposableConnectionFacade.java:81)
          com.sun.proxy.$Proxy33.createStatement(Unknown Source)
          org.jboss.narayana.tomcat.jta.integration.app.TestExecutor.writeToTheDatabase(TestExecutor.java:159)
          org.jboss.narayana.tomcat.jta.integration.app.TestExecutor.verifyRecovery(TestExecutor.java:106)
          java.base&#47;jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
          java.base&#47;jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
          java.base&#47;jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
          java.base&#47;java.lang.reflect.Method.invoke(Method.java:564)
          org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:139)
          org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:295)
          org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:249)
          org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:236)
          org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:402)
          org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:209)
          org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:221)
          org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:56)
          org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:51)
          javax.servlet.http.HttpServlet.service(HttpServlet.java:741)
          org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
      

      One can play with the context.xml in the test.war and tweak the configuration.

      Call to action

      Could you take a look at it and either help us configure the context.xml inside test.war or contribute a fix for the Narayana Tomcat integration so as it could properly handle Tomcat JDBC?
      I would kindly ask you to use my fork for the time being so as we can quickly iterate.

      Thanks

        Gliffy Diagrams

          Attachments

            Issue Links

              Activity

                People

                • Assignee:
                  zhfeng Zheng Feng
                  Reporter:
                  mbabacek Michal Karm
                  Tester:
                  Michal Karm
                  Involved:
                  Coty Sutherland, Ondrej Chaloupka, Radovan Synek, Remy Maucherat, Richa Marwaha, rrajesh1, Thomas Jenkinson
                  Need Info from:
                  Remy Maucherat
                • Votes:
                  0 Vote for this issue
                  Watchers:
                  4 Start watching this issue

                  Dates

                  • Created:
                    Updated:
                    Resolved: