这是用户在 2025-6-6 16:40 为 https://logging.apache.org/log4j/1.x/manual.html 保存的双语快照页面,由 沉浸式翻译 提供双语支持。了解如何保存?


Log4j 2 荣获 JAX 创新大奖提名!

您是否喜欢它的高性能、无垃圾日志记录以及简单灵活的配置?

Log4j 2 需要你的支持。 为 Log4j 2 投票!

生命周期终止

2015 年 8 月 5 日,Logging 服务项目管理委员会宣布 Log4j 1.x 已终止生命周期。 公告全文请参阅 Apache 博客 。建议 Log4j 1 用户升级至 Apache Log4j 2

log4j 简介:Ceki Gülcü,2002 年 3 月

版权所有 © 2000-2002 阿帕奇软件基金会。保留所有权利。本软件根据阿帕奇软件许可证 2.0 版条款发布,该许可证副本已随 log4j 发行包附带的 LICENSE 文件中包含。本文档基于 2000 年 11 月期《JavaWorld》杂志发表的 "Log4j 实现日志记录控制" 一文编写。但当前文章包含更详细和最新的信息。本简短手册还引用了同一作者(即本人)所著 "log4j 完全手册 " 中的部分文字。

摘要

本文档介绍了 log4j API 的独特功能与设计原理。log4j 是一个基于众多开发者贡献的开源项目,它允许开发人员以任意粒度控制日志语句的输出,并支持通过外部配置文件在运行时进行完全配置。最重要的是,log4j 学习曲线平缓。但请注意:根据用户反馈,它还具有令人着迷的特性。

简介

几乎每个大型应用程序都包含自己的日志记录或跟踪 API。遵循这一惯例,欧盟 SEMPER 项目决定开发自己的跟踪 API。这发生在 1996 年初。经过无数次改进、多个版本迭代和大量工作后,该 API 最终演变为 log4j——一个流行的 Java 日志记录工具包。该软件包基于 Apache 软件许可证分发,这是一个经开源倡议认证的完整开源协议。最新版 log4j(包含完整源代码、类文件和文档)可在 http://logging.apache.org/log4j/ 获取。值得一提的是,log4j 已被移植到 C、C++、C#、Perl、Python、Ruby 和 Eiffel 等语言。

在代码中插入日志语句是一种低技术含量的调试方法。这也可能是唯一可行的方法,因为调试器并非总是可用或适用。这种情况通常出现在多线程应用和大规模分布式应用中。

经验表明,日志记录是开发周期中的重要组成部分。 它具有多项优势。它能提供应用程序运行的精确 上下文信息。一旦将日志代码插入程序中,生成日志输出就无需人工干预。此外,日志输出可以保存在持久化介质中供后续分析。除了在开发周期中使用外,功能足够丰富的日志记录包还可以被视为审计工具。

正如 Brian W. Kernighan 和 Rob Pike 在他们极好的著作《程序设计实践》中所言

  As personal choice, we tend not to use debuggers beyond getting a
  stack trace or the value of a variable or two. One reason is that it
  is easy to get lost in details of complicated data structures and
  control flow; we find stepping through a program less productive
  than thinking harder and adding output statements and self-checking
  code at critical places. Clicking over statements takes longer than
  scanning the output of judiciously-placed displays. It takes less
  time to decide where to put print statements than to single-step to
  the critical section of code, even assuming we know where that
  is. More important, debugging statements stay with the program;
  debugging sessions are transient.

日志记录确实有其缺点。它可能拖慢应用程序速度。如果过于冗长,会导致滚动盲视。为了缓解这些问题,log4j 被设计为可靠、快速且可扩展的。由于日志记录很少是应用程序的主要关注点,log4j API 力求简单易懂、易于使用。

日志记录器、输出源与布局

Log4j 包含三个主要组件:日志记录器、 附加器布局器 。这三种组件协同工作,使开发者能够根据消息类型和级别进行日志记录,并在运行时控制这些消息的格式化方式及其输出位置。

