10 Replies Latest reply on Sep 20, 2013 9:53 AM by mkouba

    Resteasy, handling and logging of WebApplicationException

    jrinderle

      Resteasy logs a stracktrace for all WebApplicationExceptions, which is not what I was expecting. My expectation was that Resteasy would catch this exception and return an appropriate response, but not log the exception. This creates a lot of output in the server logs.

      * What is the most appropriate way to specify a response status? I could return Response but it seems cleaner to return a specific type and throw WebApplicationException for errors.

      I created the following test case:

       @GET
       @Path("/status/{code}")
       public String getStatus(@PathParam("code") int statusCode) {
       throw new WebApplicationException(statusCode);
       }
      


      No matter what code I specify, the exception stack trace is logged to STDERR and I get the JBossWeb default error page back (even if I modify the code to specify no content).

      * This behavior caused me to question my understanding. Should I not specify a response status by throwing a WebApplicationException? Should I instead return Response or use a custom exception with an exception mapper? In a production environment I do not need to log a stack trace for 401, 404, etc.

      * Is it possible to disable the default error page and return an empty response? I tried changing the test case to
      throw new WebApplicationException(Response.noContent().status(statusCode).build());
      but I still get default error page.

      * I was also surprised to see the exception logged to STDERR. The documentation says that Resteasy uses slf4j configured or log4j. Perhaps I have something configured incorrectly?

      I have tested this behavior with Resteasy 1.0.2GA and 1.1RC2. I am running on JBoss 4.2.3.GA.

      When I request this resource with /status/401, I get the following response (output is from curl).

      < HTTP/1.1 401 Unauthorized
      < Date: Thu, 28 May 2009 16:36:38 GMT
      < Server: Apache
      < Content-Length: 948
      < Content-Type: text/html;charset=utf-8
      * Connection #0 to host localhost left intact
      * Closing connection #0
      <html><head><title>JBossWeb/2.0.1.GA - Error report</title><style><!--H1 {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;font-size:22px;} H2 {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;font-size:16px;} H3 {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;font-size:14px;} BODY {font-family:Tahoma,Arial,sans-serif;color:black;background-color:white;} B {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;} P {font-family:Tahoma,Arial,sans-serif;background:white;color:black;font-size:12px;}A {color : black;}A.name {color : black;}HR {color : #525D76;}--></style> </head><body><h1>HTTP Status 401 - </h1><HR size="1" noshade="noshade"><p><b>type</b> Status report</p><p><b>message</b> <u></u></p><p><b>description</b> <u>This request requires HTTP authentication ().</u></p><HR size="1" noshade="noshade"><h3>JBossWeb/2.0.1.GA</h3></body></html>
      


      And the following exception is logged (I sanitized my class and package name, line 74 corresponds to the exception thrown above):

      2009-05-28 12:38:42,883 ERROR [STDERR] 147486 [ajp-127.0.0.1-8009-11] ERROR org.jboss.resteasy.core.SynchronousDispatcher - failed t
      o execute
      2009-05-28 12:38:42,883 ERROR [STDERR] javax.ws.rs.WebApplicationException
      2009-05-28 12:38:42,883 ERROR [STDERR] at my.test.app.MyResource.getSessionDetails(MyResource.ja
      va:74)
      2009-05-28 12:38:42,883 ERROR [STDERR] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      2009-05-28 12:38:42,884 ERROR [STDERR] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
      2009-05-28 12:38:42,884 ERROR [STDERR] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      2009-05-28 12:38:42,884 ERROR [STDERR] at java.lang.reflect.Method.invoke(Method.java:597)
      2009-05-28 12:38:42,884 ERROR [STDERR] at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:119)
      2009-05-28 12:38:42,884 ERROR [STDERR] at org.jboss.resteasy.core.ResourceMethod.invokeOnTarget(ResourceMethod.java:211)
      2009-05-28 12:38:42,884 ERROR [STDERR] at org.jboss.resteasy.core.ResourceMethod.invoke(ResourceMethod.java:176)
      2009-05-28 12:38:42,884 ERROR [STDERR] at org.jboss.resteasy.core.ResourceMethod.invoke(ResourceMethod.java:166)
      2009-05-28 12:38:42,884 ERROR [STDERR] at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:356)
      2009-05-28 12:38:42,884 ERROR [STDERR] at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:160)
      2009-05-28 12:38:42,885 ERROR [STDERR] at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispat
      cher.java:113)
      2009-05-28 12:38:42,885 ERROR [STDERR] at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispat
      cher.java:69)
      2009-05-28 12:38:42,885 ERROR [STDERR] at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
      2009-05-28 12:38:42,885 ERROR [STDERR] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.j
      ava:290)
      2009-05-28 12:38:42,885 ERROR [STDERR] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
      2009-05-28 12:38:42,885 ERROR [STDERR] at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96)
      2009-05-28 12:38:42,885 ERROR [STDERR] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.j
      ava:235)
      2009-05-28 12:38:42,885 ERROR [STDERR] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
      2009-05-28 12:38:42,886 ERROR [STDERR] at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:230)
      2009-05-28 12:38:42,886 ERROR [STDERR] at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
      2009-05-28 12:38:42,886 ERROR [STDERR] at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.ja
      va:182)
      2009-05-28 12:38:42,886 ERROR [STDERR] at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:84)
      2009-05-28 12:38:42,886 ERROR [STDERR] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
      2009-05-28 12:38:42,886 ERROR [STDERR] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
      2009-05-28 12:38:42,886 ERROR [STDERR] at org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:
      157)
      2009-05-28 12:38:42,886 ERROR [STDERR] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
      2009-05-28 12:38:42,886 ERROR [STDERR] at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:262)
      2009-05-28 12:38:42,887 ERROR [STDERR] at org.apache.coyote.ajp.AjpProcessor.process(AjpProcessor.java:437)
      2009-05-28 12:38:42,887 ERROR [STDERR] at org.apache.coyote.ajp.AjpProtocol$AjpConnectionHandler.process(AjpProtocol.java:366)
      2009-05-28 12:38:42,887 ERROR [STDERR] at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:446)
      2009-05-28 12:38:42,887 ERROR [STDERR] at java.lang.Thread.run(Thread.java:619)
      


      SynchronousDispatcher.java:324:

      if (!(wae instanceof NoLogWebApplicationException)) logger.error("failed to execute", wae);


      My web.xml is as follows:

      <?xml version="1.0" encoding="UTF-8"?>
      <web-app version="2.5" xmlns="http://java.sun.com/xml/ns/javaee" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://java.sun.com/xml/ns/javaee http://java.sun.com/xml/ns/javaee/web-app_2_5.xsd">
       <context-param>
       <param-name>resteasy.scan</param-name>
       <param-value>true</param-value>
       </context-param>
       <listener>
       <listener-class>org.jboss.resteasy.plugins.server.servlet.ResteasyBootstrap</listener-class>
       </listener>
       <servlet>
       <servlet-name>RESTeasy</servlet-name>
       <servlet-class>org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher</servlet-class>
       </servlet>
       <servlet-mapping>
       <servlet-name>RESTeasy</servlet-name>
       <url-pattern>/*</url-pattern>
       </servlet-mapping>
      </web-app>
      


      Thank you for your help!

        • 1. Re: Resteasy, handling and logging of WebApplicationExceptio
          andrewe

          Little late, but I noticed the same thing - JBoss seems to log to STDERR for things I didn't expect (like when a resource is deployed via jax.ws.rs.Application class).

          I thought it would show up via my log4j appender, but no such luck. Is this a bug in Resteasy?

          • 2. Re: Resteasy, handling and logging of WebApplicationExceptio
            benzhang0001

            I got the same thing.  Any one can help or any one is using it?

            • 3. Re: Resteasy, handling and logging of WebApplicationException
              nakker

              Same problem, really annoying. Anyone have a solution?

              • 4. Re: Resteasy, handling and logging of WebApplicationException
                mkouba

                You can write you own ExceptionMapper for any exception, incl. the built-in WebApplicationException, and return any response you want (and skip RESTEasy logging). Have a look at javax.ws.rs.ext.ExceptionMapper in JAX-RS API. See also http://docs.jboss.org/resteasy/docs/2.3.4.Final/userguide/html/ExceptionHandling.html#ExceptionMappers.

                • 5. Re: Resteasy, handling and logging of WebApplicationException
                  davidforce

                  Hello, I have the same problem in EAP 6.10. Writing my own javax.ws.rs.ext.ExceptionMapper did NOT help.

                   

                  I've tried @ApplicationException - no change.

                  Glassfish also logged WebApplicationException. But subclassing WebApplicationException and marking it with @ApplicationException removed it from server.log.

                   

                  I did manage a workaround; throw custom non-runtime-exception and let a custom javax.ws.rs.ext.ExceptionMapper catch it. Not pretty at all.

                  Any news / howto?

                  (sad when an issue lives 4 years, lik this one...)

                  • 6. Re: Re: Resteasy, handling and logging of WebApplicationException
                    mkouba

                    That's really strange. Similar exception mapper did work for me on AS7/RESTEasy:

                    @Provider
                    public class MyWebApplicationExceptionMapper implements
                            ExceptionMapper<WebApplicationException> {
                    
                        private static final Logger logger = ...;
                    
                        @Override
                        public Response toResponse(WebApplicationException exception) {
                            logger.warn("WebApplicationException thrown [statusCode: {}]",
                                    exception.getResponse().getStatus());
                            return Response.status(exception.getResponse().getStatus()).build();
                        }
                    
                    • 7. Re: Resteasy, handling and logging of WebApplicationException
                      davidforce

                      Thanks for prompt reply - I like!

                      The WebApplicationException IS cought by MyWebApplicationExceptionMapper. But the issue is that it is logged in server log.

                      I guess this might be the place;

                       

                      http://grepcode.com/file/repository.jboss.org/nexus/content/repositories/releases/org.jboss.resteasy/resteasy-jaxrs/2.0-beta-2/org/jboss/resteasy/core/SynchronousDispatcher.java#SynchronousDispatcher.handleWebApplicationException%28org.jboss.resteasy.spi.HttpResponse%2Cjavax.ws.rs.WebApplicationException%29

                       

                      If I read the code correctly I have to subclass org.jboss.resteasy.spi.NoLogWebApplicationException to make sure it does not end up in server.log. I find this not OK - I want my code to be provider neutral - ie. not include org.jboss.resteasy.

                      May I suggest inspiration from Glassfish? It checks if the whrown WebApplicationException is marked as http://docs.oracle.com/javaee/5/api/javax/ejb/ApplicationException.html and then excludes it from server.log.

                       

                      Server.log (i run vanilla EAP 6.1.1):

                      ------------------

                      ejb3.invocation] (http-/127.0.0.1:8080-4) JBAS014134: EJB Invocation failed on component FileloaderRestFacade for method public abstract void se.uc.fileloader.api.parser.IRESTRequesterFacade.registerParser(se.uc.fileloader.api.domainobject.RegisterDO): javax.ejb.EJBException: javax.ws.rs.WebApplicationException

                        at org.jboss.as.ejb3.tx.CMTTxInterceptor.handleExceptionInOurTx(CMTTxInterceptor.java:165) [jboss-as-ejb3-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]

                        at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:250) [jboss-as-ejb3-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]

                        at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:315) [jboss-as-ejb3-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]

                        at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:214) [jboss-as-ejb3-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]

                        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]

                        at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) [jboss-as-ejb3-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]

                        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]

                        at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64) [jboss-as-ejb3-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]

                        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]

                        at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:59) [jboss-as-ejb3-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]

                        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]

                        at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50) [jboss-as-ee-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]

                        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]

                        at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:55) [jboss-as-ejb3-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]

                        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]

                        at org.jboss.as.ee.component.TCCLInterceptor.processInvocation(TCCLInterceptor.java:45) [jboss-as-ee-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]

                        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]

                        at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]

                        at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:165) [jboss-as-ee-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]

                        at org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:182) [jboss-as-ee-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]

                        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]

                        at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]

                        at org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:72) [jboss-as-ee-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]

                        at se.uc.fileloader.api.parser.IRESTRequesterFacade$$$view128.registerParser(Unknown Source) [fileloader-api-0.0.1-SNAPSHOT.jar:]

                        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_25]

                        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_25]

                        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_25]

                        at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_25]

                        at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:167) [resteasy-jaxrs-2.3.6.Final-redhat-1.jar:2.3.6.Final-redhat-1]

                        at org.jboss.resteasy.core.ResourceMethod.invokeOnTarget(ResourceMethod.java:269) [resteasy-jaxrs-2.3.6.Final-redhat-1.jar:2.3.6.Final-redhat-1]

                        at org.jboss.resteasy.core.ResourceMethod.invoke(ResourceMethod.java:227) [resteasy-jaxrs-2.3.6.Final-redhat-1.jar:2.3.6.Final-redhat-1]

                        at org.jboss.resteasy.core.ResourceMethod.invoke(ResourceMethod.java:216) [resteasy-jaxrs-2.3.6.Final-redhat-1.jar:2.3.6.Final-redhat-1]

                        at org.jboss.resteasy.core.SynchronousDispatcher.getResponse(SynchronousDispatcher.java:542) [resteasy-jaxrs-2.3.6.Final-redhat-1.jar:2.3.6.Final-redhat-1]

                        at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:524) [resteasy-jaxrs-2.3.6.Final-redhat-1.jar:2.3.6.Final-redhat-1]

                        at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:126) [resteasy-jaxrs-2.3.6.Final-redhat-1.jar:2.3.6.Final-redhat-1]

                        at org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:208) [resteasy-jaxrs-2.3.6.Final-redhat-1.jar:2.3.6.Final-redhat-1]

                      • 8. Re: Re: Resteasy, handling and logging of WebApplicationException
                        mkouba

                        I don't think the logic you're referencing (NoLogWebApplicationException) should be executed if a custom exception mapper is found. From the stack it seems the thrown exception is javax.ejb.EJBException and javax.ws.rs.WebApplicationException is just a cause. Also it's not entirely clear what component logs the exception. Anyway JAX-RS spec states: "When choosing an exception mapping provider to map an exception, an implementation MUST use the provider whose generic type is the nearest superclass of the exception." I'm not completely sure what "generic type is the nearest superclass of the exception" means but there's no mention about exception cause. So I would say that your mapper is not executed.

                         

                        Also check the source of the closest version of RESTEasy you're using (2.3.6.Final for productized 2.3.6.Final-redhat-1):

                        http://grepcode.com/file/repo1.maven.org/maven2/org.jboss.resteasy/resteasy-jaxrs/2.3.6.Final/org/jboss/resteasy/core/SynchronousDispatcher.java#SynchronousDispatcher

                        • 9. Re: Re: Resteasy, handling and logging of WebApplicationException
                          davidforce

                          Hi, 2.3.6 is the module in eap 6.1.1. My exception mapper is invoked - ie. it does capture the WebApplicationException, I see it in my application log.

                           

                          XXX14:52:30.368 [default] WARN  [http-/127.0.0.1:8080-7] [s.u.i.f.r.MyWebApplicationExceptionMapper] ######### WebApplicationException thrown [statusCode: 403]

                           

                          I guess that some how, somwhere an  Yep, I guess this is a decision "how to log". I can work around and throw a non-runtime-exception - which a custom MyWebApplicationExceptionMapper can handle & the return suitable HTTP status.

                          • 10. Re: Re: Re: Resteasy, handling and logging of WebApplicationException
                            mkouba

                            Hi davidforce,

                            your last comment is somehow broken:

                            I guess that some how, somwhere an  Yep...

                            I still don't understand how this could be possible (maybe RESTEasy or EAP bug) but if the workaround works for you...