You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@tomee.apache.org by Jonathan Gallimore <jo...@gmail.com> on 2018/09/28 13:49:11 UTC
Connector issues
Hi Folks,
I have been looking into some issues with TomEE using Websphere MQ,
specifically issues where XA resources are returning a -7 error during a
transaction commit when the system is under load. The -7 error indicates
that the resource is closed.
The result of this error seems to be resources staying in the system
somehow associated with the connection, and subsequently, these can't be
enlisted in transactions (because they are closed).
The stacktrace is like this, and happens over and over again as the server
attempts to process more messages from the queue.
WARN Transaction- Unable to enlist XAResource
org.apache.geronimo.transaction.manager.WrapperNamedXAResource@3dd56e90,
errorCode: -7
javax.transaction.xa.XAException: The method 'xa_start' has failed with
errorCode '-7' due to the resource being closed.
at com.ibm.mq.jmqi.JmqiXAResource.start(JmqiXAResource.java:946)
~[com.ibm.mq.jmqi.jar:7.5.0.5 - p750-005-150424]
at com.ibm.mq.connector.xa.XARWrapper.start(XARWrapper.java:581)
~[com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
at
org.apache.geronimo.transaction.manager.WrapperNamedXAResource.start(WrapperNamedXAResource.java:111)
~[geronimo-transaction-3.1.4.jar:3.1.4]
at
org.apache.geronimo.transaction.manager.TransactionImpl.enlistResource(TransactionImpl.java:209)
[geronimo-transaction-3.1.4.jar:3.1.4]
at
org.apache.geronimo.connector.outbound.TransactionEnlistingInterceptor.getConnection(TransactionEnlistingInterceptor.java:60)
[geronimo-connector-3.1.4.jar:3.1.4]
at
org.apache.geronimo.connector.outbound.TransactionCachingInterceptor.getConnection(TransactionCachingInterceptor.java:101)
[geronimo-connector-3.1.4.jar:3.1.4]
at
org.apache.geronimo.connector.outbound.ConnectionHandleInterceptor.getConnection(ConnectionHandleInterceptor.java:43)
[geronimo-connector-3.1.4.jar:3.1.4]
at
org.apache.geronimo.connector.outbound.TCCLInterceptor.getConnection(TCCLInterceptor.java:39)
[geronimo-connector-3.1.4.jar:3.1.4]
at
org.apache.geronimo.connector.outbound.ConnectionTrackingInterceptor.getConnection(ConnectionTrackingInterceptor.java:66)
[geronimo-connector-3.1.4.jar:3.1.4]
at
org.apache.geronimo.connector.outbound.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:81)
[geronimo-connector-3.1.4.jar:3.1.4]
at
com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createManagedJMSConnection(ConnectionFactoryImpl.java:194)
[com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
at
com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnectionInternal(ConnectionFactoryImpl.java:153)
[com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
at
com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:138)
[com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
at
com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:123)
[com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
The issue itself bears some resemblance to these posts:
http://tomee-openejb.979440.n4.nabble.com/Unable-to-enlist-XAResource-error-td4666552.html
http://tomee-openejb.979440.n4.nabble.com/Does-tomEE-issue-double-rollbacks-td4666090.html
http://tomee-openejb.979440.n4.nabble.com/errorcode-100-when-using-websphere-MQ-with-tomee-td4666519.html
com.ibm.mq.jmqi.JmqiXAResource has a isClosed field, and this is set when
close_internal() is called. I tracked this call using AspectJ, and it
appeared to happen here:
com.ibm.mq.jmqi.JmqiXAResource.close_internal(JmqiXAResource.java:296),
com.ibm.mq.jmqi.JmqiXAResource.close(JmqiXAResource.java:423),
com.ibm.mq.jmqi.JmqiXAResource.close(JmqiXAResource.java:410),
com.ibm.msg.client.wmq.internal.WMQXASession.close(WMQXASession.java:163),
com.ibm.msg.client.jms.internal.JmsSessionImpl.close(JmsSessionImpl.java:375),
com.ibm.msg.client.jms.internal.JmsSessionImpl.close(JmsSessionImpl.java:303),
com.ibm.mq.jms.MQSession.close(MQSession.java:298),
com.ibm.mq.connector.outbound.ManagedConnectionImpl.destroy(ManagedConnectionImpl.java:298),
org.apache.geronimo.connector.outbound.MCFConnectionInterceptor.returnConnection(MCFConnectionInterceptor.java:67),
org.apache.geronimo.connector.outbound.XAResourceInsertionInterceptor.returnConnection(XAResourceInsertionInterceptor.java:47),
org.apache.geronimo.connector.outbound.AbstractSinglePoolConnectionInterceptor.internalReturn(AbstractSinglePoolConnectionInterceptor.java:148),
org.apache.geronimo.connector.outbound.AbstractSinglePoolConnectionInterceptor.returnConnection(AbstractSinglePoolConnectionInterceptor.java:129),
org.apache.geronimo.connector.outbound.TransactionEnlistingInterceptor.returnConnection(TransactionEnlistingInterceptor.java:118),
org.apache.geronimo.connector.outbound.TransactionCachingInterceptor.returnConnection(TransactionCachingInterceptor.java:119),
org.apache.geronimo.connector.outbound.ConnectionHandleInterceptor.returnConnection(ConnectionHandleInterceptor.java:71),
org.apache.geronimo.connector.outbound.TCCLInterceptor.returnConnection(TCCLInterceptor.java:50),
org.apache.geronimo.connector.outbound.ConnectionTrackingInterceptor.returnConnection(ConnectionTrackingInterceptor.java:91),
org.apache.openejb.resource.AutoConnectionTracker.setEnvironment(AutoConnectionTracker.java:62),
org.apache.geronimo.connector.outbound.ConnectionTrackingInterceptor.getConnection(ConnectionTrackingInterceptor.java:65),
org.apache.geronimo.connector.outbound.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:81),
com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createManagedJMSConnection(ConnectionFactoryImpl.java:194),
com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnectionInternal(ConnectionFactoryImpl.java:153),
com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:138),
com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:123),
The interesting part here is the
org.apache.openejb.resource.AutoConnectionTracker.setEnvironment() call,
which is destroying connections where the proxy for the connection no
longer has any references. I.e. if you had some code that did this:
----
Connection conn = connectionFactory.createConnection(); // conn is actually
a proxy to the connection
// do work
conn = null; // or conn is out of scope
----
note that conn.close() is not called. The reference count to the proxy is
now zero, so it counts as abandoned, and the next call to
createConnection() destroys the associated connection. However, if all this
happens in a transacted method, the JmqiXAResource is still enlisted with
the transaction. So when the transaction goes to commit, it fails, because
the JmqiXAResource is closed. The resource is still associated with a
ManagedConnectionInfo object through ManagedConnectionInfo.xares
(WrapperNamedXAResource). xaResource (XARWrapper - part of the RAR).theXAR
(JmqiXAResource - part of the RAR). The ManagedConnectionInfo object
somehow comes back to the pool after the rollback, and gets used again,
with the TransactionImpl.enlistResource() call failing as above.
I suspect that we're seeing this under load as GC will be taking place more
often and calls to createConnection() will be happening more frequently.
The connection proxies themselves don't do much - only calls to finalize()
and clone() are caught. I propose this patch to allow the proxies to be
disabled (the current behaviour is still the default):
https://github.com/apache/tomee/pull/174 and welcome feedback.
Running this specific case with proxies disabled has yielded positive
results. I'll try and extend this and reproduce it in a test case as well.
I'm wondering if AutoConnectionTracker's use of ReferenceQueue is thread
safe. Do anyone have any thoughts on this?
Cheers
Jon
Re: Connector issues
Posted by Jean-Louis Monteiro <jl...@tomitribe.com>.
Great note Jon.
Thanks it's appreciated
+1
Le jeu. 4 oct. 2018 à 12:01, Romain Manni-Bucau <rm...@gmail.com> a
écrit :
> +1 looks good
>
> Romain Manni-Bucau
> @rmannibucau <https://twitter.com/rmannibucau> | Blog
> <https://rmannibucau.metawerx.net/> | Old Blog
> <http://rmannibucau.wordpress.com> | Github <
> https://github.com/rmannibucau> |
> LinkedIn <https://www.linkedin.com/in/rmannibucau> | Book
> <
> https://www.packtpub.com/application-development/java-ee-8-high-performance
> >
>
>
> Le jeu. 4 oct. 2018 à 11:59, Jonathan Gallimore <
> jonathan.gallimore@gmail.com> a écrit :
>
> > I have pushed some commits onto the PR here:
> > https://github.com/apache/tomee/pull/174, and would appreciate some
> > review.
> > One the things I found was that if I hold onto a reference to the proxy
> for
> > the transaction, it doesn't get cleaned up, but then losing the reference
> > from the scope at the end of the transaction also didn't clean things up.
> > What was actually going on was:
> >
> > ----
> > connection = cf.createConnection();
> >
> > // forget to close it
> >
> > connection2 = cf.createConnection(); // different proxy, but same
> > ManagedConnectionInfo as the TransactionCachingInterceptor provides the
> > same connection
> > connection2.close(); // this removed the ManagedConnectionInfo from the
> > references field on AutoConnectionTracker, so it was no longer tracked
> for
> > cleanup.
> > ----
> >
> > The transaction then completed, and connection dropped from scope, but
> > because the ManagedConnectionInfo associated with it wasn't in the
> > references list anymore, it never got cleaned up.
> >
> > To make matters worse, TransactionCachingInterceptor sees that the
> > ManagedConnectionInfo has open handles and refuses to send it back to the
> > pool. The effect is the connections leaked and never went back to the
> pool.
> >
> > So, my latest changes:
> >
> > * Keep a proxy for as long as the transaction runs
> > * Checks the reference list and cleans up at the end
> > * Checks the ManagedConnectionInfo object, and if there are open handles,
> > destroys the connection.
> > * Additionally, if OpenEJB.connector is set to log at FINEST, it should
> > reveal where any unclosed connections are originally opened, to provide
> the
> > developer with a hint on how to fix them.
> >
> > I'll add some tests this afternoon, but any thoughts would be much
> > appreciated.
> >
> > Jon
> >
> >
> > On Fri, Sep 28, 2018 at 3:18 PM Jonathan Gallimore <
> > jonathan.gallimore@gmail.com> wrote:
> >
> > > I was thinking the same - do it through the registry. Let me have a go
> at
> > > hacking on that and I'll post back here. Many thanks for the feedback.
> > >
> > > Jon
> > >
> > > On Fri, Sep 28, 2018 at 3:15 PM Romain Manni-Bucau <
> > rmannibucau@gmail.com>
> > > wrote:
> > >
> > >> that is what I had in mind, throught it was already the case to be
> > honest
> > >> through the transaction registry - excess of enthusiasm probably ;)
> > >>
> > >> Side note: dropped G for now, if we find something impacting g-txmgr
> > we'll
> > >> add it back
> > >>
> > >> Romain Manni-Bucau
> > >> @rmannibucau <https://twitter.com/rmannibucau> | Blog
> > >> <https://rmannibucau.metawerx.net/> | Old Blog
> > >> <http://rmannibucau.wordpress.com> | Github <
> > >> https://github.com/rmannibucau> |
> > >> LinkedIn <https://www.linkedin.com/in/rmannibucau> | Book
> > >> <
> > >>
> >
> https://www.packtpub.com/application-development/java-ee-8-high-performance
> > >> >
> > >>
> > >>
> > >> Le ven. 28 sept. 2018 à 16:11, Jonathan Gallimore <
> > >> jonathan.gallimore@gmail.com> a écrit :
> > >>
> > >> > I apologize, I CC'd Geronimo in case there was anything relevant on
> > the
> > >> > Geronimo connector side. Happy to drop the CC if its not relevant.
> > >> >
> > >> > Thanks for the quick response!
> > >> >
> > >> > Off the top of my head, I wonder if we could keep a reference to the
> > >> > connection proxy in the transaction (if there is one), and remove
> the
> > >> > reference when the transaction is complete?
> > >> >
> > >> > Jon
> > >> >
> > >> > On Fri, Sep 28, 2018 at 2:57 PM Romain Manni-Bucau <
> > >> rmannibucau@gmail.com>
> > >> > wrote:
> > >> >
> > >> > > Hi Jon,
> > >> > >
> > >> > > I experienced that kind of "surprise" in recent jvm since gc is
> way
> > >> more
> > >> > > aggressive - cause lambda are way more memory consuming ;). This
> > lead
> > >> to
> > >> > > this kind of issue where the GC happens before the object should
> > >> actually
> > >> > > be finalizable.
> > >> > > I suspect we need to rework the AutoConnectionTracker to take into
> > >> > account
> > >> > > these new behaviors and actually take into consideration the
> > >> lifecycle of
> > >> > > the underlying connection.
> > >> > >
> > >> > > Maybe I got it wrong but I see the ability to disable the proxying
> > as
> > >> a
> > >> > > quickfix/workaround - which is ok - but it means we need to fix
> the
> > >> > source
> > >> > > anyway as a long term solution. Am I understanding it right? If so
> > we
> > >> > need
> > >> > > to ensure to keep the reference until the connection is released
> at
> > >> least
> > >> > > and ensure it was not closed in the pool (kind of testOnXXX).
> > >> > > Also wonder if there is anything related to geronimo since you
> cc-ed
> > >> it.
> > >> > > IIRC this logic is only in TomEE, no?
> > >> > >
> > >> > > side note: reference queue is supposed thread safe yes.
> > >> > >
> > >> > > Romain Manni-Bucau
> > >> > > @rmannibucau <https://twitter.com/rmannibucau> | Blog
> > >> > > <https://rmannibucau.metawerx.net/> | Old Blog
> > >> > > <http://rmannibucau.wordpress.com> | Github <
> > >> > > https://github.com/rmannibucau> |
> > >> > > LinkedIn <https://www.linkedin.com/in/rmannibucau> | Book
> > >> > > <
> > >> > >
> > >> >
> > >>
> >
> https://www.packtpub.com/application-development/java-ee-8-high-performance
> > >> > > >
> > >> > >
> > >> > >
> > >> > > Le ven. 28 sept. 2018 à 15:49, Jonathan Gallimore <
> > >> > > jonathan.gallimore@gmail.com> a écrit :
> > >> > >
> > >> > > > Hi Folks,
> > >> > > >
> > >> > > > I have been looking into some issues with TomEE using Websphere
> > MQ,
> > >> > > > specifically issues where XA resources are returning a -7 error
> > >> during
> > >> > a
> > >> > > > transaction commit when the system is under load. The -7 error
> > >> > indicates
> > >> > > > that the resource is closed.
> > >> > > >
> > >> > > > The result of this error seems to be resources staying in the
> > system
> > >> > > > somehow associated with the connection, and subsequently, these
> > >> can't
> > >> > be
> > >> > > > enlisted in transactions (because they are closed).
> > >> > > >
> > >> > > > The stacktrace is like this, and happens over and over again as
> > the
> > >> > > server
> > >> > > > attempts to process more messages from the queue.
> > >> > > >
> > >> > > > WARN Transaction- Unable to enlist XAResource
> > >> > > >
> > >>
> org.apache.geronimo.transaction.manager.WrapperNamedXAResource@3dd56e90
> > >> > ,
> > >> > > > errorCode: -7
> > >> > > > javax.transaction.xa.XAException: The method 'xa_start' has
> failed
> > >> with
> > >> > > > errorCode '-7' due to the resource being closed.
> > >> > > > at
> > >> > com.ibm.mq.jmqi.JmqiXAResource.start(JmqiXAResource.java:946)
> > >> > > > ~[com.ibm.mq.jmqi.jar:7.5.0.5 - p750-005-150424]
> > >> > > > at
> > >> > com.ibm.mq.connector.xa.XARWrapper.start(XARWrapper.java:581)
> > >> > > > ~[com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> > >> > > > at
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> org.apache.geronimo.transaction.manager.WrapperNamedXAResource.start(WrapperNamedXAResource.java:111)
> > >> > > > ~[geronimo-transaction-3.1.4.jar:3.1.4]
> > >> > > > at
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> org.apache.geronimo.transaction.manager.TransactionImpl.enlistResource(TransactionImpl.java:209)
> > >> > > > [geronimo-transaction-3.1.4.jar:3.1.4]
> > >> > > > at
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> org.apache.geronimo.connector.outbound.TransactionEnlistingInterceptor.getConnection(TransactionEnlistingInterceptor.java:60)
> > >> > > > [geronimo-connector-3.1.4.jar:3.1.4]
> > >> > > > at
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> org.apache.geronimo.connector.outbound.TransactionCachingInterceptor.getConnection(TransactionCachingInterceptor.java:101)
> > >> > > > [geronimo-connector-3.1.4.jar:3.1.4]
> > >> > > > at
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> org.apache.geronimo.connector.outbound.ConnectionHandleInterceptor.getConnection(ConnectionHandleInterceptor.java:43)
> > >> > > > [geronimo-connector-3.1.4.jar:3.1.4]
> > >> > > > at
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> org.apache.geronimo.connector.outbound.TCCLInterceptor.getConnection(TCCLInterceptor.java:39)
> > >> > > > [geronimo-connector-3.1.4.jar:3.1.4]
> > >> > > > at
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> org.apache.geronimo.connector.outbound.ConnectionTrackingInterceptor.getConnection(ConnectionTrackingInterceptor.java:66)
> > >> > > > [geronimo-connector-3.1.4.jar:3.1.4]
> > >> > > > at
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> org.apache.geronimo.connector.outbound.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:81)
> > >> > > > [geronimo-connector-3.1.4.jar:3.1.4]
> > >> > > > at
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createManagedJMSConnection(ConnectionFactoryImpl.java:194)
> > >> > > > [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> > >> > > > at
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnectionInternal(ConnectionFactoryImpl.java:153)
> > >> > > > [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> > >> > > > at
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:138)
> > >> > > > [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> > >> > > > at
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:123)
> > >> > > > [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> > >> > > >
> > >> > > > The issue itself bears some resemblance to these posts:
> > >> > > >
> > >> > > >
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> http://tomee-openejb.979440.n4.nabble.com/Unable-to-enlist-XAResource-error-td4666552.html
> > >> > > >
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> http://tomee-openejb.979440.n4.nabble.com/Does-tomEE-issue-double-rollbacks-td4666090.html
> > >> > > >
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> http://tomee-openejb.979440.n4.nabble.com/errorcode-100-when-using-websphere-MQ-with-tomee-td4666519.html
> > >> > > >
> > >> > > > com.ibm.mq.jmqi.JmqiXAResource has a isClosed field, and this is
> > set
> > >> > when
> > >> > > > close_internal() is called. I tracked this call using AspectJ,
> and
> > >> it
> > >> > > > appeared to happen here:
> > >> > > >
> > >> > > >
> > >>
> com.ibm.mq.jmqi.JmqiXAResource.close_internal(JmqiXAResource.java:296),
> > >> > > > com.ibm.mq.jmqi.JmqiXAResource.close(JmqiXAResource.java:423),
> > >> > > > com.ibm.mq.jmqi.JmqiXAResource.close(JmqiXAResource.java:410),
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> com.ibm.msg.client.wmq.internal.WMQXASession.close(WMQXASession.java:163),
> > >> > > >
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> com.ibm.msg.client.jms.internal.JmsSessionImpl.close(JmsSessionImpl.java:375),
> > >> > > >
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> com.ibm.msg.client.jms.internal.JmsSessionImpl.close(JmsSessionImpl.java:303),
> > >> > > > com.ibm.mq.jms.MQSession.close(MQSession.java:298),
> > >> > > >
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> com.ibm.mq.connector.outbound.ManagedConnectionImpl.destroy(ManagedConnectionImpl.java:298),
> > >> > > >
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> org.apache.geronimo.connector.outbound.MCFConnectionInterceptor.returnConnection(MCFConnectionInterceptor.java:67),
> > >> > > >
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> org.apache.geronimo.connector.outbound.XAResourceInsertionInterceptor.returnConnection(XAResourceInsertionInterceptor.java:47),
> > >> > > >
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> org.apache.geronimo.connector.outbound.AbstractSinglePoolConnectionInterceptor.internalReturn(AbstractSinglePoolConnectionInterceptor.java:148),
> > >> > > >
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> org.apache.geronimo.connector.outbound.AbstractSinglePoolConnectionInterceptor.returnConnection(AbstractSinglePoolConnectionInterceptor.java:129),
> > >> > > >
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> org.apache.geronimo.connector.outbound.TransactionEnlistingInterceptor.returnConnection(TransactionEnlistingInterceptor.java:118),
> > >> > > >
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> org.apache.geronimo.connector.outbound.TransactionCachingInterceptor.returnConnection(TransactionCachingInterceptor.java:119),
> > >> > > >
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> org.apache.geronimo.connector.outbound.ConnectionHandleInterceptor.returnConnection(ConnectionHandleInterceptor.java:71),
> > >> > > >
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> org.apache.geronimo.connector.outbound.TCCLInterceptor.returnConnection(TCCLInterceptor.java:50),
> > >> > > >
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> org.apache.geronimo.connector.outbound.ConnectionTrackingInterceptor.returnConnection(ConnectionTrackingInterceptor.java:91),
> > >> > > >
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> org.apache.openejb.resource.AutoConnectionTracker.setEnvironment(AutoConnectionTracker.java:62),
> > >> > > >
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> org.apache.geronimo.connector.outbound.ConnectionTrackingInterceptor.getConnection(ConnectionTrackingInterceptor.java:65),
> > >> > > >
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> org.apache.geronimo.connector.outbound.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:81),
> > >> > > >
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createManagedJMSConnection(ConnectionFactoryImpl.java:194),
> > >> > > >
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnectionInternal(ConnectionFactoryImpl.java:153),
> > >> > > >
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:138),
> > >> > > >
> > >> > > >
> > >> > >
> > >> >
> > >>
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:123),
> > >> > > >
> > >> > > > The interesting part here is the
> > >> > > >
> org.apache.openejb.resource.AutoConnectionTracker.setEnvironment()
> > >> > call,
> > >> > > > which is destroying connections where the proxy for the
> connection
> > >> no
> > >> > > > longer has any references. I.e. if you had some code that did
> > this:
> > >> > > >
> > >> > > > ----
> > >> > > > Connection conn = connectionFactory.createConnection(); // conn
> is
> > >> > > > actually a proxy to the connection
> > >> > > > // do work
> > >> > > >
> > >> > > > conn = null; // or conn is out of scope
> > >> > > > ----
> > >> > > >
> > >> > > > note that conn.close() is not called. The reference count to the
> > >> proxy
> > >> > is
> > >> > > > now zero, so it counts as abandoned, and the next call to
> > >> > > > createConnection() destroys the associated connection. However,
> if
> > >> all
> > >> > > this
> > >> > > > happens in a transacted method, the JmqiXAResource is still
> > enlisted
> > >> > with
> > >> > > > the transaction. So when the transaction goes to commit, it
> fails,
> > >> > > because
> > >> > > > the JmqiXAResource is closed. The resource is still associated
> > with
> > >> a
> > >> > > > ManagedConnectionInfo object through ManagedConnectionInfo.xares
> > >> > > > (WrapperNamedXAResource). xaResource (XARWrapper - part of the
> > >> > > RAR).theXAR
> > >> > > > (JmqiXAResource - part of the RAR). The ManagedConnectionInfo
> > object
> > >> > > > somehow comes back to the pool after the rollback, and gets used
> > >> again,
> > >> > > > with the TransactionImpl.enlistResource() call failing as above.
> > >> > > >
> > >> > > > I suspect that we're seeing this under load as GC will be taking
> > >> place
> > >> > > > more often and calls to createConnection() will be happening
> more
> > >> > > > frequently.
> > >> > > >
> > >> > > > The connection proxies themselves don't do much - only calls to
> > >> > > finalize()
> > >> > > > and clone() are caught. I propose this patch to allow the
> proxies
> > >> to be
> > >> > > > disabled (the current behaviour is still the default):
> > >> > > > https://github.com/apache/tomee/pull/174 and welcome feedback.
> > >> > > >
> > >> > > > Running this specific case with proxies disabled has yielded
> > >> positive
> > >> > > > results. I'll try and extend this and reproduce it in a test
> case
> > as
> > >> > > well.
> > >> > > > I'm wondering if AutoConnectionTracker's use of ReferenceQueue
> is
> > >> > thread
> > >> > > > safe. Do anyone have any thoughts on this?
> > >> > > >
> > >> > > > Cheers
> > >> > > >
> > >> > > > Jon
> > >> > > >
> > >> > > >
> > >> > > >
> > >> > > >
> > >> > > >
> > >> > > >
> > >> > > >
> > >> > >
> > >> >
> > >>
> > >
> >
>
Re: Connector issues
Posted by Romain Manni-Bucau <rm...@gmail.com>.
+1 looks good
Romain Manni-Bucau
@rmannibucau <https://twitter.com/rmannibucau> | Blog
<https://rmannibucau.metawerx.net/> | Old Blog
<http://rmannibucau.wordpress.com> | Github <https://github.com/rmannibucau> |
LinkedIn <https://www.linkedin.com/in/rmannibucau> | Book
<https://www.packtpub.com/application-development/java-ee-8-high-performance>
Le jeu. 4 oct. 2018 à 11:59, Jonathan Gallimore <
jonathan.gallimore@gmail.com> a écrit :
> I have pushed some commits onto the PR here:
> https://github.com/apache/tomee/pull/174, and would appreciate some
> review.
> One the things I found was that if I hold onto a reference to the proxy for
> the transaction, it doesn't get cleaned up, but then losing the reference
> from the scope at the end of the transaction also didn't clean things up.
> What was actually going on was:
>
> ----
> connection = cf.createConnection();
>
> // forget to close it
>
> connection2 = cf.createConnection(); // different proxy, but same
> ManagedConnectionInfo as the TransactionCachingInterceptor provides the
> same connection
> connection2.close(); // this removed the ManagedConnectionInfo from the
> references field on AutoConnectionTracker, so it was no longer tracked for
> cleanup.
> ----
>
> The transaction then completed, and connection dropped from scope, but
> because the ManagedConnectionInfo associated with it wasn't in the
> references list anymore, it never got cleaned up.
>
> To make matters worse, TransactionCachingInterceptor sees that the
> ManagedConnectionInfo has open handles and refuses to send it back to the
> pool. The effect is the connections leaked and never went back to the pool.
>
> So, my latest changes:
>
> * Keep a proxy for as long as the transaction runs
> * Checks the reference list and cleans up at the end
> * Checks the ManagedConnectionInfo object, and if there are open handles,
> destroys the connection.
> * Additionally, if OpenEJB.connector is set to log at FINEST, it should
> reveal where any unclosed connections are originally opened, to provide the
> developer with a hint on how to fix them.
>
> I'll add some tests this afternoon, but any thoughts would be much
> appreciated.
>
> Jon
>
>
> On Fri, Sep 28, 2018 at 3:18 PM Jonathan Gallimore <
> jonathan.gallimore@gmail.com> wrote:
>
> > I was thinking the same - do it through the registry. Let me have a go at
> > hacking on that and I'll post back here. Many thanks for the feedback.
> >
> > Jon
> >
> > On Fri, Sep 28, 2018 at 3:15 PM Romain Manni-Bucau <
> rmannibucau@gmail.com>
> > wrote:
> >
> >> that is what I had in mind, throught it was already the case to be
> honest
> >> through the transaction registry - excess of enthusiasm probably ;)
> >>
> >> Side note: dropped G for now, if we find something impacting g-txmgr
> we'll
> >> add it back
> >>
> >> Romain Manni-Bucau
> >> @rmannibucau <https://twitter.com/rmannibucau> | Blog
> >> <https://rmannibucau.metawerx.net/> | Old Blog
> >> <http://rmannibucau.wordpress.com> | Github <
> >> https://github.com/rmannibucau> |
> >> LinkedIn <https://www.linkedin.com/in/rmannibucau> | Book
> >> <
> >>
> https://www.packtpub.com/application-development/java-ee-8-high-performance
> >> >
> >>
> >>
> >> Le ven. 28 sept. 2018 à 16:11, Jonathan Gallimore <
> >> jonathan.gallimore@gmail.com> a écrit :
> >>
> >> > I apologize, I CC'd Geronimo in case there was anything relevant on
> the
> >> > Geronimo connector side. Happy to drop the CC if its not relevant.
> >> >
> >> > Thanks for the quick response!
> >> >
> >> > Off the top of my head, I wonder if we could keep a reference to the
> >> > connection proxy in the transaction (if there is one), and remove the
> >> > reference when the transaction is complete?
> >> >
> >> > Jon
> >> >
> >> > On Fri, Sep 28, 2018 at 2:57 PM Romain Manni-Bucau <
> >> rmannibucau@gmail.com>
> >> > wrote:
> >> >
> >> > > Hi Jon,
> >> > >
> >> > > I experienced that kind of "surprise" in recent jvm since gc is way
> >> more
> >> > > aggressive - cause lambda are way more memory consuming ;). This
> lead
> >> to
> >> > > this kind of issue where the GC happens before the object should
> >> actually
> >> > > be finalizable.
> >> > > I suspect we need to rework the AutoConnectionTracker to take into
> >> > account
> >> > > these new behaviors and actually take into consideration the
> >> lifecycle of
> >> > > the underlying connection.
> >> > >
> >> > > Maybe I got it wrong but I see the ability to disable the proxying
> as
> >> a
> >> > > quickfix/workaround - which is ok - but it means we need to fix the
> >> > source
> >> > > anyway as a long term solution. Am I understanding it right? If so
> we
> >> > need
> >> > > to ensure to keep the reference until the connection is released at
> >> least
> >> > > and ensure it was not closed in the pool (kind of testOnXXX).
> >> > > Also wonder if there is anything related to geronimo since you cc-ed
> >> it.
> >> > > IIRC this logic is only in TomEE, no?
> >> > >
> >> > > side note: reference queue is supposed thread safe yes.
> >> > >
> >> > > Romain Manni-Bucau
> >> > > @rmannibucau <https://twitter.com/rmannibucau> | Blog
> >> > > <https://rmannibucau.metawerx.net/> | Old Blog
> >> > > <http://rmannibucau.wordpress.com> | Github <
> >> > > https://github.com/rmannibucau> |
> >> > > LinkedIn <https://www.linkedin.com/in/rmannibucau> | Book
> >> > > <
> >> > >
> >> >
> >>
> https://www.packtpub.com/application-development/java-ee-8-high-performance
> >> > > >
> >> > >
> >> > >
> >> > > Le ven. 28 sept. 2018 à 15:49, Jonathan Gallimore <
> >> > > jonathan.gallimore@gmail.com> a écrit :
> >> > >
> >> > > > Hi Folks,
> >> > > >
> >> > > > I have been looking into some issues with TomEE using Websphere
> MQ,
> >> > > > specifically issues where XA resources are returning a -7 error
> >> during
> >> > a
> >> > > > transaction commit when the system is under load. The -7 error
> >> > indicates
> >> > > > that the resource is closed.
> >> > > >
> >> > > > The result of this error seems to be resources staying in the
> system
> >> > > > somehow associated with the connection, and subsequently, these
> >> can't
> >> > be
> >> > > > enlisted in transactions (because they are closed).
> >> > > >
> >> > > > The stacktrace is like this, and happens over and over again as
> the
> >> > > server
> >> > > > attempts to process more messages from the queue.
> >> > > >
> >> > > > WARN Transaction- Unable to enlist XAResource
> >> > > >
> >> org.apache.geronimo.transaction.manager.WrapperNamedXAResource@3dd56e90
> >> > ,
> >> > > > errorCode: -7
> >> > > > javax.transaction.xa.XAException: The method 'xa_start' has failed
> >> with
> >> > > > errorCode '-7' due to the resource being closed.
> >> > > > at
> >> > com.ibm.mq.jmqi.JmqiXAResource.start(JmqiXAResource.java:946)
> >> > > > ~[com.ibm.mq.jmqi.jar:7.5.0.5 - p750-005-150424]
> >> > > > at
> >> > com.ibm.mq.connector.xa.XARWrapper.start(XARWrapper.java:581)
> >> > > > ~[com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> >> > > > at
> >> > > >
> >> > >
> >> >
> >>
> org.apache.geronimo.transaction.manager.WrapperNamedXAResource.start(WrapperNamedXAResource.java:111)
> >> > > > ~[geronimo-transaction-3.1.4.jar:3.1.4]
> >> > > > at
> >> > > >
> >> > >
> >> >
> >>
> org.apache.geronimo.transaction.manager.TransactionImpl.enlistResource(TransactionImpl.java:209)
> >> > > > [geronimo-transaction-3.1.4.jar:3.1.4]
> >> > > > at
> >> > > >
> >> > >
> >> >
> >>
> org.apache.geronimo.connector.outbound.TransactionEnlistingInterceptor.getConnection(TransactionEnlistingInterceptor.java:60)
> >> > > > [geronimo-connector-3.1.4.jar:3.1.4]
> >> > > > at
> >> > > >
> >> > >
> >> >
> >>
> org.apache.geronimo.connector.outbound.TransactionCachingInterceptor.getConnection(TransactionCachingInterceptor.java:101)
> >> > > > [geronimo-connector-3.1.4.jar:3.1.4]
> >> > > > at
> >> > > >
> >> > >
> >> >
> >>
> org.apache.geronimo.connector.outbound.ConnectionHandleInterceptor.getConnection(ConnectionHandleInterceptor.java:43)
> >> > > > [geronimo-connector-3.1.4.jar:3.1.4]
> >> > > > at
> >> > > >
> >> > >
> >> >
> >>
> org.apache.geronimo.connector.outbound.TCCLInterceptor.getConnection(TCCLInterceptor.java:39)
> >> > > > [geronimo-connector-3.1.4.jar:3.1.4]
> >> > > > at
> >> > > >
> >> > >
> >> >
> >>
> org.apache.geronimo.connector.outbound.ConnectionTrackingInterceptor.getConnection(ConnectionTrackingInterceptor.java:66)
> >> > > > [geronimo-connector-3.1.4.jar:3.1.4]
> >> > > > at
> >> > > >
> >> > >
> >> >
> >>
> org.apache.geronimo.connector.outbound.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:81)
> >> > > > [geronimo-connector-3.1.4.jar:3.1.4]
> >> > > > at
> >> > > >
> >> > >
> >> >
> >>
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createManagedJMSConnection(ConnectionFactoryImpl.java:194)
> >> > > > [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> >> > > > at
> >> > > >
> >> > >
> >> >
> >>
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnectionInternal(ConnectionFactoryImpl.java:153)
> >> > > > [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> >> > > > at
> >> > > >
> >> > >
> >> >
> >>
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:138)
> >> > > > [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> >> > > > at
> >> > > >
> >> > >
> >> >
> >>
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:123)
> >> > > > [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> >> > > >
> >> > > > The issue itself bears some resemblance to these posts:
> >> > > >
> >> > > >
> >> > > >
> >> > >
> >> >
> >>
> http://tomee-openejb.979440.n4.nabble.com/Unable-to-enlist-XAResource-error-td4666552.html
> >> > > >
> >> > > >
> >> > >
> >> >
> >>
> http://tomee-openejb.979440.n4.nabble.com/Does-tomEE-issue-double-rollbacks-td4666090.html
> >> > > >
> >> > > >
> >> > >
> >> >
> >>
> http://tomee-openejb.979440.n4.nabble.com/errorcode-100-when-using-websphere-MQ-with-tomee-td4666519.html
> >> > > >
> >> > > > com.ibm.mq.jmqi.JmqiXAResource has a isClosed field, and this is
> set
> >> > when
> >> > > > close_internal() is called. I tracked this call using AspectJ, and
> >> it
> >> > > > appeared to happen here:
> >> > > >
> >> > > >
> >> com.ibm.mq.jmqi.JmqiXAResource.close_internal(JmqiXAResource.java:296),
> >> > > > com.ibm.mq.jmqi.JmqiXAResource.close(JmqiXAResource.java:423),
> >> > > > com.ibm.mq.jmqi.JmqiXAResource.close(JmqiXAResource.java:410),
> >> > > >
> >> > >
> >> >
> >>
> com.ibm.msg.client.wmq.internal.WMQXASession.close(WMQXASession.java:163),
> >> > > >
> >> > > >
> >> > >
> >> >
> >>
> com.ibm.msg.client.jms.internal.JmsSessionImpl.close(JmsSessionImpl.java:375),
> >> > > >
> >> > > >
> >> > >
> >> >
> >>
> com.ibm.msg.client.jms.internal.JmsSessionImpl.close(JmsSessionImpl.java:303),
> >> > > > com.ibm.mq.jms.MQSession.close(MQSession.java:298),
> >> > > >
> >> > > >
> >> > >
> >> >
> >>
> com.ibm.mq.connector.outbound.ManagedConnectionImpl.destroy(ManagedConnectionImpl.java:298),
> >> > > >
> >> > > >
> >> > >
> >> >
> >>
> org.apache.geronimo.connector.outbound.MCFConnectionInterceptor.returnConnection(MCFConnectionInterceptor.java:67),
> >> > > >
> >> > > >
> >> > >
> >> >
> >>
> org.apache.geronimo.connector.outbound.XAResourceInsertionInterceptor.returnConnection(XAResourceInsertionInterceptor.java:47),
> >> > > >
> >> > > >
> >> > >
> >> >
> >>
> org.apache.geronimo.connector.outbound.AbstractSinglePoolConnectionInterceptor.internalReturn(AbstractSinglePoolConnectionInterceptor.java:148),
> >> > > >
> >> > > >
> >> > >
> >> >
> >>
> org.apache.geronimo.connector.outbound.AbstractSinglePoolConnectionInterceptor.returnConnection(AbstractSinglePoolConnectionInterceptor.java:129),
> >> > > >
> >> > > >
> >> > >
> >> >
> >>
> org.apache.geronimo.connector.outbound.TransactionEnlistingInterceptor.returnConnection(TransactionEnlistingInterceptor.java:118),
> >> > > >
> >> > > >
> >> > >
> >> >
> >>
> org.apache.geronimo.connector.outbound.TransactionCachingInterceptor.returnConnection(TransactionCachingInterceptor.java:119),
> >> > > >
> >> > > >
> >> > >
> >> >
> >>
> org.apache.geronimo.connector.outbound.ConnectionHandleInterceptor.returnConnection(ConnectionHandleInterceptor.java:71),
> >> > > >
> >> > > >
> >> > >
> >> >
> >>
> org.apache.geronimo.connector.outbound.TCCLInterceptor.returnConnection(TCCLInterceptor.java:50),
> >> > > >
> >> > > >
> >> > >
> >> >
> >>
> org.apache.geronimo.connector.outbound.ConnectionTrackingInterceptor.returnConnection(ConnectionTrackingInterceptor.java:91),
> >> > > >
> >> > > >
> >> > >
> >> >
> >>
> org.apache.openejb.resource.AutoConnectionTracker.setEnvironment(AutoConnectionTracker.java:62),
> >> > > >
> >> > > >
> >> > >
> >> >
> >>
> org.apache.geronimo.connector.outbound.ConnectionTrackingInterceptor.getConnection(ConnectionTrackingInterceptor.java:65),
> >> > > >
> >> > > >
> >> > >
> >> >
> >>
> org.apache.geronimo.connector.outbound.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:81),
> >> > > >
> >> > > >
> >> > >
> >> >
> >>
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createManagedJMSConnection(ConnectionFactoryImpl.java:194),
> >> > > >
> >> > > >
> >> > >
> >> >
> >>
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnectionInternal(ConnectionFactoryImpl.java:153),
> >> > > >
> >> > > >
> >> > >
> >> >
> >>
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:138),
> >> > > >
> >> > > >
> >> > >
> >> >
> >>
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:123),
> >> > > >
> >> > > > The interesting part here is the
> >> > > > org.apache.openejb.resource.AutoConnectionTracker.setEnvironment()
> >> > call,
> >> > > > which is destroying connections where the proxy for the connection
> >> no
> >> > > > longer has any references. I.e. if you had some code that did
> this:
> >> > > >
> >> > > > ----
> >> > > > Connection conn = connectionFactory.createConnection(); // conn is
> >> > > > actually a proxy to the connection
> >> > > > // do work
> >> > > >
> >> > > > conn = null; // or conn is out of scope
> >> > > > ----
> >> > > >
> >> > > > note that conn.close() is not called. The reference count to the
> >> proxy
> >> > is
> >> > > > now zero, so it counts as abandoned, and the next call to
> >> > > > createConnection() destroys the associated connection. However, if
> >> all
> >> > > this
> >> > > > happens in a transacted method, the JmqiXAResource is still
> enlisted
> >> > with
> >> > > > the transaction. So when the transaction goes to commit, it fails,
> >> > > because
> >> > > > the JmqiXAResource is closed. The resource is still associated
> with
> >> a
> >> > > > ManagedConnectionInfo object through ManagedConnectionInfo.xares
> >> > > > (WrapperNamedXAResource). xaResource (XARWrapper - part of the
> >> > > RAR).theXAR
> >> > > > (JmqiXAResource - part of the RAR). The ManagedConnectionInfo
> object
> >> > > > somehow comes back to the pool after the rollback, and gets used
> >> again,
> >> > > > with the TransactionImpl.enlistResource() call failing as above.
> >> > > >
> >> > > > I suspect that we're seeing this under load as GC will be taking
> >> place
> >> > > > more often and calls to createConnection() will be happening more
> >> > > > frequently.
> >> > > >
> >> > > > The connection proxies themselves don't do much - only calls to
> >> > > finalize()
> >> > > > and clone() are caught. I propose this patch to allow the proxies
> >> to be
> >> > > > disabled (the current behaviour is still the default):
> >> > > > https://github.com/apache/tomee/pull/174 and welcome feedback.
> >> > > >
> >> > > > Running this specific case with proxies disabled has yielded
> >> positive
> >> > > > results. I'll try and extend this and reproduce it in a test case
> as
> >> > > well.
> >> > > > I'm wondering if AutoConnectionTracker's use of ReferenceQueue is
> >> > thread
> >> > > > safe. Do anyone have any thoughts on this?
> >> > > >
> >> > > > Cheers
> >> > > >
> >> > > > Jon
> >> > > >
> >> > > >
> >> > > >
> >> > > >
> >> > > >
> >> > > >
> >> > > >
> >> > >
> >> >
> >>
> >
>
Re: Connector issues
Posted by Jonathan Gallimore <jo...@gmail.com>.
I have pushed some commits onto the PR here:
https://github.com/apache/tomee/pull/174, and would appreciate some review.
One the things I found was that if I hold onto a reference to the proxy for
the transaction, it doesn't get cleaned up, but then losing the reference
from the scope at the end of the transaction also didn't clean things up.
What was actually going on was:
----
connection = cf.createConnection();
// forget to close it
connection2 = cf.createConnection(); // different proxy, but same
ManagedConnectionInfo as the TransactionCachingInterceptor provides the
same connection
connection2.close(); // this removed the ManagedConnectionInfo from the
references field on AutoConnectionTracker, so it was no longer tracked for
cleanup.
----
The transaction then completed, and connection dropped from scope, but
because the ManagedConnectionInfo associated with it wasn't in the
references list anymore, it never got cleaned up.
To make matters worse, TransactionCachingInterceptor sees that the
ManagedConnectionInfo has open handles and refuses to send it back to the
pool. The effect is the connections leaked and never went back to the pool.
So, my latest changes:
* Keep a proxy for as long as the transaction runs
* Checks the reference list and cleans up at the end
* Checks the ManagedConnectionInfo object, and if there are open handles,
destroys the connection.
* Additionally, if OpenEJB.connector is set to log at FINEST, it should
reveal where any unclosed connections are originally opened, to provide the
developer with a hint on how to fix them.
I'll add some tests this afternoon, but any thoughts would be much
appreciated.
Jon
On Fri, Sep 28, 2018 at 3:18 PM Jonathan Gallimore <
jonathan.gallimore@gmail.com> wrote:
> I was thinking the same - do it through the registry. Let me have a go at
> hacking on that and I'll post back here. Many thanks for the feedback.
>
> Jon
>
> On Fri, Sep 28, 2018 at 3:15 PM Romain Manni-Bucau <rm...@gmail.com>
> wrote:
>
>> that is what I had in mind, throught it was already the case to be honest
>> through the transaction registry - excess of enthusiasm probably ;)
>>
>> Side note: dropped G for now, if we find something impacting g-txmgr we'll
>> add it back
>>
>> Romain Manni-Bucau
>> @rmannibucau <https://twitter.com/rmannibucau> | Blog
>> <https://rmannibucau.metawerx.net/> | Old Blog
>> <http://rmannibucau.wordpress.com> | Github <
>> https://github.com/rmannibucau> |
>> LinkedIn <https://www.linkedin.com/in/rmannibucau> | Book
>> <
>> https://www.packtpub.com/application-development/java-ee-8-high-performance
>> >
>>
>>
>> Le ven. 28 sept. 2018 à 16:11, Jonathan Gallimore <
>> jonathan.gallimore@gmail.com> a écrit :
>>
>> > I apologize, I CC'd Geronimo in case there was anything relevant on the
>> > Geronimo connector side. Happy to drop the CC if its not relevant.
>> >
>> > Thanks for the quick response!
>> >
>> > Off the top of my head, I wonder if we could keep a reference to the
>> > connection proxy in the transaction (if there is one), and remove the
>> > reference when the transaction is complete?
>> >
>> > Jon
>> >
>> > On Fri, Sep 28, 2018 at 2:57 PM Romain Manni-Bucau <
>> rmannibucau@gmail.com>
>> > wrote:
>> >
>> > > Hi Jon,
>> > >
>> > > I experienced that kind of "surprise" in recent jvm since gc is way
>> more
>> > > aggressive - cause lambda are way more memory consuming ;). This lead
>> to
>> > > this kind of issue where the GC happens before the object should
>> actually
>> > > be finalizable.
>> > > I suspect we need to rework the AutoConnectionTracker to take into
>> > account
>> > > these new behaviors and actually take into consideration the
>> lifecycle of
>> > > the underlying connection.
>> > >
>> > > Maybe I got it wrong but I see the ability to disable the proxying as
>> a
>> > > quickfix/workaround - which is ok - but it means we need to fix the
>> > source
>> > > anyway as a long term solution. Am I understanding it right? If so we
>> > need
>> > > to ensure to keep the reference until the connection is released at
>> least
>> > > and ensure it was not closed in the pool (kind of testOnXXX).
>> > > Also wonder if there is anything related to geronimo since you cc-ed
>> it.
>> > > IIRC this logic is only in TomEE, no?
>> > >
>> > > side note: reference queue is supposed thread safe yes.
>> > >
>> > > Romain Manni-Bucau
>> > > @rmannibucau <https://twitter.com/rmannibucau> | Blog
>> > > <https://rmannibucau.metawerx.net/> | Old Blog
>> > > <http://rmannibucau.wordpress.com> | Github <
>> > > https://github.com/rmannibucau> |
>> > > LinkedIn <https://www.linkedin.com/in/rmannibucau> | Book
>> > > <
>> > >
>> >
>> https://www.packtpub.com/application-development/java-ee-8-high-performance
>> > > >
>> > >
>> > >
>> > > Le ven. 28 sept. 2018 à 15:49, Jonathan Gallimore <
>> > > jonathan.gallimore@gmail.com> a écrit :
>> > >
>> > > > Hi Folks,
>> > > >
>> > > > I have been looking into some issues with TomEE using Websphere MQ,
>> > > > specifically issues where XA resources are returning a -7 error
>> during
>> > a
>> > > > transaction commit when the system is under load. The -7 error
>> > indicates
>> > > > that the resource is closed.
>> > > >
>> > > > The result of this error seems to be resources staying in the system
>> > > > somehow associated with the connection, and subsequently, these
>> can't
>> > be
>> > > > enlisted in transactions (because they are closed).
>> > > >
>> > > > The stacktrace is like this, and happens over and over again as the
>> > > server
>> > > > attempts to process more messages from the queue.
>> > > >
>> > > > WARN Transaction- Unable to enlist XAResource
>> > > >
>> org.apache.geronimo.transaction.manager.WrapperNamedXAResource@3dd56e90
>> > ,
>> > > > errorCode: -7
>> > > > javax.transaction.xa.XAException: The method 'xa_start' has failed
>> with
>> > > > errorCode '-7' due to the resource being closed.
>> > > > at
>> > com.ibm.mq.jmqi.JmqiXAResource.start(JmqiXAResource.java:946)
>> > > > ~[com.ibm.mq.jmqi.jar:7.5.0.5 - p750-005-150424]
>> > > > at
>> > com.ibm.mq.connector.xa.XARWrapper.start(XARWrapper.java:581)
>> > > > ~[com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
>> > > > at
>> > > >
>> > >
>> >
>> org.apache.geronimo.transaction.manager.WrapperNamedXAResource.start(WrapperNamedXAResource.java:111)
>> > > > ~[geronimo-transaction-3.1.4.jar:3.1.4]
>> > > > at
>> > > >
>> > >
>> >
>> org.apache.geronimo.transaction.manager.TransactionImpl.enlistResource(TransactionImpl.java:209)
>> > > > [geronimo-transaction-3.1.4.jar:3.1.4]
>> > > > at
>> > > >
>> > >
>> >
>> org.apache.geronimo.connector.outbound.TransactionEnlistingInterceptor.getConnection(TransactionEnlistingInterceptor.java:60)
>> > > > [geronimo-connector-3.1.4.jar:3.1.4]
>> > > > at
>> > > >
>> > >
>> >
>> org.apache.geronimo.connector.outbound.TransactionCachingInterceptor.getConnection(TransactionCachingInterceptor.java:101)
>> > > > [geronimo-connector-3.1.4.jar:3.1.4]
>> > > > at
>> > > >
>> > >
>> >
>> org.apache.geronimo.connector.outbound.ConnectionHandleInterceptor.getConnection(ConnectionHandleInterceptor.java:43)
>> > > > [geronimo-connector-3.1.4.jar:3.1.4]
>> > > > at
>> > > >
>> > >
>> >
>> org.apache.geronimo.connector.outbound.TCCLInterceptor.getConnection(TCCLInterceptor.java:39)
>> > > > [geronimo-connector-3.1.4.jar:3.1.4]
>> > > > at
>> > > >
>> > >
>> >
>> org.apache.geronimo.connector.outbound.ConnectionTrackingInterceptor.getConnection(ConnectionTrackingInterceptor.java:66)
>> > > > [geronimo-connector-3.1.4.jar:3.1.4]
>> > > > at
>> > > >
>> > >
>> >
>> org.apache.geronimo.connector.outbound.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:81)
>> > > > [geronimo-connector-3.1.4.jar:3.1.4]
>> > > > at
>> > > >
>> > >
>> >
>> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createManagedJMSConnection(ConnectionFactoryImpl.java:194)
>> > > > [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
>> > > > at
>> > > >
>> > >
>> >
>> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnectionInternal(ConnectionFactoryImpl.java:153)
>> > > > [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
>> > > > at
>> > > >
>> > >
>> >
>> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:138)
>> > > > [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
>> > > > at
>> > > >
>> > >
>> >
>> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:123)
>> > > > [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
>> > > >
>> > > > The issue itself bears some resemblance to these posts:
>> > > >
>> > > >
>> > > >
>> > >
>> >
>> http://tomee-openejb.979440.n4.nabble.com/Unable-to-enlist-XAResource-error-td4666552.html
>> > > >
>> > > >
>> > >
>> >
>> http://tomee-openejb.979440.n4.nabble.com/Does-tomEE-issue-double-rollbacks-td4666090.html
>> > > >
>> > > >
>> > >
>> >
>> http://tomee-openejb.979440.n4.nabble.com/errorcode-100-when-using-websphere-MQ-with-tomee-td4666519.html
>> > > >
>> > > > com.ibm.mq.jmqi.JmqiXAResource has a isClosed field, and this is set
>> > when
>> > > > close_internal() is called. I tracked this call using AspectJ, and
>> it
>> > > > appeared to happen here:
>> > > >
>> > > >
>> com.ibm.mq.jmqi.JmqiXAResource.close_internal(JmqiXAResource.java:296),
>> > > > com.ibm.mq.jmqi.JmqiXAResource.close(JmqiXAResource.java:423),
>> > > > com.ibm.mq.jmqi.JmqiXAResource.close(JmqiXAResource.java:410),
>> > > >
>> > >
>> >
>> com.ibm.msg.client.wmq.internal.WMQXASession.close(WMQXASession.java:163),
>> > > >
>> > > >
>> > >
>> >
>> com.ibm.msg.client.jms.internal.JmsSessionImpl.close(JmsSessionImpl.java:375),
>> > > >
>> > > >
>> > >
>> >
>> com.ibm.msg.client.jms.internal.JmsSessionImpl.close(JmsSessionImpl.java:303),
>> > > > com.ibm.mq.jms.MQSession.close(MQSession.java:298),
>> > > >
>> > > >
>> > >
>> >
>> com.ibm.mq.connector.outbound.ManagedConnectionImpl.destroy(ManagedConnectionImpl.java:298),
>> > > >
>> > > >
>> > >
>> >
>> org.apache.geronimo.connector.outbound.MCFConnectionInterceptor.returnConnection(MCFConnectionInterceptor.java:67),
>> > > >
>> > > >
>> > >
>> >
>> org.apache.geronimo.connector.outbound.XAResourceInsertionInterceptor.returnConnection(XAResourceInsertionInterceptor.java:47),
>> > > >
>> > > >
>> > >
>> >
>> org.apache.geronimo.connector.outbound.AbstractSinglePoolConnectionInterceptor.internalReturn(AbstractSinglePoolConnectionInterceptor.java:148),
>> > > >
>> > > >
>> > >
>> >
>> org.apache.geronimo.connector.outbound.AbstractSinglePoolConnectionInterceptor.returnConnection(AbstractSinglePoolConnectionInterceptor.java:129),
>> > > >
>> > > >
>> > >
>> >
>> org.apache.geronimo.connector.outbound.TransactionEnlistingInterceptor.returnConnection(TransactionEnlistingInterceptor.java:118),
>> > > >
>> > > >
>> > >
>> >
>> org.apache.geronimo.connector.outbound.TransactionCachingInterceptor.returnConnection(TransactionCachingInterceptor.java:119),
>> > > >
>> > > >
>> > >
>> >
>> org.apache.geronimo.connector.outbound.ConnectionHandleInterceptor.returnConnection(ConnectionHandleInterceptor.java:71),
>> > > >
>> > > >
>> > >
>> >
>> org.apache.geronimo.connector.outbound.TCCLInterceptor.returnConnection(TCCLInterceptor.java:50),
>> > > >
>> > > >
>> > >
>> >
>> org.apache.geronimo.connector.outbound.ConnectionTrackingInterceptor.returnConnection(ConnectionTrackingInterceptor.java:91),
>> > > >
>> > > >
>> > >
>> >
>> org.apache.openejb.resource.AutoConnectionTracker.setEnvironment(AutoConnectionTracker.java:62),
>> > > >
>> > > >
>> > >
>> >
>> org.apache.geronimo.connector.outbound.ConnectionTrackingInterceptor.getConnection(ConnectionTrackingInterceptor.java:65),
>> > > >
>> > > >
>> > >
>> >
>> org.apache.geronimo.connector.outbound.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:81),
>> > > >
>> > > >
>> > >
>> >
>> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createManagedJMSConnection(ConnectionFactoryImpl.java:194),
>> > > >
>> > > >
>> > >
>> >
>> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnectionInternal(ConnectionFactoryImpl.java:153),
>> > > >
>> > > >
>> > >
>> >
>> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:138),
>> > > >
>> > > >
>> > >
>> >
>> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:123),
>> > > >
>> > > > The interesting part here is the
>> > > > org.apache.openejb.resource.AutoConnectionTracker.setEnvironment()
>> > call,
>> > > > which is destroying connections where the proxy for the connection
>> no
>> > > > longer has any references. I.e. if you had some code that did this:
>> > > >
>> > > > ----
>> > > > Connection conn = connectionFactory.createConnection(); // conn is
>> > > > actually a proxy to the connection
>> > > > // do work
>> > > >
>> > > > conn = null; // or conn is out of scope
>> > > > ----
>> > > >
>> > > > note that conn.close() is not called. The reference count to the
>> proxy
>> > is
>> > > > now zero, so it counts as abandoned, and the next call to
>> > > > createConnection() destroys the associated connection. However, if
>> all
>> > > this
>> > > > happens in a transacted method, the JmqiXAResource is still enlisted
>> > with
>> > > > the transaction. So when the transaction goes to commit, it fails,
>> > > because
>> > > > the JmqiXAResource is closed. The resource is still associated with
>> a
>> > > > ManagedConnectionInfo object through ManagedConnectionInfo.xares
>> > > > (WrapperNamedXAResource). xaResource (XARWrapper - part of the
>> > > RAR).theXAR
>> > > > (JmqiXAResource - part of the RAR). The ManagedConnectionInfo object
>> > > > somehow comes back to the pool after the rollback, and gets used
>> again,
>> > > > with the TransactionImpl.enlistResource() call failing as above.
>> > > >
>> > > > I suspect that we're seeing this under load as GC will be taking
>> place
>> > > > more often and calls to createConnection() will be happening more
>> > > > frequently.
>> > > >
>> > > > The connection proxies themselves don't do much - only calls to
>> > > finalize()
>> > > > and clone() are caught. I propose this patch to allow the proxies
>> to be
>> > > > disabled (the current behaviour is still the default):
>> > > > https://github.com/apache/tomee/pull/174 and welcome feedback.
>> > > >
>> > > > Running this specific case with proxies disabled has yielded
>> positive
>> > > > results. I'll try and extend this and reproduce it in a test case as
>> > > well.
>> > > > I'm wondering if AutoConnectionTracker's use of ReferenceQueue is
>> > thread
>> > > > safe. Do anyone have any thoughts on this?
>> > > >
>> > > > Cheers
>> > > >
>> > > > Jon
>> > > >
>> > > >
>> > > >
>> > > >
>> > > >
>> > > >
>> > > >
>> > >
>> >
>>
>
Re: Connector issues
Posted by Jonathan Gallimore <jo...@gmail.com>.
I was thinking the same - do it through the registry. Let me have a go at
hacking on that and I'll post back here. Many thanks for the feedback.
Jon
On Fri, Sep 28, 2018 at 3:15 PM Romain Manni-Bucau <rm...@gmail.com>
wrote:
> that is what I had in mind, throught it was already the case to be honest
> through the transaction registry - excess of enthusiasm probably ;)
>
> Side note: dropped G for now, if we find something impacting g-txmgr we'll
> add it back
>
> Romain Manni-Bucau
> @rmannibucau <https://twitter.com/rmannibucau> | Blog
> <https://rmannibucau.metawerx.net/> | Old Blog
> <http://rmannibucau.wordpress.com> | Github <
> https://github.com/rmannibucau> |
> LinkedIn <https://www.linkedin.com/in/rmannibucau> | Book
> <
> https://www.packtpub.com/application-development/java-ee-8-high-performance
> >
>
>
> Le ven. 28 sept. 2018 à 16:11, Jonathan Gallimore <
> jonathan.gallimore@gmail.com> a écrit :
>
> > I apologize, I CC'd Geronimo in case there was anything relevant on the
> > Geronimo connector side. Happy to drop the CC if its not relevant.
> >
> > Thanks for the quick response!
> >
> > Off the top of my head, I wonder if we could keep a reference to the
> > connection proxy in the transaction (if there is one), and remove the
> > reference when the transaction is complete?
> >
> > Jon
> >
> > On Fri, Sep 28, 2018 at 2:57 PM Romain Manni-Bucau <
> rmannibucau@gmail.com>
> > wrote:
> >
> > > Hi Jon,
> > >
> > > I experienced that kind of "surprise" in recent jvm since gc is way
> more
> > > aggressive - cause lambda are way more memory consuming ;). This lead
> to
> > > this kind of issue where the GC happens before the object should
> actually
> > > be finalizable.
> > > I suspect we need to rework the AutoConnectionTracker to take into
> > account
> > > these new behaviors and actually take into consideration the lifecycle
> of
> > > the underlying connection.
> > >
> > > Maybe I got it wrong but I see the ability to disable the proxying as a
> > > quickfix/workaround - which is ok - but it means we need to fix the
> > source
> > > anyway as a long term solution. Am I understanding it right? If so we
> > need
> > > to ensure to keep the reference until the connection is released at
> least
> > > and ensure it was not closed in the pool (kind of testOnXXX).
> > > Also wonder if there is anything related to geronimo since you cc-ed
> it.
> > > IIRC this logic is only in TomEE, no?
> > >
> > > side note: reference queue is supposed thread safe yes.
> > >
> > > Romain Manni-Bucau
> > > @rmannibucau <https://twitter.com/rmannibucau> | Blog
> > > <https://rmannibucau.metawerx.net/> | Old Blog
> > > <http://rmannibucau.wordpress.com> | Github <
> > > https://github.com/rmannibucau> |
> > > LinkedIn <https://www.linkedin.com/in/rmannibucau> | Book
> > > <
> > >
> >
> https://www.packtpub.com/application-development/java-ee-8-high-performance
> > > >
> > >
> > >
> > > Le ven. 28 sept. 2018 à 15:49, Jonathan Gallimore <
> > > jonathan.gallimore@gmail.com> a écrit :
> > >
> > > > Hi Folks,
> > > >
> > > > I have been looking into some issues with TomEE using Websphere MQ,
> > > > specifically issues where XA resources are returning a -7 error
> during
> > a
> > > > transaction commit when the system is under load. The -7 error
> > indicates
> > > > that the resource is closed.
> > > >
> > > > The result of this error seems to be resources staying in the system
> > > > somehow associated with the connection, and subsequently, these can't
> > be
> > > > enlisted in transactions (because they are closed).
> > > >
> > > > The stacktrace is like this, and happens over and over again as the
> > > server
> > > > attempts to process more messages from the queue.
> > > >
> > > > WARN Transaction- Unable to enlist XAResource
> > > >
> org.apache.geronimo.transaction.manager.WrapperNamedXAResource@3dd56e90
> > ,
> > > > errorCode: -7
> > > > javax.transaction.xa.XAException: The method 'xa_start' has failed
> with
> > > > errorCode '-7' due to the resource being closed.
> > > > at
> > com.ibm.mq.jmqi.JmqiXAResource.start(JmqiXAResource.java:946)
> > > > ~[com.ibm.mq.jmqi.jar:7.5.0.5 - p750-005-150424]
> > > > at
> > com.ibm.mq.connector.xa.XARWrapper.start(XARWrapper.java:581)
> > > > ~[com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> > > > at
> > > >
> > >
> >
> org.apache.geronimo.transaction.manager.WrapperNamedXAResource.start(WrapperNamedXAResource.java:111)
> > > > ~[geronimo-transaction-3.1.4.jar:3.1.4]
> > > > at
> > > >
> > >
> >
> org.apache.geronimo.transaction.manager.TransactionImpl.enlistResource(TransactionImpl.java:209)
> > > > [geronimo-transaction-3.1.4.jar:3.1.4]
> > > > at
> > > >
> > >
> >
> org.apache.geronimo.connector.outbound.TransactionEnlistingInterceptor.getConnection(TransactionEnlistingInterceptor.java:60)
> > > > [geronimo-connector-3.1.4.jar:3.1.4]
> > > > at
> > > >
> > >
> >
> org.apache.geronimo.connector.outbound.TransactionCachingInterceptor.getConnection(TransactionCachingInterceptor.java:101)
> > > > [geronimo-connector-3.1.4.jar:3.1.4]
> > > > at
> > > >
> > >
> >
> org.apache.geronimo.connector.outbound.ConnectionHandleInterceptor.getConnection(ConnectionHandleInterceptor.java:43)
> > > > [geronimo-connector-3.1.4.jar:3.1.4]
> > > > at
> > > >
> > >
> >
> org.apache.geronimo.connector.outbound.TCCLInterceptor.getConnection(TCCLInterceptor.java:39)
> > > > [geronimo-connector-3.1.4.jar:3.1.4]
> > > > at
> > > >
> > >
> >
> org.apache.geronimo.connector.outbound.ConnectionTrackingInterceptor.getConnection(ConnectionTrackingInterceptor.java:66)
> > > > [geronimo-connector-3.1.4.jar:3.1.4]
> > > > at
> > > >
> > >
> >
> org.apache.geronimo.connector.outbound.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:81)
> > > > [geronimo-connector-3.1.4.jar:3.1.4]
> > > > at
> > > >
> > >
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createManagedJMSConnection(ConnectionFactoryImpl.java:194)
> > > > [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> > > > at
> > > >
> > >
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnectionInternal(ConnectionFactoryImpl.java:153)
> > > > [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> > > > at
> > > >
> > >
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:138)
> > > > [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> > > > at
> > > >
> > >
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:123)
> > > > [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> > > >
> > > > The issue itself bears some resemblance to these posts:
> > > >
> > > >
> > > >
> > >
> >
> http://tomee-openejb.979440.n4.nabble.com/Unable-to-enlist-XAResource-error-td4666552.html
> > > >
> > > >
> > >
> >
> http://tomee-openejb.979440.n4.nabble.com/Does-tomEE-issue-double-rollbacks-td4666090.html
> > > >
> > > >
> > >
> >
> http://tomee-openejb.979440.n4.nabble.com/errorcode-100-when-using-websphere-MQ-with-tomee-td4666519.html
> > > >
> > > > com.ibm.mq.jmqi.JmqiXAResource has a isClosed field, and this is set
> > when
> > > > close_internal() is called. I tracked this call using AspectJ, and it
> > > > appeared to happen here:
> > > >
> > > >
> com.ibm.mq.jmqi.JmqiXAResource.close_internal(JmqiXAResource.java:296),
> > > > com.ibm.mq.jmqi.JmqiXAResource.close(JmqiXAResource.java:423),
> > > > com.ibm.mq.jmqi.JmqiXAResource.close(JmqiXAResource.java:410),
> > > >
> > >
> >
> com.ibm.msg.client.wmq.internal.WMQXASession.close(WMQXASession.java:163),
> > > >
> > > >
> > >
> >
> com.ibm.msg.client.jms.internal.JmsSessionImpl.close(JmsSessionImpl.java:375),
> > > >
> > > >
> > >
> >
> com.ibm.msg.client.jms.internal.JmsSessionImpl.close(JmsSessionImpl.java:303),
> > > > com.ibm.mq.jms.MQSession.close(MQSession.java:298),
> > > >
> > > >
> > >
> >
> com.ibm.mq.connector.outbound.ManagedConnectionImpl.destroy(ManagedConnectionImpl.java:298),
> > > >
> > > >
> > >
> >
> org.apache.geronimo.connector.outbound.MCFConnectionInterceptor.returnConnection(MCFConnectionInterceptor.java:67),
> > > >
> > > >
> > >
> >
> org.apache.geronimo.connector.outbound.XAResourceInsertionInterceptor.returnConnection(XAResourceInsertionInterceptor.java:47),
> > > >
> > > >
> > >
> >
> org.apache.geronimo.connector.outbound.AbstractSinglePoolConnectionInterceptor.internalReturn(AbstractSinglePoolConnectionInterceptor.java:148),
> > > >
> > > >
> > >
> >
> org.apache.geronimo.connector.outbound.AbstractSinglePoolConnectionInterceptor.returnConnection(AbstractSinglePoolConnectionInterceptor.java:129),
> > > >
> > > >
> > >
> >
> org.apache.geronimo.connector.outbound.TransactionEnlistingInterceptor.returnConnection(TransactionEnlistingInterceptor.java:118),
> > > >
> > > >
> > >
> >
> org.apache.geronimo.connector.outbound.TransactionCachingInterceptor.returnConnection(TransactionCachingInterceptor.java:119),
> > > >
> > > >
> > >
> >
> org.apache.geronimo.connector.outbound.ConnectionHandleInterceptor.returnConnection(ConnectionHandleInterceptor.java:71),
> > > >
> > > >
> > >
> >
> org.apache.geronimo.connector.outbound.TCCLInterceptor.returnConnection(TCCLInterceptor.java:50),
> > > >
> > > >
> > >
> >
> org.apache.geronimo.connector.outbound.ConnectionTrackingInterceptor.returnConnection(ConnectionTrackingInterceptor.java:91),
> > > >
> > > >
> > >
> >
> org.apache.openejb.resource.AutoConnectionTracker.setEnvironment(AutoConnectionTracker.java:62),
> > > >
> > > >
> > >
> >
> org.apache.geronimo.connector.outbound.ConnectionTrackingInterceptor.getConnection(ConnectionTrackingInterceptor.java:65),
> > > >
> > > >
> > >
> >
> org.apache.geronimo.connector.outbound.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:81),
> > > >
> > > >
> > >
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createManagedJMSConnection(ConnectionFactoryImpl.java:194),
> > > >
> > > >
> > >
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnectionInternal(ConnectionFactoryImpl.java:153),
> > > >
> > > >
> > >
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:138),
> > > >
> > > >
> > >
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:123),
> > > >
> > > > The interesting part here is the
> > > > org.apache.openejb.resource.AutoConnectionTracker.setEnvironment()
> > call,
> > > > which is destroying connections where the proxy for the connection no
> > > > longer has any references. I.e. if you had some code that did this:
> > > >
> > > > ----
> > > > Connection conn = connectionFactory.createConnection(); // conn is
> > > > actually a proxy to the connection
> > > > // do work
> > > >
> > > > conn = null; // or conn is out of scope
> > > > ----
> > > >
> > > > note that conn.close() is not called. The reference count to the
> proxy
> > is
> > > > now zero, so it counts as abandoned, and the next call to
> > > > createConnection() destroys the associated connection. However, if
> all
> > > this
> > > > happens in a transacted method, the JmqiXAResource is still enlisted
> > with
> > > > the transaction. So when the transaction goes to commit, it fails,
> > > because
> > > > the JmqiXAResource is closed. The resource is still associated with a
> > > > ManagedConnectionInfo object through ManagedConnectionInfo.xares
> > > > (WrapperNamedXAResource). xaResource (XARWrapper - part of the
> > > RAR).theXAR
> > > > (JmqiXAResource - part of the RAR). The ManagedConnectionInfo object
> > > > somehow comes back to the pool after the rollback, and gets used
> again,
> > > > with the TransactionImpl.enlistResource() call failing as above.
> > > >
> > > > I suspect that we're seeing this under load as GC will be taking
> place
> > > > more often and calls to createConnection() will be happening more
> > > > frequently.
> > > >
> > > > The connection proxies themselves don't do much - only calls to
> > > finalize()
> > > > and clone() are caught. I propose this patch to allow the proxies to
> be
> > > > disabled (the current behaviour is still the default):
> > > > https://github.com/apache/tomee/pull/174 and welcome feedback.
> > > >
> > > > Running this specific case with proxies disabled has yielded positive
> > > > results. I'll try and extend this and reproduce it in a test case as
> > > well.
> > > > I'm wondering if AutoConnectionTracker's use of ReferenceQueue is
> > thread
> > > > safe. Do anyone have any thoughts on this?
> > > >
> > > > Cheers
> > > >
> > > > Jon
> > > >
> > > >
> > > >
> > > >
> > > >
> > > >
> > > >
> > >
> >
>
Re: Connector issues
Posted by Romain Manni-Bucau <rm...@gmail.com>.
that is what I had in mind, throught it was already the case to be honest
through the transaction registry - excess of enthusiasm probably ;)
Side note: dropped G for now, if we find something impacting g-txmgr we'll
add it back
Romain Manni-Bucau
@rmannibucau <https://twitter.com/rmannibucau> | Blog
<https://rmannibucau.metawerx.net/> | Old Blog
<http://rmannibucau.wordpress.com> | Github <https://github.com/rmannibucau> |
LinkedIn <https://www.linkedin.com/in/rmannibucau> | Book
<https://www.packtpub.com/application-development/java-ee-8-high-performance>
Le ven. 28 sept. 2018 à 16:11, Jonathan Gallimore <
jonathan.gallimore@gmail.com> a écrit :
> I apologize, I CC'd Geronimo in case there was anything relevant on the
> Geronimo connector side. Happy to drop the CC if its not relevant.
>
> Thanks for the quick response!
>
> Off the top of my head, I wonder if we could keep a reference to the
> connection proxy in the transaction (if there is one), and remove the
> reference when the transaction is complete?
>
> Jon
>
> On Fri, Sep 28, 2018 at 2:57 PM Romain Manni-Bucau <rm...@gmail.com>
> wrote:
>
> > Hi Jon,
> >
> > I experienced that kind of "surprise" in recent jvm since gc is way more
> > aggressive - cause lambda are way more memory consuming ;). This lead to
> > this kind of issue where the GC happens before the object should actually
> > be finalizable.
> > I suspect we need to rework the AutoConnectionTracker to take into
> account
> > these new behaviors and actually take into consideration the lifecycle of
> > the underlying connection.
> >
> > Maybe I got it wrong but I see the ability to disable the proxying as a
> > quickfix/workaround - which is ok - but it means we need to fix the
> source
> > anyway as a long term solution. Am I understanding it right? If so we
> need
> > to ensure to keep the reference until the connection is released at least
> > and ensure it was not closed in the pool (kind of testOnXXX).
> > Also wonder if there is anything related to geronimo since you cc-ed it.
> > IIRC this logic is only in TomEE, no?
> >
> > side note: reference queue is supposed thread safe yes.
> >
> > Romain Manni-Bucau
> > @rmannibucau <https://twitter.com/rmannibucau> | Blog
> > <https://rmannibucau.metawerx.net/> | Old Blog
> > <http://rmannibucau.wordpress.com> | Github <
> > https://github.com/rmannibucau> |
> > LinkedIn <https://www.linkedin.com/in/rmannibucau> | Book
> > <
> >
> https://www.packtpub.com/application-development/java-ee-8-high-performance
> > >
> >
> >
> > Le ven. 28 sept. 2018 à 15:49, Jonathan Gallimore <
> > jonathan.gallimore@gmail.com> a écrit :
> >
> > > Hi Folks,
> > >
> > > I have been looking into some issues with TomEE using Websphere MQ,
> > > specifically issues where XA resources are returning a -7 error during
> a
> > > transaction commit when the system is under load. The -7 error
> indicates
> > > that the resource is closed.
> > >
> > > The result of this error seems to be resources staying in the system
> > > somehow associated with the connection, and subsequently, these can't
> be
> > > enlisted in transactions (because they are closed).
> > >
> > > The stacktrace is like this, and happens over and over again as the
> > server
> > > attempts to process more messages from the queue.
> > >
> > > WARN Transaction- Unable to enlist XAResource
> > > org.apache.geronimo.transaction.manager.WrapperNamedXAResource@3dd56e90
> ,
> > > errorCode: -7
> > > javax.transaction.xa.XAException: The method 'xa_start' has failed with
> > > errorCode '-7' due to the resource being closed.
> > > at
> com.ibm.mq.jmqi.JmqiXAResource.start(JmqiXAResource.java:946)
> > > ~[com.ibm.mq.jmqi.jar:7.5.0.5 - p750-005-150424]
> > > at
> com.ibm.mq.connector.xa.XARWrapper.start(XARWrapper.java:581)
> > > ~[com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> > > at
> > >
> >
> org.apache.geronimo.transaction.manager.WrapperNamedXAResource.start(WrapperNamedXAResource.java:111)
> > > ~[geronimo-transaction-3.1.4.jar:3.1.4]
> > > at
> > >
> >
> org.apache.geronimo.transaction.manager.TransactionImpl.enlistResource(TransactionImpl.java:209)
> > > [geronimo-transaction-3.1.4.jar:3.1.4]
> > > at
> > >
> >
> org.apache.geronimo.connector.outbound.TransactionEnlistingInterceptor.getConnection(TransactionEnlistingInterceptor.java:60)
> > > [geronimo-connector-3.1.4.jar:3.1.4]
> > > at
> > >
> >
> org.apache.geronimo.connector.outbound.TransactionCachingInterceptor.getConnection(TransactionCachingInterceptor.java:101)
> > > [geronimo-connector-3.1.4.jar:3.1.4]
> > > at
> > >
> >
> org.apache.geronimo.connector.outbound.ConnectionHandleInterceptor.getConnection(ConnectionHandleInterceptor.java:43)
> > > [geronimo-connector-3.1.4.jar:3.1.4]
> > > at
> > >
> >
> org.apache.geronimo.connector.outbound.TCCLInterceptor.getConnection(TCCLInterceptor.java:39)
> > > [geronimo-connector-3.1.4.jar:3.1.4]
> > > at
> > >
> >
> org.apache.geronimo.connector.outbound.ConnectionTrackingInterceptor.getConnection(ConnectionTrackingInterceptor.java:66)
> > > [geronimo-connector-3.1.4.jar:3.1.4]
> > > at
> > >
> >
> org.apache.geronimo.connector.outbound.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:81)
> > > [geronimo-connector-3.1.4.jar:3.1.4]
> > > at
> > >
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createManagedJMSConnection(ConnectionFactoryImpl.java:194)
> > > [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> > > at
> > >
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnectionInternal(ConnectionFactoryImpl.java:153)
> > > [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> > > at
> > >
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:138)
> > > [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> > > at
> > >
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:123)
> > > [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> > >
> > > The issue itself bears some resemblance to these posts:
> > >
> > >
> > >
> >
> http://tomee-openejb.979440.n4.nabble.com/Unable-to-enlist-XAResource-error-td4666552.html
> > >
> > >
> >
> http://tomee-openejb.979440.n4.nabble.com/Does-tomEE-issue-double-rollbacks-td4666090.html
> > >
> > >
> >
> http://tomee-openejb.979440.n4.nabble.com/errorcode-100-when-using-websphere-MQ-with-tomee-td4666519.html
> > >
> > > com.ibm.mq.jmqi.JmqiXAResource has a isClosed field, and this is set
> when
> > > close_internal() is called. I tracked this call using AspectJ, and it
> > > appeared to happen here:
> > >
> > > com.ibm.mq.jmqi.JmqiXAResource.close_internal(JmqiXAResource.java:296),
> > > com.ibm.mq.jmqi.JmqiXAResource.close(JmqiXAResource.java:423),
> > > com.ibm.mq.jmqi.JmqiXAResource.close(JmqiXAResource.java:410),
> > >
> >
> com.ibm.msg.client.wmq.internal.WMQXASession.close(WMQXASession.java:163),
> > >
> > >
> >
> com.ibm.msg.client.jms.internal.JmsSessionImpl.close(JmsSessionImpl.java:375),
> > >
> > >
> >
> com.ibm.msg.client.jms.internal.JmsSessionImpl.close(JmsSessionImpl.java:303),
> > > com.ibm.mq.jms.MQSession.close(MQSession.java:298),
> > >
> > >
> >
> com.ibm.mq.connector.outbound.ManagedConnectionImpl.destroy(ManagedConnectionImpl.java:298),
> > >
> > >
> >
> org.apache.geronimo.connector.outbound.MCFConnectionInterceptor.returnConnection(MCFConnectionInterceptor.java:67),
> > >
> > >
> >
> org.apache.geronimo.connector.outbound.XAResourceInsertionInterceptor.returnConnection(XAResourceInsertionInterceptor.java:47),
> > >
> > >
> >
> org.apache.geronimo.connector.outbound.AbstractSinglePoolConnectionInterceptor.internalReturn(AbstractSinglePoolConnectionInterceptor.java:148),
> > >
> > >
> >
> org.apache.geronimo.connector.outbound.AbstractSinglePoolConnectionInterceptor.returnConnection(AbstractSinglePoolConnectionInterceptor.java:129),
> > >
> > >
> >
> org.apache.geronimo.connector.outbound.TransactionEnlistingInterceptor.returnConnection(TransactionEnlistingInterceptor.java:118),
> > >
> > >
> >
> org.apache.geronimo.connector.outbound.TransactionCachingInterceptor.returnConnection(TransactionCachingInterceptor.java:119),
> > >
> > >
> >
> org.apache.geronimo.connector.outbound.ConnectionHandleInterceptor.returnConnection(ConnectionHandleInterceptor.java:71),
> > >
> > >
> >
> org.apache.geronimo.connector.outbound.TCCLInterceptor.returnConnection(TCCLInterceptor.java:50),
> > >
> > >
> >
> org.apache.geronimo.connector.outbound.ConnectionTrackingInterceptor.returnConnection(ConnectionTrackingInterceptor.java:91),
> > >
> > >
> >
> org.apache.openejb.resource.AutoConnectionTracker.setEnvironment(AutoConnectionTracker.java:62),
> > >
> > >
> >
> org.apache.geronimo.connector.outbound.ConnectionTrackingInterceptor.getConnection(ConnectionTrackingInterceptor.java:65),
> > >
> > >
> >
> org.apache.geronimo.connector.outbound.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:81),
> > >
> > >
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createManagedJMSConnection(ConnectionFactoryImpl.java:194),
> > >
> > >
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnectionInternal(ConnectionFactoryImpl.java:153),
> > >
> > >
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:138),
> > >
> > >
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:123),
> > >
> > > The interesting part here is the
> > > org.apache.openejb.resource.AutoConnectionTracker.setEnvironment()
> call,
> > > which is destroying connections where the proxy for the connection no
> > > longer has any references. I.e. if you had some code that did this:
> > >
> > > ----
> > > Connection conn = connectionFactory.createConnection(); // conn is
> > > actually a proxy to the connection
> > > // do work
> > >
> > > conn = null; // or conn is out of scope
> > > ----
> > >
> > > note that conn.close() is not called. The reference count to the proxy
> is
> > > now zero, so it counts as abandoned, and the next call to
> > > createConnection() destroys the associated connection. However, if all
> > this
> > > happens in a transacted method, the JmqiXAResource is still enlisted
> with
> > > the transaction. So when the transaction goes to commit, it fails,
> > because
> > > the JmqiXAResource is closed. The resource is still associated with a
> > > ManagedConnectionInfo object through ManagedConnectionInfo.xares
> > > (WrapperNamedXAResource). xaResource (XARWrapper - part of the
> > RAR).theXAR
> > > (JmqiXAResource - part of the RAR). The ManagedConnectionInfo object
> > > somehow comes back to the pool after the rollback, and gets used again,
> > > with the TransactionImpl.enlistResource() call failing as above.
> > >
> > > I suspect that we're seeing this under load as GC will be taking place
> > > more often and calls to createConnection() will be happening more
> > > frequently.
> > >
> > > The connection proxies themselves don't do much - only calls to
> > finalize()
> > > and clone() are caught. I propose this patch to allow the proxies to be
> > > disabled (the current behaviour is still the default):
> > > https://github.com/apache/tomee/pull/174 and welcome feedback.
> > >
> > > Running this specific case with proxies disabled has yielded positive
> > > results. I'll try and extend this and reproduce it in a test case as
> > well.
> > > I'm wondering if AutoConnectionTracker's use of ReferenceQueue is
> thread
> > > safe. Do anyone have any thoughts on this?
> > >
> > > Cheers
> > >
> > > Jon
> > >
> > >
> > >
> > >
> > >
> > >
> > >
> >
>
Re: Connector issues
Posted by Jonathan Gallimore <jo...@gmail.com>.
I apologize, I CC'd Geronimo in case there was anything relevant on the
Geronimo connector side. Happy to drop the CC if its not relevant.
Thanks for the quick response!
Off the top of my head, I wonder if we could keep a reference to the
connection proxy in the transaction (if there is one), and remove the
reference when the transaction is complete?
Jon
On Fri, Sep 28, 2018 at 2:57 PM Romain Manni-Bucau <rm...@gmail.com>
wrote:
> Hi Jon,
>
> I experienced that kind of "surprise" in recent jvm since gc is way more
> aggressive - cause lambda are way more memory consuming ;). This lead to
> this kind of issue where the GC happens before the object should actually
> be finalizable.
> I suspect we need to rework the AutoConnectionTracker to take into account
> these new behaviors and actually take into consideration the lifecycle of
> the underlying connection.
>
> Maybe I got it wrong but I see the ability to disable the proxying as a
> quickfix/workaround - which is ok - but it means we need to fix the source
> anyway as a long term solution. Am I understanding it right? If so we need
> to ensure to keep the reference until the connection is released at least
> and ensure it was not closed in the pool (kind of testOnXXX).
> Also wonder if there is anything related to geronimo since you cc-ed it.
> IIRC this logic is only in TomEE, no?
>
> side note: reference queue is supposed thread safe yes.
>
> Romain Manni-Bucau
> @rmannibucau <https://twitter.com/rmannibucau> | Blog
> <https://rmannibucau.metawerx.net/> | Old Blog
> <http://rmannibucau.wordpress.com> | Github <
> https://github.com/rmannibucau> |
> LinkedIn <https://www.linkedin.com/in/rmannibucau> | Book
> <
> https://www.packtpub.com/application-development/java-ee-8-high-performance
> >
>
>
> Le ven. 28 sept. 2018 à 15:49, Jonathan Gallimore <
> jonathan.gallimore@gmail.com> a écrit :
>
> > Hi Folks,
> >
> > I have been looking into some issues with TomEE using Websphere MQ,
> > specifically issues where XA resources are returning a -7 error during a
> > transaction commit when the system is under load. The -7 error indicates
> > that the resource is closed.
> >
> > The result of this error seems to be resources staying in the system
> > somehow associated with the connection, and subsequently, these can't be
> > enlisted in transactions (because they are closed).
> >
> > The stacktrace is like this, and happens over and over again as the
> server
> > attempts to process more messages from the queue.
> >
> > WARN Transaction- Unable to enlist XAResource
> > org.apache.geronimo.transaction.manager.WrapperNamedXAResource@3dd56e90,
> > errorCode: -7
> > javax.transaction.xa.XAException: The method 'xa_start' has failed with
> > errorCode '-7' due to the resource being closed.
> > at com.ibm.mq.jmqi.JmqiXAResource.start(JmqiXAResource.java:946)
> > ~[com.ibm.mq.jmqi.jar:7.5.0.5 - p750-005-150424]
> > at com.ibm.mq.connector.xa.XARWrapper.start(XARWrapper.java:581)
> > ~[com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> > at
> >
> org.apache.geronimo.transaction.manager.WrapperNamedXAResource.start(WrapperNamedXAResource.java:111)
> > ~[geronimo-transaction-3.1.4.jar:3.1.4]
> > at
> >
> org.apache.geronimo.transaction.manager.TransactionImpl.enlistResource(TransactionImpl.java:209)
> > [geronimo-transaction-3.1.4.jar:3.1.4]
> > at
> >
> org.apache.geronimo.connector.outbound.TransactionEnlistingInterceptor.getConnection(TransactionEnlistingInterceptor.java:60)
> > [geronimo-connector-3.1.4.jar:3.1.4]
> > at
> >
> org.apache.geronimo.connector.outbound.TransactionCachingInterceptor.getConnection(TransactionCachingInterceptor.java:101)
> > [geronimo-connector-3.1.4.jar:3.1.4]
> > at
> >
> org.apache.geronimo.connector.outbound.ConnectionHandleInterceptor.getConnection(ConnectionHandleInterceptor.java:43)
> > [geronimo-connector-3.1.4.jar:3.1.4]
> > at
> >
> org.apache.geronimo.connector.outbound.TCCLInterceptor.getConnection(TCCLInterceptor.java:39)
> > [geronimo-connector-3.1.4.jar:3.1.4]
> > at
> >
> org.apache.geronimo.connector.outbound.ConnectionTrackingInterceptor.getConnection(ConnectionTrackingInterceptor.java:66)
> > [geronimo-connector-3.1.4.jar:3.1.4]
> > at
> >
> org.apache.geronimo.connector.outbound.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:81)
> > [geronimo-connector-3.1.4.jar:3.1.4]
> > at
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createManagedJMSConnection(ConnectionFactoryImpl.java:194)
> > [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> > at
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnectionInternal(ConnectionFactoryImpl.java:153)
> > [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> > at
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:138)
> > [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> > at
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:123)
> > [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> >
> > The issue itself bears some resemblance to these posts:
> >
> >
> >
> http://tomee-openejb.979440.n4.nabble.com/Unable-to-enlist-XAResource-error-td4666552.html
> >
> >
> http://tomee-openejb.979440.n4.nabble.com/Does-tomEE-issue-double-rollbacks-td4666090.html
> >
> >
> http://tomee-openejb.979440.n4.nabble.com/errorcode-100-when-using-websphere-MQ-with-tomee-td4666519.html
> >
> > com.ibm.mq.jmqi.JmqiXAResource has a isClosed field, and this is set when
> > close_internal() is called. I tracked this call using AspectJ, and it
> > appeared to happen here:
> >
> > com.ibm.mq.jmqi.JmqiXAResource.close_internal(JmqiXAResource.java:296),
> > com.ibm.mq.jmqi.JmqiXAResource.close(JmqiXAResource.java:423),
> > com.ibm.mq.jmqi.JmqiXAResource.close(JmqiXAResource.java:410),
> >
> com.ibm.msg.client.wmq.internal.WMQXASession.close(WMQXASession.java:163),
> >
> >
> com.ibm.msg.client.jms.internal.JmsSessionImpl.close(JmsSessionImpl.java:375),
> >
> >
> com.ibm.msg.client.jms.internal.JmsSessionImpl.close(JmsSessionImpl.java:303),
> > com.ibm.mq.jms.MQSession.close(MQSession.java:298),
> >
> >
> com.ibm.mq.connector.outbound.ManagedConnectionImpl.destroy(ManagedConnectionImpl.java:298),
> >
> >
> org.apache.geronimo.connector.outbound.MCFConnectionInterceptor.returnConnection(MCFConnectionInterceptor.java:67),
> >
> >
> org.apache.geronimo.connector.outbound.XAResourceInsertionInterceptor.returnConnection(XAResourceInsertionInterceptor.java:47),
> >
> >
> org.apache.geronimo.connector.outbound.AbstractSinglePoolConnectionInterceptor.internalReturn(AbstractSinglePoolConnectionInterceptor.java:148),
> >
> >
> org.apache.geronimo.connector.outbound.AbstractSinglePoolConnectionInterceptor.returnConnection(AbstractSinglePoolConnectionInterceptor.java:129),
> >
> >
> org.apache.geronimo.connector.outbound.TransactionEnlistingInterceptor.returnConnection(TransactionEnlistingInterceptor.java:118),
> >
> >
> org.apache.geronimo.connector.outbound.TransactionCachingInterceptor.returnConnection(TransactionCachingInterceptor.java:119),
> >
> >
> org.apache.geronimo.connector.outbound.ConnectionHandleInterceptor.returnConnection(ConnectionHandleInterceptor.java:71),
> >
> >
> org.apache.geronimo.connector.outbound.TCCLInterceptor.returnConnection(TCCLInterceptor.java:50),
> >
> >
> org.apache.geronimo.connector.outbound.ConnectionTrackingInterceptor.returnConnection(ConnectionTrackingInterceptor.java:91),
> >
> >
> org.apache.openejb.resource.AutoConnectionTracker.setEnvironment(AutoConnectionTracker.java:62),
> >
> >
> org.apache.geronimo.connector.outbound.ConnectionTrackingInterceptor.getConnection(ConnectionTrackingInterceptor.java:65),
> >
> >
> org.apache.geronimo.connector.outbound.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:81),
> >
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createManagedJMSConnection(ConnectionFactoryImpl.java:194),
> >
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnectionInternal(ConnectionFactoryImpl.java:153),
> >
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:138),
> >
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:123),
> >
> > The interesting part here is the
> > org.apache.openejb.resource.AutoConnectionTracker.setEnvironment() call,
> > which is destroying connections where the proxy for the connection no
> > longer has any references. I.e. if you had some code that did this:
> >
> > ----
> > Connection conn = connectionFactory.createConnection(); // conn is
> > actually a proxy to the connection
> > // do work
> >
> > conn = null; // or conn is out of scope
> > ----
> >
> > note that conn.close() is not called. The reference count to the proxy is
> > now zero, so it counts as abandoned, and the next call to
> > createConnection() destroys the associated connection. However, if all
> this
> > happens in a transacted method, the JmqiXAResource is still enlisted with
> > the transaction. So when the transaction goes to commit, it fails,
> because
> > the JmqiXAResource is closed. The resource is still associated with a
> > ManagedConnectionInfo object through ManagedConnectionInfo.xares
> > (WrapperNamedXAResource). xaResource (XARWrapper - part of the
> RAR).theXAR
> > (JmqiXAResource - part of the RAR). The ManagedConnectionInfo object
> > somehow comes back to the pool after the rollback, and gets used again,
> > with the TransactionImpl.enlistResource() call failing as above.
> >
> > I suspect that we're seeing this under load as GC will be taking place
> > more often and calls to createConnection() will be happening more
> > frequently.
> >
> > The connection proxies themselves don't do much - only calls to
> finalize()
> > and clone() are caught. I propose this patch to allow the proxies to be
> > disabled (the current behaviour is still the default):
> > https://github.com/apache/tomee/pull/174 and welcome feedback.
> >
> > Running this specific case with proxies disabled has yielded positive
> > results. I'll try and extend this and reproduce it in a test case as
> well.
> > I'm wondering if AutoConnectionTracker's use of ReferenceQueue is thread
> > safe. Do anyone have any thoughts on this?
> >
> > Cheers
> >
> > Jon
> >
> >
> >
> >
> >
> >
> >
>
Re: Connector issues
Posted by Jonathan Gallimore <jo...@gmail.com>.
I apologize, I CC'd Geronimo in case there was anything relevant on the
Geronimo connector side. Happy to drop the CC if its not relevant.
Thanks for the quick response!
Off the top of my head, I wonder if we could keep a reference to the
connection proxy in the transaction (if there is one), and remove the
reference when the transaction is complete?
Jon
On Fri, Sep 28, 2018 at 2:57 PM Romain Manni-Bucau <rm...@gmail.com>
wrote:
> Hi Jon,
>
> I experienced that kind of "surprise" in recent jvm since gc is way more
> aggressive - cause lambda are way more memory consuming ;). This lead to
> this kind of issue where the GC happens before the object should actually
> be finalizable.
> I suspect we need to rework the AutoConnectionTracker to take into account
> these new behaviors and actually take into consideration the lifecycle of
> the underlying connection.
>
> Maybe I got it wrong but I see the ability to disable the proxying as a
> quickfix/workaround - which is ok - but it means we need to fix the source
> anyway as a long term solution. Am I understanding it right? If so we need
> to ensure to keep the reference until the connection is released at least
> and ensure it was not closed in the pool (kind of testOnXXX).
> Also wonder if there is anything related to geronimo since you cc-ed it.
> IIRC this logic is only in TomEE, no?
>
> side note: reference queue is supposed thread safe yes.
>
> Romain Manni-Bucau
> @rmannibucau <https://twitter.com/rmannibucau> | Blog
> <https://rmannibucau.metawerx.net/> | Old Blog
> <http://rmannibucau.wordpress.com> | Github <
> https://github.com/rmannibucau> |
> LinkedIn <https://www.linkedin.com/in/rmannibucau> | Book
> <
> https://www.packtpub.com/application-development/java-ee-8-high-performance
> >
>
>
> Le ven. 28 sept. 2018 à 15:49, Jonathan Gallimore <
> jonathan.gallimore@gmail.com> a écrit :
>
> > Hi Folks,
> >
> > I have been looking into some issues with TomEE using Websphere MQ,
> > specifically issues where XA resources are returning a -7 error during a
> > transaction commit when the system is under load. The -7 error indicates
> > that the resource is closed.
> >
> > The result of this error seems to be resources staying in the system
> > somehow associated with the connection, and subsequently, these can't be
> > enlisted in transactions (because they are closed).
> >
> > The stacktrace is like this, and happens over and over again as the
> server
> > attempts to process more messages from the queue.
> >
> > WARN Transaction- Unable to enlist XAResource
> > org.apache.geronimo.transaction.manager.WrapperNamedXAResource@3dd56e90,
> > errorCode: -7
> > javax.transaction.xa.XAException: The method 'xa_start' has failed with
> > errorCode '-7' due to the resource being closed.
> > at com.ibm.mq.jmqi.JmqiXAResource.start(JmqiXAResource.java:946)
> > ~[com.ibm.mq.jmqi.jar:7.5.0.5 - p750-005-150424]
> > at com.ibm.mq.connector.xa.XARWrapper.start(XARWrapper.java:581)
> > ~[com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> > at
> >
> org.apache.geronimo.transaction.manager.WrapperNamedXAResource.start(WrapperNamedXAResource.java:111)
> > ~[geronimo-transaction-3.1.4.jar:3.1.4]
> > at
> >
> org.apache.geronimo.transaction.manager.TransactionImpl.enlistResource(TransactionImpl.java:209)
> > [geronimo-transaction-3.1.4.jar:3.1.4]
> > at
> >
> org.apache.geronimo.connector.outbound.TransactionEnlistingInterceptor.getConnection(TransactionEnlistingInterceptor.java:60)
> > [geronimo-connector-3.1.4.jar:3.1.4]
> > at
> >
> org.apache.geronimo.connector.outbound.TransactionCachingInterceptor.getConnection(TransactionCachingInterceptor.java:101)
> > [geronimo-connector-3.1.4.jar:3.1.4]
> > at
> >
> org.apache.geronimo.connector.outbound.ConnectionHandleInterceptor.getConnection(ConnectionHandleInterceptor.java:43)
> > [geronimo-connector-3.1.4.jar:3.1.4]
> > at
> >
> org.apache.geronimo.connector.outbound.TCCLInterceptor.getConnection(TCCLInterceptor.java:39)
> > [geronimo-connector-3.1.4.jar:3.1.4]
> > at
> >
> org.apache.geronimo.connector.outbound.ConnectionTrackingInterceptor.getConnection(ConnectionTrackingInterceptor.java:66)
> > [geronimo-connector-3.1.4.jar:3.1.4]
> > at
> >
> org.apache.geronimo.connector.outbound.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:81)
> > [geronimo-connector-3.1.4.jar:3.1.4]
> > at
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createManagedJMSConnection(ConnectionFactoryImpl.java:194)
> > [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> > at
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnectionInternal(ConnectionFactoryImpl.java:153)
> > [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> > at
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:138)
> > [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> > at
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:123)
> > [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> >
> > The issue itself bears some resemblance to these posts:
> >
> >
> >
> http://tomee-openejb.979440.n4.nabble.com/Unable-to-enlist-XAResource-error-td4666552.html
> >
> >
> http://tomee-openejb.979440.n4.nabble.com/Does-tomEE-issue-double-rollbacks-td4666090.html
> >
> >
> http://tomee-openejb.979440.n4.nabble.com/errorcode-100-when-using-websphere-MQ-with-tomee-td4666519.html
> >
> > com.ibm.mq.jmqi.JmqiXAResource has a isClosed field, and this is set when
> > close_internal() is called. I tracked this call using AspectJ, and it
> > appeared to happen here:
> >
> > com.ibm.mq.jmqi.JmqiXAResource.close_internal(JmqiXAResource.java:296),
> > com.ibm.mq.jmqi.JmqiXAResource.close(JmqiXAResource.java:423),
> > com.ibm.mq.jmqi.JmqiXAResource.close(JmqiXAResource.java:410),
> >
> com.ibm.msg.client.wmq.internal.WMQXASession.close(WMQXASession.java:163),
> >
> >
> com.ibm.msg.client.jms.internal.JmsSessionImpl.close(JmsSessionImpl.java:375),
> >
> >
> com.ibm.msg.client.jms.internal.JmsSessionImpl.close(JmsSessionImpl.java:303),
> > com.ibm.mq.jms.MQSession.close(MQSession.java:298),
> >
> >
> com.ibm.mq.connector.outbound.ManagedConnectionImpl.destroy(ManagedConnectionImpl.java:298),
> >
> >
> org.apache.geronimo.connector.outbound.MCFConnectionInterceptor.returnConnection(MCFConnectionInterceptor.java:67),
> >
> >
> org.apache.geronimo.connector.outbound.XAResourceInsertionInterceptor.returnConnection(XAResourceInsertionInterceptor.java:47),
> >
> >
> org.apache.geronimo.connector.outbound.AbstractSinglePoolConnectionInterceptor.internalReturn(AbstractSinglePoolConnectionInterceptor.java:148),
> >
> >
> org.apache.geronimo.connector.outbound.AbstractSinglePoolConnectionInterceptor.returnConnection(AbstractSinglePoolConnectionInterceptor.java:129),
> >
> >
> org.apache.geronimo.connector.outbound.TransactionEnlistingInterceptor.returnConnection(TransactionEnlistingInterceptor.java:118),
> >
> >
> org.apache.geronimo.connector.outbound.TransactionCachingInterceptor.returnConnection(TransactionCachingInterceptor.java:119),
> >
> >
> org.apache.geronimo.connector.outbound.ConnectionHandleInterceptor.returnConnection(ConnectionHandleInterceptor.java:71),
> >
> >
> org.apache.geronimo.connector.outbound.TCCLInterceptor.returnConnection(TCCLInterceptor.java:50),
> >
> >
> org.apache.geronimo.connector.outbound.ConnectionTrackingInterceptor.returnConnection(ConnectionTrackingInterceptor.java:91),
> >
> >
> org.apache.openejb.resource.AutoConnectionTracker.setEnvironment(AutoConnectionTracker.java:62),
> >
> >
> org.apache.geronimo.connector.outbound.ConnectionTrackingInterceptor.getConnection(ConnectionTrackingInterceptor.java:65),
> >
> >
> org.apache.geronimo.connector.outbound.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:81),
> >
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createManagedJMSConnection(ConnectionFactoryImpl.java:194),
> >
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnectionInternal(ConnectionFactoryImpl.java:153),
> >
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:138),
> >
> >
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:123),
> >
> > The interesting part here is the
> > org.apache.openejb.resource.AutoConnectionTracker.setEnvironment() call,
> > which is destroying connections where the proxy for the connection no
> > longer has any references. I.e. if you had some code that did this:
> >
> > ----
> > Connection conn = connectionFactory.createConnection(); // conn is
> > actually a proxy to the connection
> > // do work
> >
> > conn = null; // or conn is out of scope
> > ----
> >
> > note that conn.close() is not called. The reference count to the proxy is
> > now zero, so it counts as abandoned, and the next call to
> > createConnection() destroys the associated connection. However, if all
> this
> > happens in a transacted method, the JmqiXAResource is still enlisted with
> > the transaction. So when the transaction goes to commit, it fails,
> because
> > the JmqiXAResource is closed. The resource is still associated with a
> > ManagedConnectionInfo object through ManagedConnectionInfo.xares
> > (WrapperNamedXAResource). xaResource (XARWrapper - part of the
> RAR).theXAR
> > (JmqiXAResource - part of the RAR). The ManagedConnectionInfo object
> > somehow comes back to the pool after the rollback, and gets used again,
> > with the TransactionImpl.enlistResource() call failing as above.
> >
> > I suspect that we're seeing this under load as GC will be taking place
> > more often and calls to createConnection() will be happening more
> > frequently.
> >
> > The connection proxies themselves don't do much - only calls to
> finalize()
> > and clone() are caught. I propose this patch to allow the proxies to be
> > disabled (the current behaviour is still the default):
> > https://github.com/apache/tomee/pull/174 and welcome feedback.
> >
> > Running this specific case with proxies disabled has yielded positive
> > results. I'll try and extend this and reproduce it in a test case as
> well.
> > I'm wondering if AutoConnectionTracker's use of ReferenceQueue is thread
> > safe. Do anyone have any thoughts on this?
> >
> > Cheers
> >
> > Jon
> >
> >
> >
> >
> >
> >
> >
>
Re: Connector issues
Posted by Romain Manni-Bucau <rm...@gmail.com>.
Hi Jon,
I experienced that kind of "surprise" in recent jvm since gc is way more
aggressive - cause lambda are way more memory consuming ;). This lead to
this kind of issue where the GC happens before the object should actually
be finalizable.
I suspect we need to rework the AutoConnectionTracker to take into account
these new behaviors and actually take into consideration the lifecycle of
the underlying connection.
Maybe I got it wrong but I see the ability to disable the proxying as a
quickfix/workaround - which is ok - but it means we need to fix the source
anyway as a long term solution. Am I understanding it right? If so we need
to ensure to keep the reference until the connection is released at least
and ensure it was not closed in the pool (kind of testOnXXX).
Also wonder if there is anything related to geronimo since you cc-ed it.
IIRC this logic is only in TomEE, no?
side note: reference queue is supposed thread safe yes.
Romain Manni-Bucau
@rmannibucau <https://twitter.com/rmannibucau> | Blog
<https://rmannibucau.metawerx.net/> | Old Blog
<http://rmannibucau.wordpress.com> | Github <https://github.com/rmannibucau> |
LinkedIn <https://www.linkedin.com/in/rmannibucau> | Book
<https://www.packtpub.com/application-development/java-ee-8-high-performance>
Le ven. 28 sept. 2018 à 15:49, Jonathan Gallimore <
jonathan.gallimore@gmail.com> a écrit :
> Hi Folks,
>
> I have been looking into some issues with TomEE using Websphere MQ,
> specifically issues where XA resources are returning a -7 error during a
> transaction commit when the system is under load. The -7 error indicates
> that the resource is closed.
>
> The result of this error seems to be resources staying in the system
> somehow associated with the connection, and subsequently, these can't be
> enlisted in transactions (because they are closed).
>
> The stacktrace is like this, and happens over and over again as the server
> attempts to process more messages from the queue.
>
> WARN Transaction- Unable to enlist XAResource
> org.apache.geronimo.transaction.manager.WrapperNamedXAResource@3dd56e90,
> errorCode: -7
> javax.transaction.xa.XAException: The method 'xa_start' has failed with
> errorCode '-7' due to the resource being closed.
> at com.ibm.mq.jmqi.JmqiXAResource.start(JmqiXAResource.java:946)
> ~[com.ibm.mq.jmqi.jar:7.5.0.5 - p750-005-150424]
> at com.ibm.mq.connector.xa.XARWrapper.start(XARWrapper.java:581)
> ~[com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> at
> org.apache.geronimo.transaction.manager.WrapperNamedXAResource.start(WrapperNamedXAResource.java:111)
> ~[geronimo-transaction-3.1.4.jar:3.1.4]
> at
> org.apache.geronimo.transaction.manager.TransactionImpl.enlistResource(TransactionImpl.java:209)
> [geronimo-transaction-3.1.4.jar:3.1.4]
> at
> org.apache.geronimo.connector.outbound.TransactionEnlistingInterceptor.getConnection(TransactionEnlistingInterceptor.java:60)
> [geronimo-connector-3.1.4.jar:3.1.4]
> at
> org.apache.geronimo.connector.outbound.TransactionCachingInterceptor.getConnection(TransactionCachingInterceptor.java:101)
> [geronimo-connector-3.1.4.jar:3.1.4]
> at
> org.apache.geronimo.connector.outbound.ConnectionHandleInterceptor.getConnection(ConnectionHandleInterceptor.java:43)
> [geronimo-connector-3.1.4.jar:3.1.4]
> at
> org.apache.geronimo.connector.outbound.TCCLInterceptor.getConnection(TCCLInterceptor.java:39)
> [geronimo-connector-3.1.4.jar:3.1.4]
> at
> org.apache.geronimo.connector.outbound.ConnectionTrackingInterceptor.getConnection(ConnectionTrackingInterceptor.java:66)
> [geronimo-connector-3.1.4.jar:3.1.4]
> at
> org.apache.geronimo.connector.outbound.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:81)
> [geronimo-connector-3.1.4.jar:3.1.4]
> at
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createManagedJMSConnection(ConnectionFactoryImpl.java:194)
> [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> at
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnectionInternal(ConnectionFactoryImpl.java:153)
> [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> at
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:138)
> [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> at
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:123)
> [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
>
> The issue itself bears some resemblance to these posts:
>
>
> http://tomee-openejb.979440.n4.nabble.com/Unable-to-enlist-XAResource-error-td4666552.html
>
> http://tomee-openejb.979440.n4.nabble.com/Does-tomEE-issue-double-rollbacks-td4666090.html
>
> http://tomee-openejb.979440.n4.nabble.com/errorcode-100-when-using-websphere-MQ-with-tomee-td4666519.html
>
> com.ibm.mq.jmqi.JmqiXAResource has a isClosed field, and this is set when
> close_internal() is called. I tracked this call using AspectJ, and it
> appeared to happen here:
>
> com.ibm.mq.jmqi.JmqiXAResource.close_internal(JmqiXAResource.java:296),
> com.ibm.mq.jmqi.JmqiXAResource.close(JmqiXAResource.java:423),
> com.ibm.mq.jmqi.JmqiXAResource.close(JmqiXAResource.java:410),
> com.ibm.msg.client.wmq.internal.WMQXASession.close(WMQXASession.java:163),
>
> com.ibm.msg.client.jms.internal.JmsSessionImpl.close(JmsSessionImpl.java:375),
>
> com.ibm.msg.client.jms.internal.JmsSessionImpl.close(JmsSessionImpl.java:303),
> com.ibm.mq.jms.MQSession.close(MQSession.java:298),
>
> com.ibm.mq.connector.outbound.ManagedConnectionImpl.destroy(ManagedConnectionImpl.java:298),
>
> org.apache.geronimo.connector.outbound.MCFConnectionInterceptor.returnConnection(MCFConnectionInterceptor.java:67),
>
> org.apache.geronimo.connector.outbound.XAResourceInsertionInterceptor.returnConnection(XAResourceInsertionInterceptor.java:47),
>
> org.apache.geronimo.connector.outbound.AbstractSinglePoolConnectionInterceptor.internalReturn(AbstractSinglePoolConnectionInterceptor.java:148),
>
> org.apache.geronimo.connector.outbound.AbstractSinglePoolConnectionInterceptor.returnConnection(AbstractSinglePoolConnectionInterceptor.java:129),
>
> org.apache.geronimo.connector.outbound.TransactionEnlistingInterceptor.returnConnection(TransactionEnlistingInterceptor.java:118),
>
> org.apache.geronimo.connector.outbound.TransactionCachingInterceptor.returnConnection(TransactionCachingInterceptor.java:119),
>
> org.apache.geronimo.connector.outbound.ConnectionHandleInterceptor.returnConnection(ConnectionHandleInterceptor.java:71),
>
> org.apache.geronimo.connector.outbound.TCCLInterceptor.returnConnection(TCCLInterceptor.java:50),
>
> org.apache.geronimo.connector.outbound.ConnectionTrackingInterceptor.returnConnection(ConnectionTrackingInterceptor.java:91),
>
> org.apache.openejb.resource.AutoConnectionTracker.setEnvironment(AutoConnectionTracker.java:62),
>
> org.apache.geronimo.connector.outbound.ConnectionTrackingInterceptor.getConnection(ConnectionTrackingInterceptor.java:65),
>
> org.apache.geronimo.connector.outbound.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:81),
>
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createManagedJMSConnection(ConnectionFactoryImpl.java:194),
>
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnectionInternal(ConnectionFactoryImpl.java:153),
>
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:138),
>
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:123),
>
> The interesting part here is the
> org.apache.openejb.resource.AutoConnectionTracker.setEnvironment() call,
> which is destroying connections where the proxy for the connection no
> longer has any references. I.e. if you had some code that did this:
>
> ----
> Connection conn = connectionFactory.createConnection(); // conn is
> actually a proxy to the connection
> // do work
>
> conn = null; // or conn is out of scope
> ----
>
> note that conn.close() is not called. The reference count to the proxy is
> now zero, so it counts as abandoned, and the next call to
> createConnection() destroys the associated connection. However, if all this
> happens in a transacted method, the JmqiXAResource is still enlisted with
> the transaction. So when the transaction goes to commit, it fails, because
> the JmqiXAResource is closed. The resource is still associated with a
> ManagedConnectionInfo object through ManagedConnectionInfo.xares
> (WrapperNamedXAResource). xaResource (XARWrapper - part of the RAR).theXAR
> (JmqiXAResource - part of the RAR). The ManagedConnectionInfo object
> somehow comes back to the pool after the rollback, and gets used again,
> with the TransactionImpl.enlistResource() call failing as above.
>
> I suspect that we're seeing this under load as GC will be taking place
> more often and calls to createConnection() will be happening more
> frequently.
>
> The connection proxies themselves don't do much - only calls to finalize()
> and clone() are caught. I propose this patch to allow the proxies to be
> disabled (the current behaviour is still the default):
> https://github.com/apache/tomee/pull/174 and welcome feedback.
>
> Running this specific case with proxies disabled has yielded positive
> results. I'll try and extend this and reproduce it in a test case as well.
> I'm wondering if AutoConnectionTracker's use of ReferenceQueue is thread
> safe. Do anyone have any thoughts on this?
>
> Cheers
>
> Jon
>
>
>
>
>
>
>
Re: Connector issues
Posted by Romain Manni-Bucau <rm...@gmail.com>.
Hi Jon,
I experienced that kind of "surprise" in recent jvm since gc is way more
aggressive - cause lambda are way more memory consuming ;). This lead to
this kind of issue where the GC happens before the object should actually
be finalizable.
I suspect we need to rework the AutoConnectionTracker to take into account
these new behaviors and actually take into consideration the lifecycle of
the underlying connection.
Maybe I got it wrong but I see the ability to disable the proxying as a
quickfix/workaround - which is ok - but it means we need to fix the source
anyway as a long term solution. Am I understanding it right? If so we need
to ensure to keep the reference until the connection is released at least
and ensure it was not closed in the pool (kind of testOnXXX).
Also wonder if there is anything related to geronimo since you cc-ed it.
IIRC this logic is only in TomEE, no?
side note: reference queue is supposed thread safe yes.
Romain Manni-Bucau
@rmannibucau <https://twitter.com/rmannibucau> | Blog
<https://rmannibucau.metawerx.net/> | Old Blog
<http://rmannibucau.wordpress.com> | Github <https://github.com/rmannibucau> |
LinkedIn <https://www.linkedin.com/in/rmannibucau> | Book
<https://www.packtpub.com/application-development/java-ee-8-high-performance>
Le ven. 28 sept. 2018 à 15:49, Jonathan Gallimore <
jonathan.gallimore@gmail.com> a écrit :
> Hi Folks,
>
> I have been looking into some issues with TomEE using Websphere MQ,
> specifically issues where XA resources are returning a -7 error during a
> transaction commit when the system is under load. The -7 error indicates
> that the resource is closed.
>
> The result of this error seems to be resources staying in the system
> somehow associated with the connection, and subsequently, these can't be
> enlisted in transactions (because they are closed).
>
> The stacktrace is like this, and happens over and over again as the server
> attempts to process more messages from the queue.
>
> WARN Transaction- Unable to enlist XAResource
> org.apache.geronimo.transaction.manager.WrapperNamedXAResource@3dd56e90,
> errorCode: -7
> javax.transaction.xa.XAException: The method 'xa_start' has failed with
> errorCode '-7' due to the resource being closed.
> at com.ibm.mq.jmqi.JmqiXAResource.start(JmqiXAResource.java:946)
> ~[com.ibm.mq.jmqi.jar:7.5.0.5 - p750-005-150424]
> at com.ibm.mq.connector.xa.XARWrapper.start(XARWrapper.java:581)
> ~[com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> at
> org.apache.geronimo.transaction.manager.WrapperNamedXAResource.start(WrapperNamedXAResource.java:111)
> ~[geronimo-transaction-3.1.4.jar:3.1.4]
> at
> org.apache.geronimo.transaction.manager.TransactionImpl.enlistResource(TransactionImpl.java:209)
> [geronimo-transaction-3.1.4.jar:3.1.4]
> at
> org.apache.geronimo.connector.outbound.TransactionEnlistingInterceptor.getConnection(TransactionEnlistingInterceptor.java:60)
> [geronimo-connector-3.1.4.jar:3.1.4]
> at
> org.apache.geronimo.connector.outbound.TransactionCachingInterceptor.getConnection(TransactionCachingInterceptor.java:101)
> [geronimo-connector-3.1.4.jar:3.1.4]
> at
> org.apache.geronimo.connector.outbound.ConnectionHandleInterceptor.getConnection(ConnectionHandleInterceptor.java:43)
> [geronimo-connector-3.1.4.jar:3.1.4]
> at
> org.apache.geronimo.connector.outbound.TCCLInterceptor.getConnection(TCCLInterceptor.java:39)
> [geronimo-connector-3.1.4.jar:3.1.4]
> at
> org.apache.geronimo.connector.outbound.ConnectionTrackingInterceptor.getConnection(ConnectionTrackingInterceptor.java:66)
> [geronimo-connector-3.1.4.jar:3.1.4]
> at
> org.apache.geronimo.connector.outbound.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:81)
> [geronimo-connector-3.1.4.jar:3.1.4]
> at
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createManagedJMSConnection(ConnectionFactoryImpl.java:194)
> [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> at
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnectionInternal(ConnectionFactoryImpl.java:153)
> [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> at
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:138)
> [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
> at
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:123)
> [com.ibm.mq.connector.jar:7.5.0.5-p750-005-150424]
>
> The issue itself bears some resemblance to these posts:
>
>
> http://tomee-openejb.979440.n4.nabble.com/Unable-to-enlist-XAResource-error-td4666552.html
>
> http://tomee-openejb.979440.n4.nabble.com/Does-tomEE-issue-double-rollbacks-td4666090.html
>
> http://tomee-openejb.979440.n4.nabble.com/errorcode-100-when-using-websphere-MQ-with-tomee-td4666519.html
>
> com.ibm.mq.jmqi.JmqiXAResource has a isClosed field, and this is set when
> close_internal() is called. I tracked this call using AspectJ, and it
> appeared to happen here:
>
> com.ibm.mq.jmqi.JmqiXAResource.close_internal(JmqiXAResource.java:296),
> com.ibm.mq.jmqi.JmqiXAResource.close(JmqiXAResource.java:423),
> com.ibm.mq.jmqi.JmqiXAResource.close(JmqiXAResource.java:410),
> com.ibm.msg.client.wmq.internal.WMQXASession.close(WMQXASession.java:163),
>
> com.ibm.msg.client.jms.internal.JmsSessionImpl.close(JmsSessionImpl.java:375),
>
> com.ibm.msg.client.jms.internal.JmsSessionImpl.close(JmsSessionImpl.java:303),
> com.ibm.mq.jms.MQSession.close(MQSession.java:298),
>
> com.ibm.mq.connector.outbound.ManagedConnectionImpl.destroy(ManagedConnectionImpl.java:298),
>
> org.apache.geronimo.connector.outbound.MCFConnectionInterceptor.returnConnection(MCFConnectionInterceptor.java:67),
>
> org.apache.geronimo.connector.outbound.XAResourceInsertionInterceptor.returnConnection(XAResourceInsertionInterceptor.java:47),
>
> org.apache.geronimo.connector.outbound.AbstractSinglePoolConnectionInterceptor.internalReturn(AbstractSinglePoolConnectionInterceptor.java:148),
>
> org.apache.geronimo.connector.outbound.AbstractSinglePoolConnectionInterceptor.returnConnection(AbstractSinglePoolConnectionInterceptor.java:129),
>
> org.apache.geronimo.connector.outbound.TransactionEnlistingInterceptor.returnConnection(TransactionEnlistingInterceptor.java:118),
>
> org.apache.geronimo.connector.outbound.TransactionCachingInterceptor.returnConnection(TransactionCachingInterceptor.java:119),
>
> org.apache.geronimo.connector.outbound.ConnectionHandleInterceptor.returnConnection(ConnectionHandleInterceptor.java:71),
>
> org.apache.geronimo.connector.outbound.TCCLInterceptor.returnConnection(TCCLInterceptor.java:50),
>
> org.apache.geronimo.connector.outbound.ConnectionTrackingInterceptor.returnConnection(ConnectionTrackingInterceptor.java:91),
>
> org.apache.openejb.resource.AutoConnectionTracker.setEnvironment(AutoConnectionTracker.java:62),
>
> org.apache.geronimo.connector.outbound.ConnectionTrackingInterceptor.getConnection(ConnectionTrackingInterceptor.java:65),
>
> org.apache.geronimo.connector.outbound.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:81),
>
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createManagedJMSConnection(ConnectionFactoryImpl.java:194),
>
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnectionInternal(ConnectionFactoryImpl.java:153),
>
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:138),
>
> com.ibm.mq.connector.outbound.ConnectionFactoryImpl.createConnection(ConnectionFactoryImpl.java:123),
>
> The interesting part here is the
> org.apache.openejb.resource.AutoConnectionTracker.setEnvironment() call,
> which is destroying connections where the proxy for the connection no
> longer has any references. I.e. if you had some code that did this:
>
> ----
> Connection conn = connectionFactory.createConnection(); // conn is
> actually a proxy to the connection
> // do work
>
> conn = null; // or conn is out of scope
> ----
>
> note that conn.close() is not called. The reference count to the proxy is
> now zero, so it counts as abandoned, and the next call to
> createConnection() destroys the associated connection. However, if all this
> happens in a transacted method, the JmqiXAResource is still enlisted with
> the transaction. So when the transaction goes to commit, it fails, because
> the JmqiXAResource is closed. The resource is still associated with a
> ManagedConnectionInfo object through ManagedConnectionInfo.xares
> (WrapperNamedXAResource). xaResource (XARWrapper - part of the RAR).theXAR
> (JmqiXAResource - part of the RAR). The ManagedConnectionInfo object
> somehow comes back to the pool after the rollback, and gets used again,
> with the TransactionImpl.enlistResource() call failing as above.
>
> I suspect that we're seeing this under load as GC will be taking place
> more often and calls to createConnection() will be happening more
> frequently.
>
> The connection proxies themselves don't do much - only calls to finalize()
> and clone() are caught. I propose this patch to allow the proxies to be
> disabled (the current behaviour is still the default):
> https://github.com/apache/tomee/pull/174 and welcome feedback.
>
> Running this specific case with proxies disabled has yielded positive
> results. I'll try and extend this and reproduce it in a test case as well.
> I'm wondering if AutoConnectionTracker's use of ReferenceQueue is thread
> safe. Do anyone have any thoughts on this?
>
> Cheers
>
> Jon
>
>
>
>
>
>
>