log4j的简要介绍(续)

-----------------------------------------------续----------------------------------------------------------------------------

 

通常，用户希望不仅能自定义输出目的地，而且能自定义输出的格式。这通过给appendder关联一个layout实现。layout负责根据用户的意愿格式化记录日志请求，而appender负责将格式化的输出发送到目的地。PatternLayout是标准log4j发布的一部分,让用户依据类似于C语言printf函数的转换模式来指明输出格式。例如，转换格式为"%r [%t] %-5p %c - %m%n"的PatternLayout将输出类似如下的信息：

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

第一个域是程序启动之后的毫秒数。第二个域是发出记录日志请求的线程。第三个域是日志语句的级别。 第四个域是与记录日志请求关联的logge的名字。'-'之后的文本是日志语句输出的消息。同样重要的是，log4j将会根据用户指定的标准渲染日志信息的内容。例如，如果你需要经常为Oranges（你当前工程中的对象类型）记录日志，那么你可以注册一个OrangeRenderer，它会在orange对象需要记录日志时被调用。对象依照类的继承体系渲染。例如，假设orange是fruit，如果你注册了一个FruitRenderer，所有的fruit包括orange将会被FruitRenderer渲染，当然除非你专门为orange注册一个OrangeRenderer。

对象的renderer必须实现ObjectRenderer接口。

Configuration

在应用程序代码中插入记录日志请求需要计划和精力。观察表明几乎4%的代码用于记录日志。结果，即使是中等规模的应用程序也有成千上万条记录日志语句嵌在程序中间。考虑到它们的数量，实现管理这些记录日志语句而不需要手工修改它们变得势在必行。

log4j环境完全可以用程序配置。但是，使用配置文件配置log4j要更灵活。当前，配置文件内能写在XML或者以（key=value）格式写在java属性文件中。

让我们以一个想象的使用log4j的应用程序MyApp感受一下这是怎么做的：

 

import com.foo.Bar;

 // Import log4j classes.
 import org.apache.log4j.Logger;
 import org.apache.log4j.BasicConfigurator;

 public class MyApp {

   // Define a static logger variable so that it references the
   // Logger instance named "MyApp".
   static Logger logger = Logger.getLogger(MyApp.class);

   public static void main(String[] args) {

     // Set up a simple configuration that logs on the console.
     BasicConfigurator.configure();

     logger.info("Entering application.");
     Bar bar = new Bar();
     bar.doIt();
     logger.info("Exiting application.");
   }
 }

  

 

MyApp开始引入log4j相关的类。然后定义了一个名为MyApp的静态的logger变量，正好是类的全名。

MyApp使用com.foo包中定义的Bar类。

 

package com.foo;
 import org.apache.log4j.Logger;

 public class Bar {
   static Logger logger = Logger.getLogger(Bar.class);

   public void doIt() {
     logger.debug("Did it again!");
   }
 }

 

调用BasicConfigurator.configure方法创建了一个相当简单的log4j设置。这个方法给根logger添加了一个ConsoleAppender。PatternLayout将会被设置为"%-4r [%t] %-5p %c %x - %m%n"，并以此格式化输出。

注意，默认情况下根logger的级别为Level.DEBUG。

MyApp的输出为:

0    [main] INFO  MyApp  - Entering application.
36   [main] DEBUG com.foo.Bar  - Did it again!
51   [main] INFO  MyApp  - Exiting application.

下图描述了MyApp调用BasicConfigurator.configure方法之后的对象图：

 

作为附注，log4j中子logger只连接到存在的ancestor。具体来说，loggercom.foo.Bar直接连接到根logger，因此避免了没有用到的com或者com.foologger。这极大地提升了性能，降低了log4j的内存耗费。

MyApp通过调用BasicConfigurator.configure方法配置log4j。其他类只需要导入org.apache.log4j.Logger类，检索他们需要使用的logger。

前一个例子总是输出相同的日志信息。幸运的是，修改MyApp很容易，日志输出能够在运行时控制。这是一个稍微修改的版本：

 

import com.foo.Bar;

 import org.apache.log4j.Logger;
 import org.apache.log4j.PropertyConfigurator;

 public class MyApp {

   static Logger logger = Logger.getLogger(MyApp.class.getName());

   public static void main(String[] args) {


     // BasicConfigurator replaced with PropertyConfigurator.
     PropertyConfigurator.configure(args[0]);

     logger.info("Entering application.");
     Bar bar = new Bar();
     bar.doIt();
     logger.info("Exiting application.");
   }
 }

 

 

这个版本的MyApp指令PropertyConfigurator解析一个配置文件并相应地设置日志。

这是一个简单的配置文件，可以产生和前一个基于BasicConfigurator的例子完全相同的输出。

 

