You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@cxf.apache.org by Aki Yoshida <el...@googlemail.com> on 2011/06/18 00:46:52 UTC
Oneway CXF service having problem with Gemini-Web/Tomcat-catalina
Hi,
There seems to be some IO handling problem in oneway CXF services on
equinox with the latest gemini-web.
It think I have identified the cause of the problem and that we could
fix it in CXF. But I would like to get your comments.
The problem happens sporadically for oneway services when the
StaxInInterceptor tries to instantiate the XMLStreamReader from the
InputStream object. In this test scenario, a series of oneway calls
are sequentially sent to a CXF oneway service. And sporadically, some
calls result in the following exception, that is indicating the input
stream is already closed, even though the data should be available in
the stream.
Caused by: java.lang.RuntimeException: Couldn't parse stream.
at org.apache.cxf.staxutils.StaxUtils.createXMLStreamReader(StaxUtils.java:1143)
~[na:na]
at org.apache.cxf.interceptor.StaxInInterceptor.handleMessage(StaxInInterceptor.java:105)
~[na:na]
... 27 common frames omitted
Caused by: com.ctc.wstx.exc.WstxIOException: Stream closed
at com.ctc.wstx.stax.WstxInputFactory.doCreateSR(WstxInputFactory.java:536)
~[na:na]
at com.ctc.wstx.stax.WstxInputFactory.createSR(WstxInputFactory.java:585)
~[na:na]
at com.ctc.wstx.stax.WstxInputFactory.createSR(WstxInputFactory.java:610)
~[na:na]
at com.ctc.wstx.stax.WstxInputFactory.createXMLStreamReader(WstxInputFactory.java:316)
~[na:na]
at org.apache.cxf.staxutils.StaxUtils.createXMLStreamReader(StaxUtils.java:1141)
~[na:na]
... 28 common frames omitted
Caused by: java.io.IOException: Stream closed
at org.apache.catalina.connector.InputBuffer.read(InputBuffer.java:308)
~[na:na]
at org.apache.catalina.connector.CoyoteInputStream.read(CoyoteInputStream.java:202)
~[na:na]
at org.apache.cxf.transport.servlet.LogServletInputStream.read(LogServletInputStream.java:80)
~[na:na]
at com.ctc.wstx.io.BaseReader.readBytes(BaseReader.java:155) ~[na:na]
at com.ctc.wstx.io.UTF8Reader.loadMore(UTF8Reader.java:368) ~[na:na]
at com.ctc.wstx.io.UTF8Reader.read(UTF8Reader.java:111) ~[na:na]
at com.ctc.wstx.io.ReaderBootstrapper.initialLoad(ReaderBootstrapper.java:250)
~[na:na]
at com.ctc.wstx.io.ReaderBootstrapper.bootstrapInput(ReaderBootstrapper.java:133)
~[na:na]
at com.ctc.wstx.stax.WstxInputFactory.doCreateSR(WstxInputFactory.java:531)
~[na:na]
I didn't see this problem with jetty before and started to see this
problem sporadically right after switching to gemini-web.
It seems that the error has something to do with the way in which its
previous call is handled and how the servlet container manages the
stream resources. To investigate this situation, I logged CXF's each
method call into the HttpServletRequest, HttpServetResponse,
ServletInputStream, and ServerOutputStream objects and noticed that
the input stream was always closed by a web container's cleanup thread
instead of the CXF's servlet thread. In contrast, the output stream
was always closed by the CXF servlet thread at
AbstractHTTPDestination's close(). In this method, there is an
interesting code fragment that explains this particular handling for
the oneway case:
public void close(Message msg) throws IOException {
super.close(msg);
if (msg.getExchange() == null) {
return;
}
Message m = msg.getExchange().getInMessage();
if (m == null || msg.getExchange().isOneWay()) {
return;
}
InputStream is = m.getContent(InputStream.class);
if (is != null) {
try {
is.close();
...
The intention of the above code was probably to asynchronously read
the input stream later than this point. But if the output stream is
closed and the servlet is returned, there is no guarantee that the
input stream remains available. So, I think we can close the input
stream there. Besides, OneWayProcessorInterceptor is supposed to be
pulling in the entire stream data.
if (Boolean.FALSE.equals(o)) {
//need to suck in all the data from the input stream as
//the transport might discard any data on the stream when this
//thread unwinds or when the empty response is sent back
DelegatingInputStream in =
message.get(DelegatingInputStream.class);
if (in != null) {
in.cacheInput();
}
}
So, I modified the AbstractHTTPDestination's close method to also
close the input stream upon closing the output stream. And it seems
that the problem is gone. But I am not 100% sure that this might not
be introducing another problem.
My hypothesis is that Gemini-web (tomcat-catalina) closes the input
stream with some non-deterministic behavior that sporadically causes
the input stream of the subsequent call to become closed. I think if
tomcat-cataline always closes the input stream right away after the
call comes back, it will probably also solve this problem.
Should I go ahead to put this change in 2.5 and 2.4.x? Or do you think
we should discuss this issue with the tomcat-cataline people?
Thanks.
Regards, aki
Re: Oneway CXF service having problem with Gemini-Web/Tomcat-catalina
Posted by Daniel Kulp <dk...@apache.org>.
I think you should go ahead and commit this change. Most likely, the
exclusion of the close on the input stream predates the the creation of the
OneWayProcessorInterceptor and is irrelevant (and problematic) code now that
the OneWayProcessorInterceptor pulls in the stream.
Dan
On Saturday, June 18, 2011 12:46:52 AM Aki Yoshida wrote:
> Hi,
> There seems to be some IO handling problem in oneway CXF services on
> equinox with the latest gemini-web.
> It think I have identified the cause of the problem and that we could
> fix it in CXF. But I would like to get your comments.
>
> The problem happens sporadically for oneway services when the
> StaxInInterceptor tries to instantiate the XMLStreamReader from the
> InputStream object. In this test scenario, a series of oneway calls
> are sequentially sent to a CXF oneway service. And sporadically, some
> calls result in the following exception, that is indicating the input
> stream is already closed, even though the data should be available in
> the stream.
>
> Caused by: java.lang.RuntimeException: Couldn't parse stream.
> at
> org.apache.cxf.staxutils.StaxUtils.createXMLStreamReader(StaxUtils.java:114
> 3) ~[na:na]
> at
> org.apache.cxf.interceptor.StaxInInterceptor.handleMessage(StaxInIntercepto
> r.java:105) ~[na:na]
> ... 27 common frames omitted
> Caused by: com.ctc.wstx.exc.WstxIOException: Stream closed
> at
com.ctc.wstx.stax.WstxInputFactory.doCreateSR(WstxInputFactory.java:536)
> ~[na:na]
> at com.ctc.wstx.stax.WstxInputFactory.createSR(WstxInputFactory.java:585)
> ~[na:na]
> at com.ctc.wstx.stax.WstxInputFactory.createSR(WstxInputFactory.java:610)
> ~[na:na]
> at
> com.ctc.wstx.stax.WstxInputFactory.createXMLStreamReader(WstxInputFactory.j
> ava:316) ~[na:na]
> at
> org.apache.cxf.staxutils.StaxUtils.createXMLStreamReader(StaxUtils.java:114
> 1) ~[na:na]
> ... 28 common frames omitted
> Caused by: java.io.IOException: Stream closed
> at org.apache.catalina.connector.InputBuffer.read(InputBuffer.java:308)
> ~[na:na]
> at
> org.apache.catalina.connector.CoyoteInputStream.read(CoyoteInputStream.java
> :202) ~[na:na]
> at
> org.apache.cxf.transport.servlet.LogServletInputStream.read(LogServletInput
> Stream.java:80) ~[na:na]
> at com.ctc.wstx.io.BaseReader.readBytes(BaseReader.java:155) ~[na:na]
> at com.ctc.wstx.io.UTF8Reader.loadMore(UTF8Reader.java:368) ~[na:na]
> at com.ctc.wstx.io.UTF8Reader.read(UTF8Reader.java:111) ~[na:na]
> at
> com.ctc.wstx.io.ReaderBootstrapper.initialLoad(ReaderBootstrapper.java:250)
> ~[na:na]
> at
> com.ctc.wstx.io.ReaderBootstrapper.bootstrapInput(ReaderBootstrapper.java:1
> 33) ~[na:na]
> at
com.ctc.wstx.stax.WstxInputFactory.doCreateSR(WstxInputFactory.java:531)
> ~[na:na]
>
> I didn't see this problem with jetty before and started to see this
> problem sporadically right after switching to gemini-web.
>
> It seems that the error has something to do with the way in which its
> previous call is handled and how the servlet container manages the
> stream resources. To investigate this situation, I logged CXF's each
> method call into the HttpServletRequest, HttpServetResponse,
> ServletInputStream, and ServerOutputStream objects and noticed that
> the input stream was always closed by a web container's cleanup thread
> instead of the CXF's servlet thread. In contrast, the output stream
> was always closed by the CXF servlet thread at
> AbstractHTTPDestination's close(). In this method, there is an
> interesting code fragment that explains this particular handling for
> the oneway case:
>
> public void close(Message msg) throws IOException {
> super.close(msg);
> if (msg.getExchange() == null) {
> return;
> }
> Message m = msg.getExchange().getInMessage();
> if (m == null || msg.getExchange().isOneWay()) {
> return;
> }
> InputStream is = m.getContent(InputStream.class);
> if (is != null) {
> try {
> is.close();
> ...
>
> The intention of the above code was probably to asynchronously read
> the input stream later than this point. But if the output stream is
> closed and the servlet is returned, there is no guarantee that the
> input stream remains available. So, I think we can close the input
> stream there. Besides, OneWayProcessorInterceptor is supposed to be
> pulling in the entire stream data.
>
> if (Boolean.FALSE.equals(o)) {
> //need to suck in all the data from the input stream as
> //the transport might discard any data on the stream when
> this //thread unwinds or when the empty response is sent back
> DelegatingInputStream in =
> message.get(DelegatingInputStream.class);
> if (in != null) {
> in.cacheInput();
> }
> }
>
> So, I modified the AbstractHTTPDestination's close method to also
> close the input stream upon closing the output stream. And it seems
> that the problem is gone. But I am not 100% sure that this might not
> be introducing another problem.
>
> My hypothesis is that Gemini-web (tomcat-catalina) closes the input
> stream with some non-deterministic behavior that sporadically causes
> the input stream of the subsequent call to become closed. I think if
> tomcat-cataline always closes the input stream right away after the
> call comes back, it will probably also solve this problem.
>
> Should I go ahead to put this change in 2.5 and 2.4.x? Or do you think
> we should discuss this issue with the tomcat-cataline people?
>
> Thanks.
>
> Regards, aki
--
Daniel Kulp
dkulp@apache.org
http://dankulp.com/blog
Talend - http://www.talend.com