log4j使用指南

log4j使用指南

Posted in java on 五月 31st,
2010 by kafka0102

1.Introduction

log4j是Java中老牌的日志工具了，其强大的功能、简便的使用，使得开源项目中随处可见它的身影。即便jdk1.4中引入了logging功

能，log4j还是最受欢迎的日志工具。对log4j的使用者来说，使用log4j的API就那个几个打印日志函数，最需要关注的就是它的配置文件。不
过，很多人只是从网上找个配置样例把它跑起来，而没有更有效的使用log4j处理日志。这其实也不仅仅关乎log4j的使用，而是实际的如何有效的利用工
具来记录日志、分析日志和监控日志。

log4j核心的概念有logger、appender、layout和filter，下面将分别做介绍。对于这些概念，既可以通过配置文件体现出
来，
也可以通过它的API体现处理。在使用上，关注配置文件的细节即可，而不需要关注log4j自身的API及实现方面的事情。尽管抛开配置文件，也可以使用

API来操纵配置，甚至可以扩展它，但log4j提供的功能已经很强大了，通常也不需要使用者做二次开发。为了整理出该文，我也是对log4j的实现做了
算不上深入的浏览，本文的内容主要参考log4j的参考手册及相关文章。对于log4j的配置，log4j支持java
properties文件和xml文件，本文在阐述相关配置内容采用了xml格式，因为Filter功能properties文件不能支持。

2.Loggers

log4j的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);
}



使用上，通常是在类中通过private static Logger logger =
Logger.getLogger(package.classname); 声明静态logger成员，打日志就是调用各level函数。
getLogger的参数是Logger的标识，并具有层次关系，比如“com.foo”是“com.foo.Bar”的父Logger。logger的
xml配置格式是：


<!ELEMENT logger (level?,appender-ref*)>
<!ATTLIST logger
name ID #REQUIRED
additivity (true|false) "true"
>



其中，子元素level表示输出的最低级别（默认是debug），appender-ref则引用配置中的appender（可以是多个）；其属性

name是标识，additivity表示在层级关系中，是否向上查找，比如A是B的父logger，A的level是info，B没有指定level，
当B的additivity为true，在B打日志时，发现B没有指定level，就向上查找到A并使用A的level，否则就屏蔽掉B的输出。

在logger层级中，最顶层的是root
logger，可以通过getRootLogger()得到（尽管很少有人会这么做）。常见的配置中也就是配置root
logger，那么在各个类中创建的logger会直接继承root logger的配置。

有时也可能需要对特定的logger做处理，比如我的模块中用到memcached
client库，因为模块的level是debug，这使得memcached
client库中的debug信息都会打出来，而我真的不是很关心它，所以就通过下面的配置关掉它：


<logger name="com.danga">
<level value="info"/>
</logger>



对于日志level，log4j支持通过继承Level类自定义Level，这在一些情景下或许会有帮助。比如，可以添加一个Level来表示和统
计相关的日志。另外，像上面提到的例子，logger的level是可继承的，当子logger没有指定level时，它会使用其父logger的，并一
直检查到root logger。

3.Appenders

appender表示要把日志输出到哪里去。在 log4j.dtd中，appender声明的格式如下：


<!ELEMENT appender (errorHandler?, param*, layout?, filter*, appender-ref*)>
<!ATTLIST appender
name ID #REQUIRED
class CDATA #REQUIRED
>



一个样例如下：


<appender name="console" class="org.apache.log4j.ConsoleAppender">
<param name="Target" value="System.out"/>
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern" value="%-5p %c{1} - %m%n"/>
</layout>
</appender>



下面说明appender可能包含的子元素的含义：

1）errorHandler：这是一个钩子，当appender出现异常时（比如layout无效），可以指定errorHandler来做些善后工
作，一般是不需要配置它的。

2）param：不同的appender有自己特定的参数选项，每一个param是key-value对，可以查看log4j API
doc中的Appender实现类API说明，其中的加粗字体便是。

3）layout：下面有说明。

4）filter：下面有说明。

5）appender-ref：appender也可以包含多个appender。

下面简要介绍常用的几个Appender：

1、ConsoleAppender：ConsoleAppender是将日志打到控制台上，这在开发时观察日志会相比打到文件里更方便一些。它可用的
param元素只有Target，可选值是System.out和System.err，默认的是System.out，如果配成System.err，
在eclipse的console会输出红色字体内容。如果想要把一个应用中的日志内容（包括非日志内容的异常信息）都输出到一个文件，也可以使用
ConsoleAppender，通过输出重定向把所有内容打到一个文件中去。

