我们使用 Log4j2 异步日志配置，防止日志过多的时候，成为性能瓶颈。这里简单说一下 Log4j2 异步日志的原理：Log4j2 异步日志基于高性能数据结构 Disruptor，Disruptor 是一个环形 buffer，做了很多性能优化（具体原理可以参考我的另一系列：高并发数据结构（disruptor）），Log4j2 对此的应用如下所示：
简单来说，多线程通过 log4j2 的门面类 org.apache.logging.log4j.Logger 进行日志输出，被封装成为一个 org.apache.logging.log4j.core.LogEvent，放入到 Disruptor 的环形 buffer 中。在消费端有一个单线程消费这些 LogEvent 写入对应的 Appender.
这里我们给出一个我们日志配置的模板，供大家参考：
<?xml version="1.0" encoding="UTF-8"?> <configuration> <Properties> <Property name="springAppName">app名称</Property> <Property name="LOG_ROOT">log</Property> <Property name="LOG_DATEFORMAT_PATTERN">yyyy-MM-dd HH:mm:ss.SSS</Property> <Property name="LOG_EXCEPTION_CONVERSION_WORD">%xwEx</Property> <!--对于日志级别，为了日志能对齐好看，我们占 5 个字符--> <Property name="LOG_LEVEL_PATTERN">%5p</Property> <Property name="logFormat"> %d{${LOG_DATEFORMAT_PATTERN}} ${LOG_LEVEL_PATTERN} [${springAppName},%X{traceId},%X{spanId}] [${sys:PID}] [%t][%C:%L]: %m%n${sys:LOG_EXCEPTION_CONVERSION_WORD} </Property> </Properties> <appenders> <RollingFile name="file" append="true" filePattern="${LOG_ROOT}/app.log-%d{yyyy.MM.dd.HH}" immediateFlush="false"> <PatternLayout pattern="${logFormat}"/> <Policies> <TimeBasedTriggeringPolicy interval="1" modulate="true"/> </Policies> <DirectWriteRolloverStrategy maxFiles="72"/> </RollingFile> </appenders> <loggers> <!--default logger --> <Asyncroot level="info" includeLocation="true"> <appender-ref ref="file" /> </Asyncroot> <AsyncLogger name="org.mybatis" level="off" additivity="false" includeLocation="false"> <appender-ref ref="file"/> </AsyncLogger> </loggers> </configuration>
对于其中一些重要的配置，我们这里单独拿出来分析下。
我们项目的依赖中包含了 spring-cloud-sleuth 这个链路追踪相关的依赖，其核心基于 Opentracing 标准实现。日志中可以通过打印 Span 的 SpanContext 中的 traceId 以及 spanId，就能通过这些信息，确定日志中的一条完整链路。spring-cloud-sleuth 是如何将这些信息放入日志中的呢？ Log4j2 中有这样一个抽象，即 org.apache.logging.log4j.ThreadContext，这个其实就是 Java 日志中 MDC（Mapped Diagnostic Context）的实现，可以理解成是一个线程本地的 Map，每个线程可以将日志需要的元素放入这个 ThreadContext 中，这样这个线程在打印日志的时候，就可以从这个 ThreadContext 中取出放入日志内容。日志需要有对应的占位符，例如下面这个就是将 ThreadContext 中 key 为 traceId 以及 spanId 的值取出输出：
%X{traceId},%X{spanId}
Spring Cloud 2020.0.x 之后，也就是 spring-cloud-sleuth 3.0.0 之后，放入 ThreadContext 的 key 发生了变化，原来的 traceId 与 spanId 分别是 X-B3-traceId 与 X-B3-spanId，现在改成了更为通用的 traceId 和 spanId。
这个主要因为你打日志的地方不在 spring-cloud-sleuth 管理的范围内，或者是 Span 提前结束了。这种时候，你可以在确定有 Span 的地方将 Span 缓存起来，之后再没有链路追踪信息的地方使用这个 Span，例如：
import brave.Tracer; @Autowire private Tracer tracer; //在确定有 span 的地方获取当前 span 将 span 缓存起来 Span span = tracer.currentSpan(); //之后在没有链路追踪信息的地方，使用 span 包裹起来 try (Tracer.SpanInScope cleared = tracer.withSpanInScope(span)) { //你的业务代码 }
设置 includeLocation=false，这样在日志中就无法看到日志属于的代码以及行数了。获取这个代码行数，其实是通过获取当前调用堆栈实现的。Java 9 之前是通过 new 一个 Exception 获取堆栈，Java 9 之后是通过 StackWalker。两者其实都有性能问题，在高并发的情况下，会吃掉很多 CPU，得不偿失。所以我推荐，在日志内容中直接体现所在代码行数，就不通过这个 includeLocation 获取当前堆栈从而获取代码行数了。
关闭 immediateFlush，可以减少硬盘 IO，会先写入内存 Buffer（默认是 8 KB），之后在 RingBuffer 目前消费完或者 Buffer 写满的时候才会刷盘。这个 Buffer 可以通过系统变量 log4j.encoder.byteBufferSize 改变。
这里的原理对应源码：
AbstractOutputStreamAppender.java
protected void directEncodeEvent(final LogEvent event) { getLayout().encode(event, manager); //如果配置了 immdiateFlush （默认为 true）或者当前事件是 EndOfBatch if (this.immediateFlush || event.isEndOfBatch()) { manager.flush(); } }
那么对于 Log4j2 Disruptor 异步日志来说，什么时候 LogEvent 是 EndOfBatch 呢？是在消费到的 index 等于生产发布到的最大 index 的时候，这也是比较符合性能设计考虑，即在没有消费完的时候，尽可能地不 flush，消费完当前所有的时候再去 flush：
private void processEvents() { T event = null; long nextSequence = sequence.get() + 1L; while (true) { try { final long availableSequence = sequenceBarrier.waitFor(nextSequence); if (batchStartAware != null) { batchStartAware.onBatchStart(availableSequence - nextSequence + 1); } while (nextSequence <= availableSequence) { event = dataProvider.get(nextSequence); //这里 nextSequence == availableSequence 就是 EndOfBatch eventHandler.onEvent(event, nextSequence, nextSequence == availableSequence); nextSequence++; } sequence.set(availableSequence); } catch (final TimeoutException e) { notifyTimeout(sequence.get()); } catch (final AlertException ex) { if (running.get() != RUNNING) { break; } } catch (final Throwable ex) { exceptionHandler.handleEventException(ex, nextSequence, event); sequence.set(nextSequence); nextSequence++; } } }
我们这一节详细分析了我们微服务框架中日志相关的各种配置，包括基础配置，链路追踪实现与配置以及如果没有链路追踪信息时候的解决办法，并且针对一些影响性能的核心配置做了详细说明。下一节我们将会开始分析针对日志的 RingBuffer 进行的监控。
