Log4j学习笔记

用了三四年的C++，转向Java的怀抱，还是有诸多的不适应。C++中不论多复杂的Server，只要有GDB在手，总感觉debug都不是啥大事，程序运行期间的各种状态，都可以通过GDB轻松的获取到；而到了Java中，总感觉像是被困住了手脚，有力没法使，不知道是我还掌握方法，还是事实确实如此，发现Server端的Java程序，几乎没有什么好的debug的方法。也跟一些用了几年Java的朋友聊过，大多给出的答案都是Log。以前在学校刚开始学C/C++的时候，那时候的debug就是靠printf，基本思想跟Log是一样的, 后来结识了神器GDB之后，就深深地爱上了它。现在用上了Java之后，感觉又一夜回到了解放前。我并不是说Log不重要，相反，在越复杂的系统中，Log的地位越发重要，但是对于debug而言，一点点的加Log, 然后重新编译，布署，效率实在是太低了。对于像Java这样没有GDB这样的神器的语言，Log的地位越发重要，因此像Log4j这样的组件就非常流行，前段时间在弄hadoop中异步log相关的一些事情，就顺便把log4j学习了一下，下面整理了一下log4j相关的一些内容。

1. Log4j online manual
地址：http://logging.apache.org/log4j/1.2/manual.html
本文的大部分内容是参考了这个manual，外加一些其他人的博客。

2. Log4j几个重要的概念
(1) Loggers：负责写Log的类，提供写Log相关的API
a. Logger的全名跟java中package的命名基本是差不多，不过这里有一个hierarchy的概念需要理解一下，比如说有三个名字，com.example.a, com.example.a.b, com.example.a.b.c，这里com.example.a叫做com.example.a.b的parent, 叫做com.example.a.b.c的ancestor.
b. Logger里还有一个Level的概念，这跟常规的其它log库都是一致的，Log4j中总共有这么几个Level: TRACE > DEBUG > INFO > WARN > ERROR > FATAL, log的level设得越小，Log写的最小，比如如果Log Level设的是FATAL, 那么就只有FATAL Level的Log才会写出来，其它的都不会。通常，我们都设Log Level为INFO，这样Level小于等于INFO的，包括INFO, WARN, ERROR, FATAL这几个级别的都会写出来。只有在debug的时候才会打开DEBUG或者TRACE Level的日志。
c. 下面是Logger基类对用户提供的API, 非常直观，一看就知道怎么用：

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18

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

(2) Appenders: 是Log4j中用来指定output destination的，就是哪个Logger的log，写到哪里去
a. Log4j允许同一条Log request写到多个Logger, 具体的实现就是把多个Appender，attach到指定的Logger上去
b. Log4j自带的appender有这些： console, files, GUI components, remote socket servers, JMS, NT Event Loggers, remote UNIX Syslog daemons，用户还可以实现自己的Appender来扩展Log4j的功能，比如比较常见的，实现一个写一个LogStore(比如Scribe)的Appender, 就可以简单地通过配置，把现有的Log4j写的log写到LogStore.
c. Appenders Additivity(相加性): 缺省情况下，每个Log request都会被forward给它对应的Appender，和它的parent & ancestor的Appender。如果appender C的parent或者某个ancestor把它的additivity flag设为false, 那么C收到的Log request只forward到P，P的parent & ancestor都不会收到这个Log request.

(3) Layout: 是Log4j中用来格式化Log的概念
a. Layout的基本语法和C中的printf的类似，具体可以参考：http://logging.apache.org/log4j/1.2/apidocs/org/apache/log4j/PatternLayout.html
b. Log4j中Log行号也是通过Layout来实现的，但这里需要注意的是，文档里说写行号会影响性能，如果不是debug，通常不需要写行号，这一点跟传统C/C++的Log组件不太像

3. Asynchronous Log4j
（1）Log4j的Configuration: 目前Log4j支持通过两种格式的文件来配置，一种是log4j.properties, 简单的key/value格式的文件；一种是log4j.xml，xml文件。具体使用的时候，把写好的配置文件放在程序的classpath中，这样程序运行的时候就能自动找到并加载
（2）关于log4j.properties和log4j.xml，主要的区别是，一些log4j的高级的feature, 只有log4j.xml支持，log4j.properties不支持。比如asynchronous log, 就只有log4j.xml支持。所以，如果是performance critical的程序，通常建议采用log4j.xml来配置log4j
（3）Asynchronous log4j的实现是单独起了一个线程来dump log, 这个跟预想的一致，下面是一个简单的验证：
a. async-log4j的调用栈：

b. sync-log4j的调用栈：

（4）下面是一个async-log4j配置的例子：

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23

< ?xml version="1.0" encoding="UTF-8"?> < !DOCTYPE log4j:configuration SYSTEM "log4j.dtd"> <log4j:configuration debug="false" xmlns:log4j='http://jakarta.apache.org/log4j/'> <root> <level value="info"></level> <appender -ref ref="ASYNC_DRFA"></appender> </root>   <!--Daily rolling file appender--> <appender name="DRFA" class="org.apache.log4j.DailyRollingFileAppender"> <param name="File" value="${hdfs.log.dir}/hdfs.log" /> <param name="DatePattern" value="'.'yyyy-MM-dd" /> <param name="Append" value="true" /> <layout class="org.apache.log4j.PatternLayout"> <param name="ConversionPattern" value="%d{ISO8601} %p %c: %m%n" /> </layout> </appender> <appender name="ASYNC_DRFA" class="org.apache.log4j.AsyncAppender"> <param name="BufferSize" value="500" /> </appender><appender -ref ref="DRFA"> </appender>   </log4j:configuration>

(5) 这里需要注意一点：AsyncAppender有一个叫Blocking的属性，缺省是true. 缺省情况下，如果buffer满了，在把buffer dump到磁盘的过程中，后来的log request都会被block住。但是，如果把这个属性设为false, 那么，如果buffer满了，在把buffer dump到磁盘的过程中，后来的log就会被丢弃。这里就有一个log的完整性和性能之间的tradeoff, 如果是performance very critical的程序，又不在乎丢几条log, 那么可以考虑把这个属性设为false, 其它情况下，还是用缺省的true，毕竟Log的完整性也非常重要。

4. 其它一点需要注意的点 
（1）这里提一下在mannual里介绍的一个与性能比较相关的点，先看下面的程序：

1 2 3 4 5

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

这里，在log level为DEBUG的时候，两个程序的开销差不多，第二个就多一次bool的判断，几乎可以忽略。但是在log level小于debug的时候，第一种情况下，log内容中那几个string的拼接是会发生的，而第二种情况下，string的拼接是不会发生的。这里如果string比较长的话，性能影响还是比较明显的。这是一个性能相关的可能优化的点，需要格外注意一下。

FROM: http://www.wuzesheng.com/?p=2407