users@grizzly.java.net

getWriter() has already been called for this response

From: Aart de Vries <aartdv_at_premier-gps.com>
Date: Mon, 06 Oct 2008 12:19:58 -0600

Gruesse Jeanfrancois,

Three thing:
1) If I use cometContext.setExpirationDelay(-1) my problem does indeed not surface.

2)
You wrote:
> I just want to see if the browser send back a
> request at the same time Grizzly is resuming the connection. In that
> case, the CometHandler might get invoked with the second request, but
> the Request/Response are the one from the previous resumed transaction.
Or maybe the 29000 in setExpirationDelay I use is the problem: My connections
are always resumed after 5 seconds because the onEvent answers then and
resumes the connection and removes the CometHandler from the context. Maybe
for some of these handlers (since my error is ocuring at varying time intervals),
the expiration code is trying to resume an already closed connection?

3)
If you can be a bit more specific on where to put the following code:
if (event.getType() == CometEvent.NOTIFY){


} else {
   Thread.dumpStack();
}

I put it in the following place (still using 29000 in setExpirationDelay), as I was not
sure, but I didn't get a Thread.dumpStack().

        public void onEvent(CometEvent cometEvent) throws IOException {
            if (cometEvent.getType() == CometEvent.NOTIFY){
                Message msg = (Message) cometEvent.attachment();
                try {
                    String encoded = RPC.encodeResponseForSuccess(CometServiceImpl.class.getMethod("comet", new Class[] { int.class } ), msg); //The service method is passed in to verify that the msg object is compatible with the return type's signature of the method.
                    writeResponse(req, res, encoded);
                    cometContext.resumeCometHandler(this); // Resumes connection and commit it's response. Also removes CometHandler from CometContext.
                }
                catch (Exception e) {
                    log("Exception in GWTCometHandler.onEvent: " + e);
                    e.printStackTrace();
                }
            }
            else {
                log("For Jeanfrancois **********************************************");
                Thread.dumpStack();
            }
        }

If you can suggest a better location for test, then I'll try again.

Salut,

Aart de Vries wrote:
> Bonjour Jeanfrancois,
>
> Merci pour la reaction rapide.
>
> Two things:
> 1) I do indeed call:
> cometContext.setExpirationDelay(29000);
> I do this with the intent to prevent browsers timing out the connection, or is there really no need for that. Should I not
> use cometContext.setExpirationDelay() ?

Configure la valeur a -1...oups, english: just set the value to -1. I
will properly fix the javadoc as this is unclear.


>
> 2) There seems to be indeed some kind of a race condition. I wrote you before that the client re-opens the connection
> ASAP. If I add the thread.sleep(1000) before the code that add's the CometHandler to the CometContext (on the server side,
> when the connection is re-opened), then my error does not surface anymore, even not after 20 minutes!
> public void doConnect(HttpServletRequest req, HttpServletResponse res) {
> try {
> Thread.sleep(1000);
> res.setContentType("text/html;charset=ISO-8859-1");
> GWTCometHandler cometHandler = new GWTCometHandler();
> cometHandler.attach(res);
> cometHandler.attachRequest(req);
> cometContext.addCometHandler(cometHandler); //Executing this operation tells Grizzly to suspend the underlying connection, and avoids committing the response until the handler will be removed from the context
> }
> catch (Exception e) {
> log("Exception in doConnect: " + e);
> }
> }
> Hope you can do something with this.

ah! Can you add, in your code, the following if:


if (event.getType() == CometEvent.NOTIFY){


} else {
   Thread.dumpStack();
}

and send the result. I just want to see if the browser send back a
request at the same time Grizzly is resuming the connection. In that
case, the CometHandler might get invoked with the second request, but
the Request/Response are the one from the previous resumed transaction.

Thanks

-- Jeanfrancois




