You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@hc.apache.org by "Asankha C. Perera" <as...@wso2.com> on 2007/10/14 15:44:11 UTC

Response already committed error when sending error responses on a load test

Hi

When I am doing a load test using Jakarta-HttpComponents-Bench/1.1, I am 
seeing the following stack trace if the load test returns HTTP 500 
responses. This cannot be seen a load test with HTTP 200 responses. Why 
is a connection closed when using keepalives when responding to an HTTP 
500 is this something HTTP forces?

thanks
asankha

Successful Request and Response
-----------------------------------------------
POST /soap/StockQuoteProxy HTTP/1.1
SOAPAction:  urn:getQuote
Content-Length: 311
Content-Type: text/xml; charset=UTF-8
Host: 127.0.0.1
Connection: Keep-Alive
User-Agent: Jakarta-HttpComponents-Bench/1.1
 
<soapenv:Envelope 
xmlns:soapenv="http://schemas.xmlsoap.org/soap/envelope/"> 
   <soapenv:Header/> 
   <soapenv:Body>    
      <m0:getQuote xmlns:m0="http://services.samples/xsd">       
         <m0:request>          
            <m0:symbol>IBM</m0:symbol>       
         </m0:request>    
      </m0:getQuote> 
   </soapenv:Body></soapenv:Envelope>
---------------------------------------------------
HTTP/1.1 200 OK
Content-Type: text/xml; charset=UTF-8
Host: 127.0.0.1
SOAPAction: urn:getQuote
Date: Sun, 14 Oct 2007 13:37:36 GMT
Server: Synapse-HttpComponents-NIO
Transfer-Encoding: chunked
Connection: Keep-Alive
 
f7
<?xml version='1.0' encoding='UTF-8'?>
   <soapenv:Envelope 
xmlns:soapenv="http://schemas.xmlsoap.org/soap/envelope/">
      <soapenv:Body>     
         <m:kpTryLater xmlns:m="http://kp.samples/xsd">
            <m:operation />
         </m:kpTryLater>  
      </soapenv:Body>
   </soapenv:Envelope>
0
-----------------------------------------------

Error Request and Response and Stack trace
-----------------------------------------------
POST /soap/StockQuoteProxy HTTP/1.1
SOAPAction:  urn:getQuote
Content-Length: 311
Content-Type: text/xml; charset=UTF-8
Host: 127.0.0.1
Connection: Keep-Alive
User-Agent: Jakarta-HttpComponents-Bench/1.1
 
<soapenv:Envelope 
xmlns:soapenv="http://schemas.xmlsoap.org/soap/envelope/"> 
   <soapenv:Header/> 
   <soapenv:Body>    
      <m0:getQuote xmlns:m0="http://services.samples/xsd">       
         <m0:request>          
            <m0:symbol>IBM</m0:symbol>       
         </m0:request>    
      </m0:getQuote> 
   </soapenv:Body></soapenv:Envelope>
-----------------------------------------------
HTTP/1.1 500 Internal Server Error
Content-Type: text/xml; charset=UTF-8
Host: 127.0.0.1
SOAPAction: urn:getQuote
Date: Sun, 14 Oct 2007 13:41:36 GMT
Server: Synapse-HttpComponents-NIO
Transfer-Encoding: chunked
Connection: Close
 
166
<?xml version='1.0' encoding='UTF-8'?>
   <soapenv:Envelope 
xmlns:soapenv="http://schemas.xmlsoap.org/soap/envelope/">
      <soapenv:Body>
         <soapenv:Fault>
            <faultcode 
xmlns:tns="http://www.w3.org/2003/05/soap-envelope">tns:Receiver</faultcode>
            <faultstring>**Request Denied - Backend service 
busy**</faultstring>
            <detail />
         </soapenv:Fault>
      </soapenv:Body>
   </soapenv:Envelope>
0
-----------------------------------------------
2007-10-14 19:42:16,834 [127.0.1.1-asankha] [HttpServerWorker-2] ERROR 
ServerHandler Unexpected HTTP protocol error : Response already submitted
org.apache.http.HttpException: Response already submitted
        at 
org.apache.http.impl.nio.DefaultNHttpServerConnection.submitResponse(DefaultNHttpServerConnection.java:201)
        at 
org.apache.synapse.transport.nhttp.LoggingNHttpServerConnection.submitResponse(LoggingNHttpServerConnection.java:54)
        at 
org.apache.synapse.transport.nhttp.ServerHandler.commitResponse(ServerHandler.java:221)
        at 
org.apache.synapse.transport.nhttp.HttpCoreNIOSender.sendAsyncResponse(HttpCoreNIOSender.java:350)
        at 
