WAS5.x 下使用 Log4j 为何没有日志输出的详细分析及解决办法

经常碰到有人使用了 Log4j 的项目在别处运行的好好的,一放到 WAS 下发现不能输出日志了:控制台文件 SystemOut.log 中没有 Log4j 本应输出的内容,要么就只见磁盘上有一个设定的日志文件,却总是空空如也。

本文就来以一个实际的例子分析为什么会出现这样的情况,以及告诉你应如何解决。这其中也是因为 ClassLoader 在作祟。通常我们会在通用日志框架 jakarta-commons-logging 之下使用 Log4j,这也是合情理的,因为 Struts、Hibernate 等众多框架就是这么干的,然而这却是一方面的根源。分析的过程应用了前面一篇介绍的 Eclipse 远程调试 WebSphere Application Server (WAS) 方法。

测试环境和工具是:WAS 5.1+Eclipse 3.3.2+MyEclipse 6.0.1,在 Eclipse 中建立 Web  项目 testlog(此处可下载:testlog.zip),其中所用到的 jar 包只有 commons-logging.jar(V1.0.3)、log4j-1.2.11.jar。再有为了知道是哪个 ClassLoader 加载了某个类,参考了:利用 JWhich 掌握类路径,确定类路径中的什么类将被载入

项目 testlog 简介:在 WEB-INF/classes 下有两个配置文件,commons-logging.properties 和 log4j.properties。commons-logging.properties 的内容是:

org.apache.commons.logging.LogFactory=org.apache.commons.logging.impl.Log4jFactory#Log4jFactory 已不推荐使用,新的建议是统一使用 LogFactoryImpl,然后由它决定声明哪个 Log 实现
#org.apache.commons.logging.LogFactory=org.apache.commons.logging.impl.LogFactroyImpl

log4j.properties 中配置了两个 Appender,分别输往控制台stdout(ConsoleAppender) 和 R 文件 log4j.log(DailyRollingFileAppender);输出级别设定为 DEBUG。

日志变量 log 的声明方式是:Log log = LogFactory.getLog(TestLog.class); 把该行代码放在 main 方法中是为了便于测试。该项目发布到 WAS5.1 下,通过访问 index.jsp 来进行测试,index.jsp 页面中还包括了测试日志输出和查找哪个 ClassLoader 加载了某个类的功能。

然后用 Eclipse 的远程调试功能连接到 WAS 的调试端口上就可以单步调试了。在 com.unmi.TestLog 类的行 Log log = LogFactory.getLog(TestLog.class); 上打断点,访问部署的 index.jsp 页面(如:http://10.80.39.41:9080/testlog/index.jsp),然后在 Log Message 框中输入信息,点击 Print Log 按钮,代码就停在 Log log = LogFactory.getLog(TestLog.class);  行上,我们真正就是从这里开始看问题了。

LogFactory.getLog(TestLog.class);  会调用 LogFactory.getFactory() 来获得真正的 LogFactory 实例,注意 org.apche.commons.logging.LogFactory 是个抽象类。通过看 LogFactory.getFactory() 方法代码,我们可以知道 commons-logging 是按以下顺序找到相应的 LogFactory 实现类的(详细分析见我前面写的一篇:Apache Commons Logging 是如何决定使用哪个日志实现类的)。

1. 从系统属性中查找键为 org.apache.commons.logging.LogFactory 的值作为 LogFactory 的实现类;却通过 System.getProperty("org.apache.commons.logging.LogFactory") 获得
2.  使用 JDK1.3 jar 的 Service Provider Interface(SPI) 类发现机制,从配置文件 META-INF/services/org.apache.commons.logging.LogFactory 的的第一行读取 LogFactory 的实现类名。这个 META-INF/services/org.apache.commons.logging.LogFactory 文件可以是某个 Web 应用的根目录中;也可以在 classpath 下,如某个 Jar 包中,WebRoot/WEB-INF/classes 中等。这里需多加留心下 META-INF/services/org.apache.commons.logging.LogFactory 这个目录层次及文件名。
3.  在 Classpath 下的 commons-logging.properties 文件中的,找到 org.apache.commons.logging.LogFactory 属性值作为 LogFactory 实现类
4. 前面三步未找个 LogFactory 的实现类,或有任何异常的情况下,就用默认的实现类,即 LogFactory 为我们准备的 org.apache.commons.logging.impl.LogFactoryImpl

那么 WAS 5 是在上面哪一步先下手为强的呢?就在第三步。你是不是有疑问了,我们项目中不是有一个 commons-logging.properties 文件,在其中指定了用 Log4jFactory 的吗?可是实际用运行 WAS 加载的是 $WAS_HOME/lib/ws-commons-logging.jar!/commons-logging.properties,则其中的内容是:

org.apache.commons.logging.LogFactory=com.ibm.ws.commons.logging.TrLogFactory

所以实际应用的是 WAS 5 自带的 TrLogFactory,而不是 Log4jFactory 或别的。为什么优先加载了些 commons-logging.properties 而非应用中的 commons-logging.properties,原因就是类加载器的委托机制:commons-logging.properties 是通过 ClassLoader 定位的,子 ClassLoader 加载某个类或资源时会委托给父 ClassLoader 加载,父 ClassLoader 能加载到该类或资源则优先。

应用 testlog 的类加载器 com.ibm.ws.classloader.CompoundClassLoader(从WEB-INF/class 和 WEB-INF/lib 下加载) 的父加载器是 com.ibm.ws.bootstrap.ExtClassLoader(从 $WAS_HOME/lib 下加载)。再顺带说明一下,$WAS_HOME/lib 带了 commons-logging 包 commons-logging-api.jar,它是 1.0.3版,但是 WAS 的 commons-logging-api.jar 与我们下载的 commons-logging-1.0.3.jar 相比,少了 org.apache.commons.logging.impl 包中的 Log4jFactory、Log4JCategoryLog、Log4JLogger 这几个类。所以 commons-logging 中的有些类从 WAS 的 commons-logging-api.jar 加载,有些从应用中的 commons-logging.jar 加载,以及通过不同的加载器加载的。

知道了上面那些,那我们来找可能的解决办法,使我们的应用能借助 Log4j 输出日志:

1. 修改 $WAS_HOME/lib/ws-commons-logging.jar!commons-logging.properties 的内容为:

org.apache.commons.logging.LogFactory=org.apache.commons.logging.impl.LogFactoryImpl
#或者org.apache.commons.logging.LogFactory=org.apache.commons.logging.impl.Log4jFactory

2. 把 $WAS_HOME/lib/ws-commons-logging.jar!/commons-logging.properties 文件删了?这样父 ClassLoader 是加载不到 commons-logging.properties,能用上应用中的 commons-logging.properties 文件,即使应用中没有 commons-logging.properties 文件也行(没有该文件时会使用 org.apache.commons.logging.impl.LogFactoryImpl,它找到了 Log4j 就用 Log4j),Log4j 也能用了。但这样做同样动了全局的东西。

3. 回到前面 LogFactory 决定具体实现类的步骤上,可以在第一、二步上做文章。其一,设置系统属性 org.apahe.commons.logging.LogFactory 为  org.apache.commons.logging.impl.LogFactoryImpl  或者为 org.apache.commons.logging.impl.Log4jFactory
。要在 WAS 管理控制台对相应的应用服务器设置系统属性,或在程序中设定。这样做同样影响了全局,似乎不怎么妥。

4. 还有第二步,应用 SPI,指定 SERVICE_ID,具体做法是在 WebRoot/  下放个文件 META-INF/services/org.apache.commons.logging.LogFactory,在该文件的第一行写上 org.apache.commons.logging.impl.LogFactoryImpl 或是 org.apache.commons.logging.impl.Log4jFactory 就 OK 啦,这无疑是最好的办法了。总之就是不让 WAS 用 com.ibm.ws.commons.logging.TrLogFactory因为这个文件也是通过 ClassLoader 加载的,所以 META-INF/services/org.apache.commons.logging.LogFactory 也可以放在 WebRoot/WEB-INF/classes/ 或者是你应用的某个 jar 包中。

5. 还有个办法就是直接用 Log4j,而不用或绕开 commons-logging 的 LogFactory 定位机制,直接在代码中声明使用 Log4j 的 Log,Logger log = Logger.getLogger(TestLog.class),这里的 Logger 是 org.apache.log4j.Logger。这样再换成别的日志组件就没辙了,当然很少有必要去换的。

6. 再 WAS 可以改变应用的类载入器方式。管理控制台中,在应用的属性页面,类载入器方式可以选择 PARENT_FIRST 和 PARENT_LAST,默认是 PARENT_FIRST,遵循类加载器的委托机制。若是改成 PARENT_LAST,也能让你应用中的 commons-logging.properties 优先得到加载,使用上 Log4j。真要改成 PARENT_LAST 能造成的意外情况更是不可预知的。

说到这里,记起了,有次也是因为 Log4j 未能工作,原因是某个 jar 包中有 META-INF/services/org.apache.commons.logging.LogFactory 文件。而为何只产生空的 log4j 的日志文件,应该是你哪处代码触碰到了 Log4j  的初始化行为,实际却未用上 Log4j 来输出日志。

这个应用放到 WAS 6.1.0.0 下 Log4j 可没什么问题,WAS 6.1.0.0 的包没有哪个有 META-INF/services/org.apache.commons.logging.LogFactory  这个文件,所以默认情况下会使用 org.apache.commons.logging.impl.LogFactoryImpl 实现类,由 LogFactoryImpl 也就能正确加载到 org.apache.commons.logging.impl.Log4JLogger。 

参考:1. Apache Commons-logging使用实例
        2. 利用 JWhich 掌握类路径,确定类路径中的什么类将被载入
        3. Apache Commons Logging 是如何决定使用哪个日志实现类的

 

类别: Mid-Ware. 标签: , , . 阅读(193). 订阅评论. TrackBack.

Leave a Reply

Be the First to Comment!

avatar