Hi Dinesh,
The container response logger is interfering with request forwarding.
It buffers a response entity, logs it and then writes that buffered
response to the underlying servlet output stream even if the number of
bytes is zero. So i think it may be possible to fix. Can you log an
issue?
As a work around you can disable logging of entities by doing:
params
.put("com.sun.jersey.config.feature.logging.DisableEntitylogging",
"true");
See:
https://jersey.dev.java.net/nonav/apidocs/1.1.2-ea/jersey/com/sun/jersey/api/container/filter/LoggingFilter.html
#FEATURE_LOGGING_DISABLE_ENTITY
Note that logging at the level of the Jersey layer will never log a
representation produced from JSP page at the servlet layer.
Paul.
On Oct 16, 2009, at 8:54 AM, Dinesh Narayanan wrote:
> Hello Paul,
> When I added logging filter parameters to my GuiceConfig class, I
> get the following exception - java.lang.IllegalStateException:
> PWC3990: getWriter() has already been called for this response.
> I was getting the same error even if was using only ServletContainer
> filter in my web.xml(and in Glassfish too). However the filter works
> correctly when I return a text or json(instead of returning an
> instance of Viewable) from my resource class.
>
> My config class:
> public class MyGuiceServletConfig extends
> GuiceServletContextListener {
> private static final Logger logger =
> Logger.getLogger(MyGuiceServletConfig.class);
>
> @Override
> protected Injector getInjector() {
> final ServletModule servletModule = new ServletModule() {
> @Override
> protected void configureServlets() {
> logger.info("inside configureServlets method");
> Map<String, String> params = new HashMap<String,
> String>();
> params.put("com.sun.jersey.config.feature.Redirect",
> "true");
>
> params.put("com.sun.jersey.config.feature.ImplicitViewables", "true");
> params.put("com.sun.jersey.config.property.packages",
> "com.brocade.webportal.resource");
>
> params.put("com.sun.jersey.config.property.WebPageContentRegex", "/
> (dojo|dijit|dojox|util|js|jsp)/.*");
>
>
> params
> .put
> ("com
> .sun
> .jersey
> .spi
> .container
> .ContainerRequestFilters
> ","com.sun.jersey.api.container.filter.LoggingFilter");
>
> params
> .put
> ("com
> .sun
> .jersey
> .spi
> .container
> .ContainerResponseFilters
> ","com.sun.jersey.api.container.filter.LoggingFilter");
>
> filter("/*").through(GuiceContainer.class, params);
>
> //bind resources
> bind(HelloWorldResource.class);
> }
> };
>
> return Guice.createInjector(servletModule);
> }
> }
>
> I get the following exception stacktrace:
> INFO: Initiating Jersey application, version 'Jersey: 1.1.2-ea
> 08/25/2009 04:39 PM'
> Oct 15, 2009 11:39:55 PM
> com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory
> getComponentProvider
> INFO: Binding com.brocade.webportal.resource.HelloWorldResource to
> GuiceManagedComponentProvider with the scope "PerRequest"
> Hit ENTER for redeploy
> Oct 15, 2009 11:40:07 PM
> com.sun.jersey.api.container.filter.LoggingFilter filter
> INFO: 1 * Server in-bound request
> 1 > GET http://localhost:8080/JGExample/helloworld
> 1 > accept-encoding: gzip,deflate
> 1 > connection: keep-alive
> 1 > accept-language: en-us,en;q=0.5
> 1 > host: localhost:8080
> 1 > accept-charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
> 1 > user-agent: Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10.6; en-
> US; rv:1.9.1.3) Gecko/20090824 Firefox/3.5.3
> 1 > cookie: JSESSIONID=c09ac101a1a1c6639e2d1e8a654b
> 1 > accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/
> *;q=0.8
> 1 > keep-alive: 300
> 1 >
>
> 2009-10-15 23:40:07,996 INFO
> [com.brocade.webportal.resource.HelloWorldResource] - <inside
> HelloWorldResource get()>
> 2009-10-15 23:40:07,998 INFO
> [com.brocade.webportal.resource.HelloWorldResource] - <uri info
> com.sun.jersey.server.impl.application.WebApplicationContext_at_626664fc>
> 2009-10-15 23:40:07,998 INFO
> [com.brocade.webportal.resource.HelloWorldResource] - <abs path http://localhost:8080/JGExample/helloworld
> >
> 2009-10-15 23:40:07,998 INFO
> [com.brocade.webportal.resource.HelloWorldResource] - <baseUri http://localhost:8080/JGExample/
> >
> 2009-10-15 23:40:07,998 INFO
> [com.brocade.webportal.resource.HelloWorldResource] - <getPath
> helloworld>
> Oct 15, 2009 11:40:08 PM
> com.sun.jersey.api.container.filter.LoggingFilter$Adapter finish
> INFO: 1 * Server out-bound response
> 1 < 200
> 1 < Content-Type: text/plain
> 1 <
>
> Oct 15, 2009 11:40:08 PM
> org.apache.catalina.core.StandardWrapperValve log
> SEVERE: StandardWrapperValve[default]: PWC1406: Servlet.service()
> for servlet default threw exception
> java.lang.IllegalStateException: PWC3990: getWriter() has already
> been called for this response
> at
> org
> .apache
> .coyote.tomcat5.CoyoteResponse.getOutputStream(CoyoteResponse.java:
> 669)
> at
> org
> .apache
> .coyote
> .tomcat5
> .CoyoteResponseFacade.getOutputStream(CoyoteResponseFacade.java:196)
> at com.sun.jersey.spi.container.servlet.WebComponent
> $Writer.initiate(WebComponent.java:260)
> at com.sun.jersey.spi.container.servlet.WebComponent
> $Writer.write(WebComponent.java:236)
> at com.sun.jersey.api.container.filter.LoggingFilter
> $Adapter.finish(LoggingFilter.java:238)
> at
> com
> .sun
> .jersey.spi.container.ContainerResponse.write(ContainerResponse.java:
> 274)
> at
> com
> .sun
> .jersey
> .server
> .impl
> .application
> .WebApplicationImpl._handleRequest(WebApplicationImpl.java:763)
> at
> com
> .sun
> .jersey
> .server
> .impl
> .application
> .WebApplicationImpl.handleRequest(WebApplicationImpl.java:689)
> at
> com
> .sun
> .jersey
> .server
> .impl
> .application
> .WebApplicationImpl.handleRequest(WebApplicationImpl.java:680)
> at
> com
> .sun
> .jersey.spi.container.servlet.WebComponent.service(WebComponent.java:
> 324)
> at
> com
> .sun
> .jersey
> .spi
> .container.servlet.ServletContainer.service(ServletContainer.java:425)
> at
> com
> .sun
> .jersey
> .spi
> .container.servlet.ServletContainer.doFilter(ServletContainer.java:
> 751)
> at
> com
> .sun
> .jersey
> .spi
> .container.servlet.ServletContainer.doFilter(ServletContainer.java:
> 703)
> at
> com
> .google
> .inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:129)
> at
> com
> .google
> .inject
> .servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:59)
> at
> com
> .google
> .inject
> .servlet.ManagedFilterPipeline.dispatch(ManagedFilterPipeline.java:
> 122)
> at
> com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:110)
> at
> org
> .apache
> .catalina
> .core
> .ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:
> 234)
> at
> org
> .apache
> .catalina
> .core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:202)
> at
> org
> .apache
> .catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:
> 288)
> at
> org
> .apache
> .catalina
> .core.StandardContextValve.invokeInternal(StandardContextValve.java:
> 271)
> at
> org
> .apache
> .catalina.core.StandardContextValve.invoke(StandardContextValve.java:
> 202)
> at
> org
> .apache
> .catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:632)
> at
> org
> .apache
> .catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:577)
> at
> org
> .apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:
> 571)
> at
> org
> .apache
> .catalina.core.StandardHostValve.invoke(StandardHostValve.java:206)
> at
> org
> .apache
> .catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:632)
> at
> org
> .apache
> .catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:577)
> at
> org
> .apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:
> 571)
> at
> org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:1080)
> at
> org
> .apache
> .catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:
> 150)
> at
> org
> .apache
> .catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:632)
> at
> org
> .apache
> .catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:577)
> at
> org
> .apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:
> 571)
> at
> org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:1080)
> at
> org.apache.coyote.tomcat5.CoyoteAdapter.service(CoyoteAdapter.java:
> 270)
> at
> com
> .sun
> .grizzly
> .http.DefaultProcessorTask.invokeAdapter(DefaultProcessorTask.java:
> 605)
> at
> com
> .sun
> .grizzly
> .http.DefaultProcessorTask.doProcess(DefaultProcessorTask.java:536)
> at
> com
> .sun
> .grizzly.http.DefaultProcessorTask.process(DefaultProcessorTask.java:
> 785)
> at
> com
> .sun
> .grizzly
> .http.DefaultProtocolFilter.execute(DefaultProtocolFilter.java:137)
> at
> com
> .sun
> .enterprise
> .v3.services.impl.HttpProtocolFilter.execute(HttpProtocolFilter.java:
> 110)
> at
> com
> .sun
> .grizzly
> .DefaultProtocolChain
> .executeProtocolFilter(DefaultProtocolChain.java:124)
> at
> com
> .sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:
> 90)
> at
> com
> .sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:
> 75)
> at
> com
> .sun
> .grizzly
> .ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:54)
> at
> com
> .sun
> .grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:57)
> at
> com.sun.grizzly.util.WorkerThreadImpl.run(WorkerThreadImpl.java:179)
>
>
> Thanks
> Dinesh
>
>