Repository: logging-log4j2 Updated Branches: refs/heads/master 6e69e95d3 -> df481a19c
LOG4J2-1692: Add putAll() / pushAll() methods to CloseableThreadContext Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/3ba3628f Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/3ba3628f Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/3ba3628f Branch: refs/heads/master Commit: 3ba3628fa6a94db512ceef10ecf2188ee740e857 Parents: abf29af Author: Greg Thomas <[email protected]> Authored: Fri Nov 11 16:39:51 2016 +0000 Committer: Greg Thomas <[email protected]> Committed: Fri Nov 11 16:39:51 2016 +0000 ---------------------------------------------------------------------- .../logging/log4j/CloseableThreadContext.java | 66 +++- .../log4j/CloseableThreadContextTest.java | 39 ++- src/site/xdoc/manual/thread-context.xml | 329 ++++++++++--------- 3 files changed, 272 insertions(+), 162 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/3ba3628f/log4j-api/src/main/java/org/apache/logging/log4j/CloseableThreadContext.java ---------------------------------------------------------------------- diff --git a/log4j-api/src/main/java/org/apache/logging/log4j/CloseableThreadContext.java b/log4j-api/src/main/java/org/apache/logging/log4j/CloseableThreadContext.java index 9f0a279..5a45195 100644 --- a/log4j-api/src/main/java/org/apache/logging/log4j/CloseableThreadContext.java +++ b/log4j-api/src/main/java/org/apache/logging/log4j/CloseableThreadContext.java @@ -62,8 +62,8 @@ public class CloseableThreadContext { } /** - * Populates the Thread Context Map with the supplied key/value pairs. Any existing keys in the - * {@link ThreadContext} will be replaced with the supplied values, and restored back to their original values when + * Populates the Thread Context Map with the supplied key/value pair. Any existing key in the + * {@link ThreadContext} will be replaced with the supplied value, and restored back to their original value when * the instance is closed. * * @param key The key to be added @@ -74,6 +74,31 @@ public class CloseableThreadContext { return new CloseableThreadContext.Instance().put(key, value); } + /** + * Populates the Thread Context Stack with the supplied stack. The information will be popped off when + * the instance is closed. + * + * @param values The stack of values to be added + * @return a new instance that will back out the changes when closed. + * @since 2.7.1 + */ + public static CloseableThreadContext.Instance pushAll(final ThreadContext.ContextStack stack) { + return new CloseableThreadContext.Instance().pushAll(stack); + } + + /** + * Populates the Thread Context Map with the supplied key/value pairs. Any existing keys in the + * {@link ThreadContext} will be replaced with the supplied values, and restored back to their original value when + * the instance is closed. + * + * @param values The map of key/value pairs to be added + * @return a new instance that will back out the changes when closed. + * @since 2.7.1 + */ + public static CloseableThreadContext.Instance putAll(final Map<String, String> values) { + return new CloseableThreadContext.Instance().putAll(values); + } + public static class Instance implements AutoCloseable { private int pushCount = 0; @@ -110,13 +135,13 @@ public class CloseableThreadContext { } /** - * Populates the Thread Context Map with the supplied key/value pairs. Any existing keys in the - * {@link ThreadContext} will be replaced with the supplied values, and restored back to their original values when + * Populates the Thread Context Map with the supplied key/value pair. Any existing key in the + * {@link ThreadContext} will be replaced with the supplied value, and restored back to their original value when * the instance is closed. * * @param key The key to be added * @param value The value to be added - * @return the instance that will back out the changes when closed. + * @return a new instance that will back out the changes when closed. */ public Instance put(final String key, final String value) { // If there are no existing values, a null will be stored as an old value @@ -128,6 +153,37 @@ public class CloseableThreadContext { } /** + * Populates the Thread Context Map with the supplied key/value pairs. Any existing keys in the + * {@link ThreadContext} will be replaced with the supplied values, and restored back to their original value when + * the instance is closed. + * + * @param values The map of key/value pairs to be added + * @return a new instance that will back out the changes when closed. + * @since 2.7.1 + */ + public Instance putAll(final Map<String, String> values) { + for (final Map.Entry<String, String> entry : values.entrySet()) { + put(entry.getKey(), entry.getValue()); + } + return this; + } + + /** + * Populates the Thread Context Stack with the supplied stack. The information will be popped off when + * the instance is closed. + * + * @param values The stack of values to be added + * @return a new instance that will back out the changes when closed. + * @since 2.7.1 + */ + public Instance pushAll(final ThreadContext.ContextStack stack) { + for (final String message : stack.asList()) { + push(message); + } + return this; + } + + /** * Removes the values from the {@link ThreadContext}. * <p> * Values pushed to the {@link ThreadContext} <em>stack</em> will be popped off. http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/3ba3628f/log4j-api/src/test/java/org/apache/logging/log4j/CloseableThreadContextTest.java ---------------------------------------------------------------------- diff --git a/log4j-api/src/test/java/org/apache/logging/log4j/CloseableThreadContextTest.java b/log4j-api/src/test/java/org/apache/logging/log4j/CloseableThreadContextTest.java index 1194678..6216c94 100644 --- a/log4j-api/src/test/java/org/apache/logging/log4j/CloseableThreadContextTest.java +++ b/log4j-api/src/test/java/org/apache/logging/log4j/CloseableThreadContextTest.java @@ -17,12 +17,16 @@ package org.apache.logging.log4j; import static org.hamcrest.CoreMatchers.is; +import static org.hamcrest.CoreMatchers.nullValue; import static org.junit.Assert.assertThat; import org.apache.logging.log4j.junit.ThreadContextRule; import org.junit.Rule; import org.junit.Test; +import java.util.HashMap; +import java.util.Map; + /** * Tests {@link CloseableThreadContext}. * @@ -32,9 +36,9 @@ public class CloseableThreadContextTest { private final String key = "key"; private final String value = "value"; - + @Rule - public final ThreadContextRule threadContextRule = new ThreadContextRule(); + public final ThreadContextRule threadContextRule = new ThreadContextRule(); @Test public void shouldAddAnEntryToTheMap() throws Exception { @@ -184,4 +188,35 @@ public class CloseableThreadContextTest { assertThat(ThreadContext.get(key), is(originalMapValue)); assertThat(ThreadContext.peek(), is(originalStackValue)); } + + @Test + public void putAllWillPutAllValues() throws Exception { + + final String oldValue = "oldValue"; + ThreadContext.put(key, oldValue); + + final Map<String, String> valuesToPut = new HashMap<>(); + valuesToPut.put(key, value); + + try (final CloseableThreadContext.Instance ignored = CloseableThreadContext.putAll(valuesToPut)) { + assertThat(ThreadContext.get(key), is(value)); + } + assertThat(ThreadContext.get(key), is(oldValue)); + + } + + @Test + public void pushAllWillPushAllValues() throws Exception { + + ThreadContext.push(key); + final ThreadContext.ContextStack stack = ThreadContext.getImmutableStack(); + ThreadContext.pop(); + + try (final CloseableThreadContext.Instance ignored = CloseableThreadContext.pushAll(stack)) { + assertThat(ThreadContext.peek(), is(key)); + } + assertThat(ThreadContext.peek(), is("")); + + } + } http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/3ba3628f/src/site/xdoc/manual/thread-context.xml ---------------------------------------------------------------------- diff --git a/src/site/xdoc/manual/thread-context.xml b/src/site/xdoc/manual/thread-context.xml index dd5b21c..4401258 100644 --- a/src/site/xdoc/manual/thread-context.xml +++ b/src/site/xdoc/manual/thread-context.xml @@ -26,164 +26,183 @@ </properties> <body> - <section name="Log4j 2 API"> - <subsection name="Thread Context"> - <h4>Introduction</h4> - <p>Log4j introduced the concept of the Mapped Diagnostic Context or MDC. It has been documented and - discussed in numerous places including - <a href="http://veerasundar.com/blog/2009/10/log4j-mdc-mapped-diagnostic-context-what-and-why/";>Log4j MDC: What and Why</a> and - <a href="http://blog.f12.no/wp/2004/12/09/log4j-and-the-mapped-diagnostic-context/";>Log4j and the Mapped Diagnostic Context</a>. - In addition, Log4j 1.x provides support for a Nested Diagnostic Context or NDC. It too has been documented - and discussed in various places such as - <a href="http://lstierneyltd.com/blog/development/log4j-nested-diagnostic-contexts-ndc/";>Log4j NDC</a>. - SLF4J/Logback followed with its own implementation of the MDC, which is documented very well at - <a href="http://logback.qos.ch/manual/mdc.html";>Mapped Diagnostic Context</a>. - </p> - <p>Log4j 2 continues with the idea of the MDC and the NDC but merges them into a single Thread Context. - The Thread Context Map is the equivalent of the MDC and the Thread Context Stack is the equivalent of the - NDC. Although these are frequently used for purposes other than diagnosing problems, they are still - frequently referred to as the MDC and NDC in Log4j 2 since they are already well known by those acronyms. - </p> - <h4>Fish Tagging</h4> - <p>Most real-world systems have to deal with multiple clients simultaneously. In a typical multithreaded - implementation of such a system, different threads will handle different clients. Logging is - especially well suited to trace and debug complex distributed applications. A common approach to - differentiate the logging output of one client from another is to instantiate a new separate logger for - each client. This promotes the proliferation of loggers and increases the management overhead of logging. - </p> - <p>A lighter technique is to uniquely stamp each log request initiated from the same client interaction. - Neil Harrison described this method in the book "Patterns for Logging Diagnostic Messages," in <em>Pattern - Languages of Program Design 3</em>, edited by R. Martin, D. Riehle, and F. Buschmann - (Addison-Wesley, 1997). Just as a fish can be tagged and have its movement tracked, stamping log - events with a common tag or set of data elements allows the complete flow of a transaction or a request - to be tracked. We call this <i>Fish Tagging</i>. - </p> - <p>Log4j provides two mechanisms for performing Fish Tagging; the Thread Context Map and the Thread - Context Stack. The Thread Context Map allows any number of items to be added and be identified - using key/value pairs. The Thread Context Stack allows one or more items to be pushed on the - Stack and then be identified by their order in the Stack or by the data itself. Since key/value - pairs are more flexible, the Thread Context Map is recommended when data items may be added during - the processing of the request or when there are more than one or two items. - </p> - <p>To uniquely stamp each request using the Thread Context Stack, the user pushes contextual information - on to the Stack. - </p> - <pre class="prettyprint linenums"> -ThreadContext.push(UUID.randomUUID().toString()); // Add the fishtag; + <section name="Log4j 2 API"> + <subsection name="Thread Context"> + <h4>Introduction</h4> + <p>Log4j introduced the concept of the Mapped Diagnostic Context or MDC. It has been documented and + discussed in numerous places including + <a href="http://veerasundar.com/blog/2009/10/log4j-mdc-mapped-diagnostic-context-what-and-why/";>Log4j MDC: What and Why</a> and + <a href="http://blog.f12.no/wp/2004/12/09/log4j-and-the-mapped-diagnostic-context/";>Log4j and the Mapped Diagnostic Context</a>. + In addition, Log4j 1.x provides support for a Nested Diagnostic Context or NDC. It too has been documented + and discussed in various places such as + <a href="http://lstierneyltd.com/blog/development/log4j-nested-diagnostic-contexts-ndc/";>Log4j NDC</a>. + SLF4J/Logback followed with its own implementation of the MDC, which is documented very well at + <a href="http://logback.qos.ch/manual/mdc.html";>Mapped Diagnostic Context</a>. + </p> + <p>Log4j 2 continues with the idea of the MDC and the NDC but merges them into a single Thread Context. + The Thread Context Map is the equivalent of the MDC and the Thread Context Stack is the equivalent of the + NDC. Although these are frequently used for purposes other than diagnosing problems, they are still + frequently referred to as the MDC and NDC in Log4j 2 since they are already well known by those acronyms. + </p> + <h4>Fish Tagging</h4> + <p>Most real-world systems have to deal with multiple clients simultaneously. In a typical multithreaded + implementation of such a system, different threads will handle different clients. Logging is + especially well suited to trace and debug complex distributed applications. A common approach to + differentiate the logging output of one client from another is to instantiate a new separate logger for + each client. This promotes the proliferation of loggers and increases the management overhead of logging. + </p> + <p>A lighter technique is to uniquely stamp each log request initiated from the same client interaction. + Neil Harrison described this method in the book "Patterns for Logging Diagnostic Messages," in <em>Pattern + Languages of Program Design 3</em>, edited by R. Martin, D. Riehle, and F. Buschmann + (Addison-Wesley, 1997). Just as a fish can be tagged and have its movement tracked, stamping log + events with a common tag or set of data elements allows the complete flow of a transaction or a request + to be tracked. We call this <i>Fish Tagging</i>. + </p> + <p>Log4j provides two mechanisms for performing Fish Tagging; the Thread Context Map and the Thread + Context Stack. The Thread Context Map allows any number of items to be added and be identified + using key/value pairs. The Thread Context Stack allows one or more items to be pushed on the + Stack and then be identified by their order in the Stack or by the data itself. Since key/value + pairs are more flexible, the Thread Context Map is recommended when data items may be added during + the processing of the request or when there are more than one or two items. + </p> + <p>To uniquely stamp each request using the Thread Context Stack, the user pushes contextual information + on to the Stack. + </p> + <pre class="prettyprint linenums"> + ThreadContext.push(UUID.randomUUID().toString()); // Add the fishtag; -logger.debug("Message 1"); -. -. -. -logger.debug("Message 2"); -. -. -ThreadContext.pop();</pre> - <p> - The alternative to the Thread Context Stack is the Thread Context Map. In this case, attributes - associated with the request being processed are adding at the beginning and removed at the end - as follows: - </p> - <pre class="prettyprint linenums"> -ThreadContext.put("id", UUID.randomUUID().toString()); // Add the fishtag; -ThreadContext.put("ipAddress", request.getRemoteAddr()); -ThreadContext.put("loginId", session.getAttribute("loginId")); -ThreadContext.put("hostName", request.getServerName()); -. -logger.debug("Message 1"); -. -. -logger.debug("Message 2"); -. -. -ThreadContext.clear();</pre> + logger.debug("Message 1"); + . + . + . + logger.debug("Message 2"); + . + . + ThreadContext.pop();</pre> + <p> + The alternative to the Thread Context Stack is the Thread Context Map. In this case, attributes + associated with the request being processed are adding at the beginning and removed at the end + as follows: + </p> + <pre class="prettyprint linenums"> + ThreadContext.put("id", UUID.randomUUID().toString()); // Add the fishtag; + ThreadContext.put("ipAddress", request.getRemoteAddr()); + ThreadContext.put("loginId", session.getAttribute("loginId")); + ThreadContext.put("hostName", request.getServerName()); + . + logger.debug("Message 1"); + . + . + logger.debug("Message 2"); + . + . + ThreadContext.clear();</pre> - <h4>CloseableThreadContext</h4> - <p>When placing items on the stack or map, it's necessary to remove then again when appropriate. To assist with - this, the <tt>CloseableThreadContext</tt> implements the <a href="http://docs.oracle.com/javase/7/docs/api/java/lang/AutoCloseable.html";>AutoCloseable - interface</a>. This allows items to be pushed to the stack or put in the map, and removed when the <tt>close()</tt> method is called - - or automatically as part of a try-with-resources. For example, to temporarily push something on to the stack and then remove it: - </p> - <pre class="prettyprint linenums"> -// Add to the ThreadContext stack for this try block only; -try (final CloseableThreadContext.Instance ctc = CloseableThreadContext.push(UUID.randomUUID().toString())) { + <h4>CloseableThreadContext</h4> + <p>When placing items on the stack or map, it's necessary to remove then again when appropriate. To assist with + this, the <tt>CloseableThreadContext</tt> implements the <a href="http://docs.oracle.com/javase/7/docs/api/java/lang/AutoCloseable.html";>AutoCloseable + interface</a>. This allows items to be pushed to the stack or put in the map, and removed when the <tt>close()</tt> method is called - + or automatically as part of a try-with-resources. For example, to temporarily push something on to the stack and then remove it: + </p> + <pre class="prettyprint linenums"> + // Add to the ThreadContext stack for this try block only; + try (final CloseableThreadContext.Instance ctc = CloseableThreadContext.push(UUID.randomUUID().toString())) { - logger.debug("Message 1"); -. -. - logger.debug("Message 2"); -. -. -}</pre> - <p> - Or, to temporarily put something in the map: - </p> - <pre class="prettyprint linenums"> -// Add to the ThreadContext map for this try block only; -try (final CloseableThreadContext.Instance ctc = CloseableThreadContext.put("id", UUID.randomUUID().toString()) - .put("loginId", session.getAttribute("loginId"))) { + logger.debug("Message 1"); + . + . + logger.debug("Message 2"); + . + . + }</pre> + <p> + Or, to temporarily put something in the map: + </p> + <pre class="prettyprint linenums"> + // Add to the ThreadContext map for this try block only; + try (final CloseableThreadContext.Instance ctc = CloseableThreadContext.put("id", UUID.randomUUID().toString()) + .put("loginId", session.getAttribute("loginId"))) { - logger.debug("Message 1"); -. -. - logger.debug("Message 2"); -. -. -}</pre> - <h4>Implementation details</h4> - <p>The Stack and the Map are managed per thread and are based on - <a href="http://docs.oracle.com/javase/6/docs/api/java/lang/ThreadLocal.html";>ThreadLocal</a> - by default. The Map can be configured to use an - <a href="http://docs.oracle.com/javase/6/docs/api/java/lang/InheritableThreadLocal.html";>InheritableThreadLocal</a> - by setting system property <tt>isThreadContextMapInheritable</tt> to <tt>"true"</tt>. - When configured this way, the contents of the Map will be passed to child threads. However, as - discussed in the - <a href="http://docs.oracle.com/javase/6/docs/api/java/util/concurrent/Executors.html#privilegedThreadFactory()">Executors</a> - class and in other cases where thread pooling is utilized, the ThreadContext may not always be - automatically passed to worker threads. In those cases the pooling mechanism should provide a means for - doing so. The getContext() and cloneStack() methods can be used to obtain copies of the Map and Stack - respectively. - </p> - <p> - Note that all methods of the - <a href="../log4j-api/apidocs/org/apache/logging/log4j/ThreadContext.html">ThreadContext</a> - class are static. - </p> - <h4>Including the ThreadContext when writing logs</h4> - <p> - The <a href="../log4j-api/apidocs/org/apache/logging/log4j/core/PatternLayout.html">PatternLayout</a> - provides mechanisms to print the contents of the - <a href="../log4j-api/apidocs/org/apache/logging/log4j/ThreadContext.html">ThreadContext</a> - Map and Stack. - </p> - <ul> - <li> - Use <code>%X</code> by itself to include the full contents of the Map. - </li> - <li> - Use <code>%X{key}</code> to include the specified key. - </li> - <li> - Use <code>%x</code> to include the full contents of the <a href="http://docs.oracle.com/javase/6/docs/api/java/util/Stack.html";>Stack</a>. - </li> - </ul> - <h4>Custom context data injectors for non thread-local context data</h4> - <p> - With the ThreadContext logging statements can be tagged so log entries that were related in some way - can be linked via these tags. The limitation is that this only works for logging done on the same application thread - (or child threads when configured). - </p> - <p> - Some applications have a thread model that delegates work to other threads, and - in such models, tagging attributes that are put into a thread-local map in one thread are not visible - in the other threads and logging done in the other threads will not show these attributes. - </p> - <p> - Log4j 2.7 adds a flexible mechanism to tag logging statements with context data coming from - other sources than the ThreadContext. - See the manual page on <a href="extending.html#Custom_ContextDataInjector">extending Log4j</a> for details. - </p> - </subsection> - </section> + logger.debug("Message 1"); + . + . + logger.debug("Message 2"); + . + . + }</pre> + + If you're using a thread pool, then you can initialise a CloseableThreadContext by using the + <tt>putAll(final Map<String, String> values)</tt> method; + <pre class="prettyprint linenums"> + for( final Session session : sessions ) { + try (final CloseableThreadContext.Instance ctc = CloseableThreadContext.put("loginId", session.getAttribute("loginId"))) { + logger.debug("Starting background thread for user"); + final Map<String, String> values = ThreadContext.getImmutableContext(); + executor.submit(new Runnable() { + public void run() { + try (final CloseableThreadContext.Instance ctc = CloseableThreadContext.putAll(values)) { + logger.debug("Processing for user started"); + . + logger.debug("Processing for user completed"); + } + }); + } + }</pre> + + <h4>Implementation details</h4> + <p>The Stack and the Map are managed per thread and are based on + <a href="http://docs.oracle.com/javase/6/docs/api/java/lang/ThreadLocal.html";>ThreadLocal</a> + by default. The Map can be configured to use an + <a href="http://docs.oracle.com/javase/6/docs/api/java/lang/InheritableThreadLocal.html";>InheritableThreadLocal</a> + by setting system property <tt>isThreadContextMapInheritable</tt> to <tt>"true"</tt>. + When configured this way, the contents of the Map will be passed to child threads. However, as + discussed in the + <a href="http://docs.oracle.com/javase/6/docs/api/java/util/concurrent/Executors.html#privilegedThreadFactory()">Executors</a> + class and in other cases where thread pooling is utilized, the ThreadContext may not always be + automatically passed to worker threads. In those cases the pooling mechanism should provide a means for + doing so. The getContext() and cloneStack() methods can be used to obtain copies of the Map and Stack + respectively. + </p> + <p> + Note that all methods of the + <a href="../log4j-api/apidocs/org/apache/logging/log4j/ThreadContext.html">ThreadContext</a> + class are static. + </p> + <h4>Including the ThreadContext when writing logs</h4> + <p> + The <a href="../log4j-api/apidocs/org/apache/logging/log4j/core/PatternLayout.html">PatternLayout</a> + provides mechanisms to print the contents of the + <a href="../log4j-api/apidocs/org/apache/logging/log4j/ThreadContext.html">ThreadContext</a> + Map and Stack. + </p> + <ul> + <li> + Use <code>%X</code> by itself to include the full contents of the Map. + </li> + <li> + Use <code>%X{key}</code> to include the specified key. + </li> + <li> + Use <code>%x</code> to include the full contents of the <a href="http://docs.oracle.com/javase/6/docs/api/java/util/Stack.html";>Stack</a>. + </li> + </ul> + <h4>Custom context data injectors for non thread-local context data</h4> + <p> + With the ThreadContext logging statements can be tagged so log entries that were related in some way + can be linked via these tags. The limitation is that this only works for logging done on the same application thread + (or child threads when configured). + </p> + <p> + Some applications have a thread model that delegates work to other threads, and + in such models, tagging attributes that are put into a thread-local map in one thread are not visible + in the other threads and logging done in the other threads will not show these attributes. + </p> + <p> + Log4j 2.7 adds a flexible mechanism to tag logging statements with context data coming from + other sources than the ThreadContext. + See the manual page on <a href="extending.html#Custom_ContextDataInjector">extending Log4j</a> for details. + </p> + </subsection> + </section> </body> </document>
