Update changes following feedback
Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/e57d3e77 Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/e57d3e77 Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/e57d3e77 Branch: refs/heads/master Commit: e57d3e7744ad8af320d15377188ebb81799c8576 Parents: 3ba3628 Author: Greg Thomas <[email protected]> Authored: Mon Nov 14 09:36:33 2016 +0000 Committer: Greg Thomas <[email protected]> Committed: Mon Nov 14 09:36:33 2016 +0000 ---------------------------------------------------------------------- .../logging/log4j/CloseableThreadContext.java | 29 +- .../log4j/CloseableThreadContextTest.java | 12 +- src/site/xdoc/manual/thread-context.xml | 347 ++++++++++--------- 3 files changed, 197 insertions(+), 191 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/e57d3e77/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 5a45195..2b1a842 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 @@ -18,6 +18,7 @@ package org.apache.logging.log4j; import java.util.HashMap; import java.util.Iterator; +import java.util.List; import java.util.Map; /** @@ -78,12 +79,12 @@ public class CloseableThreadContext { * 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 + * @param messages The list of messages to be added * @return a new instance that will back out the changes when closed. - * @since 2.7.1 + * @since 2.8 */ - public static CloseableThreadContext.Instance pushAll(final ThreadContext.ContextStack stack) { - return new CloseableThreadContext.Instance().pushAll(stack); + public static CloseableThreadContext.Instance pushAll(final List<String> messages) { + return new CloseableThreadContext.Instance().pushAll(messages); } /** @@ -93,7 +94,7 @@ public class CloseableThreadContext { * * @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 + * @since 2.8 */ public static CloseableThreadContext.Instance putAll(final Map<String, String> values) { return new CloseableThreadContext.Instance().putAll(values); @@ -159,11 +160,15 @@ public class CloseableThreadContext { * * @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 + * @since 2.8 */ public Instance putAll(final Map<String, String> values) { - for (final Map.Entry<String, String> entry : values.entrySet()) { - put(entry.getKey(), entry.getValue()); + final Map<String, String> currentValues = ThreadContext.getContext(); + ThreadContext.putAll(values); + for (final String key : values.keySet()) { + if (!originalValues.containsKey(key)) { + originalValues.put(key, currentValues.get(key)); + } } return this; } @@ -172,12 +177,12 @@ public class CloseableThreadContext { * 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 + * @param messages The list of messages to be added * @return a new instance that will back out the changes when closed. - * @since 2.7.1 + * @since 2.8 */ - public Instance pushAll(final ThreadContext.ContextStack stack) { - for (final String message : stack.asList()) { + public Instance pushAll(final List<String> messages) { + for (final String message : messages) { push(message); } return this; http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/e57d3e77/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 6216c94..c5e84e0 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 @@ -16,17 +16,17 @@ */ 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.List; import java.util.Map; +import static org.hamcrest.CoreMatchers.is; +import static org.junit.Assert.assertThat; + /** * Tests {@link CloseableThreadContext}. * @@ -209,10 +209,10 @@ public class CloseableThreadContextTest { public void pushAllWillPushAllValues() throws Exception { ThreadContext.push(key); - final ThreadContext.ContextStack stack = ThreadContext.getImmutableStack(); + final List<String> messages = ThreadContext.getImmutableStack().asList(); ThreadContext.pop(); - try (final CloseableThreadContext.Instance ignored = CloseableThreadContext.pushAll(stack)) { + try (final CloseableThreadContext.Instance ignored = CloseableThreadContext.pushAll(messages)) { assertThat(ThreadContext.peek(), is(key)); } assertThat(ThreadContext.peek(), is("")); http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/e57d3e77/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 4401258..35b7a96 100644 --- a/src/site/xdoc/manual/thread-context.xml +++ b/src/site/xdoc/manual/thread-context.xml @@ -26,183 +26,184 @@ </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> + 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> + If you're using a thread pool, then you can initialise a CloseableThreadContext by using the + <tt>putAll(final Map<String, String> values)</tt> and/or + <tt>pushAll(List<String> messages)</tt> methods; + <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(); + final List<String> messages = ThreadContext.getImmutableStack().asList(); + executor.submit(new Runnable() { + public void run() { + try (final CloseableThreadContext.Instance ctc = CloseableThreadContext.putAll(values).pushAll(messages)) { + 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>
