From 545f9e8bcc3e885e81530bd9c6938d8d68a43c25 Mon Sep 17 00:00:00 2001 From: Marcono1234 Date: Thu, 25 Mar 2021 19:51:07 +0100 Subject: [PATCH] Add support for Log4j 2's ThreadContext (#207) * Add Log4j 2 ThreadContext module Signed-off-by: Marcono1234 * Address Log4j 2 review feedback Signed-off-by: Marcono1234 --- .mvn/javadoc/package-list | 1 + context-propagation-bom/pom.xml | 18 ++ log4j2-propagation/README.md | 41 +++ log4j2-propagation/pom.xml | 54 ++++ .../Log4j2ThreadContextData.java | 104 +++++++ .../Log4j2ThreadContextManager.java | 167 ++++++++++ .../log4j2/threadcontext/package-info.java | 21 ++ .../nl.talsmasoftware.context.ContextManager | 1 + .../Log4j2ThreadContextDataTest.java | 284 ++++++++++++++++++ .../Log4j2ThreadContextManagerTest.java | 270 +++++++++++++++++ pom.xml | 5 +- readme.md | 2 + 12 files changed, 967 insertions(+), 1 deletion(-) create mode 100644 log4j2-propagation/README.md create mode 100644 log4j2-propagation/pom.xml create mode 100644 log4j2-propagation/src/main/java/nl/talsmasoftware/context/log4j2/threadcontext/Log4j2ThreadContextData.java create mode 100644 log4j2-propagation/src/main/java/nl/talsmasoftware/context/log4j2/threadcontext/Log4j2ThreadContextManager.java create mode 100644 log4j2-propagation/src/main/java/nl/talsmasoftware/context/log4j2/threadcontext/package-info.java create mode 100644 log4j2-propagation/src/main/resources/META-INF/services/nl.talsmasoftware.context.ContextManager create mode 100644 log4j2-propagation/src/test/java/nl/talsmasoftware/context/log4j2/threadcontext/Log4j2ThreadContextDataTest.java create mode 100644 log4j2-propagation/src/test/java/nl/talsmasoftware/context/log4j2/threadcontext/Log4j2ThreadContextManagerTest.java diff --git a/.mvn/javadoc/package-list b/.mvn/javadoc/package-list index 9cd6e9f5..8990d32f 100644 --- a/.mvn/javadoc/package-list +++ b/.mvn/javadoc/package-list @@ -11,6 +11,7 @@ nl.talsmasoftware.context.metrics nl.talsmasoftware.context.locale nl.talsmasoftware.context.mdc nl.talsmasoftware.context.slf4j.mdc +nl.talsmasoftware.context.log4j2.threadcontext nl.talsmasoftware.context.opentracing nl.talsmasoftware.context.servletrequest nl.talsmasoftware.context.springsecurity diff --git a/context-propagation-bom/pom.xml b/context-propagation-bom/pom.xml index fa5f95b3..8c84a5d8 100644 --- a/context-propagation-bom/pom.xml +++ b/context-propagation-bom/pom.xml @@ -130,6 +130,24 @@ sources + + ${project.groupId} + log4j2-propagation + ${project.version} + + + ${project.groupId} + log4j2-propagation + ${project.version} + javadoc + + + ${project.groupId} + log4j2-propagation + ${project.version} + sources + + ${project.groupId} locale-context diff --git a/log4j2-propagation/README.md b/log4j2-propagation/README.md new file mode 100644 index 00000000..25c69b92 --- /dev/null +++ b/log4j2-propagation/README.md @@ -0,0 +1,41 @@ +[![Maven Version][maven-img]][maven] + +# Log4j 2 Thread Context propagation library + +Adding the `log4j2-propagation` jar to your classpath +is all that is needed to let the [Thread Context][thread-context] +from the [Log4j 2 library][log4j2] be automatically included into +the `ContextSnapshot`. + +## How to use this library + +Add it to your classpath. +```xml + + nl.talsmasoftware.context + log4j2-propagation + [see Maven badge above] + +``` + +Done! + +Now the data of the Log4j 2 Thread Context is copied into each snapshot +from the `ContextManagers.createSnapshot()` method +to be reactivated by the `Contextsnapshot.reactivate()` call. +The `ContextAwareExecutorService` automatically propagates the full +Thread Context data into all executed tasks this way. + +When Thread Context data is propagated, it is added on top of the existing +data, if any: Thread Context stack values are pushed on top of the existing +stack; map entries are added to the existing map, only replacing existing +ones in case of a map key conflict. + +Calling `ContextManagers.clearActiveContexts()` will clear the Thread Context +data of the current thread. + + [maven-img]: https://img.shields.io/maven-central/v/nl.talsmasoftware.context/log4j2-propagation + [maven]: https://search.maven.org/artifact/nl.talsmasoftware.context/log4j2-propagation + + [log4j2]: https://logging.apache.org/log4j/2.x/index.html + [thread-context]: https://logging.apache.org/log4j/2.x/manual/thread-context.html diff --git a/log4j2-propagation/pom.xml b/log4j2-propagation/pom.xml new file mode 100644 index 00000000..90dca1ca --- /dev/null +++ b/log4j2-propagation/pom.xml @@ -0,0 +1,54 @@ + + + + + 4.0.0 + + nl.talsmasoftware.context + context-propagation-root + 1.0.9-SNAPSHOT + + + + log4j2-propagation + Propagation of Log4j 2 ThreadContext + jar + + + + 1.5 + 1.5 + ${project.groupId}.log4j2 + ${project.parent.basedir} + + + + + ${project.groupId} + context-propagation + ${project.version} + + + + org.apache.logging.log4j + log4j-api + ${log4j2.version} + + + diff --git a/log4j2-propagation/src/main/java/nl/talsmasoftware/context/log4j2/threadcontext/Log4j2ThreadContextData.java b/log4j2-propagation/src/main/java/nl/talsmasoftware/context/log4j2/threadcontext/Log4j2ThreadContextData.java new file mode 100644 index 00000000..aeb22589 --- /dev/null +++ b/log4j2-propagation/src/main/java/nl/talsmasoftware/context/log4j2/threadcontext/Log4j2ThreadContextData.java @@ -0,0 +1,104 @@ +/* + * Copyright 2016-2021 Talsma ICT + * + * Licensed 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 nl.talsmasoftware.context.log4j2.threadcontext; + +import java.util.Collections; +import java.util.List; +import java.util.Map; + +import org.apache.logging.log4j.ThreadContext; + +/** + * Snapshot of the data from the Log4j 2 {@link ThreadContext} of a + * specific thread at a certain point in the past. + */ +public class Log4j2ThreadContextData { + private final Map contextMap; + private final List contextStack; + + /** + * Applies the data to the current thread. + * + * @param data data to apply, may be {@code null} + * @param overwrite whether all existing data should overwritten + */ + static void applyToCurrentThread(Log4j2ThreadContextData data, boolean overwrite) { + if (overwrite) { + ThreadContext.clearAll(); + } + if (data != null) { + data.applyToCurrentThread(); + } + } + + /** + * Applies the data on top of the {@code ThreadContext} of the current thread. + * Conflicting entries are overwritten but all other existing data is kept. + */ + void applyToCurrentThread() { + ThreadContext.putAll(contextMap); + + // There is currently no method for pushing a collection, therefore have to + // push one by one + for (String element : contextStack) { + ThreadContext.push(element); + } + } + + private Log4j2ThreadContextData(Map contextMap, List contextStack) { + this.contextMap = Collections.unmodifiableMap(contextMap); + this.contextStack = Collections.unmodifiableList(contextStack); + } + + /** + * Captures the {@code ThreadContext} data of the current thread. + * + * @return data representing the {@code ThreadContext} of the current thread + */ + static Log4j2ThreadContextData fromCurrentThreadContext() { + // Get a copy of context map and context stack + return new Log4j2ThreadContextData(ThreadContext.getContext(), ThreadContext.getImmutableStack().asList()); + } + + /** + * Returns an unmodifiable view of the {@code ThreadContext} map contained + * in this snapshot. + * + * @return {@code ThreadContext} map contained in this snapshot + */ + public Map getContextMap() { + return contextMap; + } + + /** + * Returns an unmodifiable view of the {@code ThreadContext} stack contained + * in this snapshot. The elements are ordered from least recently added at + * the beginning of the list to most recently added at the end. + * + * @return {@code ThreadContext} stack contained in this snapshot + */ + public List getContextStack() { + return contextStack; + } + + @Override + public String toString() { + return "Log4j2ThreadContextData{" + + "map=" + contextMap + + ",stack=" + contextStack + + '}'; + } +} diff --git a/log4j2-propagation/src/main/java/nl/talsmasoftware/context/log4j2/threadcontext/Log4j2ThreadContextManager.java b/log4j2-propagation/src/main/java/nl/talsmasoftware/context/log4j2/threadcontext/Log4j2ThreadContextManager.java new file mode 100644 index 00000000..33efe3fd --- /dev/null +++ b/log4j2-propagation/src/main/java/nl/talsmasoftware/context/log4j2/threadcontext/Log4j2ThreadContextManager.java @@ -0,0 +1,167 @@ +/* + * Copyright 2016-2021 Talsma ICT + * + * Licensed 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 nl.talsmasoftware.context.log4j2.threadcontext; + +import java.util.ServiceLoader; +import java.util.concurrent.atomic.AtomicBoolean; + +import org.apache.logging.log4j.CloseableThreadContext; +import org.apache.logging.log4j.ThreadContext; + +import nl.talsmasoftware.context.Context; +import nl.talsmasoftware.context.ContextManagers; +import nl.talsmasoftware.context.clearable.ClearableContextManager; + +/** + * Manager to propagate the Log4j 2 {@link ThreadContext} data from one thread to another. + *

