You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by Alec Swan <al...@gmail.com> on 2011/08/04 18:26:40 UTC

Tomcat 6.0.32 ClientAbortException java.io.IOException

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


Re: Tomcat 6.0.32 ClientAbortException java.io.IOException

Posted by Rainer Jung <ra...@kippdata.de>.
On 04.08.2011 19:34, 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.
> 
> 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.
> 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?

If it is easily reproducible, you can sniff network traffic and see,
which side closes the connection.

Regards,

Rainer

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


Re: Tomcat 6.0.32 ClientAbortException java.io.IOException

Posted by Alec Swan <al...@gmail.com>.
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 <al...@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


Re: Tomcat 6.0.32 ClientAbortException java.io.IOException

Posted by Alec Swan <al...@gmail.com>.
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


Re: Tomcat 6.0.32 ClientAbortException java.io.IOException

Posted by André Warnier <aw...@ice-sa.com>.
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


Re: Tomcat 6.0.32 ClientAbortException java.io.IOException

Posted by Alec Swan <al...@gmail.com>.
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.

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.
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?

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


Re: Tomcat 6.0.32 ClientAbortException java.io.IOException

Posted by André Warnier <aw...@ice-sa.com>.
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


Re: Tomcat 6.0.32 ClientAbortException java.io.IOException

Posted by Rainer Jung <ra...@kippdata.de>.
On 04.08.2011 18:26, 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

300 seconds sounds like the default Timeout of the Apache Web Server. Is
there an Apache reverse proxy or something similar between the Client
and Tomcat?

As André said: Tomcat has no Timeout on processing the request. If the
request is received and the servlet is processing it, it will not
interrupt it, close the connection or similar.

Regards,

Rainer

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