You can remove the second call to setautocommit. Then setrollbackonly wont be called.
Paul Sent from my phone. Message may be brief and contain typos. On 2 May 2017 7:51 p.m., "Romain Manni-Bucau" <rmannibu...@gmail.com> wrote: > 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> > > > > > -- This email is subject to the disclaimer of Smile Communications at http://www.smilecoms.com/home/email-disclaimer/ <http://www.smilecoms.com/disclaimer>
