You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@hc.apache.org by Supun Kamburugamuva <su...@gmail.com> on 2010/03/03 15:06:50 UTC

HTTP Core NIO tries to read the request line twice

Hi,
Hi,

We got the exception[2] from couple of users. But couldn't reproduce this on
our own.

>From the logs it seems that, before this exception
NHttpServiceHandler.inputReady method has being called for the same request.
Also the request line is logged and is perfectly valid. So my conclusion is
HTTP core tries to read the request headers twice and second time it fails.
The exception we got here is generated by a version that uses the Apache
HTTP Core 4.0.beta1. Also this same issue has being observed with the HTTP
Core 4.1.alpha1 as well [1].

Is this a known issue in HTTP Core? Or is there some way that we can avoid
this case? Any help will be greatly appreciated.

Thanks,
Supun..

[1] http://wso2.org/forum/thread/8867

[2] org.apache.http.ProtocolException: Invalid request line:
at
org.apache.http.impl.nio.codecs.AbstractMessageParser.parse(AbstractMessageParser.java:184)
at
org.apache.http.impl.nio.DefaultNHttpServerConnection.consumeInput(DefaultNHttpServerConnection.java:152)
at
org.apache.synapse.transport.nhttp.LoggingNHttpServerIOTarget.consumeInput(LoggingNHttpServerIOTarget.java:154)
at
org.apache.http.impl.nio.DefaultServerIOEventDispatch.inputReady(DefaultServerIOEventDispatch.java:147)
at
org.apache.http.impl.nio.reactor.BaseIOReactor.readable(BaseIOReactor.java:161)
at
org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvent(AbstractIOReactor.java:339)
at
org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvents(AbstractIOReactor.java:319)
at
org.apache.http.impl.nio.reactor.AbstractIOReactor.execute(AbstractIOReactor.java:275)
at
org.apache.http.impl.nio.reactor.BaseIOReactor.execute(BaseIOReactor.java:104)
at
org.apache.http.impl.nio.reactor.AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:528)
at java.lang.Thread.run(Thread.java:636)
Caused by: org.apache.http.ParseException: Invalid request line:
at
org.apache.http.message.BasicLineParser.parseRequestLine(BasicLineParser.java:312)
at
org.apache.http.impl.nio.codecs.HttpRequestParser.createMessage(HttpRequestParser.java:75)
at
org.apache.http.impl.nio.codecs.AbstractMessageParser.parseHeadLine(AbstractMessageParser.java:133)
at
org.apache.http.impl.nio.codecs.AbstractMessageParser.parse(AbstractMessageParser.java:182)

-- 
Software Engineer, WSO2 Inc
http://wso2.org
supunk.blogspot.com

Re: HTTP Core NIO tries to read the request line twice

Posted by Supun Kamburugamuva <su...@gmail.com>.
Hi Oleg,

Thanks for the quick answers.

Supun..

On Thu, Mar 4, 2010 at 6:48 PM, Oleg Kalnichevski <ol...@apache.org> wrote:

> On Thu, 2010-03-04 at 16:51 +0530, Supun Kamburugamuva wrote:
> > Hi Oleg,
> >
> > We found the problem and we could re-produce it.
> >
> > What happens is client sends a request with a invalid content length.
> Actual
> > message size is higher than the content-length. I guess the decoder
> finishes
> > before the full message is read and rest of the message is considered as
> a
> > new message causing the 400 Bad request. Also it seems that the
> > ServiceHandler.exception(final NHttpServerConnection conn, final
> > HttpException e) is not called and HTTP core sends the 400 response
> directly
> > to the client.
> >
> > Does HTTP Core validate the content length? Is there a way to catch this
> > kind of errors and handle them gracefully?
> >
>
> HTTP cannot function properly unless messages are correctly delimited.
> There is really not much that can be done if the Content-Length value is
> miscalculated.
>
> Oleg
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@hc.apache.org
> For additional commands, e-mail: dev-help@hc.apache.org
>
>


-- 
Software Engineer, WSO2 Inc
http://wso2.org
supunk.blogspot.com

Re: HTTP Core NIO tries to read the request line twice

