How to get different threads to print to different log files.
This trick takes advantage of log4j's named, heirarchical loggers. Usually, you would just configure the root logger to append to an appender that points to one log file, like so:
log4j.rootLogger=INFO, MAIN_LOG_FILE
log4j.appender.MAIN_LOG_FILE=org.apache.log4j.DailyRollingFileAppender
log4j.appender.MAIN_LOG_FILE.File=/home/me/workspace/project/logs/main.log
log4j.appender.MAIN_LOG_FILE.layout=org.apache.log4j.PatternLayout
log4j.appender.MAIN_LOG_FILE.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5p %c - %m%n
And, whenever you needed to get a logger in your java code, you would just use the name of the class to get the logger.
private Logger log = Logger.getLogger(Worker.class);
or
private Logger log = Logger.getLogger(Worker.class.getName());
which is really just this (assuming Worker is in package com.whatever):
private Logger log = Logger.getLogger("com.whatever.Worker");
And, the logger for "com.whatever.Worker" is considered to be a child of the rootLogger
(everything is), so because rootLogger uses MAIN_LOG_FILE as its appender, calling
log.debug("Hello") in com.whatever.Worker outputs "Hello" to main.log.
In our example, we set the default log level for the rootLogger to INFO, but if we had a particular class we wanted to debug, we could set its logger to be the DEBUG log level instead:
log4j.logger.com.whatever.MyClass=DEBUG
and, as long as we set up our Logger inside MyClass using the name "com.whatever.MyClass", log.debug("hello") would inded print "hello" to main.log, because the logger with that name was configured that way (and is a child of the rootLogger, so its messages would still go to rootLogger's appender, MAIN_LOG_FILE, which outputs to the file main.log):
private Logger log = Logger.getLogger("com.whatever.MyClass");
Although usually, you would do this:
private Logger log = Logger.getLogger(this.getClass().getName());
or even this:
private Logger log = Logger.getLogger(this.getClass());
because log4j will call a Class object's getName() method for you.
The thing to appreciate is that log4j's loggers are handed to you based on any string you hand it, and any naming convention you like. It's just very popular to use the class/package heirarchy as a naming convention for the strings we hand to log4j. But we can use anything we like.
What we are going to do is add the thread name to the top of our heirarchy. So what we will do is instead of having a naming convention based on package.subpackage.Class, we are going to use threadName.package.subpackage.Class. (This means, of course, that we are going to have to name our threads; more on that later.)
Let's say we know we will have two worker threads named worker_1 and worker_2, and we would like instances of classes in either thread to print to a log file named for each thread. All we have to do is set up a logger naming convention for each thread, as discussed above, and then configure an appender for each logger rooted at that thread name.
In our log4j file, we set up our two loggers:
log4j.logger.worker_1=INFO, WORKER_1_LOG_FILE log4j.logger.worker_2=INFO, WORKER_2_LOG_FILE
Our two loggers use appenders named WORKER_1_LOG_FILE and WORKER_2_LOG_FILE respectively, so let's set up those two appenders:
log4j.appender.WORKER_1_LOG_FILE=org.apache.log4j.DailyRollingFileAppender
log4j.appender.WORKER_1_LOG_FILE.File=/home/me/workspace/project/logs/worker-1.log
log4j.appender.WORKER_1_LOG_FILE.layout=org.apache.log4j.PatternLayout
log4j.appender.WORKER_1_LOG_FILE.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5p %c - %m%n
log4j.appender.WORKER_2_LOG_FILE=org.apache.log4j.DailyRollingFileAppender
log4j.appender.WORKER_2_LOG_FILE.File=/home/me/workspace/project/logs/worker-2.log
log4j.appender.WORKER_2_LOG_FILE.layout=org.apache.log4j.PatternLayout
log4j.appender.WORKER_2_LOG_FILE.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5p %c - %m%n
Now, in our java code, instead of doing this to get a logger:
private Logger log = Logger.getLogger("com.whatever.MyClass");
we will do this:
private Logger log = Logger.getLogger("worker_1.com.whatever.MyClass");
so log gets the logger that is rooted at worker_1, and we just set logger worker_1 to use the appender WORKER_1_LOG_FILE. Of course, how you would really call getLogger() is like this:
private Logger log = Logger.getLogger(Thread.currentThread().getName() + "." + this.getClass().getName());
That way, different instances of your class running in different threads would get different values for Thread.currentThread().getName().
Of course, when you are first instantiating your threads, you had better give them the names you need, or none of this will work:
for (int i = 1; i <= 2; i++) {
String threadName = "worker_" + i;
log = Logger.getLogger(threadName + "." + Worker.class.getName());
Worker worker = new Worker(log);
Thread t = new Thread(worker);
t.setName(threadName);
t.start();
}
You will notice in the example above that we create a logger to hand to our Worker instances. That's because the worker instances, when instantiated, would return the wrong values for Thread.currentThread().getName(), because they are still being instantiated in the main thread. So, we hand the Worker objects log instances with the correct thread name as the root. The class pre-amble and constructor for Worker would look like this:
public class Worker implements Runnable {
private Logger log = null;
public Worker(Logger log) {
this.log = log;
}
and any use of log inside an instance of the Worker class would do the expected thing. But, most importantly, any object instantiated by our Worker instances would already be inside the correct thread, so they could just to this to get their loggers:
private Logger log = Logger.getLogger(Thread.currentThread().getName() + "." + this.getClass().getName());
which is very convenient, because it is boilerplate that can just be put inside the class definition of every object you need this sort of logging for.
Now, one problem with this solution is that although our objects correctly log their messages only to their respective thread log files, they also still log their messages to the main log file that the appender for the rootLogger uses. To get around this, you must tell log4j that messages, once handled by the loggers named for threads, do not need to be handled by the rootLogger as well:
log4j.additivity.worker_1=false log4j.additivity.worker_2=false
Now, our per-thread logging goes only to our per-thread log files, rather than to our per-thread log files plus our main log file.
Our complete example, then, is first the log4j file, which I have named log_file.properties:
log4j.rootLogger=INFO, MAIN_LOG_FILE
log4j.appender.MAIN_LOG_FILE=org.apache.log4j.DailyRollingFileAppender
log4j.appender.MAIN_LOG_FILE.File=/home/me/workspace/proj/logs/main.log
log4j.appender.MAIN_LOG_FILE.layout=org.apache.log4j.PatternLayout
log4j.appender.MAIN_LOG_FILE.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5p %c - %m%n
log4j.logger.worker_1=INFO, WORKER_1_LOG_FILE
log4j.additivity.worker_1=false
log4j.appender.WORKER_1_LOG_FILE=org.apache.log4j.DailyRollingFileAppender
log4j.appender.WORKER_1_LOG_FILE.File=/home/me/workspace/proj/logs/worker-1.log
log4j.appender.WORKER_1_LOG_FILE.layout=org.apache.log4j.PatternLayout
log4j.appender.WORKER_1_LOG_FILE.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5p %c - %m%n
log4j.logger.worker_2=INFO, WORKER_2_LOG_FILE
log4j.additivity.worker_2=false
log4j.logger.worker_2.m.SomethingElse=DEBUG
log4j.appender.WORKER_2_LOG_FILE=org.apache.log4j.DailyRollingFileAppender
log4j.appender.WORKER_2_LOG_FILE.File=/home/me/workspace/proj/logs/worker-2.log
log4j.appender.WORKER_2_LOG_FILE.layout=org.apache.log4j.PatternLayout
log4j.appender.WORKER_2_LOG_FILE.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5p %c - %m%n
com.whatever.Test:
package com.whatever;
import org.apache.log4j.Logger;
import org.apache.log4j.PropertyConfigurator;
public class Test {
// this logger will just use rootLogger
private static Logger log = Logger.getLogger(Thread.currentThread().getName() + "." + Test.class.getName());
public static void main(String args[]) {
System.out.println("Hello");
PropertyConfigurator.configure("/home/me/workspace/proj/conf/log4j/log_file.properties");
log.info("Hello world");
for (int i = 1; i <= 2; i++) {
String threadName = "worker_" + i;
log = Logger.getLogger(threadName + "." + Worker.class.getName());
Worker worker = new Worker(log);
Thread t = new Thread(worker);
t.setName(threadName);
t.start();
}
}
}
com.whatever.Worker:
package com.whatever;
import org.apache.log4j.Logger;
public class Worker implements Runnable {
private Logger log = null;
public Worker(Logger log) {
this.log = log;
}
@Override
public void run() {
SomethingElse se = new SomethingElse();
while (true) {
try {
log.info("Hello from thread named " + Thread.currentThread().getName());
se.doIt();
Thread.sleep(1000);
} catch (InterruptedException e) {
log.error("", e);
}
}
}
}
com.whatever.SomethingElse:
package com.whatever;
import org.apache.log4j.Logger;
public class SomethingElse {
private Logger log = Logger.getLogger(Thread.currentThread().getName() + "." + this.getClass().getName());
void doIt() {
log.info("This is something else! " + Thread.currentThread().getName() + " logger name: " + Thread.currentThread().getName() + "." + this.getClass().getName());
log.debug("This is a debug statement from " + Thread.currentThread().getName());
}
}
It should be noted that if you set up a thread named "worker_3" and did not set up a logger and appender for it in log_file.properties, then all loggers returned for names starting with "worker_3.*" would be considered to be children of the rootLogger, and log messages from those loggers would just go into main.log.