Hi,
I am running a JUnit test that makes several hundred calls (one after the
other) to a web service, running locally. At a certain point, the tests die
with the Axis Fault: read timed out. But this will always happen at a
different point -- some times after 375 tests, sometimes after 400, and so
on.
Any advice on how to troubleshoot this? Read time out is happening after 30
seconds. No errors in my application or axis2 logs, although I included a
little bit of the Axis 2 log after the stack trace.
Thanks, - Dave
===============The stack trace=================================
org.apache.axis2.AxisFault: Read timed out
at org.apache.axis2.AxisFault.makeFault(AxisFault.java:417)
at
org.apache.axis2.transport.http.HTTPSender.sendViaPost(HTTPSender.java:195)
at org.apache.axis2.transport.http.HTTPSender.send(HTTPSender.java:77)
at
org.apache.axis2.transport.http.CommonsHTTPTransportSender.writeMessageWithCommons(CommonsHTTPTransportSender.java:327)
at
org.apache.axis2.transport.http.CommonsHTTPTransportSender.invoke(CommonsHTTPTransportSender.java:206)
at org.apache.axis2.engine.AxisEngine.send(AxisEngine.java:396)
at
org.apache.axis2.description.OutInAxisOperationClient.send(OutInAxisOperation.java:374)
at
org.apache.axis2.description.OutInAxisOperationClient.executeImpl(OutInAxisOperation.java:211)
at
org.apache.axis2.client.OperationClient.execute(OperationClient.java:163)
at
myco.dor.dmv.driver.matching.soap.MatchingServiceStub.match(MatchingServiceStub.java:246)
at
myco.dor.dmv.driver.matching.test.MatchingServiceTest._testMatch(MatchingServiceTest.java:16831)
at
myco.dor.dmv.driver.matching.test.MatchingServiceTest._testMatch(MatchingServiceTest.java:16807)
at
myco.dor.dmv.driver.matching.test.MatchingServiceTest._testMatchCaseType(MatchingServiceTest.java:16607)
at
myco.dor.dmv.driver.matching.test.MatchingServiceTest._testMatchHyphenatedCase(MatchingServiceTest.java:16347)
at
myco.dor.dmv.driver.matching.test.MatchingServiceTest.test413MatchValid_Hyphen(MatchingServiceTest.java:1935)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at junit.framework.TestCase.runTest(TestCase.java:164)
at junit.framework.TestCase.runBare(TestCase.java:130)
at junit.framework.TestResult$1.protect(TestResult.java:106)
at junit.framework.TestResult.runProtected(TestResult.java:124)
at junit.framework.TestResult.run(TestResult.java:109)
at junit.framework.TestCase.run(TestCase.java:120)
at junit.framework.TestSuite.runTest(TestSuite.java:230)
at junit.framework.TestSuite.run(TestSuite.java:225)
at
org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:297)
at
org.apache.tools.ant.taskdefs.optional.junit.JUnitTask.executeInVM(JUnitTask.java:1072)
at
org.apache.tools.ant.taskdefs.optional.junit.JUnitTask.execute(JUnitTask.java:682)
at
org.apache.tools.ant.taskdefs.optional.junit.JUnitTask.executeOrQueue(JUnitTask.java:1434)
at
org.apache.tools.ant.taskdefs.optional.junit.JUnitTask.execute(JUnitTask.java:632)
at org.apache.tools.ant.Task.perform(Task.java:364)
at org.apache.commons.jelly.tags.ant.AntTag.doTag(AntTag.java:195)
at org.apache.commons.jelly.impl.TagScript.run(TagScript.java:250)
at org.apache.commons.jelly.impl.ScriptBlock.run(ScriptBlock.java:95)
at org.apache.commons.jelly.TagSupport.invokeBody(TagSupport.java:186)
at
org.apache.commons.jelly.tags.core.OtherwiseTag.doTag(OtherwiseTag.java:41)
at org.apache.commons.jelly.impl.TagScript.run(TagScript.java:250)
at org.apache.commons.jelly.impl.ScriptBlock.run(ScriptBlock.java:95)
at org.apache.commons.jelly.TagSupport.invokeBody(TagSupport.java:186)
at org.apache.commons.jelly.tags.core.ChooseTag.doTag(ChooseTag.java:38)
at org.apache.commons.jelly.impl.TagScript.run(TagScript.java:250)
at org.apache.commons.jelly.impl.ScriptBlock.run(ScriptBlock.java:95)
at org.apache.commons.jelly.TagSupport.invokeBody(TagSupport.java:186)
at org.apache.commons.jelly.tags.core.IfTag.doTag(IfTag.java:42)
at org.apache.commons.jelly.impl.TagScript.run(TagScript.java:250)
at org.apache.commons.jelly.impl.ScriptBlock.run(ScriptBlock.java:95)
at
org.apache.maven.jelly.tags.werkz.MavenGoalTag.runBodyTag(MavenGoalTag.java:83)
at
org.apache.maven.jelly.tags.werkz.MavenGoalTag$MavenGoalAction.performAction(MavenGoalTag.java:116)
at org.apache.maven.werkz.Goal.fire(Goal.java:691)
at org.apache.maven.werkz.Goal.attain(Goal.java:623)
at
org.apache.maven.plugin.PluginManager.attainGoals(PluginManager.java:712)
at org.apache.maven.MavenSession.attainGoals(MavenSession.java:265)
at org.apache.maven.cli.App.doMain(App.java:307)
at org.apache.maven.cli.App.main(App.java:217)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at com.werken.forehead.Forehead.run(Forehead.java:551)
at com.werken.forehead.Forehead.main(Forehead.java:581)
Caused by: java.net.SocketTimeoutException: Read timed out
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
at java.io.BufferedInputStream.read(BufferedInputStream.java:235)
at
org.apache.commons.httpclient.HttpParser.readRawLine(HttpParser.java:77)
at
org.apache.commons.httpclient.HttpParser.readLine(HttpParser.java:105)
at
org.apache.commons.httpclient.HttpConnection.readLine(HttpConnection.java:1115)
at
org.apache.commons.httpclient.MultiThreadedHttpConnectionManager$HttpConnectionAdapter.readLine(MultiThreadedHttpConnectionManager.java:1373)
at
org.apache.commons.httpclient.HttpMethodBase.readStatusLine(HttpMethodBase.java:1832)
at
org.apache.commons.httpclient.HttpMethodBase.readResponse(HttpMethodBase.java:1590)
at
org.apache.commons.httpclient.HttpMethodBase.execute(HttpMethodBase.java:995)
at
org.apache.commons.httpclient.HttpMethodDirector.executeWithRetry(HttpMethodDirector.java:397)
at
org.apache.commons.httpclient.HttpMethodDirector.executeMethod(HttpMethodDirector.java:170)
at
org.apache.commons.httpclient.HttpClient.executeMethod(HttpClient.java:396)
at
org.apache.commons.httpclient.HttpClient.executeMethod(HttpClient.java:346)
at
org.apache.axis2.transport.http.AbstractHTTPSender.executeMethod(AbstractHTTPSender.java:520)
at
org.apache.axis2.transport.http.HTTPSender.sendViaPost(HTTPSender.java:191)
... 60 more
===========Apache log=========================
...
DEBUG [org.apache.axis2.engine.Phase, resin-tcp-connection-*:8080-969
2009-10-16 07:58:50,913]:
[MessageContext: logID=urn:uuid:E065E1DD5D6A476C6A1255701540653] Invoking
flowComplete() in Phase "MessageOut"
DEBUG [org.apache.axis2.engine.Phase, resin-tcp-connection-*:8080-969
2009-10-16 07:58:50,913]:
[MessageContext: logID=urn:uuid:E065E1DD5D6A476C6A1255701540653] Invoking
flowComplete() in Phase "PolicyDetermination"
DEBUG [org.apache.axis2.engine.Phase, resin-tcp-connection-*:8080-969
2009-10-16 07:58:50,913]:
[MessageContext: logID=urn:uuid:E065E1DD5D6A476C6A1255701540653] Invoking
flowComplete() in Phase "RMPhase"
DEBUG [org.apache.axis2.engine.Phase, resin-tcp-connection-*:8080-969
2009-10-16 07:58:50,913]:
[MessageContext: logID=urn:uuid:E065E1DD5D6A476C6A1255701540653] Invoking
flowComplete() in Phase "OperationOutPhase"
DEBUG [org.apache.axis2.engine.Phase, resin-tcp-connection-*:8080-969
2009-10-16 07:58:50,913]:
[MessageContext: logID=urn:uuid:E065E1DD5D6A476C6A1255701509962] Invoking
flowComplete() in Phase "OperationInPhase"
DEBUG [org.apache.axis2.engine.Phase, resin-tcp-connection-*:8080-969
2009-10-16 07:58:50,913]:
[MessageContext: logID=urn:uuid:E065E1DD5D6A476C6A1255701509962] Invoking
flowComplete() in Phase "RMPhase"
DEBUG [org.apache.axis2.engine.Phase, resin-tcp-connection-*:8080-969
2009-10-16 07:58:50,913]:
[MessageContext: logID=urn:uuid:E065E1DD5D6A476C6A1255701509962] Invoking
flowComplete() in Phase "Dispatch"
DEBUG [org.apache.axis2.engine.Phase, resin-tcp-connection-*:8080-969
2009-10-16 07:58:50,913]:
[MessageContext: logID=urn:uuid:E065E1DD5D6A476C6A1255701509962] Invoking
flowComplete() for Handler 'HTTPLocationBasedDispatcher' in Phase 'Dispatch'
DEBUG [org.apache.axis2.engine.Phase, resin-tcp-connection-*:8080-969
2009-10-16 07:58:50,913]:
[MessageContext: logID=urn:uuid:E065E1DD5D6A476C6A1255701509962] Invoking
flowComplete() for Handler 'SOAPMessageBodyBasedDispatcher' in Phase
'Dispatch'
DEBUG [org.apache.axis2.engine.Phase, resin-tcp-connection-*:8080-969
2009-10-16 07:58:50,913]:
[MessageContext: logID=urn:uuid:E065E1DD5D6A476C6A1255701509962] Invoking
flowComplete() for Handler 'RequestURIOperationDispatcher' in Phase
'Dispatch'
DEBUG [org.apache.axis2.engine.Phase, resin-tcp-connection-*:8080-969
2009-10-16 07:58:50,913]:
[MessageContext: logID=urn:uuid:E065E1DD5D6A476C6A1255701509962] Invoking
flowComplete() for Handler 'SOAPActionBasedDispatcher' in Phase 'Dispatch'
DEBUG [org.apache.axis2.engine.Phase, resin-tcp-connection-*:8080-969
2009-10-16 07:58:50,913]:
[MessageContext: logID=urn:uuid:E065E1DD5D6A476C6A1255701509962] Invoking
flowComplete() for Handler 'RequestURIBasedDispatcher' in Phase 'Dispatch'
DEBUG [org.apache.axis2.engine.Phase, resin-tcp-connection-*:8080-969
2009-10-16 07:58:50,913]:
[MessageContext: logID=urn:uuid:E065E1DD5D6A476C6A1255701509962] Invoking
flowComplete() in Phase "PreDispatch"
DEBUG [org.apache.axis2.engine.Phase, resin-tcp-connection-*:8080-969
2009-10-16 07:58:50,913]:
[MessageContext: logID=urn:uuid:E065E1DD5D6A476C6A1255701509962] Invoking
flowComplete() in Phase "Security"
DEBUG [org.apache.axis2.engine.Phase, resin-tcp-connection-*:8080-969
2009-10-16 07:58:50,914]:
[MessageContext: logID=urn:uuid:E065E1DD5D6A476C6A1255701509962] Invoking
flowComplete() in Phase "Addressing"
DEBUG [org.apache.axis2.engine.Phase, resin-tcp-connection-*:8080-969
2009-10-16 07:58:50,914]:
[MessageContext: logID=urn:uuid:E065E1DD5D6A476C6A1255701509962] Invoking
flowComplete() for Handler 'AddressingBasedDispatcher' in Phase 'Addressing'
DEBUG [org.apache.axis2.engine.Phase, resin-tcp-connection-*:8080-969
2009-10-16 07:58:50,914]:
[MessageContext: logID=urn:uuid:E065E1DD5D6A476C6A1255701509962] Invoking
flowComplete() in Phase "Transport"
DEBUG [org.apache.axis2.engine.Phase, resin-tcp-connection-*:8080-969
2009-10-16 07:58:50,914]:
[MessageContext: logID=urn:uuid:E065E1DD5D6A476C6A1255701509962] Invoking
flowComplete() for Handler 'SOAPActionBasedDispatcher' in Phase 'Transport'
DEBUG [org.apache.axis2.engine.Phase, resin-tcp-connection-*:8080-969
2009-10-16 07:58:50,914]:
[MessageContext: logID=urn:uuid:E065E1DD5D6A476C6A1255701509962] Invoking
flowComplete() for Handler 'RequestURIBasedDispatcher' in Phase 'Transport'
DEBUG [org.apache.axis2.transport.TransportUtils,
resin-tcp-connection-*:8080-969 2009-10-16 07:58:50,914]:
Found RequestResponseTransport returning isResponseWritten()
DEBUG [org.apache.axis2.transport.TransportUtils,
resin-tcp-connection-*:8080-969 2009-10-16 07:58:50,914]:
Entering deleteAttachments()
DEBUG [org.apache.axis2.transport.TransportUtils,
resin-tcp-connection-*:8080-969 2009-10-16 07:58:50,914]:
Exiting deleteAttachments()
=================End Apache log ===========================
--
View this message in context:
http://www.nabble.com/Help-troubleshooting-org.apache.axis2.AxisFault%3A-Read-timed-out-tp25926096p25926096.html
Sent from the Axis - User mailing list archive at Nabble.com.
