Great note Jon. Thanks it's appreciated +1
Le jeu. 4 oct. 2018 à 12:01, Romain Manni-Bucau <rmannibu...@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.gallim...@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.gallim...@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 < > > rmannibu...@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.gallim...@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 < > > >> rmannibu...@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.gallim...@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 > > >> > > > > > >> > > > > > >> > > > > > >> > > > > > >> > > > > > >> > > > > > >> > > > > > >> > > > > >> > > > >> > > > > > >
