Log4j2最佳实践

[TOC]

1. 版本选择

推荐使用log4j-2.11
推荐使用slf4j作为日志门面

2. pom依赖配置和升级方案

pom配置

    <dependency>
        <groupId>org.slf4j</groupId>
        <artifactId>slf4j-api</artifactId>
        <version>1.7.24</version>
    </dependency>
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-1.2-api</artifactId>
        <version>2.11.0</version>
    </dependency>

    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-core</artifactId>
        <version>2.11.0</version>
    </dependency>
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-api</artifactId>
        <version>2.11.0</version>
    </dependency>
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-slf4j-impl</artifactId>
        <version>2.11.0</version>
    </dependency>

注意，不可同时使用log4j-slf4j-impl和log4j-to-slf4j，否则会引发循环依赖。详情见log4j官方文档。

如果使用了upcommonlog，桥接也要替换为2.x版本

    <dependency>
        <groupId>com.unionpay.common.upcommon-log</groupId>
        <artifactId>uplog-bridge-log4j2.X</artifactId>
        <version>1.2.1</version>
    </dependency>

如果使用异步日志，需要加入disruptor依赖

    <dependency>
        <groupId>com.lmax</groupId>
        <artifactId>disruptor</artifactId>
        <version>3.4.2</version>
    </dependency>

为了防止干扰，可以将其他组件引入的log4j 1的依赖exclude掉

3. log4j2配置最佳实践

示例配置1——最简配置

说明：在这种配置下，应用日志全部打印在同一个日志文件中，应用中使用的公共组件日志因为没有配置logger所以不会打印(会打印在root logger配置的console中)。建议应用根据该文件作适当修改，以适配具体的应用日志需求

配置文件如下

<?xml version="1.0" encoding="UTF-8"?>
<!-- monitorInterval配置成一个正整数，则每隔这么久的时间（秒），log4j2会刷新一次配置。如果不配置则不会动态刷新 -->
<Configuration status="INFO" monitorInterval="30">
    <Properties>
        <Property name="baseLogDir">logs</Property>
        <Property name="pattern">%d{yyyyMMdd-HHmmss.SSS} [%level] %c{1} - %msg%n</Property>
    </Properties>
    <!-- 先定义所有的appender -->
    <Appenders>
        <!-- 这个输出控制台的配置 -->
        <Console name="Console" target="SYSTEM_OUT">
            <PatternLayout>
                <Pattern>${pattern}</Pattern>
            </PatternLayout>
        </Console>
        <!-- 应用info日志 -->
        <RollingRandomAccessFile name="APPINFO_APPENDER" fileName="${baseLogDir}/appinfo.log"
            filePattern="${baseLogDir}/appinfo.log.%d{yyyyMMddHH}.%i.gz">
            <PatternLayout>
                <Pattern>${pattern}</Pattern>
            </PatternLayout>
            <Policies>
                <SizeBasedTriggeringPolicy size="500MB" />
                <TimeBasedTriggeringPolicy interval="1" modulate="true" />
            </Policies>
            <Filters>
                <ThresholdFilter level="INFO" onMatch="ACCEPT" onMismatch="DENY" />
            </Filters>
            <!-- max=20标识一小时内最多产生20个日志文件 -->
            <DefaultRolloverStrategy max="20">
                <!-- 对于指定的路径下的指定后缀的文件，只保留3天的日志文件，那么最多会有3天*24小时*20个日志文件 -->
                <!-- 注意应用需要根据业务需求和磁盘大小评估需要保留的日志个数，对于500M的日志文件来说，要根据应用日志的情况，观察单个日志压缩后文件大小，并计算总大小需要的空间 -->
                <Delete basePath="${baseLogDir}" maxDepth="1">
                    <IfFileName glob="*.gz" />
                    <IfLastModified age="3d" />
                </Delete>
            </DefaultRolloverStrategy>
        </RollingRandomAccessFile>
    </Appenders>
    <Loggers>
        <!-- root是默认的logger，也是所有logger的父级logger，如果需要，可以在这里配置一个文件appender以打印外部组件日志 -->
        <AsyncRoot level="WARN">
            <AppenderRef ref="Console" />
        </AsyncRoot>
        <!-- 应用日志，采用异步模式，name根据实际的包名修改；生产环境中additivity建议设置为false以避免在root logger中重复打印 -->
        <AsyncLogger name="com.unionpay" level="INFO" includeLocation="false" additivity="false">
            <AppenderRef ref="APPINFO_APPENDER" />
        </AsyncLogger>
    </Loggers>
