Java 日志記錄最佳實踐,寫得太好了吧!


作者:GeekerLou
來源:jianshu.com/p/546e9aace657

一、日志簡介

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 日志使用規范

  1. 在一個對象中通常只使用一個Logger對象,Logger應該是static final的,只有在少數需要在構造函數中傳遞logger的情況下才使用private final。
private static final Logger log = LoggerFactory.getLogger(Main.class);
  1. 不要使用具體的日志實現類
InterfaceImpl interface = new InterfaceImpl();

這段代碼大家都看得懂吧?應該面向接口的對象編程,而不是面向實現,這也是軟件設計模式的原則,正確的做法應該是。

Interface interface = new InterfaceImpl();

日志框架里面也是如此,上面也說了,日志有門面接口,有具體實現的實現框架,所以大家不要面向實現編程。

  1. 輸出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);//正確演示
    }
}
  1. 不允許記錄日志后又拋出異常。如捕獲異常后又拋出了自定義業務異常,此時無需記錄錯誤日志,由最終捕獲方進行異常處理。不能又拋出異常,又打印錯誤日志,不然會造成重復輸出日志。
void foo() throws LogException{
    try{
        //do somehing 
    }catch(Exception e){
        log.error("Bad Things",e);//正確
        throw new LogException("Bad Things",e);
    }
}
  1. 不允許使用標准輸出

包括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);//正確
    }
}
  1. 不允許出現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控制台。

  1. 禁止在線上環境開啟debug級別日志輸出

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

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

  1. 不要在大循環中打印日志

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

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

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

  1. 打印有意義的日志

通常情況下在程序日志里記錄一些比較有意義的狀態數據:程序啟動,退出的時間點;程序運行消耗時間;耗時程序的執行進度;重要變量的狀態變化。

五、參考資料

  1. Java 程序如何正確地打日志
  2. Java 應用中的日志
  3. 優秀日志實踐准則
  4. Java常用日志框架介紹

近期熱文推薦:

1.1,000+ 道 Java面試題及答案整理(2021最新版)

2.別在再滿屏的 if/ else 了,試試策略模式,真香!!

3.卧槽!Java 中的 xx ≠ null 是什么新語法?

4.Spring Boot 2.5 重磅發布,黑暗模式太炸了!

5.《Java開發手冊(嵩山版)》最新發布,速速下載!

覺得不錯,別忘了隨手點贊+轉發哦!


免責聲明!

本站轉載的文章為個人學習借鑒使用,本站對版權不負任何法律責任。如果侵犯了您的隱私權益,請聯系本站郵箱yoyou2525@163.com刪除。



 
粵ICP備18138465號   © 2018-2025 CODEPRJ.COM