Java日志記錄最佳實踐

一、日志簡介

1.1 日志是什麼（WHAT）

日志：記錄程式的運作軌迹，友善查找關鍵資訊，也友善快速定位解決問題。

通常，Java程式員在開發項目時都是依賴Eclipse/IDEA等內建開發工具的Debug 調試功能來跟蹤解決Bug，但項目釋出到了測試、生産環境怎麼辦？你有可能會說可以使用遠端調試，但實際并不能允許讓你這麼做。

是以，日志的作用就是在測試、生産環境沒有 Debug 調試工具時開發和測試人員定位問題的手段。日志打得好，就能根據日志的軌迹快速定位并解決線上問題，反之，日志輸出不好，不僅無法輔助定位問題反而可能會影響到程式的運作性能和穩定性。

很多介紹 AOP 的地方都采用日志來作為介紹，實際上日志要采用切面的話是極其不科學的！對于日志來說，隻是在方法開始、結束、異常時輸出一些什麼，那是絕對不夠的，這樣的日志對于日志分析沒有任何意義。如果在方法的開始和結束整個日志，那方法中呢？如果方法中沒有日志的話，那就完全失去了日志的意義！如果應用出現問題要查找由什麼原因造成的，也沒有什麼作用。這樣的日志還不如不用！

1.2 日志有什麼用（WHY）

不管是使用何種程式設計語言，日志輸出幾乎無處不再。總結起來，日志大緻有以下幾種用途：

問題追蹤：輔助排查和定位線上問題，優化程式運作性能。
狀态監控：通過日志分析，可以監控系統的運作狀态。
安全審計：審計主要展現在安全上，可以發現非授權的操作。

1.3 總結

日志在應用程式中是非常非常重要的，好的日志資訊能有助于我們在程式出現 BUG 時能快速進行定位，并能找出其中的原因。

作為一個有修養的程式猿，對日志這個東西應當引起足夠的重視。

二、日志架構（HOW）

2.1 常用的日志架構

log4j、Logging、commons-logging、slf4j、logback，開發的同學對這幾個日志相關的技術不陌生吧，為什麼有這麼多日志技術，它們都是什麼差別和聯系呢？且看下文分解：

2.1.1 Logging

這是 Java 自帶的日志工具類，在 JDK 1.5 開始就已經有了，在 java.util.logging 包下。通常情況下，這個基本沒什麼人用了，了解一下就行。

2.1.2 commons-logging

commons-logging 是日志的門面接口，它也是Apache 最早提供的日志門面接口，使用者可以根據喜好選擇不同的日志實作架構，而不必改動日志定義，這就是日志門面的好處，符合面對接口抽象程式設計。現在已經不太流行了，了解一下就行。

2.1.3 Slf4j

slf4j,英文全稱為“Simple Logging Facade for Java”，為java提供的簡單日志Facade。Facade門面，更底層一點說就是接口。它允許使用者以自己的喜好，在工程中通過slf4j接入不同的日志系統。

是以slf4j入口就是衆多接口的集合，它不負責具體的日志實作，隻在編譯時負責尋找合适的日志系統進行綁定。具體有哪些接口，全部都定義在slf4j-api中。檢視slf4j-api源碼就可以發現，裡面除了public final class LoggerFactory類之外，都是接口定義。是以slf4j-api本質就是一個接口定義。

2.1.4 Log4j

Log4j 是 Apache 的一個開源日志架構，也是市場占有率最多的一個架構。

注意：log4j 在 2015.08.05 這一天被 Apache 宣布停止維護了，使用者需要切換到 Log4j2上面去。

下面是官宣原文：

On August 5, 2015 the Logging Services Project Management Committee announced that Log4j 1.x had reached end of life. For complete text of the announcement please see the Apache Blog. Users of Log4j 1 are recommended to upgrade to Apache Log4j 2.

2.1.5 Log4j2

Log4j 2 Apache Log4j 2是apache開發的一款Log4j的更新産品。

Log4j2與Log4j1發生了很大的變化，log4j2不相容log4j1。

2.1.6 Logback

Logback 是 Slf4j 的原生實作架構，同樣也是出自 Log4j 一個人之手，但擁有比 log4j 更多的優點、特性和更做強的性能，現在基本都用來代替 log4j 成為主流。

Logback相對于log4j擁有更快的執行速度。基于我們先前在log4j上的工作，logback 重寫了内部的實作，在某些特定的場景上面，甚至可以比之前的速度快上10倍。在保證logback的元件更加快速的同時，同時所需的記憶體更加少。