Posted by Oleg Kalnichevski <ol...@apache.org>.
On Thu, 2010-03-04 at 16:51 +0530, Supun Kamburugamuva wrote:
> Hi Oleg,
> 
> We found the problem and we could re-produce it.
> 
> What happens is client sends a request with a invalid content length. Actual
> message size is higher than the content-length. I guess the decoder finishes
> before the full message is read and rest of the message is considered as a
> new message causing the 400 Bad request. Also it seems that the
> ServiceHandler.exception(final NHttpServerConnection conn, final
> HttpException e) is not called and HTTP core sends the 400 response directly
> to the client.
> 
> Does HTTP Core validate the content length? Is there a way to catch this
> kind of errors and handle them gracefully?
> 

HTTP cannot function properly unless messages are correctly delimited.
There is really not much that can be done if the Content-Length value is
miscalculated.

Oleg


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


Re: HTTP Core NIO tries to read the request line twice

Posted by Supun Kamburugamuva <su...@gmail.com>.
Hi Oleg,

We found the problem and we could re-produce it.

What happens is client sends a request with a invalid content length. Actual
message size is higher than the content-length. I guess the decoder finishes
before the full message is read and rest of the message is considered as a
new message causing the 400 Bad request. Also it seems that the
ServiceHandler.exception(final NHttpServerConnection conn, final
HttpException e) is not called and HTTP core sends the 400 response directly
to the client.

Does HTTP Core validate the content length? Is there a way to catch this
kind of errors and handle them gracefully?

Thanks,
Supun..

On Thu, Mar 4, 2010 at 4:18 PM, Oleg Kalnichevski <ol...@apache.org> wrote:

