使用Log4j进行日志记录

发布日期：2006年07月30日，更新日期：2006年07月30日

1996年初，欧洲安全电子市场(EU SEMPER)项目组决定编写自己的日志记录API，后来这个API演变成了Log4j。Log4j是一个开放源码项目，一个非常流行的Java日志记录包。它允许开发者向代码中插入日志记录语句，还允许在不修改应用程序源码的情况下修改记录日志的行为。

1996年初，欧洲安全电子市场(EU SEMPER)项目组决定编写自己的日志记录API，后来这个API演变成了Log4j。Log4j是一个开放源码项目，一个非常流行的Java日志记录包。它允许开发者向代码中插入日志记录语句，还允许在不修改应用程序源码的情况下修改日志记录的行为。

几乎每一个项目都会使用日志记录，但是由于日志记录不是项目的核心，因此受重视的程度一般不是很高。我们认为使用日志记录是一件非常严肃的事情，而且做好使用日志记录的规划比单纯记录日志本身更加重要。

本文将比较全面的阐述Log4j的设计原理和使用方法。

回页首

日志记录

日志记录记录的是应用程序运行的轨迹。我们可以通过查看这些轨迹来调试应用程序，这可能也是日志记录最为流行的用法了。但是我们必须意识到规划良好的日志记录中还含有丰富的信息，通过手工的方式或借助一些工具(大多数时候需要自己来书写这些工具)来分析挖掘这些信息。

例如，如果我们在规划中指出必须记录用户的每一次操作，记录的样式为 [日志信息]-[操作开始的时间]-[日志级别]-[日志类别]-[用户名]-[操作名]-[消息]，这只是我们假设的一种样式，实际的日志中一般会含有比这更加丰富的信息。为了更好的理解，我们根据该样式构造了一些日志记录(其中日志类别org.solol.Main、org.solol.Parser和org.solol.UserOperator使用了不同的样式)：

[日志信息]-[2006-07-30 08:54:20]-[INFO]-[org.solol.Main]-[具体的消息]
[日志信息]-[2006-07-30 08:55:20]-[INFO]-[org.solol.UserOperator]-[User1]-[查询报表1]-[具体的消息]
[日志信息]-[2006-07-30 08:55:30]-[INFO]-[org.solol.UserOperator]-[User1]-[查询报表2]-[具体的消息]
[日志信息]-[2006-07-30 08:56:01]-[INFO]-[org.solol.Parser]-[具体的消息]
[日志信息]-[2006-07-30 08:57:26]-[INFO]-[org.solol.UserOperator]-[User2]-[添加用户User3]-[具体的消息]
[日志信息]-[2006-07-30 08:58:20]-[INFO]-[org.solol.UserOperator]-[User1]-[查询报表3]-[具体的消息]
[日志信息]-[2006-07-30 08:59:38]-[INFO]-[org.solol.UserOperator]-[User3]-[查询报表1]-[具体的消息]
[日志信息]-[2006-07-30 08:59:39]-[INFO]-[org.solol.UserOperator]-[User2]-[退出系统]-[具体的消息]

从上面的日志记录中我们很容易抽取出某一用户的操作列表，如对于用户User1我们的结果为：

[日志信息]-[2006-07-30 08:55:20]-[INFO]-[org.solol.UserOperator]-[User1]-[查询报表1]-[具体的消息]
[日志信息]-[2006-07-30 08:55:30]-[INFO]-[org.solol.UserOperator]-[User1]-[查询报表2]-[具体的消息]
[日志信息]-[2006-07-30 08:58:20]-[INFO]-[org.solol.UserOperator]-[User1]-[查询报表3]-[具体的消息]

这样我们就得到了某一时间段中User1的操作列表，可以利用这一列表来进行安全分析。

我们还可以从另外的角度来分析上面的日志记录，如我们很容易统计出操作(日志类别为org.solol.UserOperator)发生的总次数(6次)，其中操作[查询报表1]为2次，[查询报表2]为1次，[查询报表3]为1次，[添加用户User3]为1次，[退出系统]为1次。这样我们就可以得出系统中的那些操作用户使用的比较频繁。

