This is an automated email from the ASF dual-hosted git repository. vy pushed a commit to branch 2.x in repository https://gitbox.apache.org/repos/asf/logging-log4j2.git
commit fefd16b7e6fccbab8b3b7b0f29675e0d6005989f Author: Volkan Yazıcı <[email protected]> AuthorDate: Fri May 24 13:30:44 2024 +0200 Rewrite `thread-context.adoc` et al. (#2535) --- src/site/antora/modules/ROOT/pages/manual/api.adoc | 30 ++- .../modules/ROOT/pages/manual/extending.adoc | 26 -- .../modules/ROOT/pages/manual/garbagefree.adoc | 3 +- .../modules/ROOT/pages/manual/thread-context.adoc | 271 +++++++-------------- .../properties-thread-context.adoc | 3 + 5 files changed, 114 insertions(+), 219 deletions(-) diff --git a/src/site/antora/modules/ROOT/pages/manual/api.adoc b/src/site/antora/modules/ROOT/pages/manual/api.adoc index 4b46a776ef..a5edfcd650 100644 --- a/src/site/antora/modules/ROOT/pages/manual/api.adoc +++ b/src/site/antora/modules/ROOT/pages/manual/api.adoc @@ -239,7 +239,7 @@ xref:manual/logbuilder.adoc[Read more on the Fluent API...] [#fish-tagging] == Fish tagging -Just as a fish can be tagged and have its movement tracked (aka. _fish tagging_), stamping log events with a common tag or set of data +Just as a fish can be tagged and have its movement tracked (aka. _fish tagging_ footnote:[Fish tagging is first described by Neil Harrison in the _"Patterns for Logging Diagnostic Messages"_ chapter of https://dl.acm.org/doi/10.5555/273448[_"Pattern Languages of Program Design 3"_ edited by R. Martin, D. Riehle, and F. Buschmann in 1997].]), 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. You can use them for several purposes, such as: @@ -283,7 +283,7 @@ xref:manual/markers.adoc[Read more on markers...] [#scoped-context] === Scoped Context -Just like a https://docs.oracle.com/en/java/javase/22/docs/api/java.base/java/lang/ScopedValue.html[Java's `ScopedValue`], in Scoped Context, the visibility of tags are associated with the block they were introduced: +Just like a https://docs.oracle.com/en/java/javase/22/docs/api/java.base/java/lang/ScopedValue.html[Java's `ScopedValue`], _Scoped Context_ facilitates associating information with a certain block of code and makings this accessible to the rest of the logging system: [source,java] ---- @@ -317,8 +317,13 @@ xref:manual/scoped-context.adoc[Read more on Scoped Context...] [#thread-context] === Thread Context -Just like https://docs.oracle.com/javase/8/docs/api/java/lang/ThreadLocal.html[Java's `ThreadLocal`], in Thread Context, the visibility of tags are associated with the thread they were introduced. -Thread Context offers both a map-structured, called _Mapped Diagnostic Context (MDC)_, and a stack-structured, called _Nested Diagnostic Context (NDC)_, storage: +Just like https://docs.oracle.com/javase/8/docs/api/java/lang/ThreadLocal.html[Java's `ThreadLocal`], _Thread Context_ facilitates associating information with the executing thread and making this information accessible to the rest of the logging system. +Thread Context offers both + +* map-structured – referred to as _Thread Context Map_ or _Mapped Diagnostic Context (MDC)_ +* stack-structured – referred to as _Thread Context Stack_ or _Nested Diagnostic Context (NDC)_ + +storage: [source,java] ---- @@ -326,13 +331,22 @@ ThreadContext.put("ipAddress", request.getRemoteAddr()); // <1> ThreadContext.put("hostName", request.getServerName()); // <1> ThreadContext.put("loginId", session.getAttribute("loginId")); // <1> -ThreadContext.push("performWork()"); // <2> +void performWork() { + ThreadContext.push("performWork()"); // <2> + + LOGGER.debug("Performing work"); // <3> + // Perform the work + + ThreadContext.pop(); // <4> +} -LOGGER.debug("Performing work"); // <3> +ThreadContext.clear(); // <5> ---- -<1> Associating properties with the logging context map of the thread -<2> Pushing properties to the logging context stack of the thread +<1> Adding properties to the thread context map +<2> Pushing properties to the thread context stack <3> Added properties can later on be used to, for instance, filter the log event, provide extra information in the layout, etc. +<4> Popping the last pushed property from the thread context stack +<5> Clearing the thread context (for both stack and map!) [CAUTION] ==== diff --git a/src/site/antora/modules/ROOT/pages/manual/extending.adoc b/src/site/antora/modules/ROOT/pages/manual/extending.adoc index f44af434b6..432d6768c1 100644 --- a/src/site/antora/modules/ROOT/pages/manual/extending.adoc +++ b/src/site/antora/modules/ROOT/pages/manual/extending.adoc @@ -580,32 +580,6 @@ ListAppender list1 = ListAppender.createAppender("List1", true, false, null, nul ListAppender list2 = ListAppender.newBuilder().setName("List1").setEntryPerNewLine(true).build(); ---- -[#Custom_ContextDataProvider] -== Custom ContextDataProvider - -The link:../javadoc/log4j-core/org/apache/logging/log4j/core/util/ContextDataProvider.html[`ContextDataProvider`] -(introduced in Log4j 2.13.2) is an interface applications and libraries can use to inject -additional key-value pairs into the LogEvent's context data. Log4j -uses `java.util.ServiceLoader` to locate and load `ContextDataProvider` instances. -Log4j itself adds the ThreadContext data to the LogEvent using -`org.apache.logging.log4j.core.impl.ThreadContextDataProvider`. Custom implementations -should implement the `org.apache.logging.log4j.core.util.ContextDataProvider` interface and -declare it as a service by defining the implmentation class in a file named -`META-INF/services/org.apache.logging.log4j.core.util.ContextDataProvider`. - -== Custom ThreadContextMap implementations - -A garbage-free `StringMap`-based context map can be installed by setting -system property `log4j2.garbagefreeThreadContextMap` to true. - -Any custom link:../javadoc/log4j-core/org/apache/logging/log4j/spi/ThreadContextMap.html[`ThreadContextMap`] -implementation can be installed by setting system property `log4j2.threadContextMap` -to the fully qualified class name of the class implementing the `ThreadContextMap` -interface. By also implementing the `ReadOnlyThreadContextMap` interface, your custom -`ThreadContextMap` implementation will be accessible to applications via the -link:../javadoc/log4j-api/org/apache/logging/log4j/ThreadContext.html#getThreadContextMap()[`ThreadContext::getThreadContextMap`] -method. - [#Custom_Plugins] == Custom Plugins diff --git a/src/site/antora/modules/ROOT/pages/manual/garbagefree.adoc b/src/site/antora/modules/ROOT/pages/manual/garbagefree.adoc index bcce913013..d06ea276c4 100644 --- a/src/site/antora/modules/ROOT/pages/manual/garbagefree.adoc +++ b/src/site/antora/modules/ROOT/pages/manual/garbagefree.adoc @@ -209,7 +209,8 @@ The `Unbox.box(primitive)` methods write directly into a `StringBuilder`, and th Not all Log4j API feature set is garbage-free, specifically: * The `ThreadContext` map (aka. MDC) is not garbage-free by default, but can be configured to be garbage-free by setting xref:#log4j2.garbagefreeThreadContextMap[the `log4j2.garbagefreeThreadContextMap` system property] to `true`. -* The `ThreadContext` stack is not garbage-free. +* The `ThreadContext` stack (aka. NDC) is not garbage-free. +* xref:manual/scoped-context.adoc[] is not garbage-free. * Logging very large messages (i.e., more than xref:#log4j2.maxReusableMsgSize[`log4j2.maxReusableMsgSize`] characters, which defaults to 518), when all loggers are xref:manual/async.adoc[asynchronous loggers], will cause the internal `StringBuilder` in the `RingBuffer` to be trimmed back to their configured maximum size. * Logging messages containing `$\{variable}` substitutions creates temporary objects. diff --git a/src/site/antora/modules/ROOT/pages/manual/thread-context.adoc b/src/site/antora/modules/ROOT/pages/manual/thread-context.adoc index d8a1e1aa4d..5b4cf6cfb3 100644 --- a/src/site/antora/modules/ROOT/pages/manual/thread-context.adoc +++ b/src/site/antora/modules/ROOT/pages/manual/thread-context.adoc @@ -17,224 +17,127 @@ = Thread Context -Log4j introduced the concept of the Mapped Diagnostic Context or MDC. It -has been documented and discussed in numerous places including -https://veerasundar.com/blog/log4j-mdc-mapped-diagnostic-context-what-and-why/[Log4j -MDC: What and Why] and -http://blog.f12.no/wp/2004/12/09/log4j-and-the-mapped-diagnostic-context/[Log4j -and the Mapped Diagnostic Context]. 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 -http://lstierneyltd.com/blog/development/log4j-nested-diagnostic-contexts-ndc/[Log4j -NDC]. SLF4J/Logback followed with its own implementation of the MDC, -which is documented very well at -http://logback.qos.ch/manual/mdc.html[Mapped Diagnostic Context]. - -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. - -== Fish Tagging - -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. - -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 _Pattern Languages -of Program Design 3_, 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 _Fish Tagging_. - -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. - -To uniquely stamp each request using the Thread Context Stack, the user -pushes contextual information on to the Stack. - -[#nested-diagnostic-context] -[source,java] ----- -ThreadContext.push(UUID.randomUUID().toString()); // Add the fishtag; +Just like https://docs.oracle.com/javase/8/docs/api/java/lang/ThreadLocal.html[Java's `ThreadLocal`], _Thread Context_ facilitates associating information with the executing thread and making this information accessible to the rest of the logging system. +Thread Context is one of many xref:manual/api.adoc#fish-tagging[_fish tagging_ capabilities provided by Log4j API]. -logger.debug("Message 1"); +[#usage] +== Usage -// ... +The entry point for associating logging-related information with the executing thread is link:../log4j-api/apidocs/org/apache/logging/log4j/ThreadContext.html[`ThreadContext`]. +It offers both -logger.debug("Message 2");. +* map-structured – referred to as _Thread Context Map_ or _Mapped Diagnostic Context (MDC)_ +* stack-structured – referred to as _Thread Context Stack_ or _Nested Diagnostic Context (NDC)_ -// ... +storage: -ThreadContext.pop(); +[source,java] ---- +ThreadContext.put("ipAddress", request.getRemoteAddr()); // <1> +ThreadContext.put("hostName", request.getServerName()); // <1> +ThreadContext.put("loginId", session.getAttribute("loginId")); // <1> -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: +void performWork() { + ThreadContext.push("performWork()"); // <2> -[#mapped-diagnostic-context] -[source,java] + LOGGER.debug("Performing work"); // <3> + // Perform the work + + ThreadContext.pop(); // <4> +} + +ThreadContext.clear(); // <5> ---- -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()); +<1> Adding properties to the thread context map +<2> Pushing properties to the thread context stack +<3> Added properties can later on be used to, for instance, filter the log event, provide extra information in the layout, etc. +<4> Popping the last pushed property from the thread context stack +<5> Clearing the thread context (for both stack and map!) -// ... +[#CloseableThreadContext] +=== Auto-clearing thread context -logger.debug("Message 1"); +When placing items on the thread context stack or map, it's necessary to remove them again when appropriate. +To assist with this, you can use link:../log4j-api/apidocs/org/apache/logging/log4j/CloseableThreadContext.html[`CloseableThreadContext`] (implementing http://docs.oracle.com/javase/7/docs/api/java/lang/AutoCloseable.html[`AutoCloseable`]) in a try-with-resources block: -// ... +[source,java] +---- +try (CloseableThreadContext.Instance ignored = CloseableThreadContext + .put("ipAddress", request.getRemoteAddr()) // <1> + .push("performWork()")) { // <1> -logger.debug("Message 2"); + LOGGER.debug("Performing work"); // <2> + // Perform the work -// ... +} -ThreadContext.clear(); +// ... // <3> ---- +<1> Making thread context changes that will only be visible **within the scope of the try-with-resources block** +<2> Added properties can later on be used to, for instance, filter the log event, provide extra information in the layout, etc. +<3> Outside the scope of the try-with-resources block made thread context changes will not be visible -== CloseableThreadContext +[#init] +=== Initializing thread context -When placing items on the stack or map, it's necessary to remove then -again when appropriate. To assist with this, the -`CloseableThreadContext` implements the -http://docs.oracle.com/javase/7/docs/api/java/lang/AutoCloseable.html[`AutoCloseable` -interface]. This allows items to be pushed to the stack or put in the -map, and removed when the `close()` 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: +It is a common use case that a single threaded execution fans out to multiple threads by means of a thread pool. +In such a case, you need to clone the context of the current thread to the ones in the pool. +For that purpose, you can use `putAll()` and `pushAll()` methods that are provided by both `ThreadContext` and `CloseableThreadContext`: [source,java] ---- -// 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("Starting background thread for user"); -// ... +Map<String, String> mdc = ThreadContext.getImmutableContext(); // <1> +List<String> ndc = ThreadContext.getImmutableStack().asList(); // <1> - logger.debug("Message 2"); +executor.submit(() -> { + try (CloseableThreadContext.Instance ignored = CloseableThreadContext + .putAll(values) // <2> + .pushAll(messages)) { // <2> -// ... + LOGGER.debug("Processing for user started"); + // ... -} + } +}); ---- +<1> Taking a snapshot of the thread context +<2> Initializing the thread context for the background task -Or, to temporarily put something in the map: - -[source,java] ----- -// 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"))) { +[#config] +== Configuration - logger.debug("Message 1"); +You can configure thread context using following properties: -// ... +include::partial$manual/systemproperties/properties-thread-context.adoc[leveloffset=+1] - logger.debug("Message 2"); +[#extending] +== Extending -// ... +Certain thread context implementation details can be customized to fit your use case. -} ----- +[#custom-ContextDataProvider] +=== Custom thread context data provider -If you're using a thread pool, then you can initialise a -CloseableThreadContext by using the -`putAll(final Map<String, String> values)` and/or -`pushAll(List<String> messages)` methods; +The link:../javadoc/log4j-core/org/apache/logging/log4j/core/util/ContextDataProvider.html[`ContextDataProvider`] is an interface applications and libraries can use to inject additional properties into a log events' context data. +Log4j uses `java.util.ServiceLoader` to locate and load `ContextDataProvider` instances. +link:../javadoc/log4j-core/org/apache/logging/log4j/core/impl/ThreadContextDataProvider.html[`ThreadContextDataProvider`] is the default implementation provided. +You can provide a custom `ContextDataProvider` implementation as follows: -[source,java] +. Create the following file in your class path: ++ +[source,text] ---- -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"); - } - }); - } -} +META-INF/services/org.apache.logging.log4j.core.util.ContextDataProvider ---- +. Write the fully-qualified class name of your custom implementation (e.g., `com.mycompany.CustomContextDataProvider`) to the file created in the previous step + +[#custom-ThreadContextMap] +=== Custom thread context map + +Custom thread context map implementations can be provided by setting xref:#log4j2.threadContextMap[the `log4j2.threadContextMap` system property] to the fully-qualified class name of the custom implementation class extending from link:../javadoc/log4j-core/org/apache/logging/log4j/spi/ThreadContextMap.html[`ThreadContextMap`]. -== Implementation details - -The Stack and the Map are managed per thread and are based on -http://docs.oracle.com/javase/6/docs/api/java/lang/ThreadLocal.html[`ThreadLocal`] -by default. The Map can be configured to use an -http://docs.oracle.com/javase/6/docs/api/java/lang/InheritableThreadLocal.html[`InheritableThreadLocal`] -(see the Configuration section). When configured this way, the contents of the Map will be passed -to child threads. However, as discussed in the -http://docs.oracle.com/javase/6/docs/api/java/util/concurrent/Executors.html#privilegedThreadFactory()[`Executors`] -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. - -Note that all methods of the -link:../javadoc/log4j-api/org/apache/logging/log4j/ThreadContext.html[`ThreadContext`] -class are static. - -=== Configuration - -* Set the system property `log4j2.disableThreadContextMap` to `true` to disable the Thread Context Map. -* Set the system property `log4j2.disableThreadContextStack` to `true` to disable the Thread Context Stack. -* Set the system property `log4j2.disableThreadContext` to `true` to disable both the Thread Context Map and Stack. -* Set the system property `log4j2.isThreadContextMapInheritable` to `true` to enable child threads to inherit the Thread -Context Map. - -== Including the ThreadContext when writing logs - -The -link:../javadoc/log4j-core/org/apache/logging/log4j/core/layout/PatternLayout.html[`PatternLayout`] -provides mechanisms to print the contents of the -link:../javadoc/log4j-api/org/apache/logging/log4j/ThreadContext.html[`ThreadContext`] -Map and Stack. - -* Use `%X` by itself to include the full contents of the Map. -* Use `%X\{key}` to include the specified key. -* Use `%x` to include the full contents of the -http://docs.oracle.com/javase/6/docs/api/java/util/Stack.html[Stack]. - -== Custom context data injectors for non thread-local context data - -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). - -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. - -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 xref:manual/extending.adoc#Custom_ContextDataProvider[extending -Log4j] for details. +While providing a custom thread context map implementation, you are advised to also extend from link:../javadoc/log4j-core/org/apache/logging/log4j/spi/ReadOnlyThreadContextMap.html[`ReadOnlyThreadContextMap`] too. +By this way, your custom thread context map implementation will be accessible to applications via +link:../javadoc/log4j-api/org/apache/logging/log4j/ThreadContext.html#getThreadContextMap()[`ThreadContext.getThreadContextMap()`]. diff --git a/src/site/antora/modules/ROOT/partials/manual/systemproperties/properties-thread-context.adoc b/src/site/antora/modules/ROOT/partials/manual/systemproperties/properties-thread-context.adoc index a3936eb2e4..71ff2533a4 100644 --- a/src/site/antora/modules/ROOT/partials/manual/systemproperties/properties-thread-context.adoc +++ b/src/site/antora/modules/ROOT/partials/manual/systemproperties/properties-thread-context.adoc @@ -85,6 +85,9 @@ GarbageFree:: a garbage-free implementation. If `true` uses an `InheritableThreadLocal` to copy the thread context map to newly created threads. +Note that, as explained in +http://docs.oracle.com/javase/6/docs/api/java/util/concurrent/Executors.html#privilegedThreadFactory()[Java's `Executors#privilegedThreadFactory()`], when you are dealing with _privileged threads_, thread context might not get propagated completely. + // tag::gcfree[] [id=log4j2.garbagefreeThreadContextMap]