> On Thu, 2010-03-04 at 15:29 +0530, Supun Kamburugamuva wrote:
> > Hi Oleg,
> >
> > Here what happens is first message is sent through synapse to the back
> end.
> > But since the second message (I didn't see a second message headers but
> > there should be a second message) is failed synapse sends 400 bad
> response
> > to the client. Both messages are coming from the same connection. So when
> > the actual response is available client is disconnected because of the
> 400
> > response.
> >
> > One thing I've noticed in Synapse NHTTP code is, ServiceHandler
> inputReady
> > method doesn't disable the events (conn.suspendInput) after decoder is
> > completed. Can this be the cause of the issue?
> >
> > Thanks,
> > Supun..
> >
>
> Hi Supun
>
> I do not know Synapse NHTTP code well enough to be able to give you a
> definitive answer without studying the code first. I am fairly sure,
> though, that the cause of the problem appears to be a blank line at the
> beginning of a new message. You can consider making the message parser
> used by Synapse to be more tolerant to such protocol violations by
> discarding empty lines at the beginning of a new message. HttpCore
> tutorial has a chapter on message parsing / formatting customization.
> Alternatively, you could improve the way Synapse deal with malformed
> messages like that by sending the client 400 status code and gracefully
> handling the client disconnect.
>
> Oleg
>
>
>
> > On Wed, Mar 3, 2010 at 9:48 PM, Oleg Kalnichevski <ol...@apache.org>
> wrote:
> >
> > > On Wed, 2010-03-03 at 19:36 +0530, Supun Kamburugamuva wrote:
> > > > Hi,
> > > > Hi,
> > > >
> > > > We got the exception[2] from couple of users. But couldn't reproduce
> this
> > > on
> > > > our own.
> > > >
> > > > From the logs it seems that, before this exception
> > > > NHttpServiceHandler.inputReady method has being called for the same
> > > request.
> > > > Also the request line is logged and is perfectly valid. So my
> conclusion
> > > is
> > > > HTTP core tries to read the request headers twice and second time it
> > > fails.
> > > > The exception we got here is generated by a version that uses the
> Apache
> > > > HTTP Core 4.0.beta1. Also this same issue has being observed with the
> > > HTTP
> > > > Core 4.1.alpha1 as well [1].
> > > >
> > > > Is this a known issue in HTTP Core? Or is there some way that we can
> > > avoid
> > > > this case? Any help will be greatly appreciated.
> > > >
> > >
> > > Hi Supun
> > >
> > >
> > > 2009-12-09 13:16:57,011 [-] [http-Listener I/O dispatcher-1] DEBUG
> > > ServerHandler HTTP connection [/67.XXX.XXX.XXX:19979]: Input ready
> > > 2009-12-09 13:16:57,012 [-] [http-Listener I/O dispatcher-1] DEBUG
> > > ServerHandler HTTP connection [/67.XXX.XXX.XXX:19979]: Content decoder
> > > [content length: 1438; pos: 0; completed: false]
> > > 2009-12-09 13:16:57,012 [-] [http-Listener I/O dispatcher-1] DEBUG
> > > ServerHandler HTTP connection [/67.XXX.XXX.XXX:19979]: Input ready
> > > 2009-12-09 13:16:57,012 [-] [http-Listener I/O dispatcher-1] DEBUG
> > > ServerHandler HTTP connection [/67.XXX.XXX.XXX:19979]: Content decoder
> > > [content length: 1438; pos: 1438; completed: true]
> > >
> > > You see, the status content decoder is set as completed. That means
> that
> > > the message has been fully processed. Therefore the subsequent event is
> > > triggered for a new message, which most likely likely is preceded with
> > > an empty line. HttpCore is rather strict about HTTP protocol violations
> > > per default and rejects the message as invalid.
> > >
> > > 2009-12-09 13:16:57,031 [-] [http-Listener I/O dispatcher-1] ERROR
> > > ServerHandler HTTP connection [/67.XXX.XXX.XXX:19979]: Invalid request
> > > line:
> > >
> > > Synapse trunk has a new option allowing to log raw message content sent
> > > across the wire (so called wire logging). If you can get the user to
> > > upgrade to the latest Synapse snapshot and reproduce the problem with
> > > the wire logging on, you can examine the raw content of the session
> > > input buffer and see if the problem involves one or two messages.
> > >
> > > Hope this helps
> > >
> > > Oleg
> > >
> > > > Thanks,
> > > > Supun..
> > > >
> > > > [1] http://wso2.org/forum/thread/8867
> > > >
> > > > [2] org.apache.http.ProtocolException: Invalid request line:
> > > > at
> > > >
> > >
> org.apache.http.impl.nio.codecs.AbstractMessageParser.parse(AbstractMessageParser.java:184)
> > > > at
> > > >
> > >
> org.apache.http.impl.nio.DefaultNHttpServerConnection.consumeInput(DefaultNHttpServerConnection.java:152)
> > > > at
> > > >
> > >
> org.apache.synapse.transport.nhttp.LoggingNHttpServerIOTarget.consumeInput(LoggingNHttpServerIOTarget.java:154)
> > > > at
> > > >
> > >
> org.apache.http.impl.nio.DefaultServerIOEventDispatch.inputReady(DefaultServerIOEventDispatch.java:147)
> > > > at
> > > >
> > >
> org.apache.http.impl.nio.reactor.BaseIOReactor.readable(BaseIOReactor.java:161)
> > > > at
> > > >
> > >
> org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvent(AbstractIOReactor.java:339)
> > > > at
> > > >
> > >
> org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvents(AbstractIOReactor.java:319)
> > > > at
> > > >
> > >
> org.apache.http.impl.nio.reactor.AbstractIOReactor.execute(AbstractIOReactor.java:275)
> > > > at
> > > >
> > >
> org.apache.http.impl.nio.reactor.BaseIOReactor.execute(BaseIOReactor.java:104)
> > > > at
> > > >
> > >
> org.apache.http.impl.nio.reactor.AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:528)
> > > > at java.lang.Thread.run(Thread.java:636)
> > > > Caused by: org.apache.http.ParseException: Invalid request line:
> > > > at
> > > >
> > >
> org.apache.http.message.BasicLineParser.parseRequestLine(BasicLineParser.java:312)
> > > > at
> > > >
> > >
> org.apache.http.impl.nio.codecs.HttpRequestParser.createMessage(HttpRequestParser.java:75)
> > > > at
> > > >
> > >
> org.apache.http.impl.nio.codecs.AbstractMessageParser.parseHeadLine(AbstractMessageParser.java:133)
> > > > at
> > > >
> > >
> org.apache.http.impl.nio.codecs.AbstractMessageParser.parse(AbstractMessageParser.java:182)
> > > >
> > >
> > >
> > >
> > > ---------------------------------------------------------------------
> > > To unsubscribe, e-mail: dev-unsubscribe@hc.apache.org
> > > For additional commands, e-mail: dev-help@hc.apache.org
> > >
> > >
> >
> >
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@hc.apache.org
> For additional commands, e-mail: dev-help@hc.apache.org
>
>


