Log4j 日志输出性能优化

10余年资深架构经验，对高性能网关、多线程、NIO、HTTP/TCP 长连接等技术有较深的研究与实战经验，主导过百亿级网关系统和亿级交易系统的设计与实现，目前主要专注于微服务架构、分布式技术。

Log4j 已成为大型系统必不可少的一部分，Log4j 可以很方便的帮助我们在程序的任何位置输出所要打印的信息，便于我们对系统在调试阶段和正式运行阶段对问题分析和定位。由于日志级别的不同，对系统的性能影响也是有很大的差距，日志级别越高，性能越高。

Log4j 主要分为error、warn、info、debug 四个级别，也是使用最多的四种，日志级别从左至右依次增加。

Log4j 对系统性能的影响程度主要体现在以下几方面：

日志输出的目的地，输出到控制台的速度比输出到文件系统的速度要慢。
日志输出格式不一样对性能也会有影响，如简单输出布局 SimpleLayout 比格式化输出布局 PatternLayout 输出速度要快。可以根据需要尽量采用简单输出布局格式输出日志信息。
日志级别越低输出的日志内容就越多，对系统系能影响很大。
日志输出方式的不同，对系统系能也是有一定影响的，采用异步输出方式比同步输出方式性能要高。
每次接收到日志输出事件就打印一条日志内容比当日志内容达到一定大小时打印系能要低。

一、Log4j BufferedIO 与 flush BufferedIO

使用 Log4j 默认写日志的时候，默认会立即刷到文件中，如果日志写入量很大的话，会带来一定的性能损耗。所以 Log4j 提供了 BufferedIO 配置选项，如果配置 BufferedIO 为 true，则使用 BufferedWriter 进行包装，写入数据量到达 bufferSize 之后，才会真正写到文件中。

官方解释了使用 Buffer 会带来 10% ~ 20% 的性能提升，但是代价也是很明显是，假如系统退出，由于最后写入的日志 Buffer 还没满，无法写入文件会导致关键日志丢失。

文本主要解决使用 Buffer 之后，所带来的以下两个问题：

当程序关闭的时候，由于一部分日志还在内存中导致的日志丢失问题
由于日志无法实时输出，给问题排查带来了困难，程序报错无法立马看到报错的信息

二、Log4j AsyncAppender

同步情况：各线程直接获得输出流进行输出（线程间不需要同步）。

异步情况：

各线程将日志写到缓存，继续执行下面的任务（这里是异步的）
日志线程发现需要记日志时独占缓存（与此同时各线程等待，此时各线程是被阻塞住的），从缓存中取出日志信息，获得输出流进行输出，将缓存解锁（各线程收到提醒，可以接着写日志了）

<appender name="DRFOUT" class="org.apache.log4j.DailyRollingFileAppender">    
  <param name="File" value="logs/brws.log" />    
  <param name="Append" value="true" />    
  <param name="DatePattern" value="yyyy_MM_dd'.'" />    
  <layout class="org.apache.log4j.PatternLayout">    
    <param name="ConversionPattern" value="%d [%t] %-5p %l %x - %m%n" />    
  </layout>    
</appender>    

<appender name="ASYNCOUT" class="org.apache.log4j.AsyncAppender">    
  <param name="BufferSize" value="512" />    
  <appender-ref ref="DRFOUT" />    
</appender>

异步输出日志工作原理

AsyncAppender 采用的是生产者消费者的模型进行异步地将 Logging Event 送到对应的 Appender 中。

生产者：外部应用了 Log4j 的系统的实时线程，实时将 Logging Event 传送进 AsyncAppender 里
中转：Buffer 和 DiscardSummary
消费者：Dispatcher 线程和 appenders

1）Logging Event 进入 AsyncAppender，AsyncAppender 会调用 append 方法，在 append 方法中会去把 logging Event 填入 Buffer 中，当消费能力不如生产能力时，AsyncAppender 会把超出 Buffer 容量的 Logging Event 放到 DiscardSummary 中，作为消费速度一旦跟不上生成速度，中转 buffer 的溢出处理的一种方案。

