Mailing-List: contact dev-help@tomcat.apache.org; run by ezmlm
Precedence: bulk
Reply-To: "Tomcat Developers List" <dev@tomcat.apache.org>
From: bugzilla@apache.org
To: dev@tomcat.apache.org
Subject: DO NOT REPLY [Bug 52009] NPE exception in
 org.apache.catalina.connector.CoyoteAdapter.service
Date: Wed, 12 Oct 2011 04:31:05 +0000
Message-ID: <bug-52009-78-87PD3IWWNA@https.issues.apache.org/bugzilla/>
In-Reply-To: <bug-52009-78@https.issues.apache.org/bugzilla/>
References: <bug-52009-78@https.issues.apache.org/bugzilla/>
Auto-Submitted: auto-generated
Content-Type: text/plain; charset="UTF-8"
Content-Transfer-Encoding: quoted-printable
MIME-Version: 1.0

https://issues.apache.org/bugzilla/show_bug.cgi?id=3D52009

--- Comment #4 from Konstantin Kolinko <knst.kolinko@gmail.com> 2011-10-12 =
04:31:05 UTC ---
> I already sent you the application in gmail, which is so large to attache=
 here.

1) I bet that you do not need all 25 Mb of dojox components of dojotoolkit.

The NPE issue is still reproducible if I delete the dojox folder from the
webapp and that shrinks its size significantly.

2) Source code for StockServlet is there - thank you, but sources of its pa=
rent
class BayeuxServlet is not available.

3) To reproduce the issue, open http://localhost:8888/QuoteStreamerApp/

Just open the page in browser and leave it open.

The page sends a flow of POST requests to
/QuoteStreamerApp/stockServlet HTTP/1.1

4) I am running with the following line added to catalina.properties file:
org.apache.coyote.http11.InternalNioInputBuffer.level =3D FINE

and it shows that there are problems in BayeuxServlet that it calls setHead=
er()
on a response that has already been recycled.
It is an application error. This is unacceptable and can lead to updating a
response that is being delivered to a different client.

Stacktrace in localhost.2011-10-12.log:

12-=D0=BE=D0=BA=D1=82-2011 08:04:02.078 SEVERE [http-nio-8888-exec-8]
org.apache.catalina.core.StandardWrapperValve.event Servlet.service() for
servlet [StockServlet] in context with path [/QuoteStreamerApp] threw excep=
tion
 java.lang.IllegalStateException: The response object has been recycled and=
 is
no longer associated with this facade
    at
org.apache.catalina.connector.ResponseFacade.isCommitted(ResponseFacade.jav=
a:325)
    at
org.apache.catalina.connector.ResponseFacade.setHeader(ResponseFacade.java:=
518)
    at
com.ibm.ws.webmsg.servlet.adapter.ServletResponse.setHeader(ServletResponse=
.java:147)
    at
com.ibm.ws.webmsg.client.bayeux.protocol.vone.JSONTransport.endResponse(JSO=
NTransport.java:191)
    at
com.ibm.ws.webmsg.client.bayeux.protocol.vone.processor.EventDeliveryProces=
sor.close(EventDeliveryProcessor.java:139)
    at
com.ibm.ws.webmsg.client.bayeux.protocol.vone.WASCEClientImpl.shutdown(WASC=
EClientImpl.java:117)
    at
com.ibm.ws.webmsg.client.bayeux.protocol.vone.processor.DisconnectProcessor=
.processMessage(DisconnectProcessor.java:63)
    at
com.ibm.ws.webmsg.client.bayeux.protocol.vone.ClientImpl.processRequest(Cli=
entImpl.java:332)
    at com.ibm.webmsg.servlet.BayeuxServlet.handleRead(BayeuxServlet.java:2=
33)
    at com.ibm.webmsg.servlet.BayeuxServlet.event(BayeuxServlet.java:210)
    at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilterEvent(Appli=
cationFilterChain.java:482)
    at
org.apache.catalina.core.ApplicationFilterChain.doFilterEvent(ApplicationFi=
lterChain.java:376)
    at
org.apache.catalina.core.StandardWrapperValve.event(StandardWrapperValve.ja=
va:414)
    at
org.apache.catalina.core.StandardContextValve.event(StandardContextValve.ja=
va:192)
    at org.apache.catalina.valves.ValveBase.event(ValveBase.java:226)
    at
org.apache.catalina.core.StandardHostValve.event(StandardHostValve.java:245)
    at org.apache.catalina.valves.ValveBase.event(ValveBase.java:226)
    at org.apache.catalina.valves.ValveBase.event(ValveBase.java:226)
    at
org.apache.catalina.core.StandardEngineValve.event(StandardEngineValve.java=
:138)
    at
org.apache.catalina.connector.CoyoteAdapter.event(CoyoteAdapter.java:211)
    at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:411)
    at
org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Proc=
essor.java:970)
    at
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(Abstra=
ctProtocol.java:515)
    at
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java=
:1550)
    at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.j=
ava:886)
    at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:=
908)
    at java.lang.Thread.run(Thread.java:662)


5) There are a lot of exceptions like
javax.jms.JMSException: Could not connect to broker URL: tcp://localhost:61=
616.
Reason: java.net.ConnectException: Connection refused: connect

but the NullPointerException at CoyoteAdapter.java:436 is reproducible.

6) The NPE is reproducible both in 7.0.22 and in trunk.


The requests to of them fail with error 500, but response sizes in different
requests are different.

I noted the following while debugging trunk:

1. In access log all requests are POST to /QuoteStreamerApp/stockServlet.
They all fail with error 500, but response sizes are different.

2. After the call to getPipeline().getFirst().invoke(request, response) the
value of request.isComet() is true.

3. The cause for NPE at CoyoteAdapter.java:436 is that at that point the
request is already recycled and request.getMappingData().context  is null.

4. The recycling happens in the finally block in CoyoteAdapter#event(..),
lines 252-254:
            if (error || response.isClosed() || !request.isComet()) {
                request.recycle();
                request.setFilterChain(null);
                response.recycle();
            }

I do not know much about request that is being recycled. It is not the first
request that was received.

5. If I put breakpoint on the request.recycle() call above, the call stack =
is:

CoyoteAdapter.event(Request, Response, SocketStatus) line: 252=20=20=20=20
CoyoteAdapter.service(Request, Response) line: 411=20=20=20=20
Http11NioProcessor(AbstractHttp11Processor<S>).process(SocketWrapper<S>) li=
ne:
970=20=20=20=20
Http11NioProtocol$Http11ConnectionHandler(AbstractProtocol$AbstractConnecti=
onHandler<S,P>).process(SocketWrapper<S>,
SocketStatus) line: 515=20=20=20=20
NioEndpoint$SocketProcessor.run() line: 1550=20=20=20=20

After returning from event() call on CoyoteAdapter:411 (the call returns fa=
lse)
the lines 431..440 are executed:
            } else if (!comet) {
                request.finishRequest();
                response.finishResponse();
                if (postParseSuccess) {
                    // Log only if processing was invoked.
                    // If postParseRequest() failed, it has already logged =
it.
                    ((Context) request.getMappingData().context).logAccess(
                            request, response,
                            System.currentTimeMillis() - req.getStartTime(),
                            false);
                }

The comet variable is false and postParseSuccess is true.
The request is already recycled and request.getMappingData().context is nul=
l,
leading to an NPE.

--=20
Configure bugmail: https://issues.apache.org/bugzilla/userprefs.cgi?tab=3De=
mail
------- You are receiving this mail because: -------
You are the assignee for the bug.=

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