blob: 59e862aae2875904324148495fa1d35af06e4807 [file] [log] [blame]
////
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.