一個月前因為某些事情被困甯波三天，在酒店裡閑着無事，然後開始看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()将需要的資訊列印到控制台中了：
1 @test
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也是将日志直接列印到控制台，但是它引入了日志級别（level，或類别）的支援：trace、debug、info、warn、error、fatal、all、off；另外，它也會自動的在每一條日志記錄之前加入日志級别、日志名稱、日志消息、異常堆棧等資訊。
1 public class simplelog1 {
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.");
然而上述的日志類simplelog1還是太簡單了，它需要為每個日志列印執行個體指定日志級别、不支援列印日志到檔案、不能友善的配置每條日志記錄的共同資訊。因而我們還需要支援可配置的日志類。
雖然日志功能在應用程式開發中是一個非常重要的部件，有些時候日志資訊的好壞可以直接影響程式開發的進度。然而日志本身不涉及到任何業務邏輯，因而需要盡量減少它的侵入性，也就說它提供的接口應該盡量的簡單。為了實作接口的簡單性，其中一種方法就是使用配置檔案記錄simplelog2的配置資訊，simplelog2則根據配置資訊初始化每一個simplelog2執行個體。這些配置資訊包括是否顯示日志名稱、時間資訊；如果顯示日志列印時間，其格式如何；預設的日志級别是什麼；支援單獨配置一些日志名稱的日志級别；如果将日志列印到日志檔案，則日志檔案的名稱和目錄在哪裡等資訊。
1 public class 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.showshortname=true
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
到目前為止，我們已經簡單的實作了一個可用的日志系統了，它隻有一個類，而且還支援配置檔案。事實上，這裡的實作參考了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。它們的類結構圖如下：
一次日志列印的序列圖如下：