org.apache.synapse.transport.nhttp.HttpCoreNIOSender.invoke(HttpCoreNIOSender.java:215)
        at org.apache.axis2.engine.AxisEngine.send(AxisEngine.java:396)
        at 
org.apache.synapse.core.axis2.Axis2Sender.sendBack(Axis2Sender.java:104)
        at 
org.apache.synapse.core.axis2.Axis2SynapseEnvironment.send(Axis2SynapseEnvironment.java:170)
        at 
org.apache.synapse.mediators.builtin.SendMediator.mediate(SendMediator.java:97)
        at 
org.apache.synapse.mediators.AbstractListMediator.mediate(AbstractListMediator.java:60)
        at 
org.apache.synapse.mediators.base.SequenceMediator.mediate(SequenceMediator.java:121)
        at 
org.apache.synapse.core.axis2.ProxyServiceMessageReceiver.receive(ProxyServiceMessageReceiver.java:140)
        at org.apache.axis2.engine.AxisEngine.receive(AxisEngine.java:145)
        at 
org.apache.axis2.transport.http.HTTPTransportUtils.processHTTPPostRequest(HTTPTransportUtils.java:275)
        at 
org.apache.synapse.transport.nhttp.ServerWorker.processPost(ServerWorker.java:211)
        at 
org.apache.synapse.transport.nhttp.ServerWorker.run(ServerWorker.java:175)
        at 
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
        at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
        at java.lang.Thread.run(Thread.java:595)


---------------------------------------------------------------------
To unsubscribe, e-mail: httpcomponents-dev-unsubscribe@jakarta.apache.org
For additional commands, e-mail: httpcomponents-dev-help@jakarta.apache.org


Re: Response already committed error when sending error responses on a load test

Posted by Roland Weber <os...@dubioso.net>.
Oleg Kalnichevski wrote:
> 
> While the connection itself may still be re-usable, the associated
> execution context gets messed up to a point, that it simply makes no
> sense to keep the connection alive.

I see. So this is an implementation issue because execution contexts
are associated with the connection rather than the request/response.
Let's put a comment in the code and leave the behavior as it is.

cheers,
  Roland


---------------------------------------------------------------------
To unsubscribe, e-mail: httpcomponents-dev-unsubscribe@jakarta.apache.org
For additional commands, e-mail: httpcomponents-dev-help@jakarta.apache.org


Re: Response already committed error when sending error responses on a load test

Posted by Oleg Kalnichevski <ol...@apache.org>.
On Sun, 2007-10-14 at 18:22 +0200, Roland Weber wrote:
> Hi Oleg,
> 
> > The 'connection: close' header is added by the ResponseConnControl
> > protocol interceptor [1]. In many cases 500 status code represents a
> > fatal error, which may leave the connection in an inconsistent state.
> 
> The connection itself should be in a consistent state, since it
> is used to send an error response. I can imagine that the response
> object may be in an inconsistent state. But then it should not be
> used for sending the response in the first place, right?
> 
> > Therefore, I think it is a reasonable defensive measure to drop the
> > connection.
> 
> I can live with that. But maybe we should discuss where exactly
> inconsistencies may occur, and whether dropping the connection
> helps to solve them.
> 

While the connection itself may still be re-usable, the associated
execution context gets messed up to a point, that it simply makes no
sense to keep the connection alive.

Oleg 


> cheers,
>   Roland
> 
> 
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: httpcomponents-dev-unsubscribe@jakarta.apache.org
> For additional commands, e-mail: httpcomponents-dev-help@jakarta.apache.org
> 
> 


---------------------------------------------------------------------
To unsubscribe, e-mail: httpcomponents-dev-unsubscribe@jakarta.apache.org
For additional commands, e-mail: httpcomponents-dev-help@jakarta.apache.org


Re: Response already committed error when sending error responses on a load test

Posted by Roland Weber <os...@dubioso.net>.
Hi Oleg,

> The 'connection: close' header is added by the ResponseConnControl
> protocol interceptor [1]. In many cases 500 status code represents a
> fatal error, which may leave the connection in an inconsistent state.

The connection itself should be in a consistent state, since it
is used to send an error response. I can imagine that the response
object may be in an inconsistent state. But then it should not be
used for sending the response in the first place, right?

> Therefore, I think it is a reasonable defensive measure to drop the
> connection.

I can live with that. But maybe we should discuss where exactly
inconsistencies may occur, and whether dropping the connection
helps to solve them.

cheers,
  Roland


---------------------------------------------------------------------
To unsubscribe, e-mail: httpcomponents-dev-unsubscribe@jakarta.apache.org
For additional commands, e-mail: httpcomponents-dev-help@jakarta.apache.org


Re: Response already committed error when sending error responses on a load test

