Log4j2使用总结

Log4j 2 包含了基于LMAX 分离库的下一代的异步日志系统，在多线程环境下，异步日志系统比 Log4j 1.x 和Logback 提高了10倍性能提升（吞吐量和延迟率 ）。原文如下:

Log4j 2 contains next-generation Asynchronous Loggers based on the LMAX Disruptor library. In multi-threaded scenarios Asynchronous Loggers have 10 times higher throughput and orders of magnitude lower latency than Log4j 1.x and Logback. 

Log4j2目前已经出到了beta8版本，估计beta9在最近一周将放出，试用了下，感觉还不错，做如下总结!

我是从logback迁移到log4j2，

删除掉原有的包 log4j-over-slf4j-1.6.4.jar logback-classic-1.0.7.jar logback-core-1.0.7.jar slf4j-api-1.6.4.jar

增添以下的包 log4j-over-slf4j-1.7.5.jar log4j-api-2.0-beta8.jar log4j-core-2.0-beta8.jar  log4j-slf4j-impl-2.0-beta8.jar

由于作者推荐，为了性能考虑，尽量不要使用slf4j，但我依赖的第三方框架比如spring有对slf4j使用，所以对JAR包做了以上的取舍，所以原有代码中要做如下的改动

改动前:import org.slf4j.Logger;
      import org.slf4j.LoggerFactory;

     private static final Logger logger = LoggerFactory.getLogger(OOXX.class);

改动后:iimport org.apache.logging.log4j.LogManager;
      import org.apache.logging.log4j.Logger;

     private static final Logger logger = LogManager.getLogger(OOXX.class);

配置文件log4j2.xml如下:

<?xml version="1.0" encoding="UTF-8"?>
<!-- status=debug 可以查看log4j的装配过程 -->
<configuration status="off" monitorInterval="1800">
  <properties>
    <property name="LOG_HOME">/log/fish</property>
    <!-- 日志备份目录 -->
    <property name="BACKUP_HOME">{LOG_HOME}/backup</property>
    <property name="STAT_NAME">stat</property>
    <property name="SERVER_NAME">global</property>
  </properties>
  <appenders>
    <!-- 定义控制台输出 -->
    <Console name="Console" target="SYSTEM_OUT" follow="true">
      <PatternLayout pattern="%date{yyyy-MM-dd HH:mm:ss.SSS} %level [%thread][%file:%line] - %msg%n" />
    </Console>
    <!-- 程序员调试日志 -->
    <RollingRandomAccessFile name="DevLog" fileName="${LOG_HOME}/${SERVER_NAME}"
      filePattern="${LOG_HOME}/${SERVER_NAME}.%d{yyyy-MM-dd-HH}.log">
      <PatternLayout pattern="%date{yyyy-MM-dd HH:mm:ss.SSS} %level [%thread][%file:%line] - %msg%n" />
      <Policies>
        <TimeBasedTriggeringPolicy interval="1" modulate="true" />
      </Policies>
    </RollingRandomAccessFile>
    <!-- 游戏产品数据分析日志 -->
    <RollingRandomAccessFile name="ProductLog"
      fileName="${LOG_HOME}/${SERVER_NAME}_${STAT_NAME}"
      filePattern="${LOG_HOME}/${SERVER_NAME}_${STAT_NAME}.%d{yyyy-MM-dd-HH}.log">
      <PatternLayout
        pattern="%date{yyyy-MM-dd HH:mm:ss.SSS} %level [%thread][%file:%line] - %msg%n" />
      <Policies>
        <TimeBasedTriggeringPolicy interval="1"
          modulate="true" />
      </Policies>
    </RollingRandomAccessFile>
  </appenders>
  <loggers>
    <!-- 3rdparty Loggers -->
    <logger name="org.springframework.core" level="info">
    </logger>
    <logger name="org.springframework.beans" level="info">
    </logger>
    <logger name="org.springframework.context" level="info">
    </logger>
    <logger name="org.springframework.web" level="info">
    </logger>
    <logger name="org.jboss.netty" level="warn">
    </logger>
    <logger name="org.apache.http" level="warn">
    </logger>
    <logger name="com.mchange.v2" level="warn">
    </logger>
    <!-- Game Stat  logger -->
    <logger name="com.u9.global.service.log" level="info"
      additivity="false">
      <appender-ref ref="ProductLog" />
    </logger>
    <!-- Root Logger -->
    <root level="DEBUG" includeLocation="true">
      <appender-ref ref="DevLog" />
      <appender-ref ref="Console" />
    </root>
  </loggers>