2.2 日志架構怎麼選

選項太多了的後果就是選擇困難症，我的看法是沒有最好的，隻有最合适的：

commons-loggin、slf4j 隻是一種日志抽象門面，不是具體的日志架構。

log4j、logback 是具體的日志實作架構。
在比較關注性能的地方，選擇Logback或自己實作高性能Logging API可能更合适。推薦： slf4j + logback .
在已經使用了Log4j的項目中，如果沒有發現問題，繼續使用可能是更合适的方式：推薦組合為： slf4j + log4j2 .
如果不想有依賴則使用java.util.logging或架構容器已經提供的日志接口。

三、記錄日志的時機

在看線上日志的時候，我們可曾陷入到日志泥潭？該出現的日志沒有，無用的日志一大堆，或者需要的資訊分散在各個角落，特别是遇到緊急的線上bug時，有效的日志被大量無意義的日志資訊淹沒，焦急且無奈地浪費大量精力查詢日志。那什麼是記錄日志的合适時機呢？

總結幾個需要寫日志的點：

程式設計語言提示異常：如今各類主流的程式設計語言都包括異常機制，業務相關的流行架構有完整的異常子產品。這類捕獲的異常是系統告知開發人員需要加以關注的，是品質非常高的報錯。應當适當記錄日志，根據實際結合業務的情況使用warn或者error級别。
業務流程預期不符：除開平台以及程式設計語言異常之外，項目代碼中結果與期望不符時也是日志場景之一，簡單來說所有流程分支都可以加入考慮。取決于開發人員判斷能否容忍情形發生。常見的合适場景包括外部參數不正确，資料處理問題導緻傳回碼不在合理範圍内等等。
系統核心角色，元件關鍵動作：系統中核心角色觸發的業務動作是需要多加關注的，是衡量系統正常運作的重要名額，建議記錄INFO級别日志，比如電商系統使用者從登入到下單的整個流程；微服務各服務節點互動；核心資料表增删改；核心元件運作等等，如果日志頻度高或者列印量特别大，可以提煉關鍵點INFO記錄，其餘酌情考慮DEBUG級别。
系統初始化：系統或者服務的啟動參數。核心子產品或者元件初始化過程中往往依賴一些關鍵配置，根據參數不同會提供不一樣的服務。務必在這裡記錄INFO日志，列印出參數以及啟動完成态服務表述。

四、日志列印最佳實踐

4.1 日志變量定義

日志變量往往不變，最好定義成final static，變量名用大寫。

private static final Logger log = LoggerFactory.getLogger({SimpleClassName}.getClass());

通常一個類隻有一個

log

對象，如果有父類可以将

log

定義在父類中。

日志變量類型定義為門面接口（如 slf4j 的 Logger），實作類可以是 Log4j、Logback 等日志實作架構，不要把實作類定義為變量類型，否則日志切換不友善，也不符合抽象程式設計思想。

另外，推薦引入lombok的依賴，在類的頭部加上

@Slf4j

的注解，之後便可以在程式的任意位置使用

log

變量列印日志資訊了，使用起來更加簡潔一點，在重構代碼尤其是修改類名的時候無需改動原有代碼。

4.2 參數占位格式

使用參數化形式{}占位，[]進行參數隔離

log.debug("Save order with order no：[{}], and order amount：[{}]");
log.debug("Save order with order no：[{}], and order amount：[{}]");

這種可讀性好，這樣一看就知道[]裡面是輸出的動态參數，{}用來占位類似綁定變量，而且隻有真正準備列印的時候才會處理參數，友善定位問題。

如果日志架構不支援參數化形式，且日志輸出時不支援該日志級别時會導緻對象備援建立，浪費記憶體，此時就需要使用 isXXEnabled 判斷，如：

if(log.isDebugEnabled()){
    // 如果日志不支援參數化形式，debug又沒開啟，那字元串拼接就是無用的代碼拼接，影響系統性能
    log.debug("Save order with order no：" + orderNo + ", and order amount：" + orderAmount);
}

至少 debug 級别是需要開啟判斷的，線上日志級别至少應該是 info 以上的。

這裡推薦大家用 SLF4J 的門面接口，可以用參數化形式輸出日志，debug 級别也不必用 if 判斷，簡化代碼。

4.3 日志的基本格式

日志輸出主要在檔案中，應包括以下内容：

日志時間
日志級别主要使用
調用鍊辨別（可選）
線程名稱
日志記錄器名稱
日志内容
異常堆棧（不一定有）

