Display thread id instead thread name in log

问题:

I have a Struts application with log4j to display information about application.

The pattern to format log's output is as follows:

log4j.appender.RALL.layout.ConversionPattern=[%p] %d{dd/MM/yyyy HH:mm:ss} [THREAD ID=%t] [CLASS=(%C{1}:%L)] %m%n 

I need to show the thread id instead the thread name in log. The conversion character that display the thread name is %t. I don't see in log4j documentation the way to get it.

Can anyone help me??

回答1:

It is possible but not so easy as just using some preconfigured patterns.

Log4j 1.X and Log4j 2.x don't have any preconfigured patterns for printing Thread ID but you can always use some "magic trick".

PatternLayout is using PatternParser class which is mark as final class and has static map of "patterns" as keys and Converters classes as values. Everytime when Parses finds pattern using for logging pattern format starting with % it uses converter matched with this pattern key in map.

You cannot add your own rule to that map, but you can still write your own MyOwnPatternLayout:

public class MyOwnPatternLayout extends PatternLayout

which will in it's format method do such trick:

public String format(LoggingEvent event) {
   String log = super.format(event);
   /*
   Now you just have to replace with regex all occurences of %i or 
   any mark you would like to use as mark to represent Thread ID 
   with Thread ID value.
   Only thing you have to be sure to not use any mark as your Thread ID
   that already is defined by PatterParser class
   */
   return log.replaceAll("%i", someThreadID);
}

The only problem is that you have to get that thread ID in some way. Sometimes all you have to do is to parse Thread name which can you easily collect:

String threadName = event.getThreadName();

For example Apache-Tomcat put thread ID at the end of thread name http-nio-/127.0.0.1-8084"-exec-41.

To be sure that thread ID is correct you can also make your own subclass of LogginEvent and Logger (MyLoggingEvent and MyLogger) and inside MyLogger create MyLoggingEvent witch will also take as argument Thread ID not only Thread Name. Then you can easly collect it in code above.

Sorry for long answer and I hope this will at least give you some help.

回答2:

One way you can do it is to add it yourself using log4j MDC. We use it for adding the username for web requests. We do this in a filter at the start of each request. Eg.

import org.apache.log4j.MDC;

...

  // Add username to MDC
  String username = ...;
  MDC.put("user", username);

Then add [%X{user}] to your conversion pattern.

回答3:

I implemented thread ID and thread priority for the upcoming 2.6. Tracking here: https://issues.apache.org/jira/browse/LOG4J2-1299

You can pick up a 2.6-SNAPSHOT build from the Apache snapshots repository: https://repository.apache.org/content/repositories/snapshots/

回答4:

You can use the ThreadContext Map to supply meta-data to log4j2. This is a String Map of values that you CAN add through normal formatting.

String threadId = String.valueOf(Thread.currentThread().getId());
ThreadContext.put("TId", threadId);

And a much more reasonable Pattern:

    <PatternLayout pattern="%d{yyyyMMdd}T%d{HHmmss.SSS} %-5level [%t] [%5X{TId}] %15c{1} - %msg%n"/>

Full Log4j2 documentation on "Fish Tagging"

回答5:

I think it is not possible to show thread id with standard log4j formatting. I also investigated through code of PatterParser class an found nothing which can be useful. I found some custom solutions, but only for IBM server which has %i option:

%i: Inserts the thread ID. Unlike the thread name (indicated by %t), this is thread's numeric ID. Note that this parameter is particular to Initiate, while the other parameters listed here are standard with log4j.

See this link

回答6:

Extend PatternLayout as below, and then specify MyPatternLayout with $X{threadId} in the format string.

This implementation uses ThreadLocal to minimize the performance impact of calculating the Thread ID:

    MyPatternLayout extends PatternLayout {

        private final ThreadLocal<String> threadId = new ThreadLocal<String>() {

            @Override
            protected String initialValue() {
                String t = Long.toString(Thread.currentThread().getId());
                MDC.put("threadId", t);
                return t;
            }
        };

        @Override
        public String format(LoggingEvent event) {

            this.threadId.get();
            return super.format(event);
        }
    }

回答7:

One possible solution is to create your own class which sits between your code and Log4J and appends the thread ID to every log message:

public class ThreadLogger
{
    // Constructor declared private to prevent instantiation.  Use static methods instead.
    private ThreadLogger() {}

    private static enum LogLevel
    {
        TRACE,
        DEBUG,
        INFO,
        WARN,
        ERROR
    }

    public static void trace(String message)
    {
        logMessage(message, LogLevel.ERROR);
    }

