synapse-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Hubert, Eric" <Eric.Hub...@foxmobile.com>
Subject RE: HttpCoreNIOListener$1 - System may be unstable: IOReactor encountered a runtime exception : null
Date Tue, 28 Apr 2009 21:53:41 GMT
Hi Andreas,

are you sure this is the same issue? 

What I observe when testing your described scenario is a NPE in ServerHandler#outputReady
(ContentOutputBuffer outBuf as context attribute synapse.response-source-buffer seems to be
null.

Reason:
In DefaultNHttpServerConnection#consumeInput the HeadLine is parsed using BasicLineParser
which throws a parse exception "Invalid request line: <bufferconent>" which is caught
in AbstractMessageParser and wrapped inside a ProtocolException reusing the message. This
one is again caught in DefaultNHttpServerConnection as a subclass of HttpException, resetting
the input and calling exception() on the NHttpServiceHandler (in our case LoggingNHttpServiceHandler).
We are now in "Synapse land" logging the error and delegating to NHttpServiceHandler#exception
(in our case ServerHandler).
We don't get a request line, thus defaulting to HTTP 1.0 and construct a BAD Request response
(400), calling #commitResponseHideExceptions.

We are writing the response LoggingNHttpServerIOTarget#produceOutput --> DefaultNHttpServerConnection#produceOutput
--> LoggingNHttpServiceHandler #outputReady --> ServerHandler#outputReady

int bytesWritten = outBuf.produceContent(encoder);

causes NPE, as outBuf is null.

This runtime exception is caught in BaseIOReactor#writable and delegated to the registered
exception handler (in our case an anonymous inner class of HttpCoreNIOListener with the following
implementation:

ioReactor.setExceptionHandler(new IOReactorExceptionHandler() {
                public boolean handle(IOException ioException) {
                    log.warn("System may be unstable: IOReactor encountered a checked exception
: "
                            + ioException.getMessage(), ioException);
                    return true;
                }

                public boolean handle(RuntimeException runtimeException) {
                    log.warn("System may be unstable: IOReactor encountered a runtime exception
: "
                            + runtimeException.getMessage(), runtimeException);
                    return true;
                }
            });

I wondering a bit about the return value. Taken from the JavaDoc of the interface IOReactorExceptionHandler#handle

True if it is safe to ignore the exception and continue execution of the I/O reactor; if the
I/O reactor must throw {@link RuntimeException} and terminate 

Hmm, is it really safe to proceed here? We do not test any detail of the RuntimeException.
To me this looks wrong.

This puts us in an endless loop.

I guess Asankha should be in the best position to comment on this. I just wanted to throw
in my quick observations on this one.

Regards,
  Eric



> -----Original Message-----
> From: Andreas Veithen [mailto:andreas.veithen@gmail.com]
> Sent: Tuesday, April 28, 2009 8:51 PM
> To: dev@synapse.apache.org
> Subject: Re: HttpCoreNIOListener$1 - System may be unstable: IOReactor
> encountered a runtime exception : null
> 
> The problem can easily be reproduced with a current snapshot build:
> - Start Synapse
> - Do a telnet localhost 8280
> - Hit enter
> 
> Andreas
> 
> On Tue, Apr 28, 2009 at 19:53, Hubert, Eric <Eric.Hubert@foxmobile.com>
> wrote:
> > Hi all,
> >
> > Hmmm, I'm actually not sure, if the issue pointed out by Paul is really
> the cause of the problem.
> >
> > Too me it looks like the status line of an HTTP request is parsed by the
> BasicLineParse which throws an exception complaining about an invalid
> protocol version (consisting of protocol name, separator and major.minor).
> >
> > According to the output read from the buffer, this string is: "
> HTTP\1.1"
> > I'm not completely sure, but I guess the trailing space will be skipped,
> but what about the separator "\". Shouldn't this be "/"?
> >
> > If the character followed by the protocol name (HTTP) is not "/" this
> exception will be thrown. Any possibility "/" changes to "\" at some
> point?
> >
> > Regards,
> >   Eric
> >
> >
> >
> >> -----Original Message-----
> >> From: Paul Fremantle [mailto:pzfreo@gmail.com]
> >> Sent: Tuesday, April 28, 2009 6:32 PM
> >> To: dev@synapse.apache.org
> >> Subject: Re: HttpCoreNIOListener$1 - System may be unstable: IOReactor
> >> encountered a runtime exception : null
> >>
> >> Murali
> >>
> >> Its probably this:
> >>
> >> https://issues.apache.org/jira/browse/SYNAPSE-341
> >>
> >> Paul
> >>
> >> On Tue, Apr 28, 2009 at 3:39 PM, cmurali <chakravarthym@sddc.army.mil>
> >> wrote:
> >> >
> >> > I am seeing the following in my synapse log after which the server
> >> becomes
> >> > non-responsive. I have no other go except to just restart synapse. Is
> >> there
> >> > any fix for this?
> >> >
> >> > Thanks,
> >> > Muralidaran Chakravarthy
> >> >
> >> >
> >> > INFO   | jvm 1    | 2009/04/27 18:17:11 | [I/O dispatcher 3] DEBUG
> >> > LoggingNHttpServiceHandler - HTTP connection [/144.100.83.31:1095]:
> GET
> >> /?
> >> > HTTP/1.0
> >> > INFO   | jvm 1    | 2009/04/27 18:17:11 | [I/O dispatcher 4] DEBUG
> >> > LoggingNHttpServiceHandler - HTTP connection [/144.100.83.31:1094]:
> >> > Connected
> >> > INFO   | jvm 1    | 2009/04/27 18:17:11 | [I/O dispatcher 3] DEBUG
> >> > LoggingNHttpServiceHandler - HTTP connection [/144.100.83.31:1091]:
> GET
> >> /?
> >> > HTTP/1.1
> >> > INFO   | jvm 1    | 2009/04/27 18:17:11 | [I/O dispatcher 4] ERROR
> >> > LoggingNHttpServiceHandler - HTTP connection [/144.100.83.31:1092]:
> Not
> >> a
> >> > valid protocol version:  HTTP\1.1
> >> > INFO   | jvm 1    | 2009/04/27 18:17:11 |
> >> org.apache.http.ProtocolException:
> >> > Not a valid protocol version:  HTTP\1.1
> >> > INFO   | jvm 1    | 2009/04/27 18:17:11 |       at
> >> >
> >>
> org.apache.http.impl.nio.codecs.AbstractMessageParser.parse(AbstractMessag
> >> eParser.java:159)
> >> > INFO   | jvm 1    | 2009/04/27 18:17:11 |       at
> >> >
> >>
> org.apache.http.impl.nio.DefaultNHttpServerConnection.consumeInput(Default
> >> NHttpServerConnection.java:114)
> >> > INFO   | jvm 1    | 2009/04/27 18:17:11 |       at
> >> >
> >>
> org.apache.synapse.transport.nhttp.PlainServerIOEventDispatch.inputReady(P
> >> lainServerIOEventDispatch.java:69)
> >> > INFO   | jvm 1    | 2009/04/27 18:17:11 |       at
> >> >
> >>
> org.apache.http.impl.nio.reactor.BaseIOReactor.readable(BaseIOReactor.java
> >> :85)
> >> > INFO   | jvm 1    | 2009/04/27 18:17:11 |       at
> >> >
> >>
> org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvent(AbstractIO
> >> Reactor.java:177)
> >> > INFO   | jvm 1    | 2009/04/27 18:17:11 |       at
> >> >
> >>
> org.apache.http.impl.nio.reactor.BaseIOReactor.processEvent(BaseIOReactor.
> >> java:66)
> >> > INFO   | jvm 1    | 2009/04/27 18:17:11 | [I/O dispatcher 3] DEBUG
> >> > LoggingNHttpServiceHandler - HTTP connection [/144.100.83.31:1085]:
> >> > Connected
> >> > INFO   | jvm 1    | 2009/04/27 18:17:11 | [I/O dispatcher 3] DEBUG
> >> > LoggingNHttpServiceHandler - HTTP connection [/144.100.83.31:1085]:
> GET
> >> /?
> >> > HTTP/1.0 INFO   | jvm 1    | 2009/04/27 18:17:11 | [I/O dispatcher 4]
> >> DEBUG
> >> > LoggingNHttpServiceHandler - HTTP connection [/144.100.83.31:1084]:
> >> > Connected
> >> > INFO   | jvm 1    | 2009/04/27 18:17:11 | [I/O dispatcher 4] DEBUG
> >> > LoggingNHttpServiceHandler - HTTP connection [/144.100.83.31:1084]:
> GET
> >> /?
> >> > HTTP/1.0 INFO   | jvm 1    | 2009/04/27 18:17:11 | [I/O dispatcher 3]
> >> DEBUG
> >> > LoggingNHttpServiceHandler - HTTP connection [/144.100.83.31:1085]:
> >> Output
> >> > ready
> >> > INFO   | jvm 1    | 2009/04/27 18:17:11 | [I/O dispatcher 3] DEBUG
> >> > LoggingNHttpServiceHandler - HTTP connection [closed]: Content
> encoder
> >> > [identity; completed: true]
> >> > INFO   | jvm 1    | 2009/04/27 18:17:11 | [I/O dispatcher 3] DEBUG
> >> > LoggingNHttpServiceHandler - HTTP connection [/144.100.83.31:1082]:
> >> Output
> >> > ready
> >> > INFO   | jvm 1    | 2009/04/27 18:17:11 | [I/O dispatcher 3] DEBUG
> >> > LoggingNHttpServiceHandler - HTTP connection [/144.100.83.31:1082]:
> >> Content
> >> > encoder [chunk-coded; completed: true]
> >> > INFO   | jvm 1    | 2009/04/27 18:17:11 | [I/O dispatcher 3] DEBUG
> >> > LoggingNHttpServiceHandler - HTTP connection [closed]: Closed
> >> > INFO   | jvm 1    | 2009/04/27 18:17:11 | [I/O dispatcher 3] DEBUG
> >> > LoggingNHttpServiceHandler - HTTP connection [closed]: Closed
> >> >
> >> >
> >> > INFO   | jvm 1    | 2009/04/27 18:17:11 | [I/O dispatcher 3] DEBUG
> >> > LoggingNHttpServiceHandler - HTTP connection [closed]: Closed
> >> > INFO   | jvm 1    | 2009/04/27 18:17:11 | [I/O dispatcher 4] WARN
> >> > HttpCoreNIOListener$1 - System may be unstable: IOReactor encountered
> a
> >> > runtime exception : null
> >> > INFO   | jvm 1    | 2009/04/27 18:17:11 |
> java.lang.NullPointerException
> >> > INFO   | jvm 1    | 2009/04/27 18:17:11 |       at
> >> >
> >>
> org.apache.synapse.transport.nhttp.ServerHandler.exception(ServerHandler.j
> >> ava:264)
> >> > INFO   | jvm 1    | 2009/04/27 18:17:11 |       at
> >> >
> >>
> org.apache.synapse.transport.nhttp.LoggingNHttpServiceHandler.exception(Lo
> >> ggingNHttpServiceHandler.java:84)
> >> > INFO   | jvm 1    | 2009/04/27 18:17:11 |       at
> >> >
> >>
> org.apache.http.impl.nio.DefaultNHttpServerConnection.consumeInput(Default
> >> NHttpServerConnection.java:145)
> >> > INFO   | jvm 1    | 2009/04/27 18:17:11 |       at
> >> >
> >>
> org.apache.synapse.transport.nhttp.PlainServerIOEventDispatch.inputReady(P
> >> lainServerIOEventDispatch.java:69)
> >> > INFO   | jvm 1    | 2009/04/27 18:17:11 |       at
> >> >
> >>
> org.apache.http.impl.nio.reactor.BaseIOReactor.readable(BaseIOReactor.java
> >> :85)
> >> > INFO   | jvm 1    | 2009/04/27 18:17:11 |       at
> >> >
> >>
> org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvent(AbstractIO
> >> Reactor.java:177)
> >> >
> >> > --
> >> > View this message in context:
> >> http://www.nabble.com/HttpCoreNIOListener%241---System-may-be-
> unstable%3A-
> >> IOReactor-encountered-a-runtime-exception-%3A-null-
> >> tp23278450p23278450.html
> >> > Sent from the Synapse - Dev mailing list archive at Nabble.com.
> >> >
> >> >
> >> > ---------------------------------------------------------------------
> >> > To unsubscribe, e-mail: dev-unsubscribe@synapse.apache.org
> >> > For additional commands, e-mail: dev-help@synapse.apache.org
> >> >
> >> >
> >>
> >>
> >>
> >> --
> >> Paul Fremantle
> >> Co-Founder and CTO, WSO2
> >> Apache Synapse PMC Chair
> >> OASIS WS-RX TC Co-chair
> >>
> >> blog: http://pzf.fremantle.org
> >> paul@wso2.com
> >>
> >> "Oxygenating the Web Service Platform", www.wso2.com
> >>
> >> ---------------------------------------------------------------------
> >> To unsubscribe, e-mail: dev-unsubscribe@synapse.apache.org
> >> For additional commands, e-mail: dev-help@synapse.apache.org
> >
> >
> 
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@synapse.apache.org
> For additional commands, e-mail: dev-help@synapse.apache.org

Mime
View raw message