[jbossts-issues] [JBoss JIRA] (JBTM-3004) "Connection is already associated with a different transaction" with Tomcat JDBC pool, XA

Tom Jenkinson (JIRA) issues at jboss.org
Wed Mar 28 10:22:01 EDT 2018 

    [ https://issues.jboss.org/browse/JBTM-3004?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13552919#comment-13552919 ] 

Tom Jenkinson commented on JBTM-3004:
-------------------------------------

This is using the TransactionalDriver you can tell this because of the ConnectionImple.

> "Connection is already associated with a different transaction" with Tomcat JDBC pool, XA
> -----------------------------------------------------------------------------------------
>
>                 Key: JBTM-3004
>                 URL: https://issues.jboss.org/browse/JBTM-3004
>             Project: JBoss Transaction Manager
>          Issue Type: Bug
>          Components: JTA
>    Affects Versions: 5.next
>         Environment: Tomcat 9.0.4, Tomcat JDBC Pool, PostgreSQL 10, Oracle JDK 8, Centos 7 x86_64
>            Reporter: Michal Karm Babacek
>            Assignee: Amos Feng
>            Priority: Critical
>              Labels: tomcat
>         Attachments: test.war
>
>
> h2. Goal
> To have a transaction manager taking care of XA capable data source with pooled connection to the database.
> h2. Means
> There are two pools in the Tomcat distribution, [Tomcat DBCP2|https://github.com/apache/tomcat/tree/TOMCAT_9_0_4/java/org/apache/tomcat/dbcp/dbcp2] and [Tomcat JDBC|https://github.com/apache/tomcat/tree/TOMCAT_9_0_4/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool]. We choose [Tomcat JDBC|https://github.com/apache/tomcat/tree/TOMCAT_9_0_4/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool], because  [Tomcat DBCP2|https://github.com/apache/tomcat/tree/TOMCAT_9_0_4/java/org/apache/tomcat/dbcp/dbcp2] does not contain XA capability. XA classes, the whole [managed package from Apache Commons DBCP2|https://github.com/apache/commons-dbcp/tree/master/src/main/java/org/apache/commons/dbcp2/managed] is removed in the Tomcat distribution.
> h3. Configuration
> With this [simple recovery test application|https://github.com/Karm/narayana/tree/narayana-tomcat-ts/tomcat/tomcat-jta/src/test/java/org/jboss/narayana/tomcat/jta/integration/app], the following is our configuration (PostgreSQL flavored): [context.xml|https://gist.github.com/Karm/0b3b06f1cd4dd359eaa0868c28c83397]. Note the disabled Arjuna connection pooling on [line 37|https://gist.github.com/Karm/0b3b06f1cd4dd359eaa0868c28c83397#file-context-xml-L37] and Tomcat JDBC Pool DataSourceFactory on [line 41|https://gist.github.com/Karm/0b3b06f1cd4dd359eaa0868c28c83397#file-context-xml-L41].
> h3. 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|https://gist.github.com/Karm/6854a09b113474f5c464282bba1c706c#file-gistfile1-txt-L494]. If you [run it with PostgreSQL Docker container as described in the doc|https://github.com/Karm/narayana/tree/narayana-tomcat-ts/tomcat#3-container---postgres-1] the test passes, i.e. the recovery works just fine. See the log including [database trace|https://gist.github.com/Karm/6854a09b113474f5c464282bba1c706c#file-gistfile1-txt-L611].
> h3. Failure
> You can either [run the test suite|https://github.com/Karm/narayana/tree/narayana-tomcat-ts/tomcat#3-container---postgres-1] 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|https://gist.github.com/Karm/f220076e435124f60256f29ceca9826f]
> 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:
> {noformat}
> karm at local:~$ curl localhost:8080/test/executor/jndi -i
> HTTP/1.1 204 
> Date: Wed, 28 Mar 2018 12:35:55 GMT
> {noformat}
> Then the recovery test, when executed *once and for the first time* also passes:
> {noformat}
> karm at local:~$ curl localhost:8080/test/executor/recovery -i
> HTTP/1.1 204 
> Date: Wed, 28 Mar 2018 12:36:13 GMT
> {noformat}
> 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:
> {noformat}
> karm at local:~/workspaceRH/narayana-play$ docker -H=tcp://127.0.0.1:2375 exec -it narayana_db bash
> root at 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
> {noformat}
> h4. Connection is already associated with a different transaction!
> When you call the app second time, it fails:
> {noformat}
> karm at 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)
> {noformat}
> One can play with the context.xml in the test.war and tweak the configuration.
> h3. 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|https://github.com/apache/tomcat/tree/TOMCAT_9_0_4/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool]?
> I would kindly ask you [to use my fork for the time being|https://github.com/Karm/narayana/tree/narayana-tomcat-ts/tomcat] so as we can quickly iterate.
> Thanks :)



--
This message was sent by Atlassian JIRA
(v7.5.0#75005)

More information about the jbossts-issues mailing list