</configuration>

TimeBased Triggering Policy

基于时间的触发策略。该策略主要是完成周期性的log文件封存工作。有两个参数：

interval，integer型，指定两次封存动作之间的时间间隔。单位:以日志的命名精度来确定单位，比如yyyy-MM-dd-HH 单位为小时，yyyy-MM-dd-HH-mm 单位为分钟

modulate，boolean型，说明是否对封存时间进行调制。若modulate=true，则封存时间将以0点为边界进行偏移计算。比如，modulate=true，interval=4hours，那么假设上次封存日志的时间为03:00，则下次封存日志的时间为04:00，之后的封存时间依次为08:00，12:00，16:00，。。。

存在问题:在Eclipse下一切运行正常，如果把应用打包成jar包发布后，cmd命令行模式下，即使Console开着的情况下，也没法输出，文件输出也没有任何日志。

问题已经解决，需要在MANIFEST.MF文件里Class-Path 最前加个'.',目的是让与jar包平级的配置文件log4j2.xml加载进来。

比如

Class-Path: . lib/antlr-2.7.6.jar lib/other.jar

这样，就把包含了log4j2.xml的路径放到了classpath,因此，log4j2能读取这个文件。感谢老外Jacob Kjome的回复！

log4j2 在Web的应用，把log4j2.xml放在src根目录下，不需要任何在代码级别的设置，直接类似JAVA应用一样使用，但把servlet改成了servlet3.0，因为官网上描述如下：

The Short Story
Log4j 2 "just works" in Servlet 3.0 and newer web applications. It is capable of automatically starting when the application deploys and shutting down when the application undeploys.Important Note! For performance reasons, containers often ignore certain JARs known not to contain TLDs or ServletContainerInitializers and do not scan them for web-fragments and initializers. Importantly, Tomcat 7 <7.0.43 ignores all JAR files named log4j*.jar, which prevents this feature from working. This has been fixed in Tomcat 7.0.43, Tomcat 8, and later. In Tomcat 7 <7.0.43 you will need to change catalina.properties and remove "log4j*.jar" from the jarsToSkip property. You may need to do something similar on other containers if they skip scanning Log4j JAR files.

但发现在eclipse下servlet2.0 也可以用的，并且不用修改catalina.properties文件。我用的是apache-tomcat-7.0.42，很奇怪！

 

有时候，为了同一份log4j文件要支持写到不同的log中（否则会导致打印的内容被覆盖，其中一个进程写不进log等问题），需要在载入的时候对内容进行动态修改，比如根据server id分别生成game1.log,game2.log

可以代码进行加载log4文件

File file = new File("log4j2.xml");
    BufferedInputStream in = null;
    try {
      in = new BufferedInputStream(new FileInputStream(file));
        final ConfigurationSource source = new ConfigurationSource();
      source.setInputStream(in);
      Configurator.initialize(null, source);
    } catch (FileNotFoundException e) {
      e.printStackTrace();
    }

要使用异步写日志的功能，必须引入​​Disruptor​​

<asyncRoot> or <asyncLogger>

官方建议一般程序员查看的日志改成异步方式，一些运营日志改成同步

Asynchronous Appenders 和 Asynchronous Loggers 区别:

在</appenders> 节点里添加

  <Async name="Async">
      <AppenderRef ref="MyFile"/>
    </Async>

为Asynchronous Appenders 性能比同步快，比Asynchronous Loggers慢

在loggers节点添加

    <AsyncLogger name="com.foo.Bar" level="trace" includeLocation="true">
      <AppenderRef ref="RandomAccessFile"/>
    </AsyncLogger>

或者添加

<!-- Root Logger -->
<asyncRoot level="DEBUG">
<appender-ref ref="DevLog" />
<appender-ref ref="Console" />
</asyncRoot>

为logger async 用的是无锁并发技术，必须引入​​Disruptor​​

测试了下，单线程异步比同步效率提高了1倍。线程越多性能提高越明显。