</Configuration>

示例配置2——日志分类

说明：在这种配置下，应用的info日志打印在appinfo.log中，应用的warn及以上日志打印在apperror.log中，其他公共组件的日志打印在server.log中。建议应用根据该配置作适当修改，以适配具体的应用日志需求

配置文件如下

<?xml version="1.0" encoding="UTF-8"?>
<!-- monitorInterval配置成一个正整数，则每隔这么久的时间（秒），log4j2会刷新一次配置。如果不配置则不会动态刷新 -->
<Configuration status="INFO" monitorInterval="30">
    <Properties>
        <!-- 应用需要修改为合适的log路径 -->
        <Property name="baseLogDir">logs</Property>
        <Property name="pattern">%d{yyyyMMdd-HHmmss.SSS} [%level] %c{1} - %msg%n</Property>
    </Properties>
    <!-- 先定义所有的appender -->
    <Appenders>
        <!-- 这个输出控制台的配置 -->
        <Console name="Console" target="SYSTEM_OUT">
            <PatternLayout>
                <Pattern>${pattern}</Pattern>
            </PatternLayout>
        </Console>
        <!-- 系统日志，可以作为root logger的appender，供打印一些中间件的日志 -->
        <RollingRandomAccessFile name="SYS_APPENDER" fileName="${baseLogDir}/server.log"
            filePattern="${baseLogDir}/server.log.%d{yyyyMMddHH}.%i.gz">
            <PatternLayout>
                <Pattern>${pattern}</Pattern>
            </PatternLayout>
            <Policies>
                <SizeBasedTriggeringPolicy size="200MB" />
                <TimeBasedTriggeringPolicy interval="1" modulate="true" />
            </Policies>
            <Filters>
                <ThresholdFilter level="INFO" onMatch="ACCEPT" onMismatch="DENY" />
            </Filters>
            <!-- max=6标识一小时内最多产生6个日志文件 -->
            <DefaultRolloverStrategy max="6">
                <!-- 对于指定的路径下的指定后缀的文件，只保留1天的日志文件，那么最多会有24小时*6个日志文件 -->
                <Delete basePath="${baseLogDir}" maxDepth="1">
                    <IfFileName glob="*.gz" />
                    <IfLastModified age="1d" />
                </Delete>
            </DefaultRolloverStrategy>
        </RollingRandomAccessFile>
        <!-- 应用info日志 -->
        <RollingRandomAccessFile name="APPINFO_APPENDER" fileName="${baseLogDir}/appinfo.log"
            filePattern="${baseLogDir}/appinfo.log.%d{yyyyMMddHH}.%i.gz">
            <PatternLayout>
                <Pattern>${pattern}</Pattern>
            </PatternLayout>
            <Policies>
                <SizeBasedTriggeringPolicy size="500MB" />
                <TimeBasedTriggeringPolicy interval="1" modulate="true" />
            </Policies>
            <Filters>
                <!-- 当前appender只打印info日志，warn及以上日志忽略，由后面的appender决定是否需要打印 -->
                <ThresholdFilter level="WARN" onMatch="DENY" onMismatch="NEUTRAL" />
                <ThresholdFilter level="INFO" onMatch="ACCEPT" onMismatch="DENY" />
            </Filters>
            <!-- max=20标识一小时内最多产生20个日志文件 -->
            <DefaultRolloverStrategy max="20">
                <!-- 对于指定的路径下的指定后缀的文件，只保留3天的日志文件，那么最多会有3天*24小时*20个日志文件 -->
                <!-- 注意应用需要根据业务需求和磁盘大小评估需要保留的日志个数，对于500M的日志文件来说，要根据应用日志的情况，观察单个日志压缩后文件大小，并计算总大小需要的空间 -->
                <Delete basePath="${baseLogDir}" maxDepth="1">
                    <IfFileName glob="*.gz" />
                    <IfLastModified age="3d" />
                </Delete>
            </DefaultRolloverStrategy>
        </RollingRandomAccessFile>
        <!-- 应用错误日志 -->
        <RollingRandomAccessFile name="APPERROR_APPENDER" fileName="${baseLogDir}/apperror.log"
            filePattern="${baseLogDir}/apperror.log.%d{yyyyMMddHH}.%i.gz">
            <PatternLayout>
                <Pattern>${pattern}</Pattern>
            </PatternLayout>
            <Policies>
                <SizeBasedTriggeringPolicy size="500MB" />
                <TimeBasedTriggeringPolicy interval="1" modulate="true" />
            </Policies>
            <Filters>
                <ThresholdFilter level="WARN" onMatch="ACCEPT" onMismatch="DENY" />
            </Filters>
            <!-- max=10标识一小时内最多产生10个日志文件 -->
            <DefaultRolloverStrategy max="10">
                <!-- 对于指定的路径下的指定后缀的文件，只保留3天的日志文件，那么最多会有3*24小时*10个日志文件 -->
                <Delete basePath="${baseLogDir}" maxDepth="1">
                    <IfFileName glob="*.gz" />
                    <IfLastModified age="3d" />
                </Delete>
            </DefaultRolloverStrategy>
        </RollingRandomAccessFile>
    </Appenders>

    <Loggers>
        <!-- root是默认的logger，也就是公共的logger，供记录一些不常打印的系统参数或者其他组件参数 -->
        <AsyncRoot level="WARN">
            <AppenderRef ref="Console" />
            <AppenderRef ref="SYS_APPENDER" />
        </AsyncRoot>
        <!-- 常打印的应用日志，建议独立配置，并采用异步模式。name根据实际的包名修改，生产环境中additivity建议设置为false以避免在root logger中重复打印 -->
        <AsyncLogger name="com.unionpay" level="INFO" includeLocation="false" additivity="false">
            <AppenderRef ref="APPINFO_APPENDER" />
            <AppenderRef ref="APPERROR_APPENDER" />
        </AsyncLogger>
    </Loggers>
