[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辅助而不是一直加)
- 对于调整级别才需要打印的日志,使用占位符的方式而不是直接拼接
网友评论