(点击上方公众号,可快速关注)
来源:高广超,
www.jianshu.com/p/5dcf4ece0de3
如有好文章投稿,请点击 → 这里了解详情
这是在公司内部的一次升级实践,删除了很多隐私的内容,所以可能不是很完整。
1、背景
在任何系统中,日志都是非常重要的组成部分,它是反映系统运行情况的重要依据,也是排查问题时的必要线索。绝大多数人都认可日志的重要性,但是又有多少人仔细想过该怎么打日志,日志对性能的影响究竟有多大呢?
新的Log4j 2.0版本有了大幅的性能提升、新的插件系统,以及配置设置方面的很多改善。Log4j 1.x 在高并发情况下出现死锁导致cpu使用率异常飙升,而Log4j2.0基于LMAX Disruptor的异步日志在多线程环境下性能会远远优于Log4j 1.x和logback ——官方测试结果。
官方测试结果
http://logging.apache.org/log4j/2.x/performance.html
本次升级是以thrift服务化项目为例子进行的,后续会在其他项目中进行,本次工作内容为:Log4j1.x 升级到 Log4j2(如果不想了解原理,可以直接跳到:3、升级方式)。
2、log4j2说明
2.1 特性
API分离: Log4j2将API与实现分离开来(log4j-api: 作为日志接口层,用于统一底层日志系统,log4j-core : 作为上述日志接口的实现,是一个实际的日志框架)。
改进的特定: Log4j2的性能在某些关键领域比Log4j 1.x更快,而且大多数情况下与Logback相当。
多个API支持:Log4j2提供最棒的性能的同时,还支持SLF4J和公共日志记录API。
自动配置加载:像Logback一样,一旦配置发生改变,Log4j2可以自动载入这些更改后的配置信息,又与Logback不同,配置发生改变时不会丢失任何日志事件。
高级过滤功能:与Logback类似,Log4j2可以支持基于上下文数据、标记,正则表达式以及日志事件中的其他组件的过滤。
插件架构:所有可以配置的组件都以Log4j插件的形式来定义。无需修改任何Log4j代码就可以创建新的Appender、Layout、Pattern Convert 等等。Log4j自动识别预定义的插件,如果在配置中引用到这些插件,Log4j就自动载入使用。
属性支持:属性可以在配置文件中引用,也可以直接替代或传入潜在的组件,属性在这些组件中能够动态解析。属性可以是配置文件,系统属性,环境变量,线程上下文映射以及事件中的数据中定义的值。用户可以通过增加自己的Lookup插件来定制自己的属性。
log4j2配置: 不支持properties文件,但却可以以json文件作为配置。
2.2 性能
吞吐量测试
平均耗时
其中:
Loggers mixed sync/async: 同步与异步logger可以混合使用,分别由标签 指定
异步Logger与异步Appender区别:AsyncAppender使用ArrayBlockingQueue来处理message,AsyncLogger使用LMAX Disruptor
AsyncAppender的做法是:应用线程创建LogEvent将其塞入Queue,消费线程取出LogEvent写磁盘。在这种框架的可扩展性不好,当加倍消费线程时各个线程的吞吐量会减半,所以总吞吐量并不会得到增加。原因是,并发queue是标准java库的一部分,会使用锁来保证数据传递的正确性。
LMAX Disruptor是一个无锁数据结构,可以在线程间传递消息。详细介绍可访问其网站:https://github.com/LMAX-Exchange/disruptor/wiki/Introduction
更多性能测试信息可参考官方报告:
http://logging.apache.org/log4j/2.x/manual/async.html#Performance
http://logging.apache.org/log4j/2.x/performance.html
2.3 主要组件
2.4 配置
Configuration
示例:
%d %-5p (%F:%L) - %m%n
/var/***/logs
fileName="${LOG_HOME}/${sys:app.key}.log"
filePattern="${LOG_HOME}/${sys:app.key}.log.%d{yyyy-MM-dd}">
fileName="${LOG_HOME}/${sys:app.key}_access_kpi.log"
filePattern="${LOG_HOME}/${sys:app.key}_access_kpi.log.%d{yyyy-MM-dd}">
fileName="${LOG_HOME}/${sys:app.key}.jmonitor.log"
filePattern="${LOG_HOME}/${sys:app.key}.jmonitor.%d{yyyy-MM-dd}.log.gz">
fileName="${LOG_HOME}/${sys:app.key}.jmonitor.logstore.log"
filePattern="${LOG_HOME}/${sys:app.key}.jmonitor.logstore.%d{yyyy-MM-dd}.log.gz">
${sys:app.key}
127.0.0.1
4252
cos_errorlog
false
false
6000
100
pattern="%d %p $${sys:app.host} $${sys:app.ip} errorlog appkey=$${sys:app.key} location=%F:%L rawlog=%replace{%replace{%m}{=}{:}}{\n|\t}{} rawexception=%replace{%replace{%ex}{=}{:}}{\n|\t}{}%n"/>
我们先看看Configuration的一些特性:
Configuration代表Log4j2的配置文件,它和LoggerContext组件一一对应(关于LoggerContext请看下文),它维护Log4j2各个组件之间的关系,其中,一个Configuration对应多个LoggerConfig组件。
Configuration可以通过四种方式配置:a)配置文件(XML、JSON和YAML);b)创建ConfigurationFactory和Configuration实现;c)通过代码调用Configuration的API构造;d)在Logger内部调用API函数构造。
Configuration能够在应用程序初始化的过程中进行自动装配,其配置内容按照一定的顺序获取,详见:AutomaticConfiguration。
当我们给Configuration设置monitorInterval时,这可以使得log4j2阶段性的读取配置文件,并重新构造Configuration。在这一过程中,log4j2不会丢失日志事件。
Configuration标签
...
该片段表明log4j2配置文件的所有内容都在这个标签内,其status属性为“WARN”说明:log4j2内部的日志会将日志级别大于WARN的日志打印到Console。除了该字段,Configuration还包括其他属性,详见:ConfigurationSyntax。
Appenders标签
所有的Appender将在和之间定义。上述例子定义了ConsoleAppender并关联PatternLayout,关于Appender和Layout请看上述相关小节。
Logger标签
所有的Logger将在和之间定义。上述例子通过定义了所有Logger的根结点(RootLogger),并通过标签关联名称为“Console”的Appender,关于Logger请看上述相关小节。
此处有必要说明additivity字段,通过配置该字段,我们可以规定是否将日志事件传递到Logger的父结点处理,其默认值为true(即默认交给parent Logger处理)。
Logger默认不会获取location信息,因此,若我们的Layout或Filter等需要location信息,我们必须给相应的设置“includeLocation=true”
Filters标签
log4j2还有一个很重要的组件——Filter,详见Filter小节。此处通过和表明这是一个组合Filter,里边包括MarkerFilter和DynamicThresholdFilter。onMatch表示和onMismatch表示经过Filter过滤后的结果,该结果有三个取值:ACCEPT、NEUTRAL和DENY。log4j2在处理LogEvents时,会通过该Filter进行过滤,若返回结果为ACCEPT,则直接处理(略过其它Filter和日志级别的过滤);若返回DENY则直接终止该LogEvents;若返回NEUTRAL,则不做决策,让后续代码做处理。
此处,Filter是通过Configuration的直接子元素配置,因此,LogEvents若被该Filter过滤之后则不会传递给Logger处理。
2.5 异步日志
Log4j2提供了异步Logger,通过不同线程实现I/O操作,目的在于为我们的应用程序提高性能。我们先来看一看它主要在哪些方面做改进:
Asynchronous Loggers。异步日志器是Log4j2新增的日志器,它的目的是让我们的应用程序在调用Logger.log()打印日志时立马返回。我们可以在程序中全部使用异步日志器,也可以使用混合的日志器,前者能给我们的程序带来很大的性能提升,而后者让我们的程序足够灵活。
LMAX Disruptor技术。异步日志器在其内部实现采用了Disruptor技术,相对于使用BlockingQueue,它提高了吞吐量和降低延时。
Asynchronous Appender。该组件在Log4j1.x已经存在,但是Log4j2实现的异步Appender使得每次写入磁盘时,都会进行flush操作,效果和配置“immediateFlush=true”一样。该异步Appender内部采用ArrayBlockingQueue的方式,因此不需要引入disruptor依赖。
RandomAccessFileAppender。该Appender采用ByteBuffer+RandomAccessFile替代了BufferedOutputStream,官方给出的测试数据是它将速度提升了20-200%。
AsyncLoggers虽然带来了极大的性能提升,我们应该经常使用。不过,它也有一些缺点,因此,我们要根据具体的应用场景决定使用同步还是异步的方式,详见:Trade-offs。
3、升级方式
以下开始说明*服务化项目如何由:Log4j1.x 升级到 Log4j2。
3.1 排除对log4j的依赖
需要确定项目pom文件中依赖的其他的jar中也不再依赖log4j及slf4j-log4j12,具体方式可以通过IDE提供的功能或者直接使用mvn dependency:tree确定依赖关系。
由于引用的jar中很多依然使用的为log4j,因此已经升级过log4j2的项目,每次在新增依赖的时候,一定需要确定一下,引用的jar是否含有对低版本的依赖,并且exclusion掉。
org.slf4j
slf4j-log4j12
log4j
log4j
3.2 添加对log4j2的依赖
1.7.12
2.3
org.slf4j
jcl-over-slf4j
${org.slf4j-version}
runtime
org.apache.logging.log4j
log4j-1.2-api
${log4j2-version}
org.apache.logging.log4j
log4j-slf4j-impl
${log4j2-version}
org.apache.logging.log4j
log4j-api
${log4j2-version}
org.apache.logging.log4j
log4j-core
${log4j2-version}
com.lmax
disruptor
3.2.0
com.sankuai.meituan
scribe-log4j2
1.0.9
3.3 JVM参数
在JVM启动参数中增加 -DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector 开启异步日志。(目前针对scribe的appender为同步appender,如果不开启异步机制会导致线程block)
3.4 XML配置
删除原log4j.xml配置文件,新增log4j2.xml,注意:需要保证log4j2.xml在resource根目录内,否则会导致配置文件加载不到(即log4j2.xml需要在class根目录内)
注意事项
1. includeLocation:Logger默认不会获取location信息,因此,若我们的Layout或Filter等需要location信息,我们必须给相应的设置“includeLocation=true”
2. additivity:通过配置该字段,我们可以规定是否将日志事件传递到Logger的父结点处理,其默认值为true
3. file文件的路径,由于启动脚本及服务器变量配置等的不确定性,因此该处建议直接配置绝对路径,可以使用/var/*/logs配置在xml中,也可以通过JVM参数 -Dapp.logdir=$LOG_HOME等方式
4. AsyncLogger为异步日志,需要添加JVM参数-DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector
5. 服务化项目启动脚本里如果对启动日志做重定向了“>> $LOGDIR/$LOGFILE 2>&1”,请不要使用Console输出日志,否则会导致重定向的日志文件将重复打印所有日志信息
6. 服务化项目不需要配置access_kpi的日志打印
Scribe说明(线上异常监控接入说明#线上异常监控接入说明-log4j2.0)
hostname:这里获取的是java启动时配置的系统参数
scribeCategory:这里写死“cos_errorlog”,这样数据组才知道这套日志需要发送给sg-errlog系统
pattern:按照数据组的要求打印日志,同时将“等号”和“回车”等替换为对应的占位符
scribeHost:scribeHost:测试环境为10.4.232.70,如果服务器上有采集器监听,则可以配置127.0.0.1
3.5 Log定义
private static final Logger LOGGER = LoggerFactory.getLogger(Boot.class);
使用slf4j进行log的定义,注意需要保证项目中不再依赖于slf4j1。如果启动时有如下提示,说明依然依赖了多个slf4j
4、参考资料
http://logging.apache.org/log4j/2.x/manual/migration.html#Configuring_Log4j_2
http://logging.apache.org/log4j/2.x/guidelines.html
http://logging.apache.org/log4j/2.x/performance.html
http://www.infoq.com/cn/articles/things-of-java-log-performance
http://www.infoq.com/cn/news/2014/08/apache-log4j2
看完本文有收获?请转发分享给更多人
关注「ImportNew」,看技术干货