</Configuration>

4. log4j调优和注意事项

4.1 日志模式-同步/异步

log4j2提供了AsyncAppender和AsyncLogger以及全局异步，开启方式如下

同步模式：默认配置即为同步模式，即没有使用任何AsyncAppender和AsyncLogger
全局异步：配置按照同步方式配，通过添加jvm启动参数即可开启全局异步，无需修改配置和应用
混合异步：使用异步Logger和同步Logger的混合配置，且不开启全局异步，即Logger配置中部分AsyncLogger，部分Logger

日志模式使用注意事项

如果使用异步，建议使用AsyncLogger实现而不是AsyncAppender
如果使用同步，AsyncLogger、AsyncAppender和全局异步只能使用一种，不可以同时配置AsyncAppender和AsyncLogger，或者配置了异步的情况下启用了全局异步

4.2 日志滚动和清除策略

log4j2提供了基于文件大小的滚动策略和基于时间的滚动策略，也可以二者并用，这里给出基于大小的滚动策略配置和基于大小/时间双滚动策略配置。

基于大小的滚动策略

按照大小滚动，启用压缩，并最多保留N个文件

  <!--此处举例为每500M滚动一个文件，且最多保留20个文件，具体需要根据应用的日志量和希望保留日志大小以及磁盘空间进行评估-->
  <RollingRandomAccessFile name="APPINFO_APPENDER" fileName="${baseLogDir}/appinfo.log"
      filePattern="${baseLogDir}/appinfo.log.%i.gz">
      <PatternLayout>
          <Pattern>${pattern}</Pattern>
      </PatternLayout>
      <Policies>
          <SizeBasedTriggeringPolicy size="500MB" />
      </Policies>
      <Filters>
          <!-- 当前appender只打印info日志，warn及以上日志忽略，由后面的错误日志记录 -->
          <ThresholdFilter level="WARN" onMatch="DENY" onMismatch="NEUTRAL" />
          <ThresholdFilter level="INFO" onMatch="ACCEPT" onMismatch="DENY" />
      </Filters>
      <!-- max=20表示最多保留20个日志文件 -->
      <DefaultRolloverStrategy max="20"/>
  </RollingRandomAccessFile>