# Set root logger level to DEBUG and its only appender to A1.
log4j.rootLogger=DEBUG, A1

# A1 is set to be a ConsoleAppender.
log4j.appender.A1=org.apache.log4j.ConsoleAppender

# A1 uses PatternLayout.
log4j.appender.A1.layout=org.apache.log4j.PatternLayout
log4j.appender.A1.layout.ConversionPattern=%-4r [%t] %-5p %c %x - %m%n

 

 

<!-- <p>请注意如果你复制和粘贴着两个例子，某些行结尾很可能包含一些空格。这些空格没有被截断，并被dPropertyConfigurator解析。在你阅读本文时，问题应该已经改正了.-->

假设我们不想看见属于com.foo包的任何组件的输出，如下配置文件展示了一种可行的方式：.

 

log4j.rootLogger=DEBUG, A1
log4j.appender.A1=org.apache.log4j.ConsoleAppender
log4j.appender.A1.layout=org.apache.log4j.PatternLayout

# Print the date in ISO 8601 format
log4j.appender.A1.layout.ConversionPattern=%d [%t] %-5p %c - %m%n

# Print only messages of level WARN or above in the package com.foo.
log4j.logger.com.foo=WARN

 

 

用这个文件配置的MyApp的输出如下：

2000-09-07 14:07:41,508 [main] INFO  MyApp - Entering application.
2000-09-07 14:07:41,529 [main] INFO  MyApp - Exiting application.

com.foo.Bar logger并没有赋予级别，它从com.foo继承级别，在配置文件中设为了WARN。Bar.doIt方法的日志语句基本为DEBUG，比logger级别低，从而doIt()方法的记录日志请求被压制了。

以下是使用多个appender的另外一份配置文件：

 

log4j.rootLogger=debug, stdout, R

log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout

# Pattern to output the caller's file name and line number.
log4j.appender.stdout.layout.ConversionPattern=%5p [%t] (%F:%L) - %m%n

log4j.appender.R=org.apache.log4j.RollingFileAppender
log4j.appender.R.File=example.log

log4j.appender.R.MaxFileSize=100KB
# Keep one backup file
log4j.appender.R.MaxBackupIndex=1

log4j.appender.R.layout=org.apache.log4j.PatternLayout
log4j.appender.R.layout.ConversionPattern=%p %t %c - %m%n

 

 

调用升级之后使用这个配置文件的MyApp将会在控制台输出如下内容：

 INFO [main] (MyApp2.java:12) - Entering application.
DEBUG [main] (Bar.java:8) - Doing it again!
 INFO [main] (MyApp2.java:15) - Exiting application.

另外，根logger分配了另外一个appender，输出内容将会被写进example.log文件。当文件达到100KB时，再从文件开头开始写。原来的example.log中的内容自动移到了example.log.1。

注意为了获得这两种不同的记录日志行为，我们不需要重新编译代码。我们能同样简单地往UNIX Syslog守护进程里写记录日志，将所有的com.foo输出到NT事件logger，或者将记录日志事件发送到一个log4j的远程服务器。服务器将根据本地服务器policy记录日志，比如将记录日志事件转发到第二个log4j服务器。

默认的初始化过程

log4j环境没有默认设置。具体地，没有默认的log4j appender。但是在某些定义好的环境下，Logger类的静态初始化器会尝试自动配置log4j。Java语言保证了一个类的静态初始化器有且只在类加载到内存中时调用一次。记住不同的类加载器会加载同一个类的不同的副本也很重要。JVM认为这些副本完全不相关。当应用程序的确切入口点依赖于运行时环境时，默认的初始化非常有用。例如，同一个应用程序能用作单个应用，applet或者web服务器控制的servlet。

确切的默认初始化算法定义如下：

1. 将系统属性log4j.defaultInitOverride设置为"false"以外的其他值会让log4j跳过默认的初始化过程。
2. 将字符串变量resource的值设为系统属性log4j.configuration的值。最好的方式指定默认的初始化文件是使用系统属性log4j.configuration。万一log4j.configuration没有定义，就设置resource为默认值"log4j.properties"。
3. 尝试将resource转换为URL。
4. 如果不能转换，比方因为MalformedURLException，就调用返回URL的org.apache.log4j.helpers.Loader.getResource(resource, Logger.class)在类路径上搜寻resource。注意"log4j.properties"是一个格式错误的URL。搜索地址见Loader.getResource(java.lang.String)。
5. 如果找不到URL，放弃默认初始化。否则根据这个URL配置log4j。

   PropertyConfigurator将被用于解析URL以配置log4j，如果URL以".xml"的扩展名结尾，就使用DOMConfigurator。你可以选择一个自定义的配置器。系统属性log4j.configuratorClass的值作为你自定义的配置器的完整类名。你指定的自定义配置器必须实现Configurator接口。

