users@grizzly.java.net

Re: getWriter() has already been called for this response

From: Jeanfrancois Arcand <Jeanfrancois.Arcand_at_Sun.COM>
Date: Mon, 06 Oct 2008 21:49:15 -0400

Salut,

Aart de Vries wrote:
> Hello Jeanfrancois,
>
> Doing:
>
> % cd v3.home/modules
> % unzip grizzly-comet-1.9.0...jar
> % jar uvf grizzly-optionals.jar com
>
>
> Worked for me. I now see things like Used canceled file descriptor
> sun.nio.ch.SelectionKeyImpl_at_175ace6
> and sun.nio.ch.SelectionKeyImpl_at_ae8af4 in the log that you probably added.
>
> In my log-dump below, I start of with the success scenario:
> 1) My client calls the doConnect on the server
> 2) The server starts off with logging "sending msg in 5 seconds
> 3) After 5 seconds onEvent gets triggered by a notify()
> 4) The server encodes the message and does a
> cometContext.resumeCometHandler(this) to close the current httpRequest
> Then these 4 steps start all over, as the client upon receipt of an
> answer makes the same request again.
>
> The second time we see the steps 1..4 and step 1 again (as the client
> tries to fetch for the 3rd time), immediately followed by the problem
> we are discussing: "getWriter() has already been called for this
> response". I'm now a bit in doubt on when exactly this error is thrown,
> because it says "Exception while dispatching incoming RPC call" and the
> stackdump is not referencing into my code.
> I hope your added log-statements give you any clues.

It doesn't looks like a bug with Comet. I feel stupid as I should have
seen before :-) In you code, are you calling getWriter() from any place?
It seems with GWT you cannot call that method and then call
getOutputStream, as GWT is always calling it.

>> 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)
>
> For me it is the end of my workday (I'm on Mountain Standard Time), but
> I'll continue this first thing tomorrow morning.

A+

-- Jeanfrancois

>
> Aart
>
> Taken from the GlassFish log:
> [#|2008-10-06T16:33:51.872-0600|INFO|GlassFish10.0|javax.enterprise.system.container.web|_ThreadID=23;_ThreadName=Thread-5;|PWC1412:
> WebModule[/CallCenter] ServletContext.log():CometService: DoConnect
> CALLED|#]
>
> [#|2008-10-06T16:33:56.864-0600|INFO|GlassFish10.0|javax.enterprise.system.container.web|_ThreadID=15;_ThreadName=Thread-5;|PWC1412:
> WebModule[/CallCenter] ServletContext.log():CometService: sending msg in
> 5 seconds|#]
>
> [#|2008-10-06T16:33:56.864-0600|INFO|GlassFish10.0|javax.enterprise.system.container.web|_ThreadID=24;_ThreadName=Thread-5;|PWC1412:
> WebModule[/CallCenter] ServletContext.log():CometService: onEvent|#]
>
> [#|2008-10-06T16:33:56.864-0600|INFO|GlassFish10.0|javax.enterprise.system.container.web|_ThreadID=24;_ThreadName=Thread-5;|PWC1412:
> WebModule[/CallCenter] ServletContext.log():CometService:
> encoded=//OK[5,2,1,["ca.safetystar.client.comet.MessageSubclass/2737666392","20048"],0,4]|#]
>
> [#|2008-10-06T16:33:56.864-0600|INFO|GlassFish10.0|null|_ThreadID=24;_ThreadName=Thread-5;|Used
> cancelled file descriptor sun.nio.ch.SelectionKeyImpl_at_175ace6
> and
> sun.nio.ch.SelectionKeyImpl_at_ae8af4|#]
>
> [#|2008-10-06T16:33:56.870-0600|INFO|GlassFish10.0|javax.enterprise.system.container.web|_ThreadID=25;_ThreadName=Thread-5;|PWC1412:
> WebModule[/CallCenter] ServletContext.log():CometService: DoConnect
> CALLED|#]
>
> [#|2008-10-06T16:34:01.865-0600|INFO|GlassFish10.0|javax.enterprise.system.container.web|_ThreadID=15;_ThreadName=Thread-5;|PWC1412:
> WebModule[/CallCenter] ServletContext.log():CometService: sending msg in
> 5 seconds|#]
>
> [#|2008-10-06T16:34:01.866-0600|INFO|GlassFish10.0|javax.enterprise.system.container.web|_ThreadID=17;_ThreadName=Thread-5;|PWC1412:
> WebModule[/CallCenter] ServletContext.log():CometService: onEvent|#]
>
> [#|2008-10-06T16:34:01.866-0600|INFO|GlassFish10.0|javax.enterprise.system.container.web|_ThreadID=17;_ThreadName=Thread-5;|PWC1412:
> WebModule[/CallCenter] ServletContext.log():CometService:
> encoded=//OK[5,2,1,["ca.safetystar.client.comet.MessageSubclass/2737666392","25050"],0,4]|#]
>
> [#|2008-10-06T16:34:01.867-0600|INFO|GlassFish10.0|null|_ThreadID=17;_ThreadName=Thread-5;|Used
> cancelled file descriptor sun.nio.ch.SelectionKeyImpl_at_88e83d
> and
> sun.nio.ch.SelectionKeyImpl_at_1feb3a6|#]
>
> [#|2008-10-06T16:34:01.873-0600|INFO|GlassFish10.0|javax.enterprise.system.container.web|_ThreadID=18;_ThreadName=Thread-5;|PWC1412:
> WebModule[/CallCenter] ServletContext.log():CometService: DoConnect
> CALLED|#]
>
> [#|2008-10-06T16:34:02.902-0600|SEVERE|GlassFish10.0|javax.enterprise.system.container.web|_ThreadID=20;_ThreadName=Thread-5;|WebModule[/CallCenter]Exception
> while dispatching incoming RPC call
> 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:568)
> at com.sun.grizzly.comet.CometEngine.handle(CometEngine.java:325)
> 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)
> |#]
>
> [#|2008-10-06T16:34:06.867-0600|INFO|GlassFish10.0|javax.enterprise.system.container.web|_ThreadID=23;_ThreadName=Thread-5;|PWC1412:
> WebModule[/CallCenter] ServletContext.log():CometService: onEvent|#]
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe_at_grizzly.dev.java.net
> For additional commands, e-mail: users-help_at_grizzly.dev.java.net
>