此种策略的空间占用计算公式为(这里计算的是最大空间需求)

日志空间需求=日志滚动阈值（例如500M）+日志留存个数*日志滚动阈值*1/压缩比(对于gz压缩比一般会是几十，具体根据应用日志压缩后计算)

例如假设压缩比为50，则500M的文件压缩后只有10M，那么上述配置总空间大小是

日志空间需求=500M+20*500*1/50=700M

基于大小/时间双滚动滚动策略

按照大小和时间滚动，启用压缩，单位时间内控制最多保留日志个数并控制总的日志留存时间

  <!--此处举例为每小时滚动一个文件且每500M滚动一个文件，控制每小时最多保留20个文件，总的文件保留3天-->
  <!--具体需要根据应用的日志量和希望保留日志大小以及磁盘空间进行评估-->
  <RollingRandomAccessFile name="APPINFO_APPENDER" fileName="${baseLogDir}/appinfo.log"
      filePattern="${baseLogDir}/appinfo.log.%d{yyyyMMddHH}.%i.gz">
      <PatternLayout>
          <Pattern>${pattern}</Pattern>
      </PatternLayout>
      <Policies>
          <SizeBasedTriggeringPolicy size="500MB" />
          <TimeBasedTriggeringPolicy interval="1" modulate="true" />
      </Policies>
      <Filters>
          <!-- 当前appender只打印info日志，warn及以上日志忽略，由后面的错误日志记录 -->
          <ThresholdFilter level="WARN" onMatch="DENY" onMismatch="NEUTRAL" />
          <ThresholdFilter level="INFO" onMatch="ACCEPT" onMismatch="DENY" />
      </Filters>
      <!-- max=20表示一小时内最多保留20个日志文件 -->
      <DefaultRolloverStrategy max="20">
          <!-- 对于指定的路径下的指定后缀的文件，只保留3天的日志文件，那么最多会有3天*24小时*20个日志文件 -->
          <!-- 注意应用需要根据业务需求和磁盘大小评估需要保留的日志个数，对于500M的日志文件来说，要根据应用日志的情况，观察单个日志压缩后文件大小，并计算总大小需要的空间 -->
          <Delete basePath="${baseLogDir}" maxDepth="1">
              <IfFileName glob="*.gz" />
              <IfLastModified age="3d" />
          </Delete>
      </DefaultRolloverStrategy>
  </RollingRandomAccessFile>

此种策略的空间占用计算公式为(这里计算的是最大空间需求)

日志留存个数=保留时间*单位时间内最大日志个数
日志空间需求=日志滚动阈值（例如500M）+日志留存个数*日志滚动阈值*1/压缩比(对于gz压缩比一般会是几十，具体根据应用日志压缩后计算)

例如假设压缩比为50，则500M的文件压缩后只有10M，那么上述配置总空间大小是

日志留存个数=3*24*20=1440
日志空间需求=500M+1440*500*1/50=15G