日志记录器层级体系

任何日志 API 相较于普通日志的首要优势 System.out.println 在于其能够禁用特定日志语句,同时允许其他日志不受阻碍地输出。这一功能的前提是:整个日志空间(即所有可能的日志语句集合)能够按照开发者设定的标准进行分类。这一特性曾促使我们选择分类作为该包的核心概念。但从 log4j 1.2 版本开始, Logger 类已取代 Category 类。对于熟悉 log4j 早期版本的用户, Logger 类可视为 Category 类的别名。

日志记录器是具名实体。其名称区分大小写,并遵循层次化命名规则:

命名层级
一个记录器被称为另一个记录器的祖先 如果其名称后加点号能构成后代记录器名称的前缀 该记录器即为其后代记录器。若两者之间不存在其他祖先记录器 则称该记录器为子记录器的父级 ,子记录器即为其子级

例如,名为 "com.foo" 的日志记录器是名为 "com.foo.Bar" 的日志记录器的父级。同样地, "java""java.util" 的父级,也是 "java.util.Vector" 的祖先级。这种命名方案对大多数开发者来说应该很熟悉。

根日志记录器位于日志记录器层次结构的顶端。它在两个方面具有特殊性:

  1. 它始终存在,
  2. 无法通过名称检索到它。

调用类的静态方法 Logger.getRootLogger 可以获取它。所有其他日志记录器都是通过类的静态方法 Logger.getLogger 实例化并获取的 该方法以所需记录器的名称作为 参数。Logger 类中的一些基本方法列在 下方。

  package org.apache.log4j;

  public class Logger {

    // Creation & retrieval methods:
    public static Logger getRootLogger();
    public static Logger getLogger(String name);

    // printing methods:
    public void trace(Object message);
    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);

    // generic printing method:
    public void log(Level l, Object message);
}

日志记录器可以被分配级别。可能的级别集合包括:

TRACE,
DEBUG,
INFO,
警告
错误以及
致命错误

这些级别定义在 org.apache.log4j.Level 类中。虽然我们不鼓励这样做,但您可以通过继承 Level 类来定义自己的级别。稍后将解释可能更好的方法。

如果某个记录器未被分配级别,则它会继承其最近被分配级别的祖先的级别。更正式地说:

级别继承

给定记录器的继承级别 C,等于从 C 开始沿记录器层次结构向上查找时遇到的第一个非空级别,直至根记录器 root

为确保所有记录器最终都能继承一个级别,根记录器始终具有一个已分配的级别。

以下是四张表格,展示了根据上述规则分配的不同级别值及其对应的继承级别结果。

示例 1
日志记录器
名称
已分配
级别
继承
级别
根记录器 Proot
X Proot
X.Y Proot
X.Y.Z Proot

在上面的示例1中,仅根记录器被分配了级别。这个级别值 Proot 会被其他记录器 XX.Y 继承 X.Y.Z .

示例2
日志记录器
名称
已分配
级别
继承
级别
根记录器 Proot
X 像素 像素
X.Y 像素 像素
X.Y.Z 像素 xyz Pxyz

在示例2中,所有记录器都分配了级别值,因此无需进行级别继承。

示例3
日志记录器
名称
已分配
级别
继承
级别
根记录器 Proot
X 像素 像素
X.Y 像素
X.Y.Z 像素 xyz Pxyz

在示例3中,日志记录器 rootXX.Y.Z 分别被分配了级别 ProotPxPxyz 。日志记录器 X.Y 从其父级继承了级别值 X .

Example 4
日志记录器
名称
已分配
级别
继承
级别
root Proot Proot
X Px Px
X.Y none Px
X.Y.Z none Px

In example 4, the loggers root and X and are assigned the levels Proot and Px respectively. The loggers X.Y and X.Y.Z inherits their level value from their nearest parent X having an assigned level..

