Quantcast
Jersey

Logging filter is not working in MVCJ

classic Classic list List threaded Threaded
♦
♦
 2 messages Options
ndchandar
Reply | Threaded
Open this post in threaded view
♦
♦
|  
Report Content as Inappropriate
♦
♦
star
♦
♦

Logging filter is not working in MVCJ

ndchandar
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 > 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@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
Paul Sandoz
Reply | Threaded
Open this post in threaded view
♦
♦
|  
Report Content as Inappropriate
♦
♦
star
♦
♦

Re: Logging filter is not working in MVCJ

Paul Sandoz
Administrator
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:


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 > 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@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
Loading...
Powered by Nabble Edit this page