注意，控制总的日志留存时间的机制，需要log4j-2.5及以上的版本支持，建议使用2.11版本

4.3 其他注意事项和调优

推荐在Configuration中添加monitorInterval以支持动态刷新
推荐使用异步日志而不是同步日志，可以是混合异步也可以是全局异步
不推荐配置AsyncAppender，如果需要混合异步，使用AsyncLogger
PatternLayout不要使用%L、%C、%method等含有“位置信息”的配置项，非常影响性能。同时logger配置中需要加上inclueLocation="false"，这样即使配置了位置信息也会被忽略
推荐使用RollingRandomAccessFile做为appender
推荐基于大小和时间的双重文件滚动策略，并配合压缩

4.4 log4j-disruptor等待策略

log4j2的日志使用了disruptor，其内部使用了基于ringbuffer的环形队列，并且也有生产者消费者的概念。在消费者等待消息事件（也就是日志消息）时，其内部有一处等待策略的配置，配置项可以是Block/Timeout/Sleep/Yield，默认Timeout，不同策略的含义如下

Block，在I/O线程等待时使用锁和条件触发机制，当cpu的优先级高于吞吐量和延迟的时候推建议使用。官方推荐在资源受限/虚拟化环境中使用
Timeout，是Block策略的变种，它将定期从等待中被唤醒，确保了如果错过了通知，disruptor消费者不会被永久阻塞，但会有较小的延迟（10ms）
Sleep，等待IO事件先自旋，然后调用Thread.yield()，最后park，在性能和cpu之间取得一个折中
Yield，等待IO事件先自旋，然后调用用Thread.yield()等待日志事件，相较于Sleep可能会消耗更多的cpu

log4j2默认策略是Timeout，在实际测试中，我们尝试测试出不同策略下的cpu占用和延迟时间情况，但测试结果并没有明显的数据对比，因此这里仅供参考，应用如果修改，需要结合场景做全面的测试。例如如果发现cpu占用较高，可以尝试修改为Block或者其他策略并测试观察。

修改disruptor wait策略的方法为（以修改为Block为例）

-Dlog4j2.asyncLoggerWaitStrategy=Block

5. slf4j代码优化建议

此处针对的是使用了slf4j的代码，不适用于其它情况

我们知道，slf4j打印日志可以使用占位符的方式，例如一般打印日志的代码：

logger.debug("this is log4j2, current time:" + System.currentTimeMillis());

在使用了slf4j的情况下，该句的功能等价于

logger.debug("this is log4j2, current time:{}", System.currentTimeMillis());

上面两行的代码功能相同，但是前一句在每次执行时，无论我们的日志级别是不是debug即以上，每次都会生成一个新的字符串，字符串的字面值是前缀加上系统当前时间。即使我们的日志级别配置成warn，该句也会产生一个新的字符串
后一句，当我们日志级别是debug或者小于debug的时候，才会真的创建一个完整的字符串，否则内存中只会有包含了占位符的唯一一个字符串

如果这种情况非常多，那么直接拼接字符串的方式对于内存的浪费就非常明显了，这时候使用占位符的方式，可以明显的改善字符串的生成数量。当然也不是说任何地方都要使用占位符，因为占位符拼接成字符串，也是有开销的，起码要遍历占位符后面的参数。因此一般建议：

对于一定要打印的日志，使用字符串拼接的方式（必要时引入StringBuilder辅助而不是一直加）
对于调整级别才需要打印的日志，使用占位符的方式而不是直接拼接

