title: 后端日志最佳實踐
Date: 2021/07/27 09:18
什么是日志荔棉?
日志是用來記錄用戶操作辑鲤、系統(tǒng)運行狀態(tài)等井赌,是一個系統(tǒng)的重要組成部分闸翅。
對于一些簡單的應用,可能并不需要在如何記錄日志的問題上花費太多精力辜伟。
但是對于作為基礎平臺為很多產品提供服務的后端程序氓侧,就必須要考慮如何依靠良好的日志來保證系統(tǒng)可靠的運行了。
你是不是也遇到過這種情況导狡?
1)請求出錯時不能通過日志直接來定位問題约巷,而需要開發(fā)人員再臨時增加日志并要求請求的發(fā)送者重新發(fā)送同樣的請求才能定位問題;
2)無法確定服務中的后臺任務是否按照期望執(zhí)行旱捧;
3)無法確定服務的內存數(shù)據(jù)結構的狀態(tài)独郎;
4)無法確定服務的異常處理邏輯(如重試)是否正確執(zhí)行;
5)無法確定服務啟動時配置是否正確加載枚赡;
在看線上日志的時候氓癌,你可曾陷入到這樣的日志泥潭?該出現(xiàn)的日志沒有标锄,無用的日志一大堆顽铸,或者需要的信息分散在各個角落茁计,特別是遇到緊急的在線bug時料皇,有效的日志被大量無意義的日志信息淹沒谓松,焦急且無奈地浪費大量精力查詢日志。那什么是記錄日志的合適時機呢践剂?
什么時候應該打日志鬼譬?
編程語言提示異常:如今各類主流的編程語言都包括異常機制。這類捕獲的異常是系統(tǒng)告知開發(fā)人員需要加以關注的逊脯,是質量非常高的報錯优质。應當適當記錄日志,根據(jù)實際結合業(yè)務的情況使用warn或者error級別军洼。
-
與業(yè)務流程預期不符:項目代碼中結果與期望不符時也是日志場景之一巩螃,常見的場景包括:
- 外部參數(shù)不正確
- 由于參數(shù)問題導致查詢出的結果不符合規(guī)范等。
-
系統(tǒng)核心角色觸發(fā)的業(yè)務動作 & 組件關鍵動作:系統(tǒng)中核心角色觸發(fā)的業(yè)務動作也是衡量系統(tǒng)正常運行的重要指標匕争,建議記錄INFO級別日志避乏。
- 電商系統(tǒng)用戶從登錄到下單的整個流程(對于電商系統(tǒng)而言,用戶就是核心角色甘桑;對于 ars 系統(tǒng)而言用戶也是核心角色拍皮,所以他的每個操作還是要記錄的)
- 微服務各服務節(jié)點交互
- 核心數(shù)據(jù)表增刪改
- 核心組件運行等
- 注:如果日志頻度高或者打印量特別大,可以提煉關鍵點INFO記錄跑杭,其余酌情考慮DEBUG級別铆帽。
系統(tǒng)初始化:系統(tǒng)或者服務的啟動參數(shù)。核心模塊或者組件初始化過程中往往依賴一些關鍵配置德谅,根據(jù)參數(shù)不同會提供不一樣的服務爹橱。務必在這里記錄INFO日志,打印出參數(shù)以及啟動完成態(tài)服務表述窄做。
其他的還有:
請求的入口和出口(也可以做一些統(tǒng)計的操作宅荤,例如:用戶IP、上傳下載的數(shù)據(jù)量浸策、請求耗時等)
外部服務的調用和返回
資源消耗操作冯键,例如讀寫文件
程序異常,例如數(shù)據(jù)庫無法連接
后臺操作庸汗,例如定時執(zhí)行任務的線程
啟動惫确、關閉、配置加載
-
審計日志
- 對涉及到重要的信息進行記錄蚯舱。
- 審計主要體現(xiàn)在安全上改化,可以發(fā)現(xiàn)非授權的操作。
日志應該怎么打枉昏?
基本格式
- 日志時間
- 日志級別主要使用
- 調用鏈標識(可選)
- 線程名稱
- 日志記錄器名稱
- 日志內容
- 異常堆棧(不一定有)
11:44:44.827 WARN [93ef3E0120160803114444] [main] [ClassPathXmlApplicationContext] Exception encountered during context initialization - cancelling refresh attempt
日志級別
- ERROR:ERROR = 報警 = 某個功能徹底不可用陈肛,比如,數(shù)據(jù)庫連接異常(需要運維人員立刻修復)兄裂、業(yè)務功能受損(即系統(tǒng)的關鍵業(yè)務流程走不下去了句旱,比如:淘寶收貨地址服務宕機導致用戶無法修改收貨地址)等情況阳藻。這種日志出現(xiàn)之后要求立刻處理。一般不能隨便的打印 error 日志谈撒。在輸出 ERROR 級別的日志時腥泥,盡量多地輸出方法入?yún)?shù)、方法執(zhí)行過程中產生的對象等數(shù)據(jù)(toString not json)啃匿。
- WARN:WARN 級別的主要輸出警告性質的內容蛔外,這些內容是可以預知且是有規(guī)劃的,比如:用戶輸入?yún)?shù)錯誤溯乒、接口響應時間過長等夹厌。在 WARN 級別的時應輸出較為詳盡的信息,以便于事后對日志進行分析裆悄。WARN代表可恢復的異常尊流,此次失敗不影響下次業(yè)務的執(zhí)行。
- INFO:INFO 級別日志記錄的是在正常運行狀態(tài)下系統(tǒng)的關鍵信息灯帮,旨在保留系統(tǒng)正常工作期間關鍵運行指標崖技。開發(fā)可以將初始化系統(tǒng)配置、業(yè)務狀態(tài)變化信息钟哥,或者用戶業(yè)務流程中的核心處理記錄到 INFO 日志中迎献,方便日常運維工作以及錯誤回溯時上下文場景復現(xiàn)。
- DEBUG:DEBUG 級別主要輸出調試性質的內容腻贰,該級別日志主要用于在開發(fā)吁恍、測試階段輸出。該級別的日志應盡可能地詳盡播演,開發(fā)人員可以將各類詳細信息記錄到DEBUG里冀瓦,起到調試的作用,包括參數(shù)信息写烤,調試細節(jié)信息翼闽,返回值信息,Mybatis 執(zhí)行的 SQL(最好在打印前判斷下日志級別洲炊,否則字符串拼接還是挺費內存的)等等感局。
小練習
---- ERROR
模型連接超時
調用模型時傳入的參數(shù)格式不正確
---- WARN
調用模型時傳入的參數(shù)值有誤
---- INFO
XX 用戶啟動機器審查
重試
---- DEBUG
調用模型的請求參數(shù)
模型響應的結果
請求的用戶信息
考慮日志使用者
打印日志時要考慮日志的使用者,我們的日志的使用者主要是開發(fā)和運維人員暂衡,所以打印的日志最好是兩者都能看懂的(有的時候能讓運維人員解決询微,就別讓他們找我們):
2021-07-23 14:28:38.103 ERROR [ main] com.dist.Demo : 獲取任務實例code請求失敗
這種日志,開發(fā)可能會看懂狂巢,但是運維人員看到可能就會一頭霧水撑毛,只能在去找開發(fā)。所以至少應該是:
# 此處使用 ERROR 級別的日志是因為模型連接超時唧领,可能是由于模型服務掛掉了
# 記錄案發(fā)現(xiàn)場信息 + 堆棧信息
2021-07-23 14:28:38.103 ERROR [ main] com.dist.Demo : 調用模型接口「http://example.com/」時由于「連接超時」導致獲取任務實例 code 失敗藻雌。請求方法為「POST」雌续,請求參數(shù)為:「{name = zs}」
... 異常堆棧
這樣運維人員一眼就能清楚問題的原因(可能是模型掛了),而不用在找開發(fā)來確定問題蹦疑。
不記錄無用的日志
1)能夠放在一條日志里的東西西雀,放在多條日志中輸出萨驶;
2)預期會發(fā)生且能夠被正常處理的異常歉摧,打印出一堆無用的堆棧;
3)開發(fā)人員在開發(fā)過程中為了調試方便而加入的“臨時”日志
日志打印注意點
-
記錄異常處理邏輯腔呜,例如:
- 對于分布式存儲系統(tǒng)叁温,當系統(tǒng)從一個存儲節(jié)點上讀數(shù)據(jù)失敗時,需要去另一個數(shù)據(jù)節(jié)點上進行重試核畴,可以將讀數(shù)據(jù)失敗這件事情記錄下來膝但,之后可以通過對日志的分析確認是否某些節(jié)點的磁盤可能存在故障。
- 如果系統(tǒng)需要請求一個外部資源谤草,可以將請求這個外部資源偶爾失敗又重試成功這件事情記錄下來跟束,具體來說:
[INFO] RequestID:b1946ac92492d2347c6235b4d2611184, auth request (to http://auth1.example.com/v2) timeout ... 1 try [INFO] RequestID:b1946ac92492d2347c6235b4d2611184, auth request (to http://auth1.example.com/v2) timeout ... 2 try [INFO] RequestID:b1946ac92492d2347c6235b4d2611184, auth request (to http://auth1.example.com/v2) success
要好于
[INFO] RequestID:b1946ac92492d2347c6235b4d2611184, auth request (to http://auth1.example.com/v2) success
因為前者可以讓我們預判被依賴的服務器服務質量有風險,也許需要進行擴容丑孩;
-
對于 trace/debug/info 級別的日志輸出冀宴,必須進行日志級別的開關判斷。
// 雖然在 debug(參數(shù))的方法體內第一行代碼 isDisabled(Level.DEBUG_INT)為真時温学,就直接 return略贮,但是參數(shù)可能會進行字符串拼接運算。此外仗岖,如果 debug(getName()) 這種參數(shù)內有 getName()方法調用逃延,無謂浪費方法調用的開銷。 // 如果判斷為真轧拄,那么可以輸出 trace 和 debug 級別的日志 if (logger.isDebugEnabled()) { logger.debug("Current ID is: {} and name is: {}", id, getName()); }
-
為避免重復打印日志揽祥,浪費磁盤空間,請關閉
additivity
<logger name="com.taobao.dubbo.config" additivity="false">
-
異常信息應該包括兩類信息:案發(fā)現(xiàn)場信息和異常堆棧信息檩电。
log.error(e.getMessage());//錯誤示范 log.erroe("Bad Things",e.getMessage());//錯誤示范 log.error("Bad Things",e);//正確演示
日志打印時禁止直接用 JSON 工具將對象轉換成 String盔然。如果對象里某些get方法被重寫,存在拋出異常的情況是嗜,則可能會因為打印日志而影響正常業(yè)務流程的執(zhí)行愈案。打印日志時僅打印出業(yè)務相關屬性值或者調用其對象的 toString() 法。
-
不允許使用標準輸出
包括
System.out.println()
和System.error.println()
語句鹅搪。因為這個只會打印到控制臺站绪,而不會記錄到日志文件中,不方便管理日志丽柿。不允許使用
e.printStackTrace()
恢准,因為他使用的也是標準錯誤輸出魂挂。注:我們其實平時拋出的異常實際上也是輸出到了標準錯誤輸出中,但是 SpringMVC 和 Dubbo 都有異常攔截器馁筐,將這些異常攔截掉(try-catch)之后通過日志框架再進行打印涂召。
如果 INFO 級別日志數(shù)量過于龐大,考慮將日志級別調整為 DEBUG敏沉。
可以使用 warn 日志級別來記錄用戶輸入?yún)?shù)錯誤的情況果正,避免用戶投訴時,無所適從盟迟。如非必要秋泳,請不要在此場景打出 error 級別,避免頻繁報警攒菠。
-
注意日志輸出的級別迫皱,error 級別只記錄系統(tǒng)邏輯出錯、異诚街冢或者重要的錯誤信息卓起。
例如根據(jù)用戶傳入的 id 查詢一個數(shù)據(jù),如果查詢不到凹炸,是否應該拋出異常戏阅,拋出異常這個動作太重了,但不通過異常由沒法結束整個調用鏈路还惠,那么怎么辦呢饲握?
太重
-
error 代表著報警,需要運維處理蚕键。
So救欧,我們可以自定義 dubbo、spring 攔截器锣光,攔截這些自定義異常笆怠,打印 warn 級別日志。
小技巧
動態(tài) DEBUG 日志輸出
DEBUG日志和INFO日志的一個重要的區(qū)別是誊爹,INFO 日志用于記錄常規(guī)的系統(tǒng)運行狀態(tài)(業(yè)務狀態(tài)變化信息蹬刷、用戶業(yè)務流程中的核心處理記錄等),對于定位一般的問題已經足夠了频丘。而 DEBUG 日志則詳細的記錄了一個請求的處理過程办成,甚至是每一個函數(shù)的輸入和輸出結果,遇到一些隱藏比較深的問題時搂漠,必須要依賴DEBUG日志迂卢。
然而,由于 DEBUG 級別的日志數(shù)量比INFO級別的數(shù)量多很多(通常差一個數(shù)量級),如果長期在線上服務器開啟 DEBUG 級別的日志輸出而克,日志量太大靶壮。再比如,有時候僅僅是由于某一個用戶的訪問模式比較特殊導致了問題员萍,如果將整個服務(特別是一個服務部署了很多臺節(jié)點時)都臨時調整為 DEBUG 級別日志輸出腾降,也非常不方便。
所以可以采用這種方案:當接收到的HTTP請求的QueryString中包含DEBUG=true
參數(shù)時碎绎,就將所有的DEBUG級別的日志也輸出螃壤。
慢操作日志
服務在接收到一個請求的時候,記錄請求的接收時間(T1)混卵,在請求處理完成待發(fā)送的時候映穗,會記錄請求發(fā)送時間(T2)窖张,通常一個請求的日志都記為INFO級別幕随,然而當出現(xiàn)請求處理時間(T2-T1)超過一定時間(如10s)時,可以將該日志提升為WARN級別宿接。通過該方法赘淮,可以預先發(fā)現(xiàn)系統(tǒng)可能存在的一些問題。
同樣的慢操作日志還可以用來記錄系統(tǒng)一些外部依賴的處理時間睦霎,如一個服務可能依賴外部認證服務器來進行認證授權梢卸。通過記錄每次認證請求的時間并將超出預期時間的請求日志采用WARN級別輸出,可以盡早發(fā)現(xiàn)認證服務器是不是需要擴容等問題副女。
慢日志的時間閾值應該是可以動態(tài)調整的蛤高,這樣在進行系統(tǒng)優(yōu)化時,可以將該報警時間閾值逐漸調小碑幅,不斷地對系統(tǒng)進行優(yōu)化戴陡。
Error 級別日志報警
上面在講日志級別的時候說過 ERROR 級別代表著系統(tǒng)某個地方出現(xiàn)了問題需要運維人員來處理,那么一般我們都會采用郵件通知的方式進行報警沟涨,Logback 也為我們提供了這樣的一個 Appender —— SMTPAppender恤批。
具體使用參見下面兩篇文章:
- https://blog.csdn.net/qq_16605855/article/details/85251357
- http://www.cxyzjd.com/article/fusugongzi/77165136
日志監(jiān)控報警注意事項:
能不報警的就不報警,只有需要運維馬上處理的錯誤才需要發(fā)送報警裹赴。這樣做的原因是避免長期的報警騷擾讓運維人員對報警不再敏感喜庞,最后真的報警來了時,變成了狼來了的傳說棋返;
明確報警關鍵字延都,例如用 ERROR 作為報警的關鍵字,而不是各種各樣的復雜規(guī)則睛竣。這樣做的原因是日志監(jiān)控本質上是不斷的進行字符串匹配操作晰房,如果規(guī)則太多太復雜,就可能對線上服務產生影響;
對于一些預警操作嫉你,例如某個服務需要重試多次才能成功月帝,或者某個用戶的配額快用完等等,可以通過每天一封報警郵件的方式來反饋幽污;
每一次系統(tǒng)出現(xiàn)故障嚷辅,都需要及時檢查日志報警是否靈敏,日志報警的描述是否準確等距误,不斷優(yōu)化日志報警簸搞;
ERROR、WARN 級別日志打印包名和行號
ERROR & WARN 日志都代表著系統(tǒng)出現(xiàn)了問題准潭,需要解決趁俊;但有時僅僅憑借著一行日志并不能很快的定位到問題,所以可以考慮將打印 ERROR刑然、WARN 日志的包名和行號打印出來寺擂。
logback 并沒有提供這種功能,不過我們可以通過自定義 Layout 來實現(xiàn)泼掠。
DEV 環(huán)境不向本地輸出日志文件
開發(fā)環(huán)境是用于開發(fā)本地調試時使用怔软,一般都只需要看控制臺就可以,所以沒必要在本地輸出日志文件择镇,那么我們可以利用 logback 的“條件表達式”來實現(xiàn):
<!-- 注:當環(huán)境為 dev 時挡逼,將日志文件輸出至系統(tǒng)緩存文件夾 -->
<if condition='property("PROFILES_ACTIVE").contains("dev")'>
<then>
<springProperty scope="context" name="LOG_PATH" source="logging.path"
defaultValue="../DEFAULT_LOG_PATH/${APPLICATION_NAME}/${PROFILES_ACTIVE}"/>
</then>
<else>
<springProperty scope="context" name="LOG_PATH" source="logging.path"
defaultValue="../DEFAULT_LOG_PATH/${APPLICATION_NAME}/${PROFILES_ACTIVE}"/>
</else>
</if>
日志輸出到不同的文件
在性能測試時遇到的另一個問題是,當并發(fā)量很大時腻豌,可能會有一些請求處理失敿铱病(如0.5%),為了對這些錯誤進行分析吝梅,需要去查這些錯誤請求的日志虱疏。而由于這種情況下日志量巨大,使得對錯誤日志的分析變得困難憔涉。
這種情況下可以將所有的錯誤日志(ERROR)同時輸出到一個單獨的文件之中订框。
我現(xiàn)在是整了 3 個日志文件:
- all.log - 存儲所有級別的日志
- warn.log - 單獨存儲 warn 級別日志
- error.log - 單獨存儲 error 級別日志
日志文件大小
日志文件不宜過大,過大的日志文件對于日志監(jiān)控兜叨,問題定位等都會帶來不便穿扳。因此需要進行日志文件的切分,日志文件應該按天來分割国旷,還是按照小時來分割矛物,應該根據(jù)日志量來決定,原則就是方便開發(fā)或運維人員能快速查找日志跪但。
logback 日志工具可以在日志文件滾動后將前一文件進行壓縮履羞,以減少磁盤空間占用,若使用 logback 對于日志量龐大的應用建議開啟該功能。
為了防止日志文件將整個磁盤空間占滿忆首,需要定期對日志文件進行刪除爱榔。例如,在收到磁盤報警時糙及,可以將兩個月以前的日志文件刪除详幽。
生產環(huán)境中的文件輸出,可以考慮使用異步文件輸出浸锨,該種方式日志并不會馬上刷新到文件中去唇聘,會產生日志延時,在停止應用時可能會導致一些還在內存中的日志未能及時刷新到文件中去而產生丟失柱搜,如果對于應用的要求并不是非常高的話迟郎,可考慮異步日志
鏈路追蹤
本部分只介紹 zipkin
Zipkin 是一款開源的分布式實時數(shù)據(jù)追蹤系統(tǒng),主要功能是聚集來自各個異構系統(tǒng)的實時監(jiān)控數(shù)據(jù)聪蘸,和微服務架構下的接口直接的調用鏈路和系統(tǒng)延時問題宪肖。
總結一下鏈路追蹤工具主要提供了以下功能:
- 將一次請求所涉及到的鏈路串聯(lián)起來,這個請求并非特指 http 請求宇姚,也可以是其他(redis匈庭、rpc)請求
- 定位整個鏈路的延時問題夫凸,通過這個來動態(tài)調整應用實例數(shù)量浑劳。
所以其實沒有必要所有的請求的鏈路都上傳到 zipkin,zipkin 為我們提供了一個采樣率的概念:
- CountingSampler 計數(shù)采集夭拌,每多少次請求才收集一個魔熏,比如說30個請求之后,再收集一個鸽扁。
- BoundarySampler 概率采集蒜绽,最小值是0.0001,最大是1桶现,0表示從來不采集躲雅。
- RateLimitingSampler 限速采集,比如說限制秒鐘最多采集10個骡和,就可以用這個相赁。
推薦文章
總結
- 以下情況下需要打日志:
- 編程語言提示異常(但一般框架會有異常攔截器攔截進行異常的打印)慰于,因為不打印進日志只會在控制臺中看到钮科。
- 程序異常,例如數(shù)據(jù)庫無法連接(ERROR)
- 輸入?yún)?shù)不正確(WARN)
- 查詢出數(shù)據(jù)不正確(根據(jù)情況選擇 WARN 或 ERROR)
- 核心角色觸發(fā)的業(yè)務動作(INFO)
- 核心數(shù)據(jù)表的增刪改(INFO)
- 核心組件的運行(INFO)
- 請求的入口和出口婆赠、外部服務的調用和返回(根據(jù)情況選擇 DEBUG 或 INFO)
- 資源消耗操作绵脯,例如讀寫文件(DEBUG)
- 后臺操作,例如定時執(zhí)行任務的線程(根據(jù)情況選擇 DEBUG 或 INFO)
- 啟動、關閉蛆挫、配置加載(INFO)
注:如果日志頻度高或者打印量特別大赃承,可以提煉關鍵點INFO記錄,其余酌情考慮DEBUG級別悴侵。
- 日志級別
- ERROR:系統(tǒng)中某個功能徹底不可用(比如數(shù)據(jù)庫異常楣导、數(shù)據(jù)庫中數(shù)據(jù)有問題等),需要運維人員立刻處理畜挨。
- WARN:WARN 代表可恢復的異常筒繁,此次失敗不影響下次業(yè)務的執(zhí)行(比如:用戶輸入?yún)?shù)錯誤、接口響應時間過長)
- INFO:正常運行狀態(tài)下系統(tǒng)關鍵信息(比如:初始化系統(tǒng)配置巴元、業(yè)務狀態(tài)變化信息毡咏,或者用戶業(yè)務流程中的核心處理記錄)。
- DEBUG:調試性質的內容逮刨,該級別日志主要用于在開發(fā)呕缭、測試階段輸出,該級別的日志應盡可能地詳盡(比如:參數(shù)信息修己,調試細節(jié)信息恢总,返回值信息)。
- 考慮日志的使用者睬愤,日志要包括案發(fā)現(xiàn)場信息和異常堆棧信息片仿,盡量讓運維人員能夠通過日志排查一部分問題。
- 記錄一些異常邏輯尤辱,比如:重試過程中日志的記錄砂豌。
- 對于 trace/debug/info 級別的日志輸出,必須進行日志級別的開關判斷光督。
- 打印時禁止使用 Json 序列化對象阳距,使用對象的 toString() 方法。
最重要的還是不斷優(yōu)化日志结借。
不斷優(yōu)化日志
有一點可以肯定筐摘,好的日志就像好的文章一樣,絕不是一遍就可以寫好的船老,而需要在實際的運維過程中咖熟,結合線上問題的定位,不斷地進行優(yōu)化努隙。
此處有以下幾個比較好的實踐:
- 在定位問題的過程中完善日志球恤,如果定位問題花費了很長時間,那就說明系統(tǒng)日志還存在問題荸镊,需要進一步完善和優(yōu)化咽斧;
- 需要思考是否可以通過優(yōu)化日志堪置,來提前預判該問題是否可能發(fā)生(如某種資源耗盡而導致的錯誤,可以對資源的使用情況進行記錄)
- 定義好整個團隊記錄日志的規(guī)范张惹,保證每個開發(fā)記錄的日志格式統(tǒng)一舀锨;特別需要說明的是,對于DEBUG/TRACE級別的日志宛逗,也需要定義好清晰的格式坎匿,而不是由開發(fā)人員自由發(fā)揮;
- 整個團隊(包括開發(fā)雷激,運維和測試)定期對記錄的日志內容進行Review替蔬;
- 運維或測試在日志中發(fā)現(xiàn)的問題,都需要及時向開發(fā)人員反映屎暇;
參考文檔
其他 TODO
1)鏈路追蹤
2)訪問日志
3)Swagger 頁面動態(tài)切換用戶 或者使用 chrome 插件實現(xiàn)(不推薦承桥,因為還要安裝,java 瀏覽器版就是這樣沒火起來的)
或者插件根悼⌒滓欤可以記住的。點擊切換用戶(cookie)挤巡,時間要比一般的長
4)其他
logback 的原理
root 和 logger 的繼承
5)規(guī)范
不能用父類的logger 對象