最近稍微大致地阅读了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负担，以及避免过量异步带来的开销。