Web Service Timeout on Load Test

Posted by acampbelle1 on 22-May-2012 07:59

I am load testing a web service host inside my Sonic environment. The most recent load test is only 5,000 small transmissions in a matter of a few minutes. It passes well up until the upper 4,000s, then a few (anywhere from one to eight) will receive an operation time out rather quickly (less than a second). I have tried increasing everything I can think of to the max.....

for the hosted web service's properties file - http.maxServerThreads, project.esbconfig.timeoutInterval, http.maxConnections

for endpoint connections - Maximum BEST_EFFORT Sessions, Maximum AT_LEAST_ONCE Sessions, Maximum EXACTLY_ONCE Sessions, Maximum Web Service Sessions, Initial Connect Timeout

But there has been no change. Below is the only error I see in the logs for the web service container. Does anyone have any ideas of what to try? Thanks.

org.apache.cxf.phase.PhaseInterceptorChain doDefaultLogging
WARNING: Interceptor for {urn:HostedWebServices/resources/wsdl/MyProcess}MyProcessService#{urn:HostedWebServices/resources/wsdl/MyProcess}MyProcess has thrown exception, unwinding now
org.apache.cxf.interceptor.Fault: Request to: MyProcess:PROCESS timed out
at org.apache.camel.component.cxf.CxfConsumer$1.checkFailure(CxfConsumer.java:124)
at org.apache.camel.component.cxf.CxfConsumer$1.invoke(CxfConsumer.java:103)
at org.apache.cxf.interceptor.ServiceInvokerInterceptor$1.run(ServiceInvokerInterceptor.java:58)
at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
at java.util.concurrent.FutureTask$Sync.innerRun(Unknown Source)
at java.util.concurrent.FutureTask.run(Unknown Source)
at org.apache.cxf.workqueue.SynchronousExecutor.execute(SynchronousExecutor.java:37)
at org.apache.cxf.interceptor.ServiceInvokerInterceptor.handleMessage(ServiceInvokerInterceptor.java:106)
at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:244)
at org.apache.cxf.transport.ChainInitiationObserver.onMessage(ChainInitiationObserver.java:110)
at org.apache.cxf.transport.http_jetty.JettyHTTPDestination.serviceRequest(JettyHTTPDestination.java:311)
at org.apache.cxf.transport.http_jetty.JettyHTTPDestination.doService(JettyHTTPDestination.java:275)
at org.apache.cxf.transport.http_jetty.JettyHTTPHandler.handle(JettyHTTPHandler.java:70)
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765)
at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230)
at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
at org.mortbay.jetty.Server.handle(Server.java:326)
at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:536)
at org.mortbay.jetty.HttpConnection$RequestHandler.content(HttpConnection.java:930)
at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:747)
at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:212)
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:405)
at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:409)
at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:582)
Caused by: com.sonicsw.xq.XQServiceException: Request to: MyProcess:PROCESS timed out
at com.progress.sonic.esb.camel.DefaultEsbMessageExchange.send(DefaultEsbMessageExchange.java:98)
at com.progress.sonic.esb.camel.SonicEsbProducer.process(SonicEsbProducer.java:105)
at org.apache.camel.processor.SendProcessor$1.doInProducer(SendProcessor.java:102)
at org.apache.camel.processor.SendProcessor$1.doInProducer(SendProcessor.java:100)
at org.apache.camel.impl.ProducerCache.doInProducer(ProducerCache.java:146)
at org.apache.camel.processor.SendProcessor.doProcess(SendProcessor.java:99)
at org.apache.camel.processor.SendProcessor.process(SendProcessor.java:87)
at org.apache.camel.processor.DelegateProcessor.processNext(DelegateProcessor.java:53)
at org.apache.camel.processor.DelegateProcessor.proceed(DelegateProcessor.java:82)
at org.apache.camel.processor.interceptor.TraceInterceptor.process(TraceInterceptor.java:93)
at org.apache.camel.processor.RedeliveryErrorHandler.processExchange(RedeliveryErrorHandler.java:223)
at org.apache.camel.processor.RedeliveryErrorHandler.processErrorHandler(RedeliveryErrorHandler.java:153)
at org.apache.camel.processor.RedeliveryErrorHandler.process(RedeliveryErrorHandler.java:91)
at org.apache.camel.processor.DefaultErrorHandler.process(DefaultErrorHandler.java:49)
at org.apache.camel.processor.DefaultChannel.process(DefaultChannel.java:206)
at org.apache.camel.processor.UnitOfWorkProcessor.processNext(UnitOfWorkProcessor.java:70)
at org.apache.camel.processor.DelegateProcessor.process(DelegateProcessor.java:48)
at org.apache.camel.management.InstrumentationProcessor.process(InstrumentationProcessor.java:67)
at org.apache.camel.component.direct.DirectProducer.process(DirectProducer.java:45)
at com.progress.sonic.esb.camel.DirectSonicEsbProducer.process(DirectSonicEsbProducer.java:51)
at org.apache.camel.processor.SendProcessor$1.doInProducer(SendProcessor.java:102)
at org.apache.camel.processor.SendProcessor$1.doInProducer(SendProcessor.java:100)
at org.apache.camel.impl.ProducerCache.doInProducer(ProducerCache.java:146)
at org.apache.camel.processor.SendProcessor.doProcess(SendProcessor.java:99)
at org.apache.camel.processor.SendProcessor.process(SendProcessor.java:87)
at org.apache.camel.processor.DelegateProcessor.processNext(DelegateProcessor.java:53)
at org.apache.camel.processor.DelegateProcessor.proceed(DelegateProcessor.java:82)
at org.apache.camel.processor.interceptor.TraceInterceptor.process(TraceInterceptor.java:93)
at org.apache.camel.processor.RedeliveryErrorHandler.processExchange(RedeliveryErrorHandler.java:223)
at org.apache.camel.processor.RedeliveryErrorHandler.processErrorHandler(RedeliveryErrorHandler.java:153)
at org.apache.camel.processor.RedeliveryErrorHandler.process(RedeliveryErrorHandler.java:91)
at org.apache.camel.processor.DefaultErrorHandler.process(DefaultErrorHandler.java:49)
at org.apache.camel.processor.DefaultChannel.process(DefaultChannel.java:206)
at org.apache.camel.processor.DelegateProcessor.processNext(DelegateProcessor.java:53)
at org.apache.camel.processor.ChoiceProcessor.process(ChoiceProcessor.java:51)
at org.apache.camel.processor.DelegateProcessor.processNext(DelegateProcessor.java:53)
at org.apache.camel.processor.DelegateProcessor.proceed(DelegateProcessor.java:82)
at org.apache.camel.processor.interceptor.TraceInterceptor.process(TraceInterceptor.java:93)
at org.apache.camel.processor.RedeliveryErrorHandler.processExchange(RedeliveryErrorHandler.java:223)
at org.apache.camel.processor.RedeliveryErrorHandler.processErrorHandler(RedeliveryErrorHandler.java:153)
at org.apache.camel.processor.RedeliveryErrorHandler.process(RedeliveryErrorHandler.java:91)
at org.apache.camel.processor.DefaultErrorHandler.process(DefaultErrorHandler.java:49)
at org.apache.camel.processor.DefaultChannel.process(DefaultChannel.java:206)
at org.apache.camel.processor.UnitOfWorkProcessor.processNext(UnitOfWorkProcessor.java:54)
at org.apache.camel.processor.DelegateProcessor.process(DelegateProcessor.java:48)
at org.apache.camel.management.InstrumentationProcessor.process(InstrumentationProcessor.java:67)
at org.apache.camel.component.cxf.CxfConsumer$1.invoke(CxfConsumer.java:98)
... 22 more