-- 
Software Engineer, WSO2 Inc
http://wso2.org
supunk.blogspot.com

Re: HTTP Core NIO tries to read the request line twice

Posted by Oleg Kalnichevski <ol...@apache.org>.
On Thu, 2010-03-04 at 15:29 +0530, Supun Kamburugamuva wrote:
> Hi Oleg,
> 
> Here what happens is first message is sent through synapse to the back end.
> But since the second message (I didn't see a second message headers but
> there should be a second message) is failed synapse sends 400 bad response
> to the client. Both messages are coming from the same connection. So when
> the actual response is available client is disconnected because of the 400
> response.
> 
> One thing I've noticed in Synapse NHTTP code is, ServiceHandler inputReady
> method doesn't disable the events (conn.suspendInput) after decoder is
> completed. Can this be the cause of the issue?
> 
> Thanks,
> Supun..
> 

Hi Supun

I do not know Synapse NHTTP code well enough to be able to give you a
definitive answer without studying the code first. I am fairly sure,
though, that the cause of the problem appears to be a blank line at the
beginning of a new message. You can consider making the message parser
used by Synapse to be more tolerant to such protocol violations by
discarding empty lines at the beginning of a new message. HttpCore
tutorial has a chapter on message parsing / formatting customization.
Alternatively, you could improve the way Synapse deal with malformed
messages like that by sending the client 400 status code and gracefully
handling the client disconnect. 

Oleg  



> On Wed, Mar 3, 2010 at 9:48 PM, Oleg Kalnichevski <ol...@apache.org> wrote:
> 
> > On Wed, 2010-03-03 at 19:36 +0530, Supun Kamburugamuva wrote:
> > > Hi,
> > > Hi,
> > >
> > > We got the exception[2] from couple of users. But couldn't reproduce this
> > on
> > > our own.
> > >
> > > From the logs it seems that, before this exception
> > > NHttpServiceHandler.inputReady method has being called for the same
> > request.
> > > Also the request line is logged and is perfectly valid. So my conclusion
> > is
> > > HTTP core tries to read the request headers twice and second time it
> > fails.
> > > The exception we got here is generated by a version that uses the Apache
> > > HTTP Core 4.0.beta1. Also this same issue has being observed with the
> > HTTP
> > > Core 4.1.alpha1 as well [1].
> > >
> > > Is this a known issue in HTTP Core? Or is there some way that we can
> > avoid
> > > this case? Any help will be greatly appreciated.
> > >
> >
> > Hi Supun
> >
> >
> > 2009-12-09 13:16:57,011 [-] [http-Listener I/O dispatcher-1] DEBUG
> > ServerHandler HTTP connection [/67.XXX.XXX.XXX:19979]: Input ready
> > 2009-12-09 13:16:57,012 [-] [http-Listener I/O dispatcher-1] DEBUG
> > ServerHandler HTTP connection [/67.XXX.XXX.XXX:19979]: Content decoder
> > [content length: 1438; pos: 0; completed: false]
> > 2009-12-09 13:16:57,012 [-] [http-Listener I/O dispatcher-1] DEBUG
> > ServerHandler HTTP connection [/67.XXX.XXX.XXX:19979]: Input ready
> > 2009-12-09 13:16:57,012 [-] [http-Listener I/O dispatcher-1] DEBUG
> > ServerHandler HTTP connection [/67.XXX.XXX.XXX:19979]: Content decoder
> > [content length: 1438; pos: 1438; completed: true]
> >
> > You see, the status content decoder is set as completed. That means that
> > the message has been fully processed. Therefore the subsequent event is
> > triggered for a new message, which most likely likely is preceded with
> > an empty line. HttpCore is rather strict about HTTP protocol violations
> > per default and rejects the message as invalid.
> >
> > 2009-12-09 13:16:57,031 [-] [http-Listener I/O dispatcher-1] ERROR
> > ServerHandler HTTP connection [/67.XXX.XXX.XXX:19979]: Invalid request
> > line:
> >
> > Synapse trunk has a new option allowing to log raw message content sent
> > across the wire (so called wire logging). If you can get the user to
> > upgrade to the latest Synapse snapshot and reproduce the problem with
> > the wire logging on, you can examine the raw content of the session
> > input buffer and see if the problem involves one or two messages.
> >
> > Hope this helps
> >
> > Oleg
> >
> > > Thanks,
> > > Supun..
> > >
> > > [1] http://wso2.org/forum/thread/8867
> > >
> > > [2] org.apache.http.ProtocolException: Invalid request line:
> > > at
> > >
> > org.apache.http.impl.nio.codecs.AbstractMessageParser.parse(AbstractMessageParser.java:184)
> > > at
> > >
> > org.apache.http.impl.nio.DefaultNHttpServerConnection.consumeInput(DefaultNHttpServerConnection.java:152)
> > > at
> > >
> > org.apache.synapse.transport.nhttp.LoggingNHttpServerIOTarget.consumeInput(LoggingNHttpServerIOTarget.java:154)
> > > at
> > >
> > org.apache.http.impl.nio.DefaultServerIOEventDispatch.inputReady(DefaultServerIOEventDispatch.java:147)
> > > at
> > >
> > org.apache.http.impl.nio.reactor.BaseIOReactor.readable(BaseIOReactor.java:161)
> > > at
> > >
> > org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvent(AbstractIOReactor.java:339)
> > > at
> > >
> > org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvents(AbstractIOReactor.java:319)
> > > at
> > >
> > org.apache.http.impl.nio.reactor.AbstractIOReactor.execute(AbstractIOReactor.java:275)
> > > at
> > >
> > org.apache.http.impl.nio.reactor.BaseIOReactor.execute(BaseIOReactor.java:104)
> > > at
> > >
> > org.apache.http.impl.nio.reactor.AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:528)
> > > at java.lang.Thread.run(Thread.java:636)
> > > Caused by: org.apache.http.ParseException: Invalid request line:
> > > at
> > >
> > org.apache.http.message.BasicLineParser.parseRequestLine(BasicLineParser.java:312)
> > > at
> > >
> > org.apache.http.impl.nio.codecs.HttpRequestParser.createMessage(HttpRequestParser.java:75)
> > > at
> > >
> > org.apache.http.impl.nio.codecs.AbstractMessageParser.parseHeadLine(AbstractMessageParser.java:133)
> > > at
> > >
> > org.apache.http.impl.nio.codecs.AbstractMessageParser.parse(AbstractMessageParser.java:182)
> > >
> >
> >
> >
> > ---------------------------------------------------------------------
> > To unsubscribe, e-mail: dev-unsubscribe@hc.apache.org
> > For additional commands, e-mail: dev-help@hc.apache.org
> >
> >
> 
> 



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


Re: HTTP Core NIO tries to read the request line twice

Posted by Supun Kamburugamuva <su...@gmail.com>.
Hi Oleg,

Here what happens is first message is sent through synapse to the back end.
But since the second message (I didn't see a second message headers but
there should be a second message) is failed synapse sends 400 bad response
to the client. Both messages are coming from the same connection. So when
the actual response is available client is disconnected because of the 400
response.

One thing I've noticed in Synapse NHTTP code is, ServiceHandler inputReady
method doesn't disable the events (conn.suspendInput) after decoder is
completed. Can this be the cause of the issue?

Thanks,
Supun..

On Wed, Mar 3, 2010 at 9:48 PM, Oleg Kalnichevski <ol...@apache.org> wrote:

> On Wed, 2010-03-03 at 19:36 +0530, Supun Kamburugamuva wrote:
> > Hi,
> > Hi,
> >
> > We got the exception[2] from couple of users. But couldn't reproduce this
> on
> > our own.
> >
> > From the logs it seems that, before this exception
> > NHttpServiceHandler.inputReady method has being called for the same
> request.
> > Also the request line is logged and is perfectly valid. So my conclusion
> is
> > HTTP core tries to read the request headers twice and second time it
> fails.
> > The exception we got here is generated by a version that uses the Apache
> > HTTP Core 4.0.beta1. Also this same issue has being observed with the
> HTTP
> > Core 4.1.alpha1 as well [1].
> >
> > Is this a known issue in HTTP Core? Or is there some way that we can
> avoid
> > this case? Any help will be greatly appreciated.
> >
>
> Hi Supun
>
>
> 2009-12-09 13:16:57,011 [-] [http-Listener I/O dispatcher-1] DEBUG
> ServerHandler HTTP connection [/67.XXX.XXX.XXX:19979]: Input ready
> 2009-12-09 13:16:57,012 [-] [http-Listener I/O dispatcher-1] DEBUG
> ServerHandler HTTP connection [/67.XXX.XXX.XXX:19979]: Content decoder
> [content length: 1438; pos: 0; completed: false]
> 2009-12-09 13:16:57,012 [-] [http-Listener I/O dispatcher-1] DEBUG
> ServerHandler HTTP connection [/67.XXX.XXX.XXX:19979]: Input ready
> 2009-12-09 13:16:57,012 [-] [http-Listener I/O dispatcher-1] DEBUG
> ServerHandler HTTP connection [/67.XXX.XXX.XXX:19979]: Content decoder
> [content length: 1438; pos: 1438; completed: true]
>
> You see, the status content decoder is set as completed. That means that
> the message has been fully processed. Therefore the subsequent event is
> triggered for a new message, which most likely likely is preceded with
> an empty line. HttpCore is rather strict about HTTP protocol violations
> per default and rejects the message as invalid.
>
> 2009-12-09 13:16:57,031 [-] [http-Listener I/O dispatcher-1] ERROR
> ServerHandler HTTP connection [/67.XXX.XXX.XXX:19979]: Invalid request
> line:
>
> Synapse trunk has a new option allowing to log raw message content sent
> across the wire (so called wire logging). If you can get the user to
> upgrade to the latest Synapse snapshot and reproduce the problem with
> the wire logging on, you can examine the raw content of the session
> input buffer and see if the problem involves one or two messages.
>
> Hope this helps
>
> Oleg
>
> > Thanks,
> > Supun..
> >
> > [1] http://wso2.org/forum/thread/8867
> >
> > [2] org.apache.http.ProtocolException: Invalid request line:
> > at
> >
> org.apache.http.impl.nio.codecs.AbstractMessageParser.parse(AbstractMessageParser.java:184)
> > at
> >
> org.apache.http.impl.nio.DefaultNHttpServerConnection.consumeInput(DefaultNHttpServerConnection.java:152)
> > at
> >
> org.apache.synapse.transport.nhttp.LoggingNHttpServerIOTarget.consumeInput(LoggingNHttpServerIOTarget.java:154)
> > at
> >
> org.apache.http.impl.nio.DefaultServerIOEventDispatch.inputReady(DefaultServerIOEventDispatch.java:147)
> > at
> >
> org.apache.http.impl.nio.reactor.BaseIOReactor.readable(BaseIOReactor.java:161)
> > at
> >
> org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvent(AbstractIOReactor.java:339)
> > at
> >
> org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvents(AbstractIOReactor.java:319)
> > at
> >
> org.apache.http.impl.nio.reactor.AbstractIOReactor.execute(AbstractIOReactor.java:275)
> > at
> >
> org.apache.http.impl.nio.reactor.BaseIOReactor.execute(BaseIOReactor.java:104)
> > at
> >
> org.apache.http.impl.nio.reactor.AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:528)
> > at java.lang.Thread.run(Thread.java:636)
> > Caused by: org.apache.http.ParseException: Invalid request line:
> > at
> >
> org.apache.http.message.BasicLineParser.parseRequestLine(BasicLineParser.java:312)
> > at
> >
> org.apache.http.impl.nio.codecs.HttpRequestParser.createMessage(HttpRequestParser.java:75)
> > at
> >
> org.apache.http.impl.nio.codecs.AbstractMessageParser.parseHeadLine(AbstractMessageParser.java:133)
> > at
> >
> org.apache.http.impl.nio.codecs.AbstractMessageParser.parse(AbstractMessageParser.java:182)
> >
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@hc.apache.org
> For additional commands, e-mail: dev-help@hc.apache.org
>
>


-- 
Software Engineer, WSO2 Inc
http://wso2.org
supunk.blogspot.com

Re: HTTP Core NIO tries to read the request line twice

Posted by Oleg Kalnichevski <ol...@apache.org>.
On Wed, 2010-03-03 at 19:36 +0530, Supun Kamburugamuva wrote:
> Hi,
> Hi,
> 
> We got the exception[2] from couple of users. But couldn't reproduce this on
> our own.
> 
> From the logs it seems that, before this exception
> NHttpServiceHandler.inputReady method has being called for the same request.
> Also the request line is logged and is perfectly valid. So my conclusion is
> HTTP core tries to read the request headers twice and second time it fails.
> The exception we got here is generated by a version that uses the Apache
> HTTP Core 4.0.beta1. Also this same issue has being observed with the HTTP
> Core 4.1.alpha1 as well [1].
> 
> Is this a known issue in HTTP Core? Or is there some way that we can avoid
> this case? Any help will be greatly appreciated.
> 

Hi Supun


2009-12-09 13:16:57,011 [-] [http-Listener I/O dispatcher-1] DEBUG
ServerHandler HTTP connection [/67.XXX.XXX.XXX:19979]: Input ready
2009-12-09 13:16:57,012 [-] [http-Listener I/O dispatcher-1] DEBUG
ServerHandler HTTP connection [/67.XXX.XXX.XXX:19979]: Content decoder
[content length: 1438; pos: 0; completed: false]
2009-12-09 13:16:57,012 [-] [http-Listener I/O dispatcher-1] DEBUG
ServerHandler HTTP connection [/67.XXX.XXX.XXX:19979]: Input ready
2009-12-09 13:16:57,012 [-] [http-Listener I/O dispatcher-1] DEBUG
ServerHandler HTTP connection [/67.XXX.XXX.XXX:19979]: Content decoder
[content length: 1438; pos: 1438; completed: true]