Logging requests are made by invoking one of the printing methods of a logger instance. These printing methods are debug, info, warn, error, fatal and log.

By definition, the printing method determines the level of a logging request. For example, if c is a logger instance, then the statement c.info("..") is a logging request of level INFO.

A logging request is said to be enabled if its level is higher than or equal to the level of its logger. Otherwise, the request is said to be disabled. A logger without an assigned level will inherit one from the hierarchy. This rule is summarized below.

Basic Selection Rule

A log request of level p in a logger with (either assigned or inherited, whichever is appropriate) level q, is enabled if p >= q.

This rule is at the heart of log4j. It assumes that levels are ordered. For the standard levels, we have DEBUG < INFO < WARN < ERROR < FATAL.

Here is an example of this rule.

   // get a logger instance named "com.foo"
   Logger  logger = Logger.getLogger("com.foo");

   // Now set its level. Normally you do not need to set the
   // level of a logger programmatically. This is usually done
   // in configuration files.
   logger.setLevel(Level.INFO);

   Logger barlogger = Logger.getLogger("com.foo.Bar");

   // This request is enabled, because WARN >= INFO.
   logger.warn("Low fuel level.");

   // This request is disabled, because DEBUG < INFO.
   logger.debug("Starting search for nearest gas station.");

   // The logger instance barlogger, named "com.foo.Bar",
   // will inherit its level from the logger named
   // "com.foo" Thus, the following request is enabled
   // because INFO >= INFO.
   barlogger.info("Located nearest gas station.");

   // This request is disabled, because DEBUG < INFO.
   barlogger.debug("Exiting gas station search");

Calling the getLogger method with the same name will always return a reference to the exact same logger object.

For example, in

   Logger x = Logger.getLogger("wombat");
   Logger y = Logger.getLogger("wombat");
xy 指向完全相同的 日志记录器对象。

Thus, it is possible to configure a logger and then to retrieve the same instance somewhere else in the code without passing around references. In fundamental contradiction to biological parenthood, where parents always preceed their children, log4j loggers can be created and configured in any order. In particular, a "parent" logger will find and link to its descendants even if it is instantiated after them.

Configuration of the log4j environment is typically done at application initialization. The preferred way is by reading a configuration file. This approach will be discussed shortly.

Log4j makes it easy to name loggers by software component. This can be accomplished by statically instantiating a logger in each class, with the logger name equal to the fully qualified name of the class. This is a useful and straightforward method of defining loggers. As the log output bears the name of the generating logger, this naming strategy makes it easy to identify the origin of a log message. However, this is only one possible, albeit common, strategy for naming loggers. Log4j does not restrict the possible set of loggers. The developer is free to name the loggers as desired.

Nevertheless, naming loggers after the class where they are located seems to be the best strategy known so far.

Appenders and Layouts

The ability to selectively enable or disable logging requests based on their logger is only part of the picture. Log4j allows logging requests to print to multiple destinations. In log4j speak, an output destination is called an appender. Currently, appenders exist for the console, files, GUI components, remote socket servers, JMS, NT Event Loggers, and remote UNIX Syslog daemons. It is also possible to log asynchronously.

More than one appender can be attached to a logger.

The addAppender method adds an appender to a given logger. Each enabled logging request for a given logger will be forwarded to all the appenders in that logger as well as the appenders higher in the hierarchy. In other words, appenders are inherited additively from the logger hierarchy. For example, if a console appender is added to the root logger, then all enabled logging requests will at least print on the console. If in addition a file appender is added to a logger, say C, then enabled logging requests for C and C's children will print on a file and on the console. It is possible to override this default behavior so that appender accumulation is no longer additive by setting the additivity flag to false.

The rules governing appender additivity are summarized below.

Appender Additivity

The output of a log statement of logger C will go to all the appenders in C and its ancestors. This is the meaning of the term "appender additivity".

