tomcat-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Alec Swan <alecs...@gmail.com>
Subject Re: Tomcat 6.0.32 ClientAbortException java.io.IOException
Date Thu, 04 Aug 2011 21:27:37 GMT
Here is a little more information.

Tomcat was processing HTTP request for 10 minutes sharp and was
eventually ready to send the response back to the client. So, Tomcat
generated a TCP [FIN, ACK] message with a valid SOAP response.
However, the very next TCP message contained the following error:

"Broken TCP. The acknowledge field is nonzero while the ACK flag is not set."

Thanks,

Alec

On Thu, Aug 4, 2011 at 3:16 PM, Alec Swan <alecswan@gmail.com> wrote:
> Thank you all for your suggestions.
>
> I've been sniffing TCP traffic all day today and noticed the following pattern:
> 1. Client sends an HTTP post to Tomcat
> 2. Tomcat receives the request and takes 15 minutes to process it
> 3. Tomcat eventually completes the request and attempts to write it
> back to the client
> 4. Client never receives the response
>
> So, you are right that the connection is dropped somewhere between the
> client and Tomcat. I removed the load balancer from the equation by
> hitting the app server directly.
>
> I am troubleshooting this in our customer's environment and have no
> idea how to go about tracking down where the connection gets dropped.
> I guess we could somehow track network hops? Any ideas on how to track
> this down?
>
> Thanks,
>
> Alec
>
> On Thu, Aug 4, 2011 at 1:52 PM, André Warnier <aw@ice-sa.com> wrote:
>> Alec Swan wrote:
>>>
>>> Hello,
>>>
>>> I agree that this is not a bug in Tomcat code, but I would appreciate
>>> any help with troubleshooting this.
>>>
>>> Let me tell you about our app. We have a thousands of Metro SOAP
>>> clients which hit our Tomcat server. Some SOAP HTTP requests take over
>>> an hour to process because queries take a very long time to execute in
>>> the database. The clients are configured to never timeout waiting on
>>> the server response.
>>>
>>
>> And could there be something else, between the client and the Tomcat, which
>> could time out if no activity happens on that connection ?
>> (I have known of routers/firewalls which did this, to save on connections to
>> maintain).
>>
>>> So, I can see the following possible causes of the Client Abort
>>> Exception logged by Tomcat:
>>>
>>> 1. The client drops its connection to the server - I would have
>>> expected the client to get some sort of offline exception and
>>> terminate the request. Instead, the client keeps waiting, so maybe
>>> this is not the problem.
>>> 2. Tomcat times out (our connectionTimeout is set to 600000) and
>>> somehow fails to write the response back.
>>
>> I think that you can rule this one out.  The connectionTimeout, if I
>> remember correctly, only applies to the time between
>> - when the client establishes the HTTP connection to Tomcat
>> - and the time when Tomcat receives the actual request on that connection
>> It is essentially meant to avoid attacks where many clients would create
>> connections to Tomcat and never send a request (and thus block threads (or
>> at least connected sockets) for nothing).
>>
>> But check the documentation to see if maybe this parameter value is taken as
>> a default for other unspecified timeouts.
>>
>>> 3. Tomcat's DBCP connection pool times out
>>>
>>> Could anybody help us enable the right kind of logging to verify the
>>> last two possible causes? Can you think of any other ways to
>>> troubleshoot this?
>>>
>>
>> You can set up an AccessLogValve and measure the time taken by each request.
>> And you can take thread dumps, as mentioned previously, to see what these
>> Tomcat threads are really doing while the client is waiting.
>> You can also trace the real packets exchanged via an external protocol
>> analyser such as Wireshark. That will tell you if it is the client dropping
>> the connection, or if something in-between is doing that.  Tomcat logs can
>> only tell you what happens in Tomcat.
>> And for Tomcat, if an intermediate agent is dropping the connection, it will
>> also look like a Client Abort.
>>
>>
>> Generally speaking, I don't think that there are many explanations for a
>> "Client Abort" exception.  If it was Tomcat doing (or not doing) something
>> and aborting the application, the error message would be different.
>> So, considering that this is a clue, and that you have no other clue until
>> now, I would start by examining that as a possible cause, and not other
>> hypothetical scenarios for which you have not seen a clue yet.
>>
>>
>>> Thanks,
>>>
>>> Alec
>>>
>>> On Thu, Aug 4, 2011 at 11:05 AM, André Warnier <aw@ice-sa.com> wrote:
>>>>
>>>> Hi.
>>>>
>>>> It dos not look to me like the problem is in Tomcat per se, but rather in
>>>> the application running inside of Tomcat, and/or the client application.
>>>>
>>>> Let me explain what leads me to that supposition :
>>>>
>>>> - according to (1) and (2) below, the SOAP request was sent by the
>>>> client,
>>>> received by Tomcat, and passed by Tomcat to the corresponding application
>>>>
>>>> Then according to the log, an exception occurs *within the application
>>>> classes* (not inside Tomcat code).  Scrolling down the log, it appears
>>>> that
>>>> :
>>>>
>>>>> Caused by: ClientAbortException: java.io.IOException
>>>>
>>>> That would mean that when the webapp within the Tomcat application is
>>>> trying
>>>> to send some output to the client, it finds the client socket closed (by
>>>> the
>>>> client).
>>>>
>>>> This could happen for instance if the client "got tired of waiting" so to
>>>> speak, hit some internal timeout waiting for a server response, and
>>>> decided
>>>> to give up and close the socket on which it was waiting for a response.
>>>> Then some time later the application tries to send some response, but
>>>> hits
>>>> the closed socket and throws the exception.
>>>>
>>>> That would explain (3) in your list, because from the point of view of
>>>> Tomcat then, this application invocation is finished (with an error, but
>>>> finished).
>>>>
>>>> Now why the application appears in (4) to still be waiting, I can only
>>>> then
>>>> attribute to some logic error in the application : it gave up waiting and
>>>> closed the socket, but still says that it is waiting ?
>>>>
>>>>
>>>> In any case, in a standard configuration, I do not think that Tomcat
>>>> would
>>>> kill an application by its own decision, even if this application took 30
>>>> minutes to return a response.
>>>>
>>>> Maybe a few thread dumps a couple of seconds apart, when Tomcat has
>>>> received
>>>> the SOAP request, may explain what the responding thread is doing that
>>>> takes
>>>> so long before sending a response.  There is information in the Tomcat
>>>> FAQ
>>>> about how to do that.
>>>>
>>>> I would also inspect the client code to check if there is a timeout for a
>>>> server response, and what it does exactly when that timeout is reached.
>>>> A standard browser would have a timeout of approx. 5 minutes, and then it
>>>> would display a page saying "the server is taking too long to respond.."
>>>> etc..
>>>> Biut with other code, it depends on the code.
>>>>
>>>>
>>>> Alec Swan wrote:
>>>>>
>>>>> Hello,
>>>>>
>>>>> We are experiencing a problem on our production servers causing our
>>>>> HTTP clients to hang. I apologize for cross-posting with Metro forum
>>>>> but this is a critical problem for us.
>>>>>
>>>>> It looks like client SOAP HTTP requests get dropped/terminated by
>>>>> Tomcat or metro without notifying the client that request was
>>>>> terminated leaving the client waiting indefinitely for response.
>>>>>
>>>>> Here is what we observed:
>>>>> 1. Client makes a SOAP call to the server
>>>>> 2. Tomcat receives HTTP request and we can see it listed on Tomcat
>>>>> Manager
>>>>> page
>>>>> 3. After about 5 minutes HTTP request disappears from the list of
>>>>> active HTTP request
>>>>> 4. The client is still waiting for response
>>>>>
>>>>> We also noticed the following exception logged in catalina.out. It is
>>>>> thrown around the same time when the problem above occurs but we are
>>>>> not sure if there is a direct correlation between them.
>>>>>
>>>>> Aug 1, 2011 12:07:44 AM
>>>>> com.sun.xml.ws.transport.http.servlet.WSServletDelegate doGet
>>>>>
>>>>> SEVERE: caught throwable
>>>>>
>>>>> javax.xml.ws.WebServiceException: com.ctc.wstx.exc.WstxIOException: null
>>>>>
>>>>>       at
>>>>> com.sun.xml.ws.encoding.StreamSOAPCodec.encode(StreamSOAPCodec.java:112)
>>>>>
>>>>>       at
>>>>>
>>>>> com.sun.xml.ws.encoding.SOAPBindingCodec.encode(SOAPBindingCodec.java:278)
>>>>>
>>>>>       at
>>>>>
>>>>> com.sun.xml.ws.transport.http.HttpAdapter.encodePacket(HttpAdapter.java:383)
>>>>>
>>>>>       at
>>>>>
>>>>> com.sun.xml.ws.transport.http.HttpAdapter.access$100(HttpAdapter.java:93)
>>>>>
>>>>>       at
>>>>>
>>>>> com.sun.xml.ws.transport.http.HttpAdapter$HttpToolkit.handle(HttpAdapter.java:529)
>>>>>
>>>>>       at
>>>>> com.sun.xml.ws.transport.http.HttpAdapter.handle(HttpAdapter.java:288)
>>>>>
>>>>>       at
>>>>>
>>>>> com.sun.xml.ws.transport.http.servlet.ServletAdapter.handle(ServletAdapter.java:143)
>>>>>
>>>>>       at
>>>>>
>>>>> com.sun.xml.ws.transport.http.servlet.WSServletDelegate.doGet(WSServletDelegate.java:155)
>>>>>
>>>>>       at
>>>>>
>>>>> com.sun.xml.ws.transport.http.servlet.WSServletDelegate.doPost(WSServletDelegate.java:189)
>>>>>
>>>>>       at
>>>>>
>>>>> com.sun.xml.ws.transport.http.servlet.WSServlet.doPost(WSServlet.java:76)
>>>>>
>>>>>       at javax.servlet.http.HttpServlet.service(HttpServlet.java:637)
>>>>>
>>>>>       at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
>>>>>
>>>>>       at
>>>>>
>>>>> org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
>>>>>
>>>>>       at
>>>>>
>>>>> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
>>>>>
>>>>>       at
>>>>>
>>>>> org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
>>>>>
>>>>>       at
>>>>>
>>>>> org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
>>>>>
>>>>>       at
>>>>>
>>>>> org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:470)
>>>>>
>>>>>       at
>>>>>
>>>>> org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
>>>>>
>>>>>       at
>>>>>
>>>>> org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
>>>>>
>>>>>       at
>>>>>
>>>>> org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
>>>>>
>>>>>       at
>>>>>
>>>>> org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298)
>>>>>
>>>>>       at
>>>>>
>>>>> org.apache.coyote.http11.Http11AprProcessor.process(Http11AprProcessor.java:864)
>>>>>
>>>>>       at
>>>>>
>>>>> org.apache.coyote.http11.Http11AprProtocol$Http11ConnectionHandler.process(Http11AprProtocol.java:579)
>>>>>
>>>>>       at
>>>>> org.apache.tomcat.util.net.AprEndpoint$Worker.run(AprEndpoint.java:1665)
>>>>>
>>>>>       at java.lang.Thread.run(Unknown Source)
>>>>>
>>>>> Caused by: com.ctc.wstx.exc.WstxIOException: null
>>>>>
>>>>>       at
>>>>>
>>>>> com.ctc.wstx.sw.BaseStreamWriter.finishDocument(BaseStreamWriter.java:1687)
>>>>>
>>>>>       at
>>>>>
>>>>> com.ctc.wstx.sw.BaseStreamWriter.writeEndDocument(BaseStreamWriter.java:585)
>>>>>
>>>>>       at
>>>>> com.sun.xml.ws.message.saaj.SAAJMessage.writeTo(SAAJMessage.java:368)
>>>>>
>>>>>       at
>>>>> com.sun.xml.ws.encoding.StreamSOAPCodec.encode(StreamSOAPCodec.java:109)
>>>>>
>>>>>       ... 24 more
>>>>>
>>>>> Caused by: ClientAbortException: java.io.IOException
>>>>>
>>>>>       at
>>>>>
>>>>> org.apache.catalina.connector.OutputBuffer.doFlush(OutputBuffer.java:319)
>>>>>
>>>>>       at
>>>>> org.apache.catalina.connector.OutputBuffer.flush(OutputBuffer.java:288)
>>>>>
>>>>>       at
>>>>>
>>>>> org.apache.catalina.connector.CoyoteOutputStream.flush(CoyoteOutputStream.java:98)
>>>>>
>>>>>       at com.ctc.wstx.io.UTF8Writer.flush(UTF8Writer.java:99)
>>>>>
>>>>>       at
>>>>> com.ctc.wstx.sw.BufferingXmlWriter.flush(BufferingXmlWriter.java:214)
>>>>>
>>>>>       at
>>>>> com.ctc.wstx.sw.BufferingXmlWriter.close(BufferingXmlWriter.java:194)
>>>>>
>>>>>       at
>>>>>
>>>>> com.ctc.wstx.sw.BaseStreamWriter.finishDocument(BaseStreamWriter.java:1685)
>>>>>
>>>>>       ... 27 more
>>>>>
>>>>> Caused by: java.io.IOException
>>>>>
>>>>>       at
>>>>>
>>>>> org.apache.coyote.http11.InternalAprOutputBuffer.flushBuffer(InternalAprOutputBuffer.java:716)
>>>>>
>>>>>       at
>>>>>
>>>>> org.apache.coyote.http11.InternalAprOutputBuffer.flush(InternalAprOutputBuffer.java:304)
>>>>>
>>>>>       at
>>>>>
>>>>> org.apache.coyote.http11.Http11AprProcessor.action(Http11AprProcessor.java:1021)
>>>>>
>>>>>       at org.apache.coyote.Response.action(Response.java:183)
>>>>>
>>>>>       at
>>>>>
>>>>> org.apache.catalina.connector.OutputBuffer.doFlush(OutputBuffer.java:314)
>>>>>
>>>>>       ... 33 more
>>>>>
>>>>>
>>>>> Any help will be greatly appreciated.
>>>>>
>>>>> Thanks!
>>>>>
>>>>> Alec
>>>>>
>>>>> ---------------------------------------------------------------------
>>>>> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
>>>>> For additional commands, e-mail: users-help@tomcat.apache.org
>>>>>
>>>>>
>>>>
>>>> ---------------------------------------------------------------------
>>>> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
>>>> For additional commands, e-mail: users-help@tomcat.apache.org
>>>>
>>>>
>>>
>>> ---------------------------------------------------------------------
>>> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
>>> For additional commands, e-mail: users-help@tomcat.apache.org
>>>
>>>
>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
>> For additional commands, e-mail: users-help@tomcat.apache.org
>>
>>
>

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Mime
View raw message