| //// |
| Licensed to the Apache Software Foundation (ASF) under one or more |
| contributor license agreements. See the NOTICE file distributed with |
| this work for additional information regarding copyright ownership. |
| The ASF licenses this file to You 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 |
| |
| https://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. |
| //// |
| = Log4j 2 API |
| Ralph Goers <rgoers@apache.org>; Gary Gregory <ggregory@apache.org> |
| |
| == Thread Context |
| |
| Log4j introduced the concept of the Mapped Diagnostic Context or MDC. It |
| has been documented and discussed in numerous places including |
| http://veerasundar.com/blog/2009/10/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. |
| |
| [source,java] |
| ---- |
| ThreadContext.push(UUID.randomUUID().toString()); // Add the fishtag; |
| |
| logger.debug("Message 1"); |
| |
| // ... |
| |
| logger.debug("Message 2");. |
| |
| // ... |
| |
| ThreadContext.pop(); |
| ---- |
| |
| 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: |
| |
| [source,java] |
| ---- |
| 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(); |
| ---- |
| |
| === CloseableThreadContext |
| |
| 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: |
| |
| [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("Message 2"); |
| |
| // ... |
| |
| } |
| ---- |
| |
| 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"))) { |
| |
| logger.debug("Message 1"); |
| |
| // ... |
| |
| logger.debug("Message 2"); |
| |
| // ... |
| |
| } |
| ---- |
| |
| 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; |
| |
| [source,java] |
| ---- |
| 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"); |
| } |
| }); |
| } |
| } |
| ---- |
| |
| === 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:../log4j-api/apidocs/org/apache/logging/log4j/ThreadContext.html[`ThreadContext`] |
| class are static. |
| |
| ==== Configuration |
| Set the system property `disableThreadContextMap` to `true` to disable the Thread Context Map. |
| Set the system property `disableThreadContextStack` to `true` to disable the Thread Context Stack. |
| Set the system property `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:../log4j-core/apidocs/org/apache/logging/log4j/core/layout/PatternLayout.html[`PatternLayout`] |
| provides mechanisms to print the contents of the |
| link:../log4j-api/apidocs/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 link:extending.html#Custom_ContextDataInjector[extending |
| Log4j] for details. |