内容


log4j提供了对日志记录的控制

开放源码 log4j API for Java 提供了快速有效的日志记录服务

Comments

几乎每个大的应用程序都包括其自己的日志记录或跟踪 API。经验表明日志记录是开发周期中的重要组成部分。同样,日志记录提供一些优点。首先,它可以提供运行应用程序的确切 上下文。一旦插入到代码中,生成日志记录输出就不需要人为干涉。其次,日志输出可以保存到永久媒体中以便以后研究。最后,除了在开发阶段中使用,十分丰富的日志记录包还可以用作审计工具。

依照该规则,在 1996 年初,EU SEMPER(欧洲安全电子市场)项目就决定编写自己的跟踪 API。在无数次改进、几次具体化和许多工作之后,该 API 已经演变成 log4j,一种流行的 Java 日志记录包。这个包按 IBM 公共许可证分发,由开放源码权威机构认证。

日志记录有其自己的缺点。它会降低应用程序的速度。如果太详细,它可能会使屏幕滚动变得看不见。为了减低这些影响,log4j 被设计成快速且灵活的。由于应用程序很少将日志记录当作是主要功能,log4j API 力争易于了解和使用。

本文从描述 log4j 体系结构的主要组件着手。然后是描述基本用法和配置的简单示例。最后通过讨论性能问题和 Sun 即将推出的日志记录 API 作为总结。

类别、附加目的地和布局

log4j 有三个主要组件:

  • 类别
  • 附加目的地
  • 布局

这三个组件共同合作,使开发者可以根据消息类型和优先级记录消息,并在运行时控制如何格式化消息以及在哪里报告消息。让我们依次研究它们。

类别层次结构

任何日志记录 API 超出纯 System.out.println 的最大优点是它可以禁用某些日志语句而允许其它语句顺利打印。该功能假设日志记录空间,即所有可能的日志记录语句的空间,按开发者选择的标准分类。

根据观察, org.log4j.Category 类是软件包的核心。类别是具有名称的实体。在 Java 开发者熟悉的命名方案中,如果类别的名称(后面加一个点)是其子类别名称的前缀,则它就是另一个类别的父代。例如,类别 com.foo 是类别 com.foo.Bar 的父代。同样, javajava.util 的父代,是 java.util.Vector 的祖辈。

根类别(在类别层次结构的顶部)有两种例外情况:

  1. 始终存在
  2. 不能按名称检索

Category 类中,调用静态 getRoot() 方法将检索根类别。静态 getInstance() 方法将实例化所有其它类别。 getInstance() 采用所期望类别的名称作为参数。下面列出了 Category 类中的一些基本方法:

package org.log4j;
public Category class {
   // Creation & retrieval methods:
   public static Category getRoot();
   public static Category getInstance(String name);
   // printing methods:
   public void debug(String message);
   public void info(String message);
   public void warn(String message);
   public void error(String message);
   // generic printing method:
   public void log(Priority p, String message);
}

可能org.log4j.Priority 类定义的集合中指定类别的优先级。虽然优先级集合与 Unix Syslog 系统的优先级集合匹配,log4j 仍建议只使用四个优先级,它们从高到低依次是 ERROR、WARN、INFO 和 DEBUG。这个集合看上去很严格,其基本原理是建立一个更灵活的类别层次结构,而不是静态的优先级集合(即使很大)。但是,您可以通过定义 Priority 类的子类来定义自己的优先级。如果某给定的类别没有指定的优先级,那么它将从其最接近的祖先处继承一个已指定优先级。同样,为确保所有类别最终都能继承优先级,根类别永远都有指定的优先级。

为生成日志记录请求,需调用类别实例的一个打印方法。那些打印方法是:

  • error()
  • warn()
  • info()
  • debug()
  • log()

根据定义,打印方法确定日志记录请求的优先级。例如,如果 c 是一个类别实例,那么 c.info("..") 语句就是一个优先级为 INFO 的日志记录请求。