以上我们从两个角度对日记记录中的信息进行了简单的挖掘，实际中待挖掘的方面要丰富的多，这取决于您的意图和您的想象力。

这里我们还要特别强调一下：所有这一切都需要有使用日志记录的良好规划。如果规划不好(即日志记录没有规律性)，那么我们挖掘时的任务就会非常繁重或者使挖掘成为一个不可能的任务。

文章到了这里我们要来描述日志记录的最为流行的用法了，即调试应用程序。我们在调试应用程序时一般会使用两种方法，除了日志记录之外，还有debugger调试器。

我们不想把他们放到一起来描述，因为这是两个完全不同的问题，虽然他们都用来调试应用程序。使用debugger调试器我们可以清楚的知道引发错误的上下文及其相关信息，也可以使用单步执行、设置断点、检查变量以及暂挂和恢复线程等等比较高级的能力，但是尽管这样它也不能替代日志记录，同样日志记录也不能替代debugger调试器。我们要结合使用这两种方法，不同的场景使用不同的方法会有更好的效果。

我们认为使用日志记录来调试应用程也应该充分考虑软件的开发周期。这里我们只考虑软件开发周期中的与日志记录有关的两个阶段：

开发阶段，用来记录应用程序的方方面面和各种细节，非常详细，使得一看到它就知道那里出了问题，出了什么样的问题。
出品阶段，要能够记录各种级别的错误和警告，同时也要适度记录应用程序正常运行的关键信息，这些信息可以给相关人员(开发人员、测试人员、用户等)极大的信心，使他们可以毫不犹豫的告诉您--瞧我们的软件在正常的运行。如一个好的web服务器的启动日志记录不仅要包含错误和警告，还要包含服务器正在启动，正在加载某某组件等等，最后还要提示启动是成功还是失败。

阅读到这里我们就应该着手实现我们的日志记录了。比较幸运的是我们有好多日志记录软件包可选，这就使我们不必关心日志记录的细节，只要把主要的精力放到日志记录的规划上就好了。我们选择的是Log4j，文章的余下部分将主要介绍这个Java日志记录软件包。

回页首

log4j的特性

log4j的特性列表：

在运行速度方面进行了优化
使用基于名称的日志(logger)层次结构
是fail-stop的
是线程安全的
不受限于预定义的实用工具集
可以在运行时使用property和xml两种格式的文件来配置日志记录的行为
在一开始就设计为能够处理Java异常
能够定向输出到文件(file)、控制台(console)、java.io.OutputStream、java.io.Writer、远程服务器、远程Unix Syslog守护者、远程JMS监听者、NT EventLog或者发送e-mail
使用DEBUG、INFO、WARN、ERROR和FATAL五5个级别
可以容易的改变日志记录的布局(Layout)
输出日志记录的目的地和写策略可以通过实现Appender接口来改变
支持为每个日志(logger)附加多个目的地(appender)
提供国际化支持

回页首

log4j的设计原理

Log4j有三个主要的组件：Logger、Appender和Layout。这三个组件相互配合使得我们可以获得非常强大的日志记录的能力。

Logger

Logger的名称是区分大小写的，依据名称可以确定其层次结构(即父子关系)，规则如下：

如果Logger A的名称后跟一个点(.)是Logger B的名称的前缀就认为Logger A是Logger B的祖先。
如果在Logger A和Logger B之间，Logger B没有任何其它的祖先就认为Logger A是Logger B的父亲。

在Logger的层次结构的最顶层是root logger，它会永远存在，而且不能通过名字取到。

上面文字的描述可能不好的理解，为此我们给出了一张图，Logger的层次结构图，从中可以非常直观的看出三种主要组件的关系和各自所起的作用。

图示 1. Logger的层次结构图

Loger x.y是Logger x.y.z的祖先，因为x.y.是x.y.z的前缀，这符合规则的前一条。另外在Logger x.y和Logger x.y.z之间，Logger x.y.z没有其它的祖先，因此Logger x.y是Logger x.y.z的父亲，这符合规则的后一条。这样我们依据上面的规则就可以构造出如图1所示的Logger的层次结构。