如果要加上位置信息比如哪个类，第几行，需要设置 includeLocation="true" 但默认不设置好像也是true,

location 主要包含了如下:

If one of the layouts is configured with a location-related attribute like HTML ​​locationInfo​​​, or one of the patterns ​​%C or $class​​​, ​​%F or %file​​​, ​​%l or %location​​​, ​​%L or %line​​​, ​​%M or %method​​, Log4j will take a snapshot of the stack, and walk the stack trace to find the location information.

====================

log4j2最终输出点

AbstractOutputStreamAppender .append(final LogEvent event)

====================

以下要翻译

shutdownHook="disable"

log4j也有ShutdownHook的程序，并且提前执行了，导致提前关闭了日志。

log4j可以配置不开启ShutdownHook

如何动态传入参数？

有时候游戏区服的ID需要动态传入，做到配置的单点化，而不是游戏配置文件config.xml配置一c次，log4j2.xml又配置一次，运维经常忘记调整区服ID导致日志覆盖的线上事故产生

System.setProperty("SERVER_ID", "1");
        GameServerService service = new GameServerService(args);
        service.start();

在配置文件中就可以按照如下方式读取到：

<properties>
        <property name="SERVER_ID">${SYS:SERVER_ID}</property>
        <property name="SERVER_NAME">gamesvr</property>
        <property name="LOG_HOME">../log/${SERVER_NAME}/${SYS:SERVER_ID}</property>
        <property name="GAMIOO_HOME">../log/stat/gamioo/${SERVER_NAME}/${SYS:SERVER_ID}</property>
    </properties>

如果你没有使用java系统属性，而是环境变量，你不应该使用 $ {sys:variable} 前缀，而是 $ {env:variable} 前缀代替

但这有个坑就是在读入参数前，不能去提前使用log4j2,如果纠结于这个那么可以在启动的时候加入参数 -DSERVER_ID=1，但这个配置要当做VM options传入，不能当做普通的变量传入

然后读取就这样读取 

String id = System.getProperty("SERVER_ID");

Making All Loggers Asynchronous

Requires disruptor-3.0.0.jar or higher on the classpath.

This is simplest to configure and gives the best performance. To make all loggers asynchronous, add the disruptor jar to the classpath and set the system property Log4jContextSelector toorg.apache.logging.log4j.core.async.AsyncLoggerContextSelector.

By default, ​​location​​ is not passed to the I/O thread by asynchronous loggers. If one of your layouts or custom filters needs location information, you need to set "includeLocation=true" in the configuration of all relevant loggers, including the root logger.

A configuration that does not require location might look like:

1. <?xml version="1.0" encoding="UTF-8"?>
2.  
3. <!-- Don't forget to set system property
4. -DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector
5. to make all loggers asynchronous. -->
6.  
7. <Configuration status="WARN">
8. <Appenders>
9. <!-- Async Loggers will auto-flush in batches, so switch off immediateFlush. -->
10. <RandomAccessFile name="RandomAccessFile" fileName="async.log" immediateFlush="false" append="false">
11. <PatternLayout>
12. <Pattern>%d %p %c{1.} [%t] %m %ex%n</Pattern>
13. </PatternLayout>
14. </RandomAccessFile>
15. </Appenders>
16. <Loggers>
17. <Root level="info" includeLocation="false">
18. <AppenderRef ref="RandomAccessFile"/>
19. </Root>
20. </Loggers>
21. </Configuration>

When AsyncLoggerContextSelector is used to make all loggers asynchronous, make sure to use normal <root> and <logger> elements in the configuration. The AsyncLoggerContextSelector will ensure that all loggers are asynchronous, using a mechanism that is different from what happens when you configure <asyncRoot> or <asyncLogger>. The latter elements are intended for mixing async with sync loggers. If you use both mechanisms together you will end up with two background threads, where your application passes the log message to thread A, which passes the message to thread B, which then finally logs the message to disk. This works, but there will be an unnecessary step in the middle.

There are a few system properties you can use to control aspects of the asynchronous logging subsystem. Some of these can be used to tune logging performance.

---------------

关于高亮颜色显示,官方介绍如下:

​​Log4j – Log4j 2 Layouts​​