How to log multiple threads in different log files?

Question

I have a JAVA class that starts various threads that have unique IDs. Each thread should log into a unique log file, named after the ID.log.

Because I only get the unique ID at runtime, I have to configure Log4J programatically:

// Get the jobID
myJobID = aJobID;
// Initialize the logger
myLogger = Logger.getLogger(myJobID);
FileAppender myFileAppender;
try
{
    myFileAppender = new FileAppender(new SimpleLayout(), myJobID + ".log", false);
    BasicConfigurator.resetConfiguration();
    BasicConfigurator.configure(myFileAppender);
} catch (IOException e1) {
// TODO Auto-generated catch block
    e1.printStackTrace();
}

Now this works fine if I start jobs sequentially - but when I start 2 threads (of the same class) simultaneously, both logs are created but the logs are mixed up: The second thread logs into the first as well as the second log.

How could I make sure that each instance is unique ? I already tried to give a unique name to each logger instance, but it did not change anything.

Answer 1

Logback has a special appender called SiftingAppender which provides a very nice solution to the type of problems you describe. A SiftingAppender can be used to separate (or sift) logging according to any runtime attribute, including thread id.

Answer 2

For log4j v2 you can use RoutingAppender to dynamically route messages. You can put value for key 'threadId' into the ThreadContext map and then use this id as a part of the file name. There is an example which I have easily applied for the same purpose as yours. See http://logging.apache.org/log4j/2.x/faq.html#separate_log_files

Be aware when putting values into ThreadContext map: "A child thread automatically inherits a copy of the mapped diagnostic context of its parent." So if you have put a value for key 'threadId' into the parent thread and eventually created multiple threads from it, then all child threads will inherit the value of 'threadId' value. I was not able to simply override this value by using put() one more time - you need to use ThreadContext.clear() or explicitly remove() the value from thread context map.

Here is my working log4j.xml:

<?xml version="1.0" encoding="UTF-8"?>
<configuration status="WARN">
    <properties>
        <property name="logMsgPattern">%d{HH:mm:ss} %-5level - %msg%n</property>
        <property name="logDir">test logs</property><!-- ${sys:testLogDir} -->
    </properties>
    <appenders>
         <Console name="Console" target="SYSTEM_OUT">           
            <PatternLayout pattern="${logMsgPattern}"/>
         </Console>

        <Routing name="Routing">
                    <Routes pattern="$${ctx:threadId}">             
                        <Route>
                            <RollingFile name="RollingFile-${ctx:threadId}" fileName="${logDir}/last-${ctx:threadId}.log" filePattern="${logDir}/%d{yyyy-MM-dd}/archived_%d{HH-mm}-${ctx:threadId}.log">
                                    <PatternLayout pattern="${logMsgPattern}"/>
                                    <Policies>
                                <OnStartupTriggeringPolicy />
                            </Policies> 
                    </RollingFile>
                        </Route>
                    </Routes>
            </Routing>  
    </appenders>

    <loggers>               
        <root level="debug">
            <appender-ref ref="Console" level="debug" />
            <appender-ref ref="Routing" level="debug"/>
        </root>                     
    </loggers>  
</configuration>

Answer 3

@havexz 's approach is quite good: writing everything to the same log file and using nested diagnostic contexts.

If your concern is about several JVMs writing to the same FileAppender, then i'd suggest two things:

• using SLF4J as a logging facade
• using logback as logging implementation, in prudent mode

In prudent mode, FileAppender will safely write to the specified file, even in the presence of other FileAppender instances running in different JVMs, potentially running on different hosts.

Answer 4

Here is the snippet of the Routing code from a working log4j.xml file.

<Appenders>

        <Console name="ConsoleAppender" target="SYSTEM_OUT">
            <PatternLayout>
                <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5level %-50logger{4}: %msg%n</pattern>
            </PatternLayout>
        </Console>
    <Routing name="RoutingAppender">
                <Routes pattern="${ctx:logFileName}">


                    <!-- This route is chosen if ThreadContext has a value for logFileName. 
                        The value dynamically determines the name of the log file. -->

                    <Route>
                        <RollingFile name="Rolling-${ctx:logFileName}"
                            fileName="${sys:log.path}/${ctx:logFileName}.javalog"
                            filePattern="./logs/${date:yyyy-MM}/${ctx:logFileName}_%d{yyyy-MM-dd}-%i.log.gz">
                            <PatternLayout>
                                <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5level %-50logger{4}: %msg%n</pattern>
                            </PatternLayout>
                            <Policies>
                                <TimeBasedTriggeringPolicy interval="6"
                                    modulate="true" />
                                <SizeBasedTriggeringPolicy size="10 MB" />
                            </Policies>
                        </RollingFile>
                    </Route>

                    <!-- This route is chosen if ThreadContext has no value for key logFileName. -->
                    <Route key="${ctx:logFileName}" ref="ConsoleAppender" />

                </Routes>
            </Routing>
</Appenders>
    <loggers>
        <root level="debug">
            <appender-ref ref="RoutingAppender" level="debug" />
        </root>
    </loggers>

The key 'logFileName' can be added to the thread context map in the run() method of the Runnable class as follows,

public class SomeClass implements Runnable{

 private int threadID;

 public SomeClass(int threadID){
   this.threadID=threadID;
   }
 @Override
 public void run() {
    String logFileName = "thread_log_"+ threadID;
    ThreadContext.put("logFileName", logFileName);
    //Some code
    ThreadContext.remove("threadId");
   }
}

In addition, the correct log4j packages must be imported, as shown below.

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.ThreadContext;

Please note that the following imports will not work. LogManager and Logger must also come from org.apache.logging.log4j.

import org.apache.log4j.LogManager;
import org.apache.log4j.Logger;
import org.apache.logging.log4j.ThreadContext;

Answer 5

As far as I can tell ThreadLocal API was designed to do what you describe.

Code like below would establish per-thread loggers each using own (per-thread) FileAppender:

/**
 * usage: threadLocalLogger.get().info("hello thread local logger")
 */
static ThreadLocal<Logger> threadLocalLogger = newThreadLocalLogger("myJobId");

private static ThreadLocal<Logger> newThreadLocalLogger(final String myJobID) {
    return new ThreadLocal<Logger>() {
        @Override
        protected Logger initialValue() {
            return logger(myJobID, Thread.currentThread().getId());
        }
    };
}

private static Logger logger(String myJobID, long threadId) {
    // Initialize the logger
    String loggerId = myJobID + "-" + threadId;
    Logger myLogger = Logger.getLogger(loggerId);
    FileAppender myFileAppender;
    try
    {
        myFileAppender = new FileAppender(new SimpleLayout(),
                loggerId + ".log", false);
        BasicConfigurator.resetConfiguration();
        BasicConfigurator.configure(myFileAppender);
    } catch (IOException e1) {
    // TODO Auto-generated catch block
        e1.printStackTrace();
    }
    return myLogger;
}

Answer 6

What about adding a static instance counter variable to your class. Then you would need a synchronized method which increases the counter for each object created and create the log file name from that value. Something like this:

class yourClass {

  private static int cnt = 0;

  public yourClass(){
    ...
    initLogger();
  }

  private synchronized initLogger(){
     yourClass.cnt++;
     myJobid = yourClass.cnt;

     //include your logging code here
  }
}