人面猴
序言：七十年代末，一起剥皮案震惊了整个滨河市，随后出现的几起案子，更是在滨河造成了极大的恐慌，老刑警刘岩，带你破解...
沈念sama阅读 206,214评论 6赞 481
死咒
序言：滨河连续发生了三起死亡事件，死亡现场离奇诡异，居然都是意外死亡，警方通过查阅死者的电脑和手机，发现死者居然都...
沈念sama阅读 88,307评论 2赞 382
救了他两次的神仙让他今天三更去死
文/潘晓璐我一进店门，熙熙楼的掌柜王于贵愁眉苦脸地迎上来，“玉大人，你说我怎么就摊上这事。” “怎么了？”我有些...
开封第一讲书人阅读 152,543评论 0赞 341
道士缉凶录：失踪的卖姜人
文/不坏的土叔我叫张陵，是天一观的道长。经常有香客问我，道长，这世上最难降的妖魔是什么？我笑而不...
开封第一讲书人阅读 55,221评论 1赞 279
港岛之恋（遗憾婚礼）
正文为了忘掉前任，我火速办了婚礼，结果婚礼上，老公的妹妹穿的比我还像新娘。我一直安慰自己，他们只是感情好，可当我...
茶点故事阅读 64,224评论 5赞 371
恶毒庶女顶嫁案：这布局不是一般人想出来的
文/花漫我一把揭开白布。她就那样静静地躺着，像睡着了一般。火红的嫁衣衬着肌肤如雪。梳的纹丝不乱的头发上，一...
开封第一讲书人阅读 49,007评论 1赞 284
城市分裂传说
那天，我揣着相机与录音，去河边找鬼。笑死，一个胖子当着我的面吹牛，可吹牛的内容都是我干的。我是一名探鬼主播，决...
沈念sama阅读 38,313评论 3赞 399
双鸳鸯连环套：你想象不到人心有多黑
文/苍兰香墨我猛地睁开眼，长吁一口气：“原来是场噩梦啊……” “哼！你这毒妇竟也来了？” 一声冷哼从身侧响起，我...
开封第一讲书人阅读 36,956评论 0赞 259
万荣杀人案实录
序言：老挝万荣一对情侣失踪，失踪者是张志新（化名）和其女友刘颖，没想到半个月后，有当地人在树林里发现了一具尸体，经...
沈念sama阅读 43,441评论 1赞 300
护林员之死
正文独居荒郊野岭守林人离奇死亡，尸身上长有42处带血的脓包…… 初始之章·张勋以下内容为张勋视角年9月15日...
茶点故事阅读 35,925评论 2赞 323
白月光启示录
正文我和宋清朗相恋三年，在试婚纱的时候发现自己被绿了。大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
茶点故事阅读 38,018评论 1赞 333
活死人
序言：一个原本活蹦乱跳的男人离奇死亡，死状恐怖，灵堂内的尸体忽然破棺而出，到底是诈尸还是另有隐情，我是刑警宁泽，带...
沈念sama阅读 33,685评论 4赞 322
日本核电站爆炸内幕
正文年R本政府宣布，位于F岛的核电站，受9级特大地震影响，放射性物质发生泄漏。R本人自食恶果不足惜，却给世界环境...
茶点故事阅读 39,234评论 3赞 307
男人毒药：我在死后第九天来索命
文/蒙蒙一、第九天我趴在偏房一处隐蔽的房顶上张望。院中可真热闹，春花似锦、人声如沸。这庄子的主人今日做“春日...
开封第一讲书人阅读 30,240评论 0赞 19
一桩弑父案，背后竟有这般阴谋
文/苍兰香墨我抬头看了看天上的太阳。三九已至，却和暖如春，着一层夹袄步出监牢的瞬间，已是汗流浃背。一阵脚步声响...
开封第一讲书人阅读 31,464评论 1赞 261
情欲美人皮
我被黑心中介骗来泰国打工，没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留，地道东北人。一个月前我还...
沈念sama阅读 45,467评论 2赞 352
代替公主和亲
正文我出身青楼，却偏偏与公主长得像，于是被迫代替她去往敌国和亲。传闻我的和亲对象是个残疾皇子，可洞房花烛夜当晚...
茶点故事阅读 42,762评论 2赞 345