一个月前因为某些事情被困宁波三天，在酒店里闲着无事，然后开始看Log4J的源码。原本之后的一个星期就应该开始写了，无奈又遇到一些事情，迟迟没有动笔。感觉工作后要做好一件额外的事情总是很难，每天下班后才能看代码、写文章，而如果中途遇到一些没有预料到的事情就很容易不了了之了，所以现在如果出现能静下心来看代码、写文章的时间，我都是特别珍惜。我一直不知道如何开场一篇文章，所以先用一些废话做引子….:(
在软件开发过程中，出现bug总是在所难免；事实上，以我个人经验，即使在实际开发阶段，fix bug时间要远超过写代码的时间。在开发阶段，比较有效的fix bug的方法当然是调试，然而如果代码比较复杂，而且开始对代码不是很熟悉，那么我们很容易在方法调用之间迷失方向；如果bug出现在多线程环境中，那么很多时候调试就无能为力了；另外当代码部署到服务器上运行时，不管是在UAT测试环境还是Production环境，此时要调试很多时候是不可能。为了解决这些问题，我们可以在开发过程中事先在一些关键点上打印出一些日志信息（log），以利于在出问题后能知道当时运行的环境信息，特别是在production上，我们可以分析log以确定问题所在，当然前提log信息足够多。不过加入日志信息后，不难想象，它会对程序的运行性能产生一定的影响，而且如果log过多会导致有用的信息不容易找到，如果过少又不具备很大的参考价值，这样的日志除了降低程序的性能，貌似对其他方面没有帮助。关于性能，Log4J号称在这面做了很多优化，但是据说logback做的更好（logback的源码还没来得及看，而且也没用过，所以还不是很了解）；而关于如何写log、在哪里写log、要把那些信息写入log中，个人感觉这是一门很大的学问，而且也是根据不同项目而不同，而本人也还没有达到那种可以列出一些比较详细的指导点，因而本文将不会涉及到这方面，本文主要从源码角度关注Log4J是如何实现的。
以下将用循序渐进的方式来讲解简单的日志类实现，并最后引出Log4J日志系统的核心实现。
直接打印日志到控制台
最简单的Logging功能实现，我想应该就是直接使用System.out.println()将需要的信息打印到控制台中了：
2 public void testBasic() {
3 System.out.println("Begin to execute testBasic() method
4
5 System.out.println("Executing
6 try {
7 throw new Exception("Deliberately throw an Exception
8 } catch(Exception e) {
9 System.out.println("Catching an Exception: " + e.getMessage());
10 e.printStackTrace(System.out);
11 }
12
13 System.out.println("Execute testBasic() method finished.");
14 }
这种方法最大的好处就是简单方便，而且不用引入第三方的依赖包。而它的功能自然也是最弱的：
1. 首先它只能将日志信息打印到控制台；
2. 它不支持分类日志信息，有些日志只是用于调试信息，在上production后不可以打印出来；而另一些日志信息则是包含一些重要信息，需要再production现实出来；有些时候为了进一步提升程序运行性能或者部署者认为系统已经很稳定了，日志信息并不是很重要，因而只需要打印错误信息、甚至关闭日志功能，在这种情况下，用这种方法就会非常麻烦。
3. 每一句日志记录中可能包含一些相似的信息，如日志级别、日志记录打印时间、日志记录对应的类等信息，如果要实现这种功能，则会出现很多重复代码。
4. 很多时候，我们希望保留日志，以备日后分析、审查用，随着日志信息的不断积累，我们并不希望所有的日志文件都在同一个文件中，而是希望日志文件能够根据一定的规则自动的切换使用新的文件。
封装日志类SimpleLog1
封装是面向对象的三大特性之一，它把对象的数据和行为聚合在一起，只提供给外界需要的接口，以提高代码的可重用性、降低代码之间的耦合、进而也增加代码的内聚性。因而对上述直接打印日志到控制台的一个简单的重构即是将打印日志的代码都提取到一个简单的日志类中：SimpleLog1。
SimpleLog1也是将日志直接打印到控制台，但是它引入了日志级别（Level，或类别）的支持：trace、debug、info、warn、error、fatal、all、off；另外，它也会自动的在每一条日志记录之前加入日志级别、日志名称、日志消息、异常堆栈等信息。
2 public static final int LOG_LEVEL_TRACE = 1;
3 public static final int LOG_LEVEL_DEBUG = 2;
4 public static final int LOG_LEVEL_INFO = 3;
5 public static final int LOG_LEVEL_WARN = 4;
6 public static final int LOG_LEVEL_ERROR = 5;
7 public static final int LOG_LEVEL_FATAL = 6;
8 public static final int LOG_LEVEL_ALL = (LOG_LEVEL_TRACE - 1);
9 public static final int LOG_LEVEL_OFF = (LOG_LEVEL_FATAL + 1);
10
11 private final String name;
12 private final int level;
13 public SimpleLog1(String name, int level) {
14 this.name = name;
15 this.level = level;
16 }
17 public SimpleLog1(Class<?> cls, int level) {
18 this(cls.getName(), level);
19 }
20 public void trace(String message) {
21 trace(message, null);
22 }
23 public void trace(String message, Throwable cause) {
24 log(LOG_LEVEL_TRACE, message, cause);
25 }
26 public boolean isTraceEnabled() {
27 return isLevelEnabled(LOG_LEVEL_TRACE);
28 }
29
30 private void log(int type, String message, Throwable cause) {
31 if(!isLevelEnabled(type)) {
32 return;
33 }
34 StringBuilder builder = new StringBuilder(32);
35
36 putLevelString(builder, type);
37 putLogName(builder, name);
38 builder.append(message);
39 if(cause != null) {
40 putCauseInfo(builder, cause);
41 }
42
43 writeLog(builder);
44 }
45 private void putLevelString(StringBuilder builder, int type) {
46 switch(type) {
47 case SimpleLog1.LOG_LEVEL_TRACE:
48 builder.append("[TRACE] "); break;
49 case SimpleLog1.LOG_LEVEL_DEBUG:
50 builder.append("[DEBUG] "); break;
51 case SimpleLog1.LOG_LEVEL_INFO:
52 builder.append("[INFO] "); break;
53 case SimpleLog1.LOG_LEVEL_WARN:
54 builder.append("[WARN] "); break;
55 case SimpleLog1.LOG_LEVEL_ERROR:
56 builder.append("[ERROR] "); break;
57 case SimpleLog1.LOG_LEVEL_FATAL:
58 builder.append("[FATAL] "); break;
59 }
60 }
61 private void putLogName(StringBuilder builder, String name) {
62 builder.append(name);
63 builder.append("-");
64 }
65 private void putCauseInfo(StringBuilder builder, Throwable cause) {
66 builder.append("<");
67 builder.append(cause.getMessage());
68 builder.append(">");
69 builder.append(System.getProperty("line.separator"));
70
71 StringWriter writer = new StringWriter();
72 PrintWriter printer = new PrintWriter(writer);
73 cause.printStackTrace(printer);
74 printer.close();
75 builder.append(writer.toString());
76 }
77 private void writeLog(StringBuilder builder) {
78 System.out.println(builder.toString());
79 }
80 private boolean isLevelEnabled(int level) {
81 if(level >= this.level) {
82 return true;
83 }
84 return false;
85 }
86 }
将打印日志封装成一个类并支持不同级别的日志打印信息后，打印日志的代码看起来更合理一些了，而且也可以为每一条日志记录加入一些共同的信息了，如日志级别、日志名称等：
2 public void testSimpleLog1() {
3 SimpleLog1 log = new SimpleLog1("levin.commons.logging.test.TestBasic",
4 SimpleLog1.LOG_LEVEL_DEBUG);
5 log.info("Begin to execute testBasic() method
6
7 log.info("Executing
8
9 try {
10 throw new Exception("Deliberately throw an Exception
11 } catch(Exception e) {
12 log.error("Catching an Exception", e);
13 }
14
15 log.info("Execute testBasic() method finished.");
16 }
然而上述的日志类SimpleLog1还是太简单了，它需要为每个日志打印实例指定日志级别、不支持打印日志到文件、不能方便的配置每条日志记录的共同信息。因而我们还需要支持可配置的日志类。
可配置的日志类SimpleLog2
虽然日志功能在应用程序开发中是一个非常重要的部件，有些时候日志信息的好坏可以直接影响程序开发的进度。然而日志本身不涉及到任何业务逻辑，因而需要尽量减少它的侵入性，也就说它提供的接口应该尽量的简单。为了实现接口的简单性，其中一种方法就是使用配置文件记录SimpleLog2的配置信息，SimpleLog2则根据配置信息初始化每一个SimpleLog2实例。这些配置信息包括是否显示日志名称、时间信息；如果显示日志打印时间，其格式如何；默认的日志级别是什么；支持单独配置一些日志名称的日志级别；如果将日志打印到日志文件，则日志文件的名称和目录在哪里等信息。
2
3 private static final String PROP_PREFIX = "levin.commons.logging.simplelog.";
4 private static final String PROP_LOG_PREFIX = PROP_PREFIX + "log.";
5 private static final String DEFAULT_DATA_FORMAT = "yyyy-MM-dd HH:mm:ss,SSS zzz";
6 private static final String DEFAULT_LEVEL = "debug";
7
8 private static SimpleDateFormat dateFormat = null;
9 private static boolean showLogName = true;
10 private static boolean showShortName = false;
11 private static boolean showDateInfo = false;
12 private static boolean flush = true;
13 private static int rootLevel;
14 private static Map<String, Integer> configLevels;
15 private static PrintStream out;
16
17 static {
18 InputStream in = getConfigInputStream("simplelog.properties");
19 Properties props = new Properties();
20 if(in != null) {
21 try {
22 props.load(in);
23 in.close();
24 } catch(IOException e) {
25 // Ignored
26 }
27 }
28 // Put all system properties
29 props.putAll(System.getProperties());
30
31 showLogName = getBooleanProperty(props, PROP_PREFIX + "showLogName", "true");
32 showShortName = getBooleanProperty(props, PROP_PREFIX + "showShortName", "false");
33 showDateInfo = getBooleanProperty(props, PROP_PREFIX + "showDateInfo", "false");
34 String dateFormatStr = getProperty(props, PROP_PREFIX + "dateFormat", DEFAULT_DATA_FORMAT);
35 dateFormat = new SimpleDateFormat(dateFormatStr);
36 rootLevel = toIntegerLevel(getProperty(props, PROP_PREFIX + "root.level", DEFAULT_LEVEL));
37 configLevels = parseConfigLevels(props);
38 String logFile = getProperty(props, PROP_PREFIX + "logFile", "");
39 boolean append = getBooleanProperty(props, PROP_PREFIX + "logFile.append", "true");
40 out = getPrintStream(logFile, append);
41 flush = getBooleanProperty(props, PROP_PREFIX + "logFile.flush", "true");
42
43 // Add shutdown hook
44 Runtime runtime = Runtime.getRuntime();
45 runtime.addShutdownHook(new Thread() {
46 @Override
47 public void run() {
48 try {
49 shutdown();
50 } catch(Exception e) {
51 System.err.println("Shutdown SimpleLog2 application failed.");
52 e.printStackTrace(System.err);
53 }
54 }
55 });
56 }
57 private static Map<String, Integer> parseConfigLevels(Properties props) {
58 Map<String, Integer> map = new TreeMap<String, Integer>();
59 for(String key : props.stringPropertyNames()) {
60 if(key != null && key.startsWith(PROP_LOG_PREFIX)) {
61 String logLevelValue = props.getProperty(key);
62 String logName = parseLogName(key);
63 map.put(logName, toIntegerLevel(logLevelValue));
64 }
65 }
66 return map;
67 }
68 private static String parseLogName(String logNameKey) {
69 return logNameKey.substring(PROP_LOG_PREFIX.length());
70 }
71 private static PrintStream getPrintStream(String logFile, boolean append) {
72 if(logFile == null || logFile.isEmpty()) {
73 return System.out;
74 }
75
76 PrintStream out = null;
77 try {
78 out = new PrintStream(new FileOutputStream(logFile, append));
79 } catch(IOException e) {
80 System.err.println("Error while create logFile[" +
81 logFile + " PrintStream: " + e.getMessage());
82 System.err.println("Output log info to console by default");
83 return System.out;
84 }
85
86 return out;
87 }
88 private static synchronized void writeLog(StringBuilder builder) {
89 out.println(builder.toString());
90 if(flush) {
91 out.flush();
92 }
93 }
94 private static InputStream getConfigInputStream(String configName) {
95 ClassLoader classLoader = getContextClassLoader();
96 InputStream in = classLoader.getResourceAsStream(configName);
97 if(in == null) {
98 in = SimpleLog2.class.getClassLoader().getResourceAsStream(configName);
99 }
100 if(in == null) {
101 in = SimpleLog2.class.getResourceAsStream(configName);
102 }
103 return in;
104 }
105 private static ClassLoader getContextClassLoader() {
106 return Thread.currentThread().getContextClassLoader();
107 }
108 private String name;
109 private int level;
110 private String shortName;
111
112 public SimpleLog2(String name) {
113 this.name = name;
114 this.level = getLogLevel(name);
115 }
116 public SimpleLog2(Class<?> cls) {
117 this(cls.getName());
118 }
119 public void setLevel(int level) {
120 this.level = level;
121 }
122 public void trace(String message) {
123 trace(message, null);
124 }
125 public void trace(String message, Throwable cause) {
126 log(LOG_LEVEL_TRACE, message, cause);
127 }
128 public boolean isTraceEnabled() {
129 return isLevelEnabled(LOG_LEVEL_TRACE);
130 }
131
132 private int getLogLevel(String logName) {
133 if(configLevels == null || configLevels.isEmpty()) {
134 return rootLevel;
135 }
136 int logLevel = -1;
137 for(String name : configLevels.keySet()) {
138 if(logName.startsWith(name)) {
139 logLevel = configLevels.get(name);
140 }
141 }
142 if(logLevel == -1) {
143 logLevel = rootLevel;
144 }
145 return logLevel;
146 }
147 private void log(int type, String message, Throwable cause) {
148 if(!isLevelEnabled(type)) {
149 return;
150 }
151
152 StringBuilder builder = new StringBuilder(32);
153
154 putDateInfo(builder);
155 putLevelString(builder, type);
156 putLogName(builder, name);
157 builder.append(message);
158 putCauseInfo(builder, cause);
159
160 writeLog(builder);
161 }
162 private void putDateInfo(StringBuilder builder) {
163 if(showDateInfo) {
164 Date date = new Date();
165 String dateStr = null;
166 synchronized(dateFormat) {
167 dateStr = dateFormat.format(date);
168 }
169 builder.append(dateStr);
170 }
171 }
172 private void putLevelString(StringBuilder builder, int type) {
173 switch(type) {
174 case SimpleLog1.LOG_LEVEL_TRACE:
175 builder.append("[TRACE] "); break;
176 case SimpleLog1.LOG_LEVEL_DEBUG:
177 builder.append("[DEBUG] "); break;
178 case SimpleLog1.LOG_LEVEL_INFO:
179 builder.append("[INFO] "); break;
180 case SimpleLog1.LOG_LEVEL_WARN:
181 builder.append("[WARN] "); break;
182 case SimpleLog1.LOG_LEVEL_ERROR:
183 builder.append("[ERROR] "); break;
184 case SimpleLog1.LOG_LEVEL_FATAL:
185 builder.append("[FATAL] "); break;
186 }
187 }
188 private void putLogName(StringBuilder builder, String name) {
189 if(showShortName) {
190 builder.append(getShortName(name));
191 } else if(showLogName) {
192 builder.append(name);
193 }
194 builder.append(" - ");
195 }
196 private void putCauseInfo(StringBuilder builder, Throwable cause) {
197 if(cause == null) {
198 return;
199 }
200 builder.append("<");
201 builder.append(cause.getMessage());
202 builder.append(">");
203 builder.append(System.getProperty("line.separator"));
204
205 StringWriter writer = new StringWriter();
206 PrintWriter printer = new PrintWriter(writer);
207 cause.printStackTrace(printer);
208 printer.close();
209 builder.append(writer.toString());
210 }
211 private boolean isLevelEnabled(int level) {
212 if(level >= this.level) {
213 return true;
214 }
215 return false;
216 }
217 private String getShortName(String name) {
218 if(shortName == null) {
219 if(name == null) {
220 shortName = "null";
221 return shortName;
222 }
223 int idx = name.lastIndexOf(".");
224 if(idx < 0) {
225 shortName = name;
226 } else {
227 shortName = name.substring(idx + 1);
228 }
229 }
230 return shortName;
231 }
232 }
在使用配置文件后，在没有增加SimpleLog2接口复杂性的基础上，使其功能更加强大，并且每个SimpleLog2的实例的日志级别都是不需要在代码中配置，并且它还支持了不同日志实例级别的继承性：
2 public void testSimpleLog2() {
3 SimpleLog2 log = new SimpleLog2("levin.commons.logging.test.TestBasic");
4 log.info("Begin to execute testBasic() method
5
6 log.info("Executing
7
8 try {
9 throw new Exception("Deliberately throw an Exception
10 } catch(Exception e) {
11 log.error("Catching an Exception", e);
12 }
13
14 log.info("Execute testBasic() method finished.");
15 }
其中典型的配置文件如下（simplelog.properties）：
levin.commons.logging.simplelog.showDateInfo=true
levin.commons.logging.simplelog.dateFormat=yyyy-MM-dd HH:mm:ss,SSS zzz
levin.commons.logging.simplelog.root.level=debug
levin.commons.logging.simplelog.logFile=log/levin.log
levin.commons.logging.simplelog.logFile.append=true
levin.commons.logging.simplelog.logFile.flush=true
levin.commons.logging.simplelog.log.level=fatal
levin.commons.logging.simplelog.log.level.commons=info
Log4J核心架构
到目前为止，我们已经简单的实现了一个可用的日志系统了，它只有一个类，而且还支持配置文件。事实上，这里的实现参考了commons-logging中的SimpleLog类，而且也部分借鉴了Log4J的实现，只是Log4J将日志打印的各个模块用不同的类进行了封装：Logger类封装了一个命名日志类，它是Log4J和使用它的应用程序的主要接口，提供打印不同级别日志的接口；Logger类包含了Level字段和Appender集合，其中Level表达当前Logger类可打印日志信息的级别；Appender接口用于对日志输出目的地的抽象，它可以是控制台、文件、网络等；Appender中包含了Layout字段，Layout类是对一条日志记录的格式的抽象，它定义了每条日志记录打印的信息内容、格式、不同类型信息的排列顺序等；而LoggingEvent类则是对每一条日志记录的抽象和封装，从而每一条日志记录所具有的信息都可以从LoggingEvent实例中查询，LoggingEvent的设计思想有点类似很多系统中的Context概念或者Servlet中的HttpRequest、HttpSession等类的设计，它将每一次日志打印的请求信息封装在一个类中，保证了数据的内聚性，所有需要获取请求信息的类只要拿到这个实例即可，而且如果需要改变请求中的部分数据，只要修改该实例即可保证该修改对所有的模块可见，从而简化了编程模型，也不会因为将很多信息分散到不同地方而到后期出现数据同步问题或是数据太分散而无法管理的问题。
通过以上分析，我们可以知道Log4J的日志打印功能的最核心类即：Logger、Appender、Level、Layout、LoggingEvent。它们的类结构图如下：
一次日志打印的序列图如下：