OmniFaces FullAjaxExceptionHandler logging specialization

Question

I've just extended the OminFaces' FullAjaxExceptionHandler class to add a simple feature needed by my project.

All I have to do is to simply log all the exceptions with my logger and add a unique error identifier both in the log and in the request (with a specific attribute name) that will be shown in the error page along with other information.

This will allow a quick retrieval of the error in the logs (the user just need to send this "identifier" to the support team). I overridden the logException() methods (tried both overloads) both but they are never called. Looking through the source of the FullAjaxExceptionHandler onn GitHub I saw that it is called in some specific cases. So instead I've overridden the findErrorPageLocation() method (this is a preliminary test code):

    public final static String ERROR_UUID = "javax.servlet.error.uuid";

    @Override
    protected String findErrorPageLocation(FacesContext context, Throwable exception) {            
        // Retrieve error page location from base class
        String location = super.findErrorPageLocation(context, exception); 
        // generate a unique error identifier
        String uuid = UUID.randomUUID().toString();
        // log into my logger
        logException(context, exception, location, "["+uuid+"]: "+exception.getMessage());
        // Retrieve request, put the new attribute to be shown into page and return the location
        HttpServletRequest req = (HttpServletRequest)context.getExternalContext().getRequest();
        req.setAttribute(ERROR_UUID, uuid);
        return location;
    }

In the page I've just added

<li>Error UUID: #{requestScope['javax.servlet.error.uuid']}</li>

to show the error uuid.

Well, it seems to work...but I don't know if this is the right place where to do such this kind of things. I would have preferred to overload only the logException() method because the thing I want to specialize is the logging and no other behaviour. Am I doing good or there's a better solution?

I'm using vanilla Java EE 7 (so JSF 2.2), OmniFaces 2.6.9 with Payara 5.181 and Java SE 1.8.0u170.

Answer 1

The FullAjaxExceptionHandler won't log exceptions of non-Ajax JSF requests. Exceptions of non-Ajax JSF requests (and non-JSF requests!) will normally reach a servlet Filter.

The findErrorPageLocation() method is indeed invoked right before the FullAjaxExceptionHandler checks whether it's an Ajax request, so you could also log exceptions of non-Ajax JSF requests there.

But if you ever want to log exceptions of non-JSF requests, then you would still need a servlet Filter. And in such case, exceptions of non-Ajax JSF requests would ultimately be logged twice. First time by the findErrorPageLocation() method of your custom exception handler and second time by the servlet Filter.

Ideally, you'd better have both a custom FullAjaxExceptionHandler and a custom FacesExceptionHandler whenever you want to finetune logging for every single possible exception thrown by the web application.

Thus, one for exceptions during JSF Ajax requests:

public class CustomExceptionHandler extends FullAjaxExceptionHandler {

    public CustomExceptionHandler(ExceptionHandler wrapped) {
        super(wrapped);
    }

    @Override
    protected void logException(FacesContext context, Throwable exception, String location, LogReason reason) {
        String uuid = UUID.randomUUID().toString();
        String ip = FacesLocal.getRemoteAddr(context);
        FacesLocal.setRequestAttribute(context, "UUID", uuid);
        super.logException(context, exception, location, "[%s][%s] %s", uuid, ip, reason.getMessage(), location);
    }

    public static class Factory extends FullAjaxExceptionHandlerFactory {
        public Factory(ExceptionHandlerFactory wrapped) {
            super(wrapped);
        }

        @Override
        public ExceptionHandler getExceptionHandler() {
            return new CustomExceptionHandler(getWrapped().getExceptionHandler());
        }
    }
}

which is mapped in faces-config.xml as

<factory>
    <exception-handler-factory>com.example.CustomExceptionHandler$Factory</exception-handler-factory>
</factory>

And another for exceptions during all other requests:

@WebFilter(filterName="customExceptionFilter")
public class CustomExceptionFilter extends FacesExceptionFilter {

    private static final Logger logger = Logger.getLogger(CustomExceptionHandler.class.getName());

