Skip to content

Commit aa4ee5f

Browse files
jhl221123Suvrat1629
jhl221123
and
Suvrat1629
authored
Expunge stale entries in InternalLoggerRegistry (#3681)
Co-authored-by: suvrat1629 <suvrat1629@gmail.com>
1 parent c669328 commit aa4ee5f

File tree

3 files changed

+216
-4
lines changed

3 files changed

+216
-4
lines changed

‎log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/internal/InternalLoggerRegistryTest.java

Lines changed: 153 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,153 @@
1+
/*
2+
* Licensed to the Apache Software Foundation (ASF) under one or more
3+
* contributor license agreements. See the NOTICE file distributed with
4+
* this work for additional information regarding copyright ownership.
5+
* The ASF licenses this file to you under the Apache License, Version 2.0
6+
* (the "License"); you may not use this file except in compliance with
7+
* the License. You may obtain a copy of the License at
8+
*
9+
* http://www.apache.org/licenses/LICENSE-2.0
10+
*
11+
* Unless required by applicable law or agreed to in writing, software
12+
* distributed under the License is distributed on an "AS IS" BASIS,
13+
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
14+
* See the License for the specific language governing permissions and
15+
* limitations under the License.
16+
*/
17+
package org.apache.logging.log4j.core.util.internal;
18+
19+
import static java.util.concurrent.TimeUnit.MILLISECONDS;
20+
import static java.util.concurrent.TimeUnit.SECONDS;
21+
import static org.awaitility.Awaitility.await;
22+
import static org.junit.jupiter.api.Assertions.assertEquals;
23+
import static org.junit.jupiter.api.Assertions.assertFalse;
24+
import static org.junit.jupiter.api.Assertions.assertNotNull;
25+
import static org.junit.jupiter.api.Assertions.assertNull;
26+
import static org.junit.jupiter.api.Assertions.assertSame;
27+
import static org.junit.jupiter.api.Assertions.assertTrue;
28+
29+
import java.lang.ref.WeakReference;
30+
import java.lang.reflect.Field;
31+
import java.util.Map;
32+
import org.apache.logging.log4j.core.Logger;
33+
import org.apache.logging.log4j.core.LoggerContext;
34+
import org.apache.logging.log4j.message.MessageFactory;
35+
import org.apache.logging.log4j.message.SimpleMessageFactory;
36+
import org.junit.jupiter.api.AfterEach;
37+
import org.junit.jupiter.api.BeforeEach;
38+
import org.junit.jupiter.api.Test;
39+
import org.junit.jupiter.api.TestInfo;
40+
41+
class InternalLoggerRegistryTest {
42+
private LoggerContext loggerContext;
43+
private InternalLoggerRegistry registry;
44+
private MessageFactory messageFactory;
45+
46+
@BeforeEach
47+
void setUp(TestInfo testInfo) throws NoSuchFieldException, IllegalAccessException {
48+
loggerContext = new LoggerContext(testInfo.getDisplayName());
49+
final Field registryField = loggerContext.getClass().getDeclaredField("loggerRegistry");
50+
registryField.setAccessible(true);
51+
registry = (InternalLoggerRegistry) registryField.get(loggerContext);
52+
messageFactory = SimpleMessageFactory.INSTANCE;
53+
}
54+
55+
@AfterEach
56+
void tearDown() {
57+
if (loggerContext != null) {
58+
loggerContext.stop();
59+
}
60+
}
61+
62+
@Test
63+
void testGetLoggerReturnsNullForNonExistentLogger() {
64+
assertNull(registry.getLogger("nonExistent", messageFactory));
65+
}
66+
67+
@Test
68+
void testComputeIfAbsentCreatesLogger() {
69+
final Logger logger = registry.computeIfAbsent(
70+
"testLogger", messageFactory, (name, factory) -> new Logger(loggerContext, name, factory) {});
71+
assertNotNull(logger);
72+
assertEquals("testLogger", logger.getName());
73+
}
74+
75+
@Test
76+
void testGetLoggerRetrievesExistingLogger() {
77+
final Logger logger = registry.computeIfAbsent(
78+
"testLogger", messageFactory, (name, factory) -> new Logger(loggerContext, name, factory) {});
79+
assertSame(logger, registry.getLogger("testLogger", messageFactory));
80+
}
81+
82+
@Test
83+
void testHasLoggerReturnsCorrectStatus() {
84+
assertFalse(registry.hasLogger("testLogger", messageFactory));
85+
registry.computeIfAbsent(
86+
"testLogger", messageFactory, (name, factory) -> new Logger(loggerContext, name, factory) {});
87+
assertTrue(registry.hasLogger("testLogger", messageFactory));
88+
}
89+
90+
@Test
91+
void testExpungeStaleWeakReferenceEntries() {
92+
final String loggerNamePrefix = "testLogger_";
93+
final int numberOfLoggers = 1000;
94+
95+
for (int i = 0; i < numberOfLoggers; i++) {
96+
final Logger logger = registry.computeIfAbsent(
97+
loggerNamePrefix + i,
98+
messageFactory,
99+
(name, factory) -> new Logger(loggerContext, name, factory) {});
100+
logger.info("Using logger {}", logger.getName());
101+
}
102+
103+
await().atMost(10, SECONDS).pollInterval(100, MILLISECONDS).untilAsserted(() -> {
104+
System.gc();
105+
registry.computeIfAbsent(
106+
"triggerExpunge", messageFactory, (name, factory) -> new Logger(loggerContext, name, factory) {});
107+
108+
final Map<MessageFactory, Map<String, WeakReference<Logger>>> loggerRefByNameByMessageFactory =
109+
reflectAndGetLoggerMapFromRegistry();
110+
final Map<String, WeakReference<Logger>> loggerRefByName =
111+
loggerRefByNameByMessageFactory.get(messageFactory);
112+
113+
int unexpectedCount = 0;
114+
for (int i = 0; i < numberOfLoggers; i++) {
115+
if (loggerRefByName.containsKey(loggerNamePrefix + i)) {
116+
unexpectedCount++;
117+
}
118+
}
119+
assertEquals(
120+
0, unexpectedCount, "Found " + unexpectedCount + " unexpected stale entries for MessageFactory");
121+
});
122+
}
123+
124+
@Test
125+
void testExpungeStaleMessageFactoryEntry() {
126+
final SimpleMessageFactory mockMessageFactory = new SimpleMessageFactory();
127+
Logger logger = registry.computeIfAbsent(
128+
"testLogger", mockMessageFactory, (name, factory) -> new Logger(loggerContext, name, factory) {});
129+
logger.info("Using logger {}", logger.getName());
130+
logger = null;
131+
132+
await().atMost(10, SECONDS).pollInterval(100, MILLISECONDS).untilAsserted(() -> {
133+
System.gc();
134+
registry.getLogger("triggerExpunge", mockMessageFactory);
135+
136+
final Map<MessageFactory, Map<String, WeakReference<Logger>>> loggerRefByNameByMessageFactory =
137+
reflectAndGetLoggerMapFromRegistry();
138+
assertNull(
139+
loggerRefByNameByMessageFactory.get(mockMessageFactory),
140+
"Stale MessageFactory entry was not removed from the outer map");
141+
});
142+
}
143+
144+
private Map<MessageFactory, Map<String, WeakReference<Logger>>> reflectAndGetLoggerMapFromRegistry()
145+
throws NoSuchFieldException, IllegalAccessException {
146+
final Field loggerMapField = registry.getClass().getDeclaredField("loggerRefByNameByMessageFactory");
147+
loggerMapField.setAccessible(true);
148+
@SuppressWarnings("unchecked")
149+
final Map<MessageFactory, Map<String, WeakReference<Logger>>> loggerMap =
150+
(Map<MessageFactory, Map<String, WeakReference<Logger>>>) loggerMapField.get(registry);
151+
return loggerMap;
152+
}
153+
}

‎log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/InternalLoggerRegistry.java

Lines changed: 50 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -18,9 +18,12 @@
1818

1919
import static java.util.Objects.requireNonNull;
2020

21+
import java.lang.ref.Reference;
22+
import java.lang.ref.ReferenceQueue;
2123
import java.lang.ref.WeakReference;
2224
import java.util.Collection;
2325
import java.util.HashMap;
26+
import java.util.Iterator;
2427
import java.util.Map;
2528
import java.util.WeakHashMap;
2629
import java.util.concurrent.locks.Lock;
@@ -40,7 +43,9 @@
4043
* A registry of {@link Logger}s namespaced by name and message factory.
4144
* This class is internally used by {@link LoggerContext}.
4245
* <p>
43-
* We don't use {@linkplain org.apache.logging.log4j.spi.LoggerRegistry the registry from Log4j API} to keep Log4j Core independent from the version of Log4j API at runtime.
46+
* We don't use {@linkplain org.apache.logging.log4j.spi.LoggerRegistry the
47+
* registry from Log4j API} to keep Log4j Core independent from the version of
48+
* Log4j API at runtime.
4449
* This also allows Log4j Core to evolve independently from Log4j API.
4550
* </p>
4651
*
@@ -53,13 +58,46 @@ public final class InternalLoggerRegistry {
5358
new WeakHashMap<>();
5459

5560
private final ReadWriteLock lock = new ReentrantReadWriteLock();
56-
5761
private final Lock readLock = lock.readLock();
58-
5962
private final Lock writeLock = lock.writeLock();
6063

64+
// ReferenceQueue to track stale WeakReferences
65+
private final ReferenceQueue<Logger> staleLoggerRefs = new ReferenceQueue<>();
66+
6167
public InternalLoggerRegistry() {}
6268

69+
/**
70+
* Expunges stale entries for logger references and message factories.
71+
*/
72+
private void expungeStaleEntries() {
73+
final Reference<? extends Logger> loggerRef = staleLoggerRefs.poll();
74+
75+
if (loggerRef != null) {
76+
writeLock.lock();
77+
try {
78+
while (staleLoggerRefs.poll() != null) {
79+
// Clear refQueue
80+
}
81+
82+
final Iterator<Map.Entry<MessageFactory, Map<String, WeakReference<Logger>>>>
83+
loggerRefByNameByMessageFactoryEntryIt =
84+
loggerRefByNameByMessageFactory.entrySet().iterator();
85+
while (loggerRefByNameByMessageFactoryEntryIt.hasNext()) {
86+
final Map.Entry<MessageFactory, Map<String, WeakReference<Logger>>>
87+
loggerRefByNameByMessageFactoryEntry = loggerRefByNameByMessageFactoryEntryIt.next();
88+
final Map<String, WeakReference<Logger>> loggerRefByName =
89+
loggerRefByNameByMessageFactoryEntry.getValue();
90+
loggerRefByName.values().removeIf(weakRef -> weakRef.get() == null);
91+
if (loggerRefByName.isEmpty()) {
92+
loggerRefByNameByMessageFactoryEntryIt.remove();
93+
}
94+
}
95+
} finally {
96+
writeLock.unlock();
97+
}
98+
}
99+
}
100+
63101
/**
64102
* Returns the logger associated with the given name and message factory.
65103
*
@@ -70,6 +108,8 @@ public InternalLoggerRegistry() {}
70108
public @Nullable Logger getLogger(final String name, final MessageFactory messageFactory) {
71109
requireNonNull(name, "name");
72110
requireNonNull(messageFactory, "messageFactory");
111+
expungeStaleEntries();
112+
73113
readLock.lock();
74114
try {
75115
final Map<String, WeakReference<Logger>> loggerRefByName =
@@ -87,6 +127,8 @@ public InternalLoggerRegistry() {}
87127
}
88128

89129
public Collection<Logger> getLoggers() {
130+
expungeStaleEntries();
131+
90132
readLock.lock();
91133
try {
92134
// Return a new collection to allow concurrent iteration over the loggers
@@ -127,6 +169,8 @@ public boolean hasLogger(final String name, final MessageFactory messageFactory)
127169
public boolean hasLogger(final String name, final Class<? extends MessageFactory> messageFactoryClass) {
128170
requireNonNull(name, "name");
129171
requireNonNull(messageFactoryClass, "messageFactoryClass");
172+
expungeStaleEntries();
173+
130174
readLock.lock();
131175
try {
132176
return loggerRefByNameByMessageFactory.entrySet().stream()
@@ -146,6 +190,7 @@ public Logger computeIfAbsent(
146190
requireNonNull(name, "name");
147191
requireNonNull(messageFactory, "messageFactory");
148192
requireNonNull(loggerSupplier, "loggerSupplier");
193+
// Skipping `expungeStaleEntries()`, it will be invoked by the `getLogger()` invocation below
149194

150195
// Read lock fast path: See if logger already exists
151196
@Nullable Logger logger = getLogger(name, messageFactory);
@@ -194,9 +239,10 @@ public Logger computeIfAbsent(
194239
if (loggerRefByName == null) {
195240
loggerRefByNameByMessageFactory.put(messageFactory, loggerRefByName = new HashMap<>());
196241
}
242+
197243
final WeakReference<Logger> loggerRef = loggerRefByName.get(name);
198244
if (loggerRef == null || (logger = loggerRef.get()) == null) {
199-
loggerRefByName.put(name, new WeakReference<>(logger = newLogger));
245+
loggerRefByName.put(name, new WeakReference<>(logger = newLogger, staleLoggerRefs));
200246
}
201247
return logger;
202248
} finally {

‎src/changelog/.2.x.x/3430_InternalLoggerRegistry_stale_entry_expunge.xml

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,13 @@
1+
<?xml version="1.0" encoding="UTF-8"?>
2+
<entry xmlns="https://logging.apache.org/xml/ns"
3+
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
4+
xsi:schemaLocation="
5+
https://logging.apache.org/xml/ns
6+
https://logging.apache.org/xml/ns/log4j-changelog-0.xsd"
7+
type="fixed">
8+
<issue id="3430" link="https://github.com/apache/logging-log4j2/issues/3430"/>
9+
<issue id="3681" link="https://github.com/apache/logging-log4j2/pull/3681"/>
10+
<description format="asciidoc">
11+
Improved expunging of stale entries in `InternalLoggerRegistry` to prevent potential memory leaks
12+
</description>
13+
</entry>

0 commit comments

Comments
 (0)