All Replies

Posted by wtam on 22-May-2012 13:57

project.esbconfig.timeoutInterval (in milliseconds) is the parameter to specific how long Sonic Connect would wait for response from the Process.  It looks like the Process is taking extra long to return responses.

Posted by acampbelle1 on 22-May-2012 14:03

Increasing the project.esbconfig.timeoutInterval was the first thing I tried. The issue is that the timeout response is received very quickly on these requests. The consumer I'm using records the time between the request and response and the timeouts are received in less than a second even though the project.esbconfig.timeoutInterval has been set to as much as 300,000 milliseconds. Any ideas what else I can try? It seems as though something is getting overloaded and immediately responding with the error. Thanks.

Posted by wtam on 22-May-2012 14:39

It sounds the receive timeout on your consumer's side (external SOAP client) should be also increased?

Posted by acampbelle1 on 23-May-2012 09:00

The issue is that the client has a timeout of 5 minutes (and the timeout response is received in less than a second), not to mention if I test non-Sonic web services with this same load test that respond much slower they don't cause this error. Any recommendations of how to dig deeper into the issue (increased Sonic logging, process tracking, etc.)? It's going to be difficult because it only shows up in these high traffic situations. Thank you for any recommendations.

Posted by wtam on 23-May-2012 09:28

Is it possible to show the error on the client side?  If it is a read timeout, it is thrown by the client (not the server).

Thanks.

Posted by acampbelle1 on 23-May-2012 13:59

I want to apologize, it appears it was on the client side. How, I'm not for sure because this client application has been used for larger load tests and not had issues, but it was getting too many connections to the host. I changed some settings on it and everything works fine now. Thanks for the assistance, and once again sorry for the trouble.

This thread is closed