    public static void debug(String message)
    {
        logMessage(message, LogLevel.ERROR);
    }

    public static void info(String message)
    {
        logMessage(message, LogLevel.ERROR);
    }

    public static void warn(String message)
    {
        logMessage(message, LogLevel.WARN);
    }

    public static void error(String message)
    {
        logMessage(message, LogLevel.ERROR);
    }

    private static void logMessage(String message, LogLevel logLevel)
    {
        // Get the Log4J logger for the class that originally wanted to log the message
        String callingClassName = Thread.currentThread().getStackTrace()[3].getClassName();
        Class callingClass;
        try
        {
            callingClass = Class.forName(callingClassName);
        }
        catch(ClassNotFoundException e)
        {
            String errorMessage = String.format("Could not reference class [%s].  Unable to log call!", callingClassName);
            throw new RuntimeException(errorMessage);
        }
        Logger logger = Logger.getLogger(callingClass);

        // Get the thread ID and place it in front of the logged message
        long threadId = Thread.currentThread().getId();
        String formattedMessage = String.format("[%s] %s", threadId, message);

        // Log the message
        switch(logLevel)
        {
            case TRACE:
                logger.trace(formattedMessage);
                break;
            case DEBUG:
                logger.debug(formattedMessage);
                break;
            case INFO:
                logger.info(formattedMessage);
                break;
            case WARN:
                logger.warn(formattedMessage);
                break;
            case ERROR:
                logger.error(formattedMessage);
                break;
        }
    }
}

Downsides:

• Performance? This adds a few extra steps to every log statement.
• Stability? This adds a potential point of failure (the Class.forName call).
• You have to replace all of your existing log statements with calls to the new class.
• The thread ID won't appear until after the regular Log4J formatting. IE:

1234 [main] INFO com.foo.bar.Baz - [1] Hello world on thread #1!
1234 [main] INFO com.foo.bar.Baz - [2] Hello world on thread #2!

回答8:

I create my own appender and set Thread.currentThread().getId() to the MDC property. %X{threadId} should give me the thread id. This solution is working since 1.2.15. You can then attach AsyncAppender to this.

public class CurrentThreadIdAppender extends AppenderSkeleton implements AppenderAttachable {

    private final AppenderAttachableImpl appenders = new AppenderAttachableImpl();

...

    @Override
    protected void append(LoggingEvent event) {   
        synchronized (appenders) {
            event.setProperty("threadId", String.valueOf(Thread.currentThread().getId()));
            appenders.appendLoopOnAppenders(event);
        }
    }

...

}

回答9:

Another elegant solution with log4j2 is to use org.apache.logging.log4j.core.pattern.LogEventPatternConverter.

You can write a class like this

@Plugin(name = "ThreadIdConverter", category = "Converter")
@ConverterKeys({ "tid" })
public class ThreadIdConverter extends LogEventPatternConverter {

    protected ThreadIdConverter(String name, String style) {
        super(name, style);
    }

    @Override
    public void format(LogEvent event, StringBuilder toAppendTo) {
        toAppendTo.append(getThreadId());
    }

    protected String getThreadId() {
        long id = Thread.currentThread().getId();
        return Long.toHexString(id);
    }

    public static ThreadIdConverter newInstance(String[] options) {
        return new ThreadIdConverter("tid", "tid");
    }
}

In this way you are creating a new pattern tid and you can use it when you define your appender's layout

<Appenders>
    <Console name="console" target="SYSTEM_OUT">
        <PatternLayout>
            <Pattern>%d{dd-MMM HH:mm:ss.SSS} %-7level [%5tid] %logger - %message%n</Pattern>
        </PatternLayout>
    </Console>
</Appenders>

The last important thing to remember is how to activate your log4j2 plugin. To do it you have to add the package that contains your plugins in the log4j2 configuration file using the package attribute on Configuration node

<?xml version="1.0" encoding="UTF-8" ?>
<!DOCTYPE Configuration>
<Configuration status="warn"
    packages="my.package.logging.plugins">
    <Appenders>
        <Console name="console" target="SYSTEM_OUT">
            <PatternLayout>
                <Pattern>%d{dd-MMM HH:mm:ss.SSS} %-7level [%5tid] %logger - %message%n</Pattern>
            </PatternLayout>
        </Console>
    </Appenders>
    <Loggers>
        <Root level="warn">
            <AppenderRef ref="console" />
        </Root>
        <Logger name="my.package" level="trace" />
    </Loggers>
</Configuration>