優秀日誌實踐準則，你做到了幾點？

阿新 • • 發佈：2018-12-27

作者介紹

劉持，網易樂得高階工程師。

程式設計師的日常離不開日誌，日誌就好比私人祕書，負責執行週期一切trace工作。優秀的日誌實踐能極大幫助地程式設計師快速定位問題，減少線上錯誤報警。本文將從日誌書寫時各方面來做闡述，依據日誌推薦的日誌等級，做相應優秀日誌實踐的推薦。

一、重新認識日誌

1、日誌級別概述

ERROR

ERROR是最高級別錯誤，反映系統發生了非常嚴重的故障，無法自動恢復到正常態工作，需要人工介入處理。系統需要將錯誤相關痕跡以及錯誤細節記錄ERROR日誌中，方便後續人工回溯解決。

WARN

WARN是低級別異常日誌，反映系統在業務處理時觸發了異常流程，但系統可恢復到正常態，下一次業務可以正常執行。但WARN級別問題需要開發人員給予足夠關注，往往表示有引數校驗問題或者程式邏輯缺陷，當功能邏輯走入異常邏輯時，應該考慮記錄WARN日誌。

INFO

INFO日誌主要記錄系統關鍵資訊，旨在保留系統正常工作期間關鍵執行指標，開發人員可以將初始化系統配置、業務狀態變化資訊，或者使用者業務流程中的核心處理記錄到INFO日誌中，方便日常運維工作以及錯誤回溯時上下文場景復現。

DEBUG

DEBUG日誌是INFO日誌的好幫手，開發人員可以將各類詳細資訊記錄到DEBUG裡，起到除錯的作用，包括引數資訊、除錯細節資訊、返回值資訊等。其它等級不方便顯示的資訊都可以通過DEBUG日誌來記錄。

2、記錄日誌的時機

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

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

程式語言提示異常：如今各類主流的程式語言都包括異常機制，業務相關的流行框架有完整的異常模組。這類捕獲的異常是系統告知開發人員需要加以關注的，是質量非常高的報錯。應當適當記錄日誌，根據實際結合業務的情況使用WARN或者ERROR級別。
業務流程預期不符：除開平臺以及程式語言異常之外，專案程式碼中結果與期望不符時也是日誌場景之一，簡單來說所有流程分支都可以加入考慮。取決於開發人員判斷能否容忍情形發生。常見的合適場景包括外部引數不正確，資料處理問題導致返回碼不在合理範圍內等。
系統核心角色，元件關鍵動作：系統中核心角色觸發的業務動作是需要多加關注的，是衡量系統正常執行的重要指標。建議記錄INFO級別日誌，比如電商系統使用者從登入到下單的整個流程；微服務各服務節點互動；核心資料表增刪改；核心元件執行等，如果日誌頻度高或者列印量特別大，可以提煉關鍵點INFO記錄，其餘酌情考慮DEBUG級別。

系統初始化：系統或者服務的啟動引數。核心模組或者元件初始化過程中往往依賴一些關鍵配置，根據引數不同會提供不一樣的服務。務必在這裡記錄INFO日誌，打印出引數以及啟動完成態服務表述。

3、警惕日誌效能代價

不管是多麼優秀的日誌工具，在日誌輸出時總會對效能產生或多或少的影響，為了將影響降低到最低，有以下幾個準則需要遵守：

