From d54265dab6d6a561ff9b3dbf1e6589d2aa3a7010 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Volkan=20Yaz=C4=B1c=C4=B1?= Date: Wed, 2 Oct 2024 14:44:41 +0200 Subject: [PATCH 1/6] Fix key removal issues in Thread Context --- .../log4j/CloseableThreadContextTest.java | 69 ++++++++++++ .../map/UnmodifiableArrayBackedMap.java | 106 +++++++----------- .../.2.x.x/3048_fix_ThreadContext_remove.xml | 8 ++ 3 files changed, 119 insertions(+), 64 deletions(-) create mode 100644 src/changelog/.2.x.x/3048_fix_ThreadContext_remove.xml diff --git a/log4j-api-test/src/test/java/org/apache/logging/log4j/CloseableThreadContextTest.java b/log4j-api-test/src/test/java/org/apache/logging/log4j/CloseableThreadContextTest.java index 56e0086a49f..5c86e713e2f 100644 --- a/log4j-api-test/src/test/java/org/apache/logging/log4j/CloseableThreadContextTest.java +++ b/log4j-api-test/src/test/java/org/apache/logging/log4j/CloseableThreadContextTest.java @@ -19,7 +19,9 @@ import static org.junit.jupiter.api.Assertions.assertEquals; import static org.junit.jupiter.api.Assertions.assertFalse; import static org.junit.jupiter.api.Assertions.assertNotNull; +import static org.junit.jupiter.api.Assertions.assertNull; +import java.util.Collections; import java.util.HashMap; import java.util.List; import java.util.Map; @@ -244,4 +246,71 @@ public void pushAllWillPushAllValues() { } assertEquals("", ThreadContext.peek()); } + + /** + * User provided test stressing nesting using {@link CloseableThreadContext#put(String, String)}. + * + * @see #2946 + */ + @Test + public void testAutoCloseableThreadContextPut() { + try (final CloseableThreadContext.Instance ctc1 = CloseableThreadContext.put("outer", "one")) { + try (final CloseableThreadContext.Instance ctc2 = CloseableThreadContext.put("outer", "two")) { + assertEquals("two", ThreadContext.get("outer")); + + try (final CloseableThreadContext.Instance ctc3 = CloseableThreadContext.put("inner", "one")) { + assertEquals("one", ThreadContext.get("inner")); + + ThreadContext.put( + "not-in-closeable", "true"); // Remove this line, and closing context behaves as expected + assertEquals("two", ThreadContext.get("outer")); + } + + assertEquals("two", ThreadContext.get("outer")); + assertNull(ThreadContext.get("inner")); // Test fails here + } + + assertEquals("one", ThreadContext.get("outer")); + assertNull(ThreadContext.get("inner")); + } + assertEquals("true", ThreadContext.get("not-in-closeable")); + + assertNull(ThreadContext.get("inner")); + assertNull(ThreadContext.get("outer")); + } + + /** + * User provided test stressing nesting using {@link CloseableThreadContext#putAll(Map)}. + * + * @see #2946 + */ + @Test + public void testAutoCloseableThreadContextPutAll() { + try (final CloseableThreadContext.Instance ctc1 = CloseableThreadContext.put("outer", "one")) { + try (final CloseableThreadContext.Instance ctc2 = CloseableThreadContext.put("outer", "two")) { + assertEquals("two", ThreadContext.get("outer")); + + try (final CloseableThreadContext.Instance ctc3 = CloseableThreadContext.put("inner", "one")) { + assertEquals("one", ThreadContext.get("inner")); + + ThreadContext.put( + "not-in-closeable", "true"); // Remove this line, and closing context behaves as expected + ThreadContext.putAll(Collections.singletonMap("inner", "two")); // But this is not a problem + System.err.println(ThreadContext.getContext()); + assertEquals("two", ThreadContext.get("inner")); + assertEquals("two", ThreadContext.get("outer")); + } + + assertEquals("two", ThreadContext.get("outer")); + assertNull(ThreadContext.get("inner")); // This is where the test fails + } + + assertEquals("one", ThreadContext.get("outer")); + assertNull(ThreadContext.get("inner")); + } + assertEquals("true", ThreadContext.get("not-in-closeable")); + + assertNull(ThreadContext.get("inner")); + assertNull(ThreadContext.get("outer")); + } } diff --git a/log4j-api/src/main/java/org/apache/logging/log4j/internal/map/UnmodifiableArrayBackedMap.java b/log4j-api/src/main/java/org/apache/logging/log4j/internal/map/UnmodifiableArrayBackedMap.java index eada687424f..a58037a63d3 100644 --- a/log4j-api/src/main/java/org/apache/logging/log4j/internal/map/UnmodifiableArrayBackedMap.java +++ b/log4j-api/src/main/java/org/apache/logging/log4j/internal/map/UnmodifiableArrayBackedMap.java @@ -20,11 +20,12 @@ import java.util.AbstractMap; import java.util.AbstractSet; import java.util.Collection; -import java.util.HashSet; import java.util.Iterator; import java.util.Map; import java.util.Objects; import java.util.Set; +import java.util.stream.Collectors; +import java.util.stream.StreamSupport; import org.apache.logging.log4j.util.ReadOnlyStringMap; import org.apache.logging.log4j.util.TriConsumer; @@ -350,82 +351,59 @@ public UnmodifiableArrayBackedMap copyAndRemove(String key) { } /** - * Creates a new instance that contains the same entries as this map, minus all - * of the keys passed in the arguments. - * - * @param key - * @param value - * @return + * Creates a new instance where the entries of provided keys are removed. */ public UnmodifiableArrayBackedMap copyAndRemoveAll(Iterable keysToRemoveIterable) { + + // Short-circuit if the map is empty if (isEmpty()) { - // shortcut: if this map is empty, the result will continue to be empty return EMPTY_MAP; } - // now we build a Set of keys to remove - Set keysToRemoveSet; - if (keysToRemoveIterable instanceof Set) { - // we already have a set, let's cast it and reuse it - keysToRemoveSet = (Set) keysToRemoveIterable; - } else { - // iterate through the keys and build a set - keysToRemoveSet = new HashSet<>(); - for (String key : keysToRemoveIterable) { - keysToRemoveSet.add(key); - } - } + // Collect distinct keys to remove + final Set keysToRemove = keysToRemoveIterable instanceof Set + ? (Set) keysToRemoveIterable + : StreamSupport.stream(keysToRemoveIterable.spliterator(), false) + .collect(Collectors.toSet()); - int firstIndexToKeep = -1; - int lastIndexToKeep = -1; - int destinationIndex = 0; - int numEntriesKept = 0; - // build the new map - UnmodifiableArrayBackedMap newMap = new UnmodifiableArrayBackedMap(numEntries); - for (int indexInCurrentMap = 0; indexInCurrentMap < numEntries; indexInCurrentMap++) { - // for each key in this map, check whether it's in the set we built above - Object key = backingArray[getArrayIndexForKey(indexInCurrentMap)]; - if (!keysToRemoveSet.contains(key)) { - // this key should be kept - if (firstIndexToKeep == -1) { - firstIndexToKeep = indexInCurrentMap; - } - lastIndexToKeep = indexInCurrentMap; - } else if (lastIndexToKeep > 0) { - // we hit a remove, copy any keys that are known ready - int numEntriesToCopy = lastIndexToKeep - firstIndexToKeep + 1; - System.arraycopy( - backingArray, - getArrayIndexForKey(firstIndexToKeep), - newMap.backingArray, - getArrayIndexForKey(destinationIndex), - numEntriesToCopy * 2); - firstIndexToKeep = -1; - lastIndexToKeep = -1; - destinationIndex += numEntriesToCopy; - numEntriesKept += numEntriesToCopy; - } - } + // Create the new map + final UnmodifiableArrayBackedMap oldMap = this; + final int oldMapEntryCount = oldMap.numEntries; + final UnmodifiableArrayBackedMap newMap = new UnmodifiableArrayBackedMap(oldMapEntryCount); - if (lastIndexToKeep > -1) { - // at least one key still requires copying - int numEntriesToCopy = lastIndexToKeep - firstIndexToKeep + 1; - System.arraycopy( - backingArray, - getArrayIndexForKey(firstIndexToKeep), - newMap.backingArray, - getArrayIndexForKey(destinationIndex), - numEntriesToCopy * 2); - numEntriesKept += numEntriesToCopy; + // Short-circuit if there is nothing to remove + if (keysToRemove.isEmpty()) { + System.arraycopy(oldMap.backingArray, 0, newMap.backingArray, 0, oldMapEntryCount * 2); + newMap.numEntries = oldMapEntryCount; + return this; } - if (numEntriesKept == 0) { - return EMPTY_MAP; + // Iterate over old map entries + int newMapEntryIndex = 0; + for (int oldMapEntryIndex = 0; oldMapEntryIndex < oldMapEntryCount; oldMapEntryIndex++) { + final int oldMapKeyIndex = getArrayIndexForKey(oldMapEntryIndex); + final Object key = oldMap.backingArray[oldMapKeyIndex]; + + // Skip entries of removed keys + @SuppressWarnings("SuspiciousMethodCalls") + final boolean removed = keysToRemove.contains(key); + if (removed) { + continue; + } + + // Copy the entry + final int oldMapValueIndex = getArrayIndexForValue(oldMapEntryIndex); + final Object value = oldMap.backingArray[oldMapValueIndex]; + final int newMapKeyIndex = getArrayIndexForKey(newMapEntryIndex); + final int newMapValueIndex = getArrayIndexForValue(newMapEntryIndex); + newMap.backingArray[newMapKeyIndex] = key; + newMap.backingArray[newMapValueIndex] = value; + newMapEntryIndex++; } - newMap.numEntries = numEntriesKept; + // Cap and return the new map + newMap.numEntries = newMapEntryIndex; newMap.updateNumEntriesInArray(); - return newMap; } diff --git a/src/changelog/.2.x.x/3048_fix_ThreadContext_remove.xml b/src/changelog/.2.x.x/3048_fix_ThreadContext_remove.xml new file mode 100644 index 00000000000..d19091dc0fa --- /dev/null +++ b/src/changelog/.2.x.x/3048_fix_ThreadContext_remove.xml @@ -0,0 +1,8 @@ + + + + Fix key removal issues in Thread Context + From 91ff32cec924a06611608bb8d86393c3e1c4be4e Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Volkan=20Yaz=C4=B1c=C4=B1?= Date: Wed, 2 Oct 2024 15:30:28 +0200 Subject: [PATCH 2/6] Improve `Iterable`-to-`Set` translation --- .../internal/map/UnmodifiableArrayBackedMap.java | 16 ++++++++++------ 1 file changed, 10 insertions(+), 6 deletions(-) diff --git a/log4j-api/src/main/java/org/apache/logging/log4j/internal/map/UnmodifiableArrayBackedMap.java b/log4j-api/src/main/java/org/apache/logging/log4j/internal/map/UnmodifiableArrayBackedMap.java index a58037a63d3..078e8c7c70b 100644 --- a/log4j-api/src/main/java/org/apache/logging/log4j/internal/map/UnmodifiableArrayBackedMap.java +++ b/log4j-api/src/main/java/org/apache/logging/log4j/internal/map/UnmodifiableArrayBackedMap.java @@ -20,12 +20,11 @@ import java.util.AbstractMap; import java.util.AbstractSet; import java.util.Collection; +import java.util.HashSet; import java.util.Iterator; import java.util.Map; import java.util.Objects; import java.util.Set; -import java.util.stream.Collectors; -import java.util.stream.StreamSupport; import org.apache.logging.log4j.util.ReadOnlyStringMap; import org.apache.logging.log4j.util.TriConsumer; @@ -361,10 +360,15 @@ public UnmodifiableArrayBackedMap copyAndRemoveAll(Iterable keysToRemove } // Collect distinct keys to remove - final Set keysToRemove = keysToRemoveIterable instanceof Set - ? (Set) keysToRemoveIterable - : StreamSupport.stream(keysToRemoveIterable.spliterator(), false) - .collect(Collectors.toSet()); + final Set keysToRemove; + if (keysToRemoveIterable instanceof Set) { + keysToRemove = (Set) keysToRemoveIterable; + } else { + keysToRemove = new HashSet<>(); + for (final String key : keysToRemoveIterable) { + keysToRemove.add(key); + } + } // Create the new map final UnmodifiableArrayBackedMap oldMap = this; From b583161bc45a64c090e3edbcc01afc6bfc4fa549 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Volkan=20Yaz=C4=B1c=C4=B1?= Date: Wed, 9 Oct 2024 15:33:26 +0200 Subject: [PATCH 3/6] Decrease visibility in `CloseableThreadContextTest` Co-authored-by: Piotr P. Karwasz --- .../org/apache/logging/log4j/CloseableThreadContextTest.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/log4j-api-test/src/test/java/org/apache/logging/log4j/CloseableThreadContextTest.java b/log4j-api-test/src/test/java/org/apache/logging/log4j/CloseableThreadContextTest.java index 5c86e713e2f..f5c07c38319 100644 --- a/log4j-api-test/src/test/java/org/apache/logging/log4j/CloseableThreadContextTest.java +++ b/log4j-api-test/src/test/java/org/apache/logging/log4j/CloseableThreadContextTest.java @@ -253,7 +253,7 @@ public void pushAllWillPushAllValues() { * @see #2946 */ @Test - public void testAutoCloseableThreadContextPut() { + void testAutoCloseableThreadContextPut() { try (final CloseableThreadContext.Instance ctc1 = CloseableThreadContext.put("outer", "one")) { try (final CloseableThreadContext.Instance ctc2 = CloseableThreadContext.put("outer", "two")) { assertEquals("two", ThreadContext.get("outer")); From edc4f3ed6cc0b60d06bd1729fea8aa067dd376cd Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Volkan=20Yaz=C4=B1c=C4=B1?= Date: Wed, 9 Oct 2024 15:33:40 +0200 Subject: [PATCH 4/6] Decrease visibility in `CloseableThreadContextTest` (2nd time) Co-authored-by: Piotr P. Karwasz --- .../org/apache/logging/log4j/CloseableThreadContextTest.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/log4j-api-test/src/test/java/org/apache/logging/log4j/CloseableThreadContextTest.java b/log4j-api-test/src/test/java/org/apache/logging/log4j/CloseableThreadContextTest.java index f5c07c38319..8a093969d87 100644 --- a/log4j-api-test/src/test/java/org/apache/logging/log4j/CloseableThreadContextTest.java +++ b/log4j-api-test/src/test/java/org/apache/logging/log4j/CloseableThreadContextTest.java @@ -285,7 +285,7 @@ void testAutoCloseableThreadContextPut() { * @see #2946 */ @Test - public void testAutoCloseableThreadContextPutAll() { + void testAutoCloseableThreadContextPutAll() { try (final CloseableThreadContext.Instance ctc1 = CloseableThreadContext.put("outer", "one")) { try (final CloseableThreadContext.Instance ctc2 = CloseableThreadContext.put("outer", "two")) { assertEquals("two", ThreadContext.get("outer")); From 466815490d5b8ba9710b3013b09a41626230667a Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Volkan=20Yaz=C4=B1c=C4=B1?= Date: Wed, 9 Oct 2024 15:43:10 +0200 Subject: [PATCH 5/6] Remove `println()` in test --- .../org/apache/logging/log4j/CloseableThreadContextTest.java | 1 - 1 file changed, 1 deletion(-) diff --git a/log4j-api-test/src/test/java/org/apache/logging/log4j/CloseableThreadContextTest.java b/log4j-api-test/src/test/java/org/apache/logging/log4j/CloseableThreadContextTest.java index 8a093969d87..bc053b080c3 100644 --- a/log4j-api-test/src/test/java/org/apache/logging/log4j/CloseableThreadContextTest.java +++ b/log4j-api-test/src/test/java/org/apache/logging/log4j/CloseableThreadContextTest.java @@ -296,7 +296,6 @@ void testAutoCloseableThreadContextPutAll() { ThreadContext.put( "not-in-closeable", "true"); // Remove this line, and closing context behaves as expected ThreadContext.putAll(Collections.singletonMap("inner", "two")); // But this is not a problem - System.err.println(ThreadContext.getContext()); assertEquals("two", ThreadContext.get("inner")); assertEquals("two", ThreadContext.get("outer")); } From df5ec8115974970b5625836d9c06a7d72a65b813 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Volkan=20Yaz=C4=B1c=C4=B1?= Date: Thu, 10 Oct 2024 13:21:50 +0200 Subject: [PATCH 6/6] Add a `copyAndRemoveAll()` test --- .../map/UnmodifiableArrayBackedMapTest.java | 20 +++++++++++++++++++ 1 file changed, 20 insertions(+) diff --git a/log4j-api-test/src/test/java/org/apache/logging/log4j/internal/map/UnmodifiableArrayBackedMapTest.java b/log4j-api-test/src/test/java/org/apache/logging/log4j/internal/map/UnmodifiableArrayBackedMapTest.java index 3f43e3e2c4d..092c082ed4e 100644 --- a/log4j-api-test/src/test/java/org/apache/logging/log4j/internal/map/UnmodifiableArrayBackedMapTest.java +++ b/log4j-api-test/src/test/java/org/apache/logging/log4j/internal/map/UnmodifiableArrayBackedMapTest.java @@ -34,6 +34,7 @@ import java.util.Set; import org.apache.logging.log4j.util.ReadOnlyStringMap; import org.apache.logging.log4j.util.TriConsumer; +import org.assertj.core.api.Assertions; import org.junit.jupiter.api.Test; public class UnmodifiableArrayBackedMapTest { @@ -373,4 +374,23 @@ public void testToMap() { // verify same instance, not just equals() assertTrue(map == map.toMap()); } + + @Test + void copyAndRemoveAll_should_work() { + + // Create the actual map + UnmodifiableArrayBackedMap actualMap = UnmodifiableArrayBackedMap.EMPTY_MAP; + actualMap = actualMap.copyAndPut("outer", "two"); + actualMap = actualMap.copyAndPut("inner", "one"); + actualMap = actualMap.copyAndPut("not-in-closeable", "true"); + + // Create the expected map + UnmodifiableArrayBackedMap expectedMap = UnmodifiableArrayBackedMap.EMPTY_MAP; + expectedMap = expectedMap.copyAndPut("outer", "two"); + expectedMap = expectedMap.copyAndPut("not-in-closeable", "true"); + + // Remove the key and verify + actualMap = actualMap.copyAndRemoveAll(Collections.singleton("inner")); + Assertions.assertThat(actualMap).isEqualTo(expectedMap); + } }