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> > >