Log4j: One log file per request

Question

We have a weblogic batch application which processes multiple requests from consumers at the same time. We use log4j for logging puposes. Right now we log into a single log file for multiple requests. It becomes tedious to debug an issue for a given request as for all requests the logs are in a single file.

So plan is to have one log file per request. The consumer sends a request ID for which processing has to be performed. Now, in reality there could be multiple consumers sending the request IDs to our application. So question is how to seggregate the log files based on the request.

We cannot start & stop the production server every time so the point in using an overridden file appender with date time stamp or request ID is ruled out. This is what is explained in the article below: http://veerasundar.com/blog/2009/08/how-to-create-a-new-log-file-for-each-time-the-application-runs/

I also tried playing around with these alternatives:

http://cognitivecache.blogspot.com/2008/08/log4j-writing-to-dynamic-log-file-for.html

http://www.mail-archive.com/[e-mail]/msg05099.html

This approach gives the desired results but it does not work properly if multiple request are send at the same time. Due to some concurrency issues logs go here and there.

I anticipate some help from you folks. Thanks in advance....

Answer 1

This problem is handled very well by Logback. I suggest to opt for it if you have the freedom.

Assuming you can, what you will need to use is is SiftingAppender. It allows you to separate log files according to some runtime value. Which means that you have a wide array of options of how to split log files.

To split your files on requestId, you could do something like this:

logback.xml

<configuration>

  <appender name="SIFT" class="ch.qos.logback.classic.sift.SiftingAppender">
    <discriminator>
      <key>requestId</key>
      <defaultValue>unknown</defaultValue>
    </discriminator>
    <sift>
      <appender name="FILE-${requestId}" class="ch.qos.logback.core.FileAppender">
        <file>${requestId}.log</file>
        <append>false</append>
        <layout class="ch.qos.logback.classic.PatternLayout">
          <pattern>%d [%thread] %level %mdc %logger{35} - %msg%n</pattern>
        </layout>
      </appender>
    </sift>
  </appender>

  <root level="DEBUG">
    <appender-ref ref="SIFT" />
  </root>

</configuration>

As you can see (inside discriminator element), you are going to discriminate the files used for writing logs on requestId. That means that each request will go to a file that has a matching requestId. Hence, if you had two requests where requestId=1 and one request where requestId=2, you would have 2 log files: 1.log (2 entries) and 2.log (1 entry).

At this point you might wonder how to set the key. This is done by putting key-value pairs in MDC (note that key matches the one defined in logback.xml file):

RequestProcessor.java

public class RequestProcessor {

    private static final Logger log = LoggerFactory.getLogger(RequestProcessor.java);

    public void process(Request request) {
        MDC.put("requestId", request.getId());
        log.debug("Request received: {}", request);
    }
}

And that's basically it for a simple use case. Now each time a request with a different (not yet encountered) id comes in, a new file will be created for it.

Answer 2

Here's my question on the same topic: dynamically creating & destroying logging appenders

I follow this up on a thread where I discuss doing something exactly like this, on the Log4J mailing list: http://www.qos.ch/pipermail/logback-user/2009-August/001220.html

Ceci Gulcu (inventor of log4j) didn't think it was a good idea...suggested using Logback instead.

We went ahead and did this anyway, using a custom file appender. See my discussions above for more details.

Answer 3

Look at SiftingAppender shipping with logback (log4j's successor), it is designed to handle the creation of appenders on runtime criteria.

If you application needs to create just one log file per session, simply create a discriminator based on the session id. Writing a discriminator involves 3 or 4 lines of code and thus should be fairly easy. Shout on the logback-user mailing list if you need help.