Remove unneeded weak reference from prefix logger

We have a custom logger implementation known as a prefix logger that is
used to write every message by the logger with a given prefix. This is
useful for node-level, index-level, and shard-level messages where we
want to log the node name, index name, and shard ID, respectively, if
possible. The mechanism that we employ is that of a marker. Log4j has a
built-in facility for managing these markers, but its effectively a
memory leak because these markers are held in a map and can never be
released. This is problematic for us since indices and shards do not
necessarily have infinite life spans and so on a node where there are
many indices being creted and destroyed, this infinite lifespan can be a
problem indeed. To solve this, we use our own cache of markers. This is
necessary to prevent too many instances of the marker for the same
prefix from being created (just think of all the shard-level components
that exist in the system), and to workaround the effective leak in
Log4j. These markers are stored as weak references in a weak hash
map. It is these weak references that are unneeded. When a key is
removed from a weak hash map, the corresponding entry is placed on a
reference queue that is eventually cleared. This commit simplifies
prefix logger by removing this unnecessary weak reference wrapper.

Relates #22460

Author: jasontedor

core/src/main/java/org/elasticsearch/common/logging/PrefixLogger.java

@@ -26,34 +26,69 @@
 import org.apache.logging.log4j.spi.ExtendedLogger;
 import org.apache.logging.log4j.spi.ExtendedLoggerWrapper;
 
-import java.lang.ref.WeakReference;
 import java.util.WeakHashMap;
 
+/**
+ * A logger that prefixes all messages with a fixed prefix specified during construction. The prefix mechanism uses the marker construct, so
+ * for the prefixes to appear, the logging layout pattern must include the marker in its pattern.
+ */
 class PrefixLogger extends ExtendedLoggerWrapper {
 
-    // we can not use the built-in Marker tracking (MarkerManager) because the MarkerManager holds
-    // a permanent reference to the marker; however, we have transient markers from index-level and
-    // shard-level components so this would effectively be a memory leak
-    private static final WeakHashMap<String, WeakReference<Marker>> markers = new WeakHashMap<>();
+    /*
+     * We can not use the built-in Marker tracking (MarkerManager) because the MarkerManager holds a permanent reference to the marker;
+     * however, we have transient markers from index-level and shard-level components so this would effectively be a memory leak. Since we
+     * can not tie into the lifecycle of these components, we have to use a mechanism that enables garbage collection of such markers when
+     * they are no longer in use.
+     */
+    private static final WeakHashMap<String, Marker> markers = new WeakHashMap<>();
+
+    /**
+     * Return the size of the cached markers. This size can vary as markers are cached but collected during GC activity when a given prefix
+     * is no longer in use.
+     *
+     * @return the size of the cached markers
+     */
+    static int markersSize() {
+        return markers.size();
+    }
 
+    /**
+     * The marker for this prefix logger.
+     */
     private final Marker marker;
 
+    /**
+     * Obtain the prefix for this prefix logger. This can be used to create a logger with the same prefix as this one.
+     *
+     * @return the prefix
+     */
     public String prefix() {
         return marker.getName();
     }
 
+    /**
+     * Construct a prefix logger with the specified name and prefix.
+     *
+     * @param logger the extended logger to wrap
+     * @param name   the name of this prefix logger
+     * @param prefix the prefix for this prefix logger
+     */
     PrefixLogger(final ExtendedLogger logger, final String name, final String prefix) {
         super(logger, name, null);
 
         final String actualPrefix = (prefix == null ? "" : prefix).intern();
         final Marker actualMarker;
         // markers is not thread-safe, so we synchronize access
         synchronized (markers) {
-            final WeakReference<Marker> marker = markers.get(actualPrefix);
-            final Marker maybeMarker = marker == null ? null : marker.get();
+            final Marker maybeMarker = markers.get(actualPrefix);
             if (maybeMarker == null) {
                 actualMarker = new MarkerManager.Log4jMarker(actualPrefix);
-                markers.put(actualPrefix, new WeakReference<>(actualMarker));
+                /*
+                 * We must create a new instance here as otherwise the marker will hold a reference to the key in the weak hash map; as
+                 * those references are held strongly, this would give a strong reference back to the key preventing them from ever being
+                 * collected. This also guarantees that no other strong reference can be held to the prefix anywhere.
+                 */
+                markers.put(new String(actualPrefix), actualMarker);
             } else {
                 actualMarker = maybeMarker;
             }

qa/evil-tests/src/test/java/org/elasticsearch/common/logging/EvilLoggerTests.java

@@ -47,6 +47,7 @@
 import java.util.regex.Pattern;
 
 import static org.hamcrest.Matchers.equalTo;
+import static org.hamcrest.Matchers.lessThan;
 import static org.hamcrest.Matchers.startsWith;
 
 public class EvilLoggerTests extends ESTestCase {
@@ -170,6 +171,20 @@ public void testPrefixLogger() throws IOException, IllegalAccessException, UserE
         }
     }
 
+    public void testPrefixLoggerMarkersCanBeCollected() throws IOException, UserException {
+        setupLogging("prefix");
+
+        final int prefixes = 1 << 19; // to ensure enough markers that the GC should collect some when we force a GC below
+        for (int i = 0; i < prefixes; i++) {
+            // this has the side effect of caching a marker with this prefix
+            Loggers.getLogger("prefix" + i, "prefix" + i);
+        }
+
+        // this will free the weakly referenced keys in the marker cache
+        System.gc();
+        assertThat(PrefixLogger.markersSize(), lessThan(prefixes));
+    }
+
     public void testProperties() throws IOException, UserException {
         final Settings.Builder builder = Settings.builder().put("cluster.name", randomAlphaOfLength(16));
         if (randomBoolean()) {