the EJB uses REQUIRED_NEW so doesnt use TxRequired, just want to ensure you didnt add dead code cause i cant see the behavior you describe
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-03 15:13 GMT+02:00 Paul Carter-Brown < paul.carter-br...@smilecoms.com>: > Sorry Romain, not sure what you mean? > > On 3 May 2017 at 14:44, Romain Manni-Bucau <rmannibu...@gmail.com> wrote: > > > Just to be sure: you removed from the EJB this annotation?: > > > > @TransactionAttribute(TransactionAttributeType.REQUIRES_NEW) > > > > > > > > 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 23:15 GMT+02:00 Paul Carter-Brown < > > paul.carter-br...@smilecoms.com>: > > > > > Hi, > > > > > > I'm not that familiar with HSQL so maybe my test case is confusing the > > > issue and not adding much value. > > > > > > Any way you can put the attached file in your openejb-core jar to > replace > > > the one in /org/apache/openejb/core/transaction/ > > > > > > It sleeps for 3s on commit. You should notice that any EJB's you call > > that > > > use TxRequired will still respond in normal latency. The source of the > > file > > > is: > > > > > > /* > > > * Licensed to the Apache Software Foundation (ASF) under one or more > > > * contributor license agreements. See the NOTICE file distributed > with > > > * this work for additional information regarding copyright ownership. > > > * The ASF licenses this file to You under the Apache License, Version > > 2.0 > > > * (the "License"); you may not use this file except in compliance with > > > * the License. You may obtain a copy of the License at > > > * > > > * http://www.apache.org/licenses/LICENSE-2.0 > > > * > > > * Unless required by applicable law or agreed to in writing, software > > > * distributed under the License is distributed on an "AS IS" BASIS, > > > * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or > > implied. > > > * See the License for the specific language governing permissions and > > > * limitations under the License. > > > */ > > > > > > package org.apache.openejb.core.transaction; > > > > > > import org.apache.openejb.ApplicationException; > > > import org.apache.openejb.SystemException; > > > > > > import javax.transaction.Transaction; > > > import javax.transaction.TransactionManager; > > > import org.slf4j.Logger; > > > import org.slf4j.LoggerFactory; > > > > > > /** > > > * 17.6.2.2 Required > > > * <p/> > > > * The Container must invoke an enterprise Bean method whose > transaction > > > * attribute is set to Required with a valid transaction context. > > > * <p/> > > > * If a client invokes the enterprise Bean's method while the client is > > > * associated with a transaction context, the container invokes the > > > enterprise > > > * Bean's method in the client's transaction context. > > > * <p/> > > > * If the client invokes the enterprise Bean's method while the client > is > > > not > > > * associated with a transaction context, the container automatically > > > starts a > > > * new transaction before delegating a method call to the enterprise > Bean > > > * business method. The Container automatically enlists all the > resource > > > * managers accessed by the business method with the transaction. If > the > > > * business method invokes other enterprise beans, the Container passes > > the > > > * transaction context with the invocation. The Container attempts to > > > commit the > > > * transaction when the business method has completed. The container > > > performs > > > * the commit protocol before the method result is sent to the client. > > > */ > > > public class TxRequired extends JtaTransactionPolicy { > > > private final Transaction clientTx; > > > private final Transaction currentTx; > > > > > > private static final Logger log = LoggerFactory.getLogger( > > > TxRequired.class); > > > > > > public TxRequired(final TransactionManager transactionManager) > throws > > > SystemException { > > > super(TransactionType.Required, transactionManager); > > > log.warn("In TxRequired constructore"); > > > clientTx = getTransaction(); > > > if (clientTx == null) { > > > log.warn("Client Tx is null"); > > > currentTx = beginTransaction(); > > > } else { > > > log.warn("Client Tx is not null"); > > > currentTx = clientTx; > > > } > > > } > > > > > > public boolean isNewTransaction() { > > > return clientTx == null; > > > } > > > > > > public boolean isClientTransaction() { > > > return !isNewTransaction(); > > > } > > > > > > public Transaction getCurrentTransaction() { > > > log.warn("In getCurrentTransaction"); > > > return currentTx; > > > } > > > > > > 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(); > > > } > > > } > > > } > > > > > > On 2 May 2017 at 22:55, Romain Manni-Bucau <rmannibu...@gmail.com> > > wrote: > > > > > >> Still, it is recoverable > > >> > > >> Said otherwise: with in memory hsqldb SHUTDOWN does pretty much > nothing, > > >> add hsqldb in scope compile and this code instead of your SHUTDOWN: > > >> > > >> final Database hsqldb = DatabaseManager.getDatabase("mem:", "hsqldb", > > >> new HsqlProperties()); > > >> hsqldb.close(1); > > >> > > >> > > >> > > >> 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 20:42 GMT+02:00 Paul Carter-Brown < > > >> paul.carter-br...@smilecoms.com>: > > >> > > >> > 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.Ser > > >> viceInvokerInterceptor$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.Ser > > >> viceInvokerInterceptor$2. > > >> > > > > > run(ServiceInvokerInterceptor.java:126) > > >> > > > > > at org.apache.cxf.workqueue.Synch > > >> ronousExecutor.execute( > > >> > > > > > SynchronousExecutor.java:37) > > >> > > > > > at org.apache.cxf.interceptor.Ser > > >> viceInvokerInterceptor. > > >> > > > > > handleMessage(ServiceInvokerInterceptor.java:131) > > >> > > > > > at org.apache.cxf.phase.PhaseInte > > >> rceptorChain.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.Stand > > >> ardWrapperValve.invoke( > > >> > > > > > StandardWrapperValve.java:198) > > >> > > > > > at org.apache.catalina.core.Stand > > >> ardContextValve.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.Nio > > >> Endpoint$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.transa > > >> ction.TxRequired.commit( > > >> > > > > > TxRequired.java:76) > > >> > > > > > at org.apache.openejb.core.transa > > >> ction.EjbTransactionUtil. > > >> > > > > > afterInvoke(EjbTransactionUtil.java:77) > > >> > > > > > at org.apache.openejb.core.statel > > >> ess.StatelessContainer._ > > >> > > > > > invoke(StatelessContainer.java:271) > > >> > > > > > at org.apache.openejb.core.statel > > >> ess.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.Di > > >> sposableConnectionFacade. > > >> > > > > 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.PhaseInte > > >> rceptorChain@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.in > > >> terceptor.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.smile > > >> coms.commons.base.lifecycle. > > >> > > > > >> > > > SmileConnectionLifecycleInterc > eptor.transactionBegun] > > >> > > > > >> > > > |TransactionBegun called on > > >> [com.mysql.jdbc.JDBC4Connectio > > >> > > > > >> n@7d0cc890] > > >> > > > > >> > > > 2017/05/01 20:35:14.083 FINE > > >> > > > > >> > > > [TomEE-Exec-12][206][com.smile > > >> coms.commons.base.lifecycle. > > >> > > > > >> > > > SmileConnectionLifecycleInterceptor.commit] > > >> > > > > >> > > > |Commit called on [com.mysql.jdbc.JDBC4Connectio > > >> n@7d0cc890] > > >> > > > > >> > > > 2017/05/01 20:35:14.083 FINE > > >> > > > > >> > > > [TomEE-Exec-12][206][com.smile > > >> coms.commons.base.lifecycle. > > >> > > > > >> > > > SmileConnectionLifecycleInterceptor.commit] > > >> > > > > >> > > > |Stack: > > >> > > > > >> > > > java.lang.Exception > > >> > > > > >> > > > at > > >> > > > > >> > > > com.smilecoms.commons.base.lifecycle. > > >> > > > > SmileConnectionLifecycleInterc > > >> > > > > >> > > > eptor.commit(SmileConnectionLi > > >> fecycleInterceptor.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.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. > > 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.transa > > >> ction.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.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. > > webservices.WsServlet.service( > > >> > > > > >> > > WsServlet.java:98) > > >> > > > > >> > > > at > > >> > > > > >> > > > org.apache.catalina.core.ApplicationFilterChain. > > >> > > > internalDoFilter( > > >> > > > > >> > > > 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.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.smile > > >> coms.commons.base.lifecycle. > > >> > > > > >> > > > SmileConnectionLifecycleInterc > > >> eptor.transactionCompleted] > > >> > > > > >> > > > |TransactionCompleted called on [com.mysql.jdbc. > > >> > > > > >> > JDBC4Connection@7d0cc890 > > >> > > > > >> > > ] > > >> > > > > >> > > > 2017/05/01 20:35:14.084 WARNING > > >> > > > > >> > > > [TomEE-Exec-12][206][org.apach > > >> e.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.PhaseInte > > >> rceptorChain@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.Polic > > >> yInInterceptor@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.Sta > > >> xInInterceptor@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.sa > > >> aj.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.Sta > > >> xOutEndingInterceptor@ > > >> > > > 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.Mes > > >> sageSenderInterceptor$ > > >> > > > 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( > > SmileConnectionLifecycleInterc > > >> > eptor. > > >> > > > > >> 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.transa > > >> ction.TxRequired.commit( > > >> > > > > >> > > > > TxRequired.java:76) > > >> > > > > >> > > > > >> at > > >> > > > > >> > > > > >> org.apache.openejb.core.transaction. > > >> > > > EjbTransactionUtil.after > > >> > > > > >> > > > > >> Invoke(EjbTransactionUtil.java:77) > > >> > > > > >> > > > > >> at > > >> > > > > >> > > > > >> org.apache.openejb.core.statel > > >> ess.StatelessContainer._ > > >> > > > invoke > > >> > > > > >> > > > > >> (StatelessContainer.java:271) > > >> > > > > >> > > > > >> at > > >> > > > > >> > > > > >> org.apache.openejb.core.statel > > >> ess.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.Synch > > >> ronousExecutor.execute( > > >> > > > Synchro > > >> > > > > >> > > > > >> nousExecutor.java:37) > > >> > > > > >> > > > > >> at > > >> > > > > >> > > > > >> org.apache.cxf.interceptor.Ser > > >> viceInvokerInterceptor. > > >> > > > 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.Stand > > >> ardWrapperValve.invoke( > > >> > > > Standar > > >> > > > > >> > > > > >> dWrapperValve.java:198) > > >> > > > > >> > > > > >> at > > >> > > > > >> > > > > >> org.apache.catalina.core.Stand > > >> ardContextValve.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.Stand > > >> ardEngineValve.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.AbstractProt > > >> ocol$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.Out > > >> goingChainInterceptor@ > > >> > > > 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-rmannib > > >> ucau.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.lif > > >> ecycle. > > >> > > > > >> > > > > >> > > > > 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.j > > >> ava: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.transa > > >> ction. > > >> > > > > >> > > > > JtaTransactionPolicy. > > >> > > > > >> > > > > >> > > > > > > > > completeTransaction( > > >> > > > > >> > JtaTransactionPolicy.java:331) > > >> > > > > >> > > > > >> > > > > > > > > at > > >> > > > > >> > > > > >> > > > > > > > > org.apache.openejb.core.transa > > >> > > > > >> > > > > >> ction.TxRequired.commit(TxRequ > > >> > > > > >> > > > > >> > > > > > > > ired.java:76) > > >> > > > > >> > > > > >> > > > > > > > > at > > >> > > > > >> > > > > >> > > > > > > > > org.apache.openejb.core.transa > > >> ction. > > >> > > > > >> > > > 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-brown@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> > > >> > > > >> > > > >> > > > > > > > > > > > > -- > > > > > > *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> > >