However, if an ancestor of logger C, say P, has the additivity flag set to false, then C's output will be directed to all the appenders in C and its ancestors upto and including P but not the appenders in any of the ancestors of P.

Loggers have their additivity flag set to true by default.

The table below shows an example:

Logger
Name
Added
Appenders
Additivity
Flag
Output Targets Comment
root A1 not applicable A1 The root logger is anonymous but can be accessed with the Logger.getRootLogger() method. There is no default appender attached to root.
x A-x1, A-x2 true A1, A-x1, A-x2 Appenders of "x" and root.
x.y none true A1, A-x1, A-x2 Appenders of "x" and root.
x.y.z A-xyz1 true A1, A-x1, A-x2, A-xyz1 Appenders in "x.y.z", "x" and root.
security A-sec false A-sec No appender accumulation since the additivity flag is set to false.
security.access none true A-sec Only appenders of "security" because the additivity flag in "security" is set to false.

More often than not, users wish to customize not only the output destination but also the output format. This is accomplished by associating a layout with an appender. The layout is responsible for formatting the logging request according to the user's wishes, whereas an appender takes care of sending the formatted output to its destination.

The PatternLayout, part of the standard log4j distribution, lets the user specify the output format according to conversion patterns similar to the C language printf function.

For example, the PatternLayout with the conversion pattern "%r [%t] %-5p %c - %m%n" will output something akin to:

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

The first field is the number of milliseconds elapsed since the start of the program. The second field is the thread making the log request. The third field is the level of the log statement. The fourth field is the name of the logger associated with the log request. The text after the '-' is the message of the statement.

Just as importantly, log4j will render the content of the log message according to user specified criteria. For example, if you frequently need to log Oranges, an object type used in your current project, then you can register an OrangeRenderer that will be invoked whenever an orange needs to be logged.

Object rendering follows the class hierarchy. For example, assuming oranges are fruits, if you register a FruitRenderer, all fruits including oranges will be rendered by the FruitRenderer, unless of course you registered an orange specific OrangeRenderer.

Object renderers have to implement the ObjectRenderer interface.

Configuration

Inserting log requests into the application code requires a fair amount of planning and effort. Observation shows that approximately 4 percent of code is dedicated to logging. Consequently, even moderately sized applications will have thousands of logging statements embedded within their code. Given their number, it becomes imperative to manage these log statements without the need to modify them manually.

The log4j environment is fully configurable programmatically. However, it is far more flexible to configure log4j using configuration files. Currently, configuration files can be written in XML or in Java properties (key=value) format.

Let us give a taste of how this is done with the help of an imaginary application MyApp that uses log4j.

 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 begins by importing log4j related classes. It then defines a static logger variable with the name MyApp which happens to be the fully qualified name of the class.

MyApp uses the Bar class defined in the package com.foo.

 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!");
   }
 }

The invocation of the BasicConfigurator.configure method creates a rather simple log4j setup. This method is hardwired to add to the root logger a ConsoleAppender. The output will be formatted using a PatternLayout set to the pattern "%-4r [%t] %-5p %c %x - %m%n".

Note that by default, the root logger is assigned to Level.DEBUG.

The output of MyApp is:

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

The figure below depicts the object diagram of MyApp after just having called the BasicConfigurator.configure method.

As a side note, let me mention that in log4j child loggers link only to their existing ancestors. In particular, the logger named com.foo.Bar is linked directly to the root logger, thereby circumventing the unused com or com.foo loggers. This significantly increases performance and reduces log4j's memory footprint.

The MyApp class configures log4j by invoking BasicConfigurator.configure method. Other classes only need to import the org.apache.log4j.Logger class, retrieve the loggers they wish to use, and log away.

The previous example always outputs the same log information. Fortunately, it is easy to modify MyApp so that the log output can be controlled at run-time. Here is a slightly modified version.

 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.");
   }
 }

This version of MyApp instructs PropertyConfigurator to parse a configuration file and set up logging accordingly.

