β

Log4j1 升级 Log4j2 实战

ImportNew 83 阅读
原文出处: 高广超

这是在公司内部的一次升级实践,删除了很多隐私的内容,所以可能不是很完整。

1、背景

在任何系统中,日志都是非常重要的组成部分,它是反映系统运行情况的重要依据,也是排查问题时的必要线索。绝大多数人都认可日志的重要性,但是又有多少人仔细想过该怎么打日志,日志对性能的影响究竟有多大呢?

新的Log4j 2.0版本有了大幅的性能提升、新的插件系统,以及配置设置方面的很多改善。Log4j 1.x 在高并发情况下出现死锁导致cpu使用率异常飙升,而Log4j2.0基于LMAX Disruptor的异步日志在多线程环境下性能会远远优于Log4j 1.x和logback —— 官方测试结果

本次升级是以thrift服务化项目为例子进行的,后续会在其他项目中进行,本次工作内容为:Log4j1.x 升级到 Log4j2(如果不想了解原理,可以直接跳到:3、升级方式)

2、log4j2说明

2.1 特性

2.2 性能

吞吐量测试

平均耗时

其中:

更多性能测试信息可参考官方报告:

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

示例:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration>

    <Properties>
        <Property name="pattern_layout">%d %-5p (%F:%L) - %m%n</Property>
        <Property name="LOG_HOME">/var/***/logs</Property>
    </Properties>

    <Appenders>
        <Console name="console" target="SYSTEM_OUT" follow="true">
            <PatternLayout pattern="${pattern_layout}"/>
        </Console>

        <RollingRandomAccessFile name="file"
                                 fileName="${LOG_HOME}/${sys:app.key}.log"
                                 filePattern="${LOG_HOME}/${sys:app.key}.log.%d{yyyy-MM-dd}">
            <PatternLayout pattern="${pattern_layout}"/>
            <Policies>
                <TimeBasedTriggeringPolicy/>
            </Policies>
        </RollingRandomAccessFile>

        <RollingRandomAccessFile name="access_kpi"
                                 fileName="${LOG_HOME}/${sys:app.key}_access_kpi.log"
                                 filePattern="${LOG_HOME}/${sys:app.key}_access_kpi.log.%d{yyyy-MM-dd}">
            <PatternLayout pattern="${pattern_layout}"/>
            <Policies>
                <TimeBasedTriggeringPolicy/>
            </Policies>
        </RollingRandomAccessFile>


        <RollingRandomAccessFile name="jmonitorappender"
                                 fileName="${LOG_HOME}/${sys:app.key}.jmonitor.log"
                                 filePattern="${LOG_HOME}/${sys:app.key}.jmonitor.%d{yyyy-MM-dd}.log.gz">
            <PatternLayout pattern="${pattern_layout}"/>
            <Policies>
                <TimeBasedTriggeringPolicy/>
            </Policies>
        </RollingRandomAccessFile>

        <RollingRandomAccessFile name="jmonitorlogstoreappender"
                                 fileName="${LOG_HOME}/${sys:app.key}.jmonitor.logstore.log"
                                 filePattern="${LOG_HOME}/${sys:app.key}.jmonitor.logstore.%d{yyyy-MM-dd}.log.gz">
            <PatternLayout pattern="${pattern_layout}"/>
            <Policies>
                <TimeBasedTriggeringPolicy/>
            </Policies>
        </RollingRandomAccessFile>

        <Scribe name="errorLog">
            <ThresholdFilter level="error" onMatch="ACCEPT" onMismatch="DENY"/>
            <Property name="hostname">${sys:app.key}</Property>
            <Property name="scribeHost">127.0.0.1</Property>
            <Property name="scribePort">4252</Property>
            <Property name="scribeCategory">cos_errorlog</Property>
            <Property name="printExceptionStack">false</Property>
            <Property name="addStackTraceToMessage">false</Property>
            <Property name="timeToWaitBeforeRetry">6000</Property>
            <Property name="sizeOfInMemoryStoreForward">100</Property>
            <PatternLayout
                    pattern="%d %p $${sys:app.host} $${sys:app.ip} errorlog appkey=$${sys:app.key} location=%F:%L rawlog=%replace{%replace{%m}{=}{:}}{\n|\t}{<br/>} rawexception=%replace{%replace{%ex}{=}{:}}{\n|\t}{<br/>}%n"/>
        </Scribe>


    </Appenders>

    <Loggers>


        <Logger name="access_kpi" level="INFO" includeLocation="true" additivity="false">
            <AppenderRef ref="access_kpi"/>
        </Logger>



        <!-- tair Loggers -->
        <Logger name="com.taobao.tair3.client"  level="WARN" includeLocation="true" additivity="false">
            <AppenderRef ref="file"/>
            <AppenderRef ref="errorLog"/>
        </Logger>

        <!-- 3rdparty Loggers -->
        <Logger name="org.springframework" level="WARN"/>
        <Logger name="org.apache.zookeeper" level="ERROR"/>
        <Logger name="org.springframework.web" level="WARN"/>

        <!-- Root Logger -->
        <Root level="INFO" includeLocation="true">
            <AppenderRef ref="file"/>
            <AppenderRef ref="console"/>
            <AppenderRef ref="errorLog"/>
        </Root>
    </Loggers>