从图1中我们还可以看到每一个Logger都有一个Level，根据该Level的值Logger决定是否处理对应的日志请求。如果Level没有被设置，就象图1中的Logger x.y一样，又该怎么办呢？答案是可以从祖先那里继承。

如果Logger C没有被设置Level，那么它将沿着它的层次结构向上查找,如果找到就继承并结束，否则会一直查找到root logger结束。因为log4j在设计时保证root logger会被设置一个默认的Level,所以任何logger都可以继承到Level。

图1中的Logger x.y没有被设置Level，但是根据上面的继承规则，Logger x.y继承了root logger的Level。

我们在来看看Logger选择日志记录请求(log request)的规则：

假设Logger M具有q级的Level，这个Level可能是设置的也可能是继承到的。

如果向Logger M发出一个Level为p的日志记录请求，那么只有满足p>=q时这个日志记录请求才会被处理。

org.apache.log4j.Logger中的不同方法发出不同Level的日志记录请求，如下：

public void debug(Object message)，发出Level为DEBUG的日志记录请求
public void info(Object message)，发出Level为INFO的日志记录请求
public void warn(Object message)，发出Level为WARN的日志记录请求
public void error(Object message)，发出Level为ERROR日志记录请求
public void fatal(Object message)，发出Level为FATAL的日志请求
public void log(Level l, Object message)，发出指定Level的日志记录请求

其中的静态常量DEBUG、INFO、WARN、ERROR、FATAL是在org.apache.log4j.Level中定义的，除了使用这些预定义的Level之外，Log4j还支持自定义Level。

注：org.apache.log4j.Level中还预定义了一些其它的Level。

Appender

在Log4j中，Appender指的是日志记录输出的目的地。当前支持的Appender(目的地)有文件(file)、控制台(console)、java.io.OutputStream、java.io.Writer、远程服务器、远程Unix Syslog守护者、远程JMS监听者、NT EventLog或者发送e-mail。如果您在上面没有找到适合的Appender，那就需要考虑实现自己的自定义Appender了。

每个Logger可以有多个Appender，但是相同的Appender只会被添加一次。

Appender的附加性意味着Logger C会将日志记录发给它的和它祖先的所有Appender。在图1中Logger a会将日志记录发给它自己的JDBCAppender和它的祖先root logger的ConsoleAppender和FileAppender。Logger x.y.z自己没有Appender，它将把日志记录发给它的祖先root logger的ConsoleAppender和FileAppender，如果Logger x.y也含有Appender，那么它们也会包括在内。

Appender的附加性是可以被中断的。假设Logger C的一个祖先为Logger P，如果Logger P的附加性标志(additivity flag)设置为假，那么Logger C会将日志记录只发给它的和在它和Logger P之间的祖先(包括Logger P)的Appender，而不会发给Logger P的祖先的Appender。Logger的附加性标志(additivity flag)默认值为ture。

在图1中如果没有设置Logger a的附加性标志(additivity flag)，而是使用默认值true，那么Logger a会将日志记录发给它自己的JDBCAppender和它祖先root logger的ConsoleAppender和FileAppender，这和上面的描述相同。如果设置Logger a的附加性标志(additivity flag)的值false，那么Logger a会将日志记录发给它自己的JDBCAppender而不会在发给它祖先root logger的ConsoleAppender和FileAppender了。

Layout

Appender定制了输出目的地，通常我们还需要定制日志记录的输出格式,在Log4j中是通过将Layout和Appender关联到一起来实现的。Layout依据用户的要求来格式化日志记录。PatternLayout(标准Log4j组件)让用户依据类似于C语言printf函数的转换模式来指定输出格式。

例如，转换模式(conversion pattern)为"%r [%t] %-5p %c - %m%n"的PatternLayout将生成类似于以下内容的输出：

176 [main] INFO  org.foo.Bar - Located nearest gas station.

在上面的输出中：