配置示例

Tomcat下的默认初始化

log4j的默认初始化在web服务器环境下尤其有用。在Tomcat 3.x and 4.x中，你应该把log4j.properties放在WEB-INF/classes目录下。 Log4j将会找到属性文件并初始化自己。这很简单并且奏效。

你也可以选择在启动Tomcat之前设置系统属性log4j.configuration。对于Tomcat 3.x 环境变量TOMCAT_OPTS用于设置命令行选项。对于Tomcat 4.0，设置环境变量CATALINA_OPTS而不是TOMCAT_OPTS。

例1

Unix shell命令

   export TOMCAT_OPTS="-Dlog4j.configuration=foobar.txt"

让log4j使用foobar.txt文件作为默认的配置文件。这个文件应该放在WEB-INF/classes目录下。PropertyConfigurator将会读取这个文件。每一个web应用程序将会使用不同的配置文件，因为每一个配置文件与一个web应用程序相关联。

例2

Unix shell命令

   export TOMCAT_OPTS="-Dlog4j.debug -Dlog4j.configuration=foobar.xml"

让log4j输出其内部的调试信息，使用foobar.xml文件作为默认的配置文件。这个文件必须放在WEB-INF/classes目录下。既然文件的扩展名是.xml，DOMConfigurator将会读取这个文件。每一个web应用程序将会使用不同的配置文件，因为每一个配置文件与一个web应用程序相关联。

例 3

Windows shell命令

   set TOMCAT_OPTS=-Dlog4j.configuration=foobar.lcf -Dlog4j.configuratorClass=com.foo.BarConfigurator 

让log4j使用foobar.lcf文件作为默认的配置文件。这个文件必须放在WEB-INF/classes目录下。因为定义了系统属性log4j.configuratorClass，自定义配置器com.foo.BarConfigurator将会读取这个文件。每一个web应用程序将会使用不同的配置文件，因为每一个配置文件与一个web应用程序相关联。

例 4

Windows shell命令

   set TOMCAT_OPTS=-Dlog4j.configuration=file:/c:/foobar.lcf

让log4j使用c:\foobar.lcf文件作为默认的配置文件。URLfile:/c:/foobar.lcf完全指定了这个文件。因此，所有的 web应用程序使用同一份配置文件。

不同的web应用程序通过它们各自的类加载器加载log4j类。因此，log4j环境的每一个镜像会独立的运作，互相之间没有同步。比如，在多个web应用程序配置中定义的完全一样的FileAppenders都会尝试写同一份文件。结果肯定不令人满意。必须确保不同web应用程序的log4j配置不使用同一个系统资源。

初始化servlet

使用特别的servlet初始化log4j也是可行的。下例：

 

package com.foo;

import org.apache.log4j.PropertyConfigurator;
import javax.servlet.http.HttpServlet;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.io.PrintWriter;
import java.io.IOException;

public class Log4jInit extends HttpServlet {

  public
  void init() {
    String prefix =  getServletContext().getRealPath("/");
    String file = getInitParameter("log4j-init-file");
    // if the log4j-init-file is not set, then no point in trying
    if(file != null) {
      PropertyConfigurator.configure(prefix+file);
    }
  }

  public
  void doGet(HttpServletRequest req, HttpServletResponse res) {
  }
}

 在web.xml中定义如下的servlet

<servlet>
    <servlet-name>log4j-init</servlet-name>
    <servlet-class>com.foo.Log4jInit</servlet-class>

    <init-param>
      <param-name>log4j-init-file</param-name>
      <param-value>WEB-INF/classes/log4j.lcf</param-value>
    </init-param>

    <load-on-startup>1</load-on-startup>
  </servlet>

 大多数真实系统不得不同时与多个客户端打交道。在这种系统的典型多线程实现中，不同的线程处理不同的客户端。日志记录尤其适合于追踪和调试复杂的分布式应用程序。为每一个客户端实例化一个分开的logger是区分不同客户端日志输出的常用方法。这促进了logger的扩散，增加了管理日志的开销。

一个轻量的技巧是给同一个客户交互发起的每一个记录日志请求盖上惟一的戳。Neil Harrison在Pattern Languages of Program Design 3"记录诊断信息的模式,"中描述了这个方法，R. Martin, D. Riehle, and F. Buschmann编辑(Addison-Wesley, 1997)。

为每一个请求盖上惟一的戳，用户将上下文信息推送到NDC，Nested Diagnostic Context的缩写。NDC如下：

  public class NDC {
    // Used when printing the diagnostic
    public static String get();

    // Remove the top of the context from the NDC.
    public static String pop();

    // Add diagnostic context for the current thread.
    public static void push(String message);

    // Remove the diagnostic context for this thread.
    public static void remove();
  }