</Configuration>

我们先看看Configuration的一些特性:

Configuration标签

<Configuration status="WARN">
  ...
</Configuration>

该片段表明log4j2配置文件的所有内容都在这个标签内,其status属性为“WARN”说明:log4j2内部的日志会将日志级别大于WARN的日志打印到Console。除了该字段,Configuration还包括其他属性,详见:ConfigurationSyntax。

Appenders标签

<Appenders>
    <Console name="Console" target="SYSTEM_OUT">
      <PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n"/>
    </Console>
</Appenders>

所有的Appender将在<Appenders>和</Appenders>之间定义。上述例子定义了ConsoleAppender并关联PatternLayout,关于Appender和Layout请看上述相关小节。

Logger标签

<Loggers>
    <Logger name="com.foo.Bar" level="trace" additivity="false" includeLocation="true">
      <AppenderRef ref="Console"/>
    </Logger>
    <Root level="error">
      <AppenderRef ref="Console"/>
    </Root>
</Loggers>

所有的Logger将在<Loggers>和</Loggers>之间定义。上述例子通过<Root>定义了所有Logger的根结点(RootLogger),并通过<AppenderRef>标签关联名称为“Console”的Appender,关于Logger请看上述相关小节。

此处有必要说明additivity字段,通过配置该字段,我们可以规定是否将日志事件传递到Logger的父结点处理,其默认值为true(即默认交给parent Logger处理)。

Logger默认不会获取location信息,因此,若我们的Layout或Filter等需要location信息,我们必须给相应的设置“includeLocation=true”

Filters标签

<Filters>
    <Marker marker="EVENT" onMatch="ACCEPT" onMismatch="NEUTRAL"/>
    <DynamicThresholdFilter key="loginId" defaultThreshold="ERROR" onMatch="ACCEPT" onMismatch="NEUTRAL">
      <KeyValuePair key="User1" value="DEBUG"/>
    </DynamicThresholdFilter>
</Filters>

log4j2还有一个很重要的组件——Filter,详见Filter小节。此处通过<Filters>和</Filters>表明这是一个组合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操作,目的在于为我们的应用程序提高性能。我们先来看一看它主要在哪些方面做改进:

AsyncLoggers虽然带来了极大的性能提升,我们应该经常使用。不过,它也有一些缺点,因此,我们要根据具体的应用场景决定使用同步还是异步的方式,详见:Trade-offs。

3、升级方式

以下开始说明*服务化项目如何由:Log4j1.x 升级到 Log4j2

3.1 排除对log4j的依赖

需要确定项目pom文件中依赖的其他的jar中也不再依赖log4j及slf4j-log4j12,具体方式可以通过IDE提供的功能或者直接使用mvn dependency:tree确定依赖关系。

由于引用的jar中很多依然使用的为log4j,因此已经升级过log4j2的项目,每次在新增依赖的时候,一定需要确定一下,引用的jar是否含有对低版本的依赖,并且exclusion掉。

<exclusions>
    <exclusion>
        <groupId>org.slf4j</groupId>
        <artifactId>slf4j-log4j12</artifactId>
    </exclusion>
    <exclusion>
        <groupId>log4j</groupId>
        <artifactId>log4j</artifactId>
    </exclusion>
</exclusions>

3.2 添加对log4j2的依赖

<properties>
    <org.slf4j-version>1.7.12</org.slf4j-version>
    <log4j2-version>2.3</log4j2-version>
</properties>

<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>jcl-over-slf4j</artifactId>
    <version>${org.slf4j-version}</version>
    <scope>runtime</scope>
</dependency>
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-1.2-api</artifactId>
    <version>${log4j2-version}</version>
</dependency>
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-slf4j-impl</artifactId>
    <version>${log4j2-version}</version>
</dependency>
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-api</artifactId>
    <version>${log4j2-version}</version>
</dependency>
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-core</artifactId>
    <version>${log4j2-version}</version>
</dependency>
<dependency>
    <groupId>com.lmax</groupId>
    <artifactId>disruptor</artifactId>
    <version>3.2.0</version>
</dependency>
<dependency>
     <groupId>com.sankuai.meituan</groupId>
     <artifactId>scribe-log4j2</artifactId>
     <version>1.0.9</version>
</dependency>

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文件的路径,由于启动脚本及服务器变量配置等的不确定性,因此该处建议直接配置绝对路径,可以使用<Property name=”LOG_HOME”>/var/*/logs</Property>配置在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的日志打印

3.5 Log定义

private static final Logger LOGGER = LoggerFactory.getLogger(Boot.class);

使用slf4j进行log的定义,注意需要保证项目中不再依赖于slf4j1。如果启动时有如下提示,说明依然依赖了多个slf4j

4、参考资料

作者:ImportNew
原文地址:Log4j1 升级 Log4j2 实战, 感谢原作者分享。

发表评论