    @Override
    public void doFilter(HttpServletRequest request, HttpServletResponse response, HttpSession session, FilterChain chain) throws ServletException, IOException {
        try {
            super.doFilter(request, response, session, chain);
        }
        catch (Exception e) {
            String uuid = UUID.randomUUID().toString();
            String ip = Servlets.getRemoteAddr(request);
            request.setAttribute("UUID", uuid);
            logger.log(Level.SEVERE, String.format("[%s][%s]", uuid, ip), e);
            throw e;
        }
    }
}

which is mapped in web.xml as the very first <filter-mapping> entry:

<filter-mapping>
    <filter-name>customExceptionFilter</filter-name>
    <url-pattern>/*</url-pattern>
</filter-mapping>

Having OmniFaces own FullAjaxExceptionHandler and FacesExceptionFilter to log all exceptions along with an UUID (and IP) would certainly be a useful improvement. This is indeed not an uncommon business requirement. It'll come in the next version.

Answer 2

I apologize for not answering your direct question but maybe I can give you a better overall solution that we use in Production that lets you avoid editing the OmniFaces code and gives you more powerful logging using a servlet filter.

Using a servlet filter you can take advantage of Log4J or SLF4J Mapped Device Context which puts a variable on the thread its being used. Just like you, we also use a UUID to generate a unique ID every time per HTTP request.

Filter:

import java.io.IOException;
import java.util.UUID;

import javax.servlet.Filter;
import javax.servlet.FilterChain;
import javax.servlet.FilterConfig;
import javax.servlet.ServletException;
import javax.servlet.ServletRequest;
import javax.servlet.ServletResponse;
import javax.servlet.http.HttpServletRequest;
import javax.ws.rs.core.HttpHeaders;

import org.apache.commons.lang3.StringUtils;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;


/**
 * Servlet filter used to attach incoming HTTP request values into the MDC so
 * they can be used throughout the entire request->response cycle for
 * logging.
 */
public class MDCLogFilter implements Filter {

   private static final Logger LOG = LoggerFactory.getLogger(MDCLogFilter.class);

   @Override
   public void doFilter(final ServletRequest request, final ServletResponse response, final FilterChain chain)
            throws IOException, ServletException {

      // add remote ip of incoming request
      MDC.put("ipv4", request.getRemoteAddr());

      // check for any specific Servlet values
      if (request instanceof HttpServletRequest) {
         final HttpServletRequest httpRequest = (HttpServletRequest) request;
         // try and get the username
         String username = httpRequest.getRemoteUser();

         // if not found then use their IP address as their username
         username = StringUtils.defaultIfBlank(username, request.getRemoteAddr());

         // uppercase the username for consistency
         MDC.put("user", StringUtils.upperCase(username));

         // first look for one passed in from the caller on the header
         String correlationId = httpRequest.getHeader("uuid");
         correlationId = StringUtils.defaultIfBlank(correlationId, UUID.randomUUID().toString());

         // unique ID for this thread context
         MDC.put("uuid", correlationId);
         request.setAttribute("javax.servlet.error.uuid", uuid);

         // get the browser user agent
         MDC.put("user-agent", httpRequest.getHeader(HttpHeaders.USER_AGENT));
      }

      try {
         chain.doFilter(request, response);
      } finally {
         MDC.clear();
      }
   }


}

In your web.xml apply this filter on every single incoming HTTP request using *.

web.xml

<!-- Inject additional logging attributes into each servlet request -->
<filter>
    <filter-name>MDCFilter</filter-name>
    <filter-class>com.melloware.servlet.MDCLogFilter</filter-class>
</filter>
<filter-mapping>
    <filter-name>MDCFilter</filter-name>
    <url-pattern>/*</url-pattern>
</filter-mapping>

Logback and Log4J can then use your MDC values in the log output so its attached to every log line. I use SLF4J and Logback so my example is below using the %X notation to display the unique ID and the user in every log line...

Log Settings:

<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender" >
    <file>application.log</file>
    <encoder>
        <pattern>%-5level - [id=%X{uuid} user=%X{user}] %logger{35} - %msg%n</pattern>
    </encoder>
</appender>

It has 2 advantages:

1. You can use your "javax.servlet.error.uuid" in your error page since its been stuffed in the request or response.
2. ALL of your log messages in your log have the UUID so you can track an entire request from the time the customer submitted through all of your logic and to the response (or ERROR) quickly and easily. if a customer calls up with that UUID on their error page you can GREP your logs for that and see their entire chain of events including the stack trace.