Here is a sample configuration file that results in identical output as the previous BasicConfigurator based example.

# 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

Suppose we are no longer interested in seeing the output of any component belonging to the com.foo package. The following configuration file shows one possible way of achieving this.

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

The output of MyApp configured with this file is shown below.

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

As the logger com.foo.Bar does not have an assigned level, it inherits its level from com.foo, which was set to WARN in the configuration file. The log statement from the Bar.doIt method has the level DEBUG, lower than the logger level WARN. Consequently, doIt() method's log request is suppressed.

Here is another configuration file that uses multiple appenders.

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

Calling the enhanced MyApp with the this configuration file will output the following on the console.

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

In addition, as the root logger has been allocated a second appender, output will also be directed to the example.log file. This file will be rolled over when it reaches 100KB. When roll-over occurs, the old version of example.log is automatically moved to example.log.1.

Note that to obtain these different logging behaviors we did not need to recompile code. We could just as easily have logged to a UNIX Syslog daemon, redirected all com.foo output to an NT Event logger, or forwarded logging events to a remote log4j server, which would log according to local server policy, for example by forwarding the log event to a second log4j server.

Default Initialization Procedure

The log4j library does not make any assumptions about its environment. In particular, there are no default log4j appenders. Under certain well-defined circumstances however, the static inializer of the Logger class will attempt to automatically configure log4j. The Java language guarantees that the static initializer of a class is called once and only once during the loading of a class into memory. It is important to remember that different classloaders may load distinct copies of the same class. These copies of the same class are considered as totally unrelated by the JVM.

The default initialization is very useful in environments where the exact entry point to the application depends on the runtime environment. For example, the same application can be used as a stand-alone application, as an applet, or as a servlet under the control of a web-server.

The exact default initialization algorithm is defined as follows:

  1. Setting the log4j.defaultInitOverride system property to any other value then "false" will cause log4j to skip the default initialization procedure (this procedure).
  2. Set the resource string variable to the value of the log4j.configuration system property. The preferred way to specify the default initialization file is through the log4j.configuration system property. In case the system property log4j.configuration is not defined, then set the string variable resource to its default value "log4j.properties".
  3. Attempt to convert the resource variable to a URL.
  4. If the resource variable cannot be converted to a URL, for example due to a MalformedURLException, then search for the resource from the classpath by calling org.apache.log4j.helpers.Loader.getResource(resource, Logger.class) which returns a URL. Note that the string "log4j.properties" constitutes a malformed URL.

    See Loader.getResource(java.lang.String) for the list of searched locations.

  5. If no URL could not be found, abort default initialization. Otherwise, configure log4j from the URL.

    The PropertyConfigurator will be used to parse the URL to configure log4j unless the URL ends with the ".xml" extension, in which case the DOMConfigurator will be used. You can optionaly specify a custom configurator. The value of the log4j.configuratorClass system property is taken as the fully qualified class name of your custom configurator. The custom configurator you specify must implement the Configurator interface.

Example Configurations

Default Initialization under Tomcat

The default log4j initialization is particularly useful in web-server environments. Under Tomcat 3.x and 4.x, you should place the log4j.properties under the WEB-INF/classes directory of your web-applications. Log4j will find the properties file and initialize itself. This is easy to do and it works.

You can also choose to set the system property log4j.configuration before starting Tomcat. For Tomcat 3.x The TOMCAT_OPTS environment variable is used to set command line options. For Tomcat 4.0, set the CATALINA_OPTS environment variable instead of TOMCAT_OPTS.

Example 1

The Unix shell command

   export TOMCAT_OPTS="-Dlog4j.configuration=foobar.txt"
tells log4j to use the file foobar.txt as the default configuration file. This file should be place under the WEB-INF/classes directory of your web-application. The file will be read using the PropertyConfigurator. Each web-application will use a different default configuration file because each file is relative to a web-application.

Example 2

The Unix shell command

   export TOMCAT_OPTS="-Dlog4j.debug -Dlog4j.configuration=foobar.xml"