You see, the status content decoder is set as completed. That means that
the message has been fully processed. Therefore the subsequent event is
triggered for a new message, which most likely likely is preceded with
an empty line. HttpCore is rather strict about HTTP protocol violations
per default and rejects the message as invalid.    

2009-12-09 13:16:57,031 [-] [http-Listener I/O dispatcher-1] ERROR
ServerHandler HTTP connection [/67.XXX.XXX.XXX:19979]: Invalid request
line:

Synapse trunk has a new option allowing to log raw message content sent
across the wire (so called wire logging). If you can get the user to
upgrade to the latest Synapse snapshot and reproduce the problem with
the wire logging on, you can examine the raw content of the session
input buffer and see if the problem involves one or two messages.     

Hope this helps

Oleg

> Thanks,
> Supun..
> 
> [1] http://wso2.org/forum/thread/8867
> 
> [2] org.apache.http.ProtocolException: Invalid request line:
> at
> org.apache.http.impl.nio.codecs.AbstractMessageParser.parse(AbstractMessageParser.java:184)
> at
> org.apache.http.impl.nio.DefaultNHttpServerConnection.consumeInput(DefaultNHttpServerConnection.java:152)
> at
> org.apache.synapse.transport.nhttp.LoggingNHttpServerIOTarget.consumeInput(LoggingNHttpServerIOTarget.java:154)
> at
> org.apache.http.impl.nio.DefaultServerIOEventDispatch.inputReady(DefaultServerIOEventDispatch.java:147)
> at
> org.apache.http.impl.nio.reactor.BaseIOReactor.readable(BaseIOReactor.java:161)
> at
> org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvent(AbstractIOReactor.java:339)
> at
> org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvents(AbstractIOReactor.java:319)
> at
> org.apache.http.impl.nio.reactor.AbstractIOReactor.execute(AbstractIOReactor.java:275)
> at
> org.apache.http.impl.nio.reactor.BaseIOReactor.execute(BaseIOReactor.java:104)
> at
> org.apache.http.impl.nio.reactor.AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:528)
> at java.lang.Thread.run(Thread.java:636)
> Caused by: org.apache.http.ParseException: Invalid request line:
> at
> org.apache.http.message.BasicLineParser.parseRequestLine(BasicLineParser.java:312)
> at
> org.apache.http.impl.nio.codecs.HttpRequestParser.createMessage(HttpRequestParser.java:75)
> at
> org.apache.http.impl.nio.codecs.AbstractMessageParser.parseHeadLine(AbstractMessageParser.java:133)
> at
> org.apache.http.impl.nio.codecs.AbstractMessageParser.parse(AbstractMessageParser.java:182)
> 



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