日志记录-保持操作的时间跟踪-对于任何关键任务系统，无论大小，都至关重要。 我们的Project-X框架也是如此 ，这就是为什么我们希望从一开始就正确地做到这一点。

基于我们在传奇的UltraESB上的登录经验， 上下文日志记录（每条日志行自动记录其原始逻辑上下文，例如它来自特定单元还是来自基础框架）是我们一直期待的事情 。

我们已经知道log4j2通过其CloseableThreadContext实现提供了上下文日志记录 ，几乎包含了我们所需要的一切。 但我们需要更多：

1. 我们需要一个合适的日志代码管理机制，其中每个日志行包含一个唯一的日志代码，分别表示子系统，模块（包），甚至是特定的日志语句的准确“指标”，这样我们就不再需要grep通过整个代码库，以找出bugger的来源。
2. 我们需要注入具有特定前缀的环境变量和系统属性，以将其自动注入到日志记录上下文中，以便特定的应用程序可以将其运行时参数注入日志（例如，对于我们的Integration Platform ，为集群ID ）。

我们还需要独立于log4j2的API，因为我们应该保留与log4j2分离的自由，并在需要时利用其他日志记录框架（例如logback ）。 尽管我们可以利用第三方包装器（例如SLF4J），但找不到适合所有需求的包装器。

因此，与以前的UltraESB一样，我们用x-logging封装了log4j2，这是我们自己的日志记录实现。 x-logging由一个API和一组到实际日志框架（例如log4j2和logback）的绑定组成，其中一个可以在服务器启动时使用Java宝贵的旧ServiceLoader机制动态地插入。 这可以帮助我们避免将log4j2特定内容泄漏到我们的实现中，因为可以将基于log4j2的实现（以及因此log4j2本身）从编译时依赖项集合中完全删除。

来自我们团队的Ruwan （也是Project-X的发起者）用log4j2破解了一段时间，最后提出了一个很酷的设计，可以自动传播日志行的当前上下文，即日志行是否源自平台（系统（又名engine ）或已部署的项目 （如果是后者），则是该项目的其他元数据（例如版本）。 最酷的部分是，一旦执行离开特定上下文，该上下文将自动清理。

如果您熟悉CloseableThreadContext ，这听起来可能很简单。 对于其他人来说，只要提及CloseableThreadContext便可以将键值对注入到日志记录上下文中就足够了，这样在关闭上下文时，仅清除在当前上下文中注入的那些值。 注入的值将自动提供给调用线程的日志记录上下文（ ThreadContext ）； 或者用英语，该线程打印的每条日志行都会在其线程上下文中看到该参数（或者用老式的行话中的MDC ）。

好的，我承认以上内容可能有点难以理解。 也许一个示例代码片段可能会做得更好：

// assume we are walking in, with nothing useful inside the contexttry (CloseableThreadContext.Instance level1 = CloseableThreadContext.put("level", "1")) {// now the context has "1" as "level"logger.debug("Commencing operation"); // will see {level=1} as the context// let's also put in a "clearance" valuelevel1.put("clearance", "nypd");// now, any log lines would see {level=1,clearance=nypd}// let's go deepertry (CloseableThreadContext.Instance level2 = CloseableThreadContext.put("level", "2").put("clearance", "fbi")) {// now both of the above "level" and "clearance" values are "masked" by the new ones// and yes, you can chain together the context mutationslogger.debug("Commencing investigation"); // will see {level=2,clearance=fbi}// putting in some morelevel2.put("access", "privileged");// now context is {level=2,clearance=fbi,access=privileged}// still deeper...try (CloseableThreadContext.Instance level3 = CloseableThreadContext.put("level", "3").put("clearance", "cia")) {// "level" and "clearance" are overridden, but "access" remains unchangedlogger.debug("Commencing consipracy"); // {level=3,clearance=cia,access=privileged}}// cool thing is, once you're out of the level3 block, the context will be restored to that of level2 (thanks to the AutoCloseable nature of CloseableThreadContext.Instance)logger.debug("Back to investigation"); // {level=2,clearance=fbi,access=privileged}}// same for exiting level 2logger.debug("Back to operation"); // {level=1,clearance=nypd}; access is gone!}logger.debug("Back to square one"); // {}; oh no, all gone!