如果日志记录请求的优先级高于或等于其类别的优先级,那么就称该日志记录请求为 启用的。否则,该请求就称做 禁用的。没有指定优先级的类别将从层次结构中继承一个优先级。

下面,可以找到该规则的一个示例:

// get a category instance named "com.foo"
Category cat = Category.getInstance("com.foo");
// Now set its priority.
cat.setPriority(Priority.INFO);
Category barcat = Category.getInstance("com.foo.Bar");
// This request is enabled, because WARN >= INFO.
cat.warn("Low fuel level.");
// This request is disabled, because DEBUG < INFO.
cat.debug("Starting search for nearest gas station.");
// The category instance barcat, named "com.foo.Bar",
// will inherit its priority from the category named
// "com.foo" Thus, the following request is enabled
// because INFO >= INFO.
barcat.info("Located nearest gas station.");
// This request is disabled, because DEBUG < INFO.
barcat.debug("Exiting gas station search");

用相同的名称调用 getInstance() 方法将始终返回对完全同名的类别对象的引用。所以,可以配置一个类别,然后在代码的其它位置检索同一个实例而不必传送引用。可以按任何顺序创建和配置类别。特别是,即使父代类别在其子代后实例化,但它可以查找并链接其子代。log4j 环境通常在应用程序初始化时配置,最好是通过读取配置文件来进行配置,我们将简要讨论该方法。

log4j 使根据 软件组件 来命名类别变得更容易。有一种实用且简单的方法可以定义类别,即在每个类中,使用与类全限定名相等的类别名称来静态实例化类别。由于日志输出给出了生成类别的名称,这种命名策略易于标识消息的来源。虽然常用,但这只是一种可能的命名类别策略。log4j 不限制可能的类别集合。开发者甚至可以随意命名类别。

附加目的地和布局

可以根据类别有选择性地启用或禁用日志记录请求只是一部分功能。log4j 还允许日志记录请求打印到多个输出目的地,按 log4j 的叫法是 附加目的地 。当前附加目的地可以是控制台、文件、GUI 组件、远程套接字服务器、NT 事件记录器和远程 UNIX Syslog 守护程序。

一个类别可以引用多个附加目的地。给定类别的每个启用的日志记录请求将转发到该类别的所有附加目的地,以及层次结构中更高级的附加目的地。换句话说,可以从类别层次结构附加继承附加目的地。例如,类别将控制台附加目的地添加到根类别,则所有启用的日志记录请求都将至少打印到控制台。另外,如果将文件附加目的地添加到类别 C,那么 CC 的子代所启用的日志记录请求将打印到文件和控制台。请注意,可以覆盖缺省行为,这样就不再附加累积的附加目的地。

通常,用户不仅要定制输出目的地,而且要定制输出格式,这可以通过将 布局 与附加目的地相关联来实现。布局根据用户的希望格式化日志记录请求,附加目的地负责将格式化的输出发送到目的地。 PatternLayout (标准 log4j 发行版的部件)让用户根据类似于 C 语言 printf 函数的转换模式来指定输出格式。

例如,转换模式为 %r [%t]%-5p %c - %m%nPatternLayout 将生成类似于以下内容的输出:

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

在以上的输出中:

  • 第一个字段等于自程序开始后消耗的毫秒数
  • 第二个字段表示日志记录请求生成的线程
  • 第三个字段表示日志语句的优先级
  • 第四个字段等于与日志请求相关的类别名称

- 后的文本表示语句的消息。

配置

将日志请求插入应用程序代码需要一定的计划和努力。观察显示用于日志记录的代码大约占应用程序全部的 4%。因此,中等规模的应用程序会有上千条日志记录语句嵌入代码中。由于它们的数量巨大,因此必须管理那些日志语句,但不必手工修改它们。

完全可以由程序来配置 log4j 环境。但是,使用配置文件配置 log4j 会更灵活。当前,可以用 XML 或 Java 特性(键=值)格式来编写配置文件。