+ * As {@code ThreadContext} already manages its own thread-local state, + * getting the active context is delegated to the {@code ThreadContext}. + * This means that closing the resulting context from {@link #getActiveContext()} will have + * no effect, because its data is not managed by this library. However, calling + * {@link #clear()} will clear the {@code ThreadContext} data of the current thread.
+ * Methods of this manager may have no effect when the {@code ThreadContext} has been disabled + * (see Log4j 2 manual). + *

+ * Initializing a new context through {@link #initializeNewContext(Log4j2ThreadContextData)} will + * add the context data on top of the existing one, if any: {@code ThreadContext} stack values + * are pushed on top of the existing stack; map entries are added to the existing map, only + * replacing existing ones in case of a map key conflict.
+ * Closing a context returned from {@link #initializeNewContext(Log4j2ThreadContextData)} will reset + * the {@code ThreadContext} to the values it had before the context was created.
+ * This means that closing nested contexts out-of-order will probably result in an undesirable state.
+ * It is therefore strongly advised to use Java's {@code try-with-resources} statement to ensure proper + * closing when nesting {@code ThreadContext} contexts. + *

+ * This manager and the contexts it creates are not suited to create {@code ThreadContext} 'scopes' + * within the same thread. Log4j 2's {@link CloseableThreadContext} should be used for that instead. + *

+ * Log4j 2 supports making {@code ThreadContext} inheritable, i.e. to have it use + * {@link InheritableThreadLocal}. In some cases this might solve the problem of propagating + * context from one thread to another. However in all cases where threads are reused (such + * as thread pool executors) this will not work. It is therefore recommended to always + * prefer using this library to cover all use cases. + *

+ * As with all manager implementations of this library there is usually no need to directly + * interact with the manager classes. Instead Java's {@link ServiceLoader} makes sure they + * are loaded as services. If an instance of this class is needed nonetheless it can be obtained + * through the field {@link #INSTANCE}. + * + * @see Log4j 2 Thread Context manual + */ +public class Log4j2ThreadContextManager implements ClearableContextManager { + /** + * Singleton instance of this class. + */ + public static final Log4j2ThreadContextManager INSTANCE = new Log4j2ThreadContextManager(); + + /** + * Returns the singleton instance. + *

+ * This method mainly exists for usage by {@link ServiceLoader}. The singleton instance + * can also directly be obtained from {@link #INSTANCE}. + * + * @return {@link #INSTANCE} + */ + // ServiceLoader supports "provider" method since Java 9 + public static Log4j2ThreadContextManager provider() { + return INSTANCE; + } + + /** + * Creates a new context manager. + * + * @deprecated + * This constructor only exists for usage by {@link ServiceLoader}. The singleton instance + * obtained from {@link #INSTANCE} should be used instead. + */ + @Deprecated + public Log4j2ThreadContextManager() { + } + + /** + * Initializes a new context for the Log4j 2 {@link ThreadContext} of the current thread. + * The data of the context is applied on top of existing data (if any) only replacing + * conflicting {@code ThreadContext} map entries but keeping all other existing data. + * + * @param value non-{@code null} data for the {@code ThreadContext} + * @return The new active context containing the specified value + * which should be closed by the caller at the end of its lifecycle from the same thread. + */ + public Context initializeNewContext(final Log4j2ThreadContextData value) { + if (value == null) { + throw new NullPointerException("value must not be null"); + } + + // Capture current ThreadContext as 'previous' and make the given data the 'new current' ThreadContext + Log4j2ThreadContextData previous = Log4j2ThreadContextData.fromCurrentThreadContext(); + Log4j2ThreadContextData.applyToCurrentThread(value, false); // Add ThreadContext data on top of existing + return new ThreadContextContext(previous, value, false); + } + + /** + * Returns a context consisting of the active Log4j 2 {@link ThreadContext} data from the current thread. + *

+ * Please note: Because these values are managed by Log4j 2 itself and not + * by this library, closing the resulting context has no effect. + * + * @return Context containing the active Log4j 2 {@code ThreadContext} data + */ + public Context getActiveContext() { + // Return fresh context that is 'already-closed'. Therefore it doesn't need previous ThreadContext data + return new ThreadContextContext(null, Log4j2ThreadContextData.fromCurrentThreadContext(), true); + } + + /** + * Clears the current Log4j 2 {@code ThreadContext} of the calling thread. + */ + public void clear() { + Log4j2ThreadContextData.applyToCurrentThread(null, true); + } + + @Override + public String toString() { + return getClass().getSimpleName(); + } + + private static final class ThreadContextContext implements Context { + private final Log4j2ThreadContextData previous, value; + private final AtomicBoolean closed; + + private ThreadContextContext(Log4j2ThreadContextData previous, Log4j2ThreadContextData value, boolean closed) { + this.previous = previous; + this.value = value; + this.closed = new AtomicBoolean(closed); + ContextManagers.onActivate(Log4j2ThreadContextManager.class, value, previous); + } + + public Log4j2ThreadContextData getValue() { + return value; + } + + public void close() { + if (closed.compareAndSet(false, true)) { + Log4j2ThreadContextData.applyToCurrentThread(previous, true); // Restore previous; overwrite current ThreadContext + ContextManagers.onDeactivate(Log4j2ThreadContextManager.class, value, previous); + } + } + + @Override + public String toString() { + return closed.get() ? "ThreadContextContext{closed}" : "ThreadContextContext{" + value + '}'; + } + } +} diff --git a/log4j2-propagation/src/main/java/nl/talsmasoftware/context/log4j2/threadcontext/package-info.java b/log4j2-propagation/src/main/java/nl/talsmasoftware/context/log4j2/threadcontext/package-info.java new file mode 100644 index 00000000..aecefa41 --- /dev/null +++ b/log4j2-propagation/src/main/java/nl/talsmasoftware/context/log4j2/threadcontext/package-info.java @@ -0,0 +1,21 @@ +/* + * Copyright 2016-2021 Talsma ICT + * + * Licensed 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. + */ + +/** + * Propagate the {@linkplain org.apache.logging.log4j.ThreadContext Log4j 2 ThreadContext} + * data from one thread to another. + */ +package nl.talsmasoftware.context.log4j2.threadcontext; diff --git a/log4j2-propagation/src/main/resources/META-INF/services/nl.talsmasoftware.context.ContextManager b/log4j2-propagation/src/main/resources/META-INF/services/nl.talsmasoftware.context.ContextManager new file mode 100644 index 00000000..bbe4a144 --- /dev/null +++ b/log4j2-propagation/src/main/resources/META-INF/services/nl.talsmasoftware.context.ContextManager @@ -0,0 +1 @@ +nl.talsmasoftware.context.log4j2.threadcontext.Log4j2ThreadContextManager diff --git a/log4j2-propagation/src/test/java/nl/talsmasoftware/context/log4j2/threadcontext/Log4j2ThreadContextDataTest.java b/log4j2-propagation/src/test/java/nl/talsmasoftware/context/log4j2/threadcontext/Log4j2ThreadContextDataTest.java new file mode 100644 index 00000000..c3d338ed --- /dev/null +++ b/log4j2-propagation/src/test/java/nl/talsmasoftware/context/log4j2/threadcontext/Log4j2ThreadContextDataTest.java @@ -0,0 +1,284 @@ +/* + * Copyright 2016-2021 Talsma ICT + * + * Licensed 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 nl.talsmasoftware.context.log4j2.threadcontext; + +import static org.hamcrest.MatcherAssert.assertThat; +import static org.hamcrest.Matchers.hasToString; +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertThrows; +import static org.junit.jupiter.api.Assertions.assertTrue; + +import java.util.Arrays; +import java.util.HashMap; +import java.util.List; +import java.util.Map; + +import org.apache.logging.log4j.ThreadContext; +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.function.Executable; + +class Log4j2ThreadContextDataTest { + @BeforeEach + @AfterEach + void clearThreadContext() { + ThreadContext.clearAll(); + } + + @Test + void testFromCurrentThreadContext() { + ThreadContext.put("map1", "value1"); + ThreadContext.put("map2", "value2"); + ThreadContext.push("stack1"); + ThreadContext.push("stack2"); + + Log4j2ThreadContextData data = Log4j2ThreadContextData.fromCurrentThreadContext(); + + Map expectedMap = new HashMap(); + expectedMap.put("map1", "value1"); + expectedMap.put("map2", "value2"); + assertEquals(expectedMap, data.getContextMap()); + + List expectedStack = Arrays.asList("stack1", "stack2"); + assertEquals(expectedStack, data.getContextStack()); + } + + @Test + void testFromCurrentThreadContext_empty() { + assertEquals(0, ThreadContext.getDepth()); + assertTrue(ThreadContext.isEmpty()); + + Log4j2ThreadContextData data = Log4j2ThreadContextData.fromCurrentThreadContext(); + assertTrue(data.getContextMap().isEmpty()); + assertTrue(data.getContextStack().isEmpty()); + + // Applying empty data should have no effect + data.applyToCurrentThread(); + assertEquals(0, ThreadContext.getDepth()); + assertTrue(ThreadContext.isEmpty()); + } + + @Test + void testFromCurrentThreadContext_empty_apply() { + assertEquals(0, ThreadContext.getDepth()); + assertTrue(ThreadContext.isEmpty()); + + Log4j2ThreadContextData data = Log4j2ThreadContextData.fromCurrentThreadContext(); + + ThreadContext.put("map1", "value1"); + ThreadContext.put("map2", "value2"); + ThreadContext.push("stack1"); + ThreadContext.push("stack2"); + + // Modification of ThreadContext should not have affected snapshot + assertTrue(data.getContextMap().isEmpty()); + assertTrue(data.getContextStack().isEmpty()); + + // Applying empty context on top of existing one should have no effect + data.applyToCurrentThread(); + + Map expectedMap = new HashMap(); + expectedMap.put("map1", "value1"); + expectedMap.put("map2", "value2"); + assertEquals(expectedMap, ThreadContext.getContext()); + + List expectedStack = Arrays.asList("stack1", "stack2"); + assertEquals(expectedStack, ThreadContext.getImmutableStack().asList()); + } + + /** + * Verify that {@link Log4j2ThreadContextData} is a snapshot and not affected + * by subsequent modification of {@link ThreadContext}. + */ + @Test + void testFromCurrentThreadContext_modification() { + ThreadContext.put("map1", "value1"); + ThreadContext.put("map2", "value2"); + ThreadContext.push("stack1"); + ThreadContext.push("stack2"); + + Log4j2ThreadContextData data = Log4j2ThreadContextData.fromCurrentThreadContext(); + + // Should not affect snapshot + ThreadContext.put("map3", "value3"); + ThreadContext.push("stack3"); + + Map expectedMap = new HashMap(); + expectedMap.put("map1", "value1"); + expectedMap.put("map2", "value2"); + assertEquals(expectedMap, data.getContextMap()); + + List expectedStack = Arrays.asList("stack1", "stack2"); + assertEquals(expectedStack, data.getContextStack()); + } + + @Test + void test_umodifiableViews() { + ThreadContext.put("map1", "value1"); + ThreadContext.put("map2", "value2"); + ThreadContext.push("stack1"); + ThreadContext.push("stack2"); + + Log4j2ThreadContextData data = Log4j2ThreadContextData.fromCurrentThreadContext(); + final Map contextMap = data.getContextMap(); + final List contextStack = data.getContextStack(); + + assertThrows(UnsupportedOperationException.class, new Executable() { + public void execute() { + contextMap.clear(); + } + }); + assertThrows(UnsupportedOperationException.class, new Executable() { + public void execute() { + contextMap.put("map3", "value3"); + } + }); + assertThrows(UnsupportedOperationException.class, new Executable() { + public void execute() { + contextStack.clear(); + } + }); + assertThrows(UnsupportedOperationException.class, new Executable() { + public void execute() { + contextStack.add("stack3"); + } + }); + + // Modification attempts should not have had any effect + Map expectedMap = new HashMap(); + expectedMap.put("map1", "value1"); + expectedMap.put("map2", "value2"); + assertEquals(expectedMap, contextMap); + + List expectedStack = Arrays.asList("stack1", "stack2"); + assertEquals(expectedStack, contextStack); + } + + @Test + void testToString() { + ThreadContext.put("map1", "value1"); + ThreadContext.put("map2", "value2"); + ThreadContext.push("stack1"); + ThreadContext.push("stack2"); + + Log4j2ThreadContextData data = Log4j2ThreadContextData.fromCurrentThreadContext(); + String expectedString = "Log4j2ThreadContextData{map=" + data.getContextMap() + + ",stack=" + data.getContextStack() + "}"; + assertThat(data, hasToString(expectedString)); + } + + /** + * Verify that {@link Log4j2ThreadContextData#applyToCurrentThread(Log4j2ThreadContextData, boolean)} + * with {@code overwrite=false} appends data to existing one, only overwriting existing + * one in case of conflict. + */ + @Test + void testApplyToCurrentThread() { + ThreadContext.put("map1", "value1"); + ThreadContext.put("map2", "value2"); + ThreadContext.push("stack1"); + ThreadContext.push("stack2"); + + Log4j2ThreadContextData data = Log4j2ThreadContextData.fromCurrentThreadContext(); + + ThreadContext.clearAll(); + ThreadContext.put("map1", "old-value1"); + ThreadContext.put("map3", "old-value3"); + ThreadContext.push("stack3"); + + Log4j2ThreadContextData.applyToCurrentThread(data, false); + + Map expectedMap = new HashMap(); + expectedMap.put("map1", "value1"); // old-value1 should have been overwritten + expectedMap.put("map2", "value2"); + expectedMap.put("map3", "old-value3"); + assertEquals(expectedMap, ThreadContext.getContext()); + + List expectedStack = Arrays.asList("stack3", "stack1", "stack2"); + assertEquals(expectedStack, ThreadContext.getImmutableStack().asList()); + } + + /** + * Verify that {@link Log4j2ThreadContextData#applyToCurrentThread(Log4j2ThreadContextData, boolean)} + * with {@code overwrite=true} overwrites all existing data. + */ + @Test + void testApplyToCurrentThread_overwrite() { + ThreadContext.put("map1", "value1"); + ThreadContext.put("map2", "value2"); + ThreadContext.push("stack1"); + ThreadContext.push("stack2"); + + Log4j2ThreadContextData data = Log4j2ThreadContextData.fromCurrentThreadContext(); + + ThreadContext.clearAll(); + ThreadContext.put("map1", "old-value1"); + ThreadContext.put("map3", "old-value3"); + ThreadContext.push("stack3"); + + Log4j2ThreadContextData.applyToCurrentThread(data, true); + + Map expectedMap = new HashMap(); + expectedMap.put("map1", "value1"); + expectedMap.put("map2", "value2"); + assertEquals(expectedMap, ThreadContext.getContext()); + + List expectedStack = Arrays.asList("stack1", "stack2"); + assertEquals(expectedStack, ThreadContext.getImmutableStack().asList()); + } + + /** + * Verify that {@link Log4j2ThreadContextData#applyToCurrentThread(Log4j2ThreadContextData, boolean)} + * with {@code data=null,overwrite=false} has no effect. + */ + @Test + void testApplyToCurrentThread_null() { + ThreadContext.put("map1", "value1"); + ThreadContext.put("map2", "value2"); + ThreadContext.push("stack1"); + ThreadContext.push("stack2"); + + // Should have no effect + Log4j2ThreadContextData.applyToCurrentThread(null, false); + + Map expectedMap = new HashMap(); + expectedMap.put("map1", "value1"); + expectedMap.put("map2", "value2"); + assertEquals(expectedMap, ThreadContext.getContext()); + + List expectedStack = Arrays.asList("stack1", "stack2"); + assertEquals(expectedStack, ThreadContext.getImmutableStack().asList()); + } + + /** + * Verify that {@link Log4j2ThreadContextData#applyToCurrentThread(Log4j2ThreadContextData, boolean)} + * with {@code data=null,overwrite=true} clears thread context. + */ + @Test + void testApplyToCurrentThread_null_overwrite() { + ThreadContext.put("map1", "value1"); + ThreadContext.put("map2", "value2"); + ThreadContext.push("stack1"); + ThreadContext.push("stack2"); + + // Should clear existing context + Log4j2ThreadContextData.applyToCurrentThread(null, true); + + assertTrue(ThreadContext.isEmpty()); + assertEquals(0, ThreadContext.getDepth()); + } +} diff --git a/log4j2-propagation/src/test/java/nl/talsmasoftware/context/log4j2/threadcontext/Log4j2ThreadContextManagerTest.java b/log4j2-propagation/src/test/java/nl/talsmasoftware/context/log4j2/threadcontext/Log4j2ThreadContextManagerTest.java new file mode 100644 index 00000000..347337d7 --- /dev/null +++ b/log4j2-propagation/src/test/java/nl/talsmasoftware/context/log4j2/threadcontext/Log4j2ThreadContextManagerTest.java @@ -0,0 +1,270 @@ +/* + * Copyright 2016-2021 Talsma ICT + * + * Licensed 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 nl.talsmasoftware.context.log4j2.threadcontext; + +import static org.hamcrest.MatcherAssert.assertThat; +import static org.hamcrest.Matchers.hasToString; +import static org.junit.jupiter.api.Assertions.assertDoesNotThrow; +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertSame; +import static org.junit.jupiter.api.Assertions.assertThrows; +import static org.junit.jupiter.api.Assertions.assertTrue; + +import java.util.Arrays; +import java.util.HashMap; +import java.util.List; +import java.util.Map; +import java.util.concurrent.Callable; +import java.util.concurrent.ExecutionException; +import java.util.concurrent.ExecutorService; +import java.util.concurrent.Executors; +import java.util.concurrent.Future; + +import org.apache.logging.log4j.ThreadContext; +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.function.Executable; + +import nl.talsmasoftware.context.Context; +import nl.talsmasoftware.context.ContextManagers; +import nl.talsmasoftware.context.ContextSnapshot; +import nl.talsmasoftware.context.executors.ContextAwareExecutorService; + +/** + * Unit test for the {@link Log4j2ThreadContextManager}. + */ +class Log4j2ThreadContextManagerTest { + + /** Underlying executor of {@link #threadpool}; not context-aware */ + ExecutorService rawThreadpool; + /** Context-aware executor */ + ExecutorService threadpool; + + @BeforeEach + void setupThreadpool() { + // Only use 1 thread because tests expect single thread to be reused + rawThreadpool = Executors.newFixedThreadPool(1); + threadpool = new ContextAwareExecutorService(rawThreadpool); + } + + @AfterEach + void shutdownThreadpool() { + threadpool.shutdown(); + } + + @BeforeEach + @AfterEach + void clearThreadContext() { + ThreadContext.clearAll(); + } + + private static Callable createGetMapValue(final String key) { + return new Callable() { + public String call() { + return ThreadContext.get(key); + } + }; + } + private static Callable createGetStackValue(final int index) { + return new Callable() { + public String call() { + return ThreadContext.getImmutableStack().asList().get(index); + } + }; + } + + @Test + void testProvider() { + assertSame(Log4j2ThreadContextManager.INSTANCE, Log4j2ThreadContextManager.provider()); + + // Verify that no-arg constructor, used by ServiceLoader, works + assertDoesNotThrow(new Executable() { + @SuppressWarnings("deprecation") + public void execute() { + new Log4j2ThreadContextManager(); + } + }); + } + + @Test + void testInitializeNewContext_null() { + assertThrows(NullPointerException.class, new Executable() { + public void execute() { + Log4j2ThreadContextManager.INSTANCE.initializeNewContext(null); + } + }); + } + + /** + * Verify that calling {@code close()} on the result of {@link Log4j2ThreadContextManager#getActiveContext()} + * has no effect because it is managed by Log4j 2. + */ + @Test + void testGetActiveContext_close() { + ThreadContext.put("map1", "value1"); + ThreadContext.put("map2", "value2"); + ThreadContext.push("stack1"); + ThreadContext.push("stack2"); + + // Should have no effect + Log4j2ThreadContextManager.INSTANCE.getActiveContext().close(); + + Map expectedMap = new HashMap(); + expectedMap.put("map1", "value1"); + expectedMap.put("map2", "value2"); + assertEquals(expectedMap, ThreadContext.getContext()); + + List expectedStack = Arrays.asList("stack1", "stack2"); + assertEquals(expectedStack, ThreadContext.getImmutableStack().asList()); + } + + @Test + void test_ThreadContextPropagation() throws ExecutionException, InterruptedException { + String mapKey = "map1"; + ThreadContext.put(mapKey, "value1"); + ThreadContext.push("stack1"); + Future mapValue = threadpool.submit(createGetMapValue(mapKey)); + assertEquals("value1", mapValue.get()); + Future stackValue = threadpool.submit(createGetStackValue(0)); + assertEquals("stack1", stackValue.get()); + } + + /** + * Verify that existing {@code ThreadContext} data is only overwritten + * in case of conflict. + */ + @Test + void test_ThreadContextPropagation_existing() throws ExecutionException, InterruptedException { + // Pretend there exists already data for the thread which was for example + // initialized when the thread was constructed + rawThreadpool.submit(new Runnable() { + public void run() { + ThreadContext.put("map1", "old-value1"); + ThreadContext.put("map2", "old-value2"); + ThreadContext.push("stack1"); + } + }).get(); + + ThreadContext.put("map1", "value1"); + ThreadContext.put("map3", "value3"); + ThreadContext.push("stack2"); + Future mapValue1 = threadpool.submit(createGetMapValue("map1")); + assertEquals("value1", mapValue1.get()); // Was overwritten + Future mapValue2 = threadpool.submit(createGetMapValue("map2")); + assertEquals("old-value2", mapValue2.get()); + Future mapValue3 = threadpool.submit(createGetMapValue("map3")); + assertEquals("value3", mapValue3.get()); + + Future stackValue1 = threadpool.submit(createGetStackValue(0)); + assertEquals("stack1", stackValue1.get()); + Future stackValue2 = threadpool.submit(createGetStackValue(1)); + assertEquals("stack2", stackValue2.get()); + + // After clearing context in current thread, worker thread should + // still have its previous context; empty thread context should + // not overwrite existing one on propagation + ThreadContext.clearAll(); + + mapValue1 = threadpool.submit(createGetMapValue("map1")); + assertEquals("old-value1", mapValue1.get()); + mapValue2 = threadpool.submit(createGetMapValue("map2")); + assertEquals("old-value2", mapValue2.get()); + Future mapSize = threadpool.submit(new Callable() { + public Integer call() { + return ThreadContext.getContext().size(); + } + }); + assertEquals(2, mapSize.get()); + + stackValue1 = threadpool.submit(createGetStackValue(0)); + assertEquals("stack1", stackValue1.get()); + Future stackSize = threadpool.submit(new Callable() { + public Integer call() { + return ThreadContext.getDepth(); + } + }); + assertEquals(1, stackSize.get()); + } + + @Test + void test_SnapshotRestoration() { + String mapKey1 = "map1"; + ThreadContext.put(mapKey1, "value1"); + ThreadContext.push("stack1"); + + ContextSnapshot snapshot = ContextManagers.createContextSnapshot(); + assertEquals("value1", ThreadContext.get(mapKey1), "New snapshot shouldn't manipulate ThreadContext map"); + assertEquals(1, ThreadContext.getContext().size()); + assertEquals("stack1", ThreadContext.peek(), "New snapshot shouldn't manipulate ThreadContext stack"); + assertEquals(1, ThreadContext.getDepth()); + + ThreadContext.put(mapKey1, "value1-new"); + assertEquals("value1-new", ThreadContext.get(mapKey1), "Sanity check: ThreadContext map changed"); + ThreadContext.push("stack2"); + assertEquals("stack2", ThreadContext.peek(), "Sanity check: ThreadContext stack changed"); + + String mapKey2 = "map2"; + ThreadContext.put(mapKey2, "value2"); + + Context reactivation = snapshot.reactivate(); + assertEquals("value1", ThreadContext.get(mapKey1), "ThreadContext changed by reactivation"); + assertEquals("value2", ThreadContext.get(mapKey2), "Existing ThreadContext data should not have been cleared"); + assertEquals(2, ThreadContext.getContext().size()); + + List expectedStack = Arrays.asList("stack1", "stack2", "stack1"); + assertEquals(expectedStack, ThreadContext.getImmutableStack().asList(), "Stack value should have been pushed on existing stack"); + + reactivation.close(); + assertEquals("value1-new", ThreadContext.get(mapKey1), "ThreadContext restored"); + assertEquals("value2", ThreadContext.get(mapKey2), "Existing ThreadContext data should not have been cleared"); + assertEquals(2, ThreadContext.getContext().size()); + + expectedStack = Arrays.asList("stack1", "stack2"); + assertEquals(expectedStack, ThreadContext.getImmutableStack().asList(), "Last stack value should have been removed again"); + } + + @Test + void testToString() { + assertThat(Log4j2ThreadContextManager.INSTANCE.toString(), hasToString("Log4j2ThreadContextManager")); + } + + @Test + void testContextToString() { + ThreadContext.put("map1", "value1"); + ThreadContext.push("stack1"); + + Log4j2ThreadContextData data = Log4j2ThreadContextData.fromCurrentThreadContext(); + + Log4j2ThreadContextManager mgr = Log4j2ThreadContextManager.INSTANCE; + assertThat(mgr.getActiveContext(), hasToString("ThreadContextContext{closed}")); + Context ctx = mgr.initializeNewContext(data); + try { + assertThat(ctx, hasToString("ThreadContextContext{" + data + "}")); + } finally { + ctx.close(); + } + } + + @Test + void testClearActiveContexts() { + ThreadContext.put("map1", "value1"); + ThreadContext.push("stack1"); + ContextManagers.clearActiveContexts(); + assertTrue(ThreadContext.isEmpty()); + assertEquals(0, ThreadContext.getDepth()); + } +} diff --git a/pom.xml b/pom.xml index 15794f7d..67813d7f 100644 --- a/pom.xml +++ b/pom.xml @@ -41,6 +41,7 @@ context-propagation-metrics context-propagation-micrometer locale-context + log4j2-propagation servletrequest-propagation slf4j-propagation spring-security-context @@ -92,8 +93,9 @@ 0.33.0 5.1.5.RELEASE 4.0.1 - 1.7.30 + 2.14.0 + 5.7.1 1.2.3 2.2 @@ -203,6 +205,7 @@ https://docs.oracle.com/en/java/javase/11/docs/api https://www.slf4j.org/api + https://logging.apache.org/log4j/2.x/log4j-api/apidocs https://metrics.dropwizard.io/4.0.0/apidocs diff --git a/readme.md b/readme.md index 89f0f326..b2b901fb 100644 --- a/readme.md +++ b/readme.md @@ -82,6 +82,7 @@ The following `ThreadLocal`-based contexts are currently supported out of the box by this context-propagation library: - [SLF4J MDC (Mapped Diagnostic Context)][slf4j mdc propagation] +- [Log4j 2 Thread Context][log4j2 thread context propagation] - [OpenTracing Span contexts][opentracing span propagation] - [Spring Security Context] - [Locale context][locale context] @@ -168,6 +169,7 @@ configure various timers in the global default metric registry of your applicati [servletrequest propagation]: servletrequest-propagation [slf4j mdc propagation]: slf4j-propagation + [log4j2 thread context propagation]: log4j2-propagation [locale context]: locale-context [spring security context]: spring-security-context [opentracing span propagation]: opentracing-span-propagation