该机制非常适合我们使用，因为我们需要包括线程的当前执行上下文以及该线程生成的每个日志行：

1. 在Project-X （ UltraESB-X的基础引擎）中，维护在基本框架级别的辅助 线程池负责代表属于特定项目的集成流处理入站消息。
2. 仅在将消息注入到特定集成流的入口连接器之后，我们才认为该线程位于项目的上下文中。 在此之前，工作线程应该做很多工作，所有这些工作都被认为属于system上下文。
3. 我们会在整个过程中生成日志，因此应自动为它们添加适当的上下文标记。
4. 而且，由于每个日志行都有特定的错误代码，因此，每次实际输出日志行时，我们都需要打开一个新的上下文，该日志行除了包含其他上下文参数外，还包含所需的日志代码。

因此，池中线程的生命周期将是一个无休止的循环，例如：

// wake up from thread pool// do system level stuffloggerA.debug(143, "Now I'm doing this cool thing : {}", param);try (CloseableThreadContext.Instance projectCtx = CloseableThreadContext.put("project", project.getName()).put("version", project.getVersion())) {// do project level stuffloggerM.debug(78, "About to get busy : {}", param);// more stuff, tra la la la
}// back to system level, do still more stuff// jump back to thread pool and have some sleep

在内部， loggerA ， loggerM等将最终调用logImpl(code, message, params)方法：

// context already has system/project info,
// logger already has a pre-computed codePrefixtry (CloseableThreadContext.Instance logCtx = CloseableThreadContext.put("logcode", codePrefix + code)) {// publish the actual log line
}// only "logcode" cleared from the context, others remain intact

我们通过引入一个CloseableContext接口来模拟这种行为，而不绑定到log4j2，该接口的log4j2变体（显然是Log4j2CloseableContext ）将以相同的方式操作CloseableThreadContext实例：

import java.io.Closeable;public interface CloseableContext extends Closeable {CloseableContext append(final String key, final String value);void close();
}

和：

import org.adroitlogic.x.logging.CloseableContext;
import org.apache.logging.log4j.CloseableThreadContext;public class Log4j2CloseableContext implements CloseableContext {private final CloseableThreadContext.Instance ctx;/* Creates an instance wrapping a new default MDC instance*/Log4j2CloseableContext() {this.ctx = CloseableThreadContext.put("impl", "project-x");}/* Adds the provided key-value pair to the currently active log4j logging (thread) context** @param key   the key to be inserted into the context* @param value the value to be inserted, corresponding to {@code key}* @return the current instance, wrapping the same logging context*/@Overridepublic CloseableContext append(String key, String value) {ctx.put(key, value);return this;}/* Closes the log4j logging context wrapped by the current instance*/@Overridepublic void close() {ctx.close();}
}

现在，我们要做的就是通过一个不错的管理界面LogContextProvider打开一个适当的上下文：

// system context is active by default...try (CloseableContext projectCtx = LogContextProvider.forProject(project.getName(), project.getVersion())) {// now in project context}// back to system context

在logImpl ：

try (CloseableContext logCtx = LogContextProvider.overlayContext("logcode", codePrefix + code)) {// call the underlying logging framework
}

由于我们将CloseableContext实现与记录器绑定一起加载（通过ServiceLoader ），因此我们知道LogContextProvider最终将最终调用正确的实现。

这就是我们的x-logging框架中的上下文日志记录的故事。

也许我们将来也可以解释我们的日志代码治理方法； 在那之前，祝您伐木愉快！

翻译自: https://www.javacodegeeks.com/2017/09/logging-style-log4j-2-contextuality-auto-cleanup-no-strings-attached.html