Logs are not recorded using CustomRequestLog

[HemanthKarniyana]

Jetty Version
12.0.14

Jetty Environment

ee8

Java Version
17

Question

Am trying to record the http request logs into a file using RequestLogWriter and CustomRequestLog as follows :
With the below setup, the file is getting created /tmp/example-2024_11_27.request.log but the logs are not getting recorded, any suggestion would be great help. Thank you.

<Configure id="Example" class="org.eclipse.jetty.ee8.webapp.WebAppContext">
  <New id="RequestLogWriter" class="org.eclipse.jetty.server.RequestLogWriter">
      <Set name="filename">/tmp/example-yyyy_mm_dd.request.log</Set>
      <Set name="filenameDateFormat"><Property name="jetty.requestlog.filenameDateFormat" default="yyyy_MM_dd"/></Set>
  </New>

  <New id="RequestLogImpl" class="org.eclipse.jetty.server.CustomRequestLog">
      <Arg><Ref refid="RequestLogWriter"/></Arg>
      <Arg>
        <Property name="jetty.customrequestlog.formatString">
          <Default>%{client}a - %u %t \"%r\" %s %O \"%{Referer}i\" \"%{User-Agent}i\"</Default>
        </Property>
      </Arg>
  </New>

  <Call name="setServer">
    <Arg>
      <New id="Server" class="org.eclipse.jetty.server.Server">
          <Set name="RequestLog"><Ref refid="RequestLogImpl"/></Set>
      </New>
    </Arg>
  </Call>
</Configure>

[joakime]

The RequestLog doesn't belong in a WebAppContext configuration.
That's far too late.

This should be done at startup of the Server.

Just enable the requestlog module, and configure it in ${jetty.base}/start.d/requestlog.ini

[HemanthKarniyana]

I have multiple webapps running in a server and i want to seperate the requestlogs based on the WebAppContext, how can i achieve this using requestLog module.

[HemanthKarniyana]

Hi @joakime any suggestions on the above comment.

[joakime]

@HemanthKarniyana you cannot do that with RequestLog.

The RequestLog only exists on the Server level. (your own XML shows this)
There's no webapp specific RequestLog support.

This is because RequestLog needs to report all request access types, even failures.
A Handler based RequestLog cannot do that, as failed requests will not even enter the Handler tree.
A Handler based RequestLog is also incapable of logging all request failure scenarios. (where a request is valid, enters the Handler tree, and then fails within a Handler)

[HemanthKarniyana]

Thank you for the response.

[joakime]

@HemanthKarniyana note, there are some solutions to RequestLog that others have been happy with.

One scenario is to use Slf4jRequestLogWriter instead of RequestLogWriter.

https://javadoc.jetty.org/jetty-12/org/eclipse/jetty/server/Slf4jRequestLogWriter.html

This makes all of the RequestLog events output on slf4j, to the named logger of your choice.
From there you can use any logging library you want to to route the requestlog events to wherever your logging library supports.

With this setup, you can use the combination of NDC/MDC with Logging event sifting/appending.
From there you would setup something in your webapps to provide a NDC/MDC context for that webapp.

And you would setup your logging library to sift based on that NDC/MDC context to individual files.

The end result is that requests that reach the webapp properly get sifted into their own logging files, but other failed requests sit in the default logging file.
This can be further refined in your logging library configuration to have a master requestlog with everything, and sub-requestlog files with webapp specific events.

[HemanthKarniyana]

Hello @joakime , i have tried the above mentioned approach. But the problem is " whenever a http request is made, the server checks for MDC.get(contextPath) before entering into the filterchain itself. the contextPath is null and always logs to default file. Below are the details, can you please help if am missing something.

