使用高效的日志工具—Log4J （1）

转自：http://www.cnblogs.com/SGSoft/articles/84099.html

大家在编程时经常不可避免地要使用到一些日志操作，比如开发阶段的调试信息、运行时的日志记录及审计。调查显示，日志代码占代码总量的4％。通常大家可以简单地使用System.out.println()语句输出日志信息，但是往往会有一些判断，比如：

if (someCondition) {
 System.out.println("some information.");
}

这些判断造成正常的程序逻辑中混杂了大量的输出语句。而在开发阶段写下的这些判断仅为了调试的语句，在开发完成时需要查找并移除。部署运行后，尤其是在一些企业应用系统中，还经常需要进一步调试，这时就遇到了更大的麻烦。所以，我们需要一套完备的、灵活的、可配置的日志工具。Log4J就是优秀的选择。

Log4J是Apache软件基金会Jakarta项目下的一个子项目，是用Java编写的优秀日志工具包。通过Log4J可以在不修改代码的情况下，方便、灵活地控制任意粒度的日志信息的开启或关闭，然后使用定制的格式，把日志信息输出到一个或多个需要的地方。并且，Log4J还有一条平滑的学习曲线，在三分钟内就可学会它的简单使用。随着使用深入，你会发现Log4J功能的强大，几乎可以满足日志方面的所有需要。

快速入门

先看一段代码，看看Log4J是多么易于上手，代码如下：

package org.javaresearch.log4j;
import org.apache.log4j.*;
public class TestLog4J {
 static Logger log = Logger.getLogger(TestLog4J.class.getName());
 public static void main(String args[]) {
  BasicConfigurator.configure();
  // logging的各种方法
  cat.debug("Start of main()");
  cat.info("Just testing a log message with priority set to INFO");
  cat.warn("Just testing a log message with priority set to WARN");
  cat.error("Just testing a log message with priority set to ERROR");
  cat.fatal("Just testing a log message with priority set to FATAL");
  // 另一种不方便的格式
  cat.log(Priority.DEBUG, "Testing a log message use a alternate form");
  log.debug("End of main().");
 }
}

把这段代码保存在一个目录下，编译运行（注意要把log4j-1.2.7.jar包含入类路径中），程序输出如下：

0 [main] DEBUG TestLog4J  - Start of main()
10 [main] INFO TestLog4J  - Just testing a log message with priority set to INFO
20 [main] WARN TestLog4J  - Just testing a log message with priority set to WARN
30 [main] ERROR TestLog4J  - Just testing a log message with priority set to ERROR
30 [main] FATAL TestLog4J  - Just testing a log message with priority set to FATAL
40 [main] DEBUG TestLog4J  - Testing a log message use a alternate form
50 [main] DEBUG TestLog4J  - End of main()

首先解释一下上面输出结果的意义。第一个数字是指程序开始运行到运行该日志语句所经历的毫秒数（用来做一点运行效率分析也不错）， “[main]”是日志事件发生的线程，随后的“DEBUG”、“INFO”等信息是相应日志信息的优先级别，“TestLog4”是当前Logger的实例名，最后是日志信息。

在这段程序中，使用了Log4J提供的一个基本配置类BasicConfigurator对Log4J进行初始化。但在实际使用时通常不这么做，因为这多少有点“硬”编码。今后如果要修改Log4J的配置，就需要修改、重新编译代码，这通常不是大家所希望的。通常，我们都提供一个名为 log4j.properties的文件，在第一次调用到Log4J时，Log4J会在类路径中定位这个文件，并读入这个文件完成的配置。这个配置文件告诉Log4J以什么样的格式、把什么样的信息、输出到什么地方。我们来看一个简单的log4j.properties配置文件的示例，代码如下：

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 [%t] %-5p %c %x - %m%n

把上面的内容存储为log4j.properties，并放到和 TestLog4J.class同一目录下（当然也可以放到其它任何目录，只要该目录被包含到类路径中即可）。具体这些配置文件中每行的意义，在以后章节会有详细的说明，现在可以先跳过。现在你可以注释掉上面程序中的 “BasicConfigurator. configure();”语句，然后使用log4j.properties属性文件完成Log4J的配置，重新编译、运行，就得到和上面一样的结果。

这样做有什么好处呢？现在就初步领略一些Log4J的灵活、强大功能。比如系统要上线了，希望输出一些警告和错误信息，这时仅需要修改 log4j.properties文件中的“log4j.rootCategory=DEBUG, A1”即可，然后设置日志输出的最低级别是WARN，设置为“log4j.root Category=WARN, A1”。此时不需要修改任何代码，重新运行系统，输出结果就变成了：

20 [main] WARN TestLog4J  - Just testing a log message with priority set to WARN
30 [main] ERROR TestLog4J  - Just testing a log message with priority set to ERROR
30 [main] FATAL TestLog4J  - Just testing a log message with priority set to FATAL

 

原理分析