每个线程管理一个NDC作为上下文信息栈。注意org.apache.log4j.NDC类的所有方法都是静态的。假设NDC打印是开启的，每次有记录日志请求，log4j相关的组件将会在当前线程的日志输出中包含整个NDC栈。这不需要用户干预，用户只需要在代码中一些定义好的地方使用push和pop方法将正确的信息放在NDC。然而，这种每一个客户端一个logger的方法要求代码做大面积的改动。

为了说明这一点，让我们以servlet向无数客户端发送内容为例。servlet能在请求最开始构建NDC，然后执行其他代码。上下文信息可以是客户端的主机名和其他请求固有的信息，典型的是cookie中包含的信息。因此，即使servlet同时服务多个客户端，同一段代码生成的日志，即同一个logger的，仍然能够区分，因为每一个客户端请求有一个不同的NDC栈。

不管怎样，一些复杂的应用程序，像虚拟主机web服务器，必须根据虚拟主机上下文和发出请求的软件组件记录不同的日志。最近发布的log4j支持多个层次结构树。这种改进让每一个虚拟主机能处理自己的logger层级结构副本。

性能

对记录日志不利的经常引用的论据是计算成本。这是一个合理的担忧，因为即使中等规模的应用程序也会产生成千上万行日志请求信息。测量和调整日志性能耗费了太多精力。Log4j声称是快速和可扩展的：速度优先，灵活其次。

用户必须考虑到一下性能问题：

1. 当记录日志关闭之后的记录日志性能
   

   当记录日志完全关闭或只是关闭某些级别，一个记录日志请求的开销包括一个方法的调用和一个整数的比较。在233兆赫兹的Pentium II机器上，一个开销一般是5到50十亿分之一秒。

   但是，这个方法调用涉及到了隐藏着的参数构造开销。

   例如，logger cat写到：

        logger.debug("Entry number: " + i + " is " + String.valueOf(entry[i]));
       

   承担了构造消息参数的开销，即整型值i和entry[i]转换为String并将这些中间字符串拼接起来，不管这些消息是否会记录。参数构造的开销可能非常高，这取决于涉及到的参数的大小。

   为了避免参数构造的开销，

         if(logger.isDebugEnabled() {
           logger.debug("Entry number: " + i + " is " + String.valueOf(entry[i]));
         }
      

   如果禁用了debug，就不会有参数构造的开销。另一方面，如果logger启用了debug，这将导致2倍的评估logger是否启用的开销：一次在debugEnabled，另一次在debug。这个开销非常重要因为评估一个logger是否启用所花的时间为实际上记录日志的1%。

   在log4j中，记录日志请求发送给了Logger类的实例。Logger是个类不是接口，牺牲一定的灵活性适当地降低了方法调用的开销。

   一些用户依赖预处理和编译时技术编译出所有的日志语句。这取得了完美的记录日志性能效率。但是， 既然产生的二进制应用程序不包含任何的日志语句，就不能开启日志。我认为，为了获取一个小小的性能提升，这个代价是不对称的。

2. 开启记录日志之后决定是否记录日志的性能
   

   本质上这是遍历logger层次结构的性能。当记录日志开启之后，log4j仍然需要比较记录日志请求的级别和发送请求的logger的级别。但是，logger没有赋予级别；它们从层次结构中继承级别。因此，它需要在它的祖先中搜索。

   这个搜索必须越快越好。比如，子logger只连接到它的存在的祖先。在BasicConfigurator的例子中，com.foo.Bar logger直接连接到根logger，因此绕过了不存在的com和com.foo logger。这极大地提升了遍历的性能，尤其是在稀疏的层级结构中。

3. 实际输出日志消息
   

   这是格式化日志输出并发送到目的地的开销。这里再次尽极大的努力使layouts越快越好。这对appender同样适用。记录日志事实上的开销大约是100到300微秒。

   实际的数据见org.apache.log4.performance.Logging。

尽管log4j的特性很多，速度是它的首要的设计目标。为了提升性能，一些log4j组件已经被重写了很多次。不管怎样，使用SimpleLayout配置时，性能测试表明log4j和System.out.println一样快。

结论

Log4j是一个用Java写的流行的记录日志的包。它的特点之一就是logger的继承。使用logger的层次结构， 可以在任何粒度控制哪些日志语句别输出。这使输出的量减少了，最小化了记录日志的成本。log4j API的优势之一是它的管理性。一旦日志语句插入到代码中，可以使用配置文件控制它们。可以选择性地启用和禁用它们并以用户选择的格式发送到多个不同的输出目标。