fix: Prevent LogBuilder memory leak in Log4j API to Logback bridge (apache#3824)

Author: ppkarwasz

log4j-to-slf4j/pom.xml

@@ -153,6 +153,45 @@
           </execution>
         </executions>
       </plugin>
+
     </plugins>
   </build>
+
+  <profiles>
+
+    <!-- Fixes incompatible with Java 8 -->
+    <profile>
+
+      <id>java8-incompat-fixes</id>
+
+      <!-- CI uses Java 8 for running tests.
+         Hence, we assume CI=Java8 and apply our changes elsewhere.
+
+         One might think why not activate using `<jdk>[16,)` instead?
+         This doesn't work, since the match is not against "the JDK running tests", but "the JDK running Maven".
+         These two JDKs can differ due to Maven Toolchains.
+         See `java8-tests` profile in `/pom.xml` for details. -->
+      <activation>
+        <property>
+          <name>!env.CI</name>
+        </property>
+      </activation>
+
+      <!-- Illegal access is disabled by default in Java 16 due to JEP-396.
+         We are relaxing it for tests. -->
+      <build>
+        <plugins>
+          <plugin>
+            <groupId>org.apache.maven.plugins</groupId>
+            <artifactId>maven-surefire-plugin</artifactId>
+            <configuration>
+              <argLine>--add-opens java.base/java.lang=ALL-UNNAMED</argLine>
+            </configuration>
+          </plugin>
+        </plugins>
+      </build>
+
+    </profile>
+
+  </profiles>
 </project>

log4j-to-slf4j/src/main/java/org/apache/logging/slf4j/SLF4JLogger.java

@@ -42,17 +42,21 @@ public class SLF4JLogger extends AbstractLogger {
 
     private final org.slf4j.Logger logger;
     private final LocationAwareLogger locationAwareLogger;
+    private final boolean useThreadLocal;
 
     public SLF4JLogger(final String name, final MessageFactory messageFactory, final org.slf4j.Logger logger) {
-        super(name, messageFactory);
-        this.logger = logger;
-        this.locationAwareLogger = logger instanceof LocationAwareLogger ? (LocationAwareLogger) logger : null;
+        this(name, messageFactory, logger, Constants.ENABLE_THREADLOCALS);
     }
 
     public SLF4JLogger(final String name, final org.slf4j.Logger logger) {
-        super(name);
+        this(name, null, logger);
+    }
+
+    SLF4JLogger(String name, MessageFactory messageFactory, org.slf4j.Logger logger, boolean useThreadLocal) {
+        super(name, messageFactory);
         this.logger = logger;
         this.locationAwareLogger = logger instanceof LocationAwareLogger ? (LocationAwareLogger) logger : null;
+        this.useThreadLocal = useThreadLocal;
     }
 
     private int convertLevel(final Level level) {
@@ -364,8 +368,8 @@ public LogBuilder atFatal() {
 
     @Override
     protected LogBuilder getLogBuilder(final Level level) {
-        final SLF4JLogBuilder builder = logBuilder.get();
-        return Constants.ENABLE_THREADLOCALS && !builder.isInUse()
+        SLF4JLogBuilder builder;
+        return useThreadLocal && !(builder = logBuilder.get()).isInUse()
                 ? builder.reset(this, level)
                 : new SLF4JLogBuilder(this, level);
     }

log4j-to-slf4j/src/test/java/org/apache/logging/slf4j/LoggerTest.java renamed to log4j-to-slf4j/src/test/java/org/apache/logging/slf4j/SLF4JLoggerTest.java

@@ -32,10 +32,13 @@
 import ch.qos.logback.classic.LoggerContext;
 import ch.qos.logback.classic.spi.ILoggingEvent;
 import ch.qos.logback.core.testUtil.StringListAppender;
+import java.lang.reflect.Field;
 import java.lang.reflect.InvocationTargetException;
+import java.lang.reflect.Method;
 import java.lang.reflect.Proxy;
 import java.util.Date;
 import java.util.List;
+import org.apache.logging.log4j.LogBuilder;
 import org.apache.logging.log4j.LogManager;
 import org.apache.logging.log4j.Logger;
 import org.apache.logging.log4j.ThreadContext;
@@ -45,13 +48,17 @@
 import org.apache.logging.log4j.spi.AbstractLogger;
 import org.apache.logging.log4j.spi.MessageFactory2Adapter;
 import org.apache.logging.log4j.test.junit.UsingStatusListener;
+import org.assertj.core.api.Assertions;
 import org.junit.jupiter.api.BeforeEach;
 import org.junit.jupiter.api.Test;
+import org.junit.jupiter.params.ParameterizedTest;
+import org.junit.jupiter.params.provider.ValueSource;
+import org.junitpioneer.jupiter.Issue;
 import org.slf4j.MDC;
 
 @UsingStatusListener
 @LoggerContextSource
-class LoggerTest {
+class SLF4JLoggerTest {
 
     private static final Object OBJ = new Object();
     // Log4j objects
@@ -265,4 +272,38 @@ void mdcCannotContainNullKey() {
             // expected
         }
     }
+
+    @ParameterizedTest
+    @ValueSource(booleans = {true, false})
+    @Issue("https://github.com/apache/logging-log4j2/issues/3819")
+    void threadLocalUsage(boolean useThreadLocal) throws ReflectiveOperationException {
+        // Reset the static ThreadLocal in SLF4JLogger
+        getLogBuilderThreadLocal().remove();
+        final org.slf4j.Logger slf4jLogger = context.getLogger(getClass());
+        Logger logger = new SLF4JLogger(slf4jLogger.getName(), null, slf4jLogger, useThreadLocal);
+        LogBuilder builder1 = logger.atInfo();
+        builder1.log("Test message");
+        LogBuilder builder2 = logger.atInfo();
+        builder2.log("Another test message");
+        // Check if the same builder is reused based on the useThreadLocal flag
+        Assertions.assertThat(isThreadLocalPresent())
+                .as("ThreadLocal should be present iff useThreadLocal is enabled")
+                .isEqualTo(useThreadLocal);
+        Assertions.assertThat(builder2 == builder1)
+                .as("Builder2 should be the same as Builder1 iff useThreadLocal is enabled")
+                .isEqualTo(useThreadLocal);
+    }
+
+    private static boolean isThreadLocalPresent() throws ReflectiveOperationException {
+        Method isPresentMethod = ThreadLocal.class.getDeclaredMethod("isPresent");
+        isPresentMethod.setAccessible(true);
+        ThreadLocal<?> threadLocal = getLogBuilderThreadLocal();
+        return (boolean) isPresentMethod.invoke(threadLocal);
+    }
+
+    private static ThreadLocal<?> getLogBuilderThreadLocal() throws ReflectiveOperationException {
+        Field logBuilderField = SLF4JLogger.class.getDeclaredField("logBuilder");
+        logBuilderField.setAccessible(true);
+        return (ThreadLocal<?>) logBuilderField.get(null);
+    }
 }

log4j-to-slf4j/src/test/resources/org/apache/logging/slf4j/LoggerTest.xml renamed to log4j-to-slf4j/src/test/resources/org/apache/logging/slf4j/SLF4JLoggerTest.xml

@@ -0,0 +1,12 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<entry xmlns="https://logging.apache.org/xml/ns"
+       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
+       xsi:schemaLocation="
+           https://logging.apache.org/xml/ns
+           https://logging.apache.org/xml/ns/log4j-changelog-0.xsd"
+       type="fixed">
+  <issue id="3819" link="https://github.com/apache/logging-log4j2/issues/3819"/>
+  <description format="asciidoc">
+    Fix potential memory leak involving `LogBuilder` in Log4j API to Logback bridge.
+  </description>
+</entry>