Understanding Jetty Handlers and Why Empty Request Log

The Problem
I am trying to add RequestLogHandler to our jetty server. According to Jetty/Tutorial/RequestLog, I add RequestLogHandler in jetty.xml then restart Jetty server.
The log file is created, but after accessing some web pages, it is still empty: nothing appears in the log.
In a Hurry?
Basically, the problem is caused by the misconfiguration of the handler chain and the misunderstanding of the difference of HandlerCollection and HandlerList.

Root Cause Analysis
The code is our loyal friend. So I attach remote debug, and try to understand jetty's code.
Basically, when a http request comes, jetty will use its QueuedThreadPool to execute it, and each request will go through a handler chain until it is handled. 
The Original Code that Doesn't Work
Because the application has some special logic when deploy web application: our customized solr war may be called app1-solr.war or app2-solr.war. But we want the web application context root is /solr.

So we deploy wars in webapps folder manually.

for (File war : wars) {
  String context = war.getName();
  if (context.endsWith("solr.war")) {
    context = "solr";
  }
}
handlerList.addHandler(webappContext);

We also define some handlers in web.xml:

<Set name="handler">
  <New id="Handlers" class="org.eclipse.jetty.server.handler.HandlerCollection">
    <Set name="handlers">
      <Array type="org.eclipse.jetty.server.Handler">
        <Item>
          <New id="Contexts" class="org.eclipse.jetty.server.handler.ContextHandlerCollection"/>
        </Item>
        <Item>
          <New id="DefaultHandler" class="org.eclipse.jetty.server.handler.DefaultHandler"/>
        </Item>
        <Item>
          <New id="RequestLog" class="org.eclipse.jetty.server.handler.RequestLogHandler"/>
        </Item>
      </Array>
    </Set>
  </New>
</Set>

The original code that starts embedded jetty looks like below:

private Server doStartEmbeddedJetty()
{
  HandlerList handlers = new HandlerList();
  for (File war : wars) {
    WebAppContext webappContext = new WebAppContext();
    webappContext.setContextPath("/" + context);
    webappContext.setWar(war.getAbsolutePath());
    handlers.addHandler(webappContext);
  }
  Handler oldHandler = server.getHandler();
  if (oldHandler != null) {
    handlers.addHandler(oldHandler);
  }
  server.setHandler(handlers);
}

Its handler chain would be like below: The whole chain is a HandlerList, which contains:
WebAppContext: solr.war
WebAppContext: app1.war
...
One HandlerCollection, it contains: ContextHandlerCollection, DefaultHandler, RequestLogHandler.

When a request comes, it will be served by one of the WebAppContext handlers, and will return, the RequestLogHandler doesn't get chance to run at all.
Check the HandlerList implementation:

//This extension of HandlerCollection will call each contained handler in turn until either an exception is thrown
public void handle(String target, Request baseRequest, HttpServletRequest request, HttpServletResponse response) 
    throws IOException, ServletException
{
    Handler[] handlers = getHandlers();
    
    if (handlers!=null && isStarted())
    {
        for (int i=0;i<handlers.length;i++)
        {
            handlers[i].handle(target,baseRequest, request, response);
            if ( baseRequest.isHandled())
            // it will return here, RequestLogHandler doesn't get chance to run at all.
                return;
        }
    }
}

The Fix
Now we know the root cause of the problem, the fix would be easy. We will honour the handlers defined in jetty.xml, and add out customized WebAppContext into ContextHandlerCollection.

private Server doStartEmbeddedJetty()
{
  ContextHandlerCollection contextHandlers = null;
  Handler oldHandler = server.getHandler();
  if (oldHandler instanceof HandlerCollection) {
    Handler[] handlers = ((HandlerCollection) oldHandler).getHandlers();
    for (Handler handler : handlers) {
      if (handler instanceof ContextHandlerCollection) {
        contextHandlers = (ContextHandlerCollection) handler;
        break;
      }
    }
  }
  assert (contextHandlers != null);
  for (File war : wars) {
    WebAppContext webappContext = new WebAppContext();
    webappContext.setContextPath("/" + context);
    webappContext.setWar(war.getAbsolutePath());
    contextHandlers.addHandler(webappContext);
  }  
  HandlerList allHandlers = new HandlerList();
  // Notice the order: have to first add shutdown handler, then add contextHandlers, which will add default handler. allHandlers.addHandler(new ShutdownHandler(server, SHUTDOWN_PASSWORD) { 
    // some customization here.
  });
  allHandlers.addHandler(contextHandlers);
  server.setHandler(allHandlers);
}

Now the handler chain would be like below: The whole chain is a HandlerCollection which contains the following parts:
One ContextHandlerCollection which contains multiple WebAppContext such as solr.war, app1.war.
One HandlerCollection which contains DefaultHandler, RequestLogHandler.

The HandlerCollection's handle implementation looks like below:

//The default implementations calls all handlers in list order, regardless of the response status or exceptions. 
public void handle(String target, Request baseRequest, HttpServletRequest request, HttpServletResponse response) 
{
  for (int i=0;i<_handlers.length;i++)
  {
      _handlers[i].handle(target,baseRequest, request, response);

  }
}

So the ContextHandlerCollection will first handle it via one of its webappContext, then the remaining HandlerCollection will handle it:  DefaultHandler checks whether this handle is alredy handled, if yes, does nothing, otherwise throws 404 not found error, the RequestLogHandler now gets the chance to run, and would write the request info into log.

Or we may change HandlerList into HandlerCollection, but we want to honour the handler order in jetty.xml. If in the future we want to add a hanlder before ContextHandlerCollection, we can just add it in jetty.xml, no need to change the code.

Miscs
The best way to learn code or debug issue is to use IDE's Remote Debug. Put breakpoint in org.eclipse.jetty.server.Server.handle().

Resources
Jetty/Tutorial/RequestLog