文章轉自http://www.2cto.com/kf/201702/536097.html
slf4j+logback搭建超實用的日志管理模塊(對日志有編號管理):日志功能在服務器端再常見不過了,我們非常有必要記錄下發生在服務器上的活動,這些日志將用於debug、統計等各種用途。
slf4j+logback這種實現方式是很常見的,好處自然是方便!。在這篇文章中,你將看到如何使用logback搭建你自己的日志組件並將日志輸出到文件、如何查看這些文件、如何為每個線程上的訪問分配獨有的一個日志id。
基本概念和准備工作
首先,介紹幾個相關的基本概念:
- slf4j:全拼為Simple Logging Facade for Java,即“為java提供的簡單日志門面”,slf4j並不是一個具體的日志解決方案,實際上,它提供的核心api只是一個名為Logger的接口(里面封裝了你可能需要的各種日志方法)和一個名為LoggerFactory工廠類。這個slf4j其實就是外觀模式里的那個Facade,它使得你不用太過糾結於某個具體的日志框架,而是只要調用slf4j里的接口就行了。並且slf4j的性能幾乎是零消耗的,畢竟它不是什么具體的東西。slf4j同時具有外觀模式帶來的各種好處,比如在logback和log4j這些子系統間方便切換。
- logback:logback是log4j創始人設計的另一個開源日志組件。logback被設計成了原生支持slf4j,也就是說調用slf4j接口時,似乎會自動調用logback,而不需要你做任何配置。我並不是很清楚是不是真的這樣,也沒研究logback和slf4j具體是如何做到這點的,但這絕對是外觀模式的成功運用。以上內容我沒有做過認真考究,時間關系不研究了,有見解的同學歡迎下面指正。
接下來,你當然需要導入相關的包,我項目里的幾個包是這個:
- slf4j-api-1.7.21.jar
- logback-classic-1.1.7.jar
- logback-core-1.1.7.jar
應該是這三個包就夠了,反正如果不全,你自己去maven上下吧,也不麻煩。
配置logback
下面就是配置logback了,請在classpath下創建一個logback.xml(如果是springMVC,跟dispatcher-servlet.xml一個目錄就行了),然后配置如下:
1 <!--?xml version="1.0" encoding="UTF-8"?--> 2 3 <!-- 4 scan:當此屬性設置為true時,配置文件如果發生改變,將會被重新加載,默認值為true。 5 scanPeriod:設置監測配置文件是否有修改的時間間隔,如果沒有給出時間單位,默認單位是毫秒當scan為true時,此屬性生效。默認的時間間隔為1分鍾。 6 debug:當此屬性設置為true時,將打印出logback內部日志信息,實時查看logback運行狀態。默認值為false。 7 --> 8 <configuration debug="false" scan="true" scanperiod="1800 seconds"> 9 10 <!-- 定義日志的根目錄,日志文件將會在運行服務端的機器上的這個路徑上被創建 --> 11 <property name="log.shop" value="/data/logs/tomcat/shop"> 12 13 <!-- 滾動記錄文件,先將日志記錄到指定文件,當符合某個條件時,將日志記錄到其他文件 --> 14 15 16 <!-- 這里關閉謹慎模式,如果開啟謹慎模式,可以使多個JVM中運行的 17 多個FileAppender實例,安全的寫入到同一個日志文件。 --> 18 <prudent>false</prudent> 19 20 <!-- 基於時間的文件滾動 --> 21 <rollingpolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy"> 22 23 <!-- 文件命名規則,這么寫就是按天滾動了,每天一個日志文件 --> 24 <filenamepattern> 25 ${log.shop}.%d{yyyy-MM-dd}.log 26 </filenamepattern> 27 28 <!-- 可選節點,控制保留的歸檔文件的最大數量,超出數量就刪除舊文件。假設設置每天滾動, 29 且maxHistory是720,則只保存最近720天的文件,刪除之前的舊文件。注意,刪除舊文件是, 30 那些為了歸檔而創建的目錄也會被刪除。 --> 31 <maxhistory>720</maxhistory> 32 </rollingpolicy> 33 34 <!-- 配置日志的輸出格式,里面這些占位符具體什么意思,參見文末的參考資料 --> 35 <layout class="ch.qos.logback.classic.PatternLayout"> 36 <pattern> 37 [%p][%d{yyyy-MM-dd HH:mm:ssS}][%c#%M]:%L-%m%n 38 </pattern> 39 </layout> 40 </appender> 41 42 <!-- 任何一個類都只會對應一個logger,要不是某個具體的logger,要不就是root,root其實 43 類似於是logger的父類。並且一個類獲取logger時,默認就是獲取root,這里把前面配好的名為 44 logfile的Appender配置給root --> 45 <root level="info"> 46 47 </appender-ref></root> 48 49 <!-- 這么配置的話,com.cry.test下的logger會走這個,並且輸出級別為info,而不在這個 50 包下的會走上面的root --> 51 <logger level="info" name="com.cry.test"> 52 53 <!-- 這個logger就能看出logback在企業應用中巨大的靈活性,我們可能不關注spring框架產生的 54 各種各樣的info日志,但還是非常關心warn級別日志的 --> 55 <logger level="warn" service="org.springframework"> 56 57 </logger></logger></property></configuration>
使用
現在可以開心的打印日志了。
比如說你想在某個類里打印日志到文件,只需要聲明為一個成員變量如下:
1 //Logger和LoggerFactory都是slf4j提供的 2 private static final Logger log = 3 LoggerFactory.getLogger(AccountController.class);
然后在任意地方調用:
log.info("Deep dark fantasy!");
好了,日志就被成功記錄了,你將在運行服務端的機器上,你指定的位置,看到日志文件:
打開文件,你將看到這樣一行:
如果服務器布置在其它機器上,比如常見的情況是部署在某台linux服務器上,那我們使用SecureCRT之類的工具連接到命令窗口上,也可以很方便的找到日志文件(或者通過grep找到),並且使用vim之類的工具查看。
現在,恭喜你成功地配置好了日志組件,並打出了日志!
新需求!按線程編號的日志!
對於企業級的應用,這樣的需求是相當常見的:
對每個請求中的日志進行編號,比如以springMVC為例,在Controller的某一個URL處理方法上,接收參數直到返回視圖之間的所有操作,我們希望都具有同樣的標識,比如打印出來的日志有同樣的LogId。
因為比如你這個url接口上調用的某個方法出了問題,那我們就很想知道發生問題的前因后果是什么樣的,並且springMVC的設計就是一個請求一個線程,同一個LogId就意味着同一個客戶端的同一次請求,可以借此追蹤該線程的行為,這對於debug或者維護顯然是非常有用的,非常實用!
那么思考一下,怎么實現呢?每個線程都有自己的一個屬性:LogId,我們還需要在這個線程方法棧中涉及到的各個方法都獲取到這個屬性並打印,比如像下面這種情況:
1 @RequestMapping(value = "/get") 2 @ResponseBody 3 public ResultBean<t> get(Param model) { 4 5 VO result = manager.findVO(model); 6 7 //LogUtil用於按規則拼接出要打印的日志字符串 8 log.info(LogUtil.logResult(model, result)); 9 10 return ResultBean.success(result); 11 }
中間還會跳到manager.findVO方法里,但它們是同一個線程調用的,所以想讓它們有同樣的LogId,該怎么辦呢?生成一個LogId然后傳參數到findVO里?未免太丑太糟糕了。那么怎么做能更優雅一些,更易讀易維護呢?
解決方案:ThreadLocal+攔截器!
前兩天剛寫過一篇分析ThreadLocal的文章(戳此鏈接查看),覺得ThreadLocal用在這里不是正合適嗎?我們希望每個線程都有一個屬於該線程的數據:LogId,這個數據應該每個線程各有一個副本,不能共享,而且最好管理方便,不要方法之間傳來傳去的。那么ThreadLocal簡直完美解決了這個問題!如果把LogId存在各個線程自己的“線程本地存儲”里,那就可以輕松實現這個需求了。
然而,怎么在一個線程開始的時候分配給它LogId呢?使用springMVC提供的攔截器豈不可以開心的實現!前兩天也是剛好寫過分析攔截器的文章(戳此鏈接查看)。
那么我們創建一個攔截器,比如可以叫作LogInceptor:
1 /** 2 * 日志處理攔截器 3 * 4 */ 5 public class LogInterceptor implements HandlerInterceptor { 6 7 @Override 8 public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object o) throws Exception { 9 LogUtil.logRequest(); 10 11 return true; 12 } 13 14 @Override 15 public void postHandle(HttpServletRequest request, HttpServletResponse response, Object o, ModelAndView modelAndView) throws Exception {} 16 17 @Override 18 public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object o, Exception e) throws Exception {} 19 }
preHandle里永遠返回true,那也就意味着這只是想做做手腳,不是要把request攔下來。我們只是想在請求到來之時,生成一個LogId。
來看看LogUtil.logRequest()怎么寫:
1 /** 2 * 記錄請求日志 3 * 4 * @param request 5 */ 6 public static void logRequest() { 7 8 //生成一個logId,怎么生成隨你便,這里就是搞個大點的隨機數 9 String logId = CommonUtil.getRandomNum(12); 10 11 //把這個logId存進線程本地數據副本里 12 LocalMap.set(LOG_ID, logId); 13 }
注意LogUtil是單例模式,不然每次搞出來一個就搞笑了。上面的LocalMap是創建的另一個類,用於保管每個線程的信息(畢竟logId應該只是線程里的多個數據之一)。我的意思是,每個線程都有一個本地數據副本,這個例子里我就讓每個線程的本地數據是一個Map,鍵值對“(LOG_ID, logId)”就保存了這個線程的logId信息。
LocalMap可以這么實現(代碼非原創,來自JiaYY):
1 public class LocalMap { 2 3 private static final ThreadLocal<map<string, object="">> CONTEXT = new ThreadLocal<>(); 4 5 private LocalMap() { 6 7 } 8 9 /** 10 * 向當前線程暫存數據 11 * 12 * @param key 13 * @param value 14 */ 15 public static void set(String key, Object value) { 16 Map<string, object=""> map = contextMap(); 17 if(map != null) { 18 map.put(key, value); 19 } 20 } 21 22 /** 23 * 從當前線程獲取暫存數據 24 * 25 * @param key 26 * @return 27 */ 28 public static String get(String key) { 29 String value = ""; 30 Map<string, object=""> map = contextMap(); 31 if(map != null && map.get(key) != null) { 32 value = String.valueOf(map.get(key)); 33 } 34 return value; 35 } 36 37 /** 38 * 資源釋放 39 */ 40 public static void destroy() { 41 Map<string, object=""> map = contextMap(); 42 if (map != null) { 43 if (!map.isEmpty()) { 44 map.clear(); 45 } 46 } 47 CONTEXT.remove(); 48 } 49 50 /** 51 * 獲取當前線程里暫存的數據 52 * @return 53 */ 54 public static Map<string, object=""> contextMap() { 55 Map<string, object=""> map = CONTEXT.get(); 56 if (map == null) { 57 map = new HashMap<>(); 58 CONTEXT.set(map); 59 } 60 return map; 61 } 62 63 }
get/set方法差不多就是這么實現,我們可愛的ThreadLocal對象也是在這被實例化的,注意這個類也是單例的,並且雖然這個類是單例的,但每個訪問它的線程將會get/set到自己的數據副本(原理見我分析ThreadLocal那篇文章)。然后ThreadLocal的泛型在這里就是一個Map,也就是前面我說的“每個線程有一個自己的Map”。
然后在LogUtil里寫一個獲取logId的方法:
1 /** 2 * 獲取請求日志id 3 * @return 4 */ 5 private static String getLogId() { 6 return LocalMap.get(LOG_ID); 7 }
現在你只要調用這個方法就可以開心的在任何地方獲取到當前線程的logId,我們的目的達到了。當然如果你在LogUtil里實現更多方便的方法,那就會用得更開心
最后一點小問題
如果你仔細看了上面的代碼,可能會擔心每次線程進來都產生一個數據副本,多了會OOM,那這個擔心是沒必要的。如果你仔細研究過ThreadLocal源碼就會發現,線程數據副本是存在於Thread類中的,而非存在於ThreadLocal,所以當線程結束,它的數據副本(作為該線程的內部變量)自然也被釋放了,其實並不會多到OOM。
但是實際上,tomcat維護了線程池,一些線程是被重復使用的, 並不會被銷毀,這樣的話當你取出線程的時候,說不定會發現線程里保存着之前的ThreadLocalMap,這就意味着你要么覆蓋掉之前的內容,要么在每次請求結束的時候,清空該線程的數據副本。前者效率略高一點,也不用多寫什么;后者效率略低一點,還需要你在攔截器afterCompletion里自己實現一個清理方法。
前者實現出來的話,其tomcat線程池占用的空間會稍大一些;后者則會小一點。但是后者還有其它的好處,比如對於一個很大的項目來說能預防未知的問題,畢竟誰也不知道別人會對這代碼干什么,會不會出現你暫時沒想到的BUG,會不會某一天每個線程都需要比較大的數據副本,保險一點總沒壞處。
我覺得這就像ACM題里,拿一個數組循環處理每次測試,你可以每次用之前清空一下,也可以直接拿來用,反正能覆蓋,但誰知道萬一某道題不能覆蓋了呢?萬一需求又變了呢?這個問題就仁者見仁,智者見智了。