一個月前因為某些事情被困寧波三天,在酒店里閑著無事,然后開始看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。它們的類結構圖如下:
一次日志打印的序列圖如下: