Best practices for Java logging from multiple threads?

Question

I want to have a diagnostic log that is produced by several tasks managing data. These tasks may be in multiple threads. Each task needs to write an element (possibly with subelements) to the log; get in and get out quickly. If this were a single-task situation I'd use XMLStreamWriter as it seems like the best match for simplicity/functionality without having to hold a ballooning XML document in memory.

But it's not a single-task situation, and I'm not sure how to best make sure this is "threadsafe", where "threadsafe" in this application means that each log element should be written to the log correctly and serially (one after the other and not interleaved in any way).

Any suggestions? I have a vague intuition that the way to go is to use a queue of log elements (with each one able to be produced quickly: my application is busy doing real work that's performance-sensitive), and have a separate thread which handles the log elements and sends them to a file so the logging doesn't interrupt the producers.

The logging doesn't necessarily have to be XML, but I do want it to be structured and machine-readable.

edit: I put "threadsafe" in quotes. Log4j seems to be the obvious choice (new to me but old to the community), why reinvent the wheel...

Answer 1

Use a logging framework, such as Log4j.

Answer 2

I think you are on the wrong path. You say “threadsafe” but you actually mean “serialized”. Threadsafe means that one thread will not interfere with data from other thread. Most of the time, threading issues are resolved beforehand and you should not worry about it just for logging sake. For example, if your write:

myVariableSum = 0 + myVariable;
//here comes other thread - Not very likely!
logger.info("Log some INFO; myVariable has value" + myVariable.toString());

You have to make sure that myVariable has not been changed by some other thread from the moment calculation (first line) was performed but before logging method was called. If this happens, you will log dirty value that was not used to perform the operation but value that was assigned by some other thread. This is generally taken care of; for example local (method level) variable can not be changed by other thread. Anyway, if you have to worry about this when logging, than 99% that your program has serious threading issues already.
All major logging frameworks are by themselves “threadsafe” meaning they can be deployed in multithreaded environments and will not display problems similar to one described above internally.
Getting traces to appear in log in order they happen is actually usually called “serialization” of calls. Serializing log writes will be a major performance bottleneck on any multithreaded app. If you use logging framework, like log4j, traces from all threads will appear in single place more or less in order they happen. However, one column is generally Thread name, so you can easily filter your log data by thread; each thread will log its data in chronological order. Check out this link: http://logging.apache.org/log4j/1.2/faq.html#1.7
Finally, if serializing log writes is what you really need, then you could use some kind of structure, like java.util.concurrent.BlockingQueue to route your messages.

Answer 3

Use logback-classic. It is a newer and better implementation of log4j.

Answer 4

You could use synchronization mechanisms (like a monitor or a semaphor) to make sure, that one log request is processed before accepting the next. This could all be hidden from the code calling the logging routines.

Answer 5

I tend to use SLF4J on top of Log4J. The parameterized logging functionality is especially attractive if you are going to have a lot of logging statements that may well get switched off in a production environment.

It can also run over the top of java.util.logging or use it's own simple output.

Answer 6

Use a logging framework, such as Log4.

and if you are not happy with the output you can write your own Appender, Filter, whatever to tweak it just write. So you could do even some caching to rearrange the entries, although I am not saying this is a good idea.

Answer 7

Use a logging framework that implements some form of the NDC pattern, like Log4J.

Answer 8

I had a similar problem and implementation demands for special logs only. My solution was:

1. I took a blockinglinkedqueue with size of *2 of the app's traffic/min.

2. All threads put the object in the queue and finishes the job.

3. Separate Log-Writer thread taking head object from queue and writing it to log4j file using a separate appender. This appender was not used for systemlogs.

This ensures that logs are written serially and always are in order.

This will not affect performance of the application since log writing is a completely separate process and will not create a bottleneck.

You can also use aysncappender of log4j.

Answer 9

log4j is and has been the standard for java logging for many years. But if you don't fancy an external dependency then the java.util.logging package provides an acceptable solution.

Answer 10

If you had to, you could roll your own .. using single-writer/single-reader FIFO or queues.

Answer 11

This is an old question but here's my solution using Log4J programmatically.

LogFactory class

import org.apache.log4j.Logger;
import org.apache.log4j.PropertyConfigurator;

import java.util.Properties;

public class LogFactory {

    private final static ThreadLocal<Logger> logFactory = new ThreadLocal<>();

    public static void createNewLogger(String className) {

        Logger log = Logger.getLogger("Thread" + className);

        Properties props = new Properties();
        props.setProperty("log4j.appender.file", "org.apache.log4j.RollingFileAppender");

        props.setProperty("log4j.appender.file.maxFileSize", "100MB");
        props.setProperty("log4j.appender.file.Append", "false");
        props.setProperty("log4j.", "100MB");
        props.setProperty("log4j.appender.file.maxBackupIndex", "100");
        props.setProperty("log4j.appender.file.File", "logs/" + className + ".log");
        props.setProperty("log4j.appender.file.threshold", "info");
        props.setProperty("log4j.appender.file.layout", "org.apache.log4j.PatternLayout");
        props.setProperty("log4j.appender.file.layout.ConversionPattern", "%d{yyyy-MM-dd HH-mm-ss} | %-5p | %C{1}:%L | %m%n");
        props.setProperty("log4j.appender.stdout", "org.apache.log4j.ConsoleAppender");
        props.setProperty("log4j.appender.stdout.Target", "System.out");
        props.setProperty("log4j.logger." + "Thread" + className, "INFO, file");
        PropertyConfigurator.configure(props);
        logFactory.set(log);
    }

    public static Logger getLogger() {
        return logFactory.get();
    }

}

Then to initialise the the logger use the following approach

logFactory.createNewLogger(String.valueOf(Thread.currentThread().getId()));
logFactory.getLogger().info(" TEST . Thread id is: " + id);

Answer 12

Developing this yourself in a thread-safe way is not trivial, so you should really use an existing logging framework that is thread-safe. The most commonly used one is Log4J, which is thread-safe (see the FAQ).