this is because eclipselink JTA integration calls setRollbackOnly() which
is welld handled by our transaction manager but as requested it is done
silently. You can
check 
org.eclipse.persistence.transaction.JTATransactionController#markTransactionForRollback_impl


Romain Manni-Bucau
@rmannibucau <https://twitter.com/rmannibucau> |  Blog
<https://blog-rmannibucau.rhcloud.com> | Old Blog
<http://rmannibucau.wordpress.com> | Github <https://github.com/rmannibucau> |
LinkedIn <https://www.linkedin.com/in/rmannibucau> | JavaEE Factory
<https://javaeefactory-rmannibucau.rhcloud.com>

2017-05-02 19:37 GMT+02:00 Paul Carter-Brown <
paul.carter-br...@smilecoms.com>:

> I cause and then catch the exception to show the connections is down. That
> same connection is then needed by the container to do the commit and yet it
> does not fail.
>
> Paul
>
> Sent from my phone. Message may be brief and contain typos.
>
>
> On 2 May 2017 6:10 p.m., "Romain Manni-Bucau" <rmannibu...@gmail.com>
> wrote:
>
> > issue with this example is you catch the exception so the jta transaction
> > is not rolledback, modified it to throw a runtime exception and make the
> tx
> > failing and it works it seems
> >
> >
> > Romain Manni-Bucau
> > @rmannibucau <https://twitter.com/rmannibucau> |  Blog
> > <https://blog-rmannibucau.rhcloud.com> | Old Blog
> > <http://rmannibucau.wordpress.com> | Github <https://github.com/
> > rmannibucau> |
> > LinkedIn <https://www.linkedin.com/in/rmannibucau> | JavaEE Factory
> > <https://javaeefactory-rmannibucau.rhcloud.com>
> >
> > 2017-05-02 12:34 GMT+02:00 Paul Carter-Brown <
> > paul.carter-br...@smilecoms.com>:
> >
> > > Hi Romain,
> > >
> > > I set the MySQL connection timeout to 2 seconds and did a sleep for 3
> > > seconds at the end of the business method.
> > >
> > > The result was that the business method still returned the primary key
> of
> > > the new row successfully yet after that there was an exception
> committing
> > > the TX and the row was not actually written to the DB.
> > >
> > > 2017/05/02 12:19:53.354 WARNING [TomEE-Exec-33][307][org.
> > apache.cxf.phase.
> > > PhaseInterceptorChain.doDefaultLogging] |Application {
> > > http://xml.smilecoms.com/IM}IM#{http://xml.smilecoms.com/
> IM}AddCustomer
> > > has thrown exception, unwinding now
> > > org.apache.cxf.interceptor.Fault: javax.transaction.SystemException:
> > > Error during two phase commit: Error during two phase commit while
> > invoking
> > > public abstract com.smilecoms.xml.schema.im.PlatformInteger
> > > com.smilecoms.xml.im.IMSoap.addCustomer(com.smilecoms.xml.
> > schema.im.Customer)
> > > throws com.smilecoms.xml.im.IMError with params [
> > > com.smilecoms.xml.schema.im.Customer@5950a117].
> > >         at org.apache.cxf.service.invoker.AbstractInvoker.
> > > createFault(AbstractInvoker.java:166)
> > >         at org.apache.cxf.jaxws.AbstractJAXWSMethodInvoker.
> createFault(
> > > AbstractJAXWSMethodInvoker.java:267)
> > >         at org.apache.openejb.server.cxf.ejb.EjbMethodInvoker.
> > > preEjbInvoke(EjbMethodInvoker.java:165)
> > >         at org.apache.openejb.server.cxf.ejb.EjbMethodInvoker.invoke(
> > > EjbMethodInvoker.java:82)
> > >         at org.apache.cxf.service.invoker.AbstractInvoker.
> > > invoke(AbstractInvoker.java:74)
> > >         at org.apache.cxf.interceptor.ServiceInvokerInterceptor$1.
> > > run(ServiceInvokerInterceptor.java:59)
> > >         at java.util.concurrent.Executors$RunnableAdapter.
> > > call(Executors.java:511)
> > >         at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> > >         at org.apache.cxf.interceptor.ServiceInvokerInterceptor$2.
> > > run(ServiceInvokerInterceptor.java:126)
> > >         at org.apache.cxf.workqueue.SynchronousExecutor.execute(
> > > SynchronousExecutor.java:37)
> > >         at org.apache.cxf.interceptor.ServiceInvokerInterceptor.
> > > handleMessage(ServiceInvokerInterceptor.java:131)
> > >         at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(
> > > PhaseInterceptorChain.java:308)
> > >         at org.apache.cxf.transport.ChainInitiationObserver.onMessage(
> > > ChainInitiationObserver.java:121)
> > >         at org.apache.cxf.transport.http.AbstractHTTPDestination.
> invoke(
> > > AbstractHTTPDestination.java:262)
> > >         at org.apache.openejb.server.cxf.CxfWsContainer.onMessage(
> > > CxfWsContainer.java:85)
> > >         at org.apache.openejb.server.webservices.WsServlet.service(
> > > WsServlet.java:98)
> > >         at org.apache.catalina.core.ApplicationFilterChain.
> > > internalDoFilter(ApplicationFilterChain.java:230)
> > >         at org.apache.catalina.core.ApplicationFilterChain.doFilter(
> > > ApplicationFilterChain.java:165)
> > >         at org.apache.catalina.core.StandardWrapperValve.invoke(
> > > StandardWrapperValve.java:198)
> > >         at org.apache.catalina.core.StandardContextValve.invoke(
> > > StandardContextValve.java:96)
> > >         at org.apache.catalina.core.StandardHostValve.invoke(
> > > StandardHostValve.java:140)
> > >         at org.apache.catalina.valves.ErrorReportValve.invoke(
> > > ErrorReportValve.java:79)
> > >         at org.apache.tomee.catalina.OpenEJBSecurityListener$
> > > RequestCapturer.invoke(OpenEJBSecurityListener.java:97)
> > >         at org.apache.catalina.core.StandardEngineValve.invoke(
> > > StandardEngineValve.java:87)
> > >         at org.apache.catalina.connector.CoyoteAdapter.service(
> > > CoyoteAdapter.java:349)
> > >         at org.apache.coyote.http11.Http11Processor.service(
> > > Http11Processor.java:783)
> > >         at org.apache.coyote.AbstractProcessorLight.process(
> > > AbstractProcessorLight.java:66)
> > >         at org.apache.coyote.AbstractProtocol$
> ConnectionHandler.process(
> > > AbstractProtocol.java:798)
> > >         at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.
> > > doRun(NioEndpoint.java:1434)
> > >         at org.apache.tomcat.util.net.SocketProcessorBase.run(
> > > SocketProcessorBase.java:49)
> > >         at java.util.concurrent.ThreadPoolExecutor.runWorker(
> > > ThreadPoolExecutor.java:1142)
> > >         at java.util.concurrent.ThreadPoolExecutor$Worker.run(
> > > ThreadPoolExecutor.java:617)
> > >         at org.apache.tomcat.util.threads.TaskThread$
> > WrappingRunnable.run(
> > > TaskThread.java:61)
> > >         at java.lang.Thread.run(Thread.java:745)
> > > Caused by: org.apache.openejb.SystemException: javax.transaction.
> > SystemException:
> > > Error during two phase commit: Error during two phase commit
> > >         at org.apache.openejb.core.transaction.JtaTransactionPolicy.
> > > completeTransaction(JtaTransactionPolicy.java:364)
> > >         at org.apache.openejb.core.transaction.TxRequired.commit(
> > > TxRequired.java:76)
> > >         at org.apache.openejb.core.transaction.EjbTransactionUtil.
> > > afterInvoke(EjbTransactionUtil.java:77)
> > >         at org.apache.openejb.core.stateless.StatelessContainer._
> > > invoke(StatelessContainer.java:271)
> > >         at org.apache.openejb.core.stateless.StatelessContainer.
> > > invoke(StatelessContainer.java:212)
> > >         at org.apache.openejb.server.cxf.ejb.EjbMethodInvoker.
> > > preEjbInvoke(EjbMethodInvoker.java:125)
> > >         ... 31 more
> > > Caused by: javax.transaction.SystemException: Error during two phase
> > > commit
> > >         at org.apache.geronimo.transaction.manager.TransactionImpl.
> > > commitResource(TransactionImpl.java:683)
> > >         at org.apache.geronimo.transaction.manager.
> > TransactionImpl.commit(
> > > TransactionImpl.java:305)
> > >         at org.apache.geronimo.transaction.manager.
> > > TransactionManagerImpl.commit(TransactionManagerImpl.java:252)
> > >         at org.apache.openejb.core.transaction.JtaTransactionPolicy.
> > > completeTransaction(JtaTransactionPolicy.java:331)
> > >         ... 36 more
> > > Caused by: javax.transaction.xa.XAException
> > >         at org.apache.openejb.resource.jdbc.managed.local.
> > > LocalXAResource.commit(LocalXAResource.java:134)
> > >         at org.apache.geronimo.transaction.manager.TransactionImpl.
> > > commitResource(TransactionImpl.java:627)
> > >         ... 39 more
> > > Caused by: java.sql.SQLException: Could not retrieve transation
> read-only
> > > status server
> > >         at com.mysql.jdbc.SQLError.createSQLException(SQLError.
> java:957)
> > >         at com.mysql.jdbc.SQLError.createSQLException(SQLError.
> java:896)
> > >         at com.mysql.jdbc.SQLError.createSQLException(SQLError.
> java:885)
> > >         at com.mysql.jdbc.SQLError.createSQLException(SQLError.
> java:860)
> > >         at com.mysql.jdbc.SQLError.createSQLException(SQLError.
> java:877)
> > >         at com.mysql.jdbc.SQLError.createSQLException(SQLError.
> java:873)
> > >         at com.mysql.jdbc.ConnectionImpl.isReadOnly(ConnectionImpl.
> > > java:3629)
> > >         at com.mysql.jdbc.ConnectionImpl.isReadOnly(ConnectionImpl.
> > > java:3598)
> > >         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> > >         at sun.reflect.NativeMethodAccessorImpl.invoke(
> > > NativeMethodAccessorImpl.java:62)
> > >         at sun.reflect.DelegatingMethodAccessorImpl.invoke(
> > > DelegatingMethodAccessorImpl.java:43)
> > >         at java.lang.reflect.Method.invoke(Method.java:498)
> > >         at org.apache.tomcat.jdbc.pool.ProxyConnection.invoke(
> > > ProxyConnection.java:126)
> > >         at org.apache.tomcat.jdbc.pool.JdbcInterceptor.invoke(
> > > JdbcInterceptor.java:108)
> > >         at org.apache.tomcat.jdbc.pool.DisposableConnectionFacade.
> > invoke(
> > > DisposableConnectionFacade.java:81)
> > >         at com.sun.proxy.$Proxy61.isReadOnly(Unknown Source)
> > >         at org.apache.openejb.resource.jdbc.managed.local.
> > > LocalXAResource.commit(LocalXAResource.java:130)
> > >         ... 40 more
> > > Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException:
> > > Communications link failure
> > >
> > >
> > > Attached is a basic test project with an EJB. I based it on an existing
> > > TomEE example on github. The example shows that the EJB returns
> > > successfully even though the commit should have failed.
> > >
> > >
> > >
> > >
> > > On 2 May 2017 at 07:59, Romain Manni-Bucau <rmannibu...@gmail.com>
> > wrote:
> > >
> > >> Interesting since it tends to comfort the timeout issue.
> > >>
> > >> Can you try putting some aggressive db timeout? Or transaction manager
> > >> timeout - default is 10mn, way too high for http.
> > >>
> > >> If still an issue I d apprecoate a small github project with a
> failling
> > >> arquillian test with your idea if possible.
> > >>
> > >> Le 1 mai 2017 23:53, "Paul Carter-Brown" <paul.carter-brown@smilecoms.
> > com
> > >> >
> > >> a écrit :
> > >>
> > >> > Hi Romain,
> > >> >
> > >> > I'm struggling to think of a way to test this as it would involve
> > >> modifying
> > >> > code in TomEE core as part of the test. I found an easy-enough way
> is
> > to
> > >> > have a JAW-WS service with CMP that does some DB changes. Then at
> the
> > >> end
> > >> > of the business method just before returning, sleep for say 20s.
> When
> > >> you
> > >> > call the service, during those 20s, shut down the database. You
> should
> > >> see
> > >> > that although the commit fails due to the DB having gone away, the
> > SOAP
> > >> > service will respond successfully.
> > >> >
> > >> > On 1 May 2017 at 21:29, Romain Manni-Bucau <rmannibu...@gmail.com>
> > >> wrote:
> > >> >
> > >> > > then it should happen also with hsqldb and you can probably share
> a
> > >> small
> > >> > > sample on github. Main challenge is to write a small failling
> test.
> > >> Will
> > >> > > try to have a look in the week.
> > >> > >
> > >> > > PS: thought to a case it can happen and is not abnormal: a
> timeout.
> > If
> > >> > you
> > >> > > timeout the EJB method is not cancelled so you get the response
> > before
> > >> > the
> > >> > > commit but this is "normal".
> > >> > >
> > >> > >
> > >> > > Romain Manni-Bucau
> > >> > > @rmannibucau <https://twitter.com/rmannibucau> |  Blog
> > >> > > <https://blog-rmannibucau.rhcloud.com> | Old Blog
> > >> > > <http://rmannibucau.wordpress.com> | Github <https://github.com/
> > >> > > rmannibucau> |
> > >> > > LinkedIn <https://www.linkedin.com/in/rmannibucau> | JavaEE
> Factory
> > >> > > <https://javaeefactory-rmannibucau.rhcloud.com>
> > >> > >
> > >> > > 2017-05-01 21:18 GMT+02:00 Paul Carter-Brown <
> > >> > > paul.carter-br...@smilecoms.com>:
> > >> > >
> > >> > > > Hi Romain,
> > >> > > >
> > >> > > > I modifed that class as follows:
> > >> > > >
> > >> > > > public void commit() throws ApplicationException,
> SystemException
> > {
> > >> > > >         // only commit if we started the transaction
> > >> > > >         log.warn("In commit - sleeping for 3000ms");
> > >> > > >         try {
> > >> > > >             Thread.sleep(3000);
> > >> > > >         } catch (Exception e) {
> > >> > > >             log.warn("Error in sleep");
> > >> > > >         }
> > >> > > >         log.warn("Woke up from sleep");
> > >> > > >         if (clientTx == null) {
> > >> > > >             log.warn("In commit - clientTx is null");
> > >> > > >             completeTransaction(currentTx);
> > >> > > >         } else {
> > >> > > >             log.warn("In commit - clientTx is not null");
> > >> > > >             fireNonTransactionalCompletion();
> > >> > > >         }
> > >> > > >     }
> > >> > > >
> > >> > > > Here is the timing of the wireshark request/response:
> > >> > > > 462 20:35:11.046374    10.0.1.57 -> 10.0.1.57    HTTP/XML 2124
> > POST
> > >> > > > /IM/IdentityManager HTTP/1.1
> > >> > > > 464 20:35:11.082010    10.0.1.57 -> 10.0.1.57    HTTP/XML 384
> > >> HTTP/1.1
> > >> > > 200
> > >> > > >
> > >> > > > My JMeter client reported a response time of 52ms on the SOAP
> > call.
> > >> > > >
> > >> > > > And the TomEE logs:
> > >> > > >
> > >> > > > 2017/05/01 20:35:11.046 FINE
> > >> > > >  [TomEE-Exec-12][206][org.apache.cxf.phase.PhaseInterceptorCh
> > >> ain.add]
> > >> > > > |Adding interceptor
> > >> > > > org.apache.cxf.transport.https.CertConstraintsInterceptor@
> > 3a37dedb
> > >> to
> > >> > > > phase
> > >> > > > pre-stream
> > >> > > > 2017/05/01 20:35:11.047 FINE
> > >> > > >  [TomEE-Exec-12][206][org.apache.cxf.phase.
> PhaseInterceptorChain.
> > >> > > > outputChainToLog]
> > >> > > > |Chain org.apache.cxf.phase.PhaseInterceptorChain@16d0091a was
> > >> > created.
> > >> > > > Current flow:
> > >> > > >   receive [PolicyInInterceptor, SaajInFaultInterceptor,
> > >> > > > AttachmentInInterceptor]
> > >> > > >   pre-stream [CertConstraintsInterceptor]
> > >> > > >   post-stream [StaxInInterceptor]
> > >> > > >   read [SAAJPreInInterceptor, WSDLGetInterceptor,
> > >> > ReadHeadersInterceptor,
> > >> > > > SoapActionInInterceptor, StartBodyInterceptor]
> > >> > > >   pre-protocol [SAAJInInterceptor]
> > >> > > >   post-protocol [CheckFaultInterceptor,
> > >> JAXBAttachmentSchemaValidation
> > >> > > > Hack]
> > >> > > >   unmarshal [DocLiteralInInterceptor, SoapHeaderInterceptor]
> > >> > > >   pre-logical [OneWayProcessorInterceptor]
> > >> > > >   post-logical [WrapperClassInInterceptor]
> > >> > > >   pre-invoke [SwAInInterceptor, HolderInInterceptor]
> > >> > > >   invoke [ServiceInvokerInterceptor]
> > >> > > >   post-invoke [SaajInInterceptor, OutgoingChainInterceptor]
> > >> > > >
> > >> > > > ...... (further logs of incoming processing)
> > >> > > >
> > >> > > > 2017/05/01 20:35:11.081 FINE
> > >> > > >  [TomEE-Exec-12][206][org.apache.cxf.phase.
> PhaseInterceptorChain.
> > >> > > > doIntercept]
> > >> > > > |Invoking handleMessage on interceptor
> > >> > > > org.apache.cxf.binding.soap.interceptor.SoapOutInterceptor$
> > >> > > > SoapOutEndingInterceptor@1f0dd756
> > >> > > > 2017/05/01 20:35:11.081 FINE
> > >> > > >  [TomEE-Exec-12][206][org.apache.cxf.phase.
> PhaseInterceptorChain.
> > >> > > > doIntercept]
> > >> > > > |Invoking handleMessage on interceptor
> > >> > > > org.apache.cxf.binding.soap.saaj.SAAJOutInterceptor$
> > >> > > > SAAJOutEndingInterceptor@720f2664
> > >> > > > 2017/05/01 20:35:11.081 FINE
> > >> > > >  [TomEE-Exec-12][206][org.apache.cxf.phase.
> PhaseInterceptorChain.
> > >> > > > doIntercept]
> > >> > > > |Invoking handleMessage on interceptor
> > >> > > > org.apache.cxf.interceptor.StaxOutEndingInterceptor@3b5f0e7e
> > >> > > > 2017/05/01 20:35:11.081 FINE
> > >> > > >  [TomEE-Exec-12][206][org.apache.cxf.phase.
> PhaseInterceptorChain.
> > >> > > > doIntercept]
> > >> > > > |Invoking handleMessage on interceptor
> > >> > > > org.apache.cxf.interceptor.MessageSenderInterceptor$
> > >> > > > MessageSenderEndingInterceptor@6ae1d81a
> > >> > > >
> > >> > > > *2017/05/01 20:35:11.082 WARNING
> > >> > > > [TomEE-Exec-12][206][org.apache.openejb.core.
> > >> > > > transaction.TxRequired.commit]
> > >> > > > |In commit - sleeping for 3000ms*
> > >> > > > *2017/05/01 20:35:14.082 WARNING
> > >> > > > [TomEE-Exec-12][206][org.apache.openejb.core.
> > >> > > > transaction.TxRequired.commit]
> > >> > > > |Woke up from sleep*
> > >> > > > 2017/05/01 20:35:14.082 WARNING
> > >> > > > [TomEE-Exec-12][206][org.apache.openejb.core.
> > >> > > > transaction.TxRequired.commit]
> > >> > > > |In commit - clientTx is null
> > >> > > > 2017/05/01 20:35:14.083 FINE
> > >> > > >  [TomEE-Exec-12][206][com.smilecoms.commons.base.lifecycle.
> > >> > > > SmileConnectionLifecycleInterceptor.transactionBegun]
> > >> > > > |TransactionBegun called on [com.mysql.jdbc.JDBC4Connectio
> > >> n@7d0cc890]
> > >> > > > 2017/05/01 20:35:14.083 FINE
> > >> > > >  [TomEE-Exec-12][206][com.smilecoms.commons.base.lifecycle.
> > >> > > > SmileConnectionLifecycleInterceptor.commit]
> > >> > > > |Commit called on [com.mysql.jdbc.JDBC4Connection@7d0cc890]
> > >> > > > 2017/05/01 20:35:14.083 FINE
> > >> > > >  [TomEE-Exec-12][206][com.smilecoms.commons.base.lifecycle.
> > >> > > > SmileConnectionLifecycleInterceptor.commit]
> > >> > > > |Stack:
> > >> > > > java.lang.Exception
> > >> > > >         at
> > >> > > > com.smilecoms.commons.base.lifecycle.
> > SmileConnectionLifecycleInterc
> > >> > > > eptor.commit(SmileConnectionLifecycleInterceptor.java:34)
> > >> > > >         at com.mysql.jdbc.ConnectionImpl$
> > >> > 2.forEach(ConnectionImpl.java:
> > >> > > > 1593)
> > >> > > >         at com.mysql.jdbc.ConnectionImpl$
> > >> > 2.forEach(ConnectionImpl.java:
> > >> > > > 1592)
> > >> > > >         at com.mysql.jdbc.IterateBlock.do
> > >> ForAll(IterateBlock.java:61)
> > >> > > >         at com.mysql.jdbc.ConnectionImpl.
> > >> commit(ConnectionImpl.java:
> > >> > > 1599)
> > >> > > >         at sun.reflect.GeneratedMethodAccessor145.
> invoke(Unknown
> > >> > Source)
> > >> > > >         at
> > >> > > > sun.reflect.DelegatingMethodAccessorImpl.invoke(
> > >> > > > DelegatingMethodAccessorImpl.java:43)
> > >> > > >         at java.lang.reflect.Method.invoke(Method.java:498)
> > >> > > >         at
> > >> > > > org.apache.tomcat.jdbc.pool.ProxyConnection.invoke(
> > >> > > > ProxyConnection.java:126)
> > >> > > >         at
> > >> > > > org.apache.tomcat.jdbc.pool.JdbcInterceptor.invoke(
> > >> > > > JdbcInterceptor.java:108)
> > >> > > >         at
> > >> > > > org.apache.tomcat.jdbc.pool.DisposableConnectionFacade.invoke(
> > >> > > > DisposableConnectionFacade.java:81)
> > >> > > >         at com.sun.proxy.$Proxy58.commit(Unknown Source)
> > >> > > >         at
> > >> > > > org.apache.openejb.resource.jdbc.managed.local.LocalXAResour
> > >> ce.commit(
> > >> > > > LocalXAResource.java:131)
> > >> > > >         at
> > >> > > > org.apache.geronimo.transaction.manager.TransactionImpl.
> > >> > commitResource(
> > >> > > > TransactionImpl.java:627)
> > >> > > >         at
> > >> > > > org.apache.geronimo.transaction.manager.TransactionImpl.commit(
> > >> > > > TransactionImpl.java:305)
> > >> > > >         at
> > >> > > > org.apache.geronimo.transaction.manager.TransactionManagerIm
> > >> pl.commit(
> > >> > > > TransactionManagerImpl.java:252)
> > >> > > >         at
> > >> > > > org.apache.openejb.core.transaction.JtaTransactionPolicy.
> > >> > > > completeTransaction(JtaTransactionPolicy.java:331)
> > >> > > >         at
> > >> > > > org.apache.openejb.core.transaction.TxRequired.commit(
> > >> > > TxRequired.java:91)
> > >> > > >         at
> > >> > > > org.apache.openejb.core.transaction.EjbTransactionUtil.
> > afterInvoke(
> > >> > > > EjbTransactionUtil.java:77)
> > >> > > >         at
> > >> > > > org.apache.openejb.core.stateless.StatelessContainer._
> > >> > > > invoke(StatelessContainer.java:271)
> > >> > > >         at
> > >> > > > org.apache.openejb.core.stateless.StatelessContainer.
> > >> > > > invoke(StatelessContainer.java:212)
> > >> > > >         at
> > >> > > > org.apache.openejb.server.cxf.ejb.EjbMethodInvoker.
> > >> > > > preEjbInvoke(EjbMethodInvoker.java:125)
> > >> > > >         at
> > >> > > > org.apache.openejb.server.cxf.ejb.EjbMethodInvoker.invoke(
> > >> > > > EjbMethodInvoker.java:82)
> > >> > > >         at
> > >> > > > org.apache.cxf.interceptor.ServiceInvokerInterceptor$1.
> > >> > > > run(ServiceInvokerInterceptor.java:59)
> > >> > > >         at
> > >> > > > java.util.concurrent.Executors$RunnableAdapter.
> > >> > call(Executors.java:511)
> > >> > > >         at java.util.concurrent.FutureTask.run(FutureTask.
> > java:266)
> > >> > > >         at
> > >> > > > org.apache.cxf.interceptor.ServiceInvokerInterceptor$2.
> > >> > > > run(ServiceInvokerInterceptor.java:126)
> > >> > > >         at
> > >> > > > org.apache.cxf.workqueue.SynchronousExecutor.execute(
> > >> > > > SynchronousExecutor.java:37)
> > >> > > >         at
> > >> > > > org.apache.cxf.interceptor.ServiceInvokerInterceptor.
> > handleMessage(
> > >> > > > ServiceInvokerInterceptor.java:131)
> > >> > > >         at
> > >> > > > org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(
> > >> > > > PhaseInterceptorChain.java:308)
> > >> > > >         at
> > >> > > > org.apache.cxf.transport.ChainInitiationObserver.onMessage(
> > >> > > > ChainInitiationObserver.java:121)
> > >> > > >         at
> > >> > > > org.apache.cxf.transport.http.AbstractHTTPDestination.invoke(
> > >> > > > AbstractHTTPDestination.java:262)
> > >> > > >         at
> > >> > > > org.apache.openejb.server.cxf.CxfWsContainer.onMessage(
> > >> > > > CxfWsContainer.java:85)
> > >> > > >         at
> > >> > > > org.apache.openejb.server.webservices.WsServlet.service(
> > >> > > WsServlet.java:98)
> > >> > > >         at
> > >> > > > org.apache.catalina.core.ApplicationFilterChain.
> internalDoFilter(
> > >> > > > ApplicationFilterChain.java:230)
> > >> > > >         at
> > >> > > > org.apache.catalina.core.ApplicationFilterChain.doFilter(
> > >> > > > ApplicationFilterChain.java:165)
> > >> > > >         at
> > >> > > > org.apache.catalina.core.StandardWrapperValve.invoke(
> > >> > > > StandardWrapperValve.java:198)
> > >> > > >         at
> > >> > > > org.apache.catalina.core.StandardContextValve.invoke(
> > >> > > > StandardContextValve.java:96)
> > >> > > >         at
> > >> > > > org.apache.catalina.core.StandardHostValve.invoke(
> > >> > > > StandardHostValve.java:140)
> > >> > > >         at
> > >> > > > org.apache.catalina.valves.ErrorReportValve.invoke(
> > >> > > > ErrorReportValve.java:79)
> > >> > > >         at
> > >> > > > org.apache.tomee.catalina.OpenEJBSecurityListener$
> > >> > > RequestCapturer.invoke(
> > >> > > > OpenEJBSecurityListener.java:97)
> > >> > > >         at
> > >> > > > org.apache.catalina.core.StandardEngineValve.invoke(
> > >> > > > StandardEngineValve.java:87)
> > >> > > >         at
> > >> > > > org.apache.catalina.connector.CoyoteAdapter.service(
> > >> > > > CoyoteAdapter.java:349)
> > >> > > >         at
> > >> > > > org.apache.coyote.http11.Http11Processor.service(
> > >> > > Http11Processor.java:783)
> > >> > > >         at
> > >> > > > org.apache.coyote.AbstractProcessorLight.process(
> > >> > > > AbstractProcessorLight.java:66)
> > >> > > >         at
> > >> > > > org.apache.coyote.AbstractProtocol$ConnectionHandler.process(
> > >> > > > AbstractProtocol.java:798)
> > >> > > >         at
> > >> > > > org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.
> > >> > > > doRun(NioEndpoint.java:1434)
> > >> > > >         at
> > >> > > > org.apache.tomcat.util.net.SocketProcessorBase.run(
> > >> > > > SocketProcessorBase.java:49)
> > >> > > >         at
> > >> > > > java.util.concurrent.ThreadPoolExecutor.runWorker(
> > >> > > > ThreadPoolExecutor.java:1142)
> > >> > > >         at
> > >> > > > java.util.concurrent.ThreadPoolExecutor$Worker.run(
> > >> > > > ThreadPoolExecutor.java:617)
> > >> > > >         at
> > >> > > > org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(
> > >> > > > TaskThread.java:61)
> > >> > > >         at java.lang.Thread.run(Thread.java:745)
> > >> > > >
> > >> > > > 2017/05/01 20:35:14.084 FINE
> > >> > > >  [TomEE-Exec-12][206][com.smilecoms.commons.base.lifecycle.
> > >> > > > SmileConnectionLifecycleInterceptor.transactionCompleted]
> > >> > > > |TransactionCompleted called on [com.mysql.jdbc.
> > >> > JDBC4Connection@7d0cc890
> > >> > > ]
> > >> > > > 2017/05/01 20:35:14.084 WARNING
> > >> > > > [TomEE-Exec-12][206][org.apache.openejb.core.transaction.
> > >> TxRequired.
> > >> > > > getCurrentTransaction]
> > >> > > > |In getCurrentTransaction
> > >> > > > 2017/05/01 20:35:14.084 FINE
> > >> > > >  [TomEE-Exec-12][206][org.apache.cxf.phase.
> PhaseInterceptorChain.
> > >> > > > doIntercept]
> > >> > > > |Invoking handleMessage on interceptor
> > >> > > > org.apache.openejb.server.cxf.client.SaajInInterceptor@3374eec1
> > >> > > > 2017/05/01 20:35:14.085 FINE
> > >> > > >  [TomEE-Exec-12][206][org.apache.cxf.phase.
> PhaseInterceptorChain.
> > >> > > > doIntercept]
> > >> > > > |Invoking handleMessage on interceptor
> > >> > > > org.apache.cxf.interceptor.OutgoingChainInterceptor@62316059
> > >> > > > 2017/05/01 20:35:14.085 FINE
> > >> > > >  [TomEE-Exec-12][206][org.apache.cxf.phase.PhaseInterceptorCh
> > >> ain.add]
> > >> > > > |Adding interceptor
> > >> > > > org.apache.cxf.transport.https.CertConstraintsInterceptor@
> > 3a37dedb
> > >> to
> > >> > > > phase
> > >> > > > pre-stream
> > >> > > > 2017/05/01 20:35:14.085 FINE
> > >> > > >  [TomEE-Exec-12][206][org.apache.cxf.phase.
> PhaseInterceptorChain.
> > >> > > > outputChainToLog]
> > >> > > > |Chain org.apache.cxf.phase.PhaseInterceptorChain@301c8187 was
> > >> > created.
> > >> > > > Current flow:
> > >> > > >   receive [PolicyInInterceptor, SaajInFaultInterceptor,
> > >> > > > AttachmentInInterceptor]
> > >> > > >   pre-stream [CertConstraintsInterceptor]
> > >> > > >   post-stream [StaxInInterceptor]
> > >> > > >   read [SAAJPreInInterceptor, WSDLGetInterceptor,
> > >> > ReadHeadersInterceptor,
> > >> > > > SoapActionInInterceptor, StartBodyInterceptor]
> > >> > > >   pre-protocol [SAAJInInterceptor]
> > >> > > >   post-protocol [CheckFaultInterceptor,
> > >> JAXBAttachmentSchemaValidation
> > >> > > > Hack]
> > >> > > >   unmarshal [DocLiteralInInterceptor, SoapHeaderInterceptor]
> > >> > > >   pre-logical [OneWayProcessorInterceptor]
> > >> > > >   post-logical [WrapperClassInInterceptor]
> > >> > > >   pre-invoke [SwAInInterceptor, HolderInInterceptor]
> > >> > > >   invoke [ServiceInvokerInterceptor]
> > >> > > >   post-invoke [SaajInInterceptor, OutgoingChainInterceptor]
> > >> > > >
> > >> > > > 2017/05/01 20:35:14.085 FINE
> > >> > > >  [TomEE-Exec-12][206][org.apache.cxf.phase.
> PhaseInterceptorChain.
> > >> > > > doIntercept]
> > >> > > > |Invoking handleMessage on interceptor
> > >> > > > org.apache.cxf.ws.policy.PolicyInInterceptor@6c760041
> > >> > > > 2017/05/01 20:35:14.085 FINE
> > >> > > >  [TomEE-Exec-12][206][org.apache.cxf.phase.
> PhaseInterceptorChain.
> > >> > > > doIntercept]
> > >> > > > |Invoking handleMessage on interceptor
> > >> > > > org.apache.openejb.server.cxf.client.SaajInFaultInterceptor@
> > 4d50ee8
> > >> > > >
> > >> > > >
> > >> > > > So this 100% confirms that the transaction is committed after
> the
> > >> > > response
> > >> > > > has been sent. I think this bug has major implications on ACID
> > >> > > compliance.
> > >> > > > I also checked on 7.0.2 and found the same behavior.
> > >> > > >
> > >> > > > Paul
> > >> > > >
> > >> > > > On 29 April 2017 at 09:57, Romain Manni-Bucau <
> > >> rmannibu...@gmail.com>
> > >> > > > wrote:
> > >> > > >
> > >> > > > > Ps:
> > >> > > > > https://github.com/apache/tomee/blob/master/container/
> > >> > > > > openejb-core/src/main/java/org/apache/openejb/core/
> > >> > > > > transaction/TxRequired.java
> > >> > > > >
> > >> > > > > Le 29 avr. 2017 09:55, "Romain Manni-Bucau" <
> > >> rmannibu...@gmail.com>
> > >> > a
> > >> > > > > écrit :
> > >> > > > >
> > >> > > > > > Should be before. You can put breakpoint/logs in TxPolicy
> and
> > >> your
> > >> > > ejb
> > >> > > > > >
> > >> > > > > > Le 29 avr. 2017 00:44, "Paul Carter-Brown"
> > >> > > > <paul.carter-brown@smilecoms.
> > >> > > > > > com> a écrit :
> > >> > > > > >
> > >> > > > > >> Hi Romain,
> > >> > > > > >>
> > >> > > > > >> A quick update. I put cxf logging on and for a typical
> > message
> > >> > > > exchange
> > >> > > > > >> for
> > >> > > > > >> a JAX-WS service backed by an EJB.At the same time I ran a
> > >> > wireshark
> > >> > > > on
> > >> > > > > >> the
> > >> > > > > >> server to see the network traffic. This is for a single
> call
> > >> under
> > >> > > no
> > >> > > > > >> concurrency so you can easily verify yourself with any SOAP
> > >> > service
> > >> > > in
> > >> > > > > >> TomEE:
> > >> > > > > >>
> > >> > > > > >> 1438 00:09:05.510294    10.0.1.57 -> 10.0.1.57    HTTP/XML
> > 1223
> > >> > POST
> > >> > > > > >> /IM/IdentityManager HTTP/1.1
> > >> > > > > >> 1439 00:09:05.510436    10.0.1.57 -> 10.0.1.57    TCP 68
> > >> mcreport
> > >> > >
> > >> > > > > 40929
> > >> > > > > >> [ACK] Seq=1721 Ack=7983 Win=323456 Len=0 TSval=70303912
> > >> > > TSecr=70303912
> > >> > > > > >> 1440 00:09:05.527410    10.0.1.57 -> 10.0.1.57    HTTP/XML
> > 1852
> > >> > > > HTTP/1.1
> > >> > > > > >> 200
> > >> > > > > >> 1441 00:09:05.527453    10.0.1.57 -> 10.0.1.57    TCP 68
> > 40929
> > >> >
> > >> > > > > mcreport
> > >> > > > > >> [ACK] Seq=7983 Ack=3505 Win=178944 Len=0 TSval=70303916
> > >> > > TSecr=70303916
> > >> > > > > >>
> > >> > > > > >> So at 00:09:05.510 the server got the request. Here are the
> > >> server
> > >> > > > logs
> > >> > > > > >> verifying this:
> > >> > > > > >>
> > >> > > > > >> 2017/04/29 00:09:05.510 FINE
> > >> > > > > >>  [TomEE-Exec-30][224][org.apache.cxf.phase.
> > >> > > PhaseInterceptorChain.add]
> > >> > > > > >> |Adding interceptor
> > >> > > > > >> org.apache.cxf.transport.https.CertConstraintsInterceptor@
> > >> > 64623f81
> > >> > > to
> > >> > > > > >> phase
> > >> > > > > >> pre-stream
> > >> > > > > >> 2017/04/29 00:09:05.510 FINE
> > >> > > > > >>  [TomEE-Exec-30][224][org.apache.cxf.phase.
> PhaseInterceptorC
> > >> > > > > >> hain.outputChainToLog]
> > >> > > > > >> |Chain org.apache.cxf.phase.PhaseInterceptorChain@713d71d3
> > was
> > >> > > > created.
> > >> > > > > >> Current flow:
> > >> > > > > >>   receive [PolicyInInterceptor, SaajInFaultInterceptor,
> > >> > > > > >> AttachmentInInterceptor]
> > >> > > > > >>   pre-stream [CertConstraintsInterceptor]
> > >> > > > > >>   post-stream [StaxInInterceptor]
> > >> > > > > >>   read [SAAJPreInInterceptor, WSDLGetInterceptor,
> > >> > > > > ReadHeadersInterceptor,
> > >> > > > > >> SoapActionInInterceptor, StartBodyInterceptor]
> > >> > > > > >>   pre-protocol [SAAJInInterceptor]
> > >> > > > > >>   post-protocol [CheckFaultInterceptor,
> > >> > > JAXBAttachmentSchemaValidation
> > >> > > > > >> Hack]
> > >> > > > > >>   unmarshal [DocLiteralInInterceptor,
> SoapHeaderInterceptor]
> > >> > > > > >>   pre-logical [OneWayProcessorInterceptor]
> > >> > > > > >>   post-logical [WrapperClassInInterceptor]
> > >> > > > > >>   pre-invoke [SwAInInterceptor, HolderInInterceptor]
> > >> > > > > >>   invoke [ServiceInvokerInterceptor]
> > >> > > > > >>   post-invoke [SaajInInterceptor, OutgoingChainInterceptor]
> > >> > > > > >>
> > >> > > > > >> 2017/04/29 00:09:05.510 FINE
> > >> > > > > >>  [TomEE-Exec-30][224][org.apache.cxf.phase.
> PhaseInterceptorC
> > >> > > > > >> hain.doIntercept]
> > >> > > > > >> |Invoking handleMessage on interceptor
> > >> > > > > >> org.apache.cxf.ws.policy.PolicyInInterceptor@1e78ace6
> > >> > > > > >> 2017/04/29 00:09:05.510 FINE
> > >> > > > > >>  [TomEE-Exec-30][224][org.apache.cxf.phase.
> PhaseInterceptorC
> > >> > > > > >> hain.doIntercept]
> > >> > > > > >> |Invoking handleMessage on interceptor
> > >> > > > > >> org.apache.openejb.server.cxf.
> client.SaajInFaultInterceptor@
> > >> > > 1338d078
> > >> > > > > >> 2017/04/29 00:09:05.510 FINE
> > >> > > > > >>  [TomEE-Exec-30][224][org.apache.cxf.phase.
> PhaseInterceptorC
> > >> > > > > >> hain.doIntercept]
> > >> > > > > >> |Invoking handleMessage on interceptor
> > >> > > > > >> org.apache.cxf.interceptor.AttachmentInInterceptor@
> 5dea89fc
> > >> > > > > >> 2017/04/29 00:09:05.510 FINE
> > >> > > > > >>  [TomEE-Exec-30][224][org.apache.cxf.phase.
> PhaseInterceptorC
> > >> > > > > >> hain.doIntercept]
> > >> > > > > >> |Invoking handleMessage on interceptor
> > >> > > > > >> org.apache.cxf.transport.https.CertConstraintsInterceptor@
> > >> > 64623f81
> > >> > > > > >> 2017/04/29 00:09:05.510 FINE
> > >> > > > > >>  [TomEE-Exec-30][224][org.apache.cxf.phase.
> PhaseInterceptorC
> > >> > > > > >> hain.doIntercept]
> > >> > > > > >> |Invoking handleMessage on interceptor
> > >> > > > > >> org.apache.cxf.interceptor.StaxInInterceptor@647520af
> > >> > > > > >> 2017/04/29 00:09:05.511 FINE
> > >> > > > > >>  [TomEE-Exec-30][224][org.apache.cxf.phase.
> > >> > > PhaseInterceptorChain.add]
> > >> > > > > >> |Adding interceptor
> > >> > > > > >> org.apache.cxf.interceptor.StaxInEndingInterceptor@
> 39dd4830
> > to
> > >> > > phase
> > >> > > > > >> pre-invoke
> > >> > > > > >> 2017/04/29 00:09:05.511 FINE
> > >> > > > > >>  [TomEE-Exec-30][224][org.apache.cxf.phase.
> PhaseInterceptorC
> > >> > > > > >> hain.outputChainToLog]
> > >> > > > > >> |Chain org.apache.cxf.phase.PhaseInterceptorChain@713d71d3
> > was
> > >> > > > > modified.
> > >> > > > > >> Current flow:
> > >> > > > > >>   receive [PolicyInInterceptor, SaajInFaultInterceptor,
> > >> > > > > >> AttachmentInInterceptor]
> > >> > > > > >>   pre-stream [CertConstraintsInterceptor]
> > >> > > > > >>   post-stream [StaxInInterceptor]
> > >> > > > > >>   read [SAAJPreInInterceptor, WSDLGetInterceptor,
> > >> > > > > ReadHeadersInterceptor,
> > >> > > > > >> SoapActionInInterceptor, StartBodyInterceptor]
> > >> > > > > >>   pre-protocol [SAAJInInterceptor]
> > >> > > > > >>   post-protocol [CheckFaultInterceptor,
> > >> > > JAXBAttachmentSchemaValidation
> > >> > > > > >> Hack]
> > >> > > > > >>   unmarshal [DocLiteralInInterceptor,
> SoapHeaderInterceptor]
> > >> > > > > >>   pre-logical [OneWayProcessorInterceptor]
> > >> > > > > >>   post-logical [WrapperClassInInterceptor]
> > >> > > > > >>   pre-invoke [StaxInEndingInterceptor, SwAInInterceptor,
> > >> > > > > >> HolderInInterceptor]
> > >> > > > > >>   invoke [ServiceInvokerInterceptor]
> > >> > > > > >>   post-invoke [SaajInInterceptor, OutgoingChainInterceptor]
> > >> > > > > >>
> > >> > > > > >> 2017/04/29 00:09:05.511 FINE
> > >> > > > > >>  [TomEE-Exec-30][224][org.apache.cxf.phase.
> PhaseInterceptorC
> > >> > > > > >> hain.doIntercept]
> > >> > > > > >> |Invoking handleMessage on interceptor
> > >> > > > > >> org.apache.cxf.binding.soap.saaj.SAAJInInterceptor$
> SAAJPreIn
> > >> > > > > >> Interceptor@6c33f463
> > >> > > > > >> 2017/04/29 00:09:05.511 FINE
> > >> > > > > >>  [TomEE-Exec-30][224][org.apache.cxf.phase.
> PhaseInterceptorC
> > >> > > > > >> hain.doIntercept]
> > >> > > > > >> |Invoking handleMessage on interceptor
> > >> > > > > >> org.apache.cxf.frontend.WSDLGetInterceptor@11c0446f
> > >> > > > > >> 2017/04/29 00:09:05.511 FINE
> > >> > > > > >>  [TomEE-Exec-30][224][org.apache.cxf.phase.
> PhaseInterceptorC
> > >> > > > > >> hain.doIntercept]
> > >> > > > > >> |Invoking handleMessage on interceptor
> > >> > > > > >> org.apache.cxf.binding.soap.interceptor.
> > >> > > > ReadHeadersInterceptor@be15cc5
> > >> > > > > >> 2017/04/29 00:09:05.511 FINE
> > >> > > > > >>  [TomEE-Exec-30][224][org.apache.cxf.phase.
> PhaseInterceptorC
> > >> > > > > >> hain.doIntercept]
> > >> > > > > >> |Invoking handleMessage on interceptor
> > >> > > > > >> org.apache.cxf.binding.soap.interceptor.
> SoapActionInIntercep
> > >> tor@
> > >> > > > > 79836009
> > >> > > > > >> 2017/04/29 00:09:05.511 FINE
> > >> > > > > >>  [TomEE-Exec-30][224][org.apache.cxf.phase.
> PhaseInterceptorC
> > >> > > > > >> hain.doIntercept]
> > >> > > > > >> |Invoking handleMessage on interceptor
> > >> > > > > >> org.apache.cxf.binding.soap.interceptor.
> > >> > > StartBodyInterceptor@70afa3ac
> > >> > > > > >> 2017/04/29 00:09:05.511 FINE
> > >> > > > > >>  [TomEE-Exec-30][224][org.apache.cxf.phase.
> PhaseInterceptorC
> > >> > > > > >> hain.doIntercept]
> > >> > > > > >> |Invoking handleMessage on interceptor
> > >> > > > > >> org.apache.cxf.binding.soap.saaj.SAAJInInterceptor@
> 3d12954e
> > >> > > > > >> .....
> > >> > > > > >>
> > >> > > > > >> Now lets look at the server logs around the time the
> response
> > >> goes
> > >> > > > back
> > >> > > > > >> and
> > >> > > > > >> also see where the commit was issued:
> > >> > > > > >>
> > >> > > > > >> 2017/04/29 00:09:05.523 FINE
> > >> > > > > >>  [TomEE-Exec-30][224][org.apache.cxf.phase.
> PhaseInterceptorC
> > >> > > > > >> hain.doIntercept]
> > >> > > > > >> |Invoking handleMessage on interceptor
> > >> > > > > >> org.apache.cxf.jaxws.handler.logical.
> LogicalHandlerOutInterc
> > >> > > > > >> eptor@128bf90f
> > >> > > > > >> 2017/04/29 00:09:05.523 FINE
> > >> > > > > >>  [TomEE-Exec-30][224][org.apache.cxf.phase.
> PhaseInterceptorC
> > >> > > > > >> hain.doIntercept]
> > >> > > > > >> |Invoking handleMessage on interceptor
> > >> > > > > >> org.apache.cxf.wsdl.interceptors.
> BareOutInterceptor@62b3ecb1
> > >> > > > > >> 2017/04/29 00:09:05.524 FINE
> > >> > > > > >>  [TomEE-Exec-30][224][org.apache.cxf.phase.
> PhaseInterceptorC
> > >> > > > > >> hain.doIntercept]
> > >> > > > > >> |Invoking handleMessage on interceptor
> > >> > > > > >> org.apache.cxf.jaxws.handler.
> soap.SOAPHandlerInterceptor$1@
> > >> > 900b115
> > >> > > > > >> *2017/04/29 00:09:05.527 FINE
> > >> > > > > >>  [TomEE-Exec-30][224][org.apache.cxf.phase.
> PhaseInterceptorC
> > >> > > > > >> hain.doIntercept]
> > >> > > > > >> |Invoking handleMessage on interceptor
> > >> > > > > >> org.apache.cxf.binding.soap.interceptor.
> SoapOutInterceptor$S
> > >> > > > > >> oapOutEndingInterceptor@10aa05f4*
> > >> > > > > >> 2017/04/29 00:09:05.527 FINE
> > >> > > > > >>  [TomEE-Exec-30][224][org.apache.cxf.phase.
> PhaseInterceptorC
> > >> > > > > >> hain.doIntercept]
> > >> > > > > >> |Invoking handleMessage on interceptor
> > >> > > > > >> org.apache.cxf.binding.soap.saaj.SAAJOutInterceptor$
> SAAJOutE
> > >> > > > > >> ndingInterceptor@66cac58b
> > >> > > > > >> 2017/04/29 00:09:05.527 FINE
> > >> > > > > >>  [TomEE-Exec-30][224][org.apache.cxf.phase.
> PhaseInterceptorC
> > >> > > > > >> hain.doIntercept]
> > >> > > > > >> |Invoking handleMessage on interceptor
> > >> > > > > >> org.apache.cxf.interceptor.StaxOutEndingInterceptor@
> 3304ff7d
> > >> > > > > >> 2017/04/29 00:09:05.527 FINE
> > >> > > > > >>  [TomEE-Exec-30][224][org.apache.cxf.phase.
> PhaseInterceptorC
> > >> > > > > >> hain.doIntercept]
> > >> > > > > >> |Invoking handleMessage on interceptor
> > >> > > > > >> org.apache.cxf.interceptor.MessageSenderInterceptor$
> MessageS
> > >> > > > > >> enderEndingInterceptor@674adcf8
> > >> > > > > >> 2017/04/29 00:09:05.529 FINE
> > >> > > > > >>  [TomEE-Exec-30][224][com.smilecoms.commons.base.
> lifecycle.S
> > >> > > > > >> mileConnectionLifecycleInterceptor.commit]
> > >> > > > > >> |Commit called on [com.mysql.jdbc.JDBC4Connection@314c8b4a
> ]
> > >> > > > > >> 2017/04/29 00:09:05.529 FINE
> > >> > > > > >>  [TomEE-Exec-30][224][com.smilecoms.commons.base.
> lifecycle.S
> > >> > > > > >> mileConnectionLifecycleInterceptor.commit]
> > >> > > > > >> |Stack:
> > >> > > > > >> java.lang.Exception
> > >> > > > > >>         at
> > >> > > > > >> com.smilecoms.commons.base.lifecycle.
> SmileConnectionLifecycl
> > >> > > > > >> eInterceptor.commit(SmileConnectionLifecycleInterceptor.
> > >> java:34)
> > >> > > > > >>         at com.mysql.jdbc.ConnectionImpl$
> > >> > > > 2.forEach(ConnectionImpl.java:
> > >> > > > > >> 1593)
> > >> > > > > >>         at com.mysql.jdbc.ConnectionImpl$
> > >> > > > 2.forEach(ConnectionImpl.java:
> > >> > > > > >> 1592)
> > >> > > > > >>         at com.mysql.jdbc.IterateBlock.
> > >> > > doForAll(IterateBlock.java:61)
> > >> > > > > >>         at com.mysql.jdbc.ConnectionImpl.
> > >> > > commit(ConnectionImpl.java:
> > >> > > > > 1599)
> > >> > > > > >>         at sun.reflect.GeneratedMethodAcc
> > >> essor138.invoke(Unknown
> > >> > > > > Source)
> > >> > > > > >>         at
> > >> > > > > >> sun.reflect.DelegatingMethodAccessorImpl.
> invoke(DelegatingMe
> > >> > > > > >> thodAccessorImpl.java:43)
> > >> > > > > >>         at java.lang.reflect.Method.
> invoke(Method.java:498)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.tomcat.jdbc.pool.ProxyConnection.invoke(
> ProxyConn
> > >> > > > > >> ection.java:126)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.tomcat.jdbc.pool.JdbcInterceptor.invoke(
> JdbcInter
> > >> > > > > >> ceptor.java:108)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.tomcat.jdbc.pool.DisposableConnectionFacade.
> invok
> > >> > > > > >> e(DisposableConnectionFacade.java:81)
> > >> > > > > >>         at com.sun.proxy.$Proxy58.commit(Unknown Source)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.openejb.resource.jdbc.managed.local.
> LocalXAResour
> > >> > > > > >> ce.commit(LocalXAResource.java:131)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.geronimo.transaction.manager.
> TransactionImpl.comm
> > >> > > > > >> itResource(TransactionImpl.java:627)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.geronimo.transaction.manager.TransactionImpl.
> > >> > > > > >> commit(TransactionImpl.java:305)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.geronimo.transaction.manager.
> TransactionManagerIm
> > >> > > > > >> pl.commit(TransactionManagerImpl.java:252)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.openejb.core.transaction.
> JtaTransactionPolicy.com
> > >> > > > > >> pleteTransaction(JtaTransactionPolicy.java:331)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.openejb.core.transaction.TxRequired.commit(
> > >> > > > > TxRequired.java:76)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.openejb.core.transaction.
> EjbTransactionUtil.after
> > >> > > > > >> Invoke(EjbTransactionUtil.java:77)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.openejb.core.stateless.StatelessContainer._
> invoke
> > >> > > > > >> (StatelessContainer.java:271)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.openejb.core.stateless.StatelessContainer.
> invoke(
> > >> > > > > >> StatelessContainer.java:212)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.openejb.server.cxf.
> ejb.EjbMethodInvoker.preEjbInv
> > >> > > > > >> oke(EjbMethodInvoker.java:125)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.openejb.server.cxf.
> ejb.EjbMethodInvoker.invoke(Ej
> > >> > > > > >> bMethodInvoker.java:82)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.cxf.service.invoker.AbstractInvoker.invoke(
> > >> > > > > >> AbstractInvoker.java:74)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.cxf.interceptor.ServiceInvokerInterceptor$1.
> run(
> > >> > > > > >> ServiceInvokerInterceptor.java:59)
> > >> > > > > >>         at
> > >> > > > > >> java.util.concurrent.Executors$RunnableAdapter.
> > >> > > > call(Executors.java:511)
> > >> > > > > >>         at java.util.concurrent.FutureTask.run(FutureTask.
> > >> > java:266)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.cxf.interceptor.ServiceInvokerInterceptor$2.
> run(
> > >> > > > > >> ServiceInvokerInterceptor.java:126)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.cxf.workqueue.SynchronousExecutor.execute(
> Synchro
> > >> > > > > >> nousExecutor.java:37)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.cxf.interceptor.ServiceInvokerInterceptor.
> handleM
> > >> > > > > >> essage(ServiceInvokerInterceptor.java:131)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.cxf.phase.PhaseInterceptorChain.
> doIntercept(Phase
> > >> > > > > >> InterceptorChain.java:308)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.cxf.transport.ChainInitiationObserver.
> onMessage(C
> > >> > > > > >> hainInitiationObserver.java:121)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.cxf.transport.http.
> AbstractHTTPDestination.invoke
> > >> > > > > >> (AbstractHTTPDestination.java:262)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.openejb.server.cxf.
> CxfWsContainer.onMessage(CxfWs
> > >> > > > > >> Container.java:85)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.openejb.server.webservices.WsServlet.service(
> WsSe
> > >> > > > > >> rvlet.java:98)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.catalina.core.ApplicationFilterChain.
> internalDoFi
> > >> > > > > >> lter(ApplicationFilterChain.java:230)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.catalina.core.ApplicationFilterChain.
> doFilter(App
> > >> > > > > >> licationFilterChain.java:165)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.catalina.core.StandardWrapperValve.invoke(
> Standar
> > >> > > > > >> dWrapperValve.java:198)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.catalina.core.StandardContextValve.invoke(
> Standar
> > >> > > > > >> dContextValve.java:96)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.catalina.core.StandardHostValve.invoke(
> StandardHo
> > >> > > > > >> stValve.java:140)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.catalina.valves.ErrorReportValve.invoke(
> ErrorRepo
> > >> > > > > >> rtValve.java:79)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.tomee.catalina.OpenEJBSecurityListener$
> RequestCap
> > >> > > > > >> turer.invoke(OpenEJBSecurityListener.java:97)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.catalina.core.StandardEngineValve.invoke(
> Standard
> > >> > > > > >> EngineValve.java:87)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.catalina.connector.
> CoyoteAdapter.service(CoyoteAd
> > >> > > > > >> apter.java:349)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.coyote.http11.Http11Processor.service(
> Http11Proce
> > >> > > > > >> ssor.java:783)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.coyote.AbstractProcessorLight.
> process(AbstractPro
> > >> > > > > >> cessorLight.java:66)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.coyote.AbstractProtocol$ConnectionHandler.
> > >> > > > > >> process(AbstractProtocol.java:798)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.
> doRun
> > >> > > > > >> (NioEndpoint.java:1434)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.tomcat.util.net.SocketProcessorBase.run(
> SocketPro
> > >> > > > > >> cessorBase.java:49)
> > >> > > > > >>         at
> > >> > > > > >> java.util.concurrent.ThreadPoolExecutor.runWorker(
> ThreadPool
> > >> > > > > >> Executor.java:1142)
> > >> > > > > >>         at
> > >> > > > > >> java.util.concurrent.ThreadPoolExecutor$Worker.run(
> ThreadPoo
> > >> > > > > >> lExecutor.java:617)
> > >> > > > > >>         at
> > >> > > > > >> org.apache.tomcat.util.threads.TaskThread$
> WrappingRunnable.
> > >> > > > > >> run(TaskThread.java:61)
> > >> > > > > >>         at java.lang.Thread.run(Thread.java:745)
> > >> > > > > >>
> > >> > > > > >> 2017/04/29 00:09:05.529 FINE
> > >> > > > > >>  [TomEE-Exec-30][224][org.apache.cxf.phase.
> PhaseInterceptorC
> > >> > > > > >> hain.doIntercept]
> > >> > > > > >> |Invoking handleMessage on interceptor
> > >> > > > > >> org.apache.openejb.server.cxf.
> client.SaajInInterceptor@41aa4
> > >> e75
> > >> > > > > >> 2017/04/29 00:09:05.530 FINE
> > >> > > > > >>  [TomEE-Exec-30][224][org.apache.cxf.phase.
> PhaseInterceptorC
> > >> > > > > >> hain.doIntercept]
> > >> > > > > >> |Invoking handleMessage on interceptor
> > >> > > > > >> org.apache.cxf.interceptor.OutgoingChainInterceptor@
> 564ef482
> > >> > > > > >>
> > >> > > > > >>
> > >> > > > > >> From what I can gather from the source, the SOAP document
> is
> > >> > flushed
> > >> > > > on
> > >> > > > > >> the
> > >> > > > > >> socket in SoapOutEndingInterceptor which I have put in
> bold.
> > >> This
> > >> > > also
> > >> > > > > >> corresponds with the wireshark timing
> > >> > > > > >>
> > >> > > > > >> The class looks like this:
> > >> > > > > >>
> > >> > > > > >> public class SoapOutEndingInterceptor extends
> > >> > > AbstractSoapInterceptor
> > >> > > > {
> > >> > > > > >>   269           public SoapOutEndingInterceptor() {
> > >> > > > > >>   270               super(SoapOutEndingInterceptor.
> > >> > class.getName(),
> > >> > > > > >> Phase.WRITE_ENDING);  271           }
> > >> > > > > >>   272
> > >> > > > > >>   273           public void handleMessage(SoapMessage
> > message)
> > >> > > throws
> > >> > > > > >> Fault {
> > >> > > > > >>   274               SoapVersion soapVersion =
> > >> > message.getVersion();
> > >> > > > > >>   275               try {
> > >> > > > > >>   276                   XMLStreamWriter xtw =
> > >> > > > > >> message.getContent(XMLStreamWriter.class);
> > >> > > > > >>   277                   if (xtw != null) {
> > >> > > > > >>   278                       xtw.writeEndElement();
> > >> > > > > >>   279                       // Write Envelope end element
> > >> > > > > >>   280                       xtw.writeEndElement();  281
> > >> > > > > >>        xtw.writeEndDocument();
> > >> > > > > >>   282
> > >> > > > > >>   283                       xtw.flush();
> > >> > > > > >>   284                   }
> > >> > > > > >>   285               } catch (XMLStreamException e) {
> > >> > > > > >>   286                   throw new SoapFault(new
> > >> > > > > >> org.apache.cxf.common.i18n.Message("XML_WRITE_EXC",
> BUNDLE),
> > >> e,
> > >> > > > > >>   287
> > >> > >  soapVersion.getSender());
> > >> > > > > >>   288               }
> > >> > > > > >>   289           }
> > >> > > > > >>   290       }
> > >> > > > > >>
> > >> > > > > >>
> > >> > > > > >> The commit is only called via MessageSenderInterceptor but
> > from
> > >> > the
> > >> > > > > stack
> > >> > > > > >> trace I can't quite work out how ServiceInvokerInterceptor
> is
> > >> > called
> > >> > > > > from
> > >> > > > > >> MessageSenderInterceptor so I can't explain the stack trace
> > of
> > >> the
> > >> > > > > commit
> > >> > > > > >> call unless it's some fancy context switching and use of
> > >> > completable
> > >> > > > > >> futures
> > >> > > > > >>
> > >> > > > > >> Any ideas what's going on?
> > >> > > > > >>
> > >> > > > > >>
> > >> > > > > >> Paul
> > >> > > > > >>
> > >> > > > > >> On 27 April 2017 at 10:39, Paul Carter-Brown <
> > >> > > > > >> paul.carter-br...@smilecoms.com> wrote:
> > >> > > > > >>
> > >> > > > > >> > For sure. I will start by pulling openejb source and
> > digging
> > >> in
> > >> > > for
> > >> > > > > >> > possible causes. A few log lines here and there and im
> > sure i
> > >> > can
> > >> > > > find
> > >> > > > > >> it
> > >> > > > > >> >
> > >> > > > > >> > Paul
> > >> > > > > >> >
> > >> > > > > >> > Sent from my phone. Message may be brief and contain
> typos.
> > >> > > > > >> >
> > >> > > > > >> >
> > >> > > > > >> > On 27 Apr 2017 10:25 a.m., "Romain Manni-Bucau" <
> > >> > > > > rmannibu...@gmail.com>
> > >> > > > > >> > wrote:
> > >> > > > > >> >
> > >> > > > > >> > ant / gradle are other options but something not IDE
> > related
> > >> > > please
> > >> > > > > (or
> > >> > > > > >> you
> > >> > > > > >> > take the risk noone will be able to run it ;))
> > >> > > > > >> >
> > >> > > > > >> >
> > >> > > > > >> > Romain Manni-Bucau
> > >> > > > > >> > @rmannibucau <https://twitter.com/rmannibucau> |  Blog
> > >> > > > > >> > <https://blog-rmannibucau.rhcloud.com> | Old Blog
> > >> > > > > >> > <http://rmannibucau.wordpress.com> | Github <
> > >> > > > > >> https://github.com/rmannibuca
> > >> > > > > >> > u> |
> > >> > > > > >> > LinkedIn <https://www.linkedin.com/in/rmannibucau> |
> > JavaEE
> > >> > > Factory
> > >> > > > > >> > <https://javaeefactory-rmannibucau.rhcloud.com>
> > >> > > > > >> >
> > >> > > > > >> > 2017-04-27 9:48 GMT+02:00 Paul Carter-Brown
> > >> > > > > >> <paul.carter-brown@smilecoms.c
> > >> > > > > >> > om
> > >> > > > > >> > >:
> > >> > > > > >> >
> > >> > > > > >> > > Will see what I can do to reproduce for you. Maven and
> I
> > do
> > >> > not
> > >> > > > get
> > >> > > > > >> one
> > >> > > > > >> > > well :-(
> > >> > > > > >> > >
> > >> > > > > >> > >
> > >> > > > > >> > >
> > >> > > > > >> > > On 27 April 2017 at 09:30, Romain Manni-Bucau <
> > >> > > > > rmannibu...@gmail.com>
> > >> > > > > >> > > wrote:
> > >> > > > > >> > >
> > >> > > > > >> > > > Ok, at that point maybe try to reproduce it on a
> small
> > >> > sample
> > >> > > on
> > >> > > > > >> > github -
> > >> > > > > >> > > > goal is to share with us your setup more or less but
> > not
> > >> > > > > >> confidential
> > >> > > > > >> > > data.
> > >> > > > > >> > > >
> > >> > > > > >> > > > You can use:
> > >> > > > > >> > > >
> > >> > > > > >> > > > <dependency>
> > >> > > > > >> > > >   <groupId>com.wix</groupId>
> > >> > > > > >> > > >   <artifactId>wix-embedded-mysql</artifactId>
> > >> > > > > >> > > >   <version>2.1.4</version>
> > >> > > > > >> > > > </dependency>
> > >> > > > > >> > > >
> > >> > > > > >> > > > And in java:
> > >> > > > > >> > > >
> > >> > > > > >> > > >
> > >> > > > > >> > > > EmbeddedMysql.anEmbeddedMysql(MysqldConfig
> > >> > > > > >> > > >         .aMysqldConfig(Version.v5_7_17)
> > >> > > > > >> > > >         .withPort(Integer.parseInt(port))
> > >> > > > > >> > > >         .withUser("user", "pass")
> > >> > > > > >> > > >         .build());
> > >> > > > > >> > > > final EmbeddedMysql mysql = builder.start()
> > >> > > > > >> > > >         .addSchema(SchemaConfig.
> > >> > > aSchemaConfig("test").build());
> > >> > > > > >> > > >
> > >> > > > > >> > > >
> > >> > > > > >> > > > To write a test with a running MySQL (first time you
> > >> launch
> > >> > it
> > >> > > > > >> > downloads
> > >> > > > > >> > > > mysql so it can be a bit long but then it is cached.
> > >> > > > > >> > > >
> > >> > > > > >> > > > This way we could grab it locally and investigate a
> bit
> > >> > more.
> > >> > > > > >> > > >
> > >> > > > > >> > > > Romain Manni-Bucau
> > >> > > > > >> > > > @rmannibucau <https://twitter.com/rmannibucau> |
> Blog
> > >> > > > > >> > > > <https://blog-rmannibucau.rhcloud.com> | Old Blog
> > >> > > > > >> > > > <http://rmannibucau.wordpress.com> | Github <
> > >> > > > > >> > > https://github.com/rmannibuca
> > >> > > > > >> > > > u> |
> > >> > > > > >> > > > LinkedIn <https://www.linkedin.com/in/rmannibucau> |
> > >> JavaEE
> > >> > > > > Factory
> > >> > > > > >> > > > <https://javaeefactory-rmannibucau.rhcloud.com>
> > >> > > > > >> > > >
> > >> > > > > >> > > > 2017-04-27 6:06 GMT+02:00 Paul Carter-Brown
> > >> > > > > >> > > <paul.carter-brown@smilecoms.c
> > >> > > > > >> > > > om
> > >> > > > > >> > > > >:
> > >> > > > > >> > > >
> > >> > > > > >> > > > > No. Autocommit is off
> > >> > > > > >> > > > >
> > >> > > > > >> > > > > Paul
> > >> > > > > >> > > > >
> > >> > > > > >> > > > > Sent from my phone. Message may be brief and
> contain
> > >> > typos.
> > >> > > > > >> > > > >
> > >> > > > > >> > > > >
> > >> > > > > >> > > > > On 27 Apr 2017 12:47 a.m., "Romain Manni-Bucau" <
> > >> > > > > >> > rmannibu...@gmail.com
> > >> > > > > >> > > >
> > >> > > > > >> > > > > wrote:
> > >> > > > > >> > > > >
> > >> > > > > >> > > > > > Are you in autocommit mode?
> > >> > > > > >> > > > > >
> > >> > > > > >> > > > > > Le 26 avr. 2017 22:37, "Paul Carter-Brown"
> > >> > > > > >> > > > <paul.carter-brown@smilecoms.
> > >> > > > > >> > > > > > com>
> > >> > > > > >> > > > > > a écrit :
> > >> > > > > >> > > > > >
> > >> > > > > >> > > > > > > Hi,
> > >> > > > > >> > > > > > >
> > >> > > > > >> > > > > > > Unfortunately, the same result with dbcp2. I
> also
> > >> > turned
> > >> > > > on
> > >> > > > > >> mysql
> > >> > > > > >> > > > > general
> > >> > > > > >> > > > > > > query log and can see the commit come through
> > after
> > >> > the
> > >> > > > > select
> > >> > > > > >> > > comes
> > >> > > > > >> > > > in
> > >> > > > > >> > > > > > on
> > >> > > > > >> > > > > > > another connection:
> > >> > > > > >> > > > > > >
> > >> > > > > >> > > > > > >
> > >> > > > > >> > > > > > > 2017-04-26T19:46:22.243742Z 20038 Query INSERT
> > INTO
> > >> > > > > >> > > > > > > SmileDB.customer_profile ... <removed>
> > >> > > > > >> > > > > > > 2017-04-26T19:46:22.245984Z 20038 Query SELECT
> > >> > > > > >> LAST_INSERT_ID()
> > >> > > > > >> > > > > > > 2017-04-26T19:46:22.291193Z 20038 Query select
> > >> > > > > >> > > @@session.tx_read_only
> > >> > > > > >> > > > > > > 2017-04-26T19:46:22.317914Z      20031 Query
> > >>  SET
> > >> > > > > >> autocommit=0
> > >> > > > > >> > > > > > > 2017-04-26T19:46:22.318088Z      20031 Query
> > >> >  SELECT
> > >> > > *
> > >> > > > > FROM
> > >> > > > > >> > > > > > > SmileDB.customer_profile WHERE
> > >> > > CUSTOMER_PROFILE_ID=1267253
> > >> > > > > AND
> > >> > > > > >> > > > > > STATUS='AC'
> > >> > > > > >> > > > > > > 2017-04-26T19:46:22.372481Z 20038 Query commit
> > >> > > > > >> > > > > > >
> > >> > > > > >> > > > > > >
> > >> > > > > >> > > > > > > And here is the log of the lifecycle listener
> > >> getting
> > >> > > > commit
> > >> > > > > >> > > called:
> > >> > > > > >> > > > > > >
> > >> > > > > >> > > > > > > 2017/04/26 21:46:22.293 FINE
> > >> > > [TomEE-Exec-31][301][com.
> > >> > > > > >> > > > > > > smilecoms.commons.base.lifecycle.
> > >> > > > > SmileConnectionLifecycleInt
> > >> > > > > >> erc
> > >> > > > > >> > > > > > > eptor.commit]
> > >> > > > > >> > > > > > > |Commit called
> > >> > > > > >> > > > > > >
> > >> > > > > >> > > > > > >
> > >> > > > > >> > > > > > >
> > >> > > > > >> > > > > > >
> > >> > > > > >> > > > > > > On 26 April 2017 at 17:12, Romain Manni-Bucau <
> > >> > > > > >> > > rmannibu...@gmail.com
> > >> > > > > >> > > > >
> > >> > > > > >> > > > > > > wrote:
> > >> > > > > >> > > > > > >
> > >> > > > > >> > > > > > > > maybe switch to dbcp pool to see if it
> behaves
> > >> the
> > >> > > same,
> > >> > > > > if
> > >> > > > > >> not
> > >> > > > > >> > > can
> > >> > > > > >> > > > > be
> > >> > > > > >> > > > > > an
> > >> > > > > >> > > > > > > > equals/hashcode issue
> > >> > > > > >> > > > > > > >
> > >> > > > > >> > > > > > > >
> > >> > > > > >> > > > > > > > Romain Manni-Bucau
> > >> > > > > >> > > > > > > > @rmannibucau <https://twitter.com/
> rmannibucau>
> > |
> > >> > > Blog
> > >> > > > > >> > > > > > > > <https://blog-rmannibucau.rhcloud.com> | Old
> > >> Blog
> > >> > > > > >> > > > > > > > <http://rmannibucau.wordpress.com> | Github
> <
> > >> > > > > >> > > > > > > https://github.com/rmannibuca
> > >> > > > > >> > > > > > > > u> |
> > >> > > > > >> > > > > > > > LinkedIn <https://www.linkedin.com/in/r
> > >> mannibucau>
> > >> > |
> > >> > > > > JavaEE
> > >> > > > > >> > > > Factory
> > >> > > > > >> > > > > > > > <https://javaeefactory-
> rmannibucau.rhcloud.com
> > >
> > >> > > > > >> > > > > > > >
> > >> > > > > >> > > > > > > > 2017-04-26 16:45 GMT+02:00 Paul Carter-Brown
> <
> > >> > > > > >> > > > > > > > paul.carter-br...@smilecoms.com>:
> > >> > > > > >> > > > > > > >
> > >> > > > > >> > > > > > > > > Hi Romain,
> > >> > > > > >> > > > > > > > >
> > >> > > > > >> > > > > > > > > In order to better understand the commit
> > >> timing, I
> > >> > > > have
> > >> > > > > >> put
> > >> > > > > >> > > some
> > >> > > > > >> > > > > > > logging
> > >> > > > > >> > > > > > > > in
> > >> > > > > >> > > > > > > > > a custom MySQL
> ConnectionLifecycleInterceptor
> > >> so
> > >> > > that
> > >> > > > I
> > >> > > > > >> can
> > >> > > > > >> > do
> > >> > > > > >> > > a
> > >> > > > > >> > > > > > stack
> > >> > > > > >> > > > > > > > > trace when commit is called and see where
> > it's
> > >> > > called
> > >> > > > > >> > relative
> > >> > > > > >> > > to
> > >> > > > > >> > > > > the
> > >> > > > > >> > > > > > > > SOAP
> > >> > > > > >> > > > > > > > > service invocation. I also put a
> > >> > Thread.sleep(1000)
> > >> > > in
> > >> > > > > the
> > >> > > > > >> > > commit
> > >> > > > > >> > > > > > > method
> > >> > > > > >> > > > > > > > of
> > >> > > > > >> > > > > > > > > my ConnectionLifecycleInterceptor to see
> how
> > it
> > >> > > > > influenced
> > >> > > > > >> > the
> > >> > > > > >> > > > > > response
> > >> > > > > >> > > > > > > > > going back to the client. Whats very
> strange
> > is
> > >> > that
> > >> > > > the
> > >> > > > > >> > 1000ms
> > >> > > > > >> > > > > sleep
> > >> > > > > >> > > > > > > > does
> > >> > > > > >> > > > > > > > > result in the response taking almost 1000ms
> > >> > longer.
> > >> > > I
> > >> > > > > say
> > >> > > > > >> > > almost,
> > >> > > > > >> > > > > > > because
> > >> > > > > >> > > > > > > > > again when running with multiple threads, I
> > can
> > >> > get
> > >> > > a
> > >> > > > > >> > situation
> > >> > > > > >> > > > > where
> > >> > > > > >> > > > > > > the
> > >> > > > > >> > > > > > > > > response beats the completion of the
> commit.
> > I
> > >> > > cannot
> > >> > > > > >> create
> > >> > > > > >> > > this
> > >> > > > > >> > > > > > when
> > >> > > > > >> > > > > > > > the
> > >> > > > > >> > > > > > > > > client has only one thread. Here is a log
> > >> snippet
> > >> > > > > showing
> > >> > > > > >> the
> > >> > > > > >> > > > > > scenario:
> > >> > > > > >> > > > > > > > >
> > >> > > > > >> > > > > > > > > 1) Here is our
> ConnectionLifecycleInterceptor
> > >> > > getting
> > >> > > > > the
> > >> > > > > >> > > commit
> > >> > > > > >> > > > > call
> > >> > > > > >> > > > > > > and
> > >> > > > > >> > > > > > > > > logging the stack before sleeping for
> 1000ms.
> > >> Its
> > >> > > > > >> committing
> > >> > > > > >> > a
> > >> > > > > >> > > > new
> > >> > > > > >> > > > > > row
> > >> > > > > >> > > > > > > > with
> > >> > > > > >> > > > > > > > > ID 615867
> > >> > > > > >> > > > > > > > > 2017/04/26 16:22:50.592 FINE
> > >> > > > > >> > > > > > > > >  [TomEE-Exec-15][207][com.smile
> > >> > > > > >> coms.commons.base.lifecycle.
> > >> > > > > >> > > > > > > > > SmileConnectionLifecycleInterc
> eptor.commit]
> > >> > > > > >> > > > > > > > > |Commit called
> > >> > > > > >> > > > > > > > > 2017/04/26 16:22:50.593 FINE
> > >> > > > > >> > > > > > > > >  [TomEE-Exec-15][207][com.smile
> > >> > > > > >> coms.commons.base.lifecycle.
> > >> > > > > >> > > > > > > > > SmileConnectionLifecycleInterc
> eptor.commit]
> > >> > > > > >> > > > > > > > > |Stack in commit. Sleeping now:
> > >> > > > > >> > > > > > > > > java.lang.Exception
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > com.smilecoms.commons.base.lifecycle.
> > >> > > > > >> > > > > SmileConnectionLifecycleInterc
> > >> > > > > >> > > > > > > > > eptor.commit(
> SmileConnectionLifecycleInterc
> > >> > > > > eptor.java:32)
> > >> > > > > >> > > > > > > > >         at com.mysql.jdbc.ConnectionImpl$
> > >> > > > > >> > > > > > > 2.forEach(ConnectionImpl.java:
> > >> > > > > >> > > > > > > > > 1593)
> > >> > > > > >> > > > > > > > >         at com.mysql.jdbc.ConnectionImpl$
> > >> > > > > >> > > > > > > 2.forEach(ConnectionImpl.java:
> > >> > > > > >> > > > > > > > > 1592)
> > >> > > > > >> > > > > > > > >         at com.mysql.jdbc.IterateBlock.
> > >> > > > > >> > > > > > doForAll(IterateBlock.java:61)
> > >> > > > > >> > > > > > > > >         at com.mysql.jdbc.ConnectionImpl.
> > >> > > > > >> > > > > > > commit(ConnectionImpl.java:159
> > >> > > > > >> > > > > > > > 9)
> > >> > > > > >> > > > > > > > >         at sun.reflect.
> > >> > GeneratedMethodAccessor137.
> > >> > > > > >> > > invoke(Unknown
> > >> > > > > >> > > > > > > Source)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > sun.reflect.DelegatingMethodAc
> > >> cessorImpl.invoke(
> > >> > > > > >> > > > > > > > > DelegatingMethodAccessorImpl.java:43)
> > >> > > > > >> > > > > > > > >         at java.lang.reflect.Method.invok
> > >> > > > > >> e(Method.java:498)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.tomcat.jdbc.pool.
> > >> > ProxyConnection.invoke(
> > >> > > > > >> > > > > > > > > ProxyConnection.java:126)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.tomcat.jdbc.pool.
> > >> > JdbcInterceptor.invoke(
> > >> > > > > >> > > > > > > > > JdbcInterceptor.java:108)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.tomcat.jdbc.pool.Di
> > >> > > > > >> sposableConnectionFacade.invok
> > >> > > > > >> > e(
> > >> > > > > >> > > > > > > > > DisposableConnectionFacade.java:81)
> > >> > > > > >> > > > > > > > >         at com.sun.proxy.$Proxy58.commit(
> > >> Unknown
> > >> > > > > Source)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.openejb.resource.jd
> > >> bc.managed.local.
> > >> > > > > >> > > > > > LocalXAResource.commit(
> > >> > > > > >> > > > > > > > > LocalXAResource.java:131)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.geronimo.transaction.manager.
> > >> > > > > TransactionImpl.
> > >> > > > > >> > > > > > > commitResource(
> > >> > > > > >> > > > > > > > > TransactionImpl.java:627)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.geronimo.transaction.manager.
> > >> > > > > >> > > TransactionImpl.commit(
> > >> > > > > >> > > > > > > > > TransactionImpl.java:305)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.geronimo.transaction.manager.
> > >> > > > > >> > > > > > TransactionManagerImpl.commit(
> > >> > > > > >> > > > > > > > > TransactionManagerImpl.java:252)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.openejb.core.transaction.
> > >> > > > > JtaTransactionPolicy.
> > >> > > > > >> > > > > > > > > completeTransaction(
> > >> > JtaTransactionPolicy.java:331)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.openejb.core.transa
> > >> > > > > >> ction.TxRequired.commit(TxRequ
> > >> > > > > >> > > > > > > > ired.java:76)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.openejb.core.transaction.
> > >> > > > EjbTransactionUtil.
> > >> > > > > >> > > > > afterInvoke(
> > >> > > > > >> > > > > > > > > EjbTransactionUtil.java:77)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.openejb.core.
> > >> > > > stateless.StatelessContainer._
> > >> > > > > >> > > > > > > > > invoke(StatelessContainer.java:271)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.openejb.core.
> > >> > > stateless.StatelessContainer.
> > >> > > > > >> > > > > > > > > invoke(StatelessContainer.java:212)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.openejb.server.cxf.
> > >> > ejb.EjbMethodInvoker.
> > >> > > > > >> > > > > > > > > preEjbInvoke(EjbMethodInvoker.java:125)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.openejb.server.cxf.
> > >> > > > > >> ejb.EjbMethodInvoker.invoke(
> > >> > > > > >> > > > > > > > > EjbMethodInvoker.java:82)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.cxf.service.invoker
> > >> .AbstractInvoker.
> > >> > > > > >> > > > > > > > > invoke(AbstractInvoker.java:74)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.cxf.interceptor.
> > >> > > > ServiceInvokerInterceptor$1.
> > >> > > > > >> > > > > > > > > run(ServiceInvokerInterceptor.java:59)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > java.util.concurrent.Executors
> > >> $RunnableAdapter.
> > >> > > > > >> > > > > > > call(Executors.java:511)
> > >> > > > > >> > > > > > > > >         at java.util.concurrent.FutureTas
> > >> > > > > >> k.run(FutureTask.
> > >> > > > > >> > > > > java:266)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.cxf.interceptor.
> > >> > > > ServiceInvokerInterceptor$2.
> > >> > > > > >> > > > > > > > > run(ServiceInvokerInterceptor.java:126)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.cxf.workqueue.
> > >> > > SynchronousExecutor.execute(
> > >> > > > > >> > > > > > > > > SynchronousExecutor.java:37)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.cxf.interceptor.
> > >> > > ServiceInvokerInterceptor.
> > >> > > > > >> > > > > handleMessage(
> > >> > > > > >> > > > > > > > > ServiceInvokerInterceptor.java:131)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.cxf.phase.
> PhaseInterceptorChain.
> > >> > > > doIntercept(
> > >> > > > > >> > > > > > > > > PhaseInterceptorChain.java:308)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.cxf.transport.Chain
> > >> > > > > >> InitiationObserver.onMessage(
> > >> > > > > >> > > > > > > > > ChainInitiationObserver.java:121)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.cxf.transport.http.
> > >> > > > > >> AbstractHTTPDestination.invoke
> > >> > > > > >> > (
> > >> > > > > >> > > > > > > > > AbstractHTTPDestination.java:262)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.openejb.server.cxf.
> > >> > > > CxfWsContainer.onMessage(
> > >> > > > > >> > > > > > > > > CxfWsContainer.java:85)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.openejb.server.webs
> > >> > > > > >> ervices.WsServlet.service(WsSe
> > >> > > > > >> > > > > > > > rvlet.java:98)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.catalina.core.Appli
> > >> > > > > >> cationFilterChain.internalDoFi
> > >> > > > > >> > > > lter(
> > >> > > > > >> > > > > > > > > ApplicationFilterChain.java:230)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.catalina.core.Appli
> > >> cationFilterChain.
> > >> > > > > doFilter(
> > >> > > > > >> > > > > > > > > ApplicationFilterChain.java:165)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.catalina.core.
> > >> > > StandardWrapperValve.invoke(
> > >> > > > > >> > > > > > > > > StandardWrapperValve.java:198)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.catalina.core.
> > >> > > StandardContextValve.invoke(
> > >> > > > > >> > > > > > > > > StandardContextValve.java:96)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.catalina.core.
> > >> > StandardHostValve.invoke(
> > >> > > > > >> > > > > > > > > StandardHostValve.java:140)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.catalina.valves.
> > >> > ErrorReportValve.invoke(
> > >> > > > > >> > > > > > > > > ErrorReportValve.java:79)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.tomee.catalina.Open
> > >> > > > > >> EJBSecurityListener$RequestCap
> > >> > > > > >> > > > > > > > turer.invoke(
> > >> > > > > >> > > > > > > > > OpenEJBSecurityListener.java:97)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.catalina.core.
> > >> > > StandardEngineValve.invoke(
> > >> > > > > >> > > > > > > > > StandardEngineValve.java:87)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.catalina.connector.
> > >> > > CoyoteAdapter.service(
> > >> > > > > >> > > > > > > > > CoyoteAdapter.java:349)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.coyote.http11.Http1
> > >> > > > > >> 1Processor.service(Http11Proce
> > >> > > > > >> > > > > > > > ssor.java:783)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.coyote.AbstractProc
> > >> essorLight.process(
> > >> > > > > >> > > > > > > > > AbstractProcessorLight.java:66)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.coyote.AbstractProtocol$
> > >> > > ConnectionHandler.
> > >> > > > > >> > process(
> > >> > > > > >> > > > > > > > > AbstractProtocol.java:798)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.tomcat.util.net.
> > >> > > > NioEndpoint$SocketProcessor.
> > >> > > > > >> > > > > > > > > doRun(NioEndpoint.java:1434)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.tomcat.util.net.
> > >> > SocketProcessorBase.run(
> > >> > > > > >> > > > > > > > > SocketProcessorBase.java:49)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > java.util.concurrent.
> > >> > ThreadPoolExecutor.runWorker(
> > >> > > > > >> > > > > > > > > ThreadPoolExecutor.java:1142)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > java.util.concurrent.
> > >> > ThreadPoolExecutor$Worker.run(
> > >> > > > > >> > > > > > > > > ThreadPoolExecutor.java:617)
> > >> > > > > >> > > > > > > > >         at
> > >> > > > > >> > > > > > > > > org.apache.tomcat.util.threads.TaskThread$
> > >> > > > > >> > > WrappingRunnable.run(
> > >> > > > > >> > > > > > > > > TaskThread.java:61)
> > >> > > > > >> > > > > > > > >         at java.lang.Thread.run(Thread.ja
> > >> va:745)
> > >> > > > > >> > > > > > > > >
> > >> > > > > >> > > > > > > > > 2) Now here is the clients request being
> > >> processed
> > >> > > in
> > >> > > > > our
> > >> > > > > >> EJB
> > >> > > > > >> > > > > looking
> > >> > > > > >> > > > > > > for
> > >> > > > > >> > > > > > > > > the row that was created above but is not
> > >> finished
> > >> > > > > >> committing
> > >> > > > > >> > > > yet.
> > >> > > > > >> > > > > > The
> > >> > > > > >> > > > > > > > row
> > >> > > > > >> > > > > > > > > with ID 615867 is not found.
> > >> > > > > >> > > > > > > > > 2017/04/26 16:22:51.588 FINE
> > >> > > > > >> > > > > > > > >  [TomEE-Exec-10][202][com.
> > >> > > > smilecoms.im.IdentityManager.
> > >> > > > > >> > > > > getCustomers]
> > >> > > > > >> > > > > > > > > |Looking up a single customer with ID
> > [615867]
> > >> > > > > >> > > > > > > > > 3) Here is the sleep having finished.
> > >> > > > > >> > > > > > > > > 2017/04/26 16:22:51.594 FINE
> > >> > > > > >> > > > > > > > >  [TomEE-Exec-15][207][com.smile
> > >> > > > > >> coms.commons.base.lifecycle.
> > >> > > > > >> > > > > > > > > SmileConnectionLifecycleInterc
> eptor.commit]
> > >> > > > > >> > > > > > > > > |Commit sleep finished
> > >> > > > > >> > > > > > > > >
> > >> > > > > >> > > > > > > > > I would expect that only after 2017/04/26
> > >> > > 16:22:51.594
> > >> > > > > >> would
> > >> > > > > >> > > the
> > >> > > > > >> > > > > > client
> > >> > > > > >> > > > > > > > > receive the SOAP response to the insert but
> > >> > clearly
> > >> > > > that
> > >> > > > > >> is
> > >> > > > > >> > not
> > >> > > > > >> > > > the
> > >> > > > > >> > > > > > > case.
> > >> > > > > >> > > > > > > > > It is slowed down by the sleep but there
> > still
> > >> > seems
> > >> > > > to
> > >> > > > > be
> > >> > > > > >> > some
> > >> > > > > >> > > > > race
> > >> > > > > >> > > > > > > > > condition where it somehow can still beat
> the
> > >> > commit
> > >> > > > > >> > returning.
> > >> > > > > >> > > > If
> > >> > > > > >> > > > > > the
> > >> > > > > >> > > > > > > > > commit were called after sending the
> response
> > >> or
> > >> > in
> > >> > > > > >> parallel
> > >> > > > > >> > to
> > >> > > > > >> > > > > doing
> > >> > > > > >> > > > > > > so
> > >> > > > > >> > > > > > > > > then I would have expected the 1000ms sleep
> > to
> > >> not
> > >> > > > > impact
> > >> > > > > >> the
> > >> > > > > >> > > > > > response
> > >> > > > > >> > > > > > > > time
> > >> > > > > >> > > > > > > > > of the service. Very very strange....
> > >> > > > > >> > > > > > > > >
> > >> > > > > >> > > > > > > > > Here is the code snippet of my
> > >> > > > > >> SmileConnectionLifecycleInterc
> > >> > > > > >> > > > > eptor:
> > >> > > > > >> > > > > > > > >
> > >> > > > > >> > > > > > > > > public class SmileConnectionLifecycleInterc
> > >> eptor
> > >> > > > > >> implements
> > >> > > > > >> > > > > > > > > ConnectionLifecycleInterceptor {
> > >> > > > > >> > > > > > > > >
> > >> > > > > >> > > > > > > > >     private static final Logger log =
> > >> > > > > >> > > > > > > > > LoggerFactory.getLogger(
> > >> > > > SmileConnectionLifecycleInterc
> > >> > > > > >> > > > > eptor.class);
> > >> > > > > >> > > > > > > > >
> > >> > > > > >> > > > > > > > >
> > >> > > > > >> > > > > > > > >     @Override
> > >> > > > > >> > > > > > > > >     public boolean commit() throws
> > >> SQLException {
> > >> > > > > >> > > > > > > > >         log.debug("Commit called");
> > >> > > > > >> > > > > > > > >         log.debug("Stack in commit.
> Sleeping
> > >> now:
> > >> > ",
> > >> > > > new
> > >> > > > > >> > > > > > Exception());
> > >> > > > > >> > > > > > > > >         try {
> > >> > > > > >> > > > > > > > >             Thread.sleep(1000);
> > >> > > > > >> > > > > > > > >         } catch (Exception e) {
> > >> > > > > >> > > > > > > > >
> > >> > > > > >> > > > > > > > >         }
> > >> > > > > >> > > > > > > > >         log.debug("Commit sleep finished");
> > >> > > > > >> > > > > > > > >         return true;
> > >> > > > > >> > > > > > > > >     }
> > >> > > > > >> > > > > > > > > ...
> > >> > > > > >> > > > > > > > >
> > >> > > > > >> > > > > > > > >
> > >> > > > > >> > > > > > > > > Any thoughts?
> > >> > > > > >> > > > > > > > >
> > >> > > > > >> > > > > > > > > Paul
> > >> > > > > >> > > > > > > > >
> > >> > > > > >> > > > > > > > > On 26 April 2017 at 13:50, Paul
> Carter-Brown
> > <
> > >> > > > > >> > > > > > > > > paul.carter-br...@smilecoms.com> wrote:
> > >> > > > > >> > > > > > > > >
> > >> > > > > >> > > > > > > > > > Thought so. Let me try and create a
> > >> reproducable
> > >> > > > test
> > >> > > > > >> case
> > >> > > > > >> > > and
> > >> > > > > >> > > > > let
> > >> > > > > >> > > > > > > you
> > >> > > > > >> > > > > > > > > > know what i find
> > >> > > > > >> > > > > > > > > >
> > >> > > > > >> > > > > > > > > > Paul
> > >> > > > > >> > > > > > > > > >
> > >> > > > > >> > > > > > > > > > Sent from my phone. Message may be brief
> > and
> > >> > > contain
> > >> > > > > >> typos.
> > >> > > > > >> > > > > > > > > >
> > >> > > > > >> > > > > > > > > >
> > >> > > > > >> > > > > > > > > > On 26 Apr 2017 13:35, "Romain
> Manni-Bucau"
> > <
> > >> > > > > >> > > > > rmannibu...@gmail.com>
> > >> > > > > >> > > > > > > > > wrote:
> > >> > > > > >> > > > > > > > > >
> > >> > > > > >> > > > > > > > > >> Hi
> > >> > > > > >> > > > > > > > > >>
> > >> > > > > >> > > > > > > > > >> Shouldn't be possible since it would
> > assume
> > >> > this
> > >> > > > > flow:
> > >> > > > > >> > > > > > > > > >>
> > >> > > > > >> > > > > > > > > >> thread1. start tx                  |
> > >> thread2. -
> > >> > > > > >> > > > > > > > > >> thread1. create the entry    | thread2.
> -
> > >> > > > > >> > > > > > > > > >> thread1. serialize the entry | thread2.
> -
> > >> > > > > >> > > > > > > > > >> thread1. commit tx              |
> > thread2. -
> > >> > find
> > >> > > > the
> > >> > > > > >> > entry
> > >> > > > > >> > > > > > > > > >> thread1.                              |
> > >> > thread2.
> > >> > > -
> > >> > > > > >> fails
> > >> > > > > >> > > > > > > > > >>
> > >> > > > > >> > > > > > > > > >> The commit will happen
> > >> > > > > >> > > > > > > > > >> in org.apache.openejb.server.cxf.
> > >> > > > > >> > > ejb.EjbMethodInvoker#invoke
> > >> > > > > >> > > > > > where
> > >> > > > > >> > > > > > > > the
> > >> > > > > >> > > > > > > > > >> serialization happens after
> > >> > > > > >> > > > > > > > > >> in org.apache.cxf.jaxb.io.
> > >> > > > DataWriterImpl#write(java.
> > >> > > > > >> > > > > lang.Object,
> > >> > > > > >> > > > > > > > > >> org.apache.cxf.service.model.M
> > >> essagePartInfo,
> > >> > T)
> > >> > > > > >> > > > > > > > > >>
> > >> > > > > >> > > > > > > > > >> Only case it should be possible to
> happen
> > >> is if
> > >> > > you
> > >> > > > > >> > wrapped
> > >> > > > > >> > > > > jaxws
> > >> > > > > >> > > > > > > > > >> servlet/layer with a custom transaction
> > >> > > management
> > >> > > > > >> > (through
> > >> > > > > >> > > a
> > >> > > > > >> > > > > > filter
> > >> > > > > >> > > > > > > > for
> > >> > > > > >> > > > > > > > > >> instance) which would start/commit
> outside
> > >> > > default
> > >> > > > > >> JAXWS
> > >> > > > > >> > > > > handling.
> > >> > > > > >> > > > > > > > > >>
> > >> > > > > >> > > > > > > > > >>
> > >> > > > > >> > > > > > > > > >> Romain Manni-Bucau
> > >> > > > > >> > > > > > > > > >> @rmannibucau <
> > https://twitter.com/rmannibuc
> > >> au>
> > >> > |
> > >> > > > > Blog
> > >> > > > > >> > > > > > > > > >> <https://blog-rmannibucau.rhcloud.com>
> |
> > >> Old
> > >> > > Blog
> > >> > > > > >> > > > > > > > > >> <http://rmannibucau.wordpress.com> |
> > >> Github <
> > >> > > > > >> > > > > > > > > >> https://github.com/rmannibucau> |
> > >> > > > > >> > > > > > > > > >> LinkedIn <https://www.linkedin.com/in/
> > >> > > rmannibucau>
> > >> > > > |
> > >> > > > > >> > JavaEE
> > >> > > > > >> > > > > > Factory
> > >> > > > > >> > > > > > > > > >> <https://javaeefactory-rmannib
> > >> ucau.rhcloud.com
> > >> > >
> > >> > > > > >> > > > > > > > > >>
> > >> > > > > >> > > > > > > > > >> 2017-04-26 12:59 GMT+02:00 Paul
> > >> Carter-Brown <
> > >> > > > > >> > > > > > > > > >> paul.carter-br...@smilecoms.com>:
> > >> > > > > >> > > > > > > > > >>
> > >> > > > > >> > > > > > > > > >> > Hi
> > >> > > > > >> > > > > > > > > >> >
> > >> > > > > >> > > > > > > > > >> > I have a call flow as follows in
> tomee:
> > >> > > > > >> > > > > > > > > >> >
> > >> > > > > >> > > > > > > > > >> > 1. Client calls jaxws service that
> adds
> > a
> > >> row
> > >> > > > into
> > >> > > > > >> mysql
> > >> > > > > >> > > > > table.
> > >> > > > > >> > > > > > > EJB
> > >> > > > > >> > > > > > > > is
> > >> > > > > >> > > > > > > > > >> > using JTA with eclipselink JPA entity
> > >> bean.
> > >> > > > Seevice
> > >> > > > > >> > > returns
> > >> > > > > >> > > > > the
> > >> > > > > >> > > > > > > > > primary
> > >> > > > > >> > > > > > > > > >> key
> > >> > > > > >> > > > > > > > > >> > of the row just added.
> > >> > > > > >> > > > > > > > > >> > 2. Client uses returned soap message
> > that
> > >> > > > contains
> > >> > > > > >> the
> > >> > > > > >> > > > primary
> > >> > > > > >> > > > > > key
> > >> > > > > >> > > > > > > > and
> > >> > > > > >> > > > > > > > > >> > calls a second service that does a
> > select
> > >> for
> > >> > > the
> > >> > > > > >> row in
> > >> > > > > >> > > > > > question.
> > >> > > > > >> > > > > > > > > >> >
> > >> > > > > >> > > > > > > > > >> > The service in 1 and 2 is in the same
> > >> tomee
> > >> > > > > instance
> > >> > > > > >> and
> > >> > > > > >> > > > > caching
> > >> > > > > >> > > > > > > in
> > >> > > > > >> > > > > > > > > jpa
> > >> > > > > >> > > > > > > > > >> is
> > >> > > > > >> > > > > > > > > >> > disabled. Tx isolation isread
> committed.
> > >> > > > > >> > > > > > > > > >> >
> > >> > > > > >> > > > > > > > > >> > Under high load and concurrency doing
> > >> about
> > >> > > 1000
> > >> > > > > tps
> > >> > > > > >> i
> > >> > > > > >> > get
> > >> > > > > >> > > > > > about a
> > >> > > > > >> > > > > > > > 20%
> > >> > > > > >> > > > > > > > > >> > failure rate where the service at
> stage
> > 2
> > >> > > cannot
> > >> > > > > find
> > >> > > > > >> > the
> > >> > > > > >> > > > row
> > >> > > > > >> > > > > > > > inserted
> > >> > > > > >> > > > > > > > > >> at
> > >> > > > > >> > > > > > > > > >> > stage 1. The row is inserted at some
> > stage
> > >> > as i
> > >> > > > do
> > >> > > > > >> see
> > >> > > > > >> > it
> > >> > > > > >> > > in
> > >> > > > > >> > > > > the
> > >> > > > > >> > > > > > > db.
> > >> > > > > >> > > > > > > > > >> Its as
> > >> > > > > >> > > > > > > > > >> > though service 1 is returning prior to
> > the
> > >> > > > database
> > >> > > > > >> > having
> > >> > > > > >> > > > > > > committed
> > >> > > > > >> > > > > > > > > the
> > >> > > > > >> > > > > > > > > >> > data. My understanding is that this
> > should
> > >> > not
> > >> > > be
> > >> > > > > >> > possible
> > >> > > > > >> > > > as
> > >> > > > > >> > > > > it
> > >> > > > > >> > > > > > > > would
> > >> > > > > >> > > > > > > > > >> > create all sorts of inconsistencies.
> Is
> > >> what
> > >> > i
> > >> > > am
> > >> > > > > >> > > observing
> > >> > > > > >> > > > > > > expected
> > >> > > > > >> > > > > > > > > >> > behaviour?
> > >> > > > > >> > > > > > > > > >> >
> > >> > > > > >> > > > > > > > > >> > Paul
> > >> > > > > >> > > > > > > > > >> >
> > >> > > > > >> > > > > > > > > >> > Sent from my phone. Message may be
> brief
> > >> and
> > >> > > > > contain
> > >> > > > > >> > > typos.
> > >> > > > > >> > > > > > > > > >> >
> > >> > > > > >> > > > > > > > > >> > --
> > >> > > > > >> > > > > > > > > >> >
> > >> > > > > >> > > > > > > > > >> >
> > >> > > > > >> > > > > > > > > >> > This email is subject to the
> disclaimer
> > of
> > >> > > Smile
> > >> > > > > >> > > > > Communications
> > >> > > > > >> > > > > > at
> > >> > > > > >> > > > > > > > > >> > http://www.smilecoms.com/home/
> > >> > > email-disclaimer/
> > >> > > > <
> > >> > > > > >> > > > > > > > > >> http://www.smilecoms.com/
> > >> > > > > >> > > > > > > > > >> > disclaimer>
> > >> > > > > >> > > > > > > > > >> >
> > >> > > > > >> > > > > > > > > >> >
> > >> > > > > >> > > > > > > > > >>
> > >> > > > > >> > > > > > > > > >
> > >> > > > > >> > > > > > > > >
> > >> > > > > >> > > > > > > > >
> > >> > > > > >> > > > > > > > > --
> > >> > > > > >> > > > > > > > >
> > >> > > > > >> > > > > > > > > *Paul Carter-Brown*
> > >> > > > > >> > > > > > > > >
> > >> > > > > >> > > > > > > > > *Group Chief Information Officer*
> > >> > > > > >> > > > > > > > >
> > >> > > > > >> > > > > > > > > *Smile Communications Pty (Ltd)       *
> > >> > > > > >> > > > > > > > > Smile +234 (0) 702 000 1234
> > >> > > > > >> > > > > > > > > Mobile +27 (0) 83 4427 179
> > >> > > > > >> > > > > > > > > Skype PaulC-B
> > >> > > > > >> > > > > > > > > paul.carter-br...@smilecoms.com
> > >> > > > > >> > > > > > > > > www.smilecoms.com
> > >> > > > > >> > > > > > > > >
> > >> > > > > >> > > > > > > > > --
> > >> > > > > >> > > > > > > > >
> > >> > > > > >> > > > > > > > >
> > >> > > > > >> > > > > > > > > This email is subject to the disclaimer of
> > >> Smile
> > >> > > > > >> > Communications
> > >> > > > > >> > > > at
> > >> > > > > >> > > > > > > > > http://www.smilecoms.com/home/
> > >> email-disclaimer/ <
> > >> > > > > >> > > > > > > > http://www.smilecoms.com/
> > >> > > > > >> > > > > > > > > disclaimer>
> > >> > > > > >> > > > > > > > >
> > >> > > > > >> > > > > > > > >
> > >> > > > > >> > > > > > > >
> > >> > > > > >> > > > > > >
> > >> > > > > >> > > > > > >
> > >> > > > > >> > > > > > >
> > >> > > > > >> > > > > > > --
> > >> > > > > >> > > > > > >
> > >> > > > > >> > > > > > > *Paul Carter-Brown*
> > >> > > > > >> > > > > > >
> > >> > > > > >> > > > > > > *Group Chief Information Officer*
> > >> > > > > >> > > > > > >
> > >> > > > > >> > > > > > > *Smile Communications Pty (Ltd)       *
> > >> > > > > >> > > > > > > Smile +234 (0) 702 000 1234
> > >> <+234%20702%20000%201234>
> > >> > > > > >> > > > > > > Mobile +27 (0) 83 4427 179
> > >> > > > > >> > > > > > > Skype PaulC-B
> > >> > > > > >> > > > > > > paul.carter-br...@smilecoms.com
> > >> > > > > >> > > > > > > www.smilecoms.com
> > >> > > > > >> > > > > > >
> > >> > > > > >> > > > > > > --
> > >> > > > > >> > > > > > >
> > >> > > > > >> > > > > > >
> > >> > > > > >> > > > > > > This email is subject to the disclaimer of
> Smile
> > >> > > > > >> Communications
> > >> > > > > >> > at
> > >> > > > > >> > > > > > > http://www.smilecoms.com/home/
> email-disclaimer/
> > <
> > >> > > > > >> > > > > > http://www.smilecoms.com/
> > >> > > > > >> > > > > > > disclaimer>
> > >> > > > > >> > > > > > >
> > >> > > > > >> > > > > > >
> > >> > > > > >> > > > > >
> > >> > > > > >> > > > >
> > >> > > > > >> > > > > --
> > >> > > > > >> > > > >
> > >> > > > > >> > > > >
> > >> > > > > >> > > > > This email is subject to the disclaimer of Smile
> > >> > > > Communications
> > >> > > > > at
> > >> > > > > >> > > > > http://www.smilecoms.com/home/email-disclaimer/ <
> > >> > > > > >> > > > http://www.smilecoms.com/
> > >> > > > > >> > > > > disclaimer>
> > >> > > > > >> > > > >
> > >> > > > > >> > > > >
> > >> > > > > >> > > >
> > >> > > > > >> > >
> > >> > > > > >> > >
> > >> > > > > >> > >
> > >> > > > > >> > > --
> > >> > > > > >> > >
> > >> > > > > >> > > *Paul Carter-Brown*
> > >> > > > > >> > >
> > >> > > > > >> > > *Group Chief Information Officer*
> > >> > > > > >> > >
> > >> > > > > >> > > *Smile Communications Pty (Ltd)       *
> > >> > > > > >> > > Smile +234 (0) 702 000 1234 <+234%20702%20000%201234>
> > >> > > > > >> > > Mobile +27 (0) 83 4427 179
> > >> > > > > >> > > Skype PaulC-B
> > >> > > > > >> > > paul.carter-br...@smilecoms.com
> > >> > > > > >> > > www.smilecoms.com
> > >> > > > > >> > >
> > >> > > > > >> > > --
> > >> > > > > >> > >
> > >> > > > > >> > >
> > >> > > > > >> > > This email is subject to the disclaimer of Smile
> > >> > Communications
> > >> > > at
> > >> > > > > >> > > http://www.smilecoms.com/home/email-disclaimer/ <
> > >> > > > > >> > http://www.smilecoms.com/
> > >> > > > > >> > > disclaimer>
> > >> > > > > >> > >
> > >> > > > > >> > >
> > >> > > > > >> >
> > >> > > > > >> >
> > >> > > > > >> >
> > >> > > > > >>
> > >> > > > > >>
> > >> > > > > >> --
> > >> > > > > >>
> > >> > > > > >> *Paul Carter-Brown*
> > >> > > > > >>
> > >> > > > > >> *Group Chief Information Officer*
> > >> > > > > >>
> > >> > > > > >> *Smile Communications Pty (Ltd)       *
> > >> > > > > >> Smile +234 (0) 702 000 1234
> > >> > > > > >> Mobile +27 (0) 83 4427 179
> > >> > > > > >> Skype PaulC-B
> > >> > > > > >> paul.carter-br...@smilecoms.com
> > >> > > > > >> www.smilecoms.com
> > >> > > > > >>
> > >> > > > > >> --
> > >> > > > > >>
> > >> > > > > >>
> > >> > > > > >> This email is subject to the disclaimer of Smile
> > >> Communications at
> > >> > > > > >> http://www.smilecoms.com/home/email-disclaimer/ <
> > >> > > > > >> http://www.smilecoms.com/disclaimer>
> > >> > > > > >>
> > >> > > > > >>
> > >> > > > >
> > >> > > >
> > >> > > >
> > >> > > >
> > >> > > > --
> > >> > > >
> > >> > > > *Paul Carter-Brown*
> > >> > > >
> > >> > > > *Group Chief Information Officer*
> > >> > > >
> > >> > > > *Smile Communications Pty (Ltd)       *
> > >> > > > Smile +234 (0) 702 000 1234
> > >> > > > Mobile +27 (0) 83 4427 179
> > >> > > > Skype PaulC-B
> > >> > > > paul.carter-br...@smilecoms.com
> > >> > > > www.smilecoms.com
> > >> > > >
> > >> > > > --
> > >> > > >
> > >> > > >
> > >> > > > This email is subject to the disclaimer of Smile Communications
> at
> > >> > > > http://www.smilecoms.com/home/email-disclaimer/ <
> > >> > > http://www.smilecoms.com/
> > >> > > > disclaimer>
> > >> > > >
> > >> > > >
> > >> > >
> > >> >
> > >> >
> > >> >
> > >> > --
> > >> >
> > >> > *Paul Carter-Brown*
> > >> >
> > >> > *Group Chief Information Officer*
> > >> >
> > >> > *Smile Communications Pty (Ltd)       *
> > >> > Smile +234 (0) 702 000 1234
> > >> > Mobile +27 (0) 83 4427 179
> > >> > Skype PaulC-B
> > >> > paul.carter-br...@smilecoms.com
> > >> > www.smilecoms.com
> > >> >
> > >> > --
> > >> >
> > >> >
> > >> > This email is subject to the disclaimer of Smile Communications at
> > >> > http://www.smilecoms.com/home/email-disclaimer/ <
> > >> http://www.smilecoms.com/
> > >> > disclaimer>
> > >> >
> > >> >
> > >>
> > >
> > >
> > >
> > > --
> > >
> > > *Paul Carter-Brown*
> > >
> > > *Group Chief Information Officer*
> > >
> > > *Smile Communications Pty (Ltd)       *
> > > Smile +234 (0) 702 000 1234
> > > Mobile +27 (0) 83 4427 179
> > > Skype PaulC-B
> > > paul.carter-br...@smilecoms.com
> > > www.smilecoms.com
> > >
> > > This email is subject to the disclaimer of Smile Communications at
> > http://www.smilecoms.com/home/email-disclaimer/ <
> http://www.smilecoms.com/
> > disclaimer>
> > >
> > >
> >
>
> --
>
>
> This email is subject to the disclaimer of Smile Communications at
> http://www.smilecoms.com/home/email-disclaimer/ <http://www.smilecoms.com/
> disclaimer>
>
>

Reply via email to