Search code examples
log4j2smtpappenderpattern-layoutasyncappender

PatternConverter not working with async appender in log4j2.17.X


We use PatternConverter to make custom conversion patterns to include the sesionId in the logs ,which is working in SMTP/console and file appenders without any issue however if we wrap the appenders with Async(used SMTP here),its coming empty in the place of the pattern

eg : conversionPattern: %p: (%s) %c{1}: %m%n Time: %d{yyyy-MM-dd HH:mm:ss}

s--->SessionId(custom pattern used in the system created using patternconverter plugin)

Synchronous SMTP appender is mailing the below log(Works perfectly):

INFO: (c5cwdac4-fw8e-12ec-cabf056af41fc) MyLoggerClass: Hello World. Time: 2022-06-24 00:25:34

Asynchronous SMTP appender is mailing the below log:

INFO: () MyLoggerClass: Hello World. Time: 2022-06-24 00:26:34

c5cwdac4-fw8e-12ec-cabf056af41fc --> Session ID is missed and coming empty .

Configuration :

<?xml version="1.0" ?>
<Configuration name="DefaultLogger" status="INFO">
<Appenders>
<SMTP name="SMTP" from="[email protected]" to="[email protected]" subject="Log4jLogger Test Message" smtpHost="mail" bufferSize="1"><PatternLayout pattern="%p: (%s) %c{1}: %m%n Time: %d{yyyy-MM-dd HH:mm:ss}"/>
<ThresholdFilter onMatch="ACCEPT" onMismatch="DENY" level="ERROR"/>
</SMTP>
<Async name="Async" includeLocation="true">
<AppenderRef ref="SMTP"/>
</Async></Appenders>
<Loggers>
<Logger name="com" level="INFO"/>
<Root level="INFO">
<AppenderRef ref="Async"/></Root>
</Loggers>
</Configuration>

Note : includeLocation is set to True but no help!


Solution

  • Your custom pattern converter is probably to blame. Although you don't share its source code, it probably uses a ThreadLocal to store the session id.

    Log4j2 formats log messages lazily, only when they are actually going to be sent by the appender. This happens after the async call, on the thread running the SMTP appender, where the ThreadLocal has no value.

    The easiest way to solve the problem is to get rid of the custom pattern converters and use a standard Log4j2 mechanism: the ThreadContext. On your worker thread you need to save the value of the session id:

    ThreadContext.put("sessionId", ...);
    

    or

    try (CloseableThreadContext.Instance ctx = CloseableThreadContext.put("sessionId", ...)) {
        ...
    }
    

    and use %X{sessionId} in your pattern (cf. builtin patterns).