layout负责将loggingevent中的信息格式化成一行日志信息。对不同格式的日志可能还需要提供头和尾等信息。另外有些layout不会处理异常信息,此时ignoresthrowable()方法返回false,并且异常信息需要appender来处理,如patternlayout。
log4j自身实现了7个layout类,我们可以通过继承自layout类以实现用户自定义的日志消息格式。log4j中已定义的layout类结构如图:
简单的写了一个功能性测试的类,从而对不同layout的输出有比较直观的了解。为了简单起见,所有的测试都打印到控制台。
1 public class layouttest {
2 private logger root;
3 @before
4 public void setup() {
5 root = logmanager.getrootlogger();
6 }
7 @test
8 public void testxxxlayout() {
9 configsetup(new xxxlayout());
10 logtest();
11 }
12 private void logtest() {
13 logger log = logger.getlogger("levin.log4j.test.testbasic");
14 log.info("begin to execute testbasic() method
");
15 log.info("executing
16 try {
17 throw new exception("deliberately throw an exception
18 } catch(exception e) {
19 log.error("catching an exception", e);
20 }
21 log.info("execute testbasic() method finished.");
22 }
23 private void configsetup(layout layout) {
24 root.addappender(createconsoleappender(layout));
25 }
26 private appender createconsoleappender(layout layout) {
27 return new consoleappender(layout);
28 }
29 }
layout类是所有log4j中layout的基类,它是一个抽象类,定义了layout的接口。
1. format()方法:将loggingevent类中的信息格式化成一行日志。
2. getcontenttype():定义日志文件的内容类型,目前在log4j中只是在smtpappender中用到,用于设置发送邮件的邮件内容类型。而layout本身也只有htmllayout实现了它。
3. getheader():定义日志文件的头,目前在log4j中只是在htmllayout中实现了它。
4. getfooter():定义日志文件的尾,目前在log4j中只是htmllayout中实现了它。
5. ignoresthrowable():定义当前layout是否处理异常类型。在log4j中,不支持处理异常类型的有:ttclayout、patternlayout、simplelayout。
6. 实现optionhandler接口,该接口定义了一个activateoptions()方法,用于配置文件解析完后,同时应用所有配置,以解决有些配置存在依赖的情况。该接口将在配置文件相关的小节中详细介绍。
由于layout接口定义比较简单,因而其代码也比较简单:
1 public abstract class layout implements optionhandler {
2 public final static string line_sep = system.getproperty("line.separator");
3 public final static int line_sep_len = line_sep.length();
4 abstract public string format(loggingevent event);
5 public string getcontenttype() {
6 return "text/plain";
7 }
8 public string getheader() {
9 return null;
10 }
11 public string getfooter() {
12 return null;
13 }
14 abstract public boolean ignoresthrowable();
15 }
simplelayout是最简单的layout,它只是打印消息级别和渲染后的消息,并且不处理异常信息。不过这里很奇怪为什么把sbuf作为成员变量?个人感觉这个会在多线程中引起问题~~~~其代码如下:
1 public string format(loggingevent event) {
2 sbuf.setlength(0);
3 sbuf.append(event.getlevel().tostring());
4 sbuf.append(" - ");
5 sbuf.append(event.getrenderedmessage());
6 sbuf.append(line_sep);
7 return sbuf.tostring();
8 }
9 public boolean ignoresthrowable() {
10 return true;
11 }
测试用例:
1 @test
2 public void testsimplelayout() {
3 configsetup(new simplelayout());
4 logtest();
5 }
测试结果:
info - begin to execute testbasic() method
info - executing
error - catching an exception
java.lang.exception: deliberately throw an exception
at levin.log4j.layout.layouttest.logtest(layouttest.java:48)
at levin.log4j.layout.layouttest.testsimplelayout(layouttest.java:25)
info - execute testbasic() method finished.
htmllayout将日志消息打印成html格式,log4j中htmllayout的实现中将每一条日志信息打印成表格中的一行,因而包含了一些header和footer信息。并且htmllayout类还支持配置是否打印位置信息和自定义title。最终htmllayout的日志打印格式如下:
<!doctype html public "-//w3c//dtd html 4.01 transitional//en" "http://www.w3.org/tr/html4/loose.dtd">
<html>
<head>
<title>${title}</title>
<style type="text/css">
<!--
body, table {font-family: arial,sans-serif; font-size: x-small;}
th {background: #336699; color: #ffffff; text-align: left;}
-->
</style>
</head>
<body bgcolor="#ffffff" topmargin="6" leftmargin="6">
<hr size="1" noshade>
log session start time ${currenttime}<br>
<br>
<table cellspacing="0" cellpadding="4" border="1" bordercolor="#224466" width="100%">
<tr>
<th>time</th>
<th>thread</th>
<th>level</th>
<th>category</th>
<th>file:line</th>
<th>message</th>
</tr>
<td>${timeelapsedfromstart}</td>
<td title="${threadname} thread">${theadname}</td>
<td title="level">
#if(${level} == “debug”)
<font color="#339933">debug</font>
#elseif(${level} >= “warn”)
<font color=”#993300”><strong>${level}</strong></font>
#else
${level}
</td>
<td title="${loggername} category">levin.log4j.test.testbasic</td>
<td>${filename}:${linenumber}</td>
<td title="message">${renderedmessage}</td>
<tr><td bgcolor="#eeeeee" style="font-size : xx-small;" colspan="6" title="nested diagnostic context">ndc: ${ndc}</td></tr>
<tr><td bgcolor="#993300" style="color:white; font-size : xx-small;" colspan="6">java.lang.exception: deliberately throw an exception
<br>&nbsp;&nbsp;&nbsp;&nbsp; at levin.log4j.layout.layouttest.logtest(layouttest.java:51)
<br>&nbsp;&nbsp;&nbsp;&nbsp; at levin.log4j.layout.layouttest.testhtmllayout(layouttest.java:34)
</td></tr>
以上所有html内容信息都要经过转义,即: ’<’ => &lt; ‘>’ => &gt; ‘&’ => &amp; ‘”’ => &quot;从上信息可以看到htmllayout支持异常处理,并且它也实现了getcontenttype()方法:
1 public string getcontenttype() {
2 return "text/html";
3 }
4 public boolean ignoresthrowable() {
5 return false;
6 }
2 public void testhtmllayout() {
3 htmllayout layout = new htmllayout();
4 layout.setlocationinfo(true);
5 layout.settitle("log4j log messages htmllayout test");
6 configsetup(layout);
7 logtest();
8 }
xmllayout将日志消息打印成xml文件格式,打印出的xml文件不是一个完整的xml文件,它可以外部实体引入到一个格式正确的xml文件中。如xml文件的输出名为abc,则可以通过以下方式引入:
<?xml version="1.0" ?>
<!doctype log4j:eventset public "-//apache//dtd log4j 1.2//en" "log4j.dtd" [<!entity data system "abc">]>
<log4j:eventset version="1.2" xmlns:log4j="http://jakarta.apache.org/log4j/">
&data;
</log4j:eventset>
xmllayout还支持设置是否支持打印位置信息以及mdc(mapped diagnostic context)信息,他们的默认值都为false:
1 private boolean locationinfo = false;
2 private boolean properties = false;
xmllayout的输出格式如下:
<log4j:event logger="${loggername}" timestamp="${eventtimestamp}" level="${level}" thread="${threadname}">
<log4j:message><![cdata[${renderedmessage}]]></log4j:message>
#if ${ndc} != null
<log4j:ndc><![cdata[${ndc}]]</log4j:ndc>
#endif
#if ${throwableinfo} != null
<log4j:throwable><![cdata[java.lang.exception: deliberately throw an exception
at levin.log4j.layout.layouttest.logtest(layouttest.java:54)
at levin.log4j.layout.layouttest.testxmllayout(layouttest.java:43)
]]></log4j:throwable>
#if ${locationinfo} != null
<log4j:locationinfo class="${classname}" method="${methodname}" file="${filename}" line="${linenumber}"/>
#if ${properties} != null
<log4j:properties>
#foreach ${key} in ${keyset}
<log4j:data name=”${key}” value=”${propvalue}”/>
#end
</log4j:properties>
</log4j:event>
从以上日志格式也可以看出xmllayout已经处理了异常信息。
1 public boolean ignoresthrowable() {
2 return false;
2 public void testxmllayout() {
3 xmllayout layout = new xmllayout();
5 layout.setproperties(true);
ttcclayout貌似有特殊含义,不过这个我还不太了解具体是什么意思。从代码角度上,该layout包含了time, thread, category, nested diagnostic context information, and rendered message等信息。其中是否打印thread(threadprinting), category(categoryprefixing), nested diagnostic(contextprinting)信息是可以配置的。ttcclayout不处理异常信息。其中format()函数代码:
2 buf.setlength(0);
3 dateformat(buf, event);
4 if (this.threadprinting) {
5 buf.append('[');
6 buf.append(event.getthreadname());
7 buf.append("] ");
8 }
9 buf.append(event.getlevel().tostring());
10 buf.append(' ');
11 if (this.categoryprefixing) {
12 buf.append(event.getloggername());
13 buf.append(' ');
14 }
15 if (this.contextprinting) {
16 string ndc = event.getndc();
17 if (ndc != null) {
18 buf.append(ndc);
19 buf.append(' ');
21 }
22 buf.append("- ");
23 buf.append(event.getrenderedmessage());
24 buf.append(line_sep);
25 return buf.tostring();
26 }
这里唯一需要解释的就是dateformat()函数,它是在其父类datelayout中定义的,用于格式化时间信息。datelayout支持的时间格式有:
null_date_format:null,此时dateformat字段为null
relative_time_date_format:relative,默认值,此时dateformat字段为relativetimedateformat实例。其实现即将loggingevent中的timestamp-starttime(relativetimedateformat实例化是初始化)。
abs_time_date_format:absolute,此时dateformat字段为absolutetimedateformat实例。它将时间信息格式化成hh:mm:ss,sss格式。这里对性能优化有一个可以参考的地方,即在格式化是,它只是每秒做一次格式化计算,而对后缀sss的变化则直接计算出来。
date_and_time_date_format:date,此时dateformat字段为datetimedateformat实例,此时它将时间信息格式化成dd mmm yyyy hh:mm:ss,sss。
iso8601_date_format:iso8601,此时dateformat字段为iso8601dateformat实例,它将时间信息格式化成yyyy-mm-dd hh:mm:ss,sss。
以及普通的simpledateformat中设置pattern的支持。
log4j推荐使用自己定义的dateformat,其文档上说log4j中定义的dateformat信息有更好的性能。
2 public void testttcclayout() {
3 ttcclayout layout = new ttcclayout();
4 layout.setdateformat("iso8601");
5 configsetup(layout);
6 logtest();
7 }
2012-07-02 23:07:34,017 [main] info levin.log4j.test.testbasic - begin to execute testbasic() method
2012-07-02 23:07:34,018 [main] info levin.log4j.test.testbasic - executing
2012-07-02 23:07:34,019 [main] error levin.log4j.test.testbasic - catching an exception
at levin.log4j.layout.layouttest.logtest(layouttest.java:63)
2012-07-02 23:07:34,022 [main] info levin.log4j.test.testbasic - execute testbasic() method finished.
个人感觉patternlayout是log4j中最常用也是最复杂的layout了。patternlayout的设计理念是loggingevent实例中所有的信息是否显示、以何种格式显示都是可以自定义的,比如要用patternlayout实现ttcclayout中的格式,可以这样设置:
2 public void testpatternlayout() {
3 patternlayout layout = new patternlayout();
4 layout.setconversionpattern("%r [%t] %p %c %x - %m%n");
该测试用例的运行结果和ttcclayout中默认的结果是一样的。完整的,patternlayout中可以设置的参数有(模拟c语言的printf中的参数):
格式字符
结果
c
显示logger name,可以配置精度,如%c{2},从后开始截取。
显示日志写入接口的雷鸣,可以配置精度,如%c{1},从后开始截取。注:会影响性能,慎用。
d
显示时间信息,后可定义格式,如%d{hh:mm:ss,sss},或log4j中定义的格式,如%d{iso8601},%d{absolute},log4j中定义的时间格式有更好的性能。
f
显示文件名,会影响性能,慎用。
l
显示日志打印是的详细位置信息,一般格式为full.qualified.caller.class.method(filename:linenumber)。注:该参数会极大的影响性能,慎用。
显示日志打印所在源文件的行号。注:该参数会极大的影响性能,慎用。
m
显示渲染后的日志消息。
显示打印日志所在的方法名。注:该参数会极大的影响性能,慎用。
n
输出平台相关的换行符。
p
显示日志level
r
显示相对时间,即从程序开始(实际上是初始化loggingevent类)到日志打印的时间间隔,以毫秒为单位。
t
显示打印日志对应的线程名称。
x
显示与当前线程相关联的ndc(nested diagnostic context)信息。
显示和当前想成相关联的mdc(mapped diagnostic context)信息。
%
%%表达显示%字符
而且patternlayout还支持在格式字符串前加入精度信息:
%-min.max[conversionchar],如%-20.30c表示显示日志名,左对齐,最短20个字符,最长30个字符,不足用空格补齐,超过的截取(从后往前截取)。
因而patternlayout实现中,最主要要解决的是如何解析上述定义的格式。实现上述格式的解析,一种最直观的方法是每次遍历格式字符串,当遇到’%’,则进入解析模式,根据’%’后不同的字符做不同的解析,对其他字符,则直接作为输出的字符。这种代码会比较直观,但是它每次都要遍历格式字符串,会引起一些性能问题,而且如果在将来引入新的格式字符,需要直接改动patternlayout代码,不利于可扩展性。
为了解决这个问题,patternlayout引入了解释器模式:
其中patternparser负责解析patternlayout中设置的conversion pattern,它将conversion pattern解析出一个链状的patternconverter,而后在每次格式化loggingevent实例是,只需要遍历该链即可:
1 public string format(loggingevent event) {
2 patternconverter c = head;
3 while (c != null) {
4 c.format(sbuf, event);
5 c = c.next;
6 }
7 return sbuf.tostring();
在解析conversion pattern时,patternparser使用了有限状态机的方法:
即patternparser定义了五种状态,初始化时literal_state,当遍历完成,则退出;否则,如果当前字符不是’%’,则将该字符添加到currentliteral中,继续遍历;否则,若下一字符是’%’,则将其当做基本字符处理,若下一字符是’n’,则添加换行符,否则,将之前收集的literal字符创建literalpatternconverter实例,添加到相应的patternconverter链中,清空currentliteral实例,并添加下一字符,解析器进入converter_state状态:
1 case literal_state:
2 // in literal state, the last char is always a literal.
3 if (i == patternlength) {
4 currentliteral.append(c);
5 continue;
7 if (c == escape_char) {
8 // peek at the next char.
9 switch (pattern.charat(i)) {
10 case escape_char:
11 currentliteral.append(c);
12 i++; // move pointer
13 break;
14 case 'n':
15 currentliteral.append(layout.line_sep);
16 i++; // move pointer
17 break;
18 default:
19 if (currentliteral.length() != 0) {
20 addtolist(new literalpatternconverter(
21 currentliteral.tostring()));
22 // loglog.debug("parsed literal converter: \""
23 // +currentliteral+"\".");
24 }
25 currentliteral.setlength(0);
26 currentliteral.append(c); // append %
27 state = converter_state;
28 formattinginfo.reset();
29 }
30 } else {
31 currentliteral.append(c);
32 }
33 break;
对converter_state状态,若当前字符是’-‘,则表明左对齐;若遇到’.’,则进入dot_state状态;若遇到数字,则进入min_state状态;若遇到其他字符,则根据字符解析出不同的patternconverter,并且如果存在可选项信息(’{}’中的信息),一起提取出来,并将状态重新设置成literal_state状态:
1 case converter_state:
2 currentliteral.append(c);
3 switch (c) {
4 case '-':
5 formattinginfo.leftalign = true;
6 break;
7 case '.':
8 state = dot_state;
9 break;
10 default:
11 if (c >= '0' && c <= '9') {
12 formattinginfo.min = c - '0';
13 state = min_state;
14 } else
15 finalizeconverter(c);
16 } // switch
17 break;
进入min_state状态,首先判断当期字符是否为数字,若是,则继续计算精度的最小值;若遇到’.’,则进入dot_state状态;否则,根据字符解析出不同的patternconverter,并且如果存在可选项信息(’{}’中的信息),一起提取出来,并将状态重新设置成literal_state状态:
1 case min_state:
3 if (c >= '0' && c <= '9')
4 formattinginfo.min = formattinginfo.min * 10 + (c - '0');
5 else if (c == '.')
6 state = dot_state;
7 else {
8 finalizeconverter(c);
9 }
10 break;
进入dot_state状态,如果当前字符是数字,则进入max_state状态;格式出错,回到literal_state状态:
1 case dot_state:
3 if (c >= '0' && c <= '9') {
4 formattinginfo.max = c - '0';
5 state = max_state;
6 } else {
7 loglog.error("error occured in position " + i
8 + ".\n was expecting digit, instead got char \""
9 + c + "\".");
10 state = literal_state;
12 break;
进入max_state状态,若为数字,则继续计算最大精度值,否则,根据字符解析出不同的patternconverter,并且如果存在可选项信息(’{}’中的信息),一起提取出来,并将状态重新设置成literal_state状态:
1 case max_state:
2 currentliteral.append(c);
3 if (c >= '0' && c <= '9')
4 formattinginfo.max = formattinginfo.max * 10 + (c - '0');
5 else {
6 finalizeconverter(c);
7 state = literal_state;
8 }
9 break;
对finalizeconvert()方法的实现,只是简单的根据不同的格式字符创建相应的patternconverter,而且各个patternconverter中的实现也是比较简单的,有兴趣的童鞋可以直接看源码,这里不再赘述。
patternlayout的这种有限状态机的设置是代码结构更加清晰,而引入解释器模式,以后如果需要增加新的格式字符,只需要添加一个新的patternconverter以及一小段case语句块即可,减少了因为需求改变而引起的代码的倾入性。
在log4j文档中指出patternlayout中存在同步问题以及其他问题,因而推荐使用enhancedpatternlayout来替换它。对这句话我个人并没有理解,首先关于同步问题,感觉其他layout中也有涉及到,而且对一个appender来说,它的doappend()方法是同步方法,因而只要不在多个appender之间共享同一个layout实例,也不会出现同步问题;更令人费解的是关于其他问题的表述,说实话,我还没有发现具体有什么其他问题,所以期待其他人来帮我解答。
但是不管怎么样,我们还是来简单的了解一下enhancedpatternlayout的一些设计思想吧。enhancedpatternlayout提供了和patternlayout相同的接口,只是其内部实现有一些改变。enhancedpatternlayout引入了loggingeventpatternconverter,它会根据不同的子类的定义从loggingevent实例中获取相应的信息;使用patternparser解析出关于patternconverters和formattinginfo两个相对独立的集合,遍历这两个集合,构建出两个对应的数组,以在以后的解析中使用。大体上,enhancedpatternlayout还是类似patternlayout的设计。这里不再赘述。
有时候,一段相同的代码需要处理不同的请求,从而导致一些看似相同的日志其实是在处理不同的请求。为了避免这种情况,从而使日志能够提供更多的信息。
要实现这种功能,一个简单的做法每个请求都有一个唯一的id或name,从而在处理这样的请求的日志中每次都写入该信息从而区分看似相同的日志。但是这种做法需要为每个日志打印语句添加相同的代码,而且这个id或name信息要一直随着方法调用传递下去,非常不方便,而且容易出错。log4j提供了两种机制实现类似的需求:ndc和mdc。ndc是nested diagnostic contexts的简称,它提供一个线程级别的栈,用户向这个栈中压入信息,这些信息可以通过layout显示出来。mdc是mapped diagnostic contexts的简称,它提供了一个线程级别的map,用户向这个map中添加键值对信息,这些信息可以通过layout以指定key的方式显示出来。
ndc主要的使用接口有:
1 public class ndc {
2 public static string get();
3 public static string pop();
4 public static string peek();
5 public static void push(string message);
6 public static void remove();
即使用前,将和当前上下文信息push如当前线程栈,使用完后pop出来:
1 @test
2 public void testndc() {
3 patternlayout layout = new patternlayout();
4 layout.setconversionpattern("%x - %m%n");
5 configsetup(layout);
6
7 ndc.push("levin");
8 ndc.push("ding");
9 logtest();
10 ndc.pop();
11 ndc.pop();
12 }
13 levin ding - begin to execute testbasic() method
14 levin ding - executing
15 levin ding - catching an exception
16 java.lang.exception: deliberately throw an exception
17 at levin.log4j.layout.layouttest.logtest(layouttest.java:86)
18
19 levin ding - execute testbasic() method finished.
ndc所有的操作都是针对当前线程的,因而不会影响其他线程。而在ndc实现中,使用一个hashtable,其key是线程实例,这样的实现导致用户需要手动的调用remove方法,移除那些push进去的数据以及移除那些已经过期的线程数据,不然就会出现内存泄露的情况;另外,如果使用线程池,在没有及时调用remove方法的情况下,容易前一线程的数据影响后一线程的结果。很奇怪为什么这里没有threadlocal或者是weakreference,这样就可以部分的解决忘记调用remove引起的后果,貌似是出于兼容性的考虑?
mdc使用了theadlocal,因而它只能使用在jdk版本大于1.2的环境中,然而其代码实现和接口也更加简洁:
1 public class mdc {
2 public static void put(string key, object o);
3 public static object get(string key);
4 public static void remove(string key);
5 public static void clear();
类似ndc,mdc在使用前也需要向其添加数据,结束后将其remove,但是remove操作不是必须的,因为它使用了theadlocal,因而不会引起内存问题;不过它还是可能在使用线程池的情况下引起问题,除非线程池在每一次线程运行结束后或每一次线程运行前将threadlocal的数据清除:
2 public void testmdc() {
4 layout.setconversionpattern("ip:%x{ip} name:%x{name} - %m%n");
7 mdc.put("ip", "127.0.0.1");
8 mdc.put("name", "levin");
10 mdc.remove("ip");
11 mdc.remove("name");
13 ip:127.0.0.1 name:levin - begin to execute testbasic() method
14 ip:127.0.0.1 name:levin - executing
15 ip:127.0.0.1 name:levin - catching an exception
17 at levin.log4j.layout.layouttest.logtest(layouttest.java:100)
19 ip:127.0.0.1 name:levin - execute testbasic() method finished.
虽然log4j提供了ndc和mdc机制,但是感觉它的实现还是有一定的侵入性的,如果要替换log模块,则会出现一定的改动,虽然我也想不出更好的解决方法,但是总感觉这个不是一个比较好的方法,在我自己的项目中基本上没有用到这个特性。