1. MDCHandler.java (created a MDCHandler.jar and placed under jetty-base/lib/ext. Add the filter mapping to the webapp.

package com.example.MDCHandler;

import javax.servlet.*;
import javax.servlet.http.HttpServletRequest;
import org.slf4j.MDC;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

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

public class MDCHandler implements Filter {

    private static final Logger logger = LoggerFactory.getLogger(MDCHandler.class);

    @Override
    public void init(FilterConfig filterConfig) throws ServletException {
        // Initialization logic, if any
    }

    @Override
    public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException {
        HttpServletRequest httpRequest = (HttpServletRequest) request;

        logger.info("Before setting MDC: contextPath={}, requestId={}", MDC.get("contextPath"), MDC.get("requestId"));
        
        // Set MDC context based on the request path or other relevant information
        String contextPath = httpRequest.getContextPath();
        String requestId = UUID.randomUUID().toString();
        
        MDC.put("contextPath", contextPath);
        MDC.put("requestId", requestId);

        // Log MDC values to ensure they're being set correctly
        logger.info("After setting MDC: contextPath={}, requestId={}", MDC.get("contextPath"), MDC.get("requestId"));

        // Ensure MDC context is propagated to worker threads
        Map<String, String> contextMap = MDC.getCopyOfContextMap();
        
        // For asynchronous tasks or worker threads, propagate MDC context
        Runnable task = () -> {
            if (contextMap != null) {
                MDC.setContextMap(contextMap);  // Propagate MDC context to the new thread
            }
            // Do some work in the worker thread, and logging will use the MDC context
            logger.info("This log comes from the worker thread with MDC context.");
        };

        // Example of submitting the task to a thread pool or new thread
        new Thread(task).start();  // Or submit it to a thread pool if applicable

        try {
            // Continue filter chain processing
            chain.doFilter(request, response);
        } finally {
            // Clear MDC context after the request is processed
            MDC.clear();
        }
    }

    @Override
    public void destroy() {
        // Cleanup, if any
    }
}

2. jetty-requestlog.xml (Used slf4j requestLogWriter instead of RequestLogWriter)

<?xml version="1.0"?>
<!DOCTYPE Configure PUBLIC "-//Jetty//Configure//EN" "https://www.eclipse.org/jetty/configure_10_0.dtd">
<Configure id="Server" class="org.eclipse.jetty.server.Server">

  <Set name="RequestLog">
    <New id="RequestLog" class="org.eclipse.jetty.server.CustomRequestLog">
      <!-- Writer -->
      <Arg>
        <New class="org.eclipse.jetty.server.Slf4jRequestLogWriter">
            <Set name="loggerName">jetty.requestlog</Set>
        </New>
      </Arg>

      <!-- Format String -->
      <Arg>
        <Property name="jetty.requestlog.formatString" deprecated="jetty.customrequestlog.formatString">
          <Default>
            <Get class="org.eclipse.jetty.server.CustomRequestLog" name="EXTENDED_NCSA_FORMAT"/>
          </Default>
        </Property>
      </Arg>
    </New>
  </Set>

</Configure>

3. logback.xml (setup the logger and siftingappender based on the contextPath).

<?xml version="1.0" encoding="UTF-8"?>

<configuration>

    <appender name="SIFT" class="ch.qos.logback.classic.sift.SiftingAppender">
        <discriminator class="ch.qos.logback.classic.sift.MDCBasedDiscriminator">
            <key>contextPath</key>
            <defaultValue>/default</defaultValue>
        </discriminator>
        <sift>
            <appender name="FILE-${contextPath}" class="ch.qos.logback.core.FileAppender">
                <file>./logs${contextPath}.request.log</file> 
                <layout class="ch.qos.logback.classic.PatternLayout">
                    <pattern>[%X{contextPath:-not-set}] [%X{requestId}] %msg%n%rEx</pattern>
                </layout>
            </appender>
        </sift>
    </appender>
    <logger name="jetty.requestlog" level="INFO" additivity="false">
        <appender-ref ref="SIFT" />
    </logger>

</configuration>

4. logFile created : ./logs/default.request.log. Contents/requestlog events are as follows. We can see the contextPath is not set by MDCHandler yet.

[not-set] [] [0:0:0:0:0:0:0:1] - - [05/Dec/2024:17:59:50 +0000] "GET /example/alive HTTP/1.1" 200 2 "-" "curl/7.29.0"
[not-set] [] [0:0:0:0:0:0:0:1] - - [05/Dec/2024:18:00:02 +0000] "GET /example/alive HTTP/1.1" 200 2 "-" "curl/7.29.0"

Please have a look whenever you got some time.

Thank you.