Migrate Recycler API to log4j-api

docs/2.17.0-interpolation.md

@@ -1,3 +1,22 @@
+<!--
+ Licensed to the Apache Software Foundation (ASF) under one
+ or more contributor license agreements.  See the NOTICE file
+ distributed with this work for additional information
+ regarding copyright ownership.  The ASF licenses this file
+ to you under the Apache License, Version 2.0 (the
+ "License"); you may not use this file except in compliance
+ with the License.  You may obtain a copy of the License at
+
+   http://www.apache.org/licenses/LICENSE-2.0
+
+ Unless required by applicable law or agreed to in writing,
+ software distributed under the License is distributed on an
+ "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+ KIND, either express or implied.  See the License for the
+ specific language governing permissions and limitations
+ under the License.
+-->
+
 I'd like to go into detail on some of the changes in 2.17.0, why they're so important, and how they relate to both [CVE-2021-45046](https://cve.mitre.org/cgi-bin/cvename.cgi?name=CVE-2021-45046) and [CVE-2021-45105](https://cve.mitre.org/cgi-bin/cvename.cgi?name=CVE-2021-45105).
 
 The substitution of untrusted log data allowed access to code that was never meant to be exposed. Lookups should be triggered only by configuration and the logging framework (including custom layout/appender/etc plugins). Not by user-provided inputs.
@@ -153,4 +172,4 @@ The fix in this case is to inline the `fileName` property value into the `Rollin
         </Route>
       </Routes>
     </Routing>
-```
+```

log4j-1.2-api/src/main/java/org/apache/log4j/layout/Log4j1SyslogLayout.java

@@ -166,32 +166,36 @@ public String toSerializable(final LogEvent event) {
         // so we generate the message first
         final String message = messageLayout != null ? messageLayout.toSerializable(event)
                 : event.getMessage().getFormattedMessage();
-        final StringBuilder buf = getStringBuilder();
-
-        buf.append('<');
-        buf.append(Priority.getPriority(facility, event.getLevel()));
-        buf.append('>');
-
-        if (header) {
-            final int index = buf.length() + 4;
-            dateConverter.format(event, buf);
-            // RFC 3164 says leading space, not leading zero on days 1-9
-            if (buf.charAt(index) == '0') {
-                buf.setCharAt(index, Chars.SPACE);
+        final StringBuilder buf = acquireStringBuilder();
+
+        try {
+            buf.append('<');
+            buf.append(Priority.getPriority(facility, event.getLevel()));
+            buf.append('>');
+
+            if (header) {
+                final int index = buf.length() + 4;
+                dateConverter.format(event, buf);
+                // RFC 3164 says leading space, not leading zero on days 1-9
+                if (buf.charAt(index) == '0') {
+                    buf.setCharAt(index, Chars.SPACE);
+                }
+
+                buf.append(Chars.SPACE);
+                buf.append(localHostname);
+                buf.append(Chars.SPACE);
             }
 
-            buf.append(Chars.SPACE);
-            buf.append(localHostname);
-            buf.append(Chars.SPACE);
-        }
+            if (facilityPrinting) {
+                buf.append(facility != null ? facility.name().toLowerCase() : "user").append(':');
+            }
 
-        if (facilityPrinting) {
-            buf.append(facility != null ? facility.name().toLowerCase() : "user").append(':');
+            buf.append(message);
+            // TODO: splitting message into 1024 byte chunks?
+            return buf.toString();
+        } finally {
+            releaseStringBuilder(buf);
         }
-
-        buf.append(message);
-        // TODO: splitting message into 1024 byte chunks?
-        return buf.toString();
     }
 
     /**

log4j-1.2-api/src/main/java/org/apache/log4j/layout/Log4j1XmlLayout.java

@@ -16,6 +16,12 @@
  */
 package org.apache.log4j.layout;
 
+import java.io.PrintWriter;
+import java.io.StringWriter;
+import java.nio.charset.StandardCharsets;
+import java.util.List;
+import java.util.Objects;
+
 import org.apache.logging.log4j.core.Layout;
 import org.apache.logging.log4j.core.LogEvent;
 import org.apache.logging.log4j.core.layout.AbstractStringLayout;
@@ -28,12 +34,6 @@
 import org.apache.logging.log4j.util.ReadOnlyStringMap;
 import org.apache.logging.log4j.util.Strings;
 
-import java.io.PrintWriter;
-import java.io.StringWriter;
-import java.nio.charset.StandardCharsets;
-import java.util.List;
-import java.util.Objects;
-
 /**
  * Port of XMLLayout in Log4j 1.x. Provided for compatibility with existing Log4j 1 configurations.
  *
@@ -75,16 +75,24 @@ public boolean isProperties() {
 
     @Override
     public void encode(final LogEvent event, final ByteBufferDestination destination) {
-        final StringBuilder text = getStringBuilder();
-        formatTo(event, text);
-        getStringBuilderEncoder().encode(text, destination);
+        final StringBuilder text = acquireStringBuilder();
+        try {
+            formatTo(event, text);
+            getStringBuilderEncoder().encode(text, destination);
+        } finally {
+            releaseStringBuilder(text);
+        }
     }
 
     @Override
     public String toSerializable(final LogEvent event) {
-        final StringBuilder text = getStringBuilder();
-        formatTo(event, text);
-        return text.toString();
+        final StringBuilder text = acquireStringBuilder();
+        try {
+            formatTo(event, text);
+            return text.toString();
+        } finally {
+            releaseStringBuilder(text);
+        }
     }
 
     private void formatTo(final LogEvent event, final StringBuilder buf) {

log4j-api-test/src/test/java/org/apache/logging/log4j/message/ReusableMessageFactoryTest.java

@@ -16,6 +16,8 @@
  */
 package org.apache.logging.log4j.message;
 
+import org.apache.logging.log4j.spi.ThreadLocalRecyclerFactory;
+import org.junit.jupiter.api.BeforeEach;
 import org.junit.jupiter.api.Test;
 
 import static org.junit.jupiter.api.Assertions.*;
@@ -25,35 +27,39 @@
  */
 public class ReusableMessageFactoryTest {
 
+    private ReusableMessageFactory factory;
+
+    @BeforeEach
+    void setUp() {
+        factory = new ReusableMessageFactory(ThreadLocalRecyclerFactory.getInstance());
+    }
+
     @Test
     public void testCreateEventReturnsDifferentInstanceIfNotReleased() throws Exception {
-        final ReusableMessageFactory factory = new ReusableMessageFactory();
         final Message message1 = factory.newMessage("text, p0={} p1={} p2={} p3={}", 1, 2, 3, 4);
         final Message message2 = factory.newMessage("text, p0={} p1={} p2={} p3={}", 9, 8, 7, 6);
         assertNotSame(message1, message2);
-        ReusableMessageFactory.release(message1);
-        ReusableMessageFactory.release(message2);
+        factory.recycle(message1);
+        factory.recycle(message2);
     }
 
     @Test
     public void testCreateEventReturnsSameInstance() throws Exception {
-        final ReusableMessageFactory factory = new ReusableMessageFactory();
         final Message message1 = factory.newMessage("text, p0={} p1={} p2={} p3={}", 1, 2, 3, 4);
 
-        ReusableMessageFactory.release(message1);
+        factory.recycle(message1);
         final Message message2 = factory.newMessage("text, p0={} p1={} p2={} p3={}", 9, 8, 7, 6);
         assertSame(message1, message2);
 
-        ReusableMessageFactory.release(message2);
+        factory.recycle(message2);
         final Message message3 = factory.newMessage("text, AAA={} BBB={} p2={} p3={}", 9, 8, 7, 6);
         assertSame(message2, message3);
-        ReusableMessageFactory.release(message3);
+        factory.recycle(message3);
     }
 
     private void assertReusableParameterizeMessage(final Message message, final String txt, final Object[] params) {
         assertTrue(message instanceof ReusableParameterizedMessage);
         final ReusableParameterizedMessage msg = (ReusableParameterizedMessage) message;
-        assertTrue(msg.reserved, "reserved");
 
         assertEquals(txt, msg.getFormat());
         assertEquals(msg.getParameterCount(), params.length, "count");
@@ -65,7 +71,6 @@ private void assertReusableParameterizeMessage(final Message message, final Stri
 
     @Test
     public void testCreateEventOverwritesFields() throws Exception {
-        final ReusableMessageFactory factory = new ReusableMessageFactory();
         final Message message1 = factory.newMessage("text, p0={} p1={} p2={} p3={}", 1, 2, 3, 4);
         assertReusableParameterizeMessage(message1, "text, p0={} p1={} p2={} p3={}", new Object[]{
                 new Integer(1), //
@@ -74,7 +79,7 @@ public void testCreateEventOverwritesFields() throws Exception {
                 new Integer(4), //
         });
 
-        ReusableMessageFactory.release(message1);
+        factory.recycle(message1);
         final Message message2 = factory.newMessage("other, A={} B={} C={} D={}", 1, 2, 3, 4);
         assertReusableParameterizeMessage(message1, "other, A={} B={} C={} D={}", new Object[]{
                 new Integer(1), //
@@ -83,12 +88,11 @@ public void testCreateEventOverwritesFields() throws Exception {
                 new Integer(4), //
         });
         assertSame(message1, message2);
-        ReusableMessageFactory.release(message2);
+        factory.recycle(message2);
     }
 
     @Test
     public void testCreateEventReturnsThreadLocalInstance() throws Exception {
-        final ReusableMessageFactory factory = new ReusableMessageFactory();
         final Message[] message1 = new Message[1];
         final Message[] message2 = new Message[1];
         final Thread t1 = new Thread("THREAD 1") {
@@ -123,8 +127,8 @@ public void run() {
                 new Integer(3), //
                 new Integer(4), //
         });
-        ReusableMessageFactory.release(message1[0]);
-        ReusableMessageFactory.release(message2[0]);
+        factory.recycle(message1[0]);
+        factory.recycle(message2[0]);
     }
 
 }

log4j-api-test/src/test/java/org/apache/logging/log4j/spi/ThreadLocalRecyclerFactoryTest.java

@@ -0,0 +1,104 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one or more
+ * contributor license agreements. See the NOTICE file distributed with
+ * this work for additional information regarding copyright ownership.
+ * The ASF licenses this file to You under the Apache license, Version 2.0
+ * (the "License"); you may not use this file except in compliance with
+ * the License. You may obtain a copy of the License at
+ *
+ *      http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the license for the specific language governing permissions and
+ * limitations under the license.
+ */
+package org.apache.logging.log4j.spi;
+
+import java.util.List;
+import java.util.Queue;
+import java.util.stream.Collectors;
+import java.util.stream.IntStream;
+
+import org.junit.jupiter.api.BeforeEach;
+import org.junit.jupiter.api.Test;
+import org.junit.jupiter.params.ParameterizedTest;
+import org.junitpioneer.jupiter.params.IntRangeSource;
+
+import static org.assertj.core.api.Assertions.assertThat;
+
+class ThreadLocalRecyclerFactoryTest {
+
+    static class RecyclableObject {
+        boolean using;
+        boolean returned;
+    }
+
+    private Recycler<RecyclableObject> recycler;
+
+    private Queue<RecyclableObject> getRecyclerQueue() {
+        return ((ThreadLocalRecyclerFactory.ThreadLocalRecycler<RecyclableObject>) recycler).getQueue();
+    }
+
+    @BeforeEach
+    void setUp() {
+        recycler = ThreadLocalRecyclerFactory.getInstance()
+                .create(RecyclableObject::new, o -> {
+                    o.using = true;
+                    o.returned = false;
+                }, o -> {
+                    o.returned = true;
+                    o.using = false;
+                });
+    }
+
+    @ParameterizedTest
+    @IntRangeSource(from = 1, to = ThreadLocalRecyclerFactory.MAX_QUEUE_SIZE, closed = true)
+    void nestedAcquiresDoNotInterfere(int acquisitionCount) {
+        // pool should start empty
+        assertThat(getRecyclerQueue()).isEmpty();
+
+        final List<RecyclableObject> acquiredObjects = IntStream.range(0, acquisitionCount)
+                .mapToObj(i -> recycler.acquire())
+                .collect(Collectors.toList());
+
+        // still nothing returned to pool
+        assertThat(getRecyclerQueue()).isEmpty();
+
+        // don't want any duplicate instances
+        assertThat(acquiredObjects).containsOnlyOnceElementsOf(acquiredObjects);
+        acquiredObjects.forEach(recycler::release);
+
+        // and now they should be back in the pool
+        assertThat(getRecyclerQueue()).hasSize(acquisitionCount);
+
+        // then reacquire them to see that they're still the same object as we've filled in
+        // the thread-local queue with returned objects
+        final List<RecyclableObject> reacquiredObjects = IntStream.range(0, acquisitionCount)
+                .mapToObj(i -> recycler.acquire())
+                .collect(Collectors.toList());
+
+        assertThat(reacquiredObjects).containsExactlyElementsOf(acquiredObjects);
+    }
+
+    @Test
+    void nestedAcquiresPastMaximumQueueSizeShouldDiscardExtraReleases() {
+        assertThat(getRecyclerQueue()).isEmpty();
+
+        // simulate a massively callstack with tons of logging
+        final List<RecyclableObject> acquiredObjects = IntStream.range(0, 1024)
+                .mapToObj(i -> recycler.acquire())
+                .collect(Collectors.toList());
+
+        // still nothing returned to pool
+        assertThat(getRecyclerQueue()).isEmpty();
+
+        // don't want any duplicate instances
+        assertThat(acquiredObjects).containsOnlyOnceElementsOf(acquiredObjects);
+        acquiredObjects.forEach(recycler::release);
+
+        // upon return, we should only have ThreadLocalRecyclerFactory.MAX_QUEUE_SIZE retained for future use
+        assertThat(getRecyclerQueue()).hasSize(ThreadLocalRecyclerFactory.MAX_QUEUE_SIZE);
+    }
+}

log4j-api/pom.xml

@@ -42,6 +42,11 @@
       <artifactId>org.osgi.resource</artifactId>
       <scope>provided</scope>
     </dependency>
+    <dependency>
+      <groupId>org.jctools</groupId>
+      <artifactId>jctools-core</artifactId>
+      <optional>true</optional>
+    </dependency>
   </dependencies>
   <build>
     <plugins>
@@ -51,10 +56,6 @@
         <configuration>
           <instructions>
             <Export-Package>org.apache.logging.log4j.*</Export-Package>
-            <Import-Package>
-              sun.reflect;resolution:=optional,
-              *
-            </Import-Package>
             <Bundle-Activator>org.apache.logging.log4j.util.Activator</Bundle-Activator>
             <_fixupmessages>"Classes found in the wrong directory";is:=warning</_fixupmessages>
           </instructions>

log4j-api/src/main/java/module-info.java

@@ -38,8 +38,12 @@
     exports org.apache.logging.log4j.status;
     exports org.apache.logging.log4j.util;
 
+    // optional support for formatting SQL date/time classes in messages properly
     requires static java.sql;
+    // optional support for running in an OSGi environment
     requires static org.osgi.framework;
+    // optional support for using JCTools in a Recycler
+    requires static org.jctools.core;
     uses org.apache.logging.log4j.spi.Provider;
     uses PropertySource;
     uses org.apache.logging.log4j.message.ThreadDumpMessage.ThreadInfoFactory;