11:44:44.827 WARN [93ef3E0120160803114444] [main] [ClassPathXmlApplicationContext] Exception encountered during context initialization - cancelling refresh attempt

4.3.1 日志時間

作為日志産生的日期和時間，這個資料非常重要，一般精确到毫秒。由于線上一般配置為按天滾動日志檔案，日期辨別在檔案名上，是以可以不放在這個時間中，使用

HH:mm:ss.SSS

格式即可。非要加上也未嘗不可，格式推薦：

yyyy-MM-dd HH:mm:ss.SSS

。

4.3.2 日志級别

日志的輸出都是分級别的，不同的設定不同的場合列印不同的日志。下面拿最普遍用的 Log4j 日志架構來做個日志級别的說明，這個也比較齊全，其他的日志架構也都大同小異。

主要使用如下的四個級别：

DEBUG：DEUBG 級别的主要輸出調試性質的内容，該級别日志主要用于在開發、測試階段輸出。該級别的日志應盡可能地詳盡，開發人員可以将各類詳細資訊記錄到DEBUG裡，起到調試的作用，包括參數資訊，調試細節資訊，傳回值資訊等等，便于在開發、測試階段出現問題或者異常時，對其進行分析。
INFO：INFO日志主要記錄系統關鍵資訊，旨在保留系統正常工作期間關鍵運作名額，開發人員可以将初始化系統配置、業務狀态變化資訊，或者使用者業務流程中的核心處理記錄到INFO日志中，友善日常運維工作以及錯誤回溯時上下文場景複現。建議在項目完成後，在測試環境将日志級别調成 INFO，然後通過 INFO 級别的資訊看看是否能了解這個應用的運用情況，如果出現問題後是否這些日志能否提供有用的排查問題的資訊。
WARN：WARN 級别的主要輸出警告性質的内容，這些内容是可以預知且是有規劃的，比如，某個方法入參為空或者該參數的值不滿足運作該方法的條件時。在 WARN 級别的時應輸出較為詳盡的資訊，以便于事後對日志進行分析
ERROR：ERROR 級别主要針對于一些不可預知的資訊，諸如：錯誤、異常等，比如，在 catch 塊中抓獲的網絡通信、資料庫連接配接等異常，若異常對系統的整個流程影響不大，可以使用 WARN 級别日志輸出。在輸出 ERROR 級别的日志時，盡量多地輸出方法入參數、方法執行過程中産生的對象等資料，在帶有錯誤、異常對象的資料時，需要将該對象一并輸出

4.3.2.1 INFO和DEBUG的選擇

DEBUG級别比INFO低，包含調試時更詳細的了解系統運作狀态的東西，比如變量的值等等，都可以輸出到DEBUG日志裡。 INFO是線上日志預設的輸出級别，回報系統的目前狀态給最終使用者看的。輸出的資訊，應該對最終使用者具有實際意義的。從功能角度上說，Info輸出的資訊可以看作是軟體産品的一部分，是以需要謹慎對待，不可随便輸出。嘗試記錄INFO日志時不妨在頭腦中模拟線上運作，如果這條日志會被頻繁列印或者大部分時間對于糾錯起不到作用，就應當考慮下調為DEBUG級别。

由于info及debug日志列印量遠大于ERROR，出于前文日志性能的考慮，如果代碼為核心代碼，執行頻率非常高，務必推敲日志設計是否合理，是否需要下調為DEBUG級别日志。
注意日志的可讀性，不妨在寫完代碼review這條日志是否通順，能否提供真正有意義的資訊。
日志輸出是多線程公用的，如果有另外一個線程正在輸出日志，上面的記錄就會被打斷，最終顯示輸出和預想的就會不一緻。

4.3.2.2 WARN,ERROR的選擇

當方法或者功能處理過程中産生不符合預期結果或者有架構報錯時可以考慮使用，常見問題處理方法包括：

增加判斷處理邏輯，嘗試本地解決：增加邏輯判斷吞掉報警永遠是最優選擇。
抛出異常，交給上層邏輯解決
記錄日志，報警提醒
使用傳回碼包裝錯誤做傳回

一般來說，WARN級别不會短信報警，ERROR級别則會短信報警甚至電話報警，ERROR級别的日志意味着系統中發生了非常嚴重的問題，必須有人馬上處理，比如資料庫不可用，系統的關鍵業務流程走不下去等等。錯誤的使用反而帶來嚴重的後果，不區分問題的重要程度，隻要有問題就error記錄下來，其實這樣是非常不負責任的，因為對于成熟的系統，都會有一套完整的報錯機制，那這個錯誤資訊什麼時候需要發出來，很多都是依據機關時間内ERROR日志的數量來确定的。是以如果我們不分輕重緩急，一律ERROR對待，就會徒增報錯的頻率，久而久之，我們的救火隊員對錯誤警報就不會那麼在意，這個警報也就失去了原始的意義。

WARN代表可恢複的異常，此次失敗不影響下次業務的執行，開發人員會苦惱某些場景下幾次失敗可容忍，頻率高的時候需要提醒，記錄ERROR的結果是線上時不時出現容忍範圍内的報警，這時報警是無意義的。但反之不記錄ERROR日志，真正出現問題則不會有實時報警，錯過最佳處理時機。

強調ERROR報警

ERROR級别的日志列印通常伴随報警通知。ERROR的報出應該伴随着業務功能受損，即上面提到的系統中發生了非常嚴重的問題，必須有人馬上處理。

ERROR日志目标

給處理者直接準确的資訊：error資訊形成自身閉環。

問題定位：

發生了什麼問題，哪些功能受到影響
擷取幫助資訊：直接幫助資訊或幫助資訊的存儲位置
通過報警知道解決方案或者找何人解決

日志模闆

log.error(“[接口名或操作名] [Some Error Msg] happens. [Probably Because]. [Probably need to do] [params] .”);
log.error(“[接口名或操作名] [Some Error Msg] happens. [Probably Because]. [please contact xxx@xxx] [params] .”);

4.3.3 調用鍊辨別

在分布式應用中，使用者的一個請求會調用若幹個服務完成，這些服務可能還是嵌套調用的，是以完成一個請求的日志并不在一個應用的日志檔案，而是分散在不同伺服器上不同應用節點的日志檔案中。該辨別是為了串聯一個請求在整個系統中的調用日志。

調用鍊辨別格式：

唯一字元串（trace ID）
調用層級（span ID）

調用鍊辨別作為可選項，無該資料時隻輸出 [] 即可。

4.3.4 線程名稱

輸出該日志的線程名稱，一般在一個應用中一個同步請求由同一線程完成，輸出線程名稱可以在各個請求産生的日志中進行分類，便于厘清目前請求上下文的日志。

4.3.5 日志記錄器名稱

日志記錄器名稱一般使用類名，日志檔案中可以輸出簡單的類名即可，看實際情況是否需要使用包名和行号等資訊。主要用于看到日志後到哪個類中去找這個日志輸出，便于定位問題所在。

4.3.6 日志内容

禁用 System.out.println和System.err.println
變參替換日志拼接
輸出日志的對象，應在其類中實作快速的 toString 方法，以便于在日志輸出時僅輸出這個對象類名和 hashCode
預防空指針:不要在日志中調用對象的方法擷取值，除非確定該對象肯定不為 null，否則很有可能會因為日志的問題而導緻應用産生空指針異常。

// 不推薦
log.debug( "Load student(id={}), name: {}" , id , student.getName() );

// 推薦
log.debug( "Load student(id={}), student: {}" , id , student );

對于一些一定需要進行拼接字元串，或者需要耗費時間、浪費記憶體才能産生的日志内容作為日志輸出時，應使用 log.isXxxxxEnable() 進行判斷後再進行拼接處理，比如：

if (log.isDebugEnable()) {
    StringBuilder builder = new StringBuilder();
    for (Student student : students) {
        builder.append("student: ").append(student);
    }
    builder.append("value: ").append(JSON.toJSONString(object));
    log.debug( "debug log example, detail: {}" , builder );
}

4.3.7 異常堆棧

異常堆棧一般會出現在 ERROR 或者 WARN 級别的日志中，異常堆棧含有方法調用鍊的系統，以及異常産生的根源。異常堆棧的日志屬于上一行日志的，在日志收集時需要将其劃至上一行中。

4.4 日志檔案

日志檔案放置于固定的目錄中，按照一定的模闆進行命名，推薦的日志檔案名稱：

目前正在寫入的日志檔案名：<應用名>[-<功能名>].log
已經滾入曆史的日志檔案名：<應用名>[-<功能名>].log.<yyyy-MM-dd>

4.5 日志配置

根據不同的環境配置不同的日志輸出方式：

本地調試可以将日志輸出到控制台上
測試環境或者生産環境輸出到檔案中，每天産生一個檔案，如果日志量龐大可以每個小時産生一個日志檔案
生産環境中的檔案輸出，可以考慮使用異步檔案輸出，該種方式日志并不會馬上重新整理到檔案中去，會産生日志延時，在停止應用時可能會導緻一些還在記憶體中的日志未能及時重新整理到檔案中去而産生丢失，如果對于應用的要求并不是非常高的話，可暫不考慮異步日志

logback 日志工具可以在日志檔案滾動後将前一檔案進行壓縮，以減少磁盤空間占用，若使用 logback 對于日志量龐大的應用建議開啟該功能。

具體的配置示例，由于篇幅較長，單獨開一篇介紹。詳情可移步：日志使用項目實戰

4.6 日志使用規範

在一個對象中通常隻使用一個Logger對象，Logger應該是static final的，隻有在少數需要在構造函數中傳遞logger的情況下才使用private final。

private static final Logger log = LoggerFactory.getLogger(Main.class);

不要使用具體的日志實作類

InterfaceImpl interface = new InterfaceImpl();

這段代碼大家都看得懂吧？應該面向接口的對象程式設計，而不是面向實作，這也是軟體設計模式的原則，正确的做法應該是。

Interface interface = new InterfaceImpl();

日志架構裡面也是如此，上面也說了，日志有門面接口，有具體實作的實作架構，是以大家不要面向實作程式設計。

輸出Exceptions的全部Throwable資訊。因為 log.error(msg) 和 log.error(msg,e.getMessage()) 這樣的日志輸出方法會丢失掉最重要的StackTrace資訊。

void foo(){
    try{
       //do somehing 
    }catch(Exception e){
        log.error(e.getMessage());//錯誤示範
        log.erroe("Bad Things",e.getMessage());//錯誤示範
        log.error("Bad Things",e);//正确示範
    }
}

不允許記錄日志後又抛出異常。如捕獲異常後又抛出了自定義業務異常，此時無需記錄錯誤日志，由最終捕獲方進行異常處理。不能又抛出異常，又列印錯誤日志，不然會造成重複輸出日志。

void foo() throws LogException{
    try{
        //do somehing 
    }catch(Exception e){
        log.error("Bad Things",e);//正确
        throw new LogException("Bad Things",e);
    }
}

不允許使用标準輸出

包括

System.out.println()

和

System.error.println()

語句。因為這個隻會列印到控制台，而不會記錄到日志檔案中，不友善管理日志。此外，标準輸出不會顯示類名和行号資訊，一旦代碼中大量出現标準輸出的代碼，且日志中列印有标準輸出的内容，很難定位日志内容和日志列印的位置，根本無法排查問題，想删除無用日志輸出也改不動，這個是筆者在重構古董代碼的時候親自踩過的一個坑。

void foo(){
    try{
       //do somehing 
    }catch(Exception e){
        Syste.out.println(e.getMessage());//錯誤
        System.error.println(e.getMessage());//錯誤
        log.error("Bad Things",e);//正确
    }
}

不允許出現printStackTrace

void foo(){
    try{
       //do somehing 
    }catch(Exception e){
        e.printStacktrace();//錯誤
        log.error("Bad Things",e);//正确
    }
}

來看一下它的源碼：

public void printStackTrace() {
    printStackTrace(System.err);
}

它其實也是利用

System.err

輸出到了Tomcat控制台。

禁止線上上環境開啟debug級别日志輸出

出于日志性能的考慮，如果代碼為核心代碼，執行頻率非常高，則輸出日志建議增加判斷，尤其是低級别的輸出<debug、info、warn>。

一是因為項目本身 debug 日志太多，二是各種架構中也大量使用 debug 的日志，線上開啟 debug 不久就會打滿磁盤，影響業務系統的正常運作。

不要在大循環中列印日志

如果你的架構使用了性能不高的 Log4j 架構，那就不要在上千個 for 循環中列印日志，這樣可能會拖垮你的應用程式，如果你的程式響應時間變慢，那要考慮是不是日志列印的過多了。

for(int i=0; i<2000; i++){
    log.info("XX");
}

最好的辦法是在循環中記錄要點，在循環外面總結列印出來。

列印有意義的日志

通常情況下在程式日志裡記錄一些比較有意義的狀态資料：程式啟動，退出的時間點；程式運作消耗時間；耗時程式的執行進度；重要變量的狀态變化。

五、參考資料

Java 程式如何正确地打日志
Java 應用中的日志
優秀日志實踐準則
Java常用日志架構介紹