在使用 log4j 的虚构应用程序 MyApp 的帮助下,让我们感受这是如何完成的:

 import com.foo.Bar;
 // Import log4j classes.
 import org.log4j.Category;
 import org.log4j.BasicConfigurator;
 public class MyApp {
   // Define a static category variable so that it references the
   // Category instance named "MyApp".
   static Category cat = Category.getInstance(MyApp.class.getName());
   public static void main(String[] args) {
     // Set up a simple configuration that logs on the console.
     BasicConfigurator.configure();
     cat.info("Entering application.");
     Bar bar = new Bar();
     bar.doIt();
     cat.info("Exiting application.");
   }
 }

在以上代码中可以看到, MyApp 一开始就导入 log4j 相关的类。然后定义名为 MyApp 的静态类别变量,该名称恰好是类的全限定名。

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

 package com.foo;
 import org.log4j.Category;
 public class Bar {
   static Category cat = Category.getInstance(Bar.class.getName());
   public void doIt() {
     cat.debug("Did it again!");
   }
 }

MyApp 中,对 BasicConfigurator.configure() 方法的调用创建了一个更简单的 log4j 设置。该方法被强制添加到根类别,即 FileAppender 打印到控制台。通过将 PatternLayout 设置成模式 %-4r [%t] %-5p %c %x - %m%n 来格式化输出。

请注意,缺省情况下,将 Priority.DEBUG 分配给根类别。

MyApp 的输出是:

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

图 1 描述了 MyApp 调用 BasicConfigurator.configure() 方法之后的对象图表。

图 1. MyApp 调用 BasicConfigurator.configure() 方法之后的对象图表
MyApp 调用 BasicConfigurator.configure() 方法之后的对象图表
MyApp 调用 BasicConfigurator.configure() 方法之后的对象图表

MyApp 类通过调用 BasicConfigurator.configure() 方法来配置 log4j。其它类只需要导入 org.log4j.Category 类,检索它们要使用的类别,并记录日志。

上例始终输出相同的日志信息。幸好,修改 MyApp 很容易,所以可以在运行时控制日志输出。接着,将看到稍作修改的版本:

 import com.foo.Bar;
 import org.log4j.Category;
 import org.log4j.PropertyConfigurator;
 public class MyApp {
   static Category cat = Category.getInstance(MyApp.class.getName());
  public static void main(String[] args) {
     // BasicConfigurator replaced with PropertyConfigurator.
     PropertyConfigurator.configure(args[0]);
     cat.info("Entering application.");
     Bar bar = new Bar();
     bar.doIt();
     cat.info("Exiting application.");
   }

这个版本的 MyApp 指示 PropertyConfigurator 分析配置文件,并相应设置日志记录。

让我们查看一个样本配置,它生成的输出与前面基于 BasicConfigurator 的示例的输出相同:

# Set root category priority to DEBUG and its only appender to A1.
log4j.rootCategory=DEBUG, A1
# A1 is set to be a FileAppender which outputs to System.out.
log4j.appender.A1=org.log4j.FileAppender
log4j.appender.A1.File=System.out
# A1 uses PatternLayout.
log4j.appender.A1.layout=org.log4j.PatternLayout
log4j.appender.A1.layout.ConversionPattern=%-4r [%t] %-5p %c %x - %m%n

假设我们不想再看到任何属于 com.foo 包的组件的输出。以下的配置文件显示了一种可行方法:

log4j.rootCategory=DEBUG, A1
log4j.appender.A1=org.log4j.FileAppender
log4j.appender.A1.File=System.out
log4j.appender.A1.layout=org.log4j.PatternLayout
# Print the date in ISO 8601 format
log4j.appender.A1.layout.ConversionPattern=%d [%t] %-5p %c - %m%n
# Print only messages of priority WARN or above in the package com.foo.
log4j.category.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 没有指定的优先级,它从 com.foo (在配置文件中其优先级设置成 WARN ) 继承优先级。 Bar.doIt() 方法中日志语句的优先级是 DEBUG ,低于类别优先级 WARN 。因此,抑制了 doIt() 的日志请求。

接着,我们将看到另一个使用多个附加目的地的配置文件:

log4j.rootCategory=debug, stdout, R
log4j.appender.stdout=org.log4j.FileAppender
log4j.appender.stdout.File=System.out
log4j.appender.stdout.layout=org.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.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.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.

另外,因为已经给根类别分配了第二个附加目的地,输出将定向到 example.log 文件。当该文件达到 100 KB 时,将把它转滚。发生转滚时,旧版本的 example.log 自动移到 example.log.1

请注意,要获取不同的日志记录行为,不需要重新编译代码。只需要将日志记录到 UNIX Syslog 守护程序,然后将所有 com.foo 输出重定向到 NT 事件记录器。同样,可以将日志记录事件转发到远程 log4j 服务器,它将根据本地服务器策略记录日志 -- 例如,将日志记录到本地文件,并将日志事件转发到第二个 log4j 服务器。

嵌套式诊断环境

大多数实际系统必须同步处理多个客户机。通常这种系统在实现多线程时,不同的线程将处理不同的客户机。鉴于此,日志记录特别适合跟踪和调试复杂的分布式应用程序。区分两个客户机的日志输出的常用方法是单独为每个客户机实例化新类别。但是,该方法会增加类别数量,并增加日志记录的管理开销。

Neil Harrison(请参阅 参考资料 )想出了一个简便方法,可以唯一标记从同一个客户机交互启动的每一个日志记录请求。要唯一标记每个请求,用户要将上下文信息放到嵌套式诊断环境 (NDC) 中。下面显示了 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.log4j.NDC 的方法都静态是的。假设已打开了 NDC 打印,每次发送日志请求时,适当的 log4j 组件会将当前线程的 整个 NDC 堆栈包括到请求输出中。这一操作无须用户介入,用户只需通过在代码的一些位置使用 push()pop() 方法将正确信息放入 NDC。与之相反,每个客户机类别方法需要代码的重大更改。

为说明这点,我们将讨论 Servlet 将内容分发到众多客户机的示例。Servlet 可以在执行其它代码之前,在请求开头构建 NDC。上下文信息可以是客户机的主机名和请求内部的其它信息,通常是 cookie 中包含的信息。因此,即使 Servlet 同步处理多个客户机,仍可以区分由同一个代码(即属于同一个类别)启动的日志,因为每个客户机请求有不同的 NDC 堆栈。请将它与以下操作的复杂程度做比较:将刚实例化的类别传递到所有在客户机请求期间执行的代码。

不过,某些复杂的应用程序,如虚拟主机 Web 服务器,必须根据虚拟主机上下文和发出请求的软件组件,单独记录日志。最新的 log4j 发行版支持多层次结构树,并允许每个虚拟主机处理自己的类别层次结构副本。

性能

日志记录经常会引起的一个争论,即它的计算开销。这是很正常的事,因为中等规模的应用程序可能生成上千个日志请求。大量精力花在测量和调整日志记录性能上。log4j 自称是快速和灵活的:首先是速度,其次才是灵活性。

但是,用户应该注意以下性能问题:

  1. 当关闭日志记录时,日志记录的性能。

    当完全关闭日志记录或者对于一组优先级关闭了日志记录时,日志请求的开销就是方法调用加上整数比较。方法调用涉及隐藏的参数结构开销。

    对于某个类别 cat ,编写

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

    会产生构造消息参数的开销,即无论是否记录消息,都会将整数 ientry[i] 转换成字符串,然后并置中间字符串。

    如果某人为速度担心,编写了:

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

    如果禁用了调试,那么这不会产生参数构造开销。另一方面,如果启用调试类别,则将产生两倍的估计是否启用该类别的开销:一次是 debugEnabled() ,另一次是 debug() 。总开销并不大,因为估计类别所耗费的时间只占实际记录的 1%。

    在 log4j 中,将对 Category 类的实例发送日志记录请求。因为 Category 是一个类,而不是接口,所以方法调用的开销很低,开销主要集中在灵活性上。

    在 233 MHz Pentium II 机器上,日志记录关闭时,日志记录的一般开销在 5 到 50 纳秒(十亿分之一秒)之间。

  2. 当打开日志记录时,决定是否记录的性能。

    在该方案中,问题集中在遍历类别层次结构的性能开销上。当打开日志记录时,log4j 仍需要将日志请求的优先级与请求类别的优先级作比较。但是,类别可能没有指定的优先级;它们可以从类别层次结构中继承优先级。于是,为了找到优先级,类别可能需要搜索它的祖辈。

    对于尽快遍历层次结构,已经取得了重大成就。例如,子类别只链接到它们现有的祖辈。在前面显示的 BasicConfigurator 示例中,类别 com.foo.Bar 直接链接到根类别,因此避开了不存在的 comcom.foo 类别,大大将提高遍历的速度,特别是在稀疏的层次结构中。

    在 233 MHz Pentium II 机器上,遍历层次结构的一般开销在 5 到 15 微秒之间。

  3. 实际的日志记录。

    格式化日志输出并将它发送到目标目的地的开销引出了另一个性能问题。同样,尽快提高布局(格式化器)的执行速度也取得了重大成就。对于附加目的地也是如此。实际日志记录的一般开销在 100 到 300 微秒之间。

尽管 log4j 有许多特性,但它的设计目标首先是速度。某些 log4j 组件已重写了多次,以提高性能。不过,研究人员经常会提出新的优化方案。

Sun 即将推出的日志记录 API

Sun 已经发起了 Java Community Process (JCP) 中的 JSR47 来为 Java 定义一个日志记录 API。生成的 API 需要 JDK 版本 1.4,并且很快就能够接受公开评审。

就体系结构而言,JSR47 API 和 log4j 非常相似。JSR47 API 支持分层的名称空间,而这正是 log4j 的主要特性。另一方面,log4j 拥有许多 JSR47 没有的特性。我的观点是,由于 log4j 的推动,JSR47 可能在推出时就已过时了。log4j 由使用它的人编写,而不是封闭的委员会。

顺便提一下,log4j 已经提供了桥接到 JSR47 API的支持,只要 JSR47 API 可用。

我还要提一下 JLog,它是 IBM alphaWorks 开发的另一种日志记录 API。在 IBM 对它重命名之前,JLog 叫作 RAS Toolkit。在 alphaWorks 站点上,JLog 的标签是“Logging Toolkit for Java”,这几乎与 log4j 迁移到 http://log4j.org 之前在 alphaWorks 上的标签相同。虽然 JLog 也是一种很好的日志记录包,但不应将它与 log4j 混淆。

结束语

log4j 是广泛使用的以 Java 编写的日志记录包。它的一个独有特性包括在类别中继承的概念。通过使用类别层次结构,它可以控制以任意间隔输出哪些日志语句,这样就减少了日志记录输出量,并将日志记录的开销降到最低。

log4j API 的一个优点是其易管理性。一旦将日志语句插入代码,就可以用配置文件控制它们。而且,可以选择性地启用或禁用它们,并以用户选择的格式将它们发送到多个不同的输出目标。此外,还设计了 log4j 包,这样日志语句可以保留在交付的代码中,并不会带来繁重的性能开销。

log4j 是集体努力的结果。我特别感谢所有为此项目做出贡献的作者。毫无例外,该软件包中最好的特性都来自用户社区。


相关主题


评论

添加或订阅评论,请先登录注册

static.content.url=http://www.ibm.com/developerworks/js/artrating/
SITE_ID=10
Zone=Java technology
ArticleID=52866
ArticleTitle=log4j提供了对日志记录的控制
publish-date=01012001