2）AsyncAppender 有个线程类 Dispatcher，它是一个简单的线程类，实现了 Runnable 接口。它是 AsyncAppender 的后台线程。

Dispatcher 所要做的工作是：

① 锁定 Buffer，让其他要对 Buffer 进行操作的线程阻塞。
② 看 Buffer 的容量是否满了，如果满了就将 Buffer 中的 Logging Event 全部取出，并清空 Buffer 和 DiscardSummary；如果没满则等待 Buffer 填满 Logging Event，然后 notify Disaptcher 线程。
③ 将取出的所有 Logging Event 交给对应 appender 进行后面的日志信息推送。

以上是 AsyncAppender 类的两个关键点：append 方法和 Dispatcher 类，通过这两个关键点实现了异步推送日志信息的功能，这样如果大量的 Logging Event 进入 AsyncAppender，就可以游刃有余地处理这些日志信息了。

三、Log4j 日志输出性能优化

众所周知，磁盘 IO 操作、网络 IO 操作、JDBC 操作等都是非常耗时的，日志输出的主要性能瓶颈也就是在写文件、写网络、写 JDBC 的时候。日志是肯定要记的，而要采用异步方式记，也就只有将这些耗时操作从主线程当中分离出去才真正的实现性能提升，也只有在线程间同步开销小于耗时操作时使用异步方式才真正有效！

1）```log4j.additivity.monitorLogger=false``

这个选项用于控制监控 logger 的日志不会输出到 rootlogger，否则会产生许多重复的数据，同时也会影响性能；

2）log4j.appender.monitorAppender.DatePattern='.'yyyy-MM-dd-HH

这个选项用于告诉 DailyRollingFileAppender 每小时输出日志，而不是默认的一天输出一次，因为监控日志的数据量很巨大，如果以天为单位输出，日志文件会很大（G级），而且再处理会很耗时。

3）log4j.appender.monitorAppender.BufferedIO=true 和· log4j.appender.monitorAppender.BufferSize=8192

这个选项用于告诉 Log4j 输出日志的时候采用缓冲的方式，而不是即时 flush 方式，并且设定了缓冲为 8K，8K 是默认值，可以根据日志输出的情况来修改。这个选项很重要，在测试中发现，当并发访问很高，例如每一秒100个并发以上，使用缓存跟不使用缓冲差距很大。

另外我想说的是，Log4j 输出缓冲日志是以 8K 为单位的，因为磁盘的一个 block 为 8K，这样可以减少碎片，也就是说假设你设置缓存为 18K，Log4j 在 16K（8K*2）的时候就会输出），而不是 18K。

4）组装输出内容之前可对 logger 的输出级别先进行判断而不要完全依赖 log4j 控制，因为组装输出日志内容也是要损耗效率的。

if (!logger.isInfoEnabled()) {
  return;
}

5）使用异步输出 org.apache.log4j.AsyncAppender

Example

<appender name="monitor" class="org.apache.log4j.DailyRollingFileAppender">
  <param name="file" value="${log.path}/monitor.log" />
  <param name="append" value="true" />
  <param name="encoding" value="UTF-8" />
  <param name="threshold" value="${log.level}" />
  <layout class="org.apache.log4j.PatternLayout">
    <param name="ConversionPattern" value="%m%n" />
  </layout>
  <param name="BufferedIO" value="true" />
  <param name="BufferSize" value="8192" />
</appender>

<appender name="monitor_async" class="org.apache.log4j.AsyncAppender">
  <appender-ref ref="monitor"/>
</appender>

<logger name="com.linkedkeeper.monitor.logger.Log" additivity="false">
  <level value="${log.level}" />
  <appender-ref ref="monitor_async" />
</logger>

四、Log4j 1.x 引发线程 BLOCKED

Apache Log4j 版本 1.x 中，使用的是 synchronized(this) 进行同步操作，所有线程共用一个 Category，而它通过 log4j.properties 指定。同一个 Category 下的线程打 log 时，需要进行全局同步，因此它的效率会很低，log4j 1.x 版不适合高并发的场景。