Log4J有三个主要部件，它们是记录器（Loggers）、输出源（Appenders）和布局（Logouts）。记录器按照布局中指定的格式把日志信息写入一个或多个输出源。输出源可以是控制台、文本文件、XML文件或Socket，甚至还可以把信息写入到Windows事件日志或通过电子邮件发送，这都需要相应的类来处理，这些相关的类是 ConsoleAppender、 FileAppender、SocketAppender、NtEventLogAppender和JMSAppender。

记录器（Logger）

首先让我们看Logger类，代码如下：

package org.apache.log4j;
public class Logger {
 //创建和恢复方法
 public static Logger getRootLogger();
 public static Logger getLogger(String name);
 public static Logger getLogger(Class clazz);
 // 打印方法
 public void debug(Object message);
 public void info(Object message);
 public void warn(Object message);
 public void error(Object message);
 public void fatal(Object message);
 // 常用打印方法
 public void log(Level l, Object message);
}

从这段代码中可以看出Logger的基本使用。首先需要获取一个Logger对象，获取Logger对象的语句为：

Logger logger = Logger.getLogger(JavaLoggingExample.class.getName());

有了这个Logger对象，就可以在需要的地方方便地输出日志信息。对于这些信息是否输出、输出的格式等，都可以通过配置文件方便地配置，而不需要修改代码，这就是Log4J带来的方便之处。

记录器的层次结构

使用Log4J的Logger.getLogger()方法时会得到一个Logger的实例。如果一个应用中包含了上千个类，那么也几乎需要上千个Logger实例。如何对这上千个Logger实例进行方便地配置，就是一个很重要的问题。Log4J采用了一种树状的继承层次巧妙地解决了这个问题。在Log4J中Logger是具有层次关系的。它有一个共同的根，位于最上层，其它Logger遵循类似包的层次，比如：

static Logger root = Logger.getRootLogger();
static Logger log1 = Logger.getLogger("org");
static Logger log2 = Logger.getLogger("org.javaresearch");
static Logger log3 = Logger.getLogger("org.javaresearch.log4j.TestLog4J");

上面代码中，log1是log2的父亲，是log3的祖先，而root是所有 log1、log2、log3的祖先，它们都从root中继承。所以，一般情况下，仅需要配置好rootLogger，其它子记录器都会从中继承 rootLogger的配置。如果修改了rootLogger的配置，其它所有的子记录器也会继承这种变化。这样就大大地方便了配置。现在回头看看在“快速入门”中的配置文件，我们仅配置了rootLogger，就可以控制所有的Logger的行为。

级别（Level）

Log4J中的一个核心概念是日志级别是有序的。Log4J内置了5种日志级别为：

DEBUG  <  INFO  <  WARN  <  ERROR  <  FATAL

右边的级别比左边的高。每一个Logger实例都有一个日志级别，上面的5种输出方法就是对应于5种不同级别的日志请求。比如，如果c是一个Logger实例，c.info("some information")就是一个INFO级别的日志请求。一个日志请求会不会输出，取决于该Logger实例的日志级别和该日志请求级别的比较。规则如下：

假如在一个级别为p的Logger实例中发生一个级别为q的日志请求，则当q >= p时请求才会启用。

我们先来看实例2代码如下：

// 得到一个logger 实例 "com.foo"
Logger  logger = Logger.getLogger("com.foo")
// 现在设置logger的级别，但正常情况是不需要刻意设置lgger级别的，因为它已经在配置文件中完成了
logger.setLevel(Level.INFO);
Logger barlogger = Logger.getLogger("com.foo.Bar");
//因为 WARN >= INFO，这个请求是可以实现的
logger.warn("Low fuel level.");
// 因为DEBUG < INFO，所以这个请求是无法实现的
logger.debug("Starting search for nearest gas station.");
// logger实例"com.foo.Bar"将从"com.foo"继承级别，这样，因为INFO >= 
INFO，所以可以实现下面的请求
barlogger.info("Located nearest gas station.");
//因为DEBUG < INFO，这个请求是不能实现的 
barlogger.debug("Exiting gas station search");

布局（Layout）

Log4J采用类似C语言中的printf函数的打印格式格式化日志信息，打印参数见表1如下：

%m	输出代码中指定的消息
%p	输出优先级，即DEBUG，INFO，WARN，ERROR，FATAL
%r	输出自应用启动到输出该log信息耗费的毫秒数
%c	输出所属的类目，通常就是所在类的全名
%t	输出产生该日志事件的线程名
%n	输出一个回车换行符，Windows平台为“\r\n”，Unix平台为“\n”
%d	输出日志时间点的日期或时间，默认格式为ISO8601，也可以在其后指定格式，比如：%d{yyy MMM dd HH:mm:ss,SSS}，输出类似：2002年10月18日 22：10：28，921
%l	输出日志事件的发生位置，包括类目名、发生的线程，以及在代码中的行数。举例：Testlog4.main(TestLog4.java:10)