最近稍微大致地阅读了log4j的源码,毕竟这是Java开源日志框架里几乎最常用的一个实现。在大多数实际应用中,还需要诸如common-logging、slf4j等Facade模式日志框架对log4j进行封装,实际日志记录、输出等级、格式化等工作都是由log4j完成。本文把注意力集中在log4j身上,探讨一下这个开源日志框架的内部。
特性
关于log4j的具体配置以及例子这里就不多说了,主要集中说一下其配置特性。作为一个开源日志框架,为了满足大部分日志需求,log4j的配置较为灵活,并且也较为容易理解,实际配置起来也并不复杂。
主要有以下可配置特性:
- 日志等级:DEBUG、INFO、WARN、ERROR等;
- 输出方式(Appender):log4j自带就有AsyncAppender、ConsoleAppender、RollingFileAppender、DailyRollingFileAppender等,还可以自己实现对应接口来定制。
- 输出格式(Layout):log4j同样自带了有PatternLayout、DateLayout等
- 可按照package的”父子“关系来让子package继承父package配置。
架构大致
主要是通过LogManager提供接口,然后Hierachy管理Logger的继承层次,LogEvent封装要记录日志的信息,另外还有Layout和Appender的层次封装实现功能等。
一些实现细节
log4j为了提高日志记录带来的性能影响,对于一些实现细节做了大量的优化。
- 日期和大小限制的日志判断
如果设置了日志记录的时间以及文件大小限制,这样每到限制时,就会进行rollover,也就是关闭当前文件,打开新的文件重新进行日志记录。因为这样需要每次打log都要进行判断,为了提高性能,对于日期大小,都会预先计算好下一次需要rollover的时间nextCheck,然后每次记录日志时只需要拿当前时间判断即可。代码如下:
//DailyRollingFileAppender
protected void subAppend(LoggingEvent event) {
long n = System.currentTimeMillis();
if (n >= nextCheck) {
now.setTime(n);
nextCheck = rc.getNextCheckMillis(now);
try {
rollOver();
}
catch(IOException ioe) {
if (ioe instanceof InterruptedIOException) {
Thread.currentThread().interrupt();
}
LogLog.error("rollOver() failed.", ioe);
}
}
super.subAppend(event);
}
}
对于文件大小限制,由于每次取文件大小较为麻烦,有种办法就是把每次log的size大小添加到count变量,然后再判断是否超过大小,超过则进行rollover操作。代码如下:
//RollingFileAppender
protected
void subAppend(LoggingEvent event) {
super.subAppend(event);
if(fileName != null && qw != null) {
long size = ((CountingQuietWriter) qw).getCount();
if (size >= maxFileSize && size >= nextRollover) {
rollOver();
}
}
}
}
//CountingQuietWriter
public
void write(String string) {
try {
out.write(string);
count += string.length();
}
catch(IOException e) {
errorHandler.error("Write failure.", e, ErrorCode.WRITE_FAILURE);
}
}
public
long getCount() {
return count;
}
- 填充pattern的空白区域
填充pattern的时候,如果内容没有超过最小size,则需要进行空白字符填充。log4j采用了一种fast space padding的方法,主要是把需要填充的长度分成两部分考虑,超过32的部分,则循环添加32个空格,少于32的话,则采用长度的bit位进行与判断来添加对应的1,2,4,8,16个空格字符。这样如果要填充的空白字符少于32,顶多需要4次循环即可解决。代码如下:
static String[] SPACES = {" ", " ", " ", " ", //1,2,4,8 spaces
" ", // 16 spaces
" " }; // 32 spaces
/**
Fast space padding method.
*/
public
void spacePad(StringBuffer sbuf, int length) {
while(length >= 32) {
sbuf.append(SPACES[5]);
length -= 32;
}
for(int i = 4; i >= 0; i--) {
if((length & (1<<i)) != 0) {
sbuf.append(SPACES[i]);
}
}
}
}
- Logger的继承
对于log4j,认为Java的包x.y.z是包x.y的子包,如果定义了父包x.y的属性,则子包会自动继承。为了实现这个,log4j利用了Logger内部的一个parent引用,这样当获取属性的时候,只需要通过parent指针获取其属性即可。在getLogger的时候,会动态计算出这个parent引用,由于父包和子包调用getLogger的顺序不能确定,因此要保证在性能理想的情况下,能够保证parent能够正确设置,log4j使用了一个ProvisionNode作为占位来辅助判断。代码如下:
public
Logger getLogger(String name, LoggerFactory factory) {
//System.out.println("getInstance("+name+") called.");
CategoryKey key = new CategoryKey(name);
// Synchronize to prevent write conflicts. Read conflicts (in
// getChainedLevel method) are possible only if variable
// assignments are non-atomic.
Logger logger;
synchronized(ht) {
Object o = ht.get(key);
if(o == null) {
logger = factory.makeNewLoggerInstance(name);
logger.setHierarchy(this);
ht.put(key, logger);
updateParents(logger);
return logger;
} else if(o instanceof Logger) {
return (Logger) o;
} else if (o instanceof ProvisionNode) {
//System.out.println("("+name+") ht.get(this) returned ProvisionNode");
logger = factory.makeNewLoggerInstance(name);
logger.setHierarchy(this);
ht.put(key, logger);
updateChildren((ProvisionNode) o, logger);
updateParents(logger);
return logger;
}
else {
// It should be impossible to arrive here
return null; // but let's keep the compiler happy.
}
}
}
如果子包的类先调用getLogger,则此时获得的Logger为NULL,这样在updateParents的时候,会不断根据x.y、x这样的顺序创建父包的
ProvisionNode作为占位,如果仍然没有找到父包,则会把root的Logger作为默认的父亲,这样就保证一定有默认属性。如果是父包的类先调用getLogger,则会获得ProvisionNode,这样就需要把ProvisionNode记录的子Logger更新parent引用。这样就保证在getLogger的时候保证顺序正常,同时也保证了通过parent获取继承属性也比较快。updateChildren和updateParents方法如下:
final
private
void updateParents(Logger cat) {
String name = cat.name;
int length = name.length();
boolean parentFound = false;
//System.out.println("UpdateParents called for " + name);
// if name = "w.x.y.z", loop thourgh "w.x.y", "w.x" and "w", but not "w.x.y.z"
for(int i = name.lastIndexOf('.', length-1); i >= 0;
i = name.lastIndexOf('.', i-1)) {
String substr = name.substring(0, i);
//System.out.println("Updating parent : " + substr);
CategoryKey key = new CategoryKey(substr); // simple constructor
Object o = ht.get(key);
// Create a provision node for a future parent.
if(o == null) {
//System.out.println("No parent "+substr+" found. Creating ProvisionNode.");
ProvisionNode pn = new ProvisionNode(cat);
ht.put(key, pn);
} else if(o instanceof Category) {
parentFound = true;
cat.parent = (Category) o;
//System.out.println("Linking " + cat.name + " -> " + ((Category) o).name);
break; // no need to update the ancestors of the closest ancestor
} else if(o instanceof ProvisionNode) {
((ProvisionNode) o).addElement(cat);
} else {
Exception e = new IllegalStateException("unexpected object type " +
o.getClass() + " in ht.");
e.printStackTrace();
}
}
// If we could not find any existing parents, then link with root.
if(!parentFound)
cat.parent = root;
}
final
private
void updateChildren(ProvisionNode pn, Logger logger) {
//System.out.println("updateChildren called for " + logger.name);
final int last = pn.size();
for(int i = 0; i < last; i++) {
Logger l = (Logger) pn.elementAt(i);
//System.out.println("Updating child " +p.name);
// Unless this child already points to a correct (lower) parent,
// make cat.parent point to l.parent and l.parent to cat.
if(!l.parent.name.startsWith(logger.name)) {
logger.parent = l.parent;
l.parent = logger;
}
}
}
- NDC和MDC
NDC和MDC能够方便地为不同线程提供上下文。NDC使用HashTable记录线程的stack信息,配置log4j的使用使用%x就可以打印出该信息,方便追踪。MDC则是用ThreadLocal保存。概念挺不错,但是代码实现得比较难看,就不拿出来了。
- 实现不够好的地方
1、由于log4j是在早期实现的一个开源日志框架,代码里还有对Java1的支持,因此在一些集合容器选择上较为“落后”。如大部分线程同步都直接选择HashTable、Stack等实现上直接使用synchronized关键字进行同步的容器,这些容器的并发远远差于1.5开始存在的concurrent的集合,如ConcurrentHashMap、CopyOnWriteArrayList等容器。因此事实上HashTable、Stack等容器其实已经是不推荐使用的。
2、对于MDC使用ThreadLocal保存不同线程上下文的方式,或许没有注意到ThreadLocal的Entry是WeakReference,因此很容易就会被gc回收掉,这样上下文内容就会神不知鬼不觉消失。
3、对于AsyncAppender,这个异步Appender的实现,采用的是一种消费-生产模式的线程同步。使用的也是对象监视器的wait、notifyAll以及ArrayList作为队列的同步。这里理所当然采用BlockingQueue等子类同步队列会很好多。
4、众所周知,在写文件的时候如果使用Buffer则会大大提升性能,同样,log4j也提供了设置buffer属性,但遗憾的是,如果没有注意flush,在程序退出的时候会丢失一些日志记录,虽然log4j提供了LogManager.shutdown方法,但如果程序异常退出从而没有调用shutdown则也是很麻烦。因此缺乏一种有效的手段去解决问题。
- 对比个人之前的一个日志实现
之前本人曾经为Android写过一个日志实现。由于Android本身对于流畅运行要求极高,为了实现最佳的日志性能,实现了一个Buffer+异步日志记录功能的模块。
主要是利用OutputStream的传递性。大致如下:
OutputStream writer = new BufferedOutputStream(new AsyncOutputStream(new FileOutputStream));
这样在Buffer写满的时候,便会自动转为异步写文件,这种记录日志的方式应该能最大化减轻记录日志所带来的IO负担,以及避免过量异步带来的开销。