Posted by Oleg Kalnichevski <ol...@apache.org>.
On Mon, 2007-10-15 at 08:56 +0200, Ortwin Glück wrote:
> 
> > The 'connection: close' header is added by the ResponseConnControl
> > protocol interceptor [1]. In many cases 500 status code represents a
> > fatal error, which may leave the connection in an inconsistent state.
> 
> This is definitely wrong behaviour. A 500 status code does not affect
> consistency of a connection.
> 
> Odi
> 

Hi Odi

Of course, the status code itself does not affect consistency of a
connection, but the exception that leads to it often does.

Anyways, I do agree that dropping connections indiscriminately on all
500 responses is probably too much.

Oleg


> ---------------------------------------------------------------------
> To unsubscribe, e-mail: httpcomponents-dev-unsubscribe@jakarta.apache.org
> For additional commands, e-mail: httpcomponents-dev-help@jakarta.apache.org
> 
> 


---------------------------------------------------------------------
To unsubscribe, e-mail: httpcomponents-dev-unsubscribe@jakarta.apache.org
For additional commands, e-mail: httpcomponents-dev-help@jakarta.apache.org


Re: Response already committed error when sending error responses on a load test

Posted by Ortwin Glück <od...@odi.ch>.

> The 'connection: close' header is added by the ResponseConnControl
> protocol interceptor [1]. In many cases 500 status code represents a
> fatal error, which may leave the connection in an inconsistent state.

This is definitely wrong behaviour. A 500 status code does not affect
consistency of a connection.

Odi

---------------------------------------------------------------------
To unsubscribe, e-mail: httpcomponents-dev-unsubscribe@jakarta.apache.org
For additional commands, e-mail: httpcomponents-dev-help@jakarta.apache.org


Re: Response already committed error when sending error responses on a load test

Posted by "Asankha C. Perera" <as...@wso2.com>.
Hi Oleg, Roland

Thanks for your prompt responses..
> The 'connection: close' header is added by the ResponseConnControl
> protocol interceptor [1]. In many cases 500 status code represents a
> fatal error, which may leave the connection in an inconsistent state.
> Therefore, I think it is a reasonable defensive measure to drop the
> connection.
>
> Do you want this changed? 
>   
Since we are dealing with SOAP messages, the SOAP spec states that a 
SOAP fault should be in a response with a HTTP 500 error. In our case 
this does not mean that anything is messed up with the HTTP connection. 
The point that makes me think something is not right is that this causes 
the 'Response already committed' error - whereas when load testing with 
non-error replies, things are fine. Let me look at the protocol 
interceptor and get back to you on this

thanks
asankha

---------------------------------------------------------------------
To unsubscribe, e-mail: httpcomponents-dev-unsubscribe@jakarta.apache.org
For additional commands, e-mail: httpcomponents-dev-help@jakarta.apache.org


Re: Response already committed error when sending error responses on a load test

Posted by Oleg Kalnichevski <ol...@apache.org>.
On Sun, 2007-10-14 at 16:37 +0200, Roland Weber wrote:
> Asankha C. Perera wrote:
> > When I am doing a load test using Jakarta-HttpComponents-Bench/1.1, I am
> > seeing the following stack trace if the load test returns HTTP 500
> > responses. This cannot be seen a load test with HTTP 200 responses. Why
> > is a connection closed when using keepalives when responding to an HTTP
> > 500 is this something HTTP forces?
> 
> I can't tell how your stack trace relates to that question.
> HTTP 1.1 does not require connections to be closed after a
> server error response. In fact, it says in section 8.1.2:
> 
>    ... the client
>    SHOULD assume that the server will maintain a persistent connection,
>    even after error responses from the server.
> 
> However, that's not a MUST. Clients are allowed to close
> connections after an error response.
> The default strategy in HttpCore does not check the response status.
> It checks for a "Connection:" header. Does your server happen to
> send "Connection: close" in case of a status 500?
> 
> cheers,
>   Roland
> 

Asankha, Roland

The 'connection: close' header is added by the ResponseConnControl
protocol interceptor [1]. In many cases 500 status code represents a
fatal error, which may leave the connection in an inconsistent state.
Therefore, I think it is a reasonable defensive measure to drop the
connection.

Do you want this changed? 

Oleg

[1]
https://svn.apache.org/repos/asf/jakarta/httpcomponents/httpcore/trunk/module-main/src/main/java/org/apache/http/protocol/ResponseConnControl.java



> 
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: httpcomponents-dev-unsubscribe@jakarta.apache.org
> For additional commands, e-mail: httpcomponents-dev-help@jakarta.apache.org
> 
> 


---------------------------------------------------------------------
To unsubscribe, e-mail: httpcomponents-dev-unsubscribe@jakarta.apache.org
For additional commands, e-mail: httpcomponents-dev-help@jakarta.apache.org


Re: Response already committed error when sending error responses on a load test