2、FileAppender：FileAppender就是把日志打到文件里，也是用的最多的，它可用的param元素如下：

1）File：输出的文件路径。

2）Append：打开日志文件的模式，默认true表示追加写，否则会清空文件已有内容。

3）BufferedIO：默认为false，如果为true表示对Writer包装成
BufferedWriter，这种缓冲方式对服务端应用来说会带来性能问题。

3、DailyRollingFileAppender：DailyRollingFileAppender是FileAppender的升级版，
它支持对日志做定期切割，这可以省去我们配置crontab定期执行脚本来切割日志，它可用的param元素如下：

1）File：输出的文件路径。

2）Append：打开日志文件的模式，默认true表示追加写， 否则会清空文件已有内容。

3）DatePattern：DailyRollingFileAppender根据该参数来调度何时切割日志，这个日期格式与
SimpleDateFormat一致，可以做到按分时天周月等不同粒度切割日志。比如，“’.'yyyy-MM-dd”表示每天零点切割日志，假如日志
文件名是foo.log，那么在2010-05-31零点执行切割后前一天的日志文件名是foo.log.2010-05-30，31号新的日志打到
foo.log。DailyRollingFileAppender日志切割的过程是：关闭打开的日志文件（foo.log）句柄，rename该日志文
件（foo.log.2010-05-30），打开新创建的日志文件（foo.log）。

4.Layouts

layout表示日志输出的格式，log4j支持的layout有TTCCLayout, HTMLLayout, PatternLayout,
SimpleLayout和XMLLayout，常用的是PatternLayout，性能最好的是SimpleLayout（因为它足够
simple）。PatternLayout支持的模式选项说明如下：

%m:输出日志消息内容.

%p: 输出日志事件的priority（DEBUG、INFO等）.

%r: 输出自程序启动后到当前的时间差，似乎用处不大。

%c: 输出category名称，也就是getLogger函数的参数，用处也不大。

%t: 输出当前的线程名，一些多线程环境中或许用的上。

%x: 输出nested diagnostic context
(NDC)，这个功能对多客户端请求的场景很有用。当使用日志查找分析问题时，很多时候希望针对某一个出问题的请求，查看它的执行流程，定位问题出在哪个
环节，这就需要对一个请求的流程做唯一标识。这个唯一标识可以是全局唯一的logid，初始由最前端的模块分配，然后贯穿流程中的所有模块。也可以是其他
东西，比如请求ip、请求参数等。这些信息可以通过log4j的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();
}



在处理请求的线程（比如servlet）中，新的请求开始处调用NDC.push方法设置标识，请求处理的最后再remove掉（也或者在push
之前先remove）。

%n: 输出平台独立的换行符，如”\n”、”\r\n”等，通常和%m连用。

WARNING：下面的参数有性能问题，对性能要求高的场景需要做好度量。

%d: 输出时间，可以指定时间格式，比如 %d{HH:mm:ss,SSS} 或 %d{dd MMM yyyy HH:mm:ss,SSS}等。

%C:
输出调用日志类方法者的fully-qualified类名，默认是输出全路径（也就是包名+类名），也可以限定{n}表示输出全称的最后n个部分，比
如”com.foo.SomeClass”, 模式%C{1}将输出”SomeClass”。

%M:输出调用日志类方法者的方法名。

%F: 输出调用日志类方法者的文件名。

%L: 输出调用日志类方法者的行号。

%l: 输出调用日志类方法者的源代码位置，它是%C.%M(%F:%L)的简称。

上面的输出选项中，和调用者位置相关的选项会有性能问题。这是因为，为了得到这些信息，log4j调用
Throwable.getStackTrace()来得到整个调用过程的栈信息，自底向上比较调用的函数名，直到找到日志函数（debug等）的上一级
函数名，然后通过反射得到一系列位置信息。这个过程显然要比其他几项的取得复杂的多，但它对分析日志查找问题却是很有用的。我的一个建议是，对于info

级别的日志，就不需要打出调用位置等信息，对于debug、warning和error则需要。另一个，输出时间也是很有必要的，否则做统计查问题都无从
下手。

5.Filter

log4j中的filter可以指定appender要输出的日志等级范围，这可以实现在应用中把不同等级的日志打到不同文件中。像debug、
info
级别，每天会产生很多，也多用来做统计分析；而warning和error级别的日志是需要监控处理的，并且人还有可能上去查看；所以把两者分开就显得很
有必要。对于有特别需求的日志，也可以单独打到一个文件里去。下面是使用filter的一个样例：


