Log4j是一个历史非常悠久的库首次发布与2001年1月,有17年历史了,那个时候Java才发布1.3版本,所以也可以从Log4j的代码中看到他使用了很多古老的JDK类,比如Hashtable,可能是因为兼容性的考虑,后续的版本也一直没有升级这些地方。虽然Log4j历史悠久,但是应该还是使用最广泛的日志实现,我们分析其实现,还是能学到很多东西的,对于后续分析Log4j2或者Logback,都是有帮助的。
在读源码之前有几个疑问:
我们分为几个部分来了解Log4j的实现:
上图为Log4j的整体结构。Log4j中最重要的三个角色:
这几个关键类和Log4j的配置项是一一对应的。Log4j在初始化时会解析配置,生成具体的Appender和Layout实现类,关联到指定的Logger上。同理,我们也可以在代码中直接配置。
比如 BasicConfigurator.configure() 这个Log4j提供的简化配置方法,可以在没有配置文件的情况下,把日志输出到控制台中,他就是直接使用代码配置的:
static public void configure() {
Logger root = Logger.getRootLogger();
// 设置RootLogger的Appender为ConsoleAppender
// 设置Layout为PatternLayout
root.addAppender(new ConsoleAppender(
new PatternLayout(PatternLayout.TTCC_CONVERSION_PATTERN)));
}
Logger是一个树结构的关系。根节点是RootLogger,这个是固定的。这个树结构和我们数据结构中学的树有一点不一样的地方,不是父节点中保存子节点的连接,而是子节点中保存父节点的连接。这和Logger的场景是匹配的,打印日志时, x.y 的Logger,首先查看自己身上是否配置有日志级别和Appender,如果有输出,然后查看其父Logger x ,查看是否配置有日志级别和Appender,如果有输出,然后再查看 x 的父Logger,也就是RootLogger,RootLogger一定会配置有日志级别,根据级别与Appender进行相应的操作。日志的继承关系是Log4j的核心。
除了每个Logger通过 parent 属性管理父Logger之外。还需要一个地方来保存所有的Logger,否则在新建Logger的时候,没法去查询对应的父Logger实例了。保存所有Logger的地方就在日志仓库LoggerRepository中,具体的实现类为Hierachy,这个类如其名,就是根据继承关系来管理Logger的日志仓库。其中有一个Hashtable来保存所有的Logger,key为Logger的name,value为Logger实例。
大致的结构说完了,我们来看一下一些场景的具体实现。
Log4j的初始化过程发生在LogManager的静态代码块中:
static final String DEFAULT_CONFIGURATION_FILE = "log4j.properties";
static final String DEFAULT_XML_CONFIGURATION_FILE = "log4j.xml";
static {
// 实例化Hierarchy,设置RootLogger,并关联到LogManager上
// 这里新建RootLogger设置的日志级别为DEBUG,也就是说如果你在日志中没有配置RootLogger,则他的日志级别为DEBUG
Hierarchy h = new Hierarchy(new RootLogger((Level) Level.DEBUG));
repositorySelector = new DefaultRepositorySelector(h);
// 从classpath中获取log4j.xml文件
// 如果不存在,则尝试获取log4j.properties文件
URL url = null;
url = Loader.getResource(DEFAULT_XML_CONFIGURATION_FILE);
if (url == null) {
url = Loader.getResource(DEFAULT_CONFIGURATION_FILE);
}
if (url != null) {
try {
// 配置文件存在,进入配置文件解析流程
OptionConverter.selectAndConfigure(url, configuratorClassName,
LogManager.getLoggerRepository());
} catch (NoClassDefFoundError e) {
LogLog.warn("Error during default initialization", e);
}
} else {
LogLog.debug("Could not find resource: [" + configurationOptionStr + "].");
}
}
初始化的过程,先实例化Hierarchy类,设置好RootLogger,后续就是尝试读取两种可能的配置文件了,可以看出 log4j.xml 的优先级是要高于 log4j.properties 的。
OptionConverter.selectAndConfigure() 方法根据不同的配置文件类型,使用 PropertyConfigurator 或者 DOMConfigurator 类对配置文件进行处理:
static public void selectAndConfigure(URL url, String clazz, LoggerRepository hierarchy) {
Configurator configurator = null;
String filename = url.getFile();
// 如果是xml文件,使用DOMConfigurator类
if (clazz == null && filename != null && filename.endsWith(".xml")) {
clazz = "org.apache.log4j.xml.DOMConfigurator";
}
if (clazz != null) {
LogLog.debug("Preferred configurator class: " + clazz);
configurator = (Configurator) instantiateByClassName(clazz,
Configurator.class,
null);
if (configurator == null) {
LogLog.error("Could not instantiate configurator [" + clazz + "].");
return;
}
} else {
// 其他情况使用PropertyConfigurator类
configurator = new PropertyConfigurator();
}
configurator.doConfigure(url, hierarchy);
}
配置处理器的类图:
这里以 PropertyConfigutator为 例:
public void doConfigure(Properties properties, LoggerRepository hierarchy) {
// ...
// 设置RootLogger
configureRootCategory(properties, hierarchy);
// 设置LoggerFactory,基本用不上
configureLoggerFactory(properties);
// 设置其他Logger
parseCatsAndRenderers(properties, hierarchy);
}
从配置设置Logger的细节很多这里就不看了,主要的步骤就是根据Log4j的配置规则,读取配置,新建Logger,设置Logger的name,level,appender,layout等,新建后的Logger会存入LogRepository中。
上面的初始化过程发生在LogManager第一次被加载时。而用户一般是不用与LogManager直接打交道的,用户通过 Logger.getLogger() 来获取Logger,这个方法代理调用 LogManger.getLogger() ,时序图如下:
// org.apache.log4j.LogManager#getLogger(java.lang.Class)
public static Logger getLogger(final Class clazz) {
// 获取日志仓库,通过日志仓库获取Logger
return getLoggerRepository().getLogger(clazz.getName());
}
// org.apache.log4j.Hierarchy#getLogger(java.lang.String, org.apache.log4j.spi.LoggerFactory)
public Logger getLogger(String name, LoggerFactory factory) {
// 保存在Hashtable中的Key对象
CategoryKey key = new CategoryKey(name);
Logger logger;
// 获取ht的锁,串行化getLogger流程
synchronized (ht) {
Object o = ht.get(key);
if (o == null) {
// 1. Hashtable中没有该Logger,新建Logger
// 新建后的Logger需要关联好其父Logger,
// 如果没有发现父Logger配置,则其父Logger为RootLogger
logger = factory.makeNewLoggerInstance(name);
logger.setHierarchy(this);
ht.put(key, logger);
updateParents(logger);
return logger;
} else if (o instanceof Logger) {
// 2. Hashtable中已经有缓存该Logger,直接返回
return (Logger) o;
} else if (o instanceof ProvisionNode) {
// 3. Hashtable中存在该name的ProvisionNode对象
// ProvisionNode对象是一个占位对象,比如配置了x.y Logger,
// 在初始化这个Logger时,会去寻找x Logger,但是x Logger不存在,
// 这个时候就会新建一个ProvisionNode对象,保存x对应的所有子Logger,
// 如果后续配置上x Logger,则可以通过ProvisionNode中的信息,建立x Logger
// 与所有其子Logger的父子关系
logger = factory.makeNewLoggerInstance(name);
logger.setHierarchy(this);
ht.put(key, logger);
updateChildren((ProvisionNode) o, logger);
updateParents(logger);
return logger;
} else {
// 不会进入的分支
return null;
}
}
}
如果日志文件中配置了 x.y Logger,则在读取配置时,这个Logger就新建好了, Logger.getLogger("x.y") 会直接从Hashtable中获取到。如果 Logger.getLogger("x.y.z") ,则会新建这个Logger,并设置Parent Logger为 x.y ,然后返回。
Log4j打印日志一般是使用具体的日志级别方法,比如 logger.debug("hello") ,这背后是什么流程呢?
public void debug(Object message) {
// 判断全局日志级别,全局日志级别由配置项log4j.threshold设置
if (repository.isDisabled(Level.DEBUG_INT))
return;
// 判断该Logger的日志级别,如果该Logger没有设置level,则查询父Logger的level,直到RootLogger
if (Level.DEBUG.isGreaterOrEqual(this.getEffectiveLevel())) {
forcedLog(FQCN, Level.DEBUG, message, null);
}
}
protected void forcedLog(String fqcn, Priority level, Object message, Throwable t) {
callAppenders(new LoggingEvent(fqcn, this, level, message, t));
}
public void callAppenders(LoggingEvent event) {
int writes = 0;
// 遍历处理该Logger,与其父Logger
for (Category c = this; c != null; c = c.parent) {
synchronized (c) {
if (c.aai != null) {
// 调用Logger关联的所有Appender进行输出
writes += c.aai.appendLoopOnAppenders(event);
}
// 如果设置additivity=false,则不会调用父Logger!
if (!c.additive) {
break;
}
}
}
if (writes == 0) {
repository.emitNoAppenderWarning(this);
}
}
Logger除了本身输出日志,还会调用父Logger进行输出,同时一些属性如果子Logger没有设置,也会使用父Logger的配置,Log4j官方的一张图片表示了这个关系:
上面代码可以看到重要配置项 additivity 的作用,如果 additivity=true ,也就是默认不配置时的效果,Logger的所有父Logger都会进行输出,如果 additivity=false ,则处理完这个Logger,就直接返回了。
日志输出的任务是交给Appender来处理的,我们这里以常用的FileAppender为例子。从前文的类图中可以看出FileAppender继承于WriterAppender。FileAppender的输出使用WriterAppender的实现:
public class WriterAppender extends AppenderSkeleton {
protected QuietWriter qw;
// 每次输出日志,是否调用Writer的flush方法。默认是每次都会调用
protected boolean immediateFlush = true;
protected void subAppend(LoggingEvent event) {
// 使用layout格式化消息,然后调用Writer的write方法输出日志
this.qw.write(this.layout.format(event));
// 判断是否设置了每次都调用flush方法,如果设置了,则调用flush方法
if (shouldFlush(event)) {
this.qw.flush();
}
}
}
WriterAppender的逻辑很直接,就是调用Writer的wter方法,然后根据配置判断是否需要跟着调用flush方法,默认情况下是每次都会调用flush的,也就是说,默认情况下,我们不用担心日志被Java框架层的缓存缓存住而导致刷新到文件中的时间较为滞后。
public class FileAppender extends WriterAppender {
// 是否使用缓冲IO,默认为false
protected boolean bufferedIO = false;
public synchronized void setFile(String fileName, boolean append, boolean bufferedIO, int bufferSize)
throws IOException {
// 如果使用缓冲IO,就不需要每次flush
if (bufferedIO) {
setImmediateFlush(false);
}
reset();
FileOutputStream ostream = null;
try {
ostream = new FileOutputStream(fileName, append);
} catch (FileNotFoundException ex) {
// ...
}
// 用FileOutputStream新建Writer,核心逻辑是new OutputStreamWriter()
Writer fw = createWriter(ostream);
// 如果配置指定要使用缓冲IO,则使用BufferedWriter进行内存缓冲
if (bufferedIO) {
fw = new BufferedWriter(fw, bufferSize);
}
this.setQWForFiles(fw);
this.fileName = fileName;
this.fileAppend = append;
this.bufferedIO = bufferedIO;
this.bufferSize = bufferSize;
writeHeader();
}
}
根据上面的分析,我们得出以下结论:
RollingFileAppender , DailyRollingFileAppender ,会根据配置的文件名新建FileOutputStream,然后进一步新建OutputStreamWriter,后续的日志操作,就是调用 Writer.write() 进行的 log4j.appender.{appenderName}.bufferedIO=true 配置项来开启缓冲区IO。开启缓冲区IO能提高打印日志的性能,但是会增加日志打印到日志写入文件的延迟。同时有一个需要关注的点是,如果开启缓冲区IO,如果程序异常退出,还未写入操作系统的日志就丢失了。而关闭缓冲IO的情况下,每次写入日志,都会调用操作系统的read系统调用,虽然这会儿日志内容不一定写到硬盘上,可能会存在于操作系统的页缓冲区中,但即使Java程序崩溃,只要操作系统不崩溃,日志是不会丢失的。这一块内容可以结合 Linux/UNIX编程如何保证文件落盘 和 Java如何保证文件落盘? 这两篇文章来学习。 根据以上分析,我们知道了日志打印时,Log4j先判断日志级别是否打开,然后交给Logger配置的Appender来输出日志。Appender先调用配置的Layout格式化日志,然后输出日志到具体的地方。比如FileAppender系列Appender会输出日志到文件,是通过OutputStreamWriter进行输出的。这个过程会在Logger的所有父Logger上进行,除非Logger本身配置了 additivity=false