Posted by Roland Weber <os...@dubioso.net>.
Asankha C. Perera wrote:
> When I am doing a load test using Jakarta-HttpComponents-Bench/1.1, I am
> seeing the following stack trace if the load test returns HTTP 500
> responses. This cannot be seen a load test with HTTP 200 responses. Why
> is a connection closed when using keepalives when responding to an HTTP
> 500 is this something HTTP forces?

I can't tell how your stack trace relates to that question.
HTTP 1.1 does not require connections to be closed after a
server error response. In fact, it says in section 8.1.2:

   ... the client
   SHOULD assume that the server will maintain a persistent connection,
   even after error responses from the server.

However, that's not a MUST. Clients are allowed to close
connections after an error response.
The default strategy in HttpCore does not check the response status.
It checks for a "Connection:" header. Does your server happen to
send "Connection: close" in case of a status 500?

cheers,
  Roland


---------------------------------------------------------------------
To unsubscribe, e-mail: httpcomponents-dev-unsubscribe@jakarta.apache.org
For additional commands, e-mail: httpcomponents-dev-help@jakarta.apache.org


Re: Response already committed error when sending error responses on a load test

Posted by Oleg Kalnichevski <ol...@apache.org>.
On Sun, 2007-10-14 at 19:14 +0530, Asankha C. Perera wrote:
> Hi
> 
> When I am doing a load test using Jakarta-HttpComponents-Bench/1.1, I am 
> seeing the following stack trace if the load test returns HTTP 500 
> responses. This cannot be seen a load test with HTTP 200 responses. Why 
> is a connection closed when using keepalives when responding to an HTTP 
> 500 is this something HTTP forces?
> 
> thanks
> asankha
> 

...

> -----------------------------------------------
> 2007-10-14 19:42:16,834 [127.0.1.1-asankha] [HttpServerWorker-2] ERROR 
> ServerHandler Unexpected HTTP protocol error : Response already submitted
> org.apache.http.HttpException: Response already submitted
>         at 
> org.apache.http.impl.nio.DefaultNHttpServerConnection.submitResponse(DefaultNHttpServerConnection.java:201)
>         at 
> org.apache.synapse.transport.nhttp.LoggingNHttpServerConnection.submitResponse(LoggingNHttpServerConnection.java:54)
>         at 
> org.apache.synapse.transport.nhttp.ServerHandler.commitResponse(ServerHandler.java:221)
>         at 
> org.apache.synapse.transport.nhttp.HttpCoreNIOSender.sendAsyncResponse(HttpCoreNIOSender.java:350)
>         at 
> org.apache.synapse.transport.nhttp.HttpCoreNIOSender.invoke(HttpCoreNIOSender.java:215)
>         at org.apache.axis2.engine.AxisEngine.send(AxisEngine.java:396)
>         at 

Asankha,

The cause of this exception is likely to be a bug in the protocol
handler. This exception can happen when if the handler initially submits
an OK response, then starts streaming out the content, runs into a
problem of some kind in the process of doing so, and then attempts to
submit an 5xx status code. 

Oleg

> org.apache.synapse.core.axis2.Axis2Sender.sendBack(Axis2Sender.java:104)
>         at 
> org.apache.synapse.core.axis2.Axis2SynapseEnvironment.send(Axis2SynapseEnvironment.java:170)
>         at 
> org.apache.synapse.mediators.builtin.SendMediator.mediate(SendMediator.java:97)
>         at 
> org.apache.synapse.mediators.AbstractListMediator.mediate(AbstractListMediator.java:60)
>         at 
> org.apache.synapse.mediators.base.SequenceMediator.mediate(SequenceMediator.java:121)
>         at 
> org.apache.synapse.core.axis2.ProxyServiceMessageReceiver.receive(ProxyServiceMessageReceiver.java:140)
>         at org.apache.axis2.engine.AxisEngine.receive(AxisEngine.java:145)
>         at 
> org.apache.axis2.transport.http.HTTPTransportUtils.processHTTPPostRequest(HTTPTransportUtils.java:275)
>         at 
> org.apache.synapse.transport.nhttp.ServerWorker.processPost(ServerWorker.java:211)
>         at 
> org.apache.synapse.transport.nhttp.ServerWorker.run(ServerWorker.java:175)
>         at 
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
>         at 
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
>         at java.lang.Thread.run(Thread.java:595)
> 
> 
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: httpcomponents-dev-unsubscribe@jakarta.apache.org
> For additional commands, e-mail: httpcomponents-dev-help@jakarta.apache.org
> 
> 


---------------------------------------------------------------------
To unsubscribe, e-mail: httpcomponents-dev-unsubscribe@jakarta.apache.org
For additional commands, e-mail: httpcomponents-dev-help@jakarta.apache.org