根本原則：有必要才記錄日誌，頻繁過量日誌對效能是有損耗的，並且這種風險不常在系統正常時出現，系統出現問題時大量ERROR、INFO等問題相關日誌有可能產生連鎖反應，造成嚴重的後果。將關鍵資訊儲存到日誌，同時考慮極端場景日誌爆發。
Logger獲取：根據系統使用的日誌框架組合，確定正確的例項獲取方式。在log4j的早期版本，一般要求使用static，而在高版本以及後來的slf4j等一些框架封裝中，該問題已經得到優化，獲取（建立）logger例項的成本已經很低。但對於多例，尤其是需要頻繁建立的class，推薦新增static字首。
輸出等級校驗：在log4j 1.x版本，對於可以預見的會頻繁產生的日誌輸出，先判斷一下(logger.isXXXEnabled()，對於效能有很大提升，在其它外觀框架或者log4j 2.x中已經自動實現。
輸出格式：禁止使用字串拼接，使用引數方式。
樣式配置：佈局配置輸出的資訊也會影響到效能，需要根據logger的具體使用場景來選擇輸出合適資訊。

上述幾點可以看出，核心都是減少日誌量 ，前兩點偏向設計，後四點偏向日誌框架及習慣，並且這四點目前一些框架組合已經能幫開發人員減少不少工作，比如log4j2.x在例項獲取，輸出等級判斷都有優化。

除開減少日誌量，還需要注意多執行緒以及高併發情況下的日誌輸出。日誌輸出本身是寫磁碟操作，自然會有效能瓶頸。更多屬於日誌框架選擇及優化方面，選擇日誌框架時除了考慮正常功能使用，務必關注該日誌框架影響效能的細節，日誌的出發點是幫助處理問題，如果成為隱患就得不償失了。介紹日誌框架選擇的文章很多，在此就不做詳細介紹了。

二、優秀的INFO、DEBUG實踐

INFO和DEBUG級別日誌描述的是系統正常執行時的表徵。在監控程式正常執行，處理客服反饋，分析使用者行為時起到重要作用。因此優秀的INFO、DEBUG日誌能幫助開發人員快速瞭解執行時的各個細節。

1、使用場景

線上問題跟蹤

客服反饋或者線上問題很難解決時，需要更多細節資訊，這時會尋求日誌的幫助，ERROR、WARN、INFO都可能對解決問題有所幫助。必要時還需要開啟DEBUG日誌幫忙線上定位問題。

場景還原

隨著資料重要性越來越高，日誌的作用不再單單幫助糾錯，構建上下文也成為日誌大放光彩的地方。還原一個會話，需要在日誌中需要加入會話標識的概念，可以是簡單的ip或者複雜會話痕跡。常見包括以下兩個角度：

模組維度記錄：登入模組、商品詳情模組、下單模組、支付模組、派發模組等；
以行為維度記錄：在什麼時間，在什麼地方，在幹什麼，結果是什麼樣；統一加上會話標識以及時間屬性即可。這也是微服務日誌以及資料分析的基礎。

監控調優

對於系統的監控調優也是日常工作之一，主要通過日誌進行資訊記錄，主要關注以下3個部分的日誌：

請求處理時間
模組操作處理的時間
核心元件操作的時間（DB、快取、磁碟IO等）

2、日誌內容

日誌應當提供如下內容：

時間，包含時區資訊和毫秒，這個工作往往日誌框架足以支援。核心屬性之一。
日誌級別，例如DEBUG、INFO以及WARN、ERROR。
會話標識，能知道是哪個客戶端或者是哪個使用者觸發、登陸賬號、seesion資訊等
功能標識，功能標識的意義在於方便日誌搜尋，跟蹤指定功能的完整軌跡，是INFO、DEBUG日誌的常見技巧。跟logger分類同一道理，更細分功能標識則是方法標識，更多使用在DEBUG做線上除錯使用。
精煉的內容，內容永遠是日誌的核心，結合上述使用場景，簡單來說包括場景資訊（誰，什麼功能等），狀態資訊(開始，中斷，結束)以及重要引數。
其它資訊，其它可能的有用資訊包括：版本號、執行緒號等。

3、INFO和DEBUG的選擇

DEBUG級別比INFO低，包含除錯時更詳細地瞭解系統執行狀態的東西，比如變數的值等，都可以輸出到DEBUG日誌裡。 INFO是線上日誌預設的輸出級別，反饋系統的當前狀態給終端使用者看的。輸出的資訊，應該對終端使用者具有實際意義的。

從功能角度上說，INFO輸出的資訊可以看作是軟體產品的一部分，所以需要謹慎對待，不可隨便輸出。嘗試記錄INFO日誌時不妨在頭腦中模擬線上執行，如果這條日誌會被頻繁列印或者大部分時間對於糾錯起不到作用，就應當考慮下調為DEBUG級別。

4、注意事項

由於INFO及DEBUG日誌列印量遠大於ERROR，出於前文日誌效能的考慮，如果程式碼為核心程式碼，執行頻率非常高，務必推敲日誌設計是否合理，是否需要下調為DEBUG級別日誌。
注意日誌的可讀性，不妨在寫完程式碼review這條日誌是否通順，能否提供真正有意義的資訊。
日誌輸出是多執行緒公用的，如果有另外一個執行緒正在輸出日誌，上面的記錄就會被打斷，最終顯示輸出和預想的就會不一致。
線上程式碼禁止出現各類print等
不要認為記錄DEBUG就等同於線上忽略。很多情況因為擔心線上出問題時缺少有用資訊而對於等級猶豫不決，擔心記錄為DEBUG對於線上除錯起不到作用。你需要的不是研究日誌級別，而是實時日誌等級調整工具。嘗試記錄為DEBUG，線上有必要使用DEBUG級別除錯時再調整對應logger級別。

三、優秀的WARN、ERROR實踐

1、使用時機和思路

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

增加判斷處理邏輯，嘗試本地解決
丟擲異常，交給上層邏輯解決
記錄日誌，報警提醒
使用返回碼包裝錯誤做返回

2、幾個成長階段

不記錄日誌，順其自然，tomcat或者框架來捕獲最後的異常
方法出入口try catch， e.printstack()， system.out， log混合使用
有判斷校驗減少異常可能性，能合理小範圍使用try catch，使用log作為唯一記錄方式
靈活運用處理辦法，合理拋留異常，報警少而精

3、方法和準則

增加邏輯判斷吞掉報警永遠是最優選擇。

不在預期範圍內的情景，則考慮返回碼包裝或者丟擲異常，需要依情況而定：

返回碼的缺點：不直觀，不友好，處處都需要進行顯示判斷，返回碼都有具體含義，但字面不體現，持續維護時程式碼理解成本高。

異常機制的缺點：

必須在系統內部，多系統互動，前後臺互動場景等無法使用。
每一個異常分支都可能需要單獨一個類作為描述和控制，大量錯誤型別造成程式碼量增加。

一旦丟擲異常，必須catch處理，挑選正確方式：

列印日誌：當前邏輯就能處理掉的，不需要上層再處理的，或者本身就是最上層。
重拋異常：判斷異常當前無法處理，需要繼續向上丟擲，可以經過異常包裝轉義。需要注意當前是否為最上層。

避免過大的try塊，儘量保持一個try塊對應一個或多個異常。

細化異常的型別，避免不顧細節丟擲Excetpion。異常類的作用就是告訴Java編譯器我們想要處理的是哪一種異常，然後針對具體的異常類進行不同的處理。
函式返回值能表達錯誤含義，則不應該列印ERROR日誌，防止ERROR日誌氾濫。錯誤不一定到邊界才能終止，只要返回到能處理它的地方就應當終止。

4、使用WARN和統計報警

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

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

請使用WARN級別配合統計報警，統計報警的實現方法有很多種：程式碼統計、指令碼統計、Zabbix統計等，挑選合適的統計方式結合WARN級別，建立頻次報警機制，做到適時、適量提醒。

5、強調ERROR報警

ERROR的報出應該伴隨著業務功能受損，即上面提到的系統中發生了非常嚴重的問題，必須有人馬上處理。

6、ERROR日誌目標

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

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

7、實用模板

日誌模板2選1：

log.error(“[介面名或操作名] [Some Error Msg] happens. [Probably Because]. [Probably need to do] [params] .”);

log.error(“[介面名或操作名] [Some Error Msg] happens. [Probably Because]. [please contact [email protected]] [params] .”);

請儘量按上述模板完成，如果實施起來有難度，至少ERROR日誌列印時需要在做一個自我問答，能非常有效地幫助評估這條報警是否有意義：這條報警看到之後我能處理嗎？應該怎麼處理? 如果是同事看到能處理或者及時通知聯絡人呢嗎？因為你不可能保證隨時都處在工作狀態，但報警時隨時有可能出現的。

8、注意事項

引數檢查不是異常

不要將屬於你的檢查工作變成ERROR日誌。引數檢查屬於開發人員的工作，而不是全部交給日誌。

留意業務相關性

技術相關異常是你需要記錄併為此做出反應的。比如記憶體不足，介面訪問超時。涉業務過深的返回需要結合實際情況考慮，比如使用者操作錯誤大多屬於業務範疇：使用者無許可權參與這次活動返回碼。在大多數場景下這個日誌作用不大。

異常增加結構化引數

異常代表一類錯誤，但僅僅是異常型別無法幫助解決問題。保留異常現場引數，保證所有相關的堆疊追蹤資訊的開始處記錄在你的日誌中。

不要記錄日誌又重新向外丟擲

四、總結

實際專案中清晰的日誌能帶來的好處想必不用多說。本文除開介紹常見日誌等級以及實踐準則之外，更希望DEBUG、WARN兩種級別更多、更靈活地利用起來，在專案中形成完整的日誌體系。實際專案中清晰的日誌能帶來的好處想必不用多說。本文除開介紹常見日誌等級以及實踐準則之外，更希望DEBUG、WARN兩種級別更多、更靈活地利用起來，在專案中形成完整的日誌體系。

參考資料

https://www.slf4j.org/manual.html

http://logging.apache.org/log4j/2.x/

附錄：阿里java程式設計規範-日誌部分

日誌規約

【強制】應用中不可直接使用日誌系統（Log4j、Logback）中的API，而應依賴使用日誌框架SLF4J中的API，使用門面模式的日誌框架，有利於維護和各個類的日誌處理方式統一。

import org.slf4j.Logger;

import org.slf4j.LoggerFactory;

private static final Logger logger = LoggerFactory.getLogger(Abc.class);

slf4j是日誌門面框架，其僅提供日誌記錄的API，而不實現日誌記錄的功能，slf4j需要通過適配庫適配到log4j或logback等日誌系統來實現日誌的記錄。使用slf4j api能夠提升程式碼和應用的可移植性，在使用不同日誌系統的應用之間能夠做到無縫的適配。同時，使用slf4j api的應用，在切換日誌系統時（比如從logback切換到log4j2，不需要程式碼改造）

【強制】日誌檔案推薦至少儲存15天，因為有些異常具備以“周”為頻次發生的特點。

【強制】應用中的擴充套件日誌（如打點、臨時監控、訪問日誌等）命名方式：appName_logType_logName.log。

logType:日誌型別，推薦分類有stats/desc/monitor/visit等；

logName:日誌描述。這種命名的好處：通過檔名就可知道日誌檔案屬於什麼應用，什麼型別，什麼目的，也有利於歸類查詢。

正例：mppserver應用中單獨監控時區轉換異常，如： mppserver_monitor_timeZoneConvert.log

說明：推薦對日誌進行分類，如將錯誤日誌和業務日誌分開存放，便於開發人員檢視，也便於通過日誌對系統進行及時監控。

【強制】對trace/debug/info級別的日誌輸出，必須使用條件輸出形式或者使用佔位符的方式。

說明：logger.debug(“Processing trade with id: ” + id + ” symbol: ” + symbol); 如果日誌級別是warn，上述日誌不會列印，但是會執行字串拼接操作，如果symbol是物件，會執行toString()方法，浪費了系統資源，執行了上述操作，最終日誌卻沒有列印。

正例：（條件）

if (logger.isDebugEnabled()) {

logger.debug(“Processing trade with id: ” + id + ” symbol: ” + symbol);

}

正例：（佔位符）

logger.debug(“Processing trade with id: {} symbol : {} “, id, symbol);

佔位符方式，log4j2/logback支援，log4j1.x是不直接支援的，只能通過slf4j庫適配

【強制】避免重複列印日誌，浪費磁碟空間，務必在log4j.xml中設定additivity=false。

正例：

additivity預設為true，即通過該logger輸出的日誌會同時輸出到root logger，如果還為該logger指定了獨立的appender，就會導致這部分日誌重複輸出

【強制】異常資訊應該包括兩類資訊：案發現場資訊和異常堆疊資訊。如果不處理，那麼通過關鍵字throws往上丟擲。

正例：

logger.error(各類引數或者物件toString + “_” + e.getMessage(), e);

記錄異常日誌的常見錯誤：

logger.error(e);

logger.error(e.getMessage());

logger.error(“上下文”+e.getMessage())；

上面這幾種都是錯的！請確保使用的是兩個入參的API，如error(String s, Throwable t)

【推薦】謹慎地記錄日誌。生產環境禁止輸出debug日誌；有選擇地輸出info日誌；如果使用warn來記錄剛上線時的業務行為資訊，一定要注意日誌輸出量的問題，避免把伺服器磁碟撐爆，並記得及時刪除這些觀察日誌。

說明：大量地輸出無效日誌，不利於系統性能提升，也不利於快速定位錯誤點。記錄日誌時請思考：這些日誌真的有人看嗎？看到這條日誌你能做什麼？能不能給問題排查帶來好處？不要認為日誌記錄不怎麼消耗效能，我見過不少事無鉅細式的日誌把系統性能嚴重拖慢的案例

【參考】可以使用warn日誌級別來記錄使用者輸入引數錯誤的情況，避免使用者投訴時，無所適從。注意日誌輸出的級別，error級別只記錄系統邏輯出錯、異常。

原文來自微信公眾號：DBAplus社群