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 <[email protected]> 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 <[email protected]> > 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: [email protected] > > > For additional commands, e-mail: [email protected] > > > > > > > > > > > > > > --------------------------------------------------------------------- > To unsubscribe, e-mail: [email protected] > For additional commands, e-mail: [email protected] > > -- Software Engineer, WSO2 Inc http://wso2.org supunk.blogspot.com
