Log4j札记 第十章 Log4j日志现场的秘密

Log4j笔记 第十章 Log4j日志现场的秘密
log4j日志现场背后的秘密

1、什么是日志现场
调用Logger打印日志的地方，称为日志现场。日志现场的属性有：类名、方法名、java文件名、和行数。
下面是一个例子。
LoggerTest.java

import org.apache.log4j.Logger;public class LoggerTest {private static final Logger logger = Logger.getLogger(LoggerTest.class);public static void main(String[] args) {new LoggerTest().test();}private void test() {// 下面一行就是日志现场 LoggerTest类，test方法，LoggerTest.java文件，第12行。logger.debug("Hello, log4j!");}}

2、让log4j在打印日志消息时，也打印出日志现场
在classpath下，添加一个log4j.xml的文件。内容如下：
log4j.xml

<?xml version="1.0" encoding="UTF-8" ?><!DOCTYPE log4j:configuration SYSTEM "log4j.dtd"><log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/" ><appender name="SYSTEM_OUT" value="%l: %m%n"/></layout></appender><root><!-- root 引用SYSTEM_OUT appender--><appender-ref ref="SYSTEM_OUT"/></root></log4j:configuration>

再运行上面的文件，
在控制台中，可以看到如下信息：日志现场（类名、方法名、java文件名、和行数）和消息。
consoleView

LoggerTest.test(LoggerTest.java:12): Hello, log4j!

3、封装log4j
在打印需要格式化的字符串时，使用Message.format()会出现如下代码。

logger.debug(MessageFormat.format(“Hello, {0}!”, “log4j”));

当日志级别大于debug时，不需要打印该消息。但是format方法还是会被调用。这造成了浪费。早期log4j官网推荐如下使用方式。

if(logger.isDebugEnabled()){logger.debug(MessageFormat.format(“Hello, {0}!”, “log4j”));}

这样就有了早期对log4j的封装版本。
CLogger.java

public class CLogger {public static void debug(Logger logger, String pattern, Object[] arguments) {if (logger.isDebugEnabled()) {logger.debug(MessageFormat.format(pattern, arguments));}}}

DLogger

import java.text.MessageFormat;import org.apache.log4j.Logger;public class DLogger {public static DLogger getLogger(Class<?> clazz) {return new DLogger(clazz);}private final Logger logger;private DLogger(Class<?> clazz) {logger = Logger.getLogger(clazz);}public void debug(String pattern, Object... arguments) {if (logger.isDebugEnabled()) {logger.debug(MessageFormat.format(pattern, arguments));}}}

4、使用封装的Logger出现的问题
一切安好，使用之。
LoggerTestThree.java

public class LoggerTestThree {private static final DLogger logger = DLogger.getLogger(LoggerTestThree.class);public static void main(String[] args) {LoggerTestThree loggerTestTwo = new LoggerTestThree();loggerTestTwo.test();}private void test() {logger.debug("Hello,{0}!", "log4j"); //我们想将日志现场定在这里。}}

使用上例的log4j.xml
在控制台看到如下信息：
console view

DLogger.debug(DLogger.java:19): Hello,log4j!

打印的日志现场是，调用Logger的debug的地方。经过我们的封装，我们希望日志现场为，调用DLogger的debug方法的地方。于是问题出来了，我们封装了日志类，也转移了日志现场。怎样找到日志现场呢？

5、如果是你，会如何定位日志现场的
首先得理解，java函数调用堆栈。从应用的入口函数（main函数）出发，对其他函数的调用，形成了函数调用堆栈。在java方法中，新建一个Throwable对象，该对象的StackTraceElement[]属性，就包括函数调用堆栈。
看如下代码：
LoggerTestTwo.java

public class LoggerTestTwo {private static final MyLogger logger = new MyLogger();public static void main(String[] args) {LoggerTestTwo loggerTestTwo = new LoggerTestTwo();loggerTestTwo.test();}private void test() {logger.debug();}}

MyLogger.java

public class MyLogger {public void debug() {Throwable throwable = new Throwable();StackTraceElement[] stackTraceElements = throwable.getStackTrace();for (StackTraceElement element : stackTraceElements) {System.out.println(element);}}}

运行上面代码，在控制台中可以看到如下信息：创建Throwable时的函数调用堆栈。
consoleView

MyLogger.debug(MyLogger.java:3)LoggerTestTwo.test(LoggerTestTwo.java:10)LoggerTestTwo.main(LoggerTestTwo.java:6)

设定我们的MyLogger.debug()方法对应，log4j中的Logger.debug()方法。那么日志现场LoggerTestTwo.test(LoggerTestTwo.java:10)就在其中。我们发现，在被MyLogger.debug() 调用的所有 (包括直接和间接调用) 方法中，新建一个Throwable，其函数调用堆栈都包括这些信息。

6、log4j是如何定位日志现场的
在被Logger的debug方法调用的方法中，创建一个Throwable对象，解析其函数调用堆栈，确认日志现场。
秘密1： fqcn（ fqnOfCallingClass，fqnOfCategoryClass） class name of first class considered part of the logging framework.  Location will be site that calls a method on this class.
fqcn是Logger的全类名。在与函数调用堆栈比对中，离开Logger类的下一个地址，就是日志现场。
在logger的debug方法，创建LoggingEvent时，传入一个名为fqcn值为Logger的全类名的字符串。这样在LoggingEven的 getLocationInformation()方法中，创建LocationInfo时，传入一个新建的Throwable和fqcn。

new LocationInfo(new Throwable(), fqnOfCategoryClass);

从LocationInfo中，既可得到日志现场。


7、改进封装log4j的技术
在log4j_1.2.16中，logMF和logSF提供了参考意见。
于是就有了上一章的封装log4j的实现。

查看更多 下一篇