JAVA日志丢失终极剖析

TOP生产环境最近频频发生日志丢失事件，上了三拨人去解决，过了一段时间又出现了，太诡异了！具体现象如下：

1. 有一半的机器日志正常生成，而另一半的机器几乎没有生成日志。

2. 在日志丢失的机器上，所有普通logger配置的日志文件都没有生成，而root logger配置的日志文件却生成了，并且root logger只记录了搜索引擎的日志，其它日志信息一个都没有。

同样的机器，同样的代码，同样的环境，为什么会出现这种问题呢？

要想弄清楚原因，我们还得先来了解JAVA开源世界里的各种日志组件。

 

一、日志介绍

1. commons-logging : Apache最早提供的日志门面接口，主要是为了避免程序的代码和具体的实现相耦合。类似于JDBC的API接口，具体的JDBC Driver是由各个数据库提供商来实现的。通过统一接口解耦，不过其内部也实现了一些简单的日志方案。

2. log4j : 应用最广泛的一种日志解决方案，主要由Appender, Logger, Pattern, Category等组成，通过log4j.xml或log4j.properties配置文件来实现日志系统的管理和多样化配置。可单独做为日志方案来使 用，也可以配合commons-logging接口来使用，以达到解耦。

3. slf4j : Simple Logger Facade for JAVA，是继commons-logging后的又一日志门面接口。与commons-logging的配置加载实现不同，slf4j是通过类加载来感 知实现的。slf4j还有一个比较好的特性是，可以通过占位符{}来实现日志替换，避免了log.isXXXEnabled这种无耐的判断。

4. logback : log4j作者的又一力作，作为一个通用可靠、快速灵活的日志框架，将作为log4j的替代和slf4j组成新的日志系统的完整实现。官网上称具有极佳的性能，在关键路径上执行速度是log4j的10倍，且内存消耗更少。

下面是各个组件之间的关系图：

 

二、加载顺序

1. commons-logging ：它是通过LogFactory.getgetFactory()方法按照固定的顺序来加载实现类的：

1) 首先：通过查找系统变量org.apache.commons.logging.LogFactory 的配置值来加载相应的实现（可通过JVM的启动参数来配置）。

2) 否则，扫描ClassPath路径下的META-INF/services/org.apache.commons.logging.LogFactory 文件，通过此文件的第一行配置值来加载实现（jcl-over-slf4j.jar中包含此文件）。

3)否则，从ClassPath中寻找commons-loggings.properties文件，通过里面的配置项org.apache.commons.logging.LogFactory 来加载相应的实现。

4)否则，使用默认的配置方式：如果能找到log4j则默认使用log4j实现，如果没有则使用JDK14Logger 实现，再没有则使用commons-logging内部提供的SimpleLog 实现。

2. slf4j : 它是通过LoggerFactory类在编译时绑定的import org.slf4j.impl.StaticLoggerBinder 类加载的，任何一种基于slf4j的实现都要有一个这个类。

 

三、如何使用

1. commons-logging + log4j

这是应用最广泛的日志方案，大部分开源软件都采用了这种方式。使用此方案只需引入commons-logging和log4j两个jar包，并提供log4j.xml或log4j.properties配置文件即可。代码如下：

1) private static final Log log = LogFactory.getLog(LogTest.class); //推荐使用这种方式

2) private static final Logger log = Logger.getLogger(LogTest.class); // 使用这种方式其实只需要引入log4j包即可

2. slf4j + logback

此方案性能高，使用灵活方便，可使用默认配置文件，也可以通过加载指定的配置文件。使用此方案需要引入slf4j, logback-core和logback-classic三个jar包。代码如下：

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

3. commons-logging + slf4j + log4j

如果原有的系统中使用的是commons-logging + log4j，需要迁移到slf4j，则需要使用jcl-over-slf4j桥接包，这个包提供了一个桥接，让底层实现是基于slf4j。使用此方案需要 引入commons-logging, jcl-over-slf4j, slf4j-log4j和log4j四个jar包。代码和commons-logging + log4j是一样的。

private static final Log log = LogFactory.getLog(LogTest.class)

 

四、问题诊断

有了上面的了解，现在来回头看一下日志丢失的问题就方便了，你会发现所有的诡异问题背后其实都是有原因的。

首先来看一下TOP生产环境中都依赖了哪些日志jar包：

- commons-logging

- log4j

- slf4j

- logback（包含org.slf4j.impl.StaticLoggerBinder）

- jcl-over-slf4j（包含META-INF/services/org.apache.commons.logging.LogFactory）

- slf4j-log4j（包含org.slf4j.impl.StaticLoggerBinder）

几乎引入了上面提到的所有日志组件，不出问题才怪，现在我们来分析一下原因：

系统中依赖了commons-logging, jcl-over-slf4j两个包，根据commons-logging的加载顺序可以知道，只要依赖了jcl-over-slf4j包，系统必定被桥 接到了slf4j的日志方案上来。更加杯具的是，系统中有两个org.slf4j.impl.StaticLoggerBinder实现，由于JVM加载 类的随机性，整个系统将会出现两种日志方案：

1) commons-logging + slf4j + logback

2) commons-logging + slf4j + log4j

由于TOP系统是采用log4j.xml来配置的，如果系统采用的是1)方案，则显然没有日志输出；如果采用的是2)方案，则输出正常。这也就解释了为什么会出现“有一半的机器日志正常生成，而另一半的机器几乎没有生成日志”

但还有一个问题无法解释的是：为什么被采用1)方案的机器上还有root.log生成，并且里面只有搜索引擎的日志。细心的同学可以发现上面的“使 用方式”中介绍了可以直接通过log4j的Logger log = Logger.getLogger(LogTest.class)来使用，果然通过查看搜索引擎的代码发现里面是直接使用了log4j来记日志的，没有采 用commons-logging门面接口，而log4j是认识log4j.xml的，再加上搜索引擎的包路径没有被配置成普通的logger，所以搜索 引擎的日志会被记录在root logger下。这也就解释了什么会出现“普通的logger没有日志生成，而root logger却有日志生成”

 

五、如何解决

1) 删除jcl-over-slf4j.jar，采用commons-logging + log4j实现

或者

2) 删除logback.jar，采用commons-logging + slf4j + log4j实现

 

来源：http://rdc.taobao.com/team/top/2011/03/06/java%E6%97%A5%E5%BF%97%E4%B8%A2%E5%A4%B1%E7%BB%88%E6%9E%81%E5%89%96%E6%9E%90/