tells log4j to output log4j-internal debugging information and to use the file foobar.xml as the default configuration file. This file should be place under the WEB-INF/classes directory of your web-application. Since the file ends with a .xml extension, it will read using the DOMConfigurator. Each web-application will use a different default configuration file because each file is relative to a web-application.

Example 3

The Windows shell command

   set TOMCAT_OPTS=-Dlog4j.configuration=foobar.lcf -Dlog4j.configuratorClass=com.foo.BarConfigurator
tells log4j to use the file foobar.lcf as the default configuration file. This file should be place under the WEB-INF/classes directory of your web-application. Due to the definition of the log4j.configuratorClass system property, the file will be read using the com.foo.BarConfigurator custom configurator. Each web-application will use a different default configuration file because each file is relative to a web-application.

Example 4

The Windows shell command

   set TOMCAT_OPTS=-Dlog4j.configuration=file:/c:/foobar.lcf
tells log4j to use the file c:\foobar.lcf as the default configuration file. The configuration file is fully specified by the URL file:/c:/foobar.lcf. Thus, the same configuration file will be used for all web-applications.

Different web-applications will load the log4j classes through their respective classloaderss. Thus, each image of the log4j environment will act independetly and without any mutual synchronization. For example, FileAppenders defined exactly the same way in multiple web-application configurations will all attempt to write the same file. The results are likely to be less than satisfactory. You must make sure that log4j configurations of different web-applications do not use the same underlying system resource.

Initialization servlet

It is also possible to use a special servlet for log4j initialization. Here is an example,

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) {
  }
}

Define the following servlet in the web.xml file for your web-application.

  <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>

Writing an initialization servlet is the most flexible way for initializing log4j. There are no constraints on the code you can place in the init() method of the servlet.

Nested Diagnostic Contexts

Most real-world systems have to deal with multiple clients simultaneously. In a typical multithreaded implementation of such a system, different threads will handle different clients. Logging is especially well suited to trace and debug complex distributed applications. A common approach to differentiate the logging output of one client from another is to instantiate a new separate logger for each client. This promotes the proliferation of loggers and increases the management overhead of logging.

A lighter technique is to uniquely stamp each log request initiated from the same client interaction. Neil Harrison described this method in the book "Patterns for Logging Diagnostic Messages," in Pattern Languages of Program Design 3, edited by R. Martin, D. Riehle, and F. Buschmann (Addison-Wesley, 1997).

To uniquely stamp each request, the user pushes contextual information into the NDC, the abbreviation of Nested Diagnostic Context. The NDC class is shown below.

  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();
  }

The NDC is managed per thread as a stack of contextual information. Note that all methods of the org.apache.log4j.NDC class are static. Assuming that NDC printing is turned on, every time a log request is made, the appropriate log4j component will include the entire NDC stack for the current thread in the log output. This is done without the intervention of the user, who is responsible only for placing the correct information in the NDC by using the push and pop methods at a few well-defined points in the code. In contrast, the per-client logger approach commands extensive changes in the code.

To illustrate this point, let us take the example of a servlet delivering content to numerous clients. The servlet can build the NDC at the very beginning of the request before executing other code. The contextual information can be the client's host name and other information inherent to the request, typically information contained in cookies. Hence, even if the servlet is serving multiple clients simultaneously, the logs initiated by the same code, i.e. belonging to the same logger, can still be distinguished because each client request will have a different NDC stack. Contrast this with the complexity of passing a freshly instantiated logger to all code exercised during the client's request.

Nevertheless, some sophisticated applications, such as virtual hosting web servers, must log differently depending on the virtual host context and also depending on the software component issuing the request. Recent log4j releases support multiple hierarchy trees. This enhancement allows each virtual host to possess its own copy of the logger hierarchy.

Performance

One of the often-cited arguments against logging is its computational cost. This is a legitimate concern as even moderately sized applications can generate thousands of log requests. Much effort was spent measuring and tweaking logging performance. Log4j claims to be fast and flexible: speed first, flexibility second.

The user should be aware of the following performance issues.

  1. Logging performance when logging is turned off.

    When logging is turned off entirely or just for a set of levels, the cost of a log request consists of a method invocation plus an integer comparison. On a 233 MHz Pentium II machine this cost is typically in the 5 to 50 nanosecond range.

    However, The method invocation involves the "hidden" cost of parameter construction.

    For example, for some logger cat, writing,

         logger.debug("Entry number: " + i + " is " + String.valueOf(entry[i]));
        
    incurs the cost of constructing the message parameter, i.e. converting both integer i and entry[i] to a String, and concatenating intermediate strings, regardless of whether the message will be logged or not. This cost of parameter construction can be quite high and it depends on the size of the parameters involved.

    To avoid the parameter construction cost write:

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

    This will not incur the cost of parameter construction if debugging is disabled. On the other hand, if the logger is debug-enabled, it will incur twice the cost of evaluating whether the logger is enabled or not: once in debugEnabled and once in debug. This is an insignificant overhead because evaluating a logger takes about 1% of the time it takes to actually log.

    In log4j, logging requests are made to instances of the Logger class. Logger is a class and not an interface. This measurably reduces the cost of method invocation at the cost of some flexibility.

    Certain users resort to preprocessing or compile-time techniques to compile out all log statements. This leads to perfect performance efficiency with respect to logging. However, since the resulting application binary does not contain any log statements, logging cannot be turned on for that binary. In my opinion this is a disproportionate price to pay in exchange for a small performance gain.

  2. The performance of deciding whether to log or not to log when logging is turned on.

    This is essentially the performance of walking the logger hierarchy. When logging is turned on, log4j still needs to compare the level of the log request with the level of the request logger. However, loggers may not have an assigned level; they can inherit them from the logger hierarchy. Thus, before inheriting a level, the logger may need to search its ancestors.

    There has been a serious effort to make this hierarchy walk to be as fast as possible. For example, child loggers link only to their existing ancestors. In the BasicConfigurator example shown earlier, the logger named com.foo.Bar is linked directly to the root logger, thereby circumventing the nonexistent com or com.foo loggers. This significantly improves the speed of the walk, especially in "sparse" hierarchies.

    The typical cost of walking the hierarchy is typically 3 times slower than when logging is turned off entirely.

  3. Actually outputting log messages

    This is the cost of formatting the log output and sending it to its target destination. Here again, a serious effort was made to make layouts (formatters) perform as quickly as possible. The same is true for appenders. The typical cost of actually logging is about 100 to 300 microseconds.

    See org.apache.log4.performance.Logging for actual figures.

Although log4j has many features, its first design goal was speed. Some log4j components have been rewritten many times to improve performance. Nevertheless, contributors frequently come up with new optimizations. You should be pleased to know that when configured with the SimpleLayout performance tests have shown log4j to log as quickly as System.out.println.

Conclusions

Log4j is a popular logging package written in Java. One of its distinctive features is the notion of inheritance in loggers. Using a logger hierarchy it is possible to control which log statements are output at arbitrary granularity. This helps reduce the volume of logged output and minimize the cost of logging.

One of the advantages of the log4j API is its manageability. Once the log statements have been inserted into the code, they can be controlled with configuration files. They can be selectively enabled or disabled, and sent to different and multiple output targets in user-chosen formats. The log4j package is designed so that log statements can remain in shipped code without incurring a heavy performance cost.

Acknowledgments

Many thanks to N. Asokan for reviewing the article. He is also one of the originators of the logger concept. I am indebted to Nelson Minar for encouraging me to write this article. He has also made many useful suggestions and corrections to this article. Log4j is the result of a collective effort. My special thanks go to all the authors who have contributed to the project. Without exception, the best features in the package have all originated in the user community.