<appender name="TRACE" class="org.apache.log4j.ConsoleAppender">
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern" value="[%t] %-5p %c - %m%n" />
</layout>
<filter class="org.apache.log4j.varia.LevelRangeFilter">
<param name="levelMin" value="DEBUG" />
<param name="levelMax" value="INFO" />
</filter>
<filter class="org.apache.log4j.varia.DenyAllFilter" />
</appender>



LevelRangeFilter可以指定某个范围（从levelMin到levelMax）的等级，在上面的配置中，如果没有
DenyAllFilter，表示从DEBUG到INFO级别的日志不做处理，而加了DenyAllFilter后含义反转，表示该appender只打
印从DEBUG到INFO的日志。log4j中另一个实用的filter是LevelMatchFilter，它准确的匹配某个日志等级。

6.Example

下面是一个完整的log4j.xml配置文件样例：


<?xml version="1.0" encoding="UTF-8" ?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">
<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/"
debug="true">
 
<appender name="info-out" class="org.apache.log4j.DailyRollingFileAppender">
<param name="File" value="${log_path}.log" />
<param name="DatePattern" value="'.'yyyy-MM-dd" />
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern" value="[%d{yyyy-MM-dd HH:mm:ss}][%p][%F(%L)]%m%n" />
</layout>
<filter class="org.apache.log4j.varia.LevelRangeFilter">
<param name="LevelMin" value="debug" />
<param name="LevelMax" value="info" />
<param name="AcceptOnMatch" value="true" />
</filter>
<filter class="org.apache.log4j.varia.DenyAllFilter" />
</appender>
 
<appender name="error-out" class="org.apache.log4j.DailyRollingFileAppender">
<param name="Append" value="false" />
<param name="DatePattern" value="'.'yyyy-MM-dd" />
<param name="File" value="${log_path}.wf.log" />
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern" value="[%d{yyyy-MM-dd HH:mm:ss}][%p][%F(%L)]%m%n" />
</layout>
<filter class="org.apache.log4j.varia.LevelRangeFilter">
<param name="LevelMin" value="warn" />
<param name="LevelMax" value="error" />
<param name="AcceptOnMatch" value="true" />
</filter>
<filter class="org.apache.log4j.varia.DenyAllFilter" />
</appender>
 
<root>
<level value="debug" />
<appender-ref ref="info-out" />
<appender-ref ref="error-out" />
</root>
 
<logger name="com.danga">
<level value="info" />
</logger>
</log4j:configuration>



对于配置中的行


<param name="File" value="${log_path}.log" />



，log_path是java property（通过-D选项指定），log4j支持之。该配置达到的目标是：

1）生成的日志文件有3个，一个是debug和info级别的日志，一个是warn和error级别的日志，还有一个是输出重定向的文件（主要是GC信
息）。

2）使用DailyRollingFileAppender切割日志文件。

3）屏蔽了com.danga层级（memcached client库）的debug日志。

7.Performance

对于log4j的性能，我没有做细致的度量。抛开log4j来说，日志操作主要性能耗在输出上，所以输出的日志内容越少越好。除此之外，log4j
使用上有两点需要注意：

1、在生产环境中，我们通常是关掉debug级别的，但如果程序中debug函数很多，还是会带来性能问题。因为debug函数输出的就是些调试信息，所
以其参数通常是多个字符串+操作构成，这种经典的构造多个临时对象的做法显然会有些性能消耗；更有甚者会调用诸如object.toString方法，而
这个被覆盖的方法很可能是将对象内的诸多属性拼凑成字符串输出，对性能有高要求的场景就很不合适。在一些基础库或框架中，就可能会看到下面的代码片断来避
免性能问题，其中的isDebugEnabled只是个判定操作，在logger层次不复杂的情况下，没有什么性能损失：


if(logger.isDebugEnabled() {
logger.debug(......);
}



2、复杂的logger层级也会带来性能问题。好的方面是，通常我们指定root logger就够了。

8.Conclusions

关于java应用中的日志处理，暂且说到这里。尽管log4j很好很强大，但如果你的程序是些如库或框架等基础服务，可以考虑
slf4j（http://www.slf4j.org）来代替log4j的API调用。slf4j是对现存的多种日志库的封装，对外提供了统一的接口，
解决了依赖的程序间的日志不兼容的问题。

9.Reference

http://logging.apache.org/log4j/1.2/manual.html

http://wiki.apache.org/logging-log4j/Log4jXmlFormat

http://www.vipan.com/htdocs/log4jhelp.html