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 < >> > > > > >> > > > > >> > > > > > > > > >> [email protected] >> >: >> > > > > >> > > > > >> > > > > > > > > >> >> > > > > >> > > > > >> > > > > > > > > >> > 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> > >