>
>
> Date: Mon, 06 Oct 2008 11:54:35 -0400
> From: Jeanfrancois Arcand <Jeanfrancois.Arcand_at_Sun.COM>
> Content-type: text/plain; format=flowed; charset=ISO-8859-1
> Subject: getWriter() has already been called for this response
>
>
> Salut,
>
>
> Aart de Vries wrote:
>> I'm on:
>> - OpenSuse 11.0
>> - java 1.6.0_07
>> - GlassfishV3-prelude-b26 (with integrated Grizzly 1.8.6)
>> - GWT 1.5.2 building upon example from
>> http://www.javascriptr.com/2008/05/28/gwt-grizzly-comet/
>> - dual core T8400 at 3GHz.
>>
>> In essence I want to achieve long polling. My evaluation code writes a
>> string message after a delay of 5 seconds
>> using the following code:
>> public void onEvent(CometEvent cometEvent) throws IOException {
>> Message msg = (Message) cometEvent.attachment();
>> try {
>> String encoded =
>> RPC.encodeResponseForSuccess(CometServiceImpl.class.getMethod("comet"),
>> msg);
>> writeResponse(req, res, encoded);
>> cometContext.resumeCometHandler(this);
>> }
>> catch (Exception e) {
>> log("Exception in GWTCometHandler.onEvent: " + e);
>> e.printStackTrace();
>> }
>> }
>> From the browser client, I keep calling this code, by re-opening a
>> connection after having received an answer.
>>
>> The code works, and glassfish is not blocking IO anymore even if I hit
>> the server with 10 browser instances. Great work
>> guys. But so now and then I get the error message below (even when I hit
>> my server form a single client), which makes
>> me believe that, although I only have a single notify() every 5 seconds,
>> sometimes more than once my onEvent gets called by
>> the Comet framework. This happens at irregular intervals, sometimes
>> after 30 seconds, sometimes after several minutes.
>
> Have you, by any chance, changed the default timeout value when creating
> the CometContext:
>
> cometContext.setExpirationDelay(..); [1]
>
> Based on the above, it seems there is a small thread race between the
> invocation of onEvent() and onInterrupt(). Can you try to synchronized
> the onEvent method to see if that help?
>
>> PS. I would be happy to evaluate Grizzly 1.8.6.1 to see if this issue is
>> already out of the way. Could somebody refer to some
>> documentation that will allow me to run 1.8.6.1 from within GlassfishV3,
>
> That's not simple. Mainly, you need to do something like:
>
> % unzip grizzly-comet-1.8.6.1.jar
> % jar uvf grizzly-optionals.jar com
>
> A+
>
> -- Jeanfrancois
>
>> since the obvious attempt of bluntly removing it's
>> grizzly-modules.jar and grizzly-optionals.jar files and adding in the
>> same directory the 1.8.6.1 jars doesn't work.
>>
>> java.lang.IllegalStateException: PWC3990: getWriter() has already been
>> called for this response
>> at
>> org.apache.catalina.connector.Response.getOutputStream(Response.java:685)
>> at
>> org.apache.catalina.connector.ResponseFacade.getOutputStream(ResponseFacade.java:213)
>> at
>> com.google.gwt.user.server.rpc.RPCServletUtils.writeResponse(RPCServletUtils.java:234)
>> at
>> com.google.gwt.user.server.rpc.RemoteServiceServlet.writeResponse(RemoteServiceServlet.java:379)
>> at
>> com.google.gwt.user.server.rpc.RemoteServiceServlet.doPost(RemoteServiceServlet.java:94)
>> at javax.servlet.http.HttpServlet.service(HttpServlet.java:754)
>> at javax.servlet.http.HttpServlet.service(HttpServlet.java:847)
>> at
>> org.apache.catalina.core.ApplicationFilterChain.servletService(ApplicationFilterChain.java:431)
>> at
>> org.apache.catalina.core.StandardWrapperValve.preInvoke(StandardWrapperValve.java:462)
>> at
>> org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:139)
>> at
>> org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:186)
>> at
>> org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:719)
>> at
>> org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:657)
>> at com.sun.enterprise.web.WebPipeline.invoke(WebPipeline.java:96)
>> at
>> com.sun.enterprise.web.PESessionLockingStandardPipeline.invoke(PESessionLockingStandardPipeline.java:98)
>> at
>> org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:187)
>> at
>> org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:719)
>> at
>> org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:657)
>> at
>> org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:651)
>> at
>> org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:1030)
>> at
>> org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:142)
>> at
>> org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:719)
>> at
>> org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:657)
>> at
>> org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:651)
>> at
>> org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:1030)
>> at
>> org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:307)
>> at
>> org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:226)
>> at
>> com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:180)
>> at
>> com.sun.grizzly.http.DefaultProcessorTask.invokeAdapter(DefaultProcessorTask.java:625)
>> at
>> com.sun.grizzly.comet.CometEngine.executeServlet(CometEngine.java:564)
>> at com.sun.grizzly.comet.CometEngine.handle(CometEngine.java:318)
>> at
>> com.sun.grizzly.comet.CometAsyncFilter.doFilter(CometAsyncFilter.java:84)
>> at
>> com.sun.grizzly.arp.DefaultAsyncExecutor.invokeFilters(DefaultAsyncExecutor.java:130)
>> at
>> com.sun.grizzly.arp.DefaultAsyncExecutor.interrupt(DefaultAsyncExecutor.java:109)
>> at
>> com.sun.grizzly.arp.AsyncProcessorTask.doTask(AsyncProcessorTask.java:88)
>> at com.sun.grizzly.http.TaskBase.call(TaskBase.java:359)
>> at
>> com.sun.grizzly.util.WorkerThreadImpl.processTask(WorkerThreadImpl.java:325)
>> at
>> com.sun.grizzly.util.WorkerThreadImpl.run(WorkerThreadImpl.java:184)
>>