Sorry Romain, not sure what you mean? On 3 May 2017 at 14:44, Romain Manni-Bucau <[email protected]> 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 < > [email protected]>: > > > 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 <[email protected]> > 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 < > >> [email protected]>: > >> > >> > 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" <[email protected]> > >> > 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 < > >> > > [email protected]>: > >> > > > >> > > > 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" < > >> [email protected]> > >> > > > 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 < > >> > > > > [email protected]>: > >> > > > > > >> > > > > > 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 < > >> [email protected]> > >> > > > > 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 < > >> > [email protected] > >> > > > > >> > > > > >> 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 < > >> > > > > >> > > [email protected]>: > >> > > > > >> > > > >> > > > > >> > > > 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. > >> > > > > >> > > > SmileConnectionLifecycleInterceptor.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 < > >> > > > > >> [email protected]> > >> > > > > >> > > > 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" < > >> > > > > >> [email protected]> > >> > > > > >> > 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 < > >> > > > > >> > > > > >> [email protected]> 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" > < > >> > > > > >> > > > > [email protected]> > >> > > > > >> > > > > >> > 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 > >> > > > > >> > > > > >> <[email protected] > >> > > > > >> > > > > >> > 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 > < > >> > > > > >> > > > > [email protected]> > >> > > > > >> > > > > >> > > 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 > >> > > > > >> > > > > >> > > <[email protected] > >> > > > > >> > > > > >> > > > 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" < > >> > > > > >> > > > > >> > [email protected] > >> > > > > >> > > > > >> > > > > >> > > > > >> > > > > >> > > > > 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 < > >> > > > > >> > > > > >> > > [email protected] > >> > > > > >> > > > > >> > > > > > >> > > > > >> > > > > >> > > > > > > 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 > >> > > > < > >> > > > > >> > > > > >> > > > > > > > [email protected]>: > >> > > > > >> > > > > >> > > > > > > > > >> > > > > >> > > > > >> > > > > > > > > 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 > >> > > > > < > >> > > > > >> > > > > >> > > > > > > > > [email protected]> > >> > 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" > >> > > > > < > >> > > > > >> > > > > >> > > > > [email protected]> > >> > > > > >> > > > > >> > > > > > > > > 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 > >> > > > > >> > > > > >> > > > > > > > > [email protected] > >> > > > > >> > > > > >> > > > > > > > > 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 > >> > > > > >> > > > > >> > > > > > > [email protected] > >> > > > > >> > > > > >> > > > > > > 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 > >> > > > > >> > > > > >> > > [email protected] > >> > > > > >> > > > > >> > > 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 > >> > > > > >> > > > > >> [email protected] > >> > > > > >> > > > > >> 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 > >> > > > > >> > > > [email protected] > >> > > > > >> > > > 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 > >> > > > > >> > [email protected] > >> > > > > >> > 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 > >> > > > > > [email protected] > >> > > > > > 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 > > [email protected] > > 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 [email protected] 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>
