Does Log4j2 and SLF4J MDC get along?

1.5k views Asked by At

Using Finatra, I'm trying to activate traceID logging, but nothing ends up in Log4J2 output.

Finatra supports SLF4J MDC. SLF4J MDC is supposed to support Log4J (2?). Log4J2 is supposed to support MDC and SLF4J.

But in the end, the MDC data is always empty reaching the message construction.

I tested with Logback as the log implementation and I had the MDC logged correctly, and it is actually relying on SLF4J MDC. I do have to use log4J2 here (cannot be questioned).

Is this just not working because Log4J2 does not work correctly with SLF4J MDC?

To get it to work with Finatra, I just have to remove the LoggingMDCFilter which pretty must only replaces the MDCAdapter with the FinagleMDCAdapter own implementation, backed by Finagle Contexts.

2

There are 2 answers

5
Piotr P. Karwasz On BEST ANSWER

As you noticed in your question FinagleMDCInitializer replaces the MDC used by the logging backend with its own.

Logback uses SLF4J as their internal API (i.e. just Logback) so it will work with any MDCAdapter implementation installed, but all the remaining SLF4J backends won't.

The same hack that permits Logback to work with Finagle can be used in Log4j2 Core. Log4j2 Core is a native implementation of Log4j2 API and it will work with any implementation of ThreadContextMap.

We want to use a ThreadContextMap implementation that delegates all methods to SLF4J's MDC. Fortunately such an implementation is included in the Apache Log4j2 API to SLF4J Adapter (another implementation of the Log4j2 API). So we can use the following trick:

  • add both log4j-core and log4j-to-slf4j to your application's classpath. Since now there are two implementations of the Log4j2 API available, we need to specify the one we actually want to use. We can do it by adding a file called log4j2.component.properties at the root of your classpath with:

    log4j2.loggerContextFactory = org.apache.logging.log4j.core.impl.Log4jContextFactory
    
  • in the same property file we specify that we want to use the ThreadContextMap implementation included in log4j-to-slf4j:

    log4j2.threadContextMap = org.apache.logging.slf4j.MDCContextMap
    
  • I assume that you already have log4j-slf4j-impl (Apache SLF4J to Log4j2 API Adapter) on your classpath.

Remark: the proposed solution assumes that FinagleMDCInitializer is called as soon as possible. SLF4J does not have an equivalent of the log4j2.threadContexMap property to force it to use a concrete implementation of MDCAdapter. Until Finagle replaces the implementations, your application will use the MDCAdapter from log4j-slf4j-impl that delegates everything to the ThreadContextMap, that delegates everything to MDCAdapter, ... You'll have a guaranteed StackOverflow.

Edit: If you end up with a StackOverflow, you can:

  • start with NOOP ThreadContextMap:

    log4j2.threadContextMap = org.apache.logging.log4j.spi.NoOpThreadContextMap
    
  • replace the MDCAdapter and ThreadContextMap all in one place:

     // Replace the `MDCAdapter`
     MDCInitializer.init();
     try {
         // Change ThreadContextMap implementation
         System.setProperty("log4j2.threadContextMap", "org.apache.logging.slf4j.MDCContextMap");
         // Properties are cached so a reload is needed
         PropertiesUtil.getProperties().reload();
         // Call ThreadContext.init()
         final Method method = ThreadContext.class.getDeclaredMethod("init");
         method.setAccessible(true);
         method.invoke(null);
     } catch (SecurityException | ReflectiveOperationException | IllegalArgumentException  e) {
         logger.warn("ThreadContext reinitialization failed.", e);
     }
    
3
rgoers On

I would add to Piotr's answer.

In accordance with SLF4J's SPI, Log4j 2 provides its own StaticMDCBinder class. This returns Log4j's MDCAdapter that acts as a bridge between the MDC API and Log4j's ThreadContextMap. When Finatra replaces that MDCAdapter the binding is lost so nothing stored in the MDC will make it into the ThreadContextMap. Note that this is necessary because Log4j does not actually use the SLF4J API anywhere except in the adapters.

I believe a better approach than what Piotr suggests would be to modify FinagleMDCInitializer to detect that Log4j-core is present and exit and then have Finatra provide its own ThreadContextMap implementation. In this case only the log4j2.thradContextMap property would need to be provided to reference the custom class and the use of log4j-to-slf4j would not be necessary.

If you do provide a custom ThreadContextMap then the call to MDCInitializer would be unnecessary and you wouldn't really need to make any changes to it as they would only be there to prevent MDCInitializer from breaking the binding with Log4j.