第一个字段表示自程序开始到发出日志记录请求时所消耗的毫秒数
第二个字段表示发出日志记录请求的线程
第三个字段表示日志记录请求的Level
第四个字段表示发出日志记录请求的Logger的名称
第五个字段(-后的文本)表示日志记录请求的消息

Log4j中还提到了一些其它的Layout，包括HTMLLayout、SimpleLayout、XMLLayout、TTCCLayout和DateLayout。如果这些不能满足您的要求，还可以自定义自己的Layout。

回页首

log4j的配置

依据既有的经验显示用于日志记录的代码大约是全部代码量的4%。如果应用程序具有一定的规模，日志记录语句的数量还是比较巨大的，因此必须有效的管理这些语句。

在Log4j中我们可以通过配置Log4j环境来有效的管理日志记录。配置的方式有三种：

通过程序配置
通过Property文件配置
通过XML文件配置

程序配置

通过程序配置Log4j环境实际上就是在应用程序的代码中改变Logger的Level或增加减少Appender等等。

Log4j提供了BasicConfigurator，它只是为root logger添加Appender。其中，

BasicConfigurator.configure()为root logger添加一个关联着PatternLayout.TTCC_CONVERSION_PATTERN的ConsoleAppender
BasicConfigurator.configure(Appender appender)为root logger添加指定的Appender

我们可以把BasicConfigurator看成是一个简单的使用程序配置Log4j环境的示例。例如，要给root logger添加两个Appender(A和B)，下面的代码分别完成了这个要求。

不使用BasicConfigurator：

//示例代码，不能直接使用
Logger root = Logger.getRootLogger();
root.addAppender(A);
root.addAppender(B);

使用BasicConfigurator：

//示例代码，不能直接使用
BasicConfigurator.configure(A);
BasicConfigurator.configure(B);

Property文件配置

这里要使用PropertyConfigurator来分析配置文件并设置日志记录，但是要注意日志记录先前的配置不会被清除和重设。

Property文件是由key=value这样的键值对所组成的，可以使用#或!作为注释行的开始。下面给出了两个简单的示例：

非常简单的示例1：

log4j.rootLogger=DEBUG, A1
	
log4j.appender.A1=org.apache.log4j.ConsoleAppender
log4j.appender.A1.layout=org.apache.log4j.PatternLayout
log4j.appender.A1.layout.ConversionPattern=%-4r %-5p [%t] %37c %3x - %m%n

稍显复杂的示例2：

log4j.rootLogger=, A1, A2

log4j.appender.A1=org.apache.log4j.ConsoleAppender
log4j.appender.A1.layout=org.apache.log4j.PatternLayout
log4j.appender.A1.layout.ConversionPattern=%d %-5p [%t] %-17c{2} (%13F:%L) %3x - %m%n

log4j.appender.A2=org.apache.log4j.FileAppender
log4j.appender.A2.File=filename.log
log4j.appender.A2.Append=false
log4j.appender.A2.layout=org.apache.log4j.PatternLayout
log4j.appender.A2.layout.ConversionPattern=%-5r %-5p [%t] %c{2} - %m%n

上面的两个示例只是让您对配置文件的格式有一个大体的认识，我们将在后面详细的描述各个配置元素的语法。

Repository-wide threshold：

Repository-wide threshold指定的Level的优先级高于Logger本身的Level。语法为log4j.threshold=[level]，level可以为OFF、FATAL、ERROR、WARN、INFO、DEBUG、ALL。也可以使用自定义Level，这时的语法为log4j.threshold=[level#classname]。默认为ALL。

依据上面的规则，我们有这样的结论：如果log4j.threshold=ERROR，Logger C的Level=DEBUG，这时只有高于等于ERROR的日志记录请求会被Logger C处理。

Appender的配置：

Appender的配置语法为

# For appender named appenderName, set its class.
# Note: The appender name can contain dots.
log4j.appender.appenderName=fully.qualified.name.of.appender.class

# Set appender specific options.
log4j.appender.appenderName.option1=value1
...
log4j.appender.appenderName.optionN=valueN
#For each named appender you can configure its Layout. 
#The syntax for configuring an appender's layout is: 
log4j.appender.appenderName.layout=fully.qualified.name.of.layout.class
log4j.appender.appenderName.layout.option1=value1
....
log4j.appender.appenderName.layout.optionN=valueN

Logger的配置：

root logger的配置语法：

log4j.rootLogger=[level], appenderName, appenderName, ...，其中level可以为OFF、FATAL、ERROR、WARN、INFO、DEBUG、ALL。也可以使用自定义Level，这时的语法为[level#classname]。

如果Level被指定那么root logger的Level将被配置为指定值。如果Level没有被指定那么root logger的Level不会被修改。从上面的语法中我们可以看出通过用,分隔的列表可以为root logger指定多个Appender。

对于root logger之外的logger语法是相似的，为log4j.logger.logger_name=[level|INHERITED|NULL], appenderName, appenderName, ...

上面只有INHERITED和NULL需要说明一下，其它部分和root logger相同。INHERITED和NULL的意义是相同的。如果我们使用了它们，意味着这个logger将不在使用自己的Level而是从它的祖先那里继承。

Logger的附加性标志(additivity flag)可以使用log4j.additivity.logger_name=[false|true]来配置。

ObjectRenderer配置：

我们可以通过ObjectRenderer来定义将消息对象转换成字符串的方式。语法为log4j.renderer.fully.qualified.name.of.rendered.class=fully.qualified.name.of.rendering.class。如：

//my.Fruit类型的消息对象将由my.FruitRenderer转换成字符串
log4j.renderer.my.Fruit=my.FruitRenderer

对上面的各个配置元素的语法理解之后，在来看示例1和2就很容易了。

PropertyConfigurator不支持Filter的配置。如果要支持Filter您可以使用DOMConfigurator，即使用XML文件的方式配置。

XML文件配置

要使用DOMConfigurator.configure()来读取XML格式的配置文件。XML文件格式的定义是通过org/apache/log4j/xml/log4j.dtd来完成的，各个配置元素的嵌套关系如下：


<!ELEMENT log4j:configuration (renderer*, appender*,(category|logger)*,root?,categoryFactory?)>

这里没有给出更为详细的内容，要了解详细的内容需要查阅log4j.dtd。

下面这个简单的示例可以使您对XML配置文件的格式有一个基本的认识：

<?xml version="1.0" encoding="UTF-8" ?>
<!DOCTYPE log4j SYSTEM "log4j.dtd">
<log4j>
  <appender name="A1" class="org.apache.log4j.FileAppender">
	<layout class="org.apache.log4j.PatternLayout">
	  <param name="ConversionPattern" value="%-5p %c{2} - %m\n"/>
	</layout>
  </appender>
  <appender name="A2" class="org.apache.log4j.FileAppender">
	<layout class="org.apache.log4j.TTCCLayout">
		<param name="DateFormat" value="ISO8601" />
	</layout>
	<param name="File" value="warning.log" />
	<param name="Append" value="false" />
  </appender>
  <category name="org.apache.log4j.xml" priority="debug">
	<appender-ref ref="A1" />
  </category>
  <root priority="debug">
	<appender-ref ref="A1" />
	<appender-ref ref="A2" />
  </root>
</log4j>

回页首

默认初始化过程

默认初始化过程在LogManager类的静态初始化器中完成。具体步骤如下：

检查系统属性log4j.defaultInitOverride，如果值为false则执行初始化过程，否则跳过初始化过程。
将系统属性log4j.configuration的值赋给变量resource。如果log4j.configuration没有被定义则使用默认值log4j.properties。
试图转换变量resource到一个url。
如果变量resource不能转换成一个url，那么将使用org.apache.log4j.helpers.Loader.getResource(resource, Logger.class)得到一个url。
如果还是得不到url，将忽略默认初始化过程。如果得到url将使用PropertyConfigurator或DOMConfigurator来配置，也可以使用自定义的XXXConfigurator。

参考资料

图解 Tomcat 体系结构
Apache Log4j项目主页
Log4j Documentation，这里的资源非常的丰富。

关于作者

solo L 一位有些理想主义的软件工程师，创建了solol.org。他常常在这里发表一些对技术的见解。