[
https://issues.apache.org/jira/browse/HTTPCORE-243?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12964748#action_12964748
]
Oleg Kalnichevski commented on HTTPCORE-243:
--------------------------------------------
Eric
I think I found the cause of the problem. Here's the relevant bits of the log
---
45:38,737 [dispatcher-2] DefaultNHttpClientConnection 'Consume input'
45:38,737 [dispatcher-2] IOSessionImpl 'I/O session client-15 [interested ops:
[r]; ready ops: [r]]: 725 bytes read'
45:38,737 [dispatcher-2] wire '>> "HTTP/1.1 200 OK[\r][\n]"'
45:38,737 [dispatcher-2] wire '>> "Server: Apache-Coyote/1.1[\r][\n]"'
45:38,737 [dispatcher-2] wire '>> "xxx"'
45:38,737 [dispatcher-2] wire '>> "Content-Type:
text/xml;charset=UTF-8[\r][\n]"'
45:38,737 [dispatcher-2] wire '>> "Transfer-Encoding: chunked[\r][\n]"'
45:38,737 [dispatcher-2] wire '>> "Date: Mon, 29 Nov 2010 10:45:38 GMT[\r][\n]"'
45:38,737 [dispatcher-2] wire '>> "[\r][\n]"'
45:38,737 [dispatcher-2] wire '>> "1c0[\r][\n]"'
45:38,737 [dispatcher-2] wire '>> "<soap:Envelope
xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/"; ...
45:38,737 [dispatcher-2] wire '>> "0[\r][\n]"'
45:38,737 [dispatcher-2] wire '>> "[\r][\n]"'
45:38,737 [dispatcher-2] ClientHandler 'HTTP connection
[<hostname>/xx.xx.xx.xx:50103] : HTTP/1.1 200 OK [Request Message ID :
urn:uuid:1CD35CE531BE8D787A22035167021095501-526448396]'
45:38,738 [dispatcher-2] ClientHandler 'Response Received for Request :
Axis2Request [Message ID :
urn:uuid:1CD35CE531BE8D787A22035167021095501-526448396] [Status Completed :
true] [Status SendingCompleted : true]'
45:38,738 [dispatcher-2] NHttpConfiguration 'Using nhttp tuning parameter :
nhttp_buffer_size = 8192'
45:38,738 [dispatcher-2] IOSessionImpl 'I/O session client-15 [interested ops:
[r]; ready ops: [r]]: Set attribute synapse.response-sink-buffer'
45:38,738 [dispatcher-2] IOSessionImpl 'I/O session client-15 [interested ops:
[r]; ready ops: [r]]: Set attribute http.response'
45:38,738 [dispatcher-2] ClientHandler 'HTTP connection
[<hostname>/xx.xx.xx.xx:50103]: Input ready [Request Message ID :
urn:uuid:1CD35CE531BE8D787A22035167021095501-526448396]'
45:38,738 [dispatcher-2] IOSessionImpl 'I/O session client-15 [interested ops:
[r]; ready ops: [r]]: 0 bytes read'
45:38,738 [dispatcher-2] IOSessionImpl 'I/O session client-15 [interested ops:
[r]; ready ops: [r]]: 0 bytes read'
45:38,738 [dispatcher-2] IOSessionImpl 'I/O session client-15 [interested ops:
[r]; ready ops: [r]]: 0 bytes read'
45:38,739 [dispatcher-2] IOSessionImpl 'I/O session client-15 [interested ops:
[r]; ready ops: [r]]: Remove attribute synapse.axis2-http-request'
45:38,739 [dispatcher-2] IOSessionImpl 'I/O session client-15 [interested ops:
[r]; ready ops: [r]]: Remove attribute synapse.axis2_message_context'
45:38,739 [dispatcher-2] IOSessionImpl 'I/O session client-15 [interested ops:
[r]; ready ops: [r]]: Remove attribute synapse.request-source-buffer'
45:38,739 [dispatcher-2] IOSessionImpl 'I/O session client-15 [interested ops:
[r]; ready ops: [r]]: Remove attribute synapse.response-sink-buffer'
45:38,739 [dispatcher-2] IOSessionImpl 'I/O session client-15 [interested ops:
[r]; ready ops: [r]]: Remove attribute http.request'
45:38,739 [dispatcher-2] IOSessionImpl 'I/O session client-15 [interested ops:
[r]; ready ops: [r]]: Remove attribute http.response'
>>> ----------------------------------------- trouble!!!!
>>> -------------------------------
45:38,739 [dispatcher-2] IOSessionImpl 'I/O session client-15 [interested ops:
[r]; ready ops: [r]]: Remove attribute http.connection'
>>> ----------------------------------------- trouble!!!!
>>> -------------------------------
45:38,739 [dispatcher-2] ConnectionPool 'Released a connection to host:
<hostname> on port : 50103 to the connection pool of current size : 1'
45:38,739 [dispatcher-2] ClientHandler 'HTTP connection
[<hostname>/xx.xx.xx.xx:50103]: Content decoder [chunk-coded; completed: true]'
>>> ----------- Big kaboom ---------------
45:58,736 [dispatcher-2] HttpCoreNIOSender 'System may be unstable: IOReactor
encountered a runtime exception : null'
---
So, the response from the origin server gets correctly processed. All is nice
and dandy. The connection is kept alive and returned to the connection pool.
The trouble is that for some reason the Synapse's NHTTP transport code removes
the 'http.connection' attribute from the I/O session context. As a result the
I/O session loses all its HTTP protocol state. In 20 seconds the origin server
closes the connection on its end. The I/O reactor on the opposite wakes up and
fires #inputReady event for that session. DefaultClientIOEventDispatch assumes
the I/O session always contains a valid HTTP connection object and causes a NPE
by trying to invoke a method on a null HTTP connection instance.
Supun
What is the reason Synapse removes ' http.connection' attribute from the I/O
session?
I'll tweak HttpCore to throw a different type of exception
(IllegalStateException most probably) but fundamentally the issue is caused by
the Synapse NHTTP transport code.
Oleg
> NPE in DefaultClientIOEventDispatch#inputReady
> ----------------------------------------------
>
> Key: HTTPCORE-243
> URL: https://issues.apache.org/jira/browse/HTTPCORE-243
> Project: HttpComponents HttpCore
> Issue Type: Bug
> Components: HttpCore NIO
> Affects Versions: 4.1
> Environment: Linux 2.6.18-6-amd64, Java 6 Update 21, 32bit
> Reporter: Eric Hubert
> Attachments: synapse_session_wire.log
>
>
> While using Synapse 1.2 with httpcore-nio 4.1 the following exceptions occurs
> WARN 2010-11-27 23:55:07,737 [http-Sender I/O dispatcher-1][][]
> org.apache.synapse.transport.nhttp.HttpCoreNIOSender 'System may be unstable:
> IOReactor encountered a runtime exception : null'
> java.lang.NullPointerException
> at
> org.apache.http.impl.nio.DefaultClientIOEventDispatch.inputReady(DefaultClientIOEventDispatch.java:148)
> at
> org.apache.http.impl.nio.reactor.BaseIOReactor.readable(BaseIOReactor.java:161)
> at
> org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvent(AbstractIOReactor.java:335)
> at
> org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvents(AbstractIOReactor.java:315)
> 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:542)
> at java.lang.Thread.run(Thread.java:619)
> FATAL 2010-11-27 23:55:08,678 [HttpCoreNIOSender][][]
> org.apache.synapse.transport.nhttp.HttpCoreNIOSender 'Encountered an I/O
> error: I/O dispatch worker terminated abnormally'
> org.apache.http.nio.reactor.IOReactorException: I/O dispatch worker
> terminated abnormally
> at
> org.apache.http.impl.nio.reactor.AbstractMultiworkerIOReactor.execute(AbstractMultiworkerIOReactor.java:324)
> at
> org.apache.synapse.transport.nhttp.HttpCoreNIOSender.executeClientEngine(HttpCoreNIOSender.java:188)
> at
> org.apache.synapse.transport.nhttp.HttpCoreNIOSender.access$000(HttpCoreNIOSender.java:77)
> at
> org.apache.synapse.transport.nhttp.HttpCoreNIOSender$3.run(HttpCoreNIOSender.java:209)
> at java.lang.Thread.run(Thread.java:619)
> Caused by: java.lang.NullPointerException
> at
> org.apache.http.impl.nio.DefaultClientIOEventDispatch.inputReady(DefaultClientIOEventDispatch.java:148)
> at
> org.apache.http.impl.nio.reactor.BaseIOReactor.readable(BaseIOReactor.java:161)
> at
> org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvent(AbstractIOReactor.java:335)
> at
> org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvents(AbstractIOReactor.java:315)
> 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:542)
> ... 